【故障处理】Bug : ASM FAILS WITH CHECKRESOURCE ERROR ERROR CODE = 139

今天一直和Oracle RAC的一个Bug在战斗（最初并不知道这个一个未解决的Bug）。代价是惨痛的，过程是迷茫和艰辛的。将此次故障处理过程分享在此，希望能够引起我们大家的一些思考。

操作系统版本：64位Linux
bomsdb2@bomsdb2 /home/oracle$ cat /etc/redhat-release
Red Hat Enterprise Linux Server release 5.1 (Tikanga)

CRS版本：10.2.0.1
secodb1@secodb1 /home/oracle$ crsctl query crs softwareversion
CRS software version on node [secodb1] is [10.2.0.1.0]

Oracle数据库软件版本：Oracle 10.2.0.3
sys@secodb> select * from v$version;

BANNER
----------------------------------------------------------------
Oracle Database 10g Enterprise Edition Release 10.2.0.3.0 - 64bi
PL/SQL Release 10.2.0.3.0 - Production
CORE    10.2.0.3.0      Production
TNS for Linux: Version 10.2.0.3.0 - Production
NLSRTL Version 10.2.0.3.0 - Production

注：虽然RAC环境中的CRS版本比Oracle软件的版本低，但RAC依然可以正常使用（的确有些不可思议），这不是该故障的根本原因。

1.故障现象
1）启动时的报错信息
（1）使用crs_start方式启动故障节点实例的报错信息
secodb2@secodb2 /home/oracle/shutdown_and_start_RAC$ crs_start ora.secodb.secodb2.inst
Attempting to start `ora.secodb.secodb2.inst` on member `secodb2`
Start of `ora.secodb.secodb2.inst` on member `secodb2` failed.
secodb1 : CRS-1018: Resource ora.secodb2.ASM2.asm (application) is already running on secodb2


CRS-0215: Could not start resource 'ora.secodb.secodb2.inst'.

这个报错很诡异。可以说没有任何的指导和提示的意义。

（2）使用srvctl方式启动故障节点实例的尝试
secodb2@secodb2 /oracle/home$ srvctl start instance -d secodb -i secodb2

使用这种方法启动不但无法启动故障节点实例，进而，这条命令一直hang死在那里！
此时实例的alert文件没有任何信息输出，问题更加的诡异。使用srvctl命令无法启动实例。

（3）使用SQL*Plus直接启动实例
SQL> startup;
ORACLE instance started.

Total System Global Area 8388608000 bytes
Fixed Size               2086096 bytes
Variable Size            1795164976 bytes
Database Buffers         6576668672 bytes
Redo Buffers             14688256 bytes
ORA-03113: end-of-file on communication channel

收到的是常见的非常模糊报错信息“ORA-03113”。

与此同时在alert中记录的部分信息如下。
……省略部分信息……
Tue Jan  4 13:50:48 2011
 Submitted all GCS remote-cache requests
 Fix write in gcs resources
Reconfiguration complete
LCK0 started with pid=18, OS id=18900
Tue Jan  4 13:50:49 2011
ALTER DATABASE   MOUNT
Tue Jan  4 13:50:50 2011
Starting background process ASMB
ASMB started with pid=20, OS id=18912
Starting background process RBAL
RBAL started with pid=21, OS id=18920
Tue Jan  4 13:50:50 2011
Shutting down instance (abort)
License high water mark = 2
Instance terminated by USER, pid = 18956

提示启动的的示例被强制abort关闭！

2）CRS状态
Name           Type           Target    State     Host
------------------------------------------------------------
ora....b1.inst application    ONLINE    ONLINE    secodb1
ora....b2.inst application    ONLINE    OFFLINE
ora....db1.srv application    ONLINE    ONLINE    secodb1
ora....db2.srv application    OFFLINE   OFFLINE
ora...._taf.cs application    ONLINE    ONLINE    secodb2
ora.secodb.db  application    ONLINE    ONLINE    secodb1
ora....SM1.asm application    ONLINE    ONLINE    secodb1
ora....B1.lsnr application    ONLINE    ONLINE    secodb1
ora....db1.gsd application    ONLINE    ONLINE    secodb1
ora....db1.ons application    OFFLINE   OFFLINE   secodb1
ora....db1.vip application    ONLINE    ONLINE    secodb1
ora....SM2.asm application    ONLINE    ONLINE    secodb2
ora....B2.lsnr application    ONLINE    ONLINE    secodb2
ora....db2.gsd application    ONLINE    ONLINE    secodb2
ora....db2.ons application    OFFLINE   OFFLINE   secodb2
ora....db2.vip application    ONLINE    ONLINE    secodb2

此时显示只有故障节点secodb2上的数据库实例没有启动起来。

2.第一次故障处理尝试
首先怀疑的是ASM存在问题，导致实例无法顺利启动。
经对ASM及Data Group的状态查看没有问题。
尝试手工重启ASM，ASM重启成功，在此基础上依然无法启动实例。
尝试处理失败。

3.第二次故障处理尝试
尝试重启整个CRS堆栈。使用“crsctl stop crs”及“crsctl start crs”命令在root用户下重启CRS。更严重的问题出现了！
此时的现象是CRS无法启动，仅停留在inittab引导的初始化状态就不再继续了启动了。
现象如下：
secodb2@secodb2 /home/oracle$ ps -ef | grep init | grep -v grep
root         1     0  0  2010 ?        00:00:08 init [5]
root     29186     1  0 16:49 ?        00:00:00 /bin/sh /etc/init.d/init.crsd run
root     29270     1  0 16:49 ?        00:00:00 /bin/sh /etc/init.d/init.cssd fatal
root     29319     1  0 16:49 ?        00:00:00 /bin/sh /etc/init.d/init.evmd run
root      7624  7554  0  2010 ?        00:00:00 /usr/bin/ssh-agent /usr/bin/dbus-launch --exit-with-session /etc/X11/xinit/Xclients
root      7629     1  0  2010 ?        00:00:00 /usr/bin/dbus-launch --exit-with-session /etc/X11/xinit/Xclients

