中亦科技黃遠邦技術人生（16） ——紅色警報--Oracle宕機潮來臨，快快行動起來！

1

前言

2月14日，情人節前夕，某數據中心一套Oracle 11.2.0.4 RAC宕了！

隔了幾天，又有一套RAC宕了！

幾天后，緊接著又有一套RAC宕了...

作為運維的你，聽到其他客戶出現這樣的宕機潮時，是不是心底會泛起一陣莫名的恐慌?

那么問題來了，貴司的數據中心到會不會也將出現類似的宕機潮呢？

這些故障是什么原因引起的呢？

這股宕機潮會繼續瘋狂延續下去么…

如果不能及時找到問題真相，那么小y相信，這股宕機潮還會繼續延續下去！

貴中心的Oracle數據庫也許正在越來越接近宕機了！可怕的是，你可能還沒有察覺到…

這絕對不是危言聳聽!

這是在一家超大型數據中心發生的真實故障，在不到兩周的時間里，三套不同Oracle數據庫先后出現了實例異常終止的情況！

無獨有偶，小y服務的其他客戶那也陸續出現了宕機的前兆!好在及時發現并處理。

眼看宕機潮來臨，看小y如何化繁為簡，幫助客戶一起解開問題的真相。

真相揭開后，您也許不難發現，這是一個共性的問題！

因此小y不敢怠慢，趕緊拿出來與大家分享，拉響了這次紅色警報！

十六期，小y將帶領大家一起去經歷一場數據中心Oracle數據庫宕機潮的分析之旅。

文章的最后，提供具體的警報和核查方法，還在猶豫什么呢？趕緊查一查吧！

2

問題來啦

小y,出事了，今天有個系統，早上RAC宕了一個節點，晚上又宕了一個節點，操作系統沒有重啟，只是數據庫實例crash掉了！目前已經開了SR，但現在原因還沒確定，領導很重視這個問題，明天你能過來一趟一起查下么？領導希望明天就能查清問題原因。

對了，這是一套11.2.0.4 RAC,打了最新的PSU的！

接到電話，小y來了精神。

來電的是國內一家超大型的國有銀行，本身就擁有一批水準很高的ORACLE DBA。

通常找到小y的問題，都是些奇奇怪怪的復雜問題，如果只懂數據庫，而對操作系統/中間件/存儲等方面缺乏足夠的了解的話，很多時候是無法解決他們的復雜問題的。

看來，一場硬仗，在所難免...

3

開始分析

先看看數據庫alert日志:

第二天早上，到了客戶現場，首先客戶向我介紹了昨天發生故障的情況：2月12日早上9點左右，11.2.0.4的RAC節點1宕了，晚上22點，節點2 宕了。

客戶幫助登陸到系統后，小y首先檢查了數據庫的alert日志，如下圖所示：

不難看到：

2017/2/128:53:49,由于數據庫的后臺進程ASMB與ASM實例通訊失敗，ASMB進程終止了數據庫實例,因此，小y需要繼續檢查ASM的alert日志，以便查看asm實例是否先出現了問題，才導致數據庫crash了。

緊接著查看ASM alert日志：

不難看到：

在數據庫crash前的幾十秒之前， 8:53:15,ASM實例的rbal后臺進程，遇到了ORA-07445的錯誤，rbal進程core dump,因此pmon進程終止了ASM實例。

也就是說，ASM實例rbal進程出現ORA-7445錯誤，導致ASM實例終止，由于數據庫實例依賴ASM實例，因此數據庫實例被終止。ASM實例具體的ORA-7445錯誤是：

小y剛一開始看到這個錯誤的時候，無奈的搖了搖頭，遇上麻煩了！

為什么小y會有如此感慨呢？資深的DBA，也許看到這個錯誤時，可能會同樣的感慨！

因為這個錯誤出錯的調用lwp_kill是一個太普通不過的調用了，在該函數core Dump的原因可能有一萬種，甚至都不止，metalink上不會記錄所有的可能…..

不過，小y還是很有信心的，只要調整到修正學院派模式，未知問題也可以很快查清。

不錯，只要集中精力分析出這個ORA-7445 [__lwp_kill()+48] [SIGIOT]錯誤的原因，也就解開了宕機潮系列問題的真相。

4

不妙的開始

看到這里，小y和之前看過該問題的幾個工程師做了一下簡單的溝通。

