JVM性能调优实践——G1 垃圾收集器分析、调优篇

前言

关于G1 GC以及其他垃圾收集器的介绍可以参考前一篇JVM性能调优实践——G1 垃圾收集器介绍篇。了解了G1垃圾收集器的运行机制之后，就可以针对一些GC相关参数来调整内存分配以及运行策略。下文的调优主要针对G1垃圾收集器进行介绍，以及会分析一下G1 GC的日志格式。

G1 GC日志分析

在执行具体的调优任务前，需要结合GC日志以及应用本身的特点。打印详细GClog,需要添加如下启动参数：

-XX:+UseG1GC -XX:+PrintGCDetails -XX:+PrintGCDateStamps

本文使用的Java version：

java version "1.8.0_60"
Java(TM) SE Runtime Environment (build 1.8.0_60-b27)
Java HotSpot(TM) 64-Bit Server VM (build 25.60-b23, mixed mode) 

下面截取gc.log 中的一次YoungGC和一次MixedGC。

2018-05-26T19:51:45.808-0800: 127.031: [GC pause (G1 Evacuation Pause) (young), 0.0063650 secs]
   [Parallel Time: 5.5 ms, GC Workers: 4]
      [GC Worker Start (ms): Min: 127030.7, Avg: 127030.7, Max: 127030.7, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 1.1, Avg: 1.3, Max: 1.5, Diff: 0.4, Sum: 5.3]
      [Update RS (ms): Min: 1.3, Avg: 1.4, Max: 1.4, Diff: 0.1, Sum: 5.4]
         [Processed Buffers: Min: 3, Avg: 12.5, Max: 24, Diff: 21, Sum: 50]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.1, Avg: 0.3, Max: 0.7, Diff: 0.5, Sum: 1.3]
      [Object Copy (ms): Min: 2.2, Avg: 2.4, Max: 2.5, Diff: 0.4, Sum: 9.5]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Termination Attempts: Min: 1, Avg: 1.8, Max: 3, Diff: 2, Sum: 7]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 5.4, Avg: 5.4, Max: 5.4, Diff: 0.1, Sum: 21.6]
      [GC Worker End (ms): Min: 127036.1, Avg: 127036.1, Max: 127036.1, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 0.6 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.3 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: 39.0M(39.0M)->0.0B(2048.0K) Survivors: 3072.0K->4096.0K Heap: 111.4M(128.0M)->72.9M(128.0M)]
 [Times: user=0.02 sys=0.00, real=0.01 secs] 

2018-05-26T19:57:20.534-0800: 461.748: [GC pause (G1 Evacuation Pause) (mixed), 0.0685311 secs]
   [Parallel Time: 67.2 ms, GC Workers: 4]
      [GC Worker Start (ms): Min: 461748.1, Avg: 461748.1, Max: 461748.1, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 0.8, Avg: 2.6, Max: 7.5, Diff: 6.6, Sum: 10.5]
      [Update RS (ms): Min: 0.0, Avg: 0.3, Max: 0.7, Diff: 0.7, Sum: 1.4]
         [Processed Buffers: Min: 0, Avg: 9.2, Max: 35, Diff: 35, Sum: 37]
      [Scan RS (ms): Min: 29.7, Avg: 34.3, Max: 36.1, Diff: 6.5, Sum: 137.1]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.5, Max: 0.8, Diff: