oracledebug hanganalyze分析会话等待及存储过程hang

测试
1,oracledebug hanganalyze普通用户可以运行吗
　SQL> oradebug hanganalyze
          Hang Analysis in d:\oracle\diag\rdbms\orcl\orcl\trace\orcl_ora_2260.trc
          SQL> conn scott/system@orcl
          已连接。
          SQL> oradebug hanganalyze
         ORA-01031: 权限不足
        
         小结：普通用户不能运行此命令
        
  SQL> conn sys/system@orcl as sysdba
          已连接。
          SQL> grant dba to scott;
         
          授权成功。
         
          SQL> conn scott/system@orcl
          已连接。
          SQL> oradebug hanganalyze
          ORA-01031: 权限不足
         
          小结：dba权限不能运行此命令
          综述：仅sysdba才可以运行此命令
2,使用方法
　　1,分别开启两个scott用户连接的session,sid分别为：72,135
      72为持锁会话,135会等待锁会话
    2,以sysdba运行如下命令
        SQL> conn sys/system@orcl as sysdba
        已连接。
        SQL> oradebug hanganalyze
        Hang Analysis in d:\oracle\diag\rdbms\orcl\orcl\trace\orcl_ora_5372.trc
SQL>
3,如何查看trace文件
   如下为trace文件内容：
 
--部分无关内容略---
 
 --如下说明hang是因为什么原因引起，即什么事件，很明显是row lock contention,因为
 --72会话update　dept一行记录，而135会话也想更新dept表的同样的记录
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 (orcl.orcl)
                   os id: 5568
              process id: 26, ORACLE.EXE (SHAD)
              session id: 135 --135会话等待锁
        session serial #: 5
    }
    is waiting for 'enq: TX - row lock contention' with wait info:
    {
                      p1: 'name|mode'=0x54580006　--等待模式
                      p2: 'usn<<16 | slot'=0x8000e　--等待相关信息
                      p3: 'sequence'=0x5819
            time in wait: 16.246637 sec
           timeout after: never
                 wait id: 51
                blocking: 0 sessions
               
            --等待历史，等３次
            wait history:
              * time between current wait and wait #1: 0.003008 sec
              1.       event: 'SQL*Net message from client'
                 time waited: 15.462328 sec
                     wait id: 50              p1: 'driver id'=0x54435000
                                              p2: '#bytes'=0x1
              * time between wait #1 and #2: 0.000010 sec
              2.       event: 'SQL*Net message to client'
                 time waited: 0.000004 sec
                     wait id: 49              p1: 'driver id'=0x54435000
                                              p2: '#bytes'=0x1
              * time between wait #2 and #3: 0.000197 sec
              3.       event: 'SQL*Net message from client'
                 time waited: 0.021308 sec
                     wait id: 48              p1: 'driver id'=0x54435000
                                              p2: '#bytes'=0x1
    }
   
    ---持锁会话
    and is blocked by
 => Oracle session identified by:
    {
                instance: 1 (orcl.orcl)
                   os id: 1996
              process id: 25, ORACLE.EXE (SHAD)
              session id: 72 --会话72
        session serial #: 29
    }
    which is waiting for 'SQL*Net message from client' with wait info:
    {
                      p1: 'driver id'=0x54435000
                      p2: '#bytes'=0x1
            time in wait: 53.462782 sec
           timeout after: never
                 wait id: 71
                blocking: 1 session --此处也说明它是持锁会话
            wait history:
              * time between current wait and wait #1: 0.000010 sec
              1.       event: 'SQL*Net message to client'
                 time waited: 0.000002 sec
                     wait id: 70              p1: 'driver id'=0x54435000
                                              p2: '#bytes'=0x1
              * time between wait #1 and #2: 0.000159 sec
              2.       event: 'SQL*Net message from client'
                 time waited: 0.003821 sec
                     wait id: 69              p1: 'driver id'=0x54435000
                                              p2: '#bytes'=0x1
              * time between wait #2 and #3: 0.000021 sec
              3.       event: 'SQL*Net message to client'
                 time waited: 0.000004 sec
                     wait id: 68              p1: 'driver id'=0x54435000
                                              p2: '#bytes'=0x1
    }
 
