rustc 自我性能分析器介绍

2020年2月25日 · Wesley Wiser 代表 自我性能分析工作组

过去一年多以来,自我性能分析工作组一直在构建用于分析 rustc 性能的工具,因为我们经常听到用户询问编译时间都花在哪里了。这对于优化编译器(编译器团队持续改进编译时间的工作之一)很有帮助,对于想要重构他们的 crate 以使其编译得更快的使用者来说也很有用。我们一直在开发一个新功能来帮助实现这一点,本文提供了其工作原理的预览。不过请注意:它仍然是实验性的,我们预计其接口会随着时间而改变。Rust Unstable Book 中有关于此功能的文档,我们会持续更新该文档,以便您始终在那里找到最新的说明。

在本文中,我们将介绍当前可用的工具,并使用它们在 rustc 编译示例 crate 时对其进行性能分析。

设置

首先,我们将安装来自 measureme 仓库的工具,以分析自我性能分析的跟踪数据。

$ cargo install --git https://github.com/rust-lang/measureme crox flamegraph summarize

现在我们有了工具,接下来下载一个示例 crate 来分析其构建过程。

$ cd ..
$ git clone https://github.com/rust-lang/regex.git
$ cd regex

我们需要使用最新的 nightly 编译器来访问不稳定的 -Z 标志。

$ rustup override set nightly

如果您之前没有安装过 nightly 编译器,这将为您下载。如果您已经安装了,请更新它以确保您使用的是最新版本。

$ rustup update nightly

分析编译器性能

现在我们可以构建它,并告诉 rustc 分析 regex crate 的构建过程。这将在工作目录中创建三个新的文件,其中包含性能分析数据。

$ cargo rustc -- -Zself-profile
$ ls
CHANGELOG.md        LICENSE-APACHE       UNICODE.md              regex-17088.string_data       regex-syntax         target
Cargo.lock          LICENSE-MIT          bench                   regex-17088.string_index      rustfmt.toml         test
Cargo.toml          PERFORMANCE.md       examples                regex-capi                    scripts              tests
HACKING.md          README.md            regex-17088.events      regex-debug                   src

新文件遵循 {crate name}-{rustc process id}.{events,string_data,string_index} 的格式。

我们将使用这三个主要工具来分析性能分析数据

summarize

顾名思义,这个工具会汇总跟踪文件中的数据。此外,summarize 还可以显示两个跟踪文件之间的“差异”,但我们不会使用此模式。

我们运行这个工具,只需传递跟踪文件的文件名(不带扩展名)即可

$ summarize summarize regex-17088
+-----------------------------------------------+-----------+-----------------+----------+------------+
| Item                                          | Self time | % of total time | Time     | Item count |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| LLVM_module_codegen_emit_obj                  | 4.89s     | 42.752          | 4.89s    | 159        |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| codegen_module                                | 1.25s     | 10.967          | 1.37s    | 159        |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| LLVM_module_optimize_module_passes            | 1.15s     | 10.022          | 1.15s    | 159        |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| LLVM_module_codegen_make_bitcode              | 786.56ms  | 6.875           | 960.73ms | 159        |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| typeck_tables_of                              | 565.18ms  | 4.940           | 689.39ms | 848        |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| LLVM_module_codegen                           | 408.01ms  | 3.566           | 6.26s    | 159        |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| mir_borrowck                                  | 224.03ms  | 1.958           | 543.33ms | 848        |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| LLVM_module_codegen_emit_compressed_bitcode   | 174.17ms  | 1.522           | 174.17ms | 159        |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| optimized_mir                                 | 157.91ms  | 1.380           | 205.29ms | 1996       |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| evaluate_obligation                           | 146.50ms  | 1.281           | 184.17ms | 8304       |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| codegen_crate                                 | 139.48ms  | 1.219           | 1.58s    | 1          |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| mir_built                                     | 123.88ms  | 1.083           | 168.01ms | 848        |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| metadata_decode_entry                         | 88.36ms   | 0.772           | 117.77ms | 55642      |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| incr_comp_copy_cgu_workproducts               | 64.21ms   | 0.561           | 64.21ms  | 1          |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| monomorphization_collector_graph_walk         | 54.11ms   | 0.473           | 344.00ms | 1          |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| link_rlib                                     | 43.21ms   | 0.378           | 43.21ms  | 1          |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| check_impl_item_well_formed                   | 41.36ms   | 0.362           | 77.14ms  | 736        |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| codegen_fulfill_obligation                    | 40.36ms   | 0.353           | 51.56ms  | 1759       |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| expand_crate                                  | 37.24ms   | 0.326           | 48.52ms  | 1          |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| symbol_name                                   | 36.31ms   | 0.317           | 39.06ms  | 5513       |
+-----------------------------------------------+-----------+-----------------+----------+------------+
| free_global_ctxt                              | 34.34ms   | 0.300           | 34.34ms  | 1          |
+-----------------------------------------------+-----------+-----------------+----------+------------+
...
Total cpu time: 11.440758871s

