问题描述：

最近碰见一个database hang的情况，但是重启之后就再也没有重现。也没有机会做system
state dump。为了重现database hang，查了查metalink，很多都是偶然发生的，有的是老
版本的数据库的bug。尝试了几种方法也不能使database hang，后来发现一个网址
http://dbsnake.com/cgi-bin/mt/mt-search.cgi?IncludeBlogs=1&tag=db%20hang%20simulation&limit=20，
上面介绍了用hold latch的方法。这的确是个好方法。但是在做了system state dump后，
找不到blocker的session。这是因为是用了”oradebug poke 0x2F0BCB4C 4 1“强制标志latch。
其实有一个更好的方法"oradebug call kslgetl 0x20008070 1",这个
方法可以hold住一个latch，并且标明自己是这个latch的holder。

环境：

Linux Server 5, Oracle 11.2.0.2

模拟步骤：

下面是模拟的步骤：

1. 启动一个session，以sys用户登录, 找到一个latch的地址。这个latch "ksqeql_"是用来
保护KSE(enqueue)相关的操作的。

点击(此处)折叠或打开

SQL> set linesize 120
SQL> col ksmfsnam format a20
SQL> col ksmfstyp format a20
SQL> col kslldnam format a30
SQL>
SQL> select k.ksmfsadr, ksmfsnam, ksmfstyp, ksmfssiz, kslldnam, kslldlvl
2 from x$ksmfsv k, x$kslld a
3 where k.ksmfstyp like '%ksllt%' and k.ksmfsadr = a.kslldadr
4 and ksmfsnam = 'ksqeql_'
5 order by ksmfsnam;
KSMFSADR KSMFSNAM KSMFSTYP KSMFSSIZ KSLLDNAM KSLLDLVL
-------- -------------------- -------------------- ---------- ------------------------------ ----------
20008070 ksqeql_ ksllt 100 enqueues 5

2. hold住latch

点击(此处)折叠或打开

oradebug setmypid
oradebug call kslgetl 0x20008070 1

返回1的时候表示已经hold住了。

3. 新起一个session，并尝试登录数据库，发现sqlplus hold住了。

4. 开始做system state dump

点击(此处)折叠或打开

[oracle@dbs101 trace]$ sqlplus -prelim '/ as sysdba'
SQL*Plus: Release 11.2.0.2.0 Production on Mon May 30 22:34:46 2011
Copyright (c) 1982, 2010, Oracle. All rights reserved.
SQL> oradebug setmypid
Statement processed.
SQL> oradebug unlimit;
Statement processed.
SQL> oradebug dump systemstate 10
Statement processed.

5. 用ass109.awk来分析trace文件

点击(此处)折叠或打开

