写点什么

如何使用 Eclipse 内存分析工具定位内存泄露

用户头像
AI乔治
关注
发布于: 2021 年 01 月 07 日
如何使用Eclipse内存分析工具定位内存泄露

本文以我司生产环境 Java 应用内存泄露为案例进行分析,讲解如何使用 Eclipse 的 MAT 分析定位问题

背景

11 月 10 号晚上 8 点收到报警邮件,一看是 OOM

打开公司监控系统查看应用各项指标发现 JVM 中老年代在持续增长(从上次发布 10 月 30 号到 11 月 10 号的 12 天内一直在增长, 存在内存泄露迹象)



从图中可以看出, 从 10 月 30 号发布到 11 月 10 号 oom 期间 11 天老年代一直在缓慢上涨, 虽然有下降, 但整体趋势是上升的,平均每天泄露约 50M 内存, 说明每次都无法完全释放干净

因为生产环境的 JVM 添加了 -XX:+HeapDumpOnOutOfMemoryError 参数,该配置会把 dump 文件的快照保存下来供后续分析排查问题,也可以使用 jmap 或 jcmd 等 jvm 命令进行 dump:

jmap -dump:format=b,file=文件名 [pid]jcmd pid GC.heap_dump 文件路径
复制代码

分析内存泄露

内存泄露和内存溢出的区别:内存泄露从老年代的增长情况看是缓慢上升的, 最终达到老年代上限才会导致溢出,有些内存泄露可能需要很长的时间发生, 所以说内存泄露更隐蔽, 不像内存溢出那样容易暴露(内存溢出直接抛出 OOM), 而且内存长时间得不到释放会导致服务性能越来越差、gc 时间变长、响应变慢:



从图中可以看出在 12 天里每天大概泄露(增长) 50M 左右, 这种情况下定位泄露原因需要多次 dump 采集样本, 然后和上次的比较分析, 即需要多个 dump 文件进行比较分析才能精确定位问题。 否则很难看出具体泄露的点, 加上 dump 文件中大部分是正常的内存使用, 会干扰问题的定位, 增加排查难度。

所以当时的做法是每天固定时间 dump 一次, 采集足够多的样本, 如下图:



另外测试环境不好重现的主要原因是不清楚是哪个接口调用引起的, 这个 Java 服务有多个暴露的 api, 而且测试环境不方便压测,压测量大了, 底层接口熔断, 压测量小看不出泄露迹象, 所以得从 dump 分析入手, 找到问题所在再去测试环境验证。

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

把下载到本地的多个 dump 文件用 mat 依次打开(“File → Open Heap Dump”), 如下图:



比如我们要分析这 3 个 dump 文件(当然你也可以分析更多个, 这样会更精准), 打开后, 使用 compare basket 功能找出内存泄露的差异点:

使用 compare basket 功能分析内存泄露

1> 菜单栏 window → compare basket ,打开比较窗口(如果最下面一栏已经有 compare basket 则这步不需要),如下图:



2> 依次打开 3 个 dump 的 dashboard 面板, 在下方的 Actions 一栏点击"histogram"或"dominator tree"生成对应的直方图或支配树列表,如下图:



直方图或支配树都可以列出堆中存活的所有对象,但二者的维度不同, 直方图按照类型统计, 支配树是以对象维度统计。

如果你对项目代码比较熟悉, 通过直方图定位内存泄露会更快,因为它是按照类型全部平铺开的,如果这个项目不是你负责的, 建议使用支配树的方式, 因为支配树包含了对象之间的引用关系(支配树视图可以展开查看内部引用层级)

3> 我们以支配树做比对, 在最下面一栏的"Navigation History (window → navigation history)"里(直方图类似)找到在第 2 步打开的支配树 dominator tree 图标, 右键添加到 compare basket, 如下图:



4> 重复上面的 2, 3 步骤依次把其他的 dump 文件添加到"compare basket"栏, 然后点击右上角的红色感叹号, 生成比较结果,如下图:



(注意比较的 dump 文件的顺序,时间最早的在上面,可以通过右上角的上箭头↑和下箭头↓调整顺序)

生成的比对结果如下:



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->B->C, C 就是间接引用)

  • Retained Size 就是当前对象被 GC 后,从 Heap 上总共能释放掉的内存。

因为这里我们比较的是支配树, 所以按照 retained heap 倒序排列, 从左到右依次为: retained heap #0 → retained heap #1 → retained heap #2(以最后一个 retained heap #2 倒序, 因为这个是最后一次 dump 的内存快照, 这样可以看出内存泄露的增长趋势)

定位内存泄露

基于上一步得出的比较结果, 可以看出"org.apache.tomcat.util.threads.TaskThread http-nio-8080-exec-*" 有内存泄露的嫌疑, 查看它的引用关系:



点击"with outgoing references"后逐层展开第一个对象内部的引用关系(以 Retained Heap 倒序,主要是看 retained size 排在前面的对象), 如下:



