性能优化-可视化GC日志分析工具

cwl_java

发布于 2020-02-13 12:46:44

1.2K0

发布于 2020-02-13 12:46:44

文章被收录于专栏：cwl_Javacwl_Java

4、可视化GC日志分析工具

4.1、GC日志输出参数

前面通过-XX:+PrintGCDetails可以对GC日志进行打印，我们就可以在控制台查看，这样虽然可以查看GC的信息，但是并不直观，可以借助于第三方的GC日志分析工具进行查看。

在日志打印输出涉及到的参数如下：

‐XX:+PrintGC 输出GC日志
‐XX:+PrintGCDetails 输出GC的详细日志
‐XX:+PrintGCTimeStamps 输出GC的时间戳（以基准时间的形式）
‐XX:+PrintGCDateStamps 输出GC的时间戳（以日期的形式，如 2013‐05‐ 04T21:53:59.234+0800）
‐XX:+PrintHeapAtGC 在进行GC的前后打印出堆的信息
‐Xloggc:../logs/gc.log 日志文件的输出路径

测试：

‐XX:+UseG1GC ‐XX:MaxGCPauseMillis=100 ‐Xmx256m ‐XX:+PrintGCDetails ‐ XX:+PrintGCTimeStamps ‐XX:+PrintGCDateStamps ‐XX:+PrintHeapAtGC 
‐ Xloggc:F://test//gc.log

运行后就可以在E盘下生成gc.log文件。如下：

Java HotSpot(TM) 64‐Bit Server VM (25.144‐b01) for windows‐amd64 JRE (1.8.0_144‐b01), built on Jul 21 2017 21:57:33 by "java_re" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 12582392k(1939600k free), swap 17300984k(5567740k free)
CommandLine flags: ‐XX:InitialHeapSize=201318272 ‐XX:MaxGCPauseMillis=100
‐XX:MaxHeapSize=268435456 ‐XX:+PrintGC ‐XX:+PrintGCDateStamps ‐ XX:+PrintGCDetails ‐XX:+PrintGCTimeStamps ‐XX:+PrintHeapAtGC ‐ XX:+UseCompressedClassPointers ‐XX:+UseCompressedOops ‐XX:+UseG1GC ‐XX:‐ UseLargePagesIndividualAllocation
{Heap before GC invocations=0 (full 0):
garbage‐first heap	total 196608K, used 9216K [0x00000000f0000000, 0x00000000f0100600, 0x0000000100000000)
region size 1024K, 9 young (9216K), 0 survivors (0K)
Metaspace	used 3491K, capacity 4500K, committed 4864K, reserved 1056768K
class space	used 381K, capacity 388K, committed 512K, reserved 1048576K
2018‐09‐24T23:06:02.230+0800: 0.379: [GC pause (G1 Evacuation Pause) (young), 0.0031038 secs]
[Parallel Time: 2.8 ms, GC Workers: 3]
[GC Worker Start (ms): Min: 378.6, Avg: 378.8, Max: 379.0, Diff:
0.3]
[Ext Root Scanning (ms): Min: 0.0, Avg: 0.4, Max: 0.8, Diff: 0.8,
Sum: 1.3]
[Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Processed Buffers: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0]
[Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1,
Sum: 0.1]
[Object Copy (ms): Min: 1.8, Avg: 1.9, Max: 1.9, Diff: 0.1, Sum:

5.6]

0.0]

3]


[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum:

[Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum:

[GC Worker Other (ms): Min: 0.0, Avg: 0.2, Max: 0.6, Diff: 0.6,

Sum: 0.6]



[GC Worker Total (ms): Min: 2.4, Avg: 2.5, Max: 2.7, Diff: 0.3,
Sum: 7.6]
[GC Worker End (ms): Min: 381.4, Avg: 381.4, Max: 381.4, Diff: 0.0] [Code Root Fixup: 0.0 ms]
[Code Root Purge: 0.0 ms] [Clear CT: 0.0 ms] [Other: 0.2 ms]
[Choose CSet: 0.0 ms] [Ref Proc: 0.1 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: 9216.0K(9216.0K)‐>0.0B(7168.0K) Survivors: 0.0B‐>2048.0K Heap: 9216.0K(192.0M)‐>1888.0K(192.0M)]
Heap after GC invocations=1 (full 0):
garbage‐first heap	total 196608K, used 1888K [0x00000000f0000000, 0x00000000f0100600, 0x0000000100000000)
region size 1024K, 2 young (2048K), 2 survivors (2048K)
Metaspace	used 3491K, capacity 4500K, committed 4864K, reserved 1056768K
class space	used 381K, capacity 388K, committed 512K, reserved 1048576K
}
[Times: user=0.00 sys=0.00, real=0.00 secs]
{Heap before GC invocations=1 (full 0):
garbage‐first heap	total 196608K, used 9056K [0x00000000f0000000, 0x00000000f0100600, 0x0000000100000000)
region size 1024K, 9 young (9216K), 2 survivors (2048K)
Metaspace	used 3492K, capacity 4500K, committed 4864K, reserved 1056768K
class space	used 381K, capacity 388K, committed 512K, reserved 1048576K
2018‐09‐24T23:06:02.310+0800: 0.458: [GC pause (G1 Evacuation Pause) (young), 0.0070126 secs]
。。。。。。。。。。。。。。。。。。。