1. 概述
本教程将介绍如何在 Java 应用中启用详细垃圾回收（Verbose GC）日志。我们将从什么是 Verbose GC 开始讲起，并说明它在性能调优和问题排查中的作用。
随后，我们会通过多个示例展示如何开启并配置 GC 日志输出，并重点讲解如何解读这些日志信息。
如果你对 JVM 的不同垃圾收集器还不太熟悉，可以先阅读我们的文章：Java 垃圾收集器详解。
2. 简单了解 Verbose Garbage Collection
开启详细的 GC 日志记录是调优内存问题、诊断应用性能瓶颈的重要手段之一。很多经验丰富的开发者认为，为了持续监控应用健康状态，应该始终关注 JVM 的 GC 行为。
✅ GC 日志提供了每次垃圾回收事件的精确数据，包括执行时间和结果。
❌ 如果不关注 GC 日志，可能错过很多性能优化机会。
随着时间推移，分析 GC 日志可以帮助我们：
- 更好地理解应用程序的行为模式
- 调整堆大小、GC 算法等参数来提升性能
- 减少 GC 频率或缩短单次停顿时间
2.1 示例程序
我们准备了一个简单的 Java 程序用于演示如何开启和查看 GC 日志：
public class Application {
private static Map<String, String> stringContainer = new HashMap<>();
public static void main(String[] args) {
System.out.println("Start of program!");
String stringWithPrefix = "stringWithPrefix";
// 加载 300 万个 String 实例到 Map 中
for (int i = 0; i < 3000000; i++) {
String newString = stringWithPrefix + i;
stringContainer.put(newString, newString);
}
System.out.println("MAP size: " + stringContainer.size());
// 显式触发 GC
System.gc();
// 移除其中 200 万个对象
for (int i = 0; i < 2000000; i++) {
String newString = stringWithPrefix + i;
stringContainer.remove(newString);
}
System.out.println("MAP size: " + stringContainer.size());
System.out.println("End of program!");
}
}
这个程序首先向 HashMap 中添加了 300 万个字符串对象，然后显式调用 System.gc()，再删除其中 200 万个对象。整个过程非常直观，便于观察 GC 行为。
接下来我们将看看如何开启 GC 日志。
3. 启用“简单”GC 日志
我们使用以下 JVM 参数运行程序以启用基本的 GC 日志输出：
-XX:+UseSerialGC -Xms1024m -Xmx1024m -verbose:gc
其中：
-XX:+UseSerialGC：指定使用串行垃圾收集器（最简单的 GC 实现）-Xms1024m -Xmx1024m：设置初始与最大堆大小为 1GB-verbose:gc：开启最基本的 GC 日志输出
⚠️ 注意：默认情况下，GC 日志会输出到标准输出（stdout），每发生一次 Young GC 或 Full GC 就输出一行。
3.1 初步理解日志输出
运行上述命令后，可以看到如下输出：
Start of program!
[GC (Allocation Failure) 279616K->146232K(1013632K), 0.3318607 secs]
[GC (Allocation Failure) 425848K->295442K(1013632K), 0.4266943 secs]
MAP size: 3000000
[Full GC (System.gc()) 434341K->368279K(1013632K), 0.5420611 secs]
[GC (Allocation Failure) 647895K->368280K(1013632K), 0.0075449 secs]
MAP size: 1000000
End of program!
我们可以从中看到：
✅ 共发生了 4 次 GC（1 次 Full GC + 3 次 Young GC）
✅ 每一行都包含内存变化和耗时信息
3.2 详细解析日志内容
每一行 GC 日志的结构如下：
GC或Full GC– 垃圾回收类型(Allocation Failure)或(System.gc())– 触发原因279616K->146232K– 回收前后占用内存(1013632K)– 当前堆总容量0.3318607 secs– 执行耗时（秒）
例如第一行：
[GC (Allocation Failure) 279616K->146232K(1013632K), 0.3318607 secs]
表示 Eden 区已满导致 GC，回收前占用 279MB，回收后减少至 146MB，总共耗时约 0.33 秒。
虽然这种日志格式足够清晰，但缺少一些关键信息，比如：
❌ 年轻代与老年代分别回收了多少
❌ 对象晋升情况
❌ 各区域的详细使用情况
因此，更详细的日志格式更有价值。
4. 启用“详细”GC 日志
要获取更详细的 GC 日志，可以加入 -XX:+PrintGCDetails 参数：
-XX:+UseSerialGC -Xms1024m -Xmx1024m -verbose:gc -XX:+PrintGCDetails
这会提供如下额外信息：
✅ 年轻代和老年代的内存使用情况
✅ 对象晋升数量
✅ GC 时间细分（用户态、系统态、真实耗时）
✅ 堆内存整体结构快照
⚠️ 注意：自 Java 9 起，-XX:+PrintGCDetails 已被弃用，取而代之的是新的统一日志机制。新版本中应使用 -Xlog:gc*。
5. 解读“详细”GC 日志
再次运行程序，输出更加丰富：
Start of program!
[GC (Allocation Failure) [DefNew: 279616K->34944K(314560K), 0.3626923 secs] 279616K->146232K(1013632K), 0.3627492 secs] [Times: user=0.33 sys=0.03, real=0.36 secs]
[GC (Allocation Failure) [DefNew: 314560K->34943K(314560K), 0.4589079 secs] 425848K->295442K(1013632K), 0.4589526 secs] [Times: user=0.41 sys=0.05, real=0.46 secs]
MAP size: 3000000
[Full GC (System.gc()) [Tenured: 260498K->368281K(699072K), 0.5580183 secs] 434341K->368281K(1013632K), [Metaspace: 2624K->2624K(1056768K)], 0.5580738 secs] [Times: user=0.50 sys=0.06, real=0.56 secs]
[GC (Allocation Failure) [DefNew: 279616K->0K(314560K), 0.0076722 secs] 647897K->368281K(1013632K), 0.0077169 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
MAP size: 1000000
End of program!
Heap
def new generation total 314560K, used 100261K [0x00000000c0000000, 0x00000000d5550000, 0x00000000d5550000)
eden space 279616K, 35% used [0x00000000c0000000, 0x00000000c61e9370, 0x00000000d1110000)
from space 34944K, 0% used [0x00000000d3330000, 0x00000000d3330188, 0x00000000d5550000)
to space 34944K, 0% used [0x00000000d1110000, 0x00000000d1110000, 0x00000000d3330000)
tenured generation total 699072K, used 368281K [0x00000000d5550000, 0x0000000100000000, 0x0000000100000000)
the space 699072K, 52% used [0x00000000d5550000, 0x00000000ebcf65e0, 0x00000000ebcf6600, 0x0000000100000000)
Metaspace used 2637K, capacity 4486K, committed 4864K, reserved 1056768K
class space used 283K, capacity 386K, committed 512K, reserved 1048576K
5.1 分析 Minor GC 日志
以一行 Minor GC 为例：
[GC (Allocation Failure) [DefNew: 279616K->34944K(314560K), 0.3626923 secs] 279616K->146232K(1013632K), 0.3627492 secs] [Times: user=0.33 sys=0.03, real=0.36 secs]
各部分含义如下：
DefNew：年轻代使用的垃圾收集器（Serial GC 的年轻代实现）279616K->34944K(314560K)：年轻代回收前后使用量及总容量0.3626923 secs：GC 耗时[Times: ...]：CPU 使用时间统计（user/sys/real）
⚠️ 使用串行 GC 时，real ≈ user + sys
5.2 分析 Full GC 日志
Full GC 行如：
[Full GC (System.gc()) [Tenured: 260498K->368281K(699072K), 0.5580183 secs] 434341K->368281K(1013632K), [Metaspace: 2624K->2624K(1056768K)], 0.5580738 secs] [Times: user=0.50 sys=0.06, real=0.56 secs]
Tenured：老年代使用的收集器Metaspace：元空间信息（Java 8+）
5.3 堆内存结构分析
最后是堆内存结构摘要：
Heap
def new generation total 314560K, used 100261K
eden space 279616K, 35% used
from space 34944K, 0% used
tenured generation total 699072K, used 368281K
Metaspace used 2637K, capacity 4486K
✅ Eden 使用率 35%，老年代使用率 52%
✅ 可用于评估是否需要调整堆分区比例
6. 添加时间和日期信息
为了便于与其他日志进行关联，可以在 GC 日志中加入时间戳：
-XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps
输出示例：
2018-12-11T02:55:23.518+0100: 2.601: [GC (Allocation ...
⚠️ Java 9+ 已弃用这两个参数，替代方案为：
-Xlog:gc*::time
7. 将日志写入文件
默认 GC 日志输出到 stdout，实际使用中建议将其重定向到文件：
-Xloggc:/path/to/file/gc.log
⚠️ Java 9+ 弃用该参数，改用：
-Xlog:gc:/path/to/file/gc.log
8. Java 9+ 统一日志系统
Java 9 引入了 -Xlog 作为统一的日志机制，取代了大量旧的 GC 参数。
常用示例：
-Xlog:gc # 输出 GC 信息到 stdout
-Xlog:gc=debug # 输出 debug 级别日志
-Xlog:gc=debug:file=gc.txt # 写入文件
-Xlog:gc=debug::pid,time # 增加 PID 和时间戳
更多信息可参考 JEP 158
9. GC 日志分析工具推荐
手动分析 GC 日志效率低且容易出错。推荐使用专业工具，例如：
✅ GCEasy.io：免费在线 GC 日志分析工具，支持多种 JVM 版本和 GC 类型，提供性能建议和图表展示。
10. 总结
本文详细介绍了 Java 中开启和分析 GC 日志的方法：
- 如何通过
-verbose:gc和-XX:+PrintGCDetails获取详细日志 - 如何添加时间戳、将日志输出到文件
- Java 9+ 新的日志机制
-Xlog - 推荐使用专业工具进行日志分析
掌握 GC 日志的阅读与分析能力，是优化 Java 应用性能的关键技能之一。