名探偵コナン並みの推理力をもったプログラマーにデバッグとか手伝ってもらったらどうだろうか。
? Takayuki Okazaki (@watermint) December6, 2011
なんて思ってたら、
@watermint つまり、「毎週超難解なバグが発生する」ということですね？＞＜
? パレオはせとあずさ♂?熱烈歓迎DeNA／ (@setoazusa) December6, 2011
！！！
お客様の中に名探偵の方はいらっしゃいませんか？＞＜
ということで、iOS Advent Calendarのネタです。今回は、iOSデバッグ界隈の中ではマイナーと言われるか、一部のファンに熱狂的な支持！といわれるか絶妙なバランスを保ったDTraceでのデバッグを取り上げます。
DTraceはもともと、Sun Microsystemsによって開発されSolaris 10に搭載されたデバッグフレームワークです。現在は、FreeBSDやMac OS Xなどでも利用することが出来ます。詳しい説明は今回は省きますがTraceと名前がついていることから想像できる通り、プログラムの実行をトレースしてどのコードが、どういう風に実行されたか。といったことを調べることが出来ます。
こんなことはありませんか？
- 初期化処理がどうやらうまくいっていないようだが、どこまで実行されたか知りたい。しかし、Xcodeのデバッガでステップ実行・ブレークポイント設定などしながら確認するにはプログラムが大きすぎる。
- NSLogを埋め込んでどこまで実行されたか確認したいが、そもそもログを埋め込むのが面倒くさい。または、ソースコードをNSLogだらけにして汚したくない。
個人的にはXcodeのブレークポイント設定はなかなかよく出来ていると思っていて、多くのケースではそれで足りると思っています。
Xcodeでブレークポイントを設定してActionにSoundを設定、ブレークポイントは自動的に続行するように設定しておけばその該当箇所が実行されたかどうか音で聞き分けて調べることが出来ます。初期化関連の問題を探すときなんかは個人的にはよく利用しています。
さて、これでも十分なんですが設定したいブレークポイントが増えてくると音の種類も限定されますしどの音がどのブレークポイントだったかよくわからなくなります。Log Messageなどのアクションを設定してログ出力するのもいいのですが、網羅的にブレークポイント設定は面倒くさすぎます。
こういうときに威力を発揮するのがDTraceです。まずは手っ取り早くつかってみましょう。XcodeについているiOSのサンプルプロジェクトLazyTableImagesを題材にしています。Xcodeであなたのデバッグしたいプロジェクトを開いて、シミュレーター上で実行してください。出ましたか？
次にターミナルから次のコマンドを実行します。
$ ps ax | grep Simulator | grep -v iPhoneSimulator
すると次のようにiOSシミュレーター上で実行されているアプリのプロセスIDが分かります。下の例だと85894ですね。
85894 ?? SX 0:00.33 /Users/watermint/Library/Application Support/iPhone Simulator/4.0.2/Applications/993BF578-B81F-4B4C-97FA-B6B6843DD47E/LazyTable.app/LazyTable 88978 s004 R+ 0:00.00 grep Simulator
さてこれが分かったら続いてdtraceを実行します。dtraceは他の人の実行しているプロセスなども丸裸にしてしまうなどでき、セキュリティー上の課題があるため一般ユーザでは実行できません。sudoをつかって実行しましょう。下記の85894の部分は調べたプロセスIDに読み替えてください。
$ sudo dtrace -p 85894 -n ‘objc$target:::entry { printf(“[%s %s]\n”, probemod, probefunc); }’
できましたか？できたらアプリを適当にタップするなど動かしてみてください。
このようにObjective Cで実行された関数がリアルタイムに出力されます。どうでしょうか？これでNSLogを仕込まなくてもトレースがとれるようになりましたね。でもちょっと出力が多すぎるようです。これではデバッグの役に立てるにはややしんどいです。出力を抑制してみましょう。
objc$target:::entryのところを、objc$target:クラス名::entryと書き換えてみましょう。ここではLazyTableImageにあるクラスのIconDownloaderとしましょうか。実際に実行するときにはあなたのプロジェクトにあるクラスをつかってください。
$ sudo dtrace -p 85894 -n ‘objc$IconDownloader::entry { printf(“[%s %s]\n”, probemod, probefunc); }’
出力が一気に減って、IconDownloaderだけになりましたね。ご想像の通り、関数名でもフィルタできます。
$ sudo dtrace -p 85894 -n ‘objc$target:IconDownloader:-indexPathInTableView:entry { printf(“[%s %s]\n”, probemod, probefunc); }’
便利ですね。これでたとえば、初期化処理のときに通らなければならない関数がちゃんと実行されているかどうか分かるようになりました。クラス名や関数名にはワイルドカードが使えます。たとえば、IconDownloader以外にIconButton、IconButtonLabelなどのクラスがあった場合にはIcon*というようにアスタリスクを指定するとIconで始まるクラス名にマッチします。
さて、デバッグしていて原因箇所がなんとなくわかってきたときに知りたいのはその関数がいつ、どこから呼ばれたか？です。呼び出し元を知りたいですよね。そういうときは、もうちょっと凝ったdtraceの使い方をしてみましょう。
次のようなファイルを用意して、trace.d というファイル名で保存しておきます
#pragma D option quiet
self int level;
objc$target:::entry
{
printf("%*s[tid=%lld][%s %s]\n",
self->level * 2, " ->",
(long long)tid, probemod, probefunc);
self->ts[probefunc] = timestamp;
self->level++;
}
objc$target:::return
{
time = timestamp - self->ts[probefunc];
self->level--;
printf("%*s[tid=%lld][%s %s] [%dms]\n",
self->level * 2, " <-", (long long)tid,
probemod, probefunc, time / 1000);
}
ではこれを実行してみましょう。
$ sudo dtrace -p 85894 -s trace.d
このように関数呼び出しをツリー状にしてダンプできます。後は必要に応じてクラス名や関数をフィルタしていけば良いでしょう。
さて、すこし駆け足になりましたがXcodeのデバッガをつかう場合と比べてだいぶ便利な機能があることがお分かりいただけたでしょうか？
コマンドラインからの実行に抵抗があるというかたはInstrumentsからもDtraceは実行できます。
さて、すこし駆け足になりましたが最後に制約事項を説明しておきます。dtraceはOS側に仕込まれたプローブという検出ポイントに対して働きます。このため、トレースしたい内容のプローブがOS側で実装されていることが必須です。このため、dtraceのプローブを持たないiOSにはdtraceを接続できません。必ずiOSシミュレータ上で実行しているアプリに対してdtraceを実行してください。
iPhoneやiPadなどのiOSが動作している実機に対しては別途従来通りのXcodeやgdbを用いたデバッグが必要です。
Mac OS XのdtraceにはObjective Cのためのプローブがいくつか用意されています。詳しくはman dtraceを参照してください。
