JVMNotes

第 20 章：GC 日志分析

zjc 于 2026-01-20 发布

这是《JVM 零基础实战指南》的独立章节版。本章从概念、实操和生产排查三个视角展开，代码块保留了原书可直接运行的版本。 GC 日志是判断 JVM 内存健康度最重要的证据。它不能直接告诉业务代码哪里有问题，但能回答三个关键问题：垃圾什么时候产生、GC 做了什么、应用为 GC 付出了什么代价。

JDK 9 以后统一使用 -Xlog 体系；JDK 8 及更早版本使用 -XX:+PrintGCDetails 等旧参数。本章以统一日志为主，同时说明旧日志的阅读方法。

20.1 开启日志

现代 JDK 通用配置：

java -Xlog:gc*,safepoint:file=gc.log:time,uptime,level,tags:filecount=10,filesize=50m \
  -jar app.jar

参数拆解：

片段 含义
gc* 所有 gc 标签日志
safepoint 安全点日志
file=gc.log 输出文件
time,uptime 时间格式
filecount=10,filesize=50m 最多 10 个文件，每个 50MB

JDK 8 常见配置：

java -XX:+PrintGCDetails \
  -XX:+PrintGCDateStamps \
  -XX:+PrintTenuringDistribution \
  -Xloggc:gc.log \
  -XX:+UseGCLogFileRotation \
  -XX:NumberOfGCLogFiles=10 \
  -XX:GCLogFileSize=50M \
  -jar app.jar

这些旧参数在新 JDK 中可能无效或行为不同，迁移时要替换为 -Xlog。

20.2 日志样本

G1 日志简化示例：

[2026-08-25T10:00:01.123+0800][12.345s] GC(12) Pause Young (Normal)
JavaHeap: 2048M->512M(4096M)
[12.400s] GC(12) PlayerThreadScan=1ms
VM Thread=3ms

Parallel 日志简化示例：

[2026-08-25T10:00:02.456+0800] GC(20) PSYoungGen: 1536M->192M(1792M)]
ParOldGen: 512M->480M(2048M)]
Heap after GC invocations=20:
  PSYoungGen 192M(1792M) ParOldGen 480M(2048M)

ZGC 日志简化示例：

GC(3) Garbage Collection (Warmup)
GC(3) Pause Mark Start 0.018ms
GC(3) Concurrent Mark 25ms
GC(3) Pause Mark End 0.021ms
GC(3) Concurrent Relocate 12ms

日志格式会随 JDK 版本变化，分析时应关注字段含义，不要死记某一行样例。

20.3 关键指标

每次 GC 至少要看四类信息。

指标 含义
GC 前堆使用 回收压力
GC 后堆使用 存活对象规模
堆容量 剩余空间
停顿时间 对应用延迟的直接影响

还应该统计：

Young GC 次数
Mixed GC 次数
Full GC 次数
平均停顿
P99 停顿
最大停顿
GC 频率
吞吐损失
晋升速率
回收效率

吞吐损失可以简化计算：

GC 时间占比 = 总 GC 停顿时间 / 观察窗口总时间 * 100%

并发 GC 的并发阶段时间不计入停顿，但会消耗 CPU，也应单独观察。

20.4 判断 Minor GC

健康的 Minor GC 通常表现为：

  1. Eden 快满时触发；
  2. 回收后新生代占用明显下降；
  3. 老年代没有快速增长；
  4. 停顿符合预期。

异常形态：

Young GC 前：Eden 1024M -> Survivor 96M -> Old 300M
Young GC 后：Eden   0M -> Survivor 96M -> Old 310M
连续 10 次

这说明每次都有对象晋升，老年代按每次 10M 增长。若增速稳定且最终会回收，可能只是缓存预热；若持续增长，就要怀疑大对象、长生命周期对象或 Survivor 过小。

20.5 判断晋升问题

常见晋升原因：

原因 日志特征 方向
Survivor 太小 对象过早进入老年代 调整比例或大小
对象太大 Eden 直接分配老年代 拆分对象
Tenuring 阈值低 晋升年龄小 观察 age 分布
突发流量 短期分配速率高 限流或扩容
对象确实长期存活 Old 稳定后不再降 属于业务数据

