使用 Strace 进行故障排除的五种简单方法-51CTO.COM

我一直感到惊讶的是，很少有人知道他们可以使用strace的所有事情。它始终是我推出的第一个调试工具之一，因为它通常在我运行的 Linux 系统上可用，并且可用于解决如此广泛的问题。

什么是strace？

Strace 非常简单地是一个跟踪系统调用执行的工具。在最简单的形式中，它可以从头到尾跟踪二进制文件的执行，并输出一行文本，其中包含系统调用的名称、参数和进程生命周期内每个系统调用的返回值。但它可以做更多的事情：

它可以根据特定的系统调用或系统调用组进行过滤
它可以通过计算特定系统调用的使用次数、所用时间以及成功和错误的数量来分析系统调用的使用情况。
它跟踪发送到进程的信号。
它可以通过 pid 附加到任何正在运行的进程。

如果你使用过其他Unix系统，这类似于“truss”。另一个（更全面）是Sun的Dtrace。

如何使用它

这只是皮毛，没有特别的重要性顺序：

1）找出程序在启动时读取哪些配置文件

有没有尝试过弄清楚为什么某些程序不读取您认为应该读取的配置文件？不得不与自定义编译或特定于发行版的二进制文件搏斗，这些二进制文件从您认为的“错误”位置读取其配置？幼稚的方法：所以这个版本的PHP从/usr/local/lib/php.ini读取php.ini（但它首先尝试/usr/local/bin）。如果我只关心特定的系统调用，更复杂的方法：同样的方法适用于许多其他事情。在不同的路径上安装了多个版本的库，并想知道实际加载了哪个版本？等。

