Systemstate Dump分析经典案例(下)

前言

接上一期:(上一期的阅读方法:关注“中亦安图”公众号后回复‘007’)

4.3.4

SSD中library cache lock的分析

接上一期:

分析到这步,前边看似毫无头绪的问题似乎理清了,大量cursor:pin S wait on X已经理清楚,所有的矛头走指向了sid 859

离真相只差一步了,我们只需要分析library cache lock的源头就能解释整个谜团了,前面老K已经提到了分析library cache lock等待事件的方法了,现在我们就来结合trace文件看看如何定位library cache lock的阻塞关系。

那好,我们就来看sid 859:

这个会话信息中我们能看到:

>> 会话在等待library cache lock等待事件,等待时间4429秒

>> 会话以S模式请求句柄为700000209bb9d80的library cache对象(request=S)

>> 句柄为700000209bb9d80的library cache对象是SYS.C_OBJ#_INTCOL#,是一个cluster(簇聚)对象。

我们就看到,会话859正在以S模式请求700000209bb9d80上的library cache lock而产生了等待,那么我们就可以确认系统中一定有另一个会话以X模式持有了700000209bb9d80上的library cache lock;同样,我们在trace文件中搜索关键字”700000209bb9d80”再过滤后能看到下面的条目:

我们定位到该条信息后,再确认该条信息所属的会话,确认其会话信息如下:

看到这里,大家有没有柳暗花明的感觉呢,我们看到持有700000209bb9d80上library cache lock的会话是624,而会话624正在等待”cursor:pin S wait on X”事件,等待的对象正是bbcee4f7;现在我们再来完善上面的等待链图:

到最后,我们发现在会话859和会话624之间,形成了死锁,具体的情况就是:

>> 会话859持有bbcee4f7上的mutex,请求700000209bb9d80上的library cache lock

>> 会话624持有700000209bb9d80上的library cache lock,请求bbcee4f7上的mutex

>> 其他会话产生大量的cursor:pin S wait on X等待事件,都是由于859长时间持有bbcee4f7上的mutex未释放导致的

到了这一步,是不是一切谜团都解开了?我们的分析是不是就完成了呢?

答案是:NO

Part 5

根因分析

5.1 第三次头脑风暴

经常做根因分析的老K此时还有疑惑:

>> 如果当时不重启,而kill掉死锁链上的会话,问题是否会解决?

>> 会话859和会话624都在做什么,为什么会死锁?

>> 单个会话持有一个cursor的mutex,怎么会让系统处于夯住的状态?

5.2 柳暗花明之会话859

现在老K重点关注的就是如何解开上面的两个疑惑了,继续分析trace。

先看会话859,截取trace文件中的信息,如下:

从标黄处的信息我们知道,这是一个数据库的后台进程;我们可以通过查看trace中这个会话所属的进程信息如下:

先回答第二个问题:会话859在做什么?

后台进程是CJQ0,这个进程是ORACLE用来调度job的;我们知道,如果某个会话以S模式请求某个对象上的library cache lock,这个会话通常是在解析某个语句或者编译某个package时需要从library cache中查找该语句涉及对象的信息;在PROCESS 24的trace文件中查找“oper EXCL”关键字,我们查到以下三条记录

在PROCESS 24的trace文件中查找“oper EXCL”关键字,我们查到以下三条记录

Mutex 7000001e7d04898(859, 0) idn bbcee4f7 oper EXCL

Mutex 7000001e5fbe4e0(859, 0) idn fb52493f oper EXCL

Mutex 7000001e8faa990(859, 0) idn a8bbc174 oper EXCL

可能有人会问?一个会话怎么同时有三个cursor?

大家不要忘了ORACLE数据库中有递归调用的说法,也就是说前端发起一条简单的sql,ORACLE后台实际上产生了一系列的递归调用,那些调用实际上也是一些sql的集合。通过idn值继续查找,提炼一下,当前正在解析的三条sql语句分别是:

这里说明一下:其实,SSD中对sql的递归调用关系是不体现的,不过从上面的三条sql语句老K还是能推断出其调用关系的;

CJQ0进程是用来调度oracle job的,从三条语句能大致的看到:a8bbc174是用来查询系统中job相关信息的sql, fb52493f是通过对象号用来查询某个对象的信息的sql,而bbcee4f7则是用来查询直方图信息的sql。

a8bbc174调用fb52493f,fb52493f调用bbcee4f7,如果这是bbcee4f7出问题,另外两个肯定无法正常执行。这里正是因为bbcee4f7无法完成解析,而导致其上层的fb52493f和a8bbc174阻塞;

新的疑点:三条SQL和C_OBJ#_INTCOL#有什么内在联系?

