strace -tt -T -v -f -e trace=file -o /data/log/strace.log -s 1024 -p 23489
-tt 在每行输出的前面,显示毫秒级别的时间
-T 显示每次系统调用所花费的时间
-v 对于某些相关调用,把完整的环境变量,文件stat结构等打出来。
-f 跟踪目标进程,以及目标进程创建的所有子进程
-e 控制要跟踪的事件和跟踪行为,比如指定要跟踪的系统调用名称
-o 把strace的输出单独写到指定的文件
-s 当系统调用的某个参数是字符串时,最多输出指定长度的内容,默认是32个字节
-p 指定要跟踪的进程pid, 要同时跟踪多个pid, 重复多次-p选项即可。
# strace -o nginx_run_time.txt -t nginx -t
# 发现问题22秒到27秒之间,Timeout了5秒,此时间段内DNS解析出现了问题,上面为联通的DNS地址。
18:22:22 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 5
18:22:22 connect(5, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("202.106.0.20")}, 16) = 0
18:22:22 poll([{fd=5, events=POLLOUT}], 1, 0) = 1 ([{fd=5, revents=POLLOUT}])
18:22:22 sendto(5, "3053671 1 7payment10linz3co"..., 38, MSG_NOSIGNAL, NULL, 0) = 38
18:22:22 poll([{fd=5, events=POLLIN|POLLOUT}], 1, 5000) = 1 ([{fd=5, revents=POLLOUT}])
18:22:22 sendto(5, "2633121 1 7payment10linz3co"..., 38, MSG_NOSIGNAL, NULL, 0) = 38
18:22:22 poll([{fd=5, events=POLLIN}], 1, 4999) = 0 (Timeout)
18:22:27 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 6
18:22:27 connect(6, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("114.114.114.114")}, 16) = 0
18:22:27 poll([{fd=6, events=POLLOUT}], 1, 0) = 1 ([{fd=6, revents=POLLOUT}])
18:22:27 sendto(6, "3053671 1 7payment10linz3co"..., 38, MSG_NOSIGNAL, NULL, 0) = 38
18:22:27 poll([{fd=6, events=POLLIN|POLLOUT}], 1, 3000) = 1 ([{fd=6, revents=POLLOUT}])
18:22:27 sendto(6, "2633121 1 7payment10linz3co"..., 38, MSG_NOSIGNAL, NULL, 0) = 38
18:22:27 poll([{fd=6, events=POLLIN}], 1, 2999) = 1 ([{fd=6, revents=POLLIN}])
# 解决方法,注释掉202.106.0.20的nameserver或者修改本地的/etc/hosts把解析时间长的域名添加进去。
# cat /etc/resolv.conf
nameserver 202.106.0.20
nameserver 114.114.114.114