ftrace、perf、bcc、bpftrace、ply的使用

目录

参考

Ftrace

经典用法

function_graph

  • 获取某个进程调用sys_open的调用栈
    运行要trace的程序，然后在调用open之前挺住，接着执行下面的命令，最后接着执行程序

    echo function_graph > /sys/kernel/debug/tracing/current_tracer
echo *sys_open > /sys/kernel/debug/tracing/set_graph_function
#echo 1 > /sys/kernel/debug/tracing/options/funcgraph-tail
echo <pid> > /sys/kernel/debug/tracing/set_ftrace_pid
echo 0 > /sys/kernel/debug/tracing/tracing_on
echo > /sys/kernel/debug/tracing/trace
echo 3 > /proc/sys/vm/drop_caches
echo 1 > /sys/kernel/debug/tracing/tracing_on

    然后执行下面的命令导出trace:

    echo 0 > /sys/kernel/debug/tracing/tracing_on
cat /sys/kernel/debug/tracing/trace > trace.log

    对于function_graph抓到的调用栈，可以使用内核提供的vim插件来阅读：Documentation/trace/function-graph-fold.vim
    用法： vim trace.log -S Documentation/trace/function-graph-fold.vim

  • 查看不同进程在某个函数上消耗的时间
    比如以rtnl_lock为例：

echo rtnl_lock > set_graph_function
echo rtnl_trylock >> set_graph_function
# 设置过滤
echo rtnl_lock > set_ftrace_filter
echo rtnl_trylock >> set_ftrace_filter
# 输出调用者的信息
echo 1 > options/funcgraph-proc # 或者 echo funcgraph-proc > trace_options
# 输出延迟标记(+ ! # * @ $)
echo 1 > options/funcgraph-overhead # 或者 echo funcgraph-overhead > trace_options
# 设置tracer
echo function_graph > current_tracer
# 启动
echo 1 > tracing_on

下面是输出：

root@ubuntu:/sys/kernel/debug/tracing# cat trace
# tracer: function_graph
#
# CPU  TASK/PID         DURATION                  FUNCTION CALLS
# |     |    |           |   |                     |   |   |   |
   4)  kworker-3574  | + 53.651 us   |  rtnl_lock();
   4)  kworker-3574  | + 11.752 us   |  rtnl_lock();
   4)  kworker-3574  |   3.186 us    |  rtnl_lock();
   4)  kworker-3574  |   5.460 us    |  rtnl_lock();
   4)  kworker-3574  |   5.090 us    |  rtnl_lock();
   4)  kworker-3574  |   2.755 us    |  rtnl_lock();
   4)  kworker-3574  |   3.246 us    |  rtnl_lock();
   4)  kworker-3574  |   6.502 us    |  rtnl_lock();
   4)  kworker-3574  |   3.016 us    |  rtnl_lock();
   4)  kworker-3574  |   2.936 us    |  rtnl_lock();
   4)  kworker-3574  |   2.455 us    |  rtnl_lock();
   4)  kworker-3574  | + 42.089 us   |  rtnl_lock();
   4)  kworker-3574  |   2.495 us    |  rtnl_lock();
   4)  kworker-3574  |   8.997 us    |  rtnl_lock();
   4)  kworker-3574  |   3.166 us    |  rtnl_lock();
   4)  kworker-3574  |   3.908 us    |  rtnl_lock();
  • 过滤影响分析的函数
echo *spin* >> set_graph_notrace
echo *rcu* >> set_graph_notrace
echo mutex* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo security* >> set_graph_notrace
echo *might* >> set_graph_notrace
echo __cond* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
  • 不跟硬件中断
echo 0 > options/funcgraph-irqs

如果不希望跟踪流程里有硬件中断处理，那么可以设置这个。这样在硬件中断中的函数不会被跟踪，
这里判断是否在硬件中断，用的时in_hardirq，而设置hardirq标志是在irq_enter_rcu，所以
还是会看到irq_enter_rcu被跟踪到，但是再往下就不会被跟踪了。

trace_point

时间延迟标志

标记 含义
+ > 10us
！ > 100us
# > 1ms
* > 10ms
@ > 100ms
$ > 1s

hist

