GC调整为G1的实验机器因为Ref Proc
的时间过长很难受,主要原因是年轻代空间很大,因为网络IO处理线程太多。 上文中可以看到:
2018-12-20T20:59:19.983+0800: 92405.779: [GC pause (G1 Evacuation Pause) (young), 0.1240010 secs] [Parallel Time: 5.6 ms, GC Workers: 4] [GC Worker Start (ms): Min: 92405778.9, Avg: 92405779.0, Max: 92405779.0, Diff: 0.1] [Ext Root Scanning (ms): Min: 2.1, Avg: 2.2, Max: 2.5, Diff: 0.4, Sum: 8.9] [Update RS (ms): Min: 0.4, Avg: 0.5, Max: 0.6, Diff: 0.2, Sum: 2.1] [Processed Buffers: Min: 11, Avg: 22.2, Max: 45, Diff: 34, Sum: 89] [Scan RS (ms): Min: 0.3, Avg: 0.3, Max: 0.3, Diff: 0.0, Sum: 1.2] [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [Object Copy (ms): Min: 2.2, Avg: 2.3, Max: 2.4, Diff: 0.2, Sum: 9.2] [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Termination Attempts: Min: 1, Avg: 4.8, Max: 7, Diff: 6, Sum: 19] [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.0, Sum: 0.2] [GC Worker Total (ms): Min: 5.4, Avg: 5.4, Max: 5.5, Diff: 0.1, Sum: 21.7] [GC Worker End (ms): Min: 92405784.4, Avg: 92405784.4, Max: 92405784.4, Diff: 0.0] [Code Root Fixup: 0.2 ms] [Code Root Purge: 0.0 ms] [Clear CT: 0.4 ms] [Other: 117.9 ms] [Choose CSet: 0.0 ms] [Ref Proc: 116.1 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.8 ms] [Eden: 2372.0M(2372.0M)->0.0B(2370.0M) Survivors: 84.0M->86.0M Heap: 2600.6M(4096.0M)->230.6M(4096.0M)] [Times: user=0.14 sys=0.00, real=0.12 secs]
oracle官方建议加上
-XX:+ParallelRefProcEnabled
上文中提到这个参数已经加上去了,运行了几天后可以看到结果如下:
2018-12-28T13:54:23.130+0800: 65850.398: [GC pause (G1 Evacuation Pause) (young), 0.0382342 secs] [Parallel Time: 5.3 ms, GC Workers: 4] [GC Worker Start (ms): Min: 65850398.3, Avg: 65850398.3, Max: 65850398.3, Diff: 0.1] [Ext Root Scanning (ms): Min: 1.7, Avg: 1.9, Max: 2.0, Diff: 0.3, Sum: 7.5] [Update RS (ms): Min: 0.5, Avg: 0.6, Max: 0.7, Diff: 0.2, Sum: 2.4] [Processed Buffers: Min: 15, Avg: 22.2, Max: 34, Diff: 19, Sum: 89] [Scan RS (ms): Min: 0.2, Avg: 0.2, Max: 0.3, Diff: 0.0, Sum: 1.0] [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [Object Copy (ms): Min: 2.3, Avg: 2.4, Max: 2.5, Diff: 0.1, 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: 2.2, Max: 4, Diff: 3, Sum: 9] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.0, Sum: 0.2] [GC Worker Total (ms): Min: 5.1, Avg: 5.2, Max: 5.2, Diff: 0.1, Sum: 20.7] [GC Worker End (ms): Min: 65850403.5, Avg: 65850403.5, Max: 65850403.5, Diff: 0.0] [Code Root Fixup: 0.2 ms] [Code Root Purge: 0.0 ms] [Clear CT: 1.0 ms] [Other: 31.8 ms] [Choose CSet: 0.0 ms] [Ref Proc: 29.6 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.3 ms] [Humongous Register: 0.0 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 1.0 ms] [Eden: 2388.0M(2388.0M)->0.0B(2384.0M) Survivors: 68.0M->72.0M Heap: 2573.7M(4096.0M)->189.8M(4096.0M)] [Times: user=0.13 sys=0.01, real=0.04 secs]
一次youngGC的时间由原来的0.124s到现在的0.038s,效果还是很明显的。