ZGC 日志需关注毫秒级阶段时间戳,重点分析 Concurrent Mark/Relocate/Remap 各轮耗时及 Remap 进度卡顿,结合 ZStatistics 中 Pages remapped 突增与线程扫描异常定位隐性延迟根源。

直接看 ZGC 日志里的阶段跳动,比猜更有用。ZGC 的日志不报“并发标记耗时 XXms”这种汇总值,而是按毫秒级精度记录每个子阶段的起止时间、是否并发、是否阻塞,关键就藏在这些时间戳的微小偏移里。
关注日志中带 “Concurrent” 前缀的阶段时间戳
ZGC 日志默认开启详细阶段打印(需加 -Xlog:gc*,gc+phases=debug)。你会看到类似:
- Concurrent Mark Start —— 并发标记开始,时间戳记为 T0
- Concurrent Mark End —— 标记结束,时间戳为 T1,T1 − T0 就是实际并发标记耗时
- Concurrent Relocate Start / End —— 转移阶段,注意它常被拆成多轮(Relocate-0, Relocate-1…),每轮都有独立时间戳
- Pause Mark Start / Pause Relocate Start —— 这些才是 STW 阶段,时间极短(通常
识别“跳动”是否真实异常,而非正常波动
毫秒级跳动本身不等于问题,要结合三类上下文交叉判断:
- 堆活跃对象规模:如果 Concurrent Mark End − Concurrent Mark Start 从 12ms 涨到 45ms,而同期堆中存活对象数翻倍(可通过 -Xlog:gc+heap=debug 查看),属合理增长
- 转移压力信号:Relocate 阶段时间跳变 + 日志中出现 Allocation Stall 或 Relocation Stall,说明应用分配速度压过了 ZGC 转移能力,正在触发自适应扩容或触发更频繁的 GC 循环
- 系统级干扰:同一时刻宿主机发生 direct reclaim(可查 /proc/vmstat 中 pgpgin/pgpgout 突增)、CPU 抢占严重(perf sched latency 显示调度延迟 > 1ms),ZGC 并发线程会被拖慢,表现为各阶段时间整体右移,但阶段间差值稳定
重点盯住重映射(Remap)阶段的隐性延迟
Remap 阶段本身不 STW,但它是唯一需要遍历所有线程栈并批量更新引用的阶段。ZGC 会把它拆成多个小批次并发执行。日志中若出现:
- Concurrent Remap (n of m) —— n/m 表示进度,若某次 n 卡住数毫秒再继续,大概率是某个线程栈过大或存在深度嵌套的本地变量引用链
- 连续多次 Remap 阶段耗时 > 3ms,且 -XX:+ZStatistics 显示 “Remap: Threads scanned” 数值远高于平均线程数,说明部分线程栈被反复扫描(常见于频繁创建匿名内部类或 Lambda 的场景)
用 ZStatistics 辅助定位跳动根源
仅靠 GC 日志不够,必须配合运行时统计:
- 加参数 -XX:+ZStatistics -Xlog:gc+stats=info,ZGC 会输出每轮 GC 后的精细指标
- 重点关注:Mark: Marked(标记对象数)、Relocate: Relocated(转移对象数)、Remap: Pages remapped(页重映射量)—— 若某轮 Remap Pages 突增 3 倍但 Relocated 对象只增 20%,说明大量对象被重复重映射,指向引用更新逻辑异常
- 对比 Pause: Total(STW 总耗时)和 Concurrent: Total(并发总耗时)的比值,健康状态下后者应是前者的 50–100 倍;若比值骤降至 10 倍以下,说明并发阶段被严重阻塞

















