如何解決生產環境宕機問題

寫在前面：該篇宕機問題的排查難度遠比上一篇（記一次解決線上OOM的心路歷程）大的太多，上一篇中內存泄漏的問題是有跡可循的，本次的宕機在業務日誌上沒有任何徵兆，另外本文有許多值得深挖的點，但願讀者能找到本身感興趣的點進行深挖，並將心得體會留言在評論區，讓你們共同進步。

 

現象：zabbix告警生產環境應用shutdown，經過堡壘機登入生產環境，查看應用容器進程，並發現沒有該業務應用的相應進程，第一感受進程在某些條件下被系統殺死了，而後查看容器日誌，發現均沒異常可尋。

 

問題：

 

一、爲什麼會沒有應用進程及異常的日誌輸出？若是真的是系統殺死了應用進程，是什麼條件觸發了它？

 

二、測試環境、UAT環境爲什麼從未有這樣的狀況，差異在哪？

 

排查： 

 

首先去查看生產環境系統資源狀況及相應容器的配置，查得該臺生產機器的總內存是8G：

 

接着查看該應用所在容器環境的變量設置：

此處能夠看到這裏爲java設置的最大內存爲4G，接着咱們又查看了部署在本臺機器上的另外一個應用環境的設置，結果和該應用同樣，設置的內存大小爲4G。

 

咱們繼續查看了該機器上的其餘java應用，發現另外還部署了一個本地queue（activitymq），且設置的最大佔用內存爲1G,此時彷佛已經能夠猜想。

 

因爲機器的總內存不夠，當應用在申請新的內存時，因爲環境變量設置的緣故並無去觸發GC，而是直接申請內存，系統方發現總內存已經不夠用，因而直接將該應用進程殺死。

爲了驗證上面的說法，咱們查找系統的相關日誌：

清晰地看到：Feb 23 00:01:09 us-app01 kernel: Out of memory: Kill process 14157 (java) score 619 or sacrifice child，此處說明的確是系統殺死了應用進程。

 

根據這裏的系統日誌查詢資料得知，系統會爲每一塊新分配的內存添加跟蹤記錄至low memory，當low memory的內存耗盡同時有須要新分配內存時，內核便會觸發Kill process，此處爲何系統選擇了kill該應用進程，個人猜測是一該應用進程屬於用戶進程，它的結束並不會影響系統的正常運行，二是因爲該應用最大可用內存設置的不合理性，須要新分配內存來存儲對象就發生在其中。

       因爲當時的進程已經被系統殺死，咱們沒法得知當時具體內存的使用及分配狀況，做爲參考依據咱們選擇查看相同環境下的另外一臺機器的內存狀況：

此處能夠看出系統的總內存爲7967m，low memory的總內存也爲7967,（64位的系統，系統總內存與low memory相同），當前low memory已經使用7832（low memory = used + buff/cache）。

 

種種跡象代表：因爲該應用及部署在同一臺機器上的另外一個應用，其環境中最大可用內存設置的不合理（系統總內存8G，這兩個應用的最大可用內存設置爲4G，同時機器上還有一個本地queue）性，致使其內部在申請內存時因爲系統的low memory被耗盡，觸使系統殺死了該應用進程。

臨時解決：

 

• 減小應用環境中的設置的最大可用內存，重啓應用。

繼續解決：

• 應用重啓後的一段時間（幾天後），咱們查看應用使用的內存狀況：

咱們想到該應用知足的業務量很小並無那種數據量特別大的場景，爲什麼系統會使用掉這麼多的內存呢，因而咱們決定對該應用從代碼角度上進行一些可行的調優。

 

首先使用jmp dump出內存快照，並導入jprofiler，藉助jprofiler進行分析：

從上圖咱們能夠看到char[]佔用了651m的內存，String佔用的是10m左右，顯然這裏對char類型的使用或者處理是有問題的，咱們進一步查看究竟是什麼地方使用了char[]，又有哪些大的char[]實例，以及其中都存了怎樣的數據：

 

這裏咱們看到有將近20個char[]實例的大小都超過了10m，其中最大的已然有30m，咱們再查看這裏都存了哪些數據：

此處能夠看到其中有一些業務數據的記錄，另外其內存數據中還有部分公司內部任務中心的一些任務信息（此處就不截圖出來了），因而咱們隱隱感受到是否是任務平臺作了什麼事情，好比收集日誌什麼的，咱們繼續查看其引用狀況：

