垃圾收集器之 Concurrent Mark Sweep 并发标记清除

上几篇文章我们讲解了单线程垃圾收集器 Serial/SerialOld ,多线程垃圾收集器 Parallel Scavenge/Old, 本文我们讲解下 Concurrent Mark Sweep 简称CMS垃圾收集器

垃圾收集器

• 新生代收集器： Serial、ParNew、Parallel Scavenge；
• 老年代收集器： Serial Old、CMS、Parallel Old；
• 通用收集器： G1；

收集器常用组合：

1. Serial + Serial Old JVM设置-XX:+UseSerialGC
2. Parallel Scavenge + Parallel Old JVM设置-XX:+UseParallelGC -XX:-UseParallelOldGC
3. ParNew + CMS配合 JVM设置-XX:+UseParNewGC -XX:+UseConcMarkSweepGC
4. G1（不需要组合其他收集器） JVM设置-XX:+UseG1GC

今天我们要讲的就是 Concurrent Mark Sweep 收集器

1.CMS Concurrent Mark Sweep标记清除收集器

• 它是一种以获取最短回收停顿时间为目标的收集器。
• 它非常符合在注重用户体验的应用上使用，是一款真正意义上的并发收集器
• 它第一次实现了让垃圾收集线程与用户线程（基本上）同时工作。

1.1 CMS垃圾收集器工作流程

CMS执行垃圾清除算法可以分为以下7个步骤：

• 初始标记（STW）
• 并发标记
• 预处理
• 可中断的预处理
• 重新标记（STW）
• 并发清除
• 并发重置

下面我们详细讲解下CMS采用标记清除算法

运行过程分为五步骤：

• 1. 初始标记：会暂停其他线程STW，从gc root开始，只标记gc root能直接引用的对象，速度很快
• 2. 并发标记：这个阶段会从gc root往下遍历所有关联的对象，耗时很长，但是不需要用户线程停顿，可以和用户线程同时一起执行，用户感知不到，但是可能会导致已经标记过的对象状态发生改变
     • 比如你第一次标记了A，现在用户再次操作A的标记已经变了，所以A对象后面需要重新标记，这就引入了第三阶段
• 3. 预处理 参数 CMSPrecleaningEnabled 选择关闭该阶段，默认启用
  • 处理新生代已经发现的引用，比如在并发阶段，在Eden区中分配了一个A对象，A对象引用了一个老年代对象B（这个B之前没有被标记），在这个阶段就会标记对象B为活跃对象。
  • 在并发标记阶段，如果老年代中有对象内部引用发生变化，会重新标记那些在并发标记阶段引用被更新的对象
• 4.可中断的预清理 CMSScheduleRemarkEdenSizeThreshold控制是否需要该阶段
  • 新生代的对象太少，就没有必要执行该阶段，直接执行重新标记阶段
• 5. 重新标记：这个阶段是为了修正之前用户线程运行产生变动的标记记录，主要就是为了处理漏标的问题，这个阶段会暂停用户线程STW，暂时时间比初始标记阶段长，但是比并标记阶段时间短
     • 该阶段采用三色标记里的增量更新算法做重新标记
• 6.并发清理：开启用户线程，此阶段用户线程和垃圾回收线程同时执行，开始回收垃圾对象，gc开始清理未标记的区域，这个阶段如果有新增的对象，会被标记为黑色且不做任何处理
• 7.并发重置：重置gc过程的标记数据，为下一次gc做准备

1.2 CMS垃圾收集器的优缺点

• 优点
  • 并发收集垃圾，停顿时间短，第一次真正意义上的并发
  • 延迟较低，用户体验较好
• 缺点
  • 竞争服务器资源，因为它收集线程和用户线程同时执行，互相抢占CPU资源，加剧CPU轮转切换
  • 并发标记和并发清理阶段，依旧会有浮动垃圾，无法处理，甚至会导致FullGC
  • 采用标记清除算法，会产生大量内存碎片，导致大对象无法分配不得不提前触发FullGC

2.CMS JVM参数配置

• -XX:+UseConcMarkSweepGC
  • 配置启用CMS
• -XX:+UseCMSCompactAtFullCollection
  • FullGC之后做压缩整理（减少碎片），针对标记清除算法的优化
• -XX:CMSFullGCsBeforeCompaction
  • 多少次FullGC之后压缩一次，默认是0，代表每次FullGC后都会压缩一次
• -XX:CMSInitiatingOccupancyFraction
  • 设置老年代的阈值，当达到阈值时会触发Full GC，默认时92%

2.1 CMS测试

设置JVM参数,启用CMS垃圾收集器

