ftrace，kprobe，tracepoint 入门

调试工具在开发过程中是必不可少的，特别是在定位 bug， 分析性能瓶颈的时候，调试工具可以给我们很大的帮助。在使用 c/c++ 做应用开发时，gdb 是我们经常使用的调试工具，在使用 gdb 时, 我们可以设置断点，查看调用栈，单步执行，修改或查看变量等。

调试工具可以帮助我们直观地观察到软件的运行过程，进而使我们快速熟悉一个新的软件。比如在工作中，想要了解已有软件的架构，只靠看代码是很难了解透彻的，通过日志和调试工具可以提高学习效率。

本文中介绍的 ftrace, kprobe, trace event 均是内核提供的调试工具，ftrace 和 kprobe 可以帮助我们确定一个函数有没有被调用，查看函数的调用栈，获取函数的形参，返回值等；trace event 是内核开发者在一些关键函数的关键位置预留的跟踪点，trace event 是静态的。

1 ftrace

ftrace 用一个文件系统 tracefs 来实现，从 /proc/filesystems 文件可以看到 linux 支持的文件系统类型，除了 tracefs，我们还可以看到 cgroup 以及 cgroup、cgroup2、sockfs、sysfs 这些。

输入 mount 可以查看 tracefs的挂载目录，如下所示，tracefs 挂载到了两个目录下，/sys/kernel/tracing 和 /sys/kernel/debug/tracing，这两个目录下的内容是相同的，每个目录都可以操作。

ftrace 目录下几个常用的文件：

文件	说明
available_tracers	该文件显示的是 ftrace 支持哪些类型的 tracer，常用的是 function 和 function_graph，function 可以确定这个函数有没有被调用到，打印调用栈；function_graph 可以跟踪改函数的调用过程。
current_tracer	当前在使用哪个 tracer，如果想要使用 function，就需要执行 echo function > current_tracer；如果想取消当前的 tracer，则执行 echo nop > current_tracer。
tracing_on	trace 开关，控制 trace 的信息是不是打印到 trace 缓冲区中，1 是打开，0 则关闭。这个开关控制的是 trace 信息是否打印到 trace 缓冲区中，而不是控制 trace 是不是被执行，这个设置为 0 的话，内核可能仍然在执行 trace 功能，只是相关的信息不再打印到 trace 缓冲区而已。
trace	这是一个环形缓冲区，tracer 的打印信息就打印到这个文件中。
available_filter_functions	这个里边显示的是哪些函数可以被 ftrace 进行跟踪，内核中并不是所有函数都能被 ftrace 跟踪的，比如实现 ftrace 功能本身的函数，inline 函数，都不能被 ftrace 跟踪。
set_ftrace_filter	使用 function 这个 tracer 的时候，要跟踪哪个函数，把这个函数 echo 到这个文件
set_graph_function	使用 function_graph 这个 tracer 的时候，需要跟踪哪个函数，把这个函数 echo 到这个文件
set_ftrace_pid	有时候我们只想跟踪我们感兴趣的线程，那么就可以把线程 id echo 到这个文件中，那么 trace 缓冲区中就只看到这个线程相关的信息

 1.1 function

function tracer，可以查看一个函数的调用栈，以及调用这个函数的进程，pid, 以及调用时在哪个 cpu 核上。

cd /sys/kernel/debug/tracing/

进入 tracing 目录，本文中记录的 ftrace, trace event 均是在该目录下工作。

echo 0 > tracing_on

tracer 开关，写 0 是关闭，写 1 是打开

echo function > current_tracer

指定当前使用的 tracer

当前系统支持的 tracer，可以 cat available_tracers 查看

echo tcp_sendmsg > set_ftrace_filter

指定要跟踪的函数

当前系统支持的，可以跟踪的函数可以 cat available_filter_functions 查看

echo 1 > tracing_on

打开 tracer 开关

cat trace 查看结果

 在使用 ftrace 监控一个函数的调用情况时，可能只需要监控某个进程的调用情况，这个时候可以将进程 pid 写入 set_ftrace_pid 文件，这样 trace 中显示的打印信息就只包括了 set_ftrace_pid 包含的 pid。

