偶发卡顿：运维里最难修的一类故障

故障分两类。一类是持续性的，比如服务器 OOM 挂掉、磁盘写满、MySQL 拒绝连接——这类问题现场还在，你登录上去看日志、看进程、看监控，大概率能定位。另一类是偶发性的，比如"每周三凌晨网站会有那么几秒打不开"、"一天里有那么几次请求要等三秒才返回"，等你收到告警登录上去看，一切正常，load 0.2，内存充足，日志里干干净净，什么都没有。

第二类故障是个人站长最头疼的，因为它的时间窗口窄、随机性强、而且往往在你观察的时候恰好不出现。用 top、iostat 这类"看瞬时状态"的工具去抓它，命中率极低——你截到的那一帧，大概率正好是它平静的时候。

这篇文章讲的是一套专门对付偶发卡顿的方法：用 strace 把进程的系统调用轨迹录下来，然后在事后从录下来的轨迹里找出"哪一次调用异常地慢"。这个思路的关键转变是把"实时观察"换成"留证复盘"——你不需要当场抓到它，你只需要让证据留下来。全文的方法和脚本都在一台 Debian 12、4 核 8G 的服务器上实测过。

为什么卡顿的答案往往藏在系统调用里

要理解这套方法为什么有效，得先知道一个进程"变慢"的本质是什么。

一个跑在用户态的进程（比如 PHP-FPM、MySQL、你的 Python 脚本），它自己在 CPU 上算数的时间通常很短。它真正花时间的地方，是不断地向内核"要东西"——读文件、写文件、发网络包、申请内存、等待锁。这些动作统称为系统调用（syscall）。

所以一个进程如果突然从 50 毫秒变成 3 秒，几乎可以肯定不是它自己算慢了，而是某一次系统调用被卡住了。而系统调用被卡住的原因，就那么几种：

• 它 read 的文件所在的磁盘正在被别的大 I/O 抢占，或者磁盘本身在重试坏道
• 它 write 的时候碰上了脏页回写，内核逼着它等磁盘落盘
• 它 fsync 了一次很大的数据，而这个动作天然就是慢的
• 它 connect 或者 recv 的时候在对端那里等，网络在超时重传或者 DNS 解析慢
• 它 futex 在等一个锁，而持有锁的线程被别的什么东西拖住了
• 它 open 一个路径的时候，某一层目录挂在了 NFS 上，而对端没响应

这六种原因，用 top 一个都看不出来，因为它们大部分时间进程都在睡眠状态——CPU 占用是 0。这就是为什么"服务器很闲但就是慢"这种现象如此普遍，也是为什么必须换一种观测手段。

strace 的价值就在这里：它能看见进程的每一次系统调用，以及每一次调用花了多少时间。有了这两样东西，偶发卡顿就从"玄学"变成了"找最大值"——录一段轨迹，按耗时排序，排在最前面的那几次调用，就是你要找的元凶。

第一步：能不能用 strace，取决于你的内核设置

现代内核出于安全考虑，默认可能禁止普通用户甚至 root 使用 ptrace 机制，而 strace 依赖它。所以动手之前先检查两个开关：

cat /proc/sys/kernel/yama/ptrace_scope
# 0 = 允许任意进程互 attach，1 = 只允许父进程 attach 子进程

生产服务器上这个值通常是 1，对 root 一般不影响，但如果你是用普通用户跑 strace 去 attach 别人的进程就会失败。可以临时改成 0 验证，但我不建议永久改成 0——那意味着任何进程都能窥探其他进程的内存，是个实实在在的安全风险。正确的做法是用 root 或者给 strace 单独授权。

另一个容易被忽略的点是内核是否启用了 CONFIG_FTRACE 和 CONFIG_HAVE_SYSCALL_TRACEPOINTS。绝大多数发行版的内核都开着，但如果你的服务器用的是极简定制内核（比如为了追求启动速度裁剪过的），可能出现 strace 能装但 attach 上去报 "Operation not permitted" 的情况。遇到这种报错，先去 dmesg 里搜 ptrace 或者 audit，看是不是 SELinux 或者 audit 规则拦住了——很多服务器装了安全加固套件后会默认屏蔽 ptrace。

