Linux 调试之 TRACE_EVENT（三）
文章目录
前言
内核内的跟踪点有助于分析内核的性能。可以跟踪和检查关键信息流，以便调试延迟问题，或者简单地找出更好的方法来调整系统。核心内核跟踪点（如调度器和中断跟踪点）让用户看到事件在内核内发生的时间和方式。模块开发人员还可以利用跟踪点；如果用户或客户有问题，开发人员可以让他们启用跟踪点并分析情况。本文将解释如何在核心内核代码之外的模块中添加跟踪点。
在Linux 调试之 TRACE_EVENT（一），解释了在核心内核中创建跟踪点的过程。
在Linux 调试之 TRACE_EVENT（二），解释了如何使用DECLARE_EVENT_CLASS（）和DEFINE_EVENT（）合并跟踪点，并介绍了TP_STRUCT__entry的字段宏和TP_printk（）的辅助函数。
前面说过内核中的大部分跟踪点都是定义在该目录下：
linux-3.10/include/trace/events/
本文将介绍如何在核心内核之外添加跟踪点（不在linux-3.10/include/trace/events/目录下的 tracepoint点），这些跟踪点可以由模块或特定于体系结构的代码使用。
比如：
// linux-3.10/arch/x86/kernel/vsyscall_trace.h
#undef TRACE_SYSTEM
#define TRACE_SYSTEM vsyscall
#if !defined(__VSYSCALL_TRACE_H) || defined(TRACE_HEADER_MULTI_READ)
#define __VSYSCALL_TRACE_H
#include <linux/tracepoint.h>
TRACE_EVENT(emulate_vsyscall,
TP_PROTO(int nr),
TP_ARGS(nr),
TP_STRUCT__entry(__field(int, nr)),
TP_fast_assign(
__entry->nr = nr;
),
TP_printk("nr = %d", __entry->nr)
);
#endif
#undef TRACE_INCLUDE_PATH
#define TRACE_INCLUDE_PATH ../../arch/x86/kernel
#define TRACE_INCLUDE_FILE vsyscall_trace
#include <trace/define_trace.h>
[root@localhost ~]# ls -l /sys/kernel/debug/tracing/events/vsyscall/
emulate_vsyscall/ enable filter
// linux-3.10/arch/x86/kvm/trace.h
#if !defined(_TRACE_KVM_H) || defined(TRACE_HEADER_MULTI_READ)
#define _TRACE_KVM_H
#include <linux/tracepoint.h>
#include <asm/vmx.h>
#include <asm/svm.h>
#include <asm/clocksource.h>
#undef TRACE_SYSTEM
#define TRACE_SYSTEM kvm
/*
* Tracepoint for guest mode entry.
*/
TRACE_EVENT(kvm_entry,
TP_PROTO(unsigned int vcpu_id),
TP_ARGS(vcpu_id),
TP_STRUCT__entry(
__field( unsigned int, vcpu_id )
),
TP_fast_assign(
__entry->vcpu_id = vcpu_id;
),
TP_printk("vcpu %u", __entry->vcpu_id)
);
/*
* Tracepoint for hypercall.
*/
TRACE_EVENT(kvm_hypercall,
TP_PROTO(unsigned long nr, unsigned long a0, unsigned long a1,
unsigned long a2, unsigned long a3),
TP_ARGS(nr, a0, a1, a2, a3),
TP_STRUCT__entry(
__field( unsigned long, nr )
__field( unsigned long, a0 )
__field( unsigned long, a1 )
__field( unsigned long, a2 )
__field( unsigned long, a3 )
),
TP_fast_assign(
__entry->nr = nr;
__entry->a0 = a0;
__entry->a1 = a1;
__entry->a2 = a2;
__entry->a3 = a3;
),
TP_printk("nr 0x%lx a0 0x%lx a1 0x%lx a2 0x%lx a3 0x%lx",
__entry->nr, __entry->a0, __entry->a1, __entry->a2,
__entry->a3)
);
/*
* Tracepoint for hypercall.
*/
TRACE_EVENT(kvm_hv_hypercall,
TP_PROTO(__u16 code, bool fast, __u16 rep_cnt, __u16 rep_idx,
__u64 ingpa, __u64 outgpa),
TP_ARGS(code, fast, rep_cnt, rep_idx, ingpa, outgpa),
TP_STRUCT__entry(
__field( __u16, rep_cnt )
__field( __u16, rep_idx )
__field( __u64, ingpa )
__field( __u64, outgpa )
__field( __u16, code )
__field( bool, fast )
),
TP_fast_assign(
__entry->rep_cnt = rep_cnt;
__entry->rep_idx = rep_idx;
__entry->ingpa = ingpa;
__entry->outgpa = outgpa;
__entry->code = code;
__entry->fast = fast;
),
TP_printk("code 0x%x %s cnt 0x%x idx 0x%x in 0x%llx out 0x%llx",
__entry->code, __entry->fast ? "fast" : "slow",
__entry->rep_cnt, __entry->rep_idx, __entry->ingpa,
__entry->outgpa)
);
......
#endif /* _TRACE_KVM_H */
#undef TRACE_INCLUDE_PATH
#define TRACE_INCLUDE_PATH arch/x86/kvm
#undef TRACE_INCLUDE_FILE
#define TRACE_INCLUDE_FILE trace
/* This part must be outside protection */
#include <trace/define_trace.h>
[root@localhost ~]# ls -l /sys/kernel/debug/tracing/events/kvm/
enable kvm_async_pf_ready/ kvm_fast_mmio/ kvm_ioapic_set_irq/ kvm_pic_set_irq/ kvm_try_async_get_page/
filter kvm_avic_incomplete_ipi/ kvm_fpu/ kvm_mmio/ kvm_pi_irte_update/ kvm_update_master_clock/
kvm_ack_irq/ kvm_avic_unaccelerated_access/ kvm_halt_poll_ns/ kvm_msi_set_irq/ kvm_pio/ kvm_userspace_exit/
kvm_age_page/ kvm_cpuid/ kvm_hv_hypercall/ kvm_msr/ kvm_ple_window/ kvm_vcpu_wakeup/
kvm_apic/ kvm_cr/ kvm_hv_timer_state/ kvm_nested_intercepts/ kvm_pml_full/ kvm_wait_lapic_expire/
kvm_apic_accept_irq/ kvm_emulate_insn/ kvm_hypercall/ kvm_nested_intr_vmexit/ kvm_pvclock_update/ kvm_write_tsc_offset/
kvm_apic_ipi/ kvm_enter_smm/ kvm_inj_exception/ kvm_nested_vmexit/ kvm_pv_eoi/ vcpu_match_mmio/
kvm_async_pf_completed/ kvm_entry/ kvm_inj_virq/ kvm_nested_vmexit_inject/ kvm_set_irq/
kvm_async_pf_doublefault/ kvm_eoi/ kvm_invlpga/ kvm_nested_vmrun/ kvm_skinit/
kvm_async_pf_not_present/ kvm_exit/ kvm_ioapic_delayed_eoi_inj/ kvm_page_fault/ kvm_track_tsc/
一、include/trace/events之外定义跟踪头文件
对于模块或体系结构特定目录中的跟踪点，在全局include/trace/events目录中包含跟踪头文件可能会使其混乱。结果是将核心内核不需要的mips_cpuh或arm_cpuh等文件放入该目录。它最终将类似于旧的include/asm-*/setup。此外，如果跟踪点进入暂存驱动程序，则将暂存头文件放入核心内核代码库将是一个糟糕的设计。
因此对于模块或体系结构特定目录中的跟踪点，不要放在全局include/trace/events目录中，include/trace/events目录中的 tracepoint 对于体系架构都是通用的。
因为 trace header files 的处理方式与其他普通的 c header files 非常不同，所以最好的解决方案是将头文件放置在使用它们的位置。例如，XFS跟踪点位于fs/xfs/xfs_trace.h中的XFS子目录中。如下：
// linux-3.10/fs/xfs/xfs_trace.h
#undef TRACE_SYSTEM
#define TRACE_SYSTEM xfs
#if !defined(_TRACE_XFS_H) || defined(TRACE_HEADER_MULTI_READ)
#define _TRACE_XFS_H
#include <linux/tracepoint.h>
struct xfs_agf;
struct xfs_alloc_arg;
struct xfs_attr_list_context;
struct xfs_buf_log_item;
struct xfs_da_args;
struct xfs_da_node_entry;
struct xfs_dquot;
struct xfs_log_item;
struct xlog_ticket;
struct xlog;
struct xlog_recover;
struct xlog_recover_item;
struct xfs_buf_log_format;
struct xfs_inode_log_format;
struct xfs_bmbt_irec;
DECLARE_EVENT_CLASS(xfs_attr_list_class,
TP_PROTO(struct xfs_attr_list_context *ctx),
TP_ARGS(ctx),
TP_STRUCT__entry(
__field(dev_t, dev)
__field(xfs_ino_t, ino)
__field(u32, hashval)
__field(u32, blkno)
__field(u32, offset)
__field(void *, alist)
__field(int, bufsize)
__field(int, count)
__field(int, firstu)
__field(int, dupcnt)
__field(int, flags)
),
TP_fast_assign(
__entry->dev = VFS_I(ctx->dp)->i_sb->s_dev;
__entry->ino = ctx->dp->i_ino;
__entry->hashval = ctx->cursor->hashval;
__entry->blkno = ctx->cursor->blkno;
__entry->offset = ctx->cursor->offset;
__entry->alist = ctx->alist;
__entry->bufsize = ctx->bufsize;
__entry->count = ctx->count;
__entry->firstu = ctx->firstu;
__entry->flags = ctx->flags;
),
TP_printk("dev %d:%d ino 0x%llx cursor h/b/o 0x%x/0x%x/%u dupcnt %u "
"alist 0x%p size %u count %u firstu %u flags %d %s",
MAJOR(__entry->dev), MINOR(__entry->dev),
__entry->ino,
__entry->hashval,
__entry->blkno,
__entry->offset,
__entry->dupcnt,
__entry->alist,
__entry->bufsize,
__entry->count,
__entry->firstu,
__entry->flags,
__print_flags(__entry->flags, "|", XFS_ATTR_FLAGS)
)
)
#define DEFINE_ATTR_LIST_EVENT(name) \
DEFINE_EVENT(xfs_attr_list_class, name, \
TP_PROTO(struct xfs_attr_list_context *ctx), \
TP_ARGS(ctx))
DEFINE_ATTR_LIST_EVENT(xfs_attr_list_sf);
DEFINE_ATTR_LIST_EVENT(xfs_attr_list_sf_all);
DEFINE_ATTR_LIST_EVENT(xfs_attr_list_leaf);
DEFINE_ATTR_LIST_EVENT(xfs_attr_list_leaf_end);
DEFINE_ATTR_LIST_EVENT(xfs_attr_list_full);
DEFINE_ATTR_LIST_EVENT(xfs_attr_list_add);
DEFINE_ATTR_LIST_EVENT(xfs_attr_list_wrong_blk);
DEFINE_ATTR_LIST_EVENT(xfs_attr_list_notfound);
DEFINE_ATTR_LIST_EVENT(xfs_attr_leaf_list);
DEFINE_ATTR_LIST_EVENT(xfs_attr_node_list);
......
#endif /* _TRACE_XFS_H */
#undef TRACE_INCLUDE_PATH
#define TRACE_INCLUDE_PATH .
#define TRACE_INCLUDE_FILE xfs_trace
#include <trace/define_trace.h>
注意这里头文件的末尾与/include/trace/events/目录下的头文件末尾不一样：
include/trace/events/sched.h作为示例，文件结尾为：
#endif /* _TRACE_SCHED_H */
/* This part must be outside protection */
#include <trace/define_trace.h>
但是，define_trace.h的一些神奇之处在于，它必须能够包括包含它的跟踪文件(TRACE_HEADER_MULTI_READ的原因)。如第一篇文章所述，跟踪头文件以CPP条件开头：
// linux-3.10/include/trace/events/sched.h
#if !defined(_TRACE_SCHED_H) || defined(TRACE_HEADER_MULTI_READ)
#define _TRACE_SCHED_H
第一篇文章解释了包含特定跟踪头的C文件中只有一个文件将在包含跟踪头之前定义CREATE_TRACE_POINTS：
// linux-3.10/kernel/sched/core.c
#define CREATE_TRACE_POINTS
#include <trace/events/sched.h>
它激活跟踪头文件包含的define_trace.h。define_trace.h文件将再次包含 header ，但将首先定义TRACE_HEADER_MULTI_READ。如cpp条件所示，此定义将允许再次读取 the trace header 的内容。
为了使define_trace.h包含跟踪头文件，它必须能够找到它。要做到这一点，需要对包含跟踪文件的Makefile进行一些更改，并且该文件需要告诉define_trace.h不要在默认位置查找它（include/trace/events）。
要告诉define_trace在哪里找到跟踪头，Makefile必须定义跟踪文件位置的路径。一种方法是扩展CFLAGS以包括以下路径：
EXTRA_CFLAGS = -I$(src)
但这会影响Makefile构建的所有文件的CFLAGS。如果希望只修改定义了CREATE_TRACE_POINTS的C文件的CFLAGS，则可以使用net/mac80211/Makefile使用的方法：
// linux-3.10/net/mac80211/Makefile
CFLAGS_driver-trace.o = -I$(src)
driver-trace.c文件包含CREATE_TRACE_POINTS定义和包含driver-trace.h，其中包含mac80211跟踪点的TRACE_EVENT（）宏。
// linux-3.10/net/mac80211/trace.h
#if !defined(__MAC80211_DRIVER_TRACE) || defined(TRACE_HEADER_MULTI_READ)
#define __MAC80211_DRIVER_TRACE
#include <linux/tracepoint.h>
#include <net/mac80211.h>
#include "ieee80211_i.h"
#undef TRACE_SYSTEM
#define TRACE_SYSTEM mac80211
......
#undef TRACE_INCLUDE_PATH
#define TRACE_INCLUDE_PATH .
#undef TRACE_INCLUDE_FILE
#define TRACE_INCLUDE_FILE trace
#include <trace/define_trace.h>
// linux-3.10/net/mac80211/trace.c
#define CREATE_TRACE_POINTS
#include "trace.h"
二、tracepoint 使用演示
为了演示如何将跟踪点添加到模块中，我编写了一个名为sillymod的简单模块，它只创建一个线程，该线程每秒唤醒一次，执行一次printk并记录执行次数。我将查看文件的相关部分，但完整的文件内容也可用： module, Makefile, the module with tracepoint 和 the trace header file.
第一步是创建所需的跟踪点。跟踪头文件的创建方式与第1部分中描述的核心跟踪头文件相同，只是添加了一些内容。标头必须首先定义文件中所有跟踪点所属的系统：
#undef TRACE_SYSTEM
#define TRACE_SYSTEM silly
这个模块创建了一个名为 silly 的跟踪系统。然后包括特殊的cpp条件：
#if !defined(_SILLY_TRACE_H) || defined(TRACE_HEADER_MULTI_READ)
#define _SILLY_TRACE_H
包括linux/tracepoint.h文件，最后是TRACE_EVENT（）宏；本例中的一个：
#include <linux/tracepoint.h>
TRACE_EVENT(me_silly,
TP_PROTO(unsigned long time, unsigned long count),
TP_ARGS(time, count),
TP_STRUCT__entry(
__field( unsigned long, time )
__field( unsigned long, count )
),
TP_fast_assign(
__entry->time = jiffies;
__entry->count = count;
),
TP_printk("time=%lu count=%lu", __entry->time, __entry->count)
);
#endif /* _SILLY_TRACE_H */
以上内容与第1部分中对核心内核跟踪点的描述相同。在#endif之后，事情变得有点不同。在包含 define_trace.h 文件之前，将添加以下内容：
/* This part must be outside protection */
#undef TRACE_INCLUDE_PATH
#define TRACE_INCLUDE_PATH .
#define TRACE_INCLUDE_FILE silly-trace
#include <trace/define_trace.h>
TRACE_INCLUDE_PATH告诉define_TRACE.h不要查找跟踪标头的默认位置（INCLUDE/TRACE/events），而是查找include 搜索路径。默认情况下， define_trace.h将包括TRACE_SYSTEM定义的文件。TRACE_INCLUDE_FILE告诉define_trace.h the trace header 称为silly-trace.h。（.h将自动添加到TRACE_INCLUDE_PATH的末尾）。
要将跟踪点添加到模块，模块现在包括跟踪头。在包含跟踪标头之前，还必须定义CREATE_TRACE_POINTS：
#define CREATE_TRACE_POINTS
#include "silly-trace.h"
现在可以将跟踪点添加到代码中：
set_current_state(TASK_INTERRUPTIBLE);
schedule_timeout(HZ);
printk("hello! %lu\n", count);
trace_me_silly(jiffies, count);
count++;
最后，Makefile必须设置CFLAGS，使includes包含 silly-trace.h 文件所在的本地目录：
CFLAGS_sillymod-event.o = -I$(src)
如果模块位于内核树中，您可能会认为，在不修改Makefile的情况下，以下功能也可以正常工作：
#define TRACE_INCLUDE_PATH ../../path/to/trace/header
在TRACE_INCLUDE_PATH 中使用“.”以外的路径名运行包含宏的风险。例如，如果XFS将TRACE_INCLUDE_PATH定义为…/…/fs/XFS/linux-3.10/XFS_TRACE.h， 它会失败。这是因为Linux构建 #defines 将名称Linux定义为空，这将使路径为…/…/fs/xfs/-3.10/xfs_trace.h。
/* sillymod-event.c */
#include <linux/module.h>
#include <linux/kthread.h>
#define CREATE_TRACE_POINTS
#include "silly-trace.h"
static void silly_thread_func(void)
{
static unsigned long count;
set_current_state(TASK_INTERRUPTIBLE);
schedule_timeout(HZ);
printk("hello! %lu\n", count);
trace_me_silly(jiffies, count);
count++;
}
static int silly_thread(void *arg)
{
while (!kthread_should_stop())
silly_thread_func();
return 0;
}
static struct task_struct *silly_tsk;
static int __init silly_init(void)
{
silly_tsk = kthread_run(silly_thread, NULL, "silly-thread");
if (IS_ERR(silly_tsk))
return -1;
return 0;
}
static void __exit silly_exit(void)
{
kthread_stop(silly_tsk);
}
module_init(silly_init);
module_exit(silly_exit);
MODULE_AUTHOR("Steven Rostedt");
MODULE_DESCRIPTION("silly-module");
MODULE_LICENSE("GPL");
/* silly-trace.h */
#undef TRACE_SYSTEM
//在/sys/kernel/debug/tracing/events/ 目录下就会多一个 silly 目录，该目录都是和 silly 相关的 tracepoint
#define TRACE_SYSTEM silly
#if !defined(_SILLY_TRACE_H) || defined(TRACE_HEADER_MULTI_READ)
#define _SILLY_TRACE_H
#include <linux/tracepoint.h>
///sys/kernel/debug/tracing/events/silly/ 目录下就会多一个 me_silly tracepoint
TRACE_EVENT(me_silly,
TP_PROTO(unsigned long time, unsigned long count),
TP_ARGS(time, count),
TP_STRUCT__entry(
__field( unsigned long, time )
__field( unsigned long, count )
),
TP_fast_assign(
__entry->time = jiffies;
__entry->count = count;
),
TP_printk("time=%lu count=%lu", __entry->time, __entry->count)
);
#endif /* _SILLY_TRACE_H */
/* This part must be outside protection */
#undef TRACE_INCLUDE_PATH
#define TRACE_INCLUDE_PATH .
#define TRACE_INCLUDE_FILE silly-trace
#include <trace/define_trace.h>
/* Makefile */
INCLUDES = -I. -I$(KDIR)/include
KBUILD_CFLAGS += -g
all: kernel_modules
obj-m := sillymod-event.o
KDIR := /lib/modules/$(shell uname -r)/build
PWD := $(shell pwd)
CFLAGS_sillymod-event.o = -I$(src)
%.ko: %.o
$(MAKE) -C $(KDIR) SUBDIRS=$(PWD) $@
kernel_modules:
$(MAKE) -C $(KDIR) SUBDIRS=$(PWD) modules
clean:
$(RM) *.o *~ *.ko *.mod.c .*.o.cmd .*.ko.cmd
$(RM) -r .tmp_versions
[root@localhost tracepoint]# insmod sillymod-event.ko
[root@localhost ~]# cd /sys/kernel/debug/tracing
[root@localhost tracing]# ls -l events/si
signal/ silly/
[root@localhost tracing]# ls -l events/silly/
enable filter me_silly/
我们可以看到有 silly event tracepoint点了。
[root@localhost tracing]# echo 1 > events/silly/me_silly/enable
[root@localhost tracing]# cat trace
# tracer: nop
#
# entries-in-buffer/entries-written: 5/5 #P:4
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
silly-thread-30154 [002] .... 308202.105824: me_silly: time=4602867670 count=177
silly-thread-30154 [003] .... 308203.106010: me_silly: time=4602868670 count=178
silly-thread-30154 [003] .... 308204.105899: me_silly: time=4602869670 count=179
silly-thread-30154 [003] .... 308205.105980: me_silly: time=4602870670 count=180
silly-thread-30154 [003] .... 308206.105974: me_silly: time=4602871670 count=181
一旦define_trace.h文件可以安全地找到跟踪头，就可以创建模块的跟踪点。要了解为什么需要所有这些操作，请查看define_trace.h
三、A look inside the magic of TRACE_EVENT()
对于那些敢于进入C预处理器神秘世界的人来说，可以看看include/trace/ftrace.h。但要注意，你在那里发现的东西可能会让你有点疯狂，或者至少认为编写代码的人有点疯狂（在这种情况下，你可能是对的）。include/trace/define_trace.h文件为TRACE_EVENT（）宏做了一些基本的设置，但是为了让跟踪能够利用它，它必须在 define_trace.h 中有一个头文件才能完成真正的工作(就像ftrace和perf一样)。
3.1 TRACE_SYSTEM宏
TRACE_SYSTEM宏用于定义跟踪点用于的系统：
#undef TRACE_SYSTEM
#define TRACE_SYSTEM sched
[root@localhost ~]# ls -l /sys/kernel/debug/tracing/events/sched/
#undef TRACE_SYSTEM
#define TRACE_SYSTEM kmem
[root@localhost ~]# ls -l /sys/kernel/debug/tracing/events/kmem/
#undef TRACE_SYSTEM
#define TRACE_SYSTEM irq
[root@localhost ~]# ls -l /sys/kernel/debug/tracing/events/irq/
3.2 TRACE_INCLUDE_FILE宏
如果文件名不是TRACE_SYSTEM.h，则为TRACE_INCLUDE_FILE。可以定义此宏来告诉define_trace.h要包含的文件。注意，不要使用“.h”，通常是用于模块或特定于体系结构的 tracepoint。
而/include/trace/events/目录下的头文件的文件名都是TRACE_SYSTEM.h。
比如：
// linux-3.10/include/trace/events/sched.h
#undef TRACE_SYSTEM
#define TRACE_SYSTEM sched //TRACE_SYSTEM.h等于头文件名sched.h
而用于模块或特定于体系结构的 tracepoint的头文件，文件名不是TRACE_SYSTEM.h：
#define TRACE_SYSTEM vsyscall 中的 vsyscall 和 vsyscall_trace.h不相等，告诉 define_trace.h 包含 vsyscall_trace.h 文件。
// linux-3.10/arch/x86/kernel/vsyscall_trace.h
#undef TRACE_SYSTEM
#define TRACE_SYSTEM vsyscall
#define TRACE_INCLUDE_FILE vsyscall_trace //不要加.h
#include <trace/define_trace.h>
#define TRACE_SYSTEM kvm 中的 kvm 和 trace.h不相等，告诉 define_trace.h 包含 trace.h 文件
// linux-3.10/arch/x86/kvm/trace.h
#undef TRACE_SYSTEM
#define TRACE_SYSTEM kvm
#define TRACE_INCLUDE_FILE trace //不要加.h
/* This part must be outside protection */
#include <trace/define_trace.h>
#define TRACE_SYSTEM xfs 中的xfs 和xfs_trace.h不相等，告诉 define_trace.h 包含 xfs_trace.h 文件
// linux-3.10/fs/xfs/xfs_trace.h
#undef TRACE_SYSTEM
#define TRACE_SYSTEM xfs
#define TRACE_INCLUDE_FILE xfs_trace //不要加.h
#include <trace/define_trace.h>
3.3 TRACE_INCLUDE_PATH宏
TRACE_INCLUDE_PATH，如果路径不是核心内核 include/trace 。则该宏可以定义要使用的路径。注意，路径是相对于define_trace.h的，而不是包含它的文件。必须使用树外模块的完整路径名。
// linux-3.10/arch/x86/kernel/vsyscall_trace.h
#undef TRACE_INCLUDE_PATH
#define TRACE_INCLUDE_PATH ../../arch/x86/kernel
// linux-3.10/fs/xfs/xfs_trace.h
#undef TRACE_INCLUDE_PATH
#define TRACE_INCLUDE_PATH .
// linux-3.10/arch/x86/kvm/trace.h
#undef TRACE_INCLUDE_PATH
#define TRACE_INCLUDE_PATH arch/x86/kvm
四、cpp tricks and treats
cpp的一个技巧，它可以使用相同的数据将字符串映射到enum：
#define DOGS { C(JACK_RUSSELL), C(BULL_TERRIER), C(ITALIAN_GREYHOUND) }
#undef C
#define C(a) ENUM_##a
enum dog_enums DOGS;
#undef C
#define C(a) #a
char *dog_strings[] = DOGS;
char *dog_to_string(enum dog_enums dog)
{
return dog_strings[dog];
}
诀窍是宏DOGS包含一个子宏C（），我们可以重新定义和更改DOGS的行为。这个概念是TRACE_EVENT（）宏如何工作的关键。可以重新定义TRACE_EVENT（）中的所有子宏，并使用TRACE_EVENT（）创建使用相同信息的不同代码。在第一篇文章中描述了创建跟踪点所需的需求。一组数据（在TRACE_EVENT（）定义中）必须能够执行多项操作。使用这个cpp技巧，它能够完成这一点。
创建的跟踪点代码要求在头文件中定义DECLARE_TRACE（name，proto，args），在某些C文件中使用DEFINE_TRACE。TRACE_EVENT（）现在同时执行这两项任务。在include/linux/tracepoint.h中：
在tracepoint.h中，宏TRACE_EVENT()第一次展开，定义了tracepoint需要的一些函数：
// linux-3.10/include/linux/tracepoint.h
#define TRACE_EVENT(name, proto, args, struct, assign, print) \
DECLARE_TRACE(name, PARAMS(proto), PARAMS(args))
PARAMS（）宏允许proto和args包含逗号，而不会被误认为DECLARE_TRACE（）的多个参数。由于 tracepoint.h 必须包含在所有跟踪头中，这使得trace_EVENT（）宏完成了跟踪点创建的第一部分。这使得TRACE_EVENT（）宏完成了跟踪点创建的第一部分。当C文件在包含跟踪头之前定义CREATE_TRACE_POINTS时，define_trace.h将激活并执行：
在define_trace.h中，宏TRACE_EVENT()第二次的展开：
// linux-3.10/include/trace/define_trace.h
#undef TRACE_EVENT
#define TRACE_EVENT(name, proto, args, tstruct, assign, print) \
DEFINE_TRACE(name)
然而，这还不够，因为define_trace.h是在使用TRACE_EVENT（）宏之后声明的。要使此代码产生影响，必须再次包含TRACE_EVENT（）宏。
// linux-3.10/include/trace/define_trace.h
#ifndef TRACE_INCLUDE_FILE
# define TRACE_INCLUDE_FILE TRACE_SYSTEM
# define UNDEF_TRACE_INCLUDE_FILE
#endif
#ifndef TRACE_INCLUDE_PATH
# define __TRACE_INCLUDE(system) <trace/events/system.h>
# define UNDEF_TRACE_INCLUDE_PATH
#else
# define __TRACE_INCLUDE(system) __stringify(TRACE_INCLUDE_PATH/system.h)
#endif
# define TRACE_INCLUDE(system) __TRACE_INCLUDE(system)
/* Let the trace headers be reread */
#define TRACE_HEADER_MULTI_READ
#include TRACE_INCLUDE(TRACE_INCLUDE_FILE)
TRACE_HEADER_MULTI_READ的定义将允许再次读取 the trace header（这就是为什么首先需要它）。TRACE_INCLUDE（TRACE_INCLODE_FILE）是更多的cpp宏技巧，将包括包含它的文件。如前几篇文章所述，如果定义了TRACE_SYSTEM.h或TRACE_INCLUDE_FILE.h，则该宏将使用该文件，如果未定义TRACE_INCLODE_PATH，则将包含include/trace/events/中的文件。当文件再次包含时，TRACE_EVENT（）宏将再次处理，但具有新的含义。
上面介绍了如何创建跟踪点。它只创建跟踪点本身，而不将其添加到跟踪程序的基础结构中。对于Ftrace，这是define_trace.h中的ftrace.h文件发挥作用的地方。ftrace.h中的宏创建 tracing/events 中的文件和目录。ftrace.h使用了前面解释的相同技巧，即重新定义TRACE_EVENT（）宏内的宏以及重新定义TRACE-EVENT（）宏本身。
这里我只是简单介绍了TRACE_EVENT（）宏的工作原理，详细请参考：
https://pwl999.blog.csdn.net/article/details/80514271
https://blog.csdn.net/jasonactions/article/details/121098704
五、使用 trace events
如果您将目录更改为debugfs文件系统装载点（通常是/sys/kernel/debug）并查看跟踪/事件，您将看到内核中定义的所有跟踪事件系统（即定义TRACE_SYSTEM的跟踪头）。
[root@localhost ~]# cd /sys/kernel/debug/tracing/events/
block/ exceptions/ hda/ iommu/ mce/ pagemap/ rcu/ sock/ vmscan/
bridge/ filelock/ hda_controller/ irq/ migrate/ power/ regmap/ sunrpc/ vsyscall/
compaction/ filemap/ hda_intel/ irq_vectors/ module/ printk/ rpm/ syscalls/ workqueue/
context_tracking/ fs_dax/ hyperv/ kmem/ mpx/ qdisc/ sched/ task/ writeback/
devlink/ ftrace/ i2c/ kvm/ napi/ random/ scsi/ timer/ xen/
dma_fence/ gpio/ i915/ kvmmmu/ net/ ras/ signal/ ucsi/ xfs/
drm/ gvt/ intel_ish/ libata/ oom/ raw_syscalls/ skb/ udp/ xhci-hcd/
比如调度的 trace.h文件：
// linux-3.10/include/trace/events/sched.h
#undef TRACE_SYSTEM
//在/sys/kernel/debug/tracing/events/ 目录下就会多一个 sched 目录，该目录都是和调度相关的 tracepoint
#define TRACE_SYSTEM sched
the enable files 用于启用 sched_switch 跟踪点：
[root@localhost ~]# ls /sys/kernel/debug/tracing/events/sched/sched_switch/
enable filter format id
the events directory 中的 the enable file 可以启用或禁用系统中的所有事件：
[root@localhost ~]# ls /sys/kernel/debug/tracing/events/enable
系统目录之一（比如：events/sched/）中的 the enable file 可以启用或禁用系统内（比如：sched子系统）的所有事件：
[root@localhost ~]# ls /sys/kernel/debug/tracing/events/sched/enable
特定事件目录（比如：/events/sched/sched_switch/）中的 the enable file 可以启用或禁用该事件（比如：sched_switch tracepoint）：
[root@localhost ~]# ls /sys/kernel/debug/tracing/events/sched/sched_switch/enable
注意，通过将“1”写入任何 the enable files ，将启用该目录及其以下的所有事件。写入“0”将禁用该目录及其以下的所有事件。
关于事件的一个很好的特点是，它们也会出现在Ftrace跟踪程序中。如果在跟踪程序运行时启用了事件，则这些事件将显示在跟踪中。启用事件可以使函数跟踪程序更具信息性：
使能调度中所有 tracepoint ：
[root@localhost tracing]# echo 1 > events/sched/enable
[root@localhost tracing]# echo function > current_tracer
查看 trace 文件：
[root@localhost tracing]# echo 1 > events/sched/enable
[root@localhost tracing]# echo function > current_tracer
[root@localhost tracing]# cat trace | more
# tracer: function
#
# entries-in-buffer/entries-written: 204256/2731329 #P:4
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
xfsaild/dm-0-2229 [002] d... 375729.983779: clear_buddies <-dequeue_entity
xfsaild/dm-0-2229 [002] d... 375729.983779: account_entity_dequeue <-dequeue_entity
xfsaild/dm-0-2229 [002] d... 375729.983780: update_min_vruntime <-dequeue_entity
xfsaild/dm-0-2229 [002] d... 375729.983780: update_cfs_shares <-dequeue_entity
xfsaild/dm-0-2229 [002] d... 375729.983780: hrtick_update <-dequeue_task_fair
xfsaild/dm-0-2229 [002] d... 375729.983781: idle_balance <-__schedule
xfsaild/dm-0-2229 [002] d... 375729.983781: msecs_to_jiffies <-idle_balance
xfsaild/dm-0-2229 [002] d... 375729.983781: put_prev_task_fair <-__schedule
xfsaild/dm-0-2229 [002] d... 375729.983781: pick_next_task_fair <-__schedule
xfsaild/dm-0-2229 [002] d... 375729.983782: pick_next_task_idle <-__schedule
xfsaild/dm-0-2229 [002] d... 375729.983782: sched_switch: prev_comm=xfsaild/dm-0 prev_pid=2229 prev_prio=120 prev_state=S ==> next_comm=swapper/2 next_pid=0 next_prio=120
<idle>-0 [002] d... 375729.983783: finish_task_switch <-__schedule
<idle>-0 [002] .... 375729.983783: _raw_spin_lock_irqsave <-__schedule
<idle>-0 [002] d... 375729.983783: post_schedule_idle <-__schedule
<idle>-0 [002] d... 375729.983784: idle_enter_fair <-post_schedule_idle
会打印所有与调度有关的跟踪点信息：
......
sched_stat_runtime: comm=pool pid=7428 runtime=337111 [ns] vruntime=1137470113803 [ns]
......
sched_switch: prev_comm=pool prev_pid=7428 prev_prio=120 prev_state=S ==> next_comm=swapper/2 next_pid=0 next_prio=120
......
sched_stat_runtime: comm=pool pid=7428 runtime=194840 [ns] vruntime=1137470308643 [ns]
......
将事件与函数图跟踪程序中的技巧相结合，我们可以找到中断延迟，以及哪些中断导致了长延迟。
[root@localhost tracing]# cat set_ftrace_filter
#### all functions enabled ####
[root@localhost tracing]# echo do_IRQ > set_ftrace_filter
[root@localhost tracing]# cat set_ftrace_filter
do_IRQ
[root@localhost tracing]# echo 1 > events/irq/irq_handler_entry/enable
[root@localhost tracing]# echo function_graph > current_tracer
[root@localhost tracing]# cat trace
# tracer: function_graph
#
# CPU DURATION FUNCTION CALLS
# | | | | | | |
0) ==========> |
0) | do_IRQ() {
0) | /* irq_handler_entry: irq=125 name=enp1s0 */
0) + 10.181 us | }
0) <========== |
0) ==========> |
0) | do_IRQ() {
0) | /* irq_handler_entry: irq=125 name=enp1s0 */
0) + 16.057 us | }
0) <========== |
0) ==========> |
0) | do_IRQ() {
0) | /* irq_handler_entry: irq=125 name=enp1s0 */
0) 5.765 us | }
0) <========== |
0) ==========> |
0) | do_IRQ() {
0) | /* irq_handler_entry: irq=125 name=enp1s0 */
0) + 12.851 us | }
0) <========== |
0) ==========> |
0) | do_IRQ() {
0) | /* irq_handler_entry: irq=125 name=enp1s0 */
0) + 18.991 us | }
0) <========== |
0) ==========> |
0) | do_IRQ() {
0) | /* irq_handler_entry: irq=125 name=enp1s0 */
0) + 12.146 us | }
0) <========== |
0) ==========> |
0) | do_IRQ() {
0) | /* irq_handler_entry: irq=125 name=enp1s0 */
0) + 20.180 us | }
0) <========== |
0) ==========> |
0) | do_IRQ() {
0) | /* irq_handler_entry: irq=125 name=enp1s0 */
0) 7.643 us | }
0) <========== |
......
将do_IRQ写入set_ftrace_filter使得函数跟踪器只跟踪do_IRQ（）函数。然后激活irq_handler_entry跟踪点，并选择function_graph跟踪程序。由于 the function graph tracer 显示函数执行的时间，因此我们可以看到中断运行的时间。但是 the function graph tracer 只显示do_IRQ（）函数运行，而不显示它执行的中断。通过启用irq_handler_entry事件，我们现在可以看到哪个中断正在运行。
总结
跟踪点是一个非常强大的工具，但要使它们有用，它们必须是灵活且易于添加的。添加TRACE_EVENT（）宏非常简单，而且它们在内核中随处可见。实现跟踪事件的代码使用许多cpp技巧来完成其任务。但是实现的复杂性简化了跟踪点的使用。创建TRACE_EVENT（）宏的经验法则是：尽可能简单地使用TRACE_EVENT（）宏，即使这会使其实现极其复杂。有时，使用的东西越容易，创建它的复杂性就越大。现在，开发人员不需要知道TRACE_EVENT（）宏是如何工作的，只需要知道已经为他们完成了工作，添加TRACE_EVENT（）很容易，现在任何开发人员都可以利用它们。
参考资料
Linux 3.10.0
https://lwn.net/Articles/383362/
https://pwl999.blog.csdn.net/article/details/80514271
https://blog.csdn.net/jasonactions/article/details/121098704
相关文章
- Linux入侵检查思路及其命令
- Linux学习之挂载光盘和U盘(六)
- [Linux] linux文件系统学习
- [Linux]如何深度裁剪文件系统和选择文件系统
- Linux MTD系统剖析
- 【问题解决方案】Linux中进入目录下文件夹
- linux dns 工具包 -- bind-utils
- linux下发布war包
- linux(ubuntu 21.10): 安装phpmyadmin5.1.1 (php8.1.1)
- Linux系统下利用wget命令把整站下载做镜像网站
- 【学习总结】快速上手Linux玩转典型应用-第2章-linux简介
- 思维导图学 Linux Shell攻略之干货篇 mysql数据库脚本管理系统
- Linux Shell脚本自动化编程实战- shell函数
- linux基础：-和--的区别
- linux centos7修改默认启动的内核（升级及切换内核）
- [Linux] 日志管理: 日志轮替 logrotate
- No space left on device 解决Linux系统磁盘空间满的办法
- 【Linux 内核】调度器 ⑧ ( 进程优先级源码 includelinuxschedprio.h | 进程分类 | 实时进程 | 普通进程 | 进程优先级数值 | 0 ~ 99 实时进程 )
- Linux系统时间同步
- L86.linux命令每日一练 -- 第12章 Linux系统常用内置命令(二)
- L81.linux命令每日一练 -- 第11章 Linux系统管理命令 -- ethtool和mii-tool
- L51.linux命令每日一练 -- 第八章 Linux磁盘与文件系统管理命令 -- mkfs和dumpe2fs
- L34.linux命令每日一练 -- 第五章 Linux信息显示与搜索文件命令 -- echo和watch
- L32.linux命令每日一练 -- 第五章 Linux信息显示与搜索文件命令 -- dmesg和stat
- L22.linux命令每日一练 -- 第三章 文件过滤及内容编辑处理命令 -- uniq和wc命令
- L1.linux命令每日一练 -- 第一章 Linux命令行简介
- Linux文件管理命令（1）-增加文件
- Linux pipe函数