溝通的結果是兩個字，不妙。

之前他們幾個比較資深的工程師已經看過該問題，也在metalink上找過是否有類似的問題，結果顯示，通過call stack匹配，一樣的case有過一些，但case沒有直接的結論，客戶已經開了一個SR到gcs，目前正在分析中..

客戶希望今天出一個大概的結果，時間緊急。

客戶他們了解小y的習慣，再緊急，也會先抽空去抽上一根煙…

小y和客戶打了個招呼后，便下樓抽煙去了。

5

正經的科普一下

趁著抽煙的縫隙，小y縷了一下思路。

也許有些同學對上面的有些術語比較困惑，什么是call stack，什么是ora-600和ora-7445錯誤。小y發現，很多DBA都是人云亦云，這里，小y稍微給大家科普下:

知識點大普及

知識點1：什么是ORA-600錯誤？

有同學會說，ORA-7445錯誤和ORA-600錯誤一樣，屬于ORACLE內部錯誤。依小y來看，這么理解其實并不準確！ORA-600錯誤是內部錯誤，但7445錯誤則不盡然！

ORA-600是ORACLE源碼中捕獲的異常，通常發生在某個特定的函數，相對比較具體，通常是ORACLE BUG。

知識點2：什么是ORA-7445錯誤？

ORA-7445錯誤和ORA-600錯誤就不一樣了。

當 ORACLE進程在運行過程中收到來自操作系統一個嚴重的信號signal，則會報ORA-7445錯誤。操作系統自身會捕獲進程的一些非法的操作，例如當一個進程嘗試往無效的內存位置去寫，出于保護操作系統的目的，操作系統將會向進程發送一個嚴重的信號，常見的例如SIGBUS和SIGSEGV信號，所以會看到進程core Dump現象的出現。

ORA-7445錯誤可以發生在代碼的任意位置，出錯的精確位置需要通過core文件來定位 。

從這段話不難看出，ORA-7445錯誤的可能性較多，本質是操作系統向進程發送一個嚴重的信號，那么原因既可能是數據庫的BUG，也有很大可能是來自操作系統的某些異常。

這也就是ORA-7445錯誤的分析比ORA-600錯誤更難的原因。

知識點3：什么是call stack?

我們在談論bug或缺陷defect的時候，都會有一個疑問，這個BUG的觸發條件是什么呢?

BUG通常都是某一種特殊的場景下觸發的，call stack就是函數的調用軌跡，這個調用軌跡就表示了BUG的具體觸發場景。

這就是小y前面提到的，在小y之前，他們已經通過核對call stack去匹配BUG了。

只不過可惜的是，MOS上出現過相同call stack的case沒有最后下結論，因此無法參考…

6

從call stack開始查找真相

小y接下來打開出現ORA-7445錯誤的rbal進程的trace文件，找到call stack部分,如下所示

首先找到ORA-7445錯誤的第一個中括號出現的函數，即lwp_kill

也就是說rbal進程core dump是在__lwp_kill這個系統調用中發生的。

Lwp就是Light Weight process即輕量級進程，kill就是終止。

細心的同學，可以看到，lwp_kill前面帶了兩個下劃線，說明不是oracle代碼中自己調用的函數，而是函數內部調用的函數，屬于遞歸的函數了。

那么小y是如何知道這些調用是什么意思的呢？

其實很簡單，這些都是來自操作系統的標準調用，度娘或者google一下就好了。

Trace文件中，call stack的調用是從下往上看，下面的函數先執行，上面的函數后執行。這個錯誤太普遍了！是一個廣義的錯誤！很多地方異常，都可能調用lwp_kill來終止進程。因此分析這個函數，沒有什么意義，我們需要繼續往下看，如下圖所示

1) 調起lwp_kill的函數是pthread_kill,這個函數的作用向某個線程傳遞一個信號，也是一個遞歸函數，繼續往下看

2) _raise，向正在執行的程序發送一個信號,raise調起了pthread_kill

3)abort()函數,從名字看就是終止， abort()函數會導致進程的異常終止，除非來自操作系統的進程終止信號即SIGABRT信號被捕捉并且信號處理句柄沒有返回 _assert(),其作用是如果它的條件返回錯誤,則終止程序執行，簡單來說就是程序做某件事情，遇到了錯誤，需要終止程序執行。

到這里，不難看到，函數的調用軌跡是