Chain 1 Signature: 'SQL*Net message from client'<='enq: TX - row lock contention'
Chain 1 Signature Hash: 0x38c48850
-------------------------------------------------------------------------------
 
===============================================================================

--如下信息说明：可以更为详细trace　hanganalyze文件
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]):
[71]/1/72/29/F2601B6C/1996/LEAF/
[134]/1/135/5/F26A714C/5568/NLEAF/[71]

*** 2012-11-30 19:17:44.515
===============================================================================
END OF HANG ANALYSIS
===============================================================================

*** 2012-11-30 19:17:44.515
Oradebug command 'hanganalyze' console output:
Hang Analysis in d:\oracle\diag\rdbms\orcl\orcl\trace\orcl_ora_5372.trc

 

--如下为模拟编译存储过程hang的trace文件

*** 2012-11-30 19:17:44.515
Oradebug command 'hanganalyze' console output:
Hang Analysis in d:\oracle\diag\rdbms\orcl\orcl\trace\orcl_ora_5372.trc

*** 2012-11-30 19:39:48.287
Processing Oradebug command 'hanganalyze'

*** 2012-11-30 19:39:48.287
===============================================================================
HANG ANALYSIS:
  instances (db_name.oracle_sid): orcl.orcl
  no oradebug node dumps
  analysis initiated by oradebug
===============================================================================
 --存储过程编译hang原因是等待library cache pin
Chains most likely to have caused the hang:
 [a] Chain 1 Signature: 'PL/SQL lock timer'<='library cache pin'
     Chain 1 Signature Hash: 0xa7a4880c
 
===============================================================================
Non-intersecting chains:
 
-------------------------------------------------------------------------------
Chain 1:
-------------------------------------------------------------------------------
    --同上述的trace文件一个道理
    Oracle session identified by:
    {
                instance: 1 (orcl.orcl)
                   os id: 5568
              process id: 26, ORACLE.EXE (SHAD)
              session id: 135
        session serial #: 5
    }
    is waiting for 'library cache pin' with wait info:
    {
                      p1: 'handle address'=0xebb45c5c
                      p2: 'pin address'=0xebd6695c
                      p3: '100*mode+namespace'=0x20a6b00010003
            time in wait: 8.797742 sec
           timeout after: 14 min 51 sec
                 wait id: 80
                blocking: 0 sessions
            wait history:
              * time between current wait and wait #1: 0.010977 sec
              1.       event: 'SQL*Net message from client'
                 time waited: 11.784077 sec
                     wait id: 79              p1: 'driver id'=0x54435000
                                              p2: '#bytes'=0x1
              * time between wait #1 and #2: 0.000003 sec
              2.       event: 'SQL*Net message to client'
                 time waited: 0.000001 sec
                     wait id: 78              p1: 'driver id'=0x54435000
                                              p2: '#bytes'=0x1
              * time between wait #2 and #3: 0.000051 sec
              3.       event: 'SQL*Net message from client'
                 time waited: 0.001355 sec
                     wait id: 77              p1: 'driver id'=0x54435000
                                              p2: '#bytes'=0x1
    }
    and is blocked by
 => Oracle session identified by:
    {
                instance: 1 (orcl.orcl)
                   os id: 1996
              process id: 25, ORACLE.EXE (SHAD)
              session id: 72
        session serial #: 29
    }
    which is waiting for 'PL/SQL lock timer' with wait info:
    {
                      p1: 'duration'=0x7530
            time in wait: 28.097329 sec
           timeout after: 4 min 31 sec
                 wait id: 273
                blocking: 1 session
            wait history:
              * time between current wait and wait #1: 0.003674 sec
              1.       event: 'SQL*Net message from client'
                 time waited: 28.093404 sec
                     wait id: 272             p1: 'driver id'=0x54435000
                                              p2: '#bytes'=0x1
              * time between wait #1 and #2: 0.000011 sec
              2.       event: 'SQL*Net message to client'
                 time waited: 0.000003 sec
                     wait id: 271             p1: 'driver id'=0x54435000
                                              p2: '#bytes'=0x1
              * time between wait #2 and #3: 0.000821 sec
              3.       event: 'SQL*Net message from client'
                 time waited: 0.005253 sec
                     wait id: 270             p1: 'driver id'=0x54435000
                                              p2: '#bytes'=0x1
    }
 
