【故障處理】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 --
作業系統版本：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/，如需轉載，請註明出處，否則將追究法律責任。
相關文章
- ORA-00600: internal error code, arguments: [15709], [29], [1]-故障處理Error
- sqlplus"strace: exec: Exec format error"故障處理SQLORMError
- error:slave communication error with ASMErrorASM
- ERROR: slave communication error with ASMErrorASM
- error的處理方式Error
- "OPatch failed with error code 73"故障一例AIError
- 【ERROR】OPatch failed with error code 73ErrorAI
- 15-錯誤處理（Error）Error
- Rails全域性處理Error薦AIError
- ORA-00600: internal error code, arguments: [4194] 錯誤處理Error
- Spring Boot Web Error Page處理Spring BootWebError
- perror error codeError
- [譯] Part 30: Golang 中的Error處理GolangError
- logstash nginx error access 日誌處理NginxError
- ORA-00600 Error的通用處理Error
- System Error CodesError
- Oracle OER 7451 in Load Indicator : Error Code = OSD-04500的問題處理OracleIndicatorError
- ORA-00600: internal error code, arguments: [kcratr_scan_lastbwr]錯誤處理ErrorAST
- 【MySQL】5.6/5.7並行複製bug導致的故障 ERROR 1755/1756MySql並行Error
- Error: Debug Failure at typeToStringErrorAI
- GTID複製報錯處理：Last_Error: Error 'Can't drop database 'test';ASTErrorDatabase
- RAID 磁碟故障input/output errorAIError
- Golang 學習——error 錯誤處理淺談GolangError
- 【ERROR】ORA-8103錯誤分析處理Error
- keil error:#8：missing closing quote 處理Error
- ORA-15186: ASMLIB error function = [asm_open], error = [1]ASMErrorFunction
- :-1: error: [Makefile.Debug:1234: debug/moc_serialportthread.cpp] Error 1Errorthread
- OPatch failed with error code 73AIError
- Windows Update error codesWindowsError
- Oracle XA Exception error codeOracleExceptionError
- Error in Memento Sample Code?Error
- [ERROR] Slave I/O: Replication event checksum Error_code: 1743Error
- 【故障處理】csscan工具無法使用，報錯“error while loading shared libraries...”CSSErrorWhile
- DataPump Export (EXPDP) Fails With Error LPX-216 Invalid CharacterExportAIError
- Autoconfig On Db Tier Fails With Error - SP2-1503AIError
- 錯誤處理：如何通過 error、deferred、panic 等處理錯誤？Error
- SQLServer mirror當機後error 9004異常處理SQLServerError
- React Error Boundary 元件異常處理方案實踐ReactError元件