使用 strace 调试软件部署

使用 strace 调试软件部署

我的日常工作主要是软件部署,这意味着我花了很多时间试图回答以下问题:

  • 该软件适用于开发人员,但不适用于我。 为什么?
  • 昨天这个软件对我有用,但今天不行了。 为什么?

这是一种与常规软件调试略有不同的调试。 常规调试是关于代码的逻辑,而部署调试是关于代码与环境之间的交互。 即使问题的根源是逻辑错误,但一切都在一台计算机上运行而不是在另一台计算机上运行的事实意味着问题在某种程度上存在于环境中。

因此,不要使用通常的调试工具,例如 GDB 我有一套不同的工具用于调试部署。 我最喜欢的工具用于处理“为什么这个软件不适合我?”之类的问题。 被称为 痕迹.

什么是 strace?

痕迹 是一个“系统调用跟踪”的工具。 它最初是为 Linux 创建的,但可以使用其他系统的工具来完成相同的调试技巧(跟踪 или 跟踪).

基本应用程序非常简单。 您只需要使用任何命令运行 strace,它就会转储所有系统调用(尽管首先您可能需要自己安装它) 痕迹):

$ strace echo Hello
...Snip lots of stuff...
write(1, "Hellon", 6)                  = 6
close(1)                                = 0
close(2)                                = 0
exit_group(0)                           = ?
+++ exited with 0 +++

这些系统调用是什么? 这有点像操作系统内核的 API。 曾几何时,软件可以直接访问其运行的硬件。 例如,如果它需要在屏幕上显示某些内容,它会使用视频设备的端口或内存映射寄存器进行播放。 当多任务计算机系统变得流行时,由于各种应用程序争夺硬件,混乱出现了。 一个应用程序中的错误可能会导致其他应用程序(甚至整个系统)瘫痪。 然后CPU中出现了特权模式(或“环保护”)。 内核成为最有特权的:它获得了对硬件的完全访问权限,从而产生了特权较低的应用程序,这些应用程序已经必须向内核请求访问权限才能通过系统调用与硬件进行交互。

在二进制级别,系统调用与简单的函数调用略有不同,但大多数程序都使用标准库中的包装器。 那些。 POSIX C 标准库包含函数调用 写(),其中包含系统调用的所有特定于体系结构的代码 .

使用 strace 调试软件部署

简而言之,应用程序与其环境(计算机系统)之间的任何交互都是通过系统调用进行的。 因此,当软件在一台机器上运行但在另一台机器上运行失败时,最好查看系统调用跟踪结果。 更具体地说,这里列出了可以使用系统调用跟踪进行分析的典型点:

  • 控制台输入/输出
  • 网络输入/输出
  • 文件系统访问和文件 I/O
  • 管理进程线程的生命周期
  • 低级内存管理
  • 访问特定设备驱动程序

何时使用 strace?

理论上, 痕迹 与用户空间中的任何程序一起使用,因为用户空间中的任何程序都必须进行系统调用。 它可以更有效地处理已编译的低级程序,但如果您可以消除来自运行时和解释器的额外噪音,它也可以处理 Python 等高级语言。

一切辉煌 痕迹 在调试在一台机器上运行良好的软件时,它会突然停止在另一台机器上运行,产生有关文件、权限的模糊消息,或者尝试执行某些命令或其他内容失败......很遗憾,但事实并非如此与证书验证错误等高级问题结合得很好。 通常这需要组合 痕迹有时 跟踪 和更高级别的工具(如命令行工具 openssl的 调试证书)。

我们将使用独立服务器作为示例,但系统调用跟踪通常可以在更复杂的部署平台上完成。 您只需要选择正确的工具即可。

简单调试示例

假设您想要运行令人惊叹的服务器应用程序 foo,这就是您最终得到的结果:

$ foo
Error opening configuration file: No such file or directory

显然它找不到你写的配置文件。 发生这种情况是因为有时当包管理器编译应用程序时,它们会覆盖预期的文件位置。 如果您遵循一个发行版的安装指南,那么在另一个发行版中您会发现文件与您预期的完全不同。 如果错误消息告诉我们在哪里查找配置文件,那么问题可能会在几秒钟内得到解决,但事实并非如此。 那么去哪里看呢?

如果您有权访问源代码,您可以阅读它并找出所有内容。 一个好的备份计划,但不是最快的解决方案。 您可以使用逐步调试器,例如 GDB 并查看程序的作用,但使用专门设计用于显示与环境交互的工具会更有效: 痕迹.