Chain 1 Signature: 'PL/SQL lock timer'<='library cache pin'
Chain 1 Signature Hash: 0xa7a4880c

--某个session等待后台进程事件也可以分析出来
===============================================================================
Sessions in an involuntary wait or not in a wait:
 
-------------------------------------------------------------------------------
Chain 1:
-------------------------------------------------------------------------------
    --等待会话
    Oracle session identified by:
    {
                instance: 1 (orcl.orcl)
                   os id: 1996
              process id: 25, ORACLE.EXE (SHAD)
              session id: 72
        session serial #: 29
    }
    is not in a wait:
    {
               last wait: 1.794896 sec ago
                blocking: 0 sessions
               
             --等待什么事件
            wait history:
              1.       event: 'log buffer space'　--等待log buffer space,
                 time waited: 0.112722 sec
                     wait id: 493            
              * time between wait #1 and #2: 0.058570 sec
              2.       event: 'log buffer space'
                 time waited: 0.554377 sec
                     wait id: 492            
              * time between wait #2 and #3: 2.730704 sec
              3.       event: 'log file switch completion'
                 time waited: 0.039726 sec
                     wait id: 491            
    }
 
Chain 1 Signature:
Chain 1 Signature Hash: 0x673a0128
-------------------------------------------------------------------------------
 
===============================================================================
Extra information that will be dumped at higher levels:
[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]):
[71]/1/72/29/F2601B6C/1996/SINGLE_NODE_NW/

*** 2012-11-30 19:53:05.027
===============================================================================
END OF HANG ANALYSIS
===============================================================================

*** 2012-11-30 19:53:05.027
Oradebug command 'hanganalyze' console output:
Hang Analysis in d:\oracle\diag\rdbms\orcl\orcl\trace\orcl_ora_5372.trc

*** 2012-11-30 19:54:13.215
Processing Oradebug command 'hanganalyze'

*** 2012-11-30 19:54:13.215
===============================================================================
HANG ANALYSIS:
  instances (db_name.oracle_sid): orcl.orcl
  no oradebug node dumps
  analysis initiated by oradebug
===============================================================================
 
Chains most likely to have caused the hang:
 [a] Chain 1 Signature: 'log file parallel write'<='log buffer space'
     Chain 1 Signature Hash: 0x56c5cf5
 [b] Chain 2 Signature: 'control file parallel write'
     Chain 2 Signature Hash: 0xc17840d5
 
===============================================================================
Non-intersecting chains:
 
