CMS日志

1. GC参数配置

-XX:+PrintGC

输出GC日志。

-verbose:gc

能够认为 -verbose:gc 是 -XX:+PrintGC 的别名。

-Xloggc:log/gc.log

输出GC日志的存储路径。

-XX:+PrintGCDetails

输出GC的详细日志。

-XX:+PrintGCDateStamps

输出GC的时间戳（以日期的形式）。

-XX:+ExplicitGCInvokesConcurrent

不管何时调用系统GC，都执行CMS GC，而不是Full GC。

-XX:+PrintHeapAtGC

在进行GC的先后打印出堆的信息。

-Xms512m

设置初始堆的大小。

-Xmx512m

堆分配的最大空间。

-Xmn1024m

设置年轻代大小。

整个JVM内存大小 = 年轻代大小 + 年老代大小 + 持久代大小，持久代通常固定大小为64m，因此增大年轻代后，将会减少年老代大小。此值对系统性能影响较大，Sun官方推荐配置为整个堆的3/8。

-Xss320K

设置每一个线程的堆栈大小。

JDK5.0之后每一个线程堆栈大小为1M，之前每一个线程堆栈大小为256K。根据应用的线程所需内存大小进行调整。在相同物理内存下，减少这个值能生成更多的线程。可是操做系统对一个进程内的线程数仍是有限制的，不能无限生成，经验值在3000~5000左右。

-XX:+UseConcMarkSweepGC

使用CMS收集器，其它相似。

-XX:NewRatio=4

设置年轻代（包括Eden和两个Survivor区）与年老代的比值（除去持久代）。设置为4，则年轻代与年老代所占比值为1：4，年轻代占整个堆栈的1/5，默认值是2即老年代是新生代内存的2倍

-XX:SurvivorRatio=4

设置年轻代中Eden区与Survivor区的大小比值。设置为4，则两个Survivor区与一个Eden区的比值为2:4，一个Survivor区占整个年轻代的1/6，默认值为8。

-XX:MaxPermSize=16m

设置持久代大小为16m。

-XX:MaxTenuringThreshold=0

设置垃圾最大年龄。若是设置为0的话，则年轻代对象不通过Survivor区，直接进入年老代。对于年老代比较多的应用，能够提升效率。若是将此值设置为一个较大值，则年轻代对象会在Survivor区进行屡次复制，这样能够增长对象再年轻代的存活时间，增长在年轻代即被回收的概论。

GC[Allocation Failure]表示向young generation(eden)给新对象申请空间，可是young generation(eden)剩余的合适空间不够所需的大小致使的minor gc。

2. Minor GC: UseParNewGC 回收日志

2018-12-29T14:39:40.102+0800: 3.856: [GC (Allocation Failure) 2018-12-29T14:39:40.102+0800: 3.856: [ParNew: 681600K->72044K(766784K), 0.0977206 secs] 681600K->72044K(4109120K), 0.0978554 secs] [Times: user=0.39 
sys=0.06, real=0.10 secs]

2018-12-29T14:39:40.102+0800 本次gc触发的时间；

3.856 jvm启动后所经历的秒数；

GC (Allocation Failure) 对象分配在新生代但空间不够致使触发一次新生代gc；

ParNew 表示这是新生代gc类型, 即ParNewGC；

681600K->72044K(766784K), 0.0977206 secs 触发新生代gc时年轻代堆的大小，回收后的年轻代堆的大小，年轻代堆的总大小，该次gc回收所耗费的时间；

681600K->72044K(4109120K) 回收前堆的总大小，回收后堆的总大小，堆的总大小。

3. Major GC: UseConcMarkSweepGC 垃圾收集

CMS垃圾收集器总共分为7个阶段，其中有2个阶段，便是初始标记和最终标记阶段，是须要暂停用户线程的，其他垃圾收集线程均与用户线程并发执行。

CMS垃圾收集器在新版本的 Java 中被标记为弃用，后续的垃圾收集器默认使用G1GC。但目前很大一部分的垃圾收集器依然是CMS，故须要了解一下CMS垃圾收集的一些流程。

3.1 Phase 1: Initial Mark 初始标记

2018-12-29T14:46:45.247+0800: 429.000: [GC (CMS Initial Mark) [1 CMS-initial-mark: 17305K(3342336K)] 607785K(4109120K), 0.0704856 secs] [Times: user=0.32 sys=0.10, real=0.07 secs]

这是CMS中两次stop-the-world事件中的一次。它有两个目标：一是标记老年代中全部的GC Roots；二是标记被年轻代中活着的对象引用的对象；

