主题
界面
GC 日志分析与 JVM 调优
1. 本节定位
「调优」不是背参数，而是：看懂日志 → 定位病 → 再动手。
★ 本节跑出三份真实 GC 日志（稳态 / 泄漏 OOM / 大对象突发），再用自写解析器读它们：
text
steady（128M 堆）：Young 13 次 0 次 Full，存活量稳定在 9M ✓✓
leak （64M 堆） ：存活量 61M→63M 顶住上限，Full GC 5 次（G1 Compaction Pause）后 OOM ✗✗
spike（128M 堆）：Full GC 里 3 次原因写着 (System.gc()) —— 是代码自己调的 ✗★★ 一个反直觉的实测细节：steady 组 13 次 Young GC 的原因全是 (G1 Humongous Allocation) ——小堆 + 1MB 数组 = 每个数组都够 Humongous 门槛（呼应 《JVM 内存结构与对象创建》）✓✓
2. 学习目标
- 会开
-Xlog:gc*并逐字段读一条 Pause 行 ★★★； - 能从日志判断「健康 / 泄漏 / 大对象 / 显式 GC」四类问题 ★★★；
- 会按「目标 → 手段 → 验证」三步做调优，而不是套参数 ★★★；
- 知道调优顺序：先看代码与存活量，再调堆与收集器 ★★★。
3. 前置知识检查
- 知道分代假说与收集器选型吗？（《垃圾回收算法与收集器》）✓
- 知道 Humongous 判定吗？（《JVM 内存结构与对象创建》）✓
4. 为什么需要这个知识
★ 线上「接口偶尔卡一下」的头号嫌疑人就是 GC ✗✓（呼应 T2-014 的 P99 毛刺）—— 而排查的起点不是调参，是日志 ✓✓✓：
| 只会这一句 | 实际要看 |
|---|---|
| 「加内存就好了」✗ | 存活量是否持续上涨（泄漏加内存也白搭） |
| 「换 ZGC 就好了」✗ | Full GC 的原因是什么（是代码在调 System.gc()） |
| 「GC 次数太多」⚠️ | 次数 × 单次停顿的总账，以及是什么在触发 |
5. 核心概念
5.1 日志怎么开 ★★★
powershell
java -Xmx64m "-Xlog:gc*:file=gc.log" -cp <classes> <主类>★ 三个关键参数 ✓✓： gc*（全部 gc 相关标签）/ file=（写文件，避免拖慢 stdout）/ 生产加 time,uptime,level,tags 等装饰 ✓。
5.2 读一条 Pause 行 ★★★
text
GC(3) Pause Young (Normal) (G1 Evacuation Pause) 33M->1M(66M) 1.346ms
↑ ↑类型 ↑原因分类 ↑GC 名称 ↑回收前→回收后(堆容量) ↑停顿★★ 三元组读法：「活多少 → 还剩多少」比「回收了多少」更有信息量 ✓✓✓ —— 回收前后都是 30M+ = 对象回收不掉（泄漏信号） ✗✗。
5.3 三份日志，三种「病」（本节实测）★★★
| steady（稳态） | leak（泄漏） | spike（大对象） | |
|---|---|---|---|
| 参数 | -Xmx128m | -Xmx64m | -Xmx128m |
| Young 次数 | 13 | 6 | 4 |
| Full 次数 | 0 ✓✓ | 5（Compaction）✗✗ | 5（3 次 System.gc()）✗ |
| 存活量趋势 | 9M 平坦 ✓ | 61M→63M 顶上限 ✗✗✗ | 18M→83M→66M→…→1M |
| 结局 | 正常结束 | OutOfMemoryError: Java heap space ✗✗✗ | 128MB 分配失败 ✗ |
★ leak 的关键证据链 ✓✓✓：存活量顶到堆上限（63M/64M）→ Full GC 反复 Compaction → 最终 OOM —— 而 G1 Compaction Pause 的含义就是「整理也腾不出空间了」✗✗。
5.4 原因分布：别把「代码自己调的 GC」当故障 ★★★
★ spike 组的 Full GC 原因分布（实测）：
text
Full｜(System.gc()) x 3 ← 实验代码里每轮显式调用 System.gc() ✓ 是我们自己引起的
Young｜(Concurrent Start) (G1 Humongous Allocation) x 2 ← 大对象触发
Full｜(G1 Compaction Pause) x 2 ← 真正「装不下」的整理★★ 同一个数字，原因不同，含义完全不同 ✓✓✓： 生产代码里出现 System.gc() 是禁忌（一次 Full GC 可能 = 数百毫秒停顿）✗✗；而 G1 Compaction Pause 才是内存压力信号 ✓。
5.5 调优套路：目标 → 手段 → 验证 ★★★
text
① 定目标：低延迟（P99 < 100ms）还是高吞吐（批处理跑得快）？
② 看日志：次数 × 单次停顿；存活量趋势；Full GC 有无与原因
③ 定手段：
存活量上涨 → 查代码（泄漏/无界缓存），调参救不了 ✗✗
存活量平坦 → 堆/收集器/Region 才有意义 ✓
大对象 → 分块处理 / 调大 Region / 抬高 Humongous 门槛 ✓
④ 验证：同一压测流量，前后对比「次数 × 停顿」与业务 SLO ✓✓★ 参数速查 ✓：
| 参数 | 作用 | 备忘 |
|---|---|---|
-Xms / -Xmx | 初始 / 最大堆 | 生产建议相等，避免扩容抖动 ✓✓ |
-XX:+UseG1GC 等 | 收集器 | 按堆大小与延迟目标选（《垃圾回收算法与收集器》）✓ |
-XX:G1HeapRegionSize | Region 大小 | 大对象多时调大，减少 Humongous ✓ |
-XX:+HeapDumpOnOutOfMemoryError | OOM 自动导堆 | 上生产前必配 ✓✓✓ |
6. 递进示例
6.1 采集
powershell
# 泄漏演练：64M 堆，几十秒看到 OOM
java -Xmx64m "-Xlog:gc*:file=gc-leak.log" -cp <classes> cn.kb.learn.deep.jvm.GcTuningLesson leak6.2 分析
powershell
java -cp <classes> cn.kb.learn.deep.jvm.GcLogParser gc-leak.log6.3 反例：看到 Full GC 就加内存
text
leak 场景把 -Xmx 从 64M 加到 128M → OOM 推迟，但照样 OOM ✗✗
根因是「静态集合只进不出」，加内存只是延后崩盘 ✓✓7. 完整可运行代码与实测
代码：labs/java-deep/src/main/java/cn/kb/learn/deep/jvm/GcTuningLesson.java（三种负载）+ GcLogParser.java（日志分析）
实测一（steady，-Xmx128m）：
text
[steady] 每轮 8MB 短命对象 x 40 轮
第 10 轮结束，堆使用约 18MB
第 20 轮结束，堆使用约 34MB
第 30 轮结束，堆使用约 50MB
第 40 轮结束，堆使用约 17MB
-- 次数与停顿 --
Young GC：13 次，平均 1.8 ms，最长 3.4 ms
全部 GC：13 次，总停顿 22.8 ms
-- 原因分布 --
Young｜(Concurrent Start) (G1 Humongous Allocation) x 13
-- 堆趋势（最后 8 次）--
9M → 9M → 9M → 9M → 9M → 9M → 9M → 9M
✓ 全程 0 次 Full GC —— 说明没有「整堆都被卡住」的回收
✓ 停顿平缓（最长 3.4 ms / 平均 1.8 ms）—— 对在线服务友好实测二（leak，-Xmx64m） —— 本节最有信息量的一份：
text
已累积 10MB，堆使用约 22MB
已累积 20MB，堆使用约 41MB
已累积 30MB，堆使用约 61MB
第 32 MB 分配失败 → OutOfMemoryError: Java heap space
（静态集合已持有 31MB，已强制清空自救）
-- 次数与停顿 --
Young GC：6 次，平均 0.9 ms；Full GC：5 次，平均 2.8 ms
-- 原因分布 --
Full｜(G1 Compaction Pause) x 5
Young｜(Concurrent Start) (G1 Humongous Allocation) x 3
...
-- 堆趋势（最后 8 次）--
61M → 61M → 63M → 63M → 63M → 63M → 63M → 1M
✗✗ 存活量顶到堆上限附近（63M / 上限 64M）：OOM 的前兆或已经发生
✗✗ 出现 Full GC 5 次 —— 先看上面的原因★★ 最后那条「1M」是故意的教学点 ✓✓✓：它来自 catch 到 OOM 后清空集合自救 —— 日志的最后一帧会「骗人」，读懂趋势必须结合代码行为 ✓✓。
实测三（spike，-Xmx128m）：
text
已分配 16MB 单块（length=16777216），堆使用约 19MB
已分配 64MB 单块（length=67108864），堆使用约 83MB
分配 128MB 失败 → OutOfMemoryError: Java heap space
-- 原因分布 --
Full｜(System.gc()) x 3
Young｜(Concurrent Start) (G1 Humongous Allocation) x 2
Full｜(G1 Compaction Pause) x 2
-- 堆趋势（最后 8 次）--
18M → 83M → 66M → 66M → 66M → 1M → 1M → 1M8. Debug 观察点
- 三份日志各跑一次并对比 ✓✓✓；
- 把 leak 的
-Xmx调成 128m：观察 OOM 只是「推迟」而不是消失 ✗✗✓； - 给 spike 去掉
System.gc()：观察 Full GC 从 5 次降到 2 次 ✓✓（原因分布直接给出答案）； - 加
-XX:+HeapDumpOnOutOfMemoryError重跑 leak：产出一个堆快照，为 《Arthas 与线上问题诊断》 的诊断埋伏笔 ✓✓✓。
9. 常见错误
| # | 错误 | 说明 |
|---|---|---|
| 1 | 看到 Full GC 就加内存 ✗✗ | 先看原因：泄漏加多少都白搭 ✓✓ |
| 2 | 把 System.gc() 引起的 Full 当故障 ✗ | 原因分布里写得清清楚楚 ✓✓ |
| 3 | 只看 GC 次数不看单次停顿 ✗ | 次数 × 停顿才是总账 ✓ |
| 4 | 不开日志靠猜 ✗✗ | 「配置对了」和「观察到对了」是两回事 ✓✓ |
| 5 | 忽略 Humongous ✗ | 小堆下 1MB 数组就是 Humongous ✓（本节 steady 实测） |
| 6 | 没配 HeapDumpOnOutOfMemoryError 就上生产 ✗✗✗ | OOM 现场只出现一次 ✓ |
10. 动手实验
- 跑三组负载 + 解析器，逐字段对照本节报表 ✓✓✓；
- 改
GcLogParser输出「每次 Young GC 的间隔」：判断分配速率 ✓✓； - 制造一次「缓存无界增长」的生产版（换成
ConcurrentHashMap缓存）重复本节流程 ✓✓✓； - 对比
-Xms64m与-Xms128m下 leak 的 GC 次数差异 ✓。
验收方式：拿到任何一份 -Xlog:gc* 日志，10 分钟内说出：有没有 Full、原因是什么、存活量是否健康、下一步该查什么。
扩展任务：给项目 A 配置「OOM 自动导堆 + GC 日志落盘」，并写一份《GC 健康基线》文档（正常频率、单次停顿上限、告警阈值）✓✓
11. 练习题
- 一条 Pause 行里
33M->1M(66M)三个数字的含义？ - 存活量「顶住堆上限」说明什么？
(System.gc())与(G1 Compaction Pause)都算 Full GC，含义差在哪？- 为什么说「泄漏加内存也白搭」？
- 生产必配的两个 GC 相关参数/开关是什么？
参考答案（要点）
- 回收前存活 33M → 回收后存活 1M（堆容量 66M） ✓✓★
- 对象装不下、回收不掉：泄漏或容量见底，OOM 前兆 ✗✗★
- 前者是代码显式调用（生产禁忌）；后者是内存压力下的整理（真实信号）✓✓★
- 因为存活对象不会被任何回收器释放，加内存只是推迟 OOM ✗✓★
-Xms=-Xmx（避免抖动） 与-XX:+HeapDumpOnOutOfMemoryError（保留现场） ✓✓★
12. 掌握标准
- [ ] 会开日志并逐字段读 Pause 行 ★★★；
- [ ] 能说出四类典型形态（健康/泄漏/大对象/显式 GC）★★★；
- [ ] 会用原因分布定位「谁在触发 GC」★★★；
- [ ] 按「目标 → 手段 → 验证」做调优 ★★★；
- [ ] 知道先查代码再调参数 ★★★。
13. 扩展资源
14. 下一步学习
《Arthas 与线上问题诊断》 Arthas 与线上问题诊断 —— 把「看日志」升级为「在线取证」。 监控侧的呼应：服务端监控与瓶颈分析见 T2-016。
进度只保存在本机浏览器，可随时清除