使用 GNU profiler 來提高代碼運(yùn)行速度

Martyn Honeyford (martynh@uk.ibm.com), 軟件工程師, IBM UK Labs Martyn Honeyford 1996 年畢業(yè)于諾丁漢大學(xué)，獲計(jì)算機(jī)科學(xué)學(xué)士學(xué)位。從那時(shí)起，他就成為位于英格蘭 Hursley 的 IBM 英國實(shí)驗(yàn)室的一名軟件工程師。他目前的職務(wù)是 WebSphere MQ Everyplace 開發(fā)團(tuán)隊(duì)中的一名開發(fā)人員。在不工作的時(shí)候，他經(jīng)常彈電吉他（彈得很差）或者瘋狂地玩電子游戲。可以通過 martynh@uk.ibm.com 與 Martyn 聯(lián)系。

?

簡介：?改進(jìn)應(yīng)用程序的性能是一項(xiàng)非常耗時(shí)耗力的工作，但是究竟程序中是哪些函數(shù)消耗掉了大部分執(zhí)行時(shí)間，這通常都不是非常明顯的。在本文中我們將學(xué)習(xí)如何使用 gprof 為 Linux ?? 平臺上的用戶空間和系統(tǒng)調(diào)用精確分析性能瓶頸。

簡介

各種軟件對于性能的需求可能會(huì)有很大的區(qū)別，但是很多應(yīng)用程序都有非常嚴(yán)格的性能需求，這一點(diǎn)并不奇怪。電影播放器就是一個(gè)很好的例子：如果一個(gè)電影播放器只能以所需要速度的 75% 來播放電影，那么它幾乎就沒什么用處了。

其他應(yīng)用程序（例如視頻編碼）如果是耗時(shí)非常長的操作，最好以 “批處理” 任務(wù)的方式運(yùn)行，此時(shí)啟動(dòng)一個(gè)作業(yè)，讓其一直運(yùn)行，然后我們就可以去干別的事情了。盡管這些類型的應(yīng)用程序沒有這種硬性性能指標(biāo)的限制，但是提高速度仍然會(huì)帶來很多好處，例如可以在給定的時(shí)間內(nèi)可以對更多電影進(jìn)行編碼，在同樣的時(shí)間內(nèi)可以以更高的品質(zhì)進(jìn)行編碼。

通常，除了最簡單的應(yīng)用程序之外，對于其他應(yīng)用程序來說，性能越好，這個(gè)應(yīng)用程序的用處就越大，也就會(huì)越流行。由于這個(gè)原因，性能考慮是（也應(yīng)該是）很多應(yīng)用程序開發(fā)人員腦袋中的第一根弦。

不幸的是，很多嘗試讓應(yīng)用程序速度更快的努力都白費(fèi)了，因?yàn)殚_發(fā)人員通常都是對自己的軟件進(jìn)行一些小型的優(yōu)化，而沒有去研究程序在更大的范圍內(nèi)是如何操作的。例如，我們可能會(huì)花費(fèi)大量的時(shí)間來讓某個(gè)特定函數(shù)的運(yùn)行速度達(dá)到原來的兩倍，這一點(diǎn)非常不錯(cuò)，但是如果這個(gè)函數(shù)很少被調(diào)用（例如打開文件），那么將這個(gè)函數(shù)的執(zhí)行時(shí)間從 200ms 減少到 100ms，對于整個(gè)軟件的總體執(zhí)行時(shí)間來說并不會(huì)有太大的影響。

有效地利用您的時(shí)間的方法是，盡量優(yōu)化軟件中被頻繁調(diào)用的部分。例如，假設(shè)應(yīng)用程序花了 50% 的時(shí)間在字符串處理函數(shù)上，如果可以對這些函數(shù)進(jìn)行優(yōu)化，提高 10% 的效率，那么應(yīng)用程序的總體執(zhí)行時(shí)間就會(huì)改進(jìn) 5%。

因此，如果希望能夠有效地對程序進(jìn)行優(yōu)化，那么精確地了解時(shí)間在應(yīng)用程序中是如何花費(fèi)的，以及真實(shí)的輸入數(shù)據(jù)，這一點(diǎn)非常重要。這種行為就稱為代碼剖析（code profiling）。本文將簡要介紹 GNU 編譯器工具包所提供的一種剖析工具，它的名字讓人可以產(chǎn)生無限遐想，叫 GNU profiler（gprof）。本文主要面向那些開放源碼軟件開發(fā)工具的新手。

