详解 GC 日志：YoungGC

· 2020-10-01 ·

本文主要介绍了 JVM 的常用参数，并详细分析了YoungGC 日志.

在线上运行着的 Java 开发的系统，YoungGC 是一个循环出现的过程，我们如何在开发过程中分析 YoungGC 呢？

要想分析 YoungGC，我们首先得让 YoungGC 留下“足迹”—— GC 日志。
我们可以手动创建一个简单的 demo，核心代码如下：

public static void main(String[] args) {
        byte[] array1 = new byte[1024 * 1024];
        array1 = new byte[1024 * 1024];
        array1 = new byte[1024 * 1024];
        array1 = null;

        byte[] array2 = new byte[2 * 1024 * 1024];
}

我们可以使用以下 jvm 参数：

-XX:NewSize=5242880 -XX:MaxNewSize=5242880 -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:SurvivorRatio=8 -XX:PretenureSizeThreshold=10485760 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XXloggc:gc.log

参数解释：

-XX:NewSize=5242880：初始新生代大小 5 MB
-XX:MaxNewSize=5242880：最大新生代大小 5 MB
-XX:InitialHeapSize=10485760：初始堆大小 10 MB
-XX:MaxHeapSize=10485760：最大堆大小 10 MB
-XX:SurvivorRatio=8：新生代中 Eden 区与一个 Survivor 区的大小之比为 8。
-XX:PretenureSizeThreshold=10485760：大对象阈值为 10 MB，超过此阈值，会尝试放入老年代
-XX:+UseParNewGC：新生代使用 ParNew 垃圾收集器
-XX:+UseConcMarkSweepGC：老年代使用 CMS 垃圾收集器
-XX:+PrintGCDetail：打印详细的GC 日志
-XX:+PrintGCTimeStamps：打印每次GC 发生的时间
将 GC 日志写入磁盘文件

结合以上代码片段和 JVM 参数，我们可以分析知道，在执行

byte[] array2 = new byte[2 * 1024 * 1024];

时，此时新生代的 Eden 区本身只剩下 4 - 3 = 1MB 的大小，会进行一次垃圾回收。

运行程序，你就会看到在在新生成的文件中保存了 gc 日志：

Memory: 4k page, physical 16777216k(418648k free)

/proc/meminfo:

CommandLine flags: 
-XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:MaxNewSize=5242880 -XX:NewSize=5242880 -XX:OldPLABSize=16 -XX:PretenureSizeThreshold=10485760 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseParNewGC 
0.145: [GC (Allocation Failure) 0.146: [ParNew: 3874K->502K(4608K), 0.0014940 secs] 3874K->1528K(9728K), 0.0016631 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 
Heap
 par new generation   total 4608K, used 3735K [0x00000007bf600000, 0x00000007bfb00000, 0x00000007bfb00000)
  eden space 4096K,  78% used [0x00000007bf600000, 0x00000007bf928690, 0x00000007bfa00000)
  from space 512K,  98% used [0x00000007bfa80000, 0x00000007bfafd818, 0x00000007bfb00000)
  to   space 512K,   0% used [0x00000007bfa00000, 0x00000007bfa00000, 0x00000007bfa80000)
 concurrent mark-sweep generation total 5120K, used 1026K [0x00000007bfb00000, 0x00000007c0000000, 0x00000007c0000000)
 Metaspace       used 3040K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 335K, capacity 388K, committed 512K, reserved 1048576K

但是日志信息明显有些混乱，但我们可以将这段 GC 日志分为 3 个部分。
第 1 个部分是：

CommandLine flags: 
-XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:MaxNewSize=5242880 -XX:NewSize=5242880 -XX:OldPLABSize=16 -XX:PretenureSizeThreshold=10485760 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseParNewGC

第 2 个部分是：

0.145: [GC (Allocation Failure) 0.146: [ParNew: 3874K->502K(4608K), 0.0014940 secs] 3874K->1528K(9728K), 0.0016631 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]

第 3 个部分是：

Heap
 par new generation   total 4608K, used 3735K [0x00000007bf600000, 0x00000007bfb00000, 0x00000007bfb00000)
  eden space 4096K,  78% used [0x00000007bf600000, 0x00000007bf928690, 0x00000007bfa00000)
  from space 512K,  98% used [0x00000007bfa80000, 0x00000007bfafd818, 0x00000007bfb00000)
  to   space 512K,   0% used [0x00000007bfa00000, 0x00000007bfa00000, 0x00000007bfa80000)
 concurrent mark-sweep generation total 5120K, used 1026K [0x00000007bfb00000, 0x00000007c0000000, 0x00000007c0000000)
 Metaspace       used 3040K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 335K, capacity 388K, committed 512K, reserved 1048576K