function tracer 选项：func_stack_trace

默认情况下，function tracer 显示的信息如上所示，调用栈只显示了一级，调用 tcp_sendmsg() 函数的是 inet_sendmsg()，具体谁调用的 inet_sendmsg()，没有显示出来。

如果设置了 func_stack_trace，那么就可以显示调用栈，执行 echo 1 > options/func_stack_trace 之后，trace 中显示的信息如下：

1.2 function graph

function graph 可以跟踪一个函数的执行过程。

我们常见的调用栈从上到下是调用关系倒序的，比如上边的 function 显示的调用栈，再比如当使用 gdb 调试程序的时候，函数 a() 调用了 b(), b() 调用了 c()，那么在函数 c() 设置断点的时候，当运行到函数 c() 的时候程序便会停止，这个时候使用 bt 命令查看到的调用栈如下。

示例代码如下：

#include <stdlib.h>
#include <stdio.h>
#include <string.h>

void c() {
  printf("in function c\n");
}

void b() {
  printf("in function b\n");
  c();
}

void a() {
  printf("in function a\n");
  b();
}


int main() {
  a();
  return 0;
}

下边的例子依然是跟踪函数 tcp_sendmsg()。

echo 0 > tracing_on

echo function_graph > current_tracer

echo tcp_sendmsg > set_graph_function

echo 1 > tracing_on

执行上述步骤之后，就可以通过 cat trace 查看 tcp_sendmsg() 的调用过程。

在默认情况下，trace 文件中会显示 tcp_sendmsg() 函数中向下的调用过程，每一个可以跟踪的函数都会展开，

这样看的话，函数调用栈比较深，这种情况下，如果要限制函数调用栈展开的深度，可以设置参数 max_graph_depth，该参数默认是 0，意思是不限制。如下是将 max_graph_depth 设置成 5 之后显示的结果，设置之后显示的函数调用深度最大是 5，如下调用关系就能看出来，函数调用关系最多显示了 5 级：

tcp_sendmsg()

调用

tcp_sendmsg_locked()

调用

tcp_push()

调用

__tcp_push_pending_frames()

调用

tcp_write_xmit()

如果将 max_graph_depth 设置为 0, 即不对打印深度做限制，那么上边的调用栈就打印了 6 层，如下图所示。

function graph 还显示了每个函数调用所消耗的时间，可以用来做性能分析。

如上图所示，显示了每个函数执行所消耗的时间，单位是微秒，如果一个函数还要调用其它函数，比如上图中的 tcp_push()，那么在函数名这一行不显示时间，而是在函数结束时右大括号 } 这一行才会显示时间，上图中 tcp_push() 消耗的时间是 10.265 μs，如果一个函数没有调用其它函数了，那么在这个函数名对应的这一行会显示时间，比如 tcp_push() 内部调用的 tcp_write_xmit()，这个函数消耗的时间是 0.961 μs。

set_ftrace_pid 选项可以设置我们感兴趣的进程 id, 该选项对于 function_graph 同样有效。

1.3 wakeup 

wakeup 可以监控进程从唤醒到被真正运行的这段时间，这段时间也可以称为调度延迟。意思是进程被唤醒之后就可以立即运行了，但是有些时候进程并不能立即运行，而是需要在运行队列中排队，然后等 cpu 轮到自己之后才开始运行，这段时间就是从进程可以被运行到真正被运行的时间，即调度延时。

和 wakeup 相关的有 3 个 tracer 分别是 wakeup, wakeup_rt 以及 wakeup_dl。这 3 种 wakeup 是按调度策略进行分类的，调度策略分为 3 类，普通调度策略(SCHED_OTHER), 实时(rt，real-time)调度策略(SCHED_RR 和 SCHED_FIFO)，截止时间(dl，deadline) 调度策略，这 3 种调度策略分别对应上边的 3 种 wakeup。

