使用strace命令跟踪系统调用

时间:2023-03-08 20:32:00
使用strace命令跟踪系统调用

一、什么是strace

strace常用来跟踪进程执行时的系统调用和所接收的信号。

在Linux世界,进程不能直接访问硬件设备,当进程需要访问硬件设备(比如读取磁盘文件,接收网络数据等等)时,必须由用户态模式切换至内核态模式,通过系统调用访问硬件设备。

strace可以跟踪到一个进程产生的系统调用,包括参数,返回值,执行消耗的时间。

什么是系统调用

系统调用(英语:system call),又称为系统呼叫,指运行在用户空间的程序向操作系统内核请求需要更高权限运行的服务。

系统调用提供用户程序与操作系统之间的接口。操作系统的进程空间分为用户空间和内核空间:

  • 操作系统内核直接运行在硬件上,提供设备管理、内存管理、任务调度等功能。
  • 用户空间通过API请求内核空间的服务来完成其功能——内核提供给用户空间的这些API, 就是系统调用

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 等
其他

查看系统调用帮助手册 man 2 函数名,例如

man 2 open
man 2 fstat
man 2 poll

附:linux系统调用表

strace的应用场景

  • 基于特定的系统调用或系统调用组进行过滤
  • 通过统计特定系统调用的使用次数,所花费的时间,以及成功和错误的数量来分析系统调用的使用。
  • 它跟踪发送到进程的信号。
  • 通过pid附加到任何正在运行的进程。
  • 调试性能问题,查看系统调用的频率,找出耗时的程序段
  • 查看程序读取的是哪些文件从而定位比如配置文件加载错误问题
  • 查看某个php脚本长时间运行“假死”情况
  • 当程序出现“Out of memory”时被系统发出的SIGKILL信息所kill
  • 另外因为strace拿到的是系统调用相关信息,一般也即是IO操作信息,这个对于排查比如cpu占用100%问题是无能为力的。这个时候就可以使用GDB工具了。

二、快速入门

strace有两种运行模式

  • 1.通过它启动要跟踪的进程,在原本的命令前加上strace

    如我们要跟踪docker ps这个执行
    strace docker ps
  • 2.跟踪已经运行的进程。传递一个-p pid选项

    如有一个python程序的pid为7067,可以这样跟踪
    strace -p 7067

三、常用参数

从一个示例命令查看

strace -tt -T -v -f -e trace=file -o /data/log/strace.log -s 1024 -p 23489

-c 统计每一系统调用的所执行的时间,次数和出错的次数等.
-d 输出strace关于标准错误的调试信息.
-f 除了跟踪当前进程外,还跟踪由fork调用所产生的子进程.
-ff 如果提供-o filename,则所有进程的跟踪结果输出到相应的filename.pid中,pid是各进程的进程号.
-F 尝试跟踪vfork调用.在-f时,vfork不被跟踪.
-h 输出简要的帮助信息.
-i 输出系统调用的入口指针寄存器值.
-q 禁止输出关于结合(attaching)、脱离(detaching)的消息,当输出重定向到一个文件时,自动抑制此类消息.
-r 打印出相对时间关于每一个系统调用,即连续的系统调用起点之间的时间差,与-t对应.
-t 打印各个系统调用被调用时的绝对时间秒级,观察程序各部分的执行时间可以用此选项。
-tt 在输出中的每一行前加上时间信息,微秒级.
-ttt 在每行输出前添加相对时间信息,格式为”自纪元时间起经历的秒数.微秒数”
-T 显示每一调用所耗的时间,其时间开销在输出行最右侧的尖括号内.
-v 冗余显示模式:显示系统调用中argv[]envp[]stat、termio(s)等数组/结构体参数所有的元素/成员内容.
-V 输出strace的版本信息.
-x 以十六进制形式输出非标准字符串 。
-xx 所有字符串以十六进制形式输出.
-a column 设置返回值的输出位置.默认为40,即"="出现在第40列.
-e expr 指定一个表达式,用来控制如何跟踪.
-e trace=set 只跟踪指定的系统 调用.例如:-e trace=open.
-e trace=file 只跟踪有关文件操作的系统调用.
-e trace=process 只跟踪有关进程控制的系统调用.
-e trace=network 跟踪与网络有关的所有系统调用.
-e trace=signal 跟踪所有与系统信号有关的系统调用
-e trace=ipc 跟踪所有与进程通讯有关的系统调用
-e abbrev=set 设定 strace输出的系统调用的结果集.-v 等与 abbrev=none.默认为abbrev=all.
-e raw=set 将指 定的系统调用的参数以十六进制显示.
-e signal=set 指定跟踪的系统信号.默认为all.如signal=!SIGIO,表示不跟踪SIGIO信号.
-e read=set 输出从指定文件中读出 的数据.例如: -e read=3,5 -e write=set
-E var 从命令的环境变量列表中移除var。
-E var=val 将var=val放入命令的环境变量列表.
-o filename 将strace的输出写入文件filename,而不是显示到标准错误输出(stderr).
-p pid 跟踪指定的进程pid,可指定多达32个(-p pid)选项以同时跟踪多个进程。该选项常用于调试后台进程.
-s strsize 限制每行输出中字符串(如read参数)的最大显示长度,默认32字节。但文件名总是完整显示
-S sortby 按指定规则对-c选项的输出直方图进行排序。sortby取值可为time、calls、name和nothing(默认 time)
-u username 以username 的UID和GID执行被跟踪的命令