-verbose:gc -XX:+UseConcMarkSweepGC -Xms10M -Xmx10M  -XX:+PrintGC -XX:+PrintGCDetails -XX:+HeapDumpOnOutOfMemoryError -XX:SurvivorRatio=8

CMSTest测试类，测试

@Slf4j
public class CMSTest {

    //JVM 参数 -verbose:gc -Xms10M -Xmx10M  -XX:+PrintGC -XX:+PrintGCDetails -XX:+HeapDumpOnOutOfMemoryError -XX:SurvivorRatio=8
    public static void main(String[] args) throws Exception {
        byte[] b = null;
        for (int i = 1; i <= 10; i++) {
            //设置 1M的对象
            log.info("======== " + i + "次添加1M对象");
            b = new byte[1 * 1024 * 1024];
            Thread.sleep(100);

        }
    }
}

打印GC日志

[GC (Allocation Failure) [ParNew: 2752K->320K(3072K), 0.0016638 secs] 2752K->916K(9920K), 0.0017058 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC (Allocation Failure) [ParNew: 3072K->320K(3072K), 0.0008008 secs] 3668K->1465K(9920K), 0.0008248 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
00:10:15.957 [main] INFO com.jzj.jvmtest.jvmready.CMSTest - ======== 1次添加1M对象
00:10:16.074 [main] INFO com.jzj.jvmtest.jvmready.CMSTest - ======== 2次添加1M对象
[GC (Allocation Failure) [ParNew: 2748K->320K(3072K), 0.0011250 secs] 3894K->2792K(9920K), 0.0011456 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
00:10:16.185 [main] INFO com.jzj.jvmtest.jvmready.CMSTest - ======== 3次添加1M对象
00:10:16.297 [main] INFO com.jzj.jvmtest.jvmready.CMSTest - ======== 4次添加1M对象
[GC (Allocation Failure) [ParNew: 2420K->22K(3072K), 0.0012212 secs] 4893K->3736K(9920K), 0.0012419 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC (CMS Initial Mark) [1 CMS-initial-mark: 3714K(6848K)] 4760K(9920K), 0.0004679 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[CMS-concurrent-mark-start]
[CMS-concurrent-mark: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[CMS-concurrent-preclean-start]
[CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC (CMS Final Remark) [YG occupancy: 1046 K (3072 K)][Rescan (parallel) , 0.0001200 secs][weak refs processing, 0.0000285 secs][class unloading, 0.0003868 secs][scrub symbol table, 0.0004698 secs][scrub string table, 0.0001029 secs][1 CMS-remark: 3714K(6848K)] 4760K(9920K), 0.0011706 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[CMS-concurrent-sweep-start]
[CMS-concurrent-sweep: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[CMS-concurrent-reset-start]
[CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
00:10:16.406 [main] INFO com.jzj.jvmtest.jvmready.CMSTest - ======== 5次添加1M对象
00:10:16.517 [main] INFO com.jzj.jvmtest.jvmready.CMSTest - ======== 6次添加1M对象
[GC (Allocation Failure) [ParNew: 2123K->11K(3072K), 0.0005590 secs] 3491K->2403K(9920K), 0.0006038 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
00:10:16.629 [main] INFO com.jzj.jvmtest.jvmready.CMSTest - ======== 7次添加1M对象
00:10:16.741 [main] INFO com.jzj.jvmtest.jvmready.CMSTest - ======== 8次添加1M对象
[GC (Allocation Failure) [ParNew: 2112K->2K(3072K), 0.0004189 secs] 4504K->3418K(9920K), 0.0004425 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
00:10:16.853 [main] INFO com.jzj.jvmtest.jvmready.CMSTest - ======== 9次添加1M对象
00:10:16.963 [main] INFO com.jzj.jvmtest.jvmready.CMSTest - ======== 10次添加1M对象
[GC (Allocation Failure) [ParNew: 2533K->139K(3072K), 0.0007700 secs] 5949K->4580K(9920K), 0.0007987 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap
 par new generation   total 3072K, used 1191K [0x00000000ff600000, 0x00000000ff950000, 0x00000000ff950000)
  eden space 2752K,  38% used [0x00000000ff600000, 0x00000000ff706f98, 0x00000000ff8b0000)
  from space 320K,  43% used [0x00000000ff900000, 0x00000000ff922f78, 0x00000000ff950000)
  to   space 320K,   0% used [0x00000000ff8b0000, 0x00000000ff8b0000, 0x00000000ff900000)
 concurrent mark-sweep generation total 6848K, used 4440K [0x00000000ff950000, 0x0000000100000000, 0x0000000100000000)
 Metaspace       used 5178K, capacity 5308K, committed 5504K, reserved 1056768K
  class space    used 574K, capacity 596K, committed 640K, reserved 1048576K

3.GC日志分析

• par new generation total 3072K 年轻代大小
• concurrent mark-sweep generation total 6848K 老年代大小
• Eden space 2752K eden区
• from space from区 320K
• to space to区 320K
• Metaspace 元空间 5308K

CMS GC日志分析 gc执行步骤

• GC (Allocation Failure) ParNew 新生代采用的是ParNew 收集器来收集新生代垃圾CMS-concurrent-sweep-start
• GC (CMS Initial Mark) 第一步 初始标记 会发生STW
• CMS-concurrent-mark-start 第二步 并发标记 会出现浮动垃圾
• CMS-concurrent-preclean-start 第三步 预处理，没有第四步 可中断预处理
• GC (CMS Final Remark) 第五步 重新标记 会发生STW
• CMS-concurrent-sweep-start 第六步 并发清理
• CMS-concurrent-reset-start 第七步 并发重置

CMS GC日志内容分析

[GC (Allocation Failure) [ParNew: 2752K->320K(3072K), 0.0016638 secs] 2752K->916K(9920K), 0.0017058 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 

• ParNew: 2752K->320K(3072K), 0.0016638 secs 新生代 gc前占用2752K，gc回收后320K, 回收了垃圾 2752-320=2432 本次年轻代回收了2432K， 年轻代总大小 3072K，gc回收垃圾耗时0.0016638 secs
• 2752K->916K(9920K), 0.0017058 secs ，Java堆 gc回收前占用2752K，g回收收获占用916K,Java堆总大小 9920K， 本次堆回收了 2752-916=1836K
• 该次GC新生代减少了2752-320=2432， Java堆总共减少了2752-916=1836K， 所以 年轻代减少的2432 - 老年代减少的1836=596K 说明该次共有596K内存从年轻代移到了老年代

[GC (CMS Initial Mark) [1 CMS-initial-mark: 3714K(6848K)] 4760K(9920K), 0.0004679 secs]

1. CMS 初始标记阶段STW， 老年代使用量 3714K，老年代总量6848， java堆使用量4760K， java堆总量9920K

[CMS-concurrent-mark-start]
[CMS-concurrent-mark: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 

2. CMS并发标记阶段，耗时 0.001 secs

[CMS-concurrent-preclean-start]
[CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 

3. 并发预处理阶段，会查找前一段执行过程中，冲新生代升级的对象或者被更新了的对象，预处理重新扫描标记，减少下一个阶段重新标记的工作量
4. 并发可终止阶段，是为了控制时间，比如扫描多长时间或者eden区比例就终止本阶段

[GC (CMS Final Remark)
[YG occupancy: 1046 K (3072 K)]
[Rescan (parallel) , 0.0001200 secs]
[weak refs processing, 0.0000285 secs][class unloading, 0.0003868 secs]
[scrub symbol table, 0.0004698 secs][scrub string table, 0.0001029 secs]
[1 CMS-remark: 3714K(6848K)] 4760K(9920K), 0.0011706 secs]
[Times: user=0.00 sys=0.00, real=0.00 secs] 

5. 重新标记阶段/最终标记阶段 STW, 从GC Root开始重新扫描整堆，标记存活的对象。需要注意的是，虽然CMS只回收老年代的垃圾对象，但是这个阶段依然需要扫描新生代，因为GC Root很多都在新生代

   • CMS Final Remark 最终标记阶段
   • YG occupancy: 1046 K (3072 K) 新生代大小为1046K， 新生代总大小3072K
   • Rescan (parallel) , 0.0001200 secs 暂停用户标记情况下，并发的标记对象的过程花费0.0001200 secs
   • weak refs processing, 0.0000285 secs 标记弱引用对象
   • class unloading, 0.0003868 secs 标记已经卸载的类对象
   • scrub symbol table, 0.0004698 secs 标记常量池未被引用的对象
   • scrub string table, 0.0001029 secs 标记常量池String类型未被引用的对象
   • 1 CMS-remark: 3714K(6848K)] 4760K(9920K), 0.0011706 secs 重新标记后 老年代使用3714K，老年代总量6848K， java堆使用量 4760K，java堆总量9920K

[CMS-concurrent-sweep-start]
[CMS-concurrent-sweep: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 

6. 并发清除阶段，清除标记的垃圾对象，花费0.001 secs

[CMS-concurrent-reset-start]
[CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 

7. 并发重置阶段，重置数据和结构信息 及花费的时间

---

至此 我们讲解了CMS垃圾收集器的配置参数及如何使用CMS垃圾收集器，并且我们通过程序调试JVM参数，配置了CMS垃圾收集器，打印了GC日志，通过对GC日志的分析，能够很好的在实战中了解到底是哪里出了问题，便于JVM调优