bpftrace[1] 可以追踪用户态函数的函数开始(uprobe)和函数返回(uretprobe)，由于我们在统计某个函数运行时间来进行性能剖析时，也经常用记下时间来统计函数的运行时间，所以利用这两种trace点，结合bpftrace提供的nsecs、lhist()等内置组件，我们可以将时间统计脚本和程序代码相分离。
本文以一个简单程序举例，希望读者能够在短时间内了解这种思想，进行灵活运用扩展。当然，复杂的统计需要更复杂的bpftrace脚本构造方法。
1. 被profile的程序
我写了一个称为sleep_prog的进行“随机正态睡眠”的小程序，代码如下[2]。(这个程序会调用sleep_func()函数1000次，每次的睡眠的时间是随机生成的，随机生成用10次[0, 100)的均匀分布之和模拟正态分布，所以，sleep_func()每次睡眠的时间应该类似均值为500 us的正态分布。)
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 |
#include <stdio.h> #include <stdlib.h> #include <unistd.h> #include <time.h> void sleep_func(int sleep_time_us) { usleep(sleep_time_us); } int main() { int lower = 0, upper = 100; srand(time(0)); for (int k = 1000; k > 0; k--) { int sleep_time_us = 0; for (int i = 0; i < 10; i++) { sleep_time_us += rand() % (upper - lower) + lower; } printf("us: %d\n", sleep_time_us); sleep_func(sleep_time_us); } return 0; } |
2. 用于统计的bpftrace脚本
bptrace工具接收脚本文件作为参数，这里我将它命名为profile.d，代码如下[2]。容易看出，我们需要追踪两个探针，分别是sleep_func()函数的开始(uprobe)和结束(‘uretprobe’)，在“开始探针”部分，我们利用内置的nsecs变量记下当前的时间到我们自定义的变量@t_start中；在"结束探针"中，我们将当前时间nsecs与@t_start相减作为本次sleep_func函数的运行时间，以内置的lhist直方图的形式存储到@my_host变量中，并清零@t_start。这样，在这个bpftrace脚本被Ctrl+c结束后，一个sleep_func()函数的运行时间分布直方图就会被打印出来。(注意： 脚本里的/home/zjc/test/sleep_prog路径应该替换成你的程序的路径)
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 |
#!/usr/bin/bpftrace uprobe:/home/zjc/test/sleep_prog:sleep_func { @t_start=nsecs; } uretprobe:/home/zjc/test/sleep_prog:sleep_func /@t_start/ { @my_hist = lhist(nsecs - @t_start, 0, 10000000, 50000); clear(@t_start); } |
3. 测试和结果
Step 1.
在A终端，编译sleep_prog程序：
|
1 2 |
gcc sleep_prog.c -o sleep_prog |
Step 2.
在B终端，用超级权限运行profile.d脚本：
|
1 2 |
sudo profile.d |
Step 3.
在A终端，运行sleep_prog程序：
|
1 2 |
./sleep_prog |
Step 4.
用Ctrl+c结束掉A中断的bpftrace脚本，样例结果如下，可以看出，的确比较符合正态分布啊~
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 |
zjc@test $ sudo ./profile.d [sudo] password for zjc: Attaching 2 probes... ^C @my_hist: [250000, 300000) 1 | | [300000, 350000) 6 |@@ | [350000, 400000) 14 |@@@@@@ | [400000, 450000) 39 |@@@@@@@@@@@@@@@@ | [450000, 500000) 63 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ | [500000, 550000) 120 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@| [550000, 600000) 82 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ | [600000, 650000) 96 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ | [650000, 700000) 53 |@@@@@@@@@@@@@@@@@@@@@@ | [700000, 750000) 18 |@@@@@@@ | [750000, 800000) 7 |@@@ | [800000, 850000) 0 | | [850000, 900000) 0 | | [900000, 950000) 0 | | [950000, 1000000) 0 | | [1000000, 1050000) 0 | | [1050000, 1100000) 0 | | [1100000, 1150000) 0 | | [1150000, 1200000) 1 | | |
[1] https://github.com/zhangjaycee/real_tech/wiki/linux_017#bpftrace
[2] https://gist.github.com/zhangjaycee/d9e0b342c8984856cea944c5c4e24dc8