输出按 self time(查询或活动本身花费的时间,不包括其调用的其他查询或活动)排序。您可以看到,大部分编译时间都花在 LLVM 上,用于生成可执行文件的二进制代码。

flamegraph

您可能已经猜到了,flamegraph 将生成性能分析数据的火焰图。要运行该工具,我们只需传递不带扩展名的文件名,就像对 summarize 所做的那样。

$ flamegraph regex-17088

这将在工作目录中创建一个名为 rustc.svg 的文件

Image of flamegraph output

点击这里尝试交互式 SVG。

crox

这个工具将自我性能分析数据处理成 Chromium 性能分析器可理解的 JSON 格式。您可以使用它来创建图形化的时间线,精确显示各种跟踪事件发生的时间。

在本节中,我们将介绍 crox 的几种不同运行模式,例如分析整个 crate 编译过程(包括依赖项)以及过滤掉小型事件。让我们从基础开始!

基本用法

要运行该工具,我们只需传递不带文件扩展名的文件名,就像我们之前做的那样

$ crox regex-17088

这将在工作目录中创建一个名为 chrome_profiler.json 的文件。要打开它,我们将使用您可能已经熟悉的常规 Chromium 性能工具。

  1. 打开 Chrome
  2. 按下 Ctrl + Shift + i (Windows/Linux) 或 Cmd + Option + i (macOS) 打开开发者工具控制台
  3. 点击控制台顶部的 Performance(性能)标签页。
  4. 点击看起来像向上箭头的“Load profile”(加载配置文件)按钮。
  5. 选择我们创建的 chrome_profiler.json 文件。

您现在应该会看到类似下面的内容

Image of chrome profiler

您可以使用鼠标滚轮或触摸板上的相应手势来放大或缩小时间线视图。

过滤短时事件

如果 chrome_profiler.json 文件太大,常规的 Chromium 性能工具打开文件可能会有问题。一个简单的解决方法是告诉 crox 移除短于指定时长的事件。

$ crox --minimum-duration 2 regex-17088

过滤掉短于 2 微秒的事件,可以将我们的 chrome_profiler.js 文件从 27MB 缩小到 11MB。

捕获事件参数

自我性能分析器可以配置为在编译期间记录事件参数。例如,查询会包含其查询键。此功能默认关闭,因为它会增加自我性能分析器的开销。

要开启此功能,我们需要记录一次新的编译过程,并向 rustc 传递一个额外的参数

$ cargo clean
$ cargo rustc -- -Zself-profile -Zself-profile-events=default,args

然后处理新的输出文件

$ crox regex-23649

现在在 Chromium 性能分析器中,如果您点击某个节点,可以在屏幕底部看到许多事件的附加数据

Image of Chrome profiler details

这表明 optimized_mir 查询正在处理 regex::compile::{{impl}}::new 函数体。

分析整个 crate 依赖图

通过使用 RUSTFLAGS 环境变量,我们可以对每个 rustc 调用进行性能分析,而不仅仅是最终的 crate。然后 crox 可以将所有性能分析数据合并到一个输出文件中。由于这会创建很多文件,我们将告诉 rustc 创建一个文件夹来存放所有跟踪文件。

$ rm regex-17088.* regex-23649.* # clean up the old trace files since we're done with them
$ cargo clean
$ RUSTFLAGS="-Zself-profile=$(pwd)/profiles -Zself-profile-events=default,args" cargo build

这在工作目录中创建了相当多的跟踪文件。现在,我们将告诉 crox 合并当前目录中的所有跟踪文件。

$ crox --dir profiles

打开这个文件会显示所有编译过的 crate

Image of Chrome profiler with all crates

点击一个 crate 会展开它,显示其中的线程和事件数据。

Image of Chrome profiler with a crate expanded

感谢阅读!

在过去的几个月里,我们自己大量使用了这些工具,它们极大地帮助我们理解编译器将时间花在了哪里。未来我们将增加更多功能,并努力使这些工具更易于使用。如果您有问题或想参与自我性能分析工作组,请查看 measureme 仓库 或访问我们的 Zulip 流