ラベル 可視化 の投稿を表示しています。 すべての投稿を表示
ラベル 可視化 の投稿を表示しています。 すべての投稿を表示

2020年6月2日火曜日

Windows Performance Analayzer で C++ ビルド時間のプロファイルをしてみよう！


最近 clang の -ftime-trace オプションと chrome://tracing を使ってビルド時間の可視化をしてみましたが、Microsoft が提供している WPA（Windows Performance Analyzer | Microsoft Docs）も便利そうということで試してみました。


使い方
セットアップ
使い方は↑のツイートのリンク先ブログにも記載されています。

必要なのは VS2019 と Windows ADK です。
リンク先からダウンロードしてインストールしてください。
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, ...）
(※ CI-Spec で調査)

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 の特殊化がありました。
https://github.com/srz-zumix/iutest/blob/4f45ac420533dfd068da2fb705e4ac3b1cc32813/include/internal/iutest_genparams_from_file.hpp#L100

おそらく、これが原因でしょう。
今回の記事はここまでですが、この修正結果については Twitter かブログで報告したいと思います。

最後に
WPA はプラットフォームは限られますが、clang -ftime-trace + chrome://tracing でプロファイルするよりも、ビルド時間のボトルネックになりやすい Template Instantiation を調べやすくていい感じだなと思いました。
セットアップや使い方も簡単なのでぜひやってみてください。

では。

追記（2020/06/15）

iuCsvFileParamsGenerator の特殊化をなくして、もっと低レベルでの特殊化（クラス外に追い出した）ところワーストから消えてることを確認しました。

今回の計測前後の etl ファイルをこちらに置いておいたので興味がある方は分析してみてください。


投稿者 時刻: 0 件のコメント:
ラベル: , , ,

2020年5月11日月曜日

chrome://tracing で並列処理の可視化をしてみたらすごく便利だった話

前回「ブログズミ: [C++] -ftime-trace オプションと Chrome でビルド時間の可視化」の続きです。
chrome://tracing の活用として iutest で使用している CI サービスの並列具合を調べて可視化してみました。

レポート集計の構成
各 CI サービスから並列具合を可視化するために使用したのは、 Intergromat と Google スプレッドシートの２つです。
構成は下図のようになっています。


まず各 CI サービスからはジョブごとに処理の開始・終了時に、Integromat で用意した Webhook URL に情報を送信します。
各 CI サービスで並列化する方法は ci-parallel リポジトリ の YAML を確認してください。
Webhook には「CIサービス名」「commit hash」「名前」「並列番号」「時刻」「開始・終了イベント」などの情報が付与されて来ます。
その情報から、Integromat で Google Drive から CI サービスごとのスプレッドシートを検索し、そこにコミットごとにシートを作成して情報を書き込みます。


そこから Chrome の tracing で表示するための json ファイルに GAS を使って変換しダウンロードします。
あとは、ダウンロードした json ファイルを tracing で読み込めば可視化が完成です。
tracing 用 json への出力
chrome://tracing の json フォーマットはこちらを参考にしました。

function getData() {  
  var sheet = SpreadsheetApp.getActiveSheet();
  var maxRow = sheet.getLastRow();//行数 -
  var maxColumn = sheet.getLastColumn();//列数 |
  var keys = [];
  var ret = [];

  //1列目のkeyの名前取得
  for (var x = 1; x <= maxColumn; x++) {
    keys.push(sheet.getRange(1, x).getValue());
  }

  var base = 0;
  //データ
  for (var y = 2; y <= maxRow; y++) {
    var json = {};
    for (var x = 1; x <= maxColumn; x++) {
      var k = keys[x-1];
      var v = sheet.getRange(y, x).getValue();
      if( k == "ts" ) {
        var d = new Date(v);
        if( base == 0 ) {
          base = d.getTime();
        }
        v = (d.getTime() - base) * 1000;
      }
      
      json[k] = v.toString();
    }
    ret.push(json);
  }

  //整形してテキストに
  return JSON.stringify(ret, null, '\t');  
}
行のヘッダー名と要素は Integromat で tracing フォーマットに合わせて書き出しているので、ほぼほぼそのまま json にしています。
時間だけ最初のレコードを起点にした差分時間に変換しています。
結果
こんな感じになりました。

詳細は ci-parallel リポジトリを確認してください。
最後に
CI サービスの並列具合を可視化しようと思い、最初は BI ツールを転々と試していたのですが、 tracing がベストマッチでした。
もちろん何をどのように可視化したいかによって、 BI ツールを使うべき場合もありますが、可視化の選択肢として tracing は覚えておいて損はなさそうです。
そして、今回は単純な Duration イベントのみを使いましたが、他のイベントも使うともっといろいろな表現ができそうです。

メモリの追跡はありですね。やってみようかな。

あと、今回はスプレッドシート使いましたが、BigQuery とか使ったほうがイケてるのかな？
この辺今まで触ってこなかったので覚えていきたいですね。

宣伝

「技術書典　応援祭」で販売した本には今回調べた並列処理の比較はありませんが、次回作に向けて鋭意活動中です。そちらには収録を予定しています。
既刊および次回作をよろしくおねがいしますmm

今回は以上です。では。
投稿者 時刻: 0 件のコメント:
ラベル: , , ,

2020年4月30日木曜日

[C++] -ftime-trace オプションと Chrome でビルド時間の可視化

C++ のビルド速くしたいなーと思ってて、そのためにはまずは計測だよねってことで調べてたら行き着いたのですが、clang に -ftime-trace があり、その出力を Chrome で可視化ができるとのこと！ （懐かしき SN Systems..）

早速、仕事でも個人でも使ってみたんですが、これはとても便利ですね。




しかも、 「chrome://tracing」 はフォーマットが公開されているので、これに従って出力すれば他にも可視化できそうです。
Trace Event Format - Google ドキュメント
↓は CircleCI での並列具合を可視化したもの。こちらについては来週ブログにしたいと思います。

今回は以上です。では。


投稿者 時刻: 0 件のコメント:
ラベル: , ,
登録: 投稿 (Atom)