Linux ftrace 内核跟踪入门
文章目录
- ftrace介绍
- 开启ftrace
- ftrace使用
- ftrace跟踪指定内核函数
- ftrace跟踪指定pid
- ftrace原理
- ftrace与strace
- trace-cmd 工具
- KernelShark
- 参考
ftrace介绍
Ftrace is an internal tracer designed to help out developers and designers of systems to find what is going on inside the kernel. It can be used for debugging or analyzing latencies and performance issues that take place outside of user-space.
ftrace 是内建于 Linux 内核的跟踪工具，从 2.6.27 开始加入主流内核。使用 ftrace 可以调试或者分析内核中发生的事情。ftrace 提供了不同的跟踪器，以用于不同的场合，比如跟踪内核函数调用、对上下文切换进行跟踪、查看中断被关闭的时长、跟踪内核态中的延迟以及性能问题等。系统开发人员可以使用 ftrace 对内核进行跟踪调试，以找到内核中出现的问题的根源，方便对其进行修复。
使用环境：Linux linuxdev 6.8.0-52-generic #53-Ubuntu SMP PREEMPT_DYNAMIC Sat Jan 11 00:06:25 UTC 2025 x86_64 x86_64 x86_64 GNU/Linux
开启ftrace
一般的linux发行版都已经开启了ftrace支持，
最基础的是这几个选项：
- CONFIG_FTRACE --> “Tracers”
- CONFIG_FUNCTION_TRACER --> Kernel Function Tracer
- CONFIG_FUNCTION_GRAPH_TRACER --> Kernel Function Graph Tracer
- CONFIG_DYNAMIC_FTRACE --> enable/disable function tracing dynamically
更多的选项可以查看内核trace模块的makefile和kconfig文件：kernel/trace/Makefile、kernel/trace/Kconfig。
ftrace 使用 tracefs 文件系统来保存控制文件以及用于显示输出的文件，启用ftrace功能后，默认会挂载出来，目前的环境上是在：tracefs /sys/kernel/tracing tracefs rw,nosuid,nodev,noexec,relatime 0 0
查看tracefs挂载点下面的内容：
$ sudo ls /sys/kernel/tracing
available_events current_tracer hwlat_detector printk_formats set_event_pid stack_max_size trace_marker tracing_thresh
available_filter_functions dynamic_events instances README set_ftrace_filter stack_trace trace_marker_raw uprobe_events
available_filter_functions_addrs dyn_ftrace_total_info kprobe_events rv set_ftrace_notrace stack_trace_filter trace_options uprobe_profile
available_tracers enabled_functions kprobe_profile saved_cmdlines set_ftrace_notrace_pid synthetic_events trace_pipe user_events_data
buffer_percent error_log max_graph_depth saved_cmdlines_size set_ftrace_pid timestamp_mode trace_stat user_events_status
buffer_size_kb events options saved_tgids set_graph_function touched_functions tracing_cpumask
buffer_subbuf_size_kb free_buffer osnoise set_event set_graph_notrace trace tracing_max_latency
buffer_total_size_kb function_profile_enabled per_cpu set_event_notrace_pid snapshot trace_clock tracing_on
tracing目录（/sys/kernel/tracing）中的文件控制着跟踪的能力。根据你在内核配置时的选项的不同，这里列的文件可能稍有差异。你可以在内核源代码目录下Documentation/trace目录中找到这些文件的信息。
下面介绍几个重要的文件：
- available_tracers
该文件列出所有当前内核支持的tracer
# cat available_tracers
timerlat osnoise hwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop
- current_tracer
该文件指出当前正在运行的tracer
# cat current_tracer
nop
- trace -> Contains the tracing data in human readable format
该文件包含可阅读的tracing数据
# cat trace
# tracer: nop
#
# entries-in-buffer/entries-written: 0/0 #P:4
#
# _-----=> irqs-off/BH-disabled
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / _-=> migrate-disable
# |||| / delay
# TASK-PID CPU# ||||| TIMESTAMP FUNCTION
# | | | ||||| | |
- tracing_on
该文件开启/关闭输出tracing数据到ring buffer（ftrace使用单独的ring buffer来存储tracing数据）
# cat tracing_on
1
ftrace使用
ftrace一般使用步骤：
- 写入一些特定文件以启用 / 禁用tracing。
- 写入一些特定文件以设置 / 取消设置过滤器以微调tracing。
- 根据步骤 1 和 2 从文件中读取生成的tracing输出。
- 清除文件中的早期输出或缓冲区。
- 缩小到你的特定用例（要跟踪的内核函数）并重复步骤 1、2、3、4。
指定某个tracer，我们只要将该tracer的名称写入current_tracer文件。
# echo function > current_tracer
随后我们可以通过trace或者trace_pipe文件读取输出
# cat trace | head -20
# tracer: function
#
# entries-in-buffer/entries-written: 205023/41961107 #P:4
#
# _-----=> irqs-off/BH-disabled
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / _-=> migrate-disable
# |||| / delay
# TASK-PID CPU# ||||| TIMESTAMP FUNCTION
# | | | ||||| | |
mintreport-tray-6561 [003] ...1. 23204.688260: seq_put_decimal_ull_width <-seq_put_decimal_ull
mintreport-tray-6561 [003] ...1. 23204.688260: seq_put_decimal_ull <-do_task_stat
mintreport-tray-6561 [003] ...1. 23204.688260: seq_put_decimal_ull_width <-seq_put_decimal_ull
mintreport-tray-6561 [003] ...1. 23204.688260: seq_put_decimal_ull <-do_task_stat
##### CPU 2 buffer started ####
<idle>-0 [002] d.h2. 23204.749361: __sysvec_apic_timer_interrupt <-sysvec_apic_timer_interrupt
<idle>-0 [002] d.h2. 23204.749362: hrtimer_interrupt <-__sysvec_apic_timer_interrupt
<idle>-0 [002] d.h2. 23204.749362: _raw_spin_lock_irqsave <-hrtimer_interrupt
如果你想关闭该tracer，直接将nop写入current_tracer文件即可。
function_graph是一种替代的函数跟踪器，它不仅跟踪函数入口，还跟踪函数的返回，允许你创建函数流的调用图，并以类似 C 语言的风格输出跟踪数据，其中包含每个函数的持续时间信息。
# cat trace | head -20
# tracer: function_graph
#
# CPU DURATION FUNCTION CALLS
# | | | | | | |
2) 0.151 us | } /* seq_printf */
2) 0.152 us | seq_printf();
2) 0.152 us | seq_printf();
2) 0.149 us | seq_printf();
2) 0.112 us | _raw_spin_lock_irqsave();
2) 0.153 us | seq_printf();
2) 0.160 us | seq_printf();
2) 0.159 us | seq_printf();
2) 0.153 us | seq_printf();
2) 0.156 us | seq_printf();
2) 0.111 us | seq_putc();
2) 0.112 us | _raw_spin_unlock_irqrestore();
2) 0.117 us | __rcu_read_unlock();
2) 4.759 us | } /* show_interrupts */
2) 0.109 us | int_seq_next();
2) 0.109 us | int_seq_stop();
ftrace跟踪指定内核函数
available_filter_functions文件展示了ftrace支持的跟踪内核函数的集合，我们可以从这里寻找需要跟踪的内核函数，或者自己指定。
# grep fork available_filter_functions
ret_from_fork
__do_sys_fork
__do_sys_vfork
tsk_fork_get_node
__traceiter_sched_process_fork
__probestub_sched_process_fork
__sched_fork
sched_fork
sched_cgroup_fork
sched_post_fork
sched_mm_cid_fork
task_fork_fair
task_fork_dl
sched_core_fork
sched_autogroup_fork
timens_on_fork
cgroup_css_set_put_fork
cgroup_fork
cgroup_cancel_fork
cgroup_post_fork
cgroup_css_set_fork
cgroup_can_fork
freezer_fork
pids_cancel_fork
pids_can_fork
cpuset_cancel_fork
cpuset_can_fork
cpuset_fork
perf_event_fork
anon_vma_fork
mem_cgroup_fork
tty_audit_fork
register_random_vmfork_notifier
unregister_random_vmfork_notifier
add_vmfork_randomness
proc_fork_connector
尝试跟踪__do_sys_fork函数，很遗憾目前环境中的内核在创建进程时不使用该函数，而是使用kernel_clone这个函数
#ifdef __ARCH_WANT_SYS_FORK
SYSCALL_DEFINE0(fork)
{
#ifdef CONFIG_MMU
struct kernel_clone_args args = {
.exit_signal = SIGCHLD,
};
return kernel_clone(&args);
#else
/* can not support in nommu mode */
return -EINVAL;
#endif
}
#endif
查找该函数：
# grep kernel_clone /sys/kernel/tracing/available_filter_functions
kernel_clone
跟踪该函数：
root@linuxdev:/sys/kernel/tracing# echo nop >current_tracer
root@linuxdev:/sys/kernel/tracing# echo kernel_clone>set_graph_function
root@linuxdev:/sys/kernel/tracing# echo function_graph >current_tracer
root@linuxdev:/sys/kernel/tracing# cat trace
# tracer: function_graph
#
# CPU DURATION FUNCTION CALLS
# | | | | | | |
0) | kernel_clone() {
0) # 1520.654 us | copy_process();
0) 2.568 us | add_device_randomness();
0) 1.289 us | get_task_pid();
0) 0.757 us | pid_vnr();
0) 0.673 us | _raw_spin_lock();
0) 3.660 us | lru_gen_add_mm();
0) 0.690 us | _raw_spin_unlock();
0) + 47.696 us | wake_up_new_task();
0) 1.016 us | put_pid();
0) # 1592.533 us | }
1) | ret_from_fork() {
1) ! 122.284 us | schedule_tail();
1) 0.859 us | syscall_exit_to_user_mode_prepare();
1) 0.638 us | mem_cgroup_handle_over_high();
1) 0.666 us | blkcg_maybe_throttle_current();
1) + 60.708 us | __rseq_handle_notify_resume();
1) 0.768 us | fpregs_assert_state_consistent();
1) 1.831 us | switch_fpu_return();
1) ! 197.731 us | }
3) | kernel_clone() {
3) # 1391.121 us | copy_process();
3) 2.695 us | add_device_randomness();
3) 1.232 us | get_task_pid();
3) 0.783 us | pid_vnr();
3) 0.669 us | _raw_spin_lock();
3) 3.709 us | lru_gen_add_mm();
3) 0.654 us | _raw_spin_unlock();
3) + 54.441 us | wake_up_new_task();
3) 1.083 us | put_pid();
3) # 1469.054 us | }
------------------------------------------
0) bash-7769 => cat-8888
------------------------------------------
0) | ret_from_fork() {
0) + 69.115 us | schedule_tail();
0) 0.804 us | syscall_exit_to_user_mode_prepare();
0) 0.689 us | mem_cgroup_handle_over_high();
0) 0.677 us | blkcg_maybe_throttle_current();
0) + 37.261 us | __rseq_handle_notify_resume();
0) 0.756 us | fpregs_assert_state_consistent();
0) 1.950 us | switch_fpu_return();
0) ! 120.873 us | }
ftrace跟踪指定pid
# echo $PID > set_ftrace_pid
以监控top进程为例：
# pidof top
8963
# echo 8963 > set_ftrace_pid
# cat trace | head -30
# tracer: function
#
# entries-in-buffer/entries-written: 13655/8126400 #P:4
#
# _-----=> irqs-off/BH-disabled
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / _-=> migrate-disable
# |||| / delay
# TASK-PID CPU# ||||| TIMESTAMP FUNCTION
# | | | ||||| | |
top-8963 [001] d..2. 27383.603413: <stack trace>
=> 0xffffffffc12840ad
=> _raw_spin_unlock
=> finish_task_switch.isra.0
=> __schedule
=> __cond_resched
=> mutex_lock
=> process_output_block
=> n_tty_write
=> iterate_tty_write
=> file_tty_write.isra.0
=> tty_write
=> vfs_write
=> ksys_write
=> __x64_sys_write
=> x64_sys_call
=> do_syscall_64
=> entry_SYSCALL_64_after_hwframe
需要注意的是每次进行新的tracing的时候需要清除下上一次tracing的配置，如果上次设置了某些过滤条件，那么可能会对本次的tracing结果产生影响
更进一步的使用建议参考Debugging Linux Kernel using ftrace着一系列文章。
ftrace原理
参考Ftrace 实现原理与开发实践
ftrace与strace
参考Ftrace 实现原理与开发实践
他们的底层原理不同，表现出来的区别是ftrace可以跟踪内核中的函数，而strace只能跟踪到系统函数调用。
strace is a utility which allows you to trace the system calls that an application makes. When an application makes a system call, it is basically asking the kernel to do something, eg file access. Use the command man strace to get strace documentation and man syscalls to get information on system calls.
ftrace is a tool used during kernel development and allows the developer to see what functions are being called within the kernel.
参考这张著名的linux性能分析工具图：
trace-cmd 工具
trace-cmd工具是Steven Rostedt创建的用于ftrace的命令行工具。
KernelShark
KernelShark是一个图形工具，作为一个前端来处理trace-cmd工具生成的tracing数据——trace.dat。
参考
ftrace - Function Tracer
Debugging Linux Kernel using ftrace
Analyze the Linux kernel with ftrace
从Ftrace开始内核探索之旅
Tracing the Linux kernel with ftrace
Debugging the kernel using Ftrace - part 1
Debugging the kernel using Ftrace - part 2
Secrets of the Ftrace function tracer
Using KernelShark to analyze the real-time scheduler
Ftrace Kernel Hooks: More than just tracing
ftrace系统实现原理
Linux性能工具(二)ftrace基础篇
linux性能分析工具–ftrace的原理与使用
Linux内核性能调试工具之ftrace
Ftrace 实现原理与开发实践