hanganalyze 解决数据库row cache lock

r囧r小猫 2022-09-30 06:17 187阅读 0赞

# hanganalyze解决row cache lock(ZT) #

[上一篇][Link 1] / [下一篇][Link 2]  2011-04-05 15:46:00 / 个人分类：[Oracle][]

[查看( 2 )][2] / [评论( 0 )][0] / [评分( 0 / 0 )][0 _ 0]

执行一个split分区的脚本时长时间没有响应。登录上去查看，手工执行了split脚本，发现确实会hang住：

**SQL** > ALTER TABLE A\_PDA\_SP\_STAT SPLIT PARTITION P\_MAX AT ( 20090609 )   
 INTO ( PARTITION P\_20090608 TABLESPACE TS\_DATA\_A , PARTITION P\_MAX TABLESPACE TS\_DATA\_A )   
 SQL >

检查该session的等待事件：

EVENT                                   P1           P2           P3   
\---------------------------- \-- ---------- ---------- ----------   
 row cache lock                           8           0           5

查了网上的一些资料，说和sga的shared pool大小不足有关，或者和sequence的cache不大有关。经过分析，这2个原因应该都不是。因为1、如果是shared pool不足，这样的现象一般是某个sql执行的比较慢，但是还是会执行完，而不是像现在这样的挂住；2，只是执行split分区，并没有和 sequence相关。

在这里，我们用**hanganalyze**来进行分析。

hanganalyze用法：

(在这里我们用oradebug来用做hanganalyze)  
1.oradebug setospid  
2.oradebug analyze < level >   
然后观察出来的trace文件。

这里的level有如下几级：

Dump     Level Dump Contains  
\----------------------------------------  
1-2      Only HANGANALYZE output, no process dump at all  
3        Level 2 + Dump only processes thought to be in a hang (IN\_HANG state)  
4        Level 3 + Dump leaf nodes (blockers) in wait chains (LEAF,LEAF\_NW,IGN\_DMP state)  
5        Level 4 + Dump all processes involved in wait chains (NLEAF state)  
10       Dump all processes (IGN state)

我们现在来看看出来的trace文件：

SQL> select spid from v$session a,v$process b where a.paddr=b.addr and a.sid=295;  
SPID  
\------------  
19237  
SQL> oradebug SETOSPID 19237  
**Oracle** pid: 235, Unix process pid: 19237, image: oracle@hl\_rdb01 (TNS V1-V3)  
SQL>  
SQL> oradebug hanganalyze 3;  
Cycle 1: (0/295)  
Cycle 2: (0/254)--(0/239)  
Hang Analysis in /oracle/app/oracle/admin/hlreport/udump/hlreport\_ora\_25247.trc  
SQL> !  
$ more /oracle/app/oracle/admin/hlreport/udump/hlreport\_ora\_25247.trc  
Dump file /oracle/app/oracle/admin/hlreport/udump/hlreport\_ora\_25247.trc  
Oracle9i Enterprise Edition Release 9.2.0.6.0 - 64bit Production  
With the Partitioning, OLAP and Oracle Data Mining options  
JServer Release 9.2.0.6.0 - Production  
ORACLE\_HOME = /oracle/app/oracle/product/9.2.0  
System name:    HP-UX  
Node name:      hl\_rdb01  
Release:        B.11.11  
Version:        U  
Machine:        9000/800  
Instance name: hlreport  
Redo thread mounted by this instance: 1  
Oracle process number: 157  
Unix process pid: 25247, image: oracle@hl\_rdb01 (TNS V1-V3)  
   
\*\*\* SESSION ID:(312.10459) 2009-05-20 16:21:58.423  
\*\*\* 2009-05-20 16:21:58.423  
==============  
HANG ANALYSIS:  
==============  
 Cycle 1 :<cnode/sid/sess\_srno/proc\_ptr/ospid/wait\_event>:  
    <0/329/43816/0x4d6b5638/23487/rowcachelock>  
 --<0/254/19761/0x4d687438/23307/librarycachelock>  
