一次 Java 内存泄漏的排查

朴灿烈づ我的快乐病毒、 2022-01-16 05:41 316阅读 0赞

[2019独角兽企业重金招聘Python工程师标准>>> ][2019_Python_] ![hot3.png][]

**一、由来**

前些日子小组内安排值班，轮流看顾我们的服务，主要做一些报警邮件处理、Bug 排查、运营 issue 处理的事。工作日还好，无论干什么都要上班的，若是轮到周末，那这一天算是毁了。

不知道是公司网络广了就这样还是网络运维组不给力，网络总有问题，不是这边交换机脱网了就是那边路由器坏了，还偶发地各种超时，而我们灵敏地服务探测服务总能准确地抓住偶现的小问题，给美好的工作加点料。好几次值班组的小伙伴们一起吐槽，商量着怎么避过服务保活机制，偷偷停了探测服务而不让人发现（虽然也并不敢）。

前些天我就在周末处理了一次探测服务的锅。

**二、问题**

**1、网络问题？**

晚上七点多开始，我就开始不停地收到报警邮件，邮件显示探测的几个接口有超时情况。 多数执行栈都在：

![1240][]

这个线程栈的报错我见得多了，我们设置的 HTTP DNS 超时是 1s， connect 超时是 2s， read 超时是 3s，这种报错都是探测服务正常发送了 HTTP 请求，服务器也在收到请求正常处理后正常响应了，但数据包在网络层层转发中丢失了，所以请求线程的执行栈会停留在获取接口响应的地方。这种情况的典型特征就是能在服务器上查找到对应的日志记录。而且日志会显示服务器响应完全正常。 与它相对的还有线程栈停留在 Socket connect 处的，这是在建连时就失败了，服务端完全无感知。

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

根据这个猜想，群登上服务器，使用请求的 request\_id 在近期服务日志中搜索一下，果不其然，就是网络丢包问题导致的接口超时了。

当然这样 leader 是不会满意的，这个结论还得有人接锅才行。于是赶紧联系运维和网络组，向他们确认一下当时的网络状态。网络组同学回复说是我们探测服务所在机房的交换机老旧，存在未知的转发瓶颈，正在优化，这让我更放心了，于是在部门群里简单交待一下，算是完成任务。

**2、问题爆发**

本以为这次值班就起这么一个小波浪，结果在晚上八点多，各种接口的报警邮件蜂拥而至，打得准备收拾东西过周日单休的我措手不及。

这次几乎所有的接口都在超时，而我们那个大量网络 I/O 的接口则是每次探测必超时，难道是整个机房故障了么。

我再次通过服务器和监控看到各个接口的指标都很正常，自己测试了下接口也完全 OK，既然不影响线上服务，我准备先通过探测服务的接口把探测任务停掉再慢慢排查。

结果给暂停探测任务的接口发请求好久也没有响应，这时候我才知道没这么简单。

**三、解决**

**1、内存泄漏**

于是赶快登陆探测服务器，首先是 top free df 三连，结果还真发现了些异常。

![1240][1240 1]

我们的探测进程 CPU 占用率特别高，达到了 900%。

我们的 Java 进程，并不做大量 CPU 运算，正常情况下，CPU 应该在 100~200% 之间，出现这种 CPU 飙升的情况，要么走到了死循环，要么就是在做大量的 GC。

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

![1240][1240 2]

这么多的 FULL GC，应该是内存泄漏没跑了，于是 使用 jstack pid > jstack.log 保存了线程栈的现场，使用 jmap -dump:format=b,file=heap.log pid 保存了堆现场，然后重启了探测服务，报警邮件终于停止了。

**jstat**

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

它支持的查看项有：

\-class 查看类加载信息

\-compile 编译统计信息

\-gc 垃圾回收信息

\-gcXXX 各区域 GC 的详细信息 如 -gcold

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

**四、排查**

问题虽然解决了，但为了防止它再次发生，还是要把根源揪出来。

**1、分析栈**

栈的分析很简单，看一下线程数是不是过多，多数栈都在干嘛。

![1240][1240 3]

才四百多线程，并无异常。

![1240][1240 4]

线程状态好像也无异常，接下来分析堆文件。

**2、下载堆 dump 文件。**

堆文件都是一些二进制数据，在命令行查看非常麻烦，Java 为我们提供的工具都是可视化的，Linux 服务器上又没法查看，那么首先要把文件下载到本地。

由于我们设置的堆内存为 4G，所以 dump 出来的堆文件也很大，下载它确实非常费事，不过我们可以先对它进行一次压缩。

