2661 字
约 8 分钟
21
S05-X04 · 线上 Full GC 频繁的排查路径:从 GC 日志到堆快照
2024-12-31
2026-11-08

监控告警弹出一条"Full GC 次数异常",接下来最常见的两种反应都不太对:一种是立刻调大 -Xmx,把问题往后推两周;另一种是直接怀疑内存泄漏,开始翻代码找静态 Map。前者掩盖症状,后者可能白忙一场——有相当比例的"Full GC 频繁"根本不是泄漏,而是晋升速度超过了回收速度、元空间触顶、或者某段代码在显式调 System.gc()。

这篇给一条可复现的路径:用 GC 日志确认事实 → 用日志事件给触发原因分类 → 用排除法证伪泄漏 → 取快照定位引用链 → 修完再量一遍。全程只用 JDK 自带工具加 MAT。


1. 先把"频繁"变成一个数

"频繁"是感受,不是指标。上日志之前先定三个量,否则修完也无法判断是否修好。

指标 怎么算 参考阈值 说明
Full GC 次数 每小时 Pause Full 行数 稳态应为 0 有周期性 Full GC 先查定时任务
停顿总时长占比 Full GC 停顿和 / 观察窗口 < 1% 超过就该处理
单次停顿 日志行末尾的 xxx ms 依 SLA 定 决定要不要换收集器
老年代基线 每次 GC 后的 used 值 应回落且平稳 单调抬升才是泄漏信号

-XX:+PrintGCDetails 那套在 JDK 9 后已经作废,JDK 17 只有统一日志:

-Xlog:gc*:file=/var/log/app/gc.log:time,uptime,level,tags:filecount=5,filesize=50m

线上来不及改参数时,先看现有日志有没有 Pause Full:

$ grep -c 'Pause Full' /var/log/app/gc.log
$ grep 'Pause Full' /var/log/app/gc.log | tail -20

2. 读日志:三个事件决定后续方向

G1 的日志行结构是 GC(编号) 事件 (类型) (原因) 前->后(总容量) 耗时。真正要盯的只有三类事件。

# 典型输出形态,按 JDK 17 核对字段顺序
[12.345s][info][gc] GC(42) Pause Young (Normal) (G1 Evacuation Pause) 512M->128M(1024M) 8.123ms
[45.678s][info][gc] GC(88) Pause Full (System.gc()) 900M->450M(1024M) 812.345ms
[45.690s][info][gc] GC(88) To-space exhausted
事件 含义 指向
Pause Young 新生代回收,正常节奏 看频率与 前->后 的存活量
Pause Full 全堆回收,STW 长 看括号里的原因,这是分诊关键
To-space exhausted 晋升时 Survivor/Old 放不下 分配速率过高或堆偏小
Evacuation Failure 复制阶段失败,退化为 Full GC 同上,且通常伴随 Full GC 峰值

Pause Full 后面括号里的原因是最有价值的信息:

$ grep -oE 'Pause Full \([^)]*\)' /var/log/app/gc.log | sort | uniq -c
   1843 Pause Full (System.gc())
      7 Pause Full (G1 Compaction Pause)

前者说明有人在调 System.gc(),跟堆大小、泄漏都没关系;后者是 G1 自己判断需要整理堆。这两种情况的处理方式完全不同,靠"调大堆"一刀切必然失效。

3. 触发原因四分类

原因 日志特征 处置方向
晋升失败 / 疏散失败 To-space exhausted、Evacuation Failure 紧邻 Full GC 增大堆或降低分配速率
元空间触顶 Metadata GC Threshold 出现在 Young GC 原因里,随后 Full GC 查类加载泄漏,评估 MaxMetaspaceSize
显式 System.gc() Pause Full (System.gc()) 找出调用点,或加 -XX:+ExplicitGCInvokesConcurrent
Humongous 分配 原因含 G1 Humongous Allocation,堆中大量 region 只放一个对象 检查大数组/大字符串/批量查询结果

Humongous 值得展开:G1 的 region 通常 1–32MB,超过 region 一半的对象直接按 Humongous 处理,占用连续 region 且集中在老年代。一个 8MB 的 byte[] 反复创建,会让老年代增长得比业务对象快得多。日志里能看到这类分配触发 Young GC 的原因,配合 jcmd GC.heap_info 看 region 使用情况。

$ jcmd 5123 GC.heap_info
# 典型输出形态
garbage-first heap   total 1048576K, used 812345K [0x00000000c0000000, 0x0000000100000000)
  region size 1024K, 233 young (238592K), 12 survivors (12288K)
  Metaspace       used 89234K, committed 96256K, reserved 1114112K

4. 排除法:先证伪"内存泄漏"

在拿快照之前,有一个几乎零成本的判断:Full GC 之后老年代能不能降下来。能降,说明对象是可回收的,问题在"回收不及时";不能降,才轮到泄漏。

$ jstat -gcutil 5123 1000 10
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT
  0.00  96.12  45.31  78.42  92.11  88.30   1204   31.204    18   22.418   53.622
  0.00  96.12  12.08  78.44  92.11  88.30   1205   31.212    18   22.418   53.630

FGC 不变而 O 稳定在 78%,说明当前没有在回收老年代,不代表泄漏;FGC 每几秒 +1 而 O 每次只降 1–2 个百分点,才是"回收不动"的形态。

