JVM GC日志深度解读：从G1 Mixed GC到ZGC低延迟实践

一、GC日志的核心价值：从“黑盒”到“透明”

GC日志是JVM内存管理的“行车记录仪”，通过解析日志可定位：

​停顿时间瓶颈​：Young GC/Mixed GC/ZGC暂停对应用的影响；​内存回收效率​：各区域（Eden/Survivor/Old）的回收频率与收益；​对象生命周期​：对象从创建到回收的全链路轨迹。

本文以G1收集器​（吞吐量优先）和ZGC收集器​（低延迟优先）为例，结合真实日志与工具，拆解GC日志的关键指标与优化逻辑。

二、G1收集器：Young GC与Mixed GC的日志解析

G1（Garbage-First）的核心是Region分区管理，将堆划分为多个大小相等的Region（默认2MB~32MB），分为Eden、Survivor、Old、Humongous（大对象）四类。

1. 真实G1 GC日志片段（-XX:+PrintGCDetails -XX:+PrintGCDateStamps）

2024-05-20T14:30:00.123+0800: [GC pause (G1 Evacuation Pause) (young), 0.0123456 secs]

[Parallel Time: 10.1 ms, GC Workers: 4]

[GC Worker Start (ms): 123456.789, 123456.790, 123456.791, 123456.792]

[Ext Root Scanning (ms): 1.2, 1.1, 1.3, 1.0] // 扫描根对象

[Update RS (ms): 2.1, 2.0, 2.2, 1.9] // 更新Remembered Set

[Scan RS (ms): 3.0, 2.9, 3.1, 2.8] // 扫描Remembered Set

[Code Root Scanning (ms): 0.5, 0.4, 0.5, 0.4] // 扫描代码根

[Object Copy (ms): 3.3, 3.2, 3.4, 3.1] // 转移存活对象

[Termination (ms): 0.0, 0.0, 0.0, 0.0] // 终止阶段

[Times: user=0.040 sys=0.010, real=0.012 secs] // 用户/系统/实际时间

