由于我调整了博客的样式表,把代码样式表的折叠按钮隐藏掉了,如果想折叠代码按下F5刷新网页 #^_^。我极力反对在博客上贴代码,但是有时候有为了把问题阐述明白,有不得不去贴些代码。
简介
strace工具作为分析应用程序的行为的工具,对开发者,学习者,内核黑客,好奇心过重的人,具有非常,非常高的使用价值。相关工具套件有:strace,ltrace.strace用来跟踪应用程序和操作系统分界点,而ltrace用来跟踪应用程序和库文件的分界点。
strace功能概述
strace用来分析系统和应用程序的边界,即系统调用和信号。优点是不用重新编译被跟踪的应用程序和所在的内核。只需要安装一个strace包即可。下面先阐述strace在跟踪系统调用时能做什么,然后举例说明怎么做。然后阐述strace不能做什么
跟踪系统是能做的事情如下:
1.能够跟踪到每个系统调用的名字,并按系统调用在应用程序执行路径上发生的先后顺序打印结果。如下,用strace 跟中"cat 1“命令可以看到在cat运行整个生命期间发起的系统调用,并从上到下按系统调用发生的先后顺序打印结果。
2.能打印出系统调用的入参,出参,以及返回值,这里出参,是用来接收系统调用返回数据的buffer,例如:ssize_t read(int fd, void *buf, size_t count);的buf中的内容。
[root@localhost /]# ls -al 1
-rw-r--r--. 1 root root 29 Dec 7 08:54 1
[root@localhost /]# cat 1
aaaaaaaaaaaaaaaaaaaaaaaaaaaa
[root@localhost /]# strace cat 1
execve("/usr/bin/cat", ["cat", "1"], [/* 25 vars */]) = 0 //execv加载cat二进制,下面都是些动态链接库的加载过程
brk(0) = 0x7d1000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8b2f28a000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)//对返回失败的结果附加了文字说明
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=35311, ...}) = 0
mmap(NULL, 35311, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f8b2f281000
close(3) = 0
open("/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@\34\2\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=2116736, ...}) = 0
mmap(NULL, 3932672, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f8b2ecab000
mprotect(0x7f8b2ee61000, 2097152, PROT_NONE) = 0
mmap(0x7f8b2f061000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1b6000) = 0x7f8b2f061000
mmap(0x7f8b2f067000, 16896, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f8b2f067000
close(3) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8b2f280000
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8b2f27e000
arch_prctl(ARCH_SET_FS, 0x7f8b2f27e740) = 0
mprotect(0x7f8b2f061000, 16384, PROT_READ) = 0
mprotect(0x60b000, 4096, PROT_READ) = 0
mprotect(0x7f8b2f28b000, 4096, PROT_READ) = 0
munmap(0x7f8b2f281000, 35311) = 0
brk(0) = 0x7d1000
brk(0x7f2000) = 0x7f2000
brk(0) = 0x7f2000
open("/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=106070960, ...}) = 0
mmap(NULL, 106070960, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f8b28782000
close(3) = 0
fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 7), ...}) = 0
open("1", O_RDONLY) = 3 //打开文件1,返回文件句柄3(特意说明下O_RDONLY,strace友好的将bit解析成了宏名)
fstat(3, {st_mode=S_IFREG|0644, st_size=29, ...}) = 0
fadvise64(3, 0, 0, POSIX_FADV_SEQUENTIAL) = 0
read(3, "aaaaaaaaaaaaaaaaaaaaaaaaaaaa\n", 65536) = 29 //读句柄3,注意这里给出了读到的内容,29 read的返回值,65536入参
write(1, "aaaaaaaaaaaaaaaaaaaaaaaaaaaa\n", 29) //将读到的内容写到控制台(1,控制台句柄)
) = 29
read(3, "", 65536) = 0
close(3) = 0
close(1) = 0
close(2) = 0
exit_group(0) = ?
+++ exited with 0 +++ //进程结束
3.能跟踪到每一个系统调用从陷入系统调用到从系统调用返回花费的时间。如下例子给出了命令"cat 1"每个系统调用的时间
[root@localhost /]# strace -T cat 1 //使用-T参数
execve("/usr/bin/cat", ["cat", "1"], [/* 25 vars */]) = 0 <0.001114> //尖括号给出execv调用花费了0.001114秒
brk(0) = 0xc81000 <0.000046> //brk花了0.000046秒
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fe6d58b8000 <0.000091>
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) <0.000187>
。。。。。。。。。。。。。。。。
4.能跟踪进程生命周期,或者生命周期内的一段时间内发生的系统调用并生成所有系统调用的简单报。
5.能跟踪到一个进程中的所有的线程发起的系统调用,对多线程应用同样可以做到1,2,3,4
[root@localhost /]# strace -c cat 1 //-c参数只生成报表
aaaaaaaaaaaaaaaaaaaaaaaaaaaa
//open行为例子说明,一次从左到右个字段的意思如下
//open: 系统调用名字
//1:有一次open系统调用返回错误
//4:一共调用了4次open系统调用
//140:平均每次open系统调用花140微妙
//0.000559:4次系统调用一共花了0.000559秒
//44.79:0.000559/(seconds列总和)
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
44.79 0.000559 140 4 1 open //上面以这一行为例子
14.58 0.000182 182 1 execve
11.86 0.000148 19 8 mmap
9.29 0.000116 29 4 mprotect
4.41 0.000055 55 1 munmap
4.01 0.000050 17 3 read
3.53 0.000044 44 1 1 access
3.45 0.000043 43 1 write
1.60 0.000020 4 5 fstat
1.12 0.000014 2 6 close
0.72 0.000009 9 1 arch_prctl
0.64 0.000008 2 4 brk
0.00 0.000000 0 1 fadvise64
------ ----------- ----------- --------- --------- ----------------
100.00 0.001248 40 1 total //所有系统调用的总时间,总次数,错误总次数
===========================================================================================================
//下面说明跟踪后台进程某一段生命周期的情况
[root@localhost /]# cat test.sh //写个测试脚本test.sh
#!/bin/bash
while :
do
ls >>/dev/null
sleep .1
done
[root@localhost /]# ./test.sh & //后台跑起来
[1] 27519
[root@localhost /]# ps -ef |grep test //找到后台测试脚本
root 27519 26451 2 09:14 pts/7 00:00:00 /bin/bash ./test.sh
root 27569 26451 0 09:15 pts/7 00:00:00 grep --color=auto test
[root@localhost /]# strace -c -f -p 27519 //跟上这个测试脚本 -p跟上面找到的pid,-f跟踪所有test.sh fork出的子进程
Process 27519 attached //这些都是ls 和sleep命令产生的子进程
Process 28546 attached
Process 28547 attached
Process 28548 attached
Process 28549 attached
Process 28550 attached
Process 28551 attached
。。。。。。
^CProcess 27519 detached //跟踪一段时间后ctrl + c终止跟踪,只结束strace 对27519没有影响
Process 28623 detached
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
70.36 1.935216 12405 156 78 wait4
6.72 0.184836 136 1357 mmap
3.83 0.105233 123 854 mprotect
3.58 0.098601 182 543 open
3.15 0.086584 106 814 close
2.10 0.057833 107 543 fstat
2.04 0.056093 80 702 rt_sigaction
1.66 0.045618 130 350 read
1.38 0.038041 57 663 rt_sigprocmask
1.03 0.028283 105 269 brk
0.63 0.017216 148 116 77 access
0.54 0.014754 127 116 munmap
0.47 0.012797 166 77 execve
0.35 0.009719 125 78 statfs
0.30 0.008339 214 39 dup2
0.28 0.007638 65 117 117 ioctl
0.26 0.007120 187 38 nanosleep
0.23 0.006275 81 77 arch_prctl
0.23 0.006255 80 78 rt_sigreturn
0.21 0.005816 75 78 getdents
0.14 0.003909 100 39 stat
0.11 0.003070 79 39 set_tid_address
0.11 0.002889 74 39 openat
0.10 0.002870 74 39 getrlimit
0.10 0.002619 67 39 set_robust_list
0.09 0.002421 62 39 write
0.02 0.000486 6 78 clone
------ ----------- ----------- --------- --------- ----------------
100.00 2.750531 7377 272 total
[root@localhost /]#
跟踪系统调用不能做到的事情如下:
1.不能跟中系统范围内的事件,例如,有时需要找到系统中哪个app修改了特定文件,用strace搞不定,用strace的前提是必须知道要跟踪的具体进程。而这个应用场景刚好和这个前提条件相反。
2.strace只能作用于系统和应用程序的边界线上,不能看到出应用内部,或者系统内核内部的情况,一般作为故障定位,heak系统的第一步。
参数详解
-c 系统调用的报表,不打印每一个系统调用详细的入参和出参。
[root@localhost /]# strace -c cat 1
aaaaaaaaaaaaaaaaaaaaaaaaaaaa
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
24.59 0.001024 128 8 mmap
21.18 0.000882 147 6 close
11.60 0.000483 97 5 fstat
9.44 0.000393 98 4 open
7.30 0.000304 76 4 mprotect
6.67 0.000278 70 4 brk
4.25 0.000177 59 3 read
3.87 0.000161 161 1 1 access
2.74 0.000114 114 1 write
2.50 0.000104 104 1 munmap
2.16 0.000090 90 1 arch_prctl
1.92 0.000080 80 1 execve
1.80 0.000075 75 1 fadvise64
------ ----------- ----------- --------- --------- ----------------
100.00 0.004165 40 1 total
-C:(大写的C) 先打印每一个系统调用的详细情况,等strace结束后打印报表
[root@localhost /]# strace -C cat 1
execve("/usr/bin/cat", ["cat", "1"], [/* 25 vars */]) = 0 //先打印每一个系统调用的详细情况
brk(0) = 0x17c3000
.............
read(3, "", 65536) = 0
close(3) = 0
close(1) = 0
close(2) = 0
exit_group(0) = ?
+++ exited with 0 +++
% time seconds usecs/call calls errors syscall //最后打印汇总报表,关于报表的解释,参考第一节”strace功能概述”
------ ----------- ----------- --------- --------- ----------------
22.45 0.000402 50 8 mmap
13.01 0.000233 58 4 open
-p:不同于直接跟命令(strace cat 1),用strace 跟踪一个已经跑起来的程序,-p为带参数选项,跟要跟踪进程的pid。如果被跟中进程自己运行结束,strace也就退出了,但是如果被跟踪进程一直运行,那么需要用ctrl + c结束strace跟踪,ctrl + c只会结束strace跟踪,不会影响被跟踪的进程
[root@localhost /]# ./test.sh & //启动一个后台进程
[1] 81552
[root@localhost /]# strace -p 81552 //-p + pid 来跟踪 test.sh
Process 81552 attached
wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 81955
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=81955, si_status=0, si_utime=0, si_stime=0} ---
wait4(-1, 0x7ffe3b080690, WNOHANG, NULL) = -1 ECHILD (No child processes)
rt_sigreturn() = 0
rt_sigaction(SIGINT, {SIG_DFL, [], SA_RESTORER, 0x7f8b52bd5250}, {0x43e670, [], SA_RESTORER, 0x7f8b52bd5250}, 8) = 0
rt_sigprocmask(SIG_BLOCK, [INT CHLD], [], 8) = 0
clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f8b535a1a10) = 81958
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
。。。。。。。。。。。。。。
wait4(-1, ^CProcess 81552 detached //这里按下了ctrl + c结束跟踪
<detached ...>
[root@localhost /]# ps -ef |grep test.sh //ctrl + c 不影响被跟踪的进程,test.sh仍然运行如初
root 81552 26451 2 10:10 pts/7 00:00:12 /bin/bash ./test.sh
root 89534 26451 0 10:18 pts/7 00:00:00 grep --color=auto test.sh
-D:对于"strace cat 1"这种形式的使用(即直接跟要跟的命令,不是通过-p参数接pid形式使用),默认strace进程回事cat进程的父进程,有时候这种父子关系会影响被跟踪进程的行为。使用-D避免这种影响。
//-----------不带-D参数时父子关系
[root@localhost ~]# ps -ef |grep test.sh
root 80626 26451 26 10:08 pts/7 00:00:03 strace ./test.sh //没有使用-D参数strace是test.sh父进程
root 80631 80626 3 10:08 pts/7 00:00:00 /bin/bash ./test.sh //被跟踪的test.sh
//-----------带-D参数时的父子关系
[root@localhost ~]# ps -ef |grep test.sh
root 81215 26451 4 10:09 pts/7 00:00:00 /bin/bash ./test.sh //被跟踪进程test.sh
root 81221 1 29 10:09 pts/7 00:00:02 strace -D ./test.sh //使用了-D参数跟踪
root 81322 26478 0 10:09 pts/8 00:00:00 grep --color=auto test.sh
[root@localhost ~]# ps -ef |grep '26451'
root 26451 26447 0 07:39 pts/7 00:00:00 -bash //被跟踪进程test.sh成了登陆shell的子进程。而不在时strace的子进程.这里的登陆shell就是运行"strace -D ./test.sh"命令所在的登陆bash环境
root 81215 26451 4 10:09 pts/7 00:00:00 /bin/bash ./test.sh
root 81439 26478 0 10:09 pts/8 00:00:00 grep --color=auto 26451
-f:当直接使用strace 跟要运行的二进制程序名时,-f参数用来跟踪父进程以及所有子进程(通过fork,vfork,clone产生的子进程)的系统调用,这里特殊说明一点通过pthread库创建出来的线程也会-f被跟踪到(因为pthread创建线程调用的是clone系统调用)
当使用-p参数跟要跟踪进程的pid时,-f参数只能跟踪到-p指定的进程以及该进程从strace运行命令时间点之后通过fork,vfork,clone创建的子进程,该时间点之前创建的子进程是跟踪不到的。但是该时间点之前创建起来的线程时能够被跟踪到的。
1 [root@localhost strace]# cat test.sh //如下写个测试脚本
2 #!/bin/bash
3 while :
4 do
5 ls >>/dev/null
6 sleep 10
7 done
8 [root@localhost strace]# strace -f ./test.sh //跟踪test.sh
9 execve("./test.sh", ["./test.sh"], [/* 25 vars */]) = 0 //开始执行test.sh
10 brk(0) = 0x130b000
。。。。。。。。。。。。
138 clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f49e1bd7a10) = 80412 //clone第一个进程,用来运行"ls”命令 注意这里返回值是接下来"ls"命令所在的子进程pid
139 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
。。。。。。。。。。。。
155 [pid 80412] dup2(3, 1) = 1
156 [pid 80412] close(3) = 0
157 [pid 80412] execve("/usr/bin/ls", ["ls"], [/* 24 vars */]) = 0 //这里再子进程80412中加载了ls二进制程序开始执行
158 [pid 80412] brk(0) = 0x12a4000
。。。。。。。。。。
258 [pid 80412] openat(AT_FDCWD, ".", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 3 //ls打开了当前目录文件
281 stat("/usr/bin/sleep", {st_mode=S_IFREG|0755, st_size=33112, ...}) = 0
282 stat("/usr/bin/sleep", {st_mode=S_IFREG|0755, st_size=33112, ...}) = 0
283 geteuid() = 0
284 getegid() = 0
285 getuid() = 0
。。。。。。。。。。
308 clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f49e1bd7a10) = 80413 //这里clone了子进程80413开始准备执行sleep命令
。。。。。。。。。。
314 wait4(-1, Process 80413 attached
315 <unfinished ...>
316 [pid 80413] close(255) = 0
。。。。。。。。。。
324 [pid 80413] execve("/usr/bin/sleep", ["sleep", "10"], [/* 24 vars */]) = 0 //这里加载sleep命令二进制程序开始执行
。。。。。。。。。。
354 [pid 80413] nanosleep({10, 0}, ^CProcess 80411 detached //这里我按下了ctrl + c终止了strace过程
355 Process 80413 detached
356 <detached ...>
//写一个测试程序,测试程序调用pthread库创建两个线程,调用fork创建一个进程
[root@localhost pthread]# cat pthread.c
#include<pthread.h>
#include<stdlib.h>
#include<stdio.h>
static void* thread_func1(void* arg) //线程1
{
while(1 == 1)
{
printf("hello world,i am the sun thread 1\n");
sleep(1);
}
return 0;
}
static void* thread_func2(void* arg) //线程2
{
while(1 == 1)
{
printf("hello world,i am the sun thread 2\n");
sleep(1);
}
return 0;
}
int main()
{
pthread_t thread;
pthread_create(&thread,NULL,thread_func1,NULL); //创建线程
pthread_create(&thread,NULL,thread_func2,NULL);
int i = fork();//创建进程
if(i==0) //子进程分支
{
while(1 == 1)
{
sleep(2);
}
}
while(1 == 1)
{
sleep(1);
}
return 0;
}
gcc -pthread -o pthread pthread.c //gcc编译
[root@localhost pthread]# ./pthread >/dev/null & //后台运行
[1] 80652 //主进程pid
[root@localhost pthread]# ps -ef |grep pthread
root 80652 46910 0 11:21 pts/1 00:00:00 ./pthread //主进程
root 80655 80652 0 11:21 pts/1 00:00:00 ./pthread //子进程
root 80657 46910 0 11:21 pts/1 00:00:00 grep --color=auto pthread
[root@localhost pthread]# ps -eLo tid,pid,comm|grep pthread
80652 80652 pthread //主进程
80653 80652 pthread //线程
80654 80652 pthread //线程
80655 80655 pthread //子进程
[root@localhost pthread]# strace -f -p 80652 //-f参数跟踪主进程
Process 80652 attached with 3 threads 这里现实strace跟踪到了3个线程(主进程,两个子线程)注意从下面pid来看strace并没有跟到子进程80655的sleep系统调用
//这个例子主要说明,使用-f 参数在strace开始时间点之前创建的子进程是不能被跟踪到的,但是在strace开始时间点之前创建出来的子线程是能被跟踪到的。
。。。。。。。。。。。。
[pid 80652] nanosleep({1, 0}, <unfinished ...> //跟踪到的主线程第一次sleep
[pid 80653] <... restart_syscall resumed> ) = 0
[pid 80653] rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 80653] rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid 80653] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 80653] nanosleep({1, 0}, <unfinished ...> //线程sleep
[pid 80654] <... restart_syscall resumed> ) = 0
[pid 80654] rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 80654] rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid 80654] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 80654] nanosleep({1, 0}, <unfinished ...> //线程sleep
[pid 80652] <... nanosleep resumed> 0x7ffee6c00c10) = 0
[pid 80652] rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 80652] rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid 80652] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 80652] nanosleep({1, 0}, <unfinished ...> //主线程第二次sleep
[pid 80653] <... nanosleep resumed> 0x7f1d4e2acd20) = 0
[pid 80653] rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 80653] rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid 80653] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 80653] nanosleep({1, 0}, <unfinished ...>
[pid 80654] <... nanosleep resumed> 0x7f1d4daabd20) = 0
[pid 80654] rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 80654] rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid 80654] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 80654] nanosleep({1, 0}, <unfinished ...>
[pid 80652] <... nanosleep resumed> 0x7ffee6c00c10) = 0
[pid 80652] rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 80652] rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid 80652] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 80652] nanosleep({1, 0}, <unfinished ...> //主线程第三次sleep 注意主线是sleep 1而创建的子进程是sleep 2,如果strace能跟踪到子线程,那么在主线程第三次sleep之前一定能跟踪到子进程的sleep系统调用,这也从反面验证了上面的结论。
。。。。。。。。。。
[pid 80654] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 80654] nanosleep({1, 0}, ^CProcess 80652 detached //这里按下ctrl +c 结束了strace跟踪
-F:功能和-f相同,已经被标记为过时
-h:打印帮助信息
-i:打印出发生系统调用时的用户态地址(个人认为应该是int,sysenter等指令所在的用户态地址),根据这个地址可以定位到用户到用户态调用对应系统调用的代码行
[root@localhost ~]# strace -i cat /dev/null
[00007f146bc6b9f7] execve("/usr/bin/cat", ["cat", "/dev/null"], [/* 24 vars */]) = 0 //注意行最前面方括号里面给出了execv系统调用发生的用户态地址
[00007fa602914b3c] brk(0) = 0x6ec000
[00007fa60291582a] mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fa602b1b000
。。。。。。。。。
-q:抑制detach和attach日志的打印,这里解释下,strace跟踪时先需要attach对应的进程,在跟踪结束时要从被跟踪的进程dettach掉,在使用-p参数跟踪进程时,会打印一条日志显示出attach到了对应的进程,结束时会打印一条日志,显示从对应的进程dettach掉了。使用-q参数后,这些dettach和attach信息就不会在出现在日志里面了
[root@localhost pthread]# ps -ef |grep sshd //找到sshd后台进程
root 1093 1 0 16:34 ? 00:00:00 /usr/sbin/sshd
root 2315 1093 0 16:36 ? 00:00:10 sshd: root@pts/0,pts/1,pts/2
root 2859 1093 0 17:21 ? 00:00:00 sshd: root@pts/3
root 3203 2841 0 17:31 pts/2 00:00:00 grep --color=auto sshd
[root@localhost pthread]# strace -f -p 1093 //跟踪到这个进程
Process 1093 attached //这里显示attach到了1093号进程
select(7, [3 4], NULL, NULL, NULL^CProcess 1093 detached
<detached ...> //这里从1093号进程detached
[root@localhost pthread]# strace -f -q -p 1093 //使用-q参数
select(7, [3 4], NULL, NULL, NULL^C <detached ...> //这里没有atach和detach信息了
[root@localhost pthread]#
-qq: 默认情况下,当被跟踪的进程运行结束时,strace会打印出进程的exit信息,使用-qq 即抑制上面说的atach和detach信息,也抑制这种exit信息的打印
[root@localhost ~]# strace cat /dev/null //不带-qq参数
execve("/usr/bin/cat", ["cat", "/dev/null"], [/* 24 vars */]) = 0
brk(0) = 0x146d000
。。。。。。。。。。。
read(3, "", 65536) = 0
close(3) = 0
close(1) = 0
close(2) = 0
exit_group(0) = ?
+++ exited with 0 +++ //这里有exit码打印
[root@localhost ~]# strace -qq cat /dev/null //带-qq参数
execve("/usr/bin/cat", ["cat", "/dev/null"], [/* 24 vars */]) = 0
brk(0) = 0x25d8000
。。。。。。。。。。
read(3, "", 65536) = 0
close(3) = 0
close(1) = 0
close(2) = 0
exit_group(0) = ? //这里不再有exit码的打印
-T:打印每一个系统调用从开始到返回的时间(可以粗略的认为每一个系统调用花的时间,这里为啥说是粗略,是因为这个时间会受到调度,中断等的影响,也就是说,可以通过这个时间测量出具体时哪个系统调用花的时间比较多,但是具体为啥比较多,还是根据内核代码分析具体的原因)
[root@localhost ~]# strace -T cat /dev/null //-T参数跟踪cat命令
execve("/usr/bin/cat", ["cat", "/dev/null"], [/* 24 vars */]) = 0 <0.000673> //尖括号里面给出了execve系统调用开始到结束的时间
brk(0) = 0x192e000 <0.000035> //尖括号里面给出了brk系统调用开始到结束的时间
。。。。。。。
mprotect(0x60b000, 4096, PROT_READ) = 0 <0.000197>
mprotect(0x7f18bc2cb000, 4096, PROT_READ) = 0 <0.000295>
-t:打印每个系统调用开始的时间
-tt:打印每个系统调用开始的时间,精确的微妙
-ttt:打印每个系统调用开始的时间,以linux元年为参考点,精确到微妙
[root@localhost ~]# strace -t cat /ddddddd //-t参数
17:56:08 execve("/usr/bin/cat", ["cat", "/ddddddd"], [/* 24 vars */]) = 0 //这行开头给出了execv开始时间精确到秒
。。。。。。。。。。
17:56:08 +++ exited with 1 +++
[root@localhost ~]# strace -tt cat /ddddddd //-tt参数给出了execve开始的时间,注意小数点后6位,精确到微妙
17:57:07.224178 execve("/usr/bin/cat", ["cat", "/ddddddd"], [/* 24 vars */]) = 0
。。。。。。。。。。
[root@localhost ~]# strace -ttt cat /ddddddd //-ttt参数给出的时间时以linux元年以来的时间,精确到小数点后六位(微妙)
1544569090.970464 execve("/usr/bin/cat", ["cat", "/ddddddd"], [/* 24 vars */]) = 0
1544569090.971789 brk(0) = 0x8a8000
-r:打印一个系统调用开始时间点相对于前一个系统调用开始时间点的差值(即相对于前一个系统调用开始时间点的相对时间)
[root@localhost ~]# strace -r cat /aaaaaaaaa //使用-r参数
0.000000 execve("/usr/bin/cat", ["cat", "/aaaaaaaaa"], [/* 24 vars */]) = 0
0.001143 brk(0) = 0x16b1000 //brk在execve开始后的0.001143秒后开始
0.000355 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f38533c2000 //mmap在brk开始后的0.000355后开始
0.000184 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
。。。。。。。。。。
-v:linux中每一个进程运行都有很多环境变量,默认情况下,为了打印整洁以及打印效率,strace插入注释来标识信息没有打印完全打印,使用-v参数来取消这中行为,让strace打印完整的环境变量信息
[root@localhost ~]# strace cat /aaaaa //不用-v参数
execve("/usr/bin/cat", ["cat", "/aaaaa"], [/* 24 vars */]) = 0 //这里看到给出了注释,第三个环境变量数组中有24个成员,没有打印出来
[root@localhost ~]# strace -v cat /aaaaa //使用-v参数
//下面完整打印出来了cat命令的环境变量信息
execve("/usr/bin/cat", ["cat", "/aaaaa"], ["XDG_SESSION_ID=3", "HOSTNAME=localhost.localdomain", "SELINUX_ROLE_REQUESTED=", "TERM=linux", "SHELL=/bin/bash", "HISTSIZE=1000", "SSH_CLIENT=127.0.0.1 51818 22", "SELINUX_USE_CURRENT_RANGE=", "SSH_TTY=/dev/pts/3", "USER=root", "LS_COLORS=rs=0:di=01;34:ln=01;36"..., "MAIL=/var/spool/mail/root", "PATH=/usr/local/sbin:/usr/local/"..., "PWD=/root", "LANG=en_US.UTF-8", "SELINUX_LEVEL_REQUESTED=", "HISTCONTROL=ignoredups", "SHLVL=1", "HOME=/root", "LOGNAME=root", "SSH_CONNECTION=127.0.0.1 51818 1"..., "LESSOPEN=||/usr/bin/lesspipe.sh "..., "XDG_RUNTIME_DIR=/run/user/0", "_=/usr/bin/strace"]) = 0
-x:将所有的非ascii码字符串以十六进制的形式打印出来
-xx:将所有的字符串以十六进制的形式打印出来
-y:对一些操作文件描述符的系统调用,显示出文件描述符对应文件的绝对路径,对比33,36,37和78,81,82,可以看到这个选项的意义。
1 [root@localhost ~]# strace cat aaaa 2 execve("/usr/bin/cat", ["cat", "aaaa"], [/* 24 vars */]) = 0 3 brk(0) = 0xa68000 4 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f89c6d45000 5 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) 6 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 7 fstat(3, {st_mode=S_IFREG|0644, st_size=35311, ...}) = 0 8 mmap(NULL, 35311, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f89c6d3c000 9 close(3) = 0 10 open("/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3 11 read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@\34\2\0\0\0\0\0"..., 832) = 832 12 fstat(3, {st_mode=S_IFREG|0755, st_size=2116736, ...}) = 0 13 mmap(NULL, 3932672, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f89c6766000 14 mprotect(0x7f89c691c000, 2097152, PROT_NONE) = 0 15 mmap(0x7f89c6b1c000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1b6000) = 0x7f89c6b1c000 16 mmap(0x7f89c6b22000, 16896, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f89c6b22000 17 close(3) = 0 18 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f89c6d3b000 19 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f89c6d39000 20 arch_prctl(ARCH_SET_FS, 0x7f89c6d39740) = 0 21 mprotect(0x7f89c6b1c000, 16384, PROT_READ) = 0 22 mprotect(0x60b000, 4096, PROT_READ) = 0 23 mprotect(0x7f89c6d46000, 4096, PROT_READ) = 0 24 munmap(0x7f89c6d3c000, 35311) = 0 25 brk(0) = 0xa68000 26 brk(0xa89000) = 0xa89000 27 brk(0) = 0xa89000 28 open("/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3 29 fstat(3, {st_mode=S_IFREG|0644, st_size=106070960, ...}) = 0 30 mmap(NULL, 106070960, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f89c023d000 31 close(3) = 0 32 fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 1), ...}) = 0 33 open("aaaa", O_RDONLY) = 3 34 fstat(3, {st_mode=S_IFREG|0644, st_size=28, ...}) = 0 35 fadvise64(3, 0, 0, POSIX_FADV_SEQUENTIAL) = 0 36 read(3, "aaaaaaaaaaaaaaaaaaaa\naaaaaa\n", 65536) = 28 37 write(1, "aaaaaaaaaaaaaaaaaaaa\naaaaaa\n", 28aaaaaaaaaaaaaaaaaaaa 38 aaaaaa 39 ) = 28 40 read(3, "", 65536) = 0 41 close(3) = 0 42 close(1) = 0 43 close(2) = 0 44 exit_group(0) = ? 45 +++ exited with 0 +++ 46 [root@localhost ~]# strace -y cat aaaa 47 execve("/usr/bin/cat", ["cat", "aaaa"], [/* 24 vars */]) = 0 48 brk(0) = 0xa1a000 49 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb6bb3b2000 50 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) 51 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 52 fstat(3</etc/ld.so.cache>, {st_mode=S_IFREG|0644, st_size=35311, ...}) = 0 53 mmap(NULL, 35311, PROT_READ, MAP_PRIVATE, 3</etc/ld.so.cache>, 0) = 0x7fb6bb3a9000 54 close(3</etc/ld.so.cache>) = 0 55 open("/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3 56 read(3</usr/lib64/libc-2.17.so>, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@\34\2\0\0\0\0\0"..., 832) = 832 57 fstat(3</usr/lib64/libc-2.17.so>, {st_mode=S_IFREG|0755, st_size=2116736, ...}) = 0 58 mmap(NULL, 3932672, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3</usr/lib64/libc-2.17.so>, 0) = 0x7fb6badd3000 59 mprotect(0x7fb6baf89000, 2097152, PROT_NONE) = 0 60 mmap(0x7fb6bb189000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3</usr/lib64/libc-2.17.so>, 0x1b6000) = 0x7fb6bb189000 61 mmap(0x7fb6bb18f000, 16896, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fb6bb18f000 62 close(3</usr/lib64/libc-2.17.so>) = 0 63 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb6bb3a8000 64 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb6bb3a6000 65 arch_prctl(ARCH_SET_FS, 0x7fb6bb3a6740) = 0 66 mprotect(0x7fb6bb189000, 16384, PROT_READ) = 0 67 mprotect(0x60b000, 4096, PROT_READ) = 0 68 mprotect(0x7fb6bb3b3000, 4096, PROT_READ) = 0 69 munmap(0x7fb6bb3a9000, 35311) = 0 70 brk(0) = 0xa1a000 71 brk(0xa3b000) = 0xa3b000 72 brk(0) = 0xa3b000 73 open("/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3 74 fstat(3</usr/lib/locale/locale-archive>, {st_mode=S_IFREG|0644, st_size=106070960, ...}) = 0 75 mmap(NULL, 106070960, PROT_READ, MAP_PRIVATE, 3</usr/lib/locale/locale-archive>, 0) = 0x7fb6b48aa000 76 close(3</usr/lib/locale/locale-archive>) = 0 77 fstat(1</dev/pts/1>, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 1), ...}) = 0 78 open("aaaa", O_RDONLY) = 3 79 fstat(3</root/aaaa>, {st_mode=S_IFREG|0644, st_size=28, ...}) = 0 80 fadvise64(3</root/aaaa>, 0, 0, POSIX_FADV_SEQUENTIAL) = 0 81 read(3</root/aaaa>, "aaaaaaaaaaaaaaaaaaaa\naaaaaa\n", 65536) = 28 82 write(1</dev/pts/1>, "aaaaaaaaaaaaaaaaaaaa\naaaaaa\n", 28aaaaaaaaaaaaaaaaaaaa 83 aaaaaa 84 ) = 28 85 read(3</root/aaaa>, "", 65536) = 0 86 close(3</root/aaaa>) = 0 87 close(1</dev/pts/1>) = 0 88 close(2</dev/pts/1>) = 0 89 exit_group(0) = ? 90 +++ exited with 0 +++
-a:用法:-a column 将系统调用的返回值对齐到column列:
1 [root@localhost ~]# strace -a 100 cat ./aaaa 2 execve("/usr/bin/cat", ["cat", "./aaaa"], [/* 24 vars */]) = 0 3 brk(0) = 0x7ec000 4 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f6de89ad000 5 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) 6 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 7 fstat(3, {st_mode=S_IFREG|0644, st_size=35311, ...}) = 0 8 mmap(NULL, 35311, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f6de89a4000 9 close(3) = 0 10 open("/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3 11 read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@\34\2\0\0\0\0\0"..., 832) = 832 12 fstat(3, {st_mode=S_IFREG|0755, st_size=2116736, ...}) = 0 13 mmap(NULL, 3932672, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f6de83ce000 14 mprotect(0x7f6de8584000, 2097152, PROT_NONE) = 0 15 mmap(0x7f6de8784000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1b6000) = 0x7f6de8784000 16 mmap(0x7f6de878a000, 16896, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f6de878a000 17 close(3) = 0 18 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f6de89a3000 19 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f6de89a1000 20 arch_prctl(ARCH_SET_FS, 0x7f6de89a1740) = 0 21 mprotect(0x7f6de8784000, 16384, PROT_READ) = 0 22 mprotect(0x60b000, 4096, PROT_READ) = 0 23 mprotect(0x7f6de89ae000, 4096, PROT_READ) = 0 24 munmap(0x7f6de89a4000, 35311) = 0 25 brk(0) = 0x7ec000 26 brk(0x80d000) = 0x80d000 27 brk(0) = 0x80d000 28 open("/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3 29 fstat(3, {st_mode=S_IFREG|0644, st_size=106070960, ...}) = 0 30 mmap(NULL, 106070960, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f6de1ea5000 31 close(3) = 0 32 fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 1), ...}) = 0 33 open("./aaaa", O_RDONLY) = 3 34 fstat(3, {st_mode=S_IFREG|0644, st_size=28, ...}) = 0 35 fadvise64(3, 0, 0, POSIX_FADV_SEQUENTIAL) = 0 36 read(3, "aaaaaaaaaaaaaaaaaaaa\naaaaaa\n", 65536) = 28 37 write(1, "aaaaaaaaaaaaaaaaaaaa\naaaaaa\n", 28aaaaaaaaaaaaaaaaaaaa 38 aaaaaa 39 ) = 28 40 read(3, "", 65536) = 0 41 close(3) = 0 42 close(1) = 0 43 close(2) = 0 44 exit_group(0) = ? 45 +++ exited with 0 +++ 46 [root@localhost ~]# strace cat ./aaaa 47 execve("/usr/bin/cat", ["cat", "./aaaa"], [/* 24 vars */]) = 0 48 brk(0) = 0x136d000 49 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fef85590000 50 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) 51 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 52 fstat(3, {st_mode=S_IFREG|0644, st_size=35311, ...}) = 0 53 mmap(NULL, 35311, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fef85587000 54 close(3) = 0 55 open("/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3 56 read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@\34\2\0\0\0\0\0"..., 832) = 832 57 fstat(3, {st_mode=S_IFREG|0755, st_size=2116736, ...}) = 0 58 mmap(NULL, 3932672, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fef84fb1000 59 mprotect(0x7fef85167000, 2097152, PROT_NONE) = 0 60 mmap(0x7fef85367000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1b6000) = 0x7fef85367000 61 mmap(0x7fef8536d000, 16896, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fef8536d000 62 close(3) = 0 63 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fef85586000 64 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fef85584000 65 arch_prctl(ARCH_SET_FS, 0x7fef85584740) = 0 66 mprotect(0x7fef85367000, 16384, PROT_READ) = 0 67 mprotect(0x60b000, 4096, PROT_READ) = 0 68 mprotect(0x7fef85591000, 4096, PROT_READ) = 0 69 munmap(0x7fef85587000, 35311) = 0 70 brk(0) = 0x136d000 71 brk(0x138e000) = 0x138e000 72 brk(0) = 0x138e000 73 open("/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3 74 fstat(3, {st_mode=S_IFREG|0644, st_size=106070960, ...}) = 0 75 mmap(NULL, 106070960, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fef7ea88000 76 close(3) = 0 77 fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 1), ...}) = 0 78 open("./aaaa", O_RDONLY) = 3 79 fstat(3, {st_mode=S_IFREG|0644, st_size=28, ...}) = 0 80 fadvise64(3, 0, 0, POSIX_FADV_SEQUENTIAL) = 0 81 read(3, "aaaaaaaaaaaaaaaaaaaa\naaaaaa\n", 65536) = 28 82 write(1, "aaaaaaaaaaaaaaaaaaaa\naaaaaa\n", 28aaaaaaaaaaaaaaaaaaaa 83 aaaaaa 84 ) = 28 85 read(3, "", 65536) = 0 86 close(3) = 0 87 close(1) = 0 88 close(2) = 0 89 exit_group(0) = ? 90 +++ exited with 0 +++