Simpleperf 三部曲 (二)

发表于 分类于 阅读次数： 本文字数： 12k 阅读时长 ≈ 22 分钟

本文是对性能分析工具哋它亢 Simpleperf 使用文档总结, 也可以看作是文档翻译.

本篇原文见 Executable commands reference.

Simpleperf 是如何工作的

现代 CPU 有一个名为性能监控单元 (PMU) 的硬件组件. PMU有几个硬件计数器, 用于计数诸如发生了多少CPU周期, 执行了多少指令或发生了多少缓存未命中等事件.

Linux 内核将这些硬件计数器封装成硬件性能事件. 此外, Linux 内核还提供与硬件无关的软件事件和跟踪点事件. Linux 内核通过 perf_event_open 系统调用将所有事件暴露给用户空间, 这个调用被 simpleperf 使用.

Simpleperf 有三个主要命令: stat, record 和 report.

stat 命令总结在一段时间内被分析的进程中发生的事件数量. 其工作原理如下:

  • 根据用户选项, simpleperf 通过对内核进行系统调用来启用分析.
  • 在分析的进程运行时, 内核启用计数器.
  • 分析结束后, simpleperf 从内核读取计数器, 并报告计数器摘要.

record 命令在一段时间内记录被分析进程的样本. 其工作原理如下:

  • 根据用户选项, simpleperf 通过对内核进行系统调用来启用分析.
  • Simpleperf 在 simpleperf 和内核之间创建映射缓冲区.
  • 在分析的进程运行时, 内核启用计数器.
  • 每当发生一定数量的事件时, 内核将样本转储到映射缓冲区.
  • Simpleperf 从映射缓冲区读取样本, 并将分析数据存储在名为perf.data的文件中.

report 命令读取 perf.data 文件和任何被分析进程使用的共享库, 并输出显示时间花费在哪些地方的报告.

Simpleperf 支持以下几个命令:

  • debug-unwind 命令: 调试/测试基于 DWARF 的离线展开, 用于调试 simpleperf.
  • dump 命令: 转储 perf.data 中的内容, 用于调试 simpleperf.
  • help 命令: 打印其他命令的帮助信息.
  • kmem 命令: 收集内核内存分配信息 (将被Python脚本替代) .
  • list 命令: 列出 Android 设备上支持的所有事件类型.
  • record 命令: 分析进程并将分析数据存储在 perf.data 中.
  • report 命令: 报告 perf.data 中的分析数据.
  • report-sample 命令: 报告 perf.data 中的每个样本, 用于支持 simpleperf 在 Android Studio 中的集成.
  • stat 命令: 分析进程并打印计数器摘要.

每个命令支持不同的选项, 可以通过帮助信息查看.

1
2
3
4
5
# 列出所有命令. 
$ simpleperf --help

# 打印 record 命令的帮助信息. 
$ simpleperf record --help

以下描述了最常用的命令, 分别是 list, stat, record 和 report.

list

这个命令列出了设备上所有可用的事件列表. 不同的设备可能支持不同的事件, 因为它们具有不同的硬件和内核.

1
2
3
4
5
6
7
8
9
10
11
12
$ simpleperf list
List of hw-cache events:
  branch-loads
  ...
List of hardware events:
  cpu-cycles
  instructions
  ...
List of software events:
  cpu-clock
  task-clock
  ...

在 ARM/ARM64 架构上, list 命令还显示了一组原始事件列表, 这些事件是设备上 ARM 性能监视器单元 (PMU) 支持的事件. 内核已经将其中的一部分包装成了硬件事件和硬件缓存事件. 例如, raw-cpu-cycles 被包装成了 cpu-cycles, raw-instruction-retired 被包装成了instructions. 原始事件的提供是为了在我们希望使用设备上支持的某些事件时, 但不幸的是内核没有将其包装成硬件事件时使用.

stat

stat 命令用于获取被分析进程的事件计数器值. 通过传递选项, 我们可以选择使用哪些事件, 监控哪些进程/线程, 监控多长时间以及打印间隔.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
# Stat using default events (cpu-cycles,instructions,...), and monitor process 7394 for 10 seconds.
$ simpleperf stat -p 7394 --duration 10
Performance counter statistics:

#         count  event_name                # count / runtime
     16,513,564  cpu-cycles                # 1.612904 GHz
      4,564,133  stalled-cycles-frontend   # 341.490 M/sec
      6,520,383  stalled-cycles-backend    # 591.666 M/sec
      4,900,403  instructions              # 612.859 M/sec
         47,821  branch-misses             # 6.085 M/sec
  25.274251(ms)  task-clock                # 0.002520 cpus used
              4  context-switches          # 158.264 /sec
            466  page-faults               # 18.438 K/sec

Total test time: 10.027923 seconds.

选择要统计的事件

我们可以通过 -e 选项选择要使用的事件 (event).

1
2
3
4
5
# Stat event cpu-cycles.
$ simpleperf stat -e cpu-cycles -p 11904 --duration 10

# Stat event cache-references and cache-misses.
$ simpleperf stat -e cache-references,cache-misses -p 11904 --duration 10

当运行 stat 命令时, 如果硬件事件的数量大于 PMU 可用的硬件计数器数量, 内核会在事件之间共享硬件计数器, 因此每个事件仅在总时间的一部分被监控. 结果, 显示的事件数量小于实际发生的事件数量. 以下是一个示例.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
# Stat using event cache-references, cache-references:u,....
$ simpleperf stat -p 7394 -e cache-references,cache-references:u,cache-references:k \
      -e cache-misses,cache-misses:u,cache-misses:k,instructions --duration 1
Performance counter statistics:

#   count  event_name           # count / runtime
  490,713  cache-references     # 151.682 M/sec
  899,652  cache-references:u   # 130.152 M/sec
  855,218  cache-references:k   # 111.356 M/sec
   61,602  cache-misses         # 7.710 M/sec
   33,282  cache-misses:u       # 5.050 M/sec
   11,662  cache-misses:k       # 4.478 M/sec
        0  instructions         #

Total test time: 1.000867 seconds.
simpleperf W cmd_stat.cpp:946] It seems the number of hardware events are more than the number of
available CPU PMU hardware counters. That will trigger hardware counter
multiplexing. As a result, events are not counted all the time processes
running, and event counts are smaller than what really happens.
Use --print-hw-counter to show available hardware counters.

在上述示例中, 我们监控了 7 个事件. 每个事件仅在总时间的一部分被监控. 因为 cache-references 的数量小于 cache-references:u (仅在用户空间的 cache-references) 和 cache-references:k (仅在内核中的 cache-references) . 指令数为零. 在打印结果后, simpleperf 会检查 CPU 是否有足够的硬件计数器来同时计数硬件事件. 如果没有, 它会打印一个警告.

为了避免硬件计数器复用, 我们可以使用 simpleperf stat --print-hw-counter 来显示每个 CPU 上的可用计数器. 然后不要监控比可用计数器更多的硬件事件.

1
2
3
4
5
6
7
8
9
$ simpleperf stat --print-hw-counter
There are 2 CPU PMU hardware counters available on cpu 0.
There are 2 CPU PMU hardware counters available on cpu 1.
There are 2 CPU PMU hardware counters available on cpu 2.
There are 2 CPU PMU hardware counters available on cpu 3.
There are 2 CPU PMU hardware counters available on cpu 4.
There are 2 CPU PMU hardware counters available on cpu 5.
There are 2 CPU PMU hardware counters available on cpu 6.
There are 2 CPU PMU hardware counters available on cpu 7.

当发生计数器复用时, 无法保证哪些事件在何时被监控. 如果我们希望确保某些事件始终同时被监控, 我们可以使用 --group 选项.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
# Stat using event cache-references, cache-references:u,....
$ simpleperf stat -p 7964 --group cache-references,cache-misses \
      --group cache-references:u,cache-misses:u --group cache-references:k,cache-misses:k \
      --duration 1
Performance counter statistics:

#     count  event_name           # count / runtime
  2,088,463  cache-references     # 181.360 M/sec
     47,871  cache-misses         # 2.292164% miss rate
  1,277,600  cache-references:u   # 136.419 M/sec
     25,977  cache-misses:u       # 2.033265% miss rate
    326,305  cache-references:k   # 74.724 M/sec
     13,596  cache-misses:k       # 4.166654% miss rate

Total test time: 1.029729 seconds.
simpleperf W cmd_stat.cpp:946] It seems the number of hardware events are more than the number of
...

选择要统计的目标

我们可以通过 -p 或-t 选项选择要监控的进程或线程. 监控一个进程相当于监控该进程中的所有线程. Simpleperf 还可以派生一个子进程来运行新命令, 然后监控该子进程.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
# 统计进程 11904 和 11905.
$ simpleperf stat -p 11904,11905 --duration 10