可以看到 TaskThead 内部有一个threadLocal, threadLocal 内部有一个concurrentHashMap,这个 map 里存的是我们的日志相关对象"com.*.framework.log.FieldAppendedValue",从下面几个 map 里的 key 可以确定是我们记录到日志系统(ElasticSearch)的对象, 这些日志对象主要记录调用接口的请求报文、响应报文、SOA 接口名称等信息,如下图:



但为什么日志对象会占用这么多内存?而且这里看到的只是其中一个 taskThread 里,继续展开 RESPONSE_CONTENT 的 val 对象 FieldAppendedValue 内部引用, 如下:



发现FieldAppendedValue内部维护了一个CopyOnWriteArrayList对象, 这个 list 里竟然存放了 10674 个值,正常来讲不可能一次接口请求会有这么多的日志对象, 而且接口请求完记录到 ES 后, 这部分内存就应该释放了才对。

查看 CopyOnWriteArrayList 内部存储的内容,如下:



随便打开 10675 个中的几个FieldAppendedValue, 发现内部存放的都是同一个接口的请求响应报文,如下图:



可以右键 copy→ value 把值复制出来查看, 接口报文如下:(响应报文)

{    "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 内部情况, 加上全部 20 个对象, 20 * 10675 大概是 213500 个接口报文,如下图:



这个接口是什么鬼?



代码分析

查看代码得知这个接口并没什么幺蛾子,只是当时的开发同学在调用这个底层接口时新接入了我们部门封装的 SOA 组件公共类:AbstractSimpleHandler.java(这个公共类主要是通过模板方法在调用接口时记录报文日志埋点、超时时间设置、mock 等功能)

这次出现 OOM 的这个 Java 项目之前调用 soa 接口是自己实现了一套公共方法(早于框架之前实现), 也就是说只有这一个接口使用了新的公共类AbstractSimpleHandler,其他的接口调用方式还是原来的方式。

新的工具类AbstractSimpleHandler记录接口报文的代码是通过调用ELKLogUtils.write()实现的, 这个方法的内部大致逻辑如下:

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

HttpContext内部维护的是一个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); } };

复制代码

所有调用 soa 底层接口的报文日志都是通过 ThreadLocal 内的 map 存储的, 然后统一发送到 ES 日志系统。

我们都知道 theadLocal 是线程安全的, 但是一般我们的项目都是部署在 Tomcat 等 web 容器里, tomcat 维护了一个 http 线程池, 就是前面截图的那个 TaskThead Http-nio*线程对象,每次前端 app 发起请求都会从 tomcat 的线程池里取一个线程处理前端的请求, 如果复用的是上一个线程, 那他内部的 threadLocal 没有清空, 还是会保存上次的报文信息,这样的话这次请求又会继续存放接口报文, 就会越积越多。。。

新接入的组件把接口报文存到threadLoacl的代码是在AbstractSimpleHandler.java里的,而清除 threadLoacl 的代码是在另外一个公共类BaseService.java里做的,也就是说要接入新的公共类除了AbstractSimpleHandler.java外,还要接入BaseService.java 这个公共类!

这个也是有历史原因的, 这个 Java 项目本身比较早, 那时候还没有我们部门框架的 SOA 公共类, 所以自己实现了一套,后来使用新的框架组件调用接口的开发小伙伴没有调研全面, 少接了一个公共类(BaseService)导致了这一问题发生。

所以这个问题的根因是 threadllocal 使用不当引起的内存泄露

弄清楚原因后就好办了, 解决办法是在请求完接口后主动调用下框架里的 HttpContext.clear(), 清除下框架内部的 threadlocal.map 即可,当然后续还是要统一接口的调用方式, 不能两套工具类并存。

使用 path to gc root 定位业务代码

还有另外一个内存泄露的嫌疑是"com.*.common.utils.ITextRendererPoolManager", 如上面比对结果的图:



单独在 dominator tree 支配树视图展开如图所示:



ITextRendererPoolManager内部使用了 apache 的一个对象缓冲池, 目的可能是为了对象复用, 继续展开,如下图:



发现是 pdf 的一个工具类:org.xhtmlrenderer.pdf.ITextRenderer, 这个开源的 pdf 工具是我们项目的邮件功能在发送附件的时候生成 pdf 文档时引入的一个第三方 jar 包,开始怀疑是否是这个开源的 pdf 工具导致的内存泄露, 但是不清楚这个 jar 包是在哪里调用的?

这里可以通过"path to gc root"查看是谁在引用他, 即我们业务代码调用的地方,如下图:



这里先说下"path to gc root"选项的含义:

  • with all references : 所有引用, 包括强引用, 弱引用, 软引用, 虚引用

  • exclude weak reference : 排除弱引用

  • exclude soft reference : 排除软引用

  • 。。。。

