原文:https://mp.weixin.qq.com/s/P8s3kuceBNovUP5adXpFCQ

    线上服务的 GC 问题,是 Java 程序非常典型的一类问题,非常考验工程师排查问题的能力。同时,几乎是面试必考题,但是能真正答好此题的人并不多,要么原理没吃透,要么缺乏实战经验。

    过去半年时间里,我们的广告系统出现了多次和 GC 相关的线上问题,有 Full GC 过于频繁的,有 Young GC 耗时过长的,这些问题带来的影响是:GC 过程中的程序卡顿,进一步导致服务超时从而影响到广告收入。
    这篇文章,我将以一个 FGC 频繁的线上案例作为引子,详细介绍下 GC 的排查过程,另外会结合 GC 的运行原理给出一份实践指南,希望对你有所帮助。内容分成以下 3 个部分:

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

    01 从一次 FGC 频繁的线上案例说起
    去年 10 月份,我们的广告召回系统在程序上线后收到了 FGC 频繁的系统告警,通过下面的监控图可以看到:平均每 35 分钟就进行了一次 FGC。而程序上线前,我们的 FGC 频次大概是 2 天一次。下面,详细介绍下该问题的排查过程。
    线上服务的 FGC 问题排查,看这篇就够了! - 图1
    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 左右,因此我们排除了内存泄漏的情况。
    线上服务的 FGC 问题排查,看这篇就够了! - 图2
    3. 通过 jmap 命令查看堆内存中的对象

    通过命令 jmap -histo 7276 | head -n20
    线上服务的 FGC 问题排查,看这篇就够了! - 图3
    上图中,按照对象所占内存大小排序,显示了存活对象的实例数、所占内存、类名。可以看到排名第一的是:int [],而且所占内存大小远远超过其他存活对象。至此,我们将怀疑目标锁定在了 int [] .
    4. 进一步 dump 堆内存文件进行分析

    锁定 int [] 后,我们打算 dump 堆内存文件,通过可视化工具进一步跟踪对象的来源。考虑堆转储过程中会暂停程序,因此我们先从服务管理平台摘掉了此节点,然后通过以下命令 dump 堆内存:
    jmap -dump:format=b,file=heap 7276
    通过 JVisualVM 工具导入 dump 出来的堆内存文件,同样可以看到各个对象所占空间,其中 int [] 占到了 50% 以上的内存,进一步往下便可以找到 int [] 所属的业务对象,发现它来自于架构团队提供的 codis 基础组件。
    线上服务的 FGC 问题排查,看这篇就够了! - 图4
    5. 通过代码分析可疑对象

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

    线上服务的 FGC 问题排查,看这篇就够了! - 图5
    至此,整个排查过程基本结束了,那为什么程序上线前没出现此问题呢?通过上图可以看到:程序上线前 YGC 的频次在 5 次左右,此次上线后 YGC 频次变成了 8 次左右,从而引发了此问题。
    6. 解决方案

    为了快速解决问题,我们将 CMS 收集器的分代年龄改成了 15 次,改完后 FGC 频次恢复到了 2 天一次,后续如果 YGC 的频次超过每分钟 15 次还会再次触发此问题。当然,我们最根本的解决方案是:优化程序以降低 YGC 的频率,同时缩短 codis 组件中 int 数组的生命周期,这里就不做展开了。

    02 GC 的运行原理介绍
    上面整个案例的分析过程中,其实涉及到很多 GC 的原理知识,如果不懂得这些原理就着手处理,其实整个排查过程是很抓瞎的。
    这里,我选择几个最核心的知识点,展开介绍下 GC 的运行原理,最后再给出一份实践指南。
    1. 堆内存结构
    大家都知道: GC 分为 YGC 和 FGC,它们均发生在 JVM 的堆内存上。先来看下 JDK8 的堆内存结构:
    线上服务的 FGC 问题排查,看这篇就够了! - 图6
    可以看到,堆内存采用了分代结构,包括新生代和老年代。新生代又分为:Eden 区,From Survivor 区(简称 S0),To Survivor 区(简称 S1 区),三者的默认比例为 8:1:1。另外,新生代和老年代的默认比例为 1:2。
    堆内存之所以采用分代结构,是考虑到绝大部分对象都是短生命周期的,这样不同生命周期的对象可放在不同的区域中,然后针对新生代和老年代采用不同的垃圾回收算法,从而使得 GC 效率最高。
    2. YGC 是什么时候触发的?
    大多数情况下,对象直接在年轻代中的 Eden 区进行分配,如果 Eden 区域没有足够的空间,那么就会触发 YGC(Minor GC),YGC 处理的区域只有新生代。因为大部分对象在短时间内都是可收回掉的,因此 YGC 后只有极少数的对象能存活下来,而被移动到 S0 区(采用的是复制算法)。
    当触发下一次 YGC 时,会将 Eden 区和 S0 区的存活对象移动到 S1 区,同时清空 Eden 区和 S0 区。当再次触发 YGC 时,这时候处理的区域就变成了 Eden 区和 S1 区(即 S0 和 S1 进行角色交换)。每经过一次 YGC,存活对象的年龄就会加 1。
    3. FGC 又是什么时候触发的?
    下面 4 种情况,对象会进入到老年代中:

    • YGC 时,To Survivor 区不足以存放存活的对象,对象会直接进入到老年代。
    • 经过多次 YGC 后,如果存活对象的年龄达到了设定阈值,则会晋升到老年代中。
    • 动态年龄判定规则,To Survivor 区中相同年龄的对象,如果其大小之和占到了 To Survivor 区一半以上的空间,那么大于此年龄的对象会直接进入老年代,而不需要达到默认的分代年龄。
    • 大对象:由 -XX:PretenureSizeThreshold 启动参数控制,若对象大小大于此值,就会绕过新生代,直接在老年代中分配。

    当晋升到老年代的对象大于了老年代的剩余空间时,就会触发 FGC(Major GC),FGC 处理的区域同时包括新生代和老年代。除此之外,还有以下 4 种情况也会触发 FGC:

    • 老年代的内存使用率达到了一定阈值(可通过参数调整),直接触发 FGC。
    • 空间分配担保:在 YGC 之前,会先检查老年代最大可用的连续空间是否大于新生代所有对象的总空间。如果小于,说明 YGC 是不安全的,则会查看参数 HandlePromotionFailure 是否被设置成了允许担保失败,如果不允许则直接触发 Full GC;如果允许,那么会进一步检查老年代最大可用的连续空间是否大于历次晋升到老年代对象的平均大小,如果小于也会触发 Full GC。
    • Metaspace(元空间)在空间不足时会进行扩容,当扩容到了 - XX:MetaspaceSize 参数的指定值时,也会触发 FGC。
    • System.gc () 或者 Runtime.gc () 被显式调用时,触发 FGC。
    1. 在什么情况下,GC 会对程序产生影响?
      不管 YGC 还是 FGC,都会造成一定程度的程序卡顿(即 Stop The World 问题:GC 线程开始工作,其他工作线程被挂起),即使采用 ParNew、CMS 或者 G1 这些更先进的垃圾回收算法,也只是在减少卡顿时间,而并不能完全消除卡顿。
      那到底什么情况下,GC 会对程序产生影响呢?根据严重程度从高到底,我认为包括以下 4 种情况:
    • FGC 过于频繁:FGC 通常是比较慢的,少则几百毫秒,多则几秒,正常情况 FGC 每隔几个小时甚至几天才执行一次,对系统的影响还能接受。但是,一旦出现 FGC 频繁(比如几十分钟就会执行一次),这种肯定是存在问题的,它会导致工作线程频繁被停止,让系统看起来一直有卡顿现象,也会使得程序的整体性能变差。
    • YGC 耗时过长:一般来说,YGC 的总耗时在几十或者上百毫秒是比较正常的,虽然会引起系统卡顿几毫秒或者几十毫秒,这种情况几乎对用户无感知,对程序的影响可以忽略不计。但是如果 YGC 耗时达到了 1 秒甚至几秒(都快赶上 FGC 的耗时了),那卡顿时间就会增大,加上 YGC 本身比较频繁,就会导致比较多的服务超时问题。
    • FGC 耗时过长:FGC 耗时增加,卡顿时间也会随之增加,尤其对于高并发服务,可能导致 FGC 期间比较多的超时问题,可用性降低,这种也需要关注。

    • YGC 过于频繁:即使 YGC 不会引起服务超时,但是 YGC 过于频繁也会降低服务的整体性能,对于高并发服务也是需要关注的。

    其中,「FGC 过于频繁」和「YGC 耗时过长」,这两种情况属于比较典型的 GC 问题,大概率会对程序的服务质量产生影响。剩余两种情况的严重程度低一些,但是对于高并发或者高可用的程序也需要关注。

    03 排查 FGC 问题的实践指南
    通过上面的案例分析以及理论介绍,再总结下 FGC 问题的排查思路,作为一份实践指南供大家参考。
    1. 清楚从程序角度,有哪些原因导致 FGC?

    • 大对象:系统一次性加载了过多数据到内存中(比如 SQL 查询未做分页),导致大对象进入了老年代。
    • 内存泄漏:频繁创建了大量对象,但是无法被回收(比如 IO 对象使用完后未调用 close 方法释放资源),先引发 FGC,最后导致 OOM.
    • 程序频繁生成一些长生命周期的对象,当这些对象的存活年龄超过分代年龄时便会进入老年代,最后引发 FGC. (即本文中的案例)
    • 程序 BUG 导致动态生成了很多新类,使得 Metaspace 不断被占用,先引发 FGC,最后导致 OOM.
    • 代码中显式调用了 gc 方法,包括自己的代码甚至框架中的代码。
    • JVM 参数设置问题:包括总内存大小、新生代和老年代的大小、Eden 区和 S 区的大小、元空间大小、垃圾回收算法等等。
    1. 清楚排查问题时能使用哪些工具
    • 公司的监控系统:大部分公司都会有,可全方位监控 JVM 的各项指标。
    • JDK 的自带工具,包括 jmap、jstat 等常用命令:# 查看堆内存各区域的使用率以及 GC 情况
      jstat -gcutil -h20 pid 1000# 查看堆内存中的存活对象,并按空间排序 jmap -histo pid | head -n20# dump 堆内存文件 jmap -dump:format=b,file=heap pid
    • 可视化的堆内存分析工具:JVisualVM、MAT 等
    1. 排查指南
    • 查看监控,以了解出现问题的时间点以及当前 FGC 的频率(可对比正常情况看频率是否正常)
    • 了解该时间点之前有没有程序上线、基础组件升级等情况。
    • 了解 JVM 的参数设置,包括:堆空间各个区域的大小设置,新生代和老年代分别采用了哪些垃圾收集器,然后分析 JVM 参数设置是否合理。
    • 再对步骤 1 中列出的可能原因做排除法,其中元空间被打满、内存泄漏、代码显式调用 gc 方法比较容易排查。
    • 针对大对象或者长生命周期对象导致的 FGC,可通过 jmap -histo 命令并结合 dump 堆内存文件作进一步分析,需要先定位到可疑对象。
    • 通过可疑对象定位到具体代码再次分析,这时候要结合 GC 原理和 JVM 参数设置,弄清楚可疑对象是否满足了进入到老年代的条件才能下结论。

    最后的话
    这篇文章通过线上案例并结合 GC 原理详细介绍了 FGC 的排查过程,同时给出了一份实践指南。
    后续会以类似的方式,再分享一个 YGC 耗时过长的案例,希望能帮助大家吃透 GC 问题排查,如果觉得本文对你有帮助,请帮丙丙转发或者点个再看