1. 项目概述为什么我们需要精确测量内核启动耗时在嵌入式系统、物联网设备、服务器固件乃至个人电脑的启动优化领域内核启动耗时是一个极其关键的指标。它直接关系到用户体验、系统响应速度以及在某些实时性要求高的场景下的系统性能底线。想象一下你正在开发一款智能门锁用户按下指纹后如果系统内核启动需要3秒那这个体验将是灾难性的。或者在数据中心成千上万台服务器同时重启每台机器内核启动时间减少1秒整体业务恢复时间就能提前数小时。因此精确测量内核启动耗时不是一项可有可无的“炫技”而是系统开发、性能调优和问题定位的基石。然而测量内核启动时间并非像在应用程序里打两个printf然后相减那么简单。内核启动过程是一个从硬件上电、引导加载程序Bootloader移交控制权到内核解压、初始化硬件、挂载根文件系统最终启动第一个用户空间进程通常是init或systemd的复杂链条。这个过程中时序信息分散、环境受限早期可能连串口输出都没有、且系统状态瞬息万变。这就需要我们掌握多种“武器”从不同维度、不同精度去捕捉这个稍纵即逝的启动过程。本文将深入探讨几种在实践中被广泛使用且各具特色的内核启动耗时统计方法。我们将从最简单直观的“目测法”开始逐步深入到需要内核配置和代码插桩的精确测量最后介绍一些高级的、集成化的性能剖析工具。我的目标是无论你是刚接触内核的开发者还是正在为产品启动速度焦头烂角的资深工程师都能在这里找到适合你当前阶段和需求的测量方案并理解其背后的原理、优劣和那些手册上不会写的“坑”。2. 核心思路与测量维度拆解在动手之前我们必须明确要测量的“内核启动耗时”具体指哪一段。笼统地说是从内核开始执行到init进程启动。但为了更精细的优化我们通常将其拆分为几个关键阶段内核解压与重定位耗时对于压缩内核如zImageBootloader将其加载到内存后内核需要先自解压并将自身代码和数据移动到正确的位置。这个阶段发生在任何控制台输出之前。内核初始化前期耗时从内核入口点start_kernel函数开始到初始化控制台、打印出第一行内核信息如“Booting Linux on physical CPU 0x0”为止。此阶段串口可能还未就绪。内核初始化主体耗时从第一行打印开始到内核调用kernel_init准备启动用户空间为止。这包括了内存管理、进程调度、设备驱动探测与初始化等绝大部分核心子系统初始化。根文件系统挂载与init启动耗时从尝试挂载根文件系统到成功执行/sbin/init或/init程序。这个阶段受存储设备如eMMC、NVMe速度和文件系统类型影响很大。不同的测量方法其测量范围、精度和侵入性各不相同。选择哪种方法取决于你的目标粗略评估还是精准优化、你的平台是否有调试接口以及你能接受的对系统代码的修改程度。2.1 方法选型背后的考量为什么需要多种方法因为没有任何一种方法是万能的。快速验证 vs. 深度优化你可能只是想快速验证一个配置改动是否有效这时一个简单的打印时间戳方法就足够了。但如果你要找到启动瓶颈就需要能输出每个初始化函数耗时的详细报告。资源受限环境 vs. 功能丰富环境在一些极低成本的MCU或早期开发板上可能连一个可用的串口都没有或者内存极其紧张无法承载复杂的性能分析工具。这时基于硬件计数器的原始方法可能是唯一选择。非侵入性 vs. 可接受修改在生产代码中你可能不希望加入任何调试代码。但在开发阶段为了获取数据对内核进行少量打点是可以接受的。有些方法甚至需要重新编译内核。理解这些维度能帮助我们在面对具体问题时快速选择最合适的“手术刀”。3. 方法一基于内核日志时间戳的粗略估算这是最快捷、最无侵入性的方法适合所有已经能正常输出内核日志的系统。3.1 原理与操作Linux内核在编译时可以启用CONFIG_PRINTK_TIME选项。启用后内核会在每条打印信息前附加一个时间戳格式通常为[秒.微秒]。这个时间戳记录的是从内核开始执行到打印该条信息时所经过的时间。操作步骤确保内核配置中启用了CONFIG_PRINTK_TIMEy。你可以在make menuconfig中查找或直接检查.config文件。# 检查.config文件 grep CONFIG_PRINTK_TIME .config # 输出应为CONFIG_PRINTK_TIMEy启动目标系统并通过串口、网络控制台等方式完整捕获内核启动日志。从日志中定位两个关键点的时间戳起点通常是内核解压后最早的信息之一例如[ 0.000000] Booting Linux on physical CPU 0x0这里的时间戳0.000000是相对零点。但更严谨的起点可以是包含“Linux version”的那一行因为它打印得更早。终点内核启动完成的标志。一个常见的标志是init进程启动日志中可能出现[ 1.234567] Run /init as init process或者根文件系统挂载成功的信息如[ 1.345678] VFS: Mounted root (ext4 filesystem) on device 179:2.将终点的时间戳减去起点的时间戳即可得到大致的启动耗时。例如从[0.000000]到[1.234567]耗时约为1.234567秒。3.2 优缺点与实操心得优点零侵入无需修改代码只需一个内核配置选项。通用性强适用于几乎所有Linux系统。简单直观直接看日志就能估算。缺点精度有限时间戳精度通常为微秒级但打印本身有开销且无法捕捉打印点之间的耗时。范围模糊无法准确测量内核解压和最早期的初始化在第一个打印之前的耗时。依赖打印点如果关键阶段没有对应的打印信息就无法测量。实操心得与注意事项注意CONFIG_PRINTK_TIME的时间源通常是内核的sched_clock()它在早期初始化阶段可能还未被校准导致最初一段时间的时间戳不准确甚至跳跃。因此用最初几条日志的时间戳做精确计算要谨慎。寻找更可靠的起点与其用第一条日志不如找一个在核心初始化之后、相对稳定的打印点作为参考起点例如与平台相关的初始化完成信息。但这会损失掉一部分启动时间的测量。结合dmesg命令在系统启动后可以通过dmesg命令查看内核环缓冲区中的日志。使用dmesg -H或dmesg --human可以以更易读的方式显示相对时间。但请注意环缓冲区可能被后来的日志覆盖尽早抓取或配置更大的缓冲区。这不是为高性能分析准备的该方法仅适用于粗略评估和对比例如改配置前和改配置后。对于需要优化到几十毫秒甚至几毫秒的场景必须使用更精确的方法。4. 方法二使用initcall_debug参数进行细粒度跟踪如果你怀疑启动慢是因为某个或某类驱动初始化太耗时那么initcall_debug内核参数是你的得力工具。它专门用于跟踪内核的initcall机制。4.1 原理与操作Linux内核将大多数子系统和驱动的初始化函数通过initcall机制分级调用如arch_initcall,subsys_initcall,device_initcall等。initcall_debug会在每个initcall函数执行前后打印详细的耗时信息。操作步骤在引导加载程序如U-Boot的内核启动参数中或在GRUB等引导器的内核命令行中添加initcall_debug参数。# 例如在U-Boot中设置bootargs setenv bootargs consolettyS0,115200 initcall_debug ... boot启动系统并捕获完整内核日志。你会看到大量新增的打印格式如下[ 0.123456] calling i2c_init0x0/0x44 1 [ 0.123789] initcall i2c_init0x0/0x44 returned 0 after 333 usecs上面例子显示i2c_init这个初始化函数耗时333微秒。分析日志。你可以看到所有initcall的执行顺序和每个的耗时。耗时特别长的函数就是潜在的优化目标。4.2 优缺点与实操心得优点细粒度能定位到具体哪个初始化函数慢。无需重编内核只需一个启动参数非常方便进行临时诊断。信息丰富除了耗时还能看到初始化顺序和返回值。缺点日志量巨大会显著增加内核日志输出可能冲掉其他重要信息也会轻微增加启动时间本身因为打印开销。范围特定只跟踪initcall不包含initcall之外的启动代码如最早的架构相关初始化。仍需手动分析从海量日志中找出最耗时的项需要一些文本处理技巧。实操心得与注意事项重定向日志到文件由于输出太多务必通过串口工具如screen,minicom或网络将日志直接保存到文件方便后续分析。使用脚本进行自动化分析写一个简单的grep、awk或Python脚本从日志中提取所有initcall的耗时并按耗时排序能快速找到瓶颈。例如# 提取并排序 (示例) grep “initcall .* returned .* after” dmesg.log | awk ‘{print $(NF-1), $0}’ | sort -nr | head -20这个命令会找出最耗时的20个initcall。结合trace_event对于更复杂的性能分析可以结合ftrace的initcall跟踪点获得结构化、更易处理的数据。但这需要内核开启CONFIG_FTRACE并挂载tracefs通常在启动完成后进行离线分析更合适。注意干扰添加initcall_debug本身会带来额外的打印开销这个开销也会被计入每个initcall的耗时中导致测量值比实际略高。在对比优化效果时应保持测量条件一致即都开启或都关闭该参数。5. 方法三利用内核的ftrace功能进行函数级剖析当initcall_debug提供的粒度还不够或者你想分析启动过程中任意函数的调用关系和耗时ftrace是Linux内核内置的最强大的跟踪工具之一。我们可以用它来记录启动过程。5.1 原理与操作ftrace的核心是“函数跟踪器”functiontracer。它可以在内核函数被调用时插入钩子记录调用时间。为了捕捉启动过程我们需要在内核命令行中通过ftrace参数预先设置好跟踪选项让内核在启动早期就开启跟踪并将数据保存在内存缓冲区中启动后再导出分析。操作步骤基于ARM平台示例配置内核确保内核编译时开启了CONFIG_FTRACEy、CONFIG_FUNCTION_TRACERy以及CONFIG_EARLY_TRACEy后者允许在非常早的阶段启用跟踪。配置启动参数在Bootloader的内核命令行中添加ftrace相关参数。# 示例参数 ftracefunction ftrace_filter* ftrace_buf_size2M trace_optionsnooverwrite initcall_debugftracefunction: 启用函数跟踪器。ftrace_filter*: 跟踪所有函数。为了减少数据量你可以设置为ftrace_filterstart_kernel*或特定模块的函数。ftrace_buf_size2M: 设置跟踪缓冲区大小。启动过程较长或跟踪函数多时需要增大。trace_optionsnooverwrite: 缓冲区满后停止跟踪而不是覆盖旧数据。这里也加上了initcall_debug可以互补。启动系统系统会正常启动但跟踪数据已经记录在内存的环形缓冲区中。提取跟踪数据系统启动后挂载debugfs或tracefs文件系统通常位于/sys/kernel/debug/tracing。mount -t debugfs nodev /sys/kernel/debug # 或 mount -t tracefs nodev /sys/kernel/tracing读取并分析数据# 查看跟踪到的函数图形化报告显示调用关系和耗时 cat /sys/kernel/debug/tracing/trace | less # 或者将数据保存到文件 cat /sys/kernel/debug/tracing/trace /tmp/boot_trace.log输出的trace文件包含了时间戳、进程名、函数名、耗时等信息格式如下# tracer: function # # entries-in-buffer/entries-written: 123456/123456 #P:4 # # _----- irqs-off # / _---- need-resched # | / _--- hardirq/softirq # || / _-- preempt-depth # ||| / delay # TASK-PID CPU# |||| TIMESTAMP FUNCTION # | | | |||| | | init-1 [000] ...1 0.123456: start_kernel -rest_init init-1 [000] ...1 0.123789: lockdep_init -start_kernel你可以使用trace-cmd工具需要单独安装来解析和生成更友好的报告例如生成函数调用图trace-cmd report /tmp/boot_trace.log report.txt5.2 优缺点与实操心得优点粒度极细可以跟踪到几乎每一个内核函数的执行。信息全面包含调用关系、时间戳、CPU、进程上下文等。灵活过滤可以只跟踪感兴趣的模块或函数减少数据量。缺点配置复杂需要正确配置内核和启动参数。数据量大跟踪所有函数会产生海量数据可能撑满缓冲区导致丢失早期数据。性能开销函数跟踪会带来显著性能开销导致测得的启动时间比实际长不能用于测量绝对时间但非常适合用于查找相对热点和瓶颈。需要启动后操作必须系统成功启动并挂载文件系统后才能读取数据。实操心得与注意事项警告在内存有限的嵌入式设备上设置过大的ftrace_buf_size可能导致内存分配失败甚至启动失败。建议从小缓冲区开始尝试。精准过滤是关键不要一上来就ftrace_filter*。先通过initcall_debug找到可疑模块然后只跟踪相关函数。例如如果发现mmc驱动初始化慢可以设置ftrace_filter*mmc*。使用trace-cmd进行前端控制trace-cmd工具比直接操作/sys文件接口更友好。你甚至可以在开发主机上通过trace-cmd远程控制目标板的跟踪。# 在主机上记录目标板启动需要网络和ssh支持 trace-cmd record -p function -e ‘sched:*’ ssh usertarget-board结合图形化工具将ftrace输出的数据导入到KernelShark等图形化工具中可以直观地看到时间线上的函数调用更容易发现密集和耗时的区域。理解开销记住开启ftrace后的启动时间不是真实值。优化前后的对比测试必须在相同的跟踪配置下进行比较的是“跟踪状态下的相对变化”。6. 方法四借助硬件性能计数器与早期打印对于追求极限精度、或者需要在没有控制台输出的最早阶段如内核解压时进行测量的场景我们需要祭出“底层武器”硬件性能计数器和最原始的打印。6.1 原理与操作几乎所有现代处理器都包含一个高精度的定时器计数器例如ARM的CNTPCT物理计数器、x86的TSC时间戳计数器。这个计数器的频率通常很高几十到几百MHz可以提供纳秒级的时间分辨率。我们可以在内核代码的关键位置直接读取这个计数器并通过某种方式将数值输出。由于在最早阶段串口可能未初始化输出方式有限。常见的方法有输出到内存将时间戳写入一段预先定义好的内存区域启动后再由用户空间程序读取并解析。输出到简单的调试硬件如通过GPIO翻转电平然后用示波器测量脉冲宽度。利用早期控制台如果配置了CONFIG_EARLY_PRINTK可以在串口驱动初始化前就通过特定硬件地址输出字符。操作步骤示例以ARM64平台使用内存存储为例定义共享内存区域在设备树DT中预留一小块内存或者在内核代码中定义一个固定的物理地址需确保该地址不会被系统使用。在内核源码中打点修改内核源码在关键函数如start_kernel,rest_init, 特定驱动probe函数的开始和结束处读取CNTPCT寄存器并存储。// 示例代码需根据具体架构调整 #include asm/arch_timer.h static u64 boot_timestamps[10]; // 假设存储10个时间点 static int ts_index 0; static inline u64 read_cntpct(void) { u64 val; asm volatile(“mrs %0, cntpct_el0” : “r” (val)); return val; } // 在需要测量的函数中调用 void some_init_function(void) { boot_timestamps[ts_index] read_cntpct(); // ... 函数实际工作 ... boot_timestamps[ts_index] read_cntpct(); }导出数据通过创建一个/proc或/sys文件节点或者在启动后期将这块内存的内容打印到日志中。计算耗时读取到的时间戳是计数器周期数需要除以计数器的频率可从CNTFRQ寄存器获取才能转换为时间。例如频率为62.5MHz差值1000000个周期则耗时 1000000 / 62500000 0.016秒 16毫秒。6.2 优缺点与实操心得优点精度最高可达纳秒级。可测量最早阶段从内核第一条指令开始就可以测量。开销极小读取寄存器速度极快对系统干扰最小。缺点侵入性最强需要修改内核源代码。实现复杂需要了解硬件架构和内核编程。数据获取不便需要设计机制将数据从早期环境传递出来。平台相关代码高度依赖特定CPU架构。实操心得与注意事项计数器可能不连续在系统休眠、CPU热插拔等情况下某些硬件计数器可能会重置。对于测量启动过程这通常不是问题。注意多核同步在SMP多核系统中每个CPU核心的定时器可能独立运行且不同步。确保你读取的是同一个核心的计数器或者使用架构提供的全局同步计数器。频率获取计数器的频率CNTFRQ可能在启动过程中改变例如从Bootloader设置的较低频率切换到内核设置的高频率。为了获得准确时间最好在内核稳定后例如在init进程中再读取一次频率用于计算或者确保内核早期代码没有改变该频率。GPIO示波器法这是一种非常实用的“土法炼钢”。在代码关键点插入GPIO置高/置低的语句。用示波器探头连接这个GPIO引脚屏幕上就会显示出一个方波波形波形的宽度就是代码段的执行时间。这种方法直观、绝对精确且无需处理数据导出特别适合在硬件开发板上快速定位瓶颈。缺点是需要硬件设备且打点数量有限。7. 方法五使用Bootloader进行分段测量有时问题可能不完全在内核Bootloader本身也可能很慢。或者你想测量从按下电源键到系统可用的完整时间。这时需要Bootloader和内核配合。7.1 原理与操作许多现代Bootloader如U-Boot也支持高精度定时器命令如timer。我们可以在Bootloader的不同阶段打点并将最后一个时间戳通过某种方式如设备树chosen节点、内核命令行参数传递给内核。内核在启动结束时读取自己的时间戳与Bootloader传来的时间戳相减得到整个引导过程的耗时。操作步骤U-Boot示例在U-Boot中打点修改U-Boot源码在board_init_f、board_init_r、bootm命令执行前等关键位置调用timer相关函数获取时间戳并存储。// U-Boot 示例 ulong ts_start, ts_load, ts_go; ts_start get_timer(0); // 记录起始时间 // ... 初始化硬件 ... ts_load get_timer(0); // 记录加载内核前时间 // ... 加载内核镜像和设备树 ... ts_go get_timer(0); // 记录跳转前时间传递时间戳给内核可以通过修改设备树Flattened Device Tree, FDT的chosen节点添加自定义属性。int node fdt_path_offset(blob, “/chosen”); fdt_setprop_u64(blob, node, “u-boot,ts-start”, ts_start); fdt_setprop_u64(blob, node, “u-boot,ts-go”, ts_go);在内核中读取在内核启动后期例如在init进程中解析设备树chosen节点中的这些属性获取时间戳。// 内核示例代码 #include linux/of.h u64 uboot_ts_go; struct device_node *chosen_node; chosen_node of_find_node_by_path(“/chosen”); if (chosen_node) { of_property_read_u64(chosen_node, “u-boot,ts-go”, uboot_ts_go); }计算并输出内核获取自己的当前时间例如用ktime_get_boottime_ns()与uboot_ts_go相减并加上U-Boot内部各阶段的耗时由U-Boot自己计算并打印即可得到从U-Boot开始到内核就绪的总时间。7.2 优缺点与实操心得优点测量范围最完整可以测量从Bootloader到内核的完整链条。责任清晰能明确划分启动时间消耗在Bootloader阶段还是内核阶段。缺点实现最复杂需要同时修改Bootloader和内核的代码。时间基准同步Bootloader和内核可能使用不同的时间源计时器它们的频率和起始点可能不一致直接相减可能无意义。需要将时间戳都转换为一个共同的、稳定的时间单位如微秒或者传递的是“从上电以来的计数器周期数”并且双方都知道这个计数器的频率。实操心得与注意事项统一时间源是关键最可靠的方法是Bootloader和内核都读取同一个硬件计数器的值如ARM的CNTPCT。Bootloader将其值传递给内核内核读取同一个计数器。这样差值就是准确的周期数再除以已知的固定频率即可得到时间。这要求双方对硬件寄存器的访问方式一致。U-Boot的timer命令U-Boot的timer命令本身就是一个很好的工具。可以在U-Boot命令行手动测试各个阶段的耗时。例如先timer reset然后执行一个命令如load再执行timer就会显示耗时。考虑存储初始化耗时对于从存储设备如eMMC、NVMe加载内核的系统存储驱动初始化和读取镜像的耗时可能是大头。Bootloader阶段的测量应包含这部分。8. 常见问题与排查技巧实录在实际操作中你肯定会遇到各种各样的问题。下面是我踩过的一些坑和总结的技巧。8.1 时间测量不准确或跳跃问题现象使用printk时间戳或早期打点得到的时间前后不一致或者出现巨大的跳跃。排查思路检查时钟源内核在启动早期会初始化系统时钟clocksource。在初始化完成前sched_clock()可能基于一个不稳定的jiffies或低精度定时器。确认你的测量点是否发生在clocksource_done_booting()之后。对于高精度需求应使用基于架构的计数器如arch_timer。确认中断状态在早期代码中中断可能被禁用。某些读取时间的函数可能依赖中断这会导致读出的时间停滞或不准。确保你使用的读时间函数在中断禁用环境下也能工作如直接读寄存器。多核处理器如果你在A核打一个点在B核打另一个点而这两个核心的本地定时器local timer没有严格同步差值就会出错。始终在同一个CPU核心上进行测量或者使用全局同步的计数器。8.2initcall_debug或ftrace没有输出问题现象添加了参数但内核启动日志里没有预期的调试信息。排查思路参数是否正确传递首先检查内核命令行是否真的包含了这些参数。在系统启动后查看/proc/cmdline。有时Bootloader传递参数的方式有误。内核配置确认内核编译时确实开启了对应的配置选项CONFIG_INITCALL_DEBUG,CONFIG_FTRACE等。检查/boot/config-$(uname -r)或内核源码下的.config文件。控制台日志级别initcall_debug和ftrace的一些输出可能使用较低的日志级别如KERN_DEBUG。确保内核命令行中有loglevel8或ignore_loglevel来显示所有级别的信息。缓冲区大小对于ftrace如果缓冲区设置得太小启动过程中的跟踪数据可能已经被覆盖。尝试增大ftrace_buf_size参数。8.3 嵌入式设备上资源紧张无法使用复杂工具问题场景设备内存小没有网络甚至串口输出都不稳定。解决策略回归基础优先使用printk时间戳和initcall_debug。它们开销相对较小。选择性跟踪如果必须用ftrace务必使用ftrace_filter将跟踪范围缩小到最可疑的几个函数并减小缓冲区大小。内存打点法采用上文提到的“硬件性能计数器与内存存储”方法。这是资源开销最小、精度最高的方法但需要开发工作量。可以只打少数几个关键点如start_kernel,rest_init,kernel_init。分段测量如果设备有LED或GPIO用GPIO翻转示波器/逻辑分析仪是最直接、零软件开销的方法。在每个关键阶段开始和结束翻转一下GPIO就能在波形图上清晰看到各阶段耗时。8.4 如何自动化收集和分析数据手动抓日志、算时间效率太低尤其是需要反复测试时。自动化脚本编写一个脚本通过串口工具自动捕获启动日志并用grep/awk提取时间戳计算差值。对于initcall_debug可以自动生成耗时排行榜。使用trace-cmd进行自动化跟踪trace-cmd可以记录、报告甚至与perf集成。可以编写脚本一键完成跟踪、数据提取和热点函数生成。集成到CI/CD在持续集成系统中可以将启动耗时作为一个关键指标进行监控。每次代码提交或 nightly build 都自动测量启动时间并生成趋势图一旦出现回归启动变慢立即告警。8.5 测量优化效果时的注意事项当你根据测量结果进行优化例如将某个驱动从内置改为模块或者调整初始化顺序后需要重新测量以验证效果。保持环境一致测量必须在相同的硬件环境、软件配置内核版本、文件系统、启动参数下进行。任何差异都可能导致结果不可比。多次测量取平均系统启动时间可能有微小波动。进行3-5次测量取平均值和标准差可以消除偶然误差。注意测量工具本身的开销如果你使用ftrace或initcall_debug进行测量优化后再次测量时必须使用完全相同的调试配置。因为开启调试本身会拖慢系统你优化掉的100ms可能被调试开销掩盖掉50ms。更好的做法是用低开销的方法如GPIO法或printk时间戳做最终验证。区分统计噪声和真实优化如果优化前后时间差在测量误差范围内例如多次测量波动就有±10ms而优化只减少了5ms那么这个优化可能并不显著或者需要更精确的测量手段来确认。测量内核启动耗时是一场与时间细节的较量。从简单的日志观察到深入内核的函数跟踪再到底层的硬件计数器每一种方法都是一把不同的尺子量程和精度各不相同。没有最好的方法只有最适合你当前场景的方法。对于大多数应用场景我建议的路径是先用CONFIG_PRINTK_TIME进行快速评估和对比如果发现明显变慢启用initcall_debug定位到慢的初始化函数如果需要更深入的调用关系分析则使用ftrace并精确过滤而对于嵌入式深度优化或驱动开发直接使用硬件计数器打点或GPIO示波器法往往能给你最直接、最可靠的答案。记住测量的目的是为了优化。一旦找到了瓶颈接下来的工作——延迟初始化、异步探测、并行化、裁剪不需要的功能——才是真正提升系统性能的开始。