ParallelGC 日志详解

GC 日志相关的 JVM 参数

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

-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]
1

-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]
1

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

• 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) / 垃圾回收器使用的线程数
1
2
3

-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]
1

-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]
1