一.問題描述

最近對系統進行壓測時發現Server日誌報如下錯誤：java.lang.OutOfMemoryError: GC overhead limit exceeded。

查看Oracle OOM文檔，在文檔中找到以下內容：

Exception in thread thread_name: java.lang.OutOfMemoryError:GC Overhead limit exceeded

Cause: The detail message "GC overhead limitexceeded" indicates that the garbage collector is running all the time andJava program is making very slow progress. After a garbage collection, if the Java process is spending more than approximately 98% of its time doing garbage collection and if it is recovering less than 2% of the heap and has been doing so far the last 5 (compile time constant) consecutive garbage collections, then a java.lang.OutOfMemoryError is thrown.This exception is typically thrown because the amount of live data barely fitsinto the Java heap having little free space for new allocations.

Action:Increase the heap size.The java.lang.OutOfMemoryError exception for GC Overhead limit exceeded can be turned off with thecommand line flag -XX:-UseGCOverheadLimit.原文鏈接如下：docs.oracle.com/javase/

上面一段文字大概意思是JVM用98%的時間回收了不到2%的堆內存，因此預測到內存即將耗盡，拋出OOM異常來提示內存不足，相當於給用戶一個警告信息。Oracle給的解決方法是提高堆內存，也可以用-XX:-UseGCOverheadLimit參數來關閉這個異常警告。

這種方式其實只是治標不治本，讓用戶提高堆內存容量，雖然解決了燃眉之急，但實際上並沒有解決內存消耗過大的根本問題。如果堆內存一直增長，最終還會提示「GC overhead limit exceeded」。即使用XX:-UseGCOverheadLimit參數關閉OOM預測提示，當內存佔用增長到極限，最後也會直接報 java.lang.OutOfMemoryError: Java heap space，造成進程停止的嚴重影響。所以Oracle給的解決方案並不靠譜，只能作為參考。

通過以上描述，可以推測進程中要麼有任務一直在申請內存，要麼發生了內存泄露。具體哪種原因還得對內存使用情況深入分析後判斷，以下是分析的整個過程。

二.MAT分析

1.獲取dump文件

登上伺服器，用 Java自帶的jmap生成dump 文件，命令如下：

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

2. 餅圖分析

將dump文件下載到自己電腦，用 MAT打開。

從overview視圖看到java.util.concurrent.ThreadPoolExecutor @ 0x744ce0aa 共佔用了1.6G內存，比例佔到了75%，可以初步判斷有一個ThreadPoolExecutor的實例佔據了大量內存，導致OOM。

3.Leak Suspects報告

點擊overview視圖下的Leak Suspects 按鈕，查看分析結果。

從報告中看到QRCodeBatchTask類中引用的ThreadPoolExecutor的對象共佔用了71.43%的內存，java.util.concurrent.LinkedBlockingQueue$Node 對象佔用的最多。

4. Histogram圖

點擊菜單欄的Hitstorgam按鈕，生成instances報告，並用Retained Heap進行排序。

圖中Shallow Heap指對象自身佔用內存大小，Retained Heap指對象自身加其引用對象總共佔用內存大小。

從圖中看出佔用內存最多的是BufferedImages對象，QRCodeTask對象排到了第四，這個對象功能後面會提到。

選中BufferedImage右鍵查show object by classby incoming class，看到確實是QRCodeTask引用了BufferedImage。

選中BufferedImage右鍵查看Merge Shortest Paths to GC Roots ->exclude all phantim/weak/softetc. references，可以得知QRCodeTask中的的backGroundImage,logoImage變數佔用內存最大。

5. DominatorTree

選中BufferedImage，點擊Dominator Tree菜單。從圖中可以看到確實是java.util.concurrent.LinkedBlockingQueue$Node引用了BufferImage，與Leak Suspects報告一致。

至此，可以基本分析出是QRCodeTask類中的兩個BufferImage 對象backGroundImage和logoImage佔用了大量內存,大概17M。

MAT分析工作基本到此結束，下一步找到相應代碼查看業務邏輯。

三.代碼分析

1.當有請求過來時會執行以下函數，把QRCodeBatchTask添加到線程池中。

public void applyQRcode() {
exec.execute(new QRCodeBatchTask());
}

2.QRCodeBatchTask會不斷往線程池提交QRCodeTask任務，並把生成的圖片賦值給QRCodeTask。

public void run() {
backImage=ImageIO.read(backGroundImageFile);
logoImage=ImageIO.read(logoFile);
for (List list : lists) {
exec.execute(new QRCodeTask(backImage，logoImage)）;
)}}

3.QRCodeTask保存backGroundImage，logoImage對象，並在任務執行中用到。

public class QRCodeTask implements Runnable {
private BufferedImage backGroundImage, logoImage;
public QRCodeTask(String backGroundImage, logoImage ) {
this.backGroundImage = backImage;
this.logoImage = logoImage;
}
}

以上業務代碼處理邏輯是每次請求過來時都會新建一個QRCodeBatchTask任務並提交到線程池中。QRCodeBatchTask會從磁碟讀取兩張圖片，賦值給新建的QRCodeTask任務，所有新建的任務都會提交到線程池中去執行。

ThreadPoolExecutor原理是把提交的所有任務添加到LinkedBlockingQueue隊列中，這也就是圖中java.util.concurrent.LinkedBlockingQueue$Node對象引用QRCodeTask對象的原因。實際壓測時候隨著請求的持續增加，新建的QRCodeBatchTask越來越多，生成的圖片也越來越多，最終導致佔用的內存持續增長直至OOM發生。

四.問題解決

原因已經知道，解決問題就相對容易了。因為每個任務用到的backGroundImage,logoImage其實是一樣的，因此可以用單例模式獲取這兩個圖片，以此來保證進程內只保留一個圖片對象，這樣就減少了內存的佔用。

通過重構代碼，再次運行程序並用VisualVM進行監控可以觀察到內存佔用趨於平穩，沒有再發生OOM，問題得到解決。


推薦閱讀：
相关文章