在事件上创建自定义的直方图。

  • 使用hist触发器通过raw_syscalls:sys_enter跟踪点来计数系统调用数量，并提供按进程pid分类的直方图
echo 'hist:keys=common_pid' > events/raw_syscalls/sys_enter/trigger
sleep 10
cat events/raw_syscalls/sys_enter/hist
...
echo '!hist:keys=command_pid' > events/raw_syscalls/sys_enter/trigger

trace_option

参考： https://www.kernel.org/doc/html/latest/trace/ftrace.html#trace-options

  • func_stack_trace: 输出函数的调用栈，配合function tracer使用，也可以用于trace-event
           bash-840761  [006] .... 101123.681864: ldsem_down_read <-tty_ldisc_ref_wait
            bash-840761  [006] .... 101123.681866: <stack trace>
 => 0xffffffffc09d6099
 => ldsem_down_read
 => tty_ldisc_ref_wait
 => tty_ioctl
 => __x64_sys_ioctl
 => do_syscall_64
 => entry_SYSCALL_64_after_hwframe
  • stacktrace： 输出函数的调用栈，配合trace-event用

perf-tools

trace-cmd

是kernelshark的后端，可以用kernelshark解析trace-cmd生成的文件。

参考

事件列举

# 列出所有跟踪事件的来源和选项
trace-cmd list
# 列出Ftrace跟踪器
trace-cmd list -t
# 列出事件源
trace-cmd list -e
# 列出系统调用跟踪点
trace-cmd list -e syscalls
# 显示指定跟踪点的格式文件
trace-cmd list -e syscalls:sys_enter_nanosleep -F

函数图示跟踪

  • 抓取某个进程调用sys_open的调用栈
    sudo trace-cmd record -p function_graph -g *sys_open -P <pid>
    可以先让进程在调用open之前停住，用sleep或者getchar，在脚本里可以用echo $$; read con; exec xxx，执行上面的命令后，再继续执行
    此外，还可以直接跟命令，比如：
    sudo trace-cmd record -p function_graph -g *sys_open -F ls
    最后执行下面的命令导出trace:
    trace-cmd report > trace.log

函数跟踪

trace-cmd record -p function -l function_name

比如：

# 为ls命令跟踪所有一个vfs_开头的内核函数
trace-cmd record -p function -l 'vfs_*' -F ls
# 跟踪以tcp_开头的所有内核函数，持续10秒
trace-cmd record -p function -l 'tcp_*' sleep 10
# 跟踪bash及其子程序的所有一个vfs_开头的内核函数
trace-cmd record -p function -l 'vfs_*' -F -c bash
# 跟踪PID为21124的所有一个vfs_开头的内核函数
trace-cmd record -p function -l 'vfs_*' -P 21124

事件跟踪

trace-cmd record -e sched:sched_process_exec

远程

# 在tcp 8081端口监听
trace-cmd listen -p 8081
# 连接到远程主机以运行记录子命令
trace-cmd record ... -N addr:port

kernelshark

kprobe

  • kprobe 的 3 种使用
  • 内核调试之kprobe
  • Linux内核 eBPF基础：kprobe原理源码分析：源码分析
  • Linux内核 eBPF基础：kprobe原理源码分析：基本介绍与使用示例
  • 打印open时的文件名
    echo 'p:myprobe do_sys_open file=+0(%si):string' > kprobe_events
    可以通过format查看log的输出格式：
    root@ubuntu:/sys/kernel/debug/tracing# cat events/kprobes/my_probe/format
    name: my_probe
ID: 2072
format:
    field:unsigned short common_type;       offset:0;       size:2; signed:0;
    field:unsigned char common_flags;       offset:2;       size:1; signed:0;
    field:unsigned char common_preempt_count;       offset:3;       size:1; signed:0;
    field:int common_pid;   offset:4;       size:4; signed:1;

    field:unsigned long __probe_ip; offset:8;       size:8; signed:0;
    field:__data_loc char[] file;   offset:16;      size:4; signed:1;

