查看原文
其他

Library cache lock 引发的一个案例

2015-09-25 李真旭 云和恩墨

美女同事说某个客户有个问题,系统出现了大量的 library cache lock. 导致业务严重受阻,具体表现是所有访问某个表的 SQL 语句都会挂起. 首先我们来看 hanganalyze 的结果:




这里对一部分内容进行简单的解释:



上述信息表上在进行 dump 时发现1513 会话阻塞了341个数据库会话 (session)。 阻塞了300多个会话,这在任何系统中恐怕都会导致很大的影响。在一个稍微的时间点 dump 又发现982会话阻塞了346个会话.


虽然这里有多条阻塞的记录,但是这不难理解,可以理解为是不同的时间点进行的(因为 dump 可能花了几分钟才完成)。


第二部分内容是死锁信息,如下:



这是 cycle 即循环,跟死锁类似。一般来讲,如果 trace 中出现了 cycle,而 cycle 涉及的进程又阻塞了大量的会话,那么系统估计都可能已经 hang了。从上述信息来看,节点2的1488 会话和节点1的700 会话互为“死锁”. 比较怪异的是,这2个会话都在等待 library cache lock. 而下面的1012 和1513 会话也是类似,也都在等待 library cache lock.


下面我们来继续解释第3部分内容:



这部分内容显示了所有进程的状态以及阻塞情况。对于进程的状态,主要是分为如下几种:



我们这里再回到主题上来、通过如下内容我们可以看到,此次故障的源头应该是会话1516,如下:



注意,这部分内容告诉我们的是,如下的会话 982,627,1488,700,1012,1513 等12个进程都是被1516 锁阻塞。


但是这需要我们注意的是,虽然这部分会话是被1516 锁阻塞,但并不是说这部分进程是1516 直接阻塞,因为很有可能是间接性的。从上述内容我们可以发现,cycle 的4个会话其实都被1516 阻塞了。这也说明一点,这里的 cycle 其实并不是真正意义上的死锁.


当然,客户解决这个问题很简单,通过将会话1516 kill 即可。 但是客户不明白的是,为什么会出现这个问题?


首先我们来看看客户的困惑是什么? 他们困惑的是为什么访问某个表的 sql 都不会挂起,哪怕是如下的 sql 也会挂起:


SQL> select count(1) from GEOSTAR.ATT_PT_LINE;


看到这里,可能很多人都会疑问,为什么 select 也会挂起? 有什么锁会阻塞 select 呢?


首先,我们来看下源头会话1516在干些什么 ?



该进程的 dump 内容比较长,有几千行,因为这里直接跳到最后。我们可以看到该会话持有了一个 Mode=x 的 CU 锁,所谓的 CU enqueue 其实是指 Bind Enqueue。我们看该 cursor 的夫游标地址是:7000004aa597e30


我们直接搜索:7000004aa597e30 可以发现如下内容:



我们可以看到,该会话在执行一个 insert 语句,访问的正是 att_pt_line 表,而且是通过 dblink 进行操作。 同时我们也可以看到该会话对这个表上进行了 library cache lock 和 pin 操作,如下:



我们知道,对应 library cache latch 的获取,实际上 Oracle SQL 语句的硬解析、软解析、甚至软软解析都是需要获取的。 对应软软解析、是否需要获得 library cache latch,在11g 中有所改变,但是客户这里是10205版本。


这里我们已经知道了1516 会话在干什么,那么仍然不知道为什么1516 会导致后面的982会话被阻塞呢 ?


我们接着来看下会话982是什么进程,在干些什么 ?




我们可以看到982会话是 Oracle 的定时任务发起的,通过 actiion name 我们可以知道、这是调用 GATHER_STATS_JOB。


很明显这是对于数据库全库的统计信息的收集。对应统计信息的收集,大家应该清楚,这其实类似 DDL 操作、默认情况之下会会导致 cursor 失效,而且还会导致 library cache lock 的产生。


出问题的这天正好是周日,对应这个定时任务,大家应该知道,周末是全天运行,如果收集失败也不会被强行终止掉。我们可以看到1516会话进程的 dump 时间点是 2015-05-09 06:16:26.707,这正好位于统计信息时候点之后不久。


