
在很大程度上,我的主要工作是软件系统的部署,也就是说,我花了大量时间尝试回答以下问题:
- 该软件适用于开发人员,但不适用于我。 怎么了
- 昨天,该软件对我有用,但今天不起作用。 怎么了
这是一种调试,与常规软件调试略有不同。 常规调试与代码逻辑有关,而部署调试与代码和环境交互有关。 即使问题的根源是一个逻辑错误,所有事物都在一台机器上运行而不在另一台机器上运行这一事实也意味着问题在环境中。
因此,我有一套不同的工具来调试部署,而不是像gdb这样的常规调试工具。 而我最喜欢的工具是用来解决诸如“为什么不耕作该软件?”之类的问题的工具 称为strace 。
什么是strace?
strace是用于跟踪系统调用的工具。 最初是在Linux下创建的,但是可以使用其他系统的工具( DTrace或ktrace )来旋转相同的调试芯片。
主要应用程序非常简单。 您只需要使用任何命令运行strace,它将所有系统调用发送到转储(尽管首先,您可能必须自己安装strace ):
$ strace echo Hello ...Snip lots of stuff... write(1, "Hello\n", 6) = 6 close(1) = 0 close(2) = 0 exit_group(0) = ? +++ exited with 0 +++
这些系统调用是什么? 它是操作系统内核的一种API。 从前,该软件可以直接访问其工作所在的硬件。 例如,如果您需要在屏幕上显示某些内容,则它会与视频设备的端口和/或内存寄存器一起播放。 当多任务计算机系统变得流行时,混乱就盛行了,因为各种应用程序都在为硬件而战。 一个应用程序中的错误可能会使其他应用程序(甚至不是整个系统)的工作崩溃。 然后特权模式(或“振铃保护”)出现在CPU中。 内核成为最特权的:它获得了对硬件的完全访问权限,从而创建了特权较低的应用程序,这些应用程序已经必须通过系统调用从内核请求访问权限才能与硬件进行交互。
在二进制级别,系统调用与简单函数调用稍有不同,但是大多数程序在标准库中使用包装器。 即 POSIX C标准库包含对write()函数的调用,该函数包含用于write系统调用的所有特定于体系结构的代码。

