性能分析工具gprof介紹

hbxtly 2014-03-26

展開全文

轉(zhuǎn)自：http://andashu.blog.51cto.com/8673810/1373382

性能分析工具gprof介紹
Ver：1.0

目錄
1. GPROF介紹 4
2. 使用步驟 4
3. 使用舉例 4
3.1 測試環(huán)境 4
3.2 測試代碼 4
3.3 數(shù)據(jù)分析 5
3.3.1 flat profile模式 6
3.3.2 call graph模式 7
4. 鏈接庫中的函數(shù) 7
5. 使用局限 8
6. 分析示例 12

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
1. gprof介紹
gprof是GNU profile工具,，可以運行于linux,、AIX、Sun等操作系統(tǒng)進行C,、C++,、Pascal、Fortran程序的性能分析,，用于程序的性能優(yōu)化以及程序瓶頸問題的查找和解決,。通過分

析應(yīng)用程序運行時產(chǎn)生的“flat profile”，可以得到每個函數(shù)的調(diào)用次數(shù),，每個函數(shù)消耗的處理器時間,，也可以得到函數(shù)的“調(diào)用關(guān)系圖”,，包括函數(shù)調(diào)用的層次關(guān)系，每個函

數(shù)調(diào)用花費了多少時間,。

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
2. 使用步驟
1) 用gcc,、g++、xlC編譯程序時,，使用-pg參數(shù),，如：g++ -pg -o test.exe test.cpp
編譯器會自動在目標(biāo)代碼中插入用于性能測試的代碼片斷，這些代碼在程序運行時采集并記錄函數(shù)的調(diào)用關(guān)系和調(diào)用次數(shù),，并記錄函數(shù)自身執(zhí)行時間和被調(diào)用函數(shù)的執(zhí)行時間,。
2) 執(zhí)行編譯后的可執(zhí)行程序，如：./test.exe,。該步驟運行程序的時間會稍慢于正常編譯的可執(zhí)行程序的運行時間,。程序運行結(jié)束后，會在程序所在路徑下生成一個缺省文

件名為gmon.out的文件,，這個文件就是記錄程序運行的性能,、調(diào)用關(guān)系,、調(diào)用次數(shù)等信息的數(shù)據(jù)文件,。
3) 使用gprof命令來分析記錄程序運行信息的gmon.out文件，如：gprof test.exe gmon.out則可以在顯示器上看到函數(shù)調(diào)用相關(guān)的統(tǒng)計,、分析信息,。上述信息也可以采用

gprof test.exe gmon.out> gprofresult.txt重定向到文本文件以便于后續(xù)分析。

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
3. 使用舉例
3.1 測試環(huán)境
本文提供的樣例的測試環(huán)境如下：
? Linux server164 2.6.9-22.ELsmp #1 SMP Mon Sep 19 18:32:14 EDT 2005 i686 i686 i386 GNU/Linux
? gcc version 3.2.3 20030502 (Red Hat Linux 3.2.3-47.3)
? GNU gprof 2.15.92.0.2
3.2 測試代碼
清單 1. 耗時測試應(yīng)用程序示例
example1.c

#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();
}
}
這個應(yīng)用程序包括兩個函數(shù)：a 和 b,，它們通過運行不同次數(shù)的循環(huán)來消耗不同的CPU時間,。main 函數(shù)中采用了一個循環(huán)來反復(fù)調(diào)用這兩個函數(shù)。函數(shù)b中循環(huán)的次數(shù)是 a 函數(shù)的

4 倍,，因此我們期望通過gprof的分析結(jié)果可以觀察到大概有 20% 的時間花在了 a 函數(shù)中,，而 80% 的時間花在了 b 函數(shù)中。
3.3 數(shù)據(jù)分析
在 gcc 編譯命令中加上 –pg參數(shù)即可,。編譯方法如下：
gcc example1.c -pg -o example1 -O2 -lc
在編譯好這個應(yīng)用程序之后,，按照普通方式運行這個程序：
./example1 50000
程序運行完之后，應(yīng)該會看到在當(dāng)前目錄中新創(chuàng)建了一個文件 gmon.out,。

