前段时间由于业务需要，需要从数据库中查询出来所有满足条件的数据，然后导入到文件中。于是随便写了个程序，查询出所有满足条件然后再写入文件。但是实际上线后却发现，程序刚开始运行马上看到部分数据写入到文件，但是后面运行越来越慢，于是对此分析排查了一下。

应用环境

JDK 1.7 + Spring 4.3 + mybatis + oracle

问题排查

查询以及写入文件伪代码如下：

  1. private void queryAllData(Request request, List querData, int count, String path, List allData) {
  2.         if (CollectionUtils.isEmpty(querData)) {
  3.             return;
  4.         }
  5.         allData.addAll(querData);
  6.         // 总 List 大于一定指定数量将数据刷新到文件
  7.         if (allData.size() > 20000) {
  8.             saveToFile(request, allData, path);
  9.         }
  10.         // 判断下一个偏移量 是否大于 总数
  11.         request.setPageNo(request.getPageNo() + 1);
  12.         // 查询下一页数据
  13.         List  newQueryData = queryDao.selectDataByPage(request);
  14.         queryAllData(request, newQueryData, count, path, allData);
  15.     }

其中 queryDao.selectDataByPage 为一个分页查找方法。这个方法目的就在于递归查找分页数据，如果某一页数据为空，就代表查询结束，此时已查询出所有数据。
为什么不直接执行 select * from table where a=xx 类似的数据直接查出所有数据？
因为写程序之前，查询了一下满足条件的数据总共有 200 w 数据，这样如果直接一把查询出所有数据，主要担心堆内存直接占满，导致 OOM 错误。
写完代码，部署到线上，然后执行导出数据，就放着不管，干其他事。过一段时间回来看数据导出结果，这个时候大吃一惊，程序竟然还没有结束，数据也才导出 3/4 左右。这个时候意识到程序肯定存在问题，于是仔细检查了一遍代码，也没看出什么。
没办法，这个时候只能分析线上程序 GC 情况了，幸好开启了打印 GC 日志的选项。拿到 GC 日志文件后，由于不太精通 GC 日志详细内容，只能借靠外部力量了。GC 日志分析网站，该网站可以分析 GC 日志，然后可以查看各个时间点堆内存占用情况。分析情况如图。
小心递归中内存泄漏 - 图1
这张图为 GC 之后堆内存占用情况。可以看出堆内存在 Full GC 之后并没有很快的降下来且很快下一次 Full GC 就开始了。这样大致可以看出，程序没有在期待时间内运行结束，就是由于堆内被占用过多，持续引起Full GC，应用程序线程持续被挂起。然后我们再看堆内存老年代占用情况。
小心递归中内存泄漏 - 图2
如上图，堆内存老年代占用空间持续上升直到接近占满，引起 Full GC，并没有缓解这种情况，之后内存占用一直接近到占满。
综上，我们可以得知程序出现了内存泄漏。
知道了原因，我们就好顺着找到问题。又顺着捋了一遍代码，可惜的是并没有看出问题。难道是 allData 数据集合越来越大，然后导致该现象？仔细查看了 saveToFile 代码逻辑。

  1. List<String> lines = Lists.newArrayListWithExpectedSize(allData.size());
  2.         for (Data data : allData) {
  3.             String line = process(data);
  4.             lines.add(line);
  5.         }
  6.         String fileName = "xx.txt";
  7.          try {
  8.             log.info("文件开始输出,输出行数{}", lines.size());
  9.             FileUtils.writeLines(new File(fileName), "utf-8", lines, true);
  10.             allData.clear();
  11.             lines = null;
  12.         } catch (IOException e) {
  13.             log.error("文件输出失败", e);
  14.             // 输出失败，先不管了，将数据继续保存集合中
  15.         }