gprof 來救援了

在開始介紹如何使用 gprof 之前，需要首先了解一下在整個(gè)開發(fā)周期中，剖析應(yīng)該在何處進(jìn)行。通常來說，編寫代碼應(yīng)該有 3 個(gè)目標(biāo)，按照重要性的次序分別如下所示：

保證軟件可以正確地工作。這通常是開發(fā)過程的重點(diǎn)。通常，如果一個(gè)軟件根本連我們期望它做的事情都實(shí)現(xiàn)不了，那么即使它運(yùn)行速度非常快，也根本沒有任何意義！顯然，正確性在某些情況下可能并不是至關(guān)重要的；例如，如果一個(gè)電影播放器可以正確地播放 99% 的電影文件，但是偶然會(huì)有些顯示問題，那它依然可以使用。但是通常來說，正確性要遠(yuǎn)遠(yuǎn)比速度更加重要。

保證軟件是可維護(hù)的。這實(shí)際上是第一個(gè)目標(biāo)的一個(gè)子項(xiàng)。通常，如果軟件編寫得可維護(hù)性不好，那么即使它最開始時(shí)可以很好地工作，很快您（或其他人）在修正 bug 或添加新特性時(shí)可能也會(huì)破壞程序的正確性。

讓軟件可以快速運(yùn)行。這就是剖析的用武之地。當(dāng)軟件可以正確運(yùn)行之后，我們就可以開始剖析的過程來幫助它更快地運(yùn)行了。

?

假設(shè)我們現(xiàn)在已經(jīng)有了一個(gè)可以工作的應(yīng)用程序，接下來讓我們來看一下如何使用 gprof 來精確測量應(yīng)用程序執(zhí)行過程中時(shí)間都花費(fèi)到什么地方去了，這樣做的目的是了解一下在什么地方進(jìn)行優(yōu)化效果最佳。

gprof 可以對 C、C++、Pascal 和 Fortran 77 應(yīng)用程序進(jìn)行剖析。本文中的例子使用的是 C。

清單 1. 耗時(shí)的應(yīng)用程序示例

#include <stdio.h> int a(void) {int i=0,g=0;while(i++<100000){g+=i;}return g; } int b(void) {int i=0,g=0;while(i++<400000){g+=i;}return g; } int main(int argc, char** argv) {int iterations;if(argc != 2){printf("Usage %s <No of Iterations>/n", argv[0]);exit(-1);}elseiterations = atoi(argv[1]);printf("No of iterations = %d/n", iterations);while(iterations--){a();b();} }

正如我們從代碼中可以看到的，這個(gè)非常簡單的應(yīng)用程序包括兩個(gè)函數(shù)：a 和 b，它們都處于一個(gè)繁忙的循環(huán)中消耗 CPU 周期。main 函數(shù)中采用了一個(gè)循環(huán)來反復(fù)調(diào)用這兩個(gè)函數(shù)。第二個(gè)函數(shù) b 循環(huán)的次數(shù)是 a 函數(shù)的 4 倍，因此我們期望在對代碼分析完之后，可以看出大概有 20% 的時(shí)間花在了 a 函數(shù)中，而 80% 的時(shí)間花在了 b 函數(shù)中。下面就開始剖析代碼，并看一下我們的這些期望是否正確。

啟用剖析非常簡單，只需要在 gcc 編譯標(biāo)志中加上 -pg 即可。編譯方法如下：

gcc example1.c -pg -o example1 -O2 -lc

在編譯好這個(gè)應(yīng)用程序之后，可以按照普通方式運(yùn)行這個(gè)程序：

./example1 50000

當(dāng)這個(gè)程序運(yùn)行完之后，應(yīng)該會(huì)看到在當(dāng)前目錄中新創(chuàng)建了一個(gè)文件 gmon.out。

使用輸出結(jié)果

首先看一下 “flat profile”，我們可以使用 gprof 命令獲得它，這需要為其傳遞可執(zhí)行文件和 gmon.out 文件作為參數(shù)，如下所示：

gprof example1 gmon.out -p

這會(huì)輸出以下內(nèi)容：

清單 2. flat profile 的結(jié)果

Flat profile: Each sample counts as 0.01 seconds.% cumulative self self totaltime seconds seconds calls ms/call ms/call name80.24 63.85 63.85 50000 1.28 1.28 b20.26 79.97 16.12 50000 0.32 0.32 a

