GC日志中real时间包含SafePoint等待（TTSP）和GC实际工作时间；差值大说明TTSP高，需结合PrintSafepointStatistics或-Xlog:safepoint定位线程卡点原因。
GC 日志里本身不直接显示 SafePoint 耗时，但会间接暴露它——关键看“停顿时间”是否远超 GC 实际工作时间。真正反映 SafePoint 延迟的，是线程到达安全点所花的时间（TTSP），这部分常被误认为是 GC 本身慢了。
看 PrintGCApplicationStoppedTime 输出的两段耗时
启用 -XX:+PrintGCApplicationStoppedTime 后，每次 STW 会打印类似：
注意两个数值：
- 前一个（0.0585911s）：整个应用线程被停止的总时长，即从第一个线程挂起到最后一个线程恢复的时间
- 后一个（0.0001795s）：真正用于“停止线程”的开销，极短，说明线程响应很快
两者差值（≈0.0584s）基本就是所有线程等待进入 SafePoint 的时间总和，也就是 TTSP 主导的延迟。如果这个差值大（比如几十毫秒甚至秒级），说明有线程迟迟无法到达 SafePoint。
结合 PrintSafepointStatistics 定位原因
仅看 GC 日志不够，必须搭配 SafePoint 统计日志才能归因。加参数：
-XX:+PrintSafepointStatistics -XX:PrintSafepointStatisticsCount=1
每触发一次 SafePoint 就输出一行，重点关注：
-
safepoint reason：如
RevokeBias（偏向锁撤销）、ParallelGCFailedAllocation（GC 触发）、ThreadDump等 - time：从触发到全部线程就绪的总耗时（含 block + vmop）
- vmop：JVM 实际执行的操作（如 GC 标记），它只在所有线程就绪后才开始
- threads 和 nonvoluntary：等待线程数、非自愿阻塞线程数，高值提示有线程卡住
例如看到大量 reason=RevokeBias 且 time > 10ms，大概率是偏向锁批量撤销拖慢了 GC 启动。
JDK 9+ 用 -Xlog:safepoint* 更清晰
推荐统一日志框架，格式更规范，支持过滤和输出控制：
-
-Xlog:safepoint*:uptime,tags：带时间戳和标签，方便对齐 GC 日志 -
-Xlog:safepoint=info:file=safepoint.log：单独写入文件，避免混杂 -
-Xlog:safepoint*=warning：只记录耗时超阈值（默认 10ms）的安全点事件
输出中 time_since_last_safepoint 和 time_to_reach_safepoint 可直接定位长延迟来源。
别把 GC 日志里的 pause 当成 SafePoint 耗时
GC 日志中常见的 [Times: user=0.02, sys=0.00, real=0.023s] 中的 real 是整个 GC 操作的 STW 时间，包含两部分：
- 线程到达 SafePoint 的等待时间（TTSP，SafePoint 开销）
- JVM 执行 GC 工作的实际时间（如标记、清理）
也就是说：real ≈ TTSP + GC work。如果 GC work 很短（如 Young GC 本应 2–5ms），但 real 达到 50ms，那多出来的 45ms 几乎全是 SafePoint 延迟。