awk -f ass109.awk dbs101_ora_18429.trc
[oracle@dbs4 trace]$ awk -f ass109.awk dbs101_ora_18429.trc
Starting Systemstate 1
.................................................................
Ass.Awk Version 1.0.9 - Processing dbs101_ora_18429.trc
System State 1
~~~~~~~~~~~~~~~~
1:
2: 0: waiting for 'pmon timer'
3: 0: waiting for 'rdbms ipc message'
4: 0: waiting for 'VKTM Logical Idle Wait'
5: 0: waiting for 'rdbms ipc message'
6: 0: waiting for 'DIAG idle wait'
7: 0: waiting for 'rdbms ipc message'
8: 0: waiting for 'PING'
9: 0: waiting for 'rdbms ipc message'
10: 0: waiting for 'DIAG idle wait'
11: 0: waiting for 'latch free' [Latch 20008070]
12: 0: waiting for 'ges remote message'
13: 0: waiting for 'gcs remote message'
14: 0: waiting for 'rdbms ipc message'
15: 0: waiting for 'KSV master wait' [Latch 20008070]
16: 0: waiting for 'rdbms ipc message'
17: 0: waiting for 'rdbms ipc message'
18: 0: waiting for 'rdbms ipc message'
19: 0: waiting for 'latch free' [Latch 20008070]
20: 0: waiting for 'latch free' [Latch 20008070]
21: 0: waiting for 'rdbms ipc message'
22: 0: waiting for 'rdbms ipc message'
23: 0: waiting for 'ASM background timer'
24: 0: waiting for 'latch free' [Latch 20008070]
25: 0: waiting for 'latch free' [Latch 20008070]
26:
27:
28: 0: waiting for 'wait for unread message on broadcast channel'
29: 0: waiting for 'Space Manager: slave idle wait'
30: 0: waiting for 'rdbms ipc message'
31: 0: waiting for 'rdbms ipc message'
32: 0: waiting for 'SQL*Net message from client'
Cmd: PL/SQL Execute
33: 0: waiting for 'class slave wait'
34: 0: waiting for 'class slave wait'
35: 0: waiting for 'class slave wait'
36: 0: waiting for 'rdbms ipc message'
37: 0: waiting for 'wait for unread message on broadcast channel'
38: 0: waiting for 'Streams AQ: qmn coordinator idle wait'
39: 0: waiting for 'rdbms ipc message'
40: 0: waiting for 'SQL*Net message from client'
42: 0: waiting for 'Streams AQ: qmn slave idle wait'
43: 0: waited for 'Streams AQ: waiting for time management or cleanup tasks'
44: 0: waiting for 'latch free' [Latch 20008070]
45: 0: waiting for 'SQL*Net message from client'
46: 0: waiting for 'SQL*Net message from client'
47: 0: waiting for 'latch free' [Latch 20008070]
Cmd: Select
57: 0: waiting for 'class slave wait'
Cmd: Select
60: 0: waiting for 'class slave wait'
Cmd: Select
63: 0: waiting for 'class slave wait'
Cmd: Select
68: 0: waiting for 'class slave wait'
Cmd: Select
69: 0: waiting for 'class slave wait'
Cmd: Select
71: 0: waiting for 'class slave wait'
Cmd: Select
72: 0: waiting for 'class slave wait'
Cmd: Select
73: 0: waiting for 'class slave wait'
Cmd: Select
80: 0: waiting for 'class slave wait'
Cmd: Select
82: 0: waiting for 'class slave wait'
Cmd: Select
83: 0: waiting for 'class slave wait'
Cmd: Select
84: 0: waiting for 'class slave wait'
Cmd: Select
85: 0: waiting for 'class slave wait'
Cmd: Select
91: 0: waiting for 'class slave wait'
Cmd: Select
97: 0: waiting for 'class slave wait'
Cmd: Select
100:0: waiting for 'class slave wait'
Cmd: Select
102:0: waiting for 'class slave wait'
Cmd: Select
104:0: waiting for 'class slave wait'
Cmd: Select
149:0: waiting for 'class slave wait'
Cmd: Select
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.
Resource Holder State
Latch 20008070 ??? Blocker
Object Names
~~~~~~~~~~~~
Latch 20008070 enqueues
59194 Lines Processed.

可以看到进程11在等待latch 20008070。

点击(此处)折叠或打开

11: 0: waiting for 'latch free' [Latch 20008070]
PROCESS 11: LMON
----------------------------------------
SO: 0x32fd3ac8, type: 2, owner: (nil), flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0x32fd3ac8, name=process, file=ksu.h LINE:12451, pg=0
(process) Oracle pid:11, ser:1, calls cur/top: 0x32759778/0x32759778
flags : (0x6) SYSTEM
flags2: (0x100), flags3: (0x0)
intr error: 0, call error: 0, sess error: 0, txn error 0
intr queue: empty
ksudlp FALSE at location: 0
(post info) last post received: 0 0 35
last post received-location: ksr2.h LINE:603 ID:ksrpublish
last process to post me: 32fe22c4 3 0
last post sent: 0 0 128
last post sent-location: kjxgn1.h LINE:171 ID:kjxgnaef
last process posted by me: 32fdd570 1 2
(latch info) wait_event=0 bits=0
Location from where call was made: ksq.h LINE:1807 ID:ksqgel: create enqueue: parent obj
Context saved from call: 846567288
waiting for 20008070 enqueues level=5
Location from where latch is held: kywm2.h LINE:185 ID:kywmcrpln: creating new WLM plan:
Context saved from call: 3215570592
state=busy [holder rapid=45] wlstate=free [value=0]
waiters [orapid (seconds since: put on list, posted, alive check)]:
11 (178, 1306757849, 4)
19 (177, 1306757849, 177)
44 (174, 1306757849, 174)
25 (162, 1306757849, 162)
47 (150, 1306757849, 150)
15 (141, 1306757849, 141)
24 (121, 1306757849, 121)
20 (117, 1306757849, 117)
waiter count=8
gotten 54415596 times wait, failed first 1012 sleeps 65
gotten 0 times nowait, failed: 0
possible holder pid = 45 spid=17550
on wait list for 20008070

可以看到进程45在hold住了latch 20008070。
state=busy [holder rapid=45] wlstate=free [value=0]

ITPub博客

利用latch的hold来模拟database hang

最新文章