Java 程式開發者,多多少少都遇到過 Java 堆記憶體溢出的錯誤,錯誤發生時可以在日志檔案中看到
java.lang.OutOfMemoryError: Java heap space
字樣。不像
NullPointerException
等其他異常,抛出
OutOfMemoryError
的代碼往往并不是罪魁禍首,隻是想申請記憶體時發現記憶體已經被其他人占光了而已。這個特點導緻開發者較難找到導緻
OutOfMemoryError
的根本原因。許多人喜歡靠前後版本代碼比較,甚至根據一些蛛絲馬迹來推測問題點,但這些手段都很低效,無法推廣。
本文從一個項目的實際例子出發,講述如何通過分析記憶體 dump 檔案定位問題代碼,甚至還原問題發生時的場景。
問題出現
最近某項目報告生産環境 伺服器的 Java 堆記憶體大小不斷攀升,懷疑存在記憶體洩漏。
接到報告後,我們就請項目運維人員做了一次記憶體 dump。在這裡推薦使用類似下面的指令(把 Java 程序
11780
記憶體 dump 到
a.hprof
檔案中):
jmap -dump:live,format=b,file=xxx.hprof 11780
的作用是隻 dump live objects,其實就是先做一次 Full GC(完整垃圾收集),然後再把記憶體 dump 出來。用這個參數的好處是可以清理掉記憶體中一些已經可以回收,但還沒被回收的對象,避免對我們後續的分析造成幹擾。 指令官方文檔: https://docs.oracle.com/en/java/javase/11/tools/jmap.html |
分析工具
Java VisualVM (不推薦)
Java VisualVM 是 JDK 自帶的 Java 記憶體分析工具,執行指令
jvisualvm
即可運作。
其實用 VisualVM 也是可以分析記憶體洩漏問題的,不過 VisualVM 的界面做得不是很人性化,用起來不如下文要重點推薦的 Eclipse Memory Analyzer,是以在這裡暫不作詳述了。
Eclipse Memory Analyzer (推薦)
Eclipse Memory Analyzer 是 Eclipse 組織開發的 Java 記憶體分析工具。
推薦到其官方首頁去下載下傳最新版本: http://www.eclipse.org/mat/
本文使用 Eclipse Memory Analyzer
1.10.0
版本,釋出于 2020 年 3 月 18 日。
分析過程
加載 dump 檔案
點選 Eclipse Memory Analyzer 菜單
File
→
Open Heap Dump…
選擇 dump 出來的
heap_live520.hprof
檔案,就開始加載。該項目生産環境記憶體比較大,dump 出來的檔案有
6GB
多,需要耐心等待幾分鐘。
加載完成後,會詢問使用者是否要顯示 Leak Suspects Report,也就是洩漏懷疑對象報告。這是 Memory Analyzer 對記憶體進行智能分析後得出的一份洩漏懷疑對象報告,一般可以選擇顯示該報告,但今天我們不使用該報告,完全手工來搞定。 |
Dominator Tree 找到“記憶體堆積點”
點選工具欄圖示
![](https://img.laitimes.com/img/__Qf2AjLwojIjJCLyojI0JCLicmbw5CMiNDN0UGOjFWY3YTMjRmNiVGNwUTYkdzYyIzN4ETM38CX0JXZ252bj91Ztl2Lc52YucWbp5GZzNmLn9Gbi1yZtl2Lc9CX6MHc0RHaiojIsJye.png)
(
Open Dominator Tree for entire heap.
),打開 Dominator Tree。dominator 直譯為“主宰者”,在這裡的意思就是占用記憶體最多的對象。
在上面的圖裡我們可以看到各個對象,格式是 類名 @ 對象位址 ,而且是按 Retained Heap 從大到小排序的。
Dominator Tree 各列含義
|
對我們來說,要觀察的就是 Retained Heap。哪個對象的 Retained Heap 大,就說明由于它的存在,這麼多記憶體都釋放不掉,那麼這個對象就可能是記憶體洩漏的點。
為了更好地說明,我們先不看排名第一的
org.apache.tomcat.util.threads.TaskThread @ 0x6ab74a1a0
,而來看排名第二的
com.mysql.cj.jdbc.result.ResultSetImpl @ 0x6a0fe1a40
。
輕按兩下該對象展開其子樹,展開幾層後,可以看到 Retained Heap 有一個斷崖式的降低(從
914677440
一下子降到了
3600
):
這個突然降低的位置稱為“記憶體堆積點” (memory accumulation point),也就是說
java.lang.Object[360145] @ 0x6b7166310
數組對象中含有
299134
個
com.mysql.cj.protocol.a.result.ByteArrayRow
元素。注意:展開時預設隻顯示 25 個子節點,要看更多的話就要再輕按兩下
Total: 25 of 299,134 entries; 299,109 more
這一行。
看到這裡,我們大概可以推斷出這是一句 SQL 傳回了将近 30 萬行資料,而且這些行資料全都堆積在記憶體中沒有得到釋放。接下去我們要找出是什麼代碼建立出了這樣一個對象。
Path To GC Roots 找到線程
右鍵點選
com.mysql.cj.jdbc.result.ResultSetImpl @ 0x6a0fe1a40
,在彈出菜單中點選
Path To GC Roots
→
with all references
:
可以看到該對象到 GC Root 的各條路徑:
GC Root 的含義請查閱 Eclipse Memory Analyzer 自帶的 Help Contents,若看英文比較吃力的話,也可參考文末的參考文檔。
一個對象可能有多條路徑通往多個 GC Root。但一般來說,其中某一個 GC Root 必定是一個線程。從上圖可以看到
com.mysql.cj.jdbc.result.ResultSetImpl @ 0x6a0fe1a40
對象通往 GC Root 的路徑有很多條,但最終都殊途同歸到了線程對象
org.apache.tomcat.util.threads.TaskThread @ 0x6ab74a1a0 http-nio-7001-exec-10
。這就是說,是
http-nio-7001-exec-10
線程在運作過程中建立出了
com.mysql.cj.jdbc.result.ResultSetImpl @ 0x6a0fe1a40
對象。那麼我們接着看看
http-nio-7001-exec-10
線程到底在幹什麼?
Thread Overview
右鍵點選
http-nio-7001-exec-10
線程對象,在彈出菜單中點選
Java Basics
→
Thread Overview and Stacks
,打開該線程的 Thread Overview:
上圖中可以看到第一行就是
http-nio-7001-exec-10
線程。輕按兩下展開該線程的堆棧,接下來就要重點觀察那些我們自己寫的類裡的方法,這裡需要憑借一些對自己代碼的熟悉度和經驗了。我們可以看到堆棧中有調用到
logwire.web.controller.ActionController.requerySelectRows
方法,這是在 選中全部 後再點選操作按鈕後會調用到的方法:
猜測可能是根據條件查詢到的資料量太大了,導緻記憶體被用完。
然後我們再看看到底是在哪個界面功能裡執行了該方法?繼續往下找,可以看到
logwire.web.controller.ActionController.doAction
方法:
這個方法裡有兩個
String
類型的 local 變量。local 變量在記憶體中沒有變量名稱,但是我們可以根據其順序來判斷它是哪個變量。在一個方法下展開的 local 變量中,第一個一定是對象本身,接下去是各個方法參數,最後是方法體内定義的局部變量(按代碼執行的順序)。是以我們在這裡看到的第一個字元串
payment_report_query
就是
doAction
方法的第一個參數(看源代碼可知是
queryName
)的值,第二個字元串
payment_back_other
就是第二個參數
action
的值。
根據
payment_report_query
和
payment_back_other
這兩條線索便可弄清使用者是在哪個界面點選了哪個按鈕,引發了記憶體溢出。
更進一步的探究:找到執行使用者
現在我們已經知道了是哪段代碼出了問題。不過如果想搞清楚使用者為什麼會執行操作,就得去問問操作者本人,那麼就需要知道執行操作的使用者是誰。
目前項目是把登入使用者資訊記在 Spring Security 架構的
SecurityContext
中,調用其
setAuthentication
方法,其本質是把登入使用者對象記在了 Java 線程本地變量 (ThreadLocal) 中。閱讀 Spring Security 代碼可知,該線程本地變量是由
org.springframework.security.core.context.ThreadLocalSecurityContextHolderStrategy
對象的靜态成員變量
contextHolder
持有的。
為了快速找到該對象,可以點選工具欄圖示
(
Create a histogram from an arbitrary set of objects.
) ,打開 Histogram。Histogram 展示了每一種 Java 類有多少個執行個體,總共占了多少記憶體。
這裡類實在太多了,我們要過濾一下,快速找到想要的類。在
Class Name
列的正規表達式過濾器中輸入
ThreadLocalSecurityContextHolderStrategy
并回車(回車後會自動在前後加上
.*
,表示前後還可以有任意多個字元),這樣就找到了那個類:
但這隻是類,而不是執行個體對象。我們需要列出該類的所有執行個體對象。右鍵點選該類後,在彈出菜單中點選
List objects
→
with outgoing references
:
可以看到該類隻有一個執行個體對象,展開以後看到了這個類的靜态變量
contextHolder
,是一個
java.lang.ThreadLocal @ 0x6a6fcc3c8
。
找到這個線程本地變量 (
ThreadLocal
) 後,我們就要看看在
http-nio-7001-exec-10
線程中對應該線程本地變量的值是什麼,也就是執行使用者是誰。
閱讀 JDK 代碼可知,線上程
Thread
對象中有一個
threadLocals
成員變量持有
ThreadLocal.ThreadLocalMap
對象。當調用
ThreadLocal
對象的
get
或
set
方法時,實際上是以
ThreadLocal
對象為 key,存入了線程的
threadLocals
中。
是以我們可以找出所有
threadLocals
的 key 中含有
java.lang.ThreadLocal @ 0x6a6fcc3c8
的線程,再找到
http-nio-7001-exec-10
線程的
threadLocals
中相應 key 的 value 即可。
右鍵點選
contextHolder
,也就是
java.lang.ThreadLocal @ 0x6a6fcc3c8
對象,在彈出菜單中點選
List objects
→
with incoming references
,找到所有引用了該對象的對象:
我們看到除了
contextHolder
以外,還有很多線程的
ThreadLocal.ThreadLocalMap
引用了該對象,這表示很多線程中都有該線程執行時的使用者:
然後要幹點體力活兒了,逐個展開後,我們最終找到了
http-nio-7001-exec-10
線程:
筆者覺得應該可以利用 OQL 功能(類似于 SQL 文法,在記憶體分析中做各種查詢),更快速地找到 線程對應的使用者。但是暫時沒花精力去詳細研究,以後有時間再補充。 |
在上面的圖中,我們看到左邊 Attributes 清單中,
value
屬性的值是一個
org.springframework.security.core.context.SecurityContextImpl @ 0x6cd141978
對象。右鍵點選該對象,在彈出菜單中點選
List objects
→
with outgoing references
,再展開:
最終就看到了該線程的執行使用者的
username
。(為保護客戶隐私,具體的
username
值用馬賽克遮蔽了)
其他
為什麼不直接用 Leak Suspects Report?
其實 Leak Suspects Report 還是很好用的,但是不能過度依賴于它。
因為 Leak Suspects Report 隻展示最可疑的兩個對象,通常是目前 Retained Heap 最大的兩個對象。但有時候 目前最大的 并非 真正洩漏的 ,如果太依賴 Leak Suspects Report,可能會找不到真正的洩漏原因。
為什麼 目前最大的 并非 真正洩漏的 ?
假設這樣一個場景:
- Java 運作參數中設定了最大堆記憶體
(200 MB
)-Xmx200m
- 系統中有一段導緻記憶體洩漏的代碼,該代碼是個死循環,每天會在一個
中添加一個元素,增加占用List
記憶體。1 MB
- 系統對外提供了一個 API,該 API 每次調用時需要占用
記憶體,調用完就全部釋放50 MB
在這樣的場景下,該系統剛啟動後可以支援大約
3
個用戶端同時調用 API,這樣總共占用
150 MB
記憶體(其他
50 MB
是 Tomcat 等啟動後固定占用的部分)。
但是過了一個月後,那段記憶體洩漏代碼的
List
占用了
30 MB
記憶體,這時若仍然有
3
個用戶端同時調用 API,則會抛出
OutOfMemoryError
。因為這時空閑記憶體隻有
120 MB
了,最多支援
2
個用戶端同時調用 API。
在這種情況下,記憶體 dump 分析會發現占用記憶體最大的仍然是那幾個 API 線程,而不能立即發現真正的記憶體洩漏點。
如何精确定位記憶體洩漏點?
既然這樣,那麼該如何精确定位記憶體洩漏點呢?
從理論上來講,不存在絕對有效的方法。但是通常生産環境的
-Xmx
參數不會設得太小,是以如果正常的代碼已經無法擷取合适大小的記憶體,那麼往往記憶體洩漏對象已經占用了很大的記憶體 (Retained Heap)。
當然,有時候并不存在嚴格意義上的“記憶體洩漏”。就以本文的例子來說,隻是因為某次查詢到的資料行數太多,撐破了
-Xmx
上限。但如果拼命增加
-Xmx
,直到足夠容納查詢到的行數,那麼查詢過後也照樣會釋放記憶體,并不會
OutOfMemoryError
。不過從代碼工程上來講,單次請求處理占用的記憶體超過
1 GB
,這種設計就是不合理的。一般來說,單次請求處理占用的記憶體應該控制在
50 MB
以内。
合理使用比較功能
有時候可以對同一個 Java 程序先後多次 dump,然後來比較這些 dump 檔案的内容。
在第一個 dump 檔案的
Navigation History
中右鍵點選某個視圖,然後
Add to Compare Basket
:
在第二個 dump 檔案也做同樣的操作。于是在
Compare Basket
中可以看到有兩個待比較對象。接着再點選
(
Compare the results
)
這樣就可以看到比較結果:
有時候可以看到某個類型的執行個體數量以及記憶體一直在增長,那麼就可能是記憶體洩漏點。
方法體内定義的局部變量,不一定能在 local 變量中找到
上文說到過線上程堆棧裡可以看到每個方法裡各個 local 變量的值。但這隻是一個籠統的說法,并不是非常精确。
看這樣一個例子:
public void method1() {
if (true) {
String s = "abc";
}
while (true) {
new ArrayList<>().add(new byte[1024]);
}
}
在上述
method1
方法中,記憶體洩漏發生在
while
循環中,清單不斷變長,最終會記憶體溢出。但是在用 Eclipse Memory Analyzer 觀察線程堆棧時,
method1
方法下是看不到字元串
abc
這個 local 變量的。因為該變量的作用域隻在
if
語句内,也許早在記憶體溢出之前,字元串
abc
就已經被 GC 回收了,這樣在分析 dump 檔案時自然就看不到了。
參考
Eclipse Memory Analyzer 自帶的 Help Contents 解釋得很詳細了。但如果閱讀英文比較慢的話,也可以看一些中文資料:
- 關于 Shallow Heap、Retained Heap、GC Root 的解釋: https://blog.csdn.net/hhww0101/article/details/8133219