一行代码引发的内存泄露的故事
我在2019年的7月和8月之间大概花了两个多星期写了一个比较简单的爬虫项目,项目主要的功能是周期性的爬取一些网站的热点信息,然后把数据存在 Redis 缓存中,然后有一个可以切换不同网站和展示信息的页面。
为什么会写这个项目呢?写这个项目的原因是在 V2EX 网站上看到很多人在分享他自己做的热点聚合网站,由于,我当时属于离职状态,好久没写代码了,于是决定也写一个类似的项目练练手。于是就写了 hot-crawler 这个项目,项目的源码放在了 GitHub 上。
写完了之后,就购买了域名和云服务器,然后就部署上去了。但是,我发现网站会偶尔访问不了,无响应。发现是服务器的程序进程挂掉了,于是重新启动项目后,我在服务器的控制面板观察服务器的资源状态,看到系统占用内存会不断的升高,所以,我猜应该是内存不足导致进程挂掉了,可是不知道为什么会导致内存泄漏。由于当时已经在网上推广了自己的网站,事情比较紧急,想着用什么方法来解决呢?于是我先是把应用程序作为 Linux 自启的系统服务,这样程序挂掉之后会自动重新启动,不至于一直访问不了。然后,我又通过加一台服务器使用 Nginx 进行负载均衡。因为程序挂掉是需要经过一段时间的,然后需要十几秒的时间重启,在相同的十几秒时间,两台服务器同时挂掉的机率比较小,通过负载均衡可以错开这十几秒,从而使得网站可以持续访问。
网站挂掉的问题解决掉了,但不是真正意义上的解决。我也想去分析程序为什么会出现泄漏,但我不知从何开始。也许可能需要学习很多 JVM 相关的知识,由于当时我的学习计划是先学习计算机基础(体系结构、操作系统、算法、网络、数据库系统等),然后在深入学习 Java 和 Java Web。所以我只能先把这个问题放着,继续学习计算机基础。然而这个问题一直在我的心中困扰着我,这也是后来促使我这么强烈地想学习 JVM 的原因。
最近一段时间一直在学习 JVM,先看了 JVM 内部的实现原理,主要是 adaptive code generation, adaptive memory management, 以及 threads and synchronization。然后看了 JVM 优化的方法,主要是如何选择 JIT compiler 和 garbage collector,如何看 GC 日志,如何使用可视化工具分析程序的运行时状态,如何调整 JVM 的参数。
经过一段时间的 JVM 的学习,我准备开始分析我之前写的 hot-crawler 这个项目。下面就是我的分析过程。
- 我先不设置 JVM 的内存大小,直接打印 GC 日志看有什么问题。下面是对应的 JVM options 和 GC log。
1 | -XX:+PrintGCDetails -Xloggc:hotcrawler_jvm.log |
1 | Java HotSpot(TM) 64-Bit Server VM (25.171-b11) for windows-amd64 JRE (1.8.0_171-b11), built on Mar 28 2018 16:06:12 by "java_re" with MS VC++ 10.0 (VS2010) |
通过上面的 GC 日志,可以看出 HotSpot VM 把我电脑的所有可用空间(4G 多)作为了最大的堆内存空间,然后进行了若干次的 Minor GC。然后进行了一次 Full GC,增加了 Metadata 即 Permanent generation 区域的内存空间大小。然后又进行了几次 Minor GC。以上是全部的 GC 日志,后面就没有任何日志了。
通过分析直接打印 GC 日志,好像看不出什么,没什么收获。
- 我决定设置 JVM 各个区域的内存空间大小(heap, young generation, permanent generation) ,然后再观察 GC 日志有什么变化。下面是对应的 JVM options 和 GC log。
1 | -XX:+PrintGCDetails -Xloggc:hotcrawler_jvm.log -Xms188m -Xmx188m -XX:NewSize=70m -XX:MaxNewSize=70m -XX:MetaspaceSize=48m -XX:MaxMetaspaceSize=48m |
1 | Java HotSpot(TM) 64-Bit Server VM (25.171-b11) for windows-amd64 JRE (1.8.0_171-b11), built on Mar 28 2018 16:06:12 by "java_re" with MS VC++ 10.0 (VS2010) |
通过上面的 GC 日志,可用看出 HotSpot VM 实际分配的各个区域的内存比我们设置的要稍微大一点。然后 JVM 进行了多次的 Minor GC,不断地收集 Young generation 的空间,可能 Young generation 空间设置的小了一点,但也感觉不是小了,因为只有项目刚启动时有 Minor GC,后面一直都没有 Minor GC 了。
然而,重点来了,重点是现在没有了 Full GC,这说明 heap 的 Old generation 和 permanent generation 的内存是够用的。通过 Windows 操作系统的进程管理器会发现程序所占的内存远远超过 JVM 堆的内存,而且程序占用的内存还在不断的上升。通过 GC 日志感觉堆内存没什么问题,那么问题出在哪里呢?
- 由于 GC 日志找不出问题,于是我决定使用 JConsole 看一下程序的运行时状态。经过一段时间的观察,我似乎找到了问题的根源,那就是 thread 太多了,并且不断的在增加。下图是 thread 的变化曲线。

于是我回想代码中哪里会创建线程或线程池,我想只有一个地方创建了线程池,那就是在爬虫的定时任务中创建线程池进行页面的爬取。这行代码如下所示:
1 | ExecutorService executorService = Executors.newFixedThreadPool(threadPoolNum); |
虽然这行创建线程池没什么问题,但是我把创建线程池的代码写在了定时任务执行的方法中,因此,每执行一次任务,就会创建一个线程池和若干的线程。我立刻把线程池定义成了成员变量,然后观察 JVM 的内存和线程,发现一切都稳定、正常了。内存空间和线程数不会一直增加。下图是修复代码后的线程变化图:

通过自己的努力,我终于解决了那个积压已久的问题。在重新部署后的那一刻,我内心是无比的兴奋与激动。
以前自己写代码主要在乎功能的实现,经过这个教训,更让我懂得了软件的性能和稳定性的重要性。