strace是一个集诊断、调试、统计与一体的工具,我们可以使用strace对应用的系统调用和信号传递的跟踪结果来对应用进行分析. strace的最简单的用法就是执行一个指定的命令,在指定的命令结束之后它也就退出了。在命令执行的过程中,strace会记录和解析命令进程的所有系统调用以及这个进程所接收到的所有的信号值。
现在我们做一个很简单的程序来演示strace的基本用法。这个程序的C语言代码如下:
# filename test.c
#include <stdio.h>
int main()
{
int a;
scanf("%d", &a);
printf("%09d\n", a);
return 0;
}
使用
gcc -o test test.c
编译得到test文件
执行期间会要求你输入一个整数,我们输入99,直接执行的结果
oracle@orainst[orcl]:~ $./test
99
000000099
通过strace执行test的结果
oracle@orainst[orcl]:~ $strace ./test
execve("./test", ["./test"], [/* 41 vars */]) = 0
uname({sys="Linux", node="orainst.desktop.mycompany.com", ...}) = 0
brk(0) = 0x8078000
fstat64(3, {st_mode=S_IFREG|0644, st_size=65900, ...}) = 0
old_mmap(NULL, 65900, PROT_READ, MAP_PRIVATE, 3, 0) = 0xbf5ef000
close(3) = 0
open("/lib/tls/libc.so.6", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\200X\1"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=1571692, ...}) = 0
old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xbf5ee000
old_mmap(NULL, 1275340, PROT_READ|PROT_EXEC, MAP_PRIVATE, 3, 0) = 0xa02000
old_mmap(0xb34000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 3, 0x132000) = 0xb34000
old_mmap(0xb37000, 9676, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb37000
close(3) = 0
set_thread_area({entry_number:-1 -> 6, base_addr:0xbf5ee740, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1, seg_not_present:0, useable:1}) = 0
munmap(0xbf5ef000, 65900) = 0
fstat64(0, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xbf5ff000
read(0, 99
"99\n", 1024) = 3
fstat64(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xbf5fe000
write(1, "000000099\n", 10000000099
) = 10
munmap(0xbf5fe000, 4096) = 0
exit_group(0) = ?
从trace结构可以看到,系统首先调用execve开始一个新的进程,接着进行些环境的初始化操作,最后停顿在”read(0,”上面,这也就是执行到了我们的scanf函数,等待我们输入数字呢,在输入完99之后,在调用write函数将格式化后的数值”000000099″输出到屏幕,最后调用exit_group退出进行,完成整个程序的执行过程。
还是使用上面的那个test程序,来观察进程接收信号的情况。 还是先strace ./test,等到等待输入的画面的时候不要输入任何东西,然后打开另外一个窗口,输入如下的命令
killall test
这时候就能看到我们的程序推出了,最后的trace结果如下:
oracle@orainst[orcl]:~
$strace ./test
execve("./test", ["./test"], [/* 41 vars */]) = 0
uname({sys="Linux", node="orainst.desktop.mycompany.com", ...}) = 0
brk(0) = 0x9ae2000
old_mmap(NULL, 65900, PROT_READ, MAP_PRIVATE, 3, 0) = 0xbf5ef000
close(3) = 0
open("/lib/tls/libc.so.6", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\200X\1"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=1571692, ...}) = 0
old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xbf5ee000
old_mmap(NULL, 1275340, PROT_READ|PROT_EXEC, MAP_PRIVATE, 3, 0) = 0x2e9000
old_mmap(0x41b000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 3, 0x132000) = 0x41b000
old_mmap(0x41e000, 9676, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x41e000
close(3) = 0
set_thread_area({entry_number:-1 -> 6, base_addr:0xbf5ee740, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1, seg_not_present:0, useable:1}) = 0
munmap(0xbf5ef000, 65900) = 0
fstat64(0, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xbf5ff000
read(0, 0xbf5ff000, 1024) = ? ERESTARTSYS (To be restarted)
--- SIGTERM (Terminated) @ 0 (0) ---
+++ killed by SIGTERM +++
trace中很清楚的告诉你test进程"+++ killed by SIGTERM +++"。
strace不光能追踪系统调用,通过使用参数-c,它还能将进程所有的系统调用做一个统计分析给你,下面就来看看strace的统计,这次我们执行带-c参数的strace:
strace -c ./test
最后能得到这样的trace结果:
oracle@orainst[orcl]:~
$strace -c ./test
execve("./test", ["./test"], [/* 41 vars */]) = 0
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
45.90 0.000140 5 27 25 open
34.43 0.000105 4 24 21 stat64
7.54 0.000023 5 5 old_mmap
2.62 0.000008 8 1 munmap
1.97 0.000006 6 1 uname
1.97 0.000006 2 3 fstat64
1.64 0.000005 3 2 1 read
1.31 0.000004 2 2 close
0.98 0.000003 3 1 brk
0.98 0.000003 3 1 mmap2
0.66 0.000002 2 1 set_thread_area
------ ----------- ----------- --------- --------- ----------------
100.00 0.000305 68 47 total
这里很清楚的告诉你调用了那些系统函数,调用次数多少,消耗了多少时间等等这些信息,这个对我们分析一个程序来说是非常有用的。
除了-c参数之外,strace还提供了其他有用的参数给我们,让我们能很方便的得到自己想要的信息,下面就对那些常用的参数一一做个介绍。
参数-o用在将strace的结果输出到文件中,如果不指定-o参数的话,默认的输出设备是STDERR,也就是说使用”-o filename”和” 2>filename”的结果是一样的。
这两个命令都是将strace结果输出到文件test.txt中
strace -c -o test.txt ./test
strace -c ./test 2>test.txt
strace可以使用参数-T将每个系统调用所花费的时间打印出来,每个调用的时间花销现在在调用行最右边的尖括号里面。
这是一个很有用的功能,strace会将每次系统调用的发生时间记录下来,只要使用-t/tt/ttt三个参数就可以看到效果了,具体的例子可以自己去尝试。
-t 输出结果精确到秒
-tt 输出结果精确到微妙
-ttt 精确到微妙,而且时间表示为unix时间戳
-s参数用于指定trace结果的每一行输出的字符串的长度,下面看看test程序中-s参数对结果有什么影响,现指定-s为20,我们输入的是25个2,但是看到的只有20个
strace -s 20 ./test
read(0, 2222222222222222222222222
"22222222222222222222"..., 1024) = 26
strace不光能自己初始化一个进程进行trace,还能追踪现有的进程,参数-p就是取这个作用的,用法也很简单,具体如下。
strace -p pid