本文主要是介绍Kernel调试追踪技术之 Ftrace on ARM64,希望对大家解决编程问题提供一定的参考价值,需要的开发者们随着小编来一起学习吧!
仅用于学习记录
转自:【原创】Kernel调试追踪技术之 Ftrace on ARM64 - HPYU - 博客园 (cnblogs.com)
本文目标:
- 理解Ftrace的一些关键实现方式,理解动态替换技术
- 理解Ftrace对性能的影响
1. Ftrace简介
Ftrace 是Kernel的官方tracing 框架。初始开发者和maintainer是Steven Rostedt,在2008年合入Kernel。
其全名是Function trace,但是功能不只有函数跟踪,还包含了静态trace event、动态trace event、stack trace、latency tracer等功能,是一个完善的trace 框架。同时提供统计、过滤、触发等功能,方便trace log的捕获和分析。
Ftrace使用per-cpu的trace buffer,buffer内容为二进制格式,执行效率高。设置CONFIG_DYNAMIC_FTRACE
后,加入的trace功能在不使用时对系统性能几乎没有影响。
从下图可以看到ftrace和Linux上其它tracing系统的关系:
[From Julia Evans](From Julia Evans](https://jvns.ca/blog/2017/07/05/linux-tracing-systems/)
2. Ftrace的使用
Ftrace的使用可以分成三种类型:
- 应用层通过tracefs文件设置,应用程序通过trace_marker插入log
- kernel中自定义trace event
- kernel中使用ftrace的API,比如trace_printk,tracing_on/off()等。
还有一些前端工具,比如命令行工具trace-cmd
, UI工具kernelShare
等可以方便tracefs的配置和显示。
2.1 通过tracefs的使用
ftracefs的官方文档是 kernel/Documentation/trace/ftrace.txt,详细介绍了ftrace的主要功能,建议仔细阅读。
tracefs默认挂载在/sys/kernel/debug/tracing/
目录下,第一层目录有50多个文件和目录,比较繁杂,Ftrace的配置和使用 中做了分类整理,并附有执行示例,建议逐个执行一遍,会有比较清晰的认识。
ftrace的 log主要有两种类型,一种是时间线的trace log,一种是记录最大latency log。
log显示格式类似,都会显示出执行程序名称、PID、CPU ID、 irq和抢占状态、时间戳、trace到的函数和父函数。
-
function tracer示例:
# tracer: function # # entries-in-buffer/entries-written: 140080/250280 #P:4 # # _-----=> irqs-off # / _----=> need-resched # | / _---=> hardirq/softirq # || / _--=> preempt-depth # ||| / delay # TASK-PID CPU# |||| TIMESTAMP FUNCTION # | | | |||| | |bash-1977 [000] .... 17284.993652: sys_close <-system_call_fastpathbash-1977 [000] .... 17284.993653: __close_fd <-sys_closebash-1977 [000] .... 17284.993653: _raw_spin_lock <-__close_fdsshd-1974 [003] .... 17284.993653: __srcu_read_unlock <-fsnotifybash-1977 [000] .... 17284.993654: add_preempt_count <-_raw_spin_lockbash-1977 [000] ...1 17284.993655: _raw_spin_unlock <-__close_fdbash-1977 [000] ...1 17284.993656: sub_preempt_count <-_raw_spin_unlockbash-1977 [000] .... 17284.993657: filp_close <-__close_fdbash-1977 [000] .... 17284.993657: dnotify_flush <-filp_closesshd-1974 [003] .... 17284.993658: sys_select <-system_call_fastpath--------
latency log只记录最大latency的调用区段,比如irqsoff显示从irq off到on的一个最大延迟,会显示完整的调用栈。tracefs里的stack_trace
会记录最大堆栈的调用栈。
-
irqoff latency 示例
# tracer: irqsoff # # irqsoff latency trace v1.1.5 on 3.8.0-test+ # ------------------------------------------------------------------- # latency: 259 us, #4/4, CPU#2 | (M:preempt VP:0, KP:0, SP:0 HP:0 #P:4) # ----------------- # | task: ps-6143 (uid:0 nice:0 policy:0 rt_prio:0) # ----------------- # => started at: __lock_task_sighand # => ended at: _raw_spin_unlock_irqrestore # # # _------=> CPU# # / _-----=> irqs-off # | / _----=> need-resched # || / _---=> hardirq/softirq # ||| / _--=> preempt-depth # |||| / delay # cmd pid ||||| time | caller # \ / ||||| \ | / ps-6143 2d... 0us!: trace_hardirqs_off <-__lock_task_sighandps-6143 2d..1 259us+: trace_hardirqs_on <-_raw_spin_unlock_irqrestoreps-6143 2d..1 263us+: time_hardirqs_on <-_raw_spin_unlock_irqrestoreps-6143 2d..1 306us : <stack trace>=> trace_hardirqs_on_caller=> trace_hardirqs_on=> _raw_spin_unlock_irqrestore=> do_task_stat=> proc_tgid_stat=> proc_single_show=> seq_read=> vfs_read=> sys_read=> system_call_fastpath
2.2 通过TRACE_EVENT定义 trace event
内核或驱动模块可以定义自己的静态trace event。定义代码可以放在include/trace/events/
或者驱动目录下。
在Kernel 4.14.74的典型运行时系统中,有1000+的trace event。
Trace Event是用include/linux/tracepoint.h
提供的宏接口来定义的。宏封装的是tracepoint的定义、注册和trace接口的定义。
Trace event定义好以后,在内核代码中调用。
-
include/linux/tracepoint.h
中有说明注释:370 /* 371 * For use with the TRACE_EVENT macro: 372 * 373 * We define a tracepoint, its arguments, its printk format 374 * and its 'fast binary record' layout. 375 * 376 * Firstly, name your tracepoint via TRACE_EVENT(name : the 377 * 'subsystem_event' notation is fine. 378 * 379 * Think about this whole construct as the 380 * 'trace_sched_switch() function' from now on. 381 * 382 * 383 * TRACE_EVENT(sched_switch, 384 * 385 * * 386 * * A function has a regular function arguments 387 * * prototype, declare it via TP_PROTO(): 388 * * 389 * 390 * TP_PROTO(struct rq *rq, struct task_struct *prev, 391 * struct task_struct *next), 392 * 393 * * 394 * * Define the call signature of the 'function'. 395 * * (Design sidenote: we use this instead of a 396 * * TP_PROTO1/TP_PROTO2/TP_PROTO3 ugliness.) 397 * * 398 * 399 * TP_ARGS(rq, prev, next), 400 * 401 * * 402 * * Fast binary tracing: define the trace record via 403 * * TP_STRUCT__entry(). You can think about it like a 404 * * regular C structure local variable definition. 405 * * 406 * * This is how the trace record is structured and will 407 * * be saved into the ring buffer. These are the fields 408 * * that will be exposed to user-space in 409 * * /sys/kernel/debug/tracing/events/<*>/format. 410 * * 411 * * The declared 'local variable' is called '__entry' 412 * * 413 * * __field(pid_t, prev_prid) is equivalent to a standard declariton: 414 * * 415 * * pid_t prev_pid; 416 * * 417 * * __array(char, prev_comm, TASK_COMM_LEN) is equivalent to: 418 * * 419 * * char prev_comm[TASK_COMM_LEN]; 420 * * 421 * 422 * TP_STRUCT__entry( 423 * __array( char, prev_comm, TASK_COMM_LEN ) 424 * __field( pid_t, prev_pid ) 425 * __field( int, prev_prio ) 426 * __array( char, next_comm, TASK_COMM_LEN ) 427 * __field( pid_t, next_pid ) 428 * __field( int, next_prio ) 429 * ),
定义一个Trace Event使用了5个宏:
TRACE_EVENT
定义一个tracepoint,它是最上层的宏,下面2-6作为它的参数TP_PROTO
定义函数原型,指定每个参数的类型TP_ARGS
列出所有参数,tracepoint的回调函数会用到TP_STRUCT__entry
定义要存入ring buffer的数据格式TP_fast_assign
对存入ring buffer的数据赋值,赋值来自前面的argsTP_printk
定义打印成可读log的格式
TRACE_EVENT(ext4_allocate_inode, TP_PROTO(struct inode *inode, struct inode *dir, int mode),TP_ARGS(inode, dir, mode), TP_STRUCT__entry( __field( dev_t, dev ) __field( ino_t, ino ) __field( ino_t, dir ) __field( __u16, mode ) ), TP_fast_assign( __entry->dev = inode->i_sb->s_dev; __entry->ino = inode->i_ino; __entry->dir = dir->i_ino; __entry->mode = mode; ), TP_printk("dev %d,%d ino %lu dir %lu mode 0%o", MAJOR(__entry->dev), MINOR(__entry->dev), (unsigned long) __entry->ino, (unsigned long) __entry->dir, __entry->mode) );
TRACE_EVENT会定义一个名为trace_xxx的接口函数,比如
trace_ext4_allocate_inode(struct inode *inode, struct inode *dir, int mode)
,驱动模块调用这个接口就插入了一个tracepoint。
vi fs/ext4/ialloc.c
struct inode *__ext4_new_inode(handle_t *handle, struct inode *dir,...ext4_debug("allocating inode %lu\n", inode->i_ino);trace_ext4_allocate_inode(inode, dir, mode); // 调用Trace event接口brelse(inode_bitmap_bh);return ret;...
}或者
struct inode *__ext4_new_inode(handle_t *handle, struct inode *dir,...ext4_debug("allocating inode %lu\n", inode->i_ino);if (trace_ext4_allocate_inode_enabled()) {// -- do something about paraments here ----trace_ext4_allocate_inode(inode, dir, mode); // 调用Trace event接口}brelse(inode_bitmap_bh);return ret;...
}
这个trace event在tracefs中的events/sysxxx/eventxxx/format
中可以看到具体格式
从format可以看到,前4个field是trace的通用信息,包括type
、flags
、prempt_count
和pid
第5个开始是定义的数据域,dev
、ino
、dir
、mode
,然后是打印格式。
这里定义的数据域是在二进制的trace buffer中的格式,cat trace或者trace-cmd等工具会把这个trace buffer中的二进制格式解析并打印。
# cat /sys/kernel/debug/tracing/events/ext4/ext4_allocate_inode/format
name: ext4_allocate_inode
ID: 746
format:field:unsigned short common_type; offset:0; size:2; signed:0;field:unsigned char common_flags; offset:2; size:1; signed:0;field:unsigned char common_preempt_count; offset:3; size:1; signed:0;field:int common_pid; offset:4; size:4; signed:1;field:dev_t dev; offset:8; size:4; signed:0;field:ino_t ino; offset:16; size:8; signed:0;field:ino_t dir; offset:24; size:8; signed:0;field:__u16 mode; offset:32; size:2; signed:0;print fmt: "dev %d,%d ino %lu dir %lu mode 0%o", ((unsigned int) ((REC->dev) >> 20)), ((unsigned int) ((REC->dev) & ((1U << 20) - 1))), (unsigned long) REC->ino, (unsigned long) REC->dir, REC->mode
-
实例:增加一个打印温度传感器抽样值的trace event
// drivers/hwmon/comp-ts_trace.h #undef TRACE_SYSTEM #define TRACE_SYSTEM trts //定义subsys,对应events下的目录#if !defined(comp_ts_TRACEE_H) || defined(TRACE_HEADER_MULTI_READ) #define comp_ts_TRACEE_H#include <linux/tracepoint.h> TRACE_EVENT(ts_irq_samples,TP_PROTO(struct ts_device *ts),TP_ARGS(ts),TP_STRUCT__entry(__field(int, irq)__array(int, smpl, 4)),TP_fast_assign(__entry->irq = ts->irq;__entry->smpl[0] = ts->cur_smpl[0];__entry->smpl[1] = ts->cur_smpl[1];__entry->smpl[2] = ts->cur_smpl[2];__entry->smpl[3] = ts->cur_smpl[3];),TP_printk("SMPL_TS[0]:%d, SMPL_TS[1]:%d, SMPL_TS[2]:%d, SMPL_TS[3]:%d",__entry->smpl[0], __entry->smpl[1], __entry->smpl[2], __entry->smpl[3]) );TRACE_EVENT(ts_temp,TP_PROTO(struct ts_device *ts ),TP_ARGS(ts),TP_STRUCT__entry(__field(int, avg)__array(int, temp, 4)),TP_fast_assign(__entry->avg = ts->cur_temp_avg;__entry->temp[0] = ts->cur_temp[0];__entry->temp[1] = ts->cur_temp[1];__entry->temp[2] = ts->cur_temp[2];__entry->temp[3] = ts->cur_temp[3];),TP_printk("temp_avg:%d, temp_TS[0]:%d, temp_TS[1]:%d, temp_TS[2]:%d, temp_TS[3]:%d",__entry->avg, __entry->temp[0], __entry->temp[1],__entry->temp[2], __entry->temp[3]) );#endif#undef TRACE_INCLUDE_PATH #undef TRACE_INCLUDE_FILE #define TRACE_INCLUDE_PATH ../../drivers/hwmon/ // 指定comp-ts_trace.h 头文件路径 #define TRACE_INCLUDE_FILE comp-ts_trace /* This part must be outside protection */ #include <trace/define_trace.h>
diff --git a/drivers/hwmon/comp-ts.c b/drivers/hwmon/comp-ts.c index fcac293b1..002e77f0f 100755 --- a/drivers/hwmon/comp-ts.c +++ b/drivers/hwmon/comp-ts.c @@ -71,6 +71,9 @@ struct ts_device {spinlock_t lock;};+#define CREATE_TRACE_POINTS // 定义struct tracepoint +#include "comp-ts_trace.h" +static inline u32 ts_reg_rd(struct ts_device *dev, u32 reg){return ioread32(dev->reg_base + reg); @@ -207,6 +210,9 @@ static int ts_temp_read(struct device *dev, enum hwmon_sensor_types type,pr_debug("avg:%ld, min:%ld, max:%ld, diff:%ld\n",ts_dev->cur_temp_avg, temp_min, temp_max, diff);+ trace_ts_irq_samples(ts_dev); + trace_ts_temp(ts_dev); +spin_unlock_irqrestore(&ts_dev->lock, flags);return 0; @@ -269,6 +275,7 @@ static irqreturn_t ts_irq_handler(int irq, void *dev_id)int i = 0;ts_status = ts_reg_rd(ts_dev, IRQ_TS_STATUS_ADDR); + trace_ts_irq_samples(ts_dev);spin_lock(&ts_dev->lock);for (i = 0; i < ts_NUM; i++) { @@ -313,6 +320,7 @@ static irqreturn_t ts_irq_handler(int irq, void *dev_id)ts_reg_wr(ts_dev, IRQ_TS_MASK_ADDR, ts_MASK);ts_dev->updated = 1;} + trace_ts_irq_samples(ts_dev);return IRQ_HANDLED;}
打开event后,得到如下log:
# echo 1> /sys/kernel/debug/tracing/events/trts/enable root:/sys/kernel/debug/tracing# cat trace # tracer: nop # # _-----=> irqs-off # / _----=> need-resched # | / _---=> hardirq/softirq # || / _--=> preempt-depth # ||| / delay # TASK-PID CPU# |||| TIMESTAMP FUNCTION # | | | |||| | |<idle>-0 [000] d.H1 35.151111: ts_irq_samples: SMPL_TS[0]:1866, SMPL_TS[1]:1876, SMPL_TS[2]:1871, SMPL_TS[3]:1881<idle>-0 [000] d.H1 35.151122: ts_irq_samples: SMPL_TS[0]:1867, SMPL_TS[1]:1877, SMPL_TS[2]:1872, SMPL_TS[3]:1881<idle>-0 [000] dnH1 35.175116: ts_irq_samples: SMPL_TS[0]:1867, SMPL_TS[1]:1877, SMPL_TS[2]:1872, SMPL_TS[3]:1881<idle>-0 [000] dnH1 35.175122: ts_irq_samples: SMPL_TS[0]:1866, SMPL_TS[1]:1874, SMPL_TS[2]:1871, SMPL_TS[3]:1883
2.3 可用的trace API
除了trace event的宏定义接口以外,include/linux/kernel.h
中还提供了一些trace打印和控制接口
int trace_printk(const char *fmt, ...)
void tracing_on(void);
void tracing_off(void);
int tracing_is_on(void);
void tracing_snapshot(void);
void tracing_snapshot_alloc(void);extern void tracing_start(void);
extern void tracing_stop(void);
extern void ftrace_dump(enum ftrace_dump_mode oops_dump_mode);
extern void trace_dump_stack(int skip);
使用trace_printk()
可以向trace buffer中插入log,相比printk,可以输出cpuid、pid、irq/preempts状态等更多信息,且因为是per-cpu的buffer,性能影响比printk低,适用于对性能敏感的代码中。
2.4 内核启动参数和sysctrl设置ftrace
启动时,也可以通过内核参数对ftrace进行配置。
https://01.org/linuxgraphics/gfx-docs/drm/admin-guide/kernel-parameters.html
trace_buf_size=nn[KMG]
trace_event=[event-list]
trace_options=[option-list]
tp_printk[FTRACE] // 把trace log 打印到kernel log buffer
traceoff_on_warning
alloc_snapshot [FTRACE]
ftrace=[tracer]
ftrace_dump_on_oops[=orig_cpu] // panic 时dump ftrace 也很有用
ftrace_filter=[function-list]
ftrace_notrace=[function-list]
ftrace_graph_filter=[function-list]
ftrace_graph_notrace=[function-list]
ftrace_graph_max_depth=<uint>
kprobe_event=[probe-list]
rcupdate.rcu_cpu_stall_ftrace_dump= [KNL]
stacktrace [FTRACE]
stacktrace_filter=[function-list]
/proc/sys/kernel
的sysctrl
有几个ftrace相关的全局配置。
/proc/sys/kernel/ftrace_dump_on_oops // oops打印ftrace log
/proc/sys/kernel/ftrace_enabled // ftrace全局开关,默认是1,设0时tracefs中无法打开trace
/proc/sys/kernel/stack_tracer_enabled
/proc/sys/kernel/traceoff_on_warning
/proc/sys/kernel/tracepoint_printk // 把trace log打印到printk log bfufer,用于早期启动debug
3. Ftrace的实现
Ftrace是多个tracing技术的结合,这里按照function trace、静态tracepoint、动态tracepoint和tracer来介绍主要的trace功能的实现。
3.1 Function Trace的实现
Ftrace是function trace的简称,但是function trace只是ftrace里面的一个功能,它可以作为function tracer工作,也可以和其它tracer一起工作,跟踪每个函数的调用关系。
function trace是基于gcc的-pg
参数插入mcount
函数实现的,这部分依赖于处理器架构,文档 Documentation/trace/ftrace-design.txt 中详细介绍了kernel中实现一个处理器架构支持mcount
需要的接口。
mcount
在不同处理器的gcc
实现名字可能略有差异,可能是mcount
,_mcount
或者__mcount
,可以通过下面命令查看,arm64中是_mcount
本文统一使用mcount。
$ echo 'main(){}' | aarch64-linux-gnu-gcc -x c -S -o - - -pg | grep mcount
<stdin>:1:1: warning: return type defaults to ‘int’ [-Wimplicit-int].global _mcountbl _mcount
ARM64的实现主要有下面三个文件
arch/arm64/kernel/entry-ftrace.S // mcount的核心实现
arch/arm64/kernel/ftrace.c // CONFIG_DYNAMIC_FTRACE 的支持接口
arch/arm64/include/asm/ftrace.h // 声明和定义arm64为ftrace核心模块提供的接口
mcount的主要任务是根据是否打开了ftrace,跳转到对应的注册函数中,做进步一处理。
3.1.1 静态mcount实现
Kernel中打开CONFIG_FUNCTION_TRACER
后,会增加-pg
编译选项,这样在每个函数入口处都会插入bl mcount
跳转指令,函数运行时会进入mcount
函数。mcount
会判断函数指针ftrace_trace_function
是否被注册,默认注册的是空函数ftrace_stub
,只有打开function tracer后才会注册具体的处理函数ftrace_trace_function
。
Makefile:
766 ifdef CONFIG_FUNCTION_TRACER
767 ifndef CC_FLAGS_FTRACE
768 CC_FLAGS_FTRACE := -pg
769 endif
770 export CC_FLAGS_FTRACE
(gdb) disassemble platform_get_irq
Dump of assembler code for function platform_get_irq:0xffffff8008579d68 <+0>: stp x29, x30, [sp, #-32]!0xffffff8008579d6c <+4>: mov x29, sp0xffffff8008579d70 <+8>: stp x19, x20, [sp, #16]0xffffff8008579d74 <+12>: mov x19, x00xffffff8008579d78 <+16>: mov w20, w10xffffff8008579d7c <+20>: mov x0, x30 // X30(LR)作为第一个参数,ARM64 kernel中实际不使用这个参数0xffffff8008579d80 <+24>: bl 0xffffff8008093694 <_mcount> <== 跳入_mcount0xffffff8008579d84 <+28>: ldr x0, [x19, #904]0xffffff8008579d88 <+32>: cbz x0, 0xffffff8008579da4 <platform_get_irq+60>
另外,如果配置了CONFIG_FUNCTION_GRAPH_TRACER
,就不再是注册ftrace_trace_function
,而是注册ftrace_graph_entry
和ftrace_graph_return
。function graph tracer是function trace的增强版,可以打印出完整的函数调用关系。
下图是静态ftrace中mount调用的function trace和function graph trace的实现流程, 代码在arch/arm64/kernel/entry-ftrace.S
3.1.2 Dynamic Ftrace
如果配置了CONFIG_DYNAMIC_FTRACE
, mcount
会被实现成一个空函数(只有一条ret
指令)。在系统启动时,mcount会被替换成nop
指令。打开tracer后,所有函数的对应位置会被动态替换成跳转到ftrace_caller()
的指令。
-
Dynamic Ftrace 代码
#else /* CONFIG_DYNAMIC_FTRACE */ /* * _mcount() is used to build the kernel with -pg option, but all the branch * instructions to _mcount() are replaced to NOP initially at kernel start up,* and later on, NOP to branch to ftrace_caller() when enabled or branch to * NOP when disabled per-function base. */ ENTRY(_mcount) ret ENDPROC(_mcount) /* * void ftrace_caller(unsigned long return_address) * @return_address: return address to instrumented function * * This function is a counterpart of _mcount() in 'static' ftrace, and * makes calls to: * - tracer function to probe instrumented function's entry, * - ftrace_graph_caller to set up an exit hook */ ENTRY(ftrace_caller) mcount_enter mcount_get_pc0 x0 // function's pc mcount_get_lr x1 // function's lr .global ftrace_call ftrace_call: // tracer(pc, lr); nop // This will be replaced with "bl xxx" // where xxx can be any kind of tracer. #ifdef CONFIG_FUNCTION_GRAPH_TRACER .global ftrace_graph_call ftrace_graph_call: // ftrace_graph_caller(); nop // If enabled, this will be replaced // "b ftrace_graph_caller" #endif mcount_exit ENDPROC(ftrace_caller) #endif /* CONFIG_DYNAMIC_FTRACE */
为了动态替换,需要在编译阶段就知道mcount在每个函数中的位置,这是通过scripts/recordmcount.pl
脚本在.o 编译后链接前记录的。所有的记录保存在kernel镜像或者xxx.ko的__mcount_loc
section里,在ftrace_init()
和ftrace_module_init()
会为这些记录(record)分配record pages内存页存放,使用指针ftrace_pages_start
指向的record pages,运行时动态打开tracer时,会做替换。
void __init ftrace_init(void)
{ret = ftrace_process_locs(NULL, //在这里替换__start_mcount_loc,__stop_mcount_loc);
}#ifdef CONFIG_FTRACE_MCOUNT_RECORD
#define MCOUNT_REC() . = ALIGN(8); \VMLINUX_SYMBOL(__start_mcount_loc) = .; \*(__mcount_loc) \VMLINUX_SYMBOL(__stop_mcount_loc) = .;
#else
#define MCOUNT_REC()
#endif
替换3万多个函数用时14ms左右
crash> sym __start_mcount_loc
ffffff8008ced458 (T) __start_mcount_loc
crash> sym __stop_mcount_loc
ffffff8008d28b88 (T) __stop_mcount_loc[ 0.000000] .text : 0xffffff8008080000 - 0xffffff8008930000 ( 8896 KB)
[ 0.000000] .rodata : 0xffffff8008930000 - 0xffffff8008c50000 ( 3200 KB)
[ 0.000000] .init : 0xffffff8008c50000 - 0xffffff8008d50000 ( 1024 KB)
[ 0.000000] .data : 0xffffff8008d50000 - 0xffffff8008eb2008 ( 1417 KB)
[ 0.000000] .bss : 0xffffff8008eb2008 - 0xffffff8009a49e00 ( 11872 KB)这个替换大概用了14ms
[3.281092 0.001971] [ 0.000000] ---ftrace_init start---
[3.281930 0.000838] [ 0.000000] ftrace: allocating 30444 entries in 119 pages
[3.295482 0.013552] [ 0.000000] ---ftrace_init end---在ftrace_replace_code中做计数,总共替换了31726个函数。
[ 136.262494] --ftrace_replace_code---count:31726
通过tracefs或者sysctrl 打开ftrace功能时,会把record对应位置替换成调用ftrace_caller()
下面是设置/proc/sys/kernel/ftrace_enabled
时的执行更新操作。
- ftrace_enable_sysctl
- update_ftrace_function
- 获取
ftrace_ops_list
头部的ftrace_ops
- 获取
- ftrace_startup_sysctl
- ftrace_startup_enable
- ftrace_run_update_code(command);
- arch_ftrace_update_code(command);
- ftrace_modify_all_code(command);
-
ftrace_replace_code
do_for_each_ftrace_rec(pg, rec) {if (rec->flags & FTRACE_FL_DISABLED) continue;failed = __ftrace_replace_code(rec, enable);if (failed) {ftrace_bug(failed, rec);/* Stop processing */return;} } while_for_each_ftrace_rec();
- ftrace_make_call
- ftrace_modify_code
- ftrace_make_call
-
- ftrace_modify_all_code(command);
- arch_ftrace_update_code(command);
- ftrace_run_update_code(command);
- ftrace_startup_enable
- update_ftrace_function
3.2 静态Trace event的实现
3.2.1 Kernel的tracepoint 概念
静态trace event就是在kernel代码中插入trace 代码。
2.2 节讲的Trace event的定义和我们在/sys/kernel/debug/tracing/events
里控制的trace event,是通过kernel 的tracepoint接口实现的,源码和文档是:
kernel/tracepoint.c // tracepoint核心实现
include/linux/tracepoint.h // tracepoint 宏接口头文件,
Documentation/trace/tracepoints.txt // 介绍tracepoint的使用方法
kernel的tracepoint是一个通用接口,用来定义个trace 点。
除了ftrace以外, perf、LTTng、Systemtap等trace 框架也会使用。
struct tracepoint { const char *name; /* Tracepoint name */struct static_key key; /* 用来控制trace的enable 和disable */ int (*regfunc)(void); /* tracepoint 注册回调函数*/void (*unregfunc)(void);struct tracepoint_func __rcu *funcs; /* tracepint 执行回调函数数组, 即可以有多个回调函数 */
};
struct tracepoint_func {void *func;void *data;int prio;
};
tracepoint的定义非常简单,主要是实现一个tracepoint对象的注册函数和回调函数。但是实际要适配各种类型回调函数的注册,又要考虑执行效率、接口易用性,实际提供的是类似于模板的宏定义接口, 在include/linux/tracepoint.h
中提供。
#define TRACE_EVENT(name, proto, args, struct, assign, print) // 定义个tracepoint#define DECLARE_EVENT_CLASS(name, proto, args, tstruct, assign, print) // 定义一个tracepoint类
#define DEFINE_EVENT(template, name, proto, args) // 定义属于一个类的tracepoint这些宏最终的调用的是__DECLARE_TRACE:
185 #define __DECLARE_TRACE(name, proto, args, cond, data_proto, data_args) \
186 extern struct tracepoint __tracepoint_##name; \
187 static inline void trace_##name(proto) \
188 { \
189 if (static_key_false(&__tracepoint_##name.key)) \
190 __DO_TRACE(&__tracepoint_##name, \
191 TP_PROTO(data_proto), \
192 TP_ARGS(data_args), \
193 TP_CONDITION(cond), 0); \
194 if (IS_ENABLED(CONFIG_LOCKDEP) && (cond)) { \
195 rcu_read_lock_sched_notrace(); \
196 rcu_dereference_sched(__tracepoint_##name.funcs);\
197 rcu_read_unlock_sched_notrace(); \
198 } \
199 } \
200 __DECLARE_TRACE_RCU(name, PARAMS(proto), PARAMS(args), \
201 PARAMS(cond), PARAMS(data_proto), PARAMS(data_args)) \
202 static inline int \
203 register_trace_##name(void (*probe)(data_proto), void *data) \ //生成多个函数
204 { \
205 return tracepoint_probe_register(&__tracepoint_##name, \
206 (void *)probe, data); \
207 } \
208 static inline int \
209 register_trace_prio_##name(void (*probe)(data_proto), void *data,\
210 int prio) \
211 { \
212 return tracepoint_probe_register_prio(&__tracepoint_##name, \
213 (void *)probe, data, prio); \
214 } \
215 static inline int \
216 unregister_trace_##name(void (*probe)(data_proto), void *data) \
217 { \
218 return tracepoint_probe_unregister(&__tracepoint_##name,\
219 (void *)probe, data); \
220 } \
221 static inline void \
222 check_trace_callback_type_##name(void (*cb)(data_proto)) \
223 { \
224 } \
225 static inline bool \
226 trace_##name##_enabled(void) \
227 { \
228 return static_key_false(&__tracepoint_##name.key); \
229 }
接口越易用,往往实现越复杂。
这些宏的定义比较复杂难懂,带有很多编译、链接相关信息,可读性很差。
可以在kernel编译过程中生成的预处理文件来看看生成的数据结构和trace函数实现是什么样的。
在Kernel/Makefile编译选项里加入-save-temps
就会保存宏展开的预处理的.i 和汇编的.s 文件了,也可以在驱动模块里加入,减少文件量。
ifdef CONFIG_DEBUG_INFO_SPLITKBUILD_CFLAGS += $(call cc-option, -gsplit-dwarf, -g)else
-KBUILD_CFLAGS += -g
+KBUILD_CFLAGS += -g -save-tempsendif
以sched_switch
event为例
include/trace/events/sched.h
125 /*
126 * Tracepoint for task switches, performed by the scheduler:
127 */
128 TRACE_EVENT(sched_switch,
129
130 TP_PROTO(bool preempt,
131 struct task_struct *prev,
132 struct task_struct *next),
133
134 TP_ARGS(preempt, prev, next),
135
136 TP_STRUCT__entry(
137 __array( char, prev_comm, TASK_COMM_LEN )
138 __field( pid_t, prev_pid )
139 __field( int, prev_prio )
140 __field( long, prev_state )
141 __array( char, next_comm, TASK_COMM_LEN )
142 __field( pid_t, next_pid )
143 __field( int, next_prio )
144 ),
145
146 TP_fast_assign(
147 memcpy(__entry->next_comm, next->comm, TASK_COMM_LEN);
148 __entry->prev_pid = prev->pid;
149 __entry->prev_prio = prev->prio;
150 __entry->prev_state = __trace_sched_switch_state(preempt, prev);
151 memcpy(__entry->prev_comm, prev->comm, TASK_COMM_LEN);
152 __entry->next_pid = next->pid;
153 __entry->next_prio = next->prio;
154 /* XXX SCHED_DEADLINE */
155 ),
156
157 TP_printk("prev_comm=%s prev_pid=%d prev_prio=%d prev_state=%s%s ==> next_comm=%s next_pid=%d next_prio=%d",
158 __entry->prev_comm, __entry->prev_pid, __entry->prev_prio,
159
160 (__entry->prev_state & (TASK_REPORT_MAX - 1)) ?
161 __print_flags(__entry->prev_state & (TASK_REPORT_MAX - 1), "|",
162 { 0x01, "S" }, { 0x02, "D" }, { 0x04, "T" },
163 { 0x08, "t" }, { 0x10, "X" }, { 0x20, "Z" },
164 { 0x40, "P" }, { 0x80, "I" }) :
165 "R",
166
167 __entry->prev_state & TASK_REPORT_MAX ? "+" : "",
168 __entry->next_comm, __entry->next_pid, __entry->next_prio)
169 );
下面是sched_switch event的展开内容,非常不易读
extern struct tracepoint __tracepoint_sched_switch;
static inline __attribute__((always_inline, unused)) __attribute__((no_instrument_function)) void trace_sched_switch(struct task_struct *t) { if (static_key_false(&__tracepoint_sched_switch.key)) do { struct tracepoint_func *it_func_ptr; void *it_func; void *__data; if (!(cpumask_test_cpu(((*({ do { const void *__vpp_verify = (typeof((&cpu_number) + 0))((void *)0); (void)__vpp_verify; } while (0); ({ unsigned long __ptr; __asm__ ("" : "=r"(__ptr) : "0"((typeof(*(&cpu_number)) *)(&cpu_number))); (typeof((typeof(*(&cpu_number)) *)(&cpu_number))) (__ptr + ((__my_cpu_offset()))); }); }))), ((const struct cpumask *)&__cpu_online_mask)))) return; if (0) { if (({ int __ret_warn_on = !!(rcu_irq_enter_disabled()); if (__builtin_expect(!!(__ret_warn_on), 0)) asm volatile (".pushsection __bug_table,\"aw\"; .align 2; 0: .long 1f - 0b; .pushsection .rodata.str,\"aMS\",@progbits,1; 2: .string \"./include/trace/events/sched.h\"; .popsection; .long 2b - 0b; .short 32; .short (1 << 0)|((1 << 1)|((9) << 8)); .popsection; 1: brk 0x800");; __builtin_expect(!!(__ret_warn_on), 0); })) return; rcu_irq_enter_irqson(); } rcu_read_lock_sched_notrace(); it_func_ptr = ({ typeof(*((&__tracepoint_sched_switch)->funcs)) *________p1 = (typeof(*((&__tracepoint_sched_switch)->funcs)) *)({ union { typeof(((&__tracepoint_sched_switch)->funcs)) __val; char __c[1]; } __u; if (1) __read_once_size(&(((&__tracepoint_sched_switch)->funcs)), __u.__c, sizeof(((&__tracepoint_sched_switch)->funcs))); else __read_once_size_nocheck(&(((&__tracepoint_sched_switch)->funcs)), __u.__c, sizeof(((&__tracepoint_sched_switch)->funcs))); do { } while (0); __u.__val; }); do { } while (0); ; ((typeof(*((&__tracepoint_sched_switch)->funcs)) *)(________p1)); }); if (it_func_ptr) { do { it_func = (it_func_ptr)->func; __data = (it_func_ptr)->data; ((void(*)(void *__data, struct task_struct *t))(it_func))(__data, t); } while ((++it_func_ptr)->func); } rcu_read_unlock_sched_notrace(); if (0) rcu_irq_exit_irqson(); } while (0); if (1 && (cpumask_test_cpu(((*({ do { const void *__vpp_verify = (typeof((&cpu_number) + 0))((void *)0); (void)__vpp_verify; } while (0); ({ unsigned long __ptr; __asm__ ("" : "=r"(__ptr) : "0"((typeof(*(&cpu_number)) *)(&cpu_number))); (typeof((typeof(*(&cpu_number)) *)(&cpu_number))) (__ptr + ((__my_cpu_offset()))); }); }))), ((const struct cpumask *)&__cpu_online_mask)))) { rcu_read_lock_sched_notrace(); ({ typeof(*(__tracepoint_sched_switch.funcs)) *________p1 = (typeof(*(__tracepoint_sched_switch.funcs)) *)({ union { typeof((__tracepoint_sched_switch.funcs)) __val; char __c[1]; } __u; if (1) __read_once_size(&((__tracepoint_sched_switch.funcs)), __u.__c, sizeof((__tracepoint_sched_switch.funcs))); else __read_once_size_nocheck(&((__tracepoint_sched_switch.funcs)), __u.__c, sizeof((__tracepoint_sched_switch.funcs))); do { } while (0); __u.__val; }); do { } while (0); ; ((typeof(*(__tracepoint_sched_switch.funcs)) *)(________p1)); }); rcu_read_unlock_sched_notrace(); } }
static inline __attribute__((always_inline, unused)) __attribute__((no_instrument_function)) void trace_sched_switch_rcuidle(struct task_struct *t) { if (static_key_false(&__tracepoint_sched_switch.key)) do { struct tracepoint_func *it_func_ptr; void *it_func; void *__data; if (!(cpumask_test_cpu(((*({ do { const void *__vpp_verify = (typeof((&cpu_number) + 0))((void *)0); (void)__vpp_verify; } while (0); ({ unsigned long __ptr; __asm__ ("" : "=r"(__ptr) : "0"((typeof(*(&cpu_number)) *)(&cpu_number))); (typeof((typeof(*(&cpu_number)) *)(&cpu_number))) (__ptr + ((__my_cpu_offset()))); }); }))), ((const struct cpumask *)&__cpu_online_mask)))) return; if (1) { if (({ int __ret_warn_on = !!(rcu_irq_enter_disabled()); if (__builtin_expect(!!(__ret_warn_on), 0)) asm volatile (".pushsection __bug_table,\"aw\"; .align 2; 0: .long 1f - 0b; .pushsection .rodata.str,\"aMS\",@progbits,1; 2: .string \"./include/trace/events/sched.h\"; .popsection; .long 2b - 0b; .short 32; .short (1 << 0)|((1 << 1)|((9) << 8)); .popsection; 1: brk 0x800");; __builtin_expect(!!(__ret_warn_on), 0); })) return; rcu_irq_enter_irqson(); } rcu_read_lock_sched_notrace(); it_func_ptr = ({ typeof(*((&__tracepoint_sched_switch)->funcs)) *________p1 = (typeof(*((&__tracepoint_sched_switch)->funcs)) *)({ union { typeof(((&__tracepoint_sched_switch)->funcs)) __val; char __c[1]; } __u; if (1) __read_once_size(&(((&__tracepoint_sched_switch)->funcs)), __u.__c, sizeof(((&__tracepoint_sched_switch)->funcs))); else __read_once_size_nocheck(&(((&__tracepoint_sched_switch)->funcs)), __u.__c, sizeof(((&__tracepoint_sched_switch)->funcs))); do { } while (0); __u.__val; }); do { } while (0); ; ((typeof(*((&__tracepoint_sched_switch)->funcs)) *)(________p1)); }); if (it_func_ptr) { do { it_func = (it_func_ptr)->func; __data = (it_func_ptr)->data; ((void(*)(void *__data, struct task_struct *t))(it_func))(__data, t); } while ((++it_func_ptr)->func); } rcu_read_unlock_sched_notrace(); if (1) rcu_irq_exit_irqson(); } while (0); }
static inline __attribute__((always_inline, unused)) __attribute__((no_instrument_function)) int register_trace_sched_switch(void (*probe)(void *__data, struct task_struct *t), void *data) { return tracepoint_probe_register(&__tracepoint_sched_switch, (void *)probe, data); }
static inline __attribute__((always_inline, unused)) __attribute__((no_instrument_function)) int register_trace_prio_sched_switch(void (*probe)(void *__data, struct task_struct *t), void *data, int prio) { return tracepoint_probe_register_prio(&__tracepoint_sched_switch, (void *)probe, data, prio); }
static inline __attribute__((always_inline, unused)) __attribute__((no_instrument_function)) int unregister_trace_sched_switch(void (*probe)(void *__data, struct task_struct *t), void *data) { return tracepoint_probe_unregister(&__tracepoint_sched_switch, (void *)probe, data); }
static inline __attribute__((always_inline, unused)) __attribute__((no_instrument_function)) void check_trace_callback_type_sched_switch(void (*cb)(void *__data, struct task_struct *t)) { }
static inline __attribute__((always_inline, unused)) __attribute__((no_instrument_function)) bool trace_sched_switch_enabled(void) { return static_key_false(&__tracepoint_sched_switch.key); }
把trace_sched_switch()
函数格式化一下,删掉部分,可以看到,流程是先通过key判断这个tracepoint是否打开了,如果打开,先检查当前cpu online的情况,再调用注册函数和trace函数原型。
static inline __attribute__((always_inline, unused)) __attribute__((no_instrument_function))
void trace_sched_switch(struct task_struct *t)
{if (static_key_false(&__tracepoint_sched_switch.key)) // 检查是否enableddo {struct tracepoint_func *it_func_ptr;void *it_func; void *__data;if (!(cpumask_test_cpu(((*( // 检查是否trace 当前CPU{.....}))), ((const struct cpumask *)&__cpu_online_mask)))) return;rcu_read_lock_sched_notrace();it_func_ptr = ({ ... *________p1 = (typeof(*((&__tracepoint_sched_switch)->funcs)) *)...}); // 获得函数指针if (it_func_ptr) { do {it_func = (it_func_ptr)->func;__data = (it_func_ptr)->data;((void(*)(void *__data, struct task_struct *t))(it_func))(__data, t); // 调用probe handler} while ((++it_func_ptr)->func); } rcu_read_unlock_sched_notrace();} while (0);...
}
3.2.2 EVENT CLASS优化代码空间占用
一个系统里可能有几千个tracepoint,每个都要定义一个tracepoint全局变量和一组函数,会导致代码段和数据段明显增加。
而经常同一个模块的多个tracepoint可能是有同样的参数、记录同样的数据结构,只是打印时机或者格式不同,利用这样的共性,可以进行分类,定义同样的注册函数和回调函数。
所以增加了两个宏:
DECLARE_EVENT_CLASS
: 定义一个模板类
DEFINE_EVENT
: 使用模板类定义一个EVENT
#define DECLARE_EVENT_CLASS(name, proto, args, tstruct, assign, print)
#define DEFINE_EVENT(template, name, proto, args) \DECLARE_TRACE(name, PARAMS(proto), PARAMS(args))201 DECLARE_EVENT_CLASS(sched_process_template,
202
203 TP_PROTO(struct task_struct *p),
204
205 TP_ARGS(p),
206
207 TP_STRUCT__entry(
208 __array( char, comm, TASK_COMM_LEN )
209 __field( pid_t, pid )
210 __field( int, prio )
211 ),
212
213 TP_fast_assign(
214 memcpy(__entry->comm, p->comm, TASK_COMM_LEN);
215 __entry->pid = p->pid;
216 __entry->prio = p->prio; /* XXX SCHED_DEADLINE */
217 ),
218
219 TP_printk("comm=%s pid=%d prio=%d",
220 __entry->comm, __entry->pid, __entry->prio)
221 );
222
223 /*
224 * Tracepoint for freeing a task:
225 */
226 DEFINE_EVENT(sched_process_template, sched_process_free,
227 TP_PROTO(struct task_struct *p),
228 TP_ARGS(p));
229
230
231 /*
232 * Tracepoint for a task exiting:
233 */
234 DEFINE_EVENT(sched_process_template, sched_process_exit,
235 TP_PROTO(struct task_struct *p),
236 TP_ARGS(p));
237
238 /*
239 * Tracepoint for waiting on task to unschedule:
240 */
241 DEFINE_EVENT(sched_process_template, sched_wait_task,
242 TP_PROTO(struct task_struct *p),
243 TP_ARGS(p));
下面是一个使用了TRACE_EVENT和DECLARE_EVENT_CLASS 对比的数据,可以看到代码段明显减少。
text data bss dec hex filename452114 2788 3520 458422 6feb6 fs/xfs/xfs.o.notrace996954 38116 4480 1039550 fdcbe fs/xfs/xfs.o.trace638482 38116 3744 680342 a6196 fs/xfs/xfs.o.class
3.2.3 如何降低性能影响?
在代码中插入tracepoint,肯定希望在不打开时,对源码性能影响最小,这里使用了动态分支(dynamic branching)技术。
struct tracepoint中的struct static_key key
就是用于dynamic branching的。
kernel的dynamic_debug接口(pr_debug,dev_dbg)也是基于这个技术实现log的动态开关。
statck-keys技术详情请参考下面文档和代码。
Documentation/static-keys.txt
include/linux/jump_label.h
arch/arm64/include/asm/jump_label.h
89 #ifdef HAVE_JUMP_LABEL //依赖于HAVA_JUMP_LABEL宏 90 91 struct static_key { 92 atomic_t enabled; 93 /*94 * Note: 95 * To make anonymous unions work with old compilers, the static 96 * initialization of them requires brackets. This creates a dependency97 * on the order of the struct with the initializers. If any fields 98 * are added, STATIC_KEY_INIT_TRUE and STATIC_KEY_INIT_FALSE may need 99 * to be modified.
100 *
101 * bit 0 => 1 if key is initially true
102 * 0 if initially false
103 * bit 1 => 1 if points to struct static_key_mod
104 * 0 if points to struct jump_entry
105 */
106 union {
107 unsigned long type;
108 struct jump_entry *entries;
109 struct static_key_mod *next;
110 };
111 };
112
113 #else
114 struct static_key {
115 atomic_t enabled;
116 };
常见的控制代码的执行的方法是if (enabled)
或者if unlikely(enabled)
做判断;
单独的if 没有分支优化,会引入较多的branch-miss;
后一种unlikely()在enabled
被设置后,也会有同样的问题。
检查的enabled
往往也是全局变量,在频繁执行的代码中,也可能引入cache 同步问题,比如这变量和其它变量共享同一个cacheline时。
最好的办法就是不判断,通过动态替换指令的方式,根据enabled值先把指令替换好,消除运行时的if 判断。具体实现原理见static-keys.txt。这个功能需要gcc v4.5以上的“asm goto”的支持,同时需要体系结构提供硬件相关实现,arm64已经提供支持,代码在arch/arm64/include/asm/jump_label.h
。
static-key提供的接口在include/linux/jump_label.h
中
DEFINE_STATIC_KEY_TRUE(key); // 定义一个默认是True的key
DEFINE_STATIC_KEY_FALSE(key); // 定义一个默认是False的key
DEFINE_STATIC_KEY_ARRAY_TRUE(keys, count); // 定义一组
DEFINE_STATIC_KEY_ARRAY_FALSE(keys, count);
static_branch_likely() // 分支判断
static_branch_unlikely()
SYSCALL_DEFINE0(getppid)
{int pid;+ if (static_branch_unlikely(&key))
+ printk("I am the true branch\n");rcu_read_lock();pid = task_tgid_vnr(rcu_dereference(current->real_parent));rcu_read_unlock();return pid;
}
从一个X86的例子可以看到,使用static key接口的代码,经过jump label优化以后,去掉了分支判断操作。如果条件为false,会直接替换成nop指令。
3.2.4 为什么使用宏定义
tracepoint里的宏定义非常难阅读和维护,为什么作者要使用宏定义开发呢?
个人认为主要有下面这些原因:
- 接口统一,使用简单
- 自动化定义接口函数、格式化数据,用户无需关心内部实现
- 模板化通用类型支持
- 性能优化,精心设计宏定义内部实现,
- 格式统一,方便设计trace解析工具
3.3 动态Trace event的实现
静态trace event需要在kernel 代码中插入trace point代码,而动态trace event是在运行时插入的。
对应tracefs里的文件是:
/sys/kernel/debug/tracing/kprobe_profile
/sys/kernel/debug/tracing/kprobe_events
/sys/kernel/debug/tracing/uprobe_profile
/sys/kernel/debug/tracing/uprobe_events
从名字可以看到是基于kprobe和uprobe机制实现的。ftrace 的dynamic trace event是通过解析写入kprobe_events的命令行字符串,注册对应函数的kprobe
或者kretprobe
的 handler,handler的工作就是把需要打印的内容写入trace buffer。
Kernel 调试追踪技术之Kprobe 介绍了kprobe的机制和使用方式。
uprobe的实现和kprobe类似。
3.4 Tracer的实现
除了上面的静态 trace event和动态 trace event以外,ftrace 还定义了一些tracer。
这些tracer是用于某个特定功能的跟踪器,可能利用trace event,function trace的功能,也可以定义一些记录时间戳的接口用于记录最大latency。
目前主要的tracer如下:
nop // 默认的空tracer,使用trace event、 dynamic trace event时设置为nop
function // function tracer,打印所有函数调用,或者通过set_ftrace_filter过滤
function_graph // 通过fucntion tracer,可以打印带缩进的调用关系wakeup // 记录最高优先级的进程的被唤醒后的最大调度延迟
wakeup_dl // 记录SCHED_DEADLINE进程被唤醒后的最大调度延迟
wakeup_rt // 记录RT 进程的被唤醒后的最大调度延迟preemptirqsoff // 记录irq和/或抢占被关闭的最大时间的backtrace
preemptoff // 记录抢占被关闭的最大时间的backtrace
irqsoff // 记录中断被关闭的最大时间的backtracblk // block 事件tracer,需要在/sys/blk/xxx/trace/enable 中打开,和events/block/ 功能基本一样
这里以irqsoff tracer代码为例做简单介绍。
preemptirqsoff、preemptoff、irqsoff这三个tracer 都定义在kernel/trace/trace_irqsoff.c
里。
定义一个tracer,首先要注册一个struct tracer
,这个tracer主要是用在做tracer状态控制的。
static struct tracer irqsoff_tracer __read_mostly =
{ .name = "irqsoff", .init = irqsoff_tracer_init, // 初始化状态,注册function trace call .reset = irqsoff_tracer_reset, // 重置为初始化状态,关闭function trace .start = irqsoff_tracer_start, // tracer_enabled = 1;.stop = irqsoff_tracer_stop, // tracer_enabled = 0; .print_max = true, .print_header = irqsoff_print_header, // 打印log 头 .print_line = irqsoff_print_line, // 空 .flag_changed = irqsoff_flag_changed, // 空
#ifdef CONFIG_FTRACE_SELFTEST .selftest = trace_selftest_startup_irqsoff,
#endif .open = irqsoff_trace_open, // 空 .close = irqsoff_trace_close, // 空 .allow_instances = true, .use_max_tr = true,
};
另外根据CONFIG_FUNCTION_TRACER
和CONFIG_FUNCTION_GRAPH_TRACER
是否配置,注册对应的函数trace 接口(跟踪每个函数)。
其实irqsoff tracer主要是定义了两个时间记录接口,在kernel关闭中断和打开中断的位置调用,计算关闭时长,如果是最大,就把latency、backtrace等信息打印到trace buffer里。
EXPORT_SYMBOL(trace_hardirqs_on);
EXPORT_SYMBOL(trace_hardirqs_off);
EXPORT_SYMBOL(trace_hardirqs_on_caller);
EXPORT_SYMBOL(trace_hardirqs_off_caller);
EXPORT_SYMBOL_GPL(start_critical_timings);
EXPORT_SYMBOL_GPL(stop_critical_timings);
irqsoff输出的log根据是否打开function trace和function graph trace会不同,可以通过trace_options里的function-trace 和display_graph选项来控制。
- 如果设置了nofunction-trace,irqsoff 的trace log显示的调用栈
- 如果设置了function-trace, nodisplay_graph,打印整个irqoff阶段的所有函数
- 如果设置了function-trace, display_graph,打印整个irqoff阶段的所有函数的结构化调用关系
4. Ftrace功能总结
Reference
- Linux tracing systems & how they fit together Linux tracing systems & how they fit together
- Linux Tracing Technologies Linux Tracing Technologies — The Linux Kernel documentation
- LWN: Using the TRACE_EVENT() macro (Part 1)
- LWN: Using the TRACE_EVENT() macro (Part 2)
- LWN: Using the TRACE_EVENT() macro (Part 3)
文章标题:Ftrace的配置和使用
本文作者:hpyu
本文链接:https://www.cnblogs.com/hpyu/articles/14348523.html
欢迎转载,请注明原文链接
好文要顶 关注我 收藏该文
HPYU
粉丝 - 14 关注 - 0
+加关注
0
0
« 上一篇: 【原创】Ftrace的配置和使用
» 下一篇: 【原创】Kernel调试追踪技术之 eBPF on ARM64
posted @ 2021-01-30 11:46 HPYU 阅读(1271) 评论(0) 编辑 收藏 举报
这篇关于Kernel调试追踪技术之 Ftrace on ARM64的文章就介绍到这儿,希望我们推荐的文章对编程师们有所帮助!