love wife love life —Roger的Oracle/MySQL/PostgreSQL数据恢复博客

Phone:18180207355 提供专业Oracle/MySQL/PostgreSQL数据恢复、性能优化、迁移升级、紧急救援等服务

A RAC node crash due to ora-00481

本站文章除注明转载外,均为本站原创: 转载自love wife love life —Roger的Oracle/MySQL/PostgreSQL数据恢复博客

本文链接地址: A RAC node crash due to ora-00481

这是某个客户的案例,这里分享给大家! 在2015/1/13号凌晨3:44分左右,XXXX集群数据库的节点1出现出现crash。
通过分析XXXX1节点的告警日志,我们发现如下内容:

从上述日志来看,在3:44:43时间点,节点1的LMON进程出现异常被终止,抛出ORA-00481错误。接着节点1的数据库实例被强行终止掉。

对于Oracle 的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。

从上述的日志分析,我们可以看出,节点1实例是被LMON进程强行终止的,而LMON进程由于本身出现异常才采取了这样的措施。那么,节点1的LMON进程为什么会出现异常呢?通过分析节点1数据库实例LMON进程的trace 内容,我们可以看到如下内容:

从上面LMON进程的trace信息来看,LMON进程检测到了DRM在进行sync时出现了timeout,最后LMON强制退出了。既然如此,那么我们就来分析为什么DRM会出现timeout;同时,我们也知道DRM的主要进程其实是LMD进程,那么我们来分析节点1实例的LMD进程的trace内容:

我们可以看到,当lmon进程遭遇ORA-00481错误之后,lmd进程也会强制abort终止掉。在LMON进程被强制终止掉之前,触发了一个process dump,如下:

通过上述的分析,我们可以看到ORA-00481错误的产生是关键,而这个错误是LMON进程产生的。
对于ORA-00481错误来讲,根据Oracle MOS文档(1950963.1)描述,通常有如下几种可能性的原因:

1)实例无法获得LE(Lock Elements)锁
2)RAC流控机制的 tickets不足

根据文档描述,我们从数据库两个节点的LMS进程trace中未发现如下的关键字信息:
Start affinity expansion for pkey 81885.0
Expand failed: pkey 81885.0, 229 shadows traversed, 153 replayed 1 retries

因此,我们可以排除第一种可能性。 同理,我们从lmd 进程的trace文件中,可以看到如下类似信息:

我们从上述红色部分内容可以看出,tickets是足够的,因此我们也可以排除第2种情况。换句话讲,该ORA-00481错误的产生,本身并不是Oracle RAC的配置问题导致。

对于LMON检查到DRM操作出现timeout,最后导致实例crash。timeout的原因通常有如下几种:

1)操作系统Load极高,例如CPU极度繁忙,导致进程无法获得CPU资源
2)进程本身处理异常,比如进程挂起
3)网络问题,比如数据库节点之间通信出现异常
4)DRM本身机制的不完善
5)Oracle DRM Bug
从上面的信息来看,系统在出现异常时,操作系统的Load是很低的,因此第一点我们可以直接排除。

我们现在的目的是需要分析出LMON检查到了什么异常,以及为什么会出现异常。LMD进程在abort之前进行了dump,那么我们可以从dump 中寻找一些蛛丝马迹,如下:

从上面LMON进程本身的dump来看,节点1实例的LMON进程状态是正常的,最后发送消息给LMON进程的是SO: 700001405330198,搜索该SO,我们可以发现为LMD进程,如下:

从LMD 进程本身的进程dump信息来看,似乎并无异常。从LMON和LMD进程的process dump来看,进程本身状态是正常的。因此我们可以排除进程挂起导致出现Timeout的可能性。

我们可以看到LMD进程一直在等待ges remote message,很明显这是和另外一个数据库节点进行通信;因此我们要分析问题的根本原因,还需要分析节点2数据库实例的一些信息。

首先我们来分析节点2实例的数据库告警日志,如下:

从节点2的数据库告警日志来看,在3:44:48时间点,开始进行实例的reconfig操作,这与整个故障的时间点是符合的。告警日志中本身并无太多信息,我们接着分析节点2数据库实例的LMON进程trace信息:

从上述LMON进程的日志来看,在故障时间点之前,数据库一直存在大量的DRM操作。上述红色部分的信息十分关键,首先节点进行reconfig时,reason 代码值为1.  关于reason值,Oracle Metalink文档有如下描述:

从reason =1 来看,数据库实例被强行终止重启也不是通信故障的问题,如果是通信的问题,那么reason值通常应该等于3. reason=1表明这是数据库节点自身监控时触发的reconfig操作。

同时我们从* kjfcln: DRM aborted due to CGS rcfg. 这段关键信息也可以确认,CGS reconfig的原因也正是由于DRM操作失败导致。同时,我们也可以看到,在3:29分开始的Begin DRM(82935)操作,一直到3:44出现故障时,这个DRM操作都没有结束(如果结束,会出现End DRM(82935) 类似关键字)。

由此也不难看出,实际上,该集群数据库可能在3:29之后就已经出现问题了。这里简单补充Oracle DRM的原理:

在Oracle RAC环境中,当某个节点对某个资源访问频率较高时,而该资源的master节点是不是local节点时,那么可能会触发DRM操作,DRM即为:Dynamic Resource Management。在Oracle 10gR1引入该特性之前,如果数据库需要更改某个资源的master节点,那么必须将数据库实例重启来完成。很显然,这一特性的引入无疑改变了一切。同时,从Oracle 10gR2开始,又引入了基于object/undo 级别的affinity。这里所谓的affinity,本质上是引入操作系统的概念,即对某个对象的亲和力程度;在数据库来看,即为对某个对象的访问频率程度。

在Oracle 10gR2版本中,默认情况下,当某个对象的被访问频率超过50时,而同时该对象的master又是其他节点时,那么Oracle则会触发DRM操作。在进程DRM操作的过程中,Oracle会将该资源的相关信息进行临时frozen,然后将该资源在其他节点进行unfrozen,然后更改资源的master节点。注意,这里临时frozen的资源其实是GRD(Global Resource Directory)中的资源。在整个DRM的过程之中,访问该资源的进程都将被临时挂起。因此,当系统出现DRM时,是很可能导致系统或进程出现异常的。

根据Oracle 文档的描述,当DRM触发较为频繁时,是很可能导致出现SYNC Timeout的,如下:

因此,我们认为此次故障的原因本质上就是因为Oracle DRM的异常导致了相关RAC核心进程的异常,最终导致了数据库实例被强行终止(当然,这本质上是为了保证数据的一致性)。目前客户已经屏蔽DRM,已经运行一周,暂时没有发现任何问题,有待进一步观察!

Leave a Reply

You must be logged in to post a comment.