如何使用Eclipse內(nèi)存分析工具定位內(nèi)存泄露

本文以我司生產(chǎn)環(huán)境Java應(yīng)用內(nèi)存泄露為案例進行分析，講解如何使用Eclipse的MAT分析定位問題

一. 背景

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

打開公司監(jiān)控系統(tǒng)查看應(yīng)用各項指標(biāo)發(fā)現(xiàn)JVM中老年代在持續(xù)增長(從上次發(fā)布10月30號到11月10號的12天內(nèi)一直在增長， 存在內(nèi)存泄露跡象)

在這里插入圖片描述

從圖中可以看出， 從10月30號發(fā)布到11月10號oom期間11天老年代一直在緩慢上漲， 雖然有下降， 但整體趨勢是上升的，平均每天泄露約50M內(nèi)存， 說明每次都無法完全釋放干凈

因為生產(chǎn)環(huán)境的JVM添加了-XX:+HeapDumpOnOutOfMemoryError參數(shù)，該配置會把dump文件的快照保存下來供后續(xù)分析排查問題，也可以使用jmap或jcmd等jvm命令進行dump：

jmap -dump:format=b，file=文件名 [pid]
jcmd pid GC.heap_dump 文件路徑

二. 分析內(nèi)存泄露

內(nèi)存泄露和內(nèi)存溢出的區(qū)別：內(nèi)存泄露從老年代的增長情況看是緩慢上升的， 最終達(dá)到老年代上限才會導(dǎo)致溢出，有些內(nèi)存泄露可能需要很長的時間發(fā)生， 所以說內(nèi)存泄露更隱蔽， 不像內(nèi)存溢出那樣容易暴露(內(nèi)存溢出直接拋出OOM)， 而且內(nèi)存長時間得不到釋放會導(dǎo)致服務(wù)性能越來越差、gc時間變長、響應(yīng)變慢：


在這里插入圖片描述

從圖中可以看出在12天里每天大概泄露(增長)50m左右， 這種情況下定位泄露原因需要多次dump采集樣本， 然后和上次的比較分析， 即需要多個dump文件進行比較分析才能精確定位問題。 否則很難看出具體泄露的點， 加上dump文件中大部分是正常的內(nèi)存使用， 會干擾問題的定位， 增加排查難度。

所以當(dāng)時的做法是每天固定時間dump一次， 采集足夠多的樣本， 如下圖：


在這里插入圖片描述

另外測試環(huán)境不好重現(xiàn)的主要原因是不清楚是哪個接口調(diào)用引起的， 這個Java服務(wù)有多個暴露的api， 而且測試環(huán)境不方便壓測，壓測量大了， 底層接口熔斷， 壓測量小看不出泄露跡象， 所以得從dump分析入手， 找到問題所在再去測試環(huán)境驗證。

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

把下載到本地的多個dump文件用mat依次打開("File → Open Heap Dump")， 如下圖:


在這里插入圖片描述

比如我們要分析這3個dump文件(當(dāng)然你也可以分析更多個， 這樣會更精準(zhǔn))， 打開后， 使用compare basket功能找出內(nèi)存泄露的差異點：

1. 使用 Compare Basket 功能分析內(nèi)存泄露

1> 菜單欄 window → compare basket ，打開比較窗口(如果最下面一欄已經(jīng)有compare basket則這步不需要)，如下圖：


在這里插入圖片描述

2> 依次打開3個dump的dashboard面板， 在下方的 Actions一欄點擊"histogram"或"dominator tree"生成對應(yīng)的直方圖或支配樹列表，如下圖：


在這里插入圖片描述

直方圖或支配樹都可以列出堆中存活的所有對象，但二者的維度不同， 直方圖按照類型統(tǒng)計， 支配樹是以對象維度統(tǒng)計。

如果你對項目代碼比較熟悉， 通過直方圖定位內(nèi)存泄露會更快，因為它是按照類型全部平鋪開的，如果這個項目不是你負(fù)責(zé)的， 建議使用支配樹的方式， 因為支配樹包含了對象之間的引用關(guān)系(支配樹視圖可以展開查看內(nèi)部引用層級)