3 种 wakeup 可以跟踪对应调度策略的调度延迟的最大值， 跟踪到的最大调度延时可以通过 cat tracing_max_latency 来查看。tracing_max_latency 中保存的是跟踪到的调度延时的最大值，类似于我们找最大值的算法，只有后边的值大于这个值的时候才会对这个值进行更新。也可以通过设置 tracing_max_latency 的值来调整跟踪，比如 wakeup 跟踪一段时间之后，跟踪到的最大调度延时是 200μs，那么后边的跟踪，只有调度延时大于 200μs 的时候才会对这个值进行更新，这个时候想重新跟踪，比如跟踪调度延时大于 100μs 的进程，就可以 echo 100 > tracing_max_latency，设置之后，下次跟踪到调度延迟大于 100μs 的时候便会将信息打印到 trace 缓冲区。

wakeup 和 wakeup_rt 的使用方式以及打印的信息格式是类似的，只是跟踪的进程的调度策略不一样，本文中只记录一个 wakeup 的例子。

如下是一个 wakeup 打印的信息：

latency: 77 μs // 跟踪到的最大调度延迟是 77μs

最大调度延迟发生在任务 migration/1 上，线程 id 是 22。

migration/1 在就绪队列中等待的时候，运行的进程是 stress，进程 id 是 20738。

wakeup 不像 function 和 function graph 那样，会显示历史的跟踪信息，wakeup 只显示一条信息，就是当前跟踪到的调度延迟最大的这条信息。

2 kprobe

probe 是探针的意思，内核中的大部分代码都是可以探测的，用户指定一个探测点，然后指定一个函数，当程序运行到这个探测点的时候便会执行这个函数，这个函数执行完毕之后，再继续执行后边的代码，这就是 kprobe 的工作方式。本文中介绍 kprobe 和 kretprobe。

2.1 kprobe

kprobe 可以探测函数的任何一个指令，当使用 kprobe 时，需要指定要探测的函数，并且要指定指令执行前要调用的函数(pre_handler)以及指令执行后要调用的函数(post_handler)。这 3 个参数是结构体 struct kprobe 的成员，如下是 struct kprobe 的结构体定义，下边只列出了结构体的 3 个成员，struct kprobe 不止包括这 3 个成员，还有其它成员。

struct kprobe {
    /* Allow user to indicate symbol name of the probe point */
    const char *symbol_name;
    
	/* Offset into the symbol */
    // kprobe 不仅仅能探测函数的入口，还能探测函数内部的指令 
    // offset 可以指定相对于函数入口的指令的偏移
	unsigned int offset;

    /* Called before addr is executed. */
    kprobe_pre_handler_t pre_handler;

    /* Called after addr is executed, unless... */
    kprobe_post_handler_t post_handler;
};

pre_handler 和 post_handler 的函数原型如下，两个形参：

① struct kprobe *，即我们加载内核模块时通过 register_kprobe() 注册的参数

② struct pt_regs *， cpu 的寄存器信息，与 cpu 架构相关，下边给出了 x86 架构下结构体定义，di, si, dx, cx, r8, r9 这 6 个寄存器分别表示入参的第 1 到 第 6 个入参

typedef int (*kprobe_pre_handler_t) (struct kprobe *, struct pt_regs *);
typedef void (*kprobe_post_handler_t) (struct kprobe *, struct pt_regs *,
                       unsigned long flags);

struct pt_regs {
/*
 * C ABI says these regs are callee-preserved. They aren't saved on kernel entry
 * unless syscall needs a complete, fully filled "struct pt_regs".
 */
    unsigned long r15;
    unsigned long r14;
    unsigned long r13;
    unsigned long r12;
    unsigned long bp;
    unsigned long bx;
/* These regs are callee-clobbered. Always saved on kernel entry. */
    unsigned long r11;
    unsigned long r10;
    unsigned long r9;
    unsigned long r8;
    unsigned long ax;
    unsigned long cx;
    unsigned long dx;
    unsigned long si;
    unsigned long di;
/*
 * On syscall entry, this is syscall#. On CPU exception, this is error code.
 * On hw interrupt, it's IRQ number:
 */
    unsigned long orig_ax;
/* Return frame for iretq */
    unsigned long ip;
    unsigned long cs;
    unsigned long flags;
    unsigned long sp;
    unsigned long ss;
/* top of stack page */
};

