sitemap

RSS地图

收藏本站

设为首页

Oracle研究中心

当前位置:Oracle研究中心 > 故障案例 >

【案例】Oracle遇到row cache lock时systemstate分析解决思路

时间:2016-10-28 22:24   来源:Oracle研究中心   作者:HTZ   点击:

天萃荷净 Oracle研究中心案例分析:运维DBA反映在数据库中遇到row cache lock,结合案例systemstate分析row cache lock产生原因和解决办法。
下面是一次测试row cache lock的systemstate分析方法,平台为11.2.04

1,使用ass来格式化systemstate的

[oracle@11rac1 sql]$ awk -f ass1039.awk /u01/app/oracle/diag/rdbms/power/power1/trace/power1_ora_14290.trc

Starting Systemstate 1
………………………………………………
Ass.Awk Version 1.0.39
~~~~~~~~~~~~~~~~~~~~~~
Source file : /u01/app/oracle/diag/rdbms/power/power1/trace/power1_ora_14290.trc

System State 1 (2014-07-16 15:14:42.518)
~~~~~~~~~~~~~~ ~~~~~~~~~~~~~~~~~~~~~~~
1: [DEAD]
2: waiting for ‘pmon timer’
3: waiting for ‘rdbms ipc message’
4: waiting for ‘VKTM Logical Idle Wait’
5: waiting for ‘rdbms ipc message’
6: waiting for ‘DIAG idle wait’
7: waiting for ‘rdbms ipc message’
8: waiting for ‘PING’
9: waiting for ‘rdbms ipc message’
10: waiting for ‘DIAG idle wait’
11: waiting for ‘rdbms ipc message’
12: waiting for ‘ges remote message’
13: waiting for ‘gcs remote message’
14: waiting for ‘rdbms ipc message’
15: waiting for ‘GCR sleep’
16: waiting for ‘rdbms ipc message’
17: waiting for ‘rdbms ipc message’
18: waiting for ‘rdbms ipc message’
19: waiting for ‘rdbms ipc message’
20: waiting for ‘smon timer’
21: waiting for ‘rdbms ipc message’
22: waiting for ‘rdbms ipc message’
23: waiting for ‘ASM background timer’
24: waiting for ‘rdbms ipc message’
25: waiting for ‘rdbms ipc message’
26:
27: waiting for ‘wait for unread message on broadcast channel’
28:
29: waiting for ‘rdbms ipc message’
30: waiting for ‘rdbms ipc message’
31: waiting for ‘rdbms ipc message’
32: waiting for ‘SQL*Net message from client’
33: waiting for ‘Space Manager: slave idle wait’
34: waiting for ‘rdbms ipc message’
35: waiting for ‘rdbms ipc message’
36: waiting for ‘rdbms ipc message’
37: waiting for ‘rdbms ipc message’
38: waiting for ‘SQL*Net message from client’
39: waiting for ‘rdbms ipc message’
40: waiting for ‘Space Manager: slave idle wait’
41: waiting for ‘wait for unread message on broadcast channel’
42: waiting for ‘Streams AQ: qmn coordinator idle wait’
43: waiting for ‘SQL*Net message from client’
Cmd: PL/SQL Execute
44: waiting for ‘SQL*Net message from client’
45: waiting for ‘Streams AQ: qmn slave idle wait’
46: waiting for ‘Streams AQ: waiting for time management or cleanup tasks’
47: waiting for ‘SQL*Net message from client’
Cmd: Select
48: waiting for ‘rdbms ipc message’
49: waiting for ‘enq: TX – row lock contention'[Enq TX-00010008-00000629]
Cmd: Select
50: waiting for ‘row cache lock’ [Rcache object=0x8f0a1990,]
Cmd: Select
51: waiting for ‘SQL*Net message from client’
52:
53:
58: waiting for ‘class slave wait’

Blockers
~~~~~~~~