判据 泄漏 配置不足
Full GC 后 O 基线 逐次抬高,不回落 回落到某个水平后又爬
观察窗口内基线斜率 与请求量无关,持续上升 与流量峰值相关
强制 jcmd GC.run 后 几乎不降 明显下降
堆快照两次对比 同一批对象稳定存在 对象集合波动大

jcmd GC.run 只是取证手段,不要写进任何定时任务——它会让线上多一次本不该有的 STW。

5. 取快照:一次就够,但要看磁盘

确认"降不下来"之后,取一份 hprof。优先用 jcmd,它能精确控制路径:

$ df -h /data/dump
$ jcmd 5123 GC.heap_dump /data/dump/heap-$(date +%H%M).hprof
注意点 后果 做法
会 STW 堆越大停越久 避开高峰,先估算耗时
文件≈堆使用量 写满磁盘 提前 df 确认余量
目录不存在 静默失败 mkdir -p 并验证可写
只在 OOM 时才自动转储 事后无现场 加 HeapDumpOnOutOfMemoryError

如果怀疑的是"缓慢增长",取两份间隔 30 分钟的快照,在 MAT 里做 histogram 对比,比看单份快照准得多:单份快照只能告诉你"谁占内存",两份对比才能告诉你"谁在变多"。

6. MAT:支配树与引用链

视图 回答的问题 使用顺序
Leak Suspects 有没有可疑聚集 第一眼,只作假设
Histogram 哪个类型实例数/字节数异常 第二眼,找异常类型
Dominator Tree 哪个对象持有量最大 第三眼,定位持有者
Path to GC Roots 谁抓着不放(排除弱引用) 第四眼,落到代码
OQL 按条件筛实例 需要精确匹配时

引用链这一步最容易出错:默认要选 exclude weak/soft references,否则会看到一堆 WeakHashMap、Finalizer、ThreadLocalMap 的软引用路径,全是噪音。

-- OQL:找出超过 10MB 的 byte[]
SELECT s FROM byte[] s WHERE s.length > 10485760

7. 五类根因与它们的引用链长相

根因 引用链特征 修复方式
静态集合只增不减 Class.staticField → HashMap → Entry → 业务对象 加容量上限或改 WeakHashMap/带过期的缓存
ThreadLocal 未 remove Thread → ThreadLocalMap → Entry → 大对象 finally 里 remove(),线程池场景必须做
监听器/回调未注销 XXManager → ListenerList → 匿名内部类 → 外部类 注册与注销成对,或改弱引用
连接池/会话泄漏 Pool → idle/active 集合 → Connection 借还成对,开 leakDetectionThreshold
缓存无上限 Cache → ConcurrentHashMap → Segment → Entry 换 Caffeine/Guava 并设 maximumSize

第 2 类在线程池环境下特别危险:线程被复用,ThreadLocalMap 跟着线程活到进程结束,remove() 漏一次就永久泄漏一份。这也是"线程数不多但老年代一直涨"的典型来源。

8. 修完怎么验证

改完代码不等于问题解决,要按窗口量:

验证项 期望 观察窗口
Pause Full 次数 稳态 0,或只在预期时点出现 ≥ 24h,跨一个流量高峰
老年代基线 每次 GC 后回落且不单调抬升 同上
单次停顿 落在 MaxGCPauseMillis 附近 同上
接口 P99 不再出现与 Full GC 对齐的尖刺 与告警阈值对齐
RSS 稳定,不持续爬升 一周

如果修完 Full GC 归零但 P99 还在抖,问题大概率不在 GC,去看线程阻塞或下游超时——GC 是最容易背锅的那一项。

9. 排错:五种常见误判

现象 误判 实际
Pause Full 很多但堆不大 以为泄漏 多半是 System.gc() 或元空间触顶
老年代高但 FGC 为 0 以为没问题 只是没触发,看分配速率与 Humongous
加了 -Xmx 后好转两周 以为修好了 泄漏若在,基线还会回来
快照里最大对象是 char[] 以为是字符串泄漏 往上看持有者,通常在业务集合里
jstat 的 O 一直 99% 以为要 OOM G1 下老年代占用高是常态,看能否回收

最后一条要强调:G1 的设计就是"尽量用满再回收",老年代 90% 并不等于危险。判断依据永远是回收后能不能降,不是瞬时占用率。

10. 边界:什么时候该换思路

情况 GC 日志够不够 下一步
停顿长但 Full GC 不频繁 不够 看 Young GC 停顿分布与 gc+phases
堆外内存增长 完全看不到 NativeMemoryTracking + pmap
分配速率过高 部分可见 async-profiler 的 alloc 模式
容器被 OOMKilled 日志可能没有 看 cgroup memory.events
类加载持续增长 只有阈值告警 jcmd VM.classloader_stats

11. 自测

  1. 判断"Full GC 频繁"要先量哪三个数?
  2. Pause Full (System.gc()) 和 Pause Full (G1 Compaction Pause) 的处理差别在哪?
  3. To-space exhausted 说明了什么?
  4. 为什么说"Full GC 后老年代能否回落"是泄漏的第一判据?
  5. 取两份快照的意义是什么,单份为什么不够?
  6. G1 下老年代占用 90% 为什么不必然是问题?
S05-X04 · 线上 Full GC 频繁的排查路径:从 GC 日志到堆快照
https://www.clxhxhhr.top/posts/5647/
作者
clxstart
发布于
2024-12-31
许可协议
CC BY-NC-SA 4.0
评论
0 条
还没有评论,先写一条吧。