ParallelGC 日志详解

GC 日志相关的 JVM 参数

与 GC 日志相关的 JVM 参数有如下 8 个：

参数名	参数含义
-XX:+PrintGC	输出简要 GC 日志
-verbose:gc	等同于 -XX:+PrintGC
-XX:+PrintGCDetails	输出详细 GC 日志
-XX:+PrintGCTimeStamps	输出 GC 的时间戳（以 JVM 启动到当前的总时长）
-XX:+PrintGCDateStamps	输出 GC 的时间戳（以日期的形式，如 2013-05-04T21:53:59.234+0800）
-XX:+PrintHeapAtGC	在进行 GC 的前后打印出堆的信息
-XX:+PrintReferenceGC	打印年轻代各个引用的数量以及时长
-Xloggc:gc.log	输出 GC 日志到文件 gc.log

-XX:+PrintGC 与 -verbose:gc

虽然上面说这两个参数是等价的，但是，-verbose:gc 是一个标准的参数，而 -XX:+PrintGC 则在 JDK 9 之后被标为废弃的 (deprecated)，所以建议使用 -verbose:gc 代替 -XX:+PrintGC。

使用-verbose:gc这个参数将会打开简略的 GC 日志。你可以看到这样的 GC 日志：

此参数已不再经常使用，所以不做详细解释

[GC (Allocation Failure) [PSYoungGen: 1363219K->24905K(1368576K)] , 0.0187118 secs]

-XX:+PrintGCDetails

使用这个参数后，将会打印详细的 GC 日志，它打印的内容包含了 -verbose:gc 参数打印的内容。

[GC (Allocation Failure) [PSYoungGen: 1363219K->24905K(1368576K)] 1983835K->646622K(2066944K), 0.0187118 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]

我们将上面的日志拆分开来：

• GC 代表这次垃圾回收的类型。GC 代表发生了 Minor GC，Full GC 代表发生了 Full GC
• Allocation Failure 简述了发生 GC 的原因。在以上例子中，是因为在年轻代中没有合适的空间导致新的对象分配失败，从而发生 GC
• [PSYoungGen: 1363219K->24905K(1368576K)] 表明了使用的垃圾回收器、年轻代的占用量变化，和年轻代的大小，在这个例子中，年轻代的使用量从1363219KB 减少到了 24905KB
• 1983835K->646622K(2066944K) 表明了整个堆的占用量变化，和整个堆的大小
• [Times: user=0.05 sys=0.00, real=0.02 secs] 表示本次 GC 消耗的时间

user 代表垃圾回收器消耗的 CPU 时间
sys 代表系统调用或等待系统事件消耗的时间
real 代表应用实际停止的时间，近似于 (user + sys) / 垃圾回收器使用的线程数

-XX:+PrintGCTimeStamps

这个参数不影响日志的详细程度，在打开之后，日志中会出现从 JVM 启动到出现日志时的毫秒数，比如下面例子的 358952.455

358952.455: [GC (Allocation Failure) [PSYoungGen: 1363219K->24905K(1368576K)] 1983835K->646622K(2066944K), 0.0187118 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]

-XX:+PrintGCDateStamps

这个参数也不影响日志的详细程度，在打开之后，日志头部会加上打印日志的时间和时区，比如下面例子的 2020-11-06T05:58:40.250+0000

2020-11-06T05:58:40.250+0000: 358952.455: [GC (Allocation Failure) [PSYoungGen: 1363219K->24905K(1368576K)] 1983835K->646622K(2066944K), 0.0187118 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]