3> 我們以支配樹做比對， 在最下面一欄的"Navigation History (window → navigation history)"里(直方圖類似)找到在第2步打開的支配樹dominator tree圖標(biāo)， 右鍵添加到compare basket， 如下圖:


在這里插入圖片描述

4> 重復(fù)上面的2， 3步驟依次把其他的dump文件添加到"compare basket"欄， 然后點擊右上角的紅色感嘆號， 生成比較結(jié)果，如下圖：


在這里插入圖片描述

（注意比較的dump文件的順序，時間最早的在上面，可以通過右上角的上箭頭↑和下箭頭↓調(diào)整順序）

生成的比對結(jié)果如下：


在這里插入圖片描述

Shallow Heap一列后面的序號 #0， #1， #2 分別對應(yīng)：

第一個dump文件占用的shallow size， 第二個dump文件占用的shallow size ， 第三個dump文件占用的shallow size

Retained Heap #0， Retained Heap #1， Retained Heap #2 這3列分別對應(yīng)：

第一個dump文件占用的retained size， 第二個dump文件占用的retained size ， 第三個dump文件占用的retained size

紅框 圈出的是內(nèi)存連續(xù)增長的對象， 可以通過右邊紅框的retained heap看出內(nèi)存變大的趨勢

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

藍(lán)框 圈出的是內(nèi)存占用下降的對象

一般我們主要關(guān)注紅框標(biāo)出的對象， 因為這部分發(fā)生內(nèi)存泄露的嫌疑最大

這里先區(qū)分兩個概念:

Shallow Size

  • 對象自身占用的內(nèi)存大小，不包括它引用的對象。
  • 針對非數(shù)組類型的對象，它的大小就是對象與它所有的成員變量大小的總和。
  • 針對數(shù)組類型的對象，它的大小是數(shù)組元素對象的大小總和。

Retained Size

  • Retained Size=當(dāng)前對象大小+當(dāng)前對象可直接或間接引用到的對象的大小總和。(間接引用的含義：A->B->C， C就是間接引用)
  • Retained Size就是當(dāng)前對象被GC后，從Heap上總共能釋放掉的內(nèi)存。

因為這里我們比較的是支配樹， 所以按照retained heap倒序排列， 從左到右依次為: retained heap #0 → retained heap #1 → retained heap #2(以最后一個retained heap #2 倒序， 因為這個是最后一次dump的內(nèi)存快照， 這樣可以看出內(nèi)存泄露的增長趨勢)

2. 定位內(nèi)存泄露

基于上一步得出的比較結(jié)果， 可以看出"org.apache.tomcat.util.threads.TaskThread http-nio-8080-exec-*" 有內(nèi)存泄露的嫌疑， 查看它的引用關(guān)系:

在這里插入圖片描述

點擊"with outgoing references"后逐層展開第一個對象內(nèi)部的引用關(guān)系(以Retained Heap倒序，主要是看retained size排在前面的對象)， 如下：
在這里插入圖片描述

可以看到TaskThead內(nèi)部有一個threadLocal， threadLocal內(nèi)部有一個concurrentHashMap， 這個map里存的是我們的日志相關(guān)對象"com.*.framework.log.FieldAppendedValue"，從下面幾個map里的key可以確定是我們記錄到日志系統(tǒng)(ElasticSearch)的對象， 這些日志對象主要記錄調(diào)用接口的請求報文、響應(yīng)報文、SOA接口名稱等信息，如下圖：
在這里插入圖片描述

但為什么日志對象會占用這么多內(nèi)存？而且這里看到的只是其中一個taskThread里，繼續(xù)展開RESPONSE_CONTENT的val對象FieldAppendedValue內(nèi)部引用， 如下:
在這里插入圖片描述

發(fā)現(xiàn)FieldAppendedValue內(nèi)部維護了一個CopyOnWriteArrayList對象， 這個list里竟然存放了10674個值，正常來講不可能一次接口請求會有這么多的日志對象， 而且接口請求完記錄到ES后， 這部分內(nèi)存就應(yīng)該釋放了才對。

