(轉載)一次生產系統 Full GC 問題分析與排查總結

一次生產系統 Full GC 問題分析與排查總結

 

轉載請註明 AIQ - 最專業的機器學習大數據社區  http://www.6aiq.com

AIQ 機器學習大數據 知乎專欄 點擊關注

一次生產系統 Full GC 問題分析與排查總結

背景

最近某線上業務系統生產環境頻頻 CPU 使用率太低，頻繁告警，經過重啓能夠緩解，可是過了一段時間又會繼續預警，線上兩個服務節點相繼出現 CPU 資源緊張，致使服務器卡死不可用，經過告警信息能夠看到如下問題：

從上圖能夠看到，目前 zabbix 監控展現 CPU 空閒時間已經低於預警線，證實目前 CPU 資源佔用太高，考慮到最近並無特別開發任務上線，可是最近有發佈過一個新的營銷活動，有多是由於忽然用戶量增加進一步凸顯該問題。

從 Pinpoint APM 監控工具看到，從 9 月 3 號下午開始，系統開始出現頻繁 full gc 的狀況，而恰好 9 月 3 號下午發佈了一個新活動，基本能夠判定這多是用戶量忽然激增，凸顯潛伏已久的系統問題，因而接下來方向就能夠往 full gc 方向去排查，找出引發 full gc 的代碼。

偵查思路

往 FULL GC 方向偵查，懷疑存在內存泄露

排查路線：

既然上面已經定位到是 FULL GC 問題，咱們就能夠用經常使用 FULL C 的手段去解決。在此次故障分析咱們是利用 MAT 去作分析，主要對如下幾點作排查：

• 程序是否內存泄露

• 程序中是否存在不合理的大對象佔用

• 程序中部分對象產生內存是否能夠優化

導出 JVM dump 文件和 jstack 線程日誌, 保留案發現場

由於公司不容許我的訪問線上服務器，因而讓運維同窗在服務器出現故障時導出 jvm dump 文件和 jstack 線程日誌，若是本身有權限去生產服務器的話，能夠經過如下指令導出 jvm dump 文件

jmap -dump:format=b,file=文件名 [服務進程ID]

結合 MAT 分析工具, 找出可疑對象

使用 MAT 前，先簡單介紹下 MAT 的一些經常使用的指標和功能概念：

• Shallow Heap 指標：對象自己佔用內存的大小，不包含對其餘對象的引用，也就是對象頭加成員變量（不是成員變量的值）的總和

• Retained Heap 指標：是該對象本身的 shallow size，加上從該對象能直接或間接訪問到對象的 shallow size 之和。換句話說，retained size 是該對象被 GC 以後所能回收到內存的總和。

• Histogram 動做：列出每一個類的實例數

• Dominator Tree 動做：列出最大的對象以及它們保存的內容

• Top Consumers 動做: 按照類和包分組打印花費最高的實例

• Duplicate Classes 動做: 檢測由多個類加載器加載的類

• Leak Suspects 報告: 包括泄密嫌疑人和系統概述

• Top Components 報告：列出大於總堆的 1％的組件的報告

經過 Leak Suspects 排查內存泄露

在Ecplise Memory Analyzer導入 JVM dump 文件，點擊工具欄上的 Leak Suspects 菜單項來生成內存泄露分析報告，也能夠直接點擊餅圖下方的 Reports->Leak Suspects連接來生成報告。如圖：

MAT 工具分析了 heap dump 後在界面上很是直觀的展現了一個餅圖，該圖深色區域被懷疑有內存泄漏，能夠發現整個 heap 才 1.5G 內存，深色區域就佔了 57.76%。接下來是一個簡短的描述，MAT 告訴咱們存在兩個可疑問題

• Problem Suspect 1：告訴咱們java.lang.Thread線程實例佔用了大量內存，一共存在5154個實例，而且明確指出system class loader加載的java.lang.Thread實例佔據了643,021,136 (41.03%)字節 ，並建議用關鍵字 "java.lang.Thread" 進行檢查。因此，MAT 經過簡單的兩句話就說明了問題所在，就算使用者沒什麼處理內存問題的經驗。在下面還有一個 "Details" 連接，MAT 給了一個參考類。如圖：

• Problem Suspect 2: 告訴咱們jdk.nashorn.internal.runtime.Context線程實例佔用了大量內存, 而且明確指出sun.misc.Launcher$ExtClassLoader @ 0x9000cf78加載的jdk.nashorn.internal.runtime.Context實例佔據了262,229,320 (16.73%)字節，並建議用關鍵字sun.misc.Launcher$ExtClassLoader @ 0x9000cf78 jdk.nashorn.internal.runtime.Context進行檢查

經過 Top Consumers 定位大對象

點擊 Actions->Top Consumers , 查看大對象有哪些

從上圖能夠看出，java.lang.Thread、jdk.nashorn.*和javax.script.*這些類實例佔據了大部份內存

問題分析

從上面分析報告，可疑大膽推斷如下結論：

• 大量java.lang.Thread實例，明顯不合理是線程使用不合理，懷疑有地方不斷建立線程，沒有使用線程池致使

