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

一. 背景

11月10號(hào)晚上8點(diǎn)收到報(bào)警郵件，一看是OOM

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

如果你對(duì)項(xiàng)目代碼比較熟悉， 通過(guò)直方圖定位內(nèi)存泄露會(huì)更快，因?yàn)樗前凑疹愋腿科戒侀_的，如果這個(gè)項(xiàng)目不是你負(fù)責(zé)的， 建議使用支配樹的方式， 因?yàn)橹錁浒藢?duì)象之間的引用關(guān)系(支配樹視圖可以展開查看內(nèi)部引用層級(jí))

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

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

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

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

（可以放大查看）

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

第一個(gè)dump文件占用的shallow size， 第二個(gè)dump文件占用的shallow size ， 第三個(gè)dump文件占用的shallow size

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

第一個(gè)dump文件占用的retained size， 第二個(gè)dump文件占用的retained size ， 第三個(gè)dump文件占用的retained size

通過(guò)Retained Heap的變化趨勢(shì)可以看出：

• 紅框 圈出的是內(nèi)存連續(xù)增長(zhǎng)的對(duì)象， 可以通過(guò)右邊紅框的retained heap看出內(nèi)存變大的趨勢(shì)

• 綠框 圈出的是沒(méi)有變化的對(duì)象(至少在這3次比較中沒(méi)有變化)

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

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

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

Shallow Size

• 對(duì)象自身占用的內(nèi)存大小，不包括它引用的對(duì)象。
  

• 針對(duì)非數(shù)組類型的對(duì)象，它的大小就是對(duì)象與它所有的成員變量大小的總和。

• 針對(duì)數(shù)組類型的對(duì)象，它的大小是數(shù)組元素對(duì)象的大小總和。

Retained Size

• Retained Size=當(dāng)前對(duì)象大小+當(dāng)前對(duì)象可直接或間接引用到的對(duì)象的大小總和。(間接引用的含義：A->B->C， C就是間接引用)
  

• Retained Size就是當(dāng)前對(duì)象被GC后，從Heap上總共能釋放掉的內(nèi)存。

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

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

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

點(diǎn)擊"with outgoing references"后逐層展開第一個(gè)對(duì)象內(nèi)部的引用關(guān)系(以Retained Heap倒序，主要是看retained size排在前面的對(duì)象)， 如下：

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

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

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

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

隨便打開10675個(gè)中的幾個(gè)FieldAppendedValue， 發(fā)現(xiàn)內(nèi)部存放的都是同一個(gè)接口的請(qǐng)求響應(yīng)報(bào)文，如下圖：

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

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

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

這個(gè)接口是什么鬼?

3. 代碼分析

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

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

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

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

HttpContext內(nèi)部維護(hù)的是一個(gè)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底層接口的報(bào)文日志都是通過(guò)ThreadLocal內(nèi)的map存儲(chǔ)的， 然后統(tǒng)一發(fā)送到ES日志系統(tǒng)。

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

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

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

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

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

4. 使用 path to gc root 定位業(yè)務(wù)代碼

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

單獨(dú)在dominator tree支配樹視圖展開如圖所示：

ITextRendererPoolManager內(nèi)部使用了apache的一個(gè)對(duì)象緩沖池， 目的可能是為了對(duì)象復(fù)用， 繼續(xù)展開，如下圖：

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

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

這里先說(shuō)下"path to gc root"選項(xiàng)的含義：

• with all references : 所有引用， 包括強(qiáng)引用， 弱引用， 軟引用， 虛引用

• exclude weak reference : 排除弱引用

• exclude soft reference : 排除軟引用

• 。。。。

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

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

發(fā)現(xiàn)是被PdfUtil這個(gè)類引用， 查看代碼發(fā)現(xiàn)PdfUtil是我們自己封裝的一個(gè)pdf工具類， 這個(gè)工具類把創(chuàng)建pdf的ITextRenderer對(duì)象緩存到了iTextRendererPoolManager對(duì)象池里， 這樣下次就不需要再重新創(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);
            }
        }

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

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

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

三. 驗(yàn)證結(jié)果

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

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

四. 總結(jié)

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

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

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

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

1. 仍然具有GC ROOT根引用但從未在應(yīng)用程序代碼中使用的對(duì)象。這也是傳統(tǒng)意義上的內(nèi)存泄漏

2. 對(duì)象太多或太大。意味著沒(méi)有足夠的堆可用于執(zhí)行應(yīng)用程序，因?yàn)閮?nèi)存中保存了太大的對(duì)象樹（例如緩存）

3. 臨時(shí)對(duì)象太多。意味著Java代碼中的處理暫時(shí)需要太多內(nèi)存

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

• 寫代碼時(shí)要加強(qiáng)這方面的意識(shí)，包括review的人

• 發(fā)布上線后要定時(shí)監(jiān)控，及早發(fā)現(xiàn)這類問(wèn)題

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

使用mat前最好把初始化內(nèi)存設(shè)置大一點(diǎn)，因?yàn)橐话闵a(chǎn)環(huán)境的dump文件都比較大，mat內(nèi)存大小至少要cover住dump文件的大小，否則打開會(huì)報(bào)錯(cuò)，配置文件如圖：

比如下面堆內(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 為單位更便于理解，如圖：

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