1. 参考资料
2. ftrace介绍
ftrace 是一个内部跟踪器，旨在帮助系统的开发人员和设计人员找到内核内部发生的事情。它可用于调试或分析发生在用户空间之外的延迟和性能问题。
尽管 ftrace 通常被认为是函数跟踪器，但它实际上是一个由多种跟踪实用程序组成的框架。有延迟跟踪来检查在禁用和启用中断之间发生了什么，以及抢占和从任务被唤醒到任务被实际调度的时间。
ftrace 最常见的用途之一是事件跟踪。 在内核跟踪和分析方面，Linux 内核有三个主要的机制：
- 跟踪点tracepoint：一种基于静态测试代码的工作机制
- 探针kprobe：一种动态跟踪机制，用于在任意时刻中断内核代码的运行，调用它自己的处理程序，在完成需要的操作之后再返回
- perf_events —— 一个访问 PMU（性能监视单元Performance Monitoring Unit）的接口
ftrace直观理解有两层含义：一是提供函数钩子的基础设施，二是基于tracefs文件系统的trace框架。常用的功能如下：
- function tracer：在函数头挂钩子函数
- function graph tracer：可以带时间戳函数执行流打印
- trace event：函数执行时调用静态的钩子函数
- kprobe：一般是挂在函数入口点，用于获取参数
- kretprobe：通常是函数出口点，执行钩子函数
3. tracer的使用
ftrace_enable是 function tracer的大开关。默认是enable，如果被disable，所有相关的trace都会被disable，包括 (perf, kprobes, stack tracing, profiling, etc)。
echo 0 > /proc/sys/kernel/ftrace_enabled
echo 1 > /proc/sys/kernel/ftrace_enabled
trace目录在以下路径：/sys/kernel/debug/tracing
用列表来遍历“tracing/”文件夹下每一个文件的作用和描述：
| file | 说明 |
|---|---|
| current_tracer | 显示当前使用的tracer，默认是nop。 |
| available_tracers | 列出当前已经注册的tracer |
| tracing_on | 0: disable ring buffer，1: enable ring buffer，这个仅仅只是禁止数据写入ring buffer，但是各种桩函数还是被调用，trace动作仍然发生，开销依然存在。 |
| trace | 该文件把ringbuffer数据输出成用户可读的格式。注意：在这个文件open时，ring buffer是临时关闭的。读操作并不会清除掉ring buffer中的数据，可以重复读； |
| trace_pipe | 文件内容和“trace”文件是一样的，区别在于：1、并行读，读操作不会disable写操作；2、只支持读一次，该读操作会清除掉ring buffer中的数据，再次去读没有内容了； |
| trace_options | 一些通用的trace相关的option |
| options | “options”是一个文件夹，包含了所有注册的tracer可配置的option |
| tracing_max_latency | 某些tracer用来记录最大latency。例如，最大中断disable时间。最大时间被记录到本文件，对应的trace被记录到“trace”文件。新的trace最有大于现在的max latency胡，才会被记录。 |
| tracing_thresh | 有一些latency tracers判断latency大于本文件的标值才会被记录。只有值大于0才会被激活。 |
| buffer_size_kb | 设置ring buffer在每个cpu上的大小。默认在每个cpu上大小都是相等的，如果显示“X”，查看“per_cpu/cpu0/buffer_size_kb”具体每个cpu的大小。 |
| buffer_total_size_kb | ring buffer总的的大小 |
| free_buffer | 本文件用来控制ring buffer的free，当free时ring buffer被resize到它的最小尺寸。使用方法：当进程不需要使用ring buffer了，他open“free_buffer”并且close文件，ring buffer会被resize到最小尺寸。 |
| tracing_cpumask | 独立控制在每个cpu上是否开trace功能。 |
| set_ftrace_filter | function tracer的filter。dynamic ftrace是通过动态修改函数代码来插入桩函数的，这让对没有被trace的函数的影响降到了最低。需要使用dynamic ftrace跟踪哪些函数：echo 函数名 > set_ftrace_filter |
| set_ftrace_notrace | function tracer的filter。和“set_ftrace_filter”的作用相反，设置哪些函数不要被trace。如果同一函数在“set_ftrace_filter”和“set_ftrace_notrace”中同时被设置，效果等同于没有 |
| set_ftrace_pid | function tracer的filter。function tracer只追踪这个文件描述的PID。 |
| set_event_pid | trace event的filter。只有本文件描述的PID的进程，才会记录其trace event。 |
| set_graph_function | function graph tracer的filter。function graph tracer仅仅trace在本文件中描述的函数。 |
| set_graph_notrace | function graph tracer的filter。和“set_graph_function”功能相反，function graph tracer不trace在本文件中描述的函数 |
| available_filter_functions | 有效的可以被设置为filter的函数名。 |
| dyn_ftrace_total_info | 该文件是调试目的，有多少个函数的桩函数被dynamic ftrace转换成nop可以被追踪。 |
| enabled_functions | 该文件用来调试ftrace的，它可以显示所有attach了回调函数的函数。 |
| function_profile_enabled | 保留被调用的函数数量的直方图, 直方图内容可以显示在以下文件中：trace_stats/function |
| trace_stats | 保存不同trace统计数据的目录 |
| kprobe_events | 通过kprobe动态的创建trace event。而通过TRACE_EVENT()宏定义的都是静态的trace event |
| kprobe_profile | kprobe trace_event的统计 |
| max_graph_depth | function graph tracer显示函数调用关系的层级 |
| printk_formats | 使用trace_printk()打印数据的格式化字符串。使用“trace”文件读取ringbuffer中trace_printk()打印的数据时，需要知道解析格式。这个文件保存了所有的trace_printk()的打印格式。 |
| saved_cmdlines | ftrace建立起了一个cache，用来记录进程“pid”和“comms”之间的映射关系，在输出时能根据pid快速查找到进程的comms。如果进程的comms没有缓冲，使用空白填充 “<…>” 。 |
| saved_cmdlines_size | saved_cmdlines这块cache的大小 |
| saved_tgids | 如果“record-tgid”选项被使能，PID对应的TGID映射也会被记录。 |
| snapshot | 显示“snapshot”缓存中的内存，类似“trace”文件。snapshot对应一块独立的ring buffer，用来快照ring buffer中的内容。 |
| stack_max_size | stack tracer的最大的堆栈尺寸 |
| stack_trace | stack tracer的最大的堆栈的具体的回调情况 |
| stack_trace_filter | stack tracer的filter。指示哪些函数可以被stack tracer跟踪。 |
| trace_clock | ring buffer记录时间戳所使用的时钟源 |
| trace_marker | 该文件运行用户态直接写内容到ring buffer，通常用来同步用户态和内核态的事件 |
| trace_marker_raw | 和“trace_marker”类似，但是写入的是二进制格式。 |
| uprobe_events | 通过uprobe动态的创建trace event。而通过TRACE_EVENT()宏定义的都是静态的trace event |
| uprobe_profile | Uprobe的统计功能 |
| instances | 这是一个创建多个ring buffer的方法，可以让不同的events使用不同的ring buffer |
| events | trace event的文件夹，包含所有通过TRACE_EVENT()宏定义的静态event 和 通过kprobe、uprobe定义的动态event |
| set_event | 使能trace event。echo xxxevent > set_event // enbale对应的xxxevent |
| available_events | 列出所有有效的event。相当于“events”文件夹中所有event名字的集合 |
| timestamp_mode | 配置ring buffer中的时间戳为delta mode还是absolute 模式 |
| hwlat_detector | Hardware Latency Detector文件夹 |
| per_cpu | per cpu的文件夹 |
| per_cpu/cpu0/buffer_size_kb | 单个cpu上的buffer size数据 |
| per_cpu/cpu0/trace | 单个cpu上的trace信息 |
| per_cpu/cpu0/trace_pipe | 单个cpu上的trace_pipe信息 |
| per_cpu/cpu0/trace_pipe_raw | 单个cpu上的二进制trace_pipe信息 |
| per_cpu/cpu0/snapshot | 单个cpu上的snapshot |
| per_cpu/cpu0/snapshot_raw | 单个cpu上的raw snapshot，返回二进制信息 |
| per_cpu/cpu0/stats | 显示每个cpu的ring buffer统计 |
ftrace目前支持的tracer有以下这些：
| tracer | 说明 |
|---|---|
| function | 追踪所有的内核函数 |
| function_graph | 和“function tracer”比较类似，但它除了探测函数的入口还探测函数的出口。它可以画出一个图形化的函数调用，类似于c源代码风格。 |
| blk | 块设备tracer |
| hwlat | 用来侦测硬件产生的延迟。 |
| irqsoff | 追踪并记录最大关闭中断时间。 |
| preemptoff | 追踪并记录最大关闭抢占时间。 |
| preemptirqsoff | 追踪并记录关闭中断 and/or 关闭抢占的最大时间。 |
| wakeup | 追踪所有任务从获得调度到被唤醒的最大延迟时间。 |
| wakeup_rt | 追踪RT与dl类型的任务从获得调度到被唤醒的最大延迟时间。 |
| wakeup_dl | 追踪Deadline类型的任务从获得调度到被唤醒的最大延迟时间。 |
| mmiotrace | 追踪硬件IO |
| branch | 追踪likely/unlikely的分支预测情况 |
| nop | 空的tracer |
“trace_options”文件(或者“option”文件夹中的文件)用来控制trace文件的输出格式，或者由tracer自动配置。
tracing# cat trace_options
print-parent
nosym-offset
nosym-addr
noverbose
noraw
nohex
nobin
noblock
trace_printk
annotate
nouserstacktrace
nosym-userobj
noprintk-msg-only
context-info
nolatency-format
record-cmd
norecord-tgid
overwrite
nodisable_on_free
irq-info
markers
noevent-fork
function-trace
nofunction-fork
nodisplay-graph
nostacktrace
notest_nop_accept
notest_nop_refuse
Disable某个选项，使用“no”前缀：
echo noprint-parent > trace_options
Enable某个选项，去掉“no”前缀：
echo sym-offset > trace_options
| Option | 说明 |
|---|---|
| print-parent | 是否打印父函数 |
| sym-offset | 是否打印符号的offset |
| sym-addr | 是否打印符号地址 |
| verbose | 显示详细信息，这涉及到启用 latency-format 选项时的跟踪文件。 |
| raw | 显示裸数据。如果用户应用知道裸数据的解析方法，可以在用户态解析，优于在内核解析。 |
| hex | 使用hex格式解析裸数据。 |
| bin | 使用bin格式解析裸数据。 |
| block | 如果设置，读trace_pipe文件不会在轮询时阻塞。 |
| trace_printk | 是否禁止trace_printk写入数据到ring buffer。 |
| annotate | 有时当 CPU 缓冲区已满且一个 CPU 缓冲区最近发生了大量事件（因此时间范围较短），而另一个 CPU 可能只有少量事件，这使得它包含了较早的事件，可能会导致混淆。当报告跟踪时，它会先显示最旧的事件，可能会看起来只有一个 CPU 运行（具有最旧事件的那个）。当设置了 annotate 选项时，它会增加提示，显示新 CPU 缓冲区的开始： -0 [001] dNs4 21169.031481: wake_up_idle_cpu <-add_timer_on -0 [001] dNs4 21169.031482: _raw_spin_unlock_irqrestore <-add_timer_on -0 [001] .Ns4 21169.031484: sub_preempt_count <-_raw_spin_unlock_irqrestore ##### CPU 2 buffer started #### -0 [002] .N.1 21169.031484: rcu_idle_exit <-cpu_idle -0 [001] .Ns3 21169.031484: _raw_spin_unlock <-clocksource_watchdog -0 [001] .Ns3 21169.031485: sub_preempt_count <-_raw_spin_unlock |
| userstacktrace | 记录用户空间的堆栈回调 |
| sym-userobj | 记录用户空间的堆栈回调，并且解析出对应符号。这在ASLR使能时非常有用，因为ASLR是随机加载库地址，事后根据堆栈可能恢复不出原来的调用关系。 |
| printk-msg-only | trace_printk()仅仅打印格式不打印参数 |
| context-info | 是否打印trace event的头部通用信息：comm, PID, timestamp, CPU, and other useful data. |
| latency-format | 是否使用“Latency trace format”打印，解释事件延迟的发生 |
| record-cmd | 是否在sched_switch时间点来创建pid到comm的转换cache。 |
| record-tgid | 是否创建pid到tgid的cache |
| overwrite | 控制ringbuffer满后的行为是，overwrite旧数据，还是discard新数据。 |
| disable_on_free | 当使用“set_free_buffer”释放ringbuffer空间时，是否停止tracing。 |
| irq-info | 是否打印相关flag信息：interrupt, preempt count, need resched |
| markers | 是否允许用户态直接通过trace_marker接口往ringbuffer中写数据 |
| event-fork | 对于trace_event，如果进程在pid filter列表中，fork创建的子进程是否自动加入到filter列表中。 |
| function-trace | 在latency tracers是否可以同时使能function tracing。 |
| function-fork | 对于function trace，如果进程在pid filter列表中，fork创建的子进程是否自动加入到filter列表中。 |
| display-graph | “function graph tracing”风格的显示 |
| stacktrace | event中是否记录堆栈回调 |
function_graph tracer特有的选项：
| option | 说明 |
|---|---|
| funcgraph-overrun | 当设置时，在跟踪每个函数之后显示graph stack的“溢出”。溢出是指调用的堆栈深度大于为每个任务保留的堆栈深度。每个任务在调用图中有一个固定的函数数组进行跟踪。如果调用的深度超过了该值，则不会跟踪该函数。溢出是因为超过该数组而错过的函数数量。 |
| funcgraph-cpu | 显示所在CPU |
| funcgraph-overhead | 显示“delay”程度 |
| funcgraph-proc | 每一行显示进程comm |
| funcgraph-duration | 每个函数返回处显示函数执行时间 |
| funcgraph-abstime | 每一行显示绝对时间戳 |
| funcgraph-irqs | 如果disable，将不会跟踪中断中的函数 |
| funcgraph-tail | 在函数结束时显示函数名 |
| sleep-time | 函数的执行时间包括进程被调度出去的sleep时间，启用后，将计算任务被调度出的时间作为函数调用的一部分。 没启用的话，每次schd out的时间进行累计，再减掉。 |
| graph-time | 在使用函数图跟踪器运行函数分析器时，要包括调用嵌套函数的时间。当未设置此选项时，函数报告的时间仅包括函数本身执行的时间，而不包括它调用的函数的时间。 |
3.1 function tracer使用：查看"vfs_open"函数调用信息
cd /sys/kernel/debug/tracing/
# 先禁用数据写入到 Ring 缓冲区
echo 0 > tracing_on
# 设置当前使用的tracer
echo function > current_tracer
cat current_tracer
function
# 过滤要跟踪的函数
echo vfs_open > set_ftrace_filter
cat set_ftrace_filter
vfs_open
# 创建文件用于测试
mkdir -p /home/idle/study/ftrace/function_tracer
touch /home/idle/study/ftrace/function_tracer/test_vfs_open
echo test_vfs_open > /home/idle/study/ftrace/function_tracer/test_vfs_open
# 使能数据写入到 Ring 缓冲区
echo 1 > tracing_on
# 触发
cat /home/idle/study/ftrace/function_tracer/test_vfs_open
test_vfs_open
# 获取trace结果
cat trace
- 首先在头部打印当前tracer的名字，这个例子里tracer是“function”；
- 然后打印”buffer中有多少个event/总共写了多少个entry”，两者的差值是丢失的entry(17 - 17 = 0 events lost)。
- 每行的信息解析格式：进程名 “cat”, 进程PID “4033”, 运行的cpu “001”, 被trace的函数 “vfs_open” 父函数 “do_open”。时间戳TIMESTAMP表示的是函数enter的时刻。
| field | 说明 |
|---|---|
| irqs-off | 中断是否disable：‘d’：中断disable； ‘.’：中断没有disable； ‘X’：架构不支持读取该信息 |
| need-resched | 需要调度标志：‘N’ both TIF_NEED_RESCHED and PREEMPT_NEED_RESCHED is set, ‘n’ only TIF_NEED_RESCHED is set, ‘p’ only PREEMPT_NEED_RESCHED is set, ‘.’ otherwise. |
| hardirq/softirq | 当前所处中断环境：‘Z’ - NMI occurred inside a hardirq, ‘z’ - NMI is running ,‘H’ - hard irq occurred inside a softirq, ‘h’ - hard irq is running, ‘s’ - soft irq is running, ‘.’ - normal context. |
| preempt-depth | 禁止抢占的深度，即禁止抢占的计数值。 |
3.2 function graph tracer使用：函数"vfs_open"的执行时间
cd /sys/kernel/debug/tracing/
# 先禁用数据写入到 Ring 缓冲区
echo 0 > tracing_on
# 清空trace文件
echo 0 > trace
# 设置当前使用的tracer
echo function_graph > current_tracer
cat current_tracer
function_graph
# 过滤要跟踪的函数
echo vfs_open > set_ftrace_filter
cat set_ftrace_filter
vfs_open
# 启用进程TASK/PID打印
echo 1 > options/funcgraph-proc
# 创建文件用于测试
mkdir -p /home/idle/study/ftrace/function_graph_tracer
touch /home/idle/study/ftrace/function_graph_tracer/test_vfs_open
echo test_vfs_open > /home/idle/study/ftrace/function_graph_tracer/test_vfs_open
# 使能数据写入到 Ring 缓冲区
echo 1 > tracing_on
# 触发
cat /home/idle/study/ftrace/function_graph_tracer/test_vfs_open
test_vfs_open
# 获取trace结果
cat trace
查看到vfs_open被执行的调试信息包括TASK/PID，函数的执行时间，接口名。原理上是通过在函数的入口点和出口点（kprobe/kretprobe）挂钩子，然后计算入口与出口的时间来实现的。
3.3 function graph tracer使用：函数"vfs_open"向下执行流
cd /sys/kernel/debug/tracing/
# 先禁用数据写入到 Ring 缓冲区
echo 0 > tracing_on
# 清空trace文件
echo 0 > trace
# 设置当前使用的tracer
echo function_graph > current_tracer
cat current_tracer
function_graph
# 不使用过滤!!!
echo > set_ftrace_filter
cat set_ftrace_filter
#### all functions enabled ####
# 使用函数图表
echo vfs_open > set_graph_function
cat set_graph_function
vfs_open
# 打印进程TASK/PID
echo 1 > options/funcgraph-proc
# 尾部注释(方便观察)
echo 1 > options/funcgraph-tail
# 创建文件用于测试
mkdir -p /home/idle/study/ftrace/function_graph_tracer
touch /home/idle/study/ftrace/function_graph_tracer/test_vfs_open
echo test_vfs_open > /home/idle/study/ftrace/function_graph_tracer/test_vfs_open
# 使能数据写入到 Ring 缓冲区
echo 1 > tracing_on
# 触发
cat /home/idle/study/ftrace/function_graph_tracer/test_vfs_open
test_vfs_open
# 获取trace结果
cat trace
vfs_open被执行时，能看到向下的执行流程，其中涉及到的函数调用和相关信息会打印出来。
3.4 wakeup tracer：追踪普通进程从被唤醒到真正得到执行之间的延迟
# 在执行延迟测试时降低跟踪程序的开销，否则会打印函数调用关系
echo 0 > options/function-trace
# 设置tracer
echo wakeup > current_tracer
echo 1 > tracing_on
# 复位最大值
echo 0 > tracing_max_latency
chrt -f 5 sleep 1
echo 0 > tracing_on
cat trace
wakeup tracer追踪优先级最高的进程，我们看到nice 0的migration进程花了282us从被唤醒到真正执行。
4. Filter commands
ftrace支持通过一系列的command来设置set_ftrace_filter，配置filter。格式如下：
<function>:<command>:<parameter>
支持以下的command：
4.1 mod
该命令使能某个模块的过滤。parameter用来定义模块。例如，追踪ext3模块的write*函数：
echo ‘write*:mod:ext3’ > set_ftrace_filter
追加配置使用’>>’，移除特定模块的函数使用’!’前缀：
echo '!writeback*:mod:ext3' >> set_ftrace_filter
支持模块通配符。例如去掉所有的函数追踪除了某个模块：
echo '!*:mod:!ext3' >> set_ftrace_filter
去掉所有的模块追踪，但是非模块的kernel部分继续追踪：
echo '!*:mod:*' >> set_ftrace_filter
4.2 traceon/traceoff
这个命令在指定的函数被调用时打开/关闭tracing。parameter定义函数命中多少次以后打开/关闭tracing，如果没有描述则不做限制。
例如，disable tracing当schedule bug命中前5次：
echo '__schedule_bug:traceoff:5' > set_ftrace_filter
这些命令是累积的，无论你是否使用追加方式配置到set_ftrace_filter。如果要移除某个命令，使用‘!’前缀并且parameter次数drop到0：
echo '!__schedule_bug:traceoff:0' > set_ftrace_filter
4.3 snapshot
配置CONFIG_TRACER_SNAPSHOT 将会使快照特性有效对于所有的non latency tracers。(Latency tracers仅仅记录最大延迟，例如“irqsoff” or “wakeup”，不能使用这个特性，因为它们已经在内部使用快照机制)。
快照在一个特定时间点保留当前trace buffer而不停止跟踪。ftrace交换当前缓存区和备用缓存区，在新的当前缓存区(之前的备用缓存区)中继续跟踪。
它用来拿到快照并且读出快照。echo 1到文件会分配一个备份的缓存区并且进行交换，然后从快照中读内容使用和trace文件同样的格式输出。读快照和系统tracing并行进行。echo 0到文件会释放备份缓存区，echo其他的正值数会清除快照的内容。
# echo 1 > events/sched/enable
# echo 1 > snapshot
# cat snapshot
# tracer: nop
#
# entries-in-buffer/entries-written: 71/71 #P:8
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
<idle>-0 [005] d... 2440.603828: sched_switch: prev_comm=swapper/5 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=snapshot-test-2 next_pid=2242 next_prio=120
sleep-2242 [005] d... 2440.603846: sched_switch: prev_comm=snapshot-test-2 prev_pid=2242 prev_prio=120 prev_state=R ==> next_comm=kworker/5:1 next_pid=60 next_prio=120
[...]
<idle>-0 [002] d... 2440.707230: sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=snapshot-test-2 next_pid=2229 next_prio=120
# cat trace
# tracer: nop
#
# entries-in-buffer/entries-written: 77/77 #P:8
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
<idle>-0 [007] d... 2440.707395: sched_switch: prev_comm=swapper/7 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=snapshot-test-2 next_pid=2243 next_prio=120
snapshot-test-2-2229 [002] d... 2440.707438: sched_switch: prev_comm=snapshot-test-2 prev_pid=2229 prev_prio=120 prev_state=S ==> next_comm=swapper/2 next_pid=0 next_prio=120
[...]
当函数命中时将会导致一个快照被触发。
echo 'native_flush_tlb_others:snapshot' > set_ftrace_filter
移除上述的配置：
echo '!native_flush_tlb_others:snapshot' > set_ftrace_filter
当你在latency tracers下尝试使用快照，将会得到以下结果：
# echo wakeup > current_tracer
# echo 1 > snapshot
bash: echo: write error: Device or resource busy
# cat snapshot
cat: snapshot: Device or resource busy
4.4 enable_event/disable_event
这些命令可以enable/disable trace event。因为function tracing回调都是非常敏感的，当这些命令注册，这些函数的tracepoint被active但是处于“soft disable”状态，它会被调用但是不会产生记录，这些tracepoint只是用来判断条件是否被触发。
格式如下：
<function>:enable_event:<system>:<event>[:count]
<function>:disable_event:<system>:<event>[:count]
echo 'try_to_wake_up:enable_event:sched:sched_switch:2' > set_ftrace_filter
移除配置：
echo '!try_to_wake_up:enable_event:sched:sched_switch:0' > set_ftrace_filter
4.5 Instances
在tracefs中有个“instances”文件夹，这个文件夹可以使用mkdir创建新的子文件夹、使用rmdir删除子文件夹。如果子文件夹被创建，它默认包含以下文件和文件夹：
# mkdir instances/foo
# ls instances/foo
buffer_size_kb buffer_total_size_kb events free_buffer per_cpu
set_event snapshot trace trace_clock trace_marker trace_options
trace_pipe tracing_on
新目录中的文件与原tracing目录中同名的文件的工作方式相同，只是所使用的缓冲区是一个单独的新缓冲区。这些文件会影响该缓冲区，但不会影响主缓冲区。
当前我们使用的内核版本linux5.0，已经有current_tracer和available_tracers，可以使用function tracer，但是不支持function_graph。
# cat available_tracers
function_graph wakeup_dl wakeup_rt wakeup preemptirqsoff preemptoff irqsoff function nop
# mkdir instances/idle
# cat instances/idle/available_tracers
wakeup_dl wakeup_rt wakeup preemptirqsoff preemptoff irqsoff function nop
# mkdir instances/foo
# echo 100000 > buffer_size_kb
# echo 1000 > instances/foo/buffer_size_kb
# echo function > current_trace
# echo 1 > instances/foo/events/sched/sched_wakeup/enable
# echo 1 > instances/foo/events/sched/sched_wakeup_new/enable
# echo 1 > instances/foo/events/sched/sched_switch/enable
# cat trace_pipe
CPU:2 [LOST 11745 EVENTS]
bash-2044 [002] .... 10594.481032: _raw_spin_lock_irqsave <-get_page_from_freelist
bash-2044 [002] d... 10594.481032: add_preempt_count <-_raw_spin_lock_irqsave
bash-2044 [002] d..1 10594.481032: __rmqueue <-get_page_from_freelist
bash-2044 [002] d..1 10594.481033: _raw_spin_unlock <-get_page_from_freelist
bash-2044 [002] d..1 10594.481033: sub_preempt_count <-_raw_spin_unlock
bash-2044 [002] d... 10594.481033: get_pageblock_flags_group <-get_pageblock_migratetype
bash-2044 [002] d... 10594.481034: __mod_zone_page_state <-get_page_from_freelist
bash-2044 [002] d... 10594.481034: zone_statistics <-get_page_from_freelist
bash-2044 [002] d... 10594.481034: __inc_zone_state <-zone_statistics
bash-2044 [002] d... 10594.481034: __inc_zone_state <-zone_statistics
bash-2044 [002] .... 10594.481035: arch_dup_task_struct <-copy_process
[...]
# cat instances/foo/trace_pipe
bash-1998 [000] d..4 136.676759: sched_wakeup: comm=kworker/0:1 pid=59 prio=120 success=1 target_cpu=000
bash-1998 [000] dN.4 136.676760: sched_wakeup: comm=bash pid=1998 prio=120 success=1 target_cpu=000
<idle>-0 [003] d.h3 136.676906: sched_wakeup: comm=rcu_preempt pid=9 prio=120 success=1 target_cpu=003
<idle>-0 [003] d..3 136.676909: sched_switch: prev_comm=swapper/3 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=rcu_preempt next_pid=9 next_prio=120
rcu_preempt-9 [003] d..3 136.676916: sched_switch: prev_comm=rcu_preempt prev_pid=9 prev_prio=120 prev_state=S ==> next_comm=swapper/3 next_pid=0 next_prio=120
bash-1998 [000] d..4 136.677014: sched_wakeup: comm=kworker/0:1 pid=59 prio=120 success=1 target_cpu=000
bash-1998 [000] dN.4 136.677016: sched_wakeup: comm=bash pid=1998 prio=120 success=1 target_cpu=000
bash-1998 [000] d..3 136.677018: sched_switch: prev_comm=bash prev_pid=1998 prev_prio=120 prev_state=R+ ==> next_comm=kworker/0:1 next_pid=59 next_prio=120
kworker/0:1-59 [000] d..4 136.677022: sched_wakeup: comm=sshd pid=1995 prio=120 success=1 target_cpu=001
kworker/0:1-59 [000] d..3 136.677025: sched_switch: prev_comm=kworker/0:1 prev_pid=59 prev_prio=120 prev_state=S ==> next_comm=bash next_pid=1998 next_prio=120
[...]
可以看到，top trace buffer只显示function tracing，foo 实例显示wakeups和task switches。
移除实例，只需简单的删除文件夹：
# rmdir instances/foo
# rmdir instances/bar
# rmdir instances/zoot
如果实例中的文件正在open状态，rmdir将会返回EBUSY失败。
4.6 Stack trace
因为kernel拥有固定的堆栈大小，所以在函数中不浪费堆栈是非常重要的。内核开发者必须小心在堆栈上分配内存，如果分配过多，系统可能会有堆栈溢出的危险，并且会发生出错，通常导致系统panic。
有一些工具用来检查这个，但是通常是中断周期性的检查使用率。但是如果你能在每个函数调用中执行这个检查，那将变得非常有用。由于fTrace提供了function trace，因此在每个函数调用中检查堆栈大小是方便的。通过stack tracer来启用。
配置CONFIG_STACK_TRACER 将会包含ftrace stack tracing功能。写 ‘1’ 到 /proc/sys/kernel/stack_tracer_enabled，使能：
# echo 1 > /proc/sys/kernel/stack_tracer_enabled
也可以在kernel启动命令行中使能，在cmdline中增加“stacktrace” 参数。
使能跟踪一段时间后，可以查看最大栈占用情况，stack_max_size这里打印的是最长栈的size。而在stack_trace 中打印的是最长栈的每个函数占用栈大小的情况，注意这里也只会记录的最长的栈情况。
运行一段时间后，看看输出：
# cat stack_max_size
2928
# cat stack_trace
Depth Size Location (18 entries)
----- ---- --------
0) 2928 224 update_sd_lb_stats+0xbc/0x4ac
1) 2704 160 find_busiest_group+0x31/0x1f1
2) 2544 256 load_balance+0xd9/0x662
3) 2288 80 idle_balance+0xbb/0x130
4) 2208 128 __schedule+0x26e/0x5b9
5) 2080 16 schedule+0x64/0x66
6) 2064 128 schedule_timeout+0x34/0xe0
7) 1936 112 wait_for_common+0x97/0xf1
8) 1824 16 wait_for_completion+0x1d/0x1f
9) 1808 128 flush_work+0xfe/0x119
10) 1680 16 tty_flush_to_ldisc+0x1e/0x20
11) 1664 48 input_available_p+0x1d/0x5c
12) 1616 48 n_tty_poll+0x6d/0x134
13) 1568 64 tty_poll+0x64/0x7f
14) 1504 880 do_select+0x31e/0x511
15) 624 400 core_sys_select+0x177/0x216
16) 224 96 sys_select+0x91/0xb9
17) 128 128 system_call_fastpath+0x16/0x1b
