4. 启动时间分析工具：使用 ftrace、bootgraph、initcall_debug 定位耗时节点

在 DTS 优化工作中，测量是优化的前提。没有精确的启动时间分布数据，任何节点裁剪都是盲目的。本章深入讲解三种内核启动分析工具：initcall_debug、bootgraph 和 ftrace，帮助你精准定位每个设备节点的初始化耗时，从而制定高效的 DTS 精简策略。

4.1 工具对比与选型

三种工具各有侧重，适用于不同优化阶段。下表从精度、开销、使用场景三个维度进行对比：

4.2 initcall_debug：快速扫描所有设备节点耗时

initcall_debug 是内核提供的最简单的启动分析参数。它会在每个 initcall（包括设备驱动 probe）执行前后打印时间戳，让你一目了然地看到哪个驱动耗时最长。

4.2.1 启用方法

在 kernel cmdline 中添加参数：

initcall_debug

启动后，通过 dmesg 查看输出，典型日志格式如下：

[    0.123456] calling  i2c_driver_init+0x0/0x20 @ 1
[    0.123789] initcall i2c_driver_init+0x0/0x20 returned 0 after 333 usecs
[    0.456789] calling  spi_master_probe+0x0/0x100 @ 2
[    0.789012] initcall spi_master_probe+0x0/0x100 returned 0 after 332223 usecs

其中 after X usecs 就是该 initcall 的耗时（微秒）。

4.2.2 快速定位耗时节点脚本

使用以下 shell 命令从 dmesg 中提取耗时排名：

dmesg | grep "initcall.*returned" | \
  sed 's/.*after \([0-9]*\) usecs.*/\1 &/' | \
  sort -rn | head -20

输出示例：

332223 initcall spi_master_probe+0x0/0x100 returned 0 after 332223 usecs
154321 initcall mmc_blk_probe+0x0/0x200 returned 0 after 154321 usecs
...

排名靠前的驱动就是 DTS 优化的重点目标。

4.3 bootgraph：生成可视化启动时间图

bootgraph 是内核源码 scripts/bootgraph.pl 提供的 Perl 脚本，它解析 initcall_debug 的日志，生成一张 SVG 格式的启动时间图，直观展示每个 initcall 的起始时间和持续时间。

4.3.1 使用步骤

1. 收集日志：启用 initcall_debug 启动系统，保存 dmesg 输出：dmesg > boot.log
2. 生成 SVG：运行脚本：perl scripts/bootgraph.pl boot.log > boot.svg
3. 查看图表：用浏览器打开 boot.svg，可以看到类似甘特图的启动时间分布。

4.3.2 SVG 图：bootgraph 启动时间分布示意

下图模拟了 bootgraph 生成的 SVG 图表结构，展示不同设备驱动的 initcall 耗时分布：

4.4 ftrace：深入分析驱动内部函数耗时

当 initcall_debug 定位到某个驱动整体耗时较长后，ftrace 可以进一步深入该驱动的内部函数调用链，找出具体是哪个子函数拖慢了速度。

4.4.1 启用 ftrace 跟踪特定驱动

以下步骤演示如何跟踪 SPI 控制器的 probe 函数：

# 挂载 tracefs
mount -t tracefs tracefs /sys/kernel/tracing

# 设置跟踪器为 function_graph
echo function_graph > /sys/kernel/tracing/current_tracer

# 设置只跟踪 spi_master_probe 函数
echo spi_master_probe > /sys/kernel/tracing/set_ftrace_filter

# 开始跟踪
echo 1 > /sys/kernel/tracing/tracing_on

# 触发驱动 probe（例如重新绑定）
echo spi_master.0 > /sys/bus/spi/drivers/spi_master/unbind
echo spi_master.0 > /sys/bus/spi/drivers/spi_master/bind

# 停止跟踪
echo 0 > /sys/kernel/tracing/tracing_on

# 查看结果
cat /sys/kernel/tracing/trace

4.4.2 ftrace 输出解读

输出示例：

# tracer: function_graph
#
# CPU  DURATION                  FUNCTION CALLS
# |     |   |                     |   |   |   |
 2)   0.125 us    |  spi_master_probe();
 2)   0.250 us    |    of_spi_parse_dt();
 2) 332.000 us    |    spi_setup();
 2)   0.125 us    |    spi_add_device();

可以看到，spi_setup() 函数耗时 332us，是整个 probe 的瓶颈。进一步分析 spi_setup 内部，可能发现是某个 GPIO 请求或时钟使能操作耗时过长。

4.4.3 SVG 图：ftrace 函数调用链分析

下图展示 ftrace 跟踪到的 SPI 驱动 probe 内部函数调用关系及耗时分布：

4.5 综合实战：从日志到 DTS 优化决策

以下是一个完整的分析流程，将三种工具串联起来：

1. 全局扫描：启用 initcall_debug，使用排序脚本找出耗时前 5 的驱动。
2. 可视化确认：使用 bootgraph 生成 SVG 图，确认耗时驱动的启动顺序和持续时间。
3. 深入分析：对排名第一的驱动使用 ftrace，跟踪其 probe 函数内部调用链，定位具体瓶颈函数。
4. DTS 优化：根据瓶颈原因，修改 DTS 节点：
   • 如果瓶颈是等待时钟稳定：在 DTS 中指定 assigned-clocks 和 assigned-clock-rates，确保时钟提前使能。
   • 如果瓶颈是 GPIO 请求超时：检查 gpios 属性是否引用了正确的 GPIO 控制器，或考虑使用 pinctrl 预配置。
   • 如果驱动完全不需要：直接设置 status = "disabled"。
5. 验证：重新编译内核和设备树，再次使用 initcall_debug 测量，确认耗时下降。

4.6 常见问题与避坑指南