strace

简介：
strace跟踪程序使用的底层系统调用，输出系统调用被执行的时间点以及各个调用耗时

[root@Dev-P02-CDF1 ~]# strace -T -tt  ping www.baidu.com  
#参数说明：-T 显示每一调用所耗费的时间
           -tt 在输出的前边加上时间，微秒级
#如何保存输出日志：
           -o 参数 example：[root@Dev-P02-CDF1 ~]# strace -T -tt  -o strace.log ping www.baidu.com
           输出重定向：[root@Dev-P02-CDF1 ~]# strace -T -tt   ping www.baidu.com   2> strace.log
日志内容截取：
......
14:24:01.960937 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 4 <0.000033>
14:24:01.961015 connect(4, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("192.168.41.154")}, 16) = 0 <0.000034>
14:24:01.961104 poll([{fd=4, events=POLLOUT}], 1, 0) = 1 ([{fd=4, revents=POLLOUT}]) <0.000027>
14:24:01.961176 sendto(4, "\377i\1\0\0\1\0\0\0\0\0\0\3www\5baidu\3com\0\0\1\0\1", 31, MSG_NOSIGNAL, NULL, 0) = 31 <0.000039>
14:24:01.961263 poll([{fd=4, events=POLLIN}], 1, 5000) = 0 (Timeout) <5.000899>
14:24:06.962238 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 5 <0.000040>
......

由此可看到是socket连接时有超时问题，详情看sin_port此参数是53，发现是DNS查询的调用；DNS地址是192.168.41.154。查询此NDS耗时5秒
我们去/etc/resolve.conf文件注释此行
[root@Dev-P02-CDF1 ~]# vi /etc/resolv.conf
# Generated by NetworkManager
#nameserver 192.168.41.154
nameserver 192.168.130.7

ping命令耗时对比：
[root@Dev-P02-CDF1 ~]# time ping www.baidu.com
PING www.a.shifen.com (220.181.111.188) 56(84) bytes of data.
^C64 bytes from 220.181.111.188: icmp_seq=1 ttl=52 time=3.48 ms

--- www.a.shifen.com ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 5009ms
rtt min/avg/max/mdev = 3.483/3.483/3.483/0.000 ms

real    0m10.018s
user    0m0.001s
sys     0m0.002s

[root@Dev-P02-CDF1 ~]# time ping www.baidu.com
PING www.a.shifen.com (220.181.111.188) 56(84) bytes of data.
64 bytes from 220.181.111.188: icmp_seq=1 ttl=52 time=3.34 ms
64 bytes from 220.181.111.188: icmp_seq=2 ttl=52 time=3.26 ms
^C
--- www.a.shifen.com ping statistics ---
2 packets transmitted, 2 received, 0% packet loss, time 1119ms
rtt min/avg/max/mdev = 3.265/3.306/3.348/0.070 ms

real    0m1.123s
user    0m0.001s
sys     0m0.003s

示例：
1.跟踪nginx, 看其启动时都访问了哪些文件
strace -tt -T -f -e trace=file -o /data/log/strace.log -s 1024 2>&1 ./nginx
2. 定位程序异常退出
strace -ttf -T -p 10893 -o tmp -e trace=process 2>&1
3.程序启动加载文件
strace -e open,acces ./sh 2>&1 | grep fileName
4. 查选程序耗时
strace -c -p 11084
5.链接服务器失败
strace -e poll,select,connect,recvfrom,sendto nc www.baidu.com 80


strace一个现有的进程

打开5912进程相关的FD：
ll /proc/5912/fd/
lrwx------ 1 oracle dba 64 Dec 30 10:55 18 -> /db/databases/orcl/redo-01-a/redo-t01-g01-m1.log 
lrwx------ 1 oracle dba 64 Dec 30 10:55 19 -> /db/databases/orcl/redo-03-a/redo-t01-g01-m2.log 
lrwx------ 1 oracle dba 64 Dec 30 10:55 20 -> /db/databases/orcl/redo-02-a/redo-t01-g02-m1.log 
lrwx------ 1 oracle dba 64 Dec 30 10:55 21 -> /db/databases/orcl/redo-04-a/redo-t01-g02-m2.log 
lrwx------ 1 oracle dba 64 Dec 30 10:55 22 -> /db/databases/orcl/redo-01-a/redo-t01-g03-m1.log 
lrwx------ 1 oracle dba 64 Dec 30 10:55 23 -> /db/databases/orcl/redo-03-a/redo-t01-g03-m2.log
lrwx------ 1 oracle dba 64 Dec 30 10:55 24 -> /db/databases/orcl/redo-02-a/redo-t01-g04-m1.log 
lrwx------ 1 oracle dba 64 Dec 30 10:55 25 -> /db/databases/orcl/redo-04-a/redo-t01-g04-m2.log

来自: http://man.linuxde.net/strace