java獲取到heapdump檔案後,如何快速分析?

2023-04-22 06:00:46

原創:扣釘日記(微信公眾號ID:codelogs),歡迎分享,非公眾號轉載保留此宣告。

簡介

在之前的OOM問題覆盤之後,本週,又一Java服務出現了記憶體問題,這次問題不嚴重,只會觸發堆記憶體佔用高報警,沒有觸發OOM,但好在之前的覆盤中總結了dump指令碼,會在堆佔用高時自動執行jstack與jmap,使得我們成功保留了問題現場。

檢視堆佔用分佈

發現有heapdump檔案後,我立馬拷貝到本機,並使用MAT分析,如下:

很顯然,好像是什麼介面分配了非常大的String物件,一個String物件約200MB,那它是哪分配的呢?

查詢大物件分配執行緒

這個分配行為肯定是某個執行緒做的,而執行緒是最常見的GC Root,因此只要查詢物件的GC Root即可,如下:

找到了大物件對應的分配執行緒是http-nio-8088-exec-6,如下:

檢視執行緒棧

如何檢視這個執行緒在幹什麼呢?在MAT中摸索了一會,沒找到相關內容,回想起我們的dump指令碼中記錄了jstack,開啟看看,如下:

可以發現,這個執行緒正在做json序列化,但我仔細找了好一會,也沒有找到相關介面的Controller,這是因為執行緒已經執行完了Controller裡面的邏輯,之後返回介面響應資料時分配的大物件。

可是,執行緒棧中沒有業務程式碼,就沒法定位是哪個介面有問題了。。。

檢查accesslog紀錄檔

考慮到分配大物件的介面肯定會很慢,於是我轉向檢視tomcat的accesslog紀錄檔,如下:

終於,找到了問題介面,這個介面是用來查詢商品資料的,當輸入3時會查詢出所有3開頭的商品,而這有20w+資料,解決問題很簡單,加個limit完事。

排查過程覆盤

然而,我一直有個習慣,就是解決一個問題後,我會反思一下問題解決過程中有多少運氣成分。

如果你經常閱讀排查問題類的技術文章,就會發現不少文章,中間突然有一步定位到了問題根因,可能是突然發現了一個線索,或是硬看程式碼看出來的,或是猜測某處有問題,我覺得這種排查過程都有不少運氣成分,我希望問題是通過多年理論基礎的積累和對診斷工具的熟練使用,而有章法的一步步查出來的。

而上面通過accesslog能夠定位到問題,有一定的運氣成分,因為本次記憶體問題不極端,如果此介面請求量大,那就會瞬間觸發多次FGC,進而會影響其它介面也變慢,進而無法分辨出哪個是導致問題的介面!

我想,從理論上來說,Java堆檔案裡面,應該有執行緒棧以及執行緒棧上的引數,因為執行緒是物件,引數也是物件,它們理應都在堆裡,於是我找了個空閒時間,又摸索起MAT這個工具了。

MAT檢視執行緒棧

摸索了一會,我就發現有這樣一個按鈕,可以檢視執行緒資訊,如下:

找到前面說的執行緒http-nio-8088-exec-6,展開後,就可以發現執行緒棧以及棧上的引數,如下:

這就找到了請求的Request引數物件,再將Request物件多次展開後,就可以找到介面url資訊,如下:

嗯,這樣分析heapdump檔案真tm的高效啊