JSON トレース プロファイル

<ph type="x-smartling-placeholder"></ph> 問題を報告する ソースを表示 夜間 · 7.3 · 7.2 · 7.1 · 7.0 · 6.5

JSON トレース プロファイルは、Bazel が何に費やしたかをすばやく把握するのに非常に役立ちます。 呼び出すことができます。

デフォルトでは、すべてのビルドに似たコマンドとクエリに対して、Bazel はそのようなプロファイルを command.profile.gz。プロファイルに --generate_json_trace_profile そのフラグが格納される場所は、 --profile フラグ。末尾が .gz の地域: GZIP で圧縮されます。フラグを使用する --experimental_announce_profile_path このファイルへのパスをログに出力します。

ツール

このプロファイルを chrome://tracing に読み込むか、分析して 他のツールで後処理します

chrome://tracing

プロファイルを可視化するには、Chrome ブラウザタブで chrome://tracing を開きます。 [読み込み] をクリックします。圧縮される可能性があるプロファイル ファイルを選択します。詳細情報 左下のボックスをクリックします。

プロファイルの例:

プロファイルの例

図 1. プロファイルの例。

次のキーボード コントロールを使用して移動できます。

  • 「選択」するには 1 を押しますモードです。このモードでは イベントの詳細を調べられます(左下を参照)。 複数のイベントを選択すると、概要と集計された統計情報が表示されます。
  • 2 キーを押すと「パン」モードです。次に、マウスをドラッグしてビューを移動します。マイページ a / d を使用して左右に移動することもできます。
  • 3 キーを押すと「ズーム」できますモードです。マウスをドラッグしてズームします。Google Chat では また、w/s を使用して拡大、縮小することもできます。
  • 「タイミング」を表示するには 4 キーを押しますこのモードでは距離を測定できます 学習します。
  • すべてのコントロールについて確認するには、? キーを押します。

bazel analyze-profile

Bazel サブコマンド analyze-profile プロファイル形式を使用し、 ビルドフェーズごとに異なるタスクの種類と、クリティカル パスの分析を行います。

たとえば、コマンドは

$ bazel build --profile=/tmp/profile.gz //path/to:target
...
$ bazel analyze-profile /tmp/profile.gz

次のような出力が生成されます。

INFO: Profile created on Tue Jun 16 08:59:40 CEST 2020, build ID: 0589419c-738b-4676-a374-18f7bbc7ac23, output base: /home/johndoe/.cache/bazel/_bazel_johndoe/d8eb7a85967b22409442664d380222c0

=== PHASE SUMMARY INFORMATION ===

Total launch phase time         1.070 s   12.95%
Total init phase time           0.299 s    3.62%
Total loading phase time        0.878 s   10.64%
Total analysis phase time       1.319 s   15.98%
Total preparation phase time    0.047 s    0.57%
Total execution phase time      4.629 s   56.05%
Total finish phase time         0.014 s    0.18%
------------------------------------------------
Total run time                  8.260 s  100.00%

Critical path (4.245 s):
       Time Percentage   Description
    8.85 ms    0.21%   _Ccompiler_Udeps for @local_config_cc// compiler_deps
    3.839 s   90.44%   action 'Compiling external/com_google_protobuf/src/google/protobuf/compiler/php/php_generator.cc [for host]'
     270 ms    6.36%   action 'Linking external/com_google_protobuf/protoc [for host]'
    0.25 ms    0.01%   runfiles for @com_google_protobuf// protoc
     126 ms    2.97%   action 'ProtoCompile external/com_google_protobuf/python/google/protobuf/compiler/plugin_pb2.py'
    0.96 ms    0.02%   runfiles for //tools/aquery_differ aquery_differ

Bazel 呼び出しアナライザ

オープンソース Bazel 呼び出しアナライザ プロファイル形式を使用し、改善方法の提案を出力します。 パフォーマンスが向上します。この分析は CLI または https://analyzer.engflow.com.

jq

JSON データの jqsed に似ています。jq の使用例: すべての ローカル アクションの実行時におけるサンドボックス作成ステップの持続時間:

$ zcat $(../bazel-6.0.0rc1-linux-x86_64 info output_base)/command.profile.gz | jq '.traceEvents | .[] | select(.name == "sandbox.createFileSystem") | .dur'
6378
7247
11850
13756
6555
7445
8487
15520
[...]

