4. ftrace 基本操作:常用 tracer 的启用与数据读取

ftrace 的核心能力由多个 tracer(跟踪器)提供,每个 tracer 专注于不同的内核行为观测维度。在中断负载与 DMA 性能分析场景中,function、function_graph、irqsoff 和 preemptoff 是最常用的四个 tracer。本节将逐一演示它们的启用方法、数据读取方式及适用场景。

4.1 tracer 启用与切换通用流程

所有 tracer 的操作均通过 /sys/kernel/debug/tracing/ 目录下的伪文件系统完成。以下为通用操作步骤:

  1. 挂载 debugfs(如未挂载):mount -t debugfs none /sys/kernel/debug
  2. 进入 tracing 目录:cd /sys/kernel/debug/tracing
  3. 查看当前可用 tracer:cat available_tracers
  4. 选择 tracer:echo function > current_tracer
  5. 启动跟踪:echo 1 > tracing_on
  6. 停止跟踪:echo 0 > tracing_on
  7. 读取数据:cat trace 或 cat trace_pipe
提示: trace_pipe 以阻塞方式持续输出最新事件,适合实时监控;trace 输出当前环形缓冲区快照,适合事后分析。

4.2 function tracer:函数调用跟踪

function tracer 记录内核中每个被调用的函数入口,是定位驱动代码执行路径的基础工具。

启用与读取示例

# 切换到 function tracer
echo function > current_tracer

# 设置只跟踪特定函数(可选,减少噪音)
echo 'dma_alloc_coherent' > set_ftrace_filter

# 开启跟踪
echo 1 > tracing_on

# 执行目标操作(如触发 DMA 分配)
# ...

# 关闭跟踪
echo 0 > tracing_on

# 读取结果
cat trace | head -20

输出字段解析

字段 含义 示例值
# tracer 当前使用的 tracer 名称 function
TASK-PID 发起调用的进程名与 PID irq/34-eth0-1234
CPU# 运行所在 CPU 编号 [000]
TIMESTAMP 事件发生时间戳(微秒) 12345.678901
FUNCTION 被调用的函数名 dma_alloc_coherent
DMA 排查要点: 使用 set_ftrace_filter 过滤出 dma_*、iommu_*、__arm_dma_* 等函数,可快速定位 DMA 映射与分配路径上的异常调用。

4.3 function_graph tracer:函数调用图

function_graph 在 function 基础上增加了函数调用层级缩进和执行耗时,是分析函数内部延迟的利器。

启用与读取示例

# 切换到 function_graph tracer
echo function_graph > current_tracer

# 设置只跟踪指定函数及其子调用
echo 'dma_alloc_coherent' > set_graph_function

# 开启跟踪
echo 1 > tracing_on

# 执行目标操作
# ...

# 关闭跟踪
echo 0 > tracing_on

# 读取结果
cat trace | head -30

输出格式特点

  • 缩进层级:每个函数调用前用 } 或 | 表示调用深度。
  • 耗时标注:函数返回行左侧显示执行耗时(微秒),如 3.141 us。
  • 调用链可视化:直观展示函数谁调用了谁,以及每层耗时。
注意: function_graph 产生的数据量极大,必须配合 set_graph_function 或 set_ftrace_pid 缩小范围,否则环形缓冲区很快被淹没。
function_graph 调用链示例:DMA 分配路径 dma_alloc_coherent + 12.345 us __dma_alloc + 8.210 us __iommu_alloc + 5.678 us __alloc_pages + 3.456 us 说明: • 每层缩进表示调用深度 • 右侧数值为函数执行耗时 • 红色节点为最深层调用

4.4 irqsoff tracer:中断关闭延迟跟踪

irqsoff tracer 专门记录内核中关闭本地中断(IRQ)的最长持续时间,是衡量中断响应延迟的关键工具。DMA 完成中断如果被长时间屏蔽,将直接导致吞吐量下降。

启用与读取示例

