trace系列2 - function graph trace学习笔记

目录

• 1.前言
• 2. function graph trace钩子函数替换过程
• • 2.1 编译阶段
  • 2.2 链接阶段
  • 2.3 运行阶段
• 3. function graph trace钩子函数执行过程
• • 3.1 ftrace_ops_no_ops
  • 3.2 ftrace_graph_caller
  • • 3.2.1 prepare_ftrace_return
    • • 3.2.1.1 ftrace_push_return_trace
      • 3.2.1.2 ftrace_graph_entry
  • 3.3 return_to_handler
  • • 3.3.1 ftrace_pop_return_trace
    • 3.3.2 trace_clock_local
    • 3.3.3 ftrace_graph_return
• 4. 总结

1.前言

本文主要是根据阅码场 《Linux内核tracers的实现原理与应用》视频课程在aarch64上的实践。通过观察钩子函数的创建过程以及替换过程，理解trace的原理。本文同样以blk_update_request函数为例进行说明function graph trace的工作原理。

kernel版本：5.10
平台：arm64

2. function graph trace钩子函数替换过程 2.1 编译阶段

同Linux ftrace学习笔记中编译阶段部分的描述。在使能内核配置项CONFIG_FTRACE时，可以看到blk_update_request函数增加了如下部分：

3f3c:       94000000        bl      0 <_mcount>

2.2 链接阶段

同Linux ftrace学习笔记中编译阶段部分的描述。在使能内核配置项CONFIG_FTRACE时，可以看到在链接阶段blk_update_request函数编译阶增加的部分，已经被替换为如下：

 bl      ffff80001002c36c <_mcount>

其中_mcount为：

ffff80001002c36c <_mcount>:
ffff80001002c36c:       d65f03c0        ret

2.3 运行阶段

同Linux ftrace学习笔记中编译阶段部分的描述。在使能内核配置项CONFIG_FTRACE时，内核在start_kernel执行时，会调用ftrace_init，它会将所有可trace函数中的_mcount进行替换，
链接阶段blk_update_request中的 bl ffff80001002c36c <_mcount> 已经被替换为nop指令

0xffff8000104e43f4 :  nop

设定trace函数blk_update_request，执行如下命令来trace函数blk_update_request

ubuntu@VM-0-9-ubuntu:~$ echo blk_update_request > /sys/kernel/debug/tracing/set_graph_function
ubuntu@VM-0-9-ubuntu:~$ echo function_graph > /sys/kernel/debug/tracing/current_tracer

