Kernel调试追踪技术之 Ftrace on ARM64

2024-03-12 12:59

本文主要是介绍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个宏:

  1. TRACE_EVENT 定义一个tracepoint,它是最上层的宏,下面2-6作为它的参数
  2. TP_PROTO 定义函数原型,指定每个参数的类型
  3. TP_ARGS 列出所有参数,tracepoint的回调函数会用到
  4. TP_STRUCT__entry 定义要存入ring buffer的数据格式
  5. TP_fast_assign 对存入ring buffer的数据赋值,赋值来自前面的args
  6. TP_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的通用信息,包括typeflagsprempt_countpid

第5个开始是定义的数据域,devinodirmode,然后是打印格式。

这里定义的数据域是在二进制的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_entryftrace_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_FTRACEmcount会被实现成一个空函数(只有一条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

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_TRACERCONFIG_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

  1. Linux tracing systems & how they fit together Linux tracing systems & how they fit together
  2. Linux Tracing Technologies Linux Tracing Technologies — The Linux Kernel documentation
  3. LWN: Using the TRACE_EVENT() macro (Part 1)
  4. LWN: Using the TRACE_EVENT() macro (Part 2)
  5. 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的文章就介绍到这儿,希望我们推荐的文章对编程师们有所帮助!



http://www.chinasem.cn/article/801330

相关文章

【专题】2024飞行汽车技术全景报告合集PDF分享(附原数据表)

原文链接: https://tecdat.cn/?p=37628 6月16日,小鹏汇天旅航者X2在北京大兴国际机场临空经济区完成首飞,这也是小鹏汇天的产品在京津冀地区进行的首次飞行。小鹏汇天方面还表示,公司准备量产,并计划今年四季度开启预售小鹏汇天分体式飞行汽车,探索分体式飞行汽车城际通勤。阅读原文,获取专题报告合集全文,解锁文末271份飞行汽车相关行业研究报告。 据悉,业内人士对飞行汽车行业

金融业开源技术 术语

金融业开源技术  术语 1  范围 本文件界定了金融业开源技术的常用术语。 本文件适用于金融业中涉及开源技术的相关标准及规范性文件制定和信息沟通等活动。

ASIO网络调试助手之一:简介

多年前,写过几篇《Boost.Asio C++网络编程》的学习文章,一直没机会实践。最近项目中用到了Asio,于是抽空写了个网络调试助手。 开发环境: Win10 Qt5.12.6 + Asio(standalone) + spdlog 支持协议: UDP + TCP Client + TCP Server 独立的Asio(http://www.think-async.com)只包含了头文件,不依

如何在Visual Studio中调试.NET源码

今天偶然在看别人代码时,发现在他的代码里使用了Any判断List<T>是否为空。 我一般的做法是先判断是否为null,再判断Count。 看了一下Count的源码如下: 1 [__DynamicallyInvokable]2 public int Count3 {4 [__DynamicallyInvokable]5 get

Linux_kernel驱动开发11

一、改回nfs方式挂载根文件系统         在产品将要上线之前,需要制作不同类型格式的根文件系统         在产品研发阶段,我们还是需要使用nfs的方式挂载根文件系统         优点:可以直接在上位机中修改文件系统内容,延长EMMC的寿命         【1】重启上位机nfs服务         sudo service nfs-kernel-server resta

计算机毕业设计 大学志愿填报系统 Java+SpringBoot+Vue 前后端分离 文档报告 代码讲解 安装调试

🍊作者:计算机编程-吉哥 🍊简介:专业从事JavaWeb程序开发,微信小程序开发,定制化项目、 源码、代码讲解、文档撰写、ppt制作。做自己喜欢的事,生活就是快乐的。 🍊心愿:点赞 👍 收藏 ⭐评论 📝 🍅 文末获取源码联系 👇🏻 精彩专栏推荐订阅 👇🏻 不然下次找不到哟~Java毕业设计项目~热门选题推荐《1000套》 目录 1.技术选型 2.开发工具 3.功能

vscode中文乱码问题,注释,终端,调试乱码一劳永逸版

忘记咋回事突然出现了乱码问题,很多方法都试了,注释乱码解决了,终端又乱码,调试窗口也乱码,最后经过本人不懈努力,终于全部解决了,现在分享给大家我的方法。 乱码的原因是各个地方用的编码格式不统一,所以把他们设成统一的utf8. 1.电脑的编码格式 开始-设置-时间和语言-语言和区域 管理语言设置-更改系统区域设置-勾选Bata版:使用utf8-确定-然后按指示重启 2.vscode

AI(文生语音)-TTS 技术线路探索学习:从拼接式参数化方法到Tacotron端到端输出

AI(文生语音)-TTS 技术线路探索学习:从拼接式参数化方法到Tacotron端到端输出 在数字化时代,文本到语音(Text-to-Speech, TTS)技术已成为人机交互的关键桥梁,无论是为视障人士提供辅助阅读,还是为智能助手注入声音的灵魂,TTS 技术都扮演着至关重要的角色。从最初的拼接式方法到参数化技术,再到现今的深度学习解决方案,TTS 技术经历了一段长足的进步。这篇文章将带您穿越时

系统架构设计师: 信息安全技术

简简单单 Online zuozuo: 简简单单 Online zuozuo 简简单单 Online zuozuo 简简单单 Online zuozuo 简简单单 Online zuozuo :本心、输入输出、结果 简简单单 Online zuozuo : 文章目录 系统架构设计师: 信息安全技术前言信息安全的基本要素:信息安全的范围:安全措施的目标:访问控制技术要素:访问控制包括:等保