在软件部署中使用 strace 进行调试 | Linux 中国

2024-02-20 14:38

本文主要是介绍在软件部署中使用 strace 进行调试 | Linux 中国,希望对大家解决编程问题提供一定的参考价值,需要的开发者们随着小编来一起学习吧!

很明显,我们能看到 CPU 主要被 clone 操作消耗了,还可以单独跟踪一下 clone:
shell> strace -T -e clone -p <PID>
通过「T」选项可以获取操作实际消耗的时间,通过「e」选项可以跟踪某个操作:

poll([{fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN}, {fd=14, events=POLLIN}, {fd=15, 
events=POLLIN}], 5, 25) = 2 ([{fd=5, revents=POLLIN}, {fd=15, revents=POLLIN}]) <0.000005>
poll([{fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN}, {fd=14, events=POLLIN}, {fd=15, 
events=POLLIN}], 5, 25) = 2 ([{fd=5, revents=POLLIN}, {fd=15, revents=POLLIN}]) <0.000005>
poll([{fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=7, events=POLLIN}, {fd=14, events=POLLIN}, {fd=15, 
events=POLLIN}], 5, 25) = 2 ([{fd=5, revents=POLLIN}, {fd=15, revents=POLLIN}]) <0.000005>

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

strace 可以生成很多输出,所以将输出保存到单独的文件是很有帮助的(就像上面的例子一样)。它还能够在控制台中避免程序自身的输出与 strace 的输出发生混淆。

使用 -s 查看更多的参数

你可能已经注意到,错误信息的第二部分没有出现在上面的例子中。这是因为 strace 默认仅显示字符串参数的前 32 个字节。如果你需要捕获更多参数,请向 strace 追加类似于-s 128 之类的参数。

-y 使得追踪文件或套接字更加容易

“一切皆文件”意味着 *nix 系统通过文件描述符进行所有 IO 操作,不管是真实的文件还是通过网络或者进程间管道。这对于编程而言是很方便的,但是在追踪系统调用时,你将很难分辨出readwrite 的真实行为。

-y参数使 strace 在注释中注明每个文件描述符的具体指向。

使用 -p 附加到正在运行的进程中

正如我们将在后面的例子中看到的,有时候你想追踪一个正在运行的程序。如果你知道这个程序的进程号为 1337 (可以通过 ps 查询),则可以这样操作:

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

使用 -f 追踪子进程

strace 默认只追踪一个进程。如果这个进程产生了一个子进程,你将会看到创建子进程的系统调用(一般是 clone),但是你看不到子进程内触发的任何调用。

如果你认为在子进程中存在错误,则需要使用-f参数启用子进程追踪功能。这样做的缺点是输出的内容会让人更加困惑。当追踪一个进程时,strace 显示的是单个调用事件流。

当追踪多个进程的时候,你将会看到以 <unfinished ...>开始的初始调用,接着是一系列针对其它线程的调用,最后才出现以<... foocall resumed>结束的初始调用。

此外,你可以使用 -ff参数将所有的调用分离到不同的文件中(查看 strace 手册 获取更多信息)。

使用 -e 进行过滤

正如你所看到的,默认的追踪输出是所有的系统调用。你可以使用-e 参数过滤你需要追踪的调用(查看 strace 手册)。这样做的好处是运行过滤后的 strace 比起使用 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
...

“错误信息之前的最后一次失败调用”这种启发式方法非常适合于查找错误。无论如何,自下而上地查找是有道理的。

一个更复杂的调试例子

就像我说的那样,简单的调试例子表现了我在大部分情况下如何使用 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 +++

在程序结束之前有一个 write 的错误信息,但是这次有些不同。首先,在此之前没有任何相关的失败系统调用。

其次,我们看到这个错误信息是由 read从别的地方读取而来的。这看起来像是真正的错误发生在别的地方,而bcrontab只是在转播这些信息。

如果你查阅了 man 2 read,你将会看到 read 的第一个参数 (3) 是一个文件描述符,这是 *nix 操作系统用于所有 IO 操作的句柄。

你该如何知道文件描述符 3 代表什么?在这种情况下,你可以使用-y参数运行strace(如上文所述),它将会在注释里告诉你文件描述符的具体指向,但是了解如何从上面这种输出中分析追踪结果是很有用的。

一个文件描述符可以来自于许多系统调用之一
(这取决于它是用于控制台、网络套接字还是真实文件等的描述符)
但不论如何,我们都可以搜索返回值为 3 的系统调用(例如,在strace 的输出中查找 =3)。

在这次 strace中可以看到有两个这样的调用:最上面的openat 以及中间的 socket

openat打开一个文件,但是紧接着的close(3)表明其已经被关闭。
(注意:文件描述符可以在打开并关闭后重复使用。)

所以 socket 调用才是与此相关的
(它是在read 之前的最后一个),
这告诉我们brcontab 正在与一个网络套接字通信。
在下一行,connect 表明文件描述符3 是一个连接到/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))

这告诉我们 /var/run/bcron-spool 套接字的监听程序是 unixserver 这个命令,它的进程 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 是一个常驻进程,所以我们可以使用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

