1. 新构建镜像在N100真机上首次上电现象还原与排查目标1.1 为什么模拟器里跑得好好的真机却起不来接手这台N100真机之前我先在虚拟化环境里把EOS系统镜像完整跑了一遍启动流程、服务注册、日志输出全部正常。按道理说同样的rootfs、同样的内核配置搬到真机上不应该出问题——但实际情况往往就是这么打脸。上电之后面板上的电源灯亮了风扇转了然后就没有然后了。网口指示灯不规律闪烁但管理面完全ping不通接上显示器和键盘屏幕上只有一行光标连BIOS自检信息都被跳过去了串口更是什么都没输出仿佛整个系统根本没有执行任何代码。我当时的判断是要么是启动介质没被正确识别要么是bootloader在早期阶段就挂掉了。但问题在于没有任何日志可以参考。做真机排查和调试虚拟机最大的区别就是虚拟机的串口、显示输出、复位行为都是虚拟化层模拟的你随时能截图、能dump内存、能暂停CPU真机则完全没有这些后悔药一旦bootloader或内核解压阶段崩溃唯一能依靠的就是硬件留给你的那点现场信息。所以这次排查的第一步不是急着改代码而是先把日志通道打通让系统在每一个关键节点都留下可追溯的痕迹。1.2 本次排查的基线环境与日志前置条件先说结论排查对象是一台使用N100处理器的紧凑型主机16GB内存一块NVMe固态作为系统盘。EOS在这个项目里指的是团队自研的一套轻量级边缘操作系统基于Linux内核裁剪跑一些定时数据采集和通信服务。镜像格式是标准的EFI引导bootloader负责加载内核和设备树然后切给内核最后由内核拉起EOS的用户态服务。为了这次排查我准备了三样东西一条USB转串口线接到主板的调试串口排针上一台单独的笔记本作为日志接收端通过串口工具持续记录输出一个装有efibootmgr和grub工具的U盘用于进恢复模式检查启动项。这里要提醒一点N100这类低功耗平台虽然体积小但调试接口往往不是标准配置。有些主板的串口排针默认是关闭的需要在BIOS里手动打开而且不同板子的针脚定义也可能有差异。我第一次接上串口后等了半分钟屏幕上一点反应都没有还以为是机器彻底没启动。后来在BIOS里找到Serial Console Redirection选项把串口重定向功能打开再把波特率设成115200才真正拿到了启动日志。拿到日志之后我会用一套固定的流程来做阶段划分先看bootloader阶段有没有执行到内核加载点再看内核早期初始化有没有报错最后看EOS用户态服务有没有拉起来。顺着这个思路排查效率会比直接盯着屏幕猜高很多。2. 真机日志采集串口、内核缓冲与用户态打点的三层组合2.1 串口配置从BIOS到内核的完整链路开始抓日志之前需要先把串口这条链路整条捋通。很多人只在BIOS里开了串口重定向但内核参数没配好结果BIOS阶段看得到输出一旦跳转到内核就突然断片。我在N100上的做法是三步走BIOS里开启串口重定向设置波特率115200、数据位8、停止位1、无校验grub配置里的kernel命令行加上两个参数consolettyS0,115200n8和earlyconuart,io,0x3f8,115200n8内核选项里保证CONFIG_SERIAL_8250和CONFIG_SERIAL_8250_CONSOLE被编译进内核不能用模块方式否则console初始化时机太晚。第二步里的earlycon参数很关键它让内核在早期阶段就能输出日志。如果没有它内核在串口驱动初始化之前的printk信息会全部丢失而这些信息往往正是判断崩溃点的关键。我实际执行时grub菜单是通过U盘里的恢复环境改的。挂载EFI分区之后直接编辑grub.cfg把kernel行整体替换掉。这里有个小坑某些固件不支持consolettyS0这样的通用写法得先通过cat /proc/tty/driver/serial确认串口对应的设备名是ttyS0还是ttyS1。如果是PCIe转出来的串口设备名可能是ttyUSB0或者ttyS4那kernel命令行也要跟着改。2.2 内核日志等级的权衡别一上来就是“安静模式”默认情况下很多发行版的内核日志等级是quiet也就是说普通级别的内核消息不会打印到串口上。真机排查时这是非常讨厌的因为你会看到系统像是完全死了实际上它只是不想说话。我的建议是排查期间把日志等级调到最详细loglevel8 ignore_loglevelloglevel8会打印绝大多数内核消息ignore_loglevel则强制忽略代码里对日志级别的限制效果接近全量输出。代价是日志量会变得非常大如果是长时间运行串口会成为瓶颈但排一次启动问题完全值得。另外串口终端还要注意抢占问题。内核的console输出和实际串口驱动数据传输是两条路径console走的是同步机制会阻塞在串口硬件上。如果你同时开了串口登录shell和console输出两者会抢同一个设备。我在这台N100上就遇到过类似情况console日志打印到一半突然被shell登录的欢迎横幅打断看起来像是日志乱序其实是两个写者同时操作串口导致的。排查期间最好只保留console输出不要用串口做登录终端。2.3 EOS服务层日志的落盘策略内存环形缓冲优先内核日志能解决启动早期的问题但EOS用户态服务的日志是另一条线。因为服务在启动过程中根文件系统可能还没完成读写挂载直接把日志写到磁盘会失败。团队里EOS的做法是所有服务日志先写入一个内存环形缓冲区默认容量2MB由日志采集服务负责读取并异步落盘。这样即使rootfs没挂载日志也不会丢只是暂时留在内存里。但这样做也有代价。环形缓冲区满了之后老日志会被新日志覆盖。所以排查启动问题时需要对最关心的那个服务单独调大缓冲或者先临时把缓冲区大小改成16MB再复现问题。我这次就吃了这个亏。第一次复现时EOS的通信服务启动到一半就崩了但当时缓冲区的老日志已经被后续的轮询服务刷掉。第二次复现才抓到真正的异常栈。所以调整排查目标服务的日志缓冲和调整内核日志等级同等重要。这里我把EOS日志系统的配置结构整理一下方便对照配置项作用排查期建议值ringbuffer_size内存日志缓冲大小16MBflush_interval刷盘间隔5秒level_filter日志级别过滤debugmodule_filter模块白名单只保留目标服务模块表格里的建议值不是越大约好因为每次刷盘都涉及I/O如果目标rootfs本来就慢刷盘间隔太短反而会拖慢服务。实测下来16MB加5秒间隔的组合比较均衡。3. 分阶段定位卡死点从bootloader、内核到EOS用户态的三级检查3.1 bootloader阶段复位向量与DDR训练日志拿到完整串口日志后第一步先看bootloader阶段有没有输出完整。正常流程应该是固件自检、内存初始化、启动设备枚举、加载grub、grub加载内核和设备树最后跳转。N100平台用的是标准UEFI引导grub应该会在屏幕上打印菜单并通过串口输出类似Loading Linux ...的信息。如果你连这行都没有看到问题大概率出在固件设置、启动介质识别或者grub配置上。我这次的情况是能看到固件自检的Logo信息但grub菜单一闪而过直接跳到黑屏。这通常意味着grub找不到配置文件或者配置文件里指定的内核路径不对。排查方法很简单在grub菜单出现时快速按e进入编辑模式看kernel行写的路径是否存在。如果路径没问题再检查root设备参数。比如我的内核命令行写成root/dev/nvme0n1p2但在这台N100上NVMe设备枚举顺序可能变化nvme0n1未必是目标盘。更稳妥的做法是通过UUID指定root分区rootPARTUUIDxxxxxx-xxxx在恢复环境里用blkid命令就能拿到分区的PARTUUID。这个参数比设备名可靠得多因为设备名在枚举顺序变化时容易漂移。3.2 内核阶段驱动加载期间挂起grub成功把内核加载到内存之后串口应该输出内核的早期日志。从earlycon开始到Run /init as init process之前都属于内核启动阶段。这个阶段最容易出现的是驱动初始化卡死。N100这类处理器集成了非常多外设从SATA控制器、网络控制器到USB控制器都是内核需要枚举和初始化的。如果某个设备的驱动在初始化时进入了一个死循环或者等待一个永远不会完成的硬件操作系统就会停在某个驱动加载点后续所有日志都没了。我这次遇到的现象是日志停在nvme nvme0: I/O 4 QID 0 timeout这行之后就再没有任何输出。这说明NVMe驱动在等待设备响应时超时了。后面我会专门讲这个问题的根因和修复。还有一种常见情况是pci设备枚举阶段卡住。如果你在日志里看到pci 0000:00:1f.0这类行之后再无下文那就需要考虑PCIe链路训练的问题。此时最快的定位方法是给内核加pcirealloc或者pcinoacpi参数看能否绕过某个有问题的路由逻辑。3.3 EOS用户态阶段首个服务启动失败内核成功切到init进程后串口会有Run /init as init process字样。从这一刻起EOS的init脚本会按依赖顺序启动各个服务。EOS的启动流程比较简单init脚本先挂载proc和sysfs再启动日志采集服务然后依次启动核心服务、通信服务、采集服务。启动顺序是写死在脚本里的。排查时我习惯在init脚本里加入阶段打点echo [EOS-INIT] stage 1: mount proc/sysfs /dev/console echo [EOS-INIT] stage 2: start logd /dev/console echo [EOS-INIT] stage 3: start core services /dev/console通过串口观察这些打点就能知道init脚本执行到了哪一步。如果打点显示stage 2之后什么都没有说明logd服务启动时阻塞了。这时再去看logd的启动脚本多半是卡在某个wait操作上。我这次在定位过程中发现卡在某个服务启动时不只是该服务的问题也可能是它依赖的底层内核接口没有准备好。比如logd需要读取/sys/kernel/debug下的信息但debugfs没有挂载导致logd打开设备文件时一直等待。打点日志的价值就在这里它告诉你执行到了哪里而不是让你沿着服务启动顺序一个个猜。4. 修复过程中最折腾的三个根因时钟基准、NVMe设备和内存映射4.1 时钟基准被误判日志时间戳产生“时空穿越”第一次完整跑通启动流程后我注意到一个很奇怪的现象串口日志的时间戳完全乱序。比如前一条日志显示12:04:33下一条突然变成09:15:02再下一条又跳到10:02:11。刚开始我以为只是时区问题后来发现时间戳跳跃的间隔恰好是几十秒到几分钟不等这显然不是时区能解释的。查下去才发现N100平台存在多种时钟源HPET、ACPI PM Timer、TSC。默认情况下Linux会优先选择TSC作为内时钟源。但N100的TSC在某些状态切换下并不稳定尤其是在开启节能特性时TSC频率会跟着CPU频率变化导致基于TSC的时间基准出现偏差。日志里能看到类似这样的提示clocksource: Switched to clocksource tsc如果后面出现明显的时间同步问题我建议在kernel命令行里强制使用HPETclocksourcehpet或者禁用TSC相关的时钟校验tscunstable按理说现代内核应该能自动判断时钟源是否可靠但真机上的硬件特征千奇百怪内核的判断并不总是准确。强制指定一个更稳定的时钟源是快速解决问题的手段。时间戳乱序对排查启动影响很大因为你需要准确判断各个服务之间的先后顺序。如果时间戳不可信只能靠日志内容里的利用计数或者行号来推断顺序。我最后选择用HPET作为时钟源重启后时间戳回归正常这个问题才算翻篇。4.2 NVMe设备在真机上的链路训练超时回到刚才提到的nvme nvme0: I/O 4 QID 0 timeout超时。这个错误反复出现导致系统盘读取失败rootfs无法挂载系统自然起不来。NVMe设备在真机上出问题最常见的嫌疑有M.2接口的PCIe链路训练不成功设备侧和主机侧速率协商失败NVMe固件有已知的省电状态bug设备在空闲后进入较低的电源状态无法及时响应命令主板在BIOS里把NVMe通道的PCIe速率设置成了Gen4而设备只支持Gen3导致链路不稳定。我先把BIOS里NVMe相关选项全部恢复成Auto问题依旧。又尝试给内核加nvme_core.default_ps_max_latency_us0参数禁用NVMe设备的自主电源状态切换这是业内常用的绕过省电bug的手段nvme_core.default_ps_max_latency_us0加了这行参数之后NVMe超时问题消失了。这说明根因确实是设备在空闲后进入了低功耗状态响应延迟超过了内核的容忍时间。这类问题在台式机上很少见因为台式机NVMe盘通常插在独立供电的M.2槽位上而且散热条件好。但N100这类紧凑主机供电余量小NVMe设备为了省电更容易触发深度电源状态。如果你也碰到NVMe超时或根本识别不到NVMe盘可以优先尝试这个方法。4.3 内存映射配置与真实可用内存不一致另一个折腾了我很久的问题是EOS内核配置里的内存映射参数与实际内存大小不匹配。N100平台的内存不是可插拔的SO-DIMM而是板载LPDDR颗粒容量固定。我们的EOS内核里为了优化启动速度写死了一段内存映射配置把物理内存按低端、高端分别预留。真机上实际可用内存是16GB但映射配置文件里只预留了8GB导致内核探测到16GB内存却因为映射配置限制只把一部分内存加入buddy allocator。表现就是系统能启动但一旦EOS的采集服务尝试申请大块内存就会收到Out of memory错误而实际上系统内存还有很多空闲。排查时用dmesg | grep Memory可以看到内核检测到的物理内存范围Memory: 16264636K/16777216K available如果内核看到的和BIOS里设置的不一致就要检查设备树或者内核命令行里是否有mem参数限制。我在EOS的grub配置里加了一段mem16G其实这不是最优解更好的做法是去掉所有mem参数让内核自己探测。只是当时为了快速验证先用mem16G试跑了一眼后面确定没问题后就把这个参数删了让系统回归自动探测。这里要提醒一下内核里写死的内存映射表最坑人因为它只在特定硬件配置下成立。一旦换一台内存容量不同的N100设备就会出问题。排查真机问题时如果能确定某个配置是写死的且与硬件实际不匹配最好的修复方式是让内核自行探测而不是不断调整固定值去迁就硬件。5. 真机日志排查的经验沉淀工具、流程与小技巧5.1 串口日志常用的三种抓取姿势真机排查时日志抓取工具的选择直接影响效率。我常用的有三种minicom / screen最直接适合短时间观察启动过程但日志量大时容易刷屏且滚动缓冲区有限picocom 自动落盘适合后台长时间记录配置好参数后可以自动把日志写到文件ser2net 网络转发适合远程排查把串口数据转发成TCP流笔记本上可以用nc接收。我个人最推荐的是第二种。在笔记本上起一个终端执行picocom -b 115200 /dev/ttyUSB0 --logfile /tmp/eos_boot.log这样日志会实时写入文件不用担心屏幕缓冲区被冲掉。等系统复现问题后直接分析日志文件即可还能用grep快速过滤关键字。5.2 “先复现再定位”原则与最小化复现真机排查的一个大忌是在还没稳定复现问题的情况下就急着去改代码。因为改完之后你根本不知道是改对的还是运气好。我的流程是拿到第一份完整日志记录现象原样重启确认问题是否稳定复现如果稳定逐步缩小范围如果只是概率性复现先记录复现时的一些环境参数比如室温、负载、启动到某步的时间然后尝试最小化复现停掉非必要服务、关闭节能特性、去掉额外外围设备。以我这次的经验为例NVMe超时是稳定复现的因此直接加参数验证而时钟源问题是不稳定复现的第一次日志乱序第二次又正常这时候就需要先最小化复现把非必要的PCIe设备全部摘掉只留NVMe系统盘。摘掉其他设备后复现概率大幅度提升才能高效定位。5.3 排查日志中那些容易被忽略的信号翻日志的时候很多人只盯error和panic容易忽略一些细微的预警信息。有两个容易被忽略的信号在真机排查里特别有用第一个是clocksource切换提示。内核自动切换时钟源多半说明默认时钟源出了问题。虽然有时候切换之后系统仍然能工作但在N100这种异构平台上这个信号值得追踪。第二个是PCIe链路降级日志。比如pcieport 0000:00:1c.0: PCIe Bus Error: severityCorrected即使是Corrected级别的报错也说明链路层出现了需要纠错的事件。偶尔一次可以忽略但如果频繁出现说明PCIe信号质量或者供电可能有隐患后续迟早变成真正故障。除此之外我还习惯在启动流程中加一种哨兵日志每个关键阶段完成后打印一条带唯一标识的日志。比如[EOS-MARK] boot_complete。这样后续根据日志分析阶段耗时、定位卡死点都会方便很多。5.4 我的最终建议与个人体会这次N100真机排查折腾了大概一个下午最后把NVMe超时、时钟源选择、内存映射三个问题都修复之后系统终于能稳定跑起来——从上电到EOS通信服务注册成功串口日志完整无断档。整个流程下来我的体会是真机排查和模拟器调试完全是两种思维模式。模拟器里遇到问题你会怀疑逻辑真机里遇到问题你首先得怀疑硬件、固件和配置差异。日志不是输出得越多越好而是要在每个关键节点都能留下可以对照的标记。一个带时间戳、分阶段打点、允许动态调整缓冲的日志系统比任何调试工具都重要。如果再让我给刚接触这类平台的人一个建议那就是拿到板子之后不要急着跑业务先花半小时把串口日志链路完整打通并确认重启后日志稳定输出。这一步虽然是体力活但在后续的每一次排查中都会帮你省下数倍的时间。