博客 / 詳情

返回

postgresql profiling

場景

分析postgresql BE的性能數據,適應於使用GCC編譯的場景。

原理

藉助gprof工具,gcc編譯的時候,加入-pg選項,則gcc會自動將目標代碼中加入性能測試代碼。程序執行過程中,性能測試代碼會記錄程序的性能數據,程序結束後,保存性能數據文件。通過gprof工具可以解碼該文件,進行查看分析。如下例:

gcc mytest.c -g -pg

説明:
. 對於程序引用的外部庫,如libc等,默認沒有-pg生成的性能代碼,不會單獨統計其函數的性能數據。可以下載對應的帶-pg選項的庫文件,如libc_p.a。(系統調用也不計算如sleep)如下例:

gcc mytest.c -g -pg -lc_p

. gprof默認不支持多線程、共享庫程序。

方法

. 編譯

打開profiling選項

./configure --enable-profiling

. 執行

$ psql
postgres=# create table t1(id int);
postgres=# insert into t1 values(1);
postgres=# insert into t1 values(2);
postgres=# \q

psql退出後,其對應的BE也隨之退出。BE退出後產生相應的gmon.out文件,默認在數據目錄的gprof/$PID目錄下

data/dn6/gprof/26516/gmon.out

. 轉換

將gmon.out轉換成可讀的格式

gprof ./install/bin/postgres ./data/dn6/gprof/26516/gmon.out > gp.out

格式説明

. 第一部分

各個函數的耗時排名。

column 意義
% time 本函數耗時所佔的比例
self seconds 本函數自身的耗時,不包含其調用的子函數的耗時。如上所述,依賴的外部庫(如memset),系統調用等會統計到本函數中,不會單獨統計。
Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total           
 time   seconds   seconds    calls   s/call   s/call  name    
 32.34      2.61     2.61    75262     0.00     0.00  handle_sync
 11.15      3.51     0.90   109412     0.00     0.00  base_yyparse
  4.71      3.89     0.38  2083921     0.00     0.00  SearchCatCacheInternal
  4.58      4.26     0.37  2940109     0.00     0.00  core_yylex
  4.21      4.60     0.34 13442073     0.00     0.00  AllocSetAlloc
  2.73      4.82     0.22  1627890     0.00     0.00  hash_search_with_hash_value
  2.60      5.03     0.21  4517373     0.00     0.00  MemoryContextAllocZeroAligned
  1.24      5.13     0.10  1297178     0.00     0.00  hash_bytes

. 第二部分

各個函數的堆棧情況,按照函數耗時排名排列。這裏的函數耗時,與第一部分不同,是包含其子函數的耗時的。

column 意義
index 排名(包含子函數的耗時)
% time 本函數耗時所佔的比例
self 同第一部分中的'self seconds'。本函數自身的耗時。
children 其調用的子函數的耗時。
called 被調用的次數(不包含遞歸調用次數)。

下面例子,為hgds_handle_sync的信息。下面是其子函數信息,按照耗時排序。上面是其caller的信息。

index % time    self  children    called     name
-----------------------------------------------
                2.61    0.46   75262/75262       PostgresMain [6]
[8]     38.0    2.61    0.46   75262         handle_sync [8]
                0.01    0.33   71509/307849      dist_extended_msg [15]
                0.00    0.06   71509/71509       handle_result [81]
                0.05    0.00   75262/82932       IsTransactionBlock [90]
                0.01    0.00   75262/75262       dlist_is_empty [206]
                0.00    0.00   75262/1496363     errstart [106]
                0.00    0.00    3836/7670        cl_bind_dist_info [526]
-----------------------------------------------

. 第三部分

函數index信息。

Index by function name

 [1385] AbortBufferIO        [121] SearchSysCache1         [8] handle_sync
 [726] AbortOutOfAnyTransaction [1010] SearchSysCache2  [1039] hash_combine64

總結

通過profiling信息,可以分析哪些函數貢獻了更多的耗時,以便針對性的優化。也可以針對兩個版本的數據進行對比,查找新增的性能殺手,進行優化。

參考資料

pgbuild説明
gprof介紹
gprof對比
系統調用不計算例子
一篇不錯的介紹

user avatar
0 位用戶收藏了這個故事!

發佈 評論

Some HTML is okay.