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

梦里梦外; 2022-06-18 11:43 401阅读 0赞

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

当数据库出现严重的性能问题或者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登录到数据库![金属质感分割线][640_wx_fmt_jpeg_tp_webp_wxfrom_5_wx_lazy_1]

$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问题

![金属质感分割线][Image 1]

> 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问题

![金属质感分割线][Image 1]

首先我们可以通过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查找阻塞者。

![640_wx_fmt_png_tp_webp_wxfrom_5_wx_lazy_1][]

根据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)

[640_wx_fmt_jpeg_tp_webp_wxfrom_5_wx_lazy_1]: /images/20220618/109306e9e5c4445596977f506d3288de.png
[Image 1]: 
[640_wx_fmt_png_tp_webp_wxfrom_5_wx_lazy_1]: /images/20220618/c3a3291b484f46b0a7bdcdf24af54242.png