openjdk 9+ 必须用 -xlog,旧参数如 -xx:+printgcdetails 已废弃且无效;-xlog:gc+pause=debug 可输出精确停顿时间,需搭配 :time 后缀统一时间戳,并补充 -xx:+printsafepointstatistics 才能看清真实stw耗时。

OpenJDK 9+ 必须用 -Xlog,旧参数无效
OpenJDK 9 起彻底废弃了 -XX:+PrintGCDetails 等旧日志开关,硬加也不会输出停顿时间。必须改用统一的 -Xlog 语法,否则日志里根本看不到 Pause 字样或毫秒数。
常见错误现象:加了 -XX:+PrintGCApplicationStoppedTime 却没输出,或者只看到 GC 类型和内存变化,但缺具体 STW 时长——基本就是还在用旧参数混搭新 JDK。
-
-Xlog:gc+pause=debug是记录停顿时间最直接的方式,会打出类似[gc,pause] GC(12) Pause Young (Normal) 45.678ms的行 - 若同时想看堆内存变化,叠加
gc+heap=debug:例如-Xlog:gc+pause=debug,gc+heap=debug - 务必加
:time后缀(如file=/path/gc.log:time),否则时间戳格式不统一,排查毛刺难对齐业务日志
-XX:+PrintGCApplicationStoppedTime 在 JDK 8 里能用,但有盲区
这个参数在 OpenJDK 8 中确实会打印类似 Total time for which application threads were stopped: 0.0456780 seconds 的汇总值,但它只统计“所有 GC 导致的停顿总和”,不区分 Young GC、Mixed GC 或 Full GC,也不标出每次停顿的起止时间点。
容易踩的坑:
- 它不输出单次停顿毫秒数,无法定位是哪一次 GC 拉长了 P99 延迟
- 如果应用里有非 GC 的 STW(比如 Safepoint 等待、JIT 编译阻塞),它也会计入,造成误判
- 必须配合
-XX:+UseGCLogFileRotation等滚动参数,否则大流量下日志刷屏后关键段被覆盖
停顿时间不准?检查是否漏了 Safepoint 统计
GC 日志里的 “Pause” 时间只是 GC 自身动作耗时,但真实 STW 往往更长——因为线程得先跑到 Safepoint 才能被暂停。这部分等待时间默认不记入 GC 日志,却直接影响接口延迟。
必须补上这两个参数才能看清全貌:
-
-XX:+PrintSafepointStatistics:开启 Safepoint 统计 -
-XX:PrintSafepointStatisticsCount=1:每触发一次 Safepoint 就打一行统计,含“到达 Safepoint 耗时”和“GC 实际执行耗时”两列
你会发现:某次日志写 Pause Young 12.3ms,但对应 Safepoint 行显示 vmop_wait_time=8.7ms —— 真实卡顿是 21ms,不是 12.3ms。
动态开启 GC 停顿日志,不用重启 JVM
线上服务不能随便重启,但又急需查某段时间的停顿毛刺?OpenJDK 7u4+ 支持运行时启用 GC 日志,底层走的是 DiagnosticCommandMBean。
用 jcmd 最快:
jcmd <pid> VM.log output=stdout what=gc+pause level=debug</pid>
这条命令会立刻把后续所有 GC 停顿日志打到标准输出(或重定向到文件),无需改启动参数、不中断服务。
注意点:
- 它只对后续 GC 生效,不会补录历史停顿
- 若 JVM 启动时已用
-Xlog写到文件,动态开启会多路输出,建议指定不同output=file=xxx避免混杂 - 权限需与 JVM 进程同用户,容器环境常因挂载限制失败,优先试 stdout
真正难的不是记下停顿时间,而是分清这几十毫秒里有多少是 GC 自己干的,多少是线程排队等 Safepoint 消耗的——后者常被忽略,却是压测时延迟突增的元凶。











