4. ftrace 基本操作:常用 tracer 的启用与数据读取
ftrace 的核心能力由多个 tracer(跟踪器)提供,每个 tracer 专注于不同的内核行为观测维度。在中断负载与 DMA 性能分析场景中,function、function_graph、irqsoff 和 preemptoff 是最常用的四个 tracer。本节将逐一演示它们的启用方法、数据读取方式及适用场景。
4.1 tracer 启用与切换通用流程
所有 tracer 的操作均通过 /sys/kernel/debug/tracing/ 目录下的伪文件系统完成。以下为通用操作步骤:
- 挂载 debugfs(如未挂载):
mount -t debugfs none /sys/kernel/debug - 进入 tracing 目录:
cd /sys/kernel/debug/tracing - 查看当前可用 tracer:
cat available_tracers - 选择 tracer:
echo function > current_tracer - 启动跟踪:
echo 1 > tracing_on - 停止跟踪:
echo 0 > tracing_on - 读取数据:
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 缩小范围,否则环形缓冲区很快被淹没。
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 回调中的调度延迟 |
| 数据量 | 较小(仅记录最大延迟) | 较小(仅记录最大延迟) |
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 选择
- 初步定位:使用
functiontracer 配合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 导致数据过载。