查看CopyOnWriteArrayList內(nèi)部存儲的內(nèi)容，如下：

在這里插入圖片描述

隨便打開10675個中的幾個FieldAppendedValue， 發(fā)現(xiàn)內(nèi)部存放的都是同一個接口的請求響應(yīng)報文，如下圖：
在這里插入圖片描述

可以右鍵copy→ value 把值復(fù)制出來查看, 接口報文如下：(響應(yīng)報文)

{
    "ResponseStatus": {
        "Timestamp": "/Date(1605583909438+0800)/",
        "Ack": "Success",
        "Errors": [],
        "Build": null,
        "Version": null,
        "Extension": []
    },
    "downloadUrl": "https://ii066.cn/hFGBEW"
}

從上面那張concurrentHashMap截圖(key : SOA_METHOD_NAME) 可知這個接口名是: getDownloadLink， 也就是說list里10675個日志對象存的都是"getDownloadLink"這個接口的報文。而且這只是其中一個TaskThead內(nèi)部情況， 加上全部20個對象， 20 * 10675 大概是213500個接口報文，如下圖：

在這里插入圖片描述

這個接口是什么鬼?


在這里插入圖片描述

3. 代碼分析

查看代碼得知這個接口并沒什么幺蛾子，只是當(dāng)時的開發(fā)同學(xué)在調(diào)用這個底層接口時新接入了我們部門封裝的SOA組件公共類：AbstractSimpleHandler.java(這個公共類主要是通過模板方法在調(diào)用接口時記錄報文日志埋點、超時時間設(shè)置、mock等功能)

這次出現(xiàn)OOM的這個Java項目之前調(diào)用soa接口是自己實現(xiàn)了一套公共方法(早于框架之前實現(xiàn))， 也就是說只有這一個接口使用了新的公共類AbstractSimpleHandler，其他的接口調(diào)用方式還是原來的方式。

新的工具類AbstractSimpleHandler記錄接口報文的代碼是通過調(diào)用ELKLogUtils.write()實現(xiàn)的， 這個方法的內(nèi)部大致邏輯如下：

Object value = HttpContext.get(BEHAVIOR_LOG);
        if (value == null) {
            value = new ConcurrentHashMap<>();
            HttpContext.add(BEHAVIOR_LOG, value);
        }

HttpContext內(nèi)部維護的是一個ThreadLocal：

public class HttpContext {

    private static final int CONTEXT_DEFAULT_SIZE = 1 << 6;