# 统计名字里包含 "chrome" 的进程.
$ simpleperf stat -p chrome --duration 10

# 正则表达式统计进程名.
$ simpleperf stat -p "chrome:(privileged|sandboxed)" --duration 10

# 统计线程 11904 和 11905.
$ simpleperf stat -t 11904,11905 --duration 10

# 开启子进程 ls 并进行统计.
$ simpleperf stat ls

# 统计安卓应用, 在非 root 设备上, 只能统计 debuggable
# 或者 profileable from shell 的应用.
$ simpleperf stat --app simpleperf.example.cpp --duration 10

# 仅统计应用的某个线程.
$ simpleperf stat --app simpleperf.example.cpp -t 11904 --duration 10

# 使用 -a 进行系统范围的统计.
$ simpleperf stat -a --duration 10

决定统计的时长

在监控现有线程时, 我们可以使用 --duration 选项来决定监控的时长. 在监控运行新命令的子进程时, simpleperf 会一直监控直到子进程结束. 在这种情况下, 我们可以随时使用 Ctrl-C 来停止监控.

1
2
3
4
5
6
7
8
9
# Stat process 11904 for 10 seconds.
$ simpleperf stat -p 11904 --duration 10

# Stat until the child process running `ls` finishes.
$ simpleperf stat ls

# Stop monitoring using Ctrl-C.
$ simpleperf stat -p 11904 --duration 10
^C

如果您希望编写脚本来控制监控时长, 可以向 simpleperf 发送 SIGINT, SIGTERM 或 SIGHUP 信号来停止监控.

更多内容见 The stat command.

record

record 命令用于转储被分析进程的样本. 每个样本可以包含生成样本的时间, 自上次样本以来的事件数量, 线程的程序计数器, 线程的调用链等信息.

通过传递选项, 我们可以选择使用哪些事件, 监控哪些进程/线程, 转储样本的频率, 监控多长时间, 以及存储样本的位置.

1
2
3
4
5
# Record on process 7394 for 10 seconds, using default event (cpu-cycles), 
# using default sample frequency (4000 samples per second),
# writing records to perf.data.
$ simpleperf record -p 7394 --duration 10
simpleperf I cmd_record.cpp:316] Samples recorded: 21430. Samples lost: 0.

选择要记录的事件

默认情况下, 使用 cpu-cycles 事件来评估消耗的 CPU 周期. 但我们也可以通过 -e 选项使用其他事件.

1
2
3
4
5
# Record using event instructions.
$ simpleperf record -e instructions -p 11904 --duration 10

# Record using task-clock, which shows the passed CPU time in nanoseconds.
$ simpleperf record -e task-clock -p 11904 --duration 10

选择要记录的目标

record 命令中选择目标的方式类似于 stat 命令.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
# Record process 11904 and 11905.
$ simpleperf record -p 11904,11905 --duration 10

# Record processes with name containing "chrome".
$ simpleperf record -p chrome --duration 10
# Record processes with name containing part matching regex "chrome:(privileged|sandboxed)".
$ simpleperf record -p "chrome:(privileged|sandboxed)" --duration 10

# Record thread 11904 and 11905.
$ simpleperf record -t 11904,11905 --duration 10

# Record a child process running `ls`.
$ simpleperf record ls

# Record the process of an Android application. On non-root devices, this only works for debuggable
# or profileable from shell apps.
$ simpleperf record --app simpleperf.example.cpp --duration 10

# Record only selected thread 11904 in an app.
$ simpleperf record --app simpleperf.example.cpp -t 11904 --duration 10

# Record system wide.
$ simpleperf record -a --duration 10

设置记录频率

我们可以通过 -f 或 -c 选项设置转储记录的频率. 例如, -f 4000 表示在监控的线程运行时, 每秒钟大约转储 4000 条记录. 如果一个监控的线程在一秒钟内运行了 0.2 秒 (在其他时间它可能被抢占或阻塞) , simpleperf 每秒钟大约转储 4000 * 0.2 / 1.0 = 800 条记录. 另一种方式是使用 -c. 例如, -c 10000 表示每当发生 10000 个事件时转储一条记录.

1
2
3
4
5
# 使用采样频率 1000 进行记录: 每秒运行采样 1000 次. 
$ simpleperf record -f 1000 -p 11904,11905 --duration 10