print fmt: "(%lx) file=\"%s\"", REC->__probe_ip, __get_str(file)
    可以通过filter设置过滤条件：
    echo 'file=="setproxy.sh"' > events/kprobes/my_probe/filter
    使能：
    echo 1 > events/kprobes/my_probe/enable
    下面是输出的log：
    cat trace 或者 cat trace_pipe
    cat-753     [001] ....  3406.761327: my_probe: (do_sys_open+0x0/0x80) file="setproxy.sh"
    可以在输出log的时候，打印open的调用栈：
    echo 1 > options/stacktrace
    可以从trace中看到如下的log：
             cat-772     [000] ....  3650.530789: my_probe: (do_sys_open+0x0/0x80) file="setproxy.sh"
         cat-772     [000] ....  3650.530980: <stack trace>
=> do_sys_open
=> do_syscall_64
=> entry_SYSCALL_64_after_hwframe
    对于不同的体系架构，进行函数调用时使用的传参规则并不相同，所以在使用kprobe提取函数参数时使用的方式也不
    相同，为了解决这一问题，内核引入了一个patch：a1303af5d79eb13a658633a9fb0ce3aed0f7decf解决了这一问题，
    使用argX来代表参数，比如上面的这个file=+0(%si):string可以替换为file=+0($arg2):string，因为
    filename是第2个参数，这里参数编号 是从1开始的。关于参数的解析可以参考内核代码：
    kernel\trace\trace_probe.c:parse_probe_arg

下面是常见的处理器的函数传参规则：

体系架构 参数1 参数2 参数3 参数4 参数5 参数6 参数7 参数8 参数9
x86 stack
x86_64 rdi rsi rdx rcx r8 r9 stack
arm r0 r1 r2 r3 stack
arm64 x0 x1 x2 x3 x4 x5 x6 x7 stack

下面是不同架构的处理器上执行系统调用时的传参规则:

Architecture Syscall instruction Syscall number in return value arg0 arg1 arg2 arg3 arg4 arg5
x86_64 syscall rax rax rdi rsi rdx rcx r8 r9
x86 int 0x80 eax eax ebx ecx edx esi edi ebp
arm svc 0 r7 r0 r0 r1 r2 r3 r4 r5
arm64 svc 0 x8 x0 x0 x1 x2 x3 x4 x5

uprobe

eBPF

bpftrace

bpftrace -e 'kprobe:shmem_user_xattr_handler_set {printf("filename = %s, value = %s size = %d flag = %x\n", str(arg3), str(arg4), arg5, sarg0)}''

Attaching 1 probe...
filename = shmem_backend_file, value = ./memory_backend.img size = 20 flag = 1
filename = shmem_backend_file, value =  size = 0 flag = 0

需要注意的是，arg从0开始，对于存放在栈里的参数，可以使用sarg来提取，函数原型：

static int shmem_user_xattr_handler_set(const struct xattr_handler *handler,
>------->------->------->-------   struct dentry *unused, struct inode *inode,
>------->------->------->-------   const char *name, const void *value,
>------->------->------->-------   size_t size, int flags)

#include <linux/mm.h>

kprobe:shmem_writepage
{
        printf("Page: 0x%x, Index: 0x%x\n", arg0, ((struct page *)arg0)->index);
}

ply

BCC

perf

image

参考

perf_event_open学习

火焰图

perf stat

perf kvm

perf trace

perf ftrace

perf probe的使用

image

  • 查看一个内核函数中指定行可以访问哪些变量
    perf probe --var kernel_function:lineno -k <kernel_source_path>/vmlinux -s <kernel_source_path>

image

  • 添加追踪事件

在上面第5行插入事件：
image

可以使用perf probe --list查看当前注册了哪些事件：

image

然后使用perf record -e probe:vfs_symlink_L5开启事件，再在另外一个窗口执行一个创建软连接的操作，然后
停止perf probe，最后用perf script查看事件：

image

  • 删除事件

image

perf sched使用

getdelays

surftrace

这是是阿里云开发的，是对ftrace的二次封装。
https://github.com/aliyun/surftrace

Systemtap

stapbpf

Dtrace

uftrace

utrace

Systrace/Perfetto

LTTng

Trace Compass

B站某UP主写的profile工具，可以学习一下

posted @ 2021-11-10 14:16  摩斯电码  阅读(2341)  评论(0)  编辑  收藏  举报