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 實現原理與開發實踐