3. Young GC 频繁的典型表现:STW 时间、GC 日志关键指标、应用响应延迟特征
在系统迁移过程中,Young GC 频繁往往不是孤立出现的,它会通过三个维度暴露问题:暂停时间(STW)、GC 日志指标以及应用层响应延迟。理解这三个维度的典型表现,是快速定位“GC 频繁是否由慢查询引发”的前提。
3.1 STW 时间:从微秒级到毫秒级的恶化
Young GC 的 Stop-The-World 时间通常较短(Parallel 收集器约 10–50ms,G1 约 1–10ms)。当迁移导致 Young GC 频繁时,STW 时间会呈现以下特征:
| 指标 | 正常范围 | 频繁时典型值 | 说明 |
|---|---|---|---|
| 单次 Young GC STW | 1–50 ms | 50–200 ms | Eden 区存活对象增多,复制耗时上升 |
| STW 累积时间/分钟 | < 100 ms | 500 ms – 2 s | GC 频率从 1 次/分钟升至 10+ 次/分钟 |
| STW 抖动(P99) | < 30 ms | 200–500 ms | 部分 GC 因晋升或引用扫描出现长暂停 |
诊断要点: 如果单次 Young GC STW 超过 100ms 且频率 > 5 次/分钟,应立刻检查 Survivor 区是否过小、对象是否过早晋升,以及是否存在大量短期对象被长生命周期对象引用。
3.2 GC 日志关键指标:三组数字揭示问题根源
开启 -Xloggc:gc.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps 后,重点关注以下三组指标:
3.2.1 频率与吞吐量
- GC 间隔时间:正常 > 10s,频繁时 < 2s,甚至 < 1s。
- 吞吐量(Throughput):正常 > 99%,频繁时可能降至 95% 以下。
- GC 总耗时占比:频繁时应用线程可用 CPU 减少 5%–15%。
3.2.2 内存分配与晋升
- Allocation Rate(MB/s):迁移后若从 50 MB/s 升至 200+ MB/s,说明有大量临时对象产生。
- Promotion Rate(MB/s):正常 < 10 MB/s,频繁时可能 > 50 MB/s,表示对象过早进入老年代。
- Survivor 区溢出次数:频繁出现
Desired survivor size不足,对象直接晋升。
3.2.3 晋升后老年代变化
- 老年代占用增长率:Young GC 后老年代增量 > 10 MB/次,说明存在大对象或长生命周期对象。
- Full GC 触发前兆:Young GC 频繁 + 老年代占用持续上升,通常会在 30 分钟内触发 Full GC。
日志分析技巧: 使用
grep "GC pause" gc.log | awk '{print $NF}' 提取每次暂停时间,快速计算 P50/P99。若 P99 超过 150ms,基本可以判定 GC 已影响业务。
3.3 应用响应延迟特征:从“偶发毛刺”到“持续高延迟”
Young GC 频繁对应用延迟的影响,通常经历三个阶段:
- 偶发毛刺期:GC 间隔 5–10s,单次 STW 20–50ms,业务 P99 延迟偶尔出现 100ms+ 尖刺。
- 持续抖动期:GC 间隔 1–3s,单次 STW 50–100ms,P99 延迟稳定在 200–500ms,P999 出现 1s+ 超时。
- 雪崩期:GC 间隔 < 1s,STW > 150ms,大量请求超时、线程池阻塞、连接池耗尽,系统进入半不可用状态。
3.4 慢查询关联延迟的识别方法
当 Young GC 频繁与慢查询同时出现时,应用响应延迟会呈现独特的“GC + SQL 双重叠加”模式:
- 延迟曲线形态:在 APM 工具中,每次 Young GC 暂停后,紧接着出现一批慢查询(RT > 1s),形成“暂停 → 积压 → 慢查询”的循环。
- 线程 Dump 特征:大量线程处于
BLOCKED或WAITING状态,堆栈顶部为java.sql.Statement.execute()或DriverManager.getConnection()。 - 数据库端特征:慢查询日志中出现大量“Sending data”或“Creating sort index”状态,且与 GC 日志时间戳高度重合。
⚠️ 常见误判: 不要将 Young GC 频繁直接归因于“内存不足”。在迁移场景中,慢查询导致连接/线程/对象积压才是 Young GC 频繁的第一推动力。应先排查数据库侧是否存在全表扫描、索引失效或大结果集返回。
3.5 关键指标速查表
| 维度 | 指标 | 正常阈值 | 频繁阈值 | 关联慢查询信号 |
|---|---|---|---|---|
| STW | 单次暂停时间 | < 50 ms | > 100 ms | 暂停后立即出现慢查询 |
| GC 日志 | Allocation Rate | < 100 MB/s | > 200 MB/s | 与慢查询执行时段同步飙升 |
| GC 日志 | Promotion Rate | < 10 MB/s | > 50 MB/s | 慢查询返回大结果集时明显升高 |
| 应用延迟 | P99 RT | < 100 ms | > 300 ms | 延迟曲线呈“锯齿+平台”混合形态 |
| 应用延迟 | P999 RT | < 300 ms | > 1 s | 超时请求集中在慢查询对应的 API |
掌握以上三个维度的典型表现后,下一步就可以通过 GC 日志与慢查询日志的时间戳对齐,精准定位是哪些 SQL 导致了 Young GC 频繁。这是第 4 章的核心内容。