G1GC 日志分析

参考：https://blogs.oracle.com/poonam/understanding-g1-gc-logs

2021-07-23T15:54:26.562+0800: 91043.595: [GC pause (G1 Evacuation Pause) (young), 0.0300306 secs]
   -- 使用 G1GC 堆年轻代进行回收，本次垃圾回收使用的总的时间为：0.03秒，即30毫秒
[Parallel Time: 28.1 ms, GC Workers: 2]
   -- 并行GC使用的时间以及并行GC使用的线程数
[GC Worker Start (ms): Min: 91043595.2, Avg: 91043595.3, Max: 91043595.3, Diff: 0.0]
[Ext Root Scanning (ms): Min: 12.6, Avg: 12.7, Max: 12.8, Diff: 0.1, Sum: 25.4]
[Update RS (ms): Min: 10.0, Avg: 10.0, Max: 10.1, Diff: 0.1, Sum: 20.1]
[Processed Buffers: Min: 146, Avg: 159.0, Max: 172, Diff: 26, Sum: 318]
[Scan RS (ms): Min: 0.2, Avg: 0.2, Max: 0.2, Diff: 0.0, Sum: 0.4]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Object Copy (ms): Min: 4.6, Avg: 4.7, Max: 4.7, Diff: 0.2, Sum: 9.3]
  -- 存活对象拷贝到其他Regions所使用的时间（每个工作线程），每个工作线程拷贝存活对象平均使用4.7毫秒，所有线程一共使用9.3毫秒
[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: 2]
[GC Worker Other (ms): Min: 0.5, Avg: 0.5, Max: 0.5, Diff: 0.0, Sum: 1.0]
[GC Worker Total (ms): Min: 28.1, Avg: 28.1, Max: 28.1, Diff: 0.0, Sum: 56.2]
[GC Worker End (ms): Min: 91043623.3, Avg: 91043623.3, Max: 91043623.3, Diff: 0.0]
[Code Root Fixup: 0.0 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 0.2 ms]
[Other: 1.7 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.3 ms]
[Ref Enq: 0.0 ms]
[Redirty Cards: 0.1 ms]
[Humongous Register: 0.1 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 0.5 ms]
[Eden: 500.0M(500.0M)->0.0B(510.0M) Survivors: 5120.0K->5120.0K Heap: 738.6M(865.0M)->233.4M(865.0M)]
  -- 伊甸区的占用（Occupancy）内存，GC前为500M，GC后为0M；
  -- 伊甸区的容量（Capacity），GC前为500M，GC后为510M（Eden区得到了扩容，下次的目标容量）， 随着需求的产生，区域被添加到Eden中，当添加的区域达到目标大小时，我们开始下一个收集。
  -- 幸存区内存大小没有变化，所以这次GC没有幸存者，新生对象被全部回收了
  -- 总的堆占用（Occupancy）的内存由GC前的738.6M 变为 GC 后的 233.4M；总的堆容量（Capacity）没有变化，还是 865M
[Times: user=0.05 sys=0.00, real=0.03 secs]
  -- 用户态代码执行时间为：0.05秒，内核态代码执行时间为0秒，总的时间为：0.03秒。