HMDT - Special Issue - Objective-C 最適化 - Sampler.app で C と Objective-C をプロファイルする

以下のドキュメントは、Profiling C and Objective-C code with Sampler.app を翻訳したものです。Mac OS X でのObjective-C の最適化手法について述べられています。

Mulle kybernetiK - Tech Info: (updated: 24.Jul.2000)

Sampler.app で C と Objective-C をプロファイルする

オリジナルの記事をアップしてからすぐ、まだ修正していないんだけどね、Marcel Weiher から次のようなメールをもらったんだ。

Subject: Re: Do you have problems using Sampler.app ?
Date: Mon, 24 Jul 2000 14:19:06 +0200

もしかしてぼくが間違ってるのかもしれないけど、Sampler はプロファイル用にコンパイルされたコードじゃなくても動きますよ。実のところ、これが Sampler の大きな利点だと思いますしね。

Marcel

このメールに対しておもしろい返事を考える前に、もう一回テストしてみるのがいい、と思ったんだ。で、その結果、もちろん Sample.app は Marcel が書いてきた通りに動いたんだ。あうう。もっと早くやっとくべきだった :)

この記事の残りの部分にはまだ価値があると思うので、どうぞ Step 2 まで飛んで下さい。

Step 1 - コードをプロファイルできる状態にしよう

プロファイルってのは、きみのコードをもうちょっと早く動かしたいときに、問題になっている箇所を見つけるための便利な方法だ。たぶん、そのコードはフレームワークからできていると思うんだ。それが最初の条件なんだけど、プロファイルするためのアプリケーションは、AppKit アプリケーションじゃないとだめなんだ。 WebObjects アプリケーションや、コマンドライン・アプリケーションは、プロファイルできないよ。もしこれらをプロファイルしたいなら、新しい AppKit アプリケーションを作って、そこにコピー／ペーストしてやるしかないね。

ただ問題があって、これに悩ませられるんだ：

アプリケーションをプロファイルするには、app や debug の代わりに、profile でビルトしないといけない。そして、直接的でも直接じゃなくてもいいけど、プロファイルバージョンのフレームワークとリンクされていることを保証しなくてはいけない。

普通、System に入っているフレームワークは、プロファイルバージョンのライブラリがインストールされているんだ。だけど、サードパーティのフレームワークの場合は、ないことがあるんだよね。そんなフレームワークを使っているときは、プロファイルのことは忘れてくれ、、、

もし Sampler.app を使ってきみのアプリケーションを起動できないときは、Terminal.app から otool を使って実行ファイルのリンクパスをチェックしてくれ。

bash-2.02$ cd SimpleProfile/SimpleProfile.profile/
bash-2.02$ otool -L SimpleProfile
SimpleProfile:

/System/Library/Frameworks/AppKit.framework/Versions/C/AppKit_profile 
(compatibility version 45.0.0, current version 380.3.0)
/System/Library/Frameworks/Foundation.framework/Versions/C/Foundation_profile 
(compatibility version 200.0.0, current version 298.81.0)
/System/Library/Frameworks/System.framework/Versions/B/System_profile 
(compatibility version 1.0.0, current version 25.0.0)

すべてのリンクされているフレームワークが、_profile っていう接尾子を持っていることを確認してくれ。そうじゃなきゃプロファイルできないよ。あるフレームワークは、他のフレームワークに依存していることも思い出してね。だから、同じように otool を使って、_profile がついているフレームワークもチェックしてね。

自分のフレームワークに、プロファイルバージョンがくっつくことを保証する、お気に入りのやり方は、Makefile.postamble の最初に、次のルールを追加することだ。

all_install: debug profile install

これで、通常バージョンとデバッグバージョンと、プロファイルバージョンが、Frameworks ディレクトリにインストールされるんだ。フレームワークをビルトするときは、徹底的にやるために、フレームワーク A が B に依存しているなら、最初に B をビルトして、それから A をするんだ。

Step 2 - アプリケーションを起動して、Sampler.app でプロファイルする

@implementation Controller

static char   dst[ 512];
static char   src[ 512];

#define LOOPS   10000


- (void)  foo
{
   unsigned int  i;

   for( i = 0; i < LOOPS; i++)
      memcpy( dst, src, sizeof( dst));
}


- (void)  bar
{
   unsigned int  i;

   for( i = 0; i < LOOPS; i++)
      memcpy( dst, src, sizeof( dst) / 2);
}


- (void) awakeFromNib
{
   unsigned int  i;
   
   NSRunAlertPanel( @"START", @"When you press \
OK there will be a 3 seconds delay, then a beep \
will be heard and the test will run.\nStart \
sampling at that moment.\nPress Stop sampling \
when you hear the second beep (or preferrably a \
bit earlier :))\n", @"OK", nil, nil);
   sleep( 3);
   NSBeep();
   
   for( i = 0; i < 1000; i++)
   {
      [self foo];
      [self bar];
   }

   NSBeep();
   sleep( 1);
   NSRunAlertPanel( @"END", @"The test is thru \
   ", @"OK", nil, nil);
}

