内核追踪技术之 ftrace

news/2024/11/25 1:24:14/

目录

一、/sys/kernel/debug/trace 目录下的文件 常用的选项

1、function_graph跟踪器

2、function跟踪器

二、查看系统支持哪些事件

1、事件跟踪

2、动态ftrace

三、添加跟踪点

四、跟踪标记

内核提供的测试模块

五、trace-cmd, kerneshark

一、/sys/kernel/debug/trace 目录下的文件 常用的选项

  • available_tracers 当前系统所支持的跟踪器
  • available_events 当前系统所支持的事件
  • current_tracer 设置和显示当前正在使用的跟踪器，默认nop
  • trace 读取跟踪信息
  • tracing_on 用于开始或暂停跟踪
  • trace_points 设置ftrace的一些相关选项

查看系统支持哪些跟踪器available_tracers

/sys/kernel/debug/tracing# cat available_tracers 
hwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop
  • hwlat 与硬件相关的延时
  • blk 跟踪块设备函数
  • mmiotrace 跟踪内存映射I/O操作
  • function_graph 函数调用关系图
  • wakeup 跟踪普通优先级的进程 从获得调度到被唤醒的最长延迟时间
  • wakeup_rt 跟踪RT类型的任务从获得调度到被唤醒的最长延迟时间
  • function 跟踪内核函数执行情况

备注：系统的跟踪器是根据内核配置后所显示的，并不是所有的。比如，当前的跟踪器没有preempt[irqs]off,在内核中配置后，可以在当前文件夹下出现。

1、function_graph跟踪器


/sys/kernel/debug/tracing#echo function_graph > current_tracer 
echo 1 > tracing_on 
...
echo 0 > tracing_on 
cat trace

 函数调用关系图

   1)   0.081 us    |        get_xsave_addr();1)   0.079 us    |        finish_task_switch();1) + 25.319 us   |      } /* schedule */1) + 25.472 us   |    } /* exit_to_usermode_loop */1)   0.076 us    |    fpregs_assert_state_consistent();1)   0.121 us    |    switch_fpu_return();1) + 35.360 us   |  }1)               |  do_syscall_64() {1)               |    __x64_sys_sendmsg() {1)               |      __sys_sendmsg() {1)               |        sockfd_lookup_light() {1)               |          __fdget() {1)               |            __fget_light() {1)   0.110 us    |              __fget();1)   0.262 us    |            }1)   0.414 us    |          }1)   0.579 us    |        }1)               |        ___sys_sendmsg() {1)               |          copy_msghdr_from_user() {1)               |            rw_copy_check_uvector() {1)               |              __check_object_size() {1)   0.092 us    |                check_stack_object();1)   0.246 us    |              }1)   0.413 us    |            }1)   0.655 us    |          }1)               |          ____sys_sendmsg() {1)               |            sock_sendmsg() {1)               |              security_socket_sendmsg() {1)               |                apparmor_socket_sendmsg() {1)   0.074 us    |                  aa_unix_msg_perm();1)   0.224 us    |                }1)   0.405 us    |              }1)               |              unix_stream_sendmsg() {1)               |                wait_for_unix_gc() {1)               |                  _cond_resched() {1)   0.075 us    |                    rcu_all_qs();1)   0.241 us    |                  }1)   0.417 us    |                }

2、function跟踪器

 function会跟踪当前系统中所有的函数，如果想跟踪单个进程则使用set_ftrace_pid

#cat set_ftrace_pid 
no pid#echo 108432 > set_ftrace_pid 
#cat set_ftrace_pid 
108432#echo function > current_tracer #cat trace

3、过滤选项

ftrace可以输出的大量报告数据很容易让人不知所措。学习如何过滤掉不需要或不属于你跟踪范围的东西是关键——过滤函数

root@ubuntu:/sys/kernel/tracing# wc -l available_filter_functions 
54574 available_filter_functions

set_ftrace_filter    追踪的函数
set_ftrace_notrace    不追踪函数

set_graph_function
set_graph_notrace

tracing_cpu_mask    CPU核

set_ftrace_pid    追踪进程/线程 PID
set_ftrace_notrace_pid 不追踪 进程/线程PID

set_event        追踪函数属于写事件组
set_event_pid    当事件追踪的 进程、线程PID
set_event_notrace_pid