3.3.1 flat profile模式
使用 gprof 命令分析gmon.out 文件,，如下所示：

gprof example1 gmon.out -p

-p參數(shù)標(biāo)識“flat profile”模式，在分析結(jié)果中不顯示函數(shù)的調(diào)用關(guān)系,，AIX平臺默認(rèn)此參數(shù)有效,。
輸出以下內(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.38 203.27 203.27 50000 4.07 4.07 b
19.61 252.87 49.60 50000 0.99 0.99 a
0.00 252.88 0.01 main

上面結(jié)果中各個列的含義如下：
%time 函數(shù)以及衍生函數(shù)（函數(shù)內(nèi)部再次調(diào)用的子函數(shù)）所占的總運行時間的百分比
cumulative seconds 函數(shù)累計執(zhí)行的時間
self seconds 函數(shù)執(zhí)行占用的時間
calls 函數(shù)的調(diào)用次數(shù)
self ms/call 每一次調(diào)用函數(shù)花費的時間microseconds，不包括衍生函數(shù)的運行時間
total ms/call 每一次調(diào)用函數(shù)花費的時間microseconds,，包括衍生函數(shù)的運行時間
name 函數(shù)名稱
列的含義,，在gprof的輸出結(jié)果中都有詳細的說明,。
從輸出結(jié)果中可以看到，正如我們期望的一樣,，b 函數(shù)所花費的時間大概是 a 函數(shù)所花費的時間的 4倍,。
很多函數(shù)調(diào)用（例如 printf）在上面的輸出結(jié)果中都沒有出現(xiàn)。這是因為大部分函數(shù)都是在C鏈接庫（libc.so）中,，而鏈接庫并沒有使用 -pg 進行編譯,，因此就沒有對鏈接庫中

的函數(shù)收集調(diào)度信息。

3.3.2 call graph模式
如果希望反映函數(shù)之間的調(diào)用關(guān)系,，需要采用如下命令：

gprof example1 gmon.out –q

-q參數(shù)標(biāo)識“call graph”模式,，在分析結(jié)果中顯示函數(shù)的調(diào)用關(guān)系。
輸出以下內(nèi)容：
清單 3. Call graph
granularity: each sample hit covers 4 byte(s) for 0.00% of 252.72 seconds

index % time self children called name
<spontaneous>
[1] 100.0 0.00 252.72 main [1]
201.41 0.00 50000/50000 b [2]
51.31 0.00 50000/50000 a [3]
-----------------------------------------------
201.41 0.00 50000/50000 main [1]
[2] 79.7 201.41 0.00 50000 b [2]
-----------------------------------------------
51.31 0.00 50000/50000 main [1]
[3] 20.3 51.31 0.00 50000 a [3]
-----------------------------------------------
上面結(jié)果中各個列的含義如下：
index 每個函數(shù)第一次出現(xiàn)時都分配了一個編號,，根據(jù)編號可以方便的查找函數(shù)的具體分析數(shù)據(jù)
%time 函數(shù)以及衍生函數(shù)（函數(shù)內(nèi)部再次調(diào)用的子函數(shù)）所占的總運行時間的百分比
self 函數(shù)的總運行時間
children 衍生函數(shù)執(zhí)行的總時間
called 函數(shù)被調(diào)用的次數(shù),，不包括遞歸調(diào)用
name 函數(shù)名稱
在name列中，可以看出函數(shù)之間的調(diào)用關(guān)系,，main函數(shù)調(diào)用a,、b函數(shù)，b函數(shù)被main函數(shù)調(diào)用,，a函數(shù)被main函數(shù)調(diào)用,。通過函數(shù)名稱后面的數(shù)字來標(biāo)識這個文件中的函數(shù)，從而可

以快速定位函數(shù)的分析數(shù)據(jù)的位置,，經(jīng)過一層層的逐步深入的分析就得到各個函數(shù)的調(diào)用關(guān)系以及各個函數(shù)的性能數(shù)據(jù),。

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
4. 鏈接庫中的函數(shù)
正如在前面曾經(jīng)介紹的，對于代碼剖析的支持是由編譯器增加的,，因此如果希望從鏈接庫（比如libc.a）中獲得剖析信息,，就需要使用 -pg 來編譯這些庫。很多操作系統(tǒng)默認(rèn)提供

了已經(jīng)啟用代碼剖析支持而編譯的鏈接庫版本,，例如：libc.a對應(yīng)的采用-pg編譯的文件為libc_p.a,。對于沒有按照標(biāo)準(zhǔn)提供類似libc_p.a鏈接庫的操作系統(tǒng)版本來說，就需要安裝

已經(jīng)編譯好的啟用代碼剖析的鏈接庫版本或者自己下載鏈接庫的源代碼進行編譯,。
使用“啟用代碼剖析的鏈接庫版本”的應(yīng)用場景,，舉例如下：
gcc example1.c -g -pg -o example1 -O2 -lc_p
然后，像普通情況下一樣運行g(shù)prof對gmon.out進行分析,，可以獲得 flat profile 或 call graph,，而此時的分析結(jié)果會非常豐富，包含很多C的標(biāo)準(zhǔn)庫函數(shù)的調(diào)用信息,，例如：

printf,、write等。
注意：上例的libc_p.a是靜態(tài)鏈接庫。gprof目前還不支持對動態(tài)鏈接庫中的函數(shù)進行性能分析,。

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
5. 使用局限
gprof的特點是它只能分析應(yīng)用程序在運行過程中所消耗掉的CPU時間,，只有當(dāng)應(yīng)用程序的函數(shù)消耗CPU的時候，gprof才能夠獲取函數(shù)的性能數(shù)據(jù),。如果應(yīng)用程序在運行過程中暫時

掛起,，并在系統(tǒng)內(nèi)核喚醒應(yīng)用程序后進一步執(zhí)行，那么在應(yīng)用程序中間暫停的時間性能數(shù)據(jù)是無法統(tǒng)計的,；而且在應(yīng)用程序等待I/O操作返回的時間,，性能數(shù)據(jù)也是無法統(tǒng)計的。
如果對清單 1 稍加修改,，就可以清楚地看出這個問題：
清單 5. 為清單 1 添加sleep()函數(shù)調(diào)用
example2.c:

#include <stdio.h>
int a(void)
{
sleep(1); /*調(diào)用系統(tǒng)函數(shù)進行sleep*/
return 0;
}
int b(void)
{
sleep(4); /*調(diào)用系統(tǒng)函數(shù)進行sleep*/
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();
}
}

