プロファイラの備忘録 (1) gprof

たまにしか使わないのでいつも「perfだっけ?gperfだっけ?」とプロファイラの名前から検索している。 あまりにも効率が悪いのでここに使い方メモを記す。

1. 準備

1.1. gprof

gprofはbinutilsに含まれるらしい。

$ sudo yum install binutils
1.2. PostgreSQL

configureに--enable-profilingオプション(と--enable-debugオプション)を設定して実行。これで-pg ( と-g)オプション付きでgccが実行される。

2. データ収集

特に準備は不要で、PostgreSQLを起動すればよい。 停止したプロセスのgmon.outが data/gprof/"プロセス番号/gmon.out"に書き込まれる。

$ find data/ | grep gmon
data/gprof/2766/gmon.out
data/gprof/avworker/gmon.out
data/gprof/2776/gmon.out
data/gprof/2775/gmon.out
data/gprof/2774/gmon.out
data/gprof/2768/gmon.out
data/gprof/2770/gmon.out

... 略 ...

よって、ある一つのSQLのプロファイルを行いたい場合、(1)SQL毎にpsqlでプロセスを立ち上げ、(2)pg_backend_pid()でプロセス番号を確認して、(4)SQL*1を実行、(3)実行後は即座に終了、する。

$ psql testdb
psql (14beta2)
Type "help" for help.

testdb=# SELECT pg_backend_pid();
 pg_backend_pid 
----------------
           2774
(1 row)

testdb=# SELECT count(*) FROM a1, a2;
 count 
-------
  2000
(1 row)

testdb=# \q

3. データ表示

最も単純に結果を知るには、以下のようにする。

$ gprof ./bin/postgres  data/gprof/2774/gmon.out


Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total           
 time   seconds   seconds    calls   s/call   s/call  name    
 12.50      0.67     0.67 166400001     0.00     0.00  ExecNestLoop
 12.12      1.31     0.65 332803335     0.00     0.00  ExecInterpExpr
 12.03      1.95     0.64 166403415     0.00     0.00  heapgettup_pagemode
  6.02      2.27     0.32 166403328     0.00     0.00  SeqNext
  5.83      2.58     0.31 499241656     0.00     0.00  MemoryContextReset
  5.45      2.87     0.29 166403415     0.00     0.00  heap_getnextslot
  4.70      3.12     0.25   739109     0.00     0.00  heapgetpage
  4.51      3.36     0.24 166401650     0.00     0.00  ExecStoreBufferHeapTuple
  4.51      3.60     0.24 166400005     0.00     0.00  fetch_input_tuple

... 略 ...

*1:pg_backend_pid()の実行が無視できる程度の負荷をかける必要がある。もしも軽いSQL処理のプロファイルを行いたい場合はpsコマンドで直接プロセス番号を確認したほうがよい。