[Eden: 1024.0M(1024.0M)->0.0B(1024.0M) // Eden区：回收前1024MB→回收后0MB（仍保留1024MB容量）

Survivor: 256.0M(256.0M)->256.0M(256.0M) // Survivor区：无变化（对象未晋升）

Old: 512.0M(2048.0M)->512.0M(2048.0M) // Old区：无回收

[Humongous: 0.0B(0.0B)->0.0B(0.0B)] // Humongous对象：无回收

[Metaspace: 3225K->3225K(1056768K)] // 元空间：无变化

[GC Cause: Allocation Failure] // GC触发原因：Eden区分配失败

[Pause Time: 12ms] // 总暂停时间：12ms

2024-05-20T14:30:10.567+0800: [GC pause (G1 Mixed GC), 0.0234567 secs]

[Parallel Time: 20.5 ms, GC Workers: 4]

[GC Worker Start (ms): 123467.890, ...]

[Ext Root Scanning (ms): 1.5, ...]

[Update RS (ms): 2.5, ...]

[Scan RS (ms): 3.5, ...]

[Code Root Scanning (ms): 0.6, ...]

[Object Copy (ms): 12.4, ...] // 转移对象时间增加（需回收Old区）

[Times: user=0.080 sys=0.020, real=0.023 secs]

[Eden: 1024.0M(1024.0M)->0.0B(1024.0M)

Survivor: 256.0M(256.0M)->256.0M(256.0M)

Old: 512.0M(2048.0M)->450.0M(2048.0M) // Old区：回收62MB（约12%）

Humongous: 0.0B(0.0B)->0.0B(0.0B)

[GC Cause: G1 Mixed GC Trigger] // 触发原因：Old区占用超过阈值

[Pause Time: 23ms] // 总暂停时间：23ms（比Young GC长）

2. 关键指标解析

指标含义优化关注点​GC Type​young（Young GC）/mixed（Mixed GC）Young GC频繁→Eden区过小；Mixed GC频繁→Old区增长过快​Parallel Time​并行阶段耗时（多线程执行）关注Object Copy（转移存活对象）占比→优化对象存活时间​Eden/Survivor/Old变化​各区域的回收量与剩余容量Old区回收比例低→调整-XX:G1MixedGCLiveThresholdPercent（默认85%）​Pause Time​总暂停时间目标：Young GC<10ms，Mixed GC<50ms（根据应用延迟要求）​GC Cause​触发原因（Allocation Failure/Mixed GC Trigger）Allocation Failure→增加Eden区；Mixed GC→优化Old区对象生命周期

3. G1优化策略：调整Mixed GC频率

若Mixed GC频繁（如每10分钟一次），可：

​增大堆大小​：-Xmx4g→减少Old区增长速度；​调整Old区回收阈值​：-XX:G1MixedGCLiveThresholdPercent=75→降低Mixed GC触发门槛（Old区占用75%即触发）；​减少Humongous对象​：-XX:G1HeapRegionSize=32m→将大对象拆分为多个Region。

三、ZGC收集器：“无停顿”的日志解读

ZGC（Z Garbage Collector）的核心是染色指针+读屏障，将GC操作（标记、转移）与应用程序并发执行，实现亚毫秒级暂停​（<1ms）。

1. 真实ZGC GC日志片段（-XX:+PrintGCDateStamps -XX:+PrintZGCStats）

2024-05-20T14:40:00.789+0800: [GC pause (ZGC) (concurrent mark), 0.0012345 secs]

[ZGC Phase: Concurrent Mark]

[Mark Start: 123489.012]

[Mark End: 123489.135] // 标记阶段耗时：123ms（并发执行）

[Root Scanning: 10ms] // 根扫描：10ms

[Marking: 113ms] // 标记对象：113ms

[ZGC Phase: Concurrent Relocation]

[Relocation Start: 123489.136]

[Relocation End: 123489.259] // 转移阶段耗时：123ms（并发执行）

[Relocation Set: 512MB] // 转移512MB对象

[Pause Time: 1.2ms] // 总暂停时间：1.2ms（仅协调阶段）

[GC Cause: Allocation Spike] // 触发原因：分配尖峰

[ZAllocationSpikeTolerance: 1.5] // 分配尖峰容忍度：1.5倍

2024-05-20T14:40:10.123+0800: [GC pause (ZGC) (concurrent transfer), 0.0009876 secs]

[ZGC Phase: Concurrent Transfer]

[Transfer Start: 123499.234]

[Transfer End: 123499.333] // 转移阶段耗时：99ms（并发）

[Pause Time: 1.0ms] // 总暂停时间：<1ms

[GC Cause: Normal] // 正常周期触发

2. 关键指标解析

指标含义优化关注点​GC Phase​Concurrent Mark（并发标记）/Concurrent Relocation（并发转移）关注并发阶段的耗时→优化CPU资源​Pause Time​总暂停时间（通常<1ms）目标：<1ms（满足低延迟要求）​ZAllocationSpikeTolerance​分配尖峰容忍度（默认1.0）高并发分配场景→调大至1.5~2.0​Relocation Set​转移的对象大小转移量大→增加堆大小或优化对象存活时间

3. ZGC优化策略：降低暂停时间

若暂停时间超过1ms，可：

​增加并发线程数​：-XX:ZCollectionThreads=8→加快并发标记/转移；​优化对象存活时间​：减少长生命周期对象→降低转移频率；​调整分配尖峰容忍度​：-XX:ZAllocationSpikeTolerance=2.0→应对突发分配。

四、工具实战：GCViewer定位瓶颈

GCViewer是开源的GC日志分析工具，可直观展示GC频率、暂停时间、内存变化。

1. 导入日志

打开GCViewer，导入G1或ZGC日志文件（支持gc.log或gc.txt）。

2. 分析G1日志

​YGC/Mixed GC频率​：查看“GC Events”标签，YGC每5秒一次→正常；Mixed GC每10分钟一次→需优化Old区；​暂停时间分布​：“Pause Times”标签，Young GC平均12ms→达标；Mixed GC平均23ms→需调整G1MixedGCLiveThresholdPercent；​内存回收效率​：“Memory”标签，Old区回收比例每次10%~15%→正常。

3. 分析ZGC日志

​暂停时间趋势​：“Pause Times”标签，平均0.8ms→达标；偶尔峰值1.5ms→检查分配尖峰；​并发阶段耗时​：“Phases”标签，并发标记123ms→正常（占总运行时间0.1%）；​转移量​：“Relocations”标签，每次转移500MB~1GB→正常（堆大小4GB）。

五、总结：G1 vs ZGC的日志与优化选择

维度G1收集器ZGC收集器​目标场景​吞吐量优先（大数据、批处理）低延迟优先（电商、实时系统）​暂停时间​Young GC<10ms，Mixed GC<50ms常态<1ms，峰值<2ms​日志关注点​Mixed GC的Old区回收比例并发阶段耗时与暂停时间峰值​优化关键词​调整Old区阈值、减少Humongous对象增加并发线程、优化对象存活时间

互动思考

G1的Mixed GC回收Old区时，如何判断哪些对象需要回收？（提示：基于对象年龄与存活率）ZGC的“并发转移”会不会导致对象引用错误？（提示：染色指针与读屏障的作用）若G1的Young GC频繁触发Full GC，可能的原因是什么？（提示：Survivor区不足→对象直接晋升Old）

​延伸阅读​：

《深入理解Java虚拟机》第6章“垃圾收集器与内存分配策略”；G1官方文档：https://docs.oracle.com/javase/11/gctuning/g1_gc.htm；ZGC官方文档：https://docs.oracle.com/javase/15/gctuning/z-gc.htm；GCViewer项目：https://github.com/chewiebug/GCViewer。

​标签​：#JVM GC #G1 #ZGC #GC日志 #性能优化

​推荐阅读​：《Java性能权威指南》、《JVM G1GC调优实战》、《ZGC设计与实现》