現(xiàn)在 a 函數(shù)和 b 函數(shù)不再處理繁忙的循環(huán)了,，而是分別調(diào)用sleep()來掛起1秒和4秒。
使用“啟用代碼剖析的鏈接庫版本”,，編譯這個應(yīng)用程序：
gcc example2.c -g -pg -o example2 -O2 -lc_p
并讓這個應(yīng)用程序循環(huán) 30 次：
./example2 30
執(zhí)行gprof example2 gmon.out –p所生成的結(jié)果如下：
清單 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 21 0.00 0.00 _IO_file_overflow
0.00 0.00 0.00 13 0.00 0.00 strncmp
0.00 0.00 0.00 8 0.00 0.00 memset
0.00 0.00 0.00 8 0.00 0.00 sigprocmask
0.00 0.00 0.00 7 0.00 0.00 getenv
0.00 0.00 0.00 6 0.00 0.00 memcpy
0.00 0.00 0.00 5 0.00 0.00 _int_malloc
0.00 0.00 0.00 5 0.00 0.00 malloc
0.00 0.00 0.00 5 0.00 0.00 sigaction
0.00 0.00 0.00 5 0.00 0.00 strsep
0.00 0.00 0.00 4 0.00 0.00 nanosleep
0.00 0.00 0.00 4 0.00 0.00 sleep
0.00 0.00 0.00 4 0.00 0.00 strpbrk
0.00 0.00 0.00 3 0.00 0.00 _IO_new_file_xsputn
0.00 0.00 0.00 3 0.00 0.00 ____strtoul_l_internal
0.00 0.00 0.00 3 0.00 0.00 __cxa_atexit
0.00 0.00 0.00 3 0.00 0.00 __strtoul_internal
0.00 0.00 0.00 2 0.00 0.00 __errno_location
0.00 0.00 0.00 2 0.00 0.00 __find_specmb
0.00 0.00 0.00 2 0.00 0.00 a
0.00 0.00 0.00 2 0.00 0.00 b
0.00 0.00 0.00 2 0.00 0.00 mempcpy
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 __init_misc
0.00 0.00 0.00 1 0.00 0.00 __libc_csu_fini
0.00 0.00 0.00 1 0.00 0.00 __libc_csu_init
0.00 0.00 0.00 1 0.00 0.00 __libc_init_first
0.00 0.00 0.00 1 0.00 0.00 __libc_init_secure
0.00 0.00 0.00 1 0.00 0.00 __libc_setup_tls
0.00 0.00 0.00 1 0.00 0.00 __libc_start_main
0.00 0.00 0.00 1 0.00 0.00 __pthread_initialize_minimal
0.00 0.00 0.00 1 0.00 0.00 __setfpucw
0.00 0.00 0.00 1 0.00 0.00 __strtol_internal
0.00 0.00 0.00 1 0.00 0.00 _dl_aux_init
0.00 0.00 0.00 1 0.00 0.00 _dl_important_hwcaps
0.00 0.00 0.00 1 0.00 0.00 _dl_init_paths
0.00 0.00 0.00 1 0.00 0.00 _dl_non_dynamic_init
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 fillin_rpath
0.00 0.00 0.00 1 0.00 0.00 fini
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 printf
0.00 0.00 0.00 1 0.00 0.00 setitimer
0.00 0.00 0.00 1 0.00 0.00 strrchr
0.00 0.00 0.00 1 0.00 0.00 uname
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é)果進行分析可見,，盡管 profile 已經(jīng)記錄了每個函數(shù)被調(diào)用的確切次數(shù)，但是為這些函數(shù)記錄的時間（實際上是所有函數(shù)）都是 0.00,。這是因為 sleep 函數(shù)實際上

