内核调试：一次多线程调试与KASAN检测实例

博主最近遇到一个非常顽固的多线程BUG，复现起来具有很大的随机性，本文介绍博主一步步定位问题并解决BUG的思路和方案，希望对大家有启发（注：本思路同样适用于用户态调试）

1. 环境说明

• OS内核：本文内核跑在QEMU环境上，详细配置见我之前的博客：用VSCode + QEMU跑起来能够可视化Debug的NOVA文件系统
• 测试程序：Filebench，一个文件系统测试工具。参考这篇博客了解其编译并放入QEMU的方法：编译静态文件系统测试工具【Filebench】并在QEMU中运行

2. 问题描述

在虚拟机上用50个线程运行如下Filebench脚本：

...
define fileset name=bigfileset,path=$dir,size=$filesize,entries=$nfiles,dirwidth=$meandirwidth,prealloc=80define process name=filereader,instances=1
{thread name=filereaderthread,memsize=10m,instances=$nthreads{flowop createfile name=createfile1,filesetname=bigfileset,fd=1flowop writewholefile name=wrtfile1,srcfd=1,fd=1,iosize=$iosizeflowop closefile name=closefile1,fd=1flowop openfile name=openfile1,filesetname=bigfileset,fd=1flowop appendfilerand name=appendfilerand1,iosize=$meanappendsize,fd=1flowop closefile name=closefile2,fd=1flowop openfile name=openfile2,filesetname=bigfileset,fd=1flowop readwholefile name=readfile1,fd=1,iosize=$iosizeflowop closefile name=closefile3,fd=1flowop deletefile name=deletefile1,filesetname=bigfilesetflowop statfile name=statfile1,filesetname=bigfileset}
}

简单来说，他就类似每个线程执行一堆文件操作序列，对应的：

• createfile: 创建文件
• writewholefile: 填充文件
• closefile：关闭文件
• openfile：打开文件
• appendfilerand：随机追加写文件
• readwholefile：读整个文件
• deletefile：删除文件
• statfile：输出文件基本属性

在运行过程中，发现被测试的文件系统删除了本不应该存在的File（具体而言，被测试的文件系统为每个目录维护一个hash表用于快速目录项索引，但是在文件删除过程中，发现在hash表里找不到对应文件），至此，事情变得扑朔迷离起来。可能的原因有很多，包括：

1. 文件删除（unlink）部分实现存在BUG
2. 文件创建（create）部分实现存在BUG
3. 多线程BUG
4. 内存踩踏BUG

最后，还可能是VFS本身的BUG，这是我最不敢想像的，如果是VFS本身的BUG，那需要做的工作就太多了……

3. 问题排查与定位

3.1 线程并发问题（减少线程数）

我在单线程下运行Filebench，发现了不少单线程下存在的内存越界问题以及强转问题。其中：

• 强转问题通常带来数值的overflow进而导致不正确的内存访问，例如，计算32位blk对应的相对偏移地址，即：

  unsigned int blk = 0xffff0000;
  unsigned long addr;addr = blk << 12;
  

  上述结果b的值为0xf0000000，而非0xffff0000000，正确的写法应该是：addr = (unsigned long)blk << 12;

• 其次，无符号数大小比较问题。切忌不能直接两数相减然后与0比较，如下：

  unsigned int a = 0;
  unsigned int b = 1;assert(a - b > 0);
  

  上述减法出来的结果是UINT32_MAX，即：0xffffffff。

这些问题解决后，单线程下的大多数BUG都消失了。接着提升线程数至2线程，同样没有问题发生；当线程数回调到50时，同样的BUG再次出现，还伴随着其他种种问题，例如：空指针访问、写入已经被删除的文件、读取已经被删除的文件等。这证明问题仍在高并发场景下仍然存在，我们继续检查前面提到的点：

1. 文件删除（unlink）部分实现存在BUG
2. 文件创建（create）部分实现存在BUG
3. 多线程BUG
4. 内存踩踏BUG

除此之外，由于观察到了空指针访问，我们还希望检查相应的指针修改情况，看看是哪行代码有可能修改该指针，即：

5. 空指针访问BUG

3.2 轻量地跟踪对象的分配与释放

为什么文件系统会访问已经被删除的File呢？ 验证问题的思路是跟踪整个Filebench运行过程中文件的创建和删除情况，看看这个文件究竟有没有被创建。

在高并发场景下，通用调试手段printk()（即内核的打印）函数已经不能够及时输出，表现为：printk: X messages dropped。

针对难以通过print调试的问题，可以考虑自行构建跟踪文件的代码，然后在出错的地方自行输出跟踪的信息。例如，在博主调试过程中，我在栈上分配了固定大小的数组，每次创建和删除文件时便向其中追加写入当前文件的inode号，在unlink调用且在父目录中找不到该文件时强行停止内核（BUG_ON(1);，详见3.3节）并输出该文件号的所有创建的和删除记录。这里要注意追踪器的轻量高效性，不能使其过度影响程序的并发，否则可能BUG无法发作。

为此博主构造了一个per cpu文件号跟踪器，相关代码如下：

