启动时间测量方法:用对工具才能找准瓶颈
说实话,我刚开始调启动性能那会儿,走了不少弯路。上来就对着代码一顿优化,结果改了三天,一测启动时间反而更长了。后来我才明白——不先学会测量,所谓的优化全是瞎蒙。今天咱们就聊聊常用的三把尺子: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 → 发现 userspace 耗时23秒,其中
ModemManager占了14秒。 - 跑 bootchart → 看到 ModemManager 在启动后10秒内一直占着 CPU 80%,其他服务只能排队。说明不是IO问题,是纯计算慢。
- 用 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限制深度。