使用 GNU profiler 來提高代碼運(yùn)行速度（轉(zhuǎn)載）

lvjunonline

使用 GNU profiler 來提高代碼運(yùn)行速度尋找應(yīng)用程序中占用時間最長的部分
級別： 初級
Martyn Honeyford
(
[email=martynh@uk.ibm.com?subject=%E4%BD%BF%E7%94%A8%20GNU%20profiler%20%E6%9D%A5%E6%8F%90%E9%AB%98%E4%BB%A3%E7%A0%81%E8%BF%90%E8%A1%8C%E9%80%9F%E5%BA%A6]martynh@uk.ibm.com[/email]
), 軟件工程師, IBM UK Labs
2006 年  5 月  08 日
改進(jìn)應(yīng)用程序的性能是一項非常耗時耗力的工作，但是究竟程序中是哪些函數(shù)消耗掉了大部分執(zhí)行時間，這通常都不是非常明顯的。在本文中我們將學(xué)習(xí)如何使用 gprof 為 Linux ®™ 平臺上的用戶空間和系統(tǒng)調(diào)用精確分析性能瓶頸。
簡介
各種軟件對于性能的需求可能會有很大的區(qū)別，但是很多應(yīng)用程序都有非常嚴(yán)格的性能需求，這一點(diǎn)并不奇怪。電影播放器就是一個很好的例子：如果一個電影播放器只能以所需要速度的 75% 來播放電影，那么它幾乎就沒什么用處了。
其他應(yīng)用程序（例如視頻編碼）如果是耗時非常長的操作，最好以 “批處理”
任務(wù)的方式運(yùn)行，此時啟動一個作業(yè)，讓其一直運(yùn)行，然后我們就可以去干別的事情了。盡管這些類型的應(yīng)用程序沒有這種硬性性能指標(biāo)的限制，但是提高速度仍然
會帶來很多好處，例如可以在給定的時間內(nèi)可以對更多電影進(jìn)行編碼，在同樣的時間內(nèi)可以以更高的品質(zhì)進(jìn)行編碼。
通常，除了最簡單的應(yīng)用程序之外，對于其他應(yīng)用程序來說，性能越好，這個應(yīng)用程序的用處就越大，也就會越流行。由于這個原因，性能考慮是（也應(yīng)該是）很多應(yīng)用程序開發(fā)人員腦袋中的第一根弦。
不幸的是，很多嘗試讓應(yīng)用程序速度更快的努力都白費(fèi)了，因為開發(fā)人員通常都是對自己的軟件進(jìn)行一些小型的優(yōu)化，而沒有去研究程序在更
大的范圍內(nèi)是如何操作的。例如，我們可能會花費(fèi)大量的時間來讓某個特定函數(shù)的運(yùn)行速度達(dá)到原來的兩倍，這一點(diǎn)非常不錯，但是如果這個函數(shù)很少被調(diào)用（例如
打開文件），那么將這個函數(shù)的執(zhí)行時間從 200ms 減少到 100ms，對于整個軟件的總體執(zhí)行時間來說并不會有太大的影響。
有效地利用您的時間的方法是，盡量優(yōu)化軟件中被頻繁調(diào)用的部分。例如，假設(shè)應(yīng)用程序花了 50% 的時間在字符串處理函數(shù)上，如果可以對這些函數(shù)進(jìn)行優(yōu)化，提高 10% 的效率，那么應(yīng)用程序的總體執(zhí)行時間就會改進(jìn) 5%。
因此，如果希望能夠有效地對程序進(jìn)行優(yōu)化，那么精確地了解時間在應(yīng)用程序中是如何花費(fèi)的，以及真實(shí)的輸入數(shù)據(jù)，這一點(diǎn)非常重要。這種行為就稱為代碼剖析（code profiling）。本文將簡要介紹 GNU 編譯器工具包所提供的一種剖析工具，它的名字讓人可以產(chǎn)生無限遐想，叫 GNU profiler（gprof）。本文主要面向那些開放源碼軟件開發(fā)工具的新手。
gprof 來救援了
在開始介紹如何使用 gprof 之前，需要首先了解一下在整個開發(fā)周期中，剖析應(yīng)該在何處進(jìn)行。通常來說，編寫代碼應(yīng)該有 3 個目標(biāo)，按照重要性的次序分別如下所示：

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

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

