1. 工具系统在自研内核中的位置不想当调试器的内核不是好内核1.1 为什么走到第五篇必须补工具系统前四篇我们把DSH内核从引导区一路做到了页表、物理内存管理和任务调度能跑起来也能看到串口输出。但说实话到了这个阶段我最大的感受不是“功能太少”而是“什么都看不见”。程序能跑是能跑内存分配对不对、页表映射有没有缺项、调度器切换那一刻CPU状态是否完整全靠猜。猜一次两次还行等到中断一多、任务一切换肉眼排查基本失效。工具系统就是在这样一个节点上被逼出来的。它不是什么锦上添花的加分项而是开发效率的分水岭——哪怕你的内核只有几百行代码只要你想继续往上加文件系统、用户态、驱动模型就必须先有一双能看到“内部状态”的眼睛。我甚至愿意这么说一个没有工具系统的内核不是一个可以持续前进的项目而是一次性演示代码。这篇就顺着DSH内核的实际情况把工具系统拆成四块来讲内核日志、控制台命令、内存与页表诊断、panic现场快照。每一块我都会给出设计思路和核心实现也会把我在调试过程中遇到的真问题放进来尤其是那些“网上教程不会写、文档里查不到”的细节。1.2 一个内核工具系统至少该有的四块我最初的想法很简单能打印日志就够了。后来发现不够因为日志只能回答“发生了什么”回答不了“现在内部状态是什么样的”。所以我把工具系统拆成了四个相互独立、但又彼此衔接的模块模块作用典型使用场景依赖基础日志子系统按级别记录内核运行过程写入环形缓冲区并输出到串口启动流程追踪、中断异常定位串口驱动、时间信息控制台命令通过命令行交互查看内核运行状态运行时查内存、查进程、查映射串口输入输出、命令表内存与页表诊断直接读取虚拟地址内容解析多级页表结构排查缺页异常、非法访问、映射错误页表基址、MMU相关寄存器panic现场快照在崩溃时保存寄存器、栈指针和关键数据结构系统死机后定位崩溃点异常处理入口、状态块存储这四块不是拍脑袋定的而是我在DSH从“能启动”到“能跑多任务”过程中真实遇到过的需求。没有日志子系统启动到哪一步挂了你都不知道没有控制台命令你只能一遍遍往代码里塞临时打印没有页表诊断虚拟内存这块基本等于盲飞没有panic快照内核一崩溃就只能靠串口最后几行字猜原因。1.3 一句话说清楚这篇的路线这篇不会讲特别花哨的设计而是尽量贴近“你手里已经有一个能跑的内核现在要往里加工具”的实际场景。代码我会直接贴关键部分虽然语法和命名会贴近DSH目前的状态但你完全可以移植到自己的项目里。无论你是刚跑通一个最小内核还是已经做到进程调度工具系统的这四块都能直接落地。2. 内核日志子系统环形缓冲区的设计细节2.1 分级日志至少区分 DEBUG 与 ERROR很多初学者写内核日志就是一个kprintf从头用到尾。这在最初几周没问题但等到你要定位一个“启动到某一步就重启”的问题时满屏信息反而等于没有信息。我给DSH做日志分级的时候参考了Linux的log level思路但精简成了六个级别enum dsh_log_level { L_TRACE 0, // 极细粒度跟踪平时关闭 L_DEBUG 1, // 调试信息开发期打开 L_INFO 2, // 正常流程里程碑 L_WARN 3, // 不致命但可疑 L_ERROR 4, // 可恢复的错误 L_PANIC 5, // 致命错误 }; static uint32_t dsh_log_mask 0x03; // 默认只输出 INFO / WARN / ERROR / PANIC分级的作用不只是“控制打印量”更关键的是让你能在不同场景下切换信息粒度。比如启动阶段我只关心INFO排查一个内存分配问题的时候我打开DEBUG追踪某个驱动状态机的时候我才打开TRACE。这样就不需要来回改代码加编译开关运行期用命令设置mask即可。我强烈建议你把日志级别做成一个运行时可配置的位掩码而不是编译期宏开关。编译期开关的问题是一旦某个分支被裁剪后续想不开机不改代码就不可能了。DSH目前的做法是控制台命令里加了一个loglevel指令直接写dsh_log_mask。2.2 环形缓冲区实现思路和 ISR 安全日志一定要有两份去路一份实时输出到串口一份写进内核内存里的环形缓冲区。实时输出让你盯着启动过程看环形缓冲区则保证你回头看“刚才那几十行”时不会被串口速度拖累也不会因为当前屏幕滚动而丢失。环形缓冲区的核心结构很简单#define LOG_BUF_SIZE (64 * 1024) static char log_buf[LOG_BUF_SIZE]; static volatile uint32_t log_head; // 写位置 static uint32_t log_tail; // 读位置也是最早有效数据的起点 void dsh_log_write(enum dsh_log_level level, const char *fmt, ...) { char tmp[256]; va_list ap; int len; uint32_t flags; uint32_t head, tail, used; // 1. 先按级别过滤 if (!(dsh_log_mask (1u level))) return; // 2. 格式化成临时缓冲区 va_start(ap, fmt); len vsnprintf(tmp, sizeof(tmp), fmt, ap); va_end(ap); if (len 0) return; // 3. 中断保护防止写日志时被打断导致环形缓冲区错乱 local_irq_save(flags); head log_head; tail log_tail; used (head - tail) % LOG_BUF_SIZE; // 4. 如果剩余空间不够就把最老的丢出去 while (used (uint32_t)len LOG_BUF_SIZE) { // 丢弃最前面的一条日志这里简化为整段覆盖 tail (tail 16) % LOG_BUF_SIZE; // 伪代码实际需要解析换行 used (head - tail) % LOG_BUF_SIZE; } // 5. 写入环形区 for (int i 0; i len; i) log_buf[(head i) % LOG_BUF_SIZE] tmp[i]; log_head (head len) % LOG_BUF_SIZE; // 6. 同时输出串口 dsh_uart_write_bytes(tmp, len); local_irq_restore(flags); }上面代码里我刻意保留了“丢弃最老日志”的简化处理实际项目里你要做的是按行丢弃也就是从tail开始往后扫描换行符把一整个完整日志行丢出去而不是按固定字节数覆盖。否则你就可能看到半行日志既难看又容易误判时间顺序。ISR安全这一点很多人会忽视。中断处理函数里也可能要打日志比如记录某次异常发生的时刻。如果日志写入过程中又来了一个相同优先级的中断或者主流程和中断同时写head和tail就会错乱。所以我在写路径上做了local_irq_save/restore。读路径也就是上串口输出的时候通常发生在主流程不会被自己打断但为了保险读的时候也建议关一下中断。2.3 和 dmesg 对齐的日志条目格式日志不能只存字符串否则时间顺序、级别、来源都靠肉眼认。我参考了Linux dmesg的做法给每条日志加一个统一的头[ 0.123456] I [cpu0] pmm: free pages: 524288 [ 0.123512] D [cpu1] pmm: init zone: 0x100000 - 0x200000构成拆开就是字段含义为什么重要[ 0.123456]内核启动后的时间戳判断卡死前最后执行到的时间点I日志级别缩写快速筛选[cpu0]哪个CPU打的日志多核环境下定位交互问题pmm:子系统标签知道这条日志来自内存管理还是进程调度free pages: 524288正文核心信息时间戳我用的是启动后的单调时钟单位是微秒配合一个启动以来累计的tick计数器换算。不要直接用rdtsc那种原始周期数除非你周期频率在运行期已经算好了不然数值一会儿大一会儿小特别难读。子系统标签也是我后来加上的。早期日志是“裸奔”的一条一条全是文字。等代码量冲到几千行光靠 grep 根本没法定位。加了标签之后我可以直接在控制台层按标签过滤比如只看pmm:开头的日志这比全文搜可靠得多。2.4 日志层我踩过的三个坑第一个坑是双核打印交错。DSH 跑到 SMP 初始化之后两个 CPU 同时打日志串口上经常出现一句话插入到另一句话中间的画面。这不是串口问题也不是日志缓冲区问题而是“分两步输出”导致的先输出前半段、然后被打断输出别的、最后再补后半段。解决方法是最终输出到串口时把一整条日志先完整塞进一个中等大小的静态缓冲区然后一次性调用串口写入。宁可让其他 CPU 等也不能让半条日志上串口。第二个坑是时间戳溢出。DSH 的 tick 是纳秒累加的一开始我用 32 位变量保存微秒数跑了几十分钟就溢出。日志一旦时间错乱排查基本就废了。后来果断把时间戳累加器换成 64 位并且每次打印都做掩码归一化确保日志头里显示的是相对启动的有效时间。第三个坑是串口省流变身丢字。115200 波特率下一秒钟理论上能传大约 11KB 字符。如果日志在极短时间内爆发比如某次循环里打了上千条调试信息串口会瞬间成为瓶颈。日志写入环形缓冲区是纳秒级别完成的但串口输出是毫秒级别的。我在 UART 驱动里加了一个 TX FIFO 等待逻辑并在日志子系统里做了一个简单限速如果连续打印间隔小于某个阈值就把后续日志只写环形缓冲区不再同步输出串口。这样你事后用dmesg命令能查到全量串口上也只看到有效信息。3. 控制台命令系统把内核变成可交互的诊断台3.1 命令表驱动架构注册即生效控制台命令系统是我最喜欢的部分因为它让内核从一个“只会往串口吐字的哑巴”变成了一个“能听指令的交互终端”。设计上我沿用了嵌入式领域非常成熟的命令表模式struct cmd_entry { const char *name; const char *usage; int (*handler)(int argc, char **argv); }; static struct cmd_entry dsh_cmd_table[] { { help, help [cmd], cmd_help }, { dmesg, dmesg [lines], cmd_dmesg }, { mem, mem addr [len], cmd_mem }, { map, map vaddr, cmd_map }, { task, task, cmd_task }, { stat, stat, cmd_stat }, { panic, panic, cmd_panic }, { loglevel,loglevel mask, cmd_loglevel}, { NULL, NULL, NULL } };命令行输入的解析我自己写了个很轻量的实现按空格拆分成argc/argv然后线性扫命令表做字符串匹配。对内核来说完全不值得为此引入一个什么现成的命令行解析库。DSH 目前没有把控制台放到独立线程里而是直接在串口中断里积累字符等回车之后在主循环里执行命令。原因很简单串口中断里执行命令本身风险很大万一某个 handler 里做内存分配导致重入那就真是自己给自己挖坑。命令 handler 的签名统一成int (*)(int argc, char **argv)返回 0 表示成功非零表示用法错误。这样 help 功能和错误提示可以直接复用。3.2 核心命令的实际价值不只是“摆弄着玩”命令是否值得加我只有一个标准它能不能在真实排障中帮上忙。以下是我在DSH里保留的命令和它们对应的真实故障场景命令输出内容我遇到的实际用处dmesg环形缓冲区里的日志串口刷屏后回看关键记录mem addr [len]指定虚拟地址的内存内容检查结构体是否初始化、链表节点是否损坏map vaddr虚拟地址对应的页表层级与物理页缺页异常时确认映射是否存在task所有进程/任务的状态、栈顶、优先级调度卡死时看是哪个任务在跑statCPU 使用率、内存总量/空闲判断是不是内存耗尽导致分配失败panic主动触发崩溃测试 panic handler 和现场快照loglevel修改日志输出掩码打开/关闭调试级别输出以mem为例它的意义在于你可以在任意时刻直接看某个地址的内存而不是在代码里写死打印结构体字段。比如遇到一个定时器队列节点行为异常输入mem 0xffff800001234560 128就能看到里面到底装了什么哪些字节像指针、哪些字节是垃圾。这个能力在调试链表、红黑树这类结构时尤其救命。map命令则是虚拟内存调试的关键。DSH 用的是 x86-64 的四级页表刚开始实现的时候我经常在map命令里直接输入一个虚拟地址看它经过 Pgd/Pud/Pmd/Pte 四层之后到底映射到了哪个物理页页的权限位和存在位对不对。这个命令做得越直观你对虚拟内存的掌控感越强。3.3 控制台命令的边界与安全性控制台命令是运行在内核态的稍不留神一条命令就能把系统打崩。我归纳出几条必须遵守的边界规则第一参数解析必须防越界。输入一个大得离谱的长度比如mem 0x1000 0xffffffff你不可能真的去读几十GB内存。我在cmd_mem里强制限制单次最多打印 512 字节超出就截断。第二handler 里禁止做睡眠或长时间阻塞。因为命令执行在主循环里如果某个 handler 死等一个永远不会出现的事件整个控制台就永久卡死。像stat这种需要遍历进程链表的命令我会先加一个循环计数上限兼带防止链表出现环。第三命令输出不要和日志子系统抢同一个临时缓冲区。最开始我把命令输出直接塞进dsh_log_write结果就是命令结果和系统日志混在一堆毫无可读性。现在命令输出走独立的cmd_printf直接到串口。4. 工具系统实战一起“启动即卡死”排障全流程4.1 现象内核跑到某一步突然不动了这套工具系统刚建好的时候我正好撞上一个DSH的回归问题某次改动之后内核启动到pmm_init的第三个 zone 就彻底卡住串口上最后一条日志是[ 0.118423] I [cpu0] pmm: init zone 2, base0x40000000, pages262144之后什么都没有。看起来像死循环也可能是CPU异常后进入了某个空的中断处理函数。在没有工具系统之前我多半会往pmm_init前后加十几行打印然后重新编译烧录来回折腾。这次我决定换个玩法完全依靠已有的日志、map、mem 和 panic handler 来做一次全流程定位。4.2 第一轮定位用日志粒度找“最后一口气”我先打开loglevel 0x3f把 TRACE 和 DEBUG 都打开重新启动。这次日志变得密密麻麻但最后的关键信息变成了[ 0.118430] D [cpu0] pmm: zone2 bitmap allocated at 0xffff800011000000 [ 0.118435] D [cpu0] pmm: zone2 bitmap primary set [ 0.118440] D [cpu0] pmm: zone2 buddy merge start问题缩小了一点不是死循环也不是CPU异常而是死在buddy merge这一步。再往下跟发现它是在一次对某个物理页结构的访问中卡住的。这种“卡住”通常指向一个无效地址要么是页表映射不存在要么是物理页管理结构里有坏数据。4.3 第二轮定位map 与 mem 直接看现场这个物理页结构体的虚拟地址已经由日志打出来了我直接在控制台输入ds map 0xffff800012345000这时候 DS 输出vaddr 0xffff800012345000 PGD: 0xffffff8000000000 - entry 0x0000000880000063 PUD: 0xffffff8000037000 - entry 0x0000000880100063 PMD: 0xffffff8000036000 - entry 0x0000000880200063 PTE: 0xffffff8000035000 - entry 0x0000000000000000 (not present)缺页。也就是说物理页管理结构所在的虚拟地址根本没有被映射。再用mem检查相邻区域发现 PTE 区域里全是零。到这里根因已经比较明显pmm_init在初始化新 zone 的时候只给新页管理结构的头部区块建立了映射没有把整个 buddy 数组所在的连续虚拟区域完整映射。后面的代码一直用未映射的虚拟地址做读改写自然就卡住。4.4 修复与验证工具系统带来的排查链路优势修复方式很简单在pmm_init的 zone2 初始化之前把该区域所需的虚拟地址范围统一调用dsh_vmm_map_contiguous映射好然后把初始化和合并代码放回到映射建立之后再执行。重新编译启动这次日志一路顺利往下走[ 0.125621] I [cpu0] pmm: all zones initialized [ 0.125630] I [cpu0] sched: idle task created [ 0.125635] I [cpu0] sched: smp boot cpu online这次排障前后只用了不到半小时相比以前靠猜和临时打印的方式快很多。关键不在于某个命令多神奇而在于整个链路是通的日志告诉你症状map 告诉你映射mem 告诉你数据panic handler 还能在你来不及输入命令时替你抓住现场。这套链路一旦建立后续任何内核改动都敢放手去做了。4.5 顺带说一句这类日志喂给AI工具也有讲究现在很多人喜欢拿系统日志直接丢给AI工具做分析我在这次排障里也试过类似做法。我的体会是工具分析的价值高度依赖日志本身的质量。如果日志没有时间戳、没有级别、没有子系统标签AI工具再强也只能从一团乱麻里瞎猜。DSH日志系统把这些结构化字段做齐了之后我确实可以直接截取一段启动日志让人工智能辅助判断可能的挂起点。但最终的现场确认还是得靠map、mem这些内核层工具因为AI看不到你寄存器里的值也管不了页表映射。5. Panic Handler 与自动状态快照把故障现场留给下一次启动5.1 panic 路径不仅要打日志还要留下现场内核开发到后期最怕的不是看不到日志而是系统直接崩溃重启。硬件watchdog一触发UART缓冲区和内存里的日志全没了留给你的只有“刚才好像崩溃了”这个事实。DSH的panic handler从一开始的“打印一行字再死”升级成了现在的“打印全套现场再死”void dsh_panic(const char *reason, uintptr_t rip, uintptr_t rsp) { // 关中断防止处理过程中被再次打断 local_irq_disable(); // 1. 报告崩溃原因 dsh_log_write(L_PANIC, KERNEL PANIC: %s, reason); // 2. 打印通用寄存器快照 dsh_print_registers(); // 3. 打印当前CPU号、栈指针、指令指针 dsh_log_write(L_PANIC, cpu%d rip0x%lx rsp0x%lx, dsh_get_cpu_id(), rip, rsp); // 4. 尝试展开调用栈如果栈布局完整 dsh_backtrace(); // 5. 保存状态块到固定地址供下电前读取或下次启动恢复 dsh_save_panic_block(); // 6. 停机 for (;;) halt(); }这个细节很重要panic之后不是立刻停而是先把自己的状态保存到一个固定内存地址。DSH 里我预留了一个0x1000起始的 4KB 区域给 panic 状态块里面记录崩溃时间、CPU、RIP、RSP、通用寄存器数组、栈顶若干字节以及崩溃前最后 256 字节的日志环形缓冲。5.2 状态块的价值崩溃后还能继续查状态块的好处是即使系统触发了watchdog重启你也能在下次启动时通过控制台命令去读取上一轮的崩溃数据。比如DSH在启动早期会检查这个状态块如果发现有记录的panic数据就在串口打出来[ 0.002011] W [cpu0] recovered panic block from previous boot [ 0.002015] W [cpu0] reason: page fault in pmm_merge [ 0.002016] W [cpu0] rip: 0xffff8000001002e4 [ 0.002017] W [cpu0] rsp: 0xffff80001f7ff630这就等于给了你一次“事后验尸”的机会而且不需要接仿真器或抓核心转储。对于教学性内核和自制内核来说简单可靠比精致优雅重要得多。5.3 和 QEMU/GDB 接驳的调试链路除了自带状态快照DSH也保留了QEMU加GDB这个标准调试通道。我的做法是用qemu-system-x86_64 -s -S启动在项目目录放一个.gdbinit脚本把关键符号加载进来然后配合串口日志和命令控制台一起用。实际使用中我总结出一个组合套路先让系统裸跑到崩溃点由 panic handler 抓现场如果现场不够再用 QEMU 的-s重新启动提前在可疑函数打断点最后用串口日志和控制台命令印证GDB看到的寄存器值和内存状态。三者互相交叉排查效率非常高。5.4 panic handler 我踩过的两个坑第一个坑是寄存器打印函数本身崩了。一开始我的dsh_print_registers里调用了一个相对复杂的格式化函数结果在栈已经损坏的情况下打印过程中又触发了一次异常直接死锁。后来我把寄存器打印改成“只依赖已保存的寄存器值不碰栈不做复杂格式化”才保证在极端情况下依然能输出。第二个坑是状态块被后续启动覆盖。第一次做状态块时我让早期启动代码无条件清零0x1000这块区域结果panic数据永远只能在串口上看到一条提示就没了。正确做法是启动早期先读取状态块并打印确认复现完成后再提供给用户一个清除命令。6. 后续功能排序与我的经验习惯工具系统的四个模块做完之后DSH 的开发体验有了质的提升。现在每次进入新功能开发我都会先把“这一功能冒什么日志、报什么错误、用什么命令查看状态”这三件事想清楚再开始写业务代码。这几乎已经成了我的习惯代码还没跑观测路径先设计好。后面的功能我的优先级排序是这样的第一优先级是把日志系统接入统一的内核配置文件让每个子系统能单独控制自己的日志开关第二优先级是给控制台加历史命令回显和Tab补全虽然这对功能性帮助不大但能显著提升使用舒适度第三优先级是把 panic 状态块里的栈回溯做得更稳健尽量从栈里还原出函数名和偏移量。我个人对工具系统最大的体会是它是一个“越早做越好”的模块千万别等项目大了再回头补。补工具的难度不在于代码本身而在于你已经习惯了“盲开盲跑”等到问题积累到无法靠猜解决时改造成本就非常高昂了。如果你现在也在做自制内核我建议从今天这篇的环形日志缓冲区和控制台命令表开始先把最基础的两块落地。不用一次做完哪怕只是加一个能看内存的命令下次你再遇到神秘问题都会觉得手里有家伙了。之后我们再聊DSH下一块内容的时候这套工具就是我们的地基。 
长河君 · 2026/10/8 15:47:33 · 阅读 1.2k 基于自研内核工具系统：日志、控制台与panic快照实战
1. 工具系统在自研内核中的位置不想当调试器的内核不是好内核1.1 为什么走到第五篇必须补工具系统前四篇我们把DSH内核从引导区一路做到了页表、物理内存管理和任务调度能跑起来也能看到串口输出。但说实话到了这个阶段我最大的感受不是“功能太少”而是“什么都看不见”。程序能跑是能跑内存分配对不对、页表映射有没有缺项、调度器切换那一刻CPU状态是否完整全靠猜。猜一次两次还行等到中断一多、任务一切换肉眼排查基本失效。工具系统就是在这样一个节点上被逼出来的。它不是什么锦上添花的加分项而是开发效率的分水岭——哪怕你的内核只有几百行代码只要你想继续往上加文件系统、用户态、驱动模型就必须先有一双能看到“内部状态”的眼睛。我甚至愿意这么说一个没有工具系统的内核不是一个可以持续前进的项目而是一次性演示代码。这篇就顺着DSH内核的实际情况把工具系统拆成四块来讲内核日志、控制台命令、内存与页表诊断、panic现场快照。每一块我都会给出设计思路和核心实现也会把我在调试过程中遇到的真问题放进来尤其是那些“网上教程不会写、文档里查不到”的细节。1.2 一个内核工具系统至少该有的四块我最初的想法很简单能打印日志就够了。后来发现不够因为日志只能回答“发生了什么”回答不了“现在内部状态是什么样的”。所以我把工具系统拆成了四个相互独立、但又彼此衔接的模块模块作用典型使用场景依赖基础日志子系统按级别记录内核运行过程写入环形缓冲区并输出到串口启动流程追踪、中断异常定位串口驱动、时间信息控制台命令通过命令行交互查看内核运行状态运行时查内存、查进程、查映射串口输入输出、命令表内存与页表诊断直接读取虚拟地址内容解析多级页表结构排查缺页异常、非法访问、映射错误页表基址、MMU相关寄存器panic现场快照在崩溃时保存寄存器、栈指针和关键数据结构系统死机后定位崩溃点异常处理入口、状态块存储这四块不是拍脑袋定的而是我在DSH从“能启动”到“能跑多任务”过程中真实遇到过的需求。没有日志子系统启动到哪一步挂了你都不知道没有控制台命令你只能一遍遍往代码里塞临时打印没有页表诊断虚拟内存这块基本等于盲飞没有panic快照内核一崩溃就只能靠串口最后几行字猜原因。1.3 一句话说清楚这篇的路线这篇不会讲特别花哨的设计而是尽量贴近“你手里已经有一个能跑的内核现在要往里加工具”的实际场景。代码我会直接贴关键部分虽然语法和命名会贴近DSH目前的状态但你完全可以移植到自己的项目里。无论你是刚跑通一个最小内核还是已经做到进程调度工具系统的这四块都能直接落地。2. 内核日志子系统环形缓冲区的设计细节2.1 分级日志至少区分 DEBUG 与 ERROR很多初学者写内核日志就是一个kprintf从头用到尾。这在最初几周没问题但等到你要定位一个“启动到某一步就重启”的问题时满屏信息反而等于没有信息。我给DSH做日志分级的时候参考了Linux的log level思路但精简成了六个级别enum dsh_log_level { L_TRACE 0, // 极细粒度跟踪平时关闭 L_DEBUG 1, // 调试信息开发期打开 L_INFO 2, // 正常流程里程碑 L_WARN 3, // 不致命但可疑 L_ERROR 4, // 可恢复的错误 L_PANIC 5, // 致命错误 }; static uint32_t dsh_log_mask 0x03; // 默认只输出 INFO / WARN / ERROR / PANIC分级的作用不只是“控制打印量”更关键的是让你能在不同场景下切换信息粒度。比如启动阶段我只关心INFO排查一个内存分配问题的时候我打开DEBUG追踪某个驱动状态机的时候我才打开TRACE。这样就不需要来回改代码加编译开关运行期用命令设置mask即可。我强烈建议你把日志级别做成一个运行时可配置的位掩码而不是编译期宏开关。编译期开关的问题是一旦某个分支被裁剪后续想不开机不改代码就不可能了。DSH目前的做法是控制台命令里加了一个loglevel指令直接写dsh_log_mask。2.2 环形缓冲区实现思路和 ISR 安全日志一定要有两份去路一份实时输出到串口一份写进内核内存里的环形缓冲区。实时输出让你盯着启动过程看环形缓冲区则保证你回头看“刚才那几十行”时不会被串口速度拖累也不会因为当前屏幕滚动而丢失。环形缓冲区的核心结构很简单#define LOG_BUF_SIZE (64 * 1024) static char log_buf[LOG_BUF_SIZE]; static volatile uint32_t log_head; // 写位置 static uint32_t log_tail; // 读位置也是最早有效数据的起点 void dsh_log_write(enum dsh_log_level level, const char *fmt, ...) { char tmp[256]; va_list ap; int len; uint32_t flags; uint32_t head, tail, used; // 1. 先按级别过滤 if (!(dsh_log_mask (1u level))) return; // 2. 格式化成临时缓冲区 va_start(ap, fmt); len vsnprintf(tmp, sizeof(tmp), fmt, ap); va_end(ap); if (len 0) return; // 3. 中断保护防止写日志时被打断导致环形缓冲区错乱 local_irq_save(flags); head log_head; tail log_tail; used (head - tail) % LOG_BUF_SIZE; // 4. 如果剩余空间不够就把最老的丢出去 while (used (uint32_t)len LOG_BUF_SIZE) { // 丢弃最前面的一条日志这里简化为整段覆盖 tail (tail 16) % LOG_BUF_SIZE; // 伪代码实际需要解析换行 used (head - tail) % LOG_BUF_SIZE; } // 5. 写入环形区 for (int i 0; i len; i) log_buf[(head i) % LOG_BUF_SIZE] tmp[i]; log_head (head len) % LOG_BUF_SIZE; // 6. 同时输出串口 dsh_uart_write_bytes(tmp, len); local_irq_restore(flags); }上面代码里我刻意保留了“丢弃最老日志”的简化处理实际项目里你要做的是按行丢弃也就是从tail开始往后扫描换行符把一整个完整日志行丢出去而不是按固定字节数覆盖。否则你就可能看到半行日志既难看又容易误判时间顺序。ISR安全这一点很多人会忽视。中断处理函数里也可能要打日志比如记录某次异常发生的时刻。如果日志写入过程中又来了一个相同优先级的中断或者主流程和中断同时写head和tail就会错乱。所以我在写路径上做了local_irq_save/restore。读路径也就是上串口输出的时候通常发生在主流程不会被自己打断但为了保险读的时候也建议关一下中断。2.3 和 dmesg 对齐的日志条目格式日志不能只存字符串否则时间顺序、级别、来源都靠肉眼认。我参考了Linux dmesg的做法给每条日志加一个统一的头[ 0.123456] I [cpu0] pmm: free pages: 524288 [ 0.123512] D [cpu1] pmm: init zone: 0x100000 - 0x200000构成拆开就是字段含义为什么重要[ 0.123456]内核启动后的时间戳判断卡死前最后执行到的时间点I日志级别缩写快速筛选[cpu0]哪个CPU打的日志多核环境下定位交互问题pmm:子系统标签知道这条日志来自内存管理还是进程调度free pages: 524288正文核心信息时间戳我用的是启动后的单调时钟单位是微秒配合一个启动以来累计的tick计数器换算。不要直接用rdtsc那种原始周期数除非你周期频率在运行期已经算好了不然数值一会儿大一会儿小特别难读。子系统标签也是我后来加上的。早期日志是“裸奔”的一条一条全是文字。等代码量冲到几千行光靠 grep 根本没法定位。加了标签之后我可以直接在控制台层按标签过滤比如只看pmm:开头的日志这比全文搜可靠得多。2.4 日志层我踩过的三个坑第一个坑是双核打印交错。DSH 跑到 SMP 初始化之后两个 CPU 同时打日志串口上经常出现一句话插入到另一句话中间的画面。这不是串口问题也不是日志缓冲区问题而是“分两步输出”导致的先输出前半段、然后被打断输出别的、最后再补后半段。解决方法是最终输出到串口时把一整条日志先完整塞进一个中等大小的静态缓冲区然后一次性调用串口写入。宁可让其他 CPU 等也不能让半条日志上串口。第二个坑是时间戳溢出。DSH 的 tick 是纳秒累加的一开始我用 32 位变量保存微秒数跑了几十分钟就溢出。日志一旦时间错乱排查基本就废了。后来果断把时间戳累加器换成 64 位并且每次打印都做掩码归一化确保日志头里显示的是相对启动的有效时间。第三个坑是串口省流变身丢字。115200 波特率下一秒钟理论上能传大约 11KB 字符。如果日志在极短时间内爆发比如某次循环里打了上千条调试信息串口会瞬间成为瓶颈。日志写入环形缓冲区是纳秒级别完成的但串口输出是毫秒级别的。我在 UART 驱动里加了一个 TX FIFO 等待逻辑并在日志子系统里做了一个简单限速如果连续打印间隔小于某个阈值就把后续日志只写环形缓冲区不再同步输出串口。这样你事后用dmesg命令能查到全量串口上也只看到有效信息。3. 控制台命令系统把内核变成可交互的诊断台3.1 命令表驱动架构注册即生效控制台命令系统是我最喜欢的部分因为它让内核从一个“只会往串口吐字的哑巴”变成了一个“能听指令的交互终端”。设计上我沿用了嵌入式领域非常成熟的命令表模式struct cmd_entry { const char *name; const char *usage; int (*handler)(int argc, char **argv); }; static struct cmd_entry dsh_cmd_table[] { { help, help [cmd], cmd_help }, { dmesg, dmesg [lines], cmd_dmesg }, { mem, mem addr [len], cmd_mem }, { map, map vaddr, cmd_map }, { task, task, cmd_task }, { stat, stat, cmd_stat }, { panic, panic, cmd_panic }, { loglevel,loglevel mask, cmd_loglevel}, { NULL, NULL, NULL } };命令行输入的解析我自己写了个很轻量的实现按空格拆分成argc/argv然后线性扫命令表做字符串匹配。对内核来说完全不值得为此引入一个什么现成的命令行解析库。DSH 目前没有把控制台放到独立线程里而是直接在串口中断里积累字符等回车之后在主循环里执行命令。原因很简单串口中断里执行命令本身风险很大万一某个 handler 里做内存分配导致重入那就真是自己给自己挖坑。命令 handler 的签名统一成int (*)(int argc, char **argv)返回 0 表示成功非零表示用法错误。这样 help 功能和错误提示可以直接复用。3.2 核心命令的实际价值不只是“摆弄着玩”命令是否值得加我只有一个标准它能不能在真实排障中帮上忙。以下是我在DSH里保留的命令和它们对应的真实故障场景命令输出内容我遇到的实际用处dmesg环形缓冲区里的日志串口刷屏后回看关键记录mem addr [len]指定虚拟地址的内存内容检查结构体是否初始化、链表节点是否损坏map vaddr虚拟地址对应的页表层级与物理页缺页异常时确认映射是否存在task所有进程/任务的状态、栈顶、优先级调度卡死时看是哪个任务在跑statCPU 使用率、内存总量/空闲判断是不是内存耗尽导致分配失败panic主动触发崩溃测试 panic handler 和现场快照loglevel修改日志输出掩码打开/关闭调试级别输出以mem为例它的意义在于你可以在任意时刻直接看某个地址的内存而不是在代码里写死打印结构体字段。比如遇到一个定时器队列节点行为异常输入mem 0xffff800001234560 128就能看到里面到底装了什么哪些字节像指针、哪些字节是垃圾。这个能力在调试链表、红黑树这类结构时尤其救命。map命令则是虚拟内存调试的关键。DSH 用的是 x86-64 的四级页表刚开始实现的时候我经常在map命令里直接输入一个虚拟地址看它经过 Pgd/Pud/Pmd/Pte 四层之后到底映射到了哪个物理页页的权限位和存在位对不对。这个命令做得越直观你对虚拟内存的掌控感越强。3.3 控制台命令的边界与安全性控制台命令是运行在内核态的稍不留神一条命令就能把系统打崩。我归纳出几条必须遵守的边界规则第一参数解析必须防越界。输入一个大得离谱的长度比如mem 0x1000 0xffffffff你不可能真的去读几十GB内存。我在cmd_mem里强制限制单次最多打印 512 字节超出就截断。第二handler 里禁止做睡眠或长时间阻塞。因为命令执行在主循环里如果某个 handler 死等一个永远不会出现的事件整个控制台就永久卡死。像stat这种需要遍历进程链表的命令我会先加一个循环计数上限兼带防止链表出现环。第三命令输出不要和日志子系统抢同一个临时缓冲区。最开始我把命令输出直接塞进dsh_log_write结果就是命令结果和系统日志混在一堆毫无可读性。现在命令输出走独立的cmd_printf直接到串口。4. 工具系统实战一起“启动即卡死”排障全流程4.1 现象内核跑到某一步突然不动了这套工具系统刚建好的时候我正好撞上一个DSH的回归问题某次改动之后内核启动到pmm_init的第三个 zone 就彻底卡住串口上最后一条日志是[ 0.118423] I [cpu0] pmm: init zone 2, base0x40000000, pages262144之后什么都没有。看起来像死循环也可能是CPU异常后进入了某个空的中断处理函数。在没有工具系统之前我多半会往pmm_init前后加十几行打印然后重新编译烧录来回折腾。这次我决定换个玩法完全依靠已有的日志、map、mem 和 panic handler 来做一次全流程定位。4.2 第一轮定位用日志粒度找“最后一口气”我先打开loglevel 0x3f把 TRACE 和 DEBUG 都打开重新启动。这次日志变得密密麻麻但最后的关键信息变成了[ 0.118430] D [cpu0] pmm: zone2 bitmap allocated at 0xffff800011000000 [ 0.118435] D [cpu0] pmm: zone2 bitmap primary set [ 0.118440] D [cpu0] pmm: zone2 buddy merge start问题缩小了一点不是死循环也不是CPU异常而是死在buddy merge这一步。再往下跟发现它是在一次对某个物理页结构的访问中卡住的。这种“卡住”通常指向一个无效地址要么是页表映射不存在要么是物理页管理结构里有坏数据。4.3 第二轮定位map 与 mem 直接看现场这个物理页结构体的虚拟地址已经由日志打出来了我直接在控制台输入ds map 0xffff800012345000这时候 DS 输出vaddr 0xffff800012345000 PGD: 0xffffff8000000000 - entry 0x0000000880000063 PUD: 0xffffff8000037000 - entry 0x0000000880100063 PMD: 0xffffff8000036000 - entry 0x0000000880200063 PTE: 0xffffff8000035000 - entry 0x0000000000000000 (not present)缺页。也就是说物理页管理结构所在的虚拟地址根本没有被映射。再用mem检查相邻区域发现 PTE 区域里全是零。到这里根因已经比较明显pmm_init在初始化新 zone 的时候只给新页管理结构的头部区块建立了映射没有把整个 buddy 数组所在的连续虚拟区域完整映射。后面的代码一直用未映射的虚拟地址做读改写自然就卡住。4.4 修复与验证工具系统带来的排查链路优势修复方式很简单在pmm_init的 zone2 初始化之前把该区域所需的虚拟地址范围统一调用dsh_vmm_map_contiguous映射好然后把初始化和合并代码放回到映射建立之后再执行。重新编译启动这次日志一路顺利往下走[ 0.125621] I [cpu0] pmm: all zones initialized [ 0.125630] I [cpu0] sched: idle task created [ 0.125635] I [cpu0] sched: smp boot cpu online这次排障前后只用了不到半小时相比以前靠猜和临时打印的方式快很多。关键不在于某个命令多神奇而在于整个链路是通的日志告诉你症状map 告诉你映射mem 告诉你数据panic handler 还能在你来不及输入命令时替你抓住现场。这套链路一旦建立后续任何内核改动都敢放手去做了。4.5 顺带说一句这类日志喂给AI工具也有讲究现在很多人喜欢拿系统日志直接丢给AI工具做分析我在这次排障里也试过类似做法。我的体会是工具分析的价值高度依赖日志本身的质量。如果日志没有时间戳、没有级别、没有子系统标签AI工具再强也只能从一团乱麻里瞎猜。DSH日志系统把这些结构化字段做齐了之后我确实可以直接截取一段启动日志让人工智能辅助判断可能的挂起点。但最终的现场确认还是得靠map、mem这些内核层工具因为AI看不到你寄存器里的值也管不了页表映射。5. Panic Handler 与自动状态快照把故障现场留给下一次启动5.1 panic 路径不仅要打日志还要留下现场内核开发到后期最怕的不是看不到日志而是系统直接崩溃重启。硬件watchdog一触发UART缓冲区和内存里的日志全没了留给你的只有“刚才好像崩溃了”这个事实。DSH的panic handler从一开始的“打印一行字再死”升级成了现在的“打印全套现场再死”void dsh_panic(const char *reason, uintptr_t rip, uintptr_t rsp) { // 关中断防止处理过程中被再次打断 local_irq_disable(); // 1. 报告崩溃原因 dsh_log_write(L_PANIC, KERNEL PANIC: %s, reason); // 2. 打印通用寄存器快照 dsh_print_registers(); // 3. 打印当前CPU号、栈指针、指令指针 dsh_log_write(L_PANIC, cpu%d rip0x%lx rsp0x%lx, dsh_get_cpu_id(), rip, rsp); // 4. 尝试展开调用栈如果栈布局完整 dsh_backtrace(); // 5. 保存状态块到固定地址供下电前读取或下次启动恢复 dsh_save_panic_block(); // 6. 停机 for (;;) halt(); }这个细节很重要panic之后不是立刻停而是先把自己的状态保存到一个固定内存地址。DSH 里我预留了一个0x1000起始的 4KB 区域给 panic 状态块里面记录崩溃时间、CPU、RIP、RSP、通用寄存器数组、栈顶若干字节以及崩溃前最后 256 字节的日志环形缓冲。5.2 状态块的价值崩溃后还能继续查状态块的好处是即使系统触发了watchdog重启你也能在下次启动时通过控制台命令去读取上一轮的崩溃数据。比如DSH在启动早期会检查这个状态块如果发现有记录的panic数据就在串口打出来[ 0.002011] W [cpu0] recovered panic block from previous boot [ 0.002015] W [cpu0] reason: page fault in pmm_merge [ 0.002016] W [cpu0] rip: 0xffff8000001002e4 [ 0.002017] W [cpu0] rsp: 0xffff80001f7ff630这就等于给了你一次“事后验尸”的机会而且不需要接仿真器或抓核心转储。对于教学性内核和自制内核来说简单可靠比精致优雅重要得多。5.3 和 QEMU/GDB 接驳的调试链路除了自带状态快照DSH也保留了QEMU加GDB这个标准调试通道。我的做法是用qemu-system-x86_64 -s -S启动在项目目录放一个.gdbinit脚本把关键符号加载进来然后配合串口日志和命令控制台一起用。实际使用中我总结出一个组合套路先让系统裸跑到崩溃点由 panic handler 抓现场如果现场不够再用 QEMU 的-s重新启动提前在可疑函数打断点最后用串口日志和控制台命令印证GDB看到的寄存器值和内存状态。三者互相交叉排查效率非常高。5.4 panic handler 我踩过的两个坑第一个坑是寄存器打印函数本身崩了。一开始我的dsh_print_registers里调用了一个相对复杂的格式化函数结果在栈已经损坏的情况下打印过程中又触发了一次异常直接死锁。后来我把寄存器打印改成“只依赖已保存的寄存器值不碰栈不做复杂格式化”才保证在极端情况下依然能输出。第二个坑是状态块被后续启动覆盖。第一次做状态块时我让早期启动代码无条件清零0x1000这块区域结果panic数据永远只能在串口上看到一条提示就没了。正确做法是启动早期先读取状态块并打印确认复现完成后再提供给用户一个清除命令。6. 后续功能排序与我的经验习惯工具系统的四个模块做完之后DSH 的开发体验有了质的提升。现在每次进入新功能开发我都会先把“这一功能冒什么日志、报什么错误、用什么命令查看状态”这三件事想清楚再开始写业务代码。这几乎已经成了我的习惯代码还没跑观测路径先设计好。后面的功能我的优先级排序是这样的第一优先级是把日志系统接入统一的内核配置文件让每个子系统能单独控制自己的日志开关第二优先级是给控制台加历史命令回显和Tab补全虽然这对功能性帮助不大但能显著提升使用舒适度第三优先级是把 panic 状态块里的栈回溯做得更稳健尽量从栈里还原出函数名和偏移量。我个人对工具系统最大的体会是它是一个“越早做越好”的模块千万别等项目大了再回头补。补工具的难度不在于代码本身而在于你已经习惯了“盲开盲跑”等到问题积累到无法靠猜解决时改造成本就非常高昂了。如果你现在也在做自制内核我建议从今天这篇的环形日志缓冲区和控制台命令表开始先把最基础的两块落地。不用一次做完哪怕只是加一个能看内存的命令下次你再遇到神秘问题都会觉得手里有家伙了。之后我们再聊DSH下一块内容的时候这套工具就是我们的地基。