天天看点

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

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 找到“内存堆积点”

点击工具栏图标 

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

 (

Open Dominator Tree for entire heap.

),打开 Dominator Tree。dominator 直译为“主宰者”,在这里的意思就是占用内存最多的对象。

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

在上面的图里我们可以看到各个对象,格式是 类名 @ 对象地址 ,而且是按 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

):

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

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

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

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

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

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:

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

上图中可以看到第一行就是 

http-nio-7001-exec-10

 线程。双击展开该线程的堆栈,接下来就要重点观察那些我们自己写的类里的方法,这里需要凭借一些对自己代码的熟悉度和经验了。我们可以看到堆栈中有调用到 

logwire.web.controller.ActionController.requerySelectRows

 方法,这是在 选中全部 后再点击操作按钮后会调用到的方法:

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

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

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

logwire.web.controller.ActionController.doAction

 方法:

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

这个方法里有两个 

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

 持有的。

为了快速找到该对象,可以点击工具栏图标 

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

 (

Create a histogram from an arbitrary set of objects.

) ,打开 Histogram。Histogram 展示了每一种 Java 类有多少个实例,总共占了多少内存。

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

这里类实在太多了,我们要过滤一下,快速找到想要的类。在 

Class Name

 列的正则表达式过滤器中输入 

ThreadLocalSecurityContextHolderStrategy

 并回车(回车后会自动在前后加上 

.*

,表示前后还可以有任意多个字符),这样就找到了那个类:

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

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

List objects

 → 

with outgoing references

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

可以看到该类只有一个实例对象,展开以后看到了这个类的静态变量 

contextHolder

,是一个 

java.lang.ThreadLocal @ 0x6a6fcc3c8

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

找到这个线程本地变量 (

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

,找到所有引用了该对象的对象:

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

我们看到除了 

contextHolder

 以外,还有很多线程的 

ThreadLocal.ThreadLocalMap

 引用了该对象,这表示很多线程中都有该线程执行时的用户:

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

然后要干点体力活儿了,逐个展开后,我们最终找到了 

http-nio-7001-exec-10

 线程:

Java 堆内存泄漏分析的一个例子
笔者觉得应该可以利用 OQL 功能(类似于 SQL 语法,在内存分析中做各种查询),更快速地找到 

http-nio-7001-exec-10

 线程对应的用户。但是暂时没花精力去详细研究,以后有时间再补充。

在上面的图中,我们看到左边 Attributes 列表中,

value

 属性的值是一个 

org.springframework.security.core.context.SecurityContextImpl @ 0x6cd141978

 对象。右键点击该对象,在弹出菜单中点击 

List objects

 → 

with outgoing references

,再展开:

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

最终就看到了该线程的执行用户的 

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

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

在第二个 dump 文件也做同样的操作。于是在 

Compare Basket

 中可以看到有两个待比较对象。接着再点击 

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

 (

Compare the results

)

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

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

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

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

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

  • 关于 Shallow Heap、Retained Heap、GC Root 的解释: https://blog.csdn.net/hhww0101/article/details/8133219