2. 启动时间度量方法

在嵌入式Linux启动优化中,“没有度量,就没有优化”。精确测量启动各阶段耗时是定位瓶颈、验证优化效果的前提。本章介绍四种从硬件到软件、从粗粒度到细粒度的度量方法,覆盖uboot阶段到用户态初始化。

度量策略选择: 硬件方法(示波器/逻辑分析仪)精度高、干扰小,适合测量uboot和内核早期阶段;软件方法(printk时间戳、bootgraph、bootchart)部署方便,适合内核启动中后期及用户态分析。实际项目中通常组合使用。

2.1 示波器/逻辑分析仪测量GPIO电平变化

这是最直接、最可靠的启动时间度量方法。通过在关键代码路径上控制GPIO电平翻转,用示波器或逻辑分析仪捕获电平变化的时间差,从而精确计算各阶段耗时。该方法不受系统负载、调度延迟或日志缓冲的影响。

2.1.1 实现步骤

  1. 硬件准备: 在目标板上预留一个空闲GPIO(如GPIO1_IO13),并引出测试点。
  2. uboot阶段: 在uboot的start.S或board_init_f函数中,添加GPIO初始化与电平翻转代码。
  3. 内核阶段: 在start_kernel、setup_arch、do_initcalls等关键函数入口/出口处,操作同一GPIO。
  4. 捕获与分析: 使用示波器(采样率≥100MSa/s)或逻辑分析仪(≥24MHz)捕获波形,测量上升沿/下降沿之间的时间差。
uboot GPIO翻转示例代码(ARM Cortex-A7):
/* 在arch/arm/lib/board.c 或 board_init_f 中 */
#define MEASURE_GPIO_BASE 0x0209C000  /* GPIO1 base */
#define MEASURE_GPIO_PIN  13

static void gpio_set_output(unsigned long base, int pin, int val) {
    unsigned long *dr = (unsigned long *)(base + 0x000);
    unsigned long *ddr = (unsigned long *)(base + 0x004);
    *ddr |= (1 << pin);  /* 设置为输出 */
    if (val)
        *dr |= (1 << pin);
    else
        *dr &= ~(1 << pin);
}

/* 在start.S中,初始化后立即拉高 */
gpio_set_output(MEASURE_GPIO_BASE, MEASURE_GPIO_PIN, 1);

/* 在board_init_r开始处拉低,标记uboot结束 */
gpio_set_output(MEASURE_GPIO_BASE, MEASURE_GPIO_PIN, 0);

2.1.2 典型测量点与波形解读

测量点 GPIO动作 测量内容 典型耗时(参考)
uboot入口 拉高 uboot启动起点 —
uboot跳转内核前 拉低 uboot阶段总耗时 200ms~2s
内核start_kernel入口 拉高 内核解压+入口延迟 50ms~500ms
内核init进程启动 拉低 内核核心初始化耗时 100ms~800ms
用户态第一个服务启动 拉高 内核驱动加载+initrd 200ms~1s
注意事项: GPIO翻转本身有几十纳秒的延迟,对于毫秒级测量可忽略;但需确保GPIO在测量期间不被其他驱动复用。逻辑分析仪触发条件应设置为上升沿触发,捕获深度建议≥10M样本点。
GPIO电平变化测量启动时间流程图 uboot入口 GPIO拉高 uboot初始化 保持高电平 跳转内核前 GPIO拉低 内核入口 GPIO拉高 内核初始化 保持高电平 init进程启动 GPIO拉低 用户态服务 GPIO拉高 说明: 示波器捕获GPIO波形后,测量相邻跳变沿的时间差,即可得到各阶段精确耗时。例如:uboot阶段 = 拉低时刻 - 拉高时刻。

2.2 内核printk时间戳

内核printk机制支持在每条日志前添加时间戳,精度可达微秒级。通过分析dmesg输出的时间戳,可以快速定位内核启动各子系统的耗时分布。

2.2.1 启用与配置

  • 内核配置: 确保 CONFIG_PRINTK_TIME=y(默认开启)。
  • 启动参数: 添加 printk.time=1 或 loglevel=8 以显示所有日志。
  • 查看日志: 启动后执行 dmesg | head -100 查看带时间戳的启动日志。
dmesg输出示例:
[    0.000000] Booting Linux on physical CPU 0x0
[    0.000042] Linux version 5.10.24 (builder@host) (gcc 9.3.0) #1 SMP
[    0.000312] CPU: ARMv7 Processor [410fc075] revision 5 (ARMv7)
[    0.150234] Calibrating delay loop... 1196.00 BogoMIPS (lpj=5980160)
[    0.350678] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[    0.520123] mmc0: new high speed SD card at address 1234
[    0.680456] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode
[    0.850234] Freeing unused kernel memory: 1024K
[    0.860012] Run /sbin/init as init process

2.2.2 时间戳解读方法