更多过滤选项
'foo*' 以foo函数开通
'*foo' 以foo函数结尾
'*foo*' 函数中有foo
'foo*bar' 收尾foo bar

同时跟踪ksys_write ksys_read
echo "ksys_write" > set_ftrace_filter
echo "ksys_read" >> set_ftrace_filter

二、查看系统支持哪些事件

cat /sys/kernel/debug/tracing/available_events 
initcall:initcall_level
initcall:initcall_start
initcall:initcall_finish
raw_syscalls:sys_enter
raw_syscalls:sys_exit
syscalls:sys_enter_rt_sigreturn
syscalls:sys_exit_rt_sigreturn
syscalls:sys_enter_mmap
syscalls:sys_exit_mmap
...

1、事件跟踪

两种跟踪机制：函数和跟踪点，前者属于简单的操作，后者可以输出开发者想要的参数、局部变量等信息。

跟踪点的位置比较固定，一般是内核开发者添加上去的，如果在运行时没有开启DEBUG，那么不占用任何系统开销的。

在源码中以trace_开头的函数,是ftrace的跟踪点。如：update_curr

static void update_curr(struct cfs_rq *cfs_rq)
{if (entity_is_task(curr)) {struct task_struct *curtask = task_of(curr);trace_sched_stat_runtime(curtask, delta_exec, curr->vruntime);cgroup_account_cputime(curtask, delta_exec);account_group_exec_runtime(curtask, delta_exec);}}

trace_sched_stat_runtime 是使用了sched_stat_runtime跟踪点，在命令行下也可以查询到

筛选 grep sched_stat_runtime

benshushu:tracing# cat /sys/kernel/debug/tracing/available_events | grep sched_stat_runtime
sched:sched_stat_runtime

找到跟踪点后如何跟踪这个事件

# echo sched:sched_stat_runtime > /sys/kernel/debug/tracing/set_event
# [ 4664.128181] Scheduler tracepoints stat_sleep, stat_iowait, stat_blocked and stat_runtime require the kernel parameter schedstats=enable or kernel.sched_schedstats=1

# echo 1 > tracing_on 
# cat trace
# tracer: nop
#
# entries-in-buffer/entries-written: 217/217   #P:4
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |bash-678   [003] d...  4749.608750: sched_stat_runtime: comm=bash pid=678 runtime=3010992 [ns] vruntime=3326653851 [ns]kworker/3:2-365   [003] d...  4749.611590: sched_stat_runtime: comm=kworker/3:2 pid=365 runtime=336064 [ns] vruntime=35834438828 [ns]rcu_sched-10    [002] d...  4749.611633: sched_stat_runtime: comm=rcu_sched pid=10 runtime=142128 [ns] vruntime=54819089300 [ns]rcu_sched-10    [002] d...  4749.618566: sched_stat_runtime: comm=rcu_sched pid=10 runtime=234512 [ns] vruntime=54819323812 [ns]rcu_sched-10    [002] d...  4749.625277: sched_stat_runtime: comm=rcu_sched pid=10 runtime=244384 [ns] vruntime=54819568196 [ns]kworker/0:1-786   [000] d...  4750.670649: sched_stat_runtime: comm=kworker/0:1 pid=786 runtime=274624 [ns] vruntime=33254509938 [ns]kworker/u8:1-47    [002] d...  4751.269334: sched_stat_runtime: comm=kworker/u8:1 pid=47 runtime=323152 [ns] vruntime=54819552788 [ns]

 解释标头

benshushu:tracing# cat trace
# tracer: nop
#
# entries-in-buffer/entries-written: 217/217   #P:4
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |bash-678   [003] d...  4749.608750: sched_stat_runtime: comm=bash pid=678 runtime=3010992 [ns] vruntime=3326653851 [ns]

TASK_PID 任务的PID

irq-off：d表示中断已经关闭；若设置"." 表示中断没有关闭

need-resched: 是否需要调度

                        N 表示设置了TIF_NEED_RESCHED和PREEMPT_NEED_RESCHED标志位，需要被调度

        n 表示设置了TIF_NEED_RESCHED

        p表示设置了PREEMPT_NEED_RESCHED

        . 表示不需要调度