会话正在请求C_OBJ#_INTCOL#上的library cache lock而产生等待,而从这三条sql的文本来看,似乎都跟C_OBJ#_INTCOL#这个对象扯不上关系,这又怎么解释呢?有细心的读者可能已经注意到了,前面老K特意指出了C_OBJ#_INTCOL#是一个cluster(簇聚)对象,cluster对象不是表,而是用来存储多个表的共同列的,那这里我们就可以注意最底层调用的sql中的histgrm$对象是否与C_OBJ#_INTCOL#有关,我们来看看histgm$的定义:

又解开了一个谜题,histgrm$确实使用了C_OBJ#_INTCOL#这个cluster对象,所以在解析使用了histgrm$表的sql语句时,需要获取C_OBJ#_INTCOL#上的library cache lock。

5.3 柳暗花明之会话624

接下来,再来看看会话624,像分析会话859一样,把单个进程的trace摘出来,我们来截取部分信息如下:

从这里看,这是一个被调起的job进程,PROCESS号为42;

这不是一个数据库的后台进程,所以,相比于之前看到的859进程,我们能看到更多的信息,我们大致知道,这个进程是数据库调起的收集统计信息的job任务,在等待”cursor:pin S wait on X”事件,等待的解析对象是bbcee4f7;

因为它以X模式持有C_OBJ#_INTCOL#这个对象的library cache lock而阻塞了关键的会话859,那么我们来看看它为什么会持有这个library cache lock;我们到PROCESS 42的进程信息中搜索oper EXCL的关键字,搜索到两条相关信息如下:

同样,我们也能从sql语句的语义上猜到两者的递归调用关系;

会话624持有了C_OBJ#_INTCOL#和I_OBJ#_INTCOL#的library cache lock,其中I_OBJ#_INTCOL#是CLUSTER的索引。现在所有疑团都解开了。可以放松一下,从头捋顺思路了。

Part 6

情景再现

终于看到了全景,看看数据库故障时刻在做什么。

在本场景中,t1时刻,数据库自动收集统计信息任务调度J000进程收集整个数据库统计信息,在收集cluster对象时,数据库只能使用analyze的方式分析;

t2时刻,因为C_OBJ#_INTCOL#对象的统计信息被更新,因为histgrm$与C_OBJ#_INTCOL#的关联关系,与histgrm$相关的sql(包括bbcee4f7)也就需要重新解析;

t3时刻,J000先收集C_OBJ#_INTCOL#统计信息,接着继续使用analyze的方式收集其索引I_OBJ#_INTCOL#的统计信息;

t4时刻,这时CJQ0进程定时查询系统JOB时,需要硬解析,递归调用bbcee4f7时对其进行解析;