时间戳(秒) 事件 耗时(ms) 阶段
0.000000 内核解压完成,start_kernel入口 — 内核入口
0.150234 延迟校准完成 150.2 早期定时器初始化
0.350678 串口驱动注册 200.4 驱动子系统初始化
0.520123 SD卡检测完成 169.4 块设备探测
0.680456 根文件系统挂载 160.3 文件系统初始化
0.860012 init进程启动 179.6 内核启动完成
实用技巧: 使用 dmesg | grep -E "^\[ *[0-9]+\.[0-9]+\]" | awk '{print $1, $NF}' 提取时间戳和最后字段,快速生成启动时间线。对于耗时异常的阶段,可进一步开启 initcall_debug 参数,打印每个初始化函数的调用耗时。
printk时间戳启动时间线(单位:ms) 0 150 350 520 680 860 入口 校准 串口 SD卡 挂载 init 解读: 每个事件节点对应dmesg中的一条时间戳记录。相邻节点的时间差即为该阶段的耗时。例如:串口初始化耗时 = 350ms - 150ms = 200ms。

2.3 bootgraph工具

bootgraph是内核源码中提供的一个Perl脚本(位于 scripts/bootgraph.pl),用于解析dmesg日志中的initcall_debug信息,生成SVG格式的启动时间分布图。它能够直观展示每个内核初始化函数的调用顺序和耗时。

2.3.1 使用步骤

  1. 内核配置: 开启 CONFIG_DEBUG_FS=y 和 CONFIG_FUNCTION_TRACER=y。
  2. 启动参数: 添加 initcall_debug 和 printk.time=1。
  3. 收集日志: 启动后执行 dmesg > boot.log。
  4. 生成图表: 在主机上运行 perl scripts/bootgraph.pl boot.log > bootgraph.svg。
bootgraph.pl 典型输出解读:
# 生成的SVG图中,每个矩形代表一个initcall函数
# 矩形宽度表示该函数的执行耗时
# 颜色通常按耗时分级:绿色(快)、黄色(中等)、红色(慢)
# 鼠标悬停可查看函数名、耗时、调用顺序等信息

2.3.2 常见瓶颈识别

函数名 典型耗时 优化建议
clk_disable_unused 50~200ms 在设备树中禁用未使用的时钟
mmc_add_host 100~500ms 使用mmc_deferred_probe或优化SD卡检测时序
phy_init 30~150ms 检查PHY复位时序,考虑使用phy_quick_probe
i2c_add_adapter 10~80ms 减少I2C总线扫描设备数量
usb_hcd_init 50~300ms 延迟USB控制器初始化或使用模块加载
注意事项: bootgraph依赖initcall_debug日志,会增加少量内核启动开销(约1~5ms)。在最终产品中应关闭此选项。另外,bootgraph仅覆盖内核initcall阶段,不包含uboot和用户态启动时间。
bootgraph initcall时间分布示意图 0ms 860ms clk_disable_unused (150ms) mmc_add_host (200ms) phy_init (80ms) i2c (50ms) usb_hcd (120ms) 其他 A B C (40ms) D 快速 (<30ms) 中等 (30~100ms) 慢 (>100ms) 分析: 红色矩形(慢速函数)是优化重点。例如,mmc_add_host耗时200ms,可通过启用mmc的deferred probe或优化SD卡检测时序来缩短。

2.4 bootchart工具

bootchart是一个用户态工具,用于收集系统启动过程中的CPU、磁盘、进程等资源使用情况,并生成图表。它覆盖从内核启动完成到用户态服务就绪的整个阶段,特别适合分析init进程和系统服务的启动顺序与耗时。

2.4.1 安装与配置

  • 内核配置: 需要 CONFIG_PROC_EVENTS=y 和 CONFIG_FTRACE=y。
  • 安装bootchart: 在buildroot或Yocto中添加 bootchart2 包。
  • 启动参数: 添加 init=/sbin/bootchartd 或 bootchart_init=/sbin/bootchartd。
  • 查看结果: 启动完成后,在 /var/log/bootchart.tgz 或 /tmp/bootchart.tgz 中获取日志,使用 pybootchartgui 工具生成PNG/SVG图表。
bootchart2配置文件(/etc/bootchartd.conf):
# 采样间隔(秒)
SAMPLING_PERIOD=0.2
# 是否收集进程统计信息
PROCESS_STATS=true
# 是否收集CPU统计信息
CPU_STATS=true
# 是否收集磁盘统计信息
DISK_STATS=true
# 最大收集时间(秒)
COLLECTION_TIME=30

2.4.2 图表解读

图表区域 展示内容 优化线索
CPU使用率曲线 各CPU核心的利用率随时间变化 CPU空闲时间过长表示等待I/O或调度延迟
磁盘I/O活动 磁盘读写速率(KB/s) 磁盘瓶颈导致进程等待,考虑使用ramfs或优化文件系统
进程启动时间线 每个进程的启动、运行、结束时间 串行启动的服务可改为并行,减少总启动时间
进程依赖关系 父子进程关系与等待时间 识别关键路径上的阻塞点
实战技巧: 使用 pybootchartgui -f svg bootchart.tgz 生成SVG格式图表。重点关注“进程启动时间线”中耗时最长的服务,以及CPU空闲期间是否有磁盘I/O等待。对于嵌入式系统,建议将 SAMPLING_PERIOD 设为0.1秒以提高时间分辨率。
bootchart进程启动时间线示意图 0s 1s 2s ← 上一章 📖 返回目录 下一章 →