Many sessions hang resolved by Hang Manager with ORA-32701 in alert log while the blocker is in 'Not in wait' status (Doc ID 1926781.1)

Last updated on OCTOBER 13, 2016

Applies to:

Oracle Database - Enterprise Edition - Version 11.2.0.2 to 11.2.0.3 [Release 11.2]
Information in this document applies to any platform.

Symptoms

In a RAC database, many sessions hang waiting for 'latch: shared pool' while the blocker is in 'Not in wait' status, after some time the Hang Manager kills the blocker to resolve the hang.

alert_racdb1.log

Fri Aug 01 08:13:46 2014
Errors in file /app/oracle/diag/rdbms/racdb/racdb1/trace/racdb1_dia0_11449.trc  (incident=448086):
ORA-32701: Possible hangs up to hang ID=11 detected
Incident details in: /app/oracle/diag/rdbms/racdb/racdb1/incident/incdir_448086/racdb1_dia0_11449_i448086.trc
DIA0 requesting termination of session sid:397 with serial # 39443 (ospid:29036) on instance 2
    due to a LOCAL, HIGH confidence hang with ID=11.
    Hang Resolution Reason: Automatic hang resolution was performed to free a
    significant number of affected sessions.
DIA0: Examine the alert log on instance 2 for session termination status of hang with ID=11.

alert_racdb2.log

Fri Aug 01 08:13:47 2014
Errors in file /app/oracle/diag/rdbms/racdb/racdb2/trace/racdb2_dia0_29919.trc  (incident=440083):
ORA-32701: Possible hangs up to hang ID=0 detected
Incident details in: /app/oracle/diag/rdbms/racdb/racdb2/incident/incdir_440083/racdb2_dia0_29919_i440083.trc
DIA0 terminating blocker (ospid: 29036 sid: 397 ser#: 39443) of hang with ID = 11
    requested by master DIA0 process on instance 1
    Hang Resolution Reason: Automatic hang resolution was performed to free a
    significant number of affected sessions.
    by terminating session sid: 397 ospid: 29036
DIA0 successfully terminated session sid:397 ospid:29036 with status 31.

racdb2_dia0_29919_i440083.trc shows:

*** 2014-08-01 08:13:47.258
Resolvable Hangs in the System
                      Root       Chain Total               Hang
   Hang Hang          Inst Root  #hung #hung  Hang   Hang  Resolution
     ID Type Status   Num  Sess   Sess  Sess  Conf   Span  Action
  ----- ---- -------- ---- ----- ----- ----- ------ ------ -------------------
     11 HANG RSLNPEND    2   397     2    20   HIGH  LOCAL Terminate Process
  Hang Resolution Reason: Automatic hang resolution was performed to free a
    significant number of affected sessions.

      inst# SessId  Ser#     OSPID PrcNm Event
      ----- ------ ----- --------- ----- -----
          2     14 51763     28909    FG latch: shared pool
          2    397 39443     29036    FG not in wait                   << this is the blocker

*** 2014-08-01 08:13:47.259
Process diagnostic dump for oracle@sunsrv07, OS id=29036,
pid: 98, proc_ser: 39, sid: 397, sess_ser: 39443

*** 2014-08-01 08:13:48.300
loadavg : 1.69 1.67 1.59
swap info: free_mem = 5899.01M rsv = 20630.68M
           alloc = 18763.03M avail = 32451.35M swap_free = 34319.00M
 F S      UID   PID  PPID   C PRI NI     ADDR     SZ    WCHAN    STIME TTY         TIME CMD
 0 O   oracle 29036     1  13  98 20        ? 1339838          08:10:41 ?           3:02 oracleracdb2 (LOCAL=NO)
Short stack dump:
ksedsts()+380<-ksdxfstk()+52<-ksdxcb()+3524<-sspuser()+140<-__sighndlr()+12<-call_user_handler()+992<-sigacthandler()+104<-kghfrunp()+1652
<-kghfnd()+3632<-kghalo()+3200<-kghgex()+900<-kghfnd()+2124<-kghprmalo()+300<-kghalp()+1916<-kghssgai()+820<-kkslcr()+604<-kkslsp()+80
<-kkslhsh()+496<-kkshmih()+84<-kksSetBindType()+4208<-kksfbc()+11044<-opiexe()+2748<-kpoal8()+1924<-opiodr()+1164<-ttcpip()+916<-opitsk()+1640
<-opiino()+924<-opiodr()+1164<-opidrv()+1032<-sou2o()+88<-opimai_real()+504<-ssthrdmain()+316<-main()+316<-_start()+380

*** 2014-08-01 08:13:48.412
current sql: SELECT TO_CHAR(val_reference_date, :"SYS_B_0"), val_reference_date
FROM STAT_VALIDATION
WHERE ...

                       holding    (efd=5) 3800f7440 Child shared pool level=7 child#=2
        Location from where latch is held: kgh.h LINE:6629 ID:kghalp:
                            waiter count=52


                     Current Wait Stack:
                        Not in wait; last wait ended 3 min 1 sec ago
                      There are 19 sessions blocked by this session.
                      Dumping one waiter:
                        inst: 2, sid: 1160, ser: 3849
                        wait event: 'latch: shared pool'
                          p1: 'address'=0x3800f7440
                          p2: 'number'=0x133
                          p3: 'tries'=0x0
                        row_wait_obj#: 153861, block#: 1838661, row#: 0, file# 9
                        min_blocked_time: 172 secs, waiter_cache_ver: 56585

 The holder process is a foreground process which is executing a select statement, it is running on a CPU with OS status "O". It blocked many sessions waiting for latch: shared pool.

 

Cause

Sign In with your My Oracle Support account

Don't have a My Oracle Support account? Click to get started

My Oracle Support provides customers with access to over a
Million Knowledge Articles and hundreds of Community platforms