4. function tracer:追踪所有内核函数调用,理解调用链,使用 set_ftrace_filter
好,咱们继续往下走。前面几章我们聊了 function_graph tracer,看到了函数间的调用关系图。但有时候,你不需要那么花哨的图表,你只想简单粗暴地知道:某个函数到底有没有被调用?被调用了多少次?
这时候,function tracer 就该登场了。它比 function_graph 更轻量,只记录函数入口和出口,不画调用树。说白了,它就是个“函数调用计数器”加上“调用栈记录器”。
function tracer 是什么?
function tracer 是 Ftrace 家族里最基础、最常用的一个 tracer。它会在每个内核函数的入口和出口处插入钩子,记录下调用信息。你可以用它来:
- 确认某个函数是否被执行
- 统计函数的调用次数
- 追踪函数的调用路径(调用链)
- 定位性能热点
我个人习惯在排查“某个功能是否生效”时,第一个想到的就是 function tracer。比如,我怀疑某个驱动没加载成功,直接 trace 它的 probe 函数,看有没有被调用,一目了然。
如何启用 function tracer
启用方式很简单,跟其他 tracer 一样:
# 切换到 function tracer
echo function > /sys/kernel/debug/tracing/current_tracer
# 查看当前 tracer
cat /sys/kernel/debug/tracing/current_tracer
然后你就可以查看 trace 输出了:
cat /sys/kernel/debug/tracing/trace
输出大概长这样:
# 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
# | | | |||| | |
<idle>-0 [000] d..1 123.456789: _raw_spin_lock <- tick_nohz_idle_enter
<idle>-0 [000] d..1 123.456790: tick_nohz_idle_enter <- cpu_idle_loop
<idle>-0 [000] d..1 123.456791: rcu_idle_enter <- tick_nohz_idle_enter
嗯,这里要注意:默认情况下,function tracer 会追踪所有内核函数。这意味着你的 trace 输出会非常庞大,几秒钟就能刷出几万行。所以,我们通常需要配合 set_ftrace_filter 来缩小范围。
set_ftrace_filter:精准控制追踪范围
这是 function tracer 最强大的功能之一。通过 set_ftrace_filter,你可以指定只追踪某些函数,或者排除某些函数。
基本用法
# 只追踪 do_sys_open 函数
echo do_sys_open > /sys/kernel/debug/tracing/set_ftrace_filter
# 查看当前过滤规则
cat /sys/kernel/debug/tracing/set_ftrace_filter
设置之后,再启用 function tracer,trace 输出里就只会包含 do_sys_open 的调用记录了。
支持通配符
你可以用 * 通配符来匹配一组函数:
# 追踪所有以 "ext4_" 开头的函数
echo ext4_* > /sys/kernel/debug/tracing/set_ftrace_filter
# 追踪所有包含 "tcp" 的函数
echo *tcp* > /sys/kernel/debug/tracing/set_ftrace_filter
我曾经在排查一个 ext4 文件系统的性能问题时,就用 ext4_* 过滤出了所有 ext4 相关的函数调用,然后发现某个写操作频繁调用 ext4_journal_start,最终定位到是日志提交过于频繁导致的性能瓶颈。
多函数过滤
你也可以一次指定多个函数,用空格或换行分隔:
# 方式一:空格分隔
echo "do_sys_open do_sys_close vfs_read" > /sys/kernel/debug/tracing/set_ftrace_filter
# 方式二:逐行添加
echo do_sys_open >> /sys/kernel/debug/tracing/set_ftrace_filter
echo do_sys_close >> /sys/kernel/debug/tracing/set_ftrace_filter
echo vfs_read >> /sys/kernel/debug/tracing/set_ftrace_filter
排除某些函数
有时候你只想排除少数几个函数,可以用 set_ftrace_notrace:
# 不追踪 schedule 和 preempt_schedule
echo schedule > /sys/kernel/debug/tracing/set_ftrace_notrace
echo preempt_schedule >> /sys/kernel/debug/tracing/set_ftrace_notrace
为什么需要排除?因为 schedule 这类函数调用太频繁了,会刷屏,而且对性能影响较大。我在做生产环境性能分析时,通常会先把 schedule、preempt_schedule、_raw_spin_lock 这些高频函数排除掉,否则 trace 输出里全是它们,根本看不清真正关心的函数。
理解调用链
function tracer 的输出里,每一行都包含了一个关键信息:调用者。格式是 被调函数 <- 调用者。
比如:
tick_nohz_idle_enter <- cpu_idle_loop
这表示 cpu_idle_loop 调用了 tick_nohz_idle_enter。
通过这种“被调函数 <- 调用者”的链式关系,你可以反向推导出完整的调用路径。举个例子,如果你看到:
do_sys_open <- SyS_open
SyS_open <- do_syscall_64
do_syscall_64 <- entry_SYSCALL_64
那么调用链就是:
entry_SYSCALL_64 → do_syscall_64 → SyS_open → do_sys_open
这比 function_graph 的树形结构更简洁,适合快速定位“谁调用了谁”。
实际案例:追踪文件打开操作
假设你想知道系统里谁在频繁打开文件,可以这样做:
# 1. 设置过滤
echo do_sys_open > /sys/kernel/debug/tracing/set_ftrace_filter
# 2. 启用 tracer
echo function > /sys/kernel/debug/tracing/current_tracer
# 3. 等待几秒,收集数据
sleep 5
# 4. 查看结果
cat /sys/kernel/debug/tracing/trace | head -50
输出可能类似:
bash-1234 [001] .... 456.789012: do_sys_open <- SyS_open
nginx-5678 [002] .... 456.789015: do_sys_open <- SyS_open
nginx-5678 [002] .... 456.789018: do_sys_open <- SyS_open
java-9012 [003] .... 456.789020: do_sys_open <- SyS_open
你看,哪个进程在调用 do_sys_open,一目了然。如果某个进程调用特别频繁,那它可能就是文件打开操作的性能瓶颈所在。
trace_pipe 配合 wc -l 来计数:
cat /sys/kernel/debug/tracing/trace_pipe | wc -l
或者用 perf 的统计功能,但那是后话了。
注意事项
- 先用
set_ftrace_filter缩小范围 - 控制追踪时间,不要长时间开启
- 观察系统负载变化,必要时停止追踪
总结
function tracer 是 Ftrace 里最基础、最实用的工具之一。它简单直接,配合 set_ftrace_filter 可以做到精准追踪。我个人觉得,它是排查“函数是否被调用”这类问题的首选方案。
下一章,我们会聊聊如何用 Ftrace 分析调度延迟,看看进程切换到底花了多少时间。到时候,function tracer 和 function_graph tracer 都会派上用场。