一、ftrace介绍
本文基于Rockpi 4A单板Linux 4.4内核介绍ftrace的使用方法，其它内核版本的ftrace使用方法类似。
ftrace(Function Tracer)是直接内置在Linux内核的跟踪程序，作为一个内部的tracer提供给系统的开发者和设计者，帮他们弄清内核正在发生的行为，用于调试或分析用户空间之外的延迟和性能问题。
ftrace是内核态的strace，用于追踪内核态的调用记录，功能比strace强大。ftrace最开始是一个函数跟踪器，主要用于记录内核函数的运行轨迹。随着功能的增加，演变成一个跟踪框架，包括：用延迟跟踪来检查中断禁用和启用之间发生的情况、抢占和从任务被唤醒到任务实际调度的时间。
整个ftrace框架可以分为几部分：ftrace核心框架，RingBuffer，debugfs，Tracepoint和各种Tracer。见下图：
image.png
二、ftrace内核配置
1、内核配置
ftrace Linux内核驱动配置方法如下：
使用make ARCH=arm64 menuconfig命令，进入如下配置界面：
image.png
选择
Kernel hacking -> Tracers，进入如下配置界面：
image.png
在
Branch Profiling (Trace likely/unlikely profiler)中，可以选择相关的Branch Profiling，配置如下：
image.png
ftrace内核代码路径：kernel/trace/，相关驱动文件如下：
root@ubuntu:/home/run/code/rockchip-bsp/kernel/kernel/trace# ls *.c
blktrace.c power-traces.c trace_benchmark.c trace_event_perf.c trace_export.c trace_kdb.c trace_output.c trace_sched_wakeup.c trace_stack.c
bpf_trace.c ring_buffer_benchmark.c trace_branch.c trace_events.c trace_functions.c trace_kprobe.c trace_printk.c trace_selftest.c trace_stat.c
ftrace.c ring_buffer.c trace.c trace_events_filter.c trace_functions_graph.c trace_mmiotrace.c trace_probe.c trace_selftest_dynamic.c trace_syscalls.c
gpu-traces.c rpm-traces.c trace_clock.c trace_events_trigger.c trace_irqsoff.c trace_nop.c trace_sched_switch.c trace_seq.c trace_uprobe.c
2、ftrace路径
单板系统启动后，ftrace 通过 debugfs向用户态提供访问接口。相关接口如下：
root@xiaotianbsp:/sys/kernel/debug/tracing# ls
README options stack_max_size
available_events per_cpu stack_trace
available_filter_functions printk_formats stack_trace_filter
available_tracers saved_cmdlines trace
buffer_size_kb saved_cmdlines_size trace_clock
buffer_total_size_kb saved_tgids trace_marker
current_tracer set_event trace_options
dyn_ftrace_total_info set_event_pid trace_pipe
enabled_functions set_ftrace_filter trace_stat
events set_ftrace_notrace tracing_cpumask
free_buffer set_ftrace_pid tracing_max_latency
function_profile_enabled set_graph_function tracing_on
instances set_graph_notrace tracing_thresh
max_graph_depth snapshot
ftrace部分节点含义如下：
1）available_filter_functions
可跟踪的所有函数列表，不在其中的函数无法跟踪。
2）available_tracers
可用跟踪器。
3）current_tracer
当前使用的跟踪器。
4）function_profile_enabled
函数性能分析器，打开后，trace_stat/目录下会显示function的统计信息。
5）max_graph_depth
显示函数最大调用深度，在后续实例中解释。
6）set_ftrace_filter
设置跟踪的函数列表，支持批量设置，如*ios。
7）set_ftrace_notrace
设置不跟踪的函数列表。
8）set_ftrace_pid
设置跟踪进程的pid，可查看用户空间接口使用内核的函数调用关系。
9）trace
跟踪的输出（Ring buffer）。
10）trace_pipe
跟踪的输出，提供持续不断的数据流（实时输出）。
11）trace_stat/
函数性能分析的输出目录。
12）tracing_on
控制trace打开和关闭。
上面节点介绍也可通过README查看
root@linaro-alip:/sys/kernel/debug/tracing# cat README
tracing mini-HOWTO:
# echo 0 > tracing_on : quick way to disable tracing
# echo 1 > tracing_on : quick way to re-enable tracing
Important files:
trace - The static contents of the buffer
To clear the buffer write into this file: echo > trace
trace_pipe - A consuming read to see the contents of the buffer
current_tracer - function and latency tracers
available_tracers - list of configured tracers for current_tracer
buffer_size_kb - view and modify size of per cpu buffer
buffer_total_size_kb - view total size of all cpu buffers
trace_clock -change the clock used to order events
local: Per cpu clock but may not be synced across CPUs
global: Synced across CPUs but slows tracing down.
counter: Not a clock, but just an increment
uptime: Jiffy counter from time of boot
perf: Same clock that perf events use
...
README对应驱动文件：kernel/trace/trace.c
static const char readme_msg[] =
"tracing mini-HOWTO:\n\n"
"# echo 0 > tracing_on : quick way to disable tracing\n"
"# echo 1 > tracing_on : quick way to re-enable tracing\n\n"
" Important files:\n"
" trace\t\t\t- The static contents of the buffer\n"
"\t\t\t To clear the buffer write into this file: echo > trace\n"
" trace_pipe\t\t- A consuming read to see the contents of the buffer\n"
" current_tracer\t- function and latency tracers\n"
" available_tracers\t- list of configured tracers for current_tracer\n"
" buffer_size_kb\t- view and modify size of per cpu buffer\n"
" buffer_total_size_kb - view total size of all cpu buffers\n\n"
" trace_clock\t\t-change the clock used to order events\n"
" local: Per cpu clock but may not be synced across CPUs\n"
" global: Synced across CPUs but slows tracing down.\n"
" counter: Not a clock, but just an increment\n"
" uptime: Jiffy counter from time of boot\n"
" perf: Same clock that perf events use\n"
....
三、ftrace种类
通过下面的命令可以查看目前系统可用的tracer和目前使用的tracer。
root@xiaotianbsp:/# cd /sys/kernel/debug/tracing/
root@xiaotianbsp:/sys/kernel/debug/tracing# cat available_tracers
blk branch function_graph wakeup_dl wakeup_rt wakeup irqsoff function nop
root@xiaotianbsp:/sys/kernel/debug/tracing# cat current_tracer
nop
tracer有很多类型，主要包括几大类：
1、函数类
1）function
表示函数被调用的流程，类似Linux内核的dump_stack()函数功能，需要配置调用栈（options/func_stack_trace）。
2）function_graph
表示本函数内部的调用实现。
2、延时类
1）irqsoff
当中断被禁止时，系统无法响应外部事件。此时，时钟也无法产生tick中断，意味着系统响应延迟。irqsoff tracer能够跟踪并记录内核中哪些函数禁止了中断，对于对于中断禁止事件最长的，irqsoff将在tracer文件的第一行标出，方便迅速定位造成响应延迟的罪魁祸首。
2）wakeup_rt
跟踪RT类型的任务从获得调度到被唤醒的最长延迟时间。
3）wakeup
跟踪普通优先级进程的调度延迟，即高优先级进程从进入ready状态到获得CPU的延迟时间。该tracer只针对实时进程。
4）preemptoff
跟踪并记录禁止内核抢占的函数，并清晰地显示出禁止抢占时间最长的内核函数。
5）preemptirqsoff
跟踪和记录禁止中断或禁止抢占的内核函数，以及禁止时间最长的函数。
3、其他类
1）blk
跟踪块设备函数。
2）branch
跟踪内核程序中的likely和unlikely分支预测命中率情况。branch tracer能够记录这些分支语句有多少次预测成功，从而优化程序提供线索。
3）nop
不跟踪任务内核活动。将nop写入current_tracer文件可删除之前所用的跟踪器，并清空之前收集到的跟踪信息。
ftrace可用来排查下面问题：
1）特定内核函数调用的频次（function）。
2）内核函数在被调用的过程中路径（调用栈）（function+stack）。
3）内核函数调用的子函数流程（function graph）。
4）由于抢占导致的高延时路径等。
四、ftrace使用方法
ftrace使用方法概括如下：
1）关闭并配置tracer类型
2）配置tracer参数
3）打开并查看tracer内容
1、function
下面介绍如何配置跟踪function功能。
root@xiaotianbsp:~#cd /sys/kernel/debug/tracing/
## 1、配置tracer类型
root@xiaotianbsp:/sys/kernel/debug/tracing# echo 0 > tracing_on
root@xiaotianbsp:/sys/kernel/debug/tracing# cat available_tracers
blk branch function_graph wakeup_dl wakeup_rt wakeup irqsoff function nop
root@xiaotianbsp:/sys/kernel/debug/tracing# echo function > current_tracer
## 2、设置tracer参数
# 跟踪blk_start_request函数
root@xiaotianbsp:/sys/kernel/debug/tracing# echo blk_start_request > set_ftrace_filter
root@xiaotianbsp:/sys/kernel/debug/tracing# echo > trace ## 清ringbuffer
## 3、查看trace
root@xiaotianbsp:/sys/kernel/debug/tracing# cat trace
# tracer: function
#
# entries-in-buffer/entries-written: 0/0 #P:6
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
root@xiaotianbsp:/sys/kernel/debug/tracing# echo 1 > tracing_on
root@xiaotianbsp:/sys/kernel/debug/tracing# cat trace
# tracer: function
#
# entries-in-buffer/entries-written: 0/0 #P:6
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
root@linaro-alip:/sys/kernel/debug/tracing# cat trace
# tracer: function
#
# entries-in-buffer/entries-written: 5/5 #P:6
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
mmcqd/0-157 [004] d... 406.503900: blk_start_request <-blk_fetch_request
mmcqd/0-157 [004] d... 406.504015: blk_start_request <-blk_fetch_request
mmcqd/0-157 [004] d... 406.515351: blk_start_request <-blk_fetch_request
mmcqd/0-157 [004] d... 406.549479: blk_start_request <-blk_fetch_request
mmcqd/0-157 [004] d... 406.599922: blk_start_request <-blk_fetch_request
如果想查看函数调用栈，可增加如下配置：
root@linaro-alip:/sys/kernel/debug/tracing# echo 0 > tracing_on
root@linaro-alip:/sys/kernel/debug/tracing# echo > trace
# 配置函数栈跟踪
root@linaro-alip:/sys/kernel/debug/tracing# echo 1 > options/func_stack_trace
root@linaro-alip:/sys/kernel/debug/tracing# echo 1 > tracing_on
root@linaro-alip:/sys/kernel/debug/tracing# cat trace
# tracer: function
#
# entries-in-buffer/entries-written: 4/4 #P:6
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
mmcqd/0-157 [004] d... 232.540969: blk_start_request <-blk_fetch_request
mmcqd/0-157 [004] d... 232.540978: <stack trace> ## 显示函数调用栈
=> ftrace_ops_no_ops
=> ftrace_graph_call
=> blk_start_request
=> blk_fetch_request
=> mmc_queue_thread
=> kthread
=> ret_from_fork
mmcqd/0-157 [004] d... 232.553196: blk_start_request <-blk_fetch_request
mmcqd/0-157 [004] d... 232.553202: <stack trace>
=> ftrace_ops_no_ops
=> ftrace_graph_call
=> blk_start_request
=> blk_fetch_request
=> mmc_queue_thread
=> kthread
=> ret_from_fork
2、function_graph
下面介绍如何配置跟踪function_graph功能。
root@xiaotianbsp:~#cd /sys/kernel/debug/tracing/
## 1、配置tracer类型
root@xiaotianbsp:/sys/kernel/debug/tracing# echo 0 > tracing_on
root@xiaotianbsp:/sys/kernel/debug/tracing# cat available_tracers
blk branch function_graph wakeup_dl wakeup_rt wakeup irqsoff function nop
root@xiaotianbsp:/sys/kernel/debug/tracing# echo function_graph > current_tracer
## 2、设置tracer参数
root@xiaotianbsp:/sys/kernel/debug/tracing# echo blk_start_request > set_graph_function
root@xiaotianbsp:/sys/kernel/debug/tracing# echo > trace ## 清ringbuffer
## 3、查看trace
root@xiaotianbsp:/sys/kernel/debug/tracing# cat trace
# tracer: function_graph
#
# CPU DURATION FUNCTION CALLS
# | | | | | | |
root@xiaotianbsp:/sys/kernel/debug/tracing# echo 1 > tracing_on
root@xiaotianbsp:/sys/kernel/debug/tracing# cat trace
# tracer: function_graph
#
# CPU DURATION FUNCTION CALLS
# | | | | | | |
4) | blk_start_request() { ## 显示函数内部调用时间
4) 1.166 us | blk_dequeue_request();
4) 0.584 us | blk_add_timer();
4) + 12.250 us | }
4) | blk_start_request() {
4) 1.166 us | blk_dequeue_request();
4) 0.584 us | blk_add_timer();
4) + 12.250 us | }
3、trace pid
下面介绍如何配置跟踪进程pid调用流程功能。
root@xiaotianbsp:~#cd /sys/kernel/debug/tracing/
## 1、配置tracer类型
root@xiaotianbsp:/sys/kernel/debug/tracing# echo 0 > tracing_on
root@xiaotianbsp:/sys/kernel/debug/tracing# cat available_tracers
blk branch function_graph wakeup_dl wakeup_rt wakeup irqsoff function nop
root@xiaotianbsp:/sys/kernel/debug/tracing# echo function_graph > current_tracer
## 2、设置tracer参数
root@xiaotianbsp:/sys/kernel/debug/tracing# ps -A | grep mmc
155 ? 00:00:00 irq/27-mmc1
157 ? 00:00:02 mmcqd/0 ## 跟踪该pid
182 ? 00:00:00 jbd2/mmcblk0p5-
root@xiaotianbsp:/sys/kernel/debug/tracing# echo 157 > set_ftrace_pid
root@xiaotianbsp:/sys/kernel/debug/tracing# echo 8 > max_graph_depth
root@xiaotianbsp:/sys/kernel/debug/tracing# echo > trace ## 清ringbuffer
## 3、查看trace
root@xiaotianbsp:/sys/kernel/debug/tracing# cat trace
# tracer: function_graph
#
# CPU DURATION FUNCTION CALLS
# | | | | | | |
root@xiaotianbsp:/sys/kernel/debug/tracing# echo 1 > tracing_on
root@xiaotianbsp:/sys/kernel/debug/tracing# cat trace
# tracer: function_graph
#
# CPU DURATION FUNCTION CALLS
# | | | | | | |
...
4) | blk_fetch_request() { ## sd卡相关操作
4) | blk_peek_request() {
4) | deadline_dispatch_requests() {
4) | deadline_remove_request.isra.0() {
4) 0.584 us | elv_rb_del();
4) 5.542 us | }
4) | elv_dispatch_add_tail() {
4) 0.292 us | elv_rqhash_del.isra.0();
4) 5.542 us | }
4) + 20.708 us | }
4) | mmc_prep_request() {
4) 0.583 us | mmc_access_rpmb();
4) 5.834 us | }
4) + 37.333 us | }
4) | blk_start_request() {
4) 0.875 us | blk_dequeue_request();
4) 0.584 us | blk_add_timer();
4) + 11.083 us | }
4) + 57.750 us | }
...
其它类型后续介绍。
注：ftrace也可以用trace-cmd命令代替操作debugfs下的trace节点跟踪，配合kernelshark，可图形化分析数据。