(最后一个 accept 调用没有在追踪期间完成。)
不幸的是,这次追踪没有包含我们想要的错误信息。
我们没有观察到bcrontan往套接字发送或接受的任何信息。
然而,我们看到了很多进程管理操作(clonewait4SIGCHLD,等等)。
这个进程产生了子进程,我们猜测真实的工作是由子进程完成的。
如果我们想捕获子进程的追踪信息,就必须往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 +++

现在我们知道了进程 ID 21470 在尝试创建文件tmp/spool.21470.1573692319.854640(相对于当前的工作目录)时得到了一个没有权限的错误。
如果我们知道当前的工作目录,就可以得到完整路径并能指出为什么该进程无法在此处创建临时文件。
不幸的是,这个进程已经退出了,所以我们不能使用 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.1573692319.854640 创建文件。最可能的原因就是典型的 *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 正常工作。

这篇关于在软件部署中使用 strace 进行调试 | Linux 中国的文章就介绍到这儿,希望我们推荐的文章对编程师们有所帮助!



http://www.chinasem.cn/article/728553

相关文章

基于Linux的ffmpeg python的关键帧抽取

《基于Linux的ffmpegpython的关键帧抽取》本文主要介绍了基于Linux的ffmpegpython的关键帧抽取,实现以按帧或时间间隔抽取关键帧,文中通过示例代码介绍的非常详细,对大家的学... 目录1.FFmpeg的环境配置1) 创建一个虚拟环境envjavascript2) ffmpeg-py

python使用库爬取m3u8文件的示例

《python使用库爬取m3u8文件的示例》本文主要介绍了python使用库爬取m3u8文件的示例,可以使用requests、m3u8、ffmpeg等库,实现获取、解析、下载视频片段并合并等步骤,具有... 目录一、准备工作二、获取m3u8文件内容三、解析m3u8文件四、下载视频片段五、合并视频片段六、错误

gitlab安装及邮箱配置和常用使用方式

《gitlab安装及邮箱配置和常用使用方式》:本文主要介绍gitlab安装及邮箱配置和常用使用方式,具有很好的参考价值,希望对大家有所帮助,如有错误或未考虑完全的地方,望不吝赐教... 目录1.安装GitLab2.配置GitLab邮件服务3.GitLab的账号注册邮箱验证及其分组4.gitlab分支和标签的

SpringBoot3应用中集成和使用Spring Retry的实践记录

《SpringBoot3应用中集成和使用SpringRetry的实践记录》SpringRetry为SpringBoot3提供重试机制,支持注解和编程式两种方式,可配置重试策略与监听器,适用于临时性故... 目录1. 简介2. 环境准备3. 使用方式3.1 注解方式 基础使用自定义重试策略失败恢复机制注意事项

nginx启动命令和默认配置文件的使用

《nginx启动命令和默认配置文件的使用》:本文主要介绍nginx启动命令和默认配置文件的使用,具有很好的参考价值,希望对大家有所帮助,如有错误或未考虑完全的地方,望不吝赐教... 目录常见命令nginx.conf配置文件location匹配规则图片服务器总结常见命令# 默认配置文件启动./nginx

在Windows上使用qemu安装ubuntu24.04服务器的详细指南

《在Windows上使用qemu安装ubuntu24.04服务器的详细指南》本文介绍了在Windows上使用QEMU安装Ubuntu24.04的全流程:安装QEMU、准备ISO镜像、创建虚拟磁盘、配置... 目录1. 安装QEMU环境2. 准备Ubuntu 24.04镜像3. 启动QEMU安装Ubuntu4

使用Python和OpenCV库实现实时颜色识别系统

《使用Python和OpenCV库实现实时颜色识别系统》:本文主要介绍使用Python和OpenCV库实现的实时颜色识别系统,这个系统能够通过摄像头捕捉视频流,并在视频中指定区域内识别主要颜色(红... 目录一、引言二、系统概述三、代码解析1. 导入库2. 颜色识别函数3. 主程序循环四、HSV色彩空间详解

Windows下C++使用SQLitede的操作过程

《Windows下C++使用SQLitede的操作过程》本文介绍了Windows下C++使用SQLite的安装配置、CppSQLite库封装优势、核心功能(如数据库连接、事务管理)、跨平台支持及性能优... 目录Windows下C++使用SQLite1、安装2、代码示例CppSQLite:C++轻松操作SQ

Python常用命令提示符使用方法详解

《Python常用命令提示符使用方法详解》在学习python的过程中,我们需要用到命令提示符(CMD)进行环境的配置,:本文主要介绍Python常用命令提示符使用方法的相关资料,文中通过代码介绍的... 目录一、python环境基础命令【Windows】1、检查Python是否安装2、 查看Python的安

Python并行处理实战之如何使用ProcessPoolExecutor加速计算

《Python并行处理实战之如何使用ProcessPoolExecutor加速计算》Python提供了多种并行处理的方式,其中concurrent.futures模块的ProcessPoolExecu... 目录简介完整代码示例代码解释1. 导入必要的模块2. 定义处理函数3. 主函数4. 生成数字列表5.