JSON 跟踪配置文件

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

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 v5.3.1 创建的配置文件,其中包含以下行:

  • action count:显示有多少并发操作正在进行中。点击 即可查看实际值。在 全新构建中,该值应达到 --jobs的值。
  • CPU usage (Bazel):对于构建的每一秒,显示 Bazel 使用的 CPU 量(值为 1 表示一个核心 100% 繁忙)。
  • Critical Path:为关键路径上的每个操作显示一个块。
  • Main Thread:Bazel 的主线程。有助于大致了解 Bazel 的运行情况,例如“启动 Blaze”“evaluateTargetPatterns” 和“runAnalysisPhase”。
  • Garbage Collector:显示次要和主要垃圾回收 (GC) 暂停。

常见性能问题

分析性能配置文件时,请注意以下事项:

  • 分析阶段 (runAnalysisPhase) 比预期慢,尤其是在 增量构建中。这可能表明规则实现不佳,例如展平依赖项集。由于目标过多、宏复杂或递归 glob,软件包加载速度可能会很慢。
  • 单个操作缓慢,尤其是关键路径上的操作。您可以将大型操作拆分为多个较小的操作,或减少 (传递)依赖项集以加快操作速度。另请检查是否存在异常高的非PROCESS_TIME(例如REMOTE_SETUPFETCH)。
  • 瓶颈,即少量线程繁忙,而所有其他线程都处于 空闲状态 / 等待结果(请参阅图 1 中大约 22 秒和 29 秒处)。 优化此问题很可能需要修改规则实现 或 Bazel 本身,以引入更多并行性。当 GC 数量异常时,也可能会发生这种情况。

配置文件格式

顶级对象包含元数据 (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_profile

另请参阅 Chrome 跟踪事件格式规范