這段call stack，用大白話來說，就是:

rbal進程在執行過程中遇到了錯誤，因此終止了rbal進程。

那么到底遇到了什么錯誤呢？為什么需要繼續往下看其他call stack

不難看到：

_Assert()是一個遞歸的調用，將其調起來的函數是clsuassertmsg。

這個函數不帶下劃線，是oracle代碼中自己的函數名，顯然在度娘或google就查不到了..

那么不妨就跟著小y來猜一猜吧。

拆開來看，即clsu+assertMsg,也就是遇到了某個錯誤，assert表示遇到了某個錯誤。

再往下看，是clsgpnp_oramemAlloc，不難看出，oramemAlloc就是分配內存，和gpnp相關模塊分配內存有關系。

結合前面的call stack,我們來總結一下:

Rbal進程在執行clsgpnp_oramemAlloc函數來進行分配內存的時候遇到了某個錯誤，因此發生了coreDump,也就是ORA-7445錯誤，繼而導致ASM和數據庫實例先后crash。

7

為什么內存無法分配呢？

到這里，我們實際上已經知道了，oracle在執行到clsgpnp_oramemAlloc這處代碼的時候，出現了錯誤，具體是什么錯誤呢？這個才是關鍵啊！但是，有辦法知道是什么錯誤么？

oracle為我們拋出了一個lwp_kill的ORA-7445錯誤，但是我們真正關心的是clsgpnp_oramemAlloc這個函數到底遇到了什么錯誤！

如果trace里要告訴我們是什么錯誤，那有多好啊！太可惜了!?

很多人也許分析到了這里，就陷入僵局了!

實際上小y只讀了幾分鐘的trace文件，就找到問題的真相了。

大家不防也可以停下來思考下一兩分鐘，如果是你，你會怎么往下查…

---------------------

思考時間....別著急往下翻哦..

-------------------------

8

慢慢接近真相

小y的方法很簡單，用正常人的思維/生活化的語言來分析就可以。

表面上，出現core dump時的調用是lwp_kill,但真正出現問題的oracle函數是clsgpnp_oramemAlloc。顯然，我們需要知道這個函數去分配內存的時候到底報了什么錯誤！！記住，需要證據，而不是猜！

有人會說，我們在trace中以clsgpnp_oramemAlloc關鍵字查找不就可以了么…

可惜的是，那你也許這么查找，最終會發現一無所獲…

是你錯了么？

不是的！是你方法不對！

小y采用的方法是將clsgpnp_oramemAlloc關鍵字截取前半截（一會您就知道為什么了），

這里查找clsgpnp_oram關鍵字，結果如下

可以看到：

真正出現問題的oracle函數是clsgpnp_oramemAlloc,

這個函數去分配內存的時候報了無法分配120K內存的錯誤！failed to allocate 120024 bytes.

看到這張圖，大家理解為什么需要截斷真正錯誤的函數名來作為查找的關鍵字了吧！

因為函數名字換行了，如果以整個函數作為關鍵字，則可能查找不到！

這算是小y為大家貢獻的一點小技巧和經驗提示吧。

這里，也許也有人說：

為什么不能直接猜clsgpnp_oramemAlloc這個函數去分配內存的時候報的錯誤呢？

最可能的不就是無法分配內存么？確實如此，但也不僅如此。

因為分配內存出錯，可能性太多了，絕不是你想象的無法分配內存的那幾種可能！

還記得小y以前文章中曾經提到過的修正學院派模式么？

如果采用猜的方法，結果是無法說服客戶和自己，無法形成完整的證據鏈，是“野路子”的典型表現之一。小y這些年面試過不少人，結果不理想，絕大部分人其實都是野路子，野路子的解決問題，典型的就是在解決問題時東一榔頭，西一棒子，靠運氣。而不是學院派的步步為營。面對復雜問題時，野路子就會抓襟見肘了。

9

真相浮出水面

Oracle的函數clsgpnp_oramemAlloc,去分配內存的時候報了無法分配120K內存的錯誤！failedto allocate 120024 bytes.

到這里，相信大家一定躍躍欲試了！想試試自己的身手，畢竟看到了這個錯誤后，問題被進一步縮小范圍了！

1） 是不是機器內存不足導致clsgpnp_oramemAlloc函數無法分配內存？

