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, "\305\367\1\0\0\1\0\0\0\0\0\0\7payment\10linz\3co"..., 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, "\263\312\1\0\0\1\0\0\0\0\0\0\7payment\10linz\3co"..., 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, "\305\367\1\0\0\1\0\0\0\0\0\0\7payment\10linz\3co"..., 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, "\263\312\1\0\0\1\0\0\0\0\0\0\7payment\10linz\3co"..., 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