CMS垃圾收集器

CMS（Concurrent Mark Sweep）收集器是以获取最短GC停顿时间为目标的收集器，它在垃圾收集时使得用户线程和GC线程能够并发执行，因此在垃圾收集过程中用户也不会感到明显的卡顿，多数应用于互联网网站或者B/S系统的服务端上。

CMS收集器是一个里程碑式的收集器，之前的收集器都是并行收集器，从CMS收集器开始后的都是并发收集器，但是CMS的缺点非常多，以至于所有的JDK版本没有一个将CMS收集器设置为默认的收集器。

长期来看，CMS收集器是要被G1等垃圾收集器替换掉的。在JDK8之后，使用它将会抛出一个警告。

Java HotSpot(TM) 64-Bit Server VM warning: Option UseConcMarkSweepGC was deprecated in version 9.0 and will likely be removed in a future release.

回收过程4步走

CMS收集器的回收过程分为下列4步：

初始标记（Initial Mark）：标记GC Roots能直接访问到的对象+新生代对象能访问到的老年代对象，这一步需要STW，但是速度很快，所以停顿时间很短。
并发标记（Concurrent Mark）：根据可达性分析算法，从上一步标记的对象开始，找出存活的对象，这个阶段用户线程和垃圾收集线程同时运行（并发），耗时较长（据统计80%的时间消耗在这个阶段），对客户端来说虽然响应时间慢了一些，但是至少还是有响应。
重新标记（Remark）：这个阶段为了修正并发标记期间因用户程序继续运行而导致错标的那一部分对象的标记记录，需要再次STW，但是时间不长。
并发清除（Concurrent Sweep）：使用标记-清除算法对垃圾对象进行回收。

优缺点

优点：

并发收集。
低停顿。

缺点：

对CPU资源非常敏感，CMS在收集过程中会开启(CPU核数+3/4（这个算法就是1/4向上取整）)个线程，对4核及以上的CPU影响较少，4核以下影响就比较大了，短时间内会造成大量的线程上下文切换，CPU占用率高。
会产生浮动垃圾（在并发标记和并发清理阶段，用户线程产生的新垃圾），可能出现Concurrent Model Failure失败而导致另一次Full GC的产生。因为垃圾收集线程核用户线程并发执行，必须要预留一定的空间给用户线程使用，因此CMS不能再老年代满了再执行垃圾回收操作，要预留一定的空间，所以CMS会在老年代的空间占用达到一定的比例时就会进行垃圾回收，这个比例可以由参数-XX:CMSInitiatingOccupancyFraction来指定，默认值为-1。
cms运行期间预留的内存不足以满足用户线程的需求，那么就会启用Serial Old收集器来进行老年代的垃圾回收，这样停顿时间就会更长了。
因为采用标记-清除算法所以会存在空间碎片的问题，空间碎片过多，会导致老年代明明有足够的空间，却无法为大对象分配一块连续的空间进行分配，不得不提前触发一次Full GC，所以JVM又提供了一个参数CMSCompactAtFullCollection用来在老年代Full GC时进行整理，这个过程又是无法并发的，空间碎片没有了，但是停顿时间不得不增长。

回收过程7步走

示例

/** * 演示CMS垃圾收集器日志的输出 * * -Xms20m -Xmx20m -Xmn10m -XX:SurvivorRatio=8 -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+UseConcMarkSweepGC */
public class CMSDemo {

    public static final int _1MB = 1024 * 1024;

    public static void main(String[] args) throws InterruptedException {

        byte[] b1 = new byte[4 * _1MB];
        System.out.println("----111----");
        byte[] b2 = new byte[4 * _1MB];
        System.out.println("----222----");
        byte[] b3 = new byte[4 * _1MB];
        System.out.println("----333----");
        byte[] b4 = new byte[2 * _1MB];
        System.out.println("----444----");
    }
}

日志输出如下：

