Linux系统进程跟踪之strace命令
简介
GitHub：https://github.com/strace/strace
按照strace官网的描述，strace是一个可用于诊断、调试和教学的Linux用户空间跟踪器。我们用它来监控用户空间进程和内核的交互，比如系统调用、信号传递、进程状态变更等。
strace底层使用内核的ptrace特性来实现其功能。
在运维的日常工作中，故障处理和问题诊断是个主要的内容，也是必备的技能。strace作为一种动态跟踪工具，能够帮助运维高效地定位进程和服务故障。它像是一个侦探，通过系统调用的蛛丝马迹，告诉你异常的真相。
strace究竟能做什么呢？它能够打开应用进程的这个黑盒，通过系统调用的线索，告诉你进程大概在干嘛。
strace常用来跟踪进程执行时的系统调用和所接收的信号。 在Linux世界，进程不能直接访问硬件设备，当进程需要访问硬件设备(比如读取磁盘文件，接收网络数据等等)时，必须由用户态模式切换至内核态模式，通 过系统调用访问硬件设备。strace可以跟踪到一个进程产生的系统调用,包括参数，返回值，执行消耗的时间。
例如：
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 | root@ubuntu:/usr# strace cat /dev/null execve("/bin/cat", ["cat", "/dev/null"], [/* 22 vars */]) = 0 brk(0) = 0xab1000 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory) mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f29379a7000 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) ... brk(0) = 0xab1000 brk(0xad2000) = 0xad2000 fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0 open("/dev/null", O_RDONLY) = 3 fstat(3, {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 3), ...}) = 0 read(3, "", 32768) = 0 close(3) = 0 close(1) = 0 close(2) = 0 exit_group(0) = ? |
每一行都是一条系统调用，等号左边是系统调用的函数名及其参数，右边是该调用的返回值。
strace 显示这些调用的参数并返回符号形式的值。strace 从内核接收信息，而且不需要以任何特殊的方式来构建内核。
strace参数
安装：
1 2 3 4 | [root@docker35 ~]# which strace /usr/bin/strace [root@docker35 ~]# rpm -qf /usr/bin/strace strace-4.24-4.el7.x86_64 |
参数：
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 | -c 统计每一系统调用的所执行的时间,次数和出错的次数等. -d 输出strace关于标准错误的调试信息. -f 跟踪由fork调用所产生的子进程. -ff 如果提供-o filename,则所有进程的跟踪结果输出到相应的filename.pid中,pid是各进程的进程号. -F 尝试跟踪vfork调用.在-f时,vfork不被跟踪. -h 输出简要的帮助信息. -i 输出系统调用的入口指针. -q 禁止输出关于脱离的消息. -r 打印出相对时间关于,,每一个系统调用. -t 在输出中的每一行前加上时间信息. -tt 在输出中的每一行前加上时间信息,微秒级. -ttt 微秒级输出,以秒了表示时间. -T 显示每一调用所耗的时间. -v 输出所有的系统调用.一些调用关于环境变量,状态,输入输出等调用由于使用频繁,默认不输出. -V 输出strace的版本信息. -x 以十六进制形式输出非标准字符串 -xx 所有字符串以十六进制形式输出. -a column 设置返回值的输出位置.默认 为40. -e expr 指定一个表达式,用来控制如何跟踪.格式如下: [qualifier=][!]value1[,value2]... qualifier只能是 trace,abbrev,verbose,raw,signal,read,write其中之一.value是用来限定的符号或数字.默认的 qualifier是 trace.感叹号是否定符号.例如: -eopen等价于 -e trace=open,表示只跟踪open调用.而-etrace!=open表示跟踪除了open以外的其他调用.有两个特殊的符号 all 和 none. 注意有些shell使用!来执行历史记录里的命令,所以要使用\\. -e trace=set 只跟踪指定的系统 调用.例如:-e trace=open,close,rean,write表示只跟踪这四个系统调用.默认的为set=all. -e trace=file 只跟踪有关文件操作的系统调用. -e trace=process 只跟踪有关进程控制的系统调用. -e trace=network 跟踪与网络有关的所有系统调用. -e strace=signal 跟踪所有与系统信号有关的 系统调用 -e trace=ipc 跟踪所有与进程通讯有关的系统调用 -e abbrev=set 设定 strace输出的系统调用的结果集.-v 等与 abbrev=none.默认为abbrev=all. -e raw=set 将指 定的系统调用的参数以十六进制显示. -e signal=set 指定跟踪的系统信号.默认为all.如 signal=!SIGIO(或者signal=!io),表示不跟踪SIGIO信号. -e read=set 输出从指定文件中读出 的数据.例如: -e read=3,5 -e write=set 输出写入到指定文件中的数据. -o filename 将strace的输出写入文件filename -p pid 跟踪指定的进程pid. -s strsize 指定输出的字符串的最大长度.默认为32.文件名一直全部输出. -u username 以username 的UID和GID执行被跟踪的命令 |
通用的完整用法
1 | strace -o output.txt -T -tt -e trace=all -p 28979 |
上面的含义是 跟踪28979进程的所有系统调用（-e trace=all），并统计系统调用的花费时间，以及开始时间（并以可视化的时分秒格式显示），最后将记录结果存在output.txt文件里面。
其它用法
1 2 3 4 5 6 7 8 9 | -- linux 跟踪sqlplus进程 strace -o /tmp/output.txt -T -tt -e trace=all sqlplus / as sysdba strace -t -p 4545 -- Unix 跟踪sqlplus进程 truss -dfaie -o /tmp/sched_trace.out.02271 sqlplus '/as sysdba' |
限制strace只跟踪特定的系统调用
如果你已经知道你要找什么，你可以让strace只跟踪一些类型的系统调用。例如，你需要看看在configure脚本里面执行的程序，你需要监视的系统调 用就是execve。让strace只记录execve的调用用这个命令：
1 | strace -f -o configure-strace.txt -e execve ./configure |
strace问题定位案例
定位进程异常退出
问题：机器上有个叫做run.sh的常驻脚本，运行一分钟后会死掉。需要查出死因。
定位：进程还在运行时，通过ps命令获取其pid, 假设我们得到的pid是24298
1 | strace -o strace.log -tt -p 24298 |
查看strace.log, 我们在最后2行看到如下内容:
1 2 | 22:47:42.803937 wait4(-1, <unfinished ...> 22:47:43.228422 +++ killed by SIGKILL +++ |
这里可以看出，进程是被其他进程用KILL信号杀死的。
实际上，通过分析，我们发现机器上别的服务有个监控脚本，它监控一个也叫做run.sh的进程，当发现run.sh进程数大于2时，就会把它杀死重启。结果导致我们这个run.sh脚本被误杀。
进程被杀退出时，strace会输出killed by SIGX(SIGX代表发送给进程的信号)等，那么，进程自己退出时会输出什么呢？
这里有个叫做test_exit的程序，其代码如下:
1 2 3 4 5 6 | #include <stdio.h> #include <stdlib.h> int main(int argc, char **argv) { exit(1); } |
我们strace看下它退出时strace上能看到什么痕迹。
1 | strace -tt -e trace=process -f ./test_exit |
说明: -e trace=process 表示只跟踪和进程管理相关的系统调用。
输出：
1 2 3 4 | 23:07:24.672849 execve("./test_exit", ["./test_exit"], [/* 35 vars */]) = 0 23:07:24.674665 arch_prctl(ARCH_SET_FS, 0x7f1c0eca7740) = 0 23:07:24.675108 exit_group(1) = ? 23:07:24.675259 +++ exited with 1 +++ |
可以看出，进程自己退出时（调用exit函数，或者从main函数返回）, 最终调用的是exit_group系统调用， 并且strace会输出exited with X（X为退出码）。
可能有人会疑惑，代码里面明明调用的是exit, 怎么显示为exit_group?
这是因为这里的exit函数不是系统调用，而是glibc库提供的一个函数，exit函数的调用最终会转化为exit_group系统调用，它会退出当前进程的所有线程。实际上，有一个叫做_exit()的系统调用(注意exit前面的下划线), 线程退出时最终会调用它。
定位共享内存异常
有个服务启动时报错：
1 2 | shmget 267264 30097568: Invalid argument Can not get shm...exit! |
错误日志大概告诉我们是获取共享内存出错，通过strace看下：
1 | strace -tt -f -e trace=ipc ./a_mon_svr ../conf/a_mon_svr.conf |
输出：
1 2 3 4 5 6 | 22:46:36.351798 shmget(0x5feb, 12000, 0666) = 0 22:46:36.351939 shmat(0, 0, 0) = ? Process 21406 attached 22:46:36.355439 shmget(0x41400, 30097568, 0666) = -1 EINVAL (Invalid argument) shmget 267264 30097568: Invalid argument Can not get shm...exit! |
这里，我们通过-e trace=ipc 选项，让strace只跟踪和进程通信相关的系统调用。
从strace输出，我们知道是shmget系统调用出错了，errno是EINVAL。同样， 查询下shmget手册页，搜索EINVAL的错误码的说明:
EINVAL A new segment was to be created and size < SHMMIN or size > SHMMAX, or no new segment was to be created, a segment with given key existed, but size is greater than the size of that segment
翻译下，shmget设置EINVAL错误码的原因为下列之一：
- 要创建的共享内存段比 SHMMIN小 (一般是1个字节)
- 要创建的共享内存段比 SHMMAX 大 (内核参数kernel.shmmax配置)
- 指定key的共享内存段已存在，其大小和调用shmget时传递的值不同。
从strace输出看，我们要连的共享内存key 0x41400, 指定的大小是30097568字节，明显与第1、2种情况不匹配。那只剩下第三种情况。使用ipcs看下是否真的是大小不匹配：
1 2 3 | ipcs -m | grep 41400 key shmid owner perms bytes nattch status 0x00041400 1015822 root 666 30095516 1 |
可以看到，已经0x41400这个key已经存在，并且其大小为30095516字节，和我们调用参数中的30097568不匹配，于是产生了这个错误。
在我们这个案例里面，导致共享内存大小不一致的原因，是一组程序中，其中一个编译为32位，另外一个编译为64位,代码里面使用了long这个变长int数据类型。
把两个程序都编译为64解决了这个问题。
这里特别说下strace的-e trace选项。
要跟踪某个具体的系统调用，-e trace=xxx即可。但有时候我们要跟踪一类系统调用，比如所有和文件名有关的调用、所有和内存分配有关的调用。
如果人工输入每一个具体的系统调用名称，可能容易遗漏。于是strace提供了几类常用的系统调用组合名字。
-e trace=file 跟踪和文件访问相关的调用(参数中有文件名)
-e trace=process 和进程管理相关的调用，比如fork/exec/exit_group
-e trace=network 和网络通信相关的调用，比如socket/sendto/connect
-e trace=signal 信号发送和处理相关，比如kill/sigaction
-e trace=desc 和文件描述符相关，比如write/read/select/epoll等
-e trace=ipc 进程见同学相关，比如shmget等
绝大多数情况，我们使用上面的组合名字就够了。实在需要跟踪具体的系统调用时，可能需要注意C库实现的差异。
比如我们知道创建进程使用的是fork系统调用，但在glibc里面，fork的调用实际上映射到了更底层的clone系统调用。使用strace时，得指定-e trace=clone, 指定-e trace=fork什么也匹配不上。
性能分析
假如有个需求，统计Linux 4.5.4 版本内核中的代码行数(包含汇编和C代码)。这里提供两个Shell脚本实现：
poor_script.sh:
1 2 3 4 5 6 7 8 9 | !/bin/bash total_line=0 while read filename; do line=$(wc -l $filename | awk ‘{print $1}’) (( total_line += line )) done < <( find linux-4.5.4 -type f ( -iname ‘.c’ -o -iname ‘.h’ -o -iname ‘*.S’ ) ) echo “total line: $total_line” |
good_script.sh:
1 2 3 4 5 | !/bin/bash find linux-4.5.4 -type f ( -iname ‘.c’ -o -iname ‘.h’ -o -iname ‘*.S’ ) -print0 \ | wc -l —files0-from - | tail -n 1 |
两段代码实现的目的是一样的。 我们通过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个进程！
而进程创建和销毁的代价是相当高的，性能不差才怪。
解决库依赖问题
starce 的另一个用处是解决和动态库相关的问题。当对一个可执行文件运行ldd时，它会告诉你程序使用的动态库和找到动态库的位置。但是如果你正在使用一个比较老 的glibc版本（2.2或更早），你可能会有一个有bug的ldd程序，它可能会报告在一个目录下发现一个动态库，但是真正运行程序时动态连接程序 （/lib/ld-linux.so.2）却可能到另外一个目录去找动态连接库。这通常因为/etc/ld.so.conf和 /etc/ld.so.cache文件不一致，或者/etc/ld.so.cache被破坏。在glibc 2.3.2版本上这个错误不会出现，可能ld-linux的这个bug已经被解决了。
尽管这样，ldd并不能把所有程序依赖的动态库列出 来，系统调用dlopen可以在需要的时候自动调入需要的动态库，而这些库可能不会被ldd列出来。作为glibc的一部分的NSS（Name Server Switch）库就是一个典型的例子，NSS的一个作用就是告诉应用程序到哪里去寻找系统帐号数据库。应用程序不会直接连接到NSS库，glibc则会通 过dlopen自动调入NSS库。如果这样的库偶然丢失，你不会被告知存在库依赖问题，但这样的程序就无法通过用户名解析得到用户ID了。让我们看一个例子：
whoami程序会给出你自己的用户名，这个程序在一些需要知道运行程序的真正用户的脚本程序里面非常有用，whoami的一个示例 输出如下：
1 2 | # whoami root |
假设因为某种原因在升 级glibc的过程中负责用户名和用户ID转换的库NSS丢失，我们可以通过把nss库改名来模拟这个环境：
1 2 3 | # mv /lib/libnss_files.so.2 /lib/libnss_files.so.2.backup # whoami whoami: cannot find username for UID 0 |
这里你可以看到，运行whoami时出现了错误，ldd程序的输出不会提供有用的帮助：
1 2 3 | # ldd /usr/bin/whoami libc.so.6 => /lib/libc.so.6 (0x4001f000) /lib/ld-linux.so.2 => /lib/ld-linux.so.2 (0x40000000) |
你只会看到whoami依赖Libc.so.6和ld-linux.so.2，它没有给出运行whoami所必须的其他库。这里时用strace跟踪 whoami时的输出：
1 2 3 4 5 6 7 8 9 10 11 12 13 14 | strace -o whoami-strace.txt whoami open("/lib/libnss_files.so.2", O_RDONLY) = -1 ENOENT (No such file or directory) open("/lib/i686/mmx/libnss_files.so.2", O_RDONLY) = -1 ENOENT (No such file or directory) stat64("/lib/i686/mmx", 0xbffff190) = -1 ENOENT (No such file or directory) open("/lib/i686/libnss_files.so.2", O_RDONLY) = -1 ENOENT (No such file or directory) stat64("/lib/i686", 0xbffff190) = -1 ENOENT (No such file or directory) open("/lib/mmx/libnss_files.so.2", O_RDONLY) = -1 ENOENT (No such file or directory) stat64("/lib/mmx", 0xbffff190) = -1 ENOENT (No such file or directory) open("/lib/libnss_files.so.2", O_RDONLY) = -1 ENOENT (No such file or directory) stat64("/lib", {st_mode=S_IFDIR|0755, st_size=2352, ...}) = 0 open("/usr/lib/i686/mmx/libnss_files.so.2", O_RDONLY) = -1 ENOENT (No such file or directory) stat64("/usr/lib/i686/mmx", 0xbffff190) = -1 ENOENT (No such file or directory) open("/usr/lib/i686/libnss_files.so.2", O_RDONLY) = -1 ENOENT (No such file or directory) |
你可以发现在不同目录下面查找libnss.so.2的尝试，但是都失败了。如果没有strace这样的工具，很难发现这个错误是由于缺少动态库造成的。现 在只需要找到libnss.so.2并把它放回到正确的位置就可以了。
总结
当发现进程或服务异常时，我们可以通过strace来跟踪其系统调用，“看看它在干啥”，进而找到异常的原因。熟悉常用系统调用，能够更好地理解和使用strace。
当然，万能的strace也不是真正的万能。当目标进程卡死在用户态时，strace就没有输出了。
这个时候我们需要其他的跟踪手段，比如gdb/perf/SystemTap等。