secodb2@secodb2 /home/oracle$ ps -ef | grep d.bin | grep -v grep
此处无信息返回，如果成功启动这里应该会返回“crsd.bin reboot”、“evmd.bin”及“ocssd.bin”信息。

与此同时查看crsd.log和ocssd.log均显示没有启动痕迹。

此时处于一种比较崩溃的状态。连重启CRS都无法完成！

4.第三次故障处理尝试
既然“crsctl stop crs”及“crsctl start crs”命令无法完成重启，我们是否可以尝试手工一步一步的去完成CRS的启动呢？
遗憾的是：Oracle 10gR2版本中没有提供有效的step by step启动CRS的方法（在Oracle 11.2.0.2版本中提供了该方法）。需要统一使用crsctl start crs启动。

5.第四次终极处理方法
首先要说的是：99.999%CRS无法启动的故障都能通过上述方法解决！
在没有任何办法的情况下只能考虑最后一搏：重启OS。
重启操作系统是影响面比较大的动作，需要等到业务都停止后再完成。

1）等待所有运行在正常节点上的业务都完成

2）备份数据库
以防万一，永远记住：备份是必须的！
可以使用expdp和rman工具完成备份。

3）重启故障节点操作系统
因为是Linux操作系统，可以使用reboot命令完成操作系统的重启。

4）检查成果
故障节点神奇般的恢复了正常！不过这只是处理结果上的成功。

6.追本溯源，探寻故障真谛
通过上述一系列高强度、高压力、紧张刺激的尝试，最终系统恢复了正常。但是面临着几大疑惑：
①为什么会出现如此诡异的故障，故障的真实原因是什么？
②如何有效避免该故障的再一次发生？
③Oracle RAC需要更加的健壮，莫名的故障对生产的冲击是可怕的。

这些问题可能只有第一个问题可以找到一些蛛丝马迹，在故障发生时CRS日志文件crsd.log中记录了下面一段有意义的信息。
2011-01-03 19:04:30.944: [  CRSAPP][1566763328]0CheckResource error for ora.secodb2.ASM2.asm error code = 139
2011-01-03 19:04:30.958: [  CRSRES][1566763328]0In stateChanged, ora.secodb2.ASM2.asm target is ONLINE
2011-01-03 19:04:30.958: [  CRSRES][1566763328]0ora.secodb2.ASM2.asm on secodb2 went OFFLINE unexpectedly
2011-01-03 19:04:30.958: [  CRSRES][1566763328]0StopResource: setting CLI values
2011-01-03 19:04:30.961: [  CRSRES][1566763328]0Attempting to stop `ora.secodb2.ASM2.asm` on member `secodb2`
2011-01-03 19:04:33.772: [  CRSRES][1535293760]0In stateChanged, ora.secodb.secodb2.inst target is ONLINE
2011-01-03 19:04:33.772: [  CRSRES][1535293760]0ora.secodb.secodb2.inst on secodb2 went OFFLINE unexpectedly
2011-01-03 19:04:33.772: [  CRSRES][1535293760]0StopResource: setting CLI values
2011-01-03 19:04:33.796: [  CRSRES][1535293760]0Attempting to stop `ora.secodb.secodb2.inst` on member `secodb2`
2011-01-03 19:04:34.439: [  CRSRES][1566763328]0Stop of `ora.secodb2.ASM2.asm` on member `secodb2` succeeded.
2011-01-03 19:04:34.440: [  CRSRES][1566763328]0ora.secodb2.ASM2.asm RESTART_COUNT=0 RESTART_ATTEMPTS=5
2011-01-03 19:04:34.440: [  CRSRES][1566763328]0Restarting ora.secodb2.ASM2.asm on secodb2
2011-01-03 19:04:34.443: [  CRSRES][1566763328]0startRunnable: setting CLI values
2011-01-03 19:04:34.443: [  CRSRES][1566763328]0Attempting to start `ora.secodb2.ASM2.asm` on member `secodb2`

而这段信息暴露出Oracle RAC的一个可怕的Bug，正是由于这个Bug导致节点实例挂起。
有关这个Bug在MOS中的信息为：Bug 10371862: ASM FAILS WITH CHECKRESOURCE ERROR ERROR CODE = 139

有关这个Bug的真实原因截止到目前还没有定论，Oracle仍然在研究应对策略。只是提到这个故障比较少见，并且会间歇性出现。这就是Bug的可怕之处。

7.小结
有关这个Bug导致的故障处理介绍完毕。将一些经验收获总结在此。
1）Oracle是不完美的，她在努力变得更加的美丽；
2）所有影响到生产的Bug都要得到最高级别的重视，希望Oracle尽快给出该Bug的原因和解决方案；
3）即便遇到Oracle的Bug导致生产系统故障，我们应该同样保持平常心来一步一步地应对，虽然这并“不轻松”；
4）永远保持对未知事物的好奇心，这样会是我们知识得到快速膨胀；
5）Last but very inportant：有效的备份永远是我们希望！（此条经验对于具有海量数据的超大型数据库不适用。）

感谢Ricky和老叶在此次故障处理过程中的献计献策，朋友永远弥足珍贵！

Good luck.

secooler
11.01.04

-- The End --

来自 “ ITPUB博客 ” ，链接：http://blog.itpub.net/519536/viewspace-683244/，如需转载，请注明出处，否则将追究法律责任。

转载于:http://blog.itpub.net/519536/viewspace-683244/