转载

【即插即用的硬干货】线上系统出现频繁 JVM FullGC 时，应该如何排查和处理？

还没关注？

快动动手指！

聊技术、论职场！

为IT人打造一个“有温度”的 狸猫技术窝

背景

我们上线Java服务的时候需要对其配置一些JVM参数，如堆空间大小、虚拟机栈大小、垃圾回收算法。对于年轻代和老年代我们可以配置不同的垃圾回收算法。在一些对 rt 要求很高的场景，服务不能有长时间的卡顿， CMS 就可以运用于此场景。

Concurrent Mark Sweep ,是一款基于并发、使用标记清除算法的垃圾回收算法，只针对老年代进行垃圾回收。

CMS收集器工作时，GC工作线程和用户线程可以并发执行，以达到降低 STW 时间的目的。

开起VM选项 -XX:+UseConcMarkSweepGC ，表示对老年代的回收采用CMS。

前置知识

STW

首先，我们需要理清一个概念，即只有 标记 阶段才需要 STW 。

标记完成以后，需要清除的对象已经确定，无论此时是否产生新的垃圾，都不影响对这些对象的清理。也就是说， 清除 阶段是可以设计成和用户线程并发执行的。

JVM在暂停的时候，需要选准一个时机，由于JVM系统运行期间的复杂性，不可能做到随时暂停，因此引入了 安全点（safepoint） 的概念：程序只有在运行到安全点的时候，才可以暂停下来。

HotSpot 采用主动中断的方式，让执行线程在运行期轮询是否需要暂停的标志，若需要则中断挂起。

HotSpot 使用了几条短小精炼的汇编指令便可完成安全点轮询以及触发线程中断，因此对系统性能的影响几乎可以忽略不计。

可达性

可达性 是指，如果一个对象会被至少一个程序中的可达对象通过直接或间接的方式引用，则称该对象是 可达的 。

更详细地说，一个对象满足以下两个条件之一，即被判定为可达的。

本身是根对象 。根（root）是指由堆以外空间访问的对象。JVM会将以下对象标记为根：

虚拟机栈（栈帧中的本地变量表）中引用的对象；
方法区中的类静态属性引用的对象；
方法区中的常量引用的对象；
本地方法栈中JNI的引用对象

被一个可达的对象引用。

CMS的几个阶段

CMS 将可达性分析分解成两个阶段：

仅扫描与根节点直接关联的对象;
继续向下扫描完所有对象。

因此， 标记 阶段也被拆分成两个阶段，即 初始标记 和 并发标记 。

CMS完整的收集过程如下：

初始标记（init-mark） ：仅扫描与根节点直接关联的对象并标记，这个阶段必须 STW , 由于跟节点数量有限，所以这个过程非常短暂。
并发标记（concurrent-marking） ：与用户线程并发标记。这个阶段在初始标记的基础上继续向下追溯标记。在并发标记阶段，用户线程和标记线程并发执行，所以用户不会感受到停顿。
并发预清理（concurrent-precleaning） ：与用户线程并发进行。在并发标记阶段一些对象的引用已经发生了变化， precleaning 会发现这些引用关系的改变，并将存活的对象标记。举个例子：如果线程A有一个指向对象X的引用，并将该引用传递给了线程B，CMS需要记录下线程B持有了对象X，即使线程A已经不存在了。 precleaning 是为了减少下一阶段“重新标记”的工作量，因为 remark 阶段会 STW 。
重新标记（remark） ： remark 阶段会 STW 。如果应用正在并发运行且在不断地改变对象引用， CMS 则不能准确地确定某个对象是否存活。所以 CMS 会在 remark 阶段 STW ，从而获取所有引用关系的改变。
并发清理（concurrent-sweeping） ：清理垃圾对象，这个阶段GC线程和用户线程并发执行。
并发重置（concurrent-reset） ：重置CMS收集器的数据结构，做好下一次执行GC任务的准备工作。

【即插即用的硬干货】线上系统出现频繁 JVM FullGC 时，应该如何排查和处理？

线上Full GC分析

线上某服务的老年代配置了CMS，但却在gc.log发现连续Full GC的问题。JVM参数配置如下：

-XX:+UseCMSInitiatingOccupancyOnly
-XX:CMSInitiatingOccupancyFraction=68

参数的意义是：在老年代到 68% 的时候，会触发一次CMS GC，应该是出现类似如下的日志：

T20:10:37.803+0800: 3246087.559: [CMS-concurrent-mark-start]
T20:10:38.463+0800: 3246088.220: [CMS-concurrent-mark: 0.661/0.661 secs] [Times: user=3.17 sys=0.56, real=0.66 secs]
T20:10:38.463+0800: 3246088.220: [CMS-concurrent-preclean-start]
T20:10:38.552+0800: 3246088.309: [CMS-concurrent-preclean: 0.069/0.089 secs] [Times: user=0.14 sys=0.04, real=0.09 secs]_
T20:10:38.552+0800: 3246088.309: [CMS-concurrent-abortable-preclean-start]

但线上环境的日志却出现如下的情况：

【即插即用的硬干货】线上系统出现频繁 JVM FullGC 时，应该如何排查和处理？

老年代配置了900M，但却在只使用了50+M的时候触发了Full GC，而且是在短暂的时间内连续触发。

配置了CMS却触发Full GC，有以下几种可能：

大对象分配时，年轻代不够，直接晋升到老年代，老年代空间也不够，触发 Full GC（老年代还剩800+M，显然不可能）
内存碎片导致（由于CMS是基于标记清除算法的，所有会导致内存碎片，但通过grep -i "cms" gc.log，JVM尚未触发过CMS回收，所以也不存在内存碎片的说法）
CMS GC失败导致（从gc.log并未找到concurrent mode failure的记录，排除）
jmap -histo（人为执行该命令）

经笔者回忆，在中午快12点的时候确实登录过线上机，执行过 jmap -histo:live 命令，经验证，手动执行 jmap -histo:live ，也确实会在gc.log出现触发 Full GC的现象，问题得到验证。