(gdb) disassemble blk_update_request
   //分配栈空间，此后sp指向栈顶
   0xffff8000104e43c8 <+0>:     sub     sp, sp, #0x60
   //根据ARM64栈帧结构，x29(FP)指向blk_mq_end_request函数栈顶
   //x30（LR）指向blk_mq_end_request中bl blk_update_request的下条指令
   //此处将x29和x30存放到栈顶偏移16字节的位置
   0xffff8000104e43cc <+4>:     stp     x29, x30, [sp,#16]
   //更新x29指向blk_update_request的栈顶+16
   0xffff8000104e43d0 <+8>:     add     x29, sp, #0x10
   0xffff8000104e43d4 <+12>:    stp     x19, x20, [sp,#32]
   0xffff8000104e43d8 <+16>:    stp     x21, x22, [sp,#48]
   0xffff8000104e43dc <+20>:    stp     x23, x24, [sp,#64]
   0xffff8000104e43e0 <+24>:    str     x25, [sp,#80]
   0xffff8000104e43e4 <+28>:    mov     x22, x0
   0xffff8000104e43e8 <+32>:    uxtb    w24, w1
   0xffff8000104e43ec <+36>:    mov     w21, w2
   //x0保存了blk_mq_end_request中bl blk_update_request的下条指令
   0xffff8000104e43f0 <+40>:    mov     x0, x30
   0xffff8000104e43f4 <+44>:    bl      0xffff80001002c370 
   0xffff8000104e43f8 <+48>     mov    w0, w24
   ......

同Linux ftrace学习笔记中编译阶段部分的描述。在执行如上语句后，nop已经被替换成了
bl 0xffff80001002c370
这点function graph trace与function trace是相同的。

前面我们说blk_update_request的nop语句，无论是function trace还是function graph trace都会被替换成 bl ftrace_caller，那么两者有何分别呢？答案就是从ftrace_caller开始产生了区别。
同Linux ftrace学习笔记中编译阶段部分的描述，通过 gdb可以看到ftrace_caller在替换之前的反汇编代码如下：

(gdb) disassemble ftrace_caller
Dump of assembler code for function ftrace_caller:
   0xffff80001002c370 <+0>:     stp     x29, x30, [sp,#-16]!
   0xffff80001002c374 <+4>:     mov     x29, sp
   0xffff80001002c378 <+8>:     sub     x0, x30, #0x4
   0xffff80001002c37c <+12>:    ldr     x1, [x29]
   0xffff80001002c380 <+16>:    ldr     x1, [x1,#8]
   0xffff80001002c384 <+20>:    nop                  
   0xffff80001002c388 <+24>:    nop                  
   0xffff80001002c38c <+28>:    ldp     x29, x30, [sp],#16
   0xffff80001002c390 <+32>:    ret
End of assembler dump.

在执行如下操作后

ubuntu@VM-0-9-ubuntu:~$echo blk_update_request > /sys/kernel/debug/tracing/set_graph_function
ubuntu@VM-0-9-ubuntu:~$echo function_graph > /sys/kernel/debug/tracing/current_tracer

当我们echo function_graph的时候，ftrace_modify_graph_caller会将这条nop指向替换成一条
"b ftrace_graph_caller"指令，注意这是不保存LR的无条件跳转。使能function_graph的时候需要disable 掉CONFIG_STRICT_MEMORY_RWX和“KERNEL_TEXT_RDONLY“这样，才会允许代码被动态修改。
替换后反汇编ftrace_caller的结果如下：

(gdb) disassemble ftrace_caller
   //x29(FP)指向blk_update_request函数栈顶+16，blk_update_request函数栈顶+16存放了blk_mq_end_request的栈顶
   //x30（LR）指向blk_update_request中bl ftrace_caller的下条指令
   0xffff80001002c370 <+0>:     stp     x29, x30, [sp,#-16]!
   //更新x29(FP)指向ftrace_caller函数栈顶
   0xffff80001002c374 <+4>:     mov     x29, sp
   //x0指向blk_update_request中当前指令bl  ftrace_caller 
   0xffff80001002c378 <+8>:     sub     x0, x30, #0x4
   //x1指向blk_mq_end_request函数栈顶
   0xffff80001002c37c <+12>:    ldr     x1, [x29]
   //x1存放blk_mq_end_request函数中bl blk_update_request的下条指令的地址
   0xffff80001002c380 <+16>:    ldr     x1, [x1,#8]
   0xffff80001002c384 <+20>:    bl      0xffff800010188ffc 
   0xffff80001002c388 <+24>:    b       0xffff80001002c394 
   0xffff80001002c38c <+28>:    ldp     x29, x30, [sp],#16
   0xffff80001002c390 <+32>:    ret

我们可以看到原本ftrace_caller中的两条nop指令分别被替换为：
bl ftrace_ops_no_ops和b ftrace_graph_caller
在调用bl ftrace_ops_no_ops和b ftrace_graph_caller前，x0,x1分别为：

• x0指向blk_update_request中当前指令bl ftrace_caller
• x1存放blk_mq_end_request函数中bl blk_update_request的下条指令的地址

3. function graph trace钩子函数执行过程

blk_update_request的钩子函数ftrace_caller主要经历了如下的调用流程：

blk_mq_end_request
    --blk_update_request
           --ftrace_caller
                  |--ftrace_ops_no_ops
                  --ftrace_graph_caller
                         --prepare_ftrace_return
                                --function_graph_enter
                                       |--ftrace_push_return_trace
                                       --ftrace_graph_entry

根据ARM64函数调用规则，可形成如下的栈帧结构：

下面将详细说明钩子函数的工作流程

3.1 ftrace_ops_no_ops

先来看下ftrace_ops_no_ops，同Linux ftrace学习笔记中编译阶段部分的描述，从ftrace_ops_no_ops源码中看到它会遍历ftrace_ops_list链表，并执行这个链表上的回调函数，这里看下ftrace_ops_list上都链接了哪些func：

(gdb) p *ftrace_ops_list
$1 = {
  func = 0xffff80001002c3b8 , 
  next = 0xffff800011c5a438 , 
....
  }, 
  trampoline = 0, 
  trampoline_size = 0, 
  list = {
    next = 0x0, 
    prev = 0x0
  }
}

可以看到此链表上只有一个ftrace_stub，它的反汇编如下：

(gdb) disassemble ftrace_stub
Dump of assembler code for function ftrace_stub:
   0xffff80001002c3b8 <+0>:     ret
End of assembler dump.

只有一个ret返回指令，这与function trace的不同，在function trace中not最终会被替换为function_trace_call函数，执行function trace操作。

3.2 ftrace_graph_caller

ftrace_caller的第二个nop被替换为ftrace_graph_caller，通过ftrace_caller函数可知调用b ftrace_graph_caller前，x0,x1分别为：

• x0指向blk_update_request中当前指令bl ftrace_caller
• x1存放blk_mq_end_request函数中bl blk_update_request的下条指令的地址
• x2指向blk_mq_end_request的栈顶

(gdb) disassemble ftrace_graph_caller
   //此时x29指向ftrace_caller栈顶，x29+8指向blk_update_request中bl ftrace_caller的下条指令的地址
   0xffff80001002c394 <+0>:     ldr     x0, [x29,#8]
   /
        //保存原始的lr值，对于本例来讲，就是blk_mq_end_request中bl blk_update_request指令的下条指令地址
        //它将用于恢复lr值
        old = *parent;

        if (!function_graph_enter(old, self_addr, frame_pointer, NULL))
                 //更新lr值，对于本例来讲，就是将blk_mq_end_request中bl blk_update_request指令的下条指令地址
                 //修改为return_to_handler
                *parent = return_hooker;
}

prepare_ftrace_return，反汇编如下：

(gdb) disassemble prepare_ftrace_return
Dump of assembler code for function prepare_ftrace_return:
   0xffff80001002c280 <+0>:     mrs     x3, sp_el0
   0xffff80001002c284 <+4>:     ldr     w3, [x3,#2460]
   0xffff80001002c288 <+8>:     cbnz    w3, 0xffff80001002c2c8 
   0xffff80001002c28c <+12>:    stp     x29, x30, [sp,#-32]!
   0xffff80001002c290 <+16>:    mov     x29, sp
   0xffff80001002c294 <+20>:    str     x19, [sp,#16]
   //x19存放了指向blk_mq_end_request函数bl blk_update_reques的下条指令地址的指针
   0xffff80001002c298 <+24>:    mov     x19, x1
   //x1存放了blk_update_request函数当前执行的指令bl ftrace_caller的地址；
   0xffff80001002c29c <+28>:    mov     x1, x0
   //x3为0
   0xffff80001002c2a0 <+32>:    mov     x3, #0x0                        // #0
   //x0存放了blk_mq_end_request函数中bl blk_update_reques的下条指令的地址
   0xffff80001002c2a4 <+36>:    ldr     x0, [x19]
   0xffff80001002c2a8 <+40>:    bl      0xffff8000101a2dfc 
   //如果function_graph_enter返回值为非0，表示失败，跳转到prepare_ftrace_return+60
   0xffff80001002c2ac <+44>:    cbnz    w0, 0xffff80001002c2bc 
   0xffff80001002c2b0 <+48>:    adrp    x0, 0xffff80001002c000 
   //此时x0的值为0xffff80001002c000+0x3bc，它就是return_to_handler
   0xffff80001002c2b4 <+52>:    add     x0, x0, #0x3bc
   //根据前述，x19存放了指向blk_mq_end_request函数bl blk_update_reques的下条指令地址的指针
   //此处就是通过重新赋值x19修改blk_mq_end_request函数bl blk_update_reques的下条指令地址为return_to_handler
   0xffff80001002c2b8 <+56>:    str     x0, [x19]
   //如果function_graph_enter返回值为非0，跳转至此
   0xffff80001002c2bc <+60>:    ldr     x19, [sp,#16]
   0xffff80001002c2c0 <+64>:    ldp     x29, x30, [sp],#32
   0xffff80001002c2c4 <+68>:    ret
   0xffff80001002c2c8 <+72>:    ret

通过prepare_ftrace_return函数可知调用function_graph_enter函数前的参数x0和x1、x2分别为：

• x0存放了blk_mq_end_request函数中bl blk_update_reques的下条指令的地址
• x1存放了blk_update_request函数当前执行的指令bl ftrace_caller的地址；
• x2指向ftrace_caller栈顶
• x3为0

如上x0, x1, x2、x3分别对应了function_graph_enter的形参ret， func，frame_pointer, retp

int function_graph_enter(unsigned long ret, unsigned long func,
                         unsigned long frame_pointer, unsigned long *retp)                                                                       
{       
        struct ftrace_graph_ent trace;                                                                                                           
                                                                                                                          
        trace.func = func;
        trace.depth = ++current->curr_ret_depth;                                                                                                 
        
        if (ftrace_push_return_trace(ret, func, frame_pointer, retp))                                                                            
                goto out;                                                                                                                        
        
                                                                                              
        if (!ftrace_graph_entry(&trace))                                                                                                         
                goto out_ret;                                                                                                                    

        return 0;
 out_ret:
        current->curr_ret_stack--;
 out:
        current->curr_ret_depth--;
        return -EBUSY;
}

3.2.1.1 ftrace_push_return_trace

通过function_graph_enter函数可知，ftrace_push_return_trace函数与之有相同的形参，因此调用ftrace_push_return_trace函数前的参数分别为：

• ret存放了blk_mq_end_request函数中bl blk_update_reques的下条指令的地址
• func存放了blk_update_request函数当前执行的指令bl ftrace_caller的地址；
• frame_pointer指向ftrace_caller栈顶
• retp为0

static int
ftrace_push_return_trace(unsigned long ret, unsigned long func,
                         unsigned long frame_pointer, unsigned long *retp)
{
        unsigned long long calltime;
        int index;

        if (unlikely(ftrace_graph_is_dead()))
                return -EBUSY;

        if (!current->ret_stack)
                return -EBUSY;

        
        smp_rmb();

        
        if (current->curr_ret_stack == FTRACE_RETFUNC_DEPTH - 1) {
                atomic_inc(¤t->trace_overrun);
                return -EBUSY;
        }

        calltime = trace_clock_local();

        index = ++current->curr_ret_stack;
        barrier();
        //存放blk_mq_end_request函数中bl blk_update_reques的下条指令的地址
        current->ret_stack[index].ret = ret;
        //存放了blk_update_request函数当前执行的指令bl ftrace_caller的地址
        current->ret_stack[index].func = func;
        current->ret_stack[index].calltime = calltime;
#ifdef HAVE_FUNCTION_GRAPH_FP_TEST
        current->ret_stack[index].fp = frame_pointer;
#endif
#ifdef HAVE_FUNCTION_GRAPH_RET_ADDR_PTR
        current->ret_stack[index].retp = retp;
#endif
        return 0;
}

3.2.1.2 ftrace_graph_entry

通过gdb可知ftrace_graph_entry函数指针被赋值为trace_graph_entry，trace_graph_entry最终会将被trace函数以及执行时间保存到ring buffer中。

(gdb) p ftrace_graph_entry
$1 = (trace_func_graph_ent_t) 0xffff8000101a1418 

3.3 return_to_handler

return_to_handler
    --ftrace_return_to_handler
          |--struct ftrace_graph_ret trace
          |--ftrace_pop_return_trace(&trace, &ret, frame_pointer)
          |--trace.rettime = trace_clock_local()
          --ftrace_graph_return(&trace)
           

前面在blk_mq_end_request-> blk_update_request-> ftrace_caller-> ftrace_graph_caller-> prepare_ftrace_return调用时，
会将blk_mq_end_request的链接地址LR替换为return_to_handler，从blk_update_request返回后将执行return_to_handler，下面看下return_to_handler函数：

SYM_CODE_START(return_to_handler)
        
        sub sp, sp, #64
        stp x0, x1, [sp]
        stp x2, x3, [sp, #16]
        stp x4, x5, [sp, #32]
        stp x6, x7, [sp, #48]

        //x0保存了blk_mq_end_request的栈顶
        mov     x0, x29                 //     parent's fp
        //根据ftrace_return_to_handler分析，
        //ftrace_return_to_handler返回值保存了blk_mq_end_request原有的链接地址
        //即bl blk_update_request的下一条地址
        bl      ftrace_return_to_handler// addr = ftrace_return_to_hander(fp);
        //x0保存了blk_mq_end_request的原来的链接地址，赋值给x30，这样在return_to_handler返回时，
        //会执行x30保存的指令地址
        mov     x30, x0                 // restore the original return address

        
        ldp x0, x1, [sp]
        ldp x2, x3, [sp, #16]
        ldp x4, x5, [sp, #32]
        ldp x6, x7, [sp, #48]
        add sp, sp, #64
        //函数返回后将执行x30保存的指令地址
        ret
SYM_CODE_END(return_to_handler)

根据对return_to_handler函数，在调用ftrace_return_to_handler之前，参数frame_pointer为blk_mq_end_request的栈顶

unsigned long ftrace_return_to_handler(unsigned long frame_pointer)
{
        struct ftrace_graph_ret trace;
        unsigned long ret;

        ftrace_pop_return_trace(&trace, &ret, frame_pointer);
        trace.rettime = trace_clock_local();
        ftrace_graph_return(&trace);
        current->curr_ret_stack--;
        //ret保存了blk_mq_end_request的返回地址，保存在x0
        return ret;
}

3.3.1 ftrace_pop_return_trace

ret用于保存blk_mq_end_request原始的返回地址（bl blk_update_request的下条地址）

static void
ftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret,
                        unsigned long frame_pointer)
{
        int index;

        index = current->curr_ret_stack;
        
        //此处ret保存了blk_mq_end_request的返回地址
		*ret = current->ret_stack[index].ret;
		//trace->func拿到了blk_mq_end_request函数bl blk_update_request当前指令的地址
        trace->func = current->ret_stack[index].func;
        trace->calltime = current->ret_stack[index].calltime;
        trace->overrun = atomic_read(¤t->trace_overrun);
        trace->depth = current->curr_ret_depth--;
}

3.3.2 trace_clock_local

u64 notrace trace_clock_local(void)
{
        u64 clock;

        
        preempt_disable_notrace();
        clock = sched_clock();
        preempt_enable_notrace();

        return clock;
}
EXPORT_SYMBOL_GPL(trace_clock_local);

获取返回当前时钟，也就是被trace函数的执行结束时间

3.3.3 ftrace_graph_return

ftrace_graph_return为trace_graph_return函数

void trace_graph_return(struct ftrace_graph_ret *trace)
{
        struct trace_array *tr = graph_array;
        struct trace_array_cpu *data;
        unsigned long flags;
        long disabled;
        int cpu; 
        int pc;

        ftrace_graph_addr_finish(trace);

        if (trace_recursion_test(TRACE_GRAPH_NOTRACE_BIT)) {
                trace_recursion_clear(TRACE_GRAPH_NOTRACE_BIT);
                return;
        }    

        local_irq_save(flags);
        cpu = raw_smp_processor_id();
        data = per_cpu_ptr(tr->array_buffer.data, cpu);
        disabled = atomic_inc_return(&data->disabled);
        if (likely(disabled == 1)) {
                pc = preempt_count();
                __trace_graph_return(tr, trace, flags, pc); 
        }    
        atomic_dec(&data->disabled);
        local_irq_restore(flags);

4. 总结

通过前面的分析，我们可以看到function graph trace 实际是在要跟踪函数的入口处和返回处分别放置了钩子函数，以本例中的blk_update_request函数为例：

1. 首先在blk_update_request函数入口处插入钩子函数ftrace_caller；
2. 钩子函数记录函数调用关系
   在 ftrace_caller->ftrace_graph_caller->prepare_ftrace_return->function_graph_enter->ftrace_push_return_trace调用关系中，
   ftrace_push_return_trace函数将记录当前函数执行地址和blk_mq_end_request的链接地址，以及调用时间和ftrace_caller栈帧地址。其中当前函数执行地址为blk_mq_end_request函数的bl blk_update_request指令的地址，blk_mq_end_request链接地址为bl blk_update_request的下一条指令的地址。通过记录如上的地址就可以还原函数调用的关系。
3. 在blk_update_request函数返回处插入钩子函数return_to_handler
   在ftrace_caller->ftrace_graph_caller->prepare_ftrace_return时会用return_to_handler替换blk_mq_end_request函数的链接地址，通过return_to_handler获取函数的执行结束时间，之后再恢复blk_mq_end_request函数的链接返回地址，blk_mq_end_request按照原来的链接返回地址继续执行

最后举例如下：
ftrace_graph.sh如下：

#!/bin/sh
debugfs=/sys/kernel/debug
echo nop > $debugfs/tracing/current_tracer 
echo 0 > $debugfs/tracing/tracing_on 
echo 0 > $debugfs/tracing/max_graph_depth 
echo $$ > $debugfs/tracing/set_ftrace_pid 
echo blk_update_request > $debugfs/tracing/set_graph_function
echo function_graph > $debugfs/tracing/current_tracer
echo 1 > $debugfs/tracing/options/funcgraph-tail 
echo 1 > $debugfs/tracing/tracing_on 
exec "$@"

执行如下命令:

# ./ftrace_graph.sh cat ftrace_graph.sh

通过如下命令查看结果

cat /sys/kernel/debug/tracing/trace

注：在执行前需要通过echo 3 > /proc/sys/vm/drop_caches 清下cache，否则可能不会触发blk_update_request 执行