プロフィール情報

プロファイルに複数の行が含まれています。通常、行の大部分が Bazel を表しています スレッドとそれに対応するイベントですが、特別な行も含まれます。

含まれる特殊な行は、コマンドの実行時に呼び出された Bazel のバージョンによって異なります。 プロファイルが作成され、さまざまなフラグでカスタマイズされる場合があります。

図 1 は、Bazel v5.3.1 で作成されたプロファイルを示しています。これらの行が含まれています。

  • action count: 処理中の同時実行アクションの数を表示します。[ 実際の値を確認できます。最大キャパシティに達すると --jobs なし 説明します。
  • CPU usage (Bazel): ビルドの 1 秒ごとに、 Bazel で使用された CPU(1 の値は、1 コアが 100% ビジー状態になることを意味します)。
  • Critical Path: クリティカル パス上のアクションごとに 1 つのブロックを表示します。
  • Main Thread: Bazel のメインスレッド。クラウド リソースの概要を把握するのに役立つ 「Launch Blaze」、「evaluateTargetPatterns」など、Bazel が行っている処理 "runAnalysisPhase" を作成します。
  • Garbage Collector: マイナーとメジャーのガベージ コレクション(GC)を表示します。 一時停止します。

パフォーマンスに関する一般的な問題

パフォーマンス プロファイルを分析する際は、以下のことに注目してください。

  • 特に次の分析フェーズで想定よりも遅い(runAnalysisPhase) 使用できます。ルールが不適切な方法で実装されている場合 Depset をフラット化します。パッケージの読み込みは、 過剰な数のターゲット、複雑なマクロ、または再帰的 glob の使用は避けます。
  • 個々のスロー・アクション、特にクリティカル・パス上のアクション。たぶん 大きなアクションを複数の小さなアクションに分割したり、 (一時的な)依存関係のセットを使用して、それらの依存関係を高速化します。また、 PROCESS_TIME 以外の高値(REMOTE_SETUPFETCH など)。
  • ボトルネック。これは、少数のスレッドがビジー状態であり、他のスレッドが 結果を待機している状態になります(図 1 の 22 秒と 29 秒前後を参照)。 これを最適化するには、多くの場合、ルールの実装に少し手を加える必要がある または Bazel 自体を使用することで、並列処理を増やすことができます。これは次の場合にも発生する可能性があります。 異常量の GC があります。

プロファイルのファイル形式

最上位オブジェクトには、メタデータ(otherData)と実際のトレースデータが含まれます。 (traceEvents)。メタデータには、呼び出し ID などの追加情報が含まれる Bazel の呼び出し日が含まれます

例:

{
  "otherData": {
    "build_id": "101bff9a-7243-4c1a-8503-9dc6ae4c3b05",
    "date": "Wed Oct 26 08:22:35 CEST 2022",
    "profile_finish_ts": "1677666095162000",
    "output_base": "/usr/local/google/_bazel_johndoe/573d4be77eaa72b91a3dfaa497bf8cd0"
  },
  "traceEvents": [
    {"name":"thread_name","ph":"M","pid":1,"tid":0,"args":{"name":"Critical Path"}},
    ...
    {"cat":"build phase marker","name":"Launch Blaze","ph":"X","ts":-1306000,"dur":1306000,"pid":1,"tid":21},
    ...
    {"cat":"package creation","name":"foo","ph":"X","ts":2685358,"dur":784,"pid":1,"tid":246},
    ...
    {"name":"thread_name","ph":"M","pid":1,"tid":11,"args":{"name":"Garbage Collector"}},
    {"cat":"gc notification","name":"minor GC","ph":"X","ts":825986,"dur":11000,"pid":1,"tid":11},
    ...
    {"cat":"action processing","name":"Compiling foo/bar.c","ph":"X","ts":54413389,"dur":357594,"pid":1,"args":{"mnemonic":"CppCompile"},"tid":341},
 ]
}

トレース イベントのタイムスタンプ(ts)と期間(dur)は、 マイクロ秒単位です。カテゴリ(cat)は、ProfilerTask の列挙値の 1 つです。 なお、イベントが非常に短く、 相互に通信しています。パス --noslim_json_profile イベントの統合を禁止するにはどうすればよいでしょうか。

関連ドキュメント: Chrome トレース イベント形式の仕様