線上FullGC問題排查實踐——手把手教你排查線上問題

作者：京東科技 南韓凱

一、問題發現與排查

1.1 找到問題原因

問題起因是我們收到了jdos的容器CPU告警，CPU使用率已經達到104%

觀察該機器日誌發現，此時有很多線程在執行跑批任務。正常來說，跑批任務是低CPU高記憶體型，所以此時考慮是FullGC引起的大量CPU占用（之前有類似情況，告知用戶後重啟應用後解決問題）。

通過泰山查看該機器記憶體使用情況：

可以看到CPU確實使用率偏高，但是記憶體使用率並不高，只有62%，屬於正常範圍內。

到這裡其實就有點迷惑了，按道理來說此時記憶體應該已經打滿才對。

後面根據其他指標，例如流量的突然進入也懷疑過是jsf介面被突然大量調用導致的cpu占滿，所以記憶體使用率不高，不過後面都慢慢排除了。其實在這裡就有點一籌莫展了，現象與猜測不符，只有CPU增長而沒有記憶體增長，那麼什麼原因會導致單方面CPU增長？然後又朝這個方向排查了半天也都被否定了。

後面突然意識到，會不會是監控有“問題”？

換句話說應該是我們看到的監控有問題，這裡的監控是機器的監控，而不是JVM的監控！

JVM的使用的CPU是在機器上能體現出來的，而JVM的堆記憶體高額使用之後在機器上體現的並不是很明顯。

遂去sgm查看對應節點的jvm相關情況：

可以看到我們的堆記憶體老年代確實有過被打滿然後又清理後的情況，查看此時的CPU使用情況也可以與GC時間對應上。

那麼此時可以確定，是Full GC引起的問題。

1.2 找到FULL GC的原因

我們首先dump出了gc前後的堆記憶體快照，

然後使用JPofiler進行記憶體分析。（JProfiler是一款堆記憶體分析工具，可以直接連接線上jvm實時查看相關信息，也可以分析dump出來的堆記憶體快照，對某一時刻的堆記憶體情況進行分析）

首先將我們dump出來的文件解壓，修改尾碼名.bin，然後打開即可。（我們使用行雲上自帶的dump小工具，也可以自己去機器上通過命令手工dump文件）

首先選擇Biggest Objects，查看當時堆記憶體中最大的幾個對象。

從圖中可以看出，四個List對象就占據了近900MB的記憶體，而我們剛剛看到堆記憶體最大也只有1.3GB，因此再加上其他的對象，很容易就會把老年代占滿引發full gc的問題。

選擇其中一個最大的對象作為我們要查看的對象

這個時候我們已經可以定位到對應的大記憶體對象對應的位置：

其實至此我們已經能夠大概定位出問題所在，如果還是不確定的話，可以查看具體的對象信息，方法如下：

可以看到我們的大List對象，其實內部是很多個Map對象，而每個Map對象中又有很多鍵值對。

在這裡也可以看到Map中的相關屬性信息。

也可以在以下界面直接看到相關信息：

然後一路點下去就可以看到對應的屬性。

至此，我們理論上已經找到了大對象在代碼中的位置。

二、問題解決

2.1 找到大對象在代碼中的位置與問題的根本原因

首先我們根據上述過程找到對應位置與邏輯

我們的項目中大概邏輯是這樣的：

1. 首先會解析用戶上傳的Excel樣本，並將其載入到記憶體中作為一個List變數，即我們上述看到的變數。一個20w的樣本，此時欄位數量有a個，大概占用空間100mb左右。
2. 然後遍歷迴圈用戶樣本，根據用戶樣本中的數據，再增加一些額外的請求數據，根據此數據請求相關結果。此時欄位數量有a+n個，占用空間已經在200mb左右。
3. 迴圈完成後將此200mb的數據存入緩存。
4. 開始生成excel，將200mb數據從緩存中取出，並根據之前記錄的a個欄位，取出初始的樣本欄位填充至excel。

用流程圖表示為：

結合一些具體排查問題的圖片：

其中一個現象是每次gc後的最小記憶體正在逐步變大，對應上述步驟中第二步，記憶體正在逐步膨脹。

結論：

將用戶上傳的excel樣本載入到記憶體中，並將其作為一個List<Map<String, String>>的結構存儲起來，首先一個20mb的excel文件以此方式存儲會膨脹占用120mb左右堆記憶體，此步驟會大量占用堆記憶體，並且因為任務邏輯原因，該大對象記憶體會在jvm中存在長達4-12小時之久，導致一但任務過多，jvm堆記憶體很容易被打滿。

這裡列舉了為什麼使用HashMap會導致記憶體膨脹，其主要原因是存儲空間效率比較低：

一個Long對象占記憶體計算：在HashMap<Long，Long>結構中，只有Key和Value所存放的兩個長整型數據是有效數據，共16位元組（2×8位元組）。這兩個長整型數據包裝成java.lang.Long對象之後，就分別具有8位元組的MarkWord、8位元組的Klass指針，再加8位元組存儲數據的long值（一個包裝對象占24位元組）。

