OOM分析之問題一)

七分熟pizza發表於2019-03-18

一.問題描述

最近對系統進行壓測時發現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/8/do… 上面一段文字大概意思是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

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,問題得到解決。

想要了解更多,關注公眾號:七分熟pizza

在這裡插入圖片描述

相關文章