Cycle 2 :<cnode/sid/sess\_srno/proc\_ptr/ospid/wait\_event>:  
    <0/295/57125/0x4d6b8978/19237/rowcachelock>  
Cycle 3 :<cnode/sid/sess\_srno/proc\_ptr/ospid/wait\_event>:  
    <0/295/57125/0x4d6b8978/19237/rowcachelock>  
Open chains found:  
Other chains found:  
Chain 1 :<cnode/sid/sess\_srno/proc\_ptr/ospid/wait\_event>:  
    <0/312/10459/0x4d69f9b8/25247/NoWait>  
Extra information that will be dumped at higher levels:  
\[level  3\] :   4 node dumps -- \[IN\_HANG\]  
\[level  5\] :   1 node dumps -- \[SINGLE\_NODE\] \[SINGLE\_NODE\_NW\] \[IGN\_DMP\]  
\[level 10\] : 223 node dumps -- \[IGN\]  
   
State of nodes

(\[nodenum\]/cnode/sid/sess\_srno/session/ospid/state/start/finish/\[adjlist\]/predecessor):  
\[0\]/0/1/1/0x4d7146c0/5132/IGN/1/2//none

……………………………………………………

\[238\]/0/239/57618/0x4d7b18a0/13476/IN\_HANG/395/402/\[294\]\[238\]\[328\]\[253\]/none  
……………………………………………………

\[253\]/0/254/19761/0x4d7bb710/23307/IN\_HANG/397/400/\[328\]\[238\]\[294\]/294

………………………………………………………………

\[294\]/0/295/57125/0x4d7d6820/19237/IN\_HANG/396/401/\[294\]\[238\]\[253\]/238  
\[328\]/0/329/43816/0x4d7ecf40/23487/IN\_HANG/398/399/\[253\]/253  
………………………………………………………………

Dumping System\_State and Fixed\_SGA in process with ospid 13476  
Dumping Process information for process with ospid 13476  
Dumping Process information for process with ospid 23307  
Dumping Process information for process with ospid 19237  
Dumping Process information for process with ospid 23487

====================  
END OF HANG ANALYSIS  
====================  
\*\*\* 2009-05-20 16:48:20.686

我们来看看(\[nodenum\]/cnode/sid/sess\_srno/session/ospid/state/start/finish/\[adjlist\]/predecessor)部分：  
nodenum是hanganalyze自己为了记录这些会话而定制的编号，从0开始排起。  
cnode是Node Id  
sid是 Session ID  
sess\_srno是serial\#  
proc\_ptr是Process Pointer  
ospid 是OS Process ID  
state 是node的状态  
adjlist是临近的node(通常代表一个blocker node)  
predecessor是Predecessor node ,通常代表一个 waiter node

state部分有几个比较重要的状态：  
1.IN\_HANG：这表示该node处于死锁状态，通常还有其他node（blocker）也处于该状态  
2.LEAF/LEAF\_NW：该node通常是blocker。通过条目的”predecessor”列可以判断这个node是否是blocker。LEAF说明该NODE没有等待其他资源，而LEAF\_NW则可能是没有等待其他资源或者是在使用CPU.  
3.NLEAF：通常可以看作这些会话是被阻塞的资源。发生这种情况一般说明**数据库**发生性能问题而不是数据库hang  
4.IGN/IGN\_DMP：这类会话通常被认为是空闲会话，除非其adjlist列里存在node。如果是非空闲会话则说明其adjlist里的node正在等待其他node释放资源。  
5.SINGLE\_NODE/SINGLE\_NODE\_NW：近似于空闲会话

现在我们来看看我们的trace出来的文件：  
Cycle 1 ::  
<0/329/43816/0x4d6b5638/23487/row cache lock>  
— <0/254/19761/0x4d687438/23307/library cache lock>  
Cycle 2 ::  
<0/295/57125/0x4d6b8978/19237/row cache lock>  
Cycle 3 ::  
<0/295/57125/0x4d6b8978/19237/row cache lock>

cycle表示oracle内部确定的死锁。其中我们的当前手工执行split的295进程也在里面。  
我们观察其他的进程在做什么，如329：