看到此處的rabbit基本能夠判定了就是任務中心client的引用，項目中其餘地方並無用到rabbit，因而咱們找到任務中心的維護人員進行詢問，他們的答案是不會去收集應用的日誌的（咱們內心的答案也是這，又不是日誌平臺的client，任務中心團隊不會作這麼傻的事）。

 

然而咱們在char[]中的確看到的都是任務平臺的信息這是怎麼回事？因而咱們查看任務平臺客戶端的源碼及對外的api，看看能有什麼線索，最終鎖定了一個問題，任務平臺客戶端使用了線程池，而且默認的線程池中線程最多爲100（這個是有些坑，簡單說明，任務中心是經過queue實現的，服務端發送任務消息，client收到後消費）。

 

咱們再看到截圖中的線程，隱隱也是任務中心client的線程池中的線程，因而咱們進一步查找到底哪裏纔會使用char[]，而且會有業務數據，查看全局代碼後咱們發現對於應用中任務消息的處理器並無直接使用char[]，組內一位同窗提醒是否是使用log4j打日誌處理不當的緣由，想想就目前現狀而言，這種說法說的通，因而咱們在每個任務處理器中查看日誌上有沒有大對象的輸出，果真找到了一些（訂單、庫存等....）。

private List<AmazonOrderInfo> getAmazonOrderNotInLocal(CustomerSalesChannelVO channel) {

        List<AmazonOrderInfo> amazonOrderInfoList = new ArrayList<>();

        try {

            Date nowTime = new Date();

            Date toTime = new Date(nowTime.getTime() - 121000);

            Date fromTime = new Date(nowTime.getTime() - 720000);

            amazonOrderInfoList = amazonOrderService.getAmazonOrderInfoNotInLocal(channel, fromTime, toTime);

            BizLogger.info("get amazon new order when amazon inventory feedback, result ： " + amazonOrderInfoList);

        } catch (Exception e) {

            BizLogger.syserror("getAmazonOrderNotInLocal error,", e);

        }

        return amazonOrderInfoList;

    }

 

    //獲取本地amazon建立失敗的平臺訂單暫用的庫存量

    private List<AmazonOrderItemVO> getAmazonErrorOrderInLocal(String customerCode) {

        AmazonOrderSO so = new AmazonOrderSO();

        so.setCustomerCode(customerCode);

        so.setStatus(AmazonOrderStatus.ERROR);

        List<AmazonOrderItemVO> amazonOrderItemVOList = amazonOrderService.getAmazonOrderItemVOList(so);

        BizLogger.info("get amazon error order item in local when amazon inventory feedback, result : " + amazonOrderItemVOList);

        return amazonOrderService.getAmazonOrderItemVOList(so);

    }

因而咱們查閱相關資料瞭解到log4j會將當前線程中被打印的最長記錄的大小進行緩存，至此該問題已經說得通了。

 

因爲任務中心的客戶端啓用了默認最大線程數爲100的線程池，這些線程用來消費服務端發送過來的任務消息，該業務應用中配置不少關於庫存、訂單的相應任務，在這些具體任務消息的處理器中存在必定的大對象日誌輸出。因爲線程是用線程池維護，每次執行完並不會被銷燬掉，所以會存在大量的緩存區域。

 

這樣也就能回答咱們最初設想的第二個問題：測試環境、UAT環境爲什麼從未有這樣的狀況，差異在哪？差異有四個地方：

 

• 系統環境的內存大小及虛機版本。

• 訂單數據或是庫存數據量的差別。

• 測試環境和UAT環境咱們並不會配置不少的job，更多的是測試完就結束。

• 應用重啓的頻率不一樣，測試環境較爲頻繁。

 

最終處理方案：

 

（1）將任務中心客戶端消費任務消息的線程池的最大線程數按照應用的實際狀況改成10。

（2）去除對大對象的日誌輸出。

 

同時將任務中心客戶端對於默認線程池的最大線程數設置的不合理性進行反饋，避免一樣的事情發生在其餘項目組。

 

總結：

 

一、當low memory被耗盡時，系統會kill掉不會影響自身穩定運行的用戶進程。

二、應用上線程池的最大線程數的設置須要根據機器環境及應用自己進行合理設置，尤爲要注意依賴消息實現的三方工具包中的線程次設置，避免被其引用的對象使用過量的緩存等。

三、在組內會議中明確，任務處理器中不容許有大對象的日誌輸出。