kernel ftrace使用示例

1 使能 kernel ftrace

内核版本信息

uname -r
5.0.0+

需要打开下面编译宏

CONFIG_FTRACE=y
CONFIG_HAVE_FUNCTION_TRACER=y
CONFIG_HAVE_FUNCTION_GRAPH_TRACER=y
CONFIG_HAVE_DYNAMIC_FTRACE=y
CONFIG_FUNCTION_TRACER=y
CONFIG_FUNCTION_GRAPH_TRACER=y
CONFIG_IRQSOFF_TRACER=y
CONFIG_SCHED_TRACER=y
CONFIG_ENABLE_DEFAULT_TRACERS=y
CONFIG_PREEMPT_TRACER=y

/sys/kernel/debug/tracing目录下提供各种tracer（跟踪器）和events（事件）

available_tracers列出系统支持的跟踪器

cat available_tracers
  blk function_graph wakeup_dl wakeup_rt wakeup irqsoff function nop

# nop 不跟踪任何信息。将nop写入current_tracer文件可以清空之前收集到的跟踪信息
# function 跟踪内核函数执行情况
# function_graph 可以显示类似C语言的函数调用关系图，比较直观
# wakeup 跟踪普通优先级的进程从获得调度到被唤醒的最长延迟时间
# wakeup_rt 跟踪RT类型的任务从获得调度到被唤醒的最长延迟时间
# irqsoff 跟踪关闭中断信息，并记录关闭的最长时长
# blk 跟踪块设备的函数

available_events列出系统支持的事件

current_tracer设置和显示当前正在使用的跟踪器。cat 或者 echo

trace读取跟踪信息。cat 查看ftrace记录下来的跟踪信息

tracing_on用于开始或者暂停跟踪

trace_options设置ftrace的一些相关选项

2 irqsoff跟踪器

示例

cd /sys/kernel/debug/tracing
echo 0 > options/function-trace # 关闭 function-trace 可以减少一些延迟
echo irqsoff > current_tracer
echo 1 > tracing_on
...[停顿]
echo 0 > tracing_on
cat trace

3 function跟踪器

示例

cat set_ftrace_pid 
 no pid
echo 766 > set_ftrace_pid # 跟踪PID为 766的进程
echo function > current_tracer
echo 1 >tracing_on
...[停顿]
echo 0 >tracing_on
cat trace

4 动态ftrace

配置内核时打开 CONFIG_HAVE_DYNAMIC_FTRACE选项，在 /sys/kernel/debug/tracing目录下

就增加 set_ftrace_filter 和 set_ftrace_notrace这两个文件节点使用。

set_ftrace_filter设置要跟踪的函数

set_ftrace_notrace设置不要跟踪的函数

available_filter_functions节点可以列出当前系统支持的所有函数

示例1

echo mutex_lock mutex_unlock > set_ftrace_filter # 关注 mutex_lock 和 mutex_unlock 两个函数
echo nop > current_tracer # 清空trace
echo function > current_tracer
cat set_ftrace_pid 
 766
echo 1 > tracing_on
...[停顿]
echo 0 > tracing_on
cat trace

示例2

echo mutex* > set_ftrace_filter	# 支持通配符查找
echo nop > current_tracer # 清空trace
echo function > current_tracer
cat set_ftrace_pid 
 766
echo 1 > tracing_on
...[停顿]
echo 0 > tracing_on
cat trace

5 事件跟踪

示例1

cat available_events # 查看系统支持的所有事件
echo syscalls:* > set_event # 跟踪 syscalls 下的所有事件
cat set_event
	syscalls:xxx
	syscalls:xxx
	syscalls:...
echo nop > current_tracer # 清空trace
echo function > current_tracer
cat set_ftrace_pid 
 766
echo 1 > tracing_on
...[停顿]
echo 0 > tracing_on
cat trace

示例2

cat available_events # 查看系统支持的所有事件
echo *:* > set_event # 跟踪所有事件
echo nop > current_tracer # 清空trace
echo function > current_tracer
cat set_ftrace_pid 
 766
echo 1 > tracing_on
...[停顿]
echo 0 > tracing_on
cat trace

6 实时监听

echo 1 > tracing_on
cat trace_pipe # 这里会阻塞，实时输出trace

7 instances的使用

有时候tracing打印的内容多，且杂。这时候instances就派上用场了。

以事件ufs为例

cd /sys/kernel/debug/tracing
echo 0 >  tracing_on
cd /sys/kernel/debug/tracing/instances
mkdir ufs  # 注意：创建目录之后，/sys/kernel/debug/tracing/trace_pipe 就不会有ufs事件的trace
cd /sys/kernel/debug/tracing/instances/ufs # ufs事件的trace都转到这个目录下
cat trace_pipe

虽然也可以用这种方式替代

cd /sys/kernel/debug/tracing
cat trace_pipe | grep fastrpc