改進應用程序的性能是一項非常耗時耗力的工作，但是究竟程序中是哪些函數消耗掉了大部分執行時間，這通常都不是非常明顯的。在本文中我們將學習如何使用 gprof 為 Linux ？？ 平台上的用戶空間和系統調用精確分析性能瓶頸。
簡介
各種軟件對於性能的需求可能會有很大的區別，但是很多應用程序都有非常嚴格的性能需求，這一點並不奇怪。電影播放器就是一個很好的例子：如果一個電影播放器只能以所需要速度的 75% 來播放電影，那麼它幾乎就沒什麼用處了。
其他應用程序（例如視頻編碼）如果是耗時非常長的操作，最好以 “批處理” 任務的方式運行，此時啟動一個作業，讓其一直運行，然後我們就可以去干別的事情了。盡管這些類型的應用程序沒有這種硬性性能指標的限制，但是提高速度仍然會帶來很多好處，例如可以在給定的時間內可以對更多電影進行編碼，在同樣的時間內可以以更高的品質進行編碼。
通常，除了最簡單的應用程序之外，對於其他應用程序來說，性能越好，這個應用程序的用處就越大，也就會越流行。由於這個原因，性能考慮是（也應該是）很多應用程序開發人員腦袋中的第一根弦。
不幸的是，很多嘗試讓應用程序速度更快的努力都白費了，因為開發人員通常都是對自己的軟件進行一些小型的優化，而沒有去研究程序在更大的范圍內是如何操作的。例如，我們可能會花費大量的時間來讓某個特定函數的運行速度達到原來的兩倍，這一點非常不錯，但是如果這個函數很少被調用（例如打開文件），那麼將這個函數的執行時間從 200ms 減少到 100ms，對於整個軟件的總體執行時間來說並不會有太大的影響。
有效地利用您的時間的方法是，盡量優化軟件中被頻繁調用的部分。例如，假設應用程序花了 50% 的時間在字符串處理函數上，如果可以對這些函數進行優化，提高 10% 的效率，那麼應用程序的總體執行時間就會改進 5%.
因此，如果希望能夠有效地對程序進行優化，那麼精確地了解時間在應用程序中是如何花費的，以及真實的輸入數據，這一點非常重要。這種行為就稱為代碼剖析（code profiling）。本文將簡要介紹 GNU 編譯器工具包所提供的一種剖析工具，它的名字讓人可以產生無限遐想，叫 GNU profiler（gprof）。本文主要面向那些開放源碼軟件開發工具的新手。
gprof 來救援了
在開始介紹如何使用 gprof 之前，需要首先了解一下在整個開發周期中，剖析應該在何處進行。通常來說，編寫代碼應該有 3 個目標，按照重要性的次序分別如下所示：
保證軟件可以正確地工作。這通常是開發過程的重點。通常，如果一個軟件根本連我們期望它做的事情都實現不了，那麼即使它運行速度非常快，也根本沒有任何意義！顯然，正確性在某些情況下可能並不是至關重要的；例如，如果一個電影播放器可以正確地播放 99% 的電影文件，但是偶然會有些顯示問題，那它依然可以使用。但是通常來說，正確性要遠遠比速度更加重要。
保證軟件是可維護的。這實際上是第一個目標的一個子項。通常，如果軟件編寫得可維護性不好，那麼即使它最開始時可以很好地工作，很快您（或其他人）在修正 bug 或添加新特性時可能也會破壞程序的正確性。
讓軟件可以快速運行。這就是剖析的用武之地。當軟件可以正確運行之後，我們就可以開始剖析的過程來幫助它更快地運行了。
假設我們現在已經有了一個可以工作的應用程序，接下來讓我們來看一下如何使用 gprof 來精確測量應用程序執行過程中時間都花費到什麼地方去了，這樣做的目的是了解一下在什麼地方進行優化效果最佳。
gprof 可以對 C、C++、Pascal 和 Fortran 77 應用程序進行剖析。本文中的例子使用的是 C.
清單 1. 耗時的應用程序示例
#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); } else iterations = atoi(argv[1]); printf("No of iterations = %d\n", iterations); while(iterations--) { a(); b(); } } 正如我們從代碼中可以看到的，這個非常簡單的應用程序包括兩個函數：a 和 b，它們都處於一個繁忙的循環中消耗 CPU 周期。main 函數中采用了一個循環來反復調用這兩個函數。第二個函數 b 循環的次數是 a 函數的 4 倍，因此我們期望在對代碼分析完之後，可以看出大概有 20% 的時間花在了 a 函數中，而 80% 的時間花在了 b 函數中。下面就開始剖析代碼，並看一下我們的這些期望是否正確。
啟用剖析非常簡單，只需要在 gcc 編譯標志中加上 -pg 即可。編譯方法如下：
gcc example1.c -pg -o example1 -O2 -lc
在編譯好這個應用程序之後，可以按照普通方式運行這個程序：
。/example1 50000
當這個程序運行完之後，應該會看到在當前目錄中新創建了一個文件 gmon.out.
使用輸出結果
首先看一下 “flat profile”，我們可以使用 gprof 命令獲得它，這需要為其傳遞可執行文件和 gmon.out 文件作為參數，如下所示：
gprof example1 gmon.out -p
這會輸出以下內容：
清單 2. flat profile 的結果
Flat profile: Each sample counts as 0.01 seconds. % cumulative self self total time seconds seconds calls ms/call ms/call name 80.24 63.85 63.85 50000 1.28 1.28 b 20.26 79.97 16.12 50000 0.32 0.32 a 從這個輸出結果中可以看到，正如我們期望的一樣，b 函數所花費的時間大概是 a 函數所花費的時間的 4 倍。真正的數字並不是十分有用；由於取整捨入錯誤，這些數字可能並不是非常精確。
聰明的讀者可能會注意到，很多函數調用（例如 printf）在這個輸出中都沒有出現。這是因為這些函數都是在 C 運行時庫（libc.so）中的，（在本例中）它們都沒有使用 -pg 進行編譯，因此就沒有對這個庫中的函數收集剖析信息。稍後我們會回到這個問題上來。
接下來我們希望了解的是 “call graph”，這可以通過下面的方式獲得：
gprof example1 gmon.out -q
這會輸出下面的結果。
清單 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] ----------------------------------------------- 最後，我們可能會希望獲得一個 “帶注解的源代碼” 清單，它會將源代碼輸出到應用程序中，並加上每個函數被調用了多少次的注釋。
要使用這種功能，請使用啟用調試功能的標志來編譯源代碼，這樣源代碼就會被加入可執行程序中：
gcc example1.c -g -pg -o example1 -O2 -lc
像以前一樣重新運行這個應用程序：
。/example1 50000
gprof 命令現在應該是：
gprof example1 gmon.out -A
這會輸出下面的結果：
清單 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); } else iterations = atoi(argv[1]); printf("No of iterations = %d\n", iterations); while(iterations--) { a(); b(); } } Top 10 Lines: Line Count 3 50000 11 50000 Execution Summary: 3 Executable lines in this file 3 Lines executed 100.00 Percent of the file executed 100000 Total number of line executions 33333.33 Average executions per line
共享庫的支持
正如在前面曾經介紹的，對於代碼剖析的支持是由編譯器增加的，因此如果希望從共享庫（包括 C 庫 libc.a）中獲得剖析信息，就需要使用 -pg 來編譯這些庫。幸運的是，很多發行版都提供了已經啟用代碼剖析支持而編譯的 C 庫版本（libc_p.a）。
在我使用的發行版 gentoo 中，需要將 “profile” 添加到 USE 標志中，並重新執行 emerge glibc.當這個過程完成之後，就會看到 /usr/lib/libc_p.a 文件已經創建好了。對於沒有按照標准提供 libc_p 的發行版本來說，需要檢查它是否可以單獨安裝，或者可能需要自己下載 glibc 的源代碼並進行編譯。
在獲得 libc_p.a 文件之後，就可以簡單地重新編譯前面的例子了，方法如下：
gcc example1.c -g -pg -o example1 -O2 -lc_p
然後，可以像以前一樣運行這個應用程序，並獲得 flat profile 或 call graph，應該會看到很多 C 運行函數，包括 printf（這些函數在我們的測試函數中並不是太重要）。
用戶時間與內核時間
現在我們已經知道如何使用 gprof 了，接下來可以簡單且有效地對應用程序進行分析了，希望可以消除性能瓶頸。
不過現在您可能已經注意到了 gprof 的最大缺陷：它只能分析應用程序在運行 過程中所消耗掉的用戶 時間。通常來說，應用程序在運行時既要花費一些時間來運行用戶代碼，也要花費一些時間來運行 “系統代碼”，例如內核系統調用。
如果對清單 1 稍加修改，就可以清楚地看出這個問題：
清單 5. 為清單 1 添加系統調用分析功能
#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); } else iterations = atoi(argv[1]); printf("No of iterations = %d\n", iterations); while(iterations--) { a(); b(); } } 正如您可以看到的，我們對清單 1 中的代碼進行了修改，現在 a 函數和 b 函數不再只處理繁忙的循環了，而是分別調用 C 運行時函數 sleep 來掛起執行 1 秒和 4 秒。
像以前一樣編譯這個應用程序：
gcc example2.c -g -pg -o example2 -O2 -lc_p
並讓這個程序循環 30 次：
。/example2 30
所生成的 flat profile 如下所示：
清單 6. flat profile 顯示了系統調用的結果
Flat profile: Each sample counts as 0.01 seconds. no time accumulated % cumulative self self total time seconds seconds calls Ts/call Ts/call name 0.00 0.00 0.00 120 0.00 0.00 sigprocmask 0.00 0.00 0.00 61 0.00 0.00 __libc_sigaction 0.00 0.00 0.00 61 0.00 0.00 sigaction 0.00 0.00 0.00 60 0.00 0.00 nanosleep 0.00 0.00 0.00 60 0.00 0.00 sleep 0.00 0.00 0.00 30 0.00 0.00 a 0.00 0.00 0.00 30 0.00 0.00 b 0.00 0.00 0.00 21 0.00 0.00 _IO_file_overflow 0.00 0.00 0.00 3 0.00 0.00 _IO_new_file_xsputn 0.00 0.00 0.00 2 0.00 0.00 _IO_new_do_write 0.00 0.00 0.00 2 0.00 0.00 __find_specmb 0.00 0.00 0.00 2 0.00 0.00 __guard_setup 0.00 0.00 0.00 1 0.00 0.00 _IO_default_xsputn 0.00 0.00 0.00 1 0.00 0.00 _IO_doallocbuf 0.00 0.00 0.00 1 0.00 0.00 _IO_file_doallocate 0.00 0.00 0.00 1 0.00 0.00 _IO_file_stat 0.00 0.00 0.00 1 0.00 0.00 _IO_file_write 0.00 0.00 0.00 1 0.00 0.00 _IO_setb 0.00 0.00 0.00 1 0.00 0.00 ____strtol_l_internal 0.00 0.00 0.00 1 0.00 0.00 ___fxstat64 0.00 0.00 0.00 1 0.00 0.00 __cxa_atexit 0.00 0.00 0.00 1 0.00 0.00 __errno_location 0.00 0.00 0.00 1 0.00 0.00 __new_exitfn 0.00 0.00 0.00 1 0.00 0.00 __strtol_internal 0.00 0.00 0.00 1 0.00 0.00 _itoa_Word 0.00 0.00 0.00 1 0.00 0.00 _mcleanup 0.00 0.00 0.00 1 0.00 0.00 atexit 0.00 0.00 0.00 1 0.00 0.00 atoi 0.00 0.00 0.00 1 0.00 0.00 exit 0.00 0.00 0.00 1 0.00 0.00 flockfile 0.00 0.00 0.00 1 0.00 0.00 funlockfile 0.00 0.00 0.00 1 0.00 0.00 main 0.00 0.00 0.00 1 0.00 0.00 mmap 0.00 0.00 0.00 1 0.00 0.00 moncontrol 0.00 0.00 0.00 1 0.00 0.00 new_do_write 0.00 0.00 0.00 1 0.00 0.00 printf 0.00 0.00 0.00 1 0.00 0.00 setitimer 0.00 0.00 0.00 1 0.00 0.00 vfprintf 0.00 0.00 0.00 1 0.00 0.00 write 如果對這個輸出結果進行分析，我們就會看到，盡管 profiler 已經記錄了每個函數被調用的確切次數，但是為這些函數記錄的時間（實際上是所有函數）都是 0.00.這是因為 sleep 函數實際上是執行了一次對內核空間的調用，從而將應用程序的執行掛起了，然後有效地暫停執行，並等待內核再次將其喚醒。由於花在用戶空間執行的時間與花在內核中睡眠的時間相比非常小，因此就被取整成零了。其原因是 gprof 僅僅是通過以固定的周期對程序運行時間 進行采樣測量來工作的。因此，當程序不運行時，就不會對程序進行采樣測量。
這實際上是一把雙刃劍。從一個方面來說，這使得有些程序非常難以進行優化，例如花費大部分時間在內核空間的程序，或者由於外部因素（例如操作系統的 I/O 子系統過載）而運行得非常慢的程序。從另一個方面來說，這意味著剖析不會受到系統中其他事件的影響（例如另外一個用戶使用了大量的 CPU 時間）。
通常，有一個很好的基准測試可以用來查看 gprof 對於幫助對應用程序進行優化是多麼有用，方法是在 time 命令下面執行它。這個命令會顯示一個應用程序運行完成需要多少時間，並可以測量它在用戶空間和內核空間各花費了多少時間。
如果查看一下清單 2 中的例子：
time ./example2 30
輸出結果應該如下所示：
清單 7. time 命令的輸出結果
No of iterations = 30 real 2m30.295s user 0m0.000s sys 0m0.004s 我們可以看出幾乎沒有多少時間被花費在執行用戶空間的代碼上，因此 gprof 在此處不會非常有用。
結束語
盡管 gprof 存在上面的限制，但是它對於優化代碼來說依然是個非常有用的工具，如果您的代碼大部分是用戶空間 CPU 密集型的，它的用處就更加明顯。首先使用 time 來運行程序從而判斷 gprof 是否能產生有用信息是個好主意。
如果 gprof 不適合您的剖析需要，那麼還有其他一些工具可以克服 gprof 部分缺陷，包括 OProfile 和 Sysprof （請參看 參考資料 中有關這些工具信息的鏈接）。
從另一個方面來說，假設我們已經安裝了 gcc，gprof 相對於其他工具來說，一個主要的優點是很可能早已在 Linux 機器上安裝了需要使用的工具。
關於作者
Martyn Honeyford 1996 年畢業於諾丁漢大學，獲計算機科學學士學位。從那時起，他就成為位於英格蘭 Hursley 的 IBM 英國實驗室的一名軟件工程師。他目前的職務是 WebSphere MQ Everyplace 開發團隊中的一名開發人員。在不工作的時候，他經常彈電吉他（彈得很差）或者瘋狂地玩電子游戲。可以通過 [email protected] 與 Martyn 聯系。