JSON 跟踪记录配置文件对于快速了解 Bazel 所花的费用非常有用 在调用期间有效
默认情况下,对于所有类似构建的命令和查询,Bazel 都会将配置文件写入名为 command-$INOVCATION_ID.profile.gz
的输出基准,其中 $INOVCATION_ID
是命令的调用标识符。Bazel 还会在输出基础目录中创建一个名为 command.profile.gz
的符号链接,指向最新命令的配置文件。您可以配置是否使用
--generate_json_trace_profile
标记以及通过
--profile
标志。以.gz
结尾的地点是
使用 GZIP 压缩。Bazel 默认会在输出基准中保留最近 5 个配置文件(可通过 --profiles_to_retain
进行配置),以便进行构建后分析。显式传递一个
包含 --profile
的配置文件路径会停用自动垃圾回收。
工具
您可以将此配置文件加载到 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
对于 JSON 数据,jq
类似于 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
:显示正在进行的并发操作数量。点击 以查看实际值。在干净 build 中,应不超过--jobs
的值。CPU usage (Bazel)
:在构建的每一秒内,显示 Bazel 使用的 CPU 量(值为 1 表示一个核心处于 100% 繁忙状态)。Critical Path
:针对关键路径上的每个操作显示一个块。Main Thread
:Bazel 的主线程。有助于您简要了解 Bazel 正在执行的操作,例如“Launch Blaze”“assessTargetPatterns”、 和“runAnalysisPhase”Garbage Collector
:显示次要和主要垃圾回收 (GC) 暂停。
常见的性能问题
分析效果概况时,请注意查看以下内容:
- 分析阶段 (
runAnalysisPhase
) 的速度比预期慢,尤其是在增量 build 上。这可能表明规则实施效果不佳, 软件包加载可能会 过多的目标、复杂的宏或递归的 glob。 - 个别缓慢的操作,尤其是关键路径上的操作。它的
将大型操作拆分为多个较小的操作,或减少
一组(传递)依赖项来加快它们的运行速度。此外,请检查非
PROCESS_TIME
是否异常偏高(例如REMOTE_SETUP
或FETCH
)。 - 瓶颈,即少量线程正忙,而其他线程则忙 空闲 / 等待结果(参见图 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
的枚举值之一。
请注意,如果某些事件非常短且彼此相近,系统会将它们合并在一起;如果您想防止事件合并,请传递 --noslim_profile
。
另请参阅 Chrome 跟踪事件格式规范。