    private static final ThreadLocal<Map<String, Object>> CONTEXT = new ThreadLocal<Map<String, Object>>() {
        @Override
        protected Map<String, Object> initialValue() {
            return new ConcurrentHashMap<>(CONTEXT_DEFAULT_SIZE);
        }
    };

所有調(diào)用soa底層接口的報文日志都是通過ThreadLocal內(nèi)的map存儲的， 然后統(tǒng)一發(fā)送到ES日志系統(tǒng)。

我們都知道theadLocal是線程安全的， 但是一般我們的項目都是部署在Tomcat等web容器里， tomcat維護了一個http線程池， 就是前面截圖的那個TaskThead Http-nio*線程對象，每次前端app發(fā)起請求都會從tomcat的線程池里取一個線程處理前端的請求， 如果復(fù)用的是上一個線程， 那他內(nèi)部的threadLocal沒有清空， 還是會保存上次的報文信息，這樣的話這次請求又會繼續(xù)存放接口報文， 就會越積越多。。。

新接入的組件把接口報文存到threadLoacl的代碼是在AbstractSimpleHandler.java里的，而清除threadLoacl的代碼是在另外一個公共類BaseService.java里做的，也就是說要接入新的公共類除了AbstractSimpleHandler.java外，還要接入BaseService.java這個公共類!

這個也是有歷史原因的， 這個Java項目本身比較早， 那時候還沒有我們部門框架的SOA公共類， 所以自己實現(xiàn)了一套，后來使用新的框架組件調(diào)用接口的開發(fā)小伙伴沒有調(diào)研全面， 少接了一個公共類(BaseService)導(dǎo)致了這一問題發(fā)生。

所以這個問題的根因是threadllocal使用不當(dāng)引起的內(nèi)存泄露

弄清楚原因后就好辦了， 解決辦法是在請求完接口后主動調(diào)用下框架里的HttpContext.clear()， 清除下框架內(nèi)部的threadlocal.map即可，當(dāng)然后續(xù)還是要統(tǒng)一接口的調(diào)用方式， 不能兩套工具類并存。

4. 使用 Path To Gc Root 定位業(yè)務(wù)代碼

還有另外一個內(nèi)存泄露的嫌疑是"com.*.common.utils.ITextRendererPoolManager"， 如上面比對結(jié)果的圖：

在這里插入圖片描述

單獨在dominator tree支配樹視圖展開如圖所示：
在這里插入圖片描述

ITextRendererPoolManager內(nèi)部使用了apache的一個對象緩沖池， 目的可能是為了對象復(fù)用， 繼續(xù)展開，如下圖：
在這里插入圖片描述

發(fā)現(xiàn)是pdf的一個工具類：org.xhtmlrenderer.pdf.ITextRenderer， 這個開源的pdf工具是我們項目的郵件功能在發(fā)送附件的時候生成pdf文檔時引入的一個第三方j(luò)ar包，開始懷疑是否是這個開源的pdf工具導(dǎo)致的內(nèi)存泄露， 但是不清楚這個jar包是在哪里調(diào)用的？

這里可以通過"path to gc root"查看是誰在引用他， 即我們業(yè)務(wù)代碼調(diào)用的地方，如下圖：

在這里插入圖片描述

這里先說下"path to gc root"選項的含義：

  • with all references : 所有引用， 包括強引用， 弱引用， 軟引用， 虛引用
  • exclude weak reference : 排除弱引用
  • exclude soft reference : 排除軟引用
  • 。。。。

我們知道軟引用， 弱引用這些在發(fā)生full gc時可能會被回收掉(回收時機不同， 具體可自行百度)， 目的是不造成內(nèi)存溢出。 一般引起內(nèi)存溢出的都是強引用，所以你可以選擇"exclude all ptantom/weak/soft reference"只查看強引用。

但在這個案例中pdf.ITextRenderer是被軟引用引用的(從上圖中可以看出)， 雖然說軟引用不會導(dǎo)致溢出， 但可能會引起內(nèi)存一點點上升(軟引用只有在內(nèi)存不足發(fā)生GC時才會被回收)， 這個跟本地緩存還不一樣， 因為shareContext對象沒有達(dá)到復(fù)用的目的， 而且最重要的是它沒有失效機制，只要沒有達(dá)到堆最大值或發(fā)生full gc就會一直存在， 這樣的話會拖累JVM的性能，所以我選擇"with all references"查看所有類型引用：

在這里插入圖片描述

發(fā)現(xiàn)是被PdfUtil這個類引用， 查看代碼發(fā)現(xiàn)PdfUtil是我們自己封裝的一個pdf工具類， 這個工具類把創(chuàng)建pdf的ITextRenderer對象緩存到了iTextRendererPoolManager對象池里， 這樣下次就不需要再重新創(chuàng)建， 代碼大致如下:

try (ByteArrayOutputStream outputStream = new ByteArrayOutputStream()) {
            iTextRenderer = iTextRendererPoolManager.borrowObject();
            ......
            iTextRenderer.layout();
        } catch (Exception e) {
            LOGGER.error(e);      
        } finally {
            if (iTextRenderer != null) {
                iTextRendererPoolManager.returnObject(iTextRenderer);
            }
        }

但是在放回對象池前沒有對ITextRenderer里面的sharedContext屬性清空， 這樣的話下次從對象池里如果還是獲取到這個對象，就會對ITextRenderer內(nèi)部的屬性sharedContext繼續(xù)疊加。。。

查了下官方使用手冊發(fā)現(xiàn)沒有這樣的用法， 所以導(dǎo)致這個問題的原因應(yīng)該是我們使用的姿勢不對

解決方法一種是繼續(xù)使用對象池，但在放回對象池之前先清除下SharedContext， 或者簡單點不再用對象池，每次new一個， 因為是在方法內(nèi)部創(chuàng)建的局部變量， 不會逃逸出方法外， 方法調(diào)用完就自動釋放了。

三. 驗證結(jié)果

修復(fù)上述兩個問題后在測試環(huán)境驗證通過然后發(fā)布上線從12月10號一直截止到今天，大概18天里內(nèi)存再沒有泄露跡象， 堆外內(nèi)存(RSS-JVM內(nèi)存)也穩(wěn)定下來，如下圖：


在這里插入圖片描述

在這里插入圖片描述

在這里插入圖片描述

至此， 內(nèi)存泄露問題算是告一段落。

四. 總結(jié)

查看git提交記錄發(fā)現(xiàn)這個問題在線上存在有一段時間了(10月30號之前就有泄露跡象)，之前一直沒報出來主要是每周都有發(fā)版，發(fā)布肯定會重啟清空內(nèi)存，發(fā)布頻繁也就掩蓋了這個問題，所以這個問題其實是一直存在的

在這里插入圖片描述

但測試環(huán)境又很難重現(xiàn)出來，很少有應(yīng)用在測試環(huán)境壓測10天以上的，壓測頻率高了，接口容易熔斷。。。

而且有些泄露也不是"真正的泄露", 比如本地緩存的失效策略設(shè)置不合理、寫多讀少、內(nèi)存占用持續(xù)上升，直到觸發(fā)拋棄策略等。

其實下面的三種情況都屬于廣義上的內(nèi)存泄露：