# 使用采样周期 100000 进行记录: 每 100000 个事件采样一次. 
$ simpleperf record -c 100000 -t 11904,11905 --duration 10

为了避免生成样本花费过多时间, kernel >= 3.10 设置了用于生成样本的最大 CPU 时间百分比 (默认是 25%) , 并在达到该限制时降低允许的最大采样频率. simpleperf 使用 --cpu-percent 选项来调整它, 但这需要 root 权限或运行 Android >= Q.

1
2
# 使用采样频率 10000 进行记录, 允许的最大 CPU 使用率为 50%. 
$ simpleperf record -f 1000 -p 11904,11905 --duration 10 --cpu-percent 50

决定记录的时长

与 stat 类似, 也可以通过 --duration 来控制记录时长.

设置存储分析数据的路径

默认情况下, simpleperf 将分析数据存储在当前目录的 perf.data 文件中. 但可以使用 -o 选项更改存储路径.

1
2
# Write records to data/perf2.data.
$ simpleperf record -p 11904 -o data/perf2.data --duration 10

记录调用图

调用图是显示函数调用关系的树结构. 以下是一个示例.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
main() {
    FunctionOne();
    FunctionTwo();
}
FunctionOne() {
    FunctionTwo();
    FunctionThree();
}
a call graph:
    main-> FunctionOne
       |    |
       |    |-> FunctionTwo
       |    |-> FunctionThree
       |
       |-> FunctionTwo

调用图显示了一个函数如何调用其他函数, 反向调用图则显示一个函数如何被其他函数调用. 要显示调用图, 我们首先需要记录它, 然后再报告它.

有两种记录调用图的方法, 一种是记录基于 dwarf 的调用图, 另一种是记录基于栈帧的调用图. 记录基于 dwarf 的调用图需要本地二进制文件中的调试信息支持. 而记录基于栈帧的调用图则需要栈帧寄存器的支持.

1
2
3
4
5
# 记录基于 dwarf 的调用图
$ simpleperf record -p 11904 -g --duration 10

# 记录基于栈帧的调用图
$ simpleperf record -p 11904 --call-graph fp --duration 10

记录 CPU 时间和非 CPU 时间

Simpleperf 是一个 CPU 分析器, 它只在线程运行在 CPU 上时生成样本. 但有时我们想知道线程在 CPU 外的时间是如何花费的 (例如, 被其他线程抢占, 在 IO 中阻塞或等待某些事件) . 为支持这一点, simpleperf 在 record 命令中添加了 --trace-offcpu 选项. 当使用 --trace-offcpu 时, simpleperf 会执行以下操作:

  1. 仅允许 cpu-clock``/task-clock 事件与 --trace-offcpu 一起使用, 这使得 simpleperf 为 cpu-clock 事件生成 on-cpu 样本.
  2. Simpleperf 还监控 sched:sched_switch 事件, 每次监控的线程从 CPU 上调度时会生成一个 sched_switch 样本.
  3. Simpleperf 还记录上下文切换记录, 因此它知道线程何时被调度回 CPU.

simpleperf 为线程收集的样本和上下文切换记录如下所示:

simpleperf_trace_offcpu_sample_mode

这里有两种类型的样本:

  1. 为 cpu-clock 事件生成的 on-cpu 样本. 每个样本中的周期值表示在 CPU 上花费了多少纳秒 (针对该样本的调用链) .
  2. 为 sched:sched_switch 事件生成的 off-cpu (sched_switch) 样本. 周期值由 simpleperf 计算为下一个 switch on 记录的时间戳减去当前样本的时间戳. 因此, 每个样本中的周期值表示在 CPU 外花费了多少纳秒 (针对该样本的调用链) .

注意: 实际上, switch on 记录和样本可能会丢失. 为了减轻精度损失, 我们计算一个 off-cpu 样本的周期为下一个 switch on 记录或样本的时间戳减去当前样本的时间戳.

通过 Python 脚本报告时, simpleperf_report_lib.py 提供 SetTraceOffCpuMode() 方法来控制如何报告样本:

  1. on-cpu 模式: 仅报告 on-cpu 样本.
  2. off-cpu 模式: 仅报告 off-cpu 样本.
  3. on-off-cpu 模式: 报告 on-cpu 和 off-cpu 样本, 可以按事件名称分开.
  4. mixed-on-off-cpu 模式: 在相同事件名称下报告 on-cpu 和 off-cpu 样本.