@end

右側のコードは、この後のデモで使われるものなんだ。サンプリングのための細かい相違点 - NSRunAlertPanel と sleep を呼ぶ事を別にすれば、[Controller awakeFromNib] メソッドは、[Controller foo] と [Controller bar] を、それぞれ呼ぶだけだ。どっちのメソッドも memcpy を何回も呼ぶんだ。[Controller foo] は 5120000 バイトコピーして、[Controller bar] は 2560000 バイトコピーする。

Controller のインスタンスは NIB ファイルの中に埋め込まれていて、アプリケーションがスタートしたときにロードされるんだ。NIB のロードが、[Controller awakeFromNib] の呼び出しのトリガーになるんだ。

二つの簡単な予測がたてられるんだ。

• [Controller foo] は [Controller bar] より遅い。なぜなら、[Controller foo] の方が仕事をしてるから。
• 時間の大部分は memcpy ルーチンに費やされる。なぜならループと関数呼び出しは、比較的時間がかからないから。

Sampler.app

profiling のウィンドウが開いたら（下を見てね）、Executable にきみにアプリケーションの "profile binary" をセットして、Arguments に -NSUseRunningCopy NO を指定してね（赤い矢印）。

その後は、Launch and Sample を押すだけだ。充分なデータが集まったと思ったら、Stop Sampling を押して、ブラウザビューに出てくるアウトプットを解析してくれ。きみのアプリケーションと Sampler.app は、2 つの別のプロセスで実行されているから、Stop Sampling をいつでも押せるんだ。あと最初はサンプリングなしで始めて、適当な時にサンプリグを開始するっていうこともできる（黄色矢印）。

Step 3 - 必要な情報をアウトプットから集める

最初に見るべきところは、集められたサンプルの数、Samples (Displayed/Total) だな（青矢印）。意味のあるサンプル数は 200。これは 10 秒のサンプリングで得られる。良い精度で集めるには、サンプリグ周期を落とすといい（ぼくは普通 5ms を使ってるよ（G4 で））。

じゃ、ブラウザビュー（緑矢印）を調べてみよう。最初に気付くのは、シンボル名にくっついている数字だ（例えば、_memcpy とか -[Controller foo] とかね）。これは「サンプルの数」を示している。この数字は、サンプルの合計数と比較しながら考えないといけない。絶対数じゃないからね。

サンプリングするとき、Sampler.app はちょっと気のきいたことをするんだよね。サンプリングしたときの CPU のプログラムカウンタを調べるだけじゃなくて、スタックのスナップショットも取るんだよ。このスタックの情報を使って、関数コールの中でどれだけ時間がかかったか、っていうことだけでなく、誰が呼んだかってことも分かるんだ。例に戻ると、memcpy を呼んだ時にどれだけ時間がかかったか、だけではなくて、[Controller foo] はどのくらい、[Controller bar] はどのくらい、ってことまで分かるんだ。

右側は、デフォルトでは、スタックフレームを表示するんだ。こいつは CPU タイムがどれだけ使われたかを示す。下から順に、memcpy までの関数コールを追い掛けることができる。もちろん、興味があるのはテストルーチン [Controller awakeFromNib] だ。こいつがサンプルのすべてを取っている（283 of 283）。これは、このルーチンがすべての CPU 時間を取っている、という意味ではなくて、このルーチンに加えて、このルーチンが呼んでいるルーチン、さらにそいつが呼んでいるルーチン、が全部で使っているということだ。

スタックを登っていくと、[Controller foo] のとなりに書いてある数字は 183 で、[Controller awakeFromNib] の数字より小さいことに気付くだろう。このテストコードのメインループは、

  for(i = 0; i < 1000; i++)
  {
      [self foo];
      [self bar];
  }

だから、[Controller bar] と [Controller foo] は、同じ回数だけ呼ばれるんだよ。だけど [Controller foo] の方が実行時間が長いんだ。[Controller bar] は、このスタックトレースには出てきてないけどね。

[Controller bar] を含むスタックトレースを見れば、[Controller bar] のサンプル数は 96 であることが分かるよ。[Controller bar] は [Controller foo] の半分しかコピーしてないからだ。これは、事前の予想にあうね。

もうひとつスタックを登ってみると、memcpy のサンプル数は 181 だ。このことから、ループと C 関数コールのオーバーヘッドは、実行時間の 3% 程度、という結論が出る。これより上のスタックフレームは、memcpy の実装の詳細に関わることだから、興味ないね。だって、我々が書いたコードは memcpy と [NSConcreteMutableSet make... の間だから。

実行時間の大部分は、自分が書いたコードじゃないところで費やされているんだから、なかなかいい感じだよね、これは。そうでないときは、コンセプトが悪いのか、アルゴリズムが間違っているのか、考えないといけない。

次回は、Objective-C の高速化についてだ（必要ならね）。コメントや修正やその他何でも、nat@mulle-kybenetik.com に送ってくれ。