# 切换到 irqsoff tracer
echo irqsoff > current_tracer

# 设置最大延迟阈值(微秒),超过此值才记录
echo 100 > tracing_max_latency

# 开启跟踪
echo 1 > tracing_on

# 等待或执行负载操作
# ...

# 关闭跟踪
echo 0 > tracing_on

# 读取最大延迟详情
cat trace

输出关键字段

字段 含义 示例值
irqsoff latency 本次记录的中断关闭延迟(微秒) 256 us
=> started at 关闭中断的函数 spin_lock_irqsave
=> ended at 重新开启中断的函数 spin_unlock_irqrestore
caller 调用关闭中断的驱动函数 dma_engine_prep_slave_sg
DMA 关联: 如果 irqsoff 报告的高延迟出现在 dma_* 或 spin_lock_irqsave 调用中,说明驱动在持有自旋锁时执行了耗时操作,必须优化临界区长度。

4.5 preemptoff tracer:抢占关闭延迟跟踪

preemptoff tracer 记录内核关闭抢占(preemption)的最长持续时间。在 SMP 系统中,抢占关闭会导致其他 CPU 无法调度当前 CPU 上的任务,影响实时性。

启用与读取示例

# 切换到 preemptoff tracer
echo preemptoff > current_tracer

# 设置最大延迟阈值
echo 200 > tracing_max_latency

# 开启跟踪
echo 1 > tracing_on

# 执行负载
# ...

# 关闭跟踪
echo 0 > tracing_on

# 读取结果
cat trace

与 irqsoff 的对比

特性 irqsoff preemptoff
跟踪对象 本地中断关闭 内核抢占关闭
影响范围 当前 CPU 中断响应 所有 CPU 的任务调度
典型触发函数 local_irq_disable preempt_disable
DMA 场景 中断处理延迟 DMA 回调中的调度延迟
数据量 较小(仅记录最大延迟) 较小(仅记录最大延迟)
irqsoff vs preemptoff:延迟跟踪范围对比 CPU 0 CPU 1 CPU 2 CPU 3 irqsoff preemptoff(影响所有 CPU 的调度) irqsoff: 仅影响当前 CPU preemptoff: 影响全局调度

4.6 常用操作速查表

操作 命令 说明
查看可用 tracer cat available_tracers 列出当前内核支持的所有 tracer
切换 tracer echo <name> > current_tracer 立即生效,旧 tracer 数据自动清空
开启/关闭跟踪 echo 1/0 > tracing_on 不切换 tracer,仅控制数据采集
清空缓冲区 echo > trace 写入空字符串清空当前跟踪数据
设置函数过滤 echo func > set_ftrace_filter 仅跟踪指定函数(function 模式)
设置图过滤 echo func > set_graph_function 仅跟踪指定函数调用图
设置延迟阈值 echo N > tracing_max_latency 仅记录超过 N 微秒的延迟事件
读取跟踪数据 cat trace 输出当前缓冲区快照
实时读取 cat trace_pipe 阻塞输出,持续等待新事件

4.7 实战建议:DMA 驱动排查中的 tracer 选择

  • 初步定位:使用 function tracer 配合 set_ftrace_filter 过滤 dma_* 函数,确认驱动是否调用了预期的 DMA API。
  • 延迟分析:使用 function_graph 跟踪 dma_alloc_coherent 或 dmaengine_prep_slave_sg,查看每步耗时。
  • 中断响应:使用 irqsoff 检测驱动中是否有过长的临界区导致 DMA 完成中断被延迟处理。
  • 调度延迟:使用 preemptoff 检测 DMA 回调函数中是否关闭抢占过久,影响其他实时任务。
最佳实践: 在调试 DMA 性能瓶颈时,建议先使用 irqsoff 和 preemptoff 做快速扫描,确认是否存在异常延迟;再使用 function_graph 对可疑路径做精细分析。避免一开始就开启 function_graph 导致数据过载。