Above is a list of all the processes. If they are waiting for a resource
then it will be given in square brackets. Below is a summary of the
waited upon resources, together with the holder of that resource.
Notes:
~~~~~
o A process id of ‘ ’ implies that the holder was not found in the
systemstate. (The holder may have released the resource before we
dumped the state object tree of the blocking process).
o Lines with ‘Enqueue conversion’ below can be ignored *unless*
other sessions are waiting on that resource too. For more, see
http://dlsunuk11.uk.oracle.com/Public/TOOLS/Ass.html#enqcnv)

Resource Holder State
Enq TX-00010008-00000629 47: waiting for ‘SQL*Net message from client’
Rcache object=0x8f0a1990, 49: 49: is waiting for 47:

Object Names
~~~~~~~~~~~~
Enq TX-00010008-00000629
Rcache object=0x8f0a1990, cid=13(dc_sequences)

Summary of Wait Events Seen (count>10)
~~~~~~~~~~~~~~~~~~~~~~~~~~~
No wait events seen more than 10 times

——————ooOoo——————
For the LATEST version of this utility see
http://dlsunuk11.uk.oracle.com/Public/Utils.html#ass

For additional documentation see
http://dlsunuk11.uk.oracle.com/Public/TOOLS/Ass.html

Suggested improvements, bugs etc. should be sent to kevin.p.quinn@oracle.com

End of report. 60404 Lines Processed.

[oracle@11rac2 sql]$ awk -f ass1039.awk /u01/app/oracle/diag/rdbms/power/power2/trace/power2_ora_9758.trc

Starting Systemstate 1
……………………………………………
Ass.Awk Version 1.0.39
~~~~~~~~~~~~~~~~~~~~~~
Source file : /u01/app/oracle/diag/rdbms/power/power2/trace/power2_ora_9758.trc

System State 1 (2014-07-16 15:15:33.423)
~~~~~~~~~~~~~~ ~~~~~~~~~~~~~~~~~~~~~~~
1: [DEAD]
2: waiting for ‘pmon timer’
3: waiting for ‘rdbms ipc message’
4: waiting for ‘VKTM Logical Idle Wait’
5: waiting for ‘rdbms ipc message’
6: waiting for ‘DIAG idle wait’
7: waiting for ‘rdbms ipc message’
8: waiting for ‘PING’
9: waiting for ‘rdbms ipc message’
10: waiting for ‘DIAG idle wait’
11: waiting for ‘rdbms ipc message’
12: waiting for ‘ges remote message’
13: waiting for ‘gcs remote message’
14: waiting for ‘rdbms ipc message’
15: waiting for ‘GCR sleep’
16: waiting for ‘rdbms ipc message’
17: waiting for ‘rdbms ipc message’
18: waiting for ‘rdbms ipc message’
19: waiting for ‘rdbms ipc message’
20: waiting for ‘smon timer’
21: waiting for ‘rdbms ipc message’
22: waiting for ‘rdbms ipc message’
23: waiting for ‘ASM background timer’
24: waiting for ‘rdbms ipc message’
25: waiting for ‘rdbms ipc message’
26: waiting for ‘wait for unread message on broadcast channel’
27:
28:
29: waiting for ‘rdbms ipc message’
30: waiting for ‘rdbms ipc message’
31: waiting for ‘rdbms ipc message’
32: waiting for ‘SQL*Net message from client’
33: waiting for ‘Space Manager: slave idle wait’
34: waiting for ‘class slave wait’
35: waiting for ‘rdbms ipc message’
36: waiting for ‘rdbms ipc message’
37: waiting for ‘rdbms ipc message’
38: waiting for ‘rdbms ipc message’
39: waiting for ‘rdbms ipc message’
40: waiting for ‘wait for unread message on broadcast channel’
41: waiting for ‘class slave wait’
42: waiting for ‘Streams AQ: qmn coordinator idle wait’
43:
44: waiting for ‘SQL*Net message from client’
45: waiting for ‘Streams AQ: qmn slave idle wait’
46: waiting for ‘row cache lock’ [Rcache object=0x8e9a5120,]
Cmd: Select
47:
48: waiting for ‘rdbms ipc message’
49: waiting for ‘Space Manager: slave idle wait’
50: waiting for ‘Space Manager: slave idle wait’
51:

