TkMixiViewerで発生していた「画面が真っ黒になって応答不能になり、しばらくするとANRが発生し強制終了しかできなくなる」現象について。原因から言い換えると、Android 2.xでonSaveInstanceStateのoutStateに数百KBの文字列を格納すると「プロセスが死ななくなる」事象について。
1週間以上悩み続けた謎の強制終了バグの原因について
1週間以上悩み続けた謎の強制終了バグの原因がついに分かった!
せっかくなのでコトの顛末を記録しておく。
原因は onSaveInstanceState で outState に「ある程度」以上のサイズの文字列を格納すると「プロセスが死ななくなる」ため。
しかも死んだままActivityも起動できなくなる(HPROFを見ると恐ろしくまっさらなプロセスだった)ので真っ黒な画面しか表示されない。もちろんonCreateも呼ばれないし、ログにも「無応答なプロセス見つけたから殺しておいたよ」という情報だけ。
デベロッパーコンソールで見えるスタックトレースも下記のように情報量ゼロ。
java.lang.NullPointerException at android.app.ActivityThread.handleStopActivity(ActivityThread.java:2493) at android.app.ActivityThread.access$1800(ActivityThread.java:121) at android.app.ActivityThread$H.handleMessage(ActivityThread.java:960) at android.os.Handler.dispatchMessage(Handler.java:99) at android.os.Looper.loop(Looper.java:130) at android.app.ActivityThread.main(ActivityThread.java:3701) at java.lang.reflect.Method.invokeNative(Native Method) at java.lang.reflect.Method.invoke(Method.java:507) at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:624) at dalvik.system.NativeStart.main(Native Method)
ちなみにPlayストアのコメントはこんな感じで荒れまくってました。。
実はデベロッパーコンソールのクラッシュレポートはもっとしんどいです。
大量に同じようなコメントがありますが一部抜粋すると、、、
これだけのコメントをされるとなんとか解決せねばなりません。追い込まれました。。
元々見えていた条件は
- Android 2.3 でよく発生している。
- ICS以降では発生していないっぽい。
- 起動・終了を繰り返すと発生する。
- 最近のバージョンアップで発生する。
ただこの最後の条件がネックで、最近の修正のdiffをずっと追いかけ続けたんだけど全く手がかりはなく。これで数日つぶれちゃった。
結局数名のユーザさんから情報提供を得てやり取りをしているうちに「バックグラウンドにすると発生しやすい」という条件を見つけ、手元のISW11Fで
「起動⇒終了⇒起動⇒FMR Memory Cleanerでメモリ解放⇒起動(ここで真っ黒)」
という再現手順にたどり着く(再現性は7割くらい)。
「あとは古いapkを入れて再現しなくなるところでdiff確認だなー」などと思って順番に入れていったんだけど結局1年前のapkでも再現しちゃうw
で、ためしにTafView*1で同じことやってみても再現しない。
そこで思いっきり視点を変えて、まずAndroidManifest.xmlからトップ画面以外の全Activityの情報を消して、ソースもがっつり消して、起動処理に必要なソースだけにして、再現しなくなるまで裸に(むしろ骨だけに)する作業を開始。
デバッグ作業でよく行われるいわゆる「追い込み漁」ですね。他の人が呼んでるの聞いたことないけど。
追い込み漁の最中、ふとしたタイミングで「通信を行わなければ発生しない」という条件を見つけ、そこから「通信処理自体」「通信後の処理」といった追い込みを続けたところ、ついに「受信したHTMLをインスタンス変数に保存する処理」をなくすことで発生しなくなるという条件を発見!!そして、その変数が onSaveInstanceState で保存されるために引き起こされるという(冒頭に書いた)原因が分かったのでした。
さて、ではなぜ「最近のバージョンアップで発生する」ようになったのか。
どうやらmixiのトップページのHTMLサイズが最近少し増えたらしく、そのタイミングとバージョンアップが重なったのでバージョンアップが原因と思われた模様。
それまでなんとか閾値を超えなかったので本不具合が顕在化しなかっただけということですね。恐ろしい限り。
「Bundleにでかい文字列を突っ込むな」っていうのはたぶん基本中の基本なんだろうし、本当にお恥ずかしい限り。
そしてこの不具合、ICSでは発生しないのでAndroid2.xのバグなんじゃないのって思ったりするんだけど実は閾値が端末によって違うのでもう誰になんといったらいいのやら。。
いずれにしても、実に1年以上存在し続けていた地雷を取り除いたわけで、、、これでなんとか、、気持ちよく新しい年を迎えられそうです。。
あーほんとしんどかった。
12/28追記
「onSaveInstanceState なんてつかわねーよハゲ!」って人のためにお伝えすると、Intent の extras も数百KBの文字列を格納するだけで(Android 2.3以前の端末では)同じような現象が起きます。
Activityがなぜか起動しないという条件に当てはまったら思い出してあげてください。
-
-
- -
-
上記はFacebookの元記事(1週間以上悩み続けた謎の強制終了バグの原因について)を一部加筆・修正したものです。
*1:同じく私が作ったFBブラウザ。TkMixiViewerのソースを元に作成したもの