從這個(gè)輸出結(jié)果中可以看到，正如我們期望的一樣，b 函數(shù)所花費(fèi)的時(shí)間大概是 a 函數(shù)所花費(fèi)的時(shí)間的 4 倍。真正的數(shù)字并不是十分有用；由于取整舍入錯(cuò)誤，這些數(shù)字可能并不是非常精確。

聰明的讀者可能會(huì)注意到，很多函數(shù)調(diào)用（例如 printf）在這個(gè)輸出中都沒有出現(xiàn)。這是因?yàn)檫@些函數(shù)都是在 C 運(yùn)行時(shí)庫（libc.so）中的，（在本例中）它們都沒有使用 -pg 進(jìn)行編譯，因此就沒有對這個(gè)庫中的函數(shù)收集剖析信息。稍后我們會(huì)回到這個(gè)問題上來。

接下來我們希望了解的是 “call graph”，這可以通過下面的方式獲得：

gprof example1 gmon.out -q

這會(huì)輸出下面的結(jié)果。

清單 3. Call graph

Call graph (explanation follows) granularity: each sample hit covers 2 byte(s) for 0.01% of 79.97 seconds index % time self children called name<spontaneous> [1] 100.0 0.00 79.97 main [1]63.85 0.00 50000/50000 b [2]16.12 0.00 50000/50000 a [3] -----------------------------------------------63.85 0.00 50000/50000 main [1] [2] 79.8 63.85 0.00 50000 b [2] -----------------------------------------------16.12 0.00 50000/50000 main [1] [3] 20.2 16.12 0.00 50000 a [3] -----------------------------------------------

最后，我們可能會(huì)希望獲得一個(gè) “帶注解的源代碼” 清單，它會(huì)將源代碼輸出到應(yīng)用程序中，并加上每個(gè)函數(shù)被調(diào)用了多少次的注釋。

要使用這種功能，請使用啟用調(diào)試功能的標(biāo)志來編譯源代碼，這樣源代碼就會(huì)被加入可執(zhí)行程序中：

gcc example1.c -g -pg -o example1 -O2 -lc

像以前一樣重新運(yùn)行這個(gè)應(yīng)用程序：

./example1 50000

gprof 命令現(xiàn)在應(yīng)該是：

gprof example1 gmon.out -A

這會(huì)輸出下面的結(jié)果：

清單 4. 帶注釋的源代碼

*** File /home/martynh/profarticle/example1.c:#include <stdio.h>50000 -> int a(void) {int i=0,g=0;while(i++<100000){g+=i;}return g;}50000 -> int b(void) {int i=0,g=0;while(i++<400000){g+=i;}return g;}int main(int argc, char** argv)##### -> {int iterations;if(argc != 2){printf("Usage %s <No of Iterations>/n", argv[0]);exit(-1);}elseiterations = atoi(argv[1]);printf("No of iterations = %d/n", iterations);while(iterations--){a();b();}} Top 10 Lines:Line Count3 5000011 50000 Execution Summary:3 Executable lines in this file3 Lines executed100.00 Percent of the file executed100000 Total number of line executions33333.33 Average executions per line

共享庫的支持

正如在前面曾經(jīng)介紹的，對于代碼剖析的支持是由編譯器增加的，因此如果希望從共享庫（包括 C 庫 libc.a）中獲得剖析信息，就需要使用 -pg 來編譯這些庫。幸運(yùn)的是，很多發(fā)行版都提供了已經(jīng)啟用代碼剖析支持而編譯的 C 庫版本（libc_p.a）。

在我使用的發(fā)行版 gentoo 中，需要將 “profile” 添加到 USE 標(biāo)志中，并重新執(zhí)行 emerge glibc。當(dāng)這個(gè)過程完成之后，就會(huì)看到 /usr/lib/libc_p.a 文件已經(jīng)創(chuàng)建好了。對于沒有按照標(biāo)準(zhǔn)提供 libc_p 的發(fā)行版本來說，需要檢查它是否可以單獨(dú)安裝，或者可能需要自己下載 glibc 的源代碼并進(jìn)行編譯。

在獲得 libc_p.a 文件之后，就可以簡單地重新編譯前面的例子了，方法如下：

gcc example1.c -g -pg -o example1 -O2 -lc_p

然后，可以像以前一樣運(yùn)行這個(gè)應(yīng)用程序，并獲得 flat profile 或 call graph，應(yīng)該會(huì)看到很多 C 運(yùn)行函數(shù)，包括 printf（這些函數(shù)在我們的測試函數(shù)中并不是太重要）。

