G1垃圾收集器(10)之mixed gc日志

2021-06-23 00:31:02 浏览数 (1)

并发标记日志

并发标记是全局的,与回收过程是两个阶段,所以并发标记可以说是独立的。

代码语言:javascript复制
//并发标记 - 初始标记阶段,在年轻代GC中完成
100.070: [GC pause (G1 Evacuation Pause) (young) (initial-mark), 0.0751469 secs]
  [Parallel Time: 74.7 ms, GC Workers: 8]
    [GC Worker Start (ms): Min: 100070.4, Avg: 100070.5, Max: 100070.6, Diff: 
      0.1]
    [Ext Root Scanning (ms): Min: 0.1, Avg: 0.2, Max: 0.3, Diff: 0.2, Sum: 
      1.6]
    [Update RS (ms): Min: 0.6, Avg: 1.1, Max: 1.5, Diff: 0.9, Sum: 8.9]
       [Processed Buffers: Min: 1, Avg: 1.6, Max: 4, Diff: 3, Sum: 13]
    [Scan RS (ms): Min: 1.0, Avg: 1.4, Max: 1.9, Diff: 0.9, Sum: 10.8]
    [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 
      0.0]
    [Object Copy (ms): Min: 71.5, Avg: 71.5, Max: 71.6, Diff: 0.1, Sum: 572.1]
    [Termination (ms): Min: 0.3, Avg: 0.3, Max: 0.4, Diff: 0.1, Sum: 2.6]
       [Termination Attempts: Min: 1382, Avg: 1515.5, Max: 1609, Diff: 227, 
         Sum: 12124]
    [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.2]
    [GC Worker Total (ms): Min: 74.5, Avg: 74.5, Max: 74.6, Diff: 0.1, Sum: 
      596.3]
    [GC Worker End (ms): Min: 100145.1, Avg: 100145.1, Max: 100145.1, Diff: 
      0.0]
  [Code Root Fixup: 0.0 ms]
  [Code Root Purge: 0.0 ms]
  [Clear CT: 0.1 ms]
  [Other: 0.4 ms]
    [Choose CSet: 0.0 ms]
    [Ref Proc: 0.1 ms]
    [Ref Enq: 0.0 ms]
    [Redirty Cards: 0.1 ms]
    [Humongous Register: 0.0 ms]
    [Humongous Reclaim: 0.0 ms]
    [Free CSet: 0.0 ms]
  [Eden: 23.0M(23.0M)->0.0B(14.0M) Survivors: 4096.0K->4096.0K Heap: 84.5M
    (128.0M)->86.5M(128.0M)]
[Times: user=0.63 sys=0.00, real=0.08 secs]

// 把YHR中Survivor分区作为根,开始并发标记根扫描
100.146: [GC concurrent-root-region-scan-start]
// 并发标记根扫描结束,花费了0.0196297,注意扫描和Mutator是并发进行,同时有多个线程并行
100.165: [GC concurrent-root-region-scan-end, 0.0196297 secs]
// 开始并发标记子阶段,这里从所有的根引用:包括Survivor和强根如栈等出发,对整个堆进行标记
100.165: [GC concurrent-mark-start]
// 标记结束,花费0.08848s
100.254: [GC concurrent-mark-end, 0.0884800 secs]
// 这里是再标记子阶段,包括再标记、引用处理、类卸载处理信息
100.254: [GC remark 100.254: [Finalize Marking, 0.0002228 secs] 100.254: 
  [GC ref-proc, 0.0001515 secs] 100.254: [Unloading, 0.0004694 secs], 
  0.0011610 secs]
  [Times: user=0.00 sys=0.00, real=0.00 secs]
// 清除处理,这里的清除仅仅回收整个分区中的垃圾
// 这里还会调整RSet,以减轻后续GC中RSet根的处理时间
100.255: [GC cleanup 86M->86M(128M), 0.0005376 secs]
  [Times: user=0.00 sys=0.00, real=0.00 secs]

混合回收日志

代码语言:javascript复制
// 混合回收Mixed GC其实和YGC的日志类似,能看到GC pause(G1EvacuationPause)(mixed)这样的信息
// 日志分析参考Y年轻代GC。
  122.132: [GC pause (G1 Evacuation Pause) (mixed), 0.0106092 secs]
  [Parallel Time: 9.8 ms, GC Workers: 8]
    [GC Worker Start (ms): Min: 122131.9, Avg: 122132.0, Max: 122132.0, 
      Diff: 0.1]
    [Ext Root Scanning (ms): Min: 0.1, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.7]
    [Update RS (ms): Min: 0.5, Avg: 0.7, Max: 0.9, Diff: 0.4, Sum: 5.4]
      [Processed Buffers: Min: 1, Avg: 1.8, Max: 3, Diff: 2, Sum: 14]
    [Scan RS (ms): Min: 1.0, Avg: 1.3, Max: 1.5, Diff: 0.5, Sum: 10.4]
    [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 
      0.0]
    [Object Copy (ms): Min: 7.5, Avg: 7.6, Max: 7.7, Diff: 0.2, Sum: 60.9]
    [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [Termination Attempts: Min: 92, Avg: 105.1, Max: 121, Diff: 29, Sum: 841]
    [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
    [GC Worker Total (ms): Min: 9.7, Avg: 9.7, Max: 9.8, Diff: 0.1, Sum: 77.6]
    [GC Worker End (ms): Min: 122141.7, Avg: 122141.7, Max: 122141.7, Diff: 0.0]
  [Code Root Fixup: 0.0 ms]
  [Code Root Purge: 0.0 ms]
  [Clear CT: 0.2 ms]
  [Other: 0.7 ms]
    [Choose CSet: 0.0 ms]
    [Ref Proc: 0.1 ms]
    [Ref Enq: 0.0 ms]
    [Redirty Cards: 0.5 ms]
    [Humongous Register: 0.0 ms]
    [Humongous Reclaim: 0.0 ms]
    [Free CSet: 0.0 ms]
  [Eden: 3072.0K(3072.0K)->0.0B(5120.0K) Survivors: 3072.0K->1024.0K 
    Heap: 105.5M(128.0M)->104.0M(128.0M)]
[Times: user=0.00 sys=0.00, real=0.01 secs]

0 人点赞