Eprobe - 基于事件的探测跟踪¶
- 作者:
Steven Rostedt <rostedt@goodmis.org>
针对 v6.17 编写
概述¶
Eprobe 是一种动态事件,它被放置在现有的事件上,用于解引用作为指针的字段,或者简单地限制在跟踪事件中记录哪些字段。
Eprobe 依赖于 kprobe 事件,因此要启用此功能,请使用 CONFIG_EPROBE_EVENTS=y 编译你的内核。
Eprobe 是通过 /sys/kernel/tracing/dynamic_events 文件创建的。
eprobe_events 简介¶
e[:[EGRP/][EEVENT]] GRP.EVENT [FETCHARGS] : Set a probe
-:[EGRP/][EEVENT] : Clear a probe
EGRP : Group name of the new event. If omitted, use "eprobes" for it.
EEVENT : Event name. If omitted, the event name is generated and will
be the same event name as the event it attached to.
GRP : Group name of the event to attach to.
EVENT : Event name of the event to attach to.
FETCHARGS : Arguments. Each probe can have up to 128 args.
$FIELD : Fetch the value of the event field called FIELD.
@ADDR : Fetch memory at ADDR (ADDR should be in kernel)
@SYM[+|-offs] : Fetch memory at SYM +|- offs (SYM should be a data symbol)
$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), VFS layer common type(%pd/%pD), "char",
"string", "ustring", "symbol", "symstr" and "bitfield" are
supported.
(STRUCT)FIELD->MEMBER[->MEMBER] : If BTF is supported, typecast FIELD to
a pointer to STRUCT and then derference the pointer defined by
->MEMBER. Note that when this is used, the FIELD name does not
need to be prefixed with a '$'.
类型¶
上面的 FETCHARGS 与 基于 Kprobe 的事件跟踪 中描述的 kprobe 事件非常相似。
eprobe 和 kprobe 的 FETCHARGS 之间的区别在于,eprobe 有一个 $FIELD 命令,它返回所附加事件的事件字段的内容。Eprobe 无法访问 kprobe 可以访问的寄存器、栈和函数参数。
如果字段参数是一个指针,可以使用 FETCHARGS 语法像内存地址一样对它进行解引用。
附加到动态事件¶
Eprobe 可以附加到动态事件以及普通事件。它可以附加到 kprobe 事件、综合事件(synthetic event)或 fprobe 事件。如果需要更改字段的类型,这会非常有用。请参见下方的示例 2。
使用示例¶
示例 1¶
eprobe 的基本用法是限制写入跟踪缓冲区的数据。例如,一个常见的跟踪事件是 sched_switch 跟踪事件。其格式为
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:char prev_comm[16]; offset:8; size:16; signed:0;
field:pid_t prev_pid; offset:24; size:4; signed:1;
field:int prev_prio; offset:28; size:4; signed:1;
field:long prev_state; offset:32; size:8; signed:1;
field:char next_comm[16]; offset:40; size:16; signed:0;
field:pid_t next_pid; offset:56; size:4; signed:1;
field:int next_prio; offset:60; size:4; signed:1;
前四个字段对所有事件都是通用的,不能被限制。但事件的其余部分包含 60 字节的信息。它记录了被调度出和调度入的前一个任务和下一个任务的名称,以及它们的 pid 和优先级。它还记录了前一个任务的状态。如果只对任务的 pid 感兴趣,为什么要把环形缓冲区浪费在所有其他字段上呢?
eprobe 可以限制记录的内容。注意,它对性能没有帮助,因为所有字段都会记录在临时缓冲区中以处理 eprobe。
# echo 'e:sched/switch sched.sched_switch prev=$prev_pid:u32 next=$next_pid:u32' >> /sys/kernel/tracing/dynamic_events
# echo 1 > /sys/kernel/tracing/events/sched/switch/enable
# cat /sys/kernel/tracing/trace
# tracer: nop
#
# entries-in-buffer/entries-written: 2721/2721 #P:8
#
# _-----=> irqs-off/BH-disabled
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / _-=> migrate-disable
# |||| / delay
# TASK-PID CPU# ||||| TIMESTAMP FUNCTION
# | | | ||||| | |
sshd-session-1082 [004] d..4. 5041.239906: switch: (sched.sched_switch) prev=1082 next=0
bash-1085 [001] d..4. 5041.240198: switch: (sched.sched_switch) prev=1085 next=141
kworker/u34:5-141 [001] d..4. 5041.240259: switch: (sched.sched_switch) prev=141 next=1085
<idle>-0 [004] d..4. 5041.240354: switch: (sched.sched_switch) prev=0 next=1082
bash-1085 [001] d..4. 5041.240385: switch: (sched.sched_switch) prev=1085 next=141
kworker/u34:5-141 [001] d..4. 5041.240410: switch: (sched.sched_switch) prev=141 next=1085
bash-1085 [001] d..4. 5041.240478: switch: (sched.sched_switch) prev=1085 next=0
sshd-session-1082 [004] d..4. 5041.240526: switch: (sched.sched_switch) prev=1082 next=0
<idle>-0 [001] d..4. 5041.247524: switch: (sched.sched_switch) prev=0 next=90
<idle>-0 [002] d..4. 5041.247545: switch: (sched.sched_switch) prev=0 next=16
kworker/1:1-90 [001] d..4. 5041.247580: switch: (sched.sched_switch) prev=90 next=0
rcu_sched-16 [002] d..4. 5041.247591: switch: (sched.sched_switch) prev=16 next=0
<idle>-0 [002] d..4. 5041.257536: switch: (sched.sched_switch) prev=0 next=16
rcu_sched-16 [002] d..4. 5041.257573: switch: (sched.sched_switch) prev=16 next=0
注意,如果在 prev_pid 和 next_pid 后面不加上 “u32”,这些值将默认以十六进制显示。
示例 2¶
如果要记录特定的系统调用,但未启用 syscalls 事件,仍然可以使用 raw_syscalls(系统调用事件不是普通事件,而是由内核中的 raw_syscalls 事件创建的)。为了跟踪 openat 系统调用,可以在 raw_syscalls 事件之上创建一个事件探测器
# cd /sys/kernel/tracing
# cat events/raw_syscalls/sys_enter/format
name: sys_enter
ID: 395
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:long id; offset:8; size:8; signed:1;
field:unsigned long args[6]; offset:16; size:48; signed:0;
print fmt: "NR %ld (%lx, %lx, %lx, %lx, %lx, %lx)", REC->id, REC->args[0], REC->args[1], REC->args[2], REC->args[3], REC->args[4], REC->args[5]
从源代码来看,sys_openat() 具有
int sys_openat(int dirfd, const char *path, int flags, mode_t mode)
{
return my_syscall4(__NR_openat, dirfd, path, flags, mode);
}
路径是第二个参数,这正是我们想要的。
# echo 'e:openat raw_syscalls.sys_enter nr=$id filename=+8($args):ustring' >> dynamic_events
这是在 x86_64 上运行的,其字长为 8 字节,并且 openat 系统调用 __NR_openat 设置为 257。
# echo 'nr == 257' > events/eprobes/openat/filter
现在启用该事件并查看跟踪。
# echo 1 > events/eprobes/openat/enable
# cat trace
# tracer: nop
#
# entries-in-buffer/entries-written: 4/4 #P:8
#
# _-----=> irqs-off/BH-disabled
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / _-=> migrate-disable
# |||| / delay
# TASK-PID CPU# ||||| TIMESTAMP FUNCTION
# | | | ||||| | |
cat-1298 [003] ...2. 2060.875970: openat: (raw_syscalls.sys_enter) nr=0x101 filename=(fault)
cat-1298 [003] ...2. 2060.876197: openat: (raw_syscalls.sys_enter) nr=0x101 filename=(fault)
cat-1298 [003] ...2. 2060.879126: openat: (raw_syscalls.sys_enter) nr=0x101 filename=(fault)
cat-1298 [003] ...2. 2060.879639: openat: (raw_syscalls.sys_enter) nr=0x101 filename=(fault)
文件名显示为 “(fault)”。这可能是因为文件名尚未调入内存,并且当前跟踪事件无法在不存在的内存中产生缺页。当 eprobe 尝试读取尚未调入内存的内存时,它将显示 “(fault)” 文本。
为了绕过这一点,由于内核可能会调入该文件名并使其存在,因此可以将其附加到一个综合事件上,该事件可以将文件名字段的地址从事件入口传递到事件末尾,这可用于在系统调用返回时显示文件名。
移除旧的 eprobe
# echo 1 > events/eprobes/openat/enable
# echo '-:openat' >> dynamic_events
这次创建一个保存文件名地址的 eprobe
# echo 'e:openat_start raw_syscalls.sys_enter nr=$id filename=+8($args):x64' >> dynamic_events
创建一个将文件名地址传递到事件末尾的综合事件
# echo 's:filename u64 file' >> dynamic_events
# echo 'hist:keys=common_pid:f=filename if nr == 257' > events/eprobes/openat_start/trigger
# echo 'hist:keys=common_pid:file=$f:onmatch(eprobes.openat_start).trace(filename,$file) if id == 257' > events/raw_syscalls/sys_exit/trigger
既然文件名地址已经传递到了系统调用的末尾,请创建另一个 eprobe 附加到退出事件以显示该字符串
# echo 'e:openat synthetic.filename filename=+0($file):ustring' >> dynamic_events
# echo 1 > events/eprobes/openat/enable
# cat trace
# tracer: nop
#
# entries-in-buffer/entries-written: 4/4 #P:8
#
# _-----=> irqs-off/BH-disabled
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / _-=> migrate-disable
# |||| / delay
# TASK-PID CPU# ||||| TIMESTAMP FUNCTION
# | | | ||||| | |
cat-1331 [001] ...5. 2944.787977: openat: (synthetic.filename) filename="/etc/ld.so.cache"
cat-1331 [001] ...5. 2944.788480: openat: (synthetic.filename) filename="/lib/x86_64-linux-gnu/libc.so.6"
cat-1331 [001] ...5. 2944.793426: openat: (synthetic.filename) filename="/usr/lib/locale/locale-archive"
cat-1331 [001] ...5. 2944.831362: openat: (synthetic.filename) filename="trace"
示例 3¶
如果 syscall 跟踪事件可用,上述过程将不需要第一个 eprobe,但仍然需要最后一个 eprobe
# echo 's:filename u64 file' >> dynamic_events
# echo 'hist:keys=common_pid:f=filename' > events/syscalls/sys_enter_openat/trigger
# echo 'hist:keys=common_pid:file=$f:onmatch(syscalls.sys_enter_openat).trace(filename,$file)' > events/syscalls/sys_exit_openat/trigger
# echo 'e:openat synthetic.filename filename=+0($file):ustring' >> dynamic_events
# echo 1 > events/eprobes/openat/enable
这将产生与示例 2 相同的结果。