前段时间由于业务需要,需要从数据库中查询出来所有满足条件的数据,然后导入到文件中。于是随便写了个程序,查询出所有满足条件然后再写入文件。但是实际上线后却发现,程序刚开始运行马上看到部分数据写入到文件,但是后面运行越来越慢,于是对此分析排查了一下。
应用环境
JDK 1.7 + Spring 4.3 + mybatis + oracle
问题排查
查询以及写入文件伪代码如下:
其中 为一个分页查找方法。这个方法目的就在于递归查找分页数据,如果某一页数据为空,就代表查询结束,此时已查询出所有数据。
为什么不直接执行 类似的数据直接查出所有数据?
因为写程序之前,查询了一下满足条件的数据总共有 200 w 数据,这样如果直接一把查询出所有数据,主要担心堆内存直接占满,导致OOM错误。
写完代码,部署到线上,然后执行导出数据,就放着不管,干其他事。过一段时间回来看数据导出结果,这个时候大吃一惊,程序竟然还没有结束,数据也才导出 3/4 左右。这个时候意识到程序肯定存在问题,于是仔细检查了一遍代码,也没看出什么。
没办法,这个时候只能分析线上程序 GC 情况了,幸好开启了打印 GC 日志的选项。拿到 GC 日志文件后,由于不太精通 GC 日志详细内容,只能借靠外部力量了。GC 日志分析网站,该网站可以分析 GC 日志,然后可以查看各个时间点堆内存占用情况。分析情况如图。
这张图为 GC 之后堆内存占用情况。可以看出堆内存在 Full GC 之后并没有很快的降下来且很快下一次 Full GC 就开始了。这样大致可以看出,程序没有在期待时间内运行结束,就是由于堆内被占用过多,持续引起Full GC,应用程序线程持续被挂起。然后我们再看堆内存老年代占用情况。
如上图,堆内存老年代占用空间持续上升直到接近占满,引起 Full GC,并没有缓解这种情况,之后内存占用一直接近到占满。
综上,我们可以得知程序出现了内存泄漏。
知道了原因,我们就好顺着找到问题。又顺着捋了一遍代码,可惜的是并没有看出问题。难道是allData数据集合越来越大,然后导致该现象?仔细查看了 代码逻辑。
可以看到,数据一旦写入到文件中,allData集合立刻清空,所以不可能是该问题导致。
看了好几遍代码之后,还是无法确定问题原因。最后一遍查看代码,灵关一现,不会是newQueryData导致的问题吧?尝试把这里代码改成下面方式。
改完代码,立刻部署,开始运行程序。这个时候查看堆内存占用情况,就可以知道改动是否有效。这里推荐一个方便查看 JVM 进程信息的工具 vjtop。可以快速查看堆内存占用情况。
运行 vjtop 之后,一直盯着堆内存占用情况。然后发现 eden 空间持续上升直到接近到满,然后发生 Minor GC ,eden 空间迅速清空。 old 区内存也没有一直占用接近到满这么夸张。大概占用 1/5 内存。改善情况如想象中一致,等待一定时间后,数据导出完毕。
分析
现在我们分析为什么出现内存泄漏。
我们知道 jvm 运行时,内存区分为 堆,虚拟机栈,方法区等。上面我们发生的现象就与虚拟机栈有关。
什么事虚拟机栈?
摘录深入 Java 虚拟机一书解释
虚拟机栈描述的是 Java 方法执行的内存模型:每个方法执行时都会创建一个栈帧用于存储局部变量表,操作数栈,动态链接,方法出口等信息。每一个方法从调用直至执行完后的过程,就对应一个栈帧在虚拟机栈中入栈到出栈的过程。
Java 线程执行方法时,jvm 虚拟机栈数据结构如图所示。
可以看出,我们在调用函数 1 时,就将该栈帧压如栈中。函数 1 调用函数 2 时,也将该栈帧压入栈中。处于栈中的栈帧包含局部变量表,操作数帧等,而局部变量表包含基本数据类型,以及对象引用指针。对象指针指向堆内存对象。就是因为对象引用指针,导致我们上面情况。为何这么说那。我们再看下面这张图。
我们可以看到,栈中每个方法 newQueryData 都指向堆中真正的对象。由于递归执行时,前面的方法都压到栈中,newQueryData 一直还指向堆中对象,然后 GC 时,由于对象还处于被引用,虚拟机判定该对象存活,所以不清理这些对象。随着递归方法越来越深入,堆积的 newQueryData 越来越多,量表引起质变,导致堆内存被占满,引发虚拟机持续 GC。但是每次 GC 之后却无法腾出空间。最后我们看到的现象就是程序执行很慢很慢。
总结
这个问题本质看起来不是很难,但是实际发生的时候排查问题着实花费不少时间。下面我们总结一下这个过程。
如果程序实际运行起来与预想差距太大,那么不用想了,肯定哪里出问题了,赶快登上机器查看吧。
程序运行必要节点的日志输出需要打印。上面程序本来刚开始写的时候,由于主观意思,想想没那么难,很快就撸完部署了。最后查看日志,由于没有必要的日志输出,都不知道程序卡在那了。
需要了解一些 JVM 相关工具,可以及时查看 JVM 相关情况,如内存使用情况。如本文的例子,实际上我们可以 dump 内存,然后分析哪里发生了内存泄漏。很不幸的是,这方面本人只是处于了解层面,用的时候却不知道如何下手,只好求助于一些现成开源工具完成。之后需要好好补这方面操作能力,哈哈哈。
本文如果使用 while 循环代替递归方式,问题可能更快定位。递归中的内存泄漏可能更加隐蔽,很容易被我们忽略,同学们下次再写递归方法的时候不仅要注意递归方法深度,还要注意这个过程需要及时释放无用对象,不要让内存泄漏发生。
好了,文章大概就这样了,下次文章再见了。
参考文章以及网站
深入 Java 虚拟机 堆内存章节
Java JVM 中 堆,栈,方法区 详解
gc 日志分析网站
查看 JVM 进程信息的工具 -- vjtop
领取专属 10元无门槛券
私享最新 技术干货