3、内核日志分析:dmesg命令、kernel log级别、驱动调试信息、死机分析

内核日志,说白了就是Linux内核的“黑匣子”。系统跑着跑着突然挂了,或者某个驱动死活不干活,第一件事就是翻内核日志。我个人习惯,只要遇到系统异常,二话不说先敲dmesg。这玩意儿比什么调试器都来得快。

3.1 dmesg命令:内核日志的入口

dmesg命令用来读取内核的环形缓冲区(ring buffer)。内核启动时的所有信息、驱动加载的log、硬件报错,全在这里。

基本用法:

# 查看全部内核日志
dmesg

# 实时监控内核日志(类似tail -f)
dmesg -w

# 只看最后20条
dmesg | tail -20

# 清空缓冲区(调试时常用)
dmesg -c

我在项目中遇到过一个问题:某款手机待机一晚后自动重启。查了所有应用层日志都没线索。最后用dmesg一看,发现是某个传感器驱动在深度睡眠时触发了看门狗复位。嗯,这种问题应用层根本看不到。

小技巧:dmesg -T 可以把时间戳转成人类可读的时间格式。默认是秒数,看着头疼。

3.2 Kernel Log级别:日志的“红绿灯”

内核日志有8个级别,从0到7。数字越小越紧急。你想想看,如果所有日志都打印出来,那屏幕根本刷不完。所以内核用级别来控制哪些日志能出来。

级别 名称 含义 典型场景
0 KERN_EMERG 系统不可用 内核崩溃、致命错误
1 KERN_ALERT 必须立即处理 严重硬件故障
2 KERN_CRIT 临界条件 驱动加载失败
3 KERN_ERR 错误 I/O错误、内存分配失败
4 KERN_WARNING 警告 资源不足、配置异常
5 KERN_NOTICE 正常但重要 驱动初始化完成
6 KERN_INFO 信息 版本号、硬件信息
7 KERN_DEBUG 调试信息 开发阶段使用

我建议你在调试驱动时,把printk的级别设为KERN_ERRKERN_WARNING。别一上来就KERN_DEBUG,否则生产环境里日志刷爆了,用户会骂娘的。

注意: 内核日志的打印级别可以通过 /proc/sys/kernel/printk 控制。默认是 4 4 1 7,分别代表:控制台日志级别、默认消息日志级别、最小控制台日志级别、默认控制台日志级别。改这个文件要小心,我曾经改完后控制台啥日志都不出了,排查了半天才发现是自己手滑。

3.3 驱动调试信息:printk的艺术

驱动开发最常用的调试手段就是printk。别看它简单,用好了能解决大问题。

基本用法:

#include <linux/kernel.h>
#include <linux/printk.h>

printk(KERN_ERR "my_driver: 初始化失败,错误码=%d\n", ret);
printk(KERN_INFO "my_driver: 设备注册成功,主设备号=%d\n", major);

我个人习惯在驱动里加一个调试开关:

#define MY_DRV_DEBUG

#ifdef MY_DRV_DEBUG
#define my_dbg(fmt, ...) \
    printk(KERN_DEBUG "my_drv: " fmt, ##__VA_ARGS__)
#else
#define my_dbg(fmt, ...) /* 空 */
#endif

这样调试时打开宏,发布时关掉。干净利落。

我曾经在调试一个USB摄像头驱动时,发现图像数据总是错位。折腾了两天,最后在printk里打印了每个DMA缓冲区的地址和长度,才发现是某个中断处理函数里把buffer指针搞乱了。说白了,printk就是驱动调试的“听诊器”。

3.4 死机分析:从dmesg里找线索

系统死机(kernel panic)是Android开发者的噩梦。但别慌,dmesg里通常有完整的“案发现场”。

典型的死机日志长这样:

[  123.456789] Kernel panic - not syncing: Fatal exception
[  123.456790] CPU: 2 PID: 1234 Comm: kworker/u16:5 Tainted: G        W
[  123.456791] Hardware name: Qualcomm Technologies, Inc. MSM8998
[  123.456792] Call trace:
[  123.456793]  [<ffffff800808c000>] dump_backtrace+0x0/0x1a0
[  123.456794]  [<ffffff800808c1a0>] show_stack+0x20/0x30
[  123.456795]  [<ffffff80082a0000>] dump_stack+0x90/0xb0
[  123.456796]  [<ffffff80080a0000>] panic+0x100/0x280
[  123.456797]  [<ffffff80080b0000>] die+0x50/0x60
[  123.456798]  [<ffffff80080c0000>] do_page_fault+0x200/0x300
[  123.456799]  [<ffffff80080d0000>] do_mem_abort+0x40/0x80

看死机日志,我一般三步走:

  1. 找panic原因:看第一行Kernel panic - not syncing后面的描述。常见的有Fatal exceptionOut of memoryUnable to handle kernel NULL pointer dereference
  2. 看调用栈:从Call trace开始,从下往上读。最下面的是触发点,最上面的是最终调用的函数。比如上面这个例子,do_mem_abort说明是内存访问异常。
  3. 查寄存器:如果日志里有PC(程序计数器)和LR(链接寄存器)的值,用addr2line工具翻译成源码行号。
核心思路: 死机分析不是靠猜的。dmesg里的每一行都有价值。我见过有人死机后直接重启,然后抱怨“又死机了”——其实日志就在那里,看一眼就能定位问题。

3.5 知识体系图

下面这张图总结了内核日志分析的核心脉络:

内核日志分析知识体系 内核日志分析 dmesg 命令 查看/监控/清空 Kernel Log 级别 (0-7) EMERG → DEBUG 驱动调试信息 printk / 调试宏 死机分析 (Kernel Panic) 找原因 → 看调用栈 → 查寄存器 入口 分类 方法 实战

3.6 实战:一次死机排查记录

我记得有一次,某款平板在播放视频时频繁死机。应用层日志啥都没有,但dmesg里留下了关键线索:

[  456.789012] Unable to handle kernel NULL pointer dereference at virtual address 00000010
[  456.789013] pgd = ffffffc0a1b00000
[  456.789014] [00000010] *pgd=0000000000000000
[  456.789015] Internal error: Oops: 96000004 [#1] PREEMPT SMP
[  456.789016] CPU: 3 PID: 5678 Comm: mediaserver Tainted: G        W
[  456.789017] PC is at msm_vidc_decoder_release+0x24/0x80 [msm_vidc]
[  456.789018] LR is at msm_vidc_decoder_release+0x20/0x80 [msm_vidc]

看到NULL pointer dereferencemsm_vidc_decoder_release,我立刻意识到是视频解码器在释放资源时访问了空指针。查代码发现,某个条件分支下没有初始化一个结构体指针,但释放函数却直接调用了它。

修复方法很简单:在释放前加个if (ptr)判断。但如果没有dmesg,这种问题可能要排查好几天。

我的经验: 遇到死机,先别急着重启。用串口或adb把dmesg日志抓下来。如果已经重启了,可以看/proc/last_kmsg(部分内核支持)或pstore目录下的文件。这些是上次死机时保存的“遗言”。

好了,内核日志分析就聊到这儿。说白了,dmesg就是内核的“朋友圈”,驱动干了什么、系统出了什么状况,全在上面。学会看它,你就能从系统层面理解很多奇怪的问题。