返回 登录
7

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 2661~2分钟 
SQL>oradebug -g all dump systemstate 2661~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处理Rrow 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$sessionv$process视图进一步排查该进程。

参考资料

  • Troubleshooting: “WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK! “(文档 ID 278316.1)

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

来源:沃趣科技(woqutech)
作者:孟庆辉,沃趣科技数据库工程师。

评论