ARTICLE · INTELLIGENCE

战地情报 · 详情页

来自尧图项目组的一线实战观察与深度解析

N100迷你主机Linux日志排查:dmesg与journald实战指南

N100迷你主机Linux日志排查:dmesg与journald实战指南 最近在调一台N100处理器的迷你主机上面跑的是一个基于Linux的嵌入式定制系统我习惯叫它EOSEmbedded Operating System。EOS的日志默认走journald同时dmesg里也能看到内核启动信息。最初我只是觉得这台机器启动比之前慢了结果一翻日志发现一连串驱动和硬件相关的报错于是把这次真机排查完整记录了下来。如果你手里也有一台N100小主机跑着类似的自制镜像、软路由系统或者轻量NAS系统这篇应该能帮你少踩几个坑。1. 排查前先弄清楚EOS日志体系与N100真机环境1.1 这台机器是什么配置为什么要用真机排查手头这台N100迷你主机是某厂商的准系统我后面自己加了内存和硬盘。N100这颗处理器4核4线程默认频率不高但胜在低功耗无风扇设计也能压住非常适合做7x24小时在线的网关、下载机、轻量虚拟化宿主机。EOS这套系统就是为了这类低功耗平台定制的底层是Linux内核上层服务全部走systemd托管。我把EOS刷到这台机器上之后一开始跑得还算正常但用了大概两周开始出现一些怪问题开机进入系统的速度从原来的30秒左右拖到1分钟以上向里写文件时偶尔卡顿某个后台服务还会自己重启。查看系统负载CPU不高内存也没满看起来不像是负载问题那就只能从日志入手。为什么一定要真机排查虚拟机里的日志通常经过虚拟化层过滤很多ACPI、电源管理、NVMe、核显相关的细节会被隐藏或者被虚拟化驱动替换掉。这种低功耗平台的怪问题往往就藏在物理机的固件、ACPI表和驱动交互里不开真机你根本看不到。所以这次排查全程在裸金属环境下操作不开虚拟机也不做远程穿透就守着机器现场看。1.2 EOS的日志架构dmesg、journald、内核环形缓冲区EOS默认的日志体系分成两层。第一层是内核日志通过dmesg可以读到内容是内核从开机开始输出的硬件初始化、驱动加载、设备注册信息存放在内核环形缓冲区里大小固定新的日志会覆盖旧的。第二层是系统日志由systemd-journald统一收集包含内核日志的副本、用户态服务的stdout、syslog消息等默认写到内存临时文件重启后不保留。排查时这两层要结合着看。dmesg适合看硬件初始化阶段的报错比如ACPI表的警告、PCIe设备枚举失败、NVMe控制器异常journald适合看系统运行阶段的日志比如某个服务崩溃、定时任务执行错误、网络接口反复up/down。我的习惯是先抓dmesg里的错误和警告再去看journald里对应时段的记录两边对照能确认报错到底发生在哪个环节。set this command set2. 从dmesg和journald入手还原启动现场2.1 dmesg里的错误和警告一眼扫出可疑点排查的第一步是先把dmesg里明显的问题捞出来。EOS默认的日志等级比较粗我用以下几组命令快速过滤。# 查看完整内核日志 dmesg # 带时间戳查看 dmesg -T # 只看错误和警告级别 dmesg --levelerr,warn # 只查看最近20条 dmesg | tail -20实测下来dmesg -T是最常用的因为EOS启动时间短内核事件又密集没有时间戳根本没法跟journald里的记录做时间对照。比如我在检查时看到了下面这类ACPI相关警告。[ 3.141592] ACPI BIOS Error (bug): Could not resolve symbol [\_SB.PC00.RP01.PXSX], AE_NOT_FOUND (20230628/psargs-330) [ 3.786543] pci 0000:00:1c.0: bridge window [mem 0x00000000-0x000fffff] to [bus 02-02] add第一眼看到ACPI BIOS Error会有点慌但实际排查后发现这是主板固件里DSDT表遗留的问题不影响任何现有硬件设备的功能。类似这种“报错看起来吓人实际上无害”的情况在N100平台上特别多后面我会专门写一节怎么区分真错和假错。现阶段要做的只是把错误收集起来逐条对应到硬件模块。2.2 journald日志用户态服务和系统运行状态的真相dmesg看的是内核journald则记录EOS里各个systemd服务的情况。我用下面这组命令定位出错的服务。# 查看本次启动的全部日志 journalctl -b # 只看本次启动的错误、警告级别日志 journalctl -b -p err journalctl -b -p warning # 查看特定服务的日志 journalctl -b -u network-setup.service # 实时跟踪日志输出 journalctl -f在排查过程中有一个文件存储服务反复重启journald里留下的原因很明确Jun 10 08:12:33 eos-host systemd[1]: storaged.service: Main process exited, codeexited, status1/FAILURE Jun 10 08:12:33 eos-host systemd[1]: storaged.service: Failed with result exit-code.这条日志指向的文件存储服务异常退出但没说具体原因。进一步用journalctl -u storaged.service -b查看服务自身输出才发现它访问某个文件系统路径时超时了。这个现象最终引导我们把目光投向存储子系统而不是服务本身的bug。所以journald排查的逻辑是层层下钻先看错误级别再看服务单元最后看服务内输出。2.3 日志持久化排查前先解决“重启丢日志”的问题EOS默认把日志放在内存里意味着如果问题重启后复现再开机检查日志时当时的现场已经没了。这个问题我踩过不止一次。所以排查之前的第一个动作是先把日志持久化。# 查看日志是否持久化 cat /etc/systemd/journald.conf | grep Storage # 如果默认是auto或volatile改成persistent # 编辑 /etc/systemd/journald.conf修改为 # Storagepersistent # 重启journald服务 systemctl restart systemd-journald改成persistent之后journald会在/var/log/journal下自动建目录日志落盘。下次重启后用journalctl --list-boots可以看到历史启动记录能够回溯多次开机的日志。这一步看起来不起眼但如果没有它后面很多对比分析都没法做。3. 逐层定位CPU、内存、存储、网络的排查实录3.1 CPU频率与温度日志N100的C-state陷阱N100这种低功耗处理器默认电源管理非常激进空闲时会频繁进入深度睡眠状态。如果EOS的CPU调频驱动没有正常工作处理器可能一直停在低频率表现为系统“慢但CPU占用率不高”。我通过cpupower检查了当前频率策略。# 查看调频驱动和可用策略 cpupower frequency-info # 查看当前所有核心频率 for cpu in /sys/devices/system/cpu/cpu[0-9]*/cpufreq; do echo $cpu: $(cat $cpu/scaling_cur_freq); done发现EOS默认选择了powersave策略所有核心基本维持在800MHz左右。这在低负载下没问题但一旦有突发任务频率爬升需要几百毫秒就会感觉到明显卡顿。解决办法是把调频策略切换为performance或者至少用ondemand之类的动态策略。# 设定所有核心为performance策略 cpupower frequency-set -g performance温度方面N100核显和CPU共用散热两颗核心跑到高负载时温度能冲到80度以上。如果用DDR5内存内存控制器也在CPU里发热更集中。EOS里用lm-sensors查看温度。sensors安装并加载相关驱动后能看到类似这样的输出。coretemp-isa-0000 Adapter: ISA adapter Package id 0: 68.0°C (high 105.0°C, crit 105.0°C) Core 0: 65.0°C (high 105.0°C, crit 105.0°C) Core 1: 67.0°C (high 105.0°C, crit 105.0°C)如果温度持续接近90度先别急着怪散热检查一下是不是调频策略导致电压偏高或者风扇曲线设置没起作用。无风扇被动散热的机箱高负载时温度升得快是正常现象关键看降下来之后能不能稳定在某个阈值以下。3.2 内存与Swap低功耗平台的隐性瓶颈N100平台的另一个特点是内存控制器只支持单通道。虽然内存容量够了但带宽比双通道平台低一截。EOS里如果跑多个容器或虚拟机内存带宽就是瓶颈。排查时先看内存是否够用。free -m vmstat 1 5free数据正常但vmstat里si和so频繁变化说明系统在内存和swap之间来回倒腾。EOS默认的swap配置是在一块SSD上划出的交换分区速度虽然比老式机械盘快但SSD的写放大和延迟依然会影响整体响应。解决思路有两个方向。一是减少swap压力调低swapiness。sysctl -w vm.swappiness10二是用zram做压缩交换。zram把一部分内存拿来做块设备数据在内存里压缩后再交换实际吞吐比SSD swap高很多。EOS的内核默认支持zram模块我后来把swap切到zram上卡顿问题明显缓解。这里提醒一句如果N100的物理内存只有8G以下zram容量不要开太大否则内存本身就不够用。3.3 存储I/O与文件系统报错NVMe掉盘和UAS兼容性排查完内存我把目光转向存储。EOS的存储服务重启问题很可能和NVMe磁盘有关。用smartctl看磁盘状态。smartctl -a /dev/nvme0n1输出里能看到温度、通电时间、以及重要的Critical Warning字段。如果这个字段不是0说明磁盘控制器认为自身状态异常。接着查内核日志里是否有NVMe相关的报错。dmesg | grep -i nvme常见的报错有这几种类型。第一种是“nvme nvme0: I/O 312 QID 1 timeout”表示某个I/O请求超时控制器没有及时响应。这种情况大多出现在待机唤醒后NVMe设备进入低功耗状态唤醒不及时导致超时。解决办法是在内核参数里加上nvme_core.default_ps_max_latency_us0禁止NVMe进入深睡眠。第二种是磁盘被识别成USB设备出现uas相关的报错。一些外接硬盘盒和N100搭配时UAS协议兼容性有问题表现为复制大文件时掉盘。解决办法是在引导参数里加上usb-storage.quirksxxxx:yyyy:u强行关闭某个设备的UAS模式。这个参数需要根据具体设备的VID:PID来填建议先用lsusb查清楚。文件系统方面如果EOS使用了btrfs或ext4日志里可能出现tree corruption或ext4-fs error的报错。处理方式不同btrfs优先尝试用“btrfs check”修复ext4则用“e2fsck -fy”在单用户模式或live环境下修复。真机修复时建议先把存储服务停掉避免写IO和修复进程打架。3.4 网络接口丢包与中断日志2.5G网卡的驱动选择N100迷你主机一般配多个2.5G网口。EOS的日志里网络相关的问题通常表现为接口反复up/down、传输速度掉到100Mbps、丢包率异常。用ethtool排查。# 查看接口统计找到丢包和错误计数 ethtool -S eth0 # 查看接口速率、协商模式 ethtool eth0 # 查看驱动信息 ethtool -i eth0如果统计里的rx_errors持续增长先检查网线和水晶头。真机排查中很多“网卡坏了”的结论最后都变成了“网线接触不良”。如果接口协商速率正常但实际吞吐偏低检查ring buffer大小。ethtool -g eth0把rx和tx的ring buffer增大能减少高并发下的丢包。ethtool -G eth0 rx 4096 tx 4096另一个隐蔽的问题是中断合并。N100平台的网卡驱动默认可能把中断合并参数调得比较激进延迟偏高。低负载时感觉不出来跑大流量时反而因为缓冲积压出现抖动。通过ethtool -c可以查看当前中断合并配置适当调低tx-usecs参数能降低尾延迟。日志里如果出现“eth0: Link is Down”反复刷屏多半是网线供电不足或者对端设备的问题而不是EOS本身。这种问题在真机调试时很容易误导我一开始以为是驱动冲突换了好几版驱动都没解决最后换了根网线就好。4. 常见问题排查与避坑实录4.1 “日志里明明有错但实际没影响”的误判N100平台最折磨人的是日志里大量看起来严重、但实际上无伤大雅的报错。我第一次刷完EOSdmesg里ACPI错误有十好几条我以为系统不稳定折腾了几天试图消除这些错误最后发现完全是浪费时间。后来我总结出一个经验ACPI错误要看最终的设备注册结果。如果后续日志中出现对应的设备成功注册、驱动成功绑定的记录那之前的ACPI解析错误只是表格式不规范可以忽略。类似的情况还包括网络接口初始化前的firmware警告接口最终还是起来了影响不大核显固件加载时的版本提示却并不影响硬件解码音频设备初始化失败但如果机器根本不用音频就不用管它。判断标准很简单就是“设备是否正常工作”。日志是帮助我们定位问题的工具不是用来满足洁癖的收藏品。只要一个报错不影响硬件的实际功能并且没有任何证据链把它跟现有故障关联起来就暂时放过它。4.2 日志被轮转吃掉重启后查不到现场这个问题在EOS里特别常见。默认的journald配置日志文件最大大小通常限制在64M或者更小空间紧张时还会自动删除旧日志。如果问题只在出问题时出现几分钟等你反应过来去查现场已经被卷走了。我后来在排查N100时遇到一个间歇性出现的服务崩溃连续三次都没抓到日志。原因是journald占用的内存区太小服务重启时把上一次的错误日志覆盖了。解决办法是把日志上限调大一些。# 查看当前journald配置 systemd-analyze cat-config systemd/journald.conf # 设置日志最大使用量为256M # 编辑/etc/systemd/journald.conf # SystemMaxUse256M systemctl restart systemd-journald排查复杂问题时我甚至会设置SystemMaxUse1G确保每一个现场都保留下来。不过要注意日志落盘过多会影响N100的SSD寿命排查结束后还是要调回合理的数值。4.3 真机与虚拟机日志差异为什么不能只靠模拟环境这次排查里的很多问题在虚拟机上完全模拟不出来。ACPI表、固件版本、NVMe低功耗、网卡中断合并这些都是硬件层面行为。虚拟机里看到的dmesg是虚拟化层翻译过的内核日志里大量真实设备的细节被隐藏。这也是我坚持真机排查的原因。如果条件允许建议给EOS装一个串口调试工具通过串口查看早期启动日志。N100小主机一般有调试串口引脚EOS默认的串口终端默认关闭需要在内核参数里加上consolettyS0,115200。开启后即使屏幕和网络都不工作也能抓到最后一段崩溃日志。5. 排查后的调优与验证5.1 日志持久化与告警配置排查工作结束后我给EOS做了一套简单的日志告警配置。核心思路是把关键错误实时过滤出来触发时写入单独文件通过EOS内置的通知机制推送。我用一个简单的systemd timer加脚本实现检测journald中最近5分钟的error级别日志如果出现指定关键词就把内容追加到/var/log/eos-alert.log。这么做的好处是不需要随时盯着终端也能知道系统什么时候出过问题。# 设置journald为持久化模式 sed -i s/#Storageauto/Storagepersistent/ /etc/systemd/journald.conf systemctl restart systemd-journald # 最多保留2次启动日志 journalctl --vacuum-boots2第一次真空清理时建议先确认当前启动没有问题再清旧日志避免把唯一的历史记录删掉。5.2 内核参数调优N100平台值得尝试的选项针对N100的功耗和中断特性我调整了几个内核参数。不过这些参数需要根据实际场景选择不是每一条对所有EOS部署都有收益。如果主要跑低延迟服务可以在内核参数里加nohz_fullall和rcu_nocbsall将CPU从周期性tick中解放出来减少调度延迟。如果主要做文件存储可以保留transparent_hugepagemadvise只在明确需要的服务上使用大页避免内存碎片化。如果遇到NVMe卡顿添加nvme_core.default_ps_max_latency_us0禁止NVMe深度电源管理。调整内核参数后不要急于一次性应用全部改动。我会先改一个参数重启验证再改下一个否则出了问题很难定位是哪条参数引起的。5.3 验证效果与收尾建议所有调优完成后我做了三轮验证。第一轮只看启动时间调整后EOS从按下电源键到进入可用状态稳定在35秒左右比最初的1分多钟明显改善。第二轮看日志错误数量dmesg中的error级别日志排除了ACPI无害警告后从最初的十几条降到0条warning级别日志里和硬件相关的只剩下温控风扇曲线的一条提示。第三轮跑了一整天的稳定性测试文件存储服务不再重启网卡吞吐稳定在2.3Gbps左右CPU温度峰值在81度空闲时跌回40度。这次排查最重要的是让我认识到N100平台上“日志干净”和“系统健康”不是一回事。很多日志报错是固件层的历史包袱真正需要关注的是那些和设备实际功能相关的错误链。后续如果再遇到类似问题我的排查顺序不变先持久化日志再抓dmesg然后journald逐服务下钻最后才动系统参数。最后再分享一个小技巧排查N100这类低功耗平台时把电源设为高性能模式同时把CPU调频策略设为performance能减少很多莫名其妙的“卡顿”。不少人觉得低功耗平台就应该省电但省电和省心往往不可兼得。如果这台机器是要长期稳定跑服务的宁可多耗几瓦电也别让CPU在深度睡眠和满血状态之间来回折腾。
RELATED READING

延伸阅读

更多一线实战笔记与深度复盘,助您持续精进