SQL > l   
  1   select machine , status , program , sql\_text from v $ session a , v $ sqlarea b   
  2 \* where a . sql\_address = b . address and a . sid = 329   
 SQL > /  
   
 MACHINE                                                           STATUS   
\-------------------------------------------------------------- \-- --------   
 PROGRAM   
\---------------------------------------------- \--  
SQL\_TEXT   
\------------------------------------------------------------------------------ \--  
hl\_rdb01                                                         ACTIVE   
 sqlplus @ hl\_rdb01 ( TNS V1 \- V3 )   
 ALTER TABLE A\_PDA\_SP\_STAT SPLIT PARTITION P\_MAX AT ( 20090609 )   INTO ( PARTITION P   
 \_20090608 TABLESPACE TS\_DATA\_A   , PARTITION P\_MAX TABLESPACE TS\_DATA\_A )   
   
 SQL > select event from v $ session\_wait where sid = 329 ;  
   
 EVENT   
\-------------------------------------------------------------- \--  
row cache lock

发现也是在执行split语句，但是问了同事，他已经把之前运行失败的脚本完全kill掉了。  
估计在数据库中进程挂死了，没有完全的释放。  
kill掉329号进程后，发现还是挂住，所以我们继续做hanganlyze：

==============  
HANG ANALYSIS:  
==============  
   
Cycle 1 : < cnode / sid / sess\_srno / proc\_ptr / ospid / wait\_event > :  
     < 0 / 295 / 57125 / 0x4d6b8978 / 19237 / row cache lock >   
Cycle 2 : < cnode / sid / sess\_srno / proc\_ptr / ospid / wait\_event > :  
     < 0 / 254 / 19761 / 0x4d687438 / 23307 / library cache lock >   
 -- < 0 / 239 / 57618 / 0x4d6b74f8 / 13476 / row cache lock >

我们继续把其他的进程杀掉。终于295的split执行成功。

SQL > ALTER TABLE A\_PDA\_SP\_STAT SPLIT PARTITION P\_MAX AT ( 20090609 )   
   INTO ( PARTITION P\_20090608 TABLESPACE TS\_DATA\_A   , PARTITION P\_MAX TABLESPACE TS\_DATA\_A )   
 SQL > /  
       
 Table altered .  
   
 Elapsed : 00 : 31 : 03.21   
 SQL >

继续执行split下一个分区，也很快完成。

SQL > ALTER TABLE A\_PDA\_SP\_STAT SPLIT PARTITION P\_MAX AT ( 20090610 )   
  2     INTO ( PARTITION P\_20090609 TABLESPACE TS\_DATA\_A   
  3    , PARTITION P\_MAX TABLESPACE TS\_DATA\_A ) ;  
   
 Table altered .  
   
 Elapsed : 00 : 00 : 00.02   
 SQL >  
至此，问题解决.

\[238\]/0/239/57618/0x4d7b18a0/13476/IN\_HANG/395/402/\[294\]\[238\]\[328\]\[253\]/none  
\[253\]/0/254/19761/0x4d7bb710/23307/IN\_HANG/397/400/\[328\]\[238\]\[294\]/294  
\[294\]/0/295/57125/0x4d7d6820/19237/IN\_HANG/396/401/\[294\]\[238\]\[253\]/238  
\[328\]/0/329/43816/0x4d7ecf40/23487/IN\_HANG/398/399/\[253\]/253  
329堵塞住了254  
254堵塞住了295  
295堵塞住了238

杀掉的应该是329,254,295

[Link 1]: http://writeblog.csdn.net/batch.common.php?action=viewspace&op=up&itemid=691713&uid=628922
[Link 2]: http://writeblog.csdn.net/batch.common.php?action=viewspace&op=next&itemid=691713&uid=628922
[Oracle]: http://writeblog.csdn.net/628922/spacelist-blog-itemtypeid-78964
[2]: http://writeblog.csdn.net/#xspace-tracks
[0]: http://writeblog.csdn.net/#xspace-itemreply
[0 _ 0]: http://writeblog.csdn.net/#xspace-itemform