Blockers
~~~~~~~~

Above is a list of all the processes. If they are waiting for a resource
then it will be given in square brackets. Below is a summary of the
waited upon resources, together with the holder of that resource.
Notes:
~~~~~
o A process id of ‘ ’ implies that the holder was not found in the
systemstate. (The holder may have released the resource before we
dumped the state object tree of the blocking process).
o Lines with ‘Enqueue conversion’ below can be ignored *unless*
other sessions are waiting on that resource too. For more, see
http://dlsunuk11.uk.oracle.com/Public/TOOLS/Ass.html#enqcnv)

Resource Holder State
Rcache object=0x8e9a5120, Blocker

Object Names
~~~~~~~~~~~~
Rcache object=0x8e9a5120, cid=13(dc_sequences)

Summary of Wait Events Seen (count>10)
~~~~~~~~~~~~~~~~~~~~~~~~~~~
No wait events seen more than 10 times

——————ooOoo——————
For the LATEST version of this utility see
http://dlsunuk11.uk.oracle.com/Public/Utils.html#ass

For additional documentation see
http://dlsunuk11.uk.oracle.com/Public/TOOLS/Ass.html

Suggested improvements, bugs etc. should be sent to kevin.p.quinn@oracle.com

End of report. 43873 Lines Processed.
Rcache object=0x8e9a5120, Blocker这里节点2没有发现阻塞者,说明阻塞者不在2节点,在1节点

2,找到row cache lock的session

以row cache lock等待事件来搜索会话的等待情况,如果没有使用ass格式化的情况下,一般我们都是这样来和
—————————————-
SO: 0x9b513658, type: 4, owner: 0x9ce441f0, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0x9ce441f0, name=session, file=ksu.h LINE:12624, pg=0
(session) sid: 52 ser: 15 trans: 0x9515a1f0, creator: 0x9ce441f0
flags: (0x41) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
flags2: (0x40009) -/-/INC
DID: , short-term DID:
txn branch: (nil)
oct: 3, prv: 0, sql: 0x8e954a20, psql: 0x8f50cfd0, user: 0/SYS
ksuxds FALSE at location: 0
service name: SYS$USERS
client details:
O/S info: user: oracle, term: pts/0, ospid: 6268
machine: 11rac2 program: sqlplus@11rac2 (TNS V1-V3)
application name: sqlplus@11rac2 (TNS V1-V3), hash value=3270042948
Current Wait Stack:
0: waiting for ‘row cache lock’
cache id=0xd, mode=0x0, request=0x5
wait_id=6656 seq_num=6657 snap_id=1
wait times: snap=0.001217 sec, exc=0.001217 sec, total=0.001217 sec
wait times: max=3.000000 sec, heur=3 min 6 sec
wait counts: calls=1 os=1
in_wait=1 iflags=0x5a2
找到row cache enqueue的信息,
这里我们可以看到最终的BLOCKER是inst:1,sid:793
这里需要记录一下行号
row cache enqueue*request来搜索,找到离刚开始最近的一行记录
37769 row cache enqueue: count=1 session=0x9b513658 object=0x8e9a5120, request=X

