hanganalyze分析会话阻塞

 

 

参考文档:USING AND READING HANGANALYZE或者[ID 215858.1]

1、模拟阻塞会话
数据库版本：
SQL> select * from v$version;

BANNER
----------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - Production
PL/SQL Release 11.2.0.2.0 - Production
CORE    11.2.0.2.0      Production
TNS for 32-bit Windows: Version 11.2.0.2.0 - Production
NLSRTL Version 11.2.0.2.0 - Production

会话1：
SQL> delete from t_lf where id=1;

已删除 1 行。

会话2：
SQL> delete from t_lf where id=1;
会话此时hang住

2、hanganalyze分析
--sys登录
SQL> oradebug setmypid
已处理的语句
SQL> oradebug unlimit;
已处理的语句
SQL> oradebug hanganalyze 3
Hang Analysis in G:\ORACLE\diag\rdbms\orcl11g\orcl11g\trace\orcl11g_ora_10972.trc

Trace file G:\ORACLE\diag\rdbms\orcl11g\orcl11g\trace\orcl11g_ora_10972.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
Windows NT Version V6.1 Service Pack 1
CPU                 : 4 - type 586, 2 Physical Cores
Process Affinity    : 0x0x00000000
Memory (Avail/Total): Ph:847M/3492M, Ph+PgF:2533M/6983M, VA:1040M/2047M
Instance name: orcl11g
Redo thread mounted by this instance: 1
Oracle process number: 25
Windows thread id: 10972, image: ORACLE.EXE (SHAD)

*** 2013-10-21 15:03:31.765
*** SESSION ID:(575.1) 2013-10-21 15:03:31.765
*** CLIENT ID:() 2013-10-21 15:03:31.765
*** SERVICE NAME:(SYS$USERS) 2013-10-21 15:03:31.765
*** MODULE NAME:(sqlplus.exe) 2013-10-21 15:03:31.765
*** ACTION NAME:() 2013-10-21 15:03:31.765
 
Processing Oradebug command 'setmypid'

*** 2013-10-21 15:03:31.765
Oradebug command 'setmypid' console output:

*** 2013-10-21 15:03:39.175
Processing Oradebug command 'unlimit'

*** 2013-10-21 15:03:39.175
Oradebug command 'unlimit' console output:

*** 2013-10-21 15:03:48.660
Processing Oradebug command 'hanganalyze 3'

*** 2013-10-21 15:03:49.237
===============================================================================
HANG ANALYSIS:
  instances (db_name.oracle_sid): orcl11g.orcl11g
  oradebug_node_dump_level: 3
  analysis initiated by oradebug
  os thread scheduling delay history: (sampling every 1.000000 secs)
    0.000000 secs at [ 15:03:48 ]
      NOTE: scheduling delay has not been sampled for 0.656762 secs    0.000000 secs from [ 15:03:44 - 15:03:49 ], 5 sec avg
    0.000000 secs from [ 15:02:49 - 15:03:49 ], 1 min avg
    0.000116 secs from [ 14:58:49 - 15:03:49 ], 5 min avg
===============================================================================
 
Chains most likely to have caused the hang:
 [a] Chain 1 Signature: 'SQL*Net message from client'<='enq: TX - row lock contention'
     Chain 1 Signature Hash: 0x38c48850
 
===============================================================================
Non-intersecting chains:
 
-------------------------------------------------------------------------------
Chain 1:
-------------------------------------------------------------------------------
    Oracle session identified by:
    {
                instance: 1 (orcl11g.orcl11g)
                   os id: 10724
              process id: 17, ORACLE.EXE (SHAD)
              session id: 572
        session serial #: 5
    }
    is waiting for 'enq: TX - row lock contention' with wait info:
    {
                      p1: 'name|mode'=0x54580006
                      p2: 'usn<<16 | slot'=0x8000f
                      p3: 'sequence'=0x427
            time in wait: 3 min 13 sec
           timeout after: never
                 wait id: 24
                blocking: 0 sessions
             current sql: delete from t_lf where id=1
             short stack: _ksedsts()+373<-_ksdxfstk()+16<-_ksdxcb()+2011<-_ssthreadsrgruncallback()+482<
            wait history:
              * time between current wait and wait #1: 0.000015 sec
              1.       event: 'SQL*Net message to client'
                 time waited: 0.000003 sec
                     wait id: 495             p1: 'driver id'=0x42455100
                                              p2: '#bytes'=0x1
              * time between wait #1 and #2: 0.000564 sec
              2.       event: 'db file scattered read'
                 time waited: 0.000744 sec
                     wait id: 494             p1: 'file#'=0x5
                                              p2: 'block#'=0x974
                                              p3: 'blocks'=0xc
              * time between wait #2 and #3: 0.000554 sec
              3.       event: 'db file scattered read'
                 time waited: 0.003634 sec
                     wait id: 493             p1: 'file#'=0x5
                                              p2: 'block#'=0x967
                                              p3: 'blocks'=0xd
    }
 
Chain 1 Signature: 'SQL*Net message from client'<='enq: TX - row lock contention'
Chain 1 Signature Hash: 0x38c48850
-------------------------------------------------------------------------------
 
===============================================================================
Extra information that will be dumped at higher levels:
[level  4] :   1 node dumps -- [LEAF] [LEAF_NW]
[level  5] :   1 node dumps -- [NO_WAIT] [INVOL_WT] [SINGLE_NODE] [NLEAF] [SINGLE_NODE_NW]
 
State of ALL nodes
([nodenum]/cnode/sid/sess_srno/session/ospid/state/[adjlist]):
[8]/1/9/15/33A37DD0/12736/LEAF/
[571]/1/572/5/330D7A30/10724/NLEAF/[8]