讓軟件可以快速運(yùn)行。這就是剖析的用武之地。當(dāng)軟件可以正確運(yùn)行之后，我們就可以開始剖析的過程來幫助它更快地運(yùn)行了。
假設(shè)我們現(xiàn)在已經(jīng)有了一個可以工作的應(yīng)用程序，接下來讓我們來看一下如何使用 gprof 來精確測量應(yīng)用程序執(zhí)行過程中時間都花費(fèi)到什么地方去了，這樣做的目的是了解一下在什么地方進(jìn)行優(yōu)化效果最佳。
gprof 可以對 C、C++、Pascal 和 Fortran 77 應(yīng)用程序進(jìn)行剖析。本文中的例子使用的是 C。
清單 1. 耗時的應(yīng)用程序示例
#include
int a(void) {
  int i=0,g=0;
  while(i++\n", argv[0]);
      exit(-1);
   }
   else
      iterations = atoi(argv[1]);
   printf("No of iterations = %d\n", iterations);
   while(iterations--)
   {
      a();
      b();
   }
}
正如我們從代碼中可以看到的，這個非常簡單的應(yīng)用程序包括兩個函數(shù)：a 和 b，它們都處于一個繁忙的循環(huán)中消耗 CPU 周期。main 函數(shù)中采用了一個循環(huán)來反復(fù)調(diào)用這兩個函數(shù)。第二個函數(shù) b 循環(huán)的次數(shù)是 a 函數(shù)的 4 倍，因此我們期望在對代碼分析完之后，可以看出大概有 20% 的時間花在了 a 函數(shù)中，而 80% 的時間花在了 b 函數(shù)中。下面就開始剖析代碼，并看一下我們的這些期望是否正確。
啟用剖析非常簡單，只需要在 gcc 編譯標(biāo)志中加上 -pg 即可。編譯方法如下：
gcc example1.c -pg -o example1 -O2 -lc
在編譯好這個應(yīng)用程序之后，可以按照普通方式運(yùn)行這個程序：
./example1 50000
當(dāng)這個程序運(yùn)行完之后，應(yīng)該會看到在當(dāng)前目錄中新創(chuàng)建了一個文件 gmon.out。
使用輸出結(jié)果
首先看一下 “flat profile”，我們可以使用 gprof 命令獲得它，這需要為其傳遞可執(zhí)行文件和 gmon.out 文件作為參數(shù)，如下所示：
gprof example1 gmon.out -p
這會輸出以下內(nèi)容：
清單 2. flat profile 的結(jié)果
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
從這個輸出結(jié)果中可以看到，正如我們期望的一樣，b 函數(shù)所花費(fèi)的時間大概是 a 函數(shù)所花費(fèi)的時間的 4 倍。真正的數(shù)字并不是十分有用；由于取整舍入錯誤，這些數(shù)字可能并不是非常精確。
聰明的讀者可能會注意到，很多函數(shù)調(diào)用（例如 printf）在這個輸出中都沒有出現(xiàn)。這是因為這些函數(shù)都是在 C 運(yùn)行時庫（libc.so）中的，（在本例中）它們都沒有使用 -pg 進(jìn)行編譯，因此就沒有對這個庫中的函數(shù)收集剖析信息。稍后我們會回到這個問題上來。
接下來我們希望了解的是 “call graph”，這可以通過下面的方式獲得：
gprof example1 gmon.out -q
這會輸出下面的結(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
                                                
[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]
-----------------------------------------------
最后，我們可能會希望獲得一個 “帶注解的源代碼” 清單，它會將源代碼輸出到應(yīng)用程序中，并加上每個函數(shù)被調(diào)用了多少次的注釋。
要使用這種功能，請使用啟用調(diào)試功能的標(biāo)志來編譯源代碼，這樣源代碼就會被加入可執(zhí)行程序中：
gcc example1.c -g -pg -o example1 -O2 -lc
像以前一樣重新運(yùn)行這個應(yīng)用程序：
./example1 50000
gprof 命令現(xiàn)在應(yīng)該是：
gprof example1 gmon.out -A
這會輸出下面的結(jié)果：
清單 4. 帶注釋的源代碼
*** File /home/martynh/profarticle/example1.c:
                #include
       50000 -> int a(void) {
                  int i=0,g=0;
                  while(i++ int b(void) {
                  int i=0,g=0;
                  while(i++ {
                   int iterations;
                   if(argc != 2)
                   {
                      printf("Usage %s \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
共享庫的支持
正如在前面曾經(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)這個過程完成之后，就會看到 /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)行這個應(yīng)用程序，并獲得 flat profile 或 call graph，應(yīng)該會看到很多 C 運(yùn)行函數(shù)，包括 printf（這些函數(shù)在我們的測試函數(shù)中并不是太重要）。
用戶時間與內(nèi)核時間
現(xiàn)在我們已經(jīng)知道如何使用 gprof 了，接下來可以簡單且有效地對應(yīng)用程序進(jìn)行分析了，希望可以消除性能瓶頸。
不過現(xiàn)在您可能已經(jīng)注意到了 gprof 的最大缺陷：它只能分析應(yīng)用程序在運(yùn)行 過程中所消耗掉的用戶 時間。通常來說，應(yīng)用程序在運(yùn)行時既要花費(fèi)一些時間來運(yùn)行用戶代碼，也要花費(fèi)一些時間來運(yùn)行 “系統(tǒng)代碼”，例如內(nèi)核系統(tǒng)調(diào)用。
如果對清單 1 稍加修改，就可以清楚地看出這個問題：
清單 5. 為清單 1 添加系統(tǒng)調(diào)用分析功能
#include
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 \n", argv[0]);
      exit(-1);
   }
   else
      iterations = 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ù) sleep 來掛起執(zhí)行 1 秒和 4 秒。
像以前一樣編譯這個應(yīng)用程序：
gcc example2.c -g -pg -o example2 -O2 -lc_p
并讓這個程序循環(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     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
如果對這個輸出結(jié)果進(jìn)行分析，我們就會看到，盡管 profiler 已經(jīng)記錄了每個函數(shù)被調(diào)用的確切次數(shù)，但是為這些函數(shù)記錄的時間（實(shí)際上是所有函數(shù)）都是 0.00。這是因為 sleep 函數(shù)實(shí)際上是執(zhí)行了一次對內(nèi)核空間的調(diào)用，從而將應(yīng)用程序的執(zhí)行掛起了，然后有效地暫停執(zhí)行，并等待內(nèi)核再次將其喚醒。由于花在用戶空間執(zhí)行的時間與花在內(nèi)核中睡眠的時間相比非常小，因此就被取整成零了。其原因是 gprof 僅僅是通過以固定的周期對程序運(yùn)行時間 進(jìn)行采樣測量來工作的。因此，當(dāng)程序不運(yùn)行時，就不會對程序進(jìn)行采樣測量。
這實(shí)際上是一把雙刃劍。從一個方面來說，這使得有些程序非常難以進(jìn)行優(yōu)化，例如花費(fèi)大部分時間在內(nèi)核空間的程序，或者由于外部因素（例如操作系統(tǒng)的
I/O 子系統(tǒng)過載）而運(yùn)行得非常慢的程序。從另一個方面來說，這意味著剖析不會受到系統(tǒng)中其他事件的影響（例如另外一個用戶使用了大量的 CPU
時間）。
通常，有一個很好的基準(zhǔn)測試可以用來查看 gprof 對于幫助對應(yīng)用程序進(jìn)行優(yōu)化是多么有用，方法是在 time 命令下面執(zhí)行它。這個命令會顯示一個應(yīng)用程序運(yùn)行完成需要多少時間，并可以測量它在用戶空間和內(nèi)核空間各花費(fèi)了多少時間。
如果查看一下清單 2 中的例子：
time ./example2 30
輸出結(jié)果應(yīng)該如下所示：
清單 7. time 命令的輸出結(jié)果
No of iterations = 30
real    2m30.295s
user    0m0.000s
sys     0m0.004s
我們可以看出幾乎沒有多少時間被花費(fèi)在執(zhí)行用戶空間的代碼上，因此 gprof 在此處不會非常有用。
結(jié)束語
盡管 gprof 存在上面的限制，但是它對于優(yōu)化代碼來說依然是個非常有用的工具，如果您的代碼大部分是用戶空間 CPU 密集型的，它的用處就更加明顯。首先使用 time 來運(yùn)行程序從而判斷 gprof 是否能產(chǎn)生有用信息是個好主意。
如果 gprof 不適合您的剖析需要，那么還有其他一些工具可以克服 gprof 部分缺陷，包括 OProfile 和 Sysprof （請參看
參考資料
中有關(guān)這些工具信息的鏈接）。
從另一個方面來說，假設(shè)我們已經(jīng)安裝了 gcc，gprof 相對于其他工具來說，一個主要的優(yōu)點(diǎn)是很可能早已在 Linux 機(jī)器上安裝了需要使用的工具。
參考資料
學(xué)習(xí)

• 您可以參閱本文在 developerWorks 全球站點(diǎn)上的
  英文原文
  。
  
• 
  有關(guān)使用 gprof 的更多信息，請參閱
  GNU profiler 手冊
  。
  
• 
  在 “
  使用 OProfile for Linux on POWER 識別性能瓶頸
  ”（developerWorks，2005 年 5 月）和 “
  用 OProfile 徹底了解性能
  ”（developerWorks，2003 年 10 月）中學(xué)習(xí)更多有關(guān) OProfile 的知識。
  
• 
  請訪問
  OProfile 主頁
  。
  
• 
  請閱讀更多有關(guān)
  System-wide Linux profiler (Sysprof)
  的內(nèi)容。
  
• 
  在
  developerWorks Linux 專區(qū)
  中可以找到為 Linux 開發(fā)人員準(zhǔn)備的更多參考資料。
  
• 
  緊密跟蹤
  developerWorks 技術(shù)活動和 Webcasts
  。
  

獲得產(chǎn)品和技術(shù)

• 
  索取免費(fèi)的 SEK for Linux
  ，這有兩張 DVD，包括最新的 IBM for Linux 的試用版軟件，包括 DB2®、Lotus®、Rational®、Tivoli® 和 WebSphere®。
  
• 
  在您的下一個 Linux 開發(fā)項目中采用
  IBM 試用版軟件
  ，這可以從 developerWorks 上直接下載。
  

討論

• 
  通過參與
  developerWorks blogs
  來加入  developerWorks 社區(qū)。
  

關(guān)于作者


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

本文來自ChinaUnix博客，如果查看原文請點(diǎn)：http://blog.chinaunix.net/u1/36494/showart_1871876.html