核心是识别real时间,即STW真实停顿;user+sys反映CPU开销,real远大于二者之和说明存在资源竞争或等待。需结合GC类型判断:Young GC应<50ms,Full GC应避免,G1 Mixed GC受MaxGCPauseMillis约束,ZGC/Shenandoah停顿极短。

分析 JVM 垃圾回收日志中的停顿时间,核心是识别日志中明确标出的 GC pause(或 GC pause time、user/sys/real time)字段,并结合 GC 类型、阶段和线程行为判断真实影响。
看懂关键时间字段:real、user、sys 的含义
JVM GC 日志(尤其使用 -XX:+PrintGCDetails -XX:+PrintGCTimeStamps 或更现代的 -Xlog:gc*)中,每次 GC 结束时通常会输出类似:
这里的 0.0421234 secs 就是本次 GC 的总停顿时间(即 real time / wall-clock time),代表应用线程被完全暂停的时长——这是最需关注的指标。
在 Linux 系统下用 time 命令运行 Java 进程时看到的 real 时间也对应此值;user 是 GC 线程自身在用户态消耗的 CPU 时间,sys 是内核态时间。三者关系通常是:real ≥ user + sys,差值越大,说明停顿中存在等待(如 I/O、锁竞争、OS 调度延迟)。
立即学习“Java免费学习笔记(深入)”;
区分不同 GC 类型对应的停顿特征
-
Young GC(Minor GC):一般停顿在几毫秒到几十毫秒,日志中常见
GC (Allocation Failure)或GC (System.gc())。若频繁发生且单次 >50ms,可能说明 Eden 太小、对象晋升过快或存在大对象直接分配。 -
Full GC(旧版 CMS/Serial/Parallel):停顿常达数百毫秒甚至秒级,日志中含
Full GC字样,伴随老年代整体回收和元空间/永久代扫描。应尽量避免。 -
G1 GC 的 Mixed GC:停顿可控,日志中标记为
GC pause (G1 Evacuation Pause) (mixed),时间取决于-XX:MaxGCPauseMillis设置与实际回收收益。注意看是否触发了to-space exhausted或evacuation failure,这类失败会导致退化为 Full GC,停顿骤增。 -
ZGC / Shenandoah GC:绝大多数阶段并发执行,日志中
Pause行仅表示极短的“染色指针更新”或“引用处理”停顿(通常 Concurrent cycle 是否被阻塞或超时。
用工具辅助定位长停顿根源
- 用 GCViewer 加载 GC 日志,它会自动提取每次 GC 的 pause 时间、类型、堆变化,并绘制成趋势图,快速发现停顿毛刺或持续上升趋势。
- 启用详细时间分解:对 G1,加
-XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xlog:gc+phases=debug(JDK 10+)可看到update rem set、scan rem set、evacuate各阶段耗时,定位瓶颈阶段。 - 结合 JFR(Java Flight Recorder):开启
-XX:+FlightRecorder -XX:StartFlightRecording=duration=60s,filename=recording.jfr,录制期间发生的 GC 事件包含精确纳秒级停顿、线程状态、安全点等待时间(safepoint sync time),能区分是 GC 本身慢,还是进入安全点耗时过长(如长循环未主动检查、JNI 阻塞等)。
警惕“隐形停顿”:安全点与安全区域开销
不是所有停顿都写在 GC 日志里。JVM 必须让所有线程到达“安全点”(safepoint)才能开始 GC。如果某线程长时间无法进入安全点(比如在执行 JNI、长循环未含 safepoint 检查、或处于自旋锁中),会导致整个 JVM 等待,这部分时间会计入 GC 的 real time,但不会反映在 GC 阶段细分中。
启用 -XX:+PrintSafepointStatistics -XX:PrintSafepointStatisticsCount=1 可打印每次安全点操作的耗时和阻塞原因。重点关注 vmop_time(VM 操作本身耗时)和 sync_time(线程同步到安全点的等待时间)。若 sync_time 显著偏高,说明有线程卡住,需结合线程 dump 分析。


















