java内存泄漏-java内存泄漏实例

特色专栏

起源

前几天，团队安排值班轮流照顾我们的服务，主要是做一些告警邮件处理，bug排查，运营问题处理。 工作日还好，不管做什么，都得上班。 如果是周末，那么这一天就毁了。

不知道是因为公司网络不够广，还是网络运维团队不够强大。 网络总是有问题。 要么这里的交换机断开，要么那里的路由器坏了。 偶尔也会出现各种超时，我们对服务检测服务比较敏感。 总是能够准确把握偶尔出现的小问题，为精彩的作品添砖加瓦。 好几次，值班组的成员一起吐槽java内存泄漏，商量如何避开服务保活机制，偷偷停止检测服务不被发现（虽然不敢）。

前几天周末处理一个检测服务锅。

问题

网络问题？

晚上7点以后，开始不停的收到告警邮件，邮件显示检测到的几个接口都超时了。 大多数执行堆栈位于：

java.io.BufferedReader.readLine(BufferedReader.java:371)
java.io.BufferedReader.readLine(BufferReader.java:389)
java_io_BufferedReader$readLine.call(Unknown Source)
com.domain.detect.http.HttpClient.getResponse(HttpClient.groovy:122)
com.domain.detect.http.HttpClient.this$2$getResponse(HttpClient.groovy)

我在这个线程堆栈中看到了很多错误。 我们设置的HTTP DNS超时为1s，连接超时为2s，读取超时为3s。 这种错误是因为检测服务正常发送HTTP请求，服务器也在正常处理请求。 之后正常响应，但是数据包在网络层的转发中丢失了，所以请求线程的执行栈会停留在获取接口响应的地方。 这种情况的一个典型特征是可以在服务器上找到相应的日志记录。 并且日志将显示服务器响应非常好。 与之相对的是，线程栈停留在Socket connect处，连接建立时就失败了，服务端完全没有察觉。

我注意到其中一个接口更频繁地报告错误。 这个接口需要上传一个4M的文件到服务器，然后经过一系列的业务逻辑处理，返回2M的文本数据，而其他接口都是简单的业务逻辑，我猜测可能是需要上传的数据太多并下载，所以超时导致丢包的概率也更大。

根据这个推测，团伙登上服务器，利用请求的request_id在最近的服务日志中查找。 果然是网络丢包问题导致的接口超时。

这样领导当然不会满意，这个结论还得有人接手。 于是赶紧联系运维和网络团队，确认了当时的网络状况。 网络组同学回复说我们检测服务所在机房的交换机比较老旧，存在未知的转发瓶颈，正在优化中。

问题爆发

本以为这次值班会有这么小的波澜，没想到晚上八点左右，各种界面的报警邮件蜂拥而至，准备收拾周日单曲的我猝不及防休息。

这个时候几乎所有的接口都超时了，而我们这个网络I/O量大的接口每次检测都要超时。 难道是整个机房都出了问题？

再次通过服务器和监控看到，各个接口的指标都是正常的。 我测试了接口，完全OK。 由于不影响在线服务，我打算通过检测服务的接口停止检测任务，然后慢慢查看。

结果我向接口发送了暂停检测任务的请求，很久没有响应。 我这才知道，事情并没有那么简单。

解决

内存泄漏

于是赶紧登陆检测服务器，首先top free df 3次，发现有些异常。

我们的探测过程的 CPU 使用率特别高，高达 900%。

我们的 Java 进程不会做大量的 CPU 计算。 正常情况下，CPU占用率应该在100%到200%之间。 如果这个 CPU 飙升，它要么进入死循环，要么进行大量 GC。

使用jstat -gc pid [interval]命令查看java进程的GC状态。 果然FULL GC达到了每秒一次。

这么多FULL GC，应该是内存泄漏没有运行java内存泄漏，所以使用jstack pid > jstack.log保存线程栈场景，使用jmap -dump:format=b,file=heap.log pid保存堆场景，然后重启 检测服务被禁用，报警邮件终于停止了。

统计数据

jstat是一个非常强大的JVM监控工具，一般用法是：jstat [-options] pid interval

它支持的查看项目有：

使用它对于定位JVM内存问题很有帮助。

疑难解答

问题虽然解决了，但是为了防止再次发生，还是要找出根本原因。

分析栈

栈的分析很简单，看是不是线程数太多，大部分栈都在干什么。

> grep 'java.lang.Thread.State' jstack.log | wc -l
> 464

只有400多个线程，没有异常。

> grep -A 1 'java.lang.Thread.State' jstack.log | grep -v 'java.lang.Thread.State' | sort | uniq -c |sort -n
 10 at java.lang.Class.forName0(Native Method)
 10 at java.lang.Object.wait(Native Method)
 16 at java.lang.ClassLoader.loadClass(ClassLoader.java:404)
 44 at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)

 344 at sun.misc.Unsafe.park(Native Method)

线程状态貌似正常，再分析堆文件。

下载堆转储文件。

堆文件都是二进制数据，在命令行查看非常麻烦。 Java提供的工具都是可视化的，在linux服务器上是看不到的，所以要先把文件下载到本地。

由于我们设置的堆内存是4G，所以dump出来的堆文件也很大。 下载下来确实很麻烦，不过我们可以先压缩一下。

gzip 是一个非常强大的压缩命令。 具体来说，我们可以设置-1~-9来指定它的压缩级别。 数据越大，压缩比越大，耗时越长。 推荐使用-6~7，-9真的太慢了​​，好处也不大。 有了这个压缩时间，就会下载额外的文件。

使用MAT分析jvm堆

MAT 是分析 Java 堆内存的强大工具。 用它打开我们的堆文件（将文件后缀改为.hprof），它会提示我们分析的类型。 本次分析，果断选择内存泄漏嫌疑。

从上面的饼图可以看出，大部分堆内存都被同一个内存占用了。 然后查看堆内存的细节，向上层追溯，很快就找到了罪魁祸首。

分析代码

找到内存泄漏的对象，在项目中全局搜索对象名，是一个Bean对象，然后定位到它的Map类型的属性。

这个Map使用ArrayList按照类型存储各个检测接口的响应结果。 每次检测后，塞入ArrayList中进行分析。 由于Bean对象不会被回收，而且这个属性也没有清除逻辑，所以十多天没有使用了。 在上线重启的情况下，Map会越来越大，直到占满内存。

内存满后，无法再为HTTP响应结果分配内存，所以一直卡在readLine。 而我们这个I/O比较多的接口，告警次数特别多，估计跟响应大需要更多的内存有关。

向代码所有者提了一个 PR，问题得到了圆满解决。

概括

其实我还是要反省一下自己。 一开始在报警邮件中有这样一个线程栈：

groovy.json.internal.JsonParserCharArray.decodeValueInternal(JsonParserCharArray.java:166)
groovy.json.internal.JsonParserCharArray.decodeJsonObject(JsonParserCharArray.java:132)
groovy.json.internal.JsonParserCharArray.decodeValueInternal(JsonParserCharArray.java:186)
groovy.json.internal.JsonParserCharArray.decodeJsonObject(JsonParserCharArray.java:132)
groovy.json.internal.JsonParserCharArray.decodeValueInternal(JsonParserCharArray.java:186)

看到这种错误的线程栈，没想仔细。 要知道TCP可以保证报文的完整性，直到收到报文才会给变量赋值。 这显然是一个内部错误。 检查可以提前发现问题，检查问题真的很糟糕。