kprobe 的注册和取消注册通过 register_kprobe() 和 unregister_kprobe() 两个函数来完成，通常在内核模块的入口函数中注册 kprobe, 在退出函数中取消注册 kprobe，两个函数的声明如下, 形参为 struct kprobe * 类型。

int register_kprobe(struct kprobe *p);
void unregister_kprobe(struct kprobe *p);

并不是所有的内核函数都是可以被探测的，不可探测的函数可以在 /sys/kernel/debug/kprobes/blacklist 中查看。

kprobe 可以通过内核模块的方式来使用，内核中提供了 kprobe 的例子，在如下目录：

samples/kprobes/kprobe_example.c

本人测试在 ubuttu 20.04 上进行，cpu 架构为 x86，探测了 tcp_sendmsg() 这个函数，并打印了函数入参信息。

tcp_sendmsg() 的声明如下，第一个参数是 struct sock * 类型，里边包含了接收缓冲区大小，发送缓冲区大小，tcp 首部的长度；第三个参数是要发送的报文的长度，保存在了 dx 寄存器。

int tcp_sendmsg(struct sock *sk, struct msghdr *msg, size_t size)

pr_info("<%s> p->addr = 0x%p, ip = %lx, flags = 0x%lx, rcv buf: %d, snd buf: %d, tcp_header len: %u, size: %ld\n",
        p->symbol_name, p->addr, regs->ip, regs->flags,
        ((struct sock *)(regs->di))->sk_rcvbuf, ((struct sock *)(regs->di))->sk_sndbuf,
        (((struct tcp_sock *)(regs->di))->tcp_header_len),
        regs->dx);

安装内核模块之后，在 dmesg 中可以看到打印信息如下，可以看到每个发送的 tcp 报文的长度。

内核模块代码：

// SPDX-License-Identifier: GPL-2.0-only
/*
 * NOTE: This example is works on x86 and powerpc.
 * Here's a sample kernel module showing the use of kprobes to dump a
 * stack trace and selected registers when kernel_clone() is called.
 *
 * For more information on theory of operation of kprobes, see
 * Documentation/trace/kprobes.rst
 *
 * You will see the trace data in /var/log/messages and on the console
 * whenever kernel_clone() is invoked to create a new process.
 */

#include <linux/kernel.h>
#include <linux/module.h>
#include <linux/kprobes.h>
#include <linux/tcp.h>
#include <net/sock.h>

#define MAX_SYMBOL_LEN  64
static char symbol[MAX_SYMBOL_LEN] = "tcp_sendmsg";
module_param_string(symbol, symbol, sizeof(symbol), 0644);

/* For each probe you need to allocate a kprobe structure */
static struct kprobe kp = {
        .symbol_name    = symbol,
};

/* kprobe pre_handler: called just before the probed instruction is executed */
static int __kprobes handler_pre(struct kprobe *p, struct pt_regs *regs)
{
        // 我是用的虚拟机是 x86 架构的，所以这里只保留了 x86 架构的寄存器使用方式        
        pr_info("<%s> p->addr = 0x%p, ip = %lx, flags = 0x%lx, rcv buf: %d, snd buf: %d, tcp_header len: %u, size: %ld\n",
                p->symbol_name, p->addr, regs->ip, regs->flags,
                ((struct sock *)(regs->di))->sk_rcvbuf, ((struct sock *)(regs->di))->sk_rcvbuf,
                (((struct tcp_sock *)(regs->di))->tcp_header_len),
                regs->dx);


        /* A dump_stack() here will give a stack backtrace */
        return 0;
}

/* kprobe post_handler: called after the probed instruction is executed */
static void __kprobes handler_post(struct kprobe *p, struct pt_regs *regs,
                                unsigned long flags)
{

}

static int __init kprobe_init(void)
{
        int ret;
        kp.pre_handler = handler_pre;
        kp.post_handler = handler_post;

        ret = register_kprobe(&kp);
        if (ret < 0) {
                pr_err("register_kprobe failed, returned %d\n", ret);
                return ret;
        }
        pr_info("Planted kprobe at %p\n", kp.addr);
        return 0;
}

static void __exit kprobe_exit(void)
{
        unregister_kprobe(&kp);
        pr_info("kprobe at %p unregistered\n", kp.addr);
}