用戶時(shí)間與內(nèi)核時(shí)間

現(xiàn)在我們已經(jīng)知道如何使用 gprof 了，接下來可以簡單且有效地對應(yīng)用程序進(jìn)行分析了，希望可以消除性能瓶頸。

不過現(xiàn)在您可能已經(jīng)注意到了 gprof 的最大缺陷：它只能分析應(yīng)用程序在運(yùn)行 過程中所消耗掉的用戶 時(shí)間。通常來說，應(yīng)用程序在運(yùn)行時(shí)既要花費(fèi)一些時(shí)間來運(yùn)行用戶代碼，也要花費(fèi)一些時(shí)間來運(yùn)行 “系統(tǒng)代碼”，例如內(nèi)核系統(tǒng)調(diào)用。

如果對清單 1 稍加修改，就可以清楚地看出這個(gè)問題：

清單 5. 為清單 1 添加系統(tǒng)調(diào)用分析功能

#include <stdio.h> int a(void) {sleep(1);return 0; } int b(void) {sleep(4);return 0; } int main(int argc, char** argv) {int iterations;if(argc != 2){printf("Usage %s <No of Iterations>/n", argv[0]);exit(-1);}elseiterations = atoi(argv[1]);printf("No of iterations = %d/n", iterations);while(iterations--){a();b();} }

正如您可以看到的，我們對清單 1 中的代碼進(jìn)行了修改，現(xiàn)在 a 函數(shù)和 b 函數(shù)不再只處理繁忙的循環(huán)了，而是分別調(diào)用 C 運(yùn)行時(shí)函數(shù) sleep 來掛起執(zhí)行 1 秒和 4 秒。

像以前一樣編譯這個(gè)應(yīng)用程序：

gcc example2.c -g -pg -o example2 -O2 -lc_p

并讓這個(gè)程序循環(huán) 30 次：

./example2 30

所生成的 flat profile 如下所示：

清單 6. flat profile 顯示了系統(tǒng)調(diào)用的結(jié)果

Flat profile: Each sample counts as 0.01 seconds.no time accumulated% cumulative self self totaltime seconds seconds calls Ts/call Ts/call name0.00 0.00 0.00 120 0.00 0.00 sigprocmask0.00 0.00 0.00 61 0.00 0.00 __libc_sigaction0.00 0.00 0.00 61 0.00 0.00 sigaction0.00 0.00 0.00 60 0.00 0.00 nanosleep0.00 0.00 0.00 60 0.00 0.00 sleep0.00 0.00 0.00 30 0.00 0.00 a0.00 0.00 0.00 30 0.00 0.00 b0.00 0.00 0.00 21 0.00 0.00 _IO_file_overflow0.00 0.00 0.00 3 0.00 0.00 _IO_new_file_xsputn0.00 0.00 0.00 2 0.00 0.00 _IO_new_do_write0.00 0.00 0.00 2 0.00 0.00 __find_specmb0.00 0.00 0.00 2 0.00 0.00 __guard_setup0.00 0.00 0.00 1 0.00 0.00 _IO_default_xsputn0.00 0.00 0.00 1 0.00 0.00 _IO_doallocbuf0.00 0.00 0.00 1 0.00 0.00 _IO_file_doallocate0.00 0.00 0.00 1 0.00 0.00 _IO_file_stat0.00 0.00 0.00 1 0.00 0.00 _IO_file_write0.00 0.00 0.00 1 0.00 0.00 _IO_setb0.00 0.00 0.00 1 0.00 0.00 ____strtol_l_internal0.00 0.00 0.00 1 0.00 0.00 ___fxstat640.00 0.00 0.00 1 0.00 0.00 __cxa_atexit0.00 0.00 0.00 1 0.00 0.00 __errno_location0.00 0.00 0.00 1 0.00 0.00 __new_exitfn0.00 0.00 0.00 1 0.00 0.00 __strtol_internal0.00 0.00 0.00 1 0.00 0.00 _itoa_word0.00 0.00 0.00 1 0.00 0.00 _mcleanup0.00 0.00 0.00 1 0.00 0.00 atexit0.00 0.00 0.00 1 0.00 0.00 atoi0.00 0.00 0.00 1 0.00 0.00 exit0.00 0.00 0.00 1 0.00 0.00 flockfile0.00 0.00 0.00 1 0.00 0.00 funlockfile0.00 0.00 0.00 1 0.00 0.00 main0.00 0.00 0.00 1 0.00 0.00 mmap0.00 0.00 0.00 1 0.00 0.00 moncontrol0.00 0.00 0.00 1 0.00 0.00 new_do_write0.00 0.00 0.00 1 0.00 0.00 printf0.00 0.00 0.00 1 0.00 0.00 setitimer0.00 0.00 0.00 1 0.00 0.00 vfprintf0.00 0.00 0.00 1 0.00 0.00 write

