Java應用異常狀態監測

阿里巴巴中間件技術專欄

 

老闆最近分派了一個任務，說線上客戶在部署應用的時候發生了系統級別的OOM，觸發了OOM Killer殺掉了應用，讓咱們解決這個問題。

對於這個任務，我從以下幾點開始調研、分析與解決。

一、什麼是系統級別的OOM（Out-Of-Memory）？

當建立進程時，進程都會創建起本身的虛擬地址空間（對於32位系統來講爲4g）。這些虛擬地址空間並不等同於物理內存，只有進程訪問這些地址空間時，操做系統纔會爲其分配物理內存並創建映射。關於虛擬內存和物理內存有不少資料，這裏再也不贅述，這篇文章寫的通俗易懂，能夠看下。

經過虛擬內存技術，操做系統能夠容許多個進程同時運行，即使它們的虛擬內存加起來遠超過系統的物理內存（和swap空間）。若是這些進程不斷訪問其虛擬地址，操做系統不得不爲它們分配物理內存，當到達一個臨界點時，操做系統耗盡了全部的物理內存和swap空間，此時OOM就發生了。

二、系統發生了OOM會怎麼樣？

當發生了OOM，操做系統有兩個選擇：1）重啓系統；2）根據策略殺死特定的進程而且釋放其內存空間。這兩種策略固然是第二種影響面較小，因爲咱們線上系統也是採起殺死特定進程的策略，所以這裏只展開第二種。

第二種行爲也稱之爲OOM Killer。那系統會殺死什麼樣的進程釋放其內存呢？這篇文檔的「Selecting a Process」部分大概描述了Linux內核的操做系統選取算法：首先，根據badness_for_task = total_vm_for_task / (sqrt(cpu_time_in_seconds) * sqrt(sqrt(cpu_time_in_minutes)))來算起始值，total_vm_for_task爲進程佔用的實際內存，cpu_time_in_seconds爲運行時間，這個公式會選取佔用內存多且運行時間短的進程；

若是進程是root進程或者擁有超級用戶權限，那麼上述得分會除以4；
若是進程可以直接訪問硬件（也就是硬件驅動），那麼將得分再除以4。
但文檔中描述並不完整，這個是Linux內核OOM_Killer的相關代碼，而後這篇文章對代碼進行了分析，除了上述因素以外還包含子進程內存、nice值、omkill_adj等因素。

操做系統會對每一個進程進行計算得分，並記錄在/proc/[pid]/oom_score文件中；當發生系統OOM時，操做系統會選取評分最高的進程進行殺死。

三、如何實現系統OOM告警？

OOM告警有兩種方式，以下：

提早OOM告警：在系統即將發生OOM時，發出告警信息。
事中/過後告警：在系統完成OOM Killer殺死進程後，發出告警信息。
提早OOM告警是最好的方式，但實際上若是想達到不誤報、不漏報，實現難度極大。咱們線上應用爲Java應用，考慮這麼個場景：客戶應用不斷申請內存，當系統物理內存佔用率達到90%的時候，系統及應用下一步行爲會是什麼樣？我的認爲有三種可能性：1）Java應用中止申請內存，而且進行了垃圾回收釋放內存，這樣系統將會恢復正常；2）應用繼續申請內存致使應用內存超過了堆大小，但此時系統仍然有部分物理內存，這樣會發生Java應用的OOM；3）應用繼續申請內存致使系統耗盡物理內存，但此時沒有超過堆內存的最大值，這樣會發生操做系統的OOM。對於這個場景來講，咱們想準確預判出系統及應用的下一步行爲難度極大。

另外一方面，咱們線上其實已經有基於機器內存使用率的報警，這個報警其實已經包含了三種可能性：1）應用自己有問題但不會致使堆溢出或者系統OOM；2）應用可能會致使堆溢出；3）應用可能會致使系統OOM。不管實際狀況爲哪種，這個報警都是有意義的。

