2011年7月17日日曜日

Mac OS XのプロファイラSharkをコマンドラインで

MacでCプログラムを書いていて、プロファイルを調べたくなった。Linuxであればgprofを使うので、とりあえず"which gprof"してみたらMac OSにも入っていた。

しかし、実際に使ってみると期待どおりに動かない。呼出回数は計測されるが時間が計測されないらしく、次の例のように 0.0 が並んでしまった。

$ gprof foo gmon.out
(中略)
  %   cumulative   self              self     total           
 time   seconds   seconds    calls  ms/call  ms/call  name    
  0.0       0.00     0.00   200001     0.00     0.00  _main [79]
  0.0       0.00     0.00   200000     0.00     0.00  _f1 [80]
  0.0       0.00     0.00   200000     0.00     0.00  _f2 [81]
  0.0       0.00     0.00   100000     0.00     0.00  _f3 [82]
  0.0       0.00     0.00        1     0.00     0.00  __start [83]

環境は以下のとおり。

$ uname -mrs
Darwin 10.8.0 x86_64

Shark

調べたところ Mac OS で gprof の動作が不完全なのはFAQというか一般常識。代わりに"Shark"を使うのが定石らしい。

そのShark、「MacOSXではgprofが使えない→Sharkを使う - 西尾泰和のはてなダイアリー」で紹介されているように、確かにこれで間に合うのだが、GUIなのが面倒でツラい。1つのプロセスのプロファイルが欲しいのに、たくさんのプロセスを一度にプロファイリングしてその中から選ぶのも冗長な気がしてしまう。

Sharkをコマンドラインで

man shark してみたら実はコマンドラインからも使えて、テキスト形式のレポートも簡単に生成できることがわかった。

以下はfooというプログラムのプロファイルをとってレポートする例。

$ shark -1 -G -i ./foo
shark 4.7.3 (383)
* Option+Esc to start/stop a trace session
* Ctrl+c to stop sampling and quit (any pending samples are processed and saved)

* Batch mode
* Watching task exits
* Profiling limited to foo (PID #33472)

Sampling Config: Time Profile
Timed Samples & Counters
-Sampling begins immediately.
-A sample is taken every 1ms.
-Sampling ends automatically after 30s.



Ready. 

Sampling...
0    #これはプログラムfooが出力した数字

Processing samples...( Ctrl-c will cancel processing; No session will be created. )


CHUDData - Analyzing samples...

(略。WARNINGが出力される…)

sharkコマンドが終わると、カレントディレクトリにファイルが2個生成される。

一つは "session_001.mshark" で、shark的には session file と呼ばれるバイナリ。プロファイルの1セッション分の情報が記録されていると思われる。

もう一つは"session_001-report.txt" で、これがテキストのレポート。次のような内容になっている。長い。

$ cat session_001-report.txt 

================================================================================
Session
================================================================================
Authored by: dminor11th on 2011-07-17 19:13:45 +0900 (started 2011-07-17 19:13:32 +0900)
Version: Shark 4.7.3-383 (Session v0.3.0)
Host: dminor11th-MacBookPro.local
Operating System: Mac OS X 10.6.8 (10K540)
Machine Class: MacBookPro5,5
Memory: 4096 MB
Processor: 2 x 2530/1064 MHz Intel Core 2 (Penryn) v7.0
Memory Controller: Unknown
IO Controller: UnknownCHUD.framework: v4.7.3
CHUDProf.kext: v366
CHUDUtils.kext: Unknown

================================================================================
Sampling Configuration
================================================================================
Timed Samples & Counters
-Sampling begins immediately.
-A sample is taken every 1ms.
-Sampling ends automatically after 30s.


================================================================================
Module: SharkProfileAnalysis
================================================================================
REPORT:


================================================================================
Active Process Summary
================================================================================
Process [PID]                     % Total
-----------------------------------------
foo [33472]                  100.0%
-----------------------------------------
Total                              100.0%

Process [PID]                     # Total
-----------------------------------------
foo [33472]                   12107
-----------------------------------------
Total                               12107

===============================================================================================
  foo [33472]
    % Total                               Symbol                  Library      Address   Length
-----------------------------------------------------------------------------------------------
      58.4%                              strncmp /usr/lib/libSystem.B.dylib 0x7fff8833c280     0xe5
      20.0%                                  f2 /Users/dminor11th/temp/foo  0x100000863    0x14c
      18.1%                                  f3 /Users/dminor11th/temp/foo  0x100000a8d     0x81
       2.4%                    dyld_stub_strncmp /Users/dminor11th/temp/foo  0x100000dae      0x6
       0.1%                           __vfprintf /usr/lib/libSystem.B.dylib 0x7fff8834662c   0x5304
       0.1%                              __bzero /usr/lib/libSystem.B.dylib 0x7fffffe00600    0x180
       0.1%                            vsnprintf /usr/lib/libSystem.B.dylib 0x7fff8837b454    0x194
(略)

「あーあ、strncmpが58.4%か…」みたいな感じ。

以上、sharkについて。これでとりあえずは Mac OS でのプロファイラには困らないかなと。

0 件のコメント:

コメントを投稿