如果未设置, 将使用 mixed-on-off-cpu 模式进行报告.

使用 report_html.py, inferno 和 report_sample.py 时, 可以通过 --trace-offcpu 选项设置报告模式.

以下是一些记录和报告 trace offcpu 配置文件的示例.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
# Check if --trace-offcpu is supported by the kernel (should be available on kernel >= 4.2).
$ simpleperf list --show-features
trace-offcpu
...

# Record with --trace-offcpu.
$ simpleperf record -g -p 11904 --duration 10 --trace-offcpu -e cpu-clock

# Record system wide with --trace-offcpu.
$ simpleperf record -a -g --duration 3 --trace-offcpu -e cpu-clock

# Record with --trace-offcpu using app_profiler.py.
$ ./app_profiler.py -p com.google.samples.apps.sunflower \
    -r "-g -e cpu-clock:u --duration 10 --trace-offcpu"

# Report on-cpu samples.
$ ./report_html.py --trace-offcpu on-cpu
# Report off-cpu samples.
$ ./report_html.py --trace-offcpu off-cpu
# Report on-cpu and off-cpu samples under different event names.
$ ./report_html.py --trace-offcpu on-off-cpu
# Report on-cpu and off-cpu samples under the same event name.
$ ./report_html.py --trace-offcpu mixed-on-off-cpu

report

report 命令用于报告由 record 命令生成的分析数据. 报告包含一个样本条目表, 每个样本条目是报告中的一行. report 命令将属于同一进程, 线程, 库, 函数的样本分组到同一个样本条目中. 然后根据样本条目的事件计数对样本条目进行排序.

通过传递选项, 我们可以决定如何过滤掉不感兴趣的样本, 如何将样本分组到样本条目中, 以及在哪里查找分析数据和二进制文件.

下面是一个示例. 记录被分组为 4 个样本条目, 每个条目是一行. 有几列, 每列显示属于样本条目的一部分信息. 第一列是 Overhead, 显示当前样本条目中事件占总事件的百分比. 由于 perf 事件是 cpu-cycles, overhead 是每个函数使用的 CPU 周期的百分比.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
# Reports perf.data, using only records sampled in libsudo-game-jni.so, grouping records using
# thread name(comm), process id(pid), thread id(tid), function name(symbol), and showing sample
# count for each row.
$ simpleperf report --dsos /data/app/com.example.sudogame-2/lib/arm64/libsudo-game-jni.so \
      --sort comm,pid,tid,symbol -n
Cmdline: /data/data/com.example.sudogame/simpleperf record -p 7394 --duration 10
Arch: arm64
Event: cpu-cycles (type 0, config 0)
Samples: 28235
Event count: 546356211

Overhead  Sample  Command    Pid   Tid   Symbol
59.25%    16680   sudogame  7394  7394  checkValid(Board const&, int, int)
20.42%    5620    sudogame  7394  7394  canFindSolution_r(Board&, int, int)
13.82%    4088    sudogame  7394  7394  randomBlock_r(Board&, int, int, int, int, int)
6.24%     1756    sudogame  7394  7394  @plt

设置读取分析数据的路径

默认情况下, report 命令从当前目录的 perf.data 文件中读取分析数据. 但可以使用 -i 选项更改读取路径.

1
simpleperf report -i data/perf2.data

设置查找二进制文件的路径

为了报告函数符号, simpleperf 需要读取被监控进程使用的可执行二进制文件以获取符号表和调试信息. 默认情况下, 路径是记录时被监控进程使用的可执行二进制文件. 然而, 这些二进制文件在报告时可能不存在或不包含符号表和调试信息. 因此, 我们可以使用 --symfs 选项重定向路径.

1
2
3
4
5
6
7
8
9
10
# In this case, when simpleperf wants to read executable binary /A/b, it reads file in /A/b.
$ simpleperf report

# In this case, when simpleperf wants to read executable binary /A/b, it prefers file in
# /debug_dir/A/b to file in /A/b.
$ simpleperf report --symfs /debug_dir

# Read symbols for system libraries built locally. Note that this is not needed since Android O,
# which ships symbols for system libraries on device.
$ simpleperf report --symfs $ANDROID_PRODUCT_OUT/symbols

报告调用图

要报告调用图, 请确保分析数据是带有调用图记录的, 如 Record call graphs 所示.

更多详细内容见 The record command.