是執(zhí)行了一次對內(nèi)核空間的調(diào)用,，從而將應(yīng)用程序的執(zhí)行掛起了，然后有效地暫停執(zhí)行,，并等待內(nèi)核再次將其喚醒,。由于花在用戶空間執(zhí)行的時間與花在內(nèi)核中睡眠的時間相比非

常小，因此就被取整成零了,。其原因是 gprof 以固定的周期對程序運行時間進行采樣測量,，當(dāng)程序掛起時,，gprof就不會對程序進行采樣測量,。
Gprof的特性使得有些程序非常難以進行優(yōu)化，例如花費大部分時間睡眠等待內(nèi)核喚醒的程序,，或者由于外部因素（例如操作系統(tǒng)的 I/O 子系統(tǒng)過載）而運行得非常慢的程序,。
通常，有一個很好的基準(zhǔn)測試可以用來查看 gprof 對于應(yīng)用程序的優(yōu)化能起多大作用,，方法是在 time 命令下面執(zhí)行應(yīng)用程序,。此命令會顯示一個應(yīng)用程序運行完成需要多少時間

，并且在用戶空間和內(nèi)核空間各花費了多少時間,。
例如：time ./example2 30
輸出結(jié)果如下所示：
清單 7. time 命令的輸出結(jié)果
No of iterations = 30
real 2m30.295s
user 0m0.000s
sys 0m0.004s
我們可以看出應(yīng)用程序整體運行150秒左右,，但大部分時間在睡眠狀態(tài)，幾乎沒有多少時間被花費在執(zhí)行用戶空間和內(nèi)核空間的代碼上,，此時gprof的分析結(jié)果無法體現(xiàn)函數(shù)的實際

