天天看點

如何使用Eclipse記憶體分析工具定位記憶體洩露

本文以我司生産環境Java應用記憶體洩露為案例進行分析,講解如何使用Eclipse的MAT分析定位問題

一. 背景

11月10号晚上8點收到報警郵件,一看是OOM

打開公司監控系統檢視應用各項名額發現JVM中老年代在持續增長(從上次釋出10月30号到11月10号的12天内一直在增長, 存在記憶體洩露迹象)

如何使用Eclipse記憶體分析工具定位記憶體洩露

從圖中可以看出, 從10月30号釋出到11月10号oom期間11天老年代一直在緩慢上漲, 雖然有下降, 但整體趨勢是上升的,平均每天洩露約50M記憶體, 說明每次都無法完全釋放幹淨

因為生産環境的JVM添加了 <code>-XX:+HeapDumpOnOutOfMemoryError</code> 參數,該配置會把dump檔案的快照儲存下來供後續分析排查問題,也可以使用jmap或jcmd等jvm指令進行dump:

二. 分析記憶體洩露

記憶體洩露和記憶體溢出的差別:記憶體洩露從老年代的增長情況看是緩慢上升的, 最終達到老年代上限才會導緻溢出,有些記憶體洩露可能需要很長的時間發生, 是以說記憶體洩露更隐蔽, 不像記憶體溢出那樣容易暴露(記憶體溢出直接抛出OOM), 而且記憶體長時間得不到釋放會導緻服務性能越來越差、gc時間變長、響應變慢:

如何使用Eclipse記憶體分析工具定位記憶體洩露

從圖中可以看出在12天裡每天大概洩露(增長) 50M 左右, 這種情況下定位洩露原因需要多次dump采集樣本, 然後和上次的比較分析, 即需要多個dump檔案進行比較分析才能精确定位問題。 否則很難看出具體洩露的點, 加上dump檔案中大部分是正常的記憶體使用, 會幹擾問題的定位, 增加排查難度。

是以當時的做法是每天固定時間dump一次, 采集足夠多的樣本, 如下圖:

如何使用Eclipse記憶體分析工具定位記憶體洩露

另外測試環境不好重制的主要原因是不清楚是哪個接口調用引起的, 這個Java服務有多個暴露的api, 而且測試環境不友善壓測,壓測量大了, 底層接口熔斷, 壓測量小看不出洩露迹象, 是以得從dump分析入手, 找到問題所在再去測試環境驗證。

這裡使用Eclipse的memory analysis tool(MAT)工具進行分析

把下載下傳到本地的多個dump檔案用mat依次打開("File → Open Heap Dump"), 如下圖:

如何使用Eclipse記憶體分析工具定位記憶體洩露

比如我們要分析這3個dump檔案(當然你也可以分析更多個, 這樣會更精準), 打開後, 使用compare basket功能找出記憶體洩露的差異點:

1. 使用 compare basket 功能分析記憶體洩露

1&gt; 菜單欄 window → compare basket ,打開比較視窗(如果最下面一欄已經有compare basket則這步不需要),如下圖:

如何使用Eclipse記憶體分析工具定位記憶體洩露

2&gt; 依次打開3個dump的dashboard面闆, 在下方的 Actions一欄點選"histogram"或"dominator tree"生成對應的直方圖或支配樹清單,如下圖:

如何使用Eclipse記憶體分析工具定位記憶體洩露

直方圖或支配樹都可以列出堆中存活的所有對象,但二者的次元不同, 直方圖按照類型統計, 支配樹是以對象次元統計。

如果你對項目代碼比較熟悉, 通過直方圖定位記憶體洩露會更快,因為它是按照類型全部平鋪開的,如果這個項目不是你負責的, 建議使用支配樹的方式, 因為支配樹包含了對象之間的引用關系(支配樹視圖可以展開檢視内部引用層級)

3&gt; 我們以支配樹做比對, 在最下面一欄的"Navigation History (window → navigation history)"裡(直方圖類似)找到在第2步打開的支配樹dominator tree圖示, 右鍵添加到compare basket, 如下圖:

如何使用Eclipse記憶體分析工具定位記憶體洩露

4&gt; 重複上面的2, 3步驟依次把其他的dump檔案添加到"compare basket"欄, 然後點選右上角的紅色感歎号, 生成比較結果,如下圖:

如何使用Eclipse記憶體分析工具定位記憶體洩露