如果對這個(gè)輸出結(jié)果進(jìn)行分析，我們就會(huì)看到，盡管 profiler 已經(jīng)記錄了每個(gè)函數(shù)被調(diào)用的確切次數(shù)，但是為這些函數(shù)記錄的時(shí)間（實(shí)際上是所有函數(shù)）都是 0.00。這是因?yàn)?sleep 函數(shù)實(shí)際上是執(zhí)行了一次對內(nèi)核空間的調(diào)用，從而將應(yīng)用程序的執(zhí)行掛起了，然后有效地暫停執(zhí)行，并等待內(nèi)核再次將其喚醒。由于花在用戶空間執(zhí)行的時(shí)間與花在內(nèi)核中睡眠的時(shí)間相比非常小，因此就被取整成零了。其原因是 gprof 僅僅是通過以固定的周期對程序運(yùn)行時(shí)間 進(jìn)行采樣測量來工作的。因此，當(dāng)程序不運(yùn)行時(shí)，就不會(huì)對程序進(jìn)行采樣測量。

這實(shí)際上是一把雙刃劍。從一個(gè)方面來說，這使得有些程序非常難以進(jìn)行優(yōu)化，例如花費(fèi)大部分時(shí)間在內(nèi)核空間的程序，或者由于外部因素（例如操作系統(tǒng)的 I/O 子系統(tǒng)過載）而運(yùn)行得非常慢的程序。從另一個(gè)方面來說，這意味著剖析不會(huì)受到系統(tǒng)中其他事件的影響（例如另外一個(gè)用戶使用了大量的 CPU 時(shí)間）。

通常，有一個(gè)很好的基準(zhǔn)測試可以用來查看 gprof 對于幫助對應(yīng)用程序進(jìn)行優(yōu)化是多么有用，方法是在 time 命令下面執(zhí)行它。這個(gè)命令會(huì)顯示一個(gè)應(yīng)用程序運(yùn)行完成需要多少時(shí)間，并可以測量它在用戶空間和內(nèi)核空間各花費(fèi)了多少時(shí)間。

如果查看一下清單 2 中的例子：

time ./example2 30

輸出結(jié)果應(yīng)該如下所示：

清單 7. time 命令的輸出結(jié)果

No of iterations = 30 real 2m30.295s user 0m0.000s sys 0m0.004s

我們可以看出幾乎沒有多少時(shí)間被花費(fèi)在執(zhí)行用戶空間的代碼上，因此 gprof 在此處不會(huì)非常有用。

結(jié)束語

盡管 gprof 存在上面的限制，但是它對于優(yōu)化代碼來說依然是個(gè)非常有用的工具，如果您的代碼大部分是用戶空間 CPU 密集型的，它的用處就更加明顯。首先使用 time 來運(yùn)行程序從而判斷 gprof 是否能產(chǎn)生有用信息是個(gè)好主意。

如果 gprof 不適合您的剖析需要，那么還有其他一些工具可以克服 gprof 部分缺陷，包括 OProfile 和 Sysprof （請參看 參考資料 中有關(guān)這些工具信息的鏈接）。

從另一個(gè)方面來說，假設(shè)我們已經(jīng)安裝了 gcc，gprof 相對于其他工具來說，一個(gè)主要的優(yōu)點(diǎn)是很可能早已在 Linux 機(jī)器上安裝了需要使用的工具。

參考資料

學(xué)習(xí)

• 您可以參閱本文在 developerWorks 全球站點(diǎn)上的 英文原文。
  
• 有關(guān)使用 gprof 的更多信息，請參閱 GNU profiler 手冊。
  
  轉(zhuǎn)載地址：http://www.ibm.com/developerworks/cn/linux/l-gnuprof.html

總結(jié)

以上是生活随笔為你收集整理的gprof 使用例程（转）的全部內(nèi)容，希望文章能夠幫你解決所遇到的問題。

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