深淵へ - ゾンビオブジェクトを検出する (Xcode編)

Mac iOS Xcode

iOSプログラミングの学習と称して書籍やネット上のサンプルコードを試しているが、「iOSプログラミング 第2版」の10章のコードにて、意図しない所で"EXC_BAD_ACCESS"に遭遇した。


"EXC_BAD_ACCESS"といえば噂には聞いていたが、iOSで最もよく遭遇する異常終了の原因の一つである。これに遭遇したということはiOSプログラミングのスタートラインに立ったということだろう。

さて、異常終了が発生したのは分ったがこれだけでは情報が不足しており手がかりも何も無い。変数ビューを見るとPossesionクラスのメンバ変数であるpossesionNameとserialNumberはNSString型だが、正しい値がセットされていないようだ。

そこで、Xcode上でアプリケーション実行時に環境変数をいくつか追加することで追加のデバッグ情報を取得することにする。
Xcode 4.2で現在のデバッグターゲットの環境変数を編集するには「スキーマの編集」が必要となるため、メニューから「Product->Edit Schema」を選択し、表示されたダイアログの左側のペインから"Run XXXXXX"(XXXXXはプロジェクト名)を選択する。

すると、スクリーンショットのように環境変数(Environment Variables)の表があるので、そこに以下の3つの環境変数とそのブール値(YES)を設定する

3つの環境変数にはそれぞれ以下の意味がある。

    • NSDebugEnabled : Foundationクラスにおける追加のデバッグ情報を有効にする
    • MallocStackLogging : メモリアロケーションの履歴の記録を有効にする
    • NSZombieEnabled :　解放済みのオブジェクト:"ゾンビオブジェクト"※1にメッセージを送出した場合に例外で通知する

特に今回の問題である"EXC_BAD_ACCESS"のトレースに重要なのは"NSZombieEnabled"環境変数である。

iOSにおいてObjective-Cのオブジェクトへのメッセージ送出(メソッド呼び出し)は、事前に正しいメッセージ(生きているオブジェクトへのメッセージ)を送出したかどうかを確認する術は無い。また、仮に既に正しく示していない参照にメッセージを送っても問題が発生するとは限らないため※2確実に例外をスローするこのスイッチが無いと追うのが困難になるのだ。


さて、新たな環境変数をセットした所でもう一度アプリケーションを実行して異常終了させると、新たな情報が増えているのが分る。

Homwpwner(352) malloc: recording malloc stacks to disk using standard recorder
Homwpwner(352) malloc: stack logs being written into /tmp/stack-logs.352.Homwpwner.Pt2OO0.index
2012-01-08 23:50:10.251 Homwpwner[352:f803] *** -[CFString respondsToSelector:]: message sent to deallocated instance 0xae437a0

"malloc:"とあるのはメモリアロケーションの履歴の記録を開始/保存しましたというログであり、次が拡張デバッグ情報の一部であり、プロセスのPID[352]で問題が発生したことを通知している。

NSZombieEnabled環境変数を有効にするとシステムは解放済みのオブジェクトに対してメッセージを送出したことを例外として通知してくれると書いたが、まさにこれがその通知である。
CFStringはNSString互換の内部型であり、この型のrespondToSelectorにより何らかのセレクタに応答するかを調べようと、オブジェクトインスタンス(アドレス:0xae437a0)にメッセージを送出したが、既に解放済み(ゾンビ)だった、という訳だ。

あとは、このオブジェクトがどこで生成されたかを調べることでゾンビの正体が分るのだが、それにはもう一つの環境変数であるMallocStackLoggingにより記録されたメモリアロケーション履歴を調べることで分る。

Xcodeで使われているデバッガ"gdb"は外部コマンドを起動できるシェルコマンドを持っており、デバッガウインドウから直接コマンドを叩くことができるので、ここからアロケーション履歴を見るためのコマンドを直接起動し直接ダンプすることができる。

(gdb) shell malloc_history 352 0xae437a0

第一パラメタはデバッガがアタッチしているアプリケーションPID、第二パラメタは対象のインスタンスアドレスである。

malloc_history(1) Mac OS X Developer Tools Manual Page

malloc_historyの出力結果 (バイナリ情報は長くなるので割愛)
malloc_history Report Version:  2.0
Process:         Homwpwner [352]
Path:            /Users/kazz/Library/Application Support/iPhone Simulator/5.0/Applications/Homwpwner.app/Homwpwner
Load Address:    0x1000
Identifier:      Homwpwner
Version:         ??? (???)
Code Type:       X86 (Native)
Parent Process:  gdb-i386-apple-darwin [354]

Date/Time:       2012-01-08 23:54:23.650 +0900
OS Version:      Mac OS X 10.7.2 (11C74)
Report Version:  7

ALLOC 0xae437a0-0xae437bf [size=32]: thread_ac7d62c0 |start | main | UIApplicationMain | -[UIApplication _run] | CFRunLoopRunInMode | CFRunLoopRunSpecific | __CFRunLoopRun | __CFRunLoopDoSource1 | __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE1_PERFORM_FUNCTION__ | PurpleEventCallback | _UIApplicationHandleEvent | -[UIApplication sendEvent:] | -[UIApplication handleEvent:withNewEvent:] | -[UIApplication _runWithURL:payload:launchOrientation:statusBarStyle:statusBarHidden:] | -[UIApplication _callInitializationDelegatesForURL:payload:suspended:] | -[HomwpwnerAppDelegate application:didFinishLaunchingWithOptions:] | -[ItemsViewController init] | -[PossessionStore createPossession] | +[Possession randomPossession] | +[NSString stringWithFormat:] | -[NSPlaceholderString initWithFormat:locale:arguments:] | _CFStringCreateWithFormatAndArgumentsAux | CFStringCreateCopy | __CFStringCreateImmutableFunnel3 | _CFRuntimeCreateInstance | CFAllocatorAllocate | __CFAllocatorSystemAllocate | malloc_zone_malloc

あとはこの中から自分が見覚えのあるソースコードと対応したものを追えば良い。この例だと、 +[Possession randomPossession] | +[NSString stringWithFormat:] で生成されたNSStringクラスのオブジェクトがゾンビ化しているのではないか、と推測することができる。


※1:解放された=死んだはずなのに活動を続けているように見えるオブジェクトをゾンビに例えている
※2:偶々使えるアドレスを参照していて処理が継続してしまうなんてこともざらである。