事中/過後告警也是一種可取的方式，緣由在於：1）這種方式可以實現不誤報、不漏報；2）對於即將發生OOM的應用來講，事中報警與事前報警時間相差其實並不大。另外，到目前爲止客訴的狀況都是抱怨其應用死了沒有任何通知，排查起來既浪費了客戶時間，也浪費了研發排查問題的時間。

綜合考慮，若是可以實現Java應用的異常狀態檢測並提供事中/過後報警與現場分析，也是頗有意義的！

四、Java應用的異常狀態爲哪些？

這裏定義的Java應用異常狀態有：

Java應用被用戶殺死（Kill、Kill -9）；
Java應用發生堆溢出；
Java應用被系統OOM（Kill -9）。

五、如何檢測出上述Java應用異常狀態？

首先，Java應用發生堆溢出能夠經過-XX:+HeapDumpOnOutOfMemoryError參數來生成dump信息，咱們能夠經過輪詢方式便可發現是否發生堆溢出（固然基於事件通知方式更好，待調研）。

所以，如今問題在於咱們怎麼發現一個Java應用被用戶殺死或者被系統OOM Kill掉？

5.1 ShutdownHook/sun.misc.Signal

老司機可能很快就想到，經過註冊shutdownHook就能夠檢測到系統信號了呀！註冊shutdownHook的確能檢測到SIGTERM信號（也就是一般不帶參數的Kill命令，如Kill pid），但不能檢測到SIGKILL信號（Kill -9）。另外，調研發現也能夠經過sun.misc.Signal.handle方法來檢測系統信號，但遺憾的是仍是不能檢測到SIGKILL信號。

5.2 strace

這個工具很是強大，它可以攔截全部的系統調用（包括SIGKILL），而且具備系統已經內置、使用方便、輸出信息可讀性好等優勢。下圖是個人一個實驗（進程24063是一個觸發系統OOM的Java進程）：

1

但這個工具的缺點是，被跟蹤的應用的性能影響很是大。應用原來進行系統調用（好比open、read、write、close）時會發生一次上下文切換（從用戶態到內核態），使用了strace以後會變成屢次上下文調用，以下圖所示：
2
（更多信息能夠參考這篇文章）

但不管如何，咱們已經找到一種可行的解決方案，雖然性能影響很大，但能夠做爲debug方案開放給客戶。

5.3 ftrace + 系統日誌

ftrace是Linux系統已經內置的工具（debugfs掛載狀況見附錄），它的做用是幫助開發人員瞭解 Linux 內核的運行時行爲，以便進行故障調試或性能分析。重要的是，它對應用自己的性能影響極小，並且咱們能夠只檢測Kill事件，這樣對客戶應用幾乎零影響（性能分析見第6節）。在咱們的場景下，它也支持內核事件（包括進程SIGKILL信號）監聽。ftrace使用起來很是方便，能夠參考這篇文檔，或者直接使用這個GITHUB腳本便可。下面是運行該GITHUB腳本的一個截圖：

3

在上圖中，SIGNAL爲15的是我執行Kill 29265命令，SIGNAL爲9的是我執行Kill -9 29428命令。但這個工具的問題在於，當Java進程觸發系統級別的OOM Killer時，並無檢測到相應的信號（待進一步調研）。

另外，當系統觸發OOM Killer時，會在系統日誌（Centos的爲/var/log/messages）中記錄下特定信息，以下所示：

4

5.4 auditd + 系統日誌

（系統日誌用來發現OOM信息，再也不贅述，下文主要介紹auditd）

同事建議能夠嘗試下auditd，所以這裏調研auditd，發現它能知足需求，並且測試性能影響比ftrace更小（性能分析見第6節）。auditd是Linux Auditing System（Linux審計系統）的一部分，它負責接收內核中發生的事件（系統調用、文件訪問），並將這些事件寫入日誌供用戶分析。

下圖是Linux審計系統的框架：

5

其中：

左邊是咱們的應用程序；

中間爲Linux內核，內核中包含了審計模塊，能夠記錄三類事件：1）User：記錄用戶產生的事件；2）Task：記錄任務類型（如fork子進程）事件；3）Exit：在系統調用結束時記錄該事件。同時，能夠結合Exclude規則來過濾事件，最終將這些事件發送到用戶空間的auditd守護進程；

