一次 JVM 停顿不只有 GC 执行时间。本文从 Safepoint 的到达、清理和执行阶段入手，结合统一日志、JFR、线程状态与系统指标，排查 GC 日志很短但服务仍出现秒级卡顿的问题。

问题背景

线上接口偶尔卡住两秒，监控显示同一时刻请求吞吐下降、线程池队列上涨，但 GC 日志中的暂停只有二十多毫秒。看到这种现象，很多人的第一反应是：既然 GC 很短，问题应该与 JVM 无关。

这个判断忽略了一个重要阶段：JVM 开始执行某些全局操作前，需要让相关 Java 线程到达安全点，也就是 Safepoint。GC 日志常让人关注垃圾收集本身花了多久，却没有充分注意 JVM 为了进入安全点等待了多久。

因此，一次可感知的停顿可以粗略理解为：

总停顿时间 = 到达安全点耗时 + 安全点清理耗时 + 安全点内操作耗时

如果 GC 操作只用了 20ms，但某个线程迟迟没有到达安全点，整个进程仍可能出现秒级抖动。

Safepoint 到底解决什么问题

垃圾收集、部分反优化、线程转储、类重定义等操作，需要在一个线程状态可控的时刻观察或修改 JVM 数据结构。HotSpot 会发起 Safepoint 请求，各线程运行到安全点轮询位置后暂停，等全局操作完成再继续执行。

这里有三个容易混淆的概念：

• Reaching safepoint：JVM 发出请求后，等待线程进入安全状态的时间。
• Cleanup：进入安全点后的清理工作，通常较短。
• At safepoint：所有线程就绪后，真正执行 GC 或其他 VM 操作的时间。

以 JDK 17 的统一日志为例，下面是一条经过简化的示意日志：

Safepoint "G1CollectForAllocation",
Reaching safepoint: 1850 ms,
Cleanup: 0.1 ms,
At safepoint: 18 ms,
Total: 1868 ms

如果只看 GC 阶段，很容易得到“暂停只有 18ms”的结论；但应用线程实际接近两秒没有正常推进。接口超时、任务积压以及连接池等待，看到的都是后者。

先把 GC 和 Safepoint 日志放在同一条时间线上

在 JDK 11、17、21 等使用统一日志的版本中，可以在启动参数中同时记录 GC 与 Safepoint：

-Xlog:gc*,safepoint=info:file=/var/log/app/jvm.log:time,uptime,level,tags:filecount=5,filesize=20M

排查时不要只搜索 Pause Young，还要按时间检查 Safepoint 的 Reaching safepoint、At safepoint 和 Total。分析方式可以归纳为：

JDK 8 使用的是较早的诊断参数，输出格式和可用选项与后续版本不同，不建议直接照搬 JDK 17 的参数。维护多套运行时环境时，应当按照实际 JDK 的 java -Xlog:help 或对应版本文档确认。

在应用内增加一个低成本的调度延迟探针

如果服务缺少进程级停顿指标，可以放入一个简单探针，观察同一 JVM 中定时线程的实际执行间隔。下面的程序可以独立运行，也可以将核心逻辑接入服务的指标系统：

import java.time.Instant;
import java.util.concurrent.Executors;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicLong;

public final class JvmSchedulingLagProbe {
    private static final long PERIOD_MS = 100;
    private static final long WARN_LAG_MS = 200;

    public static void main(String[] args) throws InterruptedException {
        ScheduledExecutorService scheduler =
                Executors.newSingleThreadScheduledExecutor(r -> {
                    Thread thread = new Thread(r, "jvm-lag-probe");
                    thread.setDaemon(true);
                    return thread;
                });

        AtomicLong lastRun = new AtomicLong(System.nanoTime());

        scheduler.scheduleAtFixedRate(() -> {
            long now = System.nanoTime();
            long previous = lastRun.getAndSet(now);
            long intervalMs = TimeUnit.NANOSECONDS.toMillis(now - previous);
            long lagMs = intervalMs - PERIOD_MS;

            if (lagMs >= WARN_LAG_MS) {
                System.out.printf(
                        "%s scheduling lag=%dms, actual interval=%dms%n",
                        Instant.now(), lagMs, intervalMs);
            }
        }, PERIOD_MS, PERIOD_MS, TimeUnit.MILLISECONDS);

        Runtime.getRuntime().addShutdownHook(new Thread(scheduler::shutdown));
        Thread.currentThread().join();
    }
}

