Oracle数据库性能障碍分析利器：SYSTEMSTATE DUMP介绍

作者孟庆辉沃趣科技数据库工程师

当数据库出现严重的性能问题或者hang了的时候，我们非常需要通过systemstate dump来知道进程在做什么，在等待什么，谁是资源的持有者，谁阻塞了别人。

在出现上述问题时，及时收集systemstate dump非常有助于问题原因的分析。

systemstate dump级别简介： 1. 级别2:dump(不包括lock element) 2. 级别10:dump 3. 级别11:dump+global cache of rac 4. 级别256:short stack（函数堆栈） 5. 级别258:级别256+级别2 6. 级别266:级别256+级别10 7. 级别267:级别256+级别11

注意

1. 级别11和级别267会dump global cache,会产生较大的trace 文件，一般不推荐。

2. 一般情况下，如果进程不是太多，建议用256，因为这样可以dump出来进程的函数堆栈，可以用来分析进程在执行什么操作，但是生成short stack比较耗时，如果进程非常多，比如2000个进程，那么可能耗时30分钟以上。这种情况下，可以生成level 10 或者 level 258， level 258 比 level 10会多收集short short stack, 但比level 10少收集一些lock element data。

3. 对于RAC系统，需要关注Bug 11800959 - A SYSTEMSTATE dump with level >= 10 in RAC dumps huge BUSY GLOBAL CACHE ELEMENTS - can hang/crash instances (Doc ID 11800959.8)。这个Bug在11.2.0.3上被修复，对于<=11.2.0.2的RAC，当系统中的lock element很多的时候，如果执行level 10、266或者267的systemstate dump时，可能会导致数据库hang或者crash，这种情况下可以采用level 258。

systemstate dump大部分时候需要手工生成，其生成方式如下：

1. 用sqlplus登录到数据库

$sqlplus / as sysdba

当数据库已经非常慢或者数据库hang到无法连接时，可使用如下方式登录：

$sqlplus -prelim / as sysdba
---------------------在单节点上 生成systemstate dump---------------------
SQL>oradebug setmypid SQL>oradebug unlimit;
SQL>oradebug dump systemstate 266;
--等1~2分钟
SQL>oradebug dump systemstate 266;
--等1~2分钟
SQL>oradebug dump systemstate 266;
SQL>oradebug tracefile_name;==>这是 生成的 文件名
---------------------在RAC上 生成systemstate dump---------------------
SQL>oradebug setmypid SQL>oradebug unlimit
SQL>oradebug -g all dump systemstate 266
--等1~2分钟 
SQL>oradebug -g all dump systemstate 266
--等1~2分钟
SQL>oradebug -g all dump systemstate 266

在我们使用prelim参数仍然无法登录数据库时，可以使用gdb调试后台进程方式生成systemstate dump，例子如下：

$ ps -ef|grep pmon
oracle2828810 04:42 ?00:00:00 ora_pmon_R11202
$ gdb $ORACLE_HOME/bin/oracle 28288

然后查看这个进程的trace文件：

$ more R11202_pmon_28288.trc

需要注意的是：虽然detach到后台进程也可以搜集到systemstate dump，但是由于有一些Bug会导致detach到的进程异常终止，所以最好不要用后台进程，因为某些后台进程的异常终止会导致数据库实例的异常终止，所以使用用户进程来做systemtate dump更稳妥一些.

2.使用systemstate dump处理row cache lock问题

Oracle process number: 77
Unix process pid: 10846, image: oracle@cpdb4532
* 2011-05-13 08:08:58.775
* SERVICE NAME:(ALFCMR_SERVICE) 2011-05-13 08:08:58.775
* SESSION ID:(1076.796) 2011-05-13 08:08:58.775
> WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK! <<<
row cache enqueue: session: 0x1df57ade8, mode: N, request: S

trace 文件头部我们可以看到：

oracle进程在等待row cache enqueue lock 请求的row cache enqueue级别是S（共享锁）所以我们能够看到77号进程在等待获取共享锁。

systemstate dump包含了数据库所有进程的状态信息，然后我们找到77号进程信息。

PROCESS 77 
----------------------------------------
.
.
----------------------------------------
SO: 0x1cdf11958, type: 50, owner: 0x17d198288, flag: INIT/-/-/0x00 
row cache enqueue: count=1 session=0x1df57ade8 object=0x1dc9a5d30, request=S savepoint=0x87b70d
row cache parent object: address=0x1dc9a5d30 cid=7(dc_users) 
. 
.

通过上面的信息我们可以看到77号进程请求在row cache dc_users上加共享锁，如果77号进程在等待加锁，也就意味着有其他进程在持有该资源，我们需要通过systemstate dump找出谁是最终的资源持有者。