可以看到，数据一旦写入到文件中，allData 集合立刻清空，所以不可能是该问题导致。
看了好几遍代码之后，还是无法确定问题原因。最后一遍查看代码，灵关一现，不会是 newQueryData 导致的问题吧？尝试把这里代码改成下面方式。

  1. private void queryAllData(Request request, List querData, int count, String path, List allData) {
  2.         if (CollectionUtils.isEmpty(querData)) {
  3.             return;
  4.         }
  5.         allData.addAll(querData);
  6.         // queryData 放入到 allData 中后，将 querData 结合清空。
  7.         querData.clear();
  8.         // 总 List 大于一定指定数量将数据刷新到文件
  9.         if (allData.size() > 20000) {
  10.             saveToFile(request, allData, path);
  11.         }
  12.         // 判断下一个偏移量 是否大于 总数
  13.         request.setPageNo(request.getPageNo() + 1);
  14.         // 查询下一页数据
  15.         newQueryData = queryDao.selectDataByPage(request);
  16.         queryAllData(request, newQueryData, count, path, allData);

改完代码，立刻部署，开始运行程序。这个时候查看堆内存占用情况，就可以知道改动是否有效。这里推荐一个方便查看 JVM 进程信息的工具 vjtop。可以快速查看堆内存占用情况。
运行 vjtop 之后，一直盯着堆内存占用情况。然后发现 eden 空间持续上升直到接近到满，然后发生 Minor GC ，eden 空间迅速清空。 old 区内存也没有一直占用接近到满这么夸张。大概占用 1/5 内存。改善情况如想象中一致，等待一定时间后，数据导出完毕。

分析

现在我们分析为什么出现内存泄漏。
我们知道 jvm 运行时，内存区分为 堆，虚拟机栈，方法区等。上面我们发生的现象就与虚拟机栈有关。
什么事虚拟机栈？
摘录深入 Java 虚拟机一书解释 虚拟机栈描述的是 Java 方法执行的内存模型：每个方法执行时都会创建一个栈帧用于存储局部变量表，操作数栈，动态链接，方法出口等信息。每一个方法从调用直至执行完后的过程，就对应一个栈帧在虚拟机栈中入栈到出栈的过程。 Java 线程执行方法时，jvm 虚拟机栈数据结构如图所示。
小心递归中内存泄漏 - 图3
可以看出，我们在调用函数 1 时，就将该栈帧压如栈中。函数 1 调用函数 2 时，也将该栈帧压入栈中。处于栈中的栈帧包含局部变量表，操作数帧等，而局部变量表包含基本数据类型，以及对象引用指针。对象指针指向堆内存对象。就是因为对象引用指针，导致我们上面情况。为何这么说那。我们再看下面这张图。
小心递归中内存泄漏 - 图4
我们可以看到，栈中每个方法 newQueryData 都指向堆中真正的对象。由于递归执行时，前面的方法都压到栈中，newQueryData 一直还指向堆中对象，然后 GC 时，由于对象还处于被引用，虚拟机判定该对象存活，所以不清理这些对象。随着递归方法越来越深入，堆积的 newQueryData 越来越多，量表引起质变，导致堆内存被占满，引发虚拟机持续 GC。但是每次 GC 之后却无法腾出空间。最后我们看到的现象就是程序执行很慢很慢。

　总结

这个问题本质看起来不是很难，但是实际发生的时候排查问题着实花费不少时间。下面我们总结一下这个过程。

  1. 如果程序实际运行起来与预想差距太大，那么不用想了，肯定哪里出问题了，赶快登上机器查看吧。
  2. 程序运行必要节点的日志输出需要打印。上面程序本来刚开始写的时候，由于主观意思，想想没那么难，很快就撸完部署了。最后查看日志，由于没有必要的日志输出，都不知道程序卡在那了。
  3. 需要了解一些 JVM 相关工具，可以及时查看 JVM 相关情况，如内存使用情况。如本文的例子，实际上我们可以 dump 内存，然后分析哪里发生了内存泄漏。很不幸的是，这方面本人只是处于了解层面，用的时候却不知道如何下手，只好求助于一些现成开源工具完成。之后需要好好补这方面操作能力，哈哈哈。
  4. 本文如果使用 while 循环代替递归方式，问题可能更快定位。递归中的内存泄漏可能更加隐蔽，很容易被我们忽略，同学们下次再写递归方法的时候不仅要注意递归方法深度，还要注意这个过程需要及时释放无用对象，不要让内存泄漏发生。

好了，文章大概就这样了，下次文章再见了。

参考文章以及网站

  1. 深入 Java 虚拟机 堆内存章节
  2. Java JVM 中 堆，栈，方法区 详解
  3. gc 日志分析网站
  4. 查看 JVM 进程信息的工具 — vjtop