module_init(kprobe_init)
module_exit(kprobe_exit)
MODULE_LICENSE("GPL");

Makefile 编译脚本：

obj-m += kprobe.o

all:
        make -C /lib/modules/$(shell uname -r)/build M=$(PWD) modules
clean:
        make -C /lib/modules/$(shell uname -r)/build M=$(PWD) clean

2.2 kretprobe

kretprobe 可以在函数返回的时候进行探测，kretprobe 和 kprobe 的区别如下：

① 探测位置不同

kprobe 可以探测函数的任何一条指令，kprobe 的探测位置是不固定的，是用户可以指定的；

kretprobe 探测的位置是固定的，函数返回处。

② 指令替换的时机不一样

对于 kprobe 来说，当使用 register_kprobe() 注册 kprobe 的时候，就会将对应位置的指令进行替换，但是对于 kretprobe 来说，因为一个函数可能在多个地方都会返回，所以函数的返回的地方是不确定的，kretprobe 的指令替换是在函数被调用的时候才确定的。

kretprobe 可以用于获取函数的返回值和函数执行消耗的时间。

struct kretprobe:

entry_handler 和 handler 这两个回调分别是函数进入的时候调用和函数返回的时候调用，由此可以计算出函数调用消耗的时间。

maxactive 表示支持同时探测的上限，由于被 kretprobe 探测的函数可能会被并发执行，所以每个执行路径的信息都要被单独保存，如果被探测的并行路径超过这个值，那么新增的调用不会被探测，而是会增加 nmissed 的统计。

struct kretprobe {
    struct kprobe kp;
    kretprobe_handler_t handler;
    kretprobe_handler_t entry_handler;
    int maxactive;
    int nmissed;
    size_t data_size;
    struct freelist_head freelist;
    struct kretprobe_holder *rph;
};

struct kretprobe_instance 维护一个调用路径的信息， 成员 data 用于保存用户的私有数据，私有数据的长度通过 struct kretprobe 中的 data_size 指定。entry_handler 和 handler 这两个回调函数的第一个形参即 struct kretprobe_handler * 类型。

struct kretprobe_instance {
    union {
        struct freelist_node freelist;
        struct rcu_head rcu;
    };
    struct llist_node llist;
    struct kretprobe_holder *rph;
    kprobe_opcode_t *ret_addr;
    void *fp;
    char data[];
};

同样的，内核源码中有一个 kretprobe 的例子, 在这个例子中，通过 kretprobe 统计了函数执行消耗的事件，并获取了函数的返回值。

samples/kprobes/kretprobe_example.c

2.2.1 /sys/kernel/debug/kprobes/

这个目录下有如下 3 个文件：

blacklist: 这个文件中的函数不能进行 probe

enabled: 是 1 的话，说明 kprobe 功能使能，这个文件可以更改，如果改成 0，那么 kprobe 功能就会失效

list: 这个文件中列出了当前被 probe 的函数

如下是安装了本文中所说的 kprobe 和 kretprobe 之后，list 文件显示的内容

2.3 kprobe on ftrace 

kprobe 有两种实现方式，一种是传统的 kprobe 实现方式，这种实现方式与 ftrace 没有任何关系；

一种是通过 ftrace 实现的 kprobe，从上文中我们可以看出，kprobe 与 ftrace 有一些相似之处，都是在函数的入口或者出口埋点，在埋点处可以捕捉一些信息。

对于被 probe 的函数，当函数支持 ftrace 时，则通过 ftrace 实现，当函数不支持 ftrace 时，则通过传统的方式实现。

如果内核中的函数被 notrace 修饰，那么这个函数是不支持 ftrace 的，当探测这个函数时，就是通过传统方式来实现的。

通过在内核代码中搜索 notrace 关键字，发现函数 ktime_get_mono_fast_ns() 被 notrace 修饰，我们尝试探测一下这个函数。

u64 notrace ktime_get_mono_fast_ns(void)
{
    return __ktime_get_fast_ns(&tk_fast_mono);
}

从 /sys/kernel/debug/kprobes/list 显示结果也可以看出来，tcp_sendmsg() 的 kprobe 后边有 [FTRACE] 标记，所以是通过 ftrace 实现的； ktime_get_mono_fast_ns() 的后边没有 FTRACE 标记， 说明是通过传统方式实现的。

