引言

有時(shí)我們需要對(duì)程序進(jìn)行優(yōu)化、減少程序響應(yīng)時(shí)間。除了一段段地對(duì)代碼進(jìn)行時(shí)間復(fù)雜度分析，我們還有更便捷的方法嗎？

若能直接找到影響程序運(yùn)行時(shí)間的函數(shù)調(diào)用，再有針對(duì)地對(duì)相關(guān)函數(shù)進(jìn)行代碼分析和優(yōu)化，那相比漫無(wú)目的地看代碼，效率就高多了。

將strace和pstack工具結(jié)合起來(lái)使用，就可以達(dá)到以上目的。strace跟蹤程序使用的底層系統(tǒng)調(diào)用，可輸出系統(tǒng)調(diào)用被執(zhí)行的時(shí)間點(diǎn)以及各個(gè)調(diào)用耗時(shí)；pstack工具對(duì)指定PID的進(jìn)程輸出函數(shù)調(diào)用棧。

下面我們通過(guò)一個(gè)簡(jiǎn)單的消息收發(fā)程序，說(shuō)明使用strace、pstack進(jìn)行程序分析的具體方法。

程序說(shuō)明
該程序是一個(gè)簡(jiǎn)單的socket程序，由server/client組成。server端監(jiān)聽(tīng)某端口，等待client的連接，client連接server后定時(shí)向server發(fā)送消息，server每接收一條消息后向client發(fā)送響應(yīng)消息。程序server與client交互如下圖示：

在程序運(yùn)行起來(lái)之后，發(fā)現(xiàn)server接收到client的submit消息之后，需要較長(zhǎng)時(shí)間才發(fā)出resp響應(yīng)。通過(guò)tcpdump抓包發(fā)現(xiàn)，time2與time1的時(shí)間間隔在1s左右：

由上初步分析可知，消息響應(yīng)慢是server端程序問(wèn)題。下面我們來(lái)看如何使用strace和pstack分析server端程序響應(yīng)慢的原因。

?

strace查看系統(tǒng)調(diào)用
首先我們拉起server/client程序，并使用strace對(duì)server進(jìn)程進(jìn)行跟蹤：

# 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

?

稍等一段時(shí)間之后，我們將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接收數(shù)據(jù)之后(對(duì)應(yīng)recvfrom調(diào)用)，經(jīng)過(guò)1s左右時(shí)間將消息發(fā)出(對(duì)應(yīng)sendto調(diào)用)，從響應(yīng)時(shí)間看，與抓包的結(jié)果吻合。又可以看出nanosleep系統(tǒng)調(diào)用耗費(fèi)了1s時(shí)間。

因而可以斷定響應(yīng)延時(shí)由nanosleep對(duì)應(yīng)的函數(shù)調(diào)用造成。

那具體是哪一個(gè)函數(shù)調(diào)用呢？在strace輸出結(jié)果中并不能找到答案，因其輸出顯示都是系統(tǒng)調(diào)用，要顯示程序中函數(shù)調(diào)用棧信息，就輪到pstack上場(chǎng)了。

?

pstack查看函數(shù)堆棧
pstack是一個(gè)腳本工具，其核心實(shí)現(xiàn)就是使用了gdb以及thread apply all bt命令，下面我們使用pstack查看server進(jìn)程函數(shù)堆棧：

# 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 ()

從以上信息可以看出，函數(shù)調(diào)用關(guān)系為：main->ha_ha->sleep，因而我們可以找到ha_ha函數(shù)進(jìn)行分析和優(yōu)化修改。

小結(jié)
本文通過(guò)一個(gè)server/client程序事例，說(shuō)明了使用strace和pstack分析響應(yīng)延時(shí)的方法。

由最初server端響應(yīng)慢現(xiàn)象，到使用strace跟蹤出具體耗時(shí)的系統(tǒng)調(diào)用，再到使用pstack查到程序中具體的耗時(shí)函數(shù)，一步步找到了影響程序運(yùn)行時(shí)間的程序代碼。

更多地了解底層，從操作系統(tǒng)層面著手，更有助于程序性能分析與優(yōu)化。

總結(jié)

以上是生活随笔為你收集整理的如何使用strace+pstack利器分析程序性能的全部?jī)?nèi)容，希望文章能夠幫你解決所遇到的問(wèn)題。

如果覺(jué)得生活随笔網(wǎng)站內(nèi)容還不錯(cuò)，歡迎將生活随笔推薦給好友。