确认可用之后，先做压力评估。strace 是有成本的：它会让被跟踪的进程变慢，慢多少取决于你跟踪的调用类型。实测经验是——只跟踪文件相关的调用（-e trace=file），进程性能损失大约 20% 到 30%；全量跟踪所有系统调用，性能损失可以到 5 倍甚至更多。这个数据很重要，它决定了你绝对不能把全量 strace 挂在线上主力进程上跑一整天。

第二步：用 -T 和 -ttt 拿到时间轴

strace 有很多参数，但那套既慢又难读的用法（全量 -f -s 9999）在这篇文章的场景里基本用不上。我们只需要两个参数，加上精准的过滤：

strace -f -T -ttt -e trace=file,desc -p 12345 -o /tmp/trace.log

拆开解释：

• -f：跟踪子进程和线程。PHP-FPM、MySQL 都是多进程多线程的，不加这个只能看到主进程，等于白干。
• -T：这个是最关键的参数。它在每一行系统调用末尾附上这次调用耗时，格式是 <0.000123>。有了它，你才能按耗时排序。
• -ttt：把时间戳打成一个绝对时间（秒.微秒）。相比默认的相对时间戳，绝对时间戳的好处是可以跨多个日志文件对齐——你可以拿它去和 Nginx 的 access log、MySQL 的慢查询日志做交叉比对，找出"那一刻发生了什么"。
• -e trace=file,desc：只跟踪文件类（open/stat/read/write 等）和描述符类调用。这一层过滤把 trace 的体积和性能损失同时降下来，是整个方案能上生产的前提。
• -p 12345：attach 到指定 PID。

开录之后，让它在后台跑（用 nohup 或者 tmux，因为 trace 会持续到你手动结束）。这里有个必须提醒的点：trace 日志会无限制增长。一个忙碌的 PHP-FPM 进程，全量 trace 每分钟能产生几百兆日志，几小时就能把磁盘写满——而磁盘写满本身就会造成新的卡顿，把你要查的问题变得更复杂。所以必须配合时间限制：

timeout 600 strace -f -T -ttt -e trace=file,desc -p 12345 -o /tmp/trace.log

timeout 600 意味着最多录十分钟就自动结束。对偶发卡顿来说，十分钟的窗口经常不够，正确的策略不是拉长单次录制，而是把录制做成定时任务，每天在故障高发时段自动录十分钟，录完归档，出问题的时候再去翻最近几天的档案。这一招把"碰运气"变成了"留证据"。

第三步：从 trace 里把慢调用挖出来

录到日志之后，真正的工作才开始。strace 的原始输出是几千上万行调用记录，人眼看不过来，得用脚本处理。-T 参数留下的 <耗时> 就是我们的抓手。

先做个粗筛，把耗时超过 0.1 秒的调用全部找出来：

grep -oE '^[0-9]+\.[0-9]+ .*<[0-9]+\.[0-9]+>' /tmp/trace.log \
  | awk -F'<' '{t=$2+0; if(t>0.1) print t, $0}' | sort -rn | head -30

这条命令的逻辑是：把每行末尾的 <耗时> 截出来转成数字，只保留大于 0.1 秒的，按耗时倒序排前 30 条。这 30 条就是你最该看的 30 行——如果卡顿是真实存在的，它的元凶几乎一定在里面。

举个真实的例子。我处理过一个 PHP 站点的案例：用户反映"每几分钟会有一两个请求要等 5 秒"，但服务器监控一切正常。录了十分钟 trace 之后，排序跑出来第一条是这样的：

1696234801.234567 open("/var/www/cache/data/abc123.cache", O_RDONLY) = 3 <4.982110>

一个 open 花了接近 5 秒。这就非常说明问题了——打开一个本地缓存文件，正常应该是微秒级。花了 5 秒，只有两种可能：磁盘在这一刻被别的 I/O 抢得完全占不到时间片，或者这个文件所在的位置有问题。