[1 CMS-initial-mark 收集阶段，开始收集全部的GC Roots和直接引用到的对象；

17305K(3342336K) 当前老年代的使用状况，老年代可用容量；

607785K(4109120K) 当前整个堆的使用状况，整个堆的容量，便是整个堆 - 老年代 = 新生代(4109120 - 3342336 = 766784)。

3.2 Phase 2: Concurrent Mark 并发标记

2018-12-29T14:46:45.317+0800: 429.071: [CMS-concurrent-mark-start]
2018-12-29T14:46:45.326+0800: 429.080: [CMS-concurrent-mark: 0.009/0.009 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]

这个阶段会遍历整个老年代而且标记全部存活的对象，从“初始化标记”阶段找到的GC Roots开始。并发标记的特色是和应用程序线程同时运行。并非老年代的全部存活对象都会被标记，由于标记的同时应用程序会改变一些对象的引用等；

CMS-concurrent-mark 并发收集阶段，这个阶段会遍历整个年老代而且标记活着的对象。

0.009/0.009 secs 展现该阶段持续的时间和时钟时间。

3.3 Phase 3: Concurrent Preclean 并发预清除

2018-12-29T14:46:45.326+0800: 429.080: [CMS-concurrent-preclean-start]
2018-12-29T14:46:45.338+0800: 429.092: [CMS-concurrent-preclean: 0.012/0.012 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]

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

在pre-clean阶段，那些可以从dirty card对象到达的对象也会被标记，这个标记作完以后，dirty card标记就会被清除了；

一些必要的清扫工做也会作，还会作一些final remark阶段须要的准备工做；

CMS-concurrent-preclean 这个阶段负责前一个阶段标记了又发生改变的对象标记。

3.4 Phase 4: Concurrent Abortable Preclean 可终止的并发预清理

2018-12-29T14:46:45.338+0800: 429.092: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 2018-12-29T14:46:50.484+0800: 434.238: [CMS-concurrent-abortable-preclean: 4.232/5.146 secs] [Times: user=5.49 sys=0.10, real=5.15 secs]

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

CMS-concurrent-abortable-preclean 可终止的并发预清理；

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

3.5 Phase 5: Final Remark 最终标记

2018-12-29T14:46:50.485+0800: 434.239: [GC (CMS Final Remark) [YG occupancy: 632074 K (766784 K)]2018-12-29T14:46:50.485+0800: 434.239: [Rescan (parallel) , 0.0791637 secs]2018-12-29T14:46:50.564+0800: 434.318: 
[weak refs processing, 0.0001243 secs]2018-12-29T14:46:50.565+0800: 434.318: [class unloading, 0.0409380 secs]2018-12-29T14:46:50.605+0800: 434.359: [scrub symbol table, 0.0136356 secs]2018-12-29T14:46:50.619+08
00: 434.373: [scrub string table, 0.0015586 secs][1 CMS-remark: 17305K(3342336K)] 649380K(4109120K), 0.1370772 secs] [Times: user=0.46 sys=0.06, real=0.13 secs]

这个阶段是CMS中第二个而且是最后一个STW的阶段。该阶段的任务是完成标记整个年老代的全部的存活对象。因为以前的预处理是并发的，它可能跟不上应用程序改变的速度，这个时候，STW是很是须要的来完成这个严酷考验的阶段；

一般CMS尽可能运行Final Remark阶段在年轻代是足够干净的时候，目的是消除紧接着的连续的几个STW阶段；

CMS Final Remark 收集阶段，这个阶段会标记老年代所有的存活对象，包括那些在并发标记阶段更改的或者新建立的引用对象；

YG occupancy: 632074 K (766784 K) 年轻代当前占用的状况和容量；

Rescan (parallel) 这个阶段在应用中止的阶段完成存活对象的标记工做；

weak refs processing 第一个子阶段，随着这个阶段的进行处理弱引用；

class unloading 第二个子阶段, 类的卸载；

scrub symbol table 最后一个子阶段, 清理字符引用等；

1 CMS-remark: 17305K(3342336K) 在这个阶段以后老年代占有的内存大小和老年代的容量；

649380K(4109120K) 在这个阶段以后整个堆的内存大小和整个堆的容量；

经过以上5个阶段的标记，老年代全部存活的对象已经被标记而且如今要经过Garbage Collector采用清扫的方式回收那些不能用的对象了。

3.6 Phase 6: Concurrent Sweep 并发清除

2018-12-29T14:46:50.622+0800: 434.376: [CMS-concurrent-sweep-start]
2018-12-29T14:46:50.635+0800: 434.388: [CMS-concurrent-sweep: 0.012/0.012 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]

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

CMS-concurrent-sweep 这个阶段主要是清除那些没有标记的对象而且回收空间。

3.7 Phase 7: Concurrent Reset 并发重置

2018-12-29T14:46:50.635+0800: 434.388: [CMS-concurrent-reset-start]
2018-12-29T14:46:50.651+0800: 434.405: [CMS-concurrent-reset: 0.016/0.016 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]

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

CMS-concurrent-reset 这个阶段从新设置CMS算法内部的数据结构，为下一个收集阶段作准备；

可参考JVM调优——之CMS GC日志分析。