ベンチマークの自動化ばかりやっていたら、そろそろリリースも近いことだし自動化は適当に切り上げて速くしろという指令を受ける。

自分が見ているレイテンシの指標のうち重要とされてているものは２つある。A, B と呼ぼう。ベンチマーク自動化で B の計測が自分の持ち物になったのが先々週くらい。去年はもっぱら A ばかり見て B は無視していたら、案の定値は悪い。

Android Q からようやく Systrace の Trace#beginAsyncSection() がアプリからも使えるようになったので、とりあえずこれらの指標を annotate してみると、指標 B の遅さは明らかに何かが間違っている。コードを睨んでつついて原因を特定、修正を試作してあるべき速さになることがわかったので真面目に書き直してレビューにだす。ここまでで一日。こんなにさっくり直るひどい性能バグを放置しといてすまなかった・・・と反省。

このエピソードからわかる、知っておくべき性能改善の常識ふたつ:

ひとつめ。なにもしてない指標は遅い。指標 B は重要といいつつ自分に限らず誰も何もしていなかった。結果としてあっさり直る数百ミリ秒の遅延がたぶん一年くらいは放置されていた。「気をつけてコードを書く」ではコードは速くならない。速くするには時間と労力をかけて測って睨んでつきとめないとダメだし、遅くしないためには労力をかけて計測を自動化し監視しないとだめ。あたりまえ。

逆にいうとなにもしていない指標を速くするのは簡単である。なぜなら自明な遅さが放置されているから。組織が十分にボンクラなら、計測のインフラを作らず誰かが遅くしたコードを定期的に直し続けるだけで雇用を維持できる。しかし幸い自分の勤務先はそこまで無力ではないのだった。

ふたつめ。可視化は重要である。Trace#beginAsyncSection() は要するにスレッドやコールスタックをまたいだ区間を Systrace 上でマークするための API。同じものは昔から Chrome にあるし、 Android platform の中にもある。しかしなぜかアプリからは使えるようになっていなかった。同じ指標をログに書き出して Systrace と照らし合わせれば理論上は同じ情報量があるし、実際自分はそうやって指標を睨んできた。が、これが正しく可視化されると暗闇に突然明かりがついたような解像度をもち見逃していた問題が次々と明らかになる。

たぶん自分は Q 以前もなんとかして Systrace に out of band の指標をつっこんで可視化する方法を用意すべきだった。しかしそうしたツールの改善に労を割かなかった。よくなかったね。目先のプレッシャーがありすぎるせいなわけだが・・・。

なお Chrome にあって Android にない重要な可視化はもう一つある。それは IPC の呼び出しを追跡できる flow event. Android の Binder なんて Chrome IPC よりよっぽどヘビーに使われているし複雑、しかも Systrace は既に必要な情報は全部もっている。にもかかわらず可視化されていないのはひどい話なのだが、Android がひどいという事実に特に驚きはない・・・と書いていてさすがに自分が見逃してるだけな気もしてきた。あとで探し直そう・・・。

追記

入っていた！がバグだらけで使い物にならん。Sigh... OS 側がトラックしやすい annotation をつけておいてやればいいのだが、そうなってないせいで guess work が発生してダメなのだろう。やれやれ。