“GC 有问题”不是一个能直接执行的判断。要落到具体参数，得先回答三个数：停顿有多长、频率有多高、是什么触发的。监控面板上的“GC 次数”曲线给不了这三样，只有日志给得了。

这篇按“开日志 → 读单行 → 算影响 → 归因到参数”的顺序走一遍。

---

1. 日志要回答的三个问题

问题	日志里的位置	读法
停顿多长	Pause 行末尾的 <n>ms	单次值要看分布，不看最大值
频率多高	行首 uptime 时间戳	相邻 Pause 的时间差，换算成每分钟次数
谁触发的	行内的 Young/Mixed/Full 与 (Cause)	括号里是触发原因，如分配失败、System.gc()

三个问题对应三种完全不同的处置：停顿长但稀少，是单次回收量太大；频率高但每次很短，是分配速率或新生代太小；Full GC 频繁，多半是晋升过快或真泄漏。只回答其中一个，参数一定会调错方向。

---

2. 开启方式：统一日志语法

JDK 9 起 -XX:+PrintGCDetails、-XX:+PrintGCTimeStamps 全部废弃，由 -Xlog 统一接管。在 JDK 17 上继续写这些老参数，要么被忽略，要么直接报参数不识别的错误。

# 最常用的一条：全量 GC 日志 + 时间戳 + 轮转
java -Xlog:gc*:file=/var/log/app/gc.log:time,uptime,level,tags:filecount=5,filesize=20M -jar app.jar

# 只要停顿，不要阶段细节
java -Xlog:gc:file=/var/log/app/gc.log:time,uptime -jar app.jar

# 需要看 G1 的决策依据时，加 debug 级 tag
java -Xlog:gc+ergo*=debug,gc+heap=debug:file=/var/log/app/gc.log:time,uptime,level,tags -jar app.jar

语法片段	作用	常见值
tag 集合	选事件类别	gc、gc*（含子 tag）、gc+phases、safepoint
输出目标	写到哪里	stdout、file=/path/gc.log
decorators	每行附加什么	time、uptime、level、tags、pid
轮转	控制文件体积	filecount=5,filesize=20M
级别	过滤粒度	info（默认）、debug、trace

生产最容易漏的是 time 与轮转：没有 time 就难以和 access log 对齐，没有轮转会打满磁盘。

不重启也能开：

$ jcmd 5123 VM.log output=/var/log/app/gc.log what=gc* decorators=time,uptime,level,tags
$ jcmd 5123 VM.log list
$ jcmd 5123 VM.log disable

---

3. G1 的关键日志行怎么读

单行的结构是固定的，把它拆成槽位看，比整行读快得多：

[<uptime>s][info][gc] GC(<序号>) Pause Young (Normal) (G1 Evacuation Pause) <前>M-><后>M(<容量>M) <停顿>ms

槽位	含义	异常信号
Pause Young (Normal)	常规年轻代回收	间隔短 → 分配快或 Eden 小
Pause Young (Concurrent Start)	并发标记周期的起点	与后续 Mixed 配对看
Pause Mixed	混合回收，连带若干老年代 region	轮次多但占用不降 → 回收不动
Pause Full (G1 Compaction Pause)	退化到 Full GC	一出现就说明并发周期没跟上分配
前M->后M(容量M)	回收前后已用堆	看“后”值是否逐次上移
Evacuation Failure	存活对象拷贝失败	目标区不足，往往紧跟 Full
to-space exhausted	目标区被耗尽	同上，属于退化前兆
Humongous 分配	对象超过 region 一半	频繁出现 → 大对象直接压老年代

Evacuation Failure 与 to-space exhausted 不是“回收了一次”，而是“这次回收没能完成搬迁”，后续通常由 Full GC 兜底。看到它们先查 Survivor 空间与晋升速率。

---

4. 停顿与并发阶段要分开算

