记一次线上内存泄漏问题的排查过程

近期需要对公司的接口做线上的巡查监控,需要写一个脚本放到服务器上,定时运行脚本监测线上接口是否正常。
测试的接口不是HTTP协议,而是公司基于TCP协议开发的私有协议,因此不能直接用现成的一些接口测试工具,需要自己写代码来调用接口。

由于是私有协议,为了方便各业务项目进行通信,开发部门统一提供了一个TClient的jar包,底层使用了netty框架进行通信。调用方只需要按照协议的格式组装二进制的包,然后直接调用TClient的sendMessage方法就可以把数据发送出去,服务端处理完成后会异步回调,将响应数据返回给客户端。

 

脚本写完了,伪代码如下
public class Demo{
   public void invoke(){

              // 创建TClient并初始化

              TClient client = new TClient(xxx);

              // 组装接口数据包

              Data data = new Data(xxx);

              // 发送数据

              Response res = client.sendMessage(data);

              // 检查结果、存储结果、发送邮件

              doSomething();

              // 关闭client

              client.close();
    }

}

 
测试脚本中,每隔一分钟,创建一个Demo对象,调用invoke方法

Demo demo = new Demo();

demo.invoke();

脚本写好后在服务器上调试了下,接口返回数据正常,于是正式启动定时任务,观察了一会,运行一切正常,Perfect!

第二天早上到公司,登上服务器,查看昨晚脚本的运行情况,看了下日志。

打开日志我就震惊了,What?OutOfMemoryError!竟然内存泄漏了!

平常都是开发写bug时出现内存泄漏,今天终于轮到我自己了!


最后一条日志显示为下午17:17左右,也就是脚本大概运行了4小时后出现了内存泄漏。查看了下脚本进程,果然已经崩溃了,并且生成了一个dump文件。


经常做性能测试的同学,对内存泄漏都不陌生。内存泄漏总结来说就是JVM中存储的对象太多了,占满了全部内存空间,并且这些对象都是不可回收的。这样程序就不能再继续运行了,因为已经没有空间了。

举个例子,就好像去饭馆吃饭,饭馆里总是不断的有人进去,也有人出来。如果某天来了一帮人占满了饭店,并且赖着不走了,这样新顾客就进不来了,这个时候估计老板就崩溃了。

我先review了脚本的代码,没发现什么异常的问题。有的朋友可能会说,你不是每个1分钟创建一个Demo对象吗,运行这么长时间,会不会是Demo对象太多了?

其实并不会,写脚本的时候也考虑过这个问题,每次new Demo对象,因为上一次脚本已经执行完了,那么上一次的Demo对象就没有引用了,这样JVM在垃圾回收的时候会把上一次的Demo对象清理掉。这样并不会造成内存泄漏。

目光再回到服务器上,Java进程在崩溃时,自动生成了一个堆dump文件,如果已经发生了内存泄漏,可以分析这个dump文件,看看里面那些对象比较多,这样就能确定原因了。

一般在工作中分析内存泄漏时,可以把dump文件下载到本地,然后通过jvisualvm或者jprofiler打开文件,工具自动会分析哪些对象数量最多。

但是这个文件有1.3G,公司服务器下载有限速,想下载下来估计得等到7月7号testfan性能测试实战班开课那天了。

突然想到另外一个分析内存泄漏的工具MAT,之前都是在windows下使用MAT,其实MAT也有Linux版本,可以直接在服务器上对dump文件进行分析。

简单介绍下工具的使用方法:

1、 登录官网,下载Linux x86_64/GTK+版本

https://www.eclipse.org/mat/downloads.php

2、 解压后修改MemoryAnalyzer.ini配置文件,配置jvm参数(要比dump文件大)

3、 执行.mat提供的脚本

./ParseHeapDump.sh /home/xxx.hprof org.eclipse.mat.api:suspects

(/home/xxx.hprof是dump文件的路径)

4、 在xxx.hprof目录下,生成了java_pid32523_Leak_Suspects.zip压缩文件

5、 下载到windows下,解压,打开index.html


在分析页面中可以看到,io.netty.channel.nio.NioEventLoopGroup对象占用了JVM中61.36%的空间。其次是io.netty.buffer.PoolThreadCache对象,占用了21.38%。

看名字这俩对象都是netty框架中的类,在网上查了下资料,“NioEventLoopGroup”是netty中的一个线程池对象。

看页面上的统计,JVM中有1145个netty的线程池对象,这是什么操作?线程池不就一个就行了吗?为什么有这么多?

看到线程池对象,就想到会不会JVM线程方面有问题?因为脚本进程现在已经崩溃了,只能重新运行脚本,然后再对线程进行监控。

