この記事は、KLab Engineer Advent Calendar 2022の7日目の記事です。

こんにちは、@makki_dです。

先日KLabから「WSNet2」というリアルタイム通信システムのOSSをリリースしました。 ここには、サーバサイドでゲームロジックを実行するサンプルとして、ゲームロジックだけを動かす.NETアプリケーションの実装も含んでいます。

ゲームロジックの実装にはパフォーマンスチューニングが不可欠です。 UnityであればProfilerウィンドウがあるのですが、.Netアプリではどのようにパフォーマンスを計測したらよいでしょうか。 いろいろ調べていたところ「dotnet-trace」コマンドを見つけました。 このツールを使うと、いつどんなメソッドが呼ばれどれくらい時間がかかったか、といった情報が見れるようになります。

dotnet-traceとは

.Net CLIツールのひとつで、上記画像のようなメソッド呼び出しのトレース情報が取得できます。 詳しくはMicrosoftのページを見ていただきたいのですが、ここでは基本的な使い方を紹介します。

トレース情報の取得

dotnet trace collect -- <traceを取得したいコマンド>

これで指定したコマンドが実行され、トレース情報が取得できます。 すでに動いているプロセスからトレース情報を取得する-p <pid>オプションもあります。

取得したトレース情報は、特に指定しなければ コマンド名_日付_時刻.nettrace というファイルに出力されます。 出力ファイルのフォーマット（Chromium, Speedscope）を指定することもできますが、*.nettraceファイルは毎回出力されますし、 dotnet trace convertコマンドで *.nettraceから変換できます（NetTrace以外からの変換はできません）。

dotnet trace convert --format Chromium ファイル名.nettrace
dotnet trace convert --format Speedscope ファイル名.nettrace

それぞれ、ファイル名.chromium.json、ファイル名.speedscope.json が出力されます。

可視化

NetTrace形式のファイルをdotnet trace reportコマンドで集計できますが、topNしかなくて力不足です。 Windowsであれば PerfView というツールもあるようですが、他の環境ではChromiumやSpeedscope形式で出力してそれ用のツールを使うのがよさそうです。

Chromium形式

GoogleChromeで chrome://tracing にアクセスし、左上の「Load」ボタンからChromium形式のファイル(*.chromium.json)を読み込みます。 操作方法は右上の「?」ボタンを押すと説明が見れます。 時系列順に、どんなメソッドが実行されているかが一目瞭然です。

Speedscope形式

ブラウザで https://speedscope.app/ にアクセスし、Speedscope形式のファイル(*.speedscope.json)を画面に従って読み込みます。 左上の「Time Order」を選択するとChromeの時と同様の時系列順の情報が見れるのに加えて、 「Sandwitch」では処理時間順にソートしたり、特定のメソッドのCaller/Calleeを一覧できたりします。 高機能なのですが、中央上部で選択されているスレッドの情報しか表示されないため、切り替えながら閲覧していくことになります。

まとめ

この記事ではdotnet-traceの基本的な使い方と、取得したトレース情報の可視化方法を紹介しました。

.NetアプリでTaskを使ったマルチスレッドな実装をしていると、どのスレッドでどの処理が行われているか分かりにくいのですが、 Chromium形式で可視化すると1ページに全てのスレッドの情報が表示されるので、目的の処理を探しやすいです。 目的のスレッドが分ったらspeedscopeで細かく調べるという使い方が便利そうです。

.NETアプリを実装するときにはdotnet-traceを活用していきたいですね。