启动时间测量方法:用对工具才能找准瓶颈

说实话,我刚开始调启动性能那会儿,走了不少弯路。上来就对着代码一顿优化,结果改了三天,一测启动时间反而更长了。后来我才明白——不先学会测量,所谓的优化全是瞎蒙。今天咱们就聊聊常用的三把尺子:systemd-analyze、bootchart 和 ftrace。它们各有脾气,用对了地方,问题就暴露得明明白白。

为什么要先学会测量?

你想想看,启动过程涉及内核、init进程、服务管理器、驱动加载、用户态服务……每个环节都可能拖后腿。不把时间分布搞清楚,你根本不知道该砍哪一块。我个人习惯是:先测后调,调完再测。每次改动前先跑一遍基准数据,回头对比才有说服力。

核心指标:总启动时间(按下电源键到桌面可用)、各阶段耗时、并行度利用率。下面几张图就是帮你把这些数字抠出来的。

工具总览:选对尺子量对距离

先给个整体对照,心里有个谱:

工具粒度输出形式适用场景
systemd-analyze秒级(systemd服务级别)文本/火焰图快速定位慢服务、cgroup耗时
bootchart毫秒级(进程级)PNG时间轴图看清楚哪些进程在打架、CPU/IO等待
ftrace微秒级(内核函数级)文本/事件流深挖内核驱动、调度、中断等底层原因

systemd-analyze:上手最快的瑞士军刀

这工具我几乎天天用。一条命令就能看到启动大致分布:

systemd-analyze

输出大概是这样的:

Startup finished in 1.234s (kernel) + 3.567s (initrd) + 12.890s (userspace) = 17.691s
graphical.target reached after 15.432s in userspace

是不是一目了然?kernel、initrd、userspace三段各占多少。但我提醒你,这个数字是“墙钟时间”,也就是你从按下电源到系统就绪的真实世界时间。瓶颈在哪一段,一眼就能锁定。

想看更细的服务级别耗时,用:

systemd-analyze blame

它会列出每个服务启动的耗时,从长到短排序。我在项目中遇到过一台嵌入式设备,总启动时间20秒,用blame一看,NetworkManager-wait-online.service占了8秒。禁掉网络等待后,直接砍到12秒。嗯,有时候慢的并不是你以为的那个家伙。

小技巧:systemd-analyze critical-chain可以显示关键路径上的服务依赖,帮你找到“木桶最短的那块板”。

bootchart:看图说话,一目了然

如果systemd-analyze是温度计,那bootchart就是B超——能看到内部活动时序。启动时启动bootchart服务,重启后会在/var/log/bootchart.tgz生成一张图。你可以用pybootchartgui把它渲染成PNG。

说实话,我团队里有几个新人一开始嫌麻烦,但真看了图之后都直呼“太清楚了”。图上横轴是时间,纵轴是进程,色块表示CPU使用率、IO等待、内存换页等。你能看到:

  • 哪些进程在并行运行——如果大量时间只有单进程在跑,说明利用率低。
  • IO瓶颈——如果某段时间全是%iowait,那就是磁盘在拖后腿。
  • 启动后期是否有大量进程同时启动导致争抢——我曾在一台高密度服务器上看到过“启动风暴”,所有服务同时醒来抢CPU,导致整机卡了2秒多。
# 安装bootchart(Debian/Ubuntu)
sudo apt install bootchart

# 重启后查看
ls /var/log/bootchart.tgz
# 解压并渲染
pybootchartgui -o bootchart.png /var/log/bootchart.tgz

注意:bootchart本身会增加一点启动开销(约0.2-0.5秒),正式测量时可以去掉。但平时调试时这点误差完全可以接受。

ftrace:内核级的“显微镜”

前面两种工具都停在进程层面。如果你发现某个驱动加载慢、调度不公、中断处理耗时,就得请ftrace出马了。这工具能在内核函数调用的瞬间打上时间戳,精度到微秒。

我习惯用trace-cmd这个封装工具:

# 录制内核函数调用(例如跟踪ext4文件系统初始化)
sudo trace-cmd record -p function_graph -g ext4_fill_super sleep 10

# 回放并查看
sudo trace-cmd report

输出会包含函数名、执行耗时、调用栈。举个例子,有个项目发现启动时内核打印“INFO: task XXX blocked for more than 120 seconds”,但不知道谁导致的。我们用ftrace加了sched_switch事件,发现是一个老旧的USB驱动在轮询设备时持有了锁,导致SSD probe被阻塞。锁定后修改驱动,启动时间稳定在3秒内。

常见的ftrace事件:

  • sched_switch:看进程为何被切换,是否频繁。
  • block:block_rq_complete:看磁盘请求完成时间。
  • irq_handler_entry/exit:看中断处理有多长。

常用命令:sudo trace-cmd list -e | grep block 看所有块相关事件;sudo trace-cmd record -e block:block_rq_complete 只抓磁盘完成事件,减少数据量。

一张图理清测量工具选择

下面是我自己常用来帮助团队决策的流程图,你看一遍就明白该用什么工具了:

启动时间测量工具选择流程 你是否知道整体时间分布? 是 否 → 先用 systemd-analyze systemd-analyze time / blame / critical-chain 瓶颈在用户态服务? 是 否 bootchart 分析进程并发与IO ftrace 追踪内核函数和事件 定位根因,针对性优化 注意 bootchart 和 ftrace 可配合使用:先宏观看流程,再微观挖细节 例如用 bootchart 发现 CPU 空闲,ftrace 定位到磁盘驱动慢

三招组合拳:我的实战套路

以我之前优化一个工业控制系统的启动为例:

  1. 先上 systemd-analyze → 发现 userspace 耗时23秒,其中 ModemManager 占了14秒。
  2. 跑 bootchart → 看到 ModemManager 在启动后10秒内一直占着 CPU 80%,其他服务只能排队。说明不是IO问题,是纯计算慢。
  3. 用 ftrace 钩子看 ModemManager 内部函数调用 → 发现它在解析 SIM 卡配置时调用了大量 strtol 循环,每次还要做UTF-8转换。改掉这部分代码后,启动时间降到8秒。

所以说,三个工具不是孤立的。我的经验是:系统层面用 systemd-analyze 扫雷,进程层面用 bootchart 看全局,内核层面用 ftrace 挖深坑。一层层剥洋葱,总能揪出真凶。

避坑指南:我踩过的几个坑

  • 场景一:systemd-analyze 对并行启动不敏感。 它只报告总时间,不会告诉你并行度是否充分。这时候一定要结合 bootchart 看时间轴上的“白板区域”。
  • 场景二:bootchart 在内存紧张时可能被 OOM 杀死。 我曾经在一台只有128MB内存的嵌入式设备上开 bootchart,系统直接重启了。解决办法是只开部分跟踪事件,或者用 bootchartd --no-memory 忽略内存采样。
  • 场景三:ftrace 数据量爆炸。 如果你不加过滤条件就抓所有函数,一次启动可能产生几百MB日志,解析时卡死。记住先 trace-cmd list -e 筛选事件,或者用 -p function_graph 配上 --max-graph-depth 3 限制深度。

小结:测量做得好,优化省一半