右邊是在用戶空間的應用程序，其中auditd是核心的守護進程，主要接收內核中產生的事件，並記錄到audit.log中，而後咱們能夠經過ausearch或者aureport來查看這些日誌；auditd在啓動時會讀取auditd.conf文件來配置守護進程的各類行爲（如日誌文件存放位置），並讀取audit.rules中的事件規則來控制內核中的事件監聽及過濾行爲；另外，咱們也能夠經過auditctl來控制內核事件監聽和過濾規則。 

關於更多信息能夠自行搜索或者看下這篇文章。

內核已經內置審計模塊，而auditd守護進程也默認在centos（>=6.8）中啓動，下面咱們來測試下該工具。首先，咱們執行以下命令：

auditctl -a always,exit -F arch=b64 -S kill -k test_kill

這條命令做用是，在kill系統調用返回時記錄事件，而且綁定test_kill標記（以便後面進行日誌篩選）。而後，咱們能夠隨便執行一個腳本並kill掉，能夠在/var/log/audit/audit.log中看到以下輸出：

6

第一條SYSCALL日誌記錄發送SIGKILL信號的進程信息，第二條OBJ_PID日誌記錄接收SIGKILL信號的進程信息。

5.5 Shell + dmesg

若是咱們可以控制Java應用的啓動腳本，那麼此方式是影響最小的方案。先看下面這個shell腳本：

7

這個腳本作了這幾個事情：

使用Java -Xms4g -Xmx4g Main來啓動一個Java應用；

Java應用退出後經過$?獲取程序退出狀態碼；

若是退出碼大於128，則爲應用收到SIGNAL退出；若是爲SIGKILL，則經過dmesg收集kernal ring buffer中的信息。

若是應用因爲被OOM Killer殺死而退出，則dmesg-kill.log中會有以下信息：

8

此方案優勢在於影響面最小，但進程殺死信息量相比auditd少，只知道收到何種SIGNAL信號；而auditd可以知道SIGNAL信號來源於哪一個進程、用戶、組。 

六、性能測試

6.1 測試環境

1

6.2 測試腳本

6.2.1 測試一：系統調用性能影響

測試方法

從/dev/zero中讀取500個字節數據並寫入到/dev/null中，循環執行1億次（也就是100M）：

dd if=/dev/zero of=/dev/null bs=500 count=100M

該腳本會產生大約2億次系統調用（read 1億次，write 1億次）。

測試結果

2

6.2.2 測試二：JAVA應用性能影響

測試方法：

構造consumer和provider應用，consumer向provider發起HSF調用，provider返回預約義數據，循環調用1百萬次，觀察consumer耗時。

測試結果：

4

七、總結

綜上，咱們能夠經過以下手段來解決客戶的應用OOM問題：

1. 使用機器的基於內存使用率報警來事前通知客戶；

2. JVM啓動參數能夠添加-XX:+HeapDumpOnOutOfMemoryError等參數來協助收集JVM內存溢出信息；

3. 經過系統日誌（/var/log/messages）或者dmesg來收集系統OOM Killer信息；

4. 使用啓動shell腳本（見5.5節）或auditd（見5.4節） ftrace 來獲取應用被Kill掉的信息（可能被客戶自身Kill掉）。

5. 【可選】開放strace工具來幫助客戶debug問題。

八、其餘工具

8.1 trap

trap命令用於指定在接收到信號後將要採起的動做，一般在腳本程序被中斷時完成清理工做。當shell接收到sigspec指定的信號時，arg參數（命令）將會被讀取，並被執行。下面我試圖攔截當前腳本的SIGTERM和SIGKILL信號：

6

測試發現，trap命令可以檢測到當前進程的SIGTERM信號，可是沒法檢測SIGKILL信號。這個命令至關於Java應用中的shutdownHook或者Signal。

九、附錄

9.1 ftrace系統debugfs掛載狀況

（注：如下統計阿里雲上主要的操做系統）

7
8