Linux诊断神器—strace工具

 2018年3月9日 14:12   Nick王   运维    1 评论   336 浏览 


简介

strace命令是一个集诊断、调试、统计于一体的工具。

可以使用strace对应用的系统调用信号传递的跟踪结果来对应用进行分析,以达到解决问题或者是了解应用程序工作过程的目的。

当然strace与专业的调试工具比如说gdb之类的是没法相比的,因为它不是一个专业的调试器。

strace的最简单的用法就是执行一个指定的命令,在指定的命令结束之后它也就退出了。在命令执行的过程中,strace会记录和解析命令进程的所有系统调用以及这个进程所接收到的所有的信号值

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

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

参数总结

-c 统计每一系统调用的所执行的时间,次数和出错的次数等.-d 输出strace关于标准错误的调试信息. 
-f 跟踪由fork调用所产生的子进程. 
-ff 如果提供-o filename,则所有进程的跟踪结果输出到相应的filename.pid中,pid是各进程的进程号. 
-F 尝试跟踪vfork调用.在-f时,vfork不被跟踪. 
-h 输出简要的帮助信息. 
-i 输出系统调用的入口指针. 
-q 禁止输出关于脱离的消息. 
-r 打印出相对时间关于,每一个系统调用.
-t 在输出中的每一行前加上时间信息. 
-tt 在输出中的每一行前加上时间信息,微秒级.
-ttt 微秒级输出.
-v 输出所有的系统调用.一些调用关于环境变量,状态,输入输出等调用由于使用频繁,默认不输出.
-V 输出strace的版本信息. 
-x 以十六进制形式输出非标准字符串-xx 所有字符串以十六进制形式输出.
-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=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执行被跟踪的命令

特别提示:诊断的时候,可以先用 -c 参数,来统计查看,以确定哪个系统调用最耗时,接下来可以使用-e 参数,只追踪指定的系统调用。追踪的结果使用-o参数,重定向到文件,以便分析。

输出参数含义

$ strace cat /dev/null 
execve("/bin/cat", ["cat", "/dev/null"], [/* 23 vars */]) = 0
brk(0)                                  = 0xe91000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f10bce47000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY)      = 3
……省略……
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)                           = ?
+++ exited with 0 +++

每一行都是一条系统调用,等号左边是系统调用的函数名及其参数,右边是该调用的返回值。

strace 显示这些调用的参数并返回符号形式的值。

strace 从内核接收信息,而且不需要以任何特殊的方式来构建内核。

命令实例

通用的完整用法:

# strace -o output.txt -T -tt -e trace=all -p 28979

上面的含义是 跟踪28979进程的所有系统调用(-e trace=all),并统计系统调用的花费时间(-T),以及开始时间(并以可视化的时分秒格式显示)(-tt),最后将记录结果存在output.txt文件里面。

常用参数

通过一些简单实例了解strace的基本用法来熟悉他的常用参数。做一个简单的程序,这个简单的C语言程序代码如下:

# cat test.c
#include <stdio.h>

int main() {
    int a;
    scanf("%d", &a);
    printf("%09d\n", a);
    return 0;
}

然后我们通过gcc -o test test.c编译一下,得到一个可执行文件test,然后用 strace 调用执行。test 直接执行在执行期间会要求你输入一个整数,我们输入99,得到如下结果:

# ./test
99
000000099

追踪系统调用

通过strace执行test:

