一、测试
session 1
SQL> select * from v$mystat where rownum=1;
SID STATISTIC# VALUE CON_ID
---------- ---------- ---------- ----------
39 0 0 0
SQL> update emp set sal=2000 where empno=7788;
1 row updated.
session 2
SQL> select * from v$mystat where rownum=1;
SID STATISTIC# VALUE CON_ID
---------- ---------- ---------- ----------
273 0 0 0
SQL> update emp set sal=3000 where empno=7788;二、查看等待链
session 3
SQL> @swc sid||':'||serial#||':'||event||':'||sql_id 1=1
old 5: REPLACE(SYS_CONNECT_BY_PATH(&1, '->'), '->', ' -> ')
new 5: REPLACE(SYS_CONNECT_BY_PATH(sid||':'||serial#||':'||event||':'||sql_id, '->'), '->', ' -> ')
old 34: START WITH (ses.state='WAITING' AND ses.wait_class!='Idle') AND &2
new 34: START WITH (ses.state='WAITING' AND ses.wait_class!='Idle') AND 1=1
SESSIONS
----------
PATH
--------------------------------------------------------------------------
1
-> 273:23340:enq: TX - row lock contention:d9sjsyawyhp59
1
-> 273:23340:enq: TX - row lock contention:d9sjsyawyhp59 -> 39:39050:SQL*Net message from client:三、hanganalyze
SQL> oradebug hanganalyze 3
Hang Analysis in /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_44331.trc四、hanganalyze分析
State of ALL nodes
([nodenum]/cnode/sid/sess_srno/session/ospid/state/[adjlist]):
[38]/1/39/39050/0x7c1cd020/44219/LEAF/
[272]/1/273/23340/0x7a191df0/44211/NLEAF/[38]([hanganalyze生成的session序列号]/实例编号/sid/serial#/会话的地址saddr/v$process spid/state/[表明会话是否等待,如有值,表明是持锁会话的CHAIN编号，否则为空])
state的几种状态
adjlist：阻塞者node
predecessor:被阻塞者
IN_HANG:遇到死锁或者处于hang状态
LEAF/LEAF_NW:通常是阻塞者或者slow node。
LEAF:持有锁的会话
LEAF_NW：持有锁的会话
NLEAF:被阻塞者
ING/ING_DMP:Idle 会话
SINGLE_NODE：等待资源或者会话
所以，直接搜索LEAF即可
五、等待链验证
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
Chain 1:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (orcl.orcl)
os id: 44211
process id: 31, oracle@19c01 (TNS V1-V3)
session id: 273
session serial #: 23340
module name: 0 (sqlplus@19c01 (TNS V1-V3))
}
is waiting for 'enq: TX - row lock contention' with wait info:
{
p1: 'name|mode'=0x54580006
p2: 'usn<<16 | slot'=0x70005
p3: 'sequence'=0x72b
time in wait: 4 min 33 sec
timeout after: never
wait id: 24
blocking: 0 sessions
current sql_id: 3571595506
current sql: update emp set sal=3000 where empno=7788
short stack: ksedsts()+426<-ksdxfstk()+58<-ksdxcb()+872<-sspuser()+200<-__sighandler()<-semtimedop()+14<-skgpwwait()+187<-ksliwat()+2218<-kslwaitctx()+188<-ksqcmi()+21656<-ksqgtlctx()+6620<-ksqgelctx()+838<-ktuGetTxForXid()+230<-ktcwit1()+367<-kdddgb()+5478<-kdusru()+458<-updrowFastPath()+1209<-qerupUpdRow()+1548<-qerupRopRowsets()+259<-kdstf110110100001000km()+12357<-kdsttgr()+2160<-qertbFetch()+1089<-qerupFetch()+1634<-updaul()+1416<-updThreePhaseExe()+340<-updexe()+405<-opiexe()+11573<-kpoal8()+2387<-opiodr()+1202<-ttcpip()
wait history:
* time between current wait and wait #1: 0.000534 sec
1. event: 'PGA memory operation'
time waited: 0.000011 sec
wait id: 23 p1: ''=0x10000
p2: ''=0x1
* time between wait #1 and #2: 0.000401 sec
2. event: 'PGA memory operation'
time waited: 0.000021 sec
wait id: 22 p1: ''=0x30000
p2: ''=0x2
* time between wait #2 and #3: 0.001380 sec
3. event: 'SQL*Net message from client'
time waited: 58.436221 sec
wait id: 21 p1: 'driver id'=0x62657100
p2: '#bytes'=0x1
}
and is blocked by
=> Oracle session identified by:
{
instance: 1 (orcl.orcl)
os id: 44219
process id: 42, oracle@19c01 (TNS V1-V3)
session id: 39
session serial #: 39050
module name: 0 (sqlplus@19c01 (TNS V1-V3))
}
which is waiting for 'SQL*Net message from client' with wait info:
{
p1: 'driver id'=0x62657100
p2: '#bytes'=0x1
time in wait: 4 min 52 sec
timeout after: never
wait id: 29
blocking: 1 session
current sql_id: 0
current sql: <none>
short stack: ksedsts()+426<-ksdxfstk()+58<-ksdxcb()+872<-sspuser()+200<-__sighandler()<-__read()+16<-sntpread()+28<-ntpfprd()+126<-nsbasic_brc()+399<-nioqrc()+438<-opikndf2()+999<-opitsk()+905<-opiino()+936<-opiodr()+1202<-opidrv()+1094<-sou2o()+165<-opimai_real()+422<-ssthrdmain()+417<-main()+256<-__libc_start_main()+243<-0x5541F689495641D7
wait history:
* time between current wait and wait #1: 0.000005 sec
1. event: 'SQL*Net message to client'
time waited: 0.000001 sec
wait id: 28 p1: 'driver id'=0x62657100
p2: '#bytes'=0x1
* time between wait #1 and #2: 0.000020 sec
2. event: 'Disk file operations I/O'
time waited: 0.000030 sec
wait id: 27 p1: 'FileOperation'=0x8
p2: 'fileno'=0x0
p3: 'filetype'=0x8
* time between wait #2 and #3: 0.000296 sec
3. event: 'PGA memory operation'
time waited: 0.000060 sec
wait id: 26 p1: ''=0x10000
p2: ''=0x1
}
Chain 1 Signature: 'SQL*Net message from client'<='enq: TX - row lock contention'
Chain 1 Signature Hash: 0x38c48850如今假设我们的环境的确不方便使用SQL查询，那么就需要用到oradebug hanganalyze来分析。
oradebug hanganalyze 3
因为我这里是RAC环境，需要分析所有实例：
oradebug -g all hanganalyze 3
分析trace文件
我们去分析这个生成的trc文件，可以很清楚的看到HANG分析部分，存在两个chain，比如我这个实验的情况就是：
Chain 1: 可以看到实例1的会话29被实例2的会话148阻塞，实例2的会话148又被实例1的会话26阻塞；
Chain 2: 可以看到实例2的会话23被实例2的会话148阻塞，而实例2的会话148又在第一个chain中。
可以发现这与我之前用SQL查询的结果是一样的意思，都可以做到快速定位最终阻塞会话是实例1的会话26，与客户确认后杀掉即可。
附：oradebug hanganalyze 3分析的trace文件中的核心信息
*** 2018-04-21 07:51:44.975
===============================================================================
HANG ANALYSIS:
instances (db_name.oracle_sid): jyzhao.jyzhao1, jyzhao.jyzhao2
oradebug_node_dump_level: 3
analysis initiated by oradebug
os thread scheduling delay history: (sampling every 1.000000 secs)
0.000000 secs at [ 07:51:44 ]
NOTE: scheduling delay has not been sampled for 0.305046 secs 0.000000 secs from [ 07:51:40 - 07:51:45 ], 5 sec avg
0.000000 secs from [ 07:50:45 - 07:51:45 ], 1 min avg
0.000000 secs from [ 07:46:45 - 07:51:45 ], 5 min avg
vktm time drift history
===============================================================================
Chains most likely to have caused the hang:
[a] Chain 1 Signature: 'SQL*Net message from client'<='enq: TX - row lock contention'<='enq: TX - row lock contention'
Chain 1 Signature Hash: 0x42598823
[b] Chain 2 Signature: 'SQL*Net message from client'<='enq: TX - row lock contention'<='enq: TX - row lock contention'
Chain 2 Signature Hash: 0x42598823
===============================================================================
Non-intersecting chains:
-------------------------------------------------------------------------------
Chain 1:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (jyzhao.jyzhao1)
os id: 2712
process id: 42, oracle@jyrac1 (TNS V1-V3)
session id: 29
session serial #: 81
}
is waiting for 'enq: TX - row lock contention' with wait info:
{
p1: 'name|mode'=0x54580006
p2: 'usn<<16 | slot'=0xe0002
p3: 'sequence'=0x3a3
time in wait: 8 min 21 sec
timeout after: never
wait id: 37
blocking: 0 sessions
current sql: update emp set job = 'CEO' where empno = 7839
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+178<-ksliwat()+2022<-kslwaitctx()+163<-k
jusuc()+3400<-ksipgetctxi()+1759<-ksqcmi()+20798<-ksqgtlctx()+3501<-ksqgelctx()+557<-ktuGetTxForXid()+131<-ktcwit1()+336<-kdddgb()+8587<-kdusru()+460<-kauupd()+412<-updrow
()+2167<-qerupFetch()+860<-updaul()+1378<-updThreePhaseExe()+318<-updexe()+638<-opiexe()+10378<-kpoal8()+2380<-opiodr()+917<-ttcpip()+2183<-opitsk()+1710<-opiino()+969<-op
iodr()+917<-opidrv()+570<-sou2o(
wait history:
* time between current wait and wait #1: 0.010123 sec
1. event: 'gc current block 2-way'
time waited: 0.000622 sec
wait id: 36 p1: ''=0x7
p2: ''=0x6483
p3: ''=0x2000001
* time between wait #1 and #2: 0.007260 sec
2. event: 'gc cr block 2-way'
time waited: 0.000501 sec
wait id: 35 p1: ''=0x6
p2: ''=0x523
p3: ''=0x2c
* time between wait #2 and #3: 0.000462 sec
3. event: 'gc cr block 2-way'
time waited: 0.000689 sec
wait id: 34 p1: ''=0x6
p2: ''=0xb0
p3: ''=0x2b
}
and is blocked by
=> Oracle session identified by:
{
instance: 2 (jyzhao.jyzhao2)
os id: 23427
process id: 41, oracle@jyrac2 (TNS V1-V3)
session id: 148
session serial #: 17715
}
which is waiting for 'enq: TX - row lock contention' with wait info:
{
p1: 'name|mode'=0x54580006
p2: 'usn<<16 | slot'=0x50008
p3: 'sequence'=0x9e6
time in wait: 9 min 9 sec
timeout after: never
wait id: 152
blocking: 2 sessions
current sql: update emp set job = 'MANAGER' where empno = 7788
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+178<-ksliwat()+2022<-kslwaitctx()+163<-k
jusuc()+3400<-ksipgetctxi()+1759<-ksqcmi()+20798<-ksqgtlctx()+3501<-ksqgelctx()+557<-ktuGetTxForXid()+131<-ktcwit1()+336<-kdddgb()+8587<-kdusru()+460<-kauupd()+412<-updrow
()+2167<-qerupFetch()+860<-updaul()+1378<-updThreePhaseExe()+318<-updexe()+638<-opiexe()+10378<-kpoal8()+2380<-opiodr()+917<-ttcpip()+2183<-opitsk()+1710<-opiino()+969<-op
iodr()+917<-opidrv()+570<-sou2o(
wait history:
* time between current wait and wait #1: 0.005023 sec
1. event: 'gc cr block 2-way'
time waited: 0.000478 sec
wait id: 151 p1: ''=0x3
p2: ''=0xc0
p3: ''=0x19
* time between wait #1 and #2: 0.000295 sec
2. event: 'gc cr block 2-way'
time waited: 0.000821 sec
wait id: 150 p1: ''=0x3
p2: ''=0x362
p3: ''=0x1a
* time between wait #2 and #3: 0.000294 sec
3. event: 'gc cr block 2-way'
time waited: 0.000431 sec
wait id: 149 p1: ''=0x3
p2: ''=0xc0
p3: ''=0x19
}
and is blocked by
=> Oracle session identified by:
{
instance: 1 (jyzhao.jyzhao1)
os id: 1648
process id: 32, oracle@jyrac1 (TNS V1-V3)
session id: 26
session serial #: 3479
}
which is waiting for 'SQL*Net message from client' with wait info:
{
p1: 'driver id'=0x62657100
p2: '#bytes'=0x1
time in wait: 9 min 28 sec
timeout after: never
wait id: 168
blocking: 3 sessions
current sql: <none>
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-read()+14<-ntpfprd()+117<-nsbasic_brc()+376<-nsbrecv()+69<-nioqrc()+4
95<-opikndf2()+978<-opitsk()+831<-opiino()+969<-opiodr()+917<-opidrv()+570<-sou2o()+103<-opimai_real()+133<-ssthrdmain()+265<-main()+201<-__libc_start_main()+253
wait history:
* time between current wait and wait #1: 0.000010 sec
1. event: 'SQL*Net message to client'
time waited: 0.000003 sec
wait id: 167 p1: 'driver id'=0x62657100
p2: '#bytes'=0x1
* time between wait #1 and #2: 0.000239 sec
2. event: 'gc current grant 2-way'
time waited: 0.000337 sec
wait id: 166 p1: ''=0x7
p2: ''=0x6483
p3: ''=0x2010001
* time between wait #2 and #3: 0.000196 sec
3. event: 'db file sequential read'
time waited: 0.000824 sec
wait id: 165 p1: 'file#'=0x7
p2: 'block#'=0x6483
p3: 'blocks'=0x1
}
Chain 1 Signature: 'SQL*Net message from client'<='enq: TX - row lock contention'<='enq: TX - row lock contention'
Chain 1 Signature Hash: 0x42598823
-------------------------------------------------------------------------------
===============================================================================
Intersecting chains:
-------------------------------------------------------------------------------
Chain 2:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 2 (jyzhao.jyzhao2)
os id: 23488
process id: 42, oracle@jyrac2 (TNS V1-V3)
session id: 23
session serial #: 12635
}
is waiting for 'enq: TX - row lock contention' with wait info:
{
p1: 'name|mode'=0x54580006
p2: 'usn<<16 | slot'=0xe0002
p3: 'sequence'=0x3a3
time in wait: 8 min 34 sec
timeout after: never
wait id: 39
blocking: 0 sessions
current sql: update emp set sal = 15000 where empno = 7839
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+178<-ksliwat()+2022<-kslwaitctx()+163<-k
jusuc()+3400<-ksipgetctxi()+1759<-ksqcmi()+20798<-ksqgtlctx()+3501<-ksqgelctx()+557<-ktuGetTxForXid()+131<-ktcwit1()+336<-kdddgb()+8587<-kdusru()+460<-kauupd()+412<-updrow
()+2167<-qerupFetch()+860<-updaul()+1378<-updThreePhaseExe()+318<-updexe()+638<-opiexe()+10378<-kpoal8()+2380<-opiodr()+917<-ttcpip()+2183<-opitsk()+1710<-opiino()+969<-op
iodr()+917<-opidrv()+570<-sou2o(
wait history:
* time between current wait and wait #1: 0.000226 sec
1. event: 'gc cr block 2-way'
time waited: 0.000605 sec
wait id: 38 p1: ''=0x3
p2: ''=0xc0
p3: ''=0x19
* time between wait #1 and #2: 0.011878 sec
2. event: 'gc cr block 2-way'
time waited: 0.000610 sec
wait id: 37 p1: ''=0x3
p2: ''=0xc0
p3: ''=0x19
* time between wait #2 and #3: 0.000316 sec
3. event: 'Disk file operations I/O'
time waited: 0.000007 sec
wait id: 36 p1: 'FileOperation'=0x2
p2: 'fileno'=0x3
p3: 'filetype'=0x2
}
and is blocked by 'instance: 2, os id: 23427, session id: 148',
which is a member of 'Chain 1'.
Chain 2 Signature: 'SQL*Net message from client'<='enq: TX - row lock contention'<='enq: TX - row lock contention'
Chain 2 Signature Hash: 0x42598823
-------------------------------------------------------------------------------
===============================================================================