hardirq/softirq：表示是否发生了软中断或硬中断

        H 表示在一次硬中断中发生了一次硬中断 

        h 表示硬中断发生

        s 表示软中断

        .表示没有中断发生

preempt-depth 表示抢占关闭的嵌套层级

delay 表示延迟的时间长度

083472e8ce284b51bac76348f731f1e7.png

设置事件后，还可以对事件进行过滤

//切换到事件下
/sys/kernel/debug/tracing/events/sched/sched_stat_runtime# //跟踪sh开头的进程
echo 'comm ~ "sh*" ' > filter

2、动态ftrace

在实际调试过程中，所需要的信息会被大量的ftrace覆盖，所以动态过滤方法很有用。

set_ftrace_filter和set_ftrace_notrace选项配对使用。前者设置要跟踪的函数，后者设置不要跟踪的函数。

available_filter_function文件可以列出当前系统支持的所有函数

#cat available_filter_functions
....
__ip6_flush_pending_frames
ip6_flush_pending_frames
ip6_autoflowlabel.part.0
ip6_finish_output2
ip6_copy_metadata
ip6_fraglist_prepare
ip6_frag_next
ip6_fraglist_init
ip6_setup_cork
ip6_sk_dst_lookup_flow
ip6_xmit
....

如 只关注hrtimer_interrupt函数

#echo hrtimer_interrupt > set_ftrace_filter # echo 1 > tracing_on 
...
# echo 0 > tracing_on 
# cat trace

三、添加跟踪点

内核中的跟踪点不能满足要求，可手动添加。

以update_curr（）为例，观察cfs_rq就绪队列中min_vruntime成员变化情况。

首先需要在include/trace/events/sched.h 的头文件中添加一个名为sched_stat_minvruntime的跟踪点。

按照宏填写参数

#define TRACE_EVENT(name,proto,args,struct,assign,print) \DECLARE_TRACE(name,PARAMS(proto),PATAMS(args))

TRACE_EVENT(sched_stat_minvruntime,TP_PROTO(struct task_struct *tsk,u64 minvruntime),TP_ARGS(tsk,minvruntime),TP_STRUCT__entry(__array(        char,   comm,   TASK_COMM_LEN   )__field(        pid_t,  pid                     )__field(        u64,    vruntime)),TP_fast_assign(memcpy(__entry->comm, t->comm, TASK_COMM_LEN);__entry->pid    = t->pid;__entry->vruntime       =minruntime;),TP_printk("comm=%s pid=%d vruntime=%Lu [ns]", __entry->comm, __entry->pid,(unsigned long long)__entry->vruntime)
);
  • name: 跟踪点名字
  • proto:该跟踪点的原型
  • args：参数
  • struct：定义跟踪器内部使用的_entry数据结构
  • assign:把参数复制到__entry数据结构中
  • print：输出的格式

