CPU 火焰图

Jan 23, 2020 22:00 · 1067 words · 3 minute read CPU Performance Debug

定位 CPU 在忙啥是性能分析的常规操作，通常涉及对堆与栈的追踪。以固定的速率采样是一种简单粗暴但行之有效的方法，来查看哪些函数（代码路径）正在频繁执行。一般通过创建定时中断来收集当前程序计数器、函数地址或回溯整个堆栈，并将其转换为我们能读懂的摘要。

分析数据可能长达数千行，而且晦涩难懂。**火焰图**就是堆栈回溯的可视化实现，可以用来快速准确地定位频繁执行的函数。

火焰图可以用于任意 CPU 任意操作系统。这里我用 Linux perf_events 来采样随手写的死循环 Python 脚本。

while True:
    print("day by day")

perf record 命令以 99 Hz 的采样率（-F）对 PID 为 13514 的目标进程（-p）记录（-g）调用栈 30 秒：

$ perf record -F 99 -p 13514 -g -- sleep 30

perf record 命令很好地将几百个堆栈回溯样本汇总为文本，合并了相似的代码路径，输出也给你安排成了树状结构，每片叶子上也都有百分比。从左上角到右下角，遵循了调用的路径（也就是堆栈追踪）。必须将从左乘到右才能算出整个堆栈的绝对百分比。

我抓的调用路径有点深而且都是匿名函数（显示为内存地址）。。。我们拿别人抓的算一下：

第一个堆栈回溯显示 do_redirection_internal() 函数占据了 20.42% * 44.13% * 35.58% * 65.26% ≈ 2%；下一个堆栈回溯显示 execute_builtin_or_function() 函数 20.42% * 44.13% * 35.58% * 34.74% * 54.55% ≈ 1%。

但是！数据太多了！

上面的输出已经是分页后的，总共有好几千行。完整的输出看起来是这样的：

火焰图

所有的数据都被整合在一张图中了。

每个块代表栈中的一个函数
Y 轴表示调用栈深度，最顶层表示当前 CPU 正在执行的函数，下面都是它的父函数。调用越深，火焰就越高。
X 轴表示抽样数。不像大多数图表示时间流，从左到右的顺序没有意义。
块的宽度表示它占用 CPU 的时间，越宽消耗越多的 CPU 时钟，或被更频繁地调用。**“平顶”**的函数可能存在性能问题。
颜色也没有意义，随机选择暖色调。

直接观察“平顶”往往不能快速定位性能问题，因为顶部很有可能是对底层库函数的调用。要快速定位性能问题，首先应该观察的是业务函数在火焰图中的宽度。

我们使用 Brendan Gregg （前 Sun 工程师，火焰图布道者）编写并开源的火焰图工具。

$ git clone https://github.com/brendangregg/FlameGraph
$ cd FlameGraph

简单来说就是三步走：

采样（多种采样工具）
折叠
flamegraph.pl

perf

$ perf record -F 99 -a -g -- sleep 60
$ perf script | ./stackcollapse-perf.pl > out.perf-folded
$ ./flamegraph.pl out.perf-folded > perf-kernel.svg

还可以利用同一份采样数据创建出多份火焰图，这里过滤出对系统读写函数的调用：

$ perf script | ./stackcollapse-perf.pl > out.perf-folded
$ grep -v cpu_idle out.perf-folded | ./flamegraph.pl > nonidle.svg
$ grep ext4 out.perf-folded | ./flamegraph.pl > ext4internals.svg
$ egrep 'system_call.*sys_(read|write)' out.perf-folded | ./flamegraph.pl > rw.svg

DTrace

DTrace 是更牛逼的动态追踪工具。

这里对 mysqld 进程采样用户级堆栈：

$ dtrace -x ustackframes=100 -n 'profile-99 /execname == "mysqld" && arg1/ {
    @[ustack()] = count(); } tick-60s { exit(0); }' -o out.stacks
$ ./stackcollapse.pl out.stacks > out.folded
$ ./flamegraph.pl out.folded > out.svg

SystemTap

SystemTap 能够通过 timer.profile 探针来采样堆栈，以系统时钟频率触发。

$ stap -s 32 -D MAXBACKTRACE=100 -D MAXSTRINGLEN=4096 -D MAXMAPENTRIES=10240 \
    -D MAXACTION=10000 -D STP_OVERLOAD_THRESHOLD=5000000000 --all-modules \
    -ve 'global s; probe timer.profile { s[backtrace()] <<< 1; }
    probe end { foreach (i in s+) { print_stack(i);
    printf("\t%d\n", @count(s[i])); } } probe timer.s(60) { exit(); }' \
    > out.stap-stacks
$ ./stackcollapse-stap.pl out.stap-stacks > out.stap-folded
$ cat out.stap-folded | ./flamegraph.pl > stap-kernel.svg

火焰图

perf

DTrace

SystemTap

查看更多