1. 背景

1.1 多个业务线的应用出现 Long GC 告警

最近一段时间,频繁收到监控系统 CAT 上报的 Long GC 告警(配置阈值为大于 3 秒)。

在这里插入图片描述

2. 分析前的一些 JVM 背景知识回顾

2.1 JVM 堆内存划分

在这里插入图片描述

  • 新生代(Young Generation)
    新生代内被划分为三个区:Eden、From Survivor、To Survivor。大多数对象在新生代被创建,Minor GC 针对的是新生代的垃圾回收。
  • 老年代(Old Generation)
    在新生代中经历了几次 Minor GC 仍然存活的对象,会被晋升到老年代。Major GC 针对的是老年代的垃圾回收。本文重点分析的 CMS 就是一种针对老年代的垃圾回收算法。另外,Full GC 是针对整堆(包括新生代和老年代)做的垃圾回收。
  • 永久代(Perm)
    主要存放已被虚拟机加载的类信息、常量、静态变量等数据。该区域对垃圾回收的影响不大,本文不会过多涉及。

2.2 CMS 垃圾回收的 6 个重要阶段

  1. initial-mark(初始标记):CMS 的第一个 STW(Stop-The-World)阶段。标记 GC Root 直接引用的对象,由于 GC Root 直接引用的对象不多,所以速度很快。
  2. concurrent-mark(并发标记):由第一阶段标记过的对象出发,所有可达的对象都在本阶段标记。
  3. concurrent-preclean(并发预清理):也是一个并发执行的阶段。在本阶段,会查找前一阶段执行过程中从新生代晋升、新分配或被更新的对象。通过并发地重新扫描这些对象,预清理阶段可以减少下一个 STW 重新标记阶段的工作量。
  4. concurrent-abortable-preclean(并发可中止的预清理):这个阶段其实跟上一个阶段做的事情一样,也是为了减少下一个 STW 重新标记阶段的工作量。增加这一阶段是为了让我们可以控制这个阶段的结束时机,比如扫描多长时间(默认 5 秒)或者 Eden 区使用占比达到期望比例(默认 50%)就结束本阶段。
  5. remark(重标记):CMS 的第二个 STW 阶段。暂停所有用户线程,从 GC Root 开始重新扫描整堆,标记存活的对象。需要注意的是,虽然 CMS 只回收老年代的垃圾对象,但是这个阶段依然需要扫描新生代,因为很多 GC Root 都在新生代,而这些 GC Root 指向的对象又在老年代,这称为“跨代引用”。
  6. concurrent-sweep(并发清理)

3. 分析

下面先看看出现 Long GC 时发生了什么。

选取其中一个应用分析其 GC 日志,发现 Long GC 发生在 CMS 的收集阶段。

在这里插入图片描述

  • 箭头 1 显示 abortable-preclean 阶段耗时 4.04 秒。
  • 箭头 2 显示的是 remark 阶段,耗时 0.11 秒。
虽然 abortable-preclean 阶段是 concurrent 的,不会暂停其他的用户线程,就算不优化可能影响也不大。但是频繁收到各个业务线的 GC 报警,长久来说也不是理想的状态。

在调优之前先看下该应用的 GC 统计数据,包括 GC 次数、耗时:

在这里插入图片描述

统计期间内(18 天)发生 CMS GC 69 次,其中 abortable preclean 阶段平均耗时 2.45 秒,final remark 阶段平均 112ms,最大耗时 170ms。

4. 优化目标

降低 abortable preclean 时间,而且不增加 final remark 的时间(因为 remark 是 STW 的)。

5. JVM 参数调优

5.1 第一次调优

先尝试调低 abortable preclean 阶段的时间,看看效果。

有两个参数可以控制这个阶段何时结束:

  • -XX:CMSMaxAbortablePrecleanTime=5000:默认值 5s,代表该阶段最大的持续时间。
  • -XX:CMSScheduleRemarkEdenPenetration=50:默认值 50%,代表 Eden 区使用比例超过 50% 就结束该阶段进入 remark。

调整为最大持续时间为 1s,Eden 区使用占比 10%,如下:

-XX:CMSMaxAbortablePrecleanTime=1000
-XX:CMSScheduleRemarkEdenPenetration=10

调整思路:
首先,每次 CMS 都发生在老年代使用占比达到 80% 时,这是由下面两个参数决定的:

-XX:CMSInitiatingOccupancyFraction=80
-XX:+UseCMSInitiatingOccupancyOnly

老年代的增长是由于部分对象在 Minor GC 后仍然存活,被晋升到老年代,导致老年代使用占比增长。也就是在每次 CMS GC 发生之前刚刚发生过一次 Minor GC,所以在那一刻新生代的使用占比是很低的。那么我们预计这个时候尽快结束 abortable preclean 阶段,在 remark 时就不需要扫描太多的 Eden 区对象,remark STW 的时间也就不会太长。

调整的思路是这样了,那到底效果如何呢?

第一次调整的结果

在这里插入图片描述

