Linux运维8 min read次阅读

strace 排障实战:用系统调用追踪把进程卡死、变慢、报错看个明白

某天晚上告警,一个 Java 服务 CPU 不高,响应时间却从 20ms 飙到 8s,日志里什么都没有。top 看它安安静静,netstat 连接也正常。这种"看起来没病但就是慢"的毛病,strace 往往一句话就定位了。

strace 到底在看什么

strace 通过 ptrace 系统调用挂到目标进程上,拦截它发出的每一个 syscall,把调用名、参数、返回值、耗时打出来。它不关心业务逻辑,只看进程和内核之间在交换什么——读文件、连 socket、拿锁、分配内存。

这层视角很特殊。top/perf 看的是资源占用,strace 看的是"阻塞点在哪"。一个进程 99% 的时间花在 futex(..., FUTEX_WAIT, ...) 上,说明它在等锁;卡在 read(...) = -1 EAGAIN 说明在非阻塞 fd 上轮询;connect(...) 之后长时间没有 send/recv,多半是网络或对端慢。

最常用的一条命令

线上排障,八成情况这一句够用:

strace -f -p 12345 -T -tt -o /tmp/trace.log
  • -p 12345 attach 到 PID 12345
  • -f 顺便跟住它之后 fork 出来的子进程(多线程程序务必加,否则只看到主线程)
  • -T 在每个 syscall 后面打印耗时,单位秒
  • -tt 带毫秒的时间戳,方便对照"什么时候开始慢"
  • -o 写文件,别直接打到终端,量很大

attach 上之后去触发一次请求,等几秒 Ctrl-C,然后看日志的尾巴。我习惯先看耗时最长的那几行。或者更简单:直接搜卡住的行。strace 输出里,如果一个 syscall 一直没出现它的 <... 返回值>,说明进程正卡在那。比如满屏最后是:

12345 14:03:21.882334 connect(8, {sa_family=AF_INET, sin_port=htons(5432), sin_addr=inet_addr("10.0.0.5")}, 16

然后很久没有下一行——那它卡在连 10.0.0.5:5432。不用再猜了,去查那台 PostgreSQL。

过滤噪声:别被海量输出淹死

一个繁忙进程每秒上千个 syscall,直接 -p 挂会刷屏。两种克制办法。

按 syscall 类别过滤,只看网络相关:

strace -f -p 12345 -e trace=network -T -tt

-e trace=network 等价于 trace=socket,connect,accept,sendto,recvfrom,...。常见分组还有 trace=file(所有文件操作)、trace=processtrace=desc(文件描述符读写)、trace=ipctrace=signal

只看失败的系统调用,这招定位权限、资源类报错极好用:

strace -f -p 12345 -e trace=file -e status=failed

-e status=failed 只打印返回负的(出错)的调用。比如一个服务启动报 "Permission denied" 但日志没说是哪个文件,挂上这行立刻看到:

open("/var/run/app.sock", O_RDWR) = -1 EACCES (Permission denied)

根因一目了然:socket 文件权限不对,不是代码问题。

不 attach 也能抓:启动即追踪

有些毛病只在进程刚起来那一瞬间。attach 已经晚了。直接让 strace 当它的父进程启动:

strace -f -o /tmp/startup.log -T -tt /usr/bin/myapp --config /etc/myapp.conf

或者 strace -f -o /tmp/c.log /usr/sbin/nginx -g 'daemon off;'。注意某些程序检测到自己被 ptrace 会改行为(尤其是带反调试逻辑的),但常规服务基本无感。

想保留原进程树、又不想 strace 当父进程,可以用 timeout 包一层控制时长。但最省事的还是上面这样直接启动。

统计视角:哪类调用最耗时

排"整体慢但不确定慢在哪"时,用 -c 做汇总,跑一段业务后 Ctrl-C

strace -f -p 12345 -c

输出一张表,按调用次数和总时间排序。我曾经靠它发现一个"慢"的服务其实是被 stat() 风暴拖垮——应用每次请求都递归 stat 一大堆不存在的目录,单次几微秒,但一秒几万次,积少成多把 IO 打满。换成缓存路径后 P99 直接砍半。

ltrace:看库函数而不是 syscall

strace 之下是内核接口。想看进程在调哪个动态库函数(比如 mallocstrlenSSL_read),用 ltrace:

ltrace -f -p 12345 -T -tt

它和 strace 参数几乎一样。适合排查"明明没做 IO 却很慢"——比如一个字符串处理库在疯狂 strlen,提示算法有 O(n²)。不过 ltrace 对多线程、静态链接、Go/Rust 这类不用 glibc 的程序支持很差,基本只有 C/C++ 动态链接的程序好使。

线上能不能随便 strace?

要泼点冷水。ptrace 会显著拖慢目标进程——每个 syscall 都要被内核拦下来交给 strace 处理,开销可能翻倍。所以:

  • 生产高峰别挂整个繁忙进程,先 -e trace=networkstatus=failed 缩小范围,抓几秒就 Ctrl-C
  • 多进程服务别 -f 跟太多,选一个具体的慢请求对应的 worker 去挂;
  • 容器里 strace 需要 SYS_PTRACE capability,Kubernetes 里要么加 securityContext.capabilities.add: ["SYS_PTRACE"],要么进特权容器;
  • Go 程序不能直接 strace -p(runtime 调度会乱),更稳的是用 /proc/<pid>/syscall 这种非侵入方式看一眼当前卡在哪个调用:
cat /proc/12345/task/*/syscall

这行不干扰进程,能立刻告诉你每个线程此刻阻塞的 syscall 编号,先粗筛再决定要不要上 strace。

一个我踩过的坑

有次定位一个偶发卡顿,strace 挂上去问题消失——典型的"海森堡效应",ptrace 改变了时序让竞态不触发。后来改用 -c 短采样 + 应用层埋点对照,才确认是连接池借还顺序导致的锁竞争,而非 syscall 层。

教训是:strace 是显微镜不是万用表,它告诉你"卡在哪一刻",但为什么卡、怎么改,还得回到代码和架构。把它当成"看进程到底在干什么"的窗口就好。它不会替你修 bug,但能帮你把"感觉哪里不对"变成"就是卡在 connect 到 10.0.0.5 花了 7 秒"这种无可辩驳的事实。剩下的,是该查网络、查对端、还是查连接池,方向就清楚了。

分享:

相关文章

评论区