文章目录
1. strace是什么?
按照strace官网的描述, strace是一个可用于诊断、调试和教学的Linux用户空间跟踪器。我们用它来监控用户空间进程和内核的交互,比如系统调用、信号传递、进程状态变更等。
strace底层使用内核的ptrace特性来实现其功能。
在运维的日常工作中,故障处理和问题诊断是个主要的内容,也是必备的技能。strace
作为一种动态跟踪工具,能够帮助运维高效地定位进程和服务故障。它像是一个侦探,通过系统调用的蛛丝马迹,告诉你异常的真相。
2. strace能做什么?
运维工程师都是实践派的人,我们还是先来个例子吧。
我们从别的机器copy了个叫做some_server的软件包过来,开发说直接启动就行,啥都不用改。可是尝试启动时却报错,根本起不来!
启动命令:
输出:
为什么起不来呢?从日志看,似乎是初始化日志文件失败,真相到底怎样呢?我们用strace来看看。
输出:
我们注意到,在输出InitLogFile failed错误的前一行,有个open系统调用:
它尝试打开文件/usr/local/apps/some_server/log//server_agent.log来写(不存在则创建),可是却出错了,返回码是-1, 系统错误号errorno为ENOENT。 查下open系统调用的手册页:
搜索ENOENT这个错误号errno的解释
这里说得比较清楚,因为我们例子中的open选项指定了O_CREAT选项,这里errno为ENOENT的原因是日志路径中某个部分不存在或者是一个失效的符号链接。我们来一级一级看下路径中的哪部分不存在:
原来是log子目录不存在!上层目录都是存在的。手工创建log子目录后,服务就能正常启动了。
回过头来, strace究竟能做什么呢?
它能够打开应用进程的这个黑盒,通过系统调用的线索,告诉你进程大概在干嘛。
3. strace怎么用?
既然strace是用来跟踪用户空间进程的系统调用和信号的,在进入strace使用的主题之前,我们的先理解什么是系统调用。
3.1 系统调用
按维基百科中的解释,在计算机中,系统调用(英语:system call),又称为系统呼叫,指运行在用户空间的程序向操作系统内核请求需要更高权限运行的服务。
系统调用提供用户程序与操作系统之间的接口。操作系统的进程空间分为用户空间
和内核空间
:
- 操作系统内核直接运行在硬件上,提供设备管理、内存管理、任务调度等功能。
- 用户空间通过API请求内核空间的服务来完成其功能——内核提供给用户空间的这些API, 就是系统调用。
在Linux系统上,应用代码通过glibc库封装的函数,间接使用系统调用。
Linux内核目前有300多个系统调用,详细的列表可以通过syscalls
手册页查看。这些系统调用主要分为几类:
- 文件和设备访问类 比如
open/close/read/write/chmod
等 - 进程管理类
fork/clone/execve/exit/getpid
等 - 信号类
signal/sigaction/kill
等 - 内存管理
brk/mmap/mlock
等 - 进程间通信IPC
shmget/semget *
信号量,共享内存,消息队列等 - 网络通信
socket/connect/sendto/sendmsg
等
熟悉Linux系统调用/系统编程,能够让我们在使用strace时得心应手。不过,对于运维的问题定位来说,知道strace这个工具,会查系统调用手册,就差不多够了。
想要深入了解的同学,建议阅读《Linux系统编程》, 《Unix环境高级编程》等书籍。
strace有两种运行模式。
一种是通过它启动要跟踪的进程。用法很简单,在原本的命令前加上strace即可。比如我们要跟踪 “ls -lh /var/log/messages
” 这个命令的执行,可以这样:
另外一种运行模式,是跟踪已经在运行的进程,在不中断进程执行的情况下,理解它在干嘛。 这种情况,给strace传递个-p pid 选项即可。
比如,有个在运行的some_server服务,第一步,查看pid:
得到其pid 17553然后就可以用strace跟踪其执行:
strace -p 17553
完成跟踪时,按ctrl + C 结束strace即可。
strace有一些选项可以调整其行为,我们这里介绍下其中几个比较常用的,然后通过示例讲解其实际应用效果。
3.2 strace常用选项
实例:跟踪nginx, 看其启动时都访问了哪些文件
4. strace问题定位案例
4.1 定位进程异常退出
问题:机器上有个叫做run.sh
的常驻脚本,运行一分钟后会死掉。需要查出死因。
定位:进程还在运行时,通过ps命令获取其pid, 假设我们得到的pid是24298
查看strace.log, 我们在最后2行看到如下内容:
这里可以看出,进程是被其他进程用KILL信号杀死的。
实际上,通过分析,我们发现机器上别的服务有个监控脚本,它监控一个也叫做run.sh的进程,当发现run.sh进程数大于2时,就会把它杀死重启。结果导致我们这个run.sh脚本被误杀。
进程被杀退出时,strace会输出killed by SIGX
(SIGX代表发送给进程的信号)等,那么,进程自己退出时会输出什么呢?
这里有个叫做test_exit的程序,其代码如下:
我们strace看下它退出时strace上能看到什么痕迹。
说明: -e trace=process 表示只跟踪和进程管理相关的系统调用。
输出:
可以看出,进程自己退出时(调用exit函数,或者从main函数返回), 最终调用的是exit_group
系统调用, 并且strace会输出exited with X
(X为退出码)。
可能有人会疑惑,代码里面明明调用的是exit, 怎么显示为exit_group?
这是因为这里的exit函数不是系统调用,而是glibc库提供的一个函数,exit函数的调用最终会转化为exit_group
系统调用,它会退出当前进程的所有线程。实际上,有一个叫做_exit()的系统调用(注意exit前面的下划线), 线程退出时最终会调用它。
4.2 定位共享内存异常
有个服务启动时报错:
错误日志大概告诉我们是获取共享内存出错,通过strace看下:
输出:
这里,我们通过-e trace=ipc
选项,让strace只跟踪和进程通信相关的系统调用。
从strace输出,我们知道是shmget系统调用出错了,errno是EINVAL。同样, 查询下shmget手册页,搜索EINVAL的错误码的说明:
翻译下,shmget设置EINVAL错误码的原因为下列之一:
要创建的共享内存段比 SHMMIN小 (一般是1个字节)
要创建的共享内存段比 SHMMAX 大 (内核参数kernel.shmmax配置)
指定key的共享内存段已存在,其大小和调用shmget时传递的值不同。
从strace输出看,我们要连的共享内存key 0x41400, 指定的大小是30097568
字节,明显与第1、2种情况不匹配。那只剩下第三种情况。使用ipcs看下是否真的是大小不匹配:
可以看到,已经0x41400这个key已经存在,并且其大小为30095516
字节,和我们调用参数中的30097568不匹配,于是产生了这个错误。
在我们这个案例里面,导致共享内存大小不一致的原因,是一组程序中,其中一个编译为32位,另外一个编译为64位,代码里面使用了long这个变长int数据类型。
把两个程序都编译为64解决了这个问题。
这里特别说下strace的-e trace选项。
要跟踪某个具体的系统调用,-e trace=xxx
即可。但有时候我们要跟踪一类系统调用,比如所有和文件名有关的调用、所有和内存分配有关的调用。
如果人工输入每一个具体的系统调用名称,可能容易遗漏。于是strace提供了几类常用的系统调用组合名字。
绝大多数情况,我们使用上面的组合名字就够了。实在需要跟踪具体的系统调用时,可能需要注意C库实现的差异。
比如我们知道创建进程使用的是fork系统调用,但在glibc里面,fork的调用实际上映射到了更底层的clone系统调用。使用strace时,得指定-e trace=clone
, 指定-e trace=fork
什么也匹配不上。
4.3 性能分析
假如有个需求,统计Linux 4.5.4 版本内核中的代码行数(包含汇编和C代码)。这里提供两个Shell脚本实现:
poor_script.sh:
good_script.sh:
两段代码实现的目的是一样的。 我们通过strace的-c选项来分别统计两种版本的系统调用情况和其所花的时间(使用-f同时统计子进程的情况)
从两个输出可以看出,good_script.sh
只需要2秒就可以得到结果:19613114
行。它大部分的调用(calls)开销是文件操作(read/open/write/close
)等,统计代码行数本来就是干这些事情。
而poor_script.sh
完成同样的任务则花了539
秒。它大部分的调用开销都在进程和内存管理上(wait4/mmap/getpid
…)。
实际上,从两个图中clone系统调用的次数,我们可以看出good_script.sh
只需要启动3个进程,而poor_script.sh
完成整个任务居然启动了126335个进程!
而进程创建和销毁的代价是相当高的,性能不差才怪。