标签：oradebug hanganalyze adjlist nleaf leaf
从11g开始，Oracle的trace格式相比10g，有很大的改变。hanganalyze trace格式也不例外。
做个小测试，认识一下。
在session1中：
SYS@tst SQL>select * from v$mystat where rownum<2; SID STATISTIC# VALUE ---------- ---------- ---------- 355 0 0 SYS@tst SQL>update scott.syk set loc=‘BJ‘ where deptno=10; 1 row updated.
在session2中：
SYS@tst SQL>select * from v$mystat where rownum<2; SID STATISTIC# VALUE ---------- ---------- ---------- 246 0 0 SYS@tst SQL>update scott.syk set loc=‘BJ‘ where deptno=10;
然后在session3中，做hanganalyze
SYS@tst SQL>oradebug setmypid Statement processed. SYS@tst SQL>oradebug hanganalyze 3 Hang Analysis in /apps/oracle/diag/rdbms/tst/tst/trace/tst_ora_20554.trc SYS@tst SQL>oradebug hanganalyze 3 Hang Analysis in /apps/oracle/diag/rdbms/tst/tst/trace/tst_ora_20554.trc SYS@tst SQL>exit
然后查看tst_ora_20554.trc
Chain 1:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (xbtst.xbtst)
os id: 20433
process id: 30, oracle@tstdb-25-220 (TNS V1-V3)
session id: 246
session serial #: 7817
}
is waiting for ‘enq: TX - row lock contention‘ with wait info:
{
p1: ‘name|mode‘=0x54580006
p2: ‘usn<<16 | slot‘=0x1001b
p3: ‘sequence‘=0x3ba
time in wait: 42.648677 sec
timeout after: never
wait id: 13
blocking: 0 sessions
current sql: update scott.syk set loc=‘BJ‘ where deptno=10
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+178<-ksliwat()+2022<-kslwaitctx()+163<-ksqcmi()+2848<-ksqgtlctx()+3501<-ksqgelctx()+557<-ktuGetTxForXid()+131<-ktcwit1()+336<-kdddgb()+8587<-kdusru()+460<-updrowFastPath()+1193<-qerupFetch()+2415<-updaul()+1378<-updThreePhaseExe()+318<-updexe()+638<-opiexe()+10378<-kpoal8()+2380<-opiodr()+917<-ttcpip()+2183<-opitsk()+1710<-opiino()+969<-opiodr()+917<-opidrv()+570<-sou2o()+103<-opimai_real()+133<-ssthrdmain()+26
wait history:
* time between current wait and wait #1: 0.000855 sec
1. event: ‘SQL*Net message from client‘
time waited: 30.441778 sec
wait id: 12 p1: ‘driver id‘=0x62657100
p2: ‘#bytes‘=0x1
* time between wait #1 and #2: 0.000059 sec
2. event: ‘SQL*Net message to client‘
time waited: 0.000001 sec
wait id: 11 p1: ‘driver id‘=0x62657100
p2: ‘#bytes‘=0x1
* time between wait #2 and #3: 0.000045 sec
3. event: ‘SQL*Net message from client‘
time waited: 0.000465 sec
wait id: 10 p1: ‘driver id‘=0x62657100
p2: ‘#bytes‘=0x1
}
and is blocked by
=> Oracle session identified by:
{
instance: 1 (xbtst.xbtst)
os id: 20329
process id: 27, oracle@tstdb-25-220 (TNS V1-V3)
session id: 355
session serial #: 2535
}
which is waiting for ‘SQL*Net message from client‘ with wait info:
{
p1: ‘driver id‘=0x62657100
p2: ‘#bytes‘=0x1
time in wait: 51.621284 sec
timeout after: never
wait id: 24
blocking: 1 session
current sql: <none>
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-read()+14<-ntpfprd()+117<-nsbasic_brc()+376<-nsbrecv()+69<-nioqrc()+495<-opikndf2()+978<-opitsk()+831<-opiino()+969<-opiodr()+917<-opidrv()+570<-sou2o()+103<-opimai_real()+133<-ssthrdmain()+265<-main()+201<-__libc_start_main()+245
wait history:
* time between current wait and wait #1: 0.000007 sec
1. event: ‘SQL*Net message to client‘
time waited: 0.000002 sec
wait id: 23 p1: ‘driver id‘=0x62657100
p2: ‘#bytes‘=0x1
* time between wait #1 and #2: 0.004410 sec
2. event: ‘SQL*Net message from client‘
time waited: 29.579867 sec
wait id: 22 p1: ‘driver id‘=0x62657100
p2: ‘#bytes‘=0x1
* time between wait #2 and #3: 0.000003 sec
3. event: ‘SQL*Net message to client‘
time waited: 0.000000 sec
wait id: 21 p1: ‘driver id‘=0x62657100
p2: ‘#bytes‘=0x1
}
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]):
[245]/1/246/7817/0xf2d616a8/20433/NLEAF/[354]
[354]/1/355/2535/0xf2ee55c8/20329/LEAF/
*** 2016-10-11 13:28:25.479
===============================================================================
END OF HANG ANALYSIS解决几个点：
[adjlist]：这个可以看做是[nodenum]
NLEAF：这个是waiter
LEAF：这个是blocker
nodenum[245]被adjlist[354]阻塞，nodenum[354]没有阻塞者。
[354]这一行中，sid为355，state为LEAF，所以355是blocker，对应上面的session1中执行的语句。
[245]这一行中，sid为246，state为NLEAF，所以246是waiter，对应上面的session2中执行的语句。
因此在分析hanganalyze时，可以通过LEAF来初步定位blocker，然后再通过NLEAF、[adjlist]来确定。
本文出自 “刚刚出壳的小鸟” 博客，请务必保留此出处http://qhd2004.blog.51cto.com/629417/1860632
标签：oradebug hanganalyze adjlist nleaf leaf
原文地址：http://qhd2004.blog.51cto.com/629417/1860632
