【JVM】GC日志分析

1. 常用GC日志命令

通过阅读GC日志，我们可以了解Java虚拟机内存分配与回收策略

• -XX:+PrintGC：输出GC日志。类似: -verbose:gc

• -XX:+PrintGCDetails：输出GC的详细日志

• -XX:+PrintGCTimeStamps：输出GC的时间戳(以基准时间的形式)

• -XX:+PrintGCDatestamps：输出GC的时间戳(以日期的形式，如2013-05-04T21:53:59.234+0800)

• -XX:+PrintHeapAtGC：在进行GC的前后打印出堆的信息

• -Xloggc:./logs/gc.log：日志文件的输出路径

[GC (Allocation Failure) [PSYoungGen: 15339K->2536K(17920K)] 15339K->12436K(58880K), 0.0021585 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC (Allocation Failure) [PSYoungGen: 17151K->2552K(17920K)] 27051K->26988K(58880K), 0.0029423 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC (Allocation Failure) [PSYoungGen: 17168K->2528K(17920K)] 41604K->41316K(58880K), 0.0026451 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[Full GC (Ergonomics) [PSYoungGen: 2528K->0K(17920K)] [ParOldGen: 38788K->40901K(40960K)] 41316K->40901K(58880K), [Metaspace: 3808K->3808K(1056768K)], 0.0135678 secs] [Times: user=0.20 sys=0.00, real=0.01 secs] 
[Full GC (Ergonomics) [PSYoungGen: 14623K->14336K(17920K)] [ParOldGen: 40901K->40897K(40960K)] 55525K->55233K(58880K), [Metaspace: 3809K->3809K(1056768K)], 0.0162805 secs] [Times: user=0.20 sys=0.00, real=0.02 secs] 
[Full GC (Allocation Failure) [PSYoungGen: 14336K->14336K(17920K)] [ParOldGen: 40897K->40845K(40960K)] 55233K->55182K(58880K), [Metaspace: 3809K->3809K(1056768K)], 0.0075369 secs] [Times: user=0.20 sys=0.00, real=0.01 secs] 
Heap
 PSYoungGen      total 17920K, used 15082K [0x00000000fec00000, 0x0000000100000000, 0x0000000100000000)
  eden space 15360K, 98% used [0x00000000fec00000,0x00000000ffaba988,0x00000000ffb00000)
  from space 2560K, 0% used [0x00000000ffb00000,0x00000000ffb00000,0x00000000ffd80000)
  to   space 2560K, 0% used [0x00000000ffd80000,0x00000000ffd80000,0x0000000100000000)
 ParOldGen       total 40960K, used 40845K [0x00000000fc400000, 0x00000000fec00000, 0x00000000fec00000)
  object space 40960K, 99% used [0x00000000fc400000,0x00000000febe3668,0x00000000fec00000)
 Metaspace       used 3840K, capacity 4536K, committed 4864K, reserved 1056768K
  class space    used 423K, capacity 428K, committed 512K, reserved 1048576K
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
	at Main.main(Main.java:15)

补充说明：

• “[GC"和”[Full GC"说明了这次垃圾收集的停顿类型，如果有"Full GC"则说明GC发生了"Stop The World"

• 使用Serial收集器在新生代的名字是Default New Generation，因此显示的是"[DefNew"

• 使用ParNew收集器在新生代的名字会变成"[ParNew”，意思是"Paralle New Generation"

• 使用Parallel Scavenge收集器在新生代的名字是”[PSYoungGen"

• 老年代的收集和新生代道理一样，名字也是收集器决定的

• 使用G1收集器的话，会显示为"garbage-first heap"

• Allocation Failure

  表明本次引起GC的原因是因为在年轻代中没有足够的空间能够存储新的数据了

• [PSYoungGen: 15339K->2536K(17920K)] 15339K->12436K(58880K)

  中括号内:GC回收前年轻代大小，回收后大小， (年轻代总大小)

  括号外:GC回收前年轻代和老年代大小，回收后大小， (年轻代和老年代总大小)

• [Times: user=0.20 sys=0.00, real=0.01 secs]

  user代表用户态回收耗时，sys内核态回收耗时，rea实际耗时。由于多核的原因，时间总和可能会超过real时间

• Heap：堆

• PSYoungGen：Parallel Scavenge收集器新生代)

• eden space：堆中的Eden区默认占比是8

• from space：堆中的survivor，这里是From Survivor区默认占比是1

• to space：堆中的survivor，这里是to Survivor区默认占比是1

• ParOldGen：老年代总大小和使用大小

• object space：空间使用百分比

• Metaspace：元空间

  • used：实际使用大小
  • capacity：当前分配块的元数据的空间
  • committed：空间块的数量
  • reserved：元数据的空间保留（但不一定提交）的量

• class space：类空间

2. 日志分析工具

GCViewer、GCEasy