读懂GC日志

添加VM启动参数-Xms30m -Xmx30m -XX:+PrintGCDetails -XX:+PrintHeapAtGC，运行如下代码

public class Test {
    public static void main(String[] args) {
        final int _1MB = 1024 * 1024;
        byte[] a1,a2,a3,a4;
        a1 = new byte[2*_1MB];
        System.out.println("----------创建2M后----------");
        a2 = new byte[2*_1MB];
        System.out.println("----------创建2M后----------");
        a3 = new byte[2*_1MB];
        System.out.println("----------创建2M后----------");
    }
}

控制台输出如下：

{Heap before GC invocations=1 (full 0):
 PSYoungGen      total 9216K, used 8187K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  eden space 8192K, 99% used [0x00000000ff600000,0x00000000ffdfed98,0x00000000ffe00000)
  from space 1024K, 0% used [0x00000000fff00000,0x00000000fff00000,0x0000000100000000)
  to   space 1024K, 0% used [0x00000000ffe00000,0x00000000ffe00000,0x00000000fff00000)
 ParOldGen       total 20480K, used 0K [0x00000000fe200000, 0x00000000ff600000, 0x00000000ff600000)
  object space 20480K, 0% used [0x00000000fe200000,0x00000000fe200000,0x00000000ff600000)
 Metaspace       used 2909K, capacity 4480K, committed 4480K, reserved 1056768K
  class space    used 305K, capacity 384K, committed 384K, reserved 1048576K
[GC (Allocation Failure) [PSYoungGen: 8187K->1011K(9216K)] 8187K->2193K(29696K), 0.0021100 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap after GC invocations=1 (full 0):
 PSYoungGen      total 9216K, used 1011K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  eden space 8192K, 0% used [0x00000000ff600000,0x00000000ff600000,0x00000000ffe00000)
  from space 1024K, 98% used [0x00000000ffe00000,0x00000000ffefce68,0x00000000fff00000)
  to   space 1024K, 0% used [0x00000000fff00000,0x00000000fff00000,0x0000000100000000)
 ParOldGen       total 20480K, used 1182K [0x00000000fe200000, 0x00000000ff600000, 0x00000000ff600000)
  object space 20480K, 5% used [0x00000000fe200000,0x00000000fe327950,0x00000000ff600000)
 Metaspace       used 2909K, capacity 4480K, committed 4480K, reserved 1056768K
  class space    used 305K, capacity 384K, committed 384K, reserved 1048576K
}
----------创建2M后----------
----------创建2M后----------
从
[GC (Allocation Failure) [PSYoungGen: 7759K->1011K(9216K)] 8941K->6521K(29696K), 0.0019065 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap after GC invocations=2 (full 0):
 PSYoungGen      total 9216K, used 1011K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  eden space 8192K, 0% used [0x00000000ff600000,0x00000000ff600000,0x00000000ffe00000)
  from space 1024K, 98% used [0x00000000fff00000,0x00000000ffffce68,0x0000000100000000)
  to   space 1024K, 0% used [0x00000000ffe00000,0x00000000ffe00000,0x00000000fff00000)
 ParOldGen       total 20480K, used 5509K [0x00000000fe200000, 0x00000000ff600000, 0x00000000ff600000)
  object space 20480K, 26% used [0x00000000fe200000,0x00000000fe7617d0,0x00000000ff600000)
 Metaspace       used 3472K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 358K, capacity 388K, committed 512K, reserved 1048576K
}
----------创建2M后----------
Heap
 PSYoungGen      total 9216K, used 3631K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  eden space 8192K, 31% used [0x00000000ff600000,0x00000000ff88edc0,0x00000000ffe00000)
  from space 1024K, 98% used [0x00000000fff00000,0x00000000ffffce68,0x0000000100000000)
  to   space 1024K, 0% used [0x00000000ffe00000,0x00000000ffe00000,0x00000000fff00000)
 ParOldGen       total 20480K, used 5509K [0x00000000fe200000, 0x00000000ff600000, 0x00000000ff600000)
  object space 20480K, 26% used [0x00000000fe200000,0x00000000fe7617d0,0x00000000ff600000)
 Metaspace       used 3505K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 365K, capacity 388K, committed 512K, reserved 1048576K

分析GC日志

Heap before是触发GC前堆内存的状态，Heap after是触发GC后堆内存的状态，在触发前后有这样一行输出：

[GC (Allocation Failure) [PSYoungGen: 7759K->1011K(9216K)] 8941K->6521K(29696K), 0.0019065 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 

• GC (Allocation Failure)：对象分配失败，此时就要触发一次Young GC
• [PSYoungGen: 7759K->1011K(9216K)]：
  • (9216K): 年轻代可用空间是9216KB，也就是9MB；Eden区是8MB，两个Survivor中只有一个是可以放存活对象的，另外一个是必须一致保持空闲的，所以他考虑年轻代的可用空间，就是Eden+1个Survivor-from的大小， 也就是9MB。
  • 7759K->1011K：对年轻代执行了一次GC，GC之前都使用了7759KB了，但是GC之后只有1011KB的对象是存活下来
  • 8941K->6521K(29696K)：8941K是GC前堆内存占用，6521K是GC后堆内存占用，29696K是堆内存总量
  • 0.0019065 secs：本次gc耗费的时间

分析GC回收后日志

Heap after GC invocations=2 (full 0):
 PSYoungGen      total 9216K, used 1011K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  eden space 8192K, 0% used [0x00000000ff600000,0x00000000ff600000,0x00000000ffe00000)
  from space 1024K, 98% used [0x00000000fff00000,0x00000000ffffce68,0x0000000100000000)
  to   space 1024K, 0% used [0x00000000ffe00000,0x00000000ffe00000,0x00000000fff00000)
 ParOldGen       total 20480K, used 5509K [0x00000000fe200000, 0x00000000ff600000, 0x00000000ff600000)
  object space 20480K, 26% used [0x00000000fe200000,0x00000000fe7617d0,0x00000000ff600000)
 Metaspace       used 3472K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 358K, capacity 388K, committed 512K, reserved 1048576K
}

• 整个堆内存总共有9216KB，其中老年代占用了1182KB，年轻代占用7759KB（9216-1182），。
• eden区占用了8192KB，占用率为0%；from区占用了1024KB，占用率为98%；to space（空闲区域）占用了1024KB（1MB），占用率为0%。
• 老年代的总大小为20480KB，其中已使用的空间为1182KB，占用率为5%。
• Metaspace（元空间）被用于存储类相关的元数据，目前已使用3472KB，最大容量为4496KB，已分配4864KB，保留了1056768KB的空间。
• class space（类空间）被用于存储类、常量的相关信息，已使用358KB，容量为388KB，已分配512KB，保留了1048576KB的空间。