你可能已经注意到，错误信息的第二部分没有出现在上面的例子中。这是因为 默认仅显示字符串参数的前 32 个字节。如果你需要捕获更多参数，请向 追加类似于 -s 128 之类的参数。
-y 使得追踪文件或套接字更加容易
“一切皆文件”意味着 *nix 系统通过文件描述符进行所有 IO 操作，不管是真实的文件还是通过网络或者进程间管道。这对于编程而言是很方便的，但是在追踪系统调用时，你将很难分辨出 read 和 write 的真实行为。
-y 参数使 在注释中注明每个文件描述符的具体指向。
使用 -p 附加到正在运行的进程中
正如我们将在后面的例子中看到的，有时候你想追踪一个正在运行的程序。如果你知道这个程序的进程号为 1337 （可以通过 ps 查询），则可以这样操作：
$ strace -p 1337 ...system call trace output...
你可能需要 root 权限才能运行。
使用 -f 追踪子进程
默认只追踪一个进程。如果这个进程产生了一个子进程，你将会看到创建子进程的系统调用（一般是 clone），但是你看不到子进程内触发的任何调用。
如果你认为在子进程中存在错误，则需要使用 -f 参数启用子进程追踪功能。这样做的缺点是输出的内容会让人更加困惑。当追踪一个进程时， 显示的是单个调用事件流。当追踪多个进程的时候，你将会看到以 开始的初始调用，接着是一系列针对其它线程的调用，最后才出现以 结束的初始调用。此外，你可以使用 -ff 参数将所有的调用分离到不同的文件中（查看 手册 获取更多信息）。
使用 -e 进行过滤
正如你所看到的，默认的追踪输出是所有的系统调用。你可以使用 -e 参数过滤你需要追踪的调用（查看 手册 ）。这样做的好处是运行过滤后的 比起使用 grep 进行二次过滤要更快。老实说，我大部分时间都不会被打扰。
并非所有的错误都是不好的
一个简单而常用的例子是一个程序在多个位置搜索文件，例如 shell 搜索哪个 bin/ 目录包含可执行文件：
$ strace sh -c uname
...
stat("/home/user/bin/uname", 0x7ffceb817820) = -1 ENOENT (No such file or directory)
stat("/usr/local/bin/uname", 0x7ffceb817820) = -1 ENOENT (No such file or directory)
stat("/usr/bin/uname", {st_mode=S_IFREG|0755, st_size=39584, ...}) = 0
...
“错误信息之前的最后一次失败调用”这种启发式方法非常适合于查找错误。无论如何，自下而上地查找是有道理的。
C 编程指南非常有助于理解系统调用
标准 C 库函数调用不属于系统调用，但它们仅是系统调用之上的唯一一个薄层。所以如果你了解（甚至只是略知一二）如何使用 C 语言，那么阅读系统调用追踪信息就非常容易。例如，如果你在调试网络系统调用，你可以尝试略读 Beej 经典的《网络编程指南》 。
一个更复杂的调试例子
就像我说的那样，简单的调试例子表现了我在大部分情况下如何使用 。然而，有时候需要一些更加细致的工作，所以这里有一个稍微复杂（且真实）的例子。
bcron 是一个任务调度器，它是经典 *nix cron 守护程序的另一种实现。它已经被安装到一台服务器上，但是当有人尝试编辑作业时间表时，发生了以下情况：
# crontab -e -u logs bcrontab: Fatal: Could not create temporary file
好的，现在 bcron 尝试写入一些文件，但是它失败了，也没有告诉我们原因。以下是 的输出：
# strace -o /tmp/trace crontab -e -u logs
bcrontab: Fatal: Could not create temporary file
# cat /tmp/trace
...
openat(AT_FDCWD, "bcrontab.14779.1573691864.847933", O_RDONLY) = 3
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f82049b4000
read(3, "#Ansible: logsaggn20 14 * * * lo"..., 8192) = 150
read(3, "", 8192) = 0
munmap(0x7f82049b4000, 8192) = 0
close(3) = 0
socket(AF_UNIX, SOCK_STREAM, 0) = 3
connect(3, {sa_family=AF_UNIX, sun_path="/var/run/bcron-spool"}, 110) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f82049b4000
write(3, "156:Slogs#Ansible: logsaggn20 1"..., 161) = 161
read(3, "32:ZCould not create temporary f"..., 8192) = 36
munmap(0x7f82049b4000, 8192) = 0
close(3) = 0
write(2, "bcrontab: Fatal: Could not creat"..., 49) = 49
unlink("bcrontab.14779.1573691864.847933") = 0
exit_group(111) = ?
+++ exited with 111 +++
在程序结束之前有一个 write 的错误信息，但是这次有些不同。首先，在此之前没有任何相关的失败系统调用。其次，我们看到这个错误信息是由 read 从别的地方读取而来的。这看起来像是真正的错误发生在别的地方，而 只是在转播这些信息。
如果你查阅了 man 2 read，你将会看到 read 的第一个参数 (3) 是一个文件描述符，这是 *nix 操作系统用于所有 IO 操作的句柄。你该如何知道文件描述符 3 代表什么？在这种情况下，你可以使用 -y 参数运行 （如上文所述），它将会在注释里告诉你文件描述符的具体指向，但是了解如何从上面这种输出中分析追踪结果是很有用的。
一个文件描述符可以来自于许多系统调用之一（这取决于它是用于控制台、网络套接字还是真实文件等的描述符），但不论如何，我们都可以搜索返回值为 3 的系统调用（例如，在 的输出中查找 =3）。在这次 中可以看到有两个这样的调用：最上面的 以及中间的 。 打开一个文件，但是紧接着的 close(3) 表明其已经被关闭。（注意：文件描述符可以在打开并关闭后重复使用。）所以 调用才是与此相关的（它是在 read 之前的最后一个），这告诉我们 正在与一个网络套接字通信。在下一行， 表明文件描述符 3 是一个连接到 /var/run/bcron-spool 的 Unix 域套接字。
因此，我们需要弄清楚 Unix 套接字的另一侧是哪个进程在监听。有两个巧妙的技巧适用于在服务器部署中调试。一个是使用 或者较新的 ss。这两个命令都描述了当前系统中活跃的网络套接字，使用 -l 参数可以显示出处于监听状态的套接字，而使用 -p 参数可以得到正在使用该套接字的程序信息。（它们还有更多有用的选项，但是这两个已经足够完成工作了。）
# ss -pl | grep /var/run/bcron-spool
u_str LISTEN 0 128 /var/run/bcron-spool 1466637 * 0 users:(("unixserver",pid=20629,fd=3))
这告诉我们 /var/run/bcron-spool 套接字的监听程序是 这个命令，它的进程 ID 为 20629。（巧合的是，这个程序也使用文件描述符 3 去连接这个套接字。）
第二个常用的工具就是使用 lsof 查找相同的信息。它可以列出当前系统中打开的所有文件（或文件描述符）。或者，我们可以得到一个具体文件的信息：
# lsof /var/run/bcron-spool COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME unixserve 20629 cron 3u unix 0x000000005ac4bd83 0t0 1466637 /var/run/bcron-spool type=STREAM
进程 20629 是一个常驻进程，所以我们可以使用 -o /tmp/trace -p 20629 去查看该进程的系统调用。如果我们在另一个终端尝试编辑 cron 的计划任务表，就可以在错误发生时捕获到以下信息：
accept(3, NULL, NULL) = 4
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7faa47c44810) = 21181
close(4) = 0
accept(3, NULL, NULL) = ? ERESTARTSYS (To be restarted if SA_RESTART is set)
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=21181, si_uid=998, si_status=0, si_utime=0, si_stime=0} ---
wait4(0, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WNOHANG|WSTOPPED, NULL) = 21181
wait4(0, 0x7ffe6bc36764, WNOHANG|WSTOPPED, NULL) = -1 ECHILD (No child processes)
rt_sigaction(SIGCHLD, {sa_handler=0x55d244bdb690, sa_mask=[CHLD], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7faa47ab9840}, {sa_handler=0x55d244bdb690, sa_mask=[CHLD], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7faa47ab9840}, 8) = 0
rt_sigreturn({mask=[]}) = 43
accept(3, NULL, NULL) = 4
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7faa47c44810) = 21200
close(4) = 0
accept(3, NULL, NULL) = ? ERESTARTSYS (To be restarted if SA_RESTART is set)
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=21200, si_uid=998, si_status=111, si_utime=0, si_stime=0} ---
wait4(0, [{WIFEXITED(s) && WEXITSTATUS(s) == 111}], WNOHANG|WSTOPPED, NULL) = 21200
wait4(0, 0x7ffe6bc36764, WNOHANG|WSTOPPED, NULL) = -1 ECHILD (No child processes)
rt_sigaction(SIGCHLD, {sa_handler=0x55d244bdb690, sa_mask=[CHLD], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7faa47ab9840}, {sa_handler=0x55d244bdb690, sa_mask=[CHLD], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7faa47ab9840}, 8) = 0
rt_sigreturn({mask=[]}) = 43
accept(3, NULL, NULL
（最后一个 调用没有在追踪期间完成。）不幸的是，这次追踪没有包含我们想要的错误信息。我们没有观察到 往套接字发送或接受的任何信息。然而，我们看到了很多进程管理操作（clone、wait4、，等等）。这个进程产生了子进程，我们猜测真实的工作是由子进程完成的。如果我们想捕获子进程的追踪信息，就必须往 追加 -f 参数。以下是我们最终使用 -f -o /tmp/trace -p 20629 找到的错误信息：
21470 openat(AT_FDCWD, "tmp/spool.21470.1573692319.854640", O_RDWR|O_CREAT|O_EXCL, 0600) = -1 EACCES (Permission denied)
21470 write(1, "32:ZCould not create temporary f"..., 36) = 36
21470 write(2, "bcron-spool[21470]: Fatal: logs:"..., 84) = 84
21470 unlink("tmp/spool.21470.1573692319.854640") = -1 ENOENT (No such file or directory)
21470 exit_group(111) = ?
21470 +++ exited with 111 +++
现在我们知道了进程 ID 21470 在尝试创建文件 tmp/spool.21470.. （相对于当前的工作目录）时得到了一个没有权限的错误。如果我们知道当前的工作目录，就可以得到完整路径并能指出为什么该进程无法在此处创建临时文件。不幸的是，这个进程已经退出了，所以我们不能使用 lsof -p 21470 去找出当前的工作目录，但是我们可以往前追溯，查找进程 ID 21470 使用哪个系统调用改变了它的工作目录。这个系统调用是 chdir（可以在搜索引擎很轻松地找到）。以下是一直往前追溯到服务器进程 ID 20629 的结果：
20629 clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7faa47c44810) = 21470
...
21470 execve("/usr/sbin/bcron-spool", ["bcron-spool"], 0x55d2460807e0 /* 27 vars */) = 0
...
21470 chdir("/var/spool/cron") = 0
...
21470 openat(AT_FDCWD, "tmp/spool.21470.1573692319.854640", O_RDWR|O_CREAT|O_EXCL, 0600) = -1 EACCES (Permission denied)
21470 write(1, "32:ZCould not create temporary f"..., 36) = 36
21470 write(2, "bcron-spool[21470]: Fatal: logs:"..., 84) = 84
21470 unlink("tmp/spool.21470.1573692319.854640") = -1 ENOENT (No such file or directory)
21470 exit_group(111) = ?
21470 +++ exited with 111 +++
（如果你在这里迷糊了，你可能需要阅读 我之前有关 *nix 进程管理和 shell 的文章 ）
现在 PID 为 20629 的服务器进程没有权限在 /var/spool/cron/tmp/spool.21470.. 创建文件。最可能的原因就是典型的 *nix 文件系统权限设置。让我们检查一下：
# ls -ld /var/spool/cron/tmp/ drwxr-xr-x 2 root root 4096 Nov 6 05:33 /var/spool/cron/tmp/ # ps u -p 20629 USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND cron 20629 0.0 0.0 2276 752 ? Ss Nov14 0:00 unixserver -U /var/run/bcron-spool -- bcron-spool
这就是问题所在！这个服务进程以 cron 用户运行，但是只有 root 用户才有向 /var/spool/cron/tmp/ 目录写入的权限。一个简单 chown cron /var/spool/cron/tmp/ 命令就能让 bcron 正常工作。（如果不是这个问题，那么下一个最有可能的怀疑对象是诸如 或者 之类的内核安全模块，因此我将会使用 dmesg 检查内核日志。）
总结
最初，系统调用追踪可能会让人不知所措，但是我希望我已经证明它们是调试一整套常见部署问题的快速方法。你可以设想一下尝试用单步调试器去调试多进程的 bcron 问题。
通过一连串的系统调用解决问题是需要练习的，但正如我说的那样，在大多数情况下，我只需要使用 从下往上追踪并查找错误。不管怎样， 节省了我很多的调试时间。我希望这也对你有所帮助。
via:
作者： Simon 选题： 译者： 校对： wxy
本文由 LCTT 原创编译， Linux中国 荣誉推出
———END———
限 时 特 惠： 本站每日持续更新海量各大内部创业教程，永久会员只需109元，全站资源免费下载 点击查看详情
站 长 微 信： nanadh666
