【故障處理】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/，如需轉載，請註明出處，否則將追究法律責任。
相關文章
- 【ERROR】OPatch failed with error code 73ErrorAI
- error的處理方式Error
- Oracle OER 7451 in Load Indicator : Error Code = OSD-04500的問題處理OracleIndicatorError
- 15-錯誤處理（Error）Error
- DataPump Export (EXPDP) Fails With Error LPX-216 Invalid CharacterExportAIError
- OPatch failed with error code 73AIError
- Error Domain=kAFAssistantErrorDomain Code=7ErrorAI
- keil error:#8：missing closing quote 處理Error
- [Code Composer Studio] fatal error #6001Error
- [譯] Part 30: Golang 中的Error處理GolangError
- 【ERROR】ORA-8103錯誤分析處理Error
- GTID複製報錯處理：Last_Error: Error 'Can't drop database 'test';ASTErrorDatabase
- 執行flutter run命令報錯：:ERROR: Could not connect to lockdownd, error code -17FlutterError
- Oracle 19C RAC 安裝 Error 4 opening dom ASM/Self in 0x5984500 報錯處理OracleErrorASM
- Golang 學習——error 錯誤處理淺談GolangError
- 【Linux】curl: (35) SSL connect error問題處理LinuxError
- 錯誤處理：如何通過 error、deferred、panic 等處理錯誤？Error
- ORA-00600: internal error code, arguments: [13011]Error
- weblogic報錯： OPatch failed with error code 73WebAIError
- 解決docker: Error response from daemon故障DockerError
- React Error Boundary 元件異常處理方案實踐ReactError元件
- Camunda 流程執行錯誤處理ERROR BOUNDARY EVENTError
- SQLServer mirror當機後error 9004異常處理SQLServerError
- The API server is burning too much error budget 異常處理APIServerError
- 莫名其妙的BUG——Compilation errorError
- BUG:ORA-00600: internal error code, arguments: [kmgs_pre_process_request_6], [6], [2873], [2560], [3Error
- 解決方案 | MiKTex SSL connect error code 35Error
- Sub-process /usr/bin/dpkg returned an error codeError
- MySQL 5.6複製報錯Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND;MySqlError
- ORA-03137: TTC protocol internal error: [12333]分析及處理ProtocolError
- 【故障處理】ORA-600:[13013],[5001]故障處理
- ORA-00600: internal error code, arguments: [2131], [9], [8]Error
- Error - RtlWerpReportException failed with status code :-1073741823. Will try to launch the processErrorExceptionAI
- ORA-00600: internal error code, arguments: [qosdExpStatRead: expcnt mismatch], [Error
- 記一次報錯 symlink(): Protocol error 問題處理ProtocolError
- returned a non-zero code: 139
- Rocky9安裝python3.6報錯 make: *** [Makefile:1102: install] Error 139PythonError
- linux故障處理Linux
- 案例ORA-00600: internal error code, arguments: [qkaffsindex3], [], [], [], []ErrorIndex