2.3.1 ftrace based kprobe 可以通过命令行来实现，这样就不用写内核模块了

probe tcp_sendmsg 函数，并打印第 3 个参数。

echo 'p:tcp_sendmsg tcp_sendmsg $arg3' >kprobe_events

echo 1 > events/kprobes/tcp_sendmsg/enable

cat trace

删除这个 kprobe:

echo -:tcp_sendmsg > kprobe_events

ftrace based kprobe 保存在 events/kprobes 目录下，这个目录中的信息类似于一个 trace event 中的信息，其中也包括 enable, format, filter, trigger 等文件。有些文章里边也把这个叫做动态 tracepoint，而把下一节记录的内核中自带的 tracepoint 叫做静态 tracepoint。

命令行格式如下：

  p[:[GRP/]EVENT] [MOD:]SYM[+offs]|MEMADDR [FETCHARGS]  : Set a probe

  r[MAXACTIVE][:[GRP/]EVENT] [MOD:]SYM[+0] [FETCHARGS]  : Set a return probe

  p:[GRP/]EVENT] [MOD:]SYM[+0]%return [FETCHARGS] : Set a return probe

  -:[GRP/]EVENT           : Clear a probe

 GRP    : Group name. If omitted, use "kprobes" for it.

 EVENT    : Event name. If omitted, the event name is generated

      based on SYM+offs or MEMADDR.

 MOD    : Module name which has given SYM.

 SYM[+offs] : Symbol+offset where the probe is inserted.

 SYM%return : Return address of the symbol

 MEMADDR  : Address where the probe is inserted.

 MAXACTIVE  : Maximum number of instances of the specified function that

      can be probed simultaneously, or 0 for the default value

      as defined in Documentation/trace/kprobes.rst section 1.3.1.

 FETCHARGS  : Arguments. Each probe can have up to 128 args.

  %REG    : Fetch register REG

  @ADDR   : Fetch memory at ADDR (ADDR should be in kernel)

  @SYM[+|-offs] : Fetch memory at SYM +|- offs (SYM should be a data symbol)

  $stackN : Fetch Nth entry of stack (N >= 0)

  $stack  : Fetch stack address.

  $argN   : Fetch the Nth function argument. (N >= 1) (\*1)

  $retval : Fetch return value.(\*2)

  $comm   : Fetch current task comm.

  +|-[u]OFFS(FETCHARG) : Fetch memory at FETCHARG +|- OFFS address.(\*3)(\*4)

  \IMM    : Store an immediate value to the argument.

  NAME=FETCHARG : Set NAME as the argument name of FETCHARG.

  FETCHARG:TYPE : Set TYPE as the type of FETCHARG. Currently, basic types

      (u8/u16/u32/u64/s8/s16/s32/s64), hexadecimal types

      (x8/x16/x32/x64), "string", "ustring" and bitfield

      are supported.

  (\*1) only for the probe on function entry (offs == 0).

  (\*2) only for return probe.

  (\*3) this is useful for fetching a field of data structures.

  (\*4) "u" means user-space dereference. See :ref:`user_mem_access`.

3 trace event

cat available_events 可以查看当前系统支持的 event。

trace event 以 子系统::事件 的格式来表示，本文中以 netif_receive_skb(网卡收到的报文会交给 netif_receive_skb() 函数处理，该函数处理的报文会交给上层协议来处理) 来举例，在 available_events 显示为 net::netif_receive_skb。事件的层次关系也表示成了目录关系，如下：

查看 netif_receive_skb 目录下有以下几个文件：

使能 netif_receive_skb 有两种方式：

(1) echo 1 > events/net/netif_receive_skb/enable

(2) echo netif_receive_skb >> set_event

同样的，关闭一个 event 也有两种方式，分别是 echo 0 > events/net/netif_receive_skb/enable 和 echo '!netif_receive_skb' >> set_event

打开 netif_receive_skb 之后，可以在 trace 文件中查看打印信息：

