nmi.jp Twitter → @tkihira
巨大 WebAssembly ファイルのコンパイル時間 Rust で WebAssembly を出力する

Chrome の隠し機能 chrome://tracing (about:tracing) の使い方


2018-02-17
Takuo Kihira

こんにちは。仕事上で chrome://tracing (about:tracing) を使う必要が出たので、私の知っている限りの情報をここでまとめることにしました。

chrome://tracing の情報は世の中にあまりありません。もし記事中に間違いを見つけられたり、より良い利用方法をご存知の方は、ぜひ @tkihira まで教えてください。よろしくお願いします!

なお実際は隠し機能ではなく、ただあまり知られていないだけです。公式の情報は https://www.chromium.org/developers/how-tos/trace-event-profiling-tool ここから辿れると思います。

注意

この機能は、Chrome のインスタンス全体のプロファイルを取るものです。不用意に実行すると、すべての Chrome のタブを巻き込んで落ちます。記事中では Chrome Canary を別に立ち上げて、そこで計測しています。皆様も気をつけてください。

どんな時に使うのか

Chrome には、皆さんご存知 DevTools があります。大変高機能で、Web の開発において頻繁に利用します。私が一番使うのはコンソールですが、他にもネットワークのログを見たり、メモリのスナップショットを取ったり、DOMにアクセスして要素を変更したり、Web 開発に便利な様々な機能が利用できます。

DevTools の中には Performance というタブがあり、ここでプロファイルを取ることが出来ます。瞬間瞬間のCPUの使用率、その時点で呼び出されている関数と消費時間、メモリ使用率、スクリーンショットなどなど、時系列でアプリケーションのいろいろな情報を記録することが出来て、それらの情報は問題の原因を探る上で貴重な手がかりになります。

普通はこれらの情報で十分足りるのですが、巨大な asm.js や WebAssembly などとガッツリ取り組んでいる場合、時たまプロファイルが出力する情報では満足出来なくなることがあります。

例として、WebAssembly の公式デモのプロファイルを取ってみましょう。Unity から出力されたサンプルゲームのプロファイルです。

WebAssembly Profiling Result

私の環境ではダウンロード完了から起動までに10秒ほどかかっているのですが、そこに記録されているのはRun Microtasksという謎の処理です。また、それ以外の何も記録されていない白い部分でも相当の時間がかかっており、一体内部でどのような処理を行っているのか(もしくは本当に何もしていないのか)をこのプロファイル結果から伺い知ることは出来ません。

(こんなことは普通に開発している限り、滅多にないんですけどね…)

このような場合に、C++ のソースコードレベルで何をしているのかチェックしたい場合に使うのが chrome://tracing (about:tracing) です。たぶん。今回は、この謎の空白部分でブラウザが何をしているのかを調べてみましょう。

使い方

chrome://tracing は、Chrome で動いているすべてのタスクのプロファイルを取ります。関係ないページを沢山開いていると、それらすべてのプロファイルも取ることになります。それは無駄ですし不用意に実行するとブラウザの反応がなくなるほど重くなるので、個人的に chrome://tracing を使う時にはそれ専用の Chrome インスタンスを別に立ち上げています。今回は Chrome Canary を使うことにしました。

まずはアドレスバーに about:tracing (もしくは chrome://tracing )と打ち込みます。そうすると次の画面が出てきます。

usage

この画面を見るときは大体切羽詰まっているので、謎の顔文字にイラッとします。ここで左上の Record ボタンを押します。

usage

とりあえず今回は WebDeveloper を選んでおきましょう。ここで Edit categories を選んで細かく出力情報を選べるので、ぜひ見てみてください。さて、ここで Record を押すとプロファイリングが始まるのですが、その前に別タブを立ち上げてプロファイル対象の準備をしましょう。

usage

私はプライベートモードで立ち上げました。プライベートモードのタブであっても問題なくプロファイルをとれます。

そして、chrome://tracing のタブに戻り、Record ボタンを押して、プロファイルの対象タブに移動し、今回の場合は Play WebAssembly ボタンを押します。そしてプロファイルしたいところまでの動作が完了したら、Stop ボタンを押してプロファイルを止めます。

usage

色々と内部で処理が終わったら、プロファイルの結果が表示されます。このプロファイル結果画面は、DevTools みたいに優しくありません。マウスツールを駆使しながら時間軸の拡大縮小を行い、目的の部分を見つけ出す必要があります。大変面倒です。

とりあえずスクロールし、Unity WebGL Player | Tanks! と書かれた Renderer を見つけ、そこの CrRendererMain に注目しましょう。

usage

マウスツールの「拡大縮小」を選び、紫のバーの先頭の方を拡大してみます。拡大縮小ツールは上にドラッグすると拡大、下にドラッグすると縮小出来ます。上手く拡大して対象をダブルクリックして、次のように具体的になにをやっているのか確認してみましょう。

usage

例えばここでは V8.ScriptCompiler が呼ばれていることが確認出来ました。では問題の、プロファイル上では空白に見えた地点で何をやっているのか確認してみましょう。紫のバーに見えた所を拡大してみると、細かいタスクの寄せ集めであることがわかります。そのうちの一つを確認してみましょう。

usage

何らかの超小さいタスクが実行されていることがわかります。ソースコードは v8_foreground_task_runner.cc、関数名は PostTask であることが読み取れます。今回のプロファイリングからは、どうやら WebAssembly のコンパイル後に、何らかの超細かい大量のタスクが実行されていること、また個々のタスクが小さすぎてオーバーヘッドが大きく無駄な時間が消費されていること、が読み取れます。これ以上調べるためには、直接ソースコードを読んで、実際にデバッグログを入れた Chromium をビルドしたりすることになりそうです。

まとめ

Chrome は DevTools のプロファイラが大変しっかりしているので、この機能が必要になる状況においてこの機能を使っても、大抵の場合、特に解決しません。それでも、どうしようも無い時にブラウザの奥底で何が起こっているのかを可能な限り理解するための手軽な方法としては結構役立ちます。以前この機能を使うことで、Chrome のバグで無駄な JavaScript の再コンパイルが発生していることを確認出来たので、報告して修正してもらったことがありました。

あまり使うことはないとは思いますが、知っていて損をする情報でもないですし、日本語資料は一切無かったと思うので、書いておきました。自分も詳しいわけではないので、(冒頭でも書きましたが)間違いやもっとよい使い方などご存知であれば、ぜひ @tkihira まで教えてください。よろしくお願いします!

追記(2018-02-18)

Twitterにて azu さんに “パフォーマンス計測に困らない!tracing活用術100” という Web を教えてもらいました。上で「日本語資料は一切なかった」とか書いておきながら、こんなに詳しいサイトがあったんですね、お恥ずかしい。ありがとうございました!