📚 课程目录第4章 function tracer

4. function tracer

Function tracer 是 Ftrace 中最基础、最常用的追踪器之一。它能够记录内核中每一个函数的调用入口和返回，生成完整的函数调用链日志。对于理解内核执行路径、定位异常函数调用、分析调度时延的源头，Function tracer 是不可或缺的工具。

适用场景： 当需要追踪“某个中断处理函数调用了哪些内核函数”、“某个系统调用在内核中的完整执行路径”或“某个驱动模块的初始化流程”时，Function tracer 是最直接的选择。

4.1 开启 function tracer

开启 function tracer 的流程分为三步：挂载 tracefs、选择追踪器、开启追踪。以下为具体操作步骤：

挂载 tracefs： 确保 tracefs 文件系统已挂载到 /sys/kernel/tracing 或 /sys/kernel/debug/tracing。
选择追踪器： 将 function 写入 current_tracer 文件。
开启追踪： 将 1 写入 tracing_on 文件。

# 挂载 tracefs（如未挂载）
mount -t tracefs tracefs /sys/kernel/tracing

# 进入 tracing 目录
cd /sys/kernel/tracing

# 选择 function tracer
echo function > current_tracer

# 开启追踪
echo 1 > tracing_on

# 执行需要追踪的操作（例如触发一个中断或系统调用）
# ...

# 关闭追踪
echo 0 > tracing_on

# 查看追踪结果
cat trace

  验证是否成功： 执行 cat current_tracer 应返回 function。执行 cat tracing_on 应返回 1。

以下 SVG 展示了开启 function tracer 的完整流程与内核中的数据结构交互：

4.2 设置 set_ftrace_filter / set_ftrace_notrace

默认情况下，function tracer 会追踪内核中所有可追踪的函数，这会产生海量日志，导致性能严重下降且难以分析。通过 set_ftrace_filter 和 set_ftrace_notrace 文件，可以精确控制追踪范围。

控制文件	作用	匹配规则	示例
`set_ftrace_filter`	白名单：仅追踪匹配的函数	支持通配符 `*`、`?`、`[abc]`	`echo 'irq_*' > set_ftrace_filter`
`set_ftrace_notrace`	黑名单：排除匹配的函数	支持通配符 `*`、`?`、`[abc]`	`echo 'schedule' > set_ftrace_notrace`

注意事项： 过滤规则基于函数名进行字符串匹配。如果同时设置了 filter 和 notrace，则 notrace 的优先级更高。修改过滤文件后，需要重新开启追踪（echo 1 > tracing_on）才能生效。

4.2.1 使用 set_ftrace_filter 精确追踪

以下示例演示如何仅追踪与中断处理相关的函数：

# 清空之前的过滤规则
echo > set_ftrace_filter

# 设置只追踪以 "irq_" 开头的函数
echo 'irq_*' > set_ftrace_filter

# 查看当前过滤规则
cat set_ftrace_filter
# 输出示例：
# irq_enter
# irq_exit
# irq_handler_entry
# irq_handler_exit
# ...

4.2.2 使用 set_ftrace_notrace 排除干扰

当需要追踪大部分函数，但想排除某些高频或已知无问题的函数时，使用黑名单：

# 排除 schedule 和 preempt_schedule 函数
echo 'schedule' > set_ftrace_notrace
echo 'preempt_schedule' >> set_ftrace_notrace

# 查看当前排除列表
cat set_ftrace_notrace

调试技巧： 在中断上下文调试中，建议先使用 echo 'handle_*' > set_ftrace_filter 或 echo 'irq_*' > set_ftrace_filter 缩小范围，避免日志爆炸。

以下 SVG 展示了 filter 与 notrace 的匹配逻辑：

4.3 查看函数调用日志

完成追踪后，可以通过 trace 文件查看原始日志，或通过 trace_pipe 实时查看流式输出。

4.3.1 查看静态日志

# 查看完整追踪日志
cat trace | head -50

# 输出示例：
# # tracer: function
# #
# # entries-in-buffer/entries-written: 1423/1423   #P:4
# #
# #                              _-----=> irqs-off
# #                             / _----=> need-resched
# #                            | / _---=> hardirq/softirq
# #                            || / _--=> preempt-depth
# #                            ||| /     delay
# #           TASK-PID   CPU#  ||||   TIMESTAMP  FUNCTION
# #              | |       |   ||||      |         |
#       swapper/0-0     [000] d..h. 123.456789: irq_enter
#       swapper/0-0     [000] d..h. 123.456790: handle_irq_event
#       swapper/0-0     [000] d..h. 123.456791: _raw_spin_lock
#       swapper/0-0     [000] d..h. 123.456792: __do_softirq
#       ...

4.3.2 实时流式输出

# 实时查看追踪日志（阻塞式，适合动态调试）
cat trace_pipe

  日志字段解读：
  TASK-PID： 当前进程名和 PID。
CPU#： 运行在哪个 CPU 上。
irqs-off： d 表示中断关闭，. 表示中断开启。
need-resched： N 表示需要重新调度，. 表示不需要。
hardirq/softirq： h 表示硬中断上下文，s 表示软中断上下文。
preempt-depth： 抢占深度计数。
TIMESTAMP： 函数调用时的时间戳。
FUNCTION： 被调用的函数名。

以下 SVG 展示了 function tracer 日志的典型结构：

4.4 实战案例：追踪中断处理函数调用链

以下是一个完整的实战案例，演示如何利用 function tracer 追踪一次中断处理过程：

# 1. 设置过滤规则，只追踪中断相关函数
echo 'irq_*' > set_ftrace_filter
echo 'handle_*' >> set_ftrace_filter

# 2. 开启追踪
echo 1 > tracing_on

# 3. 触发一个中断（例如通过网卡发包或按键）
# 这里模拟触发一个软中断
echo 1 > /proc/irq/1/smp_affinity

# 4. 关闭追踪
echo 0 > tracing_on

# 5. 查看日志
cat trace | head -30

# 输出示例：
#       swapper/0-0     [000] d..h. 124.001234: irq_enter
#       swapper/0-0     [000] d..h. 124.001235: handle_irq_event
#       swapper/0-0     [000] d..h. 124.001236: _raw_spin_lock
#       swapper/0-0     [000] d..h. 124.001237: handle_edge_irq
#       swapper/0-0     [000] d..h. 124.001238: irq_finalize_oneshot
#       swapper/0-0     [000] d..h. 124.001239: irq_exit

分析要点： 关注 irq_enter 到 irq_exit 之间的函数调用序列。如果发现某个函数耗时异常（通过时间戳差值计算），则可能是中断处理时延的瓶颈。