JDK 8 可以开启对象年龄分布：

-XX:+PrintTenuringDistribution

G1 也可以通过 gc+age=trace 观察更细信息。年龄分布要结合多次 GC 看，单次数据没有结论。

20.6 判断 Full GC

Full GC 通常不是好事，常见原因包括：

  1. 老年代空间不足；
  2. 元空间不足；
  3. System.gc() 显式触发；
  4. CMS concurrent mode failure；
  5. promotion failed；
  6. JVM 兜底行为；
  7. 巨型对象分配失败。

处理顺序：

1. 找到触发原因
2. 判断是否回收有效
3. 看回收后老年代占用
4. 分析晋升来源
5. 检查元空间和直接内存
6. 必要时抓堆 dump

如果 Full GC 后堆占用从 3.5g 降到 1g，说明有大量临时对象进入老年代，应优化分配和晋升；如果从 3.5g 只降到 3.4g，说明存活对象确实很多，扩容或减少对象才是方向。

20.7 安全点

有些延迟不是 GC 停顿导致，而是安全点等待导致。

发起安全点
  -> 等待所有 Java 线程到达安全点
  -> 执行 VM 操作
  -> 恢复线程

典型现象：

Total time for which application threads were stopped: 120ms
Garbage collection: 5ms

GC 只花了 5ms，但应用停了 120ms，多出的 115ms 可能花在等待线程进入安全点。常见原因是长循环计数没有安全点、大数组清零、反优化等。

JDK 11+ 可用：

-Xlog:safepoint

排查时不要只看 GC 日志里的 Pause，还要看应用线程总停止时间。

20.8 日志分析流程

一个实用流程：

1. 确认时间窗口和故障时间
2. 统计 GC 次数、频率、停顿分布
3. 找 Full GC、Degenerated GC、Allocation Stall
4. 对比 GC 前后新生代、老年代、元空间
5. 计算晋升速率
6. 关联流量、定时任务、缓存预热
7. 观察安全点等待
8. 得出假设并验证

表格化记录：

时间 事件 GC 前后 停顿 业务表现 结论
10:00 Young GC 2g -> 600m 20ms P99 30ms 正常
10:05 Full GC 3.8g -> 3.6g 2s 超时 存活对象高

把 GC 事件和业务指标放在同一时间轴上，很多问题会立刻显形。

20.9 常用分析工具

工具 用途
GCEasy 上传日志，生成统计图表
GCViewer 本地查看旧日志
IBM GC Policy Analyzer 分析特定策略
JFR 结合分配、锁、CPU 分析
Arthas 在线观察 JVM 和方法
Prometheus + Grafana 暴露 GC 指标并告警

工具只是汇总数据，判断仍要回到四个问题：

  1. 为什么触发；
  2. 回收了多少；
  3. 停了多久；
  4. 是否影响请求。

20.10 建议告警

指标 告警方向
5 分钟 Full GC 次数 大于 0 需关注
GC 停顿 P99 超过延迟目标
GC 时间占比 持续超过阈值
老年代回收后占用 持续增长
Allocation Stall 大于 0 需分析
安全点等待 显著高于 VM 操作耗时

不要把“GC 次数多”单独当成故障。高吞吐服务 Young GC 频繁可能是正常现象，关键看停顿和业务延迟。

本章小结

GC 日志分析的核心是把事件、耗时、空间变化和业务影响关联起来。现代 JDK 使用 -Xlog 统一日志体系，应重点观察停顿分布、回收效果、晋升速率、Full GC 原因和安全点等待。日志只能给出方向，最终结论要结合流量、线程、CPU 和堆 dump 验证。

思考题

  1. 同样 100ms 的应用停顿，为什么可能是 GC，也可能是安全点等待？
  2. 如何通过 GC 前后空间变化判断缓存泄漏？
  3. Full GC 后堆从 3.8g 降到 1.2g，说明什么？
  4. Young GC 频繁但停顿很短，一定需要调优吗？
  5. 如何设计一套 GC 告警规则？