维度	STW 停顿	并发阶段
应用线程	全部暂停	继续运行
日志标识	Pause ...	Concurrent ...
对业务的影响	直接表现为 RT 毛刺与超时	不暂停，但抢 CPU 与内存带宽
该看什么	单次时长、频率、窗口内总和	标记耗时是否追得上分配速率

看到 Concurrent Mark 占了不少 CPU 就断定“GC 拖慢了服务”，是日志分析里最常见的误判。只有 Pause 行才对应应用真的停住。

---

5. 从日志算出真实影响

单次最长停顿只是分布的一个端点。真正影响业务的是一个时间窗口内的停顿总时长与分位值。

# 提取每次 Pause 的毫秒数，算次数/总时长/均值/最长
$ grep -E 'Pause (Young|Mixed|Full)' gc.log | grep -oE '[0-9.]+ms$' | tr -d 'ms' \
  | awk '{s+=$1; n++; if($1>m)m=$1} END{printf "次数=%d 总停顿=%.0fms 均值=%.2fms 最长=%.1fms\n", n, s, s/n, m}'

# p99：只看分位，不受离群点干扰
$ grep -E 'Pause' gc.log | grep -oE '[0-9.]+ms$' | tr -d 'ms' | sort -n \
  | awk '{a[NR]=$1} END{printf "p99=%.1fms\n", a[int(NR*0.99)]}'

按分钟窗口聚合（gawk 语法，match 带数组）：

$ awk '/Pause/ { match($0,/^\[([0-9.]+)s\]/,u); match($0,/([0-9.]+)ms$/,t);
    if (u[1] != "") { w=int(u[1]/60); sum[w]+=t[1]; cnt[w]++ } }
  END { for (k in sum) printf "%dmin 停顿%.0fms 次数%d\n", k, sum[k], cnt[k] }' gc.log | sort -n

每分钟总停顿换算出占比，再和业务 RT 曲线对照：停顿窗口与超时峰值对不上，问题就不在 GC。

---

6. 三类问题与对应参数

症状	日志判据	先动什么	别先动什么
Young 过频	Pause 间隔短，Eden 每次很快填满	-XX:G1NewSizePercent / G1MaxNewSizePercent；更根本的是降分配速率	不要先收紧 MaxGCPauseMillis
Mixed 收不动	Mixed 轮次多、后M 不降、老年代接近上限	-XX:InitiatingHeapOccupancyPercent、G1HeapWastePercent、G1MixedGCLiveThresholdPercent	不要只加 -Xmx
Full 频繁	出现 Pause Full (G1 Compaction Pause)	先排泄漏与晋升过快；再看 MaxTenuringThreshold、Survivor 比例	不要把 Full 当“参数没调好”
单次停顿超目标	Pause 的 ms 明显高于目标	收紧 MaxGCPauseMillis，让 Young 更小、Mixed 每次更少	不要设成不可达的值

# 一个保守的起点，先改一项再观察一轮
java -Xmx4g -XX:MaxGCPauseMillis=200 -XX:G1NewSizePercent=20 -XX:G1MaxNewSizePercent=40 \
     -XX:InitiatingHeapOccupancyPercent=40 -Xlog:gc*:file=/var/log/app/gc.log:time,uptime,level,tags -jar app.jar

一次只改一个参数，这是唯一能归因的调法。

---

7. MaxGCPauseMillis 是目标不是保证

G1 用它来推算“这一轮能收多少个 region、年轻代该多大”。它是一个期望值，不是 SLA：

• 存活对象总量决定单次回收的下限，目标低于下限，G1 只能更频繁地做更小的回收，总开销反而上升；
• 目标越紧，Young 越小、Young GC 越多，总 CPU 占用越高；极紧（个位数毫秒）在 G1 上基本不可达。

正确用法：先测当前 p99 停顿与存活集规模，把目标设在“略优于现状且物理可达”的位置，再看窗口内总停顿是否下降。只盯达成率没意义。

