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_ullmintreport-tray-6561    [003] ...1. 23204.688260: seq_put_decimal_ull <-do_task_statmintreport-tray-6561    [003] ...1. 23204.688260: seq_put_decimal_ull_width <-seq_put_decimal_ullmintreport-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_MMUstruct 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 实现原理与开发实践