CPU Profiling 经验之谈

记录了自己在执行 CPU Profiling 的时候遇到的一些经验。

相关文章:

  1. heap profiling

Profiling 基础

首先,Performance analysis and tuning on modern CPUs 这本书是值得阅读的基础。但是里面讲述的很多内容,我目前还没有机会完全实践。

关于线程池

记录线程名

有一些方法设置线程名,包括:

  1. pthread_setname_np
  2. prctl

出于下列原因,建议线程名具有唯一性:

  1. 诸如一些线程池的实际工作内容不一样,最好以数字区分。
  2. 有一些库会扩展 std::mutex,记录上锁的线程名,用来避免重复加锁。当然这个并不好,最好用线程 id。

在一些很老的 C 库中,没有提供 pthread_setname_np 函数。CK 会写一个 dummy 的函数来替换,这可能导致一些情况下不能设置成功线程名。

线程名的切换问题

一些程序会同时记录所有线程的 CPU 用量,以及当前进程的 CPU 总用量。这两个是一致的么?至少在一个使用线程池的程序中,未必一致。

这里的原因是线程池中往往会将线程按照 ${task_name}_${task_id} 这样重新命名,从而区分用途。而处于避免线程启动和销毁的开销,又倾向于维护一个全局常驻线程池,新开辟的线程池会先尝试从这个全局线程池中取,然后用完之后再归还。这就导致如果在这个过程中线程名字发生了从 A 到 B 的变换,则可能会看到 B 对应的指标有一个很高的 delta(比如在 grafana 中能看到一个尖峰)。原因是 /proc/$pid/stat 或者 /proc/tasks/$tid/stat 里面的信息都是从启动开始经历的时钟周期,无论是 stime 还是 utime。所以,如果一开始线程名是 A,后来被某个线程池借走了,名字变成 B,但此时 A 的数据还在。如果此时,线程被归还了,名字改为 A,那么 A 的变化率就是这段时间的 jiffies 增量除以这段时间的长度。

On CPU 和 Off CPU time

Off-CPU 例如在等待阻塞 IO、锁、page swap 等的时间。这些时间不会通过普通的火焰图被反映出来,但却是影响读取性能的一个因素。我们常常要回答问题,为什么 CPU 没有被用满,但是查询依然比较慢。

设计上的 pitfall

  • 循环中的虚函数调用
  • memcpy

使用 perf probe 记录函数调用耗时

该方案整理自某同事的 idea。

考虑下面的场景,我们需要查看某动态链接库 /path/to/libtiflash_proxy.sohandle_pending_applies 函数每次调用的耗时。此时,可以借助 perf probe 去打点 $tok$tok%return,它们分别对应函数入口和函数出口。这里需要借助于一个 while 循环是因为函数可能有多个重载。

1
2
3
4
5
6
7
8
9
10
11
12
13
perf probe --del 'probe_libtiflash_proxy:*'
BIN=/path/to/libtiflash_proxy.so
TOKEN=handle_pending_applies
ITER=0
objdump $BIN --syms | grep $TOKEN | awk '{print $6}' | while read -r tok ; do
ITER=$(expr $ITER + 1)
NAME=$TOKEN\_$ITER
echo $NAME, $TOKEN, $ITER, $TOKEN\_$ITER
perf probe -x $BIN --no-demangle $NAME=$tok
perf probe -x $BIN --no-demangle $NAME=$tok%return
done
perf record -e probe_libtiflash_proxy:\* -aR sleep 10
perf script -s perf-script.py

附上 perf-script.py

关于 benchmark

pitfall

  • 需要多次运行
  • 需要预热,加载缓存
    通常可以使用启发式的方法,等待性能收敛。
  • 使用高精度时钟
  • 监控系统负载
  • 避免编译器优化
  • 缓存影响
  • 考虑动态内存分配如 new 或者 delete 对 benchmark 的影响,必要时使用预分配内存池

google benchmark

关于死锁

寻找死锁的原因

通过 gdb 可以找到对应 mutex 结构中的 owner,对应的值表示 LWP 的编号。
对于一些程序,可能 debug info 被优化掉了,此时可以选择

  1. 根据提示的行号,拷贝一份对应的源码到指定位置
  2. 自己编译一个同样 layout 的对象,然后 load 进去解析

一些工具

pstack

可以通过 https://gist.github.com/JaySon-Huang/e374da1fafa41a3fa30a24e135c60825 去合并相同的堆栈。

如果 pstack 没有安装,可以借助于 GDB 的 thread apply all bt 命令。但这个命令会对屏幕输入一堆字符,不是很好看。因此可以

1
2
set logging file mylog.txt
set logging on

或者使用命令行直接输出

1
gdb -ex "thread apply all bt" -batch -p $PID

uprobe

func_latency 工具

这也是 bcc 套装里面的一个工具。

PT_PERF 技术

主要是看 mysql 内核月报续集学的,它还给了一个应用场景
这个工具的原理是 Intel CPU 的一个 Processor Trace 技术。主要特点是开销小。它记录程序控制流,特别是 branch 跳转的信息。

这个工具可以:

  1. 跟踪某个函数在历史时间中执行时间的分布情况。
  2. 跟踪该函数所有子函数的执行情况,包含各自花了多久,占比如何。
  3. 跟踪 Off-CPU,参数 -o。
  4. 通过 –history=1 记录,拷贝数据到另一台机器上通过 –history=2 分析。
  5. 通过 -a do_command#67108864,134217727 指定对应父函数以及耗时范围,从而精准定位子函数存在的问题。

需要:

  1. 修改 perf_event_mlock_kb 支持更大的 trace buffer,减少 trace 数据丢失。
  2. 修改 kptr_restrict 支持追踪内核函数,如追踪 off-cpu 分析需要的 schedule 内核函数。

此外对 Linux 版本也有依赖。

eBPF 技术原理

包括 kprobe、uprobe、tcpdump 等工具都是基于 eBPF 技术实现的

  • kprobes:实现内核中动态跟踪。kprobes 可以跟踪到 Linux 内核中的导出函数入口或返回点,但是不是稳定 ABI 接口,可能会因为内核版本变化导致,导致跟踪失效。
  • uprobes:用户级别的动态跟踪。与 kprobes 类似,只是跟踪用户程序中的函数。
  • tracepoints:内核中静态跟踪。tracepoints 是内核开发人员维护的跟踪点,能够提供稳定的 ABI 接口,但是由于是研发人员维护,数量和场景可能受限。
  • perf_events:定时采样和 PMC。