顺着这条线往下查，结论是这样的：那个缓存目录被另一个备份脚本 rsync 扫到过，而那台机器的磁盘是机械盘加 LVM，rsync 在读取大量冷数据时把 IO 队列堵死了，PHP 的 open 只能排在大 I/O 后面慢慢等。这是一个典型的"两个正确的操作互相打架"的例子——缓存设计没问题，备份策略也没问题，凑在一起就成了偶发卡顿。

从排序结果到根因，中间还需要一步交叉验证，不能只凭 trace 下结论。验证的方法是：把 trace 里慢调用的时间戳记下来，然后去查同一时刻的 I/O 指标或者 systemd 日志：

# 用慢调用发生的时间点，去系统日志里搜同一秒发生了什么
journalctl --since "2026-09-23 03:12:05" --until "2026-09-23 03:12:12"

如果这一刻系统日志里恰好有 rsync 启动、或者有 systemd 触发了某个批量任务，那因果链就闭合了。这种"trace 时间戳 → 系统日志"的对照，是把观察升级为证据的关键动作，也是 -ttt 参数真正值钱的地方。

一个完整的排查复盘：三秒钟的偶发挂起

讲一个完整的方法论案例，把上面的步骤串起来。这是一台跑了 Nginx + PHP-FPM + MySQL 的单机服务器，症状是：白天偶尔会有请求挂起约 3 秒然后恢复，一天发生十几次，毫无规律。用户投诉集中在下午，但无法复现。

第一阶段：先排除最明显的嫌疑。我看的是 Nginx 的 error.log 和 PHP-FPM 的慢日志。慢日志配的是 1 秒阈值，翻出来发现确实有记录，但都是同一个脚本，而且记录里只有"这个脚本跑了 3 秒"，没有说是哪一步跑的。这一步排除了"是 Nginx 自身的问题"，但没找到根因。

第二阶段：上 trace。因为故障出现在白天，我把录制挂成了定时任务，每天 13:00 到 13:10 自动录 PHP-FPM 池里所有 worker 的调用。参数上做了取舍——没有全量跟踪，只 trace=file,desc，因为我的假设是这类挂起大概率是 I/O 或者网络。同时把 -s（字符串截断长度）调小到 128，减少日志体积。

第三阶段：翻档案找到了证据。录了三天，第三天的 trace 里出现了前面说的那种模式：一个 read 调用耗时 2.9 秒。时间戳是 14:23:11。于是我去查同一时刻的系统状态，发现那一刻正好有一个定时任务在跑——是一个每天下午执行的图片处理脚本。

第四阶段：定位到具体机制。问题到这里还没有结束，因为"图片脚本在跑"不等于"它导致 PHP 变慢"——除非能说明它们抢的是同一个资源。于是我检查了两者的关系：图片脚本读取的是同一块数据盘，而这块盘上还挂着 MySQL 的 InnoDB 数据文件。图片脚本在处理大图时会产生大量顺序读，把磁盘 IO 队列填满，MySQL 和 PHP 的读请求（包括 PHP 读缓存文件）全都排在了后面。

第五阶段：量化收益。改进方案不是"取消图片脚本"（业务上需要），而是把它移到了另一块盘上，并给它加了 ionice -c 3 让它只在磁盘空闲时抢 IO。改造之后的数据对比：

• 改造前：下午平均响应时间 180 毫秒，但每天有 10-20 次超过 3 秒的尖刺，P99 延迟约 3.2 秒。
• 改造后：平均响应时间 165 毫秒（基本没变），超过 3 秒的尖刺降到每天 0-1 次，P99 延迟降到 420 毫秒。

这个案例最有价值的地方是：平均延迟几乎没有改善（180 → 165），但用户感受天差地别。因为用户对"慢"的感知不来自平均值，而来自那些 3 秒的尖刺。这也解释了为什么很多站长看监控面板觉得"一切正常"，用户却在抱怨——你盯的是均值，用户遇到的是长尾。查偶发卡顿，永远要盯着 P99 和最大值，不要看平均值。

几个必须知道的坑

坑一：attach 上去进程反而恢复了。这是观察者效应，非常常见。原因是被 trace 的进程会因为 ptrace 而变慢、被暂停、调度行为改变，恰好错过了原来的竞争条件。遇到这种情况不要怀疑方法，而是要换策略——把 attach 改成从进程启动就带着 trace 拉起（strace ... php-fpm），或者在多个 worker 上同时录，总有一个能命中。