(注意比較的dump檔案的順序,時間最早的在上面,可以通過右上角的上箭頭↑和下箭頭↓調整順序)

生成的比對結果如下:

如何使用Eclipse記憶體分析工具定位記憶體洩露

(可以放大檢視)

Shallow Heap一列後面的序号 #0, #1, #2 分别對應:

第一個dump檔案占用的shallow size, 第二個dump檔案占用的shallow size , 第三個dump檔案占用的shallow size

Retained Heap #0, Retained Heap #1, Retained Heap #2 這3列分别對應:

第一個dump檔案占用的retained size, 第二個dump檔案占用的retained size , 第三個dump檔案占用的retained size

通過Retained Heap的變化趨勢可以看出:

紅框 圈出的是記憶體連續增長的對象, 可以通過右邊紅框的retained heap看出記憶體變大的趨勢

綠框 圈出的是沒有變化的對象(至少在這3次比較中沒有變化)

藍框 圈出的是記憶體占用下降的對象

一般我們主要關注紅框标出的對象, 因為這部分發生記憶體洩露的嫌疑最大

這裡先區分兩個概念:

Shallow Size

對象自身占用的記憶體大小,不包括它引用的對象。

針對非數組類型的對象,它的大小就是對象與它所有的成員變量大小的總和。

針對數組類型的對象,它的大小是數組元素對象的大小總和。

Retained Size

Retained Size=目前對象大小+目前對象可直接或間接引用到的對象的大小總和。(間接引用的含義:A-&gt;B-&gt;C, C就是間接引用)

Retained Size就是目前對象被GC後,從Heap上總共能釋放掉的記憶體。

因為這裡我們比較的是支配樹, 是以按照retained heap倒序排列, 從左到右依次為: retained heap #0 → retained heap #1 → retained heap #2(以最後一個retained heap #2 倒序, 因為這個是最後一次dump的記憶體快照, 這樣可以看出記憶體洩露的增長趨勢)

2. 定位記憶體洩露

基于上一步得出的比較結果, 可以看出"<code>org.apache.tomcat.util.threads.TaskThread http-nio-8080-exec-*</code>" 有記憶體洩露的嫌疑, 檢視它的引用關系:

如何使用Eclipse記憶體分析工具定位記憶體洩露

點選"with outgoing references"後逐層展開第一個對象内部的引用關系(以Retained Heap倒序,主要是看retained size排在前面的對象), 如下:

如何使用Eclipse記憶體分析工具定位記憶體洩露

可以看到<code>TaskThead</code>内部有一個threadLocal, threadLocal内部有一個<code>concurrentHashMap</code>,這個map裡存的是我們的日志相關對象"<code>com.*.framework.log.FieldAppendedValue</code>",從下面幾個map裡的key可以确定是我們記錄到日志系統(ElasticSearch)的對象, 這些日志對象主要記錄調用接口的請求封包、響應封包、SOA接口名稱等資訊,如下圖:

如何使用Eclipse記憶體分析工具定位記憶體洩露

但為什麼日志對象會占用這麼多記憶體?而且這裡看到的隻是其中一個taskThread裡,繼續展開RESPONSE_CONTENT的val對象<code>FieldAppendedValue</code>内部引用, 如下:

如何使用Eclipse記憶體分析工具定位記憶體洩露

發現<code>FieldAppendedValue</code>内部維護了一個<code>CopyOnWriteArrayList</code>對象, 這個list裡竟然存放了10674個值,正常來講不可能一次接口請求會有這麼多的日志對象, 而且接口請求完記錄到ES後, 這部分記憶體就應該釋放了才對。

檢視<code>CopyOnWriteArrayList</code>内部存儲的内容,如下:

如何使用Eclipse記憶體分析工具定位記憶體洩露

随便打開10675個中的幾個<code>FieldAppendedValue</code>, 發現内部存放的都是同一個接口的請求響應封包,如下圖:

如何使用Eclipse記憶體分析工具定位記憶體洩露

可以右鍵copy→ value 把值複制出來檢視, 接口封包如下:(響應封包)

從上面那張<code>concurrentHashMap</code>截圖(key : SOA_METHOD_NAME) 可知這個接口名是: getDownloadLink, 也就是說list裡10675個日志對象存的都是"getDownloadLink"這個接口的封包。而且這隻是其中一個TaskThead内部情況, 加上全部20個對象, 20 * 10675 大概是213500個接口封包,如下圖:

如何使用Eclipse記憶體分析工具定位記憶體洩露

這個接口是什麼鬼?

如何使用Eclipse記憶體分析工具定位記憶體洩露

3. 代碼分析

檢視代碼得知這個接口并沒什麼幺蛾子,隻是當時的開發同學在調用這個底層接口時新接入了我們部門封裝的SOA元件公共類:<code>AbstractSimpleHandler.java</code>(這個公共類主要是通過模闆方法在調用接口時記錄封包日志埋點、逾時時間設定、mock等功能)

這次出現OOM的這個Java項目之前調用soa接口是自己實作了一套公共方法(早于架構之前實作), 也就是說隻有這一個接口使用了新的公共類<code>AbstractSimpleHandler</code>,其他的接口調用方式還是原來的方式。

新的工具類<code>AbstractSimpleHandler</code>記錄接口封包的代碼是通過調用<code>ELKLogUtils.write()</code>實作的, 這個方法的内部大緻邏輯如下:

HttpContext内部維護的是一個<code>ThreadLocal</code>:

所有調用soa底層接口的封包日志都是通過<code>ThreadLocal</code>内的map存儲的, 然後統一發送到ES日志系統。

我們都知道theadLocal是線程安全的, 但是一般我們的項目都是部署在Tomcat等web容器裡, tomcat維護了一個http線程池, 就是前面截圖的那個<code>TaskThead Http-nio*</code>線程對象,每次前端app發起請求都會從tomcat的線程池裡取一個線程處理前端的請求, 如果複用的是上一個線程, 那他内部的<code>threadLocal</code>沒有清空, 還是會儲存上次的封包資訊,這樣的話這次請求又會繼續存放接口封包, 就會越積越多。。。

新接入的元件把接口封包存到threadLoacl的代碼是在<code>AbstractSimpleHandler.java</code>裡的,而清除threadLoacl的代碼是在另外一個公共類<code>BaseService.java</code>裡做的,也就是說要接入新的公共類除了<code>AbstractSimpleHandler.java</code>外,還要接入<code>BaseService.java</code> 這個公共類!

這個也是有曆史原因的, 這個Java項目本身比較早, 那時候還沒有我們部門架構的SOA公共類, 是以自己實作了一套,後來使用新的架構元件調用接口的開發小夥伴沒有調研全面, 少接了一個公共類(<code>BaseService</code>)導緻了這一問題發生。

是以這個問題的根因是threadllocal使用不當引起的記憶體洩露

弄清楚原因後就好辦了, 解決辦法是在請求完接口後主動調用下架構裡的<code>HttpContext.clear()</code>, 清除下架構内部的<code>threadlocal.map</code>即可,當然後續還是要統一接口的調用方式, 不能兩套工具類并存。

4. 使用 path to gc root 定位業務代碼

還有另外一個記憶體洩露的嫌疑是"<code>com.*.common.utils.ITextRendererPoolManager</code>", 如上面比對結果的圖:

如何使用Eclipse記憶體分析工具定位記憶體洩露

單獨在dominator tree支配樹視圖展開如圖所示:

如何使用Eclipse記憶體分析工具定位記憶體洩露

<code>ITextRendererPoolManager</code>内部使用了apache的一個對象緩沖池, 目的可能是為了對象複用, 繼續展開,如下圖:

如何使用Eclipse記憶體分析工具定位記憶體洩露

發現是pdf的一個工具類:<code>org.xhtmlrenderer.pdf.ITextRenderer</code>, 這個開源的pdf工具是我們項目的郵件功能在發送附件的時候生成pdf文檔時引入的一個第三方jar包,開始懷疑是否是這個開源的pdf工具導緻的記憶體洩露, 但是不清楚這個jar包是在哪裡調用的?

這裡可以通過"path to gc root"檢視是誰在引用他, 即我們業務代碼調用的地方,如下圖:

如何使用Eclipse記憶體分析工具定位記憶體洩露

這裡先說下"path to gc root"選項的含義:

with all references : 所有引用, 包括強引用, 弱引用, 軟引用, 虛引用

exclude weak reference : 排除弱引用

exclude soft reference : 排除軟引用

。。。。

我們知道軟引用, 弱引用這些在發生full gc時可能會被回收掉(回收時機不同, 具體可自行百度), 目的是不造成記憶體溢出。一般引起記憶體溢出的都是強引用,是以你可以選擇"exclude all ptantom/weak/soft reference"隻檢視強引用。

