Java 堆内存泄漏分析的一个例子

7 篇文章 0 订阅

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
 

live 的作用是只 dump live objects,其实就是先做一次 Full GC(完整垃圾收集),然后再把内存 dump 出来。用这个参数的好处是可以清理掉内存中一些已经可以回收,但还没被回收的对象,避免对我们后续的分析造成干扰。

jmap 命令官方文档: 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 找到“内存堆积点”

点击工具栏图标 images\analyzing java heapdump\dominator tree icon (Open Dominator Tree for entire heap.),打开 Dominator Tree。dominator 直译为“主宰者”,在这里的意思就是占用内存最多的对象。

images\analyzing java heapdump\dominator

在上面的图里我们可以看到各个对象,格式是 类名 @ 对象地址 ,而且是按 Retained Heap 从大到小排序的。

 

Dominator Tree 各列含义

  • Shallow Heap:对象本身占用的内存大小,不包含其引用的对象所占的内存大小。

    比如有一个 Student 对象,其成员变量有 String name 和 int age。那么 age 这个整数占 4 个字节,是算在 Student 对象的 Shallow Heap 里的。但是 name 是个字符串,Student 对象只是引用了该字符串,那么不管 name 有多长,都是不算在 Student 对象的 Shallow Heap 里的。

  • Retained Heap:对象本身以及对象直接或间接引用的其他对象占用内存大小的总和。

    以上面的例子来讲,Student 对象的 Retained Heap 就包含了该对象本身的大小加上 name 的大小。

    更准确的说法是如果对象被垃圾回收,总共能释放出的内存大小。

  • Percentage:对象 Retained Heap 在总内存中占的比例。

详细解释请查阅 Eclipse Memory Analyzer 自带的 Help Contents。

对我们来说,要观察的就是 Retained Heap。哪个对象的 Retained Heap 大,就说明由于它的存在,这么多内存都释放不掉,那么这个对象就可能是内存泄漏的点。

为了更好地说明,我们先不看排名第一的 org.apache.tomcat.util.threads.TaskThread @ 0x6ab74a1a0,而来看排名第二的 com.mysql.cj.jdbc.result.ResultSetImpl @ 0x6a0fe1a40

双击该对象展开其子树,展开几层后,可以看到 Retained Heap 有一个断崖式的降低(从 914677440 一下子降到了 3600):

images\analyzing java heapdump\accumulation point

这个突然降低的位置称为“内存堆积点” (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

images\analyzing java heapdump\click path to gc roots

可以看到该对象到 GC Root 的各条路径:

images\analyzing java heapdump\path2gc

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:

images\analyzing java heapdump\thread over view 2

上图中可以看到第一行就是 http-nio-7001-exec-10 线程。双击展开该线程的堆栈,接下来就要重点观察那些我们自己写的类里的方法,这里需要凭借一些对自己代码的熟悉度和经验了。我们可以看到堆栈中有调用到 logwire.web.controller.ActionController.requerySelectRows 方法,这是在 选中全部 后再点击操作按钮后会调用到的方法:

images\analyzing java heapdump\requerySelectRows

猜测可能是根据条件查询到的数据量太大了,导致内存被用完。

然后我们再看看到底是在哪个界面功能里执行了该方法?继续往下找,可以看到 logwire.web.controller.ActionController.doAction 方法:

images\analyzing java heapdump\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 持有的。

为了快速找到该对象,可以点击工具栏图标 images\analyzing java heapdump\histogram icon (Create a histogram from an arbitrary set of objects.) ,打开 Histogram。Histogram 展示了每一种 Java 类有多少个实例,总共占了多少内存。

images\analyzing java heapdump\histogram

这里类实在太多了,我们要过滤一下,快速找到想要的类。在 Class Name 列的正则表达式过滤器中输入 ThreadLocalSecurityContextHolderStrategy 并回车(回车后会自动在前后加上 .*,表示前后还可以有任意多个字符),这样就找到了那个类:

images\analyzing java heapdump\histogram filtered

但这只是类,而不是实例对象。我们需要列出该类的所有实例对象。右键点击该类后,在弹出菜单中点击 List objects → with outgoing references

images\analyzing java heapdump\list objects of tlschs

可以看到该类只有一个实例对象,展开以后看到了这个类的静态变量 contextHolder,是一个 java.lang.ThreadLocal @ 0x6a6fcc3c8

images\analyzing java heapdump\contextHolder

找到这个线程本地变量 (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,找到所有引用了该对象的对象:

images\analyzing java heapdump\contextHolder incoming references

我们看到除了 contextHolder 以外,还有很多线程的 ThreadLocal.ThreadLocalMap 引用了该对象,这表示很多线程中都有该线程执行时的用户:

images\analyzing java heapdump\ThreadLocalMaps

然后要干点体力活儿了,逐个展开后,我们最终找到了 http-nio-7001-exec-10 线程:

images\analyzing java heapdump\ThreadLocalMap of exec 10

 笔者觉得应该可以利用 OQL 功能(类似于 SQL 语法,在内存分析中做各种查询),更快速地找到 http-nio-7001-exec-10 线程对应的用户。但是暂时没花精力去详细研究,以后有时间再补充。

在上面的图中,我们看到左边 Attributes 列表中,value 属性的值是一个 org.springframework.security.core.context.SecurityContextImpl @ 0x6cd141978 对象。右键点击该对象,在弹出菜单中点击 List objects → with outgoing references,再展开:

images\analyzing java heapdump\username

最终就看到了该线程的执行用户的 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

images\analyzing java heapdump\add to compare basket

在第二个 dump 文件也做同样的操作。于是在 Compare Basket 中可以看到有两个待比较对象。接着再点击 images\analyzing java heapdump\icon compare (Compare the results)

images\analyzing java heapdump\compare basket

这样就可以看到比较结果:

images\analyzing java heapdump\compared tables

有时候可以看到某个类型的实例数量以及内存一直在增长,那么就可能是内存泄漏点。

方法体内定义的局部变量,不一定能在 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 解释得很详细了。但如果阅读英文比较慢的话,也可以看一些中文资料:

  • 6
    点赞
  • 20
    收藏
    觉得还不错? 一键收藏
  • 2
    评论

“相关推荐”对你有帮助么?

  • 非常没帮助
  • 没帮助
  • 一般
  • 有帮助
  • 非常有帮助
提交
评论 2
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值