结论 痕迹 可能看起来多余,但好消息是大部分内容都可以安全地忽略。 使用 -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, "177ELF2113 3 > 1 260A2 "..., 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 +++

大约输出整个第一页 痕迹 - 这通常是发射的低级准备。 (很多电话 MMAP, 保护, BRK 用于检测低级内存和显示动态库之类的事情。)实际上,在调试输出期间 痕迹 最好从最后开始阅读。 下面会有一个挑战 ,它会显示一条错误消息。 我们看上面,看到第一个错误的系统调用——调用 打开,这会引发错误 恩诺恩 (“未找到文件或目录”)尝试打开 /etc/foo/config.json。 这是配置文件应该所在的位置。

这只是一个例子,但我想说 90% 的时间我都在使用 痕迹,没有什么比这更难做到的了。 以下是完整的分步调试指南:

  • 由于程序中出现有关系统错误的模糊消息而感到不安
  • 重新启动程序 痕迹
  • 在trace结果中找到错误信息
  • 走得更高,直到遇到第一个失败的系统调用

第 4 步中的系统调用很可能会揭示出了什么问题。

提示

在向您展示更复杂的调试示例之前,我将向您展示一些有效使用的技巧 痕迹:

男人是你的朋友

在许多 *nix 系统上,可以通过运行以下命令来获取对内核的系统调用的完整列表 人系统调用。 你会看到类似的东西 布尔克(2),这意味着可以通过运行获得更多信息 男子 2 布鲁克.

小耙子: 人2叉子 显示 shell 的页面 叉子() в GNU库,事实证明,这是通过调用来实现的 克隆()。 调用语义 如果您使用以下方式编写程序,则保持不变 叉子(),然后运行跟踪 - 我找不到任何调用 ,而不是他们将会有 克隆()。 如果您开始将源与输出进行比较,这样的耙子只会让您感到困惑 痕迹.

使用 -o 将输出保存到文件

痕迹 可以生成大量输出,因此将跟踪结果存储在单独的文件中通常很有用(如上例所示)。 这也有助于避免程序输出与输出混淆 痕迹 在控制台中。

使用 -s 查看更多参数数据

您可能已经注意到,错误消息的后半部分没有显示在上面的示例跟踪中。 这是因为 痕迹 默认仅显示字符串参数的前 32 个字节。 如果您想查看更多内容,请添加类似内容 -s 128 来电 痕迹.

-y 可以更轻松地跟踪文件、套接字等。

“全部都是文件”意味着 *nix 系统使用文件描述符执行所有 I/O,无论这适用于文件、网络还是进程间管道。 这对于编程来说很方便,但是当您看到常见的情况时,很难跟踪到底发生了什么 и 在系统调用跟踪结果中。

通过添加运算符 ÿ,你会强迫 痕迹 使用其指向的注释来注释输出中的每个文件描述符。

使用 -p** 附加到已经运行的进程

正如您将在下面的示例中看到的,有时您需要跟踪已经在运行的程序。 如果知道它正在作为进程 1337 运行(例如,从输出 ps),那么你可以像这样追踪它:

$ strace -p 1337
...system call trace output...

您可能需要 root 权限。

使用 -f 监视子进程

痕迹 默认情况下,它仅跟踪一个进程。 如果该进程生成子进程,则可以看到生成子进程的系统调用,但不会显示子进程的系统调用。

如果您认为错误出现在子进程中,请使用以下语句 -f,这将启用其跟踪。 这样做的缺点是输出会让你更加困惑。 什么时候 痕迹 跟踪一个进程或一个线程,它显示单个调用事件流。 当它同时跟踪多个进程时,您可能会看到调用的开始被消息中断 ,然后 - 对其他执行分支的一堆调用,然后 - 第一个执行分支结束 <...foocall 恢复>。 或者将所有跟踪结果拆分到不同的文件中,也使用运算符 -ff (详细信息在 指南痕迹).

使用 -e 过滤跟踪

