7.6 利用控制台设备捕获中断上下文中的崩溃日志
上一节我们给手里的工具箱又加了几件利器——从栈空间检查到源码定位脚本。你可能会觉得,有了这些,哪怕内核崩溃我也能把它按在地上摩擦。
先别太自信。
之前的测试环境其实有点「温室」的味道:不管是直接 insmod 触发,还是通过工作队列触发,我们的 Oops 都发生在进程上下文里。这意味着什么呢?意味着内核还有机会「体面地」报错,把堆栈信息打印到屏幕上,甚至可能还能让你再敲几条命令。
但在真实世界里,很多棘手的崩溃发生在一个更加危险的地方——中断上下文。
那里没有进程可以责怪,没有退路,而且——如果运气不好——连屏幕输出都会被吞没。
这一节,我们要把场景推向极端:在硬中断处理函数里亲手制造一个崩溃,然后看看当系统死机、键盘失灵、连 dmesg 都敲不出来的时候,我们该如何拿到那个救命的诊断日志。
暴走的中断上下文
我们准备了一个新的测试模块 oops_inirqv3。它的逻辑很简单粗暴:利用内核的 irq_work 机制,把一个函数注册到中断上下文中去执行。
这里简单回顾一下(我们在上一章内存泄漏测试里用过类似的技术):irq_work 是一种特殊的异步执行机制,它保证回调函数会在中断上下文(通常是硬中断)里被执行。
来看代码:
// ch7/oops_inirqv3/oops_inirqv3.c
void irq_work(struct irq_work *irqwk)
{
int want_oops = 1;
PRINT_CTX(); // 打印当前上下文信息,让我们确信它在 IRQ 里
if (!!want_oops) // 好了,让我们在中断里制造个事故
// 这一行可能导致致命死锁!
*(int *)0x100 = 'x';
}
注意那个注释。我们手动往 0x100 这个地址写数据。这显然是一个非法操作(位于 NULL 陷阱页内),会触发页面异常。
现在,在你的虚拟机里加载这个模块:
cd <...>/ch7/oops_inirqv3
make
sudo insmod ./oops_inirqv3.ko
在我的测试环境里(VirtualBox 6.1 + Ubuntu 20.04 Guest + 5.10.60 内核),回车键按下去之后,发生了一件令人绝望的事:
什么都没发生。
不是那种「打印了一堆报错然后卡住」,而是屏幕直接黑屏,或者光标彻底不动了。没有 Oops 信息,没有 Kernel panic 提示,甚至连 Caps Lock 键的灯都不闪烁了。
系统彻底死给你看了。
现在怎么办?dmesg?敲不出来的。重启?日志全丢。
这时候,作为工程师,你的直觉会告诉你:内核肯定想说话,但它想说的话没能传到显示器上。 我们需要另一条通道,一条不依赖显卡驱动的通道,把内核的遗言偷偷运出来。
绕道而行:虚拟串口控制台
欢迎来到真实世界。
解决这个问题的思路非常经典,虽然我们这里的操作是针对 VirtualBox 这种虚拟化环境的,但它的思想适用于几乎所有嵌入式开发板和服务器:
既然图形界面(显示器)这路断了,我们就用串口这路把日志「走私」出来。
我们要做的,是在客户机和宿主机之间建立一根「虚拟网线」——一个虚拟串口。内核会把所有 printk 的信息同时写到这个串口里,而串口的另一端,连着你宿主机上的一个普通文本文件。
第一步:配置宿主机端的虚拟串口
如果虚拟机还在跑,先把它关机。
打开 Oracle VirtualBox 的管理界面,选中你的虚拟机,点「设置」齿轮图标。
- 在左侧菜单找到 「串口」。
- 勾选 「启用端口 1」。
- 端口模式:选择 「Raw File」(原始文件)。这意味着数据会被直接写入一个文件,而不是别的网络流或物理设备。
- 路径/地址:填入你宿主机上的一个文件路径。比如我的 Linux 宿主机上,我填的是
/home/user/console_lkd.txt。
配置好大概是这个样子(见书中图 7.21)。点 OK 保存。
第二步:告诉内核使用这个控制台
现在启动虚拟机。但在内核真正跑起来之前,我们需要劫持一下启动参数。
- 启动时狂按
Shift键,打断 GRUB 引导过程,进入菜单。 - 找到 「Advanced options for Ubuntu」,选里面那个我们要测试的自定义内核(5.10.60-prod01)。
- 按
e键编辑启动项。 - 找到以
linux /boot/vmlinuz-...开头的那一行。
这就是我们要动手脚的地方。把光标移到这一行的末尾,加上这一串参数:
console=ttyS0 console=tty0 ignore_loglevel
这里的 ttyS0 就是我们的串口设备。console=ttyS0 告诉内核「把控制台输出重定向到串口」,console=tty0 保留屏幕输出。ignore_loglevel 则是那句老话:「把所有东西都吐出来,别管什么日志级别了,我全都要」。
改完之后,按 Ctrl + X 启动系统。
验证通道与捕获崩溃
进入系统后,先别急着加载模块。我们得先确认这条「走私通道」是通的。
验证串口输出
在虚拟机里,以 root 身份执行这句:
# echo "testing serial console 1 2 3" > /dev/kmsg
这一刻,神奇的事情发生了。
切换到你的宿主机,打开你刚才指定的那个日志文件(比如 ~/console_lkd.txt)。你应该能看到刚才那行字已经躺在里面了:
$ tail -n1 ~/console_lkd.txt
[ 646.403129] testing serial console 1 2 3
通道通了。现在,即使前方是万丈深渊,我们也有一根安全绳了。
再次触发崩溃
回到虚拟机,再次加载那个狠心模块:
cd <...>/ch7/oops_inirqv3
sudo insmod ./oops_inirqv3.ko
正如预期的那样,虚拟机瞬间僵住,界面死锁。
别管它了。回到宿主机,打开那个日志文件。
胜利时刻
虽然虚拟机的屏幕像死了一样漆黑一片,但在宿主机的文本文件里,内核已经把它想说的话全都说清楚了(见书中图 7.23)。
你会看到完整的 Oops 堆栈信息,清晰得令人感动。
深入诊断:中断上下文的堆栈指纹
拿到日志只是第一步,接下来是侦探时间。
仔细看这次的 Oops 输出,它和之前在进程上下文里触发的崩溃有几个非常关键的区别。
1. RIP 指针的指向
RIP: 0010:irq_work+0x18/0x20 [oops_inirqv3]
RIP 直接指向了我们的 irq_work 函数。这证实了崩溃确实发生在我们设定的中断回调里。
2. 双重堆栈
这是最精彩的部分。你会发现这次的 Call Trace(调用栈)被分成了两截,中间有一个明显的标记:
<IRQ>
irq_work+0x18/0x20 [oops_inirqv3]
...
</IRQ>
...
在 x86_64 这种现代架构上,中断处理是使用独立的中断栈的。
... :这段区域记录的是中断发生时的执行路径。它是从中断入口开始的,这就是irq_work所在的地方。- 下方部分:这是被中断打断的进程原本的堆栈。
我们以自底向上的顺序读这个堆栈。你会发现,内核原本正在执行某个进程的任务(可能是 insmod,也可能是 idle 线程),然后突然被打断,切入了中断栈,执行了我们的代码,然后——啪,挂了。
3. 真正的「凶手」是谁?
注意 Oops 输出里的这一行:
CPU: 1 PID: 1699 Comm: insmod Tainted: G OE 5.10.60-prod01 #6
这里的 PID 是 1699,进程名是 insmod。
如果你的直觉是「啊,是 insmod 进程搞坏了内核」,那你在这个特定的案例里就错了。
还记得我们在上一章说的吗?在中断上下文里,current 宏指向的是倒霉蛋——也就是恰好当时正在跑的那个进程。它只是一个无辜的路人,被我们的硬中断「骑脸」了。代码虽然是它触发的(insmod 导致模块加载,进而注册了 irq_work),但执行崩溃指令的那一刻,CPU 其实是在替 irq_work 卖命,而不是替 insmod。
这也解释了为什么有时候你在 Oops 日志里看到的进程是 swapper(PID 0,也就是 idle 线程)。那是 CPU 正在发呆呢,突然来了个中断把 CPU 拉起来干活,结果活儿没干好,把 CPU 干崩了。swapper 纯属背锅。
4. 系统为什么会死机?
日志的最后,通常会有一行这样的提示:
Kernel panic - not syncing: Fatal exception in interrupt
这就解释了为什么你的键盘会彻底失灵。内核发现——「糟糕,我在处理中断的时候崩了,这属于不可恢复的错误,为了保证数据安全,我还是自尽吧。」于是它触发了 panic,系统停止一切调度。
写在最后与预告
这种利用串口控制台「导出」日志的方法,是嵌入式开发者和内核工程师的必修课。
而在物理机上,这种思路演变成了一种更灵活的网络工具——netconsole。它不需要物理串口线,而是通过 UDP 包把内核日志广播到局域网里的另一台机器上。
下一节,我们将把战场从 x86 虚拟机迁移到一台真正的 ARM 设备(树莓派)上,去看看异构架构下的 Oops 是什么样的,以及如何用 netconsole 这种「无线调试」手段来搞定它。