  1. 仍然具有GC ROOT根引用但從未在應(yīng)用程序代碼中使用的對象。這也是傳統(tǒng)意義上的內(nèi)存泄漏
  2. 對象太多或太大。意味著沒有足夠的堆可用于執(zhí)行應(yīng)用程序，因為內(nèi)存中保存了太大的對象樹（例如緩存）
  3. 臨時對象太多。意味著Java代碼中的處理暫時需要太多內(nèi)存

第一種是大家都熟悉的內(nèi)存泄露，后兩種多半屬于寫代碼不規(guī)范，或業(yè)務(wù)流程上設(shè)計不合理或?qū)懘a時沒充分考慮緩存的使用場景，所以：

  • 寫代碼時要加強這方面的意識，包括review的人
  • 發(fā)布上線后要定時監(jiān)控，及早發(fā)現(xiàn)這類問題

五. MAT工具使用相關(guān)事項

使用mat前最好把初始化內(nèi)存設(shè)置大一點，因為一般生產(chǎn)環(huán)境的dump文件都比較大，mat內(nèi)存大小至少要cover住dump文件的大小，否則打開會報錯，配置文件如圖：


在這里插入圖片描述

比如下面堆內(nèi)存的最大(Xmx)最小(Xms)設(shè)置為4G(具體以你dump文件大小為準(zhǔn))：

-startup
plugins/org.eclipse.equinox.launcher_1.3.100.v20150511-1540.jar
--launcher.library
plugins/org.eclipse.equinox.launcher.win32.win32.x86_64_1.1.300.v20150602-1417
-vmargs
-Xms4g
-Xmx4g

另外最好設(shè)置下顯示單位, 以兆 M/G 為單位更便于理解，如圖：

在這里插入圖片描述

在這里插入圖片描述

文章來源：http://javakk.com/1196.html

最后編輯于 ：
?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請聯(lián)系作者
【社區(qū)內(nèi)容提示】社區(qū)部分內(nèi)容疑似由AI輔助生成，瀏覽時請結(jié)合常識與多方信息審慎甄別。
平臺聲明：文章內(nèi)容（如有圖片或視頻亦包括在內(nèi)）由作者上傳并發(fā)布，文章內(nèi)容僅代表作者本人觀點，簡書系信息發(fā)布平臺，僅提供信息存儲服務(wù)。

相關(guān)閱讀更多精彩內(nèi)容

友情鏈接更多精彩內(nèi)容