把trace_sched_stat_minvruntime(）添加到update_curr()函数中

static void update_curr(struct cfs_rq *cfs_rq)
{if (entity_is_task(curr)) {struct task_struct *curtask = task_of(curr);trace_sched_stat_runtime(curtask, delta_exec, curr->vruntime);trace_sched_stat_minvruntime(curtask,cfs_rq->mim_vruntime);}
}

重新编译内核，在sys节点上看到添加跟踪节点。

cd /sys/kernel/debug/tracing/events/sched/sched_stat_minvruntime/# ls
enable	filter	format	id  trigger
# cat format 
name: sched_stat_minvruntime
ID: 171
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:0;field:pid_t pid;	offset:24;	size:4;	signed:1;field:u64 vruntime;	offset:32;	size:8;	signed:0;print fmt: "comm=%s pid=%d vruntime=%Lu [ns]", REC->comm, REC->pid, (unsigned long long)REC->vruntime

查看添加的事件 

tracing# echo sched:sched_stat_minvruntime > set_event
tracing# echo 1 > tracing_on 
tracing# cat trace
# tracer: nop
#
# entries-in-buffer/entries-written: 587/587   #P:4
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |bash-555   [003] d.h.   236.982374: sched_stat_minvruntime: comm=bash pid=555 vruntime=1669227760 [ns]bash-555   [003] d.h.   236.985426: sched_stat_minvruntime: comm=bash pid=555 vruntime=1672976144 [ns]bash-555   [003] d...   236.986699: sched_stat_minvruntime: comm=bash pid=555 vruntime=1674223536 [ns]rcu_sched-10    [002] d...   236.986838: sched_stat_minvruntime: comm=rcu_sched pid=10 vruntime=23631132868 [ns]rcu_sched-10    [002] d...   236.994794: sched_stat_minvruntime: comm=rcu_sched

四、跟踪标记

trace_marker,可以跟踪用户程序。trace_marker是一个文件节点，允许用户程序写入字符串，ftrace会记录该写入动作的时间戳。

可以观察用户程序在两个跟踪标记之间的内核空间中发生的事情

trace_marker所在的文件路径

/sys/kernel/debug/tracing/trace_marker

int main()
{int fd_mark = open("/sys/kernel/debug/tracing/trace_marker", O_CREAT|O_RDWR, 0666);int fd_trace = open("/sys/kernel/debug/tracing/tracing_on", O_CREAT|O_RDWR, 0666);write(fd_trace, "1", 2);//添加markerwrite(fd_mark, "start time...", 11);/* to do something */write(fd_mark, "end time...", 11);write(fd_trace, "0", 2);close(fd_mark);close(fd_trace);
}

内核提供的测试模块

sample/trace_events目录

五、trace-cmd, kerneshark

trace-cmd 遵循reset->record->stop->report，使用report收集数据，Ctrl+C终止，生成trace.data文件。

追踪

trace-cmd record -e 'sched_wakeup*' -e sched_switch -e 'sched_migrate*'

解析 使用trace-cmd report解析data.dat文件 文字形式

benshushu:~# trace-cmd report trace.dat 
cpus=4trace-cmd-6338  [003]   599.589634: sched_wakeup:         rcu_sched:10 [120] success=1 CPU:003trace-cmd-6320  [000]   599.589635: sched_switch:         trace-cmd:6320 [120] R ==> trace-cmd:6337 [120]trace-cmd-6338  [003]   599.590964: sched_wakeup:         ksoftirqd/3:26 [120] success=1 CPU:003trace-cmd-6338  [003]   599.591186: sched_switch:         trace-cmd:6338 [120] R ==> rcu_sched:10 [120]rcu_sched-10    [003]   599.591324: sched_switch:         rcu_sched:10 [120] W ==> ksoftirqd/3:26 [120]ksoftirqd/3-26    [003]   599.591380: sched_switch:         ksoftirqd/3:26 [120] S ==> trace-cmd:6338 [120]trace-cmd-6336  [002]   599.592586: sched_switch:         trace-cmd:6336 [120] S ==> swapper/2:0 [120]<idle>-0     [002]   599.592718: sched_wakeup:         dhcpcd:733 [120] success=1 CPU:002trace-cmd-6335  [001]   599.592781: sched_switch:         trace-cmd:6335 [120] S ==> trace-cmd:6320 [120]<idle>-0     [002]   599.592887: sched_wakeup:         rcu_sched:10 [120] success=1 CPU:003<idle>-0     [002]   599.592928: sched_switch:         swapper/2:0 [120] R ==> dhcpcd:733 [120]dhcpcd-733   [002]   599.594394: sched_migrate_task:   comm=kworker/u8:2 pid=151 prio=120 orig_cpu=0 dest_cpu=2dhcpcd-733   [002]   599.594628: sched_wakeup:         kworker/u8:2:151 [120] success=1 CPU:002dhcpcd-733   [002]   599.594854: sched_switch:         dhcpcd:733 [120] D ==> kworker/u8:2:151 [120]kworker/u8:2-151   [002]   599.595194: sched_wakeup_new:     kworker/u8:2:6339 [120] success=1 CPU:002kworker/u8:2-151   [002]   599.595248: sched_switch:         kworker/u8:2:151 [120] S ==> kworker/u8:2:6339 [120]

kernelshark是以图形的形式解析data.dat文件

kernelshark trace.dat

d33fe09266f64a818084acdcd4de569f.png

参考

内核ftrace
 


http://www.ppmy.cn/news/551432.html

相关文章

Linux ARM平台开发系列讲解（网络篇） 2.3 Marvell 88EA6321/88EA6320 Switch 设备树的配置分析

Linux ARM平台开发系列讲解（网络篇） 2.3 Marvell 88EA6321/88EA6320 Switch 设备树的配置分析

1. 概述 交换机设备树主要是要配置它的端口数量，每个Port的物理模式（例如Mac to Phy）、双工模式、连接速度、地址和与之连接的PHY地址等等，这一节就以88EA6321做例子解析一下DSA设备树，以主控S32G274A为例。 2. 参考文档 Linux5.10中，有Marvell 的交换机系列的设备树配…
阅读更多...
Linux ARM平台开发系列讲解（网络篇） 2.2 Marvell 88EA6321/88EA6320 Switch 寄存器解读篇

Linux ARM平台开发系列讲解（网络篇） 2.2 Marvell 88EA6321/88EA6320 Switch 寄存器解读篇

1. 概述 本章解读一些常用到的Marvell 88e6321/88ea6321寄存器，首先得拿到88E6321/88E6320 Functional Specification手册，由于NDA限制，这里就不发下载链接了。 2. 芯片寻址模式 88e6321 支持两种芯片寻址访问模式，分别是多芯片寻址模式（Multi-chip Addressing Mode）和…
阅读更多...
记录：Qt Creator 10配置安卓开发环境

记录：Qt Creator 10配置安卓开发环境

Qt Creator 现在的安卓开发环境配置相比老版本方便了不少&#xff0c;本文以目前在线安装版的 Qt Creator 10.0.2 Qt 5.15 / Qt 6.5 为例做演示&#xff08;有些文件可能会因为网络问题需要科学上网才能下载&#xff09;。 1.下载 JDK 11 https://adoptium.net/zh-CN/temuri…
阅读更多...
Adobe Photoshop 2020 新建菜单频繁闪烁 Mac版

Adobe Photoshop 2020 新建菜单频繁闪烁 Mac版

小伙伴们安装了Adobe Photoshop 2020后经常会问我新建画布闪烁以及创建按钮无法点击应该怎么解决&#xff0c;今天小编就教大家设置一下。 解决方法一&#xff1a; 1、首先打开ps&#xff0c;如图所示&#xff0c;点击左上角Photoshop->首选项->常规界面 2、在首选项页…
阅读更多...
photoshop是中文版怎么改成英文版！！

photoshop是中文版怎么改成英文版！！

很多用户在本站下载了ps动作插件&#xff0c;但是ps动作必须在photoshop英文版中进行&#xff0c;如果你photoshop是中文版怎么改成英文版呢&#xff1f;那么Mac电脑如何将ps中文切换英文呢&#xff1f;今天小编啦和大分享ps中文版改成英文版教程&#xff01; 这里用的是p/s20…
阅读更多...
Adobe Photoshop CC2020版本介绍-新手学习PS那个版本好？

Adobe Photoshop CC2020版本介绍-新手学习PS那个版本好？

如何开始使用PS&#xff1f;新手学习PS哪个版本好&#xff1f;如何快速掌握PS&#xff1f;在等待有关PS的这些问题时&#xff0c;小编最近收到了许多这样的问题&#xff1f; adobe系统公司相信从事设计行业的人都不会陌生&#xff0c;Adobe系统公司旗下如图像处理软件Adobe Ph…
阅读更多...
Adobe Photoshop CC 2019 for Mac（版本介绍）

Adobe Photoshop CC 2019 for Mac（版本介绍）

【Adobe Photoshop 简介】 Photoshop CC 2019 for Mac 破解版专为所有设计人员而设计。从海报到包装&#xff0c;从普通的横幅到绚丽的网站&#xff0c;从令人难忘的徽标到吸引眼球的图标&#xff0c;Photoshop 在不断推动创意世界向前发展。利用直观的工具和易用的模板&#…
阅读更多...
PhotoShop中蒙版介绍

PhotoShop中蒙版介绍

PhotoShop 中蒙版简介 大家好&#xff0c;我是wumbuk&#xff0c;最近在使用PhotoShop&#xff0c;简单地记录下PhotoShop中蒙版的用法 文章目录 PhotoShop 中蒙版简介前言一、快速蒙版1. 快速抠图 二、图层蒙版2.1 方式一2.2 方式二2.3 利用蒙版做照片合并 三、矢量蒙版四、剪…
阅读更多...
最新文章

Copyright @ 2022~2023