于是我们可以大胆的猜测,统计信息后面其实是没有运行完成的,这也就是为什么982会话会导致大量的 library cache lock 等待的原因。


那么最后,为什么 select 这个表会挂起呢?


其实很简单,这是因为这个表的统计信息收集其实未完成,正在在进行中。而我们也知道这是会导致 cursor 失效的,那么针对这个表的所有 SQL 都必须进行硬解析,这毫无疑问,解析是需要获得 library cache pin 和 lock 的。 所有客户会发现任何一个会话去访问这个表出现的等待事件都是 library cache lock.


针对这一点,我们可以通过如下的实验来进行验证:


首先调整游标缓存的参数:


www.killdb.com>show parameter session_cached_cursors NAME TYPE VALUE ------------------------------------ ----------- ------------------------------ session_cached_cursors integer 0 www.killdb.com>select count(1) from t_library_lock; COUNT(1) ---------- 50042 www.killdb.com>select sql_id,hash_value,sql_Text from v$sqlarea where sql_text like '%t_library_lock%'; SQL_ID HASH_VALUE SQL_TEXT ------------- ---------- -------------------------------------------------------------------------------- c7sdcrtz4t3k3 2118946371 select sql_id,sql_Text from v$sqlarea where sql_text like '%t_library_lock%' f8m4jqsaypc7m 367702259 select count(1) from t_library_lock www.killdb.com>select to_char(367702259,'xxxxxxxxxx') from dual; TO_CHAR(367 ----------- 15eab0f3


那么如何选择 trace 的 level 呢? 首先来看下文档说明:



这里取后两位:b0f3 , 至于如何计算,我们来看文档示意图:




根据 Oracle 文档描述,这里还需要针对 pin、lock 以及 hash 的操作,对应的 level 分别是:

0×00002000

0×00000020

0×00000010


那么最后的 level 应该是:b0f30000+2000+20+10=b0f32030


最后再将其转换为10进制,则如下:




那么最后针对该 SQL 的 library cache pin/lock 操作 trace 即:

oradebug setospid xxx

oradebug event 10049 trace name context forever,level 2968723504

oradebug event 10049 trace name context off;


下面我们开始进行测试,首先我们来测试硬解析.


### 硬解析



我们来看下 trace 的内容:



从 trace 的内容我们可以清楚的看到,对应 SQL 的硬解析,是需要获得 library cache lock 和 library cache pin 操作的。


而且对应 select 语句,library cache lock 的 mode 是 NULL,而 library cache pin 的 mode 是 X.


### 测试软解析


--session 1 www.killdb.com>select count(1) from t_library_lock; COUNT(1) ---------- 50042 --session 2 www.killdb.com>oradebug event 10049 trace name context forever,level 2968723504 Statement processed. www.killdb.com>oradebug tracefile_name /home/ora10g/admin/test/udump/test_ora_10200.trc www.killdb.com>


此时的 trace 内容如下:




我们可以看到,对应 SQL 语句的软解析是不需要获得 library cache pin 操作的,只需要获得 library cache lock 即可,而且 mode 为 NULL。


### 软软解析




我们来看下软软解析的 trace 内容:




我们可以看到,SQL 的软软解析这里其实没有获得 library cache pin 和 library cache lock 操作.


最后我们来总结一下:


1、10205 版本中,SQL 硬解析是需要获得 library cache pin 和 lock 的,且分别的 mode 是 X 和 NULL。

2、10205 版本中,SQL 软解析是需要获得 library cache lock,mode 为 NULL。

3、10205 版本中,SQL 软软解析是不需要获得 library cache lock 和 pin 的。

4、其他版本可能不同、尤其是 mutex 的引入,11g 中可能有很大的变化,这一点稍后再进行验证。


------The End


文章来源:【love wife & love life —Roger 的 Oracle 技术博客】

配图来源:http://supercom.com.tr/en/database-security/

2015 Oracle 技术嘉年华10月7日前五折门票抢购进行中,长按上方图片识别二维码注册参会!



点击“阅读原文”查看原文章详情。

您可能也对以下帖子感兴趣

文章有问题?点此查看未经处理的缓存