JSON 追蹤記錄設定檔

回報問題 查看原始碼 夜間 7.2 7.1 7.0 6.5 6.4

如要迅速瞭解 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 即可開啟「縮放」模式。然後拖曳滑鼠來縮放。你可以 您也可以使用 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

jq 和 JSON 資料的 sed 一樣。使用 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 執行緒和相應的事件,但也有一些特殊的資料列。

包含的特殊資料列取決於 設定檔建立,並可以用不同的標記自訂。

圖 1 顯示使用 Bazel v5.3.1 建立的設定檔,當中包含下列資料列:

  • action count:顯示中同時執行的操作數。按一下 即可查看實際值代碼的值應等於 「--jobs」乾淨 建構應用程式
  • CPU usage (Bazel):顯示建構的每秒 Bazel 使用的 CPU (值為 1 等於一個核心處於 100% 忙碌狀態)。
  • Critical Path:針對重要路徑中的每個動作顯示一個區塊。
  • Main Thread:Bazel 的主執行緒。這有助於概略瞭解 Bazel 正在執行什麼動作,例如「Launch Blaze」、「業務評估模式」 和「runAnalysisPhase」
  • Garbage Collector:顯示小型和主要垃圾收集 (GC) 暫停。

常見效能問題

分析成效概況時,請找出:

  • 比預期分析階段 (runAnalysisPhase) 慢,尤其是在 漸進式建構作業這可能表示規則執行不當, 以扁平的解碼器為例系統可能會要求 目標過多、複雜巨集或遞迴 glob。
  • 個別的緩慢動作,尤其是重要路徑上的動作。有可能 可以將大型動作分成多個較小的動作 一組 (遞移) 依附元件來加快其速度。同時檢查是否有異常 高非 PROCESS_TIME (例如 REMOTE_SETUPFETCH)。
  • 瓶頸,只有少量執行緒處於忙碌狀態,其他所有執行緒則仍在處理中 閒置 / 等待結果 (請參閱圖 1 約 22 和 29s)。 要進行最佳化,就可能需要符合規則的導入方式。 或 Bazel 本身,以引入更多平行處理可能發生這種情況 垃圾收集量異常

設定檔檔案格式

頂層物件包含中繼資料 (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 的其中一個列舉值。 請注意,某些事件很短且接近 資源;票證 --noslim_json_profile 如果不想合併事件

另請參閱 Chrome 追蹤事件格式規格