然後這2個Long對象組成Map.Entry之後，又多了16位元組的對象頭（8位元組MarkWord+8位元組Klass指針=16位元組），然後一個8位元組的next欄位和4位元組的int型的hash欄位（8位元組next指針+4位元組hash欄位+4位元組填充=16位元組），為了對齊，還必須添加4位元組的空白填充，最後還有HashMap中對這個Entry的8位元組的引用，這樣增加兩個長整型數字，實際耗費的記憶體為(Long(24byte)×2)+Entry(32byte)+HashMapRef(8byte)=88byte，空間效率為有效數據除以全部記憶體空間，即16位元組/88位元組=18%。

——《深入理解Java虛擬機》5.2.6

以下是剛上傳的excel中dump出的堆記憶體對象，其占用的記憶體達到了128mb，而上傳的excel實際只有17.11mb。

空間效率17.1mb/128mb≈13.4%

2.2 如何解決此問題

暫且不討論上述流程是否合理，解決辦法一般可以分為兩類，一類是治本，即不把該對象放入jvm記憶體中，轉而存入緩存中，不在記憶體中則大對象問題自然迎刃而解。另一類是治標，即縮小該大記憶體對象，在日常使用場景下使其一般不會觸發頻繁的full gc問題。

兩種方式各有優劣：

2.2.1 激進治療：不把他存入記憶體

解決邏輯也很簡單，例如在載入數據時，將其按照樣本載入數據一條一條存入redis緩存，然後我們只需要知道樣本中有多少的數量，按照數量的先後順序從緩存中取出數據，即可解決該問題。

優點：可以從根本上解決此問題，以後基本上不會存在該問題，數據量再大隻需要添加相應的redis資源即可。

缺點：首先會增加許多redis緩存空間消耗，其次從顯示考慮對於我們項目來說，此處代碼古老且晦澀難懂，改動需要較大工作量與回歸測試。

2.2.2 保守治療：縮減其數據量

分析2.1的上述流程，首先第三步是完全沒必要的，先存入緩存再取出，額外占用緩存空間。（猜測系歷史問題，此處不再深究）。

其次是在第二步中，多出來的欄位n，在請求結束後該欄位就已經無用了，因此可以考慮在請求結束後刪除無用欄位。

此時也有兩種解決方案，一種是只刪除無用欄位縮減其map大小，然後將其作為參數傳遞給生成excel使用；另一種方式是請求完成直接刪除該map，然後在生成excel時再重新讀取用戶上傳的excel樣本。

優點：改動較小，不需要太複雜的回歸測試

缺點：在極端大數據量情況下，仍有可能出現full gc的情況

具體實現方式就不展開了。

其中一種實現方式

//獲取有用的欄位
String[] colEnNames = (String[]) colNameMap.get(Constant.BATCH_COL_EN_NAMES);
List<String> colList = Arrays.asList(colEnNames);
//去除無用的欄位
param.keySet().removeIf(key -> !colList.contains(key));

三、拓展思考

首先本文中監控圖是在復現當時場景時人為製造的gc常見。

在cpu使用率圖中，大家可以觀察到cpu使用率上升時間確實跟gc的時間相吻合，但是並沒有出現當時場景中的104%的CPU使用率。

其實直接原因比較簡單，就是因為系統雖然出現了full gc，但是並沒有頻繁出現。

小範圍低頻率的full gc不太會引起系統的cpu飆升，這也是我們所看到的現象。

那麼當時的場景是什麼原因呢？

我們上文提到過，我們在堆記憶體中的大對象是會隨著任務的進行逐步膨脹的，那麼當我們的任務足夠多，時間足夠長，就有可能導致每次full gc後可用空間變得越來越小，當可用空間小到一定程度之後就，每次full gc完成之後發現空間還是不夠使用，就會觸發下一次的gc，從而導致最終結果的頻繁發生gc，引起cpu頻率的飆升不下。

四、問題排查總結

• 當我們遇到線上cpu使用率過高的情況時，可以先查看是否是full gc引起的問題，註意要看的是jvm的監控，或者使用jstat相關命令查看。不要被機器記憶體監控所誤導。
• 如果確定是gc引起的問題，可以通過JProfiler直連線上jvm或者使用dump保存堆快照後離線分析。
• 首先可以找到最大的對象，一般情況下是大對象引起的full gc。還有一種情況是，不像這麼明顯是四個大對象，也可能是比較均衡的十幾個50mb的對象，具體情況還需要具體分析。
• 通過上述工具找到確定有問題的對象後找到其堆棧對應的代碼位置，通過代碼分析找到問題的具體原因，通過其他現象推演猜測是否正確，進而找到問題的真正原因。
• 根據問題的原因解決此問題。

當然，上述只是不算很複雜的排查情況，不同的系統肯定有不同的記憶體情況，我們應當具體問題具體分析，而從此次問題中可以學到的就是如果排查解決問題的思路。