最好的方式是通过object=0x1dc9a5d30去搜索systemstate dump。

PROCESS 218:
---------------------------------------- 
.
.
SO: 0x1cdf118f8, type: 50, owner: 0x1ceb0f178, flag: INIT/-/-/0x00
row cache enqueue: count=1 session=0x1da54cf68 object=0x1dc9a5d30, request=X savepoint=0x11e
row cache parent object: address=0x1dc9a5d30 cid=7(dc_users)

上面的搜索结果中，我们发现218号进程在请求对object=0x1dc9a5d30添加排他锁，这往往意味着他处于资源等待队列的第一位，其他的资源请求都是排在他的后面，所以我们需要找到是谁锁住了这个进程。

PROCESS 164:
----------------------------------------
.
.
O/S info: user: u1m, term: , ospid: 1234, machine: cpc44711 program:
last wait for 'SQL*Net message from client' blocking sess=0x(nil) seq=36289 wait_t ime=6943 seconds since wait started=2539
driver id=54435000, #bytes=1, =0
. 
. 
SO: 0x1cdf11418, type: 50, owner: 0x1ccc26120, flag: INIT/-/-/0x00
row cache enqueue: count=2 session=0x1df578318 object=0x1dc9a5d30, mode=S savepoint=0xb1bd8e
row cache parent object: address=0x1dc9a5d30 cid=7(dc_users) hash=fc968070 typ=11 transaction=(nil) flags=00000002
own=0x1dc9a5e00[0x1cdf11448,0x1cdf11448] wat=0x1dc9a5e10[0x1cdf11928,0x17d5192e0] mode=S

我们根据object=0x1dc9a5d30最终找到上面部分内容，根据信息我们可以看到164进程以共享模式持有object：0x1dc9a5d30,因此阻塞了想要以排他模式持有该资源的进程218，而且可以看到164进程是持有CPU资源的（可以根据进程信息显示last wait for 'SQL*Net message from client' 而不是waiting for 'SQL*Net message from client'看出），而且持有CPU时间为2539（根据seconds since wait started=2539看出），接下来我们就可以围绕该进程排查。

3.使用systemstate dump处理library cache lock问题

首先我们可以通过SQL找出任意一个目前正在处于library cache lock的进程，从该进程着手排查。

select pid from v$process where addr=
(select paddr from v$session where event='library cache lock' );

然后我们根据查到的进程号到systemstate dump文件中查找：

PROCESS 20:
----------------------------------------
SO: 0x7d2bd820, type: 2, owner: (nil), flag: INIT/-/-/0x00
(process) Oracle pid=20, calls cur/top: 0x7d3d62d0/0x7d3d85dc, flag: (0) -
int error: 0, call error: 0, sess error: 0, txn error 0
(post info) last post received: 109 0 4
last post received-location: kslpsr
last process to post me: 7d2b8d94 1 6
last post sent: 0 0 24 
last post sent-location: ksasnd
last process posted by me: 7d2b8d94 1 6 (latch info) wait_event=0 bits=0
Process Group: DEFAULT, pseudo proc: 0x7d2ed5dc
O/S info: user: oracle, term: pts/7, ospid: 19759
OSD pid info: Unix process pid: 19759, image: goblin.forgotten.realms (TNS V1-V3)
<cut>
(session) sid: 141 trans: (nil), creator: 0x7d2bd820, flag: (41) USR/- BSY/-/-/-/-/-
DID: 0001-0014-00000668, short-term DID: 0000-0000-00000000 
txn branch: (nil) 
oct: 6, prv: 0, sql: 0x62d01c34, psql: 0x7c20f24c, user: 542/SCOTT
service name: SYS$USERS
O/S info: user: oracle, term: pts/7, ospid: 19758, machine: goblin.forgotten.realm s
program: sqlplus@goblin.forgotten.realms (TNS V1-V3)
application name: SQL*Plus, hash value=3669949024
waiting for 'library cache lock' blocking sess=0x(nil) seq=36 wait_time=0 seconds since wait started=11
handle address=62d064dc, lock address=79f88a68, 100*mode+namespace=c9

可以看到20号进程在等待library cache lock，我们可以根据handle address=62d064dc查找阻塞者。

根据handle address我们可以查询到18号进程目前正在以排他模式（mode=X）持有该锁。然后我们可以使用v$session及v$process视图进一步排查该进程。

参考资料

1.Troubleshooting: "WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK! "(文档 ID 278316.1)

2.How to Find which Session is Holding a Particular Library Cache Lock(文档 ID 122793.1)