運行時間,。

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
6. 分析示例
在新疆聯(lián)通進行綜合入庫程序上線前的測試過程中，測試人員發(fā)現(xiàn)程序運行效率低下。下面以整個調(diào)優(yōu)的過程來舉例說明基于gprof的性能分析方法,。
性能分析前的準(zhǔn)備階段,，性能分析數(shù)據(jù)的生成步驟如下：
1) 首先更改makefile文件中的CC=g++ -g –pg 行，添加-pg參數(shù),。
2) 執(zhí)行make clean刪除所有的目標(biāo)文件,、可執(zhí)行文件
3) 重新編譯
4) 在命令行執(zhí)行可執(zhí)行程序，并通過控制臺發(fā)送啟動命令
5) 程序退出后在fileindb執(zhí)行程序目錄下生成gmon.out(不是控制臺目錄)
6) 執(zhí)行g(shù)prof fileindb > gsmindb_mon_result.txt把分析結(jié)果重定向到gsmindb_mon_result.txt文件
下面就是從gsmindb_mon_result.txt文件中截取的部分內(nèi)容：

打開gsmindb_mon_result.txt文件后,，可以看到127行：
[3] 37.2 0.00 41.90 1 .main [3]
0.00 41.88 1/1 .CMainManager::Run(int&) [4]
可見main函數(shù)中的CMainManager::Run運行時間(41.88)幾乎占據(jù)了所有的運行時間(41.90),，再查CMainManager::Run的分析數(shù)據(jù)在148行：
[4] 37.2 0.00 41.88 1 .CMainManager::Run(int&) [4]
0.00 41.81 1/1 .CBaseBillFile::DoEveryBill() [5]
可見CMainManager::Run 函數(shù)中CBaseBillFile::DoEveryBill執(zhí)行占了幾乎所有的時間，對于占用時間比重很小的函數(shù)可以忽略,。采用上面的方法一步一步向下查找,，最終確定289

行：
0.56 11.98 849922/849922 .CMobileFavour::CheckAllCondition(int,int) [11]
[12] 11.1 0.56 11.98 849922 .CGsmFavourCheck::CheckAllCondition() [12]
0.06 5.82 849922/849922 .CGsmFavourCheck::CheckCallKind() [14]
在 CGsmFavourCheck::CheckAllCondition()所調(diào)用的函數(shù)中 CGsmFavourCheck::CheckCallKind()占用時間的比重過大，幾乎達到 50%,；CGsmFavourCheck::CheckAllCondition總共用

時11.98,，而CGsmFavourCheck::CheckCallKind()函數(shù)就占用了5.82，從而說明CGsmFavourCheck::CheckCallKind()函數(shù)需要作進一步優(yōu)化,，以提高整體的運行效率,。

本站是提供個人知識管理的網(wǎng)絡(luò)存儲空間，所有內(nèi)容均由用戶發(fā)布,，不代表本站觀點,。請注意甄別內(nèi)容中的聯(lián)系方式、誘導(dǎo)購買等信息,，謹(jǐn)防詐騙,。如發(fā)現(xiàn)有害或侵權(quán)內(nèi)容，請點擊一鍵舉報,。

久久国产成人av_抖音国产毛片_a片网站免费观看_A片无码播放手机在线观看,色五月在线观看,亚洲精品m在线观看,女人自慰的免费网址,悠悠在线观看精品视频,一级日本片免费的,亚洲精品久,国产精品成人久久久久久久

性能分析工具gprof介紹