Linux动态追踪——ftrace

2024-03-10 23:04
文章标签 动态 linux 追踪 ftrace

本文主要是介绍Linux动态追踪——ftrace,希望对大家解决编程问题提供一定的参考价值,需要的开发者们随着小编来一起学习吧!

目录

摘要

1 初识

1.1 tracefs

1.2 文件描述

2 函数跟踪

2.1 函数的调用栈

2.2 函数调用栈

2.3 函数的子调用

3 事件跟踪

4 简化命令行工具

5 总结


摘要

        Linux下有多种动态追踪的机制,常用的有 ftrace、perf、eBPF 等,每种机制适应于不同的场景,今天学习一下ftrace的常见用法。

        ftrace 是一个内部跟踪器,旨在帮助开发人员查找内核内部发生的情况。ftrace 是几个分类跟踪实用程序的框架,其最常见的用途是函数跟踪、事件跟踪。

1 初识

1.1 tracefs

        ftrace 提供了类似于 procfs 的虚拟文件系统,以文件的形式为用户空间提供了交互接口。这样,我们不用依赖额外的工具,就能跟 ftrace 交互,完成跟踪的目标。

        ftracefs 挂载点通常位于 /sys/kernel/tracing 目录,如果你的这个目录下什么都没有,那么可以通过这个命令安装挂载点:

mount -t tracefs nodev /sys/kernel/tracing

        进入 tracing 目录查看,真是多:

[root@172 ~]# cd /sys/kernel/tracing/
[root@172 tracing]# ls
available_events            kprobe_events        set_ftrace_notrace  trace_marker_raw
available_filter_functions  kprobe_profile       set_ftrace_pid      trace_options
available_tracers           max_graph_depth      set_graph_function  trace_pipe
buffer_size_kb              options              set_graph_notrace   trace_stat
...

1.2 文件描述

        其中 available_tracers 描述了支持的跟踪器的种类,常用的是 function 和 function_graph

[root@172 tracing]# cat available_tracers 
hwlat blk function_graph wakeup_dl wakeup_rt wakeup function nop

        current_tracer 表示正在使用的跟踪器:

[root@172 tracing]# cat current_tracer 
nop

        available_filter_functions 为可跟踪的完整函数列表:

[root@172 tracing]# cat available_filter_functions  |grep "sys_open"
do_sys_open
__x64_sys_open
__ia32_sys_open
__x64_sys_openat
__ia32_sys_openat
__ia32_compat_sys_open
__ia32_compat_sys_openat
__x64_sys_open_by_handle_at
__ia32_sys_open_by_handle_at
__ia32_compat_sys_open_by_handle_at
proc_sys_open

        其它常见文件含义如下:

  • current_tracer:顾名思义为当前在用的跟踪器
  • function_profile_enabled:启用函数性能分析器
  • set_ftrace_filter:选择跟踪函数的列表
  • se_event_pid:设置跟踪进程的PID
  • tracing_on:启用跟踪
  • trace_options:跟踪的选项类型
  • trace_stat:函数性能分析输出的目录
  • trace:跟踪的输出文件

        ​​​​​​​看完了又好像啥都没看一样,还是看看实操什么样的!

2 函数跟踪

        前面写了,ftrace 支持好几种类型的跟踪器,这里实际使用一下看看效果如何。

2.1 函数的调用栈

        这里看下那个程序有调用到 fork 这个系统调用呢?通过 available_filter_functions 输出知道了其支持查看 _do_fork 这个函数的跟踪:

[root@172 tracing]# cat available_filter_functions | grep "fork"
_do_fork
...

        那我们就跟踪下 __do_fork 的调用:

# 设置跟踪器类型为 function
[root@172 tracing]# echo function > current_tracer 
# 设置要跟踪的函数名
[root@172 tracing]# echo _do_fork > set_ftrace_filter 
# 启用跟踪
[root@172 tracing]# echo 1 > tracing_on 
# 触发 fork 系统调用
[root@172 tracing]# ps aux | grep "bash" | grep -v "grep"
root        1485  0.0  0.7 236608  5940 pts/0    Ss   15:09   0:01 -bash

        查看 trace 输出:

[root@172 tracing]# cat trace
# tracer: function
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |bash-1485  [000] ....  2832.519248: _do_fork <-do_syscall_64bash-1485  [000] ....  2832.519502: _do_fork <-do_syscall_64bash-1485  [000] ....  2837.109585: _do_fork <-do_syscall_64bash-1485  [000] ....  2837.113690: _do_fork <-do_syscall_64bash-1485  [000] ....  2838.637411: _do_fork <-do_syscall_64bash-1485  [000] ....  2838.639147: _do_fork <-do_syscall_64

        其中 TASK-PID 表示调用 _do_fork 的进程 id,CPU 000 表示该进程运行在0号 cpu,TIMESTAMP 为函数调用的时间戳,FUNCTION 显示了 _do_fork 由  do_syscall_64 调用。

        执行完毕后还需要关闭跟踪:

[root@172 tracing]# echo 0 > tracing_on
[root@172 tracing]# echo > set_ftrace_filter 
[root@172 tracing]# echo > current_tracer 
[root@172 tracing]# echo nop > current_tracer

2.2 函数调用栈

        有时候只知道函数被哪些进程调用,信息可能还不够全面,我们需要知道详细的调用栈,方便理清执行流程。这就依赖 options/func_stack_track 选项了。具体执行过程跟刚刚还是差不多的。

[root@172 tracing]# echo function > current_tracer 
[root@172 tracing]# echo 0 >tracing_on 
[root@172 tracing]# echo _do_fork > set_ftrace_filter
# 开启跟踪函数的调用栈
[root@172 tracing]# echo 1 > options/func_stack_trace 
[root@172 tracing]# echo 1 > tracing_on 
[root@172 tracing]# cat trace
# tracer: function
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |bash-1485  [000] ....  4195.579130: _do_fork <-do_syscall_64bash-1485  [000] ....  4195.579157: <stack trace>=> 0xffffffffc0871061=> _do_fork=> do_syscall_64=> entry_SYSCALL_64_after_hwframebash-1485  [000] ....  4195.582865: _do_fork <-do_syscall_64bash-1485  [000] ....  4195.582882: <stack trace>=> 0xffffffffc0871061=> _do_fork=> do_syscall_64=> entry_SYSCALL_64_after_hwframe
[root@172 tracing]# echo 0 > tracing_on
[root@172 tracing]# echo 0 > options/func_stack_trace
[root@172 tracing]# echo > set_ftrace_filter 
[root@172 tracing]# echo nop > current_tracer

        这次的输出明显更全面了,可以看出调用栈最顶层的入口是 entry_SYSCALL_64_after_hwframe 函数。完事还是要记得关闭。

2.3 函数的子调用

        知道了函数的调用栈,没发现问题,可能调用都是合理的,这时候可能想知道这个函数内部做了些什么事情,有没有异常,这时就用到了 function_graph 跟踪器。

[root@172 tracing]# echo _do_fork > set_graph_function
[root@172 tracing]# echo function_graph > current_tracer
[root@172 tracing]# echo 1 > tracing_on
[root@172 tracing]# cat trace | head -n 20
# tracer: function_graph
#
# CPU  DURATION                  FUNCTION CALLS
# |     |   |                     |   |   |   |0)               |  _do_fork() {0)               |    copy_process.part.34() {0)   0.116 us    |      _raw_spin_lock_irq();0)               |      recalc_sigpending() {0)   0.099 us    |        recalc_sigpending_tsk();0)   1.068 us    |      }0)   0.475 us    |      tsk_fork_get_node();0)               |      kmem_cache_alloc_node() {0)               |        _cond_resched() {0)   0.109 us    |          rcu_all_qs();0)   1.074 us    |        }0)   0.105 us    |        should_failslab();0)   1.143 us    |        memcg_kmem_get_cache();0)   0.109 us    |        memcg_kmem_put_cache();0)   6.998 us    |      }0)               |      __memcg_kmem_charge() {
[root@172 tracing]# echo 0 > tracing_on 
[root@172 tracing]# echo nop > current_tracer
[root@172 tracing]# echo > set_graph_function

        输出中的 DURATION 列表示执行耗时,FUNCTION 下的调用层级也很明显

3 事件跟踪

        available_events 描述了 ftrace 支持跟踪的所有事件,这也是内核提前定义的一批静态跟踪点:

[root@172 tracing]# cat available_events | grep "kill"
syscalls:sys_exit_tkill
syscalls:sys_enter_tkill
syscalls:sys_exit_tgkill
syscalls:sys_enter_tgkill
syscalls:sys_exit_kill
syscalls:sys_enter_kill
[root@172 tracing]# cat available_events | grep "tcp"
tcp:tcp_probe
tcp:tcp_retransmit_synack
tcp:tcp_rcv_space_adjust
tcp:tcp_destroy_sock
tcp:tcp_receive_reset
tcp:tcp_send_reset
tcp:tcp_retransmit_skb
[root@172 tracing]# cat available_events | grep "net:"
net:netif_rx_ni_entry
net:netif_rx_entry
net:netif_receive_skb_entry
net:napi_gro_receive_entry
net:napi_gro_frags_entry
net:netif_rx
net:netif_receive_skb
net:net_dev_queue
net:net_dev_xmit_timeout
net:net_dev_xmit
net:net_dev_start_xmit

        支持的事件种类也比较多,有 syscall、net、tcp、udp 等等。netif_receive_skb 用于处理内核从网卡收到的网络包,其主要对收到的 skb 进行校验然后交给 IP 层处理。通过下面的命令查看 netif_receive_skb 支持的选项:

[root@172 tracing]# ls events/net/netif_receive_skb
enable  filter  format  hist  id  trigger

         让我们跟踪一下 netif_receive_skb 这个事件:

[root@172 tracing]# echo 1 > events/net/netif_receive_skb/enable
[root@172 tracing]# echo 1 > tracing_on 
[root@172 tracing]# cat trace
# tracer: nop
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |<idle>-0     [000] ..s.  7835.671429: netif_receive_skb: dev=eth0 skbaddr=0000000073ef12d9 len=40<idle>-0     [000] ..s.  7836.593411: netif_receive_skb: dev=eth0 skbaddr=0000000073ef12d9 len=92<idle>-0     [000] ..s.  7836.638960: netif_receive_skb: dev=eth0 skbaddr=00000000b6a6098d len=40
[root@172 tracing]# echo 0 > tracing_on 
[root@172 tracing]# echo 0 > events/net/netif_receive_skb/enable

4 简化命令行工具

        你可能觉得 tracefs 每次跟踪都涉及多个文件的操作,这也太麻烦了。实际上,也有一个同样烦恼于此的小哥提供了更简单的命令,可以一次性配置好几个文件,也就是 trace-cmd

        例如可以通过这样的命令来跟踪函数的调用栈:

# 执行跟踪命令一段时间
[root@172 /]# trace-cmd record -p function -l '_do_fork' --func-stackplugin 'function'
Hit Ctrl^C to stop recording
^CCPU0 data recorded at offset=0x4bf0004096 bytes in size
[root@172 /]# 
# 查看跟踪结果
[root@172 /]# trace-cmd report
cpus=1bash-1662  [000]   333.965070: function:             _do_forkbash-1662  [000]   333.965096: kernel_stack:         <stack trace>
=> __this_module (ffffffffc062e061)
=> _do_fork (ffffffff942b02c5)
=> do_syscall_64 (ffffffff9420419b)
=> entry_SYSCALL_64_after_hwframe (ffffffff94c000ad)

         跟踪函数的子调用:

[root@172 /]# 
[root@172 /]# trace-cmd record -p function_graph -g '_do_fork'plugin 'function_graph'
Hit Ctrl^C to stop recording
^CCPU0 data recorded at offset=0x4bf000208896 bytes in size
[root@172 /]# trace-cmd report | head -n20
cpus=1bash-1662  [000]   641.179614: funcgraph_entry:                   |  _do_fork() {bash-1662  [000]   641.179629: funcgraph_entry:                   |    copy_process.part.34() {bash-1662  [000]   641.179629: funcgraph_entry:        0.030 us   |      _raw_spin_lock_irq();bash-1662  [000]   641.179630: funcgraph_entry:                   |      recalc_sigpending() {bash-1662  [000]   641.179630: funcgraph_entry:        0.034 us   |        recalc_sigpending_tsk();bash-1662  [000]   641.179630: funcgraph_exit:         0.268 us   |      }bash-1662  [000]   641.179630: funcgraph_entry:        0.123 us   |      tsk_fork_get_node();bash-1662  [000]   641.179631: funcgraph_entry:                   |      kmem_cache_alloc_node() {

        跟踪静态事件:

[root@172 /]# trace-cmd record -e net:netif_receive_skb
Hit Ctrl^C to stop recording
^CCPU0 data recorded at offset=0x4bf0004096 bytes in size
[root@172 /]# trace-cmd report
cpus=1<idle>-0     [000]   770.613285: netif_receive_skb:    dev=eth0 skbaddr=0xffff8b4078ce4b00 len=40<idle>-0     [000]   771.040836: netif_receive_skb:    dev=eth0 skbaddr=0xffff8b4078ce4b00 len=112<idle>-0     [000]   771.473463: netif_receive_skb:    dev=eth0 skbaddr=0xffff8b4078ce4d00 len=203

5 总结

        事件跟踪主要依赖于内核中定义的静态事件点,这些事件点可以理解为内核中的特定位置,当某些特定事件发生时,例如系统调用、中断处理或进程状态改变等,这些事件点就会被触发。通过 tracefs 文件系统,开发人员可以启用这些事件点,从而收集有关内核某些部分运行情况的数据。事件跟踪的一个显著特点是它可以设定跟踪条件,使得跟踪过程更加精细化和有针对性。

        相比之下,函数跟踪则更加关注于程序执行过程中的函数调用情况。在函数跟踪中,ftrace 会在指定的函数入口添加 trace 函数,从而记录函数的调用栈和相关信息。这种跟踪方式使得开发人员能够观察到函数是如何被调用的,以及它们在执行过程中的行为。函数跟踪的一个优势在于它可以轻松地过滤出需要关注的函数,从而避免被大量无关信息淹没。

        总结来说,事件跟踪和函数跟踪在 ftrace 中各有侧重。事件跟踪主要关注内核中特定事件的发生和变化,而函数跟踪则更侧重于程序执行过程中的函数调用情况。根据具体的调试需求,开发人员可以选择使用合适的跟踪机制来获取所需的信息。

这篇关于Linux动态追踪——ftrace的文章就介绍到这儿,希望我们推荐的文章对编程师们有所帮助!



http://www.chinasem.cn/article/795816

相关文章

Oracle数据库定时备份脚本方式(Linux)

《Oracle数据库定时备份脚本方式(Linux)》文章介绍Oracle数据库自动备份方案,包含主机备份传输与备机解压导入流程,强调需提前全量删除原库数据避免报错,并需配置无密传输、定时任务及验证脚本... 目录说明主机脚本备机上自动导库脚本整个自动备份oracle数据库的过程(建议全程用root用户)总结

Linux如何查看文件权限的命令

《Linux如何查看文件权限的命令》Linux中使用ls-R命令递归查看指定目录及子目录下所有文件和文件夹的权限信息,以列表形式展示权限位、所有者、组等详细内容... 目录linux China编程查看文件权限命令输出结果示例这里是查看tomcat文件夹总结Linux 查看文件权限命令ls -l 文件或文件夹

idea的终端(Terminal)cmd的命令换成linux的命令详解

《idea的终端(Terminal)cmd的命令换成linux的命令详解》本文介绍IDEA配置Git的步骤:安装Git、修改终端设置并重启IDEA,强调顺序,作为个人经验分享,希望提供参考并支持脚本之... 目录一编程、设置前二、前置条件三、android设置四、设置后总结一、php设置前二、前置条件

Linux系统中查询JDK安装目录的几种常用方法

《Linux系统中查询JDK安装目录的几种常用方法》:本文主要介绍Linux系统中查询JDK安装目录的几种常用方法,方法分别是通过update-alternatives、Java命令、环境变量及目... 目录方法 1:通过update-alternatives查询(推荐)方法 2:检查所有已安装的 JDK方

Linux系统之lvcreate命令使用解读

《Linux系统之lvcreate命令使用解读》lvcreate是LVM中创建逻辑卷的核心命令,支持线性、条带化、RAID、镜像、快照、瘦池和缓存池等多种类型,实现灵活存储资源管理,需注意空间分配、R... 目录lvcreate命令详解一、命令概述二、语法格式三、核心功能四、选项详解五、使用示例1. 创建逻

Linux下在线安装启动VNC教程

《Linux下在线安装启动VNC教程》本文指导在CentOS7上在线安装VNC,包含安装、配置密码、启动/停止、清理重启步骤及注意事项,强调需安装VNC桌面以避免黑屏,并解决端口冲突和目录权限问题... 目录描述安装VNC安装 VNC 桌面可能遇到的问题总结描js述linux中的VNC就类似于Window

linux下shell脚本启动jar包实现过程

《linux下shell脚本启动jar包实现过程》确保APP_NAME和LOG_FILE位于目录内,首次启动前需手动创建log文件夹,否则报错,此为个人经验,供参考,欢迎支持脚本之家... 目录linux下shell脚本启动jar包样例1样例2总结linux下shell脚本启动jar包样例1#!/bin

go动态限制并发数量的实现示例

《go动态限制并发数量的实现示例》本文主要介绍了Go并发控制方法,通过带缓冲通道和第三方库实现并发数量限制,文中通过示例代码介绍的非常详细,对大家的学习或者工作具有一定的参考学习价值,需要的朋友们下面... 目录带有缓冲大小的通道使用第三方库其他控制并发的方法因为go从语言层面支持并发,所以面试百分百会问到

Linux之platform平台设备驱动详解

《Linux之platform平台设备驱动详解》Linux设备驱动模型中,Platform总线作为虚拟总线统一管理无物理总线依赖的嵌入式设备,通过platform_driver和platform_de... 目录platform驱动注册platform设备注册设备树Platform驱动和设备的关系总结在 l

linux批量替换文件内容的实现方式

《linux批量替换文件内容的实现方式》本文总结了Linux中批量替换文件内容的几种方法,包括使用sed替换文件夹内所有文件、单个文件内容及逐行字符串,强调使用反引号和绝对路径,并分享个人经验供参考... 目录一、linux批量替换文件内容 二、替换文件内所有匹配的字符串 三、替换每一行中全部str1为st