11.2.0.3 RAC(VCS)节点crash以及hang的问题分析
2014-04-24 11:16
302 查看
昨天某个客户的一套双节RAC其中一个节点crash,同时最后导致另外一个节点也hang住,只能shutdown abort.
且出现shutdown abort实例之后,还有部分进程无法通过kill -9 进行kill的情况。其中有lgwr,arch等进程.
首先我们来看下,在下午出现crash的节点的alert log信息:
?
我们可以看到,最早在Apr 22 17:25:05 2014 时间点,即抛出LMON IPC send timeout的错误了。
Receiver: inst 2 binc 95439 ospid 13752 这里的receiver进程为节点2的13752进程,即节点2的LMON进程。
对于LMON进程,主要是监控RAC的GES信息,当然其作用不仅仅局限于此,其还负责检查集群中各个Node的健康
情况,当有节点出现故障是,负责进行reconfig以及GRD(global resource Directory)的恢复等等。我们知道
RAC的脑裂机制,如果IO fencing是Oracle本身来完成,也就是说由CLusterware来完成。那么Lmon进程检查到
实例级别出现脑裂时,会通知clusterware来进行脑裂操作,然而其并不会等待clusterware的处理结果。当等待
超过一定时间,那么LMON进程会自动触发IMR(instance membership recovery),这实际上也就是我们所说的
Instance membership reconfig。
其次,lmon进程主要通过2种心跳机制来检查判断集群节点的健康状态:
1) 网络心跳 (主要是通过ping进行检测)
2) 控制文件磁盘心跳,其实就是每个节点的ckpt进程每3s更新一次controlfile的机制。
所以这里大家可以看出,Lmon进程是需要操作controlfile的。否则无法判断第2点。
虽然从上面的错误来看,该实例是被LMHB进程给终止掉的,这里我们需要说明一下,LMBH进程的原理。
LMBH进程是Oracle 11R2版本引入的一个进程,该进程的作用的监控LMD,LMON,LCK,LMS等核心进程,防止这些Oracle
关键性后台进程spin或不被阻塞。该进程会定时的将监控的信息打印输出在trace文件中,便于我们进行诊断,
这也是11gR2一个亮点。当LMBH进程发现其他核心进程出现异常时,会尝试发起一些kill动作,如何有进程被阻塞的话。
如果一定时间内仍然无法解决,那么将触发保护,将实例强行终止掉,当然,这是为了保证RAC节点数据的完整性和一致性。
这里比较郁闷的是,这个diag的dump并没有产没 /u01/app/oa_base/diag/rdbms/authorcl/authorcl1/trace/authorcl1_diag_27561.trc
我们首先来看下Node1的Lmon进程的信息:
?
如下是该进程的资源使用情况:
?
我们可以看到,系统在该时间点load并不高,Memory也很充足。
这里有一个问题,该节点LMON进程hung的原因是什么? 从日志分析来看,是由于无法获得enq: CF – contention。
我们知道ckpt 进程会定时更新操作controlfile,且就需要获得该enqueue。 所有这里我大胆的假设,是由于ckpt持有CF的latch
不释放,导致LMON进程无法获得. 根据这一点我搜mos 发现一个bug,可惜该bug说已经在11.2.0.3中fixed了。
Bug 10276173 LMON hang possible while trying to get access to CKPT progress record
该bug描述说,当在进行reconfig时,lmon会尝试去获得ckpt processes record,会等待enq: CF -contention,会导致hung.
根据文档来看,显然这跟我们的实际情况不符。
下面我们来结合Node2的日志进行综合分析:
?
我们可以看到Node2 在Apr 22 17:26:59 2014 节点Node1的LMBH终止instance的信息了。然后在后面抛出hung的信息,
不过Oracle自动解决了hung的session。 下面我们来看下Node2上lmon进程的trace内容:
?
从lmon的trace信息我们可以看出,该进程正在等待control file sequential read,且已经等待了7分42秒。
根据trace的时间点,我们可以向前推进7分42秒,换句话讲,从17:19:18秒就开始等待了。
既然是controlfile的等待,那么我们就有必要来看下Node2节点上的ckpt进程在干什么了? 如下是ckpt进程的信息:
?
我们可以看到,Node2的ckpt进程等待control file sequential read,等待了7分40秒。同时大家还可以看到,ckpt
进程阻塞了2个进程,也就是说ckpt进程有2个waiter,其中一个waiter的信息是:sid:291,ser:59157
且该waiter进程的等待事件居然是DFS lock handle,这是一个比较危险的event。 这里我们还无法确认这个waiter是什么?
同时ckpt进程为啥等待这么长的时间 ?
大家知道11g引入的hung auto resolution,那么我们就来看下Node1上的diag的信息:
?
这里提到M000进程,大家应该知道这是跟AWR快照有关系的进程,该进程其实是被CKPT所阻塞,我们也可以来看下该进程
的情况,如下:
?
从这里看,root sess却是833,也就是我们Node2节点的CKPT进程。 到这里或许有人会说,问题的原因
应该很明确了,由于Node2 ckpt的异常,到这Node2 节点Lmon进程异常,由于需要和Node1的Lmon进程
进行通信,导致Node1 的lmon进程出现IPc send timeout的情况。
其实不然,到最后至始至终我们都没有完全弄清楚为何CKPT进程会等待这么长时间 ?
到这里我不得不怀疑IO的问题了,再回过头来分析Node1的diag trace时,发现一个有趣的事情:
?
我们可以看到,Node1上,lgwr进程阻塞了17个会话,等待log file parallel write,一直持续了4分32秒。
如果将时间点2014-04-22 17:24:08,向前推进4分32秒,那么就是2014-04-22 17:19:36.
我们再来检查Node2的操作系统日志你会发现有意思的事情:
?
我们可以看到,在17:19:16秒时vertias的VVR出现了异常。这也就是为什么我们在前面分析看到Node2在17:19:18时出现control file sequential read
等待的原因。虽然从vcs的日志什么信息:
?
所以,最后我的感觉是根本原因是vcs的问题。虽然vertias的工程师一直解释这里的Log overflow protection没有太大的关系。
针对这个问题,欢迎大家探讨。
补充:关于ora-29770导致实例crash的问题,Oracle确实有不少的bug,但是针对这个情况,目前没有发现符合的。如下是来自Oracle MOS的搜索结果:
Bug 11890804:LMHB crashes instance with ORA-29770 after long “control file sequential read” waits
Bug 8888434: LMHB crashes the instance with LMON waiting on controlfile read
Bug 11890804: LMHB TERMINATE INSTANCE WHEN LMON WAIT CHANGE FROM CF READ AFTER 60 SEC
Bug 13467673: CSS MISSCOUNT AND ALL ASM DOWN WITH ORA-29770 BY LMHB
Bug 13390052: KJFMGCR_HBCHECKALL MESSAGES ARE CONTINUOUSLY LOGGED IN LMHB TRACE FILE.
Bug 13322797: LMHB TERMINATES THE INSTANCE DUE TO ERROR 29770
Bug 13061883: LMHB IS TERMINATING THE INSTANCE DURING SHUTDOWN IMMEDIATE
Bug 12886605: ESSC: LMHB TERMINATE INSTANCE DUE TO 29770 – LMON WAIT ENQ: AM – DISK OFFLINE
Bug 12757321: LMHB TERMINATING THE INSTANCE DUE TO ERROR 29770
Bug 10296263: LMHB (OSPID: 15872): TERMINATING THE INSTANCE DUE TO ERROR 29770
Bug 10431752: SINGLE NODE RAC: LMHB TERMINATES INSTANCE DUE TO 29770
Bug 11656856: LMHB (OSPID: 27701): TERMINATING THE INSTANCE DUE TO ERROR 29770
Bug 10411143: INSTANCE CRASHES WITH IPC SEND TIMEOUT AND LMHB TERMINATES WITH ORA-29770
Bug 11704041: DATABASE INSTANCE CRASH BY LMHB PROCESS
Bug 10412545: ORA-29770 LMHB TERMINATE INSTANCE DUE TO VARIOUS LONG CSS WAIT
Bug 10147827: INSTANCE TERMINATED BY LMHB WITH ERROR ORA-29770
Bug 10016974: ORA-29770 LMD IS HUNG FOR MORE THAN 70 SECONDS AND LMHB TERMINATE INSTANCE
Bug 9376100: LMHB TERMINATING INSTANCE DUE ERROR 29770
且出现shutdown abort实例之后,还有部分进程无法通过kill -9 进行kill的情况。其中有lgwr,arch等进程.
首先我们来看下,在下午出现crash的节点的alert log信息:
?
Receiver: inst 2 binc 95439 ospid 13752 这里的receiver进程为节点2的13752进程,即节点2的LMON进程。
对于LMON进程,主要是监控RAC的GES信息,当然其作用不仅仅局限于此,其还负责检查集群中各个Node的健康
情况,当有节点出现故障是,负责进行reconfig以及GRD(global resource Directory)的恢复等等。我们知道
RAC的脑裂机制,如果IO fencing是Oracle本身来完成,也就是说由CLusterware来完成。那么Lmon进程检查到
实例级别出现脑裂时,会通知clusterware来进行脑裂操作,然而其并不会等待clusterware的处理结果。当等待
超过一定时间,那么LMON进程会自动触发IMR(instance membership recovery),这实际上也就是我们所说的
Instance membership reconfig。
其次,lmon进程主要通过2种心跳机制来检查判断集群节点的健康状态:
1) 网络心跳 (主要是通过ping进行检测)
2) 控制文件磁盘心跳,其实就是每个节点的ckpt进程每3s更新一次controlfile的机制。
所以这里大家可以看出,Lmon进程是需要操作controlfile的。否则无法判断第2点。
虽然从上面的错误来看,该实例是被LMHB进程给终止掉的,这里我们需要说明一下,LMBH进程的原理。
LMBH进程是Oracle 11R2版本引入的一个进程,该进程的作用的监控LMD,LMON,LCK,LMS等核心进程,防止这些Oracle
关键性后台进程spin或不被阻塞。该进程会定时的将监控的信息打印输出在trace文件中,便于我们进行诊断,
这也是11gR2一个亮点。当LMBH进程发现其他核心进程出现异常时,会尝试发起一些kill动作,如何有进程被阻塞的话。
如果一定时间内仍然无法解决,那么将触发保护,将实例强行终止掉,当然,这是为了保证RAC节点数据的完整性和一致性。
这里比较郁闷的是,这个diag的dump并没有产没 /u01/app/oa_base/diag/rdbms/authorcl/authorcl1/trace/authorcl1_diag_27561.trc
我们首先来看下Node1的Lmon进程的信息:
?
?
这里有一个问题,该节点LMON进程hung的原因是什么? 从日志分析来看,是由于无法获得enq: CF – contention。
我们知道ckpt 进程会定时更新操作controlfile,且就需要获得该enqueue。 所有这里我大胆的假设,是由于ckpt持有CF的latch
不释放,导致LMON进程无法获得. 根据这一点我搜mos 发现一个bug,可惜该bug说已经在11.2.0.3中fixed了。
Bug 10276173 LMON hang possible while trying to get access to CKPT progress record
该bug描述说,当在进行reconfig时,lmon会尝试去获得ckpt processes record,会等待enq: CF -contention,会导致hung.
根据文档来看,显然这跟我们的实际情况不符。
下面我们来结合Node2的日志进行综合分析:
?
不过Oracle自动解决了hung的session。 下面我们来看下Node2上lmon进程的trace内容:
?
根据trace的时间点,我们可以向前推进7分42秒,换句话讲,从17:19:18秒就开始等待了。
既然是controlfile的等待,那么我们就有必要来看下Node2节点上的ckpt进程在干什么了? 如下是ckpt进程的信息:
?
进程阻塞了2个进程,也就是说ckpt进程有2个waiter,其中一个waiter的信息是:sid:291,ser:59157
且该waiter进程的等待事件居然是DFS lock handle,这是一个比较危险的event。 这里我们还无法确认这个waiter是什么?
同时ckpt进程为啥等待这么长的时间 ?
大家知道11g引入的hung auto resolution,那么我们就来看下Node1上的diag的信息:
?
的情况,如下:
?
应该很明确了,由于Node2 ckpt的异常,到这Node2 节点Lmon进程异常,由于需要和Node1的Lmon进程
进行通信,导致Node1 的lmon进程出现IPc send timeout的情况。
其实不然,到最后至始至终我们都没有完全弄清楚为何CKPT进程会等待这么长时间 ?
到这里我不得不怀疑IO的问题了,再回过头来分析Node1的diag trace时,发现一个有趣的事情:
?
如果将时间点2014-04-22 17:24:08,向前推进4分32秒,那么就是2014-04-22 17:19:36.
我们再来检查Node2的操作系统日志你会发现有意思的事情:
?
等待的原因。虽然从vcs的日志什么信息:
?
针对这个问题,欢迎大家探讨。
补充:关于ora-29770导致实例crash的问题,Oracle确实有不少的bug,但是针对这个情况,目前没有发现符合的。如下是来自Oracle MOS的搜索结果:
Bug 11890804:LMHB crashes instance with ORA-29770 after long “control file sequential read” waits
Bug 8888434: LMHB crashes the instance with LMON waiting on controlfile read
Bug 11890804: LMHB TERMINATE INSTANCE WHEN LMON WAIT CHANGE FROM CF READ AFTER 60 SEC
Bug 13467673: CSS MISSCOUNT AND ALL ASM DOWN WITH ORA-29770 BY LMHB
Bug 13390052: KJFMGCR_HBCHECKALL MESSAGES ARE CONTINUOUSLY LOGGED IN LMHB TRACE FILE.
Bug 13322797: LMHB TERMINATES THE INSTANCE DUE TO ERROR 29770
Bug 13061883: LMHB IS TERMINATING THE INSTANCE DURING SHUTDOWN IMMEDIATE
Bug 12886605: ESSC: LMHB TERMINATE INSTANCE DUE TO 29770 – LMON WAIT ENQ: AM – DISK OFFLINE
Bug 12757321: LMHB TERMINATING THE INSTANCE DUE TO ERROR 29770
Bug 10296263: LMHB (OSPID: 15872): TERMINATING THE INSTANCE DUE TO ERROR 29770
Bug 10431752: SINGLE NODE RAC: LMHB TERMINATES INSTANCE DUE TO 29770
Bug 11656856: LMHB (OSPID: 27701): TERMINATING THE INSTANCE DUE TO ERROR 29770
Bug 10411143: INSTANCE CRASHES WITH IPC SEND TIMEOUT AND LMHB TERMINATES WITH ORA-29770
Bug 11704041: DATABASE INSTANCE CRASH BY LMHB PROCESS
Bug 10412545: ORA-29770 LMHB TERMINATE INSTANCE DUE TO VARIOUS LONG CSS WAIT
Bug 10147827: INSTANCE TERMINATED BY LMHB WITH ERROR ORA-29770
Bug 10016974: ORA-29770 LMD IS HUNG FOR MORE THAN 70 SECONDS AND LMHB TERMINATE INSTANCE
Bug 9376100: LMHB TERMINATING INSTANCE DUE ERROR 29770
相关文章推荐
- 11.2.0.3 RAC(VCS)节点crash以及hang的问题分析
- RAC一个节点自动重启问题分析
- rac节点频繁重启的问题分析
- RAC某节点v$asm_disk查询hang分析处理
- Android Crash 问题分析以及解决
- 一个rac问题分析过程由于进程资源不足导致的问题
- 利用crash 分析软死锁问题
- 编程珠玑 第一章 问题以及分析解答
- BigMC安装在ubuntu下遇到的问题。(问题分析以及思路)
- [置顶] "在证书存储区中找不到清单签名证书"问题分析以及解决方案
- 你所不知道的SQL Server数据库启动过程,以及启动不起来的各种问题的分析及解决技巧
- MySQL 出现 java.sql.SQLException 之 Got error 28 from storage engine 问题分析以及解决方法
- AIX下Oracle 10g RAC 双节点时间不同步问题解决
- 睿城_技术02----说一下关于平台在属性查询,以及空间查询分析等时候遇到的问题
- Android 通过form表单上传文字,图片,视频等(通过key值)以及问题分析
- Scripts:分析RAC hang的脚本(此脚本要慎用,在某些版本下可能会导致系统重启)RACDIAG.SQL
- LINUX+10.2.0.3 RAC删除、增加节点所遇问题记录
- 关于内网版网站建设的一些问题以及分析
- 分析诊断某省公司后台数据库Oracle 11g hang住问题
- hbase region lookups流程以及rpc线程卡死问题分析