Ftrace 进阶用法

Liu Lichao 创作于 2021/03/03

By 法海 of TinyLab.org Jan 23, 2021

前言

本文为 Ftrace 系列文章第二篇，描述 Ftrace 进阶用法。上一篇文章中我们接触到了 Ftrace 基本概念，知道了如何 trace 一个函数，知道了如何 enable 一个 trace event。

同时，上一篇文章也遗留了几个问题：

某个函数被谁调用？调用栈是什么？
如何跟踪某个进程？如何跟踪一个命令，但是这个命令执行时间很短？
用户态的行为轨迹如何与内核中的 trace 联系到一起？
如何跟踪过滤多个进程？多个函数？
如何灵活控制 trace 的开关？

本文将一一解答上述问题。

查看函数调用栈

查看函数调用栈是内核调试最最基本得需求，常用方法：

函数内部添加 WARN_ON(1)
ftrace

trace 函数的时候，设置 echo 1 > options/func_stack_trace 即可在 trace 结果中获取追踪函数的调用栈。

以 dev_attr_show 函数为例，看看 ftrace 如何帮我们获取调用栈：

$ cd /sys/kernel/debug/tracing
$ sudo -s
# echo 0 > tracing_on
# echo function > current_tracer
# echo dev_attr_show > set_ftrace_filter

// 设置 func_stack_trace
# echo 1 > options/func_stack_trace

# echo 1 > tracing_on

# cat trace

# tracer: function
#
# entries-in-buffer/entries-written: 8/8   #P:4
#
#                                _-----=> irqs-off
#                               / _----=> need-resched
#                              | / _---=> hardirq/softirq
#                              || / _--=> preempt-depth
#                              ||| /     delay
#           TASK-PID     CPU#  ||||   TIMESTAMP  FUNCTION
#              | |         |   ||||      |         |
             top-3008    [003] ....   621.507777: dev_attr_show <-sysfs_kf_seq_show
             top-3008    [003] ....   621.507784: <stack trace>
 => dev_attr_show
 => sysfs_kf_seq_show
 => kernfs_seq_show
 => seq_read
 => kernfs_fop_read
 => __vfs_read
 => vfs_read
 => ksys_read
 => __x64_sys_read
 => do_syscall_64
 => entry_SYSCALL_64_after_hwframe
 => 0
 => 0
 => 0
 => 0
 => 0
 => 0
 => 0
 => 0

如何跟踪一个命令，但是这个命令执行时间很短？

首先我们介绍一下 ftrace 过滤控制相关文件：

文件名	功能
set_ftrace_filter	function tracer 只跟踪某个函数
set_ftrace_notrace	function tracer 不跟踪某个函数
set_graph_function	function_graph tracer 只跟踪某个函数
set_graph_notrace	function_graph tracer 不跟踪某个函数
set_event_pid	trace event 只跟踪某个进程
set_ftrace_pid	function/function_graph tracer 只跟踪某个进程

如果这时候问：如何跟踪某个进程内核态的某个函数？

答案是肯定的，将被跟踪进程的 pid 设置到 set_event_pid/set_ftrace_pid 文件即可。

但是如果问题变成了，我要调试 kill 的内核执行流程，如何办呢？

因为 kill 运行时间很短，我们不能知道它的 pid，所以就没法过滤了。

调试这种问题的小技巧，即 脚本化，这个技巧在很多地方用到：

sh -c "echo $$ > set_ftrace_pid; echo 1 > tracing_on; kill xxx; echo 0 > tracing_on"

PS：请在这里面加上你需要过滤的函数或其它设置

过滤技巧 - 如何跟踪过滤多个进程？多个函数？

情景1：函数名雷同，可以使用正则匹配

# cd /sys/kernel/debug/tracing
# echo 'dev_attr_*' > set_ftrace_filter
# cat set_ftrace_filter
dev_attr_store
dev_attr_show

情景2：追加某个函数

用法为：echo xxx >> set_ftrace_filter，例如，先设置 dev_attr_*：

# cd /sys/kernel/debug/tracing
# echo 'dev_attr_*' > set_ftrace_filter
# cat set_ftrace_filter
dev_attr_store
dev_attr_show

再将 ip_rcv 追加到跟踪函数中：

# cd /sys/kernel/debug/tracing
# echo ip_rcv >> set_ftrace_filter
# cat set_ftrace_filter
dev_attr_store
dev_attr_show
ip_rcv

情景3：基于模块过滤

格式为：<function>:<command>:<parameter>，例如，过滤 ext3 module 的 write* 函数：

$ echo 'write*:mod:ext3' > set_ftrace_filter

情景4：从过滤列表中删除某个函数，使用“感叹号”

感叹号用来移除某个函数，把上面追加的 ip_rcv 去掉：

# cd /sys/kernel/debug/tracing
# cat set_ftrace_filter
dev_attr_store
dev_attr_show
ip_rcv
# echo '!ip_rcv' >> set_ftrace_filter
# cat set_ftrace_filter
dev_attr_store
dev_attr_show

PS：上述所有涉及通配符的操作最好都加上单引号。

用户态内核态联动

有些问题是需要将用户态、内核态的行为联系在一起的，但是 printf/printk 天然是分家的，如何办？

答案是 trace_marker，用户态程序只需要打开 trace_marker 节点可以向其中写入内容，写入的内容会体现在 trace 文件中，与内核态的各种 trace 融合在一起，提供时间线、事件参考。

# cd /sys/kernel/debug/tracing
# echo 'hello ftrace' > trace_marker
# cat trace

# tracer: nop
#
# entries-in-buffer/entries-written: 1/1   #P:4
#
#                                _-----=> irqs-off
#                               / _----=> need-resched
#                              | / _---=> hardirq/softirq
#                              || / _--=> preempt-depth
#                              ||| /     delay
#           TASK-PID     CPU#  ||||   TIMESTAMP  FUNCTION
#              | |         |   ||||      |         |
           <...>-2157    [001] ....  1227.772963: tracing_mark_write: hello ftrace

灵活控制 trace 开关

用户态

用户态程序可以很灵活的控制 trace 开关，因为可以在程序中打开 tracing_on 文件，灵活控制何时 enable，何时 disable。

内核态

如何在跟踪内核函数的时候灵活控制 trace enable/disable 呢？

首先明确这件事的意义：根据条件及时停止，更准确获取现场信息，同时防止后面的无效信息冲掉有效信息。

这种功能是通过 set_ftrace_filter 实现的，控制范式：<function>:<command>:<parameter>

简单示例：遇到 __schedule_bug 函数后关闭 trace

# echo '__schedule_bug:traceoff' > set_ftrace_filter

除了 traceoff 外，set_ftrace_filter 还支持其它的关键字，感兴趣的请阅读：filter-commands

前端工具

Ftrace 提供了 trace 能力，但是使用起来还是有点麻烦，所以有一些前端工具，一来方便大家使用，比如 trace-cmd，二来将许多调试能力大一统，比如 perf/bcc。

下一篇，我们来简单介绍下 ftrace 前端工具。