莫名其妙的HANG住现象

这是一个2013年的案例,老白的一个客户突然发过来一份AWR报告,让我帮助分析下这个报告时段里发生了什么。当时客户的系统某些应用模块的写操作就像HANG死了一样,不过DBA登上去看没发现有什么问题,操作系统与访问数据库的一些视图的速度都很正常,系统负载也不高。也不是所有的用户模块都有问题,只是部分写操作特别慢,平时秒钟级的模块有时候要HANG死几分钟甚至有些写操作就像死了一样,几分钟后报超时失败。这种现象持续了2个小时左右,然后系统就自动恢复正常了。

拿到AWR报告,首先我看了看负载情况:

莫名其妙的HANG住现象

这是一套10.2.0.4的系统,从负载上看确实不高。从TOP等待事件上看

莫名其妙的HANG住现象

似乎也很正常,行锁等待最高,平均488毫秒似乎也没有客户说的那样HANG死几分钟的情况。于是我直接看了看锁等待的详情章节:

从这里看行锁的等待数量并不多,不过等待的平均延时高达1400秒以上,这和客户描述的现象有点相似了。那么什么原因导致的呢?从等待事件上看不出有什么异常:

后台进程的db file parallel write/log file parallel write也很正常,平均等待3、4毫秒。

闩锁也是正常的,从系统活跃统计看,索引方面会影响行锁性能的指标也都很正常。

从AWR报告上看似乎看不出任何和系统有关的问题。让用户分析了ASH数据中等待行锁的会话情况,阻塞这些会话的都是一些正常的用户会话。而且这些会话的阻塞者的等待事件都很正常:SQL*Net message from client或者SQL*Net message to client。

难道是应用程序出现了问题?客户也问过开发商,问他们今天应用是否有变更或者有什么特殊的地方,开发商回答应用一切正常。不过从老白目前的分析看,数据库系统并无问题,阻塞者都在等待和client的交互,似乎是某某个会话停在那里不动了,导致其他会话长时间等待某个行锁。这种情况往往是应用出问题了才会出现。这些阻塞者也是JDBC应用,不是SQLPLUS登上去的,所以似乎也不好确定一定是应用的问题。

于是老白想到了从10.2开始,这种情况下如果存在会话长时间HANG住,RAC环境中,diag后台进程会进行HANG的诊断。于是让用户把DIAG的TRACE发过来认真分析了一下。这一分析,问题就清晰了。在当天的9:57分开始系统就出现了会话HANG住的现象,DIAG把相关的会话都做了PROCESS STATE DUMP。从PROCESS DUMP上可以看出:

阻塞者确实没有被其他会话HANG住,在等待客户端的网络消息。被阻塞者就在等待这个会话持有的行锁。

于是我们分析了行锁的情况:

这个锁就是HANG住另外一个会话的锁,res: 0x7000004e5196ad0, mode: X, lock_flag: 0x0。对于资源的状态是排他锁。很幸运,我们在diag的trace里,看到了一小时后又一次HANG分析的信息,这个行锁依然存在:

这个会话的等待事件也没有变化,只是等待时长多了3000多秒。

一个锁经过一个小时还没释放,而且会话还一直在等待客户端消息。这个证据让开发商无法辩驳,只好承认了今天一个业务部门在测试一个新的后台作业。于是他们拿出相关代码进行了分析,很快就找到了一处exception中没有进行rollback处理直接返回了。

问题真相大白了,不过这种场景时时出现在我们身边,只有找到确凿证据,开发商才会承认自己应用的问题。DBA也必须掌握类似老白分析问题所用的技巧,才能在这种争执中不处于被动。

莫名其妙的HANG住现象》来自互联网,仅为收藏学习,如侵权请联系删除。本文URL:http://www.hashtobe.com/882.html