---

8. 与业务指标对齐

# 用同一时间轴对齐：先圈出停顿窗口，再去 access log 里看这段时间的超时
$ grep -E 'Pause (Young|Mixed|Full)' gc.log | awk '$0 ~ /ms$/ {print}' | tail -n 20

# 单次停顿超过阈值的行，作为“可疑窗口”列表
$ awk '/Pause/ && /ms$/ { n=$0; sub(/.*[^0-9.]([0-9.]+)ms$/, "\\1", n);
    if (n+0 > 100) print }' gc.log | head

对齐之后看两件事：超时请求是否集中在停顿窗口内；停顿窗口内的 RT 分布是否整体右移。若超时均匀散布在全程，GC 只是背景噪声，真正的原因在别处（下游、锁、连接池）。

---

9. ZGC / Shenandoah 的日志差异

收集器	关键日志行	该看什么
G1	Pause Young/Mixed/Full、Concurrent Mark Cycle	停顿分布 + Mixed 是否收得动
ZGC	Pause Mark Start/End、Pause Relocate Start、Concurrent Mark/Relocate	停顿次数少、与堆大小关系弱；重点看并发阶段是否追得上分配，以及 Allocation Stall
Shenandoah	Pause Init Mark、Pause Final Mark、Pause Final Evac	同上，另看 Degenerated GC 是否频繁
Parallel / Serial	Pause Young、Pause Full	只有停顿与频率，没有并发阶段可看

以停顿时间为目标的收集器，判据从“单次停顿最长多少”换成“停顿是否稳定、并发阶段有没有被分配速率拖垮”。ZGC 上出现 Allocation Stall，说明分配快过并发回收，调停顿目标无效，要降分配或加堆。

---

10. 排错：读日志时的误判

现象	原因	处理
日志里没有时间戳	decorator 未加 time	补 :time,uptime,level,tags
日志把磁盘打满	没配轮转	filecount + filesize，或交给 logrotate
只盯单次最长停顿	单点不代表分布	统计窗口总停顿与 p99
把 Concurrent 阶段算成停顿	只看 CPU 曲线	以 Pause 行为准
Evacuation Failure 反复出现	目标区不足、晋升过快	调 Survivor 比例与 IHOP，查大对象
Humongous 频繁	大对象超过 region 一半	调 G1HeapRegionSize，或减少大数组
老参数不生效	JDK 9 起 PrintGCDetails 废弃	改 -Xlog:gc*
业务无感却在调参	停顿短、频率低	不调，别为指标好看而动参数

---

11. 边界：GC 日志回答不了什么

场景	日志给不了	该看什么
谁在制造垃圾	只有回收结果	JFR ObjectAllocationSample、async-profiler alloc
停顿期间哪些请求超时	只有时间点	access log / trace 对齐
堆外与 Metaspace	不在 GC 日志范围	NMT、jcmd VM.metaspace
被容器限流导致的“卡顿”	不是 GC 造成的	/sys/fs/cgroup/cpu.stat 的 throttling 计数
收集器内部决策	需要更细 tag	-Xlog:gc+ergo*=debug、gc+heap=debug

一句话收口：GC 日志能证明“停了多久、停了几次、谁触发”，证明不了“为什么有这么多对象”。 后者要回到分配侧去看。

---

12. 自测

1. 只有 Pause 行能代表应用真的停住，Concurrent 行为什么不能算停顿？
2. 日志里没有 time decorator，会失去哪一种分析能力？
3. 为什么说“窗口内总停顿”比“单次最长停顿”更能反映业务影响？
4. Evacuation Failure 出现时，先查什么，而不是先动 MaxGCPauseMillis？
5. MaxGCPauseMillis 设得比存活集能支撑的下限还低，会发生什么？
6. ZGC 日志里出现 Allocation Stall，说明并发回收与分配速率是什么关系？