答案是NO，首先從監控數據/oswatcher中可以看到，機器內存還很富余。

       2）是不是操作系統ulimit內存方面設置的比較小呢？

       答案是NO，ulimit配置正常

難道我們方向錯了？

有時候，看上去，我們快接近了事情的真相，但又可能與真相插肩而過？為什么呢

在這里，小y賣個關子，答案就在下方的空白后，讀者可自行選擇什么時候往下翻…

小y說過，如果只懂數據庫，而對操作系統/中間件/存儲等方面缺乏足夠的了解的話，很多時候是無法解決大型數據中心那些復雜問題的。

查看宕機前的RBAL進程的內存消耗，如下圖所示

這是一個HPUX 11.31 ia64的操作系統(實際上該問題與操作系統無關)，

我們調出glance的歷史，不難看到，Res Mem達到了4209480K，即4G左右。

聽到4G這個詞，是不是想到了些什么呢？沒錯，像是一個限制！

從上圖可以看到，操作系統的maxdsize_64bit參數設置的正是4G，即單個進程的data最大只能到4G！

為什么RBAL進程內存用那么多內存？

顯然，RBAL進程存在內存泄露的情況。正常而言，rbal進程的內存在100M以上。

我們通過檢查歷史數據，確認了rbal進程存在內存該情況！

是什么觸發rbal進程內存泄露呢？

通過分析和比對，發現該庫數據庫有一個和其他數據庫不一樣的地方：

ASMalert日志中頻繁的發生voting File relocation的情況，如下所示。

最終，在解決了voting File relocation的情況后，rbal進程的內存不再繼續增加，問題得到了根本解決。之后，客戶自己也申請到了一個patch.。

10

宕機潮事件還原

通過閱讀ORA-7445的call stack,小y化繁為簡，還原了事件的發生過程。

1、為什么ASM rbal進程出現 ORA-7445[lwp_kill]錯誤后進程core Dump?

因此ASM實例 rbal后臺進程存在內存泄露，當內存泄露到OS對單個進程的限制之后，進程無法分配內存而crash，繼而先后導致asm實例和數據庫實例crash

2、為什么會導致宕機潮

因為rbal進程內存泄露的速度差不多,在一個維護日中啟動的多套數據庫，經過小一年的時間后，也就差不多同時到了OS對單個進程的限制,因此先后發生了“宕機潮”

事實上，在第一套出現宕機的時候，小y已經協助客戶查明了ASM rbal進程內存泄露的問題，只是沒來得及全面梳理和整改所有系統，在此期間又先后發生了另外兩套RAC的宕機。

3、一定會出現宕機么？

不一定，如果操作系統對單個系統的使用沒有上限，則不會出現宕機，但會出現rbal進程將整個系統內存耗盡的情況，如果不及時監控，可能導致性能和無法telnet/ssh的情況。

簡而言之，同一個問題，但在不同的OS配置下會表現出不同的故障現象！

4、rbal進程core dump一定是出現在clsgpnp_oramemAlloc整個函數么？

顯然，如果內存泄露到了OS單個進程的限制，無論哪個需要分配內存的函數，都可能遇到無法分配內存繼而coreDump的情況！因此，答案是不一定。這就是一個故障，可能有多個不同故障現象，但本質都是一回事！

5、rbal進程內存泄露只發生在HPUX么？

NO！我們不僅在HPUX上發現了該問題，其他客戶的AIX環境下，RBAL進程的內存已經使用了8G，并且還在持續上升。這個問題不區分平臺，目前確認受到影響的版本是11.2.0.4!其他版本我們還在陸續確認。

11

紅色警報響起！

詳細原因見上文“宕機潮事件還原”章節的分析

1、小y在這里代表中亦科技向大家鄭重提示一個較大的風險：

Oracle 11.2.0.4版本的RAC，ASM的rbal后臺進程存在內存泄露的情況，將可能導致宕機潮，目前已經有多個客戶出現該情況，影響了包括HPUX/AIX/LINUX等在內的操作系統。

2、建議

建議按照下列方法全面梳理是否存在該情況，并增加進程一級內存使用情況的監控。

3、解決問題的方法：

如果檢查有類似問題，欲了解問題的解決方法，

可以添加小y的微信，shadow-huang-bj

注明：加入中亦科技Oracle微信群

小y將在后續分享中第一時間在微信群以及”中亦安圖”公眾號中揭曉