Linux ftrace框架介绍及运用【转】
转自：
目录：
1. ftrace背景
2. 框架介绍
3. 主要代码分析
4. ftrace的配置和使用
5. ftrace相关工具
在日常工作中，经常会需要对内核进行Debug、或者进行优化工作。一些简单的问题，可以通过dmesg/printk查看，优化借助一些工具进行。
但是当问题逻辑复杂，优化面宽泛的时候，往往无从下手。
需要从上到下、模块到模块之间分析，这时候就不得不借助于Linux提供的静态(Trace Event)动态(各种Tracer)进行分析。
同时还不得不借助工具、或者编写脚本进行分析，以缩小问题范围、发现问题。
简单的使用Tracepoint已经不能满足需求，因此就花点精力进行梳理。
Documentation/trace，ftrace代码主要在kernel/trace，ftrace相关头文件在include/trace中。
WiKiPedia有关于ftrace的简单介绍。
ftrace的作者在LinuxCon 2010有一篇关于Ftrace Linux Kernel Tracing的slides值得一读。
set_ftrace_filter-------------用于显示指定要跟踪的函数
set_ftrace_notrace------------用于指定不跟踪的函数，缺省为空。
set_ftrace_pid----------------用于指定要追踪特定进程的函数。
Function graph配置：
max_graph_depth---------------函数嵌套的最大深度。
set_graph_function------------设置要清晰显示调用关系的函数，在使用function_graph跟踪器是使用，缺省对所有函数都生成调用关系。
set_graph_notrace-------------不跟踪特定的函数嵌套调用。
Stack trace设置：
stack_max_size----------------当使用stack跟踪器时，记录产生过的最大stack size
stack_trace-------------------显示stack的back trace
stack_trace_filter------------设置stack tracer不检查的函数名称
Kernel dynamic events:
kprobe_events
kprobe_profile
Userspace dynamic events:
uprobe_events
uprobe_profile
4.1 通用配置
使能和配置大小
常用的配置有对Trace的开关(tracing_on)
echo 0/1 > /sys/kernel/debug/tracing/tracing_on
设置RingBuffer大小(buffer_size_kb),同时buffer_total_size_kb就变成NR_CPUS的倍数。
trace、trace_pipe和snapshot的区别？
trace是从RingBuffer中取出内容，trace_pipe会一直读取Buffer流。
snapshot是trace的一个瞬间快照：
echo 0 > snapshot : Clears and frees snapshot buffer
echo 1 > snapshot : Allocates snapshot buffer, if not already allocated.
Takes a snapshot of the main buffer.
echo 2 > snapshot : Clears snapshot buffer (but does not allocate or free)
(Doesn't have to be '2' works with any number that
is not a '0' or '1')
Tracer
从available_tracers可以获取系统支持的Tracer,current_tracer是当前使用中的Tracer。
Events只有在nop tracer下才会起作用，同时多个tracer不能共享。同一时候只能一个Tracer在生效。
cat available_tracers
hwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop
echo function > current_tracer
instances
在instances目录下，可以通过mkdir创建instance，rmdir删除instance。
新目录下，有很多类似tracing下的文件，可以对其进行配置。然后读取专有的trace/trace_pipe。
mkdir foo
ls foo
available_tracers options set_ftrace_pid trace_options
buffer_size_kb per_cpu snapshot trace_pipe
buffer_total_size_kb set_event trace tracing_cpumask
current_tracer set_event_pid trace_clock tracing_max_latency
events set_ftrace_filter trace_marker tracing_on
free_buffer set_ftrace_notrace trace_marker_rawrmdir foo
特定CPU信息
抓取特定CPU信息0~3：
echo f > tracing_cpumask
查看特定CPU信息：
cat per_cpu/cpu3/trace
用户空间插入Trace标记
有时候需要往Trace中插入标记，trace_marker/trace_marker_raw提供了这样功能。
echo CAPTURE_START > trace_marker
echo CAPTURE_START > trace_marker_raw
Trace选项设置
通过options内容设置，对Trace的输出进行定制，控制输出大小。
trace_option是options设置的结果，可以看出开了哪些选项，关闭了哪些选项。
echo 0/1 > options/irq-info
4.2 Tracepoint
可以对系统特定事件进行跟踪，在available_events可以找到所有事件。然后将需要的时间通过echo xxx >> set_event写入。也可以通过events目录来打开。
4.2.1 Trace Events生效条件
在current_tracer为nop，然后设置tracing/events下面的enable，即可通过tracing/trace或者tracing/trace_pipe查看内容。
4.2.2 Trace Events的过滤功能？
对特定Events的过滤，只打开需要监控的Events。
如果要禁用某个时间在事件前加上！，如echo "!sys_enter_nic" >> set_event。
echo net >set_event--------------------------------打开所有net目录下的事件
echo skb >>set_event------------------------------附加设置skb到目录下
过滤的表达式是：field-name relational-operator value，多表达式可以通过逻辑运算符&&或者||来组合。
数字可以通过==、！=、>、<、&&、||等等来组合filter，来过滤掉很多不需要信息。
文字可以通过==、!=、~l来组合filter。
如针对timer_start事件的Trace：
# tracer: nop
#
# entries-in-buffer/entries-written: 327/327 #P:4
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
Xorg-1684 [000] d... 1140567.102754: timer_start: timer=ffff8800b20300f0 function=intel_uncore_fw_release_timer [i915] expires=4579967822 [timeout=1] flags=0x00000001
nxnode.bin-11900 [000] d.s. 1140567.105061: timer_start: timer=ffff8803aa293508 function=intel_pstate_timer_func expires=4579967825 [timeout=3] flags=0x00100000
-0 [000] dNs. 1140567.108404: timer_start: timer=ffff8802cf845698 function=tcp_delack_timer expires=4579967832 [timeout=10] flags=0x00000000
在events目录下，有很多子目录。这些目录里面可以使用filter，过滤很多不需要的信息。
通过format可以知道，timer_start这个时间的field名称，然后在filter进行设置。
针对某一pid进行过滤。
将对应pid写入set_event_pid，就可达到只监控某个进程的Events。
清空跟踪器
对子系统的filter写入0，即可清空整个子系统的filter
echo 0 > filter
4.2.3 Events的trigger功能
enable_event/disable_event
stacktrace
snapshot
traceon/traceoff
4.3 如何在Linux command line启动Events
4.3 function跟踪器及动态ftrace
function跟踪器可以用于跟踪内核函数的调用情况，用于调试分析bug或者了解内核运行过程。
4.3.1 打开Function跟踪器
echo function > /sys/kernel/debug/tracing/current_tracer
4.3.2 在trace_stat中显示function的统计信息
4.3.2.1 trace_stat的使用
trace_stat/function0在系统初始化就创建，通过function_profile_enabled进行开关。
统计的函数在set_ftrace_filter和set_ftrace_notrace中设置。
echo 0/1 > function_profile_enabled
在使能function优化功能之后，可以查看不同CPU下每个函数执行时间统计信息。
每列表示的内容分别是：函数名称、调用次数、总耗时、平均耗时、耗时均方差。
cat trace_stat/function0
Function Hit Time Avg s^2
-------- --- ---- --- ---
schedule 65154 1721953948 us 26428.98 us 940990.8 us
schedule_hrtimeout_range 9655 920051856 us 95292.78 us 1284647 us
schedule_hrtimeout_range_clock 9655 920046552 us 95292.23 us 1139416 us
poll_schedule_timeout 5562 768940036 us 138248.8 us 13748771 us
do_sys_poll 9188 485558063 us 52846.98 us 6242561 us
SyS_poll 8419 469986128 us 55824.45 us 6183267 us
core_sys_select 1853 283704721 us 153105.6 us 2109401 us
do_select 1853 283689546 us 153097.4 us 3187699 us
SyS_futex 40313 260910692 us 6472.122 us 8796046 us
do_futex 40313 260888660 us 6471.576 us 8397810 us
futex_wait 18824 260325650 us 13829.45 us 4756645 us
4.3.2.2 通用tracer_stat注册register_stat_tracer()
register_stat_tracer()->init_stat_file()->
tracing_stat_open,
.read = seq_read,
.llseek = seq_lseek,
.release = tracing_stat_release
};
tracing_stat_fops);
...
}
trace_stat_seq_ops);
...
}
stat_seq_show
};
session->ts->stat_show(s, l->stat);
}
4.3.2.3 function trace_stat流程
trace_stat/function0相关代码流程如下：
ftrace_init_debugfs()->ftrace_profile_debugfs()->register_stat_tracer()
static const struct file_operations ftrace_profile_fops = {
.open = tracing_open_generic,
.read = ftrace_profile_read,
.write = ftrace_profile_write,
.llseek = default_llseek,
};
/* used to initialize the real stat files */
static struct tracer_stat function_stats __initdata = {
.name = "functions",
.stat_start = function_stat_start,
.stat_next = function_stat_next,
.stat_cmp = function_stat_cmp,
.stat_headers = function_stat_headers,
.stat_show = function_stat_show
};
static __init void ftrace_profile_debugfs(struct dentry *d_tracer)
{
struct ftrace_profile_stat *stat;
struct dentry *entry;
char *name;
int ret;
int cpu;
for_each_possible_cpu(cpu) {
stat = &per_cpu(ftrace_profile_stats, cpu);
/* allocate enough for function name + cpu number */
name = kmalloc(32, GFP_KERNEL);
...
stat->stat = function_stats;
snprintf(name, 32, "function%d", cpu);----------------------会在trace_stat目录下创建function0节点，0表示CPU序号。
stat->stat.name = name;
ret = register_stat_tracer(&stat->stat);--------------------注册function_stats
...
}
entry = debugfs_create_file("function_profile_enabled", 0644,
d_tracer, NULL, &ftrace_profile_fops);----------创建function_profile_enabled节点，函数集为ftrace_profile_fops
...
}
写function_profile_enabled触发代码流程：
static ssize_t
ftrace_profile_write(struct file *filp, const char __user *ubuf,
size_t cnt, loff_t *ppos)
{
unsigned long val;
int ret;
ret = kstrtoul_from_user(ubuf, cnt, 10, &val);
if (ret)
return ret;
val = !!val;
mutex_lock(&ftrace_profile_lock);
if (ftrace_profile_enabled ^ val) {
if (val) {
ret = ftrace_profile_init();
if (ret < 0) {
cnt = ret;
goto out;
}
ret = register_ftrace_profiler();
if (ret < 0) {
cnt = ret;
goto out;
}
ftrace_profile_enabled = 1;
} else {
ftrace_profile_enabled = 0;
/*
* unregister_ftrace_profiler calls stop_machine
* so this acts like an synchronize_sched.
*/
unregister_ftrace_profiler();
}
}
out:
mutex_unlock(&ftrace_profile_lock);
*ppos += cnt;
return cnt;
}
static int register_ftrace_profiler(void)
{
return register_ftrace_graph(&profile_graph_return,
&profile_graph_entry);
}
static void unregister_ftrace_profiler(void)
{
unregister_ftrace_graph();
}
显示profile结果
setup_trace_event);
static __init int event_trace_init(void)
{
struct ftrace_event_call **call;
struct dentry *d_tracer;
struct dentry *entry;
struct dentry *d_events;
int ret;
char *buf = bootup_event_buf;
char *token;
...
while (true) {
token = strsep(&buf, ",");
if (!token)
break;
if (!*token)
continue;
ret = ftrace_set_clr_event(token, 1);
if (ret)
pr_warning("Failed to enable trace event: %s\n", token);
}
...
return 0;
}
4.9.2 ftrace相关设置
在command line中设置ftrace可以在开机时启动指定tracer。
指定tracer在register_tracer()中进行。
static char bootup_tracer_buf[MAX_TRACER_SIZE] __initdata;
static char *default_bootup_tracer;
static int __init set_cmdline_ftrace(char *str)
{
strncpy(bootup_tracer_buf, str, MAX_TRACER_SIZE);
default_bootup_tracer = bootup_tracer_buf;------------------------------------------指定tracer的名称
/* We are using ftrace early, expand it */
ring_buffer_expanded = 1;
return 1;
}
__setup("ftrace=", set_cmdline_ftrace);
int register_tracer(struct tracer *type)
__releases(kernel_lock)
__acquires(kernel_lock)
{
struct tracer *t;
int ret = 0;
...
out:
tracing_selftest_running = false;
mutex_unlock(&trace_types_lock);
if (ret || !default_bootup_tracer)
goto out_unlock;
if (strncmp(default_bootup_tracer, type->name, MAX_TRACER_SIZE))--------------------比较当前注册的tracer是否和ftrace设置的。
goto out_unlock;
printk(KERN_INFO "Starting tracer '%s'\n", type->name);
/* Do we want this tracer to start on bootup? */
tracing_set_tracer(type->name);------------------------------------------------------在注册的时候就指定tracer。
default_bootup_tracer = NULL;
/* disable other selftests, since this will break it. */
tracing_selftest_disabled = 1;
#ifdef CONFIG_FTRACE_STARTUP_TEST
printk(KERN_INFO "Disabling FTRACE selftests due to running tracer '%s'\n",
type->name);
#endif
out_unlock:
return ret;
}
ftrace function_graph分析》
6.0 GCC -pg选项
对比打开-pg和不打开汇编代码，查看区别，以cpu_down为例。分别查看不同选项下的反汇编。
|
未开function/function_graph tracer |
仅开function tracer |
开function/function_graph tracer |
|
0000038c |
000003c0 |
00000400 |
__gnu_mcount_nc定义如下：
ENTRY(__gnu_mcount_nc)
#ifdef CONFIG_DYNAMIC_FTRACE
mov ip, lr
ldmia sp!, {lr}
mov pc, ip
#else
__mcount
#endif
ENDPROC(__gnu_mcount_nc)
6.1 打开哪些选项才能实现ftrace功能？
可以看出在定义了CONFIG_FUNCTION_TRACER、CONFIG_DYNAMIC_FTRACE之后就具备了recordmcount的功能。
如果再定义CONFIG_HAVE_C_RECORDMCOUNT，那么就会使用recordmcount.c而不是recordmcount.pl来进行mcount处理。
.config中定义：
CONFIG_FUNCTION_TRACER=y
CONFIG_HAVE_C_RECORDMCOUNT=y
CONFIG_DYNAMIC_FTRACE=y
CONFIG_FTRACE_MCOUNT_RECORD=y
Makefile中定义：
ifdef CONFIG_FUNCTION_TRACER
ifndef CC_FLAGS_FTRACE
CC_FLAGS_FTRACE := -pg
endif
export CC_FLAGS_FTRACE
ifdef CONFIG_HAVE_FENTRY
CC_USING_FENTRY := $(call cc-option, -mfentry -DCC_USING_FENTRY)
endif
KBUILD_CFLAGS += $(CC_FLAGS_FTRACE) $(CC_USING_FENTRY)
KBUILD_AFLAGS += $(CC_USING_FENTRY)
ifdef CONFIG_DYNAMIC_FTRACE
ifdef CONFIG_HAVE_C_RECORDMCOUNT
BUILD_C_RECORDMCOUNT := y
export BUILD_C_RECORDMCOUNT
endif
endif
endif
Makefile.build中定义：
ifdef CONFIG_FTRACE_MCOUNT_RECORD
ifdef BUILD_C_RECORDMCOUNT
ifeq ("$(origin RECORDMCOUNT_WARN)", "command line")
RECORDMCOUNT_FLAGS = -w
endif
# Due to recursion, we must skip empty.o.
# The empty.o file is created in the make process in order to determine
# the target endianness and word size. It is made before all other C
# files, including recordmcount.
sub_cmd_record_mcount = \
if [ $(@) != "scripts/mod/empty.o" ]; then \
$(objtree)/scripts/recordmcount $(RECORDMCOUNT_FLAGS) "$(@)"; \
fi;
recordmcount_source := $(srctree)/scripts/recordmcount.c \
$(srctree)/scripts/recordmcount.h
else...
endif
...
# Built-in and composite module parts
$(obj)/%.o: $(src)/%.c $(recordmcount_source) FORCE
$(call cmd,force_checksrc)
$(call if_changed_rule,cc_o_c)
# Single-part modules are special since we need to mark them in $(MODVERDIR)
$(single-used-m): $(obj)/%.o: $(src)/%.c $(recordmcount_source) FORCE
$(call cmd,force_checksrc)
$(call if_changed_rule,cc_o_c)
@{ echo $(@:.o=.ko); echo $@; } > $(MODVERDIR)/$(@F:.o=.mod)
6.2 ftrace的mcount功能是如何实现的？
在Documentation/trace/ftrace.txt中有一段解释：
If CONFIG_DYNAMIC_FTRACE is set, the system will run with virtually no overhead when function tracing is disabled.
The way this works is the mcount function call (placed at the start of every kernel function, produced by the -pg switch in gcc), starts of pointing to a simple return. (Enabling FTRACE will include the -pg switch in the compiling of the kernel.) At compile time every C file object is run through the recordmcount program (located in the scripts directory).
This program will parse the ELF headers in the C object to find all the locations in the .text section that call mcount.
(Note, only white listed .text sections are processed,
since processing other sections like .init.text may cause races due to those sections being freed unexpectedly). A new section called "__mcount_loc" is created that holds references to all the mcount call sites in the .text section. The recordmcount program re-links this section back into the original object.
The final linking stage of the kernel will add all these references into a single table.
在c文件编译完之后，recordmcount增加一个__mcount_loc段。
在vmlinux.lds.h文件中对__mcount_loc段归集，在系统初始化的时候有两个参数很重要__start_mcount_loc和__stop_mcount_loc。
在available_function
#define MCOUNT_REC() . = ALIGN(8); \
VMLINUX_SYMBOL(__start_mcount_loc) = .; \
*(__mcount_loc) \
VMLINUX_SYMBOL(__stop_mcount_loc) = .;
/* init and exit section handling */
#define INIT_DATA \
*(.init.data) \
...
KERNEL_CTORS() \
*(.init.rodata) \
MCOUNT_REC() \
...
KERNEL_DTB()
#define INIT_DATA_SECTION(initsetup_align) \
.init.data : AT(ADDR(.init.data) - LOAD_OFFSET) { \
INIT_DATA \
...
}
6.3 引入ftrace对性能的影响有多大？
在不使用的时候在入口点插入nop，在使用的时候才会替换成
On boot up, before SMP is initialized, the dynamic ftrace code scans this table and updates all the locations into nops.
It also records the locations, which are added to the available_filter_functions list.
在启动阶段，SMP初始化之前，ftrace扫描__mcount_loc段，将所有入口地址mcount使用nop替代。这样只要不打开，开销非常小，基本上不产生性能影响。
Modules are processed as they are loaded and before they are executed.
When a module is unloaded, it also removes its functions from the ftrace function list.
This is automatic in the module unload code, and the module author does not need to worry about it. When tracing is enabled, the process of modifying the function tracepoints is dependent on architecture.
... The new method of modifying the function tracepoints is to place a breakpoint at the location to be modified,
sync all CPUs, modify the rest of the instruction not covered by the breakpoint.
Sync all CPUs again, and then remove the breakpoint with the finished version to the ftrace call site.
在内核初始化的初期，ftrace 查询 __mcount_loc 段，得到每个函数的入口地址，并将 mcount 替换为 nop 指令。这样在默认情况下，ftrace 不会对内核性能产生影响。
当用户打开 ftrace 功能时，ftrace 将这些 nop 指令动态替换为 ftrace_caller，该函数将调用用户注册的 trace 函数。
6.4 核心函数ftrace_caller/ftrace_graph_caller
#ifdef CONFIG_DYNAMIC_FTRACE
ENTRY(ftrace_caller)
UNWIND(.fnstart)
__ftrace_caller
UNWIND(.fnend)
ENDPROC(ftrace_caller)
#endif
.macro __ftrace_caller suffix
mcount_enter------------------------------------宏mcount_enter
mcount_get_lr r1 @ lr of instrumented func
mcount_adjust_addr r0, lr @ instrumented function
.globl ftrace_call\suffix
ftrace_call\suffix:
bl ftrace_stub
#ifdef CONFIG_FUNCTION_GRAPH_TRACER
.globl ftrace_graph_call\suffix
ftrace_graph_call\suffix:
mov r0, r0
#endif
mcount_exit------------------------------------宏mcount_exit
.endm
.macro mcount_enter----------------------------------mcount_enter定义
stmdb sp!, {r0-r3, lr}
.endm
.macro mcount_get_lr reg
ldr \reg, [fp, #-4]
.endm
.macro mcount_exit---------------------------------mcount_exit定义
ldr lr, [fp, #-4]
ldmia sp!, {r0-r3, pc}
.endm
function_graph：
#ifdef CONFIG_FUNCTION_GRAPH_TRACER
ENTRY(ftrace_graph_caller)
UNWIND(.fnstart)
__ftrace_graph_caller
UNWIND(.fnend)
ENDPROC(ftrace_graph_caller)
#endif
.macro __ftrace_graph_caller
sub r0, fp, #4 @ &lr of instrumented routine (&parent)
#ifdef CONFIG_DYNAMIC_FTRACE
@ called from __ftrace_caller, saved in mcount_enter
ldr r1, [sp, #16] @ instrumented routine (func)
mcount_adjust_addr r1, r1
#else
@ called from __mcount, untouched in lr
mcount_adjust_addr r1, lr @ instrumented routine (func)
#endif
mov r2, fp @ frame pointer
bl prepare_ftrace_return
mcount_exit
.endm
参考文档：
1. The Linux Kernel Tracepoint API
2. Linux内核跟踪之trace框架分析
3. linux ftrace追踪一（基本技术结构粗略剖析）
4. 使用 ftrace 调试 Linux 内核，第 1 部分 & 使用 ftrace 调试 Linux 内核，第 2 部分 & 使用 ftrace 调试 Linux 内核，第 3 部分
5. Linux Tracepoint内核文档
6. ftrace简介
联系方式:arnoldlu@qq.com