JSON 追蹤設定檔非常實用,可快速瞭解 Bazel 在叫用期間花費的時間。
根據預設,對於所有類似建構的指令和查詢,Bazel 會將這類設定檔寫入 command.profile.gz
。您可以設定是否要使用 --generate_json_trace_profile
標記寫入設定檔,以及使用 --profile
標記寫入的位置。結尾為 .gz
的位置會使用 GZIP 壓縮。使用 --experimental_announce_profile_path
旗標,將此檔案的路徑列印到記錄中。
工具
您可以將這個設定檔載入 chrome://tracing
,或使用其他工具分析及後處理。
chrome://tracing
如要將設定檔視覺化,請在 Chrome 瀏覽器分頁中開啟 chrome://tracing
,按一下「Load」,然後選取 (可能已壓縮) 的設定檔。如要查看更詳細的結果,請按一下左下角的方塊。
設定檔範例:
圖 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 執行緒及其對應事件,但也包含一些特殊資料列。
所包含的特殊列取決於建立設定檔時所叫用的 Bazel 版本,並可透過不同的標記進行自訂。
圖 1 顯示使用 Bazel 5.3.1 版建立的設定檔,其中包含以下列:
action count
:顯示同時執行的動作數量。按一下即可查看實際值。應為清除建構中--jobs
的值。CPU usage (Bazel)
:針對每秒的建構作業,顯示 Bazel 使用的 CPU 數量 (值為 1 等於一個核心的使用率為 100%)。Critical Path
:針對關鍵路徑上的每個動作顯示一個區塊。Main Thread
:Bazel 的主要執行緒。可用於取得 Bazel 執行作業的概略圖,例如「Launch Blaze」、「evaluateTargetPatterns」和「runAnalysisPhase」。Garbage Collector
:顯示次要和主要垃圾收集 (GC) 暫停。
常見效能問題
分析效能設定檔時,請留意以下事項:
- 分析階段 (
runAnalysisPhase
) 的速度比預期慢,尤其是在增量建構作業中。這可能是實作規則不佳的徵兆,例如會將 depset 扁平化。目標過多、巨集複雜或迴圈 glob 會導致套件載入速度變慢。 - 個別緩慢動作,尤其是在重要路徑上的動作。您可以將大型動作拆分成多個較小的動作,或是減少 (傳遞) 依附元件組合,以便加快動作速度。另外,請檢查是否有異常高的非
PROCESS_TIME
(例如REMOTE_SETUP
或FETCH
)。 - 瓶頸:少數執行緒忙碌時,其他執行緒處於閒置 / 等待結果的狀態 (請參閱圖 1 中 22 秒和 29 秒處)。如要進行最佳化,您很可能需要調整規則實作或 Bazel 本身,以便引入更多平行作業。當垃圾收集次數異常時,也可能會發生這種情況。
設定檔檔案格式
頂層物件包含中繼資料 (otherData
) 和實際的追蹤資料 (traceEvents
)。中繼資料包含額外資訊,例如 Bazel 叫用 ID 和叫用日期。
範例:
{
"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 追蹤記錄事件格式規格。