使い方
セットアップ
使い方は↑のツイートのリンク先ブログにも記載されています。
リンク先からダウンロードしてインストールしてください。
VS2019 では Community Edition でも問題なくプロファイリングできます。
次に VS2019 のインストールディレクトリから perf_msvcbuildinsights.dll を ADK のインストールディレクトリにコピーします。
「C:\Program Files (x86)\Microsoft Visual Studio\2019\{Edition}\VC\Tools\MSVC\{Version}\bin\Hostx64\x64」
→「C:\Program Files (x86)\Windows Kits\10\Windows Performance Toolkit」
（Visual Studio の方のパスは環境によって変わるので適宜変更してください。筆者環境では「C:\Program Files (x86)\Microsoft Visual Studio\2019\Community\VC\Tools\MSVC\14.26.28801\bin\Hostx64\x64」でした）
筆者が試したときは、ADK インストールディレクトリにすでに同名ファイルがありましたので、バックアップを取ってコピーしました。
このコピーをしておかないと C++ Build Insights （Template instantiations や Files）が見られないので注意してください。
トレース
準備が整ったらプロファイルを取得してみましょう。
こちらもブログの手順のとおりに行えば ok です。
まずは、「x64 Native Tools Command Prompt for VS 2019」を管理者権限で起動します。（vcvarsall.bat などから環境セットアップしたプロセスでも ok）
vcperf /start /level3 name
でトレースを開始します。
開始できたら、普通に Visual Studio でビルドしてください。（IDE からでもコマンドからでもどちらでも ok）
ビルドが終わったら vcperf を停止させます。このとき出力ファイルを指定します。
vcperf /stop /templates name output.etl
WPA で表示する
etl ファイルができたら WPA で表示してみましょう。
etl ファイルをダブルクリックすれば WPA が起動します。
ローディングが終わると以下のように表示されます。
あとは、Diagnostics から項目を選んでいけばビルドで何にどれだけ時間がかかっているのかが確認できます。
CircleCI で vcperf
ローカル環境でプロファイルを取得することもできますが、面倒なので CI でやるようにしてみました。今回使用した CI サービスは CircleCI です。
ターゲットとなるのはおなじみ「自作 C++ テスティングフレームワーク」の
iutest です。
CircleCI を選択した理由は、すでに -ftime-trace の結果を CircleCI の成果物として保存するようにしていたので、vcperf の成果物も CircleCI に置こうと思ったからです。
それ以外の理由は特にありません。VS2019 がインストールされている Windows エージェントが使用可能なサービスであれば他でも問題ないと思います。（AppVeyor, Azure Pipelines, GitHub Actions, ...）
config.yml と計測用に追加したバッチファイルがこちら。
orbs:
win: circleci/windows@2.2.0
jobs:
vcperf:
executor: win/default
environment:
CMAKE_GENERATOR_NAME: "Visual Studio 16 2019"
CMAKE: "C:/CMake/bin/cmake.exe"
steps:
- checkout
- run:
name: install
command: |
$ProgressPreference = "SilentlyContinue"
Invoke-WebRequest -URI https://github.com/Kitware/CMake/releases/download/v3.16.4/cmake-3.16.4-win64-x64.zip -OutFile $Env:HOMEPATH\cmake-3.16.4-win64-x64.zip
Expand-Archive $Env:HOMEPATH\cmake-3.16.4-win64-x64.zip -DestinationPath "C:\"
Rename-Item "C:\cmake-3.16.4-win64-x64" -NewName CMake
- run:
name: cmake
shell: bash.exe
command: |
mkdir build && cd build && ${CMAKE} ../projects/cmake -G "${CMAKE_GENERATOR_NAME}" -A x64
- run:
name: vcperf
shell: cmd.exe
command: .circleci\vcperf_build.bat
- store_artifacts:
path: .\iutest.etl
call tools\VisualStudio\vcperf.bat /start /level3 iutest
%CMAKE% --build .\build
call tools\VisualStudio\vcperf.bat /stop /templates iutest iutest.etl
計測用にバッチファイルを別途用意しているのは config.yml の command で１つずつ処理しようとしたら vcvarsall.bat の exit 0 で処理が止まってしまったからです。
vcvarsall は vcperf.bat から呼び出されるようになってます。
もっと良い解決方法あれば教えて下さいmm
このジョブが完了すると Artifacts に iutest.etl がアップロードされています。
ダウンロードして WPA で確認してみましょう。
iutest のプロファイルを見てみる
では CircleCI で取得した etl ファイルを見てみましょう。
Build Explorer
まずは「Build Explorer」の結果↑
どのような処理がどのくらい時間がかかったかがわかります。
１ファイルのコンパイルにおいてどのようなことをしているのかも詳細に確認することができます。
Files
次に「Files」です↑
こちらは各ファイルの処理にどれだけ時間がかかったかがわかります。
また呼び出された回数もわかるので、Count が多いファイルは無駄に include されていないか確認すると良いかもしれません。
↑のようにファイルを展開すると、どこから include されたかどうかが１つずつ確認することができます。
Template Instantiations
最後に「Template Instantiations」です↑
こちらでは template の実体化にかかった時間がわかります。
デフォルトでは「Primary Template Name」が Visible になっているので、 すべての引数パターンが template クラス・関数名でまとめて表示されています。
こちらの Visible のチェックを外すと template 引数違いで時間順に並べられます。
これでボトルネックになっている template の実体化が見つけやすくなると思います。
また検索機能を使うことで、↓のように特定の名前に絞って表示することもできます。
Specialization Names のノードを開くと、どこから実体化されたかもわかるようになってます。
改善ポイント
さて、iutest に絞り込んだ場合 iuCsvFileParamsGenerator<float> の実体化がトップでした。
しかしながら、この iuCsvFileParamsGenerator は CSV ファイルからテストパラメータを読み込ませるときにしか実体化されない想定でした。
上記の2枚目の画像を見ていただくと、Count が 155 回記録されています。
今回記録したときのビルドでは複数のテストをビルドしていますので、おそらくテストの数（exe の数）だけ実体化されていそうです。
使うときにだけ実体化されるのが理想なので、詳細を追ってみたところ、iuCsvFileParamsGenerator<float>::ToParam の特殊化がありました。
おそらく、これが原因でしょう。
今回の記事はここまでですが、この修正結果については Twitter かブログで報告したいと思います。
最後に
WPA はプラットフォームは限られますが、clang -ftime-trace + chrome://tracing でプロファイルするよりも、ビルド時間のボトルネックになりやすい Template Instantiation を調べやすくていい感じだなと思いました。
セットアップや使い方も簡単なのでぜひやってみてください。
では。
追記（2020/06/15）
iuCsvFileParamsGenerator の特殊化をなくして、もっと低レベルでの特殊化（クラス外に追い出した）ところワーストから消えてることを確認しました。
今回の計測前後の etl ファイルをこちらに置いておいたので興味がある方は分析してみてください。
