起動時間が長いとクラッシュ
iOS アプリは起動に時間がかかりすぎるとクラッシュする。具体的にはアプリで -[UIApplication application:didFinishLaunchingWithOptions:] での処理が規定された時間を越えた場合に iOS によって強制終了させられてしまう。これが原因で落ちた場合はクラッシュレポートの execution code が 0x8badf00d ("ate bad food") が出る。
（例）Incident Identifier: A3345F94-896E-4D74-AC14-282B3A8996C7 CrashReporter Key: 5e0a8626193824c21a4b9fef635fa1542c92d1c2 : Exception Type: 00000020 Exception Codes: 0x8badf00d Highlighted Thread: 0 Application Specific Information: LazyStartSample failed to launch in time Elapsed total CPU time (seconds): 1.530 (user 0.590, system 0.940), 8% CPU Elapsed application CPU time (seconds): 0.270, 1% CPU :Technical Note TN2151: Understanding and Analyzing iPhone OS Application Crash Reports によれば
Watchdog timeout: distinguished by exception code 0x8badf00d. Timeouts occur when an application takes too long to launch, terminate, or respond to system events.とある。Watchdog（監視プロセス）がアプリの起動時間を監視していて一定時間を超過するとそのアプリを強制終了する。限界時間はドキュメントで見つけられなかったが実測値で 20秒程度だった（iOS4.2.1/3GS）。
起動時間制限の例外
Technical Q&A QA1592: Application does not crash when launched from debugger but crashes when launched by user. によれば Xcode を経由しての実機デバッグ実行時はこの制限が外れるとのこと。これはアプリ本体の実行時間とは別にデバッガの初期化処理などで時間がかかる為。この為開発中には問題が出なかったに、リリース後に問題が表面化するということもありうる。
サンプル
-[UIApplication application:didFinishLaunchingWithOptions:] で単純に 25秒間 sleep するコードを書いてみた。
- (BOOL)application:(UIApplication *)application
didFinishLaunchingWithOptions:(NSDictionary *)launchOptions {
[self.window addSubview:viewController.view];
[self.window makeKeyAndVisible];
NSLog(@"%s|%@", __PRETTY_FUNCTION__, @"sleeping...");
[NSThread sleepForTimeInterval:25.0];
NSLog(@"%s|%@", __PRETTY_FUNCTION__, @"finished");
return YES;
}
実機で実行させしばらくした後に意図通りアプリが落ちる。ログは次の通り。
Incident Identifier: A3345F94-896E-4D74-AC14-282B3A8996C7 CrashReporter Key: 5e0a8626193824c21a4b9fef635fa1542c92d1c2 Hardware Model: iPhone2,1 Process: LazyStartSample [315] Path: /var/mobile/Applications/88AB96AC-0253-418B-8AE3-.... Identifier: LazyStartSample Version: ??? (???) Code Type: ARM (Native) Parent Process: launchd [1] Date/Time: 2011-02-11 16:13:03.788 +0900 OS Version: iPhone OS 4.2.1 (8C148a) Report Version: 104 Exception Type: 00000020 Exception Codes: 0x8badf00d Highlighted Thread: 0 Application Specific Information: LazyStartSample failed to launch in time Elapsed total CPU time (seconds): 1.530 (user 0.590, system 0.940), 8% CPU Elapsed application CPU time (seconds): 0.270, 1% CPU Thread 0: 0 libSystem.B.dylib 0x311de9f0 0x31165000 + 498160 1 libSystem.B.dylib 0x31167e28 0x31165000 + 11816 :sleep() なので（当然ながら）CPU 時間はほとんど使っていないが、起動時間が長いと強制終了させられる。
対策
アプリ起動時間を減らすしかない。でも時間がかかる処理があるとしたらどうするか。例えば Core Data のマイグレーションが行われる場合、処理件数が多いと数十秒かかるケースがある。この時間は Core Data を使っている限りは避けられない。とすると、処理時間がかかる処理の実行タイミングを遅らせるしかない。サンプルでは、-[UIApplication application:didFinishLaunchingWithOptions:] に sleep(25) を入れていた。試しに -applicationDidBecomeActive:に入れみたが駄目。では最初に表示されるビューコントローラのメソッドへ移したらどうか。
× viewDidLoad × viewWillAppear: × viewDidAppear:結果は×。最初のビューの初期化タイミングはアプリケーション起動時間に含まれてしまう。コールスタックを見ると理由がわかる（NSLog(@"%@", [NSThread callStackSymbols]);）。
0 0x00002609 -[LazyStartSampleViewController viewDidAppear:] + 44 1 0x338e52e7 -[UIViewController viewDidMoveToWindow:shouldAppearOrDisappear:] + 446 2 0x338b86ab -[UIView(Internal) _didMoveFromWindow:toWindow:] + 506 3 0x338b8433 -[UIView(Hierarchy) _postMovedFromSuperview:] + 106 4 0x338a382f -[UIView(Internal) _addSubview:positioned:relativeTo:] + 678 5 0x338a357f -[UIView(Hierarchy) addSubview:] + 22 6 0x00002307 -[LazyStartSampleAppDelegate application:didFinishLaunchingWithOptions:] + 82 :application:didFinishLaunchingWithOptions: の処理内だからまだアプリケーション起動が完了していないということになる。
試しにビューにボタンを付けて、起動後にユーザが押した場合に sleep(25)すると問題なく処理できた。
試しに SubViewController を新たに作り、メインのビューの -viewDidAppear: の中からこのビューをモーダル表示させてみた。
- (void)viewDidAppear:(BOOL)animated
{
SubViewController* viewController = [[SubViewController alloc] init];
[self presentModalViewController:viewController
animated:YES];
[viewController release];
}そしてサブビューの -viewDidAppear: 内で sleep(25)をかけてみる。- (void)viewDidAppear:(BOOL)animated
{
NSLog(@"%s|%@", __PRETTY_FUNCTION__, @"sleeping...");
[NSThread sleepForTimeInterval:25.0];
NSLog(@"%s|%@", __PRETTY_FUNCTION__, @"finished");
}さて実行する。起動後一瞬だけメインビューが表示された後、下からサブビューがせり上がってきてモーダル表示される。
2011-02-04 23:08:50.517 LazyStartSample[69102:207] -[SubViewController viewDidAppear:]|sleeping... 2011-02-04 23:09:15.869 LazyStartSample[69102:207] -[SubViewController viewDidAppear:]|finished出た。無事に処理し終えた。
ちなみにサブビューの viewDidAppear: におけるコールスタックは次の通り。
0 0x0000275d -[SubViewController viewDidAppear:] + 44 1 0x33972301 -[UIWindowController transitionViewDidComplete:fromView:toView:] + 860 2 0x3391af83 -[UITransitionView notifyDidCompleteTransition:] + 106 3 0x3391ae1b -[UITransitionView _didCompleteTransition:] + 798 4 0x33971f9b -[UITransitionView _transitionDidStop:finished:] + 34 5 0x338b4337 -[UIViewAnimationState sendDelegateAnimationDidStop:finished:] + 190 6 0x338c0c15 -[UIViewAnimationState animationDidStop:finished:] + 40 7 0x30a89ea9 _ZL23run_animation_callbacksdPv + 292 8 0x30a89d4b _ZN2CAL14timer_callbackEP16__CFRunLoopTimerPv + 122 9 0x314870a3 __CFRUNLOOP_IS_CALLING_OUT_TO_A_TIMER_CALLBACK_FUNCTION__ + 14 10 0x31486b5b __CFRunLoopDoTimer + 850 11 0x314581b5 __CFRunLoopRun + 1088application:didFinishLaunchingWithOptions: とは無関係にランループのイベントから処理が始まっている。つまりアプリ起動時間にはカウントされない。
この方法を使う場合の流れのイメージは次のとおり。
1. メインビュー viewDidAppear: で時間のかかる処理が必要か判断する。 （例えば Core Data のマイグレーション） 2. 処理が必要な場合、サブビューを呼び出しそこで時間のかかる処理を行う。 この時、ユーザに処理中であることを表示する（ウェイトカーソルなど。必要なら キャンセルボタン）。終了後は自動もしくはユーザの確認の上、メインビューへ戻る。 3. 処理が不要な場合はそのままメインビューで処理を続行する。
ソースコード
GitHub からどうぞ。
LazyStartSample at 2011-02-04 from xcatsan/iOS-Sample-Code - GitHub
参考情報
"ate bad food"
0x8BADF00D ("ate bad food") is used by Apple in iOS crash reports, when an application takes too long to launch,
Cocoaの日々: +[NSThread callStackSymbols]でコールスタックのダンプ
- - - -
現在アプリバージョンアップに伴う Core Data マイグレーションでまさにこの問題に直面中。上記アプローチでまずは対応する予定だがうまく行ったらその顛末を後ほどブログで紹介する。
Responses
Leave a Response