gzip 是个功能很强大的压缩命令，特别是我们可以设置 -1 ~ -9 来指定它的压缩级别，数据越大压缩比率越大，耗时也就越长，推荐使用 -6~7， -9 实在是太慢了，且收益不大，有这个压缩的时间，多出来的文件也下载好了。

**3、使用 MAT 分析 jvm heap**

MAT 是分析 Java 堆内存的利器，使用它打开我们的堆文件（将文件后缀改为 .hprof）, 它会提示我们要分析的种类，对于这次分析，果断选择 memory leak suspect。

![1240][1240 5]

从上面的饼图中可以看出，绝大多数堆内存都被同一个内存占用了，再查看堆内存详情，向上层追溯，很快就发现了罪魁祸首。

![1240][1240 6]

**4、分析代码**

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

这个 Map 根据类型用 ArrayList 存储了每次探测接口响应的结果，每次探测完都塞到 ArrayList 里去分析，由于 Bean 对象不会被回收，这个属性又没有清除逻辑，所以在服务十来天没有上线重启的情况下，这个 Map 越来越大，直至将内存占满。

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

给代码 owner 提了 PR，问题圆满解决。

**五、小结**

其实还是要反省一下自己的，一开始报警邮件里还有这样的线程栈：

![1240][1240 7]

看到这种报错线程栈却没有细想，要知道 TCP 是能保证消息完整性的，况且消息没有接收完也不会把值赋给变量，这种很明显的是内部错误，如果留意后细查是能提前查出问题所在的，查问题真是差了哪一环都不行啊。

***扩展阅读***

[一次毕生难忘的 Java 内存泄漏排查经历][Java]

[深入分析 ThreadLocal 内存泄漏问题][ThreadLocal]

[深入了解Java之虚拟机内存][Java 1]

[从面试题看问题之JVM和内存][JVM]

[排查Java线上服务故障的方法和实例分析][Java 2]

转载于:https://my.oschina.net/javafirst/blog/3028597

[2019_Python_]: https://my.oschina.net/u/2663968/blog/3061697
[hot3.png]: /images/20220114/d592e3f18862496eb941d1492f222668.png
[1240]: /images/20220114/f5ebfac1e37a4b95b1bacd275fd1c0fa.png
[1240 1]: /images/20220114/c1afda293bc7441e91bec5d12530bc4a.png
[1240 2]: /images/20220114/f311d2756b35481987bb021ef699ebf8.png
[1240 3]: /images/20220114/5d3d695992c54f7083867bcadb50787d.png
[1240 4]: /images/20220114/992665bc06f34b7eb34211aaa8927220.png
[1240 5]: /images/20220114/105b05aac5c54767b58ca1dcc5d20333.png
[1240 6]: /images/20220114/a7b54455775a4574a4aac3859ea0beb0.png
[1240 7]: /images/20220114/6f4e8b186a6c47c3953d56170414413b.png
[Java]: http://mp.weixin.qq.com/s?__biz=MzU5NTAzNjM0Mw==&mid=2247485898&idx=3&sn=e172138222146df21b3ff0e01251710e&chksm=fe795812c90ed104b33472981b178543b45d88f3c705cb3dee0dbeb628bb9eb7c96953ab172e&scene=21#wechat_redirect
[ThreadLocal]: http://mp.weixin.qq.com/s?__biz=MzU5NTAzNjM0Mw==&mid=2247485714&idx=2&sn=4e3e1c40137892ce90e136ab0545fb82&chksm=fe7958cac90ed1dcfa3ba60b0abe0681231fe105224211fff4b99c98b7bf41286b4c43eeab74&scene=21#wechat_redirect
[Java 1]: http://mp.weixin.qq.com/s?__biz=MzU5NTAzNjM0Mw==&mid=2247485874&idx=2&sn=6533223eb96122e2c21f8a833b626c02&chksm=fe79586ac90ed17cb4896e94343f9b34a674e9540a6144954fa2e74f3fbe4191cc1e9bd8f34c&scene=21#wechat_redirect
[JVM]: http://mp.weixin.qq.com/s?__biz=MzU5NTAzNjM0Mw==&mid=2247484209&idx=2&sn=d714622b7adf99ea98a75da443286279&chksm=fe7952e9c90edbffeff53786e5e77ae37ed71ef86bcf4c6fb256e7a31f3d82f653bb78b1d774&scene=21#wechat_redirect
[Java 2]: http://mp.weixin.qq.com/s?__biz=MzU5NTAzNjM0Mw==&mid=2247485556&idx=2&sn=446122e551b2bb37c9e4df00e70a06de&chksm=fe7959acc90ed0baf13e5185d7edfc576414ef20f53e0136ce483cf524b2d4ffb801a3a05781&scene=21#wechat_redirect