四、实用示例

1.跟踪redis-server, 看其启动时都访问了哪些文件

strace -tt -T -f -e trace=file -o /home/chenqionghe/log/strace.log -s 1024 redis-server

日志文件如下

15711 10:18:06.423843 execve("/usr/bin/redis-server", ["redis-server"], 0x7ffe3e8af6c8 /* 25 vars */) = 0 <0.000203>
15711 10:18:06.424317 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory) <0.000053>
15711 10:18:06.424442 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) <0.000041>
15711 10:18:06.424584 openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 <0.000055>
15711 10:18:06.424819 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory) <0.000020>
15711 10:18:06.424904 openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libm.so.6", O_RDONLY|O_CLOEXEC) = 3 <0.000053>
15711 10:18:06.425282 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory) <0.000051>
15711 10:18:06.425425 openat(AT_FDCWD, "/usr/lib/x86_64-linux-gnu/libjemalloc.so.1", O_RDONLY|O_CLOEXEC) = 3 <0.000027>
15711 10:18:06.425865 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory) <0.000026>

2.找出程序在启动时读取的配置文件

bash-4.4# strace php 2>&1 | grep php.ini
open("/usr/bin/php.ini", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/etc/php7/php.ini", O_RDONLY) = 3

3.定位进程异常退出

问题:机器上有个叫做run.sh的常驻脚本,运行一分钟后会死掉。需要查出死因。

定位:进程还在运行时,通过ps命令获取其pid, 假设我们得到的pid是24298

strace -o strace.log -tt -p 24298

查看strace.log, 我们在最后2行看到如下内容:

22:47:42.803937 wait4(-1,  <unfinished ...>
22:47:43.228422 +++ killed by SIGKILL +++

这里可以看出,进程是被其他进程用KILL信号杀死的。

进程自己退出时是调用exit_group,如下

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

4.定位共享内存异常

有个服务启动时报错:

shmget 267264 30097568: Invalid argument
Can not get shm...exit!

错误日志大概告诉我们是获取共享内存出错,通过strace看下:

strace -tt -f -e trace=ipc ./a_mon_svr     ../conf/a_mon_svr.conf

输出:

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看下是否真的是大小不匹配:

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解决了这个问题。

参考链接

Linux系统调用列表

https://www.ibm.com/developerworks/cn/linux/kernel/syscall/part1/appendix.html

strace参数含义

https://www.cnblogs.com/duanxz/p/6012768.html

strace用法详解

https://www.linuxidc.com/Linux/2018-01/150654.htm

strace工具使用手册

https://blog.csdn.net/Huangxiang6/article/details/81295752