記一次記憶體溢出排查過程

有一個服務經常會停止服務，一開始沒特别注意，出問題就重新部署。

後來有一次重新開機前看了眼 GC，發現一直在 Full GC:

[149644.445s][info][gc,start       ] GC(2210) Pause Full (Allocation Failure)
[149644.447s][info][gc,phases,start] GC(2210) Phase 1: Mark live objects
[149644.708s][info][gc,phases      ] GC(2210) Phase 1: Mark live objects 261.113ms
[149644.708s][info][gc,phases,start] GC(2210) Phase 2: Compute new object addresses
[149644.771s][info][gc,phases      ] GC(2210) Phase 2: Compute new object addresses 62.603ms
[149644.771s][info][gc,phases,start] GC(2210) Phase 3: Adjust pointers
[149644.903s][info][gc,phases      ] GC(2210) Phase 3: Adjust pointers 131.929ms
[149644.903s][info][gc,phases,start] GC(2210) Phase 4: Move objects
[149644.903s][info][gc,phases      ] GC(2210) Phase 4: Move objects 0.011ms
[149644.905s][info][gc,heap        ] GC(2210) DefNew: 314553K->314553K(314560K)
[149644.905s][info][gc,heap        ] GC(2210) Tenured: 699071K->699071K(699072K)
[149644.905s][info][gc,metaspace   ] GC(2210) Metaspace: 83387K->83387K(1126400K)
[149644.905s][info][gc             ] GC(2210) Pause Full (Allocation Failure) 989M->989M(989M) 459.957ms
[149644.905s][info][gc,cpu         ] GC(2210) User=0.46s Sys=0.00s Real=0.46s
[149644.907s][info][gc,start       ] GC(2211) Pause Full (Allocation Failure)
[149644.910s][info][gc,phases,start] GC(2211) Phase 1: Mark live objects
[149645.168s][info][gc,phases      ] GC(2211) Phase 1: Mark live objects 258.422ms
[149645.168s][info][gc,phases,start] GC(2211) Phase 2: Compute new object addresses
[149645.231s][info][gc,phases      ] GC(2211) Phase 2: Compute new object addresses 63.401ms
[149645.231s][info][gc,phases,start] GC(2211) Phase 3: Adjust pointers
[149645.365s][info][gc,phases      ] GC(2211) Phase 3: Adjust pointers 133.363ms
[149645.365s][info][gc,phases,start] GC(2211) Phase 4: Move objects
[149645.367s][info][gc,phases      ] GC(2211) Phase 4: Move objects 1.892ms
[149645.368s][info][gc,heap        ] GC(2211) DefNew: 314559K->312083K(314560K)
[149645.368s][info][gc,heap        ] GC(2211) Tenured: 699071K->699071K(699072K)
[149645.368s][info][gc,metaspace   ] GC(2211) Metaspace: 83387K->83387K(1126400K)
[149645.368s][info][gc             ] GC(2211) Pause Full (Allocation Failure) 989M->987M(989M) 460.962ms
[149645.368s][info][gc,cpu         ] GC(2211) User=0.46s Sys=0.00s Real=0.46s      

服務限制了 4G 記憶體，在沒有指定 ​

​-Xmx​

​​ 的情況下隻能使用 ​

​1G​

​ 記憶體，

了解更多 GC 内容看這裡: ​​HotSpot Virtual Machine Garbage Collection Tuning Guide​​​ 和 ​​GC Tuning: In Practice​​

當時着急用服務就又直接重新開機了，直到今天，才在重新開機前盡可能保留了更多的資訊。

下面是監控和 GC 的實時截圖：

服務啟動兩天後，實際上在1天前就已經占滿記憶體開始頻繁 GC。GC 實時資訊：

FGC 比 YGC 還多，E年輕代滿了，O老年代也滿的。每次可用的隻有 S1, S2 中的不到 10% 的空間。

這次本來要導出 dump 資訊，可惜手快重新開機沒拷出來。等新服務啟動一段時間後，線上上通過 ​

​jps​

​​ 檢視 id，然後使用 ​

​jmap -dump:live,format=b,file=heap.bin <pid>​

​ 導出 dump 資訊。

jmap 詳細資料： ​​https://docs.oracle.com/en/java/javase/11/tools/jmap.html#GUID-D2340719-82BA-4077-B0F3-2803269B7F41​​

導出 heap.bin 後，先通過 ​​VisualVM​​​ 打開了，能看到有限的資訊，關鍵還不熟悉 ​​OQL 文法​​​，很不友善，是以使用 ​​記憶體分析器(MAT)​​ 進行分析。

Memory Analyzer (MAT) 記憶體分析器(MAT)

Eclipse Memory Analyzer 是一個快速且功能豐富的 Java 堆分析器，它可以幫助您發現記憶體洩漏并減少記憶體消耗。

使用記憶體分析器分析數億個對象的高效堆轉儲，快速計算對象的保留大小，檢視是誰阻止垃圾收集器收集對象，運作報告自動提取洩漏嫌疑人。

用 mat 打開後，根據提示資訊找到了下面的地方：

​

​XDocReportRegistry​

​​ 中的 ​

​MapCacheStoreage​

​ 占用了 63.81% 的空間，從名字來看是緩存，而緩存是最容易出現記憶體溢出的地方。

在工具類中有如下調用：

這裡的 ​

​loadReport​

​ 如下：

這個方法預設是緩存的，但是使用的地方每次都是傳入新的 ​

​InputStream​

​​，緩存的 ​

​IXDocReport​

​ 根本沒有用上，是以該方法隻要執行一次都會導緻緩存增加一個，最終會将記憶體占滿。

最簡單的解決方法就是調用 ​

​loadReport​

​​ 的時候指定 ​

​cacheReport=false​

​ 禁用緩存。

解決了這裡記憶體溢出的問題後，服務所用記憶體應該會大幅度降低，等服務運作一兩天後再補充兩張資源占用圖。

在 ​​2019 年部落格總結​​ 中提過：