----111----
2021-02-06T16:44:45.722+0800: 0.098: [GC (Allocation Failure) 2021-02-06T16:44:45.722+0800: 0.098: [ParNew: 5424K->581K(9216K), 0.0146141 secs] 5424K->4678K(19456K), 0.0146905 secs] [Times: user=0.03 sys=0.02, real=0.02 secs] 
----222----
2021-02-06T16:44:45.745+0800: 0.121: [GC (Allocation Failure) 2021-02-06T16:44:45.745+0800: 0.121: [ParNew: 4918K->330K(9216K), 0.0025120 secs] 9015K->9090K(19456K), 0.0025765 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2021-02-06T16:44:45.748+0800: 0.124: [GC (CMS Initial Mark) [1 CMS-initial-mark: 8760K(10240K)] 13186K(19456K), 0.0003743 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2021-02-06T16:44:45.749+0800: 0.125: [CMS-concurrent-mark-start]
----333----
----444----
2021-02-06T16:44:45.750+0800: 0.126: [CMS-concurrent-mark: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2021-02-06T16:44:45.750+0800: 0.126: [CMS-concurrent-preclean-start]
2021-02-06T16:44:45.750+0800: 0.126: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2021-02-06T16:44:45.750+0800: 0.126: [CMS-concurrent-abortable-preclean-start]
2021-02-06T16:44:45.750+0800: 0.126: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2021-02-06T16:44:45.750+0800: 0.126: [GC (CMS Final Remark) [YG occupancy: 6768 K (9216 K)]2021-02-06T16:44:45.750+0800: 0.126: [Rescan (parallel) , 0.0004946 secs]2021-02-06T16:44:45.751+0800: 0.127: [weak refs processing, 0.0000192 secs]2021-02-06T16:44:45.751+0800: 0.127: [class unloading, 0.0002698 secs]2021-02-06T16:44:45.751+0800: 0.127: [scrub symbol table, 0.0001761 secs]2021-02-06T16:44:45.751+0800: 0.127: [scrub string table, 0.0000488 secs][1 CMS-remark: 8760K(10240K)] 15528K(19456K), 0.0010916 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2021-02-06T16:44:45.751+0800: 0.127: [CMS-concurrent-sweep-start]
2021-02-06T16:44:45.752+0800: 0.128: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2021-02-06T16:44:45.752+0800: 0.128: [CMS-concurrent-reset-start]
2021-02-06T16:44:45.752+0800: 0.128: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap
 par new generation   total 9216K, used 6932K [0x04800000, 0x05200000, 0x05200000)
  eden space 8192K,  80% used [0x04800000, 0x04e72980, 0x05000000)
  from space 1024K,  32% used [0x05000000, 0x05052908, 0x05100000)
  to   space 1024K,   0% used [0x05100000, 0x05100000, 0x05200000)
 concurrent mark-sweep generation total 10240K, used 8759K [0x05200000, 0x05c00000, 0x05c00000)
 Metaspace       used 144K, capacity 2280K, committed 2368K, reserved 4480K

下面对上面的日志进行具体分析。

MinorGC

2021-02-06T16:44:45.722+0800: 0.098: [GC (Allocation Failure) 2021-02-06T16:44:45.722+0800: 0.098: [ParNew: 5424K->581K(9216K), 0.0146141 secs] 5424K->4678K(19456K), 0.0146905 secs] [Times: user=0.03 sys=0.02, real=0.02 secs]

2021-02-06T16:44:45.722+0800：GC开始时间，由参数-XX:+PrintGCDateStamps控制。
0.098：GC开始，相对JVM启动的相对时间，单位是秒。
GC：区别MinorGC和FullGC的标识，这次代表的是MinorGC。
Allocation Failure：MinorGC发生的原因，在这里时由于年轻代不满足申请的空间，因此触发了MinorGC。
ParNew：新生代使用的垃圾收集器的名称。
5424K->581K：收集前后年轻代的使用情况。
9216K：整个年轻代的容量。
0.0146141 secs：这个解释用原滋原味的解释：Duration for the collection w/o final cleanup.
5424K->4678K：收集前后整个堆的使用情况。
19456K：整个堆的容量。
0.0146905 secs：ParNew收集器标记和复制年轻代活着的对象所花费的时间（包括和老年代通信的开销、对象晋升到老年代时间、垃圾收集周期结束一些最后的清理对象等的花销）。
user=0.03 sys=0.02, real=0.02 secs：GC事件的持续时间，通过多种分类来进行衡量:
user：此次垃圾回收, 垃圾收集线程消耗的所有CPU时间(Total CPU time).
sys：操作系统调用(OS call) 以及等待系统事件的时间(waiting for system event)
real：应用程序暂停的时间(Clock time). 由于串行垃圾收集器(Serial Garbage Collector)只会使用单个线程, 所以real time等于user以及system time的总和，多线程下并不会相等。

Initial Mark

这是CMS回收过程中两次STW中的一次，这个阶段主要是找出所有GCROOTs所直接引用的对象，以及新生代中对象所引用的老年代对象。

2021-02-06T16:44:45.748+0800: 0.124: [GC (CMS Initial Mark) [1 CMS-initial-mark: 8760K(10240K)] 13186K(19456K), 0.0003743 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

CMS Initial Mark：初始标记阶段，收集所有的GC Roots和新生代直接引用的老年代对象。
8760K：当前老年代使用情况。
10240K：老年代的容量。
13186K：当前整个堆的使用情况。
19456K：整个堆的容量。

Concurrent Mark

这个阶段会根据上一个阶段中找到的对象开始遍历老年代的所有对象，然后标记出存活的对象。并发标记阶段垃圾回收线程和用户线程并发执行，并不是老年代所有存活的对象都会被标记，因为在用户线程会改变对象的一些引用。

在上面的图中，与阶段1的图进行对象，就会发现有一个对象的引用发生了变化。

2021-02-06T16:44:45.749+0800: 0.125: [CMS-concurrent-mark-start]
2021-02-06T16:44:45.750+0800: 0.126: [CMS-concurrent-mark: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

0.001/0.001 secs：展示该阶段持续的时间和时钟时间。

Concurrent Preclean

这个阶段又是一个并发阶段，和应用线程并行运行，不会中断他们。前一个阶段在并行运行的时候，一些对象的引用已经发生了变化，当这些引用发生变化的时候，JVM会标记堆的这个区域为Dirty Card(包含被标记但是改变了的对象，被认为"dirty")，这就是Card Marking。

在pre-clean阶段，那些能够从dirty card对象到达的对象也会被标记，这个标记做完之后，dirty card标记就会被清除了，如下：

另外，一些必要的清扫工作也会做，还会做一些final remark阶段需要的准备工作。

2021-02-06T16:44:45.750+0800: 0.126: [CMS-concurrent-preclean-start]
2021-02-06T16:44:45.750+0800: 0.126: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

Concurrent Abortable Preclean

又一个并发阶段，不会停止应用程序线程。这个阶段尝试着去承担STW的Final Remark阶段足够多的工作。这个阶段持续的时间依赖好多的因素，由于这个阶段是重复的做相同的事情直到发生aboart的条件（比如：重复的次数、多少量的工作、持续的时间等等）之一才会停止。

这个阶段很大程度的影响着即将来临的Final Remark的停顿，有相当一部分重要的 configuration options 和失败的模式；

2021-02-06T16:44:45.750+0800: 0.126: [CMS-concurrent-abortable-preclean-start]
2021-02-06T16:44:45.750+0800: 0.126: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

Final Remark

这个阶段是CMS中第二个并且是最后一个STW的阶段。该阶段的任务是完成标记整个年老代的所有的存活对象。由于之前的预处理是并发的，它可能跟不上应用程序改变的速度，这个时候，STW是非常需要的来完成这个严酷考验的阶段。

通常CMS尽量运行Final Remark阶段在年轻代是足够干净的时候，目的是消除紧接着的连续的几个STW阶段。

通过以上5个阶段的标记，老年代所有存活的对象已经被标记并且现在要通过Garbage Collector采用清扫的方式回收那些不能用的对象了。

2021-02-06T16:44:45.750+0800: 0.126: [GC (CMS Final Remark) [YG occupancy: 6768 K (9216 K)]2021-02-06T16:44:45.750+0800: 0.126: [Rescan (parallel) , 0.0004946 secs]2021-02-06T16:44:45.751+0800: 0.127: [weak refs processing, 0.0000192 secs]2021-02-06T16:44:45.751+0800: 0.127: [class unloading, 0.0002698 secs]2021-02-06T16:44:45.751+0800: 0.127: [scrub symbol table, 0.0001761 secs]2021-02-06T16:44:45.751+0800: 0.127: [scrub string table, 0.0000488 secs][1 CMS-remark: 8760K(10240K)] 15528K(19456K), 0.0010916 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

YG occupancy: 6768 K (9216 K)：年轻代当前占用情况和容量。
Rescan (parallel) , 0.0004946 secs：STW，重新标记存活的对象花费的时间。
weak refs processing, 0.0000192 secs：第一个子阶段，处理弱引用。
class unloading, 0.0002698 secs：第二个子阶段，类卸载。
scrub symbol table, 0.0001761 secs：第三个子阶段，清理符号表。
scrub string table, 0.0000488 secs：第四个子阶段，清理字符串表。
8760K(10240K)：在这个阶段之后老年代占有的内存大小和老年代的容量。
15528K(19456K)：在这个阶段之后整个堆的内存大小和整个堆的容量。

Concurrent Sweep

和应用线程同时进行，不需要STW。这个阶段的目的就是移除那些不用的对象，回收他们占用的空间并且为将来使用。

2021-02-06T16:44:45.751+0800: 0.127: [CMS-concurrent-sweep-start]
2021-02-06T16:44:45.752+0800: 0.128: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

Concurrent Reset

这个阶段并发执行，重新设置CMS算法内部的数据结构，准备下一个CMS生命周期的使用。

2021-02-06T16:44:45.752+0800: 0.128: [CMS-concurrent-reset-start]
2021-02-06T16:44:45.752+0800: 0.128: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

CMS垃圾收集器及日志详解