高速化日記 (9) - Processing Traces

前回のつづき。

機能 F が招くコマ落ちの原因探求、最初の被疑者たる CPU 負荷は無罪の見通しとなったため、他の指標をさがす。

コマ落ちの直接の原因である HAL API A のレイテンシは機能 F の有無でどのくらい違うんだろうか。Systrace の HTML を肉眼で眺めていてもいまいち決定的な違いが見えない。重い腰を挙げて Colab を開き、適当に正規表現を書いて Systrace 内のデータに含まれる該当 API のトレースを読んでレイテンシを抜き出す。そして時系列にプロットしてみる。

と、やはり F 有効時はちょっと悪い気がする。しかしなぜかがわからない・・・。

さて、件の API は何かと言うと、共有メモリ (gralloc) のアロケーションである。そして件の API 内部のトレースには要求されたメモリのサイズが書いてある。このサイズを見ると、誰が要求したメモリなのかがひと目でわかる。そしてサイズがでかいほどレイテンシは大きくなりがち。

ふと思い立ってパーサのロジックを書き足し、プロット (scatterplot) にサイズを反映してみる。X 軸を時系列、Y をレイテンシ。サイズを色に割り振ると・・・やはりサイズがでかいアロケーションは遅い。そして F 有効時はそもそも「サイズのでかいアロケーション」の数が多い!沢山の細かいアロケーションに隠れていて気づかなかったが、こりゃ遅くなるわ!アプリのログや同僚へのインタビューでこの事実を確認する。振り返るとアルゴリズムの性質から自然な帰結である。OMG.

この初歩的な問題に何週間も気づいてなかったのは shame. 肉眼さん・・・。

API リクエストの頻度自体は他の機能によるリクエストが支配的で、総数は機能 F の有無で大きな差はない。しかし他の機能がリクエストするアロケーションはぜんぶサイズが小さい。F によるアロケーションはでかい。しかも F のスレッドが直接リクエストを発行するのではなく、F がメモリを長時間保有するせいで普段はプロセス内で資源が再利用され省略されるアロケーションが発生してしまうという間接的な症状なのでグチャっとしたトレースを睨むだけでは気付けなかった。

というわけで可視化重要。あとゴチャっとしたデータをパースして構造化するのも重要。トレースをパースするコード片を書き溜めないとな。

可視化素人としては subplot の利用と scatterplot の color axis を使えるようになったのが最近のブレークスルーであった。