聊聊飞哥使用 tracepoint 和 kprobe 进行内核源码跟踪的技术原理!
# perf list tracepoint
List of pre-defined events (to be used in -e):
alarmtimer:alarmtimer_cancel [Tracepoint event]
alarmtimer:alarmtimer_fired [Tracepoint event]
alarmtimer:alarmtimer_start [Tracepoint event]
alarmtimer:alarmtimer_suspend [Tracepoint event]
block:block_bio_backmerge [Tracepoint event]
block:block_bio_bounce [Tracepoint event]
block:block_bio_complete [Tracepoint event]
block:block_bio_frontmerge [Tracepoint event]
block:block_bio_queue [Tracepoint event]
block:block_bio_remap [Tracepoint event]
......
sched:sched_switch [Tracepoint event]
sched:sched_wait_task [Tracepoint event]
sched:sched_wake_idle_without_ipi [Tracepoint event]
sched:sched_wakeup [Tracepoint event]
sched:sched_wakeup_new [Tracepoint event]
sched:sched_waking [Tracepoint event]
scsi:scsi_dispatch_cmd_done [Tracepoint event]
.....
我们拿 sched:sched_switch 这个静态跟踪点来举例。实际上,该跟踪点在内核中是在进程调度器的核心函数 __schedule 中埋下的,就是我们下面列出的源码中的 trace_sched_switch 这一行。这样每次内核执行到 __schedule 的时候,都会调用该跟踪点。
//file:kernel/sched/core.c
staticvoid __sched notrace __schedule(bool preempt)
{
...
trace_sched_switch(preempt, prev, next);
}
那找到可用的跟踪点之后,下一步就是真正使用它来跟踪。ftrace 、trace-cmd、perf 都可以跟踪系统里的这些静态跟踪点。我们分别介绍一下这几种工具的用法。
第一种是 ftrace。这个工具使用起来步骤虽然有点小麻烦,但是是所有工具中最接近底层的一个,所以我先介绍它。使用这个工具首先是要进入到 sched_switch 所在的伪文件目录下来。然后给目录下的 enable 写入 1 表示打开该静态跟踪点。
# cd /sys/kernel/debug/tracing/events/sched/sched_switch
# echo 1 > /sys/kernel/debug/tracing/events/sched/sched_switch/enable
然后访问 cat 跟踪 ftrace 下公用的 trace_pipe 就可以看到打印出来的内核输出了。在输出的结果中可以看到触发该静态跟踪点时的进程名、进程 pid、进程 prio 等数据。如下。
# cat /sys/kernel/debug/tracing/trace_pipe
<...>-1997939 [002] d... 19251337.694159: sched_switch: prev_comm=node prev_pid=1997939 prev_prio=120 prev_state=S ==> next_comm=swapper/2 next_pid=0 next_prio=120
<...>-1997960 [004] d... 19251337.694159: sched_switch: prev_comm=node prev_pid=1997960 prev_prio=120 prev_state=S ==> next_comm=swapper/4 next_pid=0 next_prio=120
<idle>-0 [002] d... 19251337.694166: sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=node next_pid=1997939 next_prio=120
<...>-1997957 [003] d... 19251337.694170: sched_switch: prev_comm=node prev_pid=1997957 prev_prio=120 prev_state=S ==> next_comm=swapper/3 next_pid=0 next_prio=120
<idle>-0 [005] d... 19251337.694308: sched_switch: prev_comm=swapper/5 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=node next_pid=1997958 next_prio=120
......
跟踪完毕后记得把这个跟踪点的开关给关了。
# echo 0 > /sys/kernel/debug/tracing/events/sched/sched_switch/enable
第二个工具是使用 perf 命令。前面咱们介绍了如何通过 perf list 查看支持的跟踪点。如下所示,该命令的输出也显示当前系统支持 sched:sched_switch 这个静态跟踪点。
# perf list
...
sched:sched_switch
找到跟踪点后,就可以使用 perf record 进行下一步的跟踪了。perf record 会根据 sched:sched_switch 跟踪点时间来进行录制,然后输出到 perf.data 文件中。
# perf record -e 'sched:sched_switch' -a sleep 3
该文件需要使用 perf script 来进行解析,将跟踪当时的现场都打印出来。
# perf script
migration/0 11 [000] 337467.469254: sched:sched_switch: prev_comm=migration/0 prev_pid=11 prev_prio=0 prev_state=S ==> next_comm=swapper/0 next_pid=0 next_pri
perf 3979944 [001] 337467.469273: sched:sched_switch: prev_comm=perf prev_pid=3979944 prev_prio=120 prev_state=R+ ==> next_comm=migration/1 next_pid=15 ne
migration/1 15 [001] 337467.469290: sched:sched_switch: prev_comm=migration/1 prev_pid=15 prev_prio=0 prev_state=S ==> next_comm=swapper/1 next_pid=0 next_pri
perf 3979944 [002] 337467.469307: sched:sched_switch: prev_comm=perf prev_pid=3979944 prev_prio=120 prev_state=R+ ==> next_comm=migration/2 next_pid=20 ne
migration/2 20 [002] 337467.469322: sched:sched_switch: prev_comm=migration/2 prev_pid=20 prev_prio=0 prev_state=S ==> next_comm=swapper/2 next_pid=0 next_pri
perf 3979944 [003] 337467.469345: sched:sched_switch: prev_comm=perf prev_pid=3979944 prev_prio=120 prev_state=R+ ==> next_comm=migration/3 next_pid=25 ne
migration/3 25 [003] 337467.469371: sched:sched_switch: prev_comm=migration/3 prev_pid=25 prev_prio=0 prev_state=S ==> next_comm=swapper/3 next_pid=0 next_pri
perf 3979944 [004] 337467.469384: sched:sched_switch: prev_comm=perf prev_pid=3979944 prev_prio=120 prev_state=R+ ==> next_comm=migration/4 next_pid=30 ne
......
在调试跟踪的时候,一般更有用的是把事件发生时的函数调用栈给记录下来。用 perf record 命令时加个 -g 参数就可以了,就可以录制时记录调用栈信息。
# perf record -e 'sched:sched_switch' -a -g sleep 3
# perf script
redis-server 3990071 [002] 338407.091729: sched:sched_switch: prev_comm=redis-server prev_pid=3990071 prev_prio=120 prev_state=S ==> next_comm=swapper/2 next_pid=0 ne
ffffffff81788c99 __sched_text_start+0x3a9 (/usr/lib/debug/boot/vmlinux-5.4.56.bsk.10-amd64)
ffffffff81788c99 __sched_text_start+0x3a9 (/usr/lib/debug/boot/vmlinux-5.4.56.bsk.10-amd64)
ffffffff81789030 schedule+0x40 (/usr/lib/debug/boot/vmlinux-5.4.56.bsk.10-amd64)
ffffffff8178d0e7 schedule_hrtimeout_range_clock+0x87 (/usr/lib/debug/boot/vmlinux-5.4.56.bsk.10-amd64)
ffffffff8130602e ep_poll+0x44e (/usr/lib/debug/boot/vmlinux-5.4.56.bsk.10-amd64)
ffffffff81306100 do_epoll_wait+0xb0 (/usr/lib/debug/boot/vmlinux-5.4.56.bsk.10-amd64)
ffffffff8130613a __x64_sys_epoll_wait+0x1a (/usr/lib/debug/boot/vmlinux-5.4.56.bsk.10-amd64)
ffffffff81004269 do_syscall_64+0x59 (/usr/lib/debug/boot/vmlinux-5.4.56.bsk.10-amd64)
ffffffff8180008c entry_SYSCALL_64+0x7c (/usr/lib/debug/boot/vmlinux-5.4.56.bsk.10-amd64)
7f9a753e221f epoll_wait+0x4f (/usr/lib/x86_64-linux-gnu/libc-2.28.so)
100000000 [unknown] ([unknown])
......
我的这台开发机部署了 redis,所以在录制的时候抓到了 redis-server 进程触发 sched_switch 静态跟踪点时的调用栈情况。
静态跟踪点是静态定义到内核源码中的。优点是对系统运行影响比较小,稳定性比较好。但它的缺点是不可能把所有内核函数中都埋一个跟踪点进去。要新增新的跟踪点需要修改和重新编译内核,这显然不是很灵活。
2.2 动态跟踪
在内核中,kprobes 是一种动态的跟踪机制。它允许动态地插入代码来监视内核中的大多数的函数。但缺点是由于太过于灵活,对系统的带来的影响不像 tracepoint 那么可控。另外就是它需要内核编译时打开了 CONFIG_KPROBE_EVENT 选项才能用。
# cat /boot/config-5.4.56.bsk.10-amd64 | grep CONFIG_KPROBE_EVENT
我们来用一个例子,看看动态跟踪 kprobes 如何使用。首先还是进入到 ftrace 根目录 /sys/kernel/debug/tracing。操作 kprobe_events 文件就可以添加一个动态跟踪点。格式是 "p:自定义的名字 函数名",如果要跟踪内核的 schedule 这个核心函数,操作方法如下。
# cd /sys/kernel/debug/tracing
# echo 'p:yanfei schedule' >> kprobe_events
上面的例子中创建了一个名为 yanfei 的跟踪点,这个时候会生成一个新的目录,位于 events/kprobes/yanfei 路径下。
# cd /sys/kernel/debug/tracing/
# ll events/kprobes/yanfei
total 0
-rw-r--r-- 1 root root 0 May 20 08:37 enable
-rw-r--r-- 1 root root 0 May 20 08:37 filter
-r--r--r-- 1 root root 0 May 20 08:37 format
-r--r--r-- 1 root root 0 May 20 08:37 id
-rw-r--r-- 1 root root 0 May 20 08:37 trigger
其中的 enable 是该跟踪点的开关,我们把它打开后,通过 cat /sys/kernel/debug/tracing/ trace_pipe 文件就可以看到动态跟踪的输出了。不过我觉得更有用的是用 perf 来采样查看这个动态跟踪点的函数调用栈。
在添加完这个跟踪点后可以用 perf 命令看到这个跟踪点。
# perf probe --list
kprobes:yanfei (on schedule@kernel/sched/core.c)
接着使用 perf record 子命令进行录制。然后使用 perf script 可以查看到调用的栈信息。
# perf record -e kprobes:yanfei -a -g sleep 1
# perf script
redis-server 3990071 [003] 341464.819710: kprobes:yanfei: (ffffffff81788ff0)
ffffffff81788ff1 schedule+0x1 (/usr/lib/debug/boot/vmlinux-5.4.56.bsk.10-amd64)
ffffffff8178d0e7 schedule_hrtimeout_range_clock+0x87 (/usr/lib/debug/boot/vmlinux-5.4.56.bsk.10-amd64)
ffffffff8130602e ep_poll+0x44e (/usr/lib/debug/boot/vmlinux-5.4.56.bsk.10-amd64)
ffffffff81306100 do_epoll_wait+0xb0 (/usr/lib/debug/boot/vmlinux-5.4.56.bsk.10-amd64)
ffffffff8130613a __x64_sys_epoll_wait+0x1a (/usr/lib/debug/boot/vmlinux-5.4.56.bsk.10-amd64)
ffffffff81004269 do_syscall_64+0x59 (/usr/lib/debug/boot/vmlinux-5.4.56.bsk.10-amd64)
ffffffff8180008c entry_SYSCALL_64+0x7c (/usr/lib/debug/boot/vmlinux-5.4.56.bsk.10-amd64)
7f9a753e221f epoll_wait+0x4f (/usr/lib/x86_64-linux-gnu/libc-2.28.so)
100000000 [unknown] ([unknown])
三、内核跟踪原理
在上一小节中我们介绍了静态跟踪和动态跟踪分别都是怎么使用的。在这一小节中我们来看看它们分别是如何实现的,原理到底是什么。
3.1 静态跟踪点 tracepoint
静态跟踪点的入口是在每个要跟踪的位置埋下的 trace_xxx 的函数。例如前面我们提到的,在 __schedule 路径下执行了 trace_sched_switch 这个静态跟踪点。
//file:kernel/sched/core.c
staticvoid __sched notrace __schedule(bool preempt)
{
...
trace_sched_switch(preempt, prev, next);
}
另外在源码中还可以在多处搜到 register_trace_sched_switch 在这个静态跟踪点上注册了一些钩子函数。
kernel/trace/ftrace.c: register_trace_sched_switch(ftrace_filter_pid_sched_switch_probe, tr);
kernel/trace/trace_sched_switch.c: ret = register_trace_sched_switch(probe_sched_switch, NULL);
kernel/trace/trace_sched_wakeup.c: ret = register_trace_sched_switch(probe_wakeup_sched_switch, NULL);
kernel/trace/fgraph.c: ret = register_trace_sched_switch(ftrace_graph_probe_sched_switch, NULL);
这样每当内核执行到 __schedule 函数中的 trace_sched_switch 时,就会调用到所注册的这些 ftrace_filter_pid_sched_switch_probe、probe_sched_switch、probe_wakeup_sched_switch、ftrace_graph_probe_sched_switch 等函数来完成整个静态跟踪过程。
但你在源码里实际上根本搜不到 trace_sched_switch 和 register_trace_sched_switch 函数的实现。这是因为内核并不是通过直接定义的方式来声明和实现的 trace_xxx 跟踪点函数。而是采用了炫技般的宏定义来做的。这些宏实现是挺复杂的,不用太扣细节,我们来简单了解下这个实现过程就行了。
内核实现静态跟踪点的宏主要有三个,分别是:
DEFINE_TRACE:这个宏用来定义一个静态跟踪点 DECLARE_TRACE:这个宏用来声明和实现这个静态跟踪点相关的各种 trace_xxx,register_trace_xxx 相关的函数 DO_TRACE:这个宏用来执行通过 register_trace_xxx 注册上来的钩子函数
我们先来看 DEFINE_TRACE,我们把整个定义过程精简了一下,如下:
//file:include/linux/tracepoint.h
#define DEFINE_TRACE(name) \
DEFINE_TRACE_FN(name, NULL, NULL);
#define DEFINE_TRACE_FN(name, reg, unreg) \
struct tracepoint __tracepoint_##name \
......
可见,这个宏主要是定义了一个名为 __tracepoint_##name 的 struct tracepoint 类型的对象。其中 ##name 就是跟踪点的名字。struct tracepoint 是一个内核对象,它的定义如下
//file:include/linux/tracepoint-defs.h
structtracepoint {
constchar *name; /* Tracepoint name */
structstatic_keykey;
int (*regfunc)(void);
void (*unregfunc)(void);
structtracepoint_func __rcu *funcs;
};
其中每个成员含义如下
name:tracepoint的名字 key:tracepoint状态,1表示disable,0表示enable regfunc:添加钩子函数的函数 unregfunc:卸载钩子函数的函数 funcs:tracepoint中所有的钩子函数链表
再来看 DECLARE_TRACE 宏,它用来声明和实现这个静态跟踪点相关的各种 trace_xxx,register_trace_xxx 相关的函数。我们简单看下它的实现。
//file:include/linux/tracepoint.h
#define DECLARE_TRACE(name, proto, args) \
__DECLARE_TRACE(name, PARAMS(proto), PARAMS(args), \
cpu_online(raw_smp_processor_id()), \
PARAMS(void *__data, proto), \
PARAMS(__data, args))
好么,宏套宏,再继续看 __DECLARE_TRACE。同样为了方便你看,我精简了很多
#define __DECLARE_TRACE(name, proto, args, cond, data_proto, data_args) \
extern struct tracepoint __tracepoint_##name; \
static inline void trace_##name(proto) \
{ \
//判断trace point是否disable
//如果开启的话,就调用__DO_TRACE遍历执行trace point中的桩函数
if (static_key_false(&__tracepoint_##name.key)) \
__DO_TRACE(&__tracepoint_##name, \
TP_PROTO(data_proto), \
TP_ARGS(data_args), \
TP_CONDITION(cond), 0); \
} \
staticinlineint \
register_trace_##name(void (*probe)(data_proto), void *data) \
{ \
return tracepoint_probe_register(&__tracepoint_##name, \
(void *)probe, data); \
} \
......
这个宏主要是声明和实现了 trace_xxx 和 register_trace_xxx 相关的函数。这样,我们前面看到的 trace_sched_switch 和 register_trace_sched_switch 就有了。
这里值得注意的是,如果静态跟踪点没有开启,trace_xxx 跟踪的开销非常的低。 trace_xxx 本身是个内联函数,而且如果跟踪点未开启的话,直接 if 判断开关没开后就退出了。所以静态跟踪 tracepoint 在关闭状态的时候对内核的运行基本没有啥影响。
如果开启了某个静态跟踪点后,就会进入 __DO_TRACE 进行真正的跟踪过程。
//file:include/linux/tracepoint.h
//运行实际的trace函数
#define __DO_TRACE(tp, proto, args, cond, rcuidle) \
do {
...
it_func_ptr = rcu_dereference_raw((tp)->funcs);
if (it_func_ptr) {
do {
it_func = (it_func_ptr)->func;
__data = (it_func_ptr)->data;
((void(*)(proto))(it_func))(args);
} while ((++it_func_ptr)->func);
}
}while(0)
__DO_TRACE 就是把 tracepoint 内核对象中之前注册的 funcs 拿出来都执行了一遍。这样每当内核执行到 trace_sched_switch 时,就会调用到注册的 ftrace_filter_pid_sched_switch_probe、probe_sched_switch、probe_wakeup_sched_switch、ftrace_graph_probe_sched_switch 这些钩子函数了,进而完成整个静态跟踪过程。
这就是 tracepoint 的核心实现过程。
3.2 动态跟踪 kprobes
静态跟踪 tracepoint 虽然是一大堆的宏的定义,但原理还是在想跟踪的地方埋下了一个函数。而动态跟踪 kprobes 的实现原理不是埋,而是直接替换了要跟踪的函数的地址。
kprobes 找到要跟踪的指令,直接用一个 BREAKPOINT_INSTRUCTION 指令将其替换掉,并将原来的指令保存起来。后面内核再次运行完上图中的指令 1 后就会进入到 BREAKPOINT_INSTRUCTION 对应的处理流程,处理完后仍然会调回到指令 2 继续往下执行。
kprobes 使用的核心是 register_kprobe 函数。在 samples/kprobes/kprobe_example.c 文件下有一个完整的使用例子。我把它简化了一下
staticstructkprobekp;
// 注册kprobe
staticint __init my_module_init(void)
{
int ret;
kp.pre_handler = handler_pre;
kp.post_handler = handler_post;
kp.fault_handler = handler_fault;
kp.symbol_name = "write"; // 指定要跟踪的内核符号
ret = register_kprobe(&kp);
if (ret < 0) {
printk(KERN_INFO "register_kprobe failed, returned %d\n", ret);
return ret;
}
printk(KERN_INFO "kprobe registered\n");
return0;
}
module_init(my_module_init);
在这个示例中,就定义了一个 kprobe 动态跟踪点,并指定要跟踪 write 这个内核符号,调用 register_kprobe 将其注册到内核上。这个注册过程主要就是保存原来的函数地址,并替换相应的指令为 BREAKPOINT_INSTRUCTION。
// file:kernel/kprobes.c
intregister_kprobe(struct kprobe *p)
{
// 获取探测点的地址
addr = kprobe_addr(p);
p->addr = addr;
// 保存原有的指令
prepare_kprobe(p);
// 执行指令替换
arm_kprobe(p)
...
}
在 register_kprobe 函数中,核心的操作是以上三步,其余代码都被我精简掉了。
kprobe_addr:是根据符号来查找函数地址的 prepare_kprobe:是将原来的指令给保存起来 arm_kprobe:将指令替换掉
我们重点看 arm_kprobe 是如何将指令替换掉的。它会调用到 arch_arm_kprobe,而每个 CPU 架构都有自己专用的 arch_arm_kprobe 函数的实现,对于 x86 架构来说,它的实现位于 arch/x86/kernel/kprobes/core.c 文件下。
//file: arch/x86/kernel/kprobes/core.c
voidarch_arm_kprobe(struct kprobe *p)
{
text_poke(p->addr, ((unsignedchar []){BREAKPOINT_INSTRUCTION}), 1);
}
看简单吧,x86 架构调用 text_poke 就完成了替换。
当后面内核再次运行到到替换的 BREAKPOINT_INSTRUCTION 指令后将触发 INT3 中断,进而调用到架构相关的 kprobe_int3_handler。在这里,将会获取到 kprobe 跟踪点,发现它有 pre_handler,好,那就跟踪之。
//file:arch/x86/kernel/kprobes/core.c
intkprobe_int3_handler(struct pt_regs *regs)
{
// 获取 kprobe
p = get_kprobe(addr);
// 执行 pre_handler
if (!p->pre_handler || !p->pre_handler(p, regs))
setup_singlestep(p, regs, kcb, 0);
...
}
最后再把被替换的指令翻出来,让内核继续运行。总体上来说,内核的 kprobe 的原理就是利用 BREAKPOINT_INSTRUCTION 半路截个胡,执行自己想要的跟踪函数后,再将处理流程还原回原来的指令继续进行。
四、总结
今天的文章中,咱们分了三部分来介绍。
首先第一部分咱们聊了聊 Linux 跟踪技术这个话题。perf、ftrace、trace-cmd,eBPF,BCC、bpftrace 等工具都算是跟踪这个范畴的工具。这些工具可以帮助我们观测系统运行状态,帮助分析系统的性能瓶颈。不管是哪种工具,其实底层都是依赖 tracepoint、kprobe 等底层的机制来工作的。
第二部分我们演示一下如何跟踪内核函数调用,以及查看调用栈。这里我用到了 ftrace 和 perf 工具。perf 的 -g 选项不但能查看到函数的名字,而且还能追踪其调用链路,非常实用。
第三部分我们从内核视角聊了聊 tracepoint 和 kprobes 是如何实现的。这两个技术听起来唬人,但其实原理都非常的简单。tracepoint 只不过是在内核函数中插入了一些钩子而已。kprobe 是在内核运行过程中动态地替换要跟踪的函数指令为 BREAKPOINT 指令。这个指令触发一段运行逻辑执行跟踪工作后,再跳回原来的函数来执行。仅此而已。
本文提到的部分内容在咱们的《深入理解Linux进程与内存》中也有设计,也欢迎入手纸质版。
最后,欢迎转发和关注!