Java 服务 P99 从 50ms 飙到 2s？G1 Full GC 从日志到代码的完整排查

现象：P99 从 50ms 飙到 2s，日志里全是 Full GC

线上一个 Java 商品详情服务，QPS 稳定在 1200 左右，没做任何发版。某天开始 P99 从 50ms 爬到 2s，监控大盘上 CPU 不高、内存也没打满，只有一条曲线异常：Full GC 从每天 1 次变成每小时 6 次。

这类问题的坑在于"看起来不像 GC 问题"：堆内存使用率只有 60%，没有 OOM，JVM 进程也活着。但 G1 的 Full GC 是 STW 的，一次 800ms 的停顿足以把 P99 拉爆。

第一步：先确认 Full GC 频率，别猜

别一上来就 dump 堆，先花 10 秒看清事实：

jstat -gcutil <pid> 1000 20

输出里重点看四列：

• FGC：Full GC 次数，30 秒内涨了 3 次就说明有问题
• FGCT：Full GC 累计耗时，用它除以 FGC 得到平均停顿
• O：老年代使用率，注意它是不是"GC 后仍缓慢上涨"
• GCT：总 GC 耗时占运行时间比例，超过 5% 就要处理

本次实测：30 秒内 FGC 涨 3 次、单次平均 780ms、老年代每次 Full GC 后仍停在 68% 不降 —— 这是典型的存活对象真的多，不是 GC 参数配得不激进。

第二步：开 GC 日志，看清是谁触发了 Full GC

JDK 9+ 统一用 unified logging，不用再纠结 -XX:+PrintGCDetails：

-Xlog:gc*,gc+heap=info,gc+ergo*=debug:file=/data/logs/gc.log:time,uptime,level,tags:filecount=10,filesize=50m

G1 触发 Full GC 通常只有三种原因，日志里能直接看到关键字：

• to-space exhausted：Survivor 区放不下晋升对象，说明晋升速率远大于回收速率
• humongous allocation：分配了超过 Region 大小一半的大对象，这类对象直接在老年代分配
• Metadata GC Threshold：元空间/类加载器泄漏，跟堆没关系但一样 STW

本次日志里反复出现 humongous allocation，配合 G1 Evacuation Pause (young) 前的老年代占比，方向就锁定了：有超大对象在持续分配。

第三步：jmap 找大对象，别直接 dump 整堆

整堆 dump 一个 8G 的堆会 STW 好几秒，线上慎用。先用轻量的方式看直方图：

jmap -histo:live <pid> | head -20

本次头部出现：

num     #instances         #bytes  class name
  1:          1240      4823449600  [B
  2:       2188331       105040288  java.lang.String
  3:          1240          99200  com.example.detail.PriceSnapshot

1240 个 byte[] 占了 4.8G，平均每个 3.9MB —— 明显是 humongous object。再看持有者 PriceSnapshot，只有 1240 个实例，每个持有一个巨大 byte 数组。

追代码发现：PriceSnapshot 会把整份价格配置 JSON 序列化后缓存在对象里做快照对比，而配置在某次运营操作后从 200KB 膨胀到 4MB，缓存条目数又是按商品维度 1240 个，于是堆里堆了 4.8G 的大对象。

第四步：三层一起治，只改参数没用

1）业务层：快照改成差分存储

根本原因是把完整 JSON 当快照存。改成只存 diff：

public class PriceSnapshot {
    // 改造前：private byte[] rawJson;
    private Map<Long, Integer> changedItems; // 只存变化的 SKU
    private long baseVersion;
}

改造后单个快照从 3.9MB 降到平均 6KB，1240 个实例合计不到 8MB。

2）缓存层：给容器加硬上限

这类"按业务维度无界缓存"必须有上限和淘汰，用 Caffeine 一行搞定：

Cache<Long, PriceSnapshot> cache = Caffeine.newBuilder()
    .maximumSize(2000)
    .maximumWeight(128L * 1024 * 1024)   // 总权重上限 128MB
    .weigher((k, v) -> v.estimatedBytes())
    .expireAfterWrite(Duration.ofMinutes(10))
    .build();

关键在 maximumWeight + weigher：只限制条目数没用，1000 个 4MB 的对象照样是 4G。

3）JVM 层：让 G1 对大对象更友好

参数是辅助手段，但在大对象不可避免时能明显减少 humongous 分配次数：

-XX:+UseG1GC
-XX:MaxGCPauseMillis=200
-XX:G1HeapRegionSize=16m          # 默认按堆大小推算，1MB~32MB
-XX:G1HeapWastePercent=5
-XX:InitiatingHeapOccupancyPercent=40
-XX:G1MixedGCLiveThresholdPercent=85

G1HeapRegionSize 是最容易被忽略的一个：Region 越大，被判为 humongous 的对象阈值（Region/2）越高，大对象进入年轻代回收的几率就越大。本次从默认 4MB 调到 16MB，阈值从 2MB 提到 8MB，正好覆盖大部分快照对象。

效果对比

五个实战坑

1. jmap -histo:live 会触发一次 Full GC。它要统计存活对象，等于强制回收。线上执行前先确认这个实例已经在负载均衡里被摘掉，或者至少挑低峰期。
2. 别只看 heap used 就下结论。堆用 60% 也可能频繁 Full GC，判断依据应该是 FGC 频率和 GC 后老年代回收率，不是使用率绝对值。
3. G1 的 humongous 对象是"整 Region 占用"。一个 3.9MB 对象在 4MB Region 里独占一个 Region，即使只用了 97% 的空间也无法再分配其他对象，实际浪费远大于对象本身大小。
4. maximumSize 拦不住大对象。缓存条目数限制和内存占用是两件事，必须配 maximumWeight 或自己做大小预算。
5. 元空间泄漏会伪装成堆问题。如果 GC 日志里出现 Metadata GC Threshold，去看 jstat -gcmetacapacity 和动态代理类数量（jcmd <pid> VM.classloader_stats），方向完全不同。

小结

Full GC 排查的顺序应该是：jstat 确认频率 → GC 日志看触发原因 → histo 找大对象 → 代码定位持有者 → 业务/缓存/JVM 三层一起治。只调 MaxGCPauseMillis 是最常见的无效努力，它只能让单次停顿短一点，改不了"每 10 分钟攒出 4G 大对象"这个事实。