在dbsnake 上看到的这篇文章,转过来。 主要还是学习解决问题的一个思路。这个往往比问题的解决更重要。

      

内容如下:

 

       今天接到同事的电话,说他的一个存储过程已经run了一个多小时了,还在继续run,他觉得极不正常,按道理说不应该run这么长时间。

我说那我去看一下吧。

 

       这个库是一个AIX上的10.2.0.4,我采集了一下问题时间段的AWR报告:

 

      

系统在经历严重的library cache pin以及library cache lock等待。

看出导致上述library cache pin和library cache lock的并不是hardparse。

       对于library cache pin等待来说,AWR报告的作用有限,最有效的方式就是找到持有library cache pin以及等待library cache pin的session,然后看看他们在做什么:

 

SQL> SELECT s.sid, kglpnmod"Mode", kglpnreq "Req", SPID "OS Process"

2 FROM v$session_wait w, x$kglpn p,v$session s ,v$process o

3 WHERE p.kglpnuse=s.saddr

4 AND kglpnhdl=w.p1raw

5 and w.event like '%library cache pin%'

6 and s.paddr=o.addr

7 /

 

SID Mode Req OS Process

---------- ---------- ---------- ------------

396 0 2 6381970

396 0 2 6381970

396 0 2 6381970

396 0 2 6381970

341 2 0 4092132

341 2 0 4092132

341 2 0 4092132

341 2 0 4092132

363 0 2 3514690

363 0 2 3514690

363 0 2 3514690

363 0 2 3514690

304 0 2 3977478

304 0 2 3977478

304 0 2 3977478

304 0 2 3977478

354 0 3 3137874

354 0 3 3137874

354 0 3 3137874

354 0 3 3137874

 

20 rows selected

 

       我那位run存储过程的同事所在的session是396,从上述结果里我们可以看出来396现在想以Share模式(即Req=2)去持有library cache pin,同时现在持有上述library cache pin的是session 341,且341的持有模式也是Share(即Mode=2)。

       本来Share和Share是可以共享的,但不幸的是在396之前,session 354想以Exclusive模式(即Req=3)去持有上述librarycache pin,这直接导致了396需要处于等待的Queue中,同时处于Queue中的还有363和304。

 

我为什么这么说呢,因为oracle对library cache pin的解释中有一句非常经典的话:

An X request (3) will be blocked by anypins held S mode (2) on the object.
An S request (2) will be blocked by any X mode (3) pin held, or may queue behind some other X request.

 

所以从AWR报告和上述查询结果中我们可以得出如下结论:

       1、 我那位run存储过程的同事为什么run了1个多小时还没有run完是因为这个存储过程正在经历严重的library cache pin等待;

也就是说341阻塞了354,而354又间接阻塞了396。

 

既然知道了原因,那我们去看一下session 341在做什么事情:

SQL> selectdecode(sql_hash_value,0,prev_hash_value,sql_hash_value) from v$session wheresid=341;

DECODE(SQL_HASH_VALUE,0,PREV_H

------------------------------

784727971

 

间隔10秒钟后再次执行:--间隔10秒查询的目的是判断session 的内容是否改变,从而判断出session 在干什么

SQL> selectdecode(sql_hash_value,0,prev_hash_value,sql_hash_value) from v$session wheresid=341;

DECODE(SQL_HASH_VALUE,0,PREV_H

------------------------------

784727971

 

间隔10秒钟后再次执行:

SQL> selectdecode(sql_hash_value,0,prev_hash_value,sql_hash_value) from v$session wheresid=341;

DECODE(SQL_HASH_VALUE,0,PREV_H

------------------------------

784727971

 

SQL> select sql_text from v$sqltextwhere hash_value=784727971 order by piece;

SQL_TEXT

----------------------------------------------------------------

begin -- Call the procedurep_adj_rrp_main(o_vc_flag => :o_vc_flag); end;

 

       从结果里可以看到341一直在run一个存储过程。

       给持有341的那位大姐打电话,问她在做什么,她告诉我说她从昨晚就开始run这个存储过程,今早来看发现死掉了,所以她就没管了。

 

       知道原因后处理起来还是很容易的,当我把session 341干掉后,整个系统的library cache pin一下子就降下来了,接着我那位同事的run了一个多小时的存储过程过了没多久就run完了。