这里必须强调：调度延迟不等于 Safepoint。它还可能来自容器 CPU 限流、宿主机抢占、系统负载过高，甚至探针线程本身得不到调度。它的价值是提供统一时间点：发现延迟后，再去关联 Safepoint 日志、GC 日志和操作系统指标。生产环境中最好上报直方图或计数器，而不是持续打印标准输出。

Reaching safepoint 很高时如何继续定位

1. 先排除 CPU 调度问题

线程只有真正获得 CPU 时间，才有机会执行到安全点轮询位置。容器 CPU 配额过低时，即使机器总体 CPU 使用率不高，进程也可能被周期性限流。

可以同步观察：

pidstat -p <pid> 1
pidstat -t -p <pid> 1
top -H -p <pid>
vmstat 1

运行在容器中时，还应检查 cgroup 的 cpu.stat。不同 cgroup 版本字段略有差异，重点关注限流次数和累计限流时间。若 Safepoint 延迟与 CPU throttling 同时出现，优先调整 CPU 配额、线程数量和并发模型，而不是先扩大堆内存。

2. 使用持续 JFR，而不是事后只抓一次线程栈

问题发生后执行一次 jcmd Thread.print，经常只能看到恢复后的现场。更实用的方式是提前开启一段时间的 JFR：

jcmd <pid> JFR.start name=stall settings=profile \
  duration=120s filename=/tmp/stall.jfr

在 JDK Mission Control 中，将 Safepoint、GC Pause、线程运行、CPU 负载和锁等待放到同一时间轴检查。不同 JDK 版本记录的事件名称和默认阈值可能不同，因此应以实际录制结果为准。

如果某个计算线程长时间占用 CPU，应继续检查对应栈帧、热点方法和编译情况；如果大量线程都运行缓慢，更像是 CPU 饱和或容器限流，而不是某一个业务方法单独阻塞。

3. 正确理解 native 状态

线程栈出现 native 方法，不代表它一定阻碍了 Safepoint。普通线程进入本地代码后，JVM 往往可以将其视为处于安全状态；真正需要关注的是 JNI 临界区、频繁的 Java/native 边界切换，以及本地库是否长时间持有 JVM 相关资源。

因此，“看到 native 栈帧就归因于第三方库”通常证据不足，还需要结合 JFR、CPU 采样和 Safepoint 时间验证。

常见误区

只根据 GC 次数判断停顿

GC 次数多不一定造成长停顿，次数少也不代表没有 Safepoint 问题。应当同时看分配速率、GC 阶段耗时和 Safepoint 总时间。

直接扩大堆内存

扩大堆可能降低 GC 频率，也可能让单次回收处理更多数据。对于主要耗时位于 Reaching safepoint 的问题，它通常不是针对性解决方案。

把所有停顿都归因于 JVM

如果应用探针出现延迟，但 Safepoint 日志没有对应记录，应立即转向线程池排队、锁竞争、事件循环阻塞、磁盘抖动和宿主机调度，而不是继续调整 GC 参数。

为了排查而永久开启过量日志

safepoint=info 通常适合持续观察，但更细粒度的 JVM 调试日志可能快速增长。应配置滚动策略，并先在预发环境确认日志量和开销。

实践建议

建立性能排查基线时，至少保留四类时间线：请求延迟、GC 与 Safepoint、进程 CPU、容器限流。告警也不要只盯着堆使用率，可以增加 Safepoint 总停顿时间和应用调度延迟。

排查顺序建议固定下来：先确认用户感知的卡顿时间，再对齐 Safepoint；然后区分“到达慢”还是“执行慢”；最后用 JFR 和系统指标寻找线程、CPU 或具体 VM 操作。这样可以避免在没有证据时反复更换收集器、扩大堆或修改业务线程池。

总结

GC 日志中的暂停时间短，并不能证明 JVM 没有经历长停顿。Safepoint 的关键不只是停下来做了什么，还包括所有相关线程花了多久才停下来。

面对“GC 只有几十毫秒，接口却卡了几秒”的现象，最有效的方法不是先调参数，而是把 Reaching safepoint、At safepoint、JFR 事件和操作系统调度指标对齐。只有先判断时间究竟消耗在哪个阶段，后续优化才不会变成猜测。