引言
有時我們需要對程序進行優化、減少程序響應時間。除了一段段地對代碼進行時間復雜度分析,我們還有更便捷的方法嗎?
若能直接找到影響程序運行時間的函數調用,再有針對地對相關函數進行代碼分析和優化,那相比漫無目的地看代碼,效率就高多了。
將strace和pstack工具結合起來使用,就可以達到以上目的。strace跟蹤程序使用的底層系統調用,可輸出系統調用被執行的時間點以及各個調用耗時;pstack工具對指定PID的進程輸出函數調用棧。
下面我們通過一個簡單的消息收發程序,說明使用strace、pstack進行程序分析的具體方法。
程序說明
該程序是一個簡單的socket程序,由server/client組成。server端監聽某端口,等待client的連接,client連接server后定時向server發送消息,server每接收一條消息后向client發送響應消息。程序server與client交互如下圖示:
在程序運行起來之后,發現server接收到client的submit消息之后,需要較長時間才發出resp響應。通過tcpdump抓包發現,time2與time1的時間間隔在1s左右:
由上初步分析可知,消息響應慢是server端程序問題。下面我們來看如何使用strace和pstack分析server端程序響應慢的原因。
strace查看系統調用
首先我們拉起server/client程序,並使用strace對server進程進行跟蹤:
# ps -elf | grep server | grep -v grep 0 S root 16739 22642 0 76 0 - 634 1024 14:26 pts/2 00:00:00 ./server # strace -o server.strace -Ttt -p 16739 Process 16739 attached - interrupt to quit
稍等一段時間之后,我們將strace停掉, server.strace文件中有以下輸出:
14:46:39.741366 select(8, [3 4], NULL, NULL, {1, 0}) = 1 (in [4], left {0, 1648}) <0.998415> 14:46:40.739965 recvfrom(4, "hello", 6, 0, NULL, NULL) = 5 <0.000068> 14:46:40.740241 write(1, "hello\n", 6) = 6 <0.000066> 14:46:40.740414 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0 <0.000046> 14:46:40.740565 rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0 <0.000048> 14:46:40.740715 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 <0.000046> 14:46:40.740853 nanosleep({1, 0}, {1, 0}) = 0 <1.000276> 14:46:41.741284 sendto(4, "hello\0", 6, 0, NULL, 0) = 6 <0.000111>
可以看到server接收數據之后(對應recvfrom調用),經過1s左右時間將消息發出(對應sendto調用),從響應時間看,與抓包的結果吻合。又可以看出nanosleep系統調用耗費了1s時間。
因而可以斷定響應延時由nanosleep對應的函數調用造成。
那具體是哪一個函數調用呢?在strace輸出結果中並不能找到答案,因其輸出顯示都是系統調用,要顯示程序中函數調用棧信息,就輪到pstack上場了。
pstack查看函數堆棧
pstack是一個腳本工具,其核心實現就是使用了gdb以及thread apply all bt命令,下面我們使用pstack查看server進程函數堆棧:
# sh pstack.sh 16739 #0 0x00002ba1f8152650 in __nanosleep_nocancel () from /lib64/libc.so.6 #1 0x00002ba1f8152489 in sleep () from /lib64/libc.so.6 #2 0x00000000004007bb in ha_ha () #3 0x0000000000400a53 in main ()
從以上信息可以看出,函數調用關系為:main->ha_ha->sleep,因而我們可以找到ha_ha函數進行分析和優化修改。
小結
本文通過一個server/client程序事例,說明了使用strace和pstack分析響應延時的方法。
由最初server端響應慢現象,到使用strace跟蹤出具體耗時的系統調用,再到使用pstack查到程序中具體的耗時函數,一步步找到了影響程序運行時間的程序代碼。
更多地了解底層,從操作系統層面着手,更有助於程序性能分析與優化。
本文中使用的server/client程序和pstack腳本可從這里下載。