我们知道软引用, 弱引用这些在发生 full gc 时可能会被回收掉(回收时机不同, 具体可自行百度), 目的是不造成内存溢出。一般引起内存溢出的都是强引用,所以你可以选择"exclude all ptantom/weak/soft reference"只查看强引用。

但在这个案例中pdf.ITextRenderer是被软引用引用的(从上图中可以看出), 虽然说软引用不会导致溢出, 但可能会引起内存一点点上升(软引用只有在内存不足发生 GC 时才会被回收), 这个跟本地缓存还不一样, 因为shareContext对象没有达到复用的目的, 而且最重要的是它没有失效机制,只要没有达到堆最大值或发生 full gc 就会一直存在, 这样的话会拖累 JVM 的性能,所以我选择"with all references"查看所有类型引用:



发现是被 PdfUtil 这个类引用, 查看代码发现 PdfUtil 是我们自己封装的一个 pdf 工具类, 这个工具类把创建 pdf 的 ITextRenderer 对象缓存到了 iTextRendererPoolManager 对象池里, 这样下次就不需要再重新创建, 代码大致如下:

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 内部的属性 sharedContext 继续叠加。。。

查了下官方使用手册发现没有这样的用法, 所以导致这个问题的原因应该是我们使用的姿势不对

解决方法一种是继续使用对象池,但在放回对象池之前先清除下 SharedContext, 或者简单点不再用对象池,每次 new 一个, 因为是在方法内部创建的局部变量, 不会逃逸出方法外, 方法调用完就自动释放了。

验证结果

修复上述两个问题后在测试环境验证通过然后发布上线从 12 月 10 号一直截止到今天,大概 18 天里内存再没有泄露迹象, 堆外内存(RSS-JVM 内存)也稳定下来,如下图:





至此, 内存泄露问题算是告一段落。

总结

查看 git 提交记录发现这个问题在线上存在有一段时间了(10 月 30 号之前就有泄露迹象),之前一直没报出来主要是每周都有发版,发布肯定会重启清空内存,发布频繁也就掩盖了这个问题,所以这个问题其实是一直存在的



但测试环境又很难重现出来,很少有应用在测试环境压测 10 天以上的,压测频率高了,接口容易熔断。。。

而且有些泄露也不是"真正的泄露", 比如本地缓存的失效策略设置不合理、写多读少、内存占用持续上升,直到触发抛弃策略等。

其实下面的三种情况都属于广义上的内存泄露:

  1. 仍然具有 GC ROOT 根引用但从未在应用程序代码中使用的对象。这也是传统意义上的内存泄漏

  2. 对象太多或太大。意味着没有足够的堆可用于执行应用程序,因为内存中保存了太大的对象树(例如缓存)

  3. 临时对象太多。意味着 Java 代码中的处理暂时需要太多内存

第一种是大家都熟悉的内存泄露,后两种多半属于写代码不规范,或业务流程上设计不合理或写代码时没充分考虑缓存的使用场景,所以:

  • 写代码时要加强这方面的意识,包括 review 的人

  • 发布上线后要定时监控,及早发现这类问题

MAT 工具使用相关事项

使用 mat 前最好把初始化内存设置大一点,因为一般生产环境的 dump 文件都比较大,mat 内存大小至少要 cover 住 dump 文件的大小,否则打开会报错,配置文件如图:



比如下面堆内存的最大(Xmx)最小(Xms)设置为 4G(具体以你 dump 文件大小为准):

-startupplugins/org.eclipse.equinox.launcher_1.3.100.v20150511-1540.jar--launcher.libraryplugins/org.eclipse.equinox.launcher.win32.win32.x86_64_1.1.300.v20150602-1417-vmargs-Xms4g-Xmx4g
复制代码

另外最好设置下显示单位, 以兆 M 或 G 为单位更便于理解,如图:




如果你想学好 JAVA 这门技术,也想在 IT 行业拿高薪,可以进来看看 ,群里有:Java 工程化、高性能及分布式、高性能、深入浅出。高架构。性能调优、Spring,MyBatis,Netty 源码分析和大数据等多个知识点。



如果你想拿高薪的,想学习的,想就业前景好的,想跟别人竞争能取得优势的,想进阿里面试但担心面试不过的,你都可以来,加 V:psk12221 (小白和广告勿扰)


看完三件事❤️

如果你觉得这篇内容对你还蛮有帮助,我想邀请你帮我三个小忙:

  1. 点赞,转发,有你们的 『点赞和评论』,才是我创造的动力。

  2. 关注公众号 『 java 烂猪皮 』,不定期分享原创知识。

  3. 同时可以期待后续文章 ing🚀


本文来自公众号:Java 老 K,互联网一线 java 开发老兵,工作 10 年有余,梦想敲一辈子代码,以梦为码,不负韶华。


用户头像

AI乔治

关注

分享后端技术干货。公众号【 Java烂猪皮】 2019.06.30 加入

一名默默无闻的扫地僧!

评论

发布
暂无评论
如何使用Eclipse内存分析工具定位内存泄露