在统计期间(17 小时左右)内,发生过 2 次 CMS GC。Abortable Preclean 平均耗时 835ms,这是预期内的。但是 Final Remark 平均耗时 495ms(调整前是 112ms),其中一次是 80ms,另一次是 910ms!将近 1 秒钟!Remark 是 STW 的!对于要求低延时的应用来说这是无法接受的!

对比这两次 CMS GC 的详细 GC 日志,我们发现了一些对分析问题非常有用的东西。

remark 耗时 80ms 的那次 GC 日志

在这里插入图片描述

[YG occupancy: 181274 K (1887488 K)] - 年轻代当前占用情况和总容量

耗时 80ms 的这次 remark 发生时(早上 9 点,非高峰时段),新生代(YG)占用 181.274M。

remark 耗时 910ms 的那次 GC 日志

在这里插入图片描述

[YG occupancy: 773427 K (1887488 K)]

耗时 910ms 的这次 remark 发生时(晚上 10 点左右,高峰时段),新生代(YG)占用 773.427M。
因为这个时候是高峰期,新生代的占用量上升得非常快。几乎同样的时间内,非高峰时段仅上升到 181M,但是高峰时段就上升到 773M。

结论: 如果 abortable preclean 阶段时间太短,随后在 remark 时,新生代占用越大,则 remark 持续的时间(STW)越长。

这就陷入了两难:不缩短 abortable preclean 耗时会报 Long GC;缩短的话,remark 阶段又会变长,而且是 STW,更不能接受。

对于这种情况,CMS 提供了 -XX:+CMSScavengeBeforeRemark 参数,尝试在 remark 阶段之前进行一次 Minor GC,以降低新生代的占用。

-XX:+CMSScavengeBeforeRemark
Enables scavenging attempts before the CMS remark step. By default, this option is disabled.

5.2 第二次调优

调优前的考虑:
增加 -XX:+CMSScavengeBeforeRemark 不是没有代价的,因为这会增加一次 Minor GC 停顿。所以这个方案好或者不好的判断标准就是:增加 CMSScavengeBeforeRemark 参数之后的 Minor GC 停顿时间 + Remark 停顿时间,如果比增加之前的 Remark GC 停顿时间要小,这才是好的方案。

第二次调整的结果

在这里插入图片描述

在统计期间(20 小时左右)内,发生 3 次 CMS GC。Abortable preclean 平均耗时 693ms。Final remark 平均耗时 50ms,最大耗时 60ms。Final remark 的时间比调优前的平均时间(112ms)更低。

那么 CMS GC 前的 Minor GC 停顿时间又如何呢?来看看详细的 GC 日志。

3 次 CMS GC remark 前的 Minor GC 日志分析

第 1 次是非高峰时段的表现,Minor GC 耗时 0.01s + remark 耗时 0.06s = 0.07s = 70ms,如下:

在这里插入图片描述

第 2 次是高峰时段,Minor GC 耗时 0.01s + remark 耗时 0.05s = 0.06s = 60ms,如下:

在这里插入图片描述

第 3 次是非高峰时段,Minor GC 耗时 0.00s + remark 耗时 0.04s = 0.04s = 40ms,如下:

在这里插入图片描述

所以,3 次 Minor GC + remark 耗时的平均耗时 < 60ms,这比第一次调优时 remark 平均耗时 495ms 好得多了。

6. 优化结果

至此,我们最初的目标——降低 abortable preclean 时间,而且不增加 final remark 的时间——已经达到了。甚至 remark 的时间也缩短了。

7. 小结

解决 abortable preclean 时间过长的方案可以归结为两步:

  • 缩短 abortable preclean 时长,通过调整这两个参数:

    -XX:CMSMaxAbortablePrecleanTime=xxx
    -XX:CMSScheduleRemarkEdenPenetration=xxx

    调整为多少的一个判断标准是: abortable preclean 阶段结束时,新生代的空间占用不能大于某个参考值。在前面第一次调优后,新生代(YG)占用 181.274M,remark 耗时 80ms;新生代(YG)占用 773.427M 时,remark 耗时 910ms。所以这个参考值可以是 300M。而如果新生代增长过快,像这次调优应用 2 秒内就能用光 2G 新生代堆空间的,就只能通过 -XX:+CMSScavengeBeforeRemark 做一次 Minor GC 了。

  • 增加 -XX:+CMSScavengeBeforeRemark 参数,开启 remark 前进行 Minor GC 的尝试。
    虽然官方说明增加这个参数是尝试进行 Minor GC,不一定会进行,但实际使用起来,几乎每次 remark 前都会 Minor GC。

8. 总结

  1. 调优前明确目标。
  2. 调优过程对 GC 指标进行数据统计分析(本文借助 gceasy.io 在线分析工具)来验证效果。
  3. 需要能看懂 GC 日志。
  4. GC 调优不是一个一蹴而就的事情,它是微调、观察、再微调的过程。所以需要比较深入了解 GC 的一些基础,才能少走弯路。

说明: CMS 垃圾收集器在 JDK 9 中被标记为废弃,并在 JDK 14 中被正式移除。本文内容主要适用于 JDK 8 及以下版本。