#define CPU 32
#define MAX_FILE 4000u32 remove_lists_pos[CPU];
u32 remove_lists[CPU][MAX_FILE];
spinlock_t remove_locks[CPU];u32 create_lists_pos[CPU];
u32 create_lists[CPU][MAX_FILE];
spinlock_t create_locks[CPU];// 创建文件部分伪代码
int create(dir) {...// per cpu create跟踪器int cpuid, i, is_find = 0;int start_cpuid = smp_processor_id();for (i = 0; i < 32; i++) {cpuid = (start_cpuid + i) % CPU ;spin_lock(&create_locks[cpuid]);if (create_lists_pos[cpuid] < MAX_FILE ) {create_lists[cpuid][create_lists_pos[cpuid]++] = inode;spin_unlock(&create_locks[cpuid]);break;}spin_unlock(&create_locks[cpuid]);}...
}// 删除文件部分伪代码
int unlink(dir, inode) {...// per cpu unlink跟踪器int cpuid, i, is_find = 0;int start_cpuid = smp_processor_id();for (i = 0; i < 32; i++) {cpuid = (start_cpuid + i) % CPU ;spin_lock(&remove_locks[cpuid]);if (remove_lists_pos[cpuid] < MAX_FILE ) {remove_lists[cpuid][remove_lists_pos[cpuid]++] = inode;spin_unlock(&remove_locks[cpuid]);break;}spin_unlock(&remove_locks[cpuid]);}...// 目录里面没有找到inodeif (inode not found in dir) {int i, j;// 输出跟踪记录for (i = 0; i < 32; i++) {for (j = 0; j < remove_lists_pos[i]; j++) {if (create_lists[i][j] == inode) {hk_info("%s: create_lists[%d][%d] %lu\n", __func__, i, j, create_lists[i][j]);}if (remove_lists[i][j] == inode) {hk_info("%s: remove_lists[%d][%d] %lu\n", __func__, i, j, remove_lists[i][j]);}}}// 停止内核BUG_ON(1);}
}

折腾一番后，博主发现几个更有意思的问题：有些文件确实根本就没有create就被unlink了，这是根本不能发生的事情（除非VFS有BUG）。再者反复核对文件的删除和创建逻辑，也没有发现问题，看来事出另有因，我们继续往下检查：

1. 文件删除（unlink）部分实现存在BUG
2. 文件创建（create）部分实现存在BUG
3. 多线程BUG
4. 内存踩踏BUG
5. 空指针访问BUG

3.3 检查空指针与潜在修改者

在内核中，开发者通常使用BUG_ON(condition)来当作断言assert(condition)。例如：

void *pointer = get_pointer();
BUG_ON(pointer == NULL);

这样就能使系统在上述pointer为空时停下来，验证确实是这个变量为空。

此外，博主还经常使用BUG_ON()来验证某个函数一定不会被调用，某个可能修改pointer的的变量是否真的被调用等（即用于确定潜在修改者），这点比较鸡肋，不过对于视觉疲劳懒得翻printk记录的人来说，这是省事的好方法。举个例子：

void *pointer = NULL;void threadB(){// 确认线程B永远不会调用，一旦调用系统就会报错BUG_ON(1);// 如果线程B会被调用，删除BUG_ON(1)，浏览代码// 确认线程B会对pointer做出什么事pointer = 0x1;
}

总而言之，博主在代码中各式各样的指针处都写上了BUG_ON(1)，但遗憾的是，我并没有发现存在修改者会使该指针变空。此时，只剩下一条路可走：内存溢出或内存踩踏使得乱象丛生。

1. 文件删除（unlink）部分实现存在BUG
2. 文件创建（create）部分实现存在BUG
3. 多线程BUG
4. 内存踩踏BUG
5. 空指针访问BUG

3.4 KASAN检查

KASAN是一个强大的内存泄漏、越界访问问题的检测工具，参考资料很多：

• KASAN实现原理
• KASAN配置
• KASAN实践

进一步的，我们cd到内核源码目录下，直接用脚本开启下述config即可：

[deadpool@localhost linux-5.1]$ ls
arch   COPYING  Documentation  include  Kbuild   lib          Makefile         modules.order   README   security    tools  vmlinux
block  CREDITS  drivers        init     Kconfig  LICENSES     mm               Module.symvers  samples  sound       usr    vmlinux-gdb.py
certs  crypto   fs             ipc      kernel   MAINTAINERS  modules.builtin  net             scripts  System.map  virt   vmlinux.o
[deadpool@localhost linux-5.1]$ ./scripts/config -e CONFIG_SLUB_DEBUG
[deadpool@localhost linux-5.1]$ ./scripts/config -e CONFIG_SLUB_DEBUG_ON
[deadpool@localhost linux-5.1]$ ./scripts/config -e CONFIG_KASAN
[deadpool@localhost linux-5.1]$ ./scripts/config -e CONFIG_KASAN_INLINE

然后make -j32编译即可。接着，果然，检查出如下类似错误：

==================================================================
BUG: KASAN: use-after-free in function+0xxx/0xxx [xx_module]
Write of size 8 at addr `addr1` by task filebench/2760
...
The buggy address belongs to the object at `addr`
...
==================================================================

上面报错信息中，关注：

• 报错类型：use-after-free，访问了free后的内存
• function：具体哪个函数访问的
• addr1: 具体访问addr1处变量产生的错误
• addr：addr1属于addr处的对象（malloc出来的对象）

接着，检查function函数，至此，终于找到了这个藏得非常深的BUG，由于不方便开放源码，这里简单来说就是在并发地插入hash表时，没有正确地上锁，导致出现各种各样的问题。

4. 总结

至此，终于结束了这为期两天的DEBUG之旅，现在回想起来，要是从一开始就使用KASAN，也许一下就能够解决遇到的问题，以后一定要多多使用KASAN来帮忙检查内存相关的错误。

题外话，听说rust好像可以在编译阶段就避免很多这样类似的问题，看来真的有必要向Linux Kernel中引入rust。

OK，就这样，起飞🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫🛫