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)
杭州沃趣科技股份有限公司创建于2012年(股票代码:839849),创始团队为原阿里巴巴数据库及系统运维团队核心骨干,凭借着多年的运维经验,为行业客户提供专业数据库、系统相关的服务和产品;专注为用户提供基于高性能、高可用、可扩展的开放数据库云平台解决方案的国产厂商。
沃趣科技的产品已广泛应用于证券、保险、医疗、广电传媒、银行、电信、能源电力、快递物流、公共事业、大型企业等,为这些行业用户持续提供行业解决方案及服务支持。
研发中心位于杭州,同时在北京、上海、广州、南京、兰州建立了分支机构,拥有辐射全国的销售和服务体系。
我们始终坚信,数据是驱动企业创新的源动力!坚持围绕企业数据库做好一件事
——让高性能触手可及!