$ strace php 2>&1 | grep php.ini
open("/usr/local/bin/php.ini", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/local/lib/php.ini", O_RDONLY) = 4
lstat64("/usr/local/lib/php.ini", {st_mode=S_IFLNK|0777, st_size=27, ...}) = 0
readlink("/usr/local/lib/php.ini", "/usr/local/Zend/etc/php.ini", 4096) = 27
lstat64("/usr/local/Zend/etc/php.ini", {st_mode=S_IFREG|0664, st_size=40971, ...}) = 0

$ strace -e open php 2>&1 | grep php.ini
open("/usr/local/bin/php.ini", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/local/lib/php.ini", O_RDONLY) = 4

2）为什么这个程序打不开我的文件？

曾经遇到过一个程序，它默默地拒绝读取它没有读取访问权限的文件，但你只是在发誓多年后才发现，因为你认为它实际上没有找到该文件？好吧，您已经知道该怎么做：查找失败的 open（）或 access（）系统调用

$ strace -e open,access 2>&1 | grep your-filename

3）这个过程现在在做什么？

曾经有一个进程突然占用大量 CPU 吗？还是一个过程似乎悬而未决？然后你找到pid，然后这样做：啊。所以在这种情况下，它挂在对futex（）的调用中。顺便说一下，在这种情况下，它并没有告诉我们那么多 - 挂在 futex 上可能是由很多事情引起的（futex 是 Linux 内核中的锁定机制）。以上来自一个正常工作但空闲的 Apache 子进程，该进程正在等待收到请求。但是“strace -p”非常有用，因为它消除了大量的猜测，并且通常不需要重新启动具有更广泛日志记录的应用程序（甚至重新编译它）。

root@dev:~# strace -p 15427
Process 15427 attached - interrupt to quit
futex(0x402f4900, FUTEX_WAIT, 2, NULL 
Process 15427 detached

4）什么是花时间？

你始终可以在打开分析的情况下重新编译应用，并获得准确的信息，尤其是关于你自己的代码的哪些部分需要时间，这是你应该做的。但通常，能够快速将 strace 附加到流程以查看它当前花费的时间（尤其是诊断问题）是非常有用的。这是 90% 的 CPU 使用率，因为它实际上正在做真正的工作，还是失控的东西。以下是您的操作：使用 -c -p 启动 strace 后，您只需等待多长时间，然后使用 ctrl-c 退出。Strace 将按上述方式吐出分析数据。在这种情况下，它是一个空闲的 Postgres “postmaster” 进程，它花费大部分时间在 select（）中安静地等待。在这种情况下，它在每次select（）调用之间调用getppid（）和time（），这是一个相当标准的事件循环。你也可以运行这个“从头到尾”，这里用“ls”：几乎你所期望的，它大部分时间都花在两次调用上来读取目录条目（只有两次，因为它是在一个小目录上运行的）。

root@dev:~# strace -c -p 11084
Process 11084 attached - interrupt to quit
Process 11084 detached
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 94.59    0.001014          48        21           select
  2.89    0.000031           1        21           getppid
  2.52    0.000027           1        21           time
------ ----------- ----------- --------- --------- ----------------
100.00    0.001072                    63           total
root@dev:~#

root@dev:~# strace -c >/dev/null ls
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 23.62    0.000205         103         2           getdents64
 18.78    0.000163          15        11         1 open
 15.09    0.000131          19         7           read
 12.79    0.000111           7        16           old_mmap
  7.03    0.000061           6        11           close
  4.84    0.000042          11         4           munmap
  4.84    0.000042          11         4           mmap2
  4.03    0.000035           6         6         6 access
  3.80    0.000033           3        11           fstat64
  1.38    0.000012           3         4           brk
  0.92    0.000008           3         3         3 ioctl
  0.69    0.000006           6         1           uname
  0.58    0.000005           5         1           set_thread_area
  0.35    0.000003           3         1           write
  0.35    0.000003           3         1           rt_sigaction
  0.35    0.000003           3         1           fcntl64
  0.23    0.000002           2         1           getrlimit
  0.23    0.000002           2         1           set_tid_address
  0.12    0.000001           1         1           rt_sigprocmask
------ ----------- ----------- --------- --------- ----------------
100.00    0.000868                    87        10 total

5）为什么 **** 我无法连接到该服务器？

调试某些进程未连接到远程服务器的原因可能非常令人沮丧。DNS 可能会失败，连接可能会挂起，服务器可能会发送一些意外的内容等。你可以使用 tcpdump 来分析很多，这也是一个非常好的工具，但很多时候 strace 会给你更少的喋喋不休，仅仅是因为它只会返回与“你的”进程生成的系统调用相关的数据。例如，如果您试图弄清楚连接到同一数据库服务器的数百个正在运行的进程中的一个是做什么的（其中挑选与 tcpdump 的正确连接是一场噩梦），strace 使生活变得容易得多。这是“nc”跟踪连接到端口 80 上的 www.news.com 的示例，没有任何问题：那么这里会发生什么？注意到 /var/run/nscd/socket 的连接尝试了吗？这意味着 nc 首先尝试连接到 NSCD - 名称服务缓存守护程序 - 通常用于依赖 NIS、YP、LDAP 或类似目录协议进行名称查找的设置中。在这种情况下，连接失败。然后它移动到 DNS（DNS 是端口 53，因此在下面的连接中是“sin_port=htons（53）”。您可以看到它随后执行“sendto（）”调用，发送包含 www.news.com 的DNS数据包。然后，它会读回一个数据包。无论出于何种原因，它尝试了三次，最后一次请求略有不同。在这种情况下，我最好的猜测是 www.news.com 是一个 CNAME（“别名”），多个请求可能只是 nc 如何处理它的人工制品。最后，它最终向它找到的 IP 发出 connect（）。请注意，它返回 EINPROGRESS。这意味着连接是非阻塞的 - nc 想要继续处理。然后，它调用 select（），当连接成功时成功。尝试将“read”和“write”添加到提供给strace的系统调用列表中，并在连接时输入一个字符串，你会得到这样的结果：这表明它从标准输入读取“test”+换行，并将其写回网络连接，然后调用poll（）等待回复，从网络连接读取回复并将其写入标准输出。一切似乎都正常。

$ strace -e poll,select,connect,recvfrom,sendto nc www.news.com 80
sendto(3, "\\24\\0\\0\\0\\26\\0\\1\\3\\255\\373NH\\0\\0\\0\\0\\0\\0\\0\\0", 20, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 20
connect(3, {sa_family=AF_FILE, path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
connect(3, {sa_family=AF_FILE, path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
connect(3, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("62.30.112.39")}, 28) = 0
poll([{fd=3, events=POLLOUT, revents=POLLOUT}], 1, 0) = 1
sendto(3, "\\213\\321\\1\\0\\0\\1\\0\\0\\0\\0\\0\\0\\3www\\4news\\3com\\0\\0\\34\\0\\1", 30, MSG_NOSIGNAL, NULL, 0) = 30
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
recvfrom(3, "\\213\\321\\201\\200\\0\\1\\0\\1\\0\\1\\0\\0\\3www\\4news\\3com\\0\\0\\34\\0\\1\\300\\f"..., 1024, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("62.30.112.39")}, [16]) = 153
connect(3, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("62.30.112.39")}, 28) = 0
poll([{fd=3, events=POLLOUT, revents=POLLOUT}], 1, 0) = 1
sendto(3, "k\\374\\1\\0\\0\\1\\0\\0\\0\\0\\0\\0\\3www\\4news\\3com\\0\\0\\1\\0\\1", 30, MSG_NOSIGNAL, NULL, 0) = 30
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
recvfrom(3, "k\\374\\201\\200\\0\\1\\0\\2\\0\\0\\0\\0\\3www\\4news\\3com\\0\\0\\1\\0\\1\\300\\f"..., 1024, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("62.30.112.39")}, [16]) = 106
connect(3, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("62.30.112.39")}, 28) = 0
poll([{fd=3, events=POLLOUT, revents=POLLOUT}], 1, 0) = 1
sendto(3, "\\\\\\2\\1\\0\\0\\1\\0\\0\\0\\0\\0\\0\\3www\\4news\\3com\\0\\0\\1\\0\\1", 30, MSG_NOSIGNAL, NULL, 0) = 30
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
recvfrom(3, "\\\\\\2\\201\\200\\0\\1\\0\\2\\0\\0\\0\\0\\3www\\4news\\3com\\0\\0\\1\\0\\1\\300\\f"..., 1024, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("62.30.112.39")}, [16]) = 106
connect(3, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("216.239.122.102")}, 16) = -1 EINPROGRESS (Operation now in progress)
select(4, NULL, [3], NULL, NULL)        = 1 (out [3])

read(0, "test\\n", 1024)                 = 5
write(3, "test\\n", 5)                   = 5
poll([{fd=3, events=POLLIN, revents=POLLIN}, {fd=0, events=POLLIN}], 2, -1) = 1
read(3, "\"-//IETF//"..., 1024) = 216
write(1, "\"-//IETF//"..., 216) = 216

使用 Strace 进行故障排除的五种简单方法