HotSpot的G1收集器（日志分析）

-Xmx1024m -Xms1024m -XX:+UseG1GC -XX:+PrintGCDetails -XX:MaxGCPauseMillis=200 -Xloggc:/Users/xuefeihu/Desktop/gc.log

# 初始标记（包含一次新生代GC）
9.585: [GC pause (Metadata GC Threshold) (young) (initial-mark), 0.0465863 secs]  # 程序暂停0.046s
   [Parallel Time: 35.8 ms, GC Workers: 4]  # 并行时间35.8ms，4个GC线程
      [GC Worker Start (ms): Min: 9584.8, Avg: 9584.8, Max: 9584.9, Diff: 0.0] #开始时刻
      [Ext Root Scanning (ms): Min: 2.5, Avg: 2.7, Max: 3.1, Diff: 0.5, Sum: 11.0] #根扫描耗时
      [Update RS (ms): Min: 0.3, Avg: 0.5, Max: 0.7, Diff: 0.3, Sum: 1.9] #更细记忆集（RS, Remembered Set）耗时
# G1中每块区域都有一个RS与之对应，RS记录了该区域被其他区域引用的对象。回收时，就把RS作为根集的一部分，从而加快回收。
         [Processed Buffers: Min: 1, Avg: 2.0, Max: 4, Diff: 3, Sum: 8]  #Processed Buffers就是记录引用变化的缓存空间
      [Scan RS (ms): Min: 0.3, Avg: 0.4, Max: 0.5, Diff: 0.1, Sum: 1.5]  #扫描RS耗时
      [Code Root Scanning (ms): Min: 0.2, Avg: 0.7, Max: 1.6, Diff: 1.4, Sum: 2.9] #根扫描耗时
      [Object Copy (ms): Min: 21.6, Avg: 22.4, Max: 22.8, Diff: 1.2, Sum: 89.4] #对象拷贝（疏散回收的区域）
      [Termination (ms): Min: 0.0, Avg: 2.6, Max: 9.1, Diff: 9.1, Sum: 10.3] #线程在终止阶段的耗时
#（线程在终止前，会检查其他线程的队列，看是否有未清理完的Reference。如有则帮助其他线程清理，之后再尝试终止）
         [Termination Attempts: Min: 1, Avg: 1.2, Max: 2, Diff: 1, Sum: 5] #尝试终止次数
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] #GC线程花在其他任务中的耗时
      [GC Worker Total (ms): Min: 26.8, Avg: 29.3, Max: 35.8, Diff: 9.0, Sum: 117.1] # GC线程耗时
      [GC Worker End (ms): Min: 9611.6, Avg: 9614.1, Max: 9620.6, Diff: 9.0] # 完成时刻
   [Code Root Fixup: 0.8 ms]
   [Code Root Purge: 0.2 ms]
   [Clear CT: 0.1 ms] #清空CardTable耗时，RS是依赖CardTable记录区域存活对象的
   [Other: 9.7 ms] # 其他任务耗时
      [Choose CSet: 0.0 ms] #选取将要被回收的区域的集合 耗时
      [Ref Proc: 8.6 ms] #弱引用、软引用的处理耗时
      [Ref Enq: 0.1 ms] #弱引用、软引用的入队耗时
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.0 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.5 ms] # 释放被回收区域的耗时（包含他们的RS）
   [Eden: 92.0M(97.0M)->0.0B(187.0M) Survivors: 9216.0K->12.0M Heap: 108.0M(1024.0M)->23.5M(1024.0M)]
 [Times: user=0.10 sys=0.01, real=0.05 secs] 
# 根区域扫描
9.634: [GC concurrent-root-region-scan-start]
9.652: [GC concurrent-root-region-scan-end, 0.0184308 secs]
# 并发标记
9.652: [GC concurrent-mark-start]
9.693: [GC concurrent-mark-end, 0.0406187 secs]
# 重新标记
9.695: [GC remark 9.695: [Finalize Marking, 0.0005100 secs] 9.695: [GC ref-proc, 0.0003461 secs] 9.696: [Unloading, 0.0069466 secs], 0.0082011 secs]
 [Times: user=0.02 sys=0.00, real=0.01 secs] 
# 独占清理
9.703: [GC cleanup 25M->21M(1024M), 0.0027119 secs]
 [Times: user=0.00 sys=0.01, real=0.00 secs] 
# 并发清理
9.706: [GC concurrent-cleanup-start]
9.706: [GC concurrent-cleanup-end, 0.0000167 secs]
# 新生代GC
12.560: [GC pause (G1 Evacuation Pause) (young), 0.0631821 secs]
......   


# 下一轮的并发标记周期
12.701: [GC pause (Metadata GC Threshold) (young) (initial-mark), 0.0206027 secs]
   [Parallel Time: 18.9 ms, GC Workers: 4]
......

# 混合回收 （其日志的详情可以参考，新生代GC的日志）
18.315: [GC pause (G1 Evacuation Pause) (mixed), 0.0095319 secs]
   [Parallel Time: 8.6 ms, GC Workers: 4]
      [GC Worker Start (ms): Min: 18315.3, Avg: 18315.3, Max: 18315.3, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 0.5, Avg: 0.8, Max: 1.2, Diff: 0.7, Sum: 3.2]
      [Update RS (ms): Min: 2.2, Avg: 2.5, Max: 2.6, Diff: 0.4, Sum: 9.9]
         [Processed Buffers: Min: 2, Avg: 4.0, Max: 5, Diff: 3, Sum: 16]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.1]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.1, Max: 0.4, Diff: 0.4, Sum: 0.4]
      [Object Copy (ms): Min: 4.7, Avg: 5.1, Max: 5.3, Diff: 0.6, Sum: 20.4]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 8.5, Avg: 8.5, Max: 8.5, Diff: 0.0, Sum: 34.0]
      [GC Worker End (ms): Min: 18323.8, Avg: 18323.8, Max: 18323.8, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 0.8 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.6 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.0 ms]
      [Humongous Register: 0.0 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.0 ms]
   [Eden: 1024.0K(1024.0K)->0.0B(89.0M) Survivors: 7168.0K->1024.0K Heap: 40.5M(150.0M)->37.0M(150.0M)]
 [Times: user=0.03 sys=0.00, real=0.01 secs] 
......