解析的过程中需要以S模式请求持有histgrm$及其相关对象(也就包括C_OBJ#_INTCOL#及其索引I_OBJ#_INTCOL#)的library cache lock;

t4时刻,J000进程正在analyze索引I_OBJ#_INTCOL#,也就以X模式持有了I_OBJ#_INTCOL#上的library cache lock;

在J000使用analyze的过程中,同样需要执行相关递归sql,需要进行硬解析,也就调用了上面说到的关键sql bbcee4f7;

所以最后造成了死锁。

Part 7

问题定位

其实在上述分析的过程中,我们基本可以判断为bug,(MOS):1628214.1 Database Appears to Hang with Deadlock Involving SYS.C_COBJ# or C_OBJ#_INTCOL# While Statistics Maintenance Job is Running

Part 8

写在最后

到上面为止,我们已经定位bug,也获得了事中和事后的解决方案,不过老K更关注的是大家是否能从这个CASE中获得一些收获,这里不妨问问自己:

>> Systemstatedump中的cursor:pin S wait on X 我会查了吗?

>> Systemstatedump中的library cache lock 我会查了吗?

>> 如果我要模拟让我的数据库夯我会做吗?

>> 还有一个没有回答的问题?如果下次再遇到同样的问题,我能通过杀掉死锁链条里的进程解决这个问题么?

如果你的答案都是肯定的,那么老K觉得这篇分享很有价值。

如果以上问题你还有疑问,可以通过微信或者QQ共同交流讨论

时间: 2024-10-08 09:40:25

Systemstate Dump分析经典案例(下)的相关文章

Systemstate Dump分析经典案例(上)

前言 本期我们邀请中亦科技的另外一位Oracle专家老K来给大家分享systemstate dump分析的经典案例.后续我们还会有更多技术专家带来更多诚意分享. 老K作为一个长期在数据中心奋战的数据库工程师,看到小y前期的分享,有种跃跃欲试的感觉,也想把我日常遇到的一些有意思的案例拿出来分享讨论,希望我们都能从中获得些许收获,少走弯路.同时本文涉及到很多基础知识,又涉及看似枯燥的trace分析,但老K还是建议大家耐心看完本文. 精彩预告 如何分析cursor:pin S wait on X? 如

Hadoop经典案例Spark实现(七)——日志分析:分析非结构化文件

相关文章推荐 Hadoop经典案例Spark实现(一)--通过采集的气象数据分析每年的最高温度 Hadoop经典案例Spark实现(二)--数据去重问题 Hadoop经典案例Spark实现(三)--数据排序 Hadoop经典案例Spark实现(四)--平均成绩 Hadoop经典案例Spark实现(五)--求最大最小值问题 Hadoop经典案例Spark实现(六)--求最大的K个值并排序 Hadoop经典案例Spark实现(七)--日志分析:分析非结构化文件 1.需求:根据tomcat日志计算ur

多线程十大经典案例之一 双线程读写队列数据

本文配套程序下载地址为:http://download.csdn.net/detail/morewindows/5136035 转载请标明出处,原文地址:http://blog.csdn.net/morewindows/article/details/8646902 欢迎关注微博:http://weibo.com/MoreWindows 在<秒杀多线程系列>的前十五篇中介绍多线程的相关概念,多线程同步互斥问题<秒杀多线程第四篇一个经典的多线程同步问题>及解决多线程同步互斥的常用方法

秒杀多线程第十六篇 多线程十大经典案例之一 双线程读写队列数据

版权声明:本文为博主原创文章,未经博主允许不得转载. 目录(?)[+] 本文配套程序下载地址为:http://download.csdn.net/detail/morewindows/5136035 转载请标明出处,原文地址:http://blog.csdn.net/morewindows/article/details/8646902 欢迎关注微博:http://weibo.com/MoreWindows 在<秒杀多线程系列>的前十五篇中介绍多线程的相关概念,多线程同步互斥问题<秒杀多

oracle systemstate dump介绍

当数据库出现严重的性能问题或者hang了的时候,服务器端sqlplus也无法连接时,此时如果想获取数据库当前的状态信息,以便事后诊断,那么我们非常需要通过systemstate dump来知道进程在做什么,在等待什么,谁是资源的持有者,谁阻塞了别人.在出现上述问题时,及时收集systemstate dump非常有助于问题原因的分析.ORACLE 10g 开始,sqlplus提供了这么一个功能参数-prelim,在sqlplus无法连接的情况下,连接登录到数据库.下面关于这些知识点的一个总结 Th

网络机器人的识别与攻防的经典案例

本文我们介绍一个网络机器人的识别与攻防的经典案例.使用到的代码见本人的superword项目: https://github.com/ysc/superword/blob/master/src/main/java/org/apdplat/superword/tools/ProxyIp.java 我们的目的是要使用机器人自动获取站点http://ip.qiaodm.com/ 和站点http://proxy.goubanjia.com/ 的免费高速HTTP代理IP和端口号. 不过他们未对机器人进行识

性能分析之-- JAVA Thread Dump 分析综述

性能分析之-- JAVA Thread Dump 分析综述 一.Thread Dump介绍 1.1什么是Thread Dump? Thread Dump是非常有用的诊断Java应用问题的工具.每一个Java虚拟机都有及时生成所有线程在某一点状态的thread-dump的能力,虽然各个 Java虚拟机打印的thread dump略有不同,但是大多都提供了当前活动线程的快照,及JVM中所有Java线程的堆栈跟踪信息,堆栈信息一般包含完整的类名及所执行的方法,如果可能的话还有源代码的行数. 1.2 T

(Mirage系列之七)Mirage经典案例之管理和发布应用层

在(Mirage系列之二)VMware Horizon Mirage的经典用户用例及真实案例分析中我们介绍过,Mirage从逻辑上把终端桌面分层了三层:系统层(包括驱动和基础层),应用层,以及用户数据层.在(Mirage系列之五)Mirage经典案例之桌面驱动和基础层管理中我们讲到Mirage可以灵活方便的管理终端的驱动并且发布基础层.本文将介绍Mirage如何管理终端的应用层. 一个公司往往有很多部门,各部门所需要的工作软件也不尽相同.Mirage通过分层这个核心技术,将应用层剥离出来,使得管

多线程面试题系列(16):多线程十大经典案例之一 双线程读写队列数据

前十五篇中介绍多线程的相关概念,多线程同步互斥问题(第四篇)及解决多线程同步互斥的常用方法--关键段.事件.互斥量.信号量.读写锁.为了让大家更加熟练运用多线程,将会有十篇文章来讲解十个多线程使用案例,相信看完这十篇后会让你能更加游刃有余的使用多线程. 首先来看第一篇--第十六篇 多线程十大经典案例之一 双线程读写队列数据 <多线程十大经典案例之一双线程读写队列数据>案例描述: MFC对话框中一个按钮的响应函数实现两个功能:显示数据同时处理数据,因此开两个线程,一个线程显示数据(开了一个定时器