Profiling with Perf

有一个很好的参考资料 perfwiki。

perfwiki 的组织方式是从 perf 的实现原理出发，先讲 perf 提供了什么手段，再举例子讲能用来干什么。即先讲 perf profiling 过程中最重要的对象 event，然后 perf stat 就是执行程序前后 event 数量之差，perf record 就是执行程序过程中事件每发生固定次数就采集一个样本。这个角度 perfwiki 做得很好了，本文尝试换一个角度组织，先讲有哪些 profiling 任务，再讲用户可能希望一个 profiling 工具提供哪些功能，最后映射到 perf 的实现上。理论上这种结构可以落实到多种 profiler 实现上，但我其实没用过其他 profiler（挖坑）

识别性能瓶颈

最经典的任务是将 CPU 执行的时间按“CPU在执行哪个函数”进行划分，然后查看哪些函数用时最长，然后着力优化这些函数。实际上还有其他类型的性能瓶颈，例如 Top-down 将 CPU uop-slot 按“等前端、等后端、执行错误的分支、正常执行”进行划分，或者有些性能瓶颈是多核间在等锁，CPU 大部分时间其实在等锁，但我们看到 “CPU 在等待”这个信息其实没啥价值，等等。

最直觉的做法是进出函数时都打印带时间戳的日志，然后分析日志来统计每个函数的执行时间。这种做法有其优势：日志内容运行时可控，例如可以记录下函数参数和返回值，这些日志可以同时用于 debug。但显著的问题有两点：

需要主动知道哪些函数是潜在的热点需要被记录，然后手动为他们写日志语句；或者需要一个额外工具来自动为所有函数插入这种日志；更进一步，这两点在没有源码时都不现实；
当函数调用次数过多时，记录这些日志本身可能会成为性能瓶颈，因为这涉及格式化、与硬盘交互等等；

幸运的是，有一个非常聪明的思路同时解决了这两个问题，就是把“CPU在执行哪个函数”看作一个概率分布，然后对他进行采样。只要采样频率足够，就能足够逼近原始分布。并且，如果一个地方是性能瓶颈，他在原始分布中应该占比很高，所以不用担心采样过程中漏掉它。

实现这种采样有两个要点。（1）实现固定间隔发起采样事件，这在 perf 里用 perf record 实现。这个命令做的就是固定间隔采样。这里的间隔具体的定义是 event 数量间隔，当事件为 cycles 时，固定 event 数量间隔就对应于固定执行时间。-F 参数可以指定采样频率，-a 参数指定对所有 CPU 采样，-C 参数指定了要采样的 CPU 列表。（2）每个样本内需要记录 CPU 在执行哪个函数，更好的情况是知道当前调用栈。-g 参数就告诉 perf record 记录下调用栈，这里记录的只是每层调用栈的返回地址（挖坑：调用栈的栈帧，以及这里记的是不是返回地址），把它翻译成函数符号是后续工作。这个命令对整个 CPU 采样，所以可能会采到其他进程。可以直接把执行其他进程的样本剃除，或者给 perf record 加上 -p 参数，考虑到 perf record 的意义是对概率分布进行采样，这么操作没什么问题。

perfwiki 中指出，现代 CPU 的实现方式导致采集到的样本的指令位置可能并不精准地是 event 数量间隔到达的那一刻，会有偏移（skid）。当事件为 cycles 时这不是太大的问题，但事件是 cache-miss 等时就要注意精确的样本位置不能用来参考。

perf record 采集到的样本内容是二进制的，用 perf script 处理后长下面的样子：（TODO: 换一个简单的程序，不要用cpu-clock）

zebra 2228528 [007] 196350.576148:   10101010 cpu-clock: 
            72be3b6fa59f __libc_calloc+0x7f (/usr/lib/x86_64-linux-gnu/libc.so.6)
            72be3bacf581 listnode_add+0x61 (/usr/lib/libfrr.so.0.0.0)
            5ebb25f4c736 rib_meta_queue_early_route_add+0x16 (/usr/lib/frr/zebra)
            5ebb25f10345 zread_route_add+0x1a5 (/usr/lib/frr/zebra)
            5ebb25f14046 zserv_handle_commands+0x116 (/usr/lib/frr/zebra)
            5ebb25f83780 zserv_process_messages+0x100 (/usr/lib/frr/zebra)
            72be3bb25854 event_call+0x84 (/usr/lib/libfrr.so.0.0.0)
            72be3bacec78 frr_run+0xc8 (/usr/lib/libfrr.so.0.0.0)
            5ebb25ee3bc6 main+0x3e6 (/usr/lib/frr/zebra)
            72be3b67dd90 __libc_start_call_main+0x80 (/usr/lib/x86_64-linux-gnu/libc.so.6)

bgpd 2225676 [006] 196350.576150:   10101010 cpu-clock: 
            75d5018c01dd __tls_get_addr+0xd (/usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2)
            75d501851d68 socket+0x4ee (/usr/lib/libpreload.so)
            75d501851efe socket+0x684 (/usr/lib/libpreload.so)
            75d501710ec2 event_fetch+0x322 (/usr/lib/libfrr.so.0.0.0)
            75d5016bac83 frr_run+0xd3 (/usr/lib/libfrr.so.0.0.0)
            574331820f53 main+0x393 (/usr/lib/frr/bgpd)
            75d5012bad90 __libc_start_call_main+0x80 (/usr/lib/x86_64-linux-gnu/libc.so.6)
...

采到样本之后展示性能瓶颈有几种方式，我最喜欢的是火焰图（flamegraph）。这个项目画火焰图的方法很直白。首先获得调用栈，对上面的输出做简单的文字处理就能得到下面的内容，它按照字典序（而非时间序）排序，并且调用栈相同的样本被合并：

bgpd;__libc_start_call_main;main;frr_run;event_fetch;socket;socket;__tls_get_addr 10101010
zebra;__libc_start_call_main;main;frr_run;event_call;zserv_process_messages;zserv_handle_commands;zread_route_add;rib_meta_queue_early_route_add;listnode_add;__libc_calloc 10101010
...

一般要做 breakdown 的话调用栈就是这样从 main 开始逐渐细化即可。效果如下：

TODO

理解这个图的方式是：第 k 层的宽度代表了 CPU 处在这个函数内的时间比例，第 k+1 层可能有多个被调用的函数，他们之间的关系也就显示了这个函数内部。画这个图的方法就是，如果两个样本第 k 层相同，就把他们在第 k 层连起来。

还有有一种 reversed 火焰图，火焰图最宽的部分是最后被调用的函数，然后它的宽度被分成它的每个 caller 分别占据多少比例。在确定了某个热点函数后，如果这个函数有多个 caller，这个图会很有用。效果如下：

Wilson's blog

识别性能瓶颈