目录
摘要
ftrace 和 perf 都是 Linux 提供的动态追踪功能,两者有一定相似性,却又有不同的侧重点。ftrace 更侧重于事件跟踪和内核行为的实时分析,perf 更侧重于性能分析和事件统计。
跟踪系统调用
一般对于用户进程的系统调用跟踪,常用 strace :
[root@centos ~]# strace -p 1545
strace: Process 1545 attached
select(0, NULL, NULL, NULL, {tv_sec=0, tv_usec=636974}) = 0 (Timeout)
wait4(1552, 0x7ffccc4863c4, WNOHANG, NULL) = 0
wait4(1553, 0x7ffccc4863c4, WNOHANG, NULL) = 0
strace 用起来简单,但其实有不可忽略的性能问题。究其原因,乃是因为 strace 基于 ptrace() 系统调用实现,在事件多的场景下,存在频繁的用户态、内核态之间的切换,因此需尽量避免在线上环境使用。
perf 也提供了 trace 功能,不同的是,perf 基于内核事件实现,性能较 strace 要优越许多。
比如我们可以通过这样的命令跟踪指定的进程:
[root@centos ~]# perf trace -p 1545
? ( ): ... [continued]: select()) = 0 Timeout
0.029 ( 0.004 ms): wait4(upid: 1552 (barad_agent), stat_addr: 0x7ffccc4863c4, options: NOHANG
0.039 ( 0.003 ms): wait4(upid: 1553 (barad_agent), stat_addr: 0x7ffccc4863c4, options: NOHANG
0.049 (5000.708 ms): select(tvp: 0x7ffccc486860 ) = 0 Timeout
可惜的是,由于 perf 基于内核的跟踪点信息实现,这些信息不一定完整,所以 perf 的输出不一定有参数和返回值信息。
跟踪事件
同 ftrace 一样,perf 也支持事件跟踪,perf list 描述了其预定义的跟踪事件:
[root@centos ~]# perf list | grep net
net:napi_gro_frags_entry [Tracepoint event]
net:napi_gro_receive_entry [Tracepoint event]
net:net_dev_queue [Tracepoint event]
net:net_dev_xmit [Tracepoint event]
net:netif_receive_skb [Tracepoint event]
net:netif_receive_skb_entry [Tracepoint event]
net:netif_rx [Tracepoint event]
net:netif_rx_entry [Tracepoint event]
net:netif_rx_ni_entry [Tracepoint event]
支持的事件种类也是比较多的,可以通过 -e 指定感兴趣的事件进行跟踪。这里我们还是以 netif_receive_skb 为例测试一下:
[root@centos ~]# perf record -e net:netif_receive_skb
^C[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.149 MB perf.data (10 samples) ]
[root@centos ~]# perf script
swapper 0 [001] 14224.192066: net:netif_receive_skb: dev=eth0 skbaddr=0xffff96c9b9a10800 len=28
swapper 0 [001] 14224.780290: net:netif_receive_skb: dev=eth0 skbaddr=0xffff96c9b9a10800 len=132
swapper 0 [001] 14224.784794: net:netif_receive_skb: dev=eth0 skbaddr=0xffff96c9b9a10500 len=52
swapper 0 [000] 14225.050872: net:netif_receive_skb: dev=eth0 skbaddr=0xffff96c9b9bafd00 len=52
跟踪函数
当然了,如果这些预定义的事件并不满足我们的需求,perf 也支持我们自己指定函数名,这就要用的 perf probe 工具了。
跟踪内核函数
让我们来用 perf probe 跟踪一下 do_fork() 这个内核函数,首先通过 --add 选项添加要跟踪的函数名:
[root@centos ~]# perf probe --add do_fork
Added new event:
probe:do_fork (on do_fork)
You can now use it in all perf tools, such as:
perf record -e probe:do_fork -aR sleep 1
然后按照提示执行 perf record 就好了:
[root@centos ~]# perf record -e probe:do_fork -aR sleep 1
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.163 MB perf.data (16 samples) ]
[root@centos ~]#
[root@centos ~]# perf script
crond 1230 [001] 16150.475442: probe:do_fork: (ffffffff8b29e700)
crond 3271 [001] 16150.480182: probe:do_fork: (ffffffff8b29e700)
flock 3272 [000] 16150.481877: probe:do_fork: (ffffffff8b29e700)
sh 3273 [001] 16150.482651: probe:do_fork: (ffffffff8b29e700)
start.sh 3274 [000] 16150.483937: probe:do_fork: (ffffffff8b29e700)
start.sh 3274 [001] 16150.484779: probe:do_fork: (ffffffff8b29e700)
start.sh 3276 [000] 16150.484940: probe:do_fork: (ffffffff8b29e700)
start.sh 3276 [000] 16150.485024: probe:do_fork: (ffffffff8b29e700)
[root@centos ~]# perf probe --del do_for
最后也还是要记得删掉 probe 的跟踪点。上面的输出就是 perf 在 1s 内采样输出的结果了。实际中,我们可能还需要指定 do_fork 的参数具体传了什么。
[root@centos ~]# perf probe -V do_fork
Available variables at do_fork
@<do_fork+0>
int* child_tidptr
int* parent_tidptr
long unsigned int clone_flags
long unsigned int stack_size
long unsigned int stack_start
如果提示找不到符号,那可能是没有安装 kernel-debuginfo 包,可以下载对应版本的 rpm 来手动安装:
wget http://debuginfo.centos.org/7/x86_64/kernel-debuginfo-common-x86_64-$(uname -r).rpm
wget http://debuginfo.centos.org/7/x86_64/kernel-debuginfo-$(uname -r).rpm
rpm -ivh kernel-debuginfo-common-x86_64-$(uname -r).rpm
rpm -ivh kernel-debuginfo-$(uname -r).rpm
知道了参数之后,就可以用如下的方法跟踪函数的参数啦:
[root@centos ~]# perf probe --add 'do_fork child_tidptr clone_flags'
Added new event:
probe:do_fork (on do_fork with child_tidptr clone_flags)
You can now use it in all perf tools, such as:
perf record -e probe:do_fork -aR sleep 1
[root@centos ~]# perf record -e probe:do_fork -aR sleep 3
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.171 MB perf.data (26 samples) ]
[root@centos ~]#
[root@centos ~]# perf script
barad_agent 1566 [001] 19545.036400: probe:do_fork: (ffffffff8b29e700) child_tidptr=0x7fb2cc9939d0 clone_flags=0x3d0
barad_agent 16816 [001] 19545.036916: probe:do_fork: (ffffffff8b29e700) child_tidptr=0x7fb2cc9939d0 clone_flags=0x120
barad_agent 1566 [000] 19545.037944: probe:do_fork: (ffffffff8b29e700) child_tidptr=0x7fb2bf1ca9d0 clone_flags=0x3d0
# 记得删掉跟踪点
[root@centos ~]# perf probe --del 'do_fork'
Removed event: probe:do_fork
跟踪用户函数
同样的,perf 也可以跟踪用户空间的函数调用。bash 作为命令行输入的窗口,会调用 readline 方法从标准 io 读取用户的输入,并返回一个字符串,我们可以通过如下的命令对其进行跟踪:
[root@centos ~]# perf probe -x /bin/bash 'readline%return +0($retval):string'
Added new event:
probe_bash:readline__return (on readline%return in /usr/bin/bash with +0($retval):string)
You can now use it in all perf tools, such as:
perf record -e probe_bash:readline__return -aR sleep 1
[root@centos ~]# perf record -e probe_bash:readline__return -aR sleep 5
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.173 MB perf.data (1 samples) ]
[root@centos ~]#
[root@centos ~]# perf script
[root@centos ~]# perf record -e probe_bash:readline__return -aR sleep 3
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.184 MB perf.data ]
[root@centos ~]#
[root@centos ~]# perf script
bash 3289 [000] 19913.376245: probe_bash:readline__return: (48aea0 <- 41e75a) arg1="pwd"
# 删除跟踪点
[root@centos ~]# perf probe --del probe_bash:readline__return
Removed event: probe_bash:readline__return
如果不清楚参数,但是有带符号表的二进制文件的话,也可以通过以下的命令查询函数名及参数:
# 通过 -x 指定二进制路径,--funcs 查询方法名
[root@centos ~]# perf probe -x ./a.out --funcs
completed.6355
data_start
deregister_tm_clones
frame_dummy
fun
main
printf@plt
register_tm_clones
# 查询 fun 方法的参数
[root@centos ~]# perf probe -x ./a.out -V fun
Available variables at fun
@<fun+0>
int a
性能分析
perf stat 与 perf top
除了跟踪,perf最常用的就是性能分析了。如通过 perf stat 统计消耗时钟周期及缺页次数:
[root@centos ~]# perf stat -e cpu-clock,page-faults
^C
Performance counter stats for 'system wide':
6,053.73 msec cpu-clock # 2.000 CPUs utilized
2,345 page-faults # 0.387 K/sec
3.026891428 seconds time elapsed
通过 perf top -g 对热点函数及调用栈进行采样,光标移动到对应的行上按下 Enter 就可以展开调用栈:
Samples: 3K of event 'cpu-clock', 4000 Hz, Event count (approx.): 409744295 lost: 0/0 drop: 0/0
Children Self Shared Object Symbol
- 14.10% 0.59% [kernel] [k] __do_softirq ◆
+ 2.22% __do_softirq ▒
+ 10.27% 0.06% [kernel] [k] arch_cpu_idle ▒
- 9.42% 0.05% [kernel] [k] system_call_fastpath ▒
+ 8.79% 8.79% [kernel] [k] _raw_spin_unlock_irqrestore
perf top 帮助我们清晰的看到热点函数的,包括占用的 cpu 时间比以及所属进程或是动态库。
火焰图
有时候光看这些符号对个函数整体占用的分布并没有直观的感受,这时候火焰图就派上了用场。
生成火焰图需要依赖一个开源的脚本工具,从这里下载即可:
https://github.com/brendangregg/FlameGraph
脚本准备完毕可以开始执行下面的命令生成火焰图了,具体用法在对应脚本中也有详细的注释说明:
# 统计热点函数及调用栈信息
[root@centos ~]# perf record -F 99 -a -g -- sleep 5
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.282 MB perf.data (990 samples) ]
# 调用脚本生成火焰图
[root@centos ~]# perf script | ./FlameGraph-master/stackcollapse-perf.pl > out.tmp && ./FlameGraph-master/flamegraph.pl out.tmp > out.svg
生成的火焰图效果如下,其横轴为样本的数量,可以理解为耗时的近似值,纵轴表示调用栈的深度,图的底部即时调用栈的最底层:
总结
总结来说,perf 常用的功能就是 trace 跟踪函数、事件,top、stat、record 统计分析性能。配合第三方脚本生成火焰图提供可视化的界面。perf 提供的功能还不止于此,不过知道这些常用的方法也能帮助我们排查问题及性能优化了。
标签:fork,do,perf,centos,probe,Linux,root,追踪 From: https://blog.csdn.net/qq_33724710/article/details/136635083