其实我们还可以下面的方式来搜索
以type: 75, owner: 0x9515a1f0来搜索,因为我们知道,row cache enqueue的type是75,并且owner是属于process跟session的owner是一致的。
其中还可以以row cache enqueue*session*9b513658来搜索
SO: 0x8e990c40, type: 75, owner: 0x9515a1f0, flag: INIT/-/-/0x00 if: 0x1 c: 0x1
proc=0x9ce441f0, name=row cache enqueues, file=kqr.h LINE:2064, pg=0
row cache enqueue: count=1 session=0x9b513658 object=0x8e9a5120, request=X
savepoint=0x46
row cache parent object: address=0x8e9a5120 cid=13(dc_sequences)
hash=152264bc typ=11 transaction=(nil) flags=00000000
own=0x8e9a51e8[0x8e9a51e8,0x8e9a51e8] wat=0x8e9a51f8[0x8e990ce8,0x8e990ce8] mode=N
status=-/-/-/-/-/-/-/-/-
request=X release=FALSE flags=a
instance lock=QN 152264bc 374026d7
data=
00012a05 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 152264bc 8e9a5120 00000000
947397a8 00000000 947397a8 00000000 00000005 00000000 26784f80 00007f3c
00000000 00000000 00000000 00000000 8e9a5120 00000000 8e9a52f0 00000000
8e9a52f0 00000000 8e9a5318 00000000 0000000a 152264bc 374026d7 00000000
00000101 00000000 0000011d 00000000 99dd8510 00000000 9ce336f0 00000000
8f4eb538 00000000 98c04f78 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 99f79978 00000000
00000001 0000009a 00050001 08910321 8e9a5388 00000000 8e9a5388 00000000
0730efec 00000000 26784fa0 00007f3c 99f799d0 00000000 99f799d0 00000000
00000000 00000000 00000000 00000000 00000000 00000000 99dd8510 00000000
98c05018 00000000 8f4eb5d8 00000000 9b554ec8 00000000 00000000 00000002
8e9a53f8 00000000 8e9a53f8 00000000 00000000 00000000 00000000 00000000
8e9a5418 00000000 8e9a5418 00000000 8e9a5428 00000000 8e9a5428 00000000
99dca9b8 00000000 99dca9b8 00000000 00000000 00004fe7 26784f88 00007f3c
00000000 00000000 00000000 00000000 8e9a5468 00000000 8e9a5468 00000000
00000000 00000000 00000000 00000000 feb172d0 00007fff 10600160 09000200
00000000 00000000 06c25c14 00000000 26784fa0 00007f3c 00000000 00000000
f251fa11 00000002 00000000 00000000 8e9a51e8 00000000
kssdmh: so 0x8e990c40 (type 75, "row cache enqueues") may not have children
红色的部分就是row cache enqueue的信息
instance lock=QN 152264bc 374026d7这里是全局锁的信息,如果在本地没有找到阻塞者的时候,我们就要以这个在其它的节点找到。

3,搜索阻塞者

