在高性能计算领域，我们习惯在代码、算法或基础设施中寻找瓶颈。但有一次最棘手的问题并不在这些地方，而是 Java 虚拟机（JVM）的垃圾回收器与服务器磁盘之间的隐蔽交互。结果是，一个每秒处理数百万请求的服务出现了 15 秒以上的全局暂停（Stop-the-World，STW）。
核心要点
- 这次长暂停看起来像 GC 变慢，根因却是 GC 日志写入被磁盘 I/O 阻塞。
- GC 日志中的
real时间远大于user + sys，是判断线程等待 I/O 或调度的关键信号。 - STW 期间如果 GC 线程阻塞在日志
write()，整个应用也会被连带冻结。 - 临时方案是把 GC 日志写到
tmpfs，并配合日志轮转限制内存占用。 - 现代 JVM 可优先考虑异步 GC 日志，用
-Xlog:async将日志 I/O 移出关键路径。
故障现象：503 突增
当时我正在处理一个大规模 Java 服务。该服务每秒处理数百万用户请求，系统原本为极高吞吐量设计，却持续受到负载均衡器间歇性超时峰值困扰，并向用户返回 503 响应。
我们发现，在负载情况下，一部分 Web 服务器会停滞并停止接受新连接数秒，导致请求堆积并失败。唯一线索是，这种行为与大量磁盘 I/O 时段相关，而这些磁盘 I/O 来自同一主机上的另一个基于磁盘的缓存系统。
这类问题难排查，是因为现象在应用层表现为超时和 503，但根因并不一定在业务代码、网络或 GC 算法本身。
关键证据：GC 日志里的时间差
经过数周调试，我们终于在垃圾回收日志中找到了关键证据。一次典型的新生代垃圾回收停顿应该在几十或几百毫秒。但日志中出现了这样的记录：
[timestamp]: 184512.789: [GC [PSYoungGen: 1058042K->17224K(1069568K)]
3112024K->2018456K(3258112K), 15.3495220 secs]
[Times: user=0.25 sys=0.05, real=15.35 secs]
乍一看，这像是一次长得离谱的 GC 暂停。但真正关键的是 [Times] 部分：
| 字段 | 含义 | 这次日志中的表现 |
|---|---|---|
user |
GC 进程使用的用户态 CPU 时间 | 0.25 秒 |
sys |
GC 进程使用的内核态 CPU 时间 | 0.05 秒 |
real |
从暂停开始到结束的墙钟时间 | 15.35 秒 |
user + sys 只有 0.30 秒，而 real 却有 15.35 秒。这说明 JVM 全局停顿持续了 15 秒以上，但 GC 线程真正占用 CPU 的时间只有 0.3 秒。其余时间里，STW 线程处于等待状态。
这个差异把排查方向从“GC 算法为什么这么慢”转向“GC 线程为什么没有运行”。
根因：GC 日志写入阻塞了 STW
年轻代 GC 是 Stop-the-World 事件。JVM 会暂停所有应用线程，以便安全移动内存。我们发现，这次 GC 操作的最后一步是将日志条目同步写入 GC 日志文件。
问题就出在这个看似无害的 write() 系统调用上。
同一台主机上的磁盘被其他缓存进程激烈争用，内核 I/O 队列已经饱和。GC 线程写日志时进入队列等待物理磁盘。由于此时 JVM 处于 STW 暂停状态，整个应用都被冻结，只能等待那一行日志写入完成。
最终修复也很直接：不再把 GC 日志写入那个竞争激烈的磁盘。
解决方案一：把 GC 日志写到 tmpfs
我们的最初解决方案是文件系统级修复：将 GC 日志路径从物理磁盘上的默认位置改为内存支持的文件系统。
配置方式
将日志输出从类似下面的路径：
-Xloggc:/var/log/my-app/gc.log
改到 tmpfs 路径，例如：
-Xloggc:/dev/shm/my-app-gc.log
为什么有效
写入 tmpfs 不是真正的磁盘 I/O，而是内存到内存的复制，通常会非常快。write() 调用快速返回，STW 暂停也就不会被磁盘队列拖长。
如何控制内存风险
把日志写到内存会带来一个合理担忧：日志是否会耗尽内存？我们通过 JVM 内置日志轮转控制总大小：
-XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=6 -XX:GCLogFileSize=20M
这会将 GC 日志总内存使用量限制在约 120MB，降低进程失控风险。
这个方案的缺点
- 日志是临时的：
/dev/shm中的日志会在系统重启或容器重启后丢失。 - 归档链路需要补齐：日志不再自动进入原来的持久化日志系统，如仍需保留，需要配置单独的日志传输代理或边车。
解决方案二：使用异步 GC 日志
多年里，tmpfs 是一种常见权宜方案。后来，亚马逊 Corretto 团队开发并贡献了正式 JVM 功能，用于支持异步 GC 日志记录，该功能已成为 OpenJDK 17 中的标准功能。
配置方式
在 -Xlog 标志中使用 async：
-Xlog:async -XX:AsyncLogBufferSize=100M
为什么有效
STW GC 线程不再直接执行 I/O。它将日志消息写入内存缓冲区，然后立即恢复应用线程。随后，由独立的低优先级后台线程负责将缓冲区内容刷新到磁盘。
优点
- 这是 JVM 层面的正式解决方案。
- 不需要操作系统级技巧。
- 日志仍可写入标准文件路径，便于现有日志采集链路处理。
需要注意
- 极端突发场景下，异步缓冲区可能被填满，进而导致主线程停滞。
- 较旧 Java 部署无法使用该能力。
为什么容器时代仍要重视这个问题
在容器时代，这个问题可能以新的形式出现。现代实践通常建议应用直接把日志输出到 stdout 或 stderr。但 stdout 并不是不会阻塞的虚无空间，它是一个管道，必须有其他进程从管道另一端读取。
这个读取方通常是容器运行时，例如 containerd，也可能是 Fluentd、Vector、Logstash 等日志代理。如果日志代理变慢、配置错误，或它自己的网络和磁盘 I/O 阻塞，读取缓冲区可能被填满。背压会沿管道向上传递，导致应用下一次对 stdout 执行 write() 时阻塞。
如果 JVM 在 STW 暂停期间尝试把 GC 日志写入 stdout，而日志代理又处理不过来，同样可能把日志延迟放大成应用级停顿。
排障判断路径
遇到类似 JVM 长暂停，可以按下面顺序判断：
- 查看 GC 日志中的
real、user、sys。 - 如果
real远大于user + sys，不要只盯着 GC 算法本身。 - 同步查看磁盘 I/O、日志写入路径、容器日志管道和宿主机负载。
- 判断 GC 日志是否写在高争用磁盘、网络文件系统或阻塞日志管道上。
- 优先尝试异步日志；无法使用时，再考虑
tmpfs和日志轮转。
核心经验
real与user + sys的差异是重要信号：高real、低user + sys通常不是 CPU 算法问题，而是 I/O、网络或调度等待。- 关键路径上不要做阻塞 I/O：包括“简单的”日志记录，也可能拖住整个应用。
- 现代 JVM 优先使用异步日志：
-Xlog:async是将 GC 日志 I/O 移出关键路径的清晰方法。 - 容器里的
stdout也可能阻塞：日志代理和容器运行时的背压会影响应用写日志。
FAQ
GC 日志里 real 很高就一定是磁盘问题吗？
不一定。它说明墙钟时间很长，但 CPU 时间不高，可能是磁盘 I/O、网络 I/O 或操作系统调度等待。本文案例的根因是 GC 日志写入等待磁盘。
把 GC 日志写到 tmpfs 是否推荐长期使用？
它能快速规避物理磁盘 I/O 阻塞，但日志易丢失，需要轮转和采集补偿。现代 JVM 更推荐优先使用异步 GC 日志。
为什么普通日志也会导致应用停顿？
如果日志写入发生在关键线程或 STW 期间，且日志目标发生阻塞，线程就会等待 I/O。关键线程等待时，应用整体也可能被拖住。
总结
这次故障的本质不是 GC 算法慢，而是 GC 日志写入被磁盘 I/O 阻塞，并且阻塞发生在 STW 期间。排查 JVM 长暂停时，不要只看暂停总时长，要对比 real 与 user + sys。当墙钟时间远大于 CPU 时间时，应把 I/O、日志路径和调度等待纳入排查。解决方向是把阻塞 I/O 从关键路径移走，现代 JVM 可优先使用异步 GC 日志。
原文链接：https://dzone.com/articles/the-jvm-pause-that-wasnt-a-war-story
