小心递归中内存泄漏
小心递归中内存泄漏
前段时间由于业务需要，需要从数据库中查询出来所有满足条件的数据，然后导入到文件中。于是随便写了个程序，查询出所有满足条件然后再写入文件。但是实际上线后却发现，程序刚开始运行马上看到部分数据写入到文件，但是后面运行越来越慢，于是对此分析排查了一下。
应用环境
JDK 1.7 + Spring 4.3 + mybatis + oracle
问题排查
查询以及写入文件伪代码如下：
private void queryAllData(Request request, List querData, int count, String path, List allData) {
if (CollectionUtils.isEmpty(querData)) {
return;
}
allData.addAll(querData);
// 总 List 大于一定指定数量将数据刷新到文件
if (allData.size() > 20000) {
saveToFile(request, allData, path);
}
// 判断下一个偏移量 是否大于 总数
request.setPageNo(request.getPageNo() + 1);
// 查询下一页数据
List newQueryData = queryDao.selectDataByPage(request);
queryAllData(request, newQueryData, count, path, allData);
}其中 queryDao.selectDataByPage 为一个分页查找方法。这个方法目的就在于递归查找分页数据，如果某一页数据为空，就代表查询结束，此时已查询出所有数据。
为什么不直接执行 select * from table where a=xx 类似的数据直接查出所有数据？
因为写程序之前，查询了一下满足条件的数据总共有 200 w 数据，这样如果直接一把查询出所有数据，主要担心堆内存直接占满，导致 OOM 错误。
写完代码，部署到线上，然后执行导出数据，就放着不管，干其他事。过一段时间回来看数据导出结果，这个时候大吃一惊，程序竟然还没有结束，数据也才导出 3/4 左右。这个时候意识到程序肯定存在问题，于是仔细检查了一遍代码，也没看出什么。
没办法，这个时候只能分析线上程序 GC 情况了，幸好开启了打印 GC 日志的选项。拿到 GC 日志文件后，由于不太精通 GC 日志详细内容，只能借靠外部力量了。GC 日志分析网站，该网站可以分析 GC 日志，然后可以查看各个时间点堆内存占用情况。分析情况如图。
这张图为 GC 之后堆内存占用情况。可以看出堆内存在 Full GC 之后并没有很快的降下来且很快下一次 Full GC 就开始了。这样大致可以看出，程序没有在期待时间内运行结束，就是由于堆内被占用过多，持续引起Full GC，应用程序线程持续被挂起。然后我们再看堆内存老年代占用情况。
如上图，堆内存老年代占用空间持续上升直到接近占满，引起 Full GC，并没有缓解这种情况，之后内存占用一直接近到占满。
综上，我们可以得知程序出现了内存泄漏。
知道了原因，我们就好顺着找到问题。又顺着捋了一遍代码，可惜的是并没有看出问题。难道是 allData 数据集合越来越大，然后导致该现象？仔细查看了 saveToFile 代码逻辑。
List<String> lines = Lists.newArrayListWithExpectedSize(allData.size());
for (Data data : allData) {
String line = process(data);
lines.add(line);
}
String fileName = "xx.txt";
try {
log.info("文件开始输出,输出行数{}", lines.size());
FileUtils.writeLines(new File(fileName), "utf-8", lines, true);
allData.clear();
lines = null;
} catch (IOException e) {
log.error("文件输出失败", e);
// 输出失败，先不管了，将数据继续保存集合中
}可以看到，数据一旦写入到文件中，allData 集合立刻清空，所以不可能是该问题导致。
看了好几遍代码之后，还是无法确定问题原因。最后一遍查看代码，灵关一现，不会是 newQueryData 导致的问题吧？尝试把这里代码改成下面方式。
private void queryAllData(Request request, List querData, int count, String path, List allData) {
if (CollectionUtils.isEmpty(querData)) {
return;
}
allData.addAll(querData);
// queryData 放入到 allData 中后，将 querData 结合清空。
querData.clear();
// 总 List 大于一定指定数量将数据刷新到文件
if (allData.size() > 20000) {
saveToFile(request, allData, path);
}
// 判断下一个偏移量 是否大于 总数
request.setPageNo(request.getPageNo() + 1);
// 查询下一页数据
newQueryData = queryDao.selectDataByPage(request);
queryAllData(request, newQueryData, count, path, allData);改完代码，立刻部署，开始运行程序。这个时候查看堆内存占用情况，就可以知道改动是否有效。这里推荐一个方便查看 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