打印信息包括线程 id, event 发生在哪个 cpu 核上，时间戳，这 3 个信息是 trace event 共有的信息，每个 event 都会打印这 3 个信息；后边的信息， dev 表示报文从哪个网卡接收，skbaddr 表示 struct sk_buff 的地址，sk_buff 在内核中管理一个报文，在传输层，网络层，链路层，网卡驱动中均会用到这个数据结构，len 是报文的长度，这 3 个信息是 netif_receive_skb 这个 event 特有的。

3.1 format 和 filter 

format 中最后一行显示了这个 event 向 trace 文件中打印的信息的格式。如下图所示，netif_receive_skb event 打印的信息和我们上边看到的打印的信息格式是一致的。

format 中除了最后一行的 print fmt 用来定义打印到缓冲区 trace 中的内容格式，上边还有多个 filed。

field 分为两类，一类是有 common 开头的，一类是没有 common 开头，common 开头的是 trace event 提供的共用的变量，没有 common 开头的 field 是这个 trace event 自己定义的。

field 可以用来过滤信息，添加了过滤信息，那么打印到缓冲区的信息都是满足过滤条件的。比如我们常常需要关注某个进程的信息，比如 pid xxx，这个时候就可以使用如下命令来添加过滤条件。

echo common_pid==xxx > events/net/netif_receive_skb/filter

如果过滤条件有多个，可以使用 || 或者 &，分别表示或，与。如下命令表示过滤条件 pid 为 xxx, 报文长度大于 yyy 。

echo "common_pid==xxx && len > yyy" > events/net/netif_receive_skb/filter

如果想要清除过滤条件，那么向 filter 写 0 即可。

echo 0 > events/net/netif_receive_skb/filter

另外，过滤 pid 还有一种方法，就是设置文件 set_event_pid，这个文件是针对 event 全局的，上边的方式是针对单独的一个 event。

增加 pid 过滤: echo 3026 > set_event_pid

去掉 pid 过滤: echo > set_event_pid

3.2 trigger

filter 决定满足什么样的条件的日志会被打印到 trace 缓冲区里，在讨论 filter 的时候，只讨论一个 trace event，没有涉及到多个 event 之间的相互关系。filter 只能决定日志要不要打印到 trace 缓冲区，即使当条件不满足时，日志不打印到 trace 中，那么这次 event 也是触发了。

trigger 关心的是 event 要不要触发的问题，不是触发之后日志要不要打印的问题，并且在 trigger 中还可以设置多个 event 之间的关系，比如当一个 event 发生的时候触发另外一个 event，命令字 enable_event 和 disable_event 就可以实现这个目的。

trigger 做的事情是控制这个 event 什么时候触发，什么时候不触发。

3.2.1 当有系统调用 read() 触发时，使能 sched_switch 事件

echo 'enable_event:sched:sched_switch:1' > /sys/kernel/debug/tracing/events/syscalls/sys_enter_read/trigger

sched::shced_switch 是跟踪的进程切换的信息，会打印出这次进程调度的时候，上一个进程和下一个调度运行的进程信息。

disable 跟踪，命令行如下。

echo 'disable_event:sched:sched_switch:1' > /sys/kernel/debug/tracing/events/syscalls/sys_enter_read/trigger

有的 trigger 是可以直接在使能命令行前加 ! 进行去使能的，比如下边的命令，但是这样操作对于有些 trigger 不生效，比如当前这个实验，就是不生效的。

需要先 disable_event 去使能，然后再在 disable 的命令行前加 ! 来删除这个 trigger。

echo '!enable_event:sched:sched_switch:1' > /sys/kernel/debug/tracing/events/syscalls/sys_enter_read/trigger

3.2.2 trigger 打印调用栈

在调用 kmalloc 的时候打印调用栈：

echo 'stacktrace' > \
      /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger

加上过滤条件，当申请的内存大于 65535 的时候才打印调用栈，并且只打印 5 次。

 echo 'stacktrace:5 if bytes_req >= 65536' > \
      /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger

去使能 trigger

# echo '!stacktrace' > \
      /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger

# echo '!stacktrace:5 if bytes_req >= 65536' > \
      /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger

4 参考文档

Event Tracing — The Linux Kernel documentation