JVM GC Log的分析

示例代码

public class Test {
    public static void main(String[] args) {
        // 1M 大小
        int size = 1024 * 1024;

        // 构建原生数据类型的数组
        byte[] allocate1 = new byte[2 * size];
        byte[] allocate2 = new byte[2 * size];
        byte[] allocate3 = new byte[3 * size];
        byte[] allocate4 = new byte[3 * size];
    }
}

指定运行程序的JVM启动参数

JVM启动参数说明：

-verbose:gc，表示输出详细的垃圾回收的日志
-Xms20M，堆初始大小
-Xmx20M，堆的最大大小，通常与初始大小设置成一样，防止出现jvm内存的抖动情况
-Xmn10M，表示堆空间中，指定新生代大小为10M
-XX:+PrintGCDetails，表示打印GC的详情
-XX:SurvivorRatio=8，表示Eden空间与Survivor空间的比例是8:1，
                     由于指定了新生代的空间是10M，所以这里的Eden空间是8M，2个Survivor空间分别占用1M大小

执行结果分析

[GC (Allocation Failure) [PSYoungGen: 6779K->936K(9216K)] 6779K->5040K(19456K), 0.0029926 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap
 PSYoungGen      total 9216K, used 7401K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  eden space 8192K, 78% used [0x00000000ff600000,0x00000000ffc507d8,0x00000000ffe00000)
  from space 1024K, 91% used [0x00000000ffe00000,0x00000000ffeea020,0x00000000fff00000)
  to   space 1024K, 0% used [0x00000000fff00000,0x00000000fff00000,0x0000000100000000)
 ParOldGen       total 10240K, used 4104K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000)
  object space 10240K, 40% used [0x00000000fec00000,0x00000000ff002020,0x00000000ff600000)
 Metaspace       used 3413K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 369K, capacity 388K, committed 512K, reserved 1048576K

这里分析每一行的log输出的含义：

• 第1行gc日志的的分析：

1. “GC (Allocation Failure)”代表发生了Minor GC，小括号中是发生GC的原因，这里的原因（Allocation Failure）是最常见的原因
2. “PSYoungGen”中的PS代表的是Parallel Scavenge垃圾收集器，YoungGen代表的是年轻代
3. “6779K->936K(9216K)”中箭头左边表示垃圾回收之前存活对象占用新生代的空间大小（6779K），箭头右边表示当执行完垃圾回收之后存活空间的占用新生代的大小（936K），小括号中的大小表示新生代总的大小（9216K），这里的新生代总空间大小为9216K即9M，但是程序中配置的jvm参数（-Xmn10M）的新生代的大小是10M，由于新生代中分了Eden和2个Survivor区，配置的比例是8:1，但是2个survivor区只有一个在使用，所以输出的大小是Eden区+1个survivor区=9M
4. “6779K->5040K(19456K)”中箭头左边表示GC之前堆大小（6779K），箭头右边表示的是GC之后堆大小（5040K），小括号中的大小是堆总可用容量（19456K）即19M，加上浪费的1M的survivor区正好20M
5. “0.0029926 secs”表示的是GC执行的时间，单位秒
6. “[Times: user=0.00 sys=0.00, real=0.00 secs]”分别指的是用户空间、内核空间、真正执行的花费时间，单位秒

• 第2行下面描述了堆区的使用情况

1. PSYoungGen，堆区年轻代使用情况，PS指的是Parallel Scavenge垃圾收集器
2. ParOldGen，堆区老年代使用情况，ParOld指的是Parallel Old垃圾收集器
   可以看到老年区使用情况的已使用空间的大小是4104K

 ParOldGen       total 10240K, used 4104K

这个4104K是怎么计算出来的？
执行完GC后年轻代释放的空间 = （6779K - 936K = 5843K），这个释放大小包括：释放的垃圾、被挪到老年代的空间
执行完GC后堆释放的空间 = （6779K - 5040K = 1739K），这个大小是真正释放的垃圾对象的大小
可以看出，这二者释放空间的差值正好是老年代使用的空间（5843K - 1739K = 4104K）

• Metaspace表示的是元空间（JDK8之后的内存空间）的使用情况，垃圾收集器在这个空间的收集性价比很低。