简而言之,应用程序与其环境(计算机系统)之间的任何交互都是通过系统调用进行的。 因此,当软件在一台机器上而不是另一台机器上运行时,最好查看跟踪系统调用的结果。 更具体地说,这是可以使用系统调用跟踪进行分析的典型点的列表:
- 控制台I / O
- 网络输入/输出
- 文件系统访问和文件I / O
- 进程/线程生命周期管理
- 低级内存管理
- 访问特定的设备驱动程序
何时使用strace?
从理论上讲, strace可用于用户空间中的任何程序,因为用户空间中的任何程序都应进行系统调用。 它可以与已编译的低级程序一起更有效地工作,但是如果您可以克服运行时和解释程序带来的额外噪音,那么它也可以与Python等高级语言一起工作。
尽管strace具有出色的性能,但它在调试可在一台机器上正常运行的软件时会表现出来,但突然停止在另一台机器上工作,给出有关文件,权限或执行某些命令或某些操作的尝试失败的含糊不清的信息……这很可惜,但并不是很好它与诸如证书验证错误之类的高级问题结合在一起。 这通常需要strace (有时是ltrace)和更高级别的工具(例如,用于调试证书的openssl命令行工具)的组合。
例如,我们在独立服务器上工作,但是跟踪系统调用通常可以在更复杂的部署平台上执行。 您只需要选择正确的工具箱即可。
简单调试示例
假设您要运行很棒的foo服务器应用程序,但事实证明:
$ foo Error opening configuration file: No such file or directory
显然,他找不到您编写的配置文件。 发生这种情况是因为有时,程序包管理器在编译应用程序时会覆盖文件的预期位置。 而且,如果您按照一种发行版的安装指南进行操作,则在另一种发行版中,发现文件完全不在我期望的位置。 如果错误消息指出要在哪里查找配置文件,但未给出说明,则可以在几秒钟内解决问题。 那么在哪里看?
如果您有权访问源代码,则可以阅读并查找。 一个好的备份计划,但不是最快的解决方案。 您可以使用gdb之类的逐步调试器来查看程序的功能,但是使用专门设计用来显示与环境交互作用的工具strace效率更高。
strace的结论似乎是多余的,但是好消息是,可以安全地忽略大多数。 使用-o运算符将跟踪结果保存到单独的文件中通常很有用:
$ strace -o /tmp/trace foo Error opening configuration file: No such file or directory $ cat /tmp/trace execve("foo", ["foo"], 0x7ffce98dc010 /* 16 vars */) = 0 brk(NULL) = 0x56363b3fb000 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 fstat(3, {st_mode=S_IFREG|0644, st_size=25186, ...}) = 0 mmap(NULL, 25186, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f2f12cf1000 close(3) = 0 openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3 read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260A\2\0\0\0\0\0"..., 832) = 832 fstat(3, {st_mode=S_IFREG|0755, st_size=1824496, ...}) = 0 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f2f12cef000 mmap(NULL, 1837056, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f2f12b2e000 mprotect(0x7f2f12b50000, 1658880, PROT_NONE) = 0 mmap(0x7f2f12b50000, 1343488, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x22000) = 0x7f2f12b50000 mmap(0x7f2f12c98000, 311296, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x16a000) = 0x7f2f12c98000 mmap(0x7f2f12ce5000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1b6000) = 0x7f2f12ce5000 mmap(0x7f2f12ceb000, 14336, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f2f12ceb000 close(3) = 0 arch_prctl(ARCH_SET_FS, 0x7f2f12cf0500) = 0 mprotect(0x7f2f12ce5000, 16384, PROT_READ) = 0 mprotect(0x56363b08b000, 4096, PROT_READ) = 0 mprotect(0x7f2f12d1f000, 4096, PROT_READ) = 0 munmap(0x7f2f12cf1000, 25186) = 0 openat(AT_FDCWD, "/etc/foo/config.json", O_RDONLY) = -1 ENOENT (No such file or directory) dup(2) = 3 fcntl(3, F_GETFL) = 0x2 (flags O_RDWR) brk(NULL) = 0x56363b3fb000 brk(0x56363b41c000) = 0x56363b41c000 fstat(3, {st_mode=S_IFCHR|0620, st_rdev=makedev(0x88, 0x8), ...}) = 0 write(3, "Error opening configuration file"..., 60) = 60 close(3) = 0 exit_group(1) = ? +++ exited with 1 +++
关于strace输出的整个第一页通常是启动的底层准备。 (有很多mmap , mprotect , brk调用诸如检测低级内存和显示动态库之类的东西。)实际上,在调试期间,最好从头读取strace输出。 底部是对write的调用,其中显示一条错误消息。 我们在上方查看,并且看到了第一个错误的系统调用- 引发 ENOENT错误(“未找到文件或目录”)的openat调用,试图打开/etc/foo/config.json 。 在这里,配置文件应该在这里。
这只是一个例子,但我想说90%的时间我都使用strace ,没有什么是更困难的事情了,不必这样做。 以下是完整的分步调试指南:
- 程序中出现错误的系统错误消息,对此感到沮丧
- 用strace重新启动程序
- 在跟踪结果中查找错误消息
- 往上走直到遇到第一个失败的系统调用
步骤4中的系统调用很可能会显示出问题所在。
小费
在显示更复杂的调试示例之前,我将告诉您一些有效使用strace的技巧:
男人是你的朋友
在许多* nix系统上,可以通过运行man syscalls获得内核系统调用的完整列表。 您将看到类似brk(2)的信息 ,这意味着您可以通过运行man 2 brk获得更多信息。
一个小耙子: man 2 fork向我展示了GNU libc中 fork()外壳的页面,事实证明这是使用clone()调用实现的。 如果您编写一个使用fork()并开始跟踪的程序,则fork调用的语义将保持不变-我不会找到fork调用,而是使用clone()代替它们。 仅当您开始将源与strace的输出进行比较时,这样的耙子才会引起混淆。
使用-o将输出保存到文件
strace可以生成大量输出,因此将跟踪结果存储在单独的文件中通常很有用(如上例所示)。 而且它有助于避免将程序输出与控制台中的strace输出混淆。
使用-s查看更多参数数据
您可能已经注意到,上述跟踪示例中未显示错误消息的后半部分。 这是因为strace默认情况下仅显示字符串参数的前32个字节。 如果您想查看更多内容,请在strace调用中添加-s 128之类的内容。
-y有助于跟踪文件\套接字\等等。
“一切都是文件”意味着* nix系统使用文件描述符执行所有I / O,无论它适用于文件,网络还是进程间通道。 这对于编程很方便,但是当您看到系统调用的跟踪结果中的常规读写操作时,很难跟踪实际发生的情况。
通过添加-u运算符,您可以强制strace在输出中注释每个文件描述符并指出其指向的内容。
使用-p **附加到已经运行的进程
从下面的示例可以看出,有时您需要跟踪已经运行的程序。 如果您知道它正在作为进程1337运行(例如,根据ps的结论),那么您可以像这样跟踪它:
$ strace -p 1337 ...system call trace output...
也许您需要root特权。
使用-f监视子进程
strace默认情况下仅跟踪一个进程。 如果此进程产生了子进程,则可以看到产生该子进程的系统调用,但是不会显示该子进程的系统调用。
如果您认为错误出在子进程中,请使用-f运算符,这将启用其跟踪。 缺点是结论会使您更加困惑。 当strace跟踪一个进程或一个线程时,它显示单个呼叫事件流。 当它一次跟踪多个进程时,您可能会看到调用的开始被<unfinished ...>消息打断,然后一堆对其他执行分支的调用,然后才是第一个带有<... foocall resumed>的结束 。 或者,也使用-ff运算符将所有跟踪结果分成不同的文件(有关详细信息, 请参见 strace 手册 )。
用-e过滤跟踪
如您所见,跟踪结果是所有可能的系统调用的真实结果。 使用-e标志,可以过滤跟踪(请参见strace manual )。 主要优势在于,运行带有过滤的跟踪要比进行完整跟踪然后执行grep更快。 老实说,我几乎总是不在乎。
并非所有的错误都是不好的
一个简单而常见的示例是程序一次在多个位置查找文件,例如在shell中查找,其中basket /目录包含一个可执行文件:
$ 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中的操作方式和操作,您将更容易理解跟踪系统调用的结果。 例如,如果您在调试对联网系统的调用时遇到麻烦,请查阅相同的经典Bija的“网络编程指南” 。
更复杂的调试示例
我已经说过,简单调试的示例就是大多数情况下我必须处理strace的示例。 但是,有时需要进行真正的调查,因此这是调试更复杂的真实示例。
bcron是任务处理调度程序,是* nix cron守护程序的另一种实现。 它安装在服务器上,但是当有人尝试编辑时间表时,会发生以下情况:
# crontab -e -u logs bcrontab: Fatal: Could not create temporary file
好的,因此bcron尝试写入某个文件,但该文件无法解决 ,他也不承认为什么。 发现strace :
# 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: logsagg\n20 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\0#Ansible: logsagg\n20 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 +++
最后,有一条写错误消息,但是这次有所不同。 首先,在此之前通常不会发生相关的系统调用错误。 其次,很明显,某人已经阅读了错误消息。 似乎真正的问题出在其他地方,而bcrontab只是播放消息。
如果查看man 2 read ,您会看到第一个参数(3)是* nix用于所有I / O处理的文件描述符。 如何找出文件描述符3代表什么? 在这种情况下,您可以使用-u运算符(请参见上文)运行strace ,它会自动告诉您,但是,为了计算这些信息,了解如何读取和分析跟踪结果很有用。
文件描述符的来源可以是许多系统调用中的一种(全部取决于控制台,网络套接字,文件本身或其他内容的描述符),但正是如此,我们正在寻找返回3(t .e。在跟踪结果中寻找“ = 3”)。 结果,其中有两个:顶部的openat和中间的socket 。 openat打开文件,但是在关闭 (3)之后将显示它再次关闭。 (耙:文件描述符在打开和关闭时可以重复使用)。 socket()调用是合适的,因为它是read()之前的最后一个调用,并且事实证明bcrontab通过套接字与某些东西一起工作。 下一行显示文件描述符沿路径/ var / run / bcron-spool与unix域套接字关联。
因此,另一方面,您需要找到附加到unix套接字的进程。 有两个不错的技巧可用于调试服务器部署。 第一种是使用netstat或更新的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))
这表明侦听器是与进程ID 20629一起使用的inixserver命令。(而且,巧合的是,它使用文件描述符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进程是一个长期存在的服务器,因此您可以使用strace -o / tmp / trace -p 20629之类的东西将strace附加到它。 如果我们在另一个终端中编辑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
(跟踪时,最后一个accept()将不会完成。)同样,令人遗憾的是,此结果不包含我们正在寻找的错误。 我们看不到bcrontag将发送到套接字或从套接字接收的任何消息。 而是完全控制该过程( clone , wait4 , SIGCHLD等)。此过程会产生一个子进程,您可能会猜到该子进程确实有效。 如果需要捕获她的踪迹,请在呼叫中添加strace -f 。 这是通过使用strace -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 +++
现在,这是东西。 尝试在路径tmp / spool.21470.1573692319.854640 (指当前工作目录)上创建文件时,进程21470收到“拒绝访问”错误。 如果我们仅知道当前的工作目录,那么我们将知道完整的路径,并且可以弄清楚为什么该进程无法在其中创建自己的临时文件。 不幸的是,该过程已经退出,因此您不能只使用lsof -p 21470查找当前目录,而是可以使用其他方法-查找可更改目录的PID 21470系统调用。 (如果没有,则PID 21470必须已从父级继承了它们,并且无法通过lsof -p找出 。)此系统调用为chdir (在现代网络搜索引擎的帮助下很容易找到)。 这是基于跟踪结果(直至PID 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 process control and shells上的文章 。)因此,PID 20629服务器未获得沿/var/spool/cron/tmp/spool.21470.1573692319.854640路径创建文件的权限。 , — . :
# 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 . ( , — SELinux AppArmor, dmesg .)
合计
, , , , — . , bcron , .
, , , strace , , . , strace . , .