strace
1、简介
strace是Linux环境下的一款程序调试工具,用来检察一个应用程序所使用的系统调用。Strace是一个简单的跟踪系统调用执行的工具。在其最简单的形式中,它可以从开始到结束跟踪二进制的执行,并在进程的生命周期中输出一行具有系统调用名称,每个系统调用的参数和返回值的文本行。
2、安装
官方网址:
http://sourceforge.net/project/showfiles.php?group_id=2861&package_id=2819
[root@RedHat_test ~] yum install strace
3、strace命令常用格式
[root@RedHat_test ~] man strace -tt : 在每行输出的前面,显示毫秒级别的时间 -T : 显示每次系统调用所花费的时间 -v : 对于某些相关调用,把完整的环境变量,文件stat结构等打出来。 -f : 跟踪目标进程,以及目标进程创建的所有子进程 -e : 控制要跟踪的事件和跟踪行为,比如指定要跟踪的系统调用名称 -o : 把strace的输出单独写到指定的文件 -s : 当系统调用的某个参数是字符串时,最多输出指定长度的内容,默认是32个字节 -p : 指定要跟踪的进程pid, 要同时跟踪多个pid, 重复多次-p选项即可。
4、跟踪ls命令
[root@RedHat_test opt] strace ls execve("/bin/ls", ["ls"], [/* 46vars */]) =0 brk(0) =0x1ab9000 access("/etc/ld.so.nohwcap", F_OK) =-1ENOENT (No such file or directory) mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =0x7fcf695fb000 access("/etc/ld.so.preload", R_OK) =-1ENOENT (No such file or directory) open("/etc/ld.so.cache", O_RDONLY) =3 fstat(3, {st_mode=S_IFREG|0644, st_size=102786, ...}) =0 mmap(NULL, 102786, PROT_READ, MAP_PRIVATE, 3, 0) =0x7fcf695e1000 close(3) =0 access("/etc/ld.so.nohwcap", F_OK) =-1ENOENT (No such file or directory) open("/lib/librt.so.1", O_RDONLY) =3
5、寻找被程序读取的php配置文件
[root@RedHat_test ~] strace php 2>&1 | grep php.ini
6、跟踪指定的系统调用
[root@RedHat_test ~] strace -e open cat dead.letter open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) =3 open("/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) =3 open("/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) =3 open("dead.letter", O_RDONLY) =-1ENOENT (No such file or directory) cat: dead.letteropen("/usr/share/locale/locale.alias", O_RDONLY|O_CLOEXEC) =3 open("/usr/share/locale/zh_CN.UTF-8/LC_MESSAGES/libc.mo", O_RDONLY) =-1ENOENT (No such file or directory) open("/usr/share/locale/zh_CN.utf8/LC_MESSAGES/libc.mo", O_RDONLY) =-1ENOENT (No such file or directory) open("/usr/share/locale/zh_CN/LC_MESSAGES/libc.mo", O_RDONLY) =3 open("/usr/lib64/gconv/gconv-modules.cache", O_RDONLY) =3 : 没有那个文件或目录 +++exited with 1+++
7、跟踪进程
[root@RedHat_test ~] strace -p 2208 strace: Process 2208attached restart_syscall(<... resuming interrupted poll ...> ) =1 read(5, "\1\0\0\0\0\0\0\0", 16) =8 futex(0x560eaba76640, FUTEX_WAKE_PRIVATE, 1) =1 poll([{fd=5, events=POLLIN}, {fd=8, events=POLLIN}], 2, -1) =1([{fd=5, revents=POLLIN}]) read(5, "\1\0\0\0\0\0\0\0", 16) =8 poll([{fd=5, events=POLLIN}, {fd=8, events=POLLIN}], 2, -1) =1([{fd=5, revents=POLLIN}]) read(5, "\1\0\0\0\0\0\0\0", 16) =8 poll([{fd=5, events=POLLIN}, {fd=8, events=POLLIN}], 2, -1) =1([{fd=8, revents=POLLIN}]) write(5, "\1\0\0\0\0\0\0\0", 8) =8 write(7, "\1\0\0\0\0\0\0\0", 8) =8 futex(0x560eaba6b9e0, FUTEX_WAKE_PRIVATE, 1) =1 futex(0x560eaba861c0, FUTEX_WAKE_PRIVATE, 1) =1 futex(0x560eaba6d198, FUTEX_WAKE_PRIVATE, 1) =1 poll([{fd=8, events=POLLIN}], 1, 0) =1([{fd=8, revents=POLLIN}]) read(8, "\2\0\0\0\200\0\0\0}\327\5\0\20\0\0\00018452\0\0\0\0\0\0\0\0\0\0\0"..., 2048) =64 ---------------------------------------------------------------------------------------- 常见使用方法 [root@RedHat_test ~] strace -T -e access -p 2208 ----------------------------------------------------------------------------------------
8、统计跟踪结果的概要
[root@RedHat_test ~] strace -c ls 1.pyfile.log scripts tsar correct jdk-8u91-linux-x64.tar.gz test yunweimao % time seconds usecs/call calls errors syscall -------------------------------------------------------------- 26.43 0.000315 12 27 mmap 15.52 0.000185 19 10 open 9.98 0.000119 7 18 mprotect 6.71 0.000080 10 8 read 6.71 0.000080 6 13 close 6.21 0.000074 7 11 fstat 4.45 0.000053 27 2 munmap 3.86 0.000046 23 2 statfs 2.85 0.000034 34 1 stat 2.68 0.000032 16 2 getdents 2.60 0.000031 31 1 openat 2.18 0.000026 13 2 write 2.10 0.000025 13 2 1access 1.85 0.000022 22 1 set_tid_address 1.59 0.000019 6 3 brk 1.26 0.000015 8 2 ioctl 1.01 0.000012 6 2 rt_sigaction 0.59 0.000007 7 1 execve 0.50 0.000006 6 1 getrlimit 0.50 0.000006 6 1 set_robust_list 0.42 0.000005 5 1 rt_sigprocmask 0.00 0.000000 0 1 arch_prctl -------------------------------------------------------------- 100.00 0.001192 112 1total
9、保存输出结果
[root@RedHat_test ~] strace -o process_strace -p 2208 [root@RedHat_test ~] ls process_strace [root@RedHat_test ~] tail -f 10 process_strace tail: 无法打开"100"读取数据: 没有那个文件或目录 ==> process_strace <== futex(0x560eaba6b9e0, FUTEX_WAKE_PRIVATE, 1) =1 futex(0x560eaba861c0, FUTEX_WAKE_PRIVATE, 1) =1 futex(0x560eaba6d198, FUTEX_WAKE_PRIVATE, 1) =1 poll([{fd=8, events=POLLIN}], 1, 0) =1([{fd=8, revents=POLLIN}]) read(8, "\2\0\0\0\0\2\0\0\0\0\0\0\20\0\0\00018457\0\0\0\0\0\0\0\0\0\0\0"..., 2048) =64 poll([{fd=8, events=POLLIN}], 1, 0) =0(Timeout) write(5, "\1\0\0\0\0\0\0\0", 8) =8 poll([{fd=5, events=POLLIN}, {fd=8, events=POLLIN}], 2, -1) =1([{fd=5, revents=POLLIN}]) read(5, "\2\0\0\0\0\0\0\0", 16) =8 poll([{fd=5, events=POLLIN}, {fd=8, events=POLLIN}], 2, -1<detached ...>
10、跟踪nginx, 看其启动时都访问了哪些文件
[root@RedHat_test ~] strace -tt -T -f -e trace=file -o /data/log/strace.log -s 1024 service nginx restart [root@RedHat_test ~] cat /data/log/strace.log 3259713:51:52.873281 execve("/usr/sbin/service", ["service", "nginx", "restart"], [/* 27vars */]) =0<0.000319> 3259713:51:52.874064 access("/etc/ld.so.preload", R_OK) =-1ENOENT (No such file or directory) <0.000017> 3259713:51:52.874184 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) =3<0.000017> 3259713:51:52.874343 open("/lib64/libtinfo.so.5", O_RDONLY|O_CLOEXEC) =3<0.000017> 3259713:51:52.874549 open("/lib64/libdl.so.2", O_RDONLY|O_CLOEXEC) =3<0.000017> 3259713:51:52.874750 open("/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) =3<0.000017> 每一行输出的最后尖括号中的数据表示执行耗时,单位是秒
11、显示时间戳
[root@RedHat_test ~] strace -t ls 11:48:02 execve("/usr/bin/ls", ["ls"], [/* 27vars */]) =0 11:48:02 brk(NULL) =0x23ba000 11:48:02 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =0x7fa562bae000 11:48:02 access("/etc/ld.so.preload", R_OK) =-1ENOENT (No such file or directory) 11:48:02 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) =3 11:48:02 fstat(3, {st_mode=S_IFREG|0644, st_size=35957, ...}) =0 11:48:02 mmap(NULL, 35957, PROT_READ, MAP_PRIVATE, 3, 0) =0x7fa562ba5000 11:48:02 close(3) =0 11:48:02 open("/lib64/libselinux.so.1", O_RDONLY|O_CLOEXEC) =3 11:48:02 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\320i\0\0\0\0\0\0"..., 832) =832 11:48:02 fstat(3, {st_mode=S_IFREG|0755, st_size=155784, ...}) =0 11:48:02 mmap(NULL, 2255184, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =0x7fa562767000 11:48:02 mprotect(0x7fa56278b000, 2093056, PROT_NONE) =0 11:48:02 mmap(0x7fa56298a000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x23000) =0x7fa56298a000 11:48:02 mmap(0x7fa56298c000, 6480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) =0x7fa56298c000 11:48:02 close(3) =0 11:48:02 open("/lib64/libcap.so.2", O_RDONLY|O_CLOEXEC) =3 11:48:02 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0 \26\0\0\0\0\0\0"..., 832) =832 11:48:02 fstat(3, {st_mode=S_IFREG|0755, st_size=20032, ...}) =0 ---------------------------------------------------------------------------------------- -tt : 展示微秒级别的时间戳 [root@RedHat_test ~] strace -tt ls -ttt : 展示微秒级的时间戳,但是它并不是打印当前时间,而是显示自从epoch(译注:1970年1月1日00:00:00 UTC)以来的所经过的秒数 [root@RedHat_test ~] strace -ttt ls -r : 展示相对时间戳 [root@RedHat_test ~] strace -r ls ----------------------------------------------------------------------------------------
关于运维学习、分享、交流,笔者开通了微信公众号【运维猫】,感兴趣的朋友可以关注下,欢迎加入,建立属于我们自己的小圈子,一起学运维知识。
声明:本站所有文章,如无特殊说明或标注,均为本站原创发布。任何个人或组织,在未征得本站同意时,禁止复制、盗用、采集、发布本站内容到任何网站、书籍等各类媒体平台。如若本站内容侵犯了原著者的合法权益,可联系我们进行处理。