一个内核 Oops 问题的分析及解决
source link: https://os.51cto.com/article/708740.html
Go to the source link to view the article. You can view the picture content, updated content and better typesetting reading experience. If the link is broken, please click the button below to view the snapshot at that time.
一个内核 Oops 问题的分析及解决-51CTO.COM
最近在调试设备时，遇到了一个偶发的开机死机问题。通过查看输出日志，发现内核报告了oops错误，如下所示(中间省略了部分日志，以......代替)：
Unable to handle kernel NULL pointer dereference at virtual address 0000000c
pgd = cdd90000
[0000000c] *pgd=8df4d831, *pte=00000000, *ppte=00000000
Internal error: Oops: 17 [#1] SMP ARM
CPU: 0 PID: 206 Comm: mount Tainted: P O 3.18.20 #4
task: ced40e40 ti: cdf7c000 task.ti: cdf7c000
PC is at exfat_fill_super+0xc8/0x4cc [exfat]
LR is at exfat_fill_super+0x48/0x4cc [exfat]
pc : [<bf64b670>] lr : [<bf64b5f0>] psr: a0080013
sp : cdf7de48 ip : ffffffff fp : c0744a30
r10: 00000001 r9 : bf652dac r8 : 00008000
r7 : cdf80000 r6 : cf302000 r5 : cdf85000 r4 : cdf41000
r3 : 00000000 r2 : cdf85104 r1 : 00000003 r0 : 000001b5
Flags: NzCv IRQs on FIQs on Mode SVC_32 ISA ARM Segment user
Control: 10c5387d Table: 8dd9006a DAC: 00000015
SP: 0xcdf7ddc8:
ddc8 cfa70880 fffffffc 0000000b cf17f800 cf4ea000 cf17f600 00000000 cfdee780
dde8 bf64b670 a0080013 ffffffff cdf7de34 00008000 c0012e18 000001b5 00000003
......
Process mount (pid: 206, stack limit = 0xcdf7c238)
Stack: (0xcdf7de48 to 0xcdf7e000)
de40: 00000001 cdf41000 cdf7deb0 cf17f60c 00000001 00008000
de60: cdf41000 cdf7c038 c0744a30 c0264164 bf652db4 cdf7de84 3b9aca00 00000004
de80: cf4ea6c0 00000083 cf4ea734 cf302000 cf4ea6c0 00000083 00008000 cdf41000
......
dfc0: 01197040 01197040 be9fff49 00000015 be9fff31 00008000 00000000 00000000
dfe0: b6e3d2e0 be9ffaf8 0007ebec b6e3d2f0 60080010 be9fff49 00000000 00000000
[<bf64b670>] (exfat_fill_super [exfat]) from [<c00d12ec>] (mount_bdev+0x168/0x190)
[<c00d12ec>] (mount_bdev) from [<bf64b0ac>] (exfat_fs_mount+0x18/0x20 [exfat])
[<bf64b0ac>] (exfat_fs_mount [exfat]) from [<c00d1fd4>] (mount_fs+0x14/0xcc)
[<c00d1fd4>] (mount_fs) from [<c00ea480>] (vfs_kern_mount+0x4c/0x104)
[<c00ea480>] (vfs_kern_mount) from [<c00ed214>] (do_mount+0x194/0xb54)
[<c00ed214>] (do_mount) from [<c00edf1c>] (SyS_mount+0x74/0xa0)
[<c00edf1c>] (SyS_mount) from [<c000e4e0>] (ret_fast_syscall+0x0/0x38)
Code: e5851108 e3a01003 e593300c e5933308 (e1d330bc)从上述日志信息中，初步可以看出，在挂载exfat格式文件系统的存储卡时，内核出现了空指针访问问题，最终导致内核奔溃并输出oops。因为之前没有遇到过这个问题，且最近硬件更换了读卡器，存储卡也更新换代了，从之前的100MB/s换到了120MB/s，所以，最初怀疑问题可能是因为更换读卡器或(和)存储卡导致的。但是，硬件和卡的变更到底是如何影响并导致上述oops错误的，这其中的细节并不清楚。好在堆栈信息比较明确，异常时，PC指针指向了这个位置：exfat_fill_super+0xc8/0x4cc (PC is at exfat_fill_super+0xc8/0x4cc [exfat])。那我们就顺藤摸瓜，看看这个位置对应的代码是什么。
首先，在工程中搜索exfat_fill_super这个函数，了解其位置和关联模块。一番操作下来，发现这个函数在第三方开源库exfat中。这个库提供了exfat文件系统挂载的支持，并被编译为ko库文件，在系统启动时insmod到系统中。
其次，我们看看问题日志中，PC指针指向的代码具体是哪一行?因为日志中只提示在exfat_fill_super这个函数的0xc8偏移处，为了准确找到这个位置，我们需要借助gdb，如下所示：
(gdb) l exfat_fill_super
sb->s_d_op = &exfat_dentry_ops;
}
#endif
static int exfat_fill_super(struct super_block *sb, void *data, int silent)
{
struct inode *root_inode = NULL;
struct exfat_sb_info *sbi;
int debug, ret;
long error;
(gdb) l *exfat_fill_super+0xc8
0x9670 is at ./exfat-nofuse-master/exfat_super.c:2301.
int option;
char *iocharset;
opts->fs_uid = current_uid();
opts->fs_gid = current_gid();
opts->fs_fmask = opts->fs_dmask = current->fs->umask;
opts->allow_utime = (unsigned short) -1;
opts->codepage = exfat_default_codepage;
opts->iocharset = exfat_default_iocharset;
opts->casesensitive = 0;可以看到，gdb告诉我们，0xc8偏移在2301这一行(也告诉我们对应的汇编在0x9670处，后面会用到)：
2301 opts->fs_fmask = opts->fs_dmask = current->fs->umask;但是，比较烦人的是，这行代码是连续赋值，并且都使用到了指针，所以并不能一下就确定问题到底在那一个赋值上产生。不过，不着急，我们先看看这行代码做了什么。按照C语言的规则，连续赋值是从右到左执行，所以先执行的应该是：
opts->fs_dmask = current->fs->umask;执行这行代码时，需要先确定current->fs，再确定fs->umask，最后，将结果给opts->fs_dmask。所以，就这一处赋值而言，就有三个可能的疑点。
先看第一个current->fs。这里current是一个宏，用于获取当前线程的任务结构体(这里又隐藏一个指针)。
#define get_current() (current_thread_info()->task)
#define current get_current()对于当前arm平台，线程信息是通过堆栈寄存器获取的。
static inline struct thread_info *current_thread_info(void)
{
register unsigned long sp asm ("sp");
return (struct thread_info *)(sp & ~(THREAD_SIZE - 1));
}从上面代码，进一步的得知，线程信息是堆栈寄存器通过位运算获得的。这里的THREAD_SIZE定义如下：
#define THREAD_SIZE_ORDER 1
#define THREAD_SIZE (PAGE_SIZE << THREAD_SIZE_ORDER)这是一个跟页面大小相关的量。在当前系统中，PAGE_SIZE为4KB大小，所以THREAD_SIZE为8KB大小，也即0x2000，一共14位。减去1，就是1FFFF，取反就是0b’0000(第一个0占1bit，其余为4bit)，然后参与“与”运算。这一连串的运算，总结为一句话，就是将给定的栈指针地址的低13位与0进行与运算，即将栈指针低13位清零。
这就是说内核线程结构体是在当前栈8KB对齐的低地址处。这是内核在设计时故意安排的，可以提高查找效率。我们来看这个指针获取是否存在空指针访问的问题：
current_thread_info()->task回到最开始的日志中，部分信息如下：
task: ced40e40 ti: cdf7c000 task.ti: cdf7c000
PC is at exfat_fill_super+0xc8/0x4cc [exfat]
LR is at exfat_fill_super+0x48/0x4cc [exfat]
pc : [<bf64b670>] lr : [<bf64b5f0>] psr: a0080013
sp : cdf7de48 ip : ffffffff fp : c0744a30其中，sp在cdf7de48，所以thread_info的位置应该是cdf7c000，从上面的日志中也可以看到ti是cdf7c000，所以这个位置不会是空指针的位置。
这里的task是thread_info结构体的一个子域，如下：
struct thread_info {
unsigned long flags; /* low level flags */
int preempt_count; /* 0 => preemptable, <0 => bug */
mm_segment_t addr_limit; /* address limit */
struct task_struct *task; /* main task structure */
struct exec_domain *exec_domain; /* execution domain */那么，task有没有可能是一个空指针呢?上面oosp的日志也给出了，task: ced40e40，所以，task也不为空。
这样，current就指代了这里的task，一个不为空的地址。所以我们再看current->fs。
这里的fs是task_struct结构体的一个子域struct fs_struct *fs;(部分字段省略)。
struct task_struct {
volatile long state; /* -1 unrunnable, 0 runnable, >0 stopped */
void *stack;
atomic_t usage;
unsigned int flags; /* per process flags, defined below */
unsigned int ptrace;
......
/* CPU-specific state of this task */
struct thread_struct thread;
/* filesystem information */
struct fs_struct *fs;
/* open file information */
struct files_struct *files;
/* namespaces */
struct nsproxy *nsproxy;
......
#ifdef CONFIG_PERF_EVENTS
struct perf_event_context *perf_event_ctxp[perf_nr_task_contexts];
struct mutex perf_event_mutex;
struct list_head perf_event_list;
#endif
#ifdef CONFIG_DEBUG_PREEMPT
unsigned long preempt_disable_ip;
#endif
......
};
从上面的定义，可以看到，它是跟文件系统相关的一个结构体。分析到这里时，考虑到问题所在函数为exfat_fill_super，看名字似乎是填充文件系统超级快的操作，加之测试部门反馈，问题出现后，格式化存储卡就会恢复，所以我怀疑，会不会是因为更换读卡器和存储卡，导致读取超级块信息有误，才使得文件系统相关访问出现空指针，并报告oops。
为了验证这一想法，我将上述连续赋值的这行代码(即前述问题所在的2301行代码)进行拆分，分为多条语句，然后在每一个指针使用点添加日志，以便在问题出现时，输出问题到底在哪个指针上。另外，为了尽可能保留环境，在问题出现后，采取软重启设备，并通过重新配置uboot参数，让内核通过nfs挂载根文件系统，这样就可以替换之前的ko库文件来测试了。
奇怪的是，每次替换后，问题就不出现了。这一现象似乎打破了之前的猜测，感觉问题又偏向软件一侧了。在这种取巧的打印方案没有取得效果后，我决定直接分析汇编代码，看看问题出现时，空指针到底落在了哪里。反汇编目标文件，结合gdb报告的位置(前面已提到)和oops中报告的指令内容。
Code: e5851108 e3a01003 e593300c e5933308 (e1d330bc)确定问题就在下面汇编中9670这一行：
9660: e5851108 str r1, [r5, #264] ; 0x108
9664: e3a01003 mov r1, #3
9668: e593300c ldr r3, [r3, #12]
966c: e5933308 ldr r3, [r3, #776] ; 0x308
9670: e1d330bc ldrh r3, [r3, #12]
9674: e1c2c0bc strh ip, [r2, #12]
9678: e1c200be strh r0, [r2, #14]
967c: e1c230ba strh r3, [r2, #10]
9680: e1c230b8 strh r3, [r2, #8]这是一条加载指令，即将r3寄存器指示的内存地址，偏移12位置后的两个字节，加载到r3寄存器中。这里r3指示的内存地址是什么呢?根据oops中给出的信息，是00000000，加上12，就是地址0000000C，所以oops报告。
Unable to handle kernel NULL pointer dereference at virtual address 0000000c结合C代码及问题点前后的汇编代码，直观感觉，这里的12应该是一个结构体中某一个子域的偏移，找到这个偏移对应的域，那么就可以确定是在哪一个赋值上出现了空指针。
回到C代码，问题代码行前后有好几个结构体使用，为了快速确定偏移，我选择参考内核container_of宏，定义一个找偏移的宏。
#define my_offsetof(TYPE, MEMBER) ((size_t)&((TYPE *)0)->MEMBER)通过这个宏，快速找到每一个元素在结构体中的偏移。当然，也可以通过看代码来确定，但是没有这种方法来得快。就是通过这个操作，引出了问题的最终原因。我们继续。
添加获取偏移的日志后，得到的相关偏移信息如下：
task_offset=12, fs_offset=904, umask_offset=12, fs_fmask=8, fs_dmask=10这里的12、904、12、、8、10似乎跟汇编有隐隐的对应关系。但是这里的904跟776没有什么关系。我决定再看看添加日志后目标文件的反汇编代码，如下：
97b8: e3a0b000 mov fp, #0
97bc: e3a0207b mov r2, #123 ; 0x7b
97c0: e3000000 movw r0, #0
97c4: e300a000 movw sl, #0
97c8: e5933388 ldr r3, [r3, #904] ; 0x388
97cc: e3400000 movt r0, #0
97d0: e340a000 movt sl, #0
97d4: e1d330bc ldrh r3, [r3, #12]
97d8: e1c930ba strh r3, [r9, #10]
97dc: e1c930b8 strh r3, [r9, #8]
97e0: e5cb2000 strb r2, [fp]
97e4: e595300c ldr r3, [r5, #12]因为此时代码被修改，所以只能大概判断之前问题所在的汇编范围。从上面可以看出，这一次汇编里的数值跟打印出来的偏移对应上了。根据这次的偏移，结合汇编，基本可以确定，之前出问题的汇编对应的就是C代码中的fs->umask这个语句。
因为fs为空，所以再去获取umask，就会报空指针异常。那问题来了，为啥fs会变空呢?有经验的读者，此时可能已经猜出问题的原因了。
我们看到，之前代码反汇编后，fs的偏移是776，添加日志重新编译后，反汇编成了904。虽然添加日志，导致代码被修改，但是并不影响这个偏移，所以，这里的fs偏移可能就是问题所在。对于偏移变化，我考虑了三个因素，分别进行了验证：
1.是ko库文件因为flash坏块或其他原因，导致二进制文件部分bit翻转。实际验证后，排除了这个原因。
2.是ko库针对不同平台编译的，放置错误导致。实际验证后，这个原因也排除了。
3.是当前添加日志后所编译ko库，其依赖的内核配置跟之前编译ko库依赖的内核配置相比有更新，也就是内核配置发生了变化(内核版本本身是一致的)。这种情况最常见的就是对内核进行了menuconfig操作。检查fs所在的task_struct结构体，发现其中有很多ifdef，不过都不曾配置过，倒是有一个perf相关的CONFIG_PERF_EVENTS，由于调测性能所需，是后来新配置的。但是这个配置选项在fs结构体后面(见前面task_struct结构体)，按理说是不影响fs在整个结构体中偏移的。考虑到task_struct结构体里面包含了很多子结构体，不排除上述perf配置影响了fs前面的某些子结构体而导致fs自己的偏移发生变化。
说了这么多，那么到底是不是呢，验证一下就知道了。关闭上述选项，重新编译内核，之后再编译exfat，查看汇编，发现偏移回到了776。Yes，问题就是这里了。最终原因就是内核更新了，但是ko没有更新，导致二者不匹配(旧的ko库从776偏移找fs，但是在新内核中，fs的偏移已经成了904)，产生了潜在的问题。
问题原因最终是找到了，但是问题产生的过程，其实更值得引起注意：ko库因为也是在内核空间运行，所以需要跟kernel版本匹配起来，做版本一致管理。进一步的，不仅仅是嵌入式领域，桌面端也同样的，如果系统中加载了ko库，当更新kernel时，就需要考虑对ko库的影响。二者需要统一起来看待和管理。
个人简介：lccz(龙城赤子)，资深嵌入式开发者，爱好Linux内核相关技术。
Recommend
About Joyk
Aggregate valuable and interesting links.
Joyk means Joy of geeK