脚本运行过程中,通过监控jvm,发现old区确实在不断的缓慢增加,这样长时间跑下去,应该就会重现昨天晚上的问题。

执行jstack命令打印线程堆栈信息

jstack pid > thread.log

打开thread.log看了下,线程状态倒没啥问题,但是堆栈中有大量的nioEventLoopGroup线程,看编号有1000+,通过命令统计了下,确实有1000+个nioEventLoopGroup线程。
 
这个数量跟上面MAT工具分析的实例数量也差不多对应上了,现在问题基本上就确定了。也就是说在内存泄漏发生前,JVM中存在1000+个nioEventLoopGroup线程,每个线程创建了一个NioEventLoopGroup对象,因为线程池的特性,所以这些线程处于都是运行状态的。

并且在脚本运行过程中发现,这个nioEventLoopGroup线程并不是开始就是1000+,而是从0慢慢涨上来的。也就是说随着脚本的运行,慢慢积累上来的。

这个时候目光又回到了我的脚本中,虽然并不是因为我不断的new Demo对象造成了内存泄漏,但是肯定跟这个行为有关系,nioEventLoopGroup是netty框架用到的对象,于是就想到了代码中的TClient client = new TClient(xxx); 

打开TClient的jar包看了下,在TClient的构造函数里,确实创建了一个nioEventLoopGroup对象


然后在connect方法中,使用了这个线程池对象bossGroup
 

现在基本上确定是什么原因了,如下:

a>   每隔1分钟,脚本会new一个Demo对象

b>   Demo对象的invoke方法里又new了一个TClient对象

c>   TClient对象内部在做netty连接初始化的时候,创建了NioEventLoopGroup线程池对象

虽然脚本中创建的Demo对象和TClient对象都会被JVM回收,但是可能是因为netty使用NioEventLoopGroup线程池和服务端建立了长连接,导致线程池对象并不会被回收。这样长时间跑下来,JVM中中的NioEventLoopGroup对象就会越来越多,最终导致了内存泄漏。

这么来看,还真是每次new Demo间接带来的影响。知道原因就好说了,Demo对象不能在每次运行的时候创建,而且放在类初始化的时候创建一个。无论脚本跑多少次,都只有一个NioEventLoopGroup对象了。

重新修改了下脚本,长时间运行监控了下,确实内存使用很稳定,没有出现内存泄漏的情况。

问题似乎是得到了解决,但是等等。我脑海中突然又想到另外一个问题,虽然我在脚本中每次都创建一个TClient对象,但是每次跑完后,都会调用TClient的close方法啊,close方法里应该会释放NioEventLoopGroup对象啊,难道没做吗?

打开TClient的jar包看了下close方法

在close方法中,确实把NioEventLoopGroup置为null了,对于一个普通的对象来说,只要对象引用为null,那么在下次JVM垃圾回收的时候,就会把这个对象回收掉。但是对于一个线程池对象来说,因为线程池中有活动线程存在,所以尽管置为null了,JVM也不会回收这个线程池。一般的线程池对象,都是通过shutdown方法来销毁线程池的。

查看了下netty的api文档,确实有shutdownGracefully方法(优雅关闭)
 


现在问题彻底搞清楚了,TClient的close方法中,只是简单的将线程池对象置为null,并没有进行shutdown操作,因此JVM并不能回收线程池对象。从而造成了,即便用户调用了close方法,其实资源也没有销毁,最终自然就会出现内存泄漏。

作为一个通用的工具包,内部的资源的释放,并不能靠调用者来保证。理论上来说,即便我每次都new TClient对象,只要我都关闭了。在业务层面来说,也是正常行为。不能让调用者必须缓存client对象,否则就会出现内存泄漏,这样是不合理的。

在跟相关开发沟通后,对代码做了修改,加上了shutdown方法,仍然用老的脚本进行测试,在长时间的运行后,内存依然保持正常。因此这个问题终于解决了。


最后总结一下

1、 此问题的根本原因是client包中close方法没有成功销毁资源

2、 理论上来说,重复创建大量对象并不会造成内存泄漏,但是如果代码中同时也创建了第三方包的对象,在不了解其实现细节的情况了,可能其内部会创建一些不可被回收的对象,这个时候就会有内存泄漏的风险。因此还是尽量的复用对象,减少内存泄漏问题的发生。

 

作  者:Testfan 北河

出  处:微信公众号:自动化软件测试平台

版权说明:欢迎转载,但必须注明出处,并在文章页面明显位置给出文章链接

posted @ 2019-07-08 14:31  码同学软件测试  阅读(2015)  评论(0编辑  收藏  举报