线上服务的 GC 问题排查，看这篇就够了 _GC

线上服务的GC问题，是JAVA程序非常典型的一类问题，非常考验工程师排查问题的能力。同时，几乎是面试必考题，但是能真正答好此题的人并不多，要么原理没吃透，要么缺乏实战经验。
过去半年时间里，我们的广告系统出现了多次和GC相关的线上问题，有Full GC过于频繁的，有Young GC耗时过长的，这些问题带来的影响是：GC过程中的程序卡顿，进一步导致服务超时从而影响到广告收入。
这篇文章，我将以一个FGC频繁的线上案例作为引子，详细介绍下GC的排查过程，另外会结合GC的运行原理给出一份实践指南，希望对你有所帮助。内容分成以下3个部分：

从一次FGC频繁的线上案例说起
GC的运行原理介绍
排查FGC问题的实践指南

01 从一次FGC频繁的线上案例说起
去年10月份，我们的广告召回系统在程序上线后收到了FGC频繁的系统告警，通过下面的监控图可以看到：平均每35分钟就进行了一次FGC 。而程序上线前，我们的FGC频次大概是2天一次。下面，详细介绍下该问题的排查过程。

文章插图

1. 检查JVM配置
通过以下命令查看JVM的启动参数：
ps aux | grep "ApplicationName=adsearch"

-Xms4g -Xmx4g -Xmn2g -Xss1024K
-XX:ParallelGCThreads=5
-XX:+UseConcMarkSweepGC
-XX:+UseParNewGC
-XX:+UseCMSCompactAtFullCollection
-XX:CMSInitiatingOccupancyFraction=80

可以看到堆内存为4G，新生代为2G，老年代也为2G，新生代采用ParNew收集器，老年代采用并发标记清除的CMS收集器，当老年代的内存占用率达到80%时会进行FGC 。
进一步通过 jmap -heap 7276 | head -n20 可以得知新生代的Eden区为1.6G，S0和S1区均为0.2G 。
2. 观察老年代的内存变化
通过观察老年代的使用情况，可以看到：每次FGC后，内存都能回到500M左右，因此我们排除了内存泄漏的情况。

文章插图

3. 通过jmap命令查看堆内存中的对象
通过命令 jmap -histo 7276 | head -n20

文章插图

上图中，按照对象所占内存大小排序，显示了存活对象的实例数、所占内存、类名。可以看到排名第一的是：int[]，而且所占内存大小远远超过其他存活对象。至此，我们将怀疑目标锁定在了 int[] .
4. 进一步dump堆内存文件进行分析
锁定 int[] 后，我们打算dump堆内存文件，通过可视化工具进一步跟踪对象的来源。考虑堆转储过程中会暂停程序，因此我们先从服务管理平台摘掉了此节点，然后通过以下命令dump堆内存：
jmap -dump:format=b,file=heap 7276
通过JVisualVM工具导入dump出来的堆内存文件，同样可以看到各个对象所占空间，其中int[]占到了50%以上的内存，进一步往下便可以找到 int[] 所属的业务对象，发现它来自于架构团队提供的codis基础组件。

文章插图

5. 通过代码分析可疑对象
通过代码分析，codis基础组件每分钟会生成约40M大小的int数组，用于统计TP99 和 TP90，数组的生命周期是一分钟。而根据第2步观察老年代的内存变化时，发现老年代的内存基本上也是每分钟增加40多M，因此推断：这40M的int数组应该是从新生代晋升到老年代。
我们进一步查看了YGC的频次监控，通过下图可以看到大概1分钟有8次左右的YGC，这样基本验证了我们的推断：因为CMS收集器默认的分代年龄是6次，即YGC 6次后还存活的对象就会晋升到老年代，而codis组件中的大数组生命周期是1分钟，刚好满足这个要求。

文章插图

至此，整个排查过程基本结束了，那为什么程序上线前没出现此问题呢？通过上图可以看到：程序上线前YGC的频次在5次左右，此次上线后YGC频次变成了8次左右，从而引发了此问题。
6. 解决方案
为了快速解决问题，我们将CMS收集器的分代年龄改成了15次，改完后FGC频次恢复到了2天一次，后续如果YGC的频次超过每分钟15次还会再次触发此问题。当然，我们最根本的解决方案是：优化程序以降低YGC的频率，同时缩短codis组件中int数组的生命周期，这里就不做展开了。
02 GC的运行原理介绍
上面整个案例的分析过程中，其实涉及到很多GC的原理知识，如果不懂得这些原理就着手处理，其实整个排查过程是很抓瞎的。