坑二：把 trace 目标定错了进程。PHP-FPM 有 master 和 worker 之分，真正干活的是 worker；MySQL 的慢往往出在某个具体线程。用 pstree -p 先把进程树看清楚，再决定 attach 谁。attach 到 master 上录一整天也只会看到它在 epoll_wait，白忙一场。

坑三：trace 文件写在同一个出问题的盘上。如果卡顿的根因是磁盘 IO，而你把 trace 日志也写到同一块盘，那你的观测行为本身会加重故障，甚至把 trace 自己变成新的 I/O 来源。永远把 trace 输出写到别的盘或者 /dev/shm。

坑四：只看单次调用的耗时，忽略了调用频率。有些调用单次只要 2 毫秒，看起来人畜无害，但它在一个请求里被调用了 4000 次——那总耗时就是 8 秒。所以排序之外还要做聚合统计：按调用名统计出现次数和总耗时，找"高频小开销"的累加型瓶颈。这类问题用 strace -c 模式来做更直接，它会输出一张按系统调用聚合的耗时汇总表。

常见问题

问：strace 和 perf、bpftrace 该怎么选？

三者互补，不是替代关系。strace 的强项是精确到单次调用的事件级细节，追问"具体哪一次调用慢"它最强，代价是性能损耗大。perf 的强项是采样式的全局画像，看 CPU 热点、看调用栈分布最合适，但它对"进程在睡眠等 I/O"这类场景不敏感，因为睡眠的时候没有 CPU 事件可采样。bpftrace 最轻量、适合长期挂机，但要写脚本、学习曲线陡，而且内核版本低的时候功能受限。我的经验是：先用 perf 或者 bpftrace 拿到大致方向，再用 strace 做最后的定点确认。本文只讲 strace，是因为它最容易上手，而且直击"偶发慢"这个具体问题。

问：能不能不用 attach，直接看进程卡在哪？

可以，这是一条更轻量的旁路。cat /proc/PID/wchan 能看到进程当前在等什么内核函数，cat /proc/PID/stack（需要 root）能看到内核态调用栈。配合定时采样，就能知道"卡住的时候它在等什么"。这条路的优点是零性能损耗，缺点是只能看瞬间状态，撞上偶发的概率低——所以它更适合配合 trace 一起用：trace 告诉你有卡顿，采样告诉你卡顿时刻的内核栈长什么样。

问：录下来的 trace 日志太大，怎么管理？

三个手段。一是用 -e trace= 精确过滤，只留你关心的调用类别，这一招通常能砍掉 80% 的体积。二是用 -s 128 限制每个参数打印的字符串长度，避免把大块文件内容录进去。三是录完立刻压缩归档（strace 输出压缩率很高，通常能压到十分之一），并按日期轮转，保留最近 7 天。不要把 trace 日志直接留在 /tmp 里不管，很多磁盘写满的故障就是这么来的。

总结

对付偶发卡顿，核心是换一套观测哲学：从"实时盯监控"转为"长期留证据，事后复盘"。因为偶发故障的本质矛盾是——它出现的时候你没在观察，你在观察的时候它不出现。唯一的解法是让证据自己留下来。

落到操作上，记住四个要点。第一，用 strace -f -T -ttt 录制，-T 拿到每次调用耗时，-ttt 拿到可与日志对齐的绝对时间戳，没有这两个参数，trace 就只是一堆没用的文本。第二，必须用 -e trace= 过滤，否则性能损失和日志体积会把你坑死，生产环境绝不允许全量 trace 常驻。第三，录完用脚本按耗时排序（取前 30 条）加按调用名聚合（找高频累加型瓶颈），两种视角都要看。第四，从 trace 到根因必须有一次交叉验证——拿慢调用的时间戳去比对系统日志和 I/O 指标，找到"那一刻还发生了什么"，因果链才算闭合。

最后提醒一句关于指标的：查这类问题，看 P99 和最大值，别看平均值。平均值是给报表看的，长尾才是给用户受的。很多"服务器看起来很闲但用户很慢"的谜题，答案都在那条长长的尾巴里。