# strace ./test
execve("./test", ["./test"], [/* 24 vars */]) = 0
brk(0)                                  = 0x1c00000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5fed583000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY)      = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=18457, ...}) = 0
mmap(NULL, 18457, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f5fed57e000
close(3)                                = 0
open("/lib64/libc.so.6", O_RDONLY)      = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0p\356\1\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1920936, ...}) = 0
mmap(NULL, 3750152, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f5fecfd1000
mprotect(0x7f5fed15b000, 2097152, PROT_NONE) = 0
mmap(0x7f5fed35b000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x18a000) = 0x7f5fed35b000
mmap(0x7f5fed360000, 18696, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f5fed360000
close(3)                                = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5fed57d000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5fed57c000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5fed57b000
arch_prctl(ARCH_SET_FS, 0x7f5fed57c700) = 0
mprotect(0x7f5fed35b000, 16384, PROT_READ) = 0
mprotect(0x7f5fed584000, 4096, PROT_READ) = 0
munmap(0x7f5fed57e000, 18457)           = 0
fstat(0, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5fed582000
read(0, 99  ###############注意这里,系统会在这里等待我们的输入,99是我们自己输入的内容
"99\n", 1024)                   = 3
fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5fed581000
write(1, "000000099\n", 10000000099
)             = 10
exit_group(0)                           = ?
+++ exited with 0 +++

从strace结构可以看到,系统首先调用execve开始一个新的进程(execve在父进程中fork一个子进程,在子进程中调用exec函数启动新的程序),接着进行些环境的初始化操作,最后停顿在read(0,上面,这也就是执行到了我们的scanf函数,等待我们输入数字。

在输入完99之后,然后调用write函数将格式化后的数值000000099输出到屏幕,最后调用exit_group退出进行,完成整个程序的执行过程。

跟踪信号传递

我们还是使用上面的那个test程序,来观察进程接收信号的情况。还是先strace ./test,等到等待输入的画面的时候不要输入任何东西,然后打开另外一个窗口,输入如下的命令:

# killall test

这时候我们就看到我们的程序退出了,最后strace的结果如下:

# strace ./test
execve("./test", ["./test"], [/* 24 vars */]) = 0
brk(0)                                  = 0xeba000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f23e59ae000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY)      = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=18457, ...}) = 0
mmap(NULL, 18457, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f23e59a9000
close(3)                                = 0
open("/lib64/libc.so.6", O_RDONLY)      = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0p\356\1\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1920936, ...}) = 0
mmap(NULL, 3750152, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f23e53fc000
mprotect(0x7f23e5586000, 2097152, PROT_NONE) = 0
mmap(0x7f23e5786000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x18a000) = 0x7f23e5786000
mmap(0x7f23e578b000, 18696, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f23e578b000
close(3)                                = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f23e59a8000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f23e59a7000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f23e59a6000
arch_prctl(ARCH_SET_FS, 0x7f23e59a7700) = 0
mprotect(0x7f23e5786000, 16384, PROT_READ) = 0
mprotect(0x7f23e59af000, 4096, PROT_READ) = 0
munmap(0x7f23e59a9000, 18457)           = 0
fstat(0, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f23e59ad000
read(0, 0x7f23e59ad000, 1024)           = ? ERESTARTSYS (To be restarted if SA_RESTART is set)  #### 看这里
--- SIGTERM {si_signo=SIGTERM, si_code=SI_USER, si_pid=2432, si_uid=0} ---
+++ killed by SIGTERM +++

strace中很清楚的告诉你test进程+++ killed by SIGTERM +++

系统调用统计 -c 参数

strace不光能追踪系统调用,通过使用参数-c,它还能将进程所有的系统调用做一个统计分析给你,下面就来看看strace的统计,这次我们执行带-c参数的strace:

# strace -c dd if=/dev/zero of=t.data bs=1M count=20
20+0 records in
20+0 records out
20971520 bytes (21 MB) copied, 0.0251672 s, 833 MB/s
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 43.14    0.006491         282        23           write
 39.34    0.005919         493        12           close
 13.29    0.002000         143        14         5 open
  4.10    0.000617          25        25           read
  0.13    0.000020           3         7           mprotect
  0.00    0.000000           0         7           fstat
  0.00    0.000000           0         1           lseek
  0.00    0.000000           0        17           mmap
  0.00    0.000000           0         2           munmap
  0.00    0.000000           0         3           brk
  0.00    0.000000           0         6           rt_sigaction
  0.00    0.000000           0         1           rt_sigprocmask
  0.00    0.000000           0         1         1 access
  0.00    0.000000           0         2           dup2
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         1           getrlimit
  0.00    0.000000           0         1           arch_prctl
  0.00    0.000000           0         2         1 futex
  0.00    0.000000           0         1           set_tid_address
  0.00    0.000000           0         2           clock_gettime
  0.00    0.000000           0         1           set_robust_list
------ ----------- ----------- --------- --------- ----------------
100.00    0.015047                   130         7 total

这里很清楚的告诉你调用了那些系统函数,调用次数多少,消耗了多少时间等等这些信息,这个对我们分析一个程序来说是非常有用的。

重定向输出 -o参数

参数-o用在将strace的结果输出到文件中,如果不指定-o参数的话,默认的输出设备是STDERR,也就是说使用 -o filename 和 2>filename 的结果是一样的。

## 这两个命令都是将strace结果输出到文件test.txt中
# strace -c -o test.txt dd if=/dev/zero of=t.data bs=1M count=20
# strace -c dd if=/dev/zero of=t.data bs=1M count=20 2> test1.txt

对系统调用进行计时 -T 参数

strace可以使用参数-T将每个系统调用所花费的时间打印出来,每个调用的时间花销现在在调用行最右边的尖括号里面

例子:

# strace -T ls -lh
execve("/bin/ls", ["ls", "-lh"], [/* 24 vars */]) = 0 <0.000175>
brk(0)                                  = 0x1c16000 <0.000006>
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f3e9fa6d000 <0.000067>
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory) <0.000040>
open("/etc/ld.so.cache", O_RDONLY)      = 3 <0.000083>
……省略……
open("/etc/nsswitch.conf", O_RDONLY)    = 4 <0.000020>
fstat(4, {st_mode=S_IFREG|0644, st_size=1688, ...}) = 0 <0.000017>
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f3e9fa6b000 <0.000020>
read(4, "#\n# /etc/nsswitch.conf\n#\n# An ex"..., 4096) = 1688 <0.000021>
read(4, "", 4096)                       = 0 <0.000017>
close(4)                                = 0 <0.000017>
……省略……
lstat("test.txt", {st_mode=S_IFREG|0644, st_size=1502, ...}) = 0 <0.000020>
lgetxattr("test.txt", "security.selinux", "unconfined_u:object_r:admin_home_t:s0", 255) = 38 <0.000024>
lstat("test.txt", {st_mode=S_IFREG|0644, st_size=1502, ...}) = 0 <0.000018>
lgetxattr("test.txt", "system.posix_acl_access", 0x0, 0) = -1 ENODATA (No data available) <0.000022>
lgetxattr("test.txt", "system.posix_acl_default", 0x0, 0) = -1 ENODATA (No data available) <0.000052>
lstat("t.data", {st_mode=S_IFREG|0644, st_size=20971520, ...}) = 0 <0.000031>
lgetxattr("t.data", "security.selinux", "unconfined_u:object_r:admin_home_t:s0", 255) = 38 <0.000050>
lstat("t.data", {st_mode=S_IFREG|0644, st_size=20971520, ...}) = 0 <0.000007>
lgetxattr("t.data", "system.posix_acl_access", 0x0, 0) = -1 ENODATA (No data available) <0.000006>
lgetxattr("t.data", "system.posix_acl_default", 0x0, 0) = -1 ENODATA (No data available) <0.000005>
lstat("test1.txt", {st_mode=S_IFREG|0644, st_size=1588, ...}) = 0 <0.000006>
……省略……

系统调用的时间 -t 参数

这是一个很有用的功能,strace会将每次系统调用的发生时间记录下来,只要使用-t/tt/ttt三个参数就可以看到效果了,具体的例子可以自己去尝试。

参数名输出样式说明
-t10:33:04 exit_group(0)输出结果精确到秒
-tt10:33:48.159682 exit_group(0)输出结果精确到微妙
-ttt1262169244.788478 exit_group(0)精确到微妙,而且时间表示为unix时间戳

截断输出 -s 参数

-s参数用于指定strace结果的每一行输出的字符串的长度,下面看看test程序中-s参数对结果有什么影响,现指定-s为20,然后在read的时候我们输入一个超过20个字符的数字串

# strace -s 20 ./test
read(0, 2222222222222222222222222        // 我们输入的2一共有25个
"22222222222222222222"..., 1024) = 26       // 而我们看到的结果中2只有20个

strace一个现有的进程 -p 参数

strace不光能自己初始化一个进程进行strace,还能追踪现有的进程,参数-p就是取这个作用的,用法也很简单,具体如下:

# strace -p pid

限制strace只跟踪特定的系统调用 -e 参数

如果你已经知道你要找什么,你可以让strace只跟踪一些类型的系统调用。例如,你需要看看在configure脚本里面执行的程序,你需要监视的系统调用就是execve。让strace只记录execve的调用用这个命令:

# strace -f -o configure-strace.txt -e trace=execve ./configure





如无特殊说明,文章均为本站原创,转载请注明出处