-------------------------------------------------------------------------------
Chain 1:
-------------------------------------------------------------------------------
    Oracle session identified by:
    {
                instance: 1 (orcl.orcl)
                   os id: 1996
              process id: 25, ORACLE.EXE (SHAD)
              session id: 72
        session serial #: 29
    }
    is waiting for 'log buffer space' with wait info:
    {
            time in wait: 0.058057 sec
           timeout after: never
                 wait id: 546
                blocking: 0 sessions
            wait history:
              * time between current wait and wait #1: 0.205410 sec
              1.       event: 'log file switch completion'
                 time waited: 0.170435 sec
                     wait id: 545            
              * time between wait #1 and #2: 2.264604 sec
              2.       event: 'log buffer space'
                 time waited: 0.158046 sec
                     wait id: 544            
              * time between wait #2 and #3: 0.368460 sec
              3.       event: 'log buffer space'
                 time waited: 0.030237 sec
                     wait id: 543            
    }
    and is blocked by
 => Oracle session identified by:
    {
                instance: 1 (orcl.orcl)
                   os id: 5544
              process id: 11, ORACLE.EXE (LGWR)
              session id: 189
        session serial #: 1
    }
    which is waiting for 'log file parallel write' with wait info:
    {
                      p1: 'files'=0x1
                      p2: 'blocks'=0x37e
                      p3: 'requests'=0x1
            time in wait: 0.219642 sec
           timeout after: never
                 wait id: 7393
                blocking: 1 session
            wait history:
              * time between current wait and wait #1: 0.043510 sec
              1.       event: 'control file sequential read'
                 time waited: 0.000368 sec
                     wait id: 7392            p1: 'file#'=0x0
                                              p2: 'block#'=0x20
                                              p3: 'blocks'=0x1
              * time between wait #1 and #2: 0.000489 sec
              2.       event: 'control file sequential read'
                 time waited: 0.000401 sec
                     wait id: 7391            p1: 'file#'=0x0
                                              p2: 'block#'=0x16
                                              p3: 'blocks'=0x1
              * time between wait #2 and #3: 0.000041 sec
              3.       event: 'control file sequential read'
                 time waited: 0.000341 sec
                     wait id: 7390            p1: 'file#'=0x0
                                              p2: 'block#'=0x1
                                              p3: 'blocks'=0x1
    }
 
Chain 1 Signature: 'log file parallel write'<='log buffer space'
Chain 1 Signature Hash: 0x56c5cf5
-------------------------------------------------------------------------------
 
===============================================================================
Sessions in an involuntary wait or not in a wait:
 
-------------------------------------------------------------------------------
Chain 2:
-------------------------------------------------------------------------------
    Oracle session identified by:
    {
                instance: 1 (orcl.orcl)
                   os id: 5548
              process id: 12, ORACLE.EXE (CKPT)
              session id: 3
        session serial #: 1
    }
    is waiting for 'control file parallel write' with wait info:
    {
                      p1: 'files'=0x2
                      p2: 'block#'=0x3
                      p3: 'requests'=0x2
            time in wait: 0.012544 sec
           timeout after: never
                 wait id: 4688
                blocking: 0 sessions
            wait history:
              * time between current wait and wait #1: 0.000196 sec
              1.       event: 'rdbms ipc message'
                 time waited: 2.995334 sec
                     wait id: 4687            p1: 'timeout'=0x12c
              * time between wait #1 and #2: 0.000014 sec
              2.       event: 'rdbms ipc message'
                 time waited: 0.000003 sec
                     wait id: 4686            p1: 'timeout'=0x12c
              * time between wait #2 and #3: 0.000036 sec
              3.       event: 'control file sequential read'
                 time waited: 0.000253 sec
                     wait id: 4685            p1: 'file#'=0x0
                                              p2: 'block#'=0x14
                                              p3: 'blocks'=0x1
    }
 
Chain 2 Signature: 'control file parallel write'
Chain 2 Signature Hash: 0xc17840d5
-------------------------------------------------------------------------------
 
===============================================================================
Extra information that will be dumped at higher levels:
[level  4] :   1 node dumps -- [LEAF] [LEAF_NW]
[level  5] :   2 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]):
[2]/1/3/1/F256C9CC/5548/SINGLE_NODE/
[71]/1/72/29/F2601B6C/1996/NLEAF/[188]
[188]/1/189/1/F2764D8C/5544/LEAF/

*** 2012-11-30 19:54:13.230
===============================================================================
END OF HANG ANALYSIS
===============================================================================

*** 2012-11-30 19:54:13.230
Oradebug command 'hanganalyze' console output:
Hang Analysis in d:\oracle\diag\rdbms\orcl\orcl\trace\orcl_ora_5372.trc

 

4,小结：
    1,仅sysdba可运行
    2,运行命令即知道trace文件所在路径
    3,trace文件结构清晰

来自 “ ITPUB博客 ” ，链接：http://blog.itpub.net/9240380/viewspace-750424/，如需转载，请注明出处，否则将追究法律责任。

转载于:http://blog.itpub.net/9240380/viewspace-750424/