• 大量jdk.nashorn.internal._和javax.script._相關實例，而jdk.nashorn.*這個包是 Nashorn JavaScript 引擎的包，主要是 nashorn 用於在 JVM 上以原生方式運行動態的 JavaScript 代碼來擴展 Java 的功能，javax.script包用於 javascript 與 java 交互操做。因而能夠基本判定這是跟 javascript 腳本相關操做有關，應該是有地方不斷建立 javascript 腳本相關對象沒有被回收。

結合以上兩點，推測應用程序線程和腳本操做部分出現問題，與該系統相關開發人員溝通，確實該系統是有大量 javascript 腳本操做，是經過 Javascript 腳本作一些特性開發，而後在在 java 調用執行。嘗試使用包名jdk.nashorn查找運維導出的 jstack 線程日誌，看看最接近的業務代碼是什麼

果真看到了線程日誌裏面找到了疑似線程操做的業務代碼，經過查看源碼，一步步查看調用鏈，發現了有個地方會每次實例初始化都會建立一份腳本引擎

這段代碼大概做用是把每一個任務的規則腳本存放在腳本引擎，而後存放在threadLocal裏，每一個MissionEventHandler實例初始化都會建立一個threadLocal用於存放當前線程任務腳本，以防多線程操做同一個MissionEventHandler實例會引發腳本因併發被篡改問題。而通過沿着調用鏈查看源碼瞭解，這些MissionEventHandler實例只會業務人員點擊任務下線的時候纔會進行銷燬處理，那就是隻要任務不下線，這些任務會一直存活在內存中。

可是隻要MissionEventHandler實例數量控制好，應該是不會出現上述大量腳本相關實例引起頻繁 FULL GC 問題，接下來咱們的偵查方向就是查看MissionEventHandler實例建立源頭，** 是否系統存在批量建立該實例的代碼？** 繼續沿着調用鏈查看源代碼，發現了一個異步觀察者類，它是用來通知消息事件的，如下是其中一個方法

這裏是使用了CompletableFuture的supplyAsync(Supplier supplier)方法進行異步處理，再進一步查看supplyAsync的源碼

從上面代碼能夠看到，supplyAsync有 2 個重載方法，當咱們不指定線程池，它默認是調用第一個方法，ForkJoinPool.getCommonPoolParallelism() > 1纔會使用 commonPool 線程池，不然該方法默認會每次建立一條新的線程去處理。那有沒有多是ForkJoinPool.getCommonPoolParallelism()<=1致使每次都建立新的線程呢?咱們進一步查看ForkJoinPool.getCommonPoolParallelism()源碼，發現這方法使用 Java 8 中的ForkJoinPool.commonPool()可使用一個特殊的 ForkJoinPool。該池使用一個取決於可用內核數量的預設並行度。通常狀況下，預設的並行度是CPU 內核數 -1，該系統在生產環境運行的服務器核數爲 2，那就是並行度爲 1，即這裏的ForkJoinPool.getCommonPoolParallelism()=1, 意味着CompletableFuture的supplyAsync方法在這裏處理業務是每次都建立一條新的線程去處理。

總結

根據上面的分析，一切都真相大白，以前看到的大量java.lang.Thread實例就是由於處理業務時，默認每次都會開啓一條新的線程，致使出現大量的線程實例，而這些大量的線程實例又會引起大量的通知消息操做，致使持有的腳本相關實例無法被回收，從而引起了大量jdk.nashorn.internal.*和javax.script.*佔據堆內存。

解決方案

這裏的解決方案很簡單，這裏引起的問題都是由於沒有使用到線程池致使的，能夠採起如下兩種措施:

• 經過在 tomcat 配置 jvm 啓動參數-Djava.util.concurrent.ForkJoinPool.common.parallelism=2, 可讓supplyAsync(Supplier supplier)方法啓動默認的ForkJoinPool.commonPool()去執行

• 改成調用CompletableFuture supplyAsync(Supplier supplier,Executor executor)，給方法指定線程池 (推薦)

在本次改造是使用第二個方案，建立了一個自定義線程池，而後指定線程池去執行操做，修改後代碼以下 (高亮部分)：

上線後觀察監控

上線後經過 PINPOINT 觀察，再也沒出現 FULL GC 問題，以下圖所示：

Java 引用法則說明

從最強到最弱，不一樣的引用（可到達性）級別反映了對象的生命週期。

• Strong Ref(強引用)：一般咱們編寫的代碼都是 Strong Ref，於此對應的是強可達性，只有去掉強可達，對象才被回收。

• Soft Ref(軟引用)：對應軟可達性，只要有足夠的內存，就一直保持對象，直到發現內存吃緊且沒有 Strong Ref 時纔回收對象。通常可用來實現緩存，經過 java.lang.ref.SoftReference 類實現。

• Weak Ref(弱引用)：比 Soft Ref 更弱，當發現不存在 Strong Ref 時，馬上回收對象而沒必要等到內存吃緊的時候。經過 java.lang.ref.WeakReference 和 java.util.WeakHashMap 類實現。

• Phantom Ref(虛引用)：根本不會在內存中保持任何對象，你只能使用 Phantom Ref 自己。通常用於在進入 finalize() 方法後進行特殊的清理過程，經過 java.lang.ref.PhantomReference 實現。