正如您所看到的,跟踪的结果是所有可能的系统调用的真实堆积。 旗帜 -e 您可以过滤跟踪(请参阅 领导痕迹)。 主要优点是运行过滤跟踪比执行完整跟踪更快 grep的`在。 老实说,我几乎总是不在乎。

并非所有错误都是坏事

一个简单且常见的示例是程序同时在多个位置查找文件,就像 shell 查找包含可执行文件的目录一样:

$ 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 的网络编程指南.

更复杂的调试示例

我已经说过,简单调试的示例是我在使用时最需要处理的示例 痕迹。 然而,有时需要进行真正的调查,因此这里有一个更高级调试的现实示例。

布克伦 - 任务处理调度程序,*nix 守护进程的另一个实现 cron的。 它安装在服务器上,但是当有人尝试编辑时间表时,会发生以下情况:

# crontab -e -u logs
bcrontab: Fatal: Could not create temporary file

好吧,这意味着 布克伦 尝试写入某个文件,但没有成功,而且他不承认原因。 揭秘 痕迹:

# 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 +++

接近尾声时出现错误消息 ,但这一次有些不同。 首先,没有相关的系统调用错误,这种错误通常发生在这之前。 其次,很明显有人已经在某个地方阅读了错误消息。 看起来真正的问题在其他地方,并且 定时任务表 只是回放该消息。

如果你看看 人2读,您可以看到第一个参数 (3) 是一个文件描述符,*nix 将其用于所有 I/O 处理。 如何找出文件描述符 3 代表什么? 在这种特殊情况下,您可以运行 痕迹 西奥佩拉托罗姆 ÿ (见上文)它会自动告诉你,但要弄清楚这样的事情,了解如何读取和解析跟踪结果是很有用的。

文件描述符的源可以是许多系统调用之一(这完全取决于描述符的用途 - 控制台、网络套接字、文件本身或其他东西),但无论如何,我们都会寻找通过返回 3 进行调用(即我们在跟踪结果中查找“= 3”)。 在此结果中有 2 个: 打开 在最顶部和 插座 在中间。 打开 打开文件但是 关闭(3)然后将显示它再次关闭。 (Rake:文件描述符在打开和关闭时可以重用)。 称呼 插座() 合适,因为这是之前的最后一篇 读(),事实证明 bcrontab 通过套接字进行某些操作。 下一行显示文件描述符与 unix 域套接字 在路上 /var/run/bcron-spool.

因此,我们需要找到与 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))

这表明监听器是命令 UNIX服务器,以进程 ID 20629 运行。(巧合的是,它使用文件描述符 3 作为套接字。)

用于查找相同信息的第二个真正有用的工具称为 。 它列出了系统上所有打开的文件(或文件描述符)。 或者您可以获得有关某一特定文件的信息:

# 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。 如果您在另一个终端中编辑 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

(最后的 接受() 跟踪时不会完成。)同样,不幸的是,这个结果不包含我们正在查找的错误。 我们没有看到 bcrontag 向套接字发送或从套接字接收的任何消息。 相反,完整的过程控制(克隆, 等待4, 信号寄存器 等)此进程会生成一个子进程,正如您可能猜到的那样,该子进程执行真正的工作。 如果您需要追踪她的踪迹,请加入通话 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 +++

现在,就是这样。 进程 21470 尝试在路径创建文件时收到“访问被拒绝”错误 tmp/spool.21470.1573692319.854640 (与当前工作目录相关)。 如果我们只知道当前工作目录,我们也会知道完整路径,并能够找出进程无法在其中创建临时文件的原因。 不幸的是,该进程已经退出,所以你不能只使用 lsof -p 21470 为了找到当前目录,但您可以朝相反的方向工作 - 查找更改目录的 PID 21470 系统调用。 (如果没有,PID 21470一定是从它的父级继承了它们,这已经通过 lsof-p 找不到。)这个系统调用是 目录 (借助现代在线搜索引擎很容易找到)。 这是根据跟踪结果反向搜索的结果,一直到服务器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 进程管理和 shell.) 因此,服务器 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/ 将使 布克伦 正常工作。 (如果这不是问题,那么下一个最有可能的嫌疑是像 SELinux 或 AppArmor 这样的内核安全模块,所以我会检查内核消息日志 dmesg的.)

在总

系统调用跟踪对于初学者来说可能会让人不知所措,但我希望我已经证明它们是调试一整类常见部署问题的快速方法。 想象一下尝试调试多进程 布克伦使用逐步调试器。

沿着系统调用链向后解析跟踪结果需要技巧,但正如我所说,几乎总是使用 痕迹,我只是获取跟踪结果并从末尾开始查找错误。 反正, 痕迹 帮助我节省大量调试时间。 我希望它对你也有用。

来源: habr.com

添加评论