但在這個案例中<code>pdf.ITextRenderer</code>是被軟引用引用的(從上圖中可以看出), 雖然說軟引用不會導緻溢出, 但可能會引起記憶體一點點上升(軟引用隻有在記憶體不足發生GC時才會被回收), 這個跟本地緩存還不一樣, 因為<code>shareContext</code>對象沒有達到複用的目的, 而且最重要的是它沒有失效機制,隻要沒有達到堆最大值或發生full gc就會一直存在, 這樣的話會拖累JVM的性能,是以我選擇"with all references"檢視所有類型引用:

如何使用Eclipse記憶體分析工具定位記憶體洩露

發現是被<code>PdfUtil</code>這個類引用, 檢視代碼發現<code>PdfUtil</code>是我們自己封裝的一個pdf工具類, 這個工具類把建立pdf的<code>ITextRenderer</code>對象緩存到了<code>iTextRendererPoolManager</code>對象池裡, 這樣下次就不需要再重新建立, 代碼大緻如下:

但是在放回對象池前沒有對ITextRenderer裡面的<code>sharedContext</code>屬性清空, 這樣的話下次從對象池裡如果還是擷取到這個對象,就會對ITextRenderer内部的屬性<code>sharedContext</code>繼續疊加。。。

查了下官方使用手冊發現沒有這樣的用法, 是以導緻這個問題的原因應該是我們使用的姿勢不對

解決方法一種是繼續使用對象池,但在放回對象池之前先清除下<code>SharedContext</code>, 或者簡單點不再用對象池,每次new一個, 因為是在方法内部建立的局部變量, 不會逃逸出方法外, 方法調用完就自動釋放了。

三. 驗證結果

修複上述兩個問題後在測試環境驗證通過然後釋出上線從12月10号一直截止到今天,大概18天裡記憶體再沒有洩露迹象, 堆外記憶體(RSS-JVM記憶體)也穩定下來,如下圖:

如何使用Eclipse記憶體分析工具定位記憶體洩露
如何使用Eclipse記憶體分析工具定位記憶體洩露
如何使用Eclipse記憶體分析工具定位記憶體洩露

至此, 記憶體洩露問題算是告一段落。

四. 總結

檢視git送出記錄發現這個問題線上上存在有一段時間了(10月30号之前就有洩露迹象),之前一直沒報出來主要是每周都有發版,釋出肯定會重新開機清空記憶體,釋出頻繁也就掩蓋了這個問題,是以這個問題其實是一直存在的

如何使用Eclipse記憶體分析工具定位記憶體洩露

但測試環境又很難重制出來,很少有應用在測試環境壓測10天以上的,壓測頻率高了,接口容易熔斷。。。

而且有些洩露也不是"真正的洩露", 比如本地緩存的失效政策設定不合理、寫多讀少、記憶體占用持續上升,直到觸發抛棄政策等。

其實下面的三種情況都屬于廣義上的記憶體洩露:

仍然具有GC ROOT根引用但從未在應用程式代碼中使用的對象。這也是傳統意義上的記憶體洩漏

對象太多或太大。意味着沒有足夠的堆可用于執行應用程式,因為記憶體中儲存了太大的對象樹(例如緩存)

臨時對象太多。意味着Java代碼中的處理暫時需要太多記憶體

第一種是大家都熟悉的記憶體洩露,後兩種多半屬于寫代碼不規範,或業務流程上設計不合理或寫代碼時沒充分考慮緩存的使用場景,是以:

寫代碼時要加強這方面的意識,包括review的人

釋出上線後要定時監控,及早發現這類問題

五. MAT工具使用相關事項

使用mat前最好把初始化記憶體設定大一點,因為一般生産環境的dump檔案都比較大,mat記憶體大小至少要cover住dump檔案的大小,否則打開會報錯,配置檔案如圖:

如何使用Eclipse記憶體分析工具定位記憶體洩露

比如下面堆記憶體的最大(Xmx)最小(Xms)設定為4G(具體以你dump檔案大小為準):

另外最好設定下顯示機關, 以兆 M或G 為機關更便于了解,如圖:

如何使用Eclipse記憶體分析工具定位記憶體洩露
如何使用Eclipse記憶體分析工具定位記憶體洩露

其他更多功能請參考MAT官方使用文檔:https://help.eclipse.org/2020-09/index.jsp?topic=/org.eclipse.mat.ui.help/welcome.html