4. function tracer:开启function tracer、设置set_ftrace_filter/set_ftrace_notrace、查看函数调用日志。
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 之间的函数调用序列。如果发现某个函数耗时异常(通过时间戳差值计算),则可能是中断处理时延的瓶颈。