以row cache enqueue*object*8e9a5120来搜索
在2节点没有搜索到阻塞者,回到1节点的trace文件搜索
那么我们只能以instance lock=QN 152264bc 374026d7来搜索
这里可以得到下面的2行,分别进入相应的行,找到MODE的
54281 instance lock=QN 152264bc 374026d7
54922 instance lock=QN 152264bc 374026d7
得到mode的row cache enqueue的信息
—————————————-
SO: 0x8e5c2150, type: 75, owner: 0x951b5128, flag: INIT/-/-/0x00 if: 0x1 c: 0x1
proc=0x9cde1780, name=row cache enqueues, file=kqr.h LINE:2064, pg=0
row cache enqueue: count=1 session=0x9b4728e8 object=0x8f0a1990, mode=X
savepoint=0x29
row cache parent object: address=0x8f0a1990 cid=13(dc_sequences)
hash=152264bc typ=11 transaction=0x951b5128 flags=0000012a
own=0x8f0a1a58[0x8e5c21f8,0x8e5c21f8] wat=0x8f0a1a68[0x8e5d5e58,0x8e5d5e58] mode=X
status=VALID/UPDATE/-/-/IO/-/-/-/-
request=N release=TRUE flags=8
instance lock=QN 152264bc 374026d7
data=
00012a05 0002000c 000f0002 00020001 000002c1 00000000 00000000 00000000
02c10000 00000000 00000000 00000000 00000000 646464ce 64646464 64646464
00646464 00800000 00000000 00000000 00000000 00000000 000003c1 00000000
00000000 00000000 2d2d0000 2d2d2d2d 2d2d2d2d 2d2d2d2d 2d2d2d2d 2d2d2d2d
2d2d2d2d 2d2d2d2d 2d2d2d2d 2d2d2d2d 00000000 152264bc 8f0a1990 00000000
947397a8 00000000 947397a8 00000000 00000000 00000000 2d95f900 00007f5f
00000001 00000000 00000000 00000000 8f0a1990 00000000 8f0a1b60 00000000
8f0a1b60 00000000 8f0a1b88 00000000 00000008 152264bc 374026d7 00000000
00000101 00000000 0000011d 00000000 99cdOracleо8068 00000000 9cdcda70 00000000
8e4f6420 00000000 8e5b8288 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000 00000000 00000000 00000000 999b9938 00000000
00000001 00095556 00050520 08910321 8f0a1bf8 00000000 8f0a1bf8 00000000
00000000 00000000 2d95f920 00007f5f 999b9980 00000000 999b9980 00000000
06c25c14 00000000 00000000 00000000 2d95f920 00007f5f 99cd8068 00000000
8e5b8328 00000000 8e4f64c0 00000000 9c337718 00000000 00000000 00000002
8f0a1c68 00000000 8f0a1c68 00000000 00000000 00000000 00000000 00000000
8f0a1c88 00000000 8f0a1c88 00000000 8f0a1c98 00000000 8f0a1c98 00000000
8f0a1ca8 00000000 8f0a1ca8 00000000 00000000 00000000 2d95f908 00007f5f
00000000 00000000 00000000 00000000 8f0a1cd8 00000000 8f0a1cd8 00000000
00000000 00000000 00000000 00000000 5e2f04e8 00007fff 10600160 00000100
03000001 00000000 00000000 00000000 00000000 00000000 00000000 00000000
00000000 00000001 00000108 00000000 8f0a1a58 00000000
kssdmh: so 0x8e5c2150 (type 75, "row cache enqueues") may not have children
以9b4728e8*type: 4来搜索会话的信息,可以看到会话正在等待TX的等待事件
—————————————-
SO: 0x9b4728e8, type: 4, owner: 0x9cde1780, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0x9cde1780, name=session, file=ksu.h LINE:12624, pg=0
(session) sid: 795 ser: 15 trans: 0x951b5128, creator: 0x9cde1780
flags: (0x41) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
flags2: (0x9) -/-/INC
DID: , short-term DID:
txn branch: (nil)
oct: 3, prv: 0, sql: 0x8e4f5860, psql: 0x8f112090, user: 0/SYS
ksuxds FALSE at location: 0
service name: SYS$USERS
client details:
O/S info: user: oracle, term: pts/1, ospid: 6441
machine: 11rac1 program: sqlplus@11rac1 (TNS V1-V3)
application name: sqlplus@11rac1 (TNS V1-V3), hash value=985707405
Current Wait Stack:
0: waiting for ‘enq: TX – row lock contention‘
关于enq的等待,见enqueue

本文固定链接: http://www.htz.pw/2014/07/16/systemstate%e5%88%86%e6%9e%90row-cache-lock.html | 认真就输

--------------------------------------ORACLE-DBA----------------------------------------

最权威、专业的Oracle案例资源汇总之【案例】Oracle遇到row cache lock时systemstate分析解决思路

本文由大师惜分飞原创分享,网址:http://www.oracleplus.net/arch/1096.html

Oracle研究中心

关键词:

systemstate分析row cache lock案例

测试row cache lock的systemstate分析方法

row cache lock