Linux: ftrace 之事件跟踪

1. 前言

限于作者能力水平,本文可能存在谬误,因此而给读者带来的损失,作者不做任何承诺。

2. 背景

本文基于内核文档 Event Tracing 翻译整理而成。

3. 使用内核事件跟踪系统

我们可以使用 tracepoint 来跟踪内核状态。但并不是所有的 tracepoint 都可以使用 事件跟踪系统 来进行跟踪。

3.1 启用、禁用追踪事件

我们使用 ftrace 跟踪系统set_event 文件接口来跟踪内核预定义事件:

# cd /sys/kernel/debug/tracing/
# ls -l set_event
-rw-r--r-- 1 root root 0 417 15:41 set_event

set_event 写入一个事件名,启用对某事件的追踪。譬如,按如下操作跟踪进程唤醒事件

# echo 0 > tracing_on
# echo > trace
# echo sched_wakeup >> set_event
# echo 1 > tracing_on
# cat trace
# tracer: nop
#
# entries-in-buffer/entries-written: 2557/2557   #P:4
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
            Xorg-1099  [001] d...  3236.276655: sched_wakeup: comm=compiz pid=2325 prio=120 target_cpu=000
            bash-3053  [003] d...  3236.276988: sched_wakeup: comm=kworker/u256:0 pid=3827 prio=120 target_cpu=002
          <idle>-0     [000] dNh.  3236.277061: sched_wakeup: comm=gnome-terminal- pid=2996 prio=120 target_cpu=000
          <idle>-0     [000] dNh.  3236.278700: sched_wakeup: comm=compiz pid=2325 prio=120 target_cpu=000
          <idle>-0     [003] dNs.  3236.278708: sched_wakeup: comm=kworker/3:0 pid=29 prio=120 target_cpu=003
          <idle>-0     [000] dNs.  3236.278710: sched_wakeup: comm=kworker/0:0 pid=3658 prio=120 target_cpu=000
          <idle>-0     [001] dNs.  3236.278710: sched_wakeup: comm=kworker/1:1 pid=36 prio=120 target_cpu=001
          <idle>-0     [003] dNs.  3236.278737: sched_wakeup: comm=rcu_sched pid=8 prio=120 target_cpu=002
          compiz-2325  [000] d...  3236.278901: sched_wakeup: comm=Xorg pid=1099 prio=120 target_cpu=001
            Xorg-1099  [001] d...  3236.279001: sched_wakeup: comm=compiz pid=2325 prio=120 target_cpu=000
          compiz-2325  [000] d...  3236.279319: sched_wakeup: comm=Xorg pid=1099 prio=120 target_cpu=001
            Xorg-1099  [001] d...  3236.279416: sched_wakeup: comm=compiz pid=2325 prio=120 target_cpu=000
          compiz-2325  [000] d...  3236.279700: sched_wakeup: comm=Xorg pid=1099 prio=120 target_cpu=001
            Xorg-1099  [001] d...  3236.279813: sched_wakeup: comm=compiz pid=2325 prio=120 target_cpu=000
          compiz-2325  [000] d...  3236.280148: sched_wakeup: comm=Xorg pid=1099 prio=120 target_cpu=001
            Xorg-1099  [001] d...  3236.280441: sched_wakeup: comm=compiz pid=2325 prio=120 target_cpu=000

命令 echo sched_wakeup >> set_event 中使用 >> 而不是 > ,因为如果使用 > ,会先禁用所有的追踪事件,而使用 >> 可以防止这种事情。
移除某个事件追踪

# echo '!sched_wakeup' >> set_event

在事件名前加上 ! 移除对事件的追踪。
移除对所有事件的追踪

# echo > set_event

启用对所有事件的追踪

# echo *:* > set_event

系统支持的所有事件记录在文件 available_events 中:

# root@bill-virtual-machine:/sys/kernel/debug/tracing# more available_events
v4l2:v4l2_dqbuf
v4l2:v4l2_qbuf
v4l2:vb2_v4l2_buf_done
v4l2:vb2_v4l2_buf_queue
v4l2:vb2_v4l2_dqbuf
v4l2:vb2_v4l2_qbuf
vb2:vb2_buf_done
vb2:vb2_buf_queue
vb2:vb2_dqbuf
vb2:vb2_qbuf
drm:drm_vblank_event
drm:drm_vblank_event_queued
drm:drm_vblank_event_delivered
raw_syscalls:sys_exit
raw_syscalls:sys_enter
vsyscall:emulate_vsyscall
xen:xen_cpu_set_ldt
xen:xen_cpu_write_gdt_entry
xen:xen_cpu_load_idt
[...]

在内核启动阶段,可以通过命令行选项,开启指定事件追踪:

trace_event=[event-list]

3.2 追踪事件的目录结构

所有的追踪事件按子系统类别组织在目录 events 下:

# ls events/
alarmtimer  dma_fence   fs            iommu        migrate  page_isolation  rcu        sock                     timer      writeback
block       drm         fs_dax        irq          mmc      pagemap         regmap     spi                      tlb        x86_fpu
bpf         enable      ftrace        irq_matrix   module   percpu          regulator  swiotlb                  udp        xdp
bridge      exceptions  gpio          irq_vectors  mpx      power           rpm        sync_trace               v4l2       xen
cgroup      ext4        header_event  jbd2         msr      printk          sched      syscalls                 vb2        xhci-hcd
clk         fib         header_page   kmem         napi     qdisc           scsi       task                     vmscan
cma         fib6        huge_memory   libata       net      random          signal     tcp                      vsyscall
compaction  filelock    hyperv        mce          nmi      ras             skb        thermal                  wbt
cpuhp       filemap     i2c           mdio         oom      raw_syscalls    smbus      thermal_power_allocator  workqueue

events 目录下所有子目录就是子系统类别,如 sched,syscalls,... 。写入到 set_event 文件接口启用的事件,可以按格式 <subsystem>:* 的形式组织,如开启所有 irq 类别的追踪事件,可以向 set_event 写入:

# echo irq:* > set_event

每个子系统类别(如 irq, sched, ...)下的每个事件,在子系统目录下,都会有一个以事假名命名的目录:

# ls events/irq
enable  filter  irq_handler_entry  irq_handler_exit  softirq_entry  softirq_exit  softirq_raise

我们看到,irq 事件子系统包含 irq_handler_entry,irq_handler_exit ,softirq_entry ,softirq_exit softirq_raise 这 5 个事件,每个事件对应一个目录,目录下包含事件的属性节点。如 irq_handler_entry 事件:

# ls events/irq/irq_handler_entry/
enable  filter  format  hist  id  trigger

启用禁用某个跟踪事件,除了可以通过写 set_event 外,还可以通过修改事件目录下的 enable 文件接口:

# echo 1 > events/irq/irq_handler_entry/enable 启用 irq:irq_handler_entry 事件
# echo 0 > events/irq/irq_handler_entry/enable 禁用 irq:irq_handler_entry 事件

修改事件的 enable ,会间接的修改 set_event 文件接口。

3.3 追踪事件数据格式

每个追踪事件,都有一个格式文件 format

# ls -l events/sched/sched_wakeup/format
-r--r--r-- 1 root root 0 417 15:41 events/sched/sched_wakeup/format
# cat events/sched/sched_wakeup/format
# cat events/sched/sched_wakeup/format
name: sched_wakeup
ID: 307
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:char comm[16];	offset:8;	size:16;	signed:1;
	field:pid_t pid;	offset:24;	size:4;	signed:1;
	field:int prio;	offset:28;	size:4;	signed:1;
	field:int success;	offset:32;	size:4;	signed:1;
	field:int target_cpu;	offset:36;	size:4;	signed:1;

print fmt: "comm=%s pid=%d prio=%d target_cpu=%03d", REC->comm, REC->pid, REC->prio, REC->target_cpu

format 文件描述了事件日志数据的每个域(field):name: 部分显示了事件名称;ID: 部分显示了事件 ID;format: 部分显示了事件数据各域(field)的 域数据类型,域名字,域偏移位置,域大小,这些信息可用于解析跟踪事件二进制数据流,也可用于事件过滤器定位事件数据域(field)名;print fmt: 部分显示在文本模式显示事件数据的格式化字串。
事件数据的数据域(field)中,有一部分是所有事件都相同的,这些相同的数据域名以 common_ 打头,如上面输出的 common_type,common_flags,common_preempt_count,common_pid 这 4 个数据域;事件的其它数据域因事件而异,对应域 TRACE_EVENT() 定义的数据域。

3.4 事件过滤器

当事件写入跟踪缓冲时,跟踪系统对比跟踪数据和跟踪事件关联的过滤器布尔表达式,和过滤表达式不匹配的数据将被丢弃。

3.4.1 过滤器表达式语法

过滤器表达式由一个或多个 谓词 组成,可以使用逻辑运算符 && 或 || 进行组合。谓词 是指比较事件数据域和常量值的子句:匹配返回1,不匹配返回0。看一下过滤表达式的语法:

field-name relational-operator value

括号可用于提供任意逻辑分组,双引号可用于防止 shell 将运算符解释为 shell 元字符。
可用数据域名称 field-name,可以在事件的 format 文件中的 field 字段找到;关系运算符 relational-operator ,取决于要测试的数据域的类型:数字类型数据域可用的关系运算符有 ==, !=, <, <=, >, >=, &字符串类型数据域可硬的关系运算符有 ==, !=, ~~ 关系运算符后可跟通配符 *,? ,字符集 ([) 。如:

prev_comm ~ "*sh"
prev_comm ~ "sh*"
prev_comm ~ "*sh*"
prev_comm ~ "ba*sh"

如果追踪事件的数据域名是指向用户空间的指针(例如 sys_enter_openat 中的filename 参数),则必须将 .ustring 附加到字段名称:filename.ustring ~ "password" ,因为内核必须知道指针指向的是用户空间内存。你可以将任何指向函数地址的 long 类型转换为函数地址(通过 .function 后缀),并与函数名做比较,如 call_site.function == security_prepare_creds 。当数据域 call_site 指向函数 security_prepare_creds 时,事件数据内容将进行过滤。也就是说,它将比较 call_site 的值,如果它大于或等于函数 security_prepare_creds 的起始地址且小于该函数的末尾地址时,则过滤器将返回 true。
.function 后缀仅可用于 long 类型,且仅可用 ==!= 运算符进行比较。

3.4.2 设置和清除事件过滤器

通过写事件的 filter 文件节点来设置事件的过滤器。如:

# echo "common_preempt_count > 4" > events/sched/sched_wakeup/filter
# echo "((sig >= 10 && sig < 15) || sig == 17) && comm != bash" > events/signal/signal_generate/filter

通过向事件的 filter 文件节点写 0 来清除事件过滤器:

# echo 0 > events/sched/sched_wakeup/filter
# cat events/sched/sched_wakeup/filter
none

# echo 0 > events/signal/signal_generate/filter
# cat events/signal/signal_generate/filter
none

3.4.3 事件过滤器的限制

如果事件过滤器是针对字符串指针(char *)的, 且该指针不是指向跟踪系统 ring buffer 内的字符串,而是指针内核或用户空间内存,在这样的情形下,出于安全考虑,最多将指针指向的 1024 个字节拷贝到临时缓冲进行比较;另外,如果指针指向的地址无法访问,则认为比较不匹配。

3.4.4 事件子系统(subsystem)过滤器

我们看到,不光事件自身目录下会有过滤器文件接口 filter ,事件所属的子系统下也会有一个 filter 文件接口:

# ls events/sched/filter -l
-rw-r--r-- 1 root root 0 419 12:06 events/sched/filter

通过子系统(subsystem)过滤器接口文件 filter ,可以对子系统(subsystem)下所有事件进行的事件过滤器设置和清除。但请注意,如果子系统中任何事件的过滤器缺少子系统(subsystem)过滤器中指定的数据域,或者由于任何其他原因无法应用过滤器,则该事件的过滤器将保留其以前的设置。混合对事件和事件子系统(subsystem)的过滤器接口进行配置,这可能会导致意料之外的设置,从而造成一定的混乱。
看一个设置子系统(subsystem)的例子:

# echo "common_pid == 1970" > events/sched/filter
# cat events/sched/filter
### global filter ###
# Use this to set filters for multiple events.
# Only events with the given fields will be affected.
# If no events are modified, an error message will be displayed here
# cat events/sched/*/filter
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970
common_pid == 1970

看到了吗?子系统(subsystem)filter 文件里面,没有设置的过滤器配置,取而代之的是将对子系统(subsystem) 的 filter 文件的设置,传递给子系统(subsystem) 下各个事件的 filter 文件接口。
如果我们对 子系统(subsystem)filter 文件写 0 ,又会产生什么效果呢?

# echo 0 > events/sched/filter
# cat events/sched/*/filter
none
none
none
none
none
none
none
none
none
none
none
none
none
none
none
none
none
none
none
none
none
none
none
none

整个子系统(subsystem) 事件的 filter 设置都被清除了。试图设置非公共数据域到子系统(subsystem) 的 filter ,设置将被不支持数据域的事件忽略。

3.4.5 按进程ID进行过滤

# echo $$ > set_event_pid
echo 123 244 1 >> set_event_pid

3.5 事件触发器(trigger)命令

跟踪事件可以按条件调用触发器(trigger)命令,这些命令将在后面详细介绍。这些命令可以启用或禁用事件,或者在事件触发时,进行栈跟踪。每当事件触发时,都会调用事件关联的触发器命令(trigger)集。被过滤器规则过滤掉的事件的命令不会被触发。
可通过改写事件的 trigger 文件,将触发器(trigger)命令添加到事件或从事件中移除。事件可以关联任意个数的触发器(trigger)命令,但前提是命令要支持关联的事件。
写入到 trigger 文件接口的语法,基本上基于写入 set_ftrace_filter 的语法,但它们之间还是存在一些重要差异。
注意,写 trace_marker 文件将触发 events/ftrace/print/trigger 中配置的触发器命令。

3.5.1 配置事件触发器(trigger)命令表达式语法

添加触发器(trigger)命令表达式语法:

echo 'command[:count] [if filter]' > trigger

移除触发器(trigger)命令表达式语法,在添加的表达式前面添加一个 !

echo '!command[:count] [if filter]' > trigger

移除触发器(trigger)命令表达式语法中,[if filter] 不用于匹配命令,因此将其删除,仍然可以达到相同的效果。
添加移除表达式中 filter 部分的语法,和章节 3.4 中过滤器语法相同。

3.5.2 支持的触发器(trigger)命令

3.5.2.1 enable_event / disable_event

关联了 enable_event / disable_event 触发器命令的事件,当被触发时可以禁用或启用其它跟踪事件。

# echo 'enable_event:kmem:kmalloc:1' > events/syscalls/sys_enter_read/trigger

上面的命令,导致在进入 read() 系统调用时,启用对事件 kmem:kmalloc 的追踪1次

# echo 'disable_event:kmem:kmalloc' > events/syscalls/sys_exit_read/trigger

上面的命令,导致每次退出 read() 系统调用时,禁用对事件 kmem:kmalloc 的追踪。
设置 enable_event / disable_event 触发命令的语法表达式为:

enable_event:<system>:<event>[:count]
disable_event:<system>:<event>[:count]

移除前面的触发命令语法表达式为:

echo '!enable_event:kmem:kmalloc:1' > events/syscalls/sys_enter_read/trigger
echo '!disable_event:kmem:kmalloc' > events/syscalls/sys_exit_read/trigger
3.5.2.2 stacktrace

每当事件触发时,导出跟踪缓冲中的堆栈追踪记录。如下面的命令,每次 kmalloc 被触发时,导出跟踪缓冲中堆栈追踪记录:

# echo 'stacktrace' > events/kmem/kmalloc/trigger

下面的命令表示,前5次调用 kmalloc 分配大于等于 64KB 的内存时,导出跟踪缓冲中堆栈追踪记录:

# echo 'stacktrace:5 if bytes_req >= 65536' > events/kmem/kmalloc/trigger

stacktrace 触发器命令的语法表示式为:

stacktrace[:count]

通过下面的操作,移除前述添加的stacktrace 触发器命令:

# echo '!stacktrace' > events/kmem/kmalloc/trigger
# echo '!stacktrace:5 if bytes_req >= 65536' > events/kmem/kmalloc/trigger

后一条命令的移除操作也可以通过如下命令达到:

# echo '!stacktrace:5' > events/kmem/kmalloc/trigger
3.5.2.3 snapshot

事件被触发时,记录当前事件数据快照到 snapshot 缓冲。如下面的命令表示,每当磁盘拔出时,如果磁盘请求队列的长度大于1(还有数据没刷往磁盘?),则记录当前事件数据快照到 snapshot 缓冲。

# echo 'snapshot if nr_rq > 1' > events/block/block_unplug/trigger

如果要仅记录一个事件数据快照,按如下操作:

# echo 'snapshot:1 if nr_rq > 1' > events/block/block_unplug/trigger

移除操作:

# echo '!snapshot if nr_rq > 1' > events/block/block_unplug/trigger
# echo '!snapshot:1 if nr_rq > 1' > events/block/block_unplug/trigger
3.5.2.4 traceon / traceoff

在事件触发时,开启或关闭事件追踪,如果不指定次数,则开关次数不限。如下面的命令,当第一次拔出磁盘时,如果磁盘请求队列的长度大于1(还有数据没刷往磁盘?),则关闭事件追踪。

# echo 'traceoff:1 if nr_rq > 1' > events/block/block_unplug/trigger

为了总是在磁盘拔出,且磁盘请求队列的长度大于1时,总是关闭追踪事件,按如下操作:

# echo 'traceoff if nr_rq > 1' > events/block/block_unplug/trigger

移除操作:

# echo '!traceoff:1 if nr_rq > 1' > events/block/block_unplug/trigger
# echo '!traceoff if nr_rq > 1' > events/block/block_unplug/trigger
3.5.2.5 hist

参见 https://www.kernel.org/doc/html/latest/trace/histogram.html

  • 0
    点赞
  • 6
    收藏
    觉得还不错? 一键收藏
  • 0
    评论
Linux中有两个常用的跟踪工具,分别是strace和ftrace。 strace是一个用户空间的跟踪工具,它可以追踪和记录应用程序的系统调用和信号。通过strace,我们可以了解应用程序在执行过程中与操作系统之间的交互,包括文件操作、网络通信、进程管理等。strace可以帮助开发人员调试和分析应用程序的问题,定位性能瓶颈和错误。 ftraceLinux内核提供的跟踪工具,用于追踪内核中的函数调用和事件。它是内建于Linux内核中的,可以通过配置内核选项来启用和配置。ftrace提供了多个跟踪器,用于不同的场景,比如跟踪函数调用、上下文切换、中断关闭时长等。通过ftrace,我们可以深入了解内核的执行流程和性能瓶颈,帮助开发人员进行内核调试和性能优化。 总结来说,strace用于跟踪用户空间应用程序的系统调用和信号,而ftrace用于跟踪内核中的函数调用和事件。它们都是在Linux系统中进行高级性能分析和调试的重要工具。\[1\]\[2\]\[3\] #### 引用[.reference_title] - *1* *2* [Linux 追踪技术 ftrace 简介(一)](https://blog.csdn.net/weixin_45030965/article/details/125738911)[target="_blank" data-report-click={"spm":"1018.2226.3001.9630","extra":{"utm_source":"vip_chatgpt_common_search_pc_result","utm_medium":"distribute.pc_search_result.none-task-cask-2~all~insert_cask~default-1-null.142^v91^insertT0,239^v4^insert_chatgpt"}} ] [.reference_item] - *3* [Linux:内核调试方法之strace ,ltrace, ptrace, ftrace, sysrq](https://blog.csdn.net/hhd1988/article/details/129562459)[target="_blank" data-report-click={"spm":"1018.2226.3001.9630","extra":{"utm_source":"vip_chatgpt_common_search_pc_result","utm_medium":"distribute.pc_search_result.none-task-cask-2~all~insert_cask~default-1-null.142^v91^insertT0,239^v4^insert_chatgpt"}} ] [.reference_item] [ .reference_list ]

“相关推荐”对你有帮助么?

  • 非常没帮助
  • 没帮助
  • 一般
  • 有帮助
  • 非常有帮助
提交
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值