内核调试秘籍
登录
标签搜索
侧边栏壁纸
博主昵称
adtxl

  • 累计撰写 342 篇文章
  • 累计收到 8 条评论
Linux

内核调试秘籍

adtxl
adtxl
2022-07-06 / 0 评论 / 1,039 阅读 / 正在检测是否收录...

转载整理自《奔跑吧 Linux内核》，张天飞著

1. printk

printk是内核中最简单最有效的调试方法。printk是内核提供的格式化打印函数，它和C库所提供的printf()函数类似。printk函数和printf函数的一个重要区别是前者提供打印等级，内核根据这个等级判断是否在终端或者串口中打印输出。

// include/linux/kern_levels.h

#define KERN_EMERG    KERN_SOH "0"    /* system is unusable */
#define KERN_ALERT    KERN_SOH "1"    /* action must be taken immediately */
#define KERN_CRIT    KERN_SOH "2"    /* critical conditions */
#define KERN_ERR    KERN_SOH "3"    /* error conditions */
#define KERN_WARNING    KERN_SOH "4"    /* warning conditions */
#define KERN_NOTICE    KERN_SOH "5"    /* normal but significant condition */
#define KERN_INFO    KERN_SOH "6"    /* informational */
#define KERN_DEBUG    KERN_SOH "7"    /* debug-level messages */

Linux内核为printk定义了8个打印等级，KERN_EMERG等级最高，KERN_DEBUG等级最低。在内核配置时，有一个宏来设定系统默认的打印等级CONFIG_MESSAGE_LOGLEVEL_DEFAULT，通常设置为4，即只有打印等级高于4时才会打印到终端或者串口，也就是KERN_EMERG到KERN_ERR。通常在产品开发阶段，会把系统默认等级设置到最低，以便在开发测试阶段可以暴露更多的问题和调试信息，在产品发布时再把打印等级设置为0或者4。

// defconfig
CONFIG_MESSAGE_LOGLEVEL_DEFAULT = 8 // 默认打印等级设置为8，即打开所有的打印信息

此外，还可以通过在启动内核时传递commandline给内核的方法来修改系统默认的打印等级，例如，传递loglevel=8给内核启动参数。

在系统运行时，也可以修改系统的打印等级。

# cat /proc/sys/kernel/printk
7    4    1    7

# echo 8 > /proc/sys/kernel/printk    // 打开所有的内核打印
# echo 0 > /proc/sys/kernel/printk    // 关闭所有的内核打印

上述内容分别表示控制台打印等级、默认信息打印等级、最低打印等级和默认控制台打印等级。

在实际的调试中，把函数名字（__func__）和行号(__LINE__)打印出来也是一个很好的小技巧。

printk(KERN_EMERG "figo: %s, %d", __func__, __LINE__);

需要注意printk的打印格式，否则在编译时可能出现很多的WARNING，如下表所示

数据类型printk格式符
int%d or %x
unsigned%u or %x
long%ld or %lx
long long%lld or %llx
unsigned long long%llu or %llx
size_t%zu or %zx
ssize_t%zd or %zx
函数指针%pf

内核还提供了一些在实际工程中会用到的有趣的打印。

  • 打印内存buffer的数据函数print_hex_dump()
  • 打印堆栈函数dump_stack()

2. 动态打印

动态打印（Dynamic Printk Debugging）时内核子系统开发者最喜欢的打印手段之一。在系统运行时，动态打印可以由系统维护者动态打开哪些内核子系统的打印，可以有选择性地打开某些模块的打印，而printk是全局的，只能设置打印等级。要使用动态打印，必须在内核配置时打开CONFIG_DYNAMIC_DEBUG宏。内核代码里使用了大量pr_debug()/dev_dbg()函数来打印信息，这些就使用了动态打印技术，另外还需要系统挂载debugfs文件系统。

动态打印在debugfs文件系统中有一个control文件节点，文件节点记录了系统中所有使用动态打印技术的文件名和路径、打印所在的行号、模块名字和要打印的语句。

# cat /sys/kernel/debug/dynamic_debug/control
......
mm/cma.c:441 [cma]cma_alloc =_ "%s(cma %p, count %zu, align %d)\012"
mm/cma.c:486 [cma]cma_alloc =_ "%s(): memory range at %p is busy, retrying\012"
mm/cma.c:509 [cma]cma_alloc =_ "%s(): returned %p\012"
mm/cma.c:531 [cma]cma_release =_ "%s(page %p)\012"
mm/cma.c:267 [cma]cma_declare_contiguous =_ "%s(size %pa, base %pa, limit %pa alignment %pa)\012"
......

例如上面的cma模块，代码路径在mm/cma.c文件，打印语句所在行号是372，所在函数是cma_alloc()，要打印的语句是"%s(cma %p, count %zu, align %d)\012".

在使用动态打印技术之前，可以先通过查询control文件获知系统有哪些动态打印语句，例如 cat control | grep xxx

下面举例来说明如何使用动态打印技术。

// 打开svcsock.c文件中所有动态打印语句
# echo 'file svcsock.c +p' > /sys/kernel/debug/dynamic_debug/control

// 打开usbcore模块所有动态打印语句
# echo 'module usbcore +p' > /sys/kernel/debug/dynamic_debug/control

// 打开svc_process()函数中所有动态打印语句
# echo 'func svc_process +p' > /sys/kernel/debug/dynamic_debug/control

// 关闭svc_process()函数中所有的动态打印语句
# echo 'func svc_process -p' > /sys/kernel/debug/dynamic_debug/control

// 打开文件路径中包含usb的文件里所有的动态打印语句
# echo -n '*usb* +p' > /sys/kernel/debug/dynamic_debug/control

// 打开系统所有的动态打印语句
# echo -n '+p' > /sys/kernel/debug/dynamic_debug/control

上面是打开动态打印语句的例子，除了能打印pr_debug()/dev_dbg()函数中定义的输出外，还能打印一些额外的信息，例如函数名、行号、模块名字和线程ID等。

  • p：打开动态打印语句
  • f：打印函数名
  • l：打印行号
  • m：打印模块名字
  • t：打印线程ID

在调试一些系统启动方面的代码，例如SMP初始化、USB核心初始化等，这些代码在系统进入shell终端时已经初始化完成，因此无法及时打开动态打印语句。
这时可以在内核启动时传递参数给内核，在系统初始化时动态打开它们，这是一个实际工程中非常好用的技巧。

例如调试SMP初始化的代码，查询到ARM SMP模块有一些动态打印语句。

# cat /sys/kernel/debug/dynamic_debug/control | grep smp
arch/arm64/kernel/setup.c:143 [setup]smp_build_mpidr_hash =_ "mask of set bits %#llx\012"
arch/arm64/kernel/setup.c:183 [setup]smp_build_mpidr_hash =_ "MPIDR hash: aff0[%u] aff1[%u] aff2[%u] aff3[%u] mask[%#llx] bits[%u]\012"
arch/arm64/kernel/smp.c:507 [smp]acpi_map_gic_cpu_interface =_ "skipping disabled CPU entry with 0x%llx MPIDR\012"
arch/arm64/kernel/smp.c:654 [smp]of_parse_and_init_cpus =_ "cpu logical map 0x%llx\012"

在内核commandline中添加smp.dyndbg=+plft,不知道是这个模块没有运行，还是这个功能在使用的版本上没支持，dmesg没看到相关log，但看了下参数是加上去了，以后再研究吧。

# cat /sys/kernel/debug/dynamic_debug/control | grep smp
arch/arm64/kernel/setup.c:143 [setup]smp_build_mpidr_hash =_ "mask of set bits %#llx\012"
arch/arm64/kernel/setup.c:183 [setup]smp_build_mpidr_hash =_ "MPIDR hash: aff0[%u] aff1[%u] aff2[%u] aff3[%u] mask[%#llx] bits[%u]\012"
arch/arm64/kernel/smp.c:507 [smp]acpi_map_gic_cpu_interface =pflt "skipping disabled CPU entry with 0x%llx MPIDR\012"
arch/arm64/kernel/smp.c:654 [smp]of_parse_and_init_cpus =pflt "cpu logical map 0x%llx\012"

还可以在各个子系统的Makefile中添加ccflags来打开动态打印。

// Makefile
ccflags-y := -DDEBUG
ccflags-y += -DVERBOSE_DEBUG

3. RAM console

上面讲述了printk和动态打印技术，它们有一个明显的缺点，都需要往串口/终端等硬件设备里输出，因此有大量打印时，系统会变得很慢。在一些对时间和时序要求比较严格的地方，这些打印延迟会影响调试效果。

trace_printk使用方法和printk一样，它输出的信息会写入ftrace的循环缓存中（ring buffer），即相当于写内存，速度比写串口等硬件设备要快好几个数量级。常用的一些场景有调度器、中断和时序要求严格的驱动。

内核还提供另外一种RAM Console的技术叫pstore。pstore是使用RAM作为存储介质的一种特殊的文件系统，主要用于在系统宕机时将日志信息写到pstore中，系统重启后再把这些日志信息写入磁盘或eMMC等存储介质。

4. OOPS分析

在编写驱动程序或内核模块时，常常会显示或隐藏地对指针进行非法取值或使用不正确的指针，导致内核产生一个oops错误。当处理器在内核空间访问一个非法的指针时，因为虚拟地址到物理地址的映射关系没有建立，触发一个缺页中断，在缺页中断中因为该地址是非法的，内核无法正确地为该地址建立映射关系，因此内核触发了一个oops错误。

下面写一个简单的内核模块，来验证如何分析一个内核oops错误。

// oops_test.c

#include <linux/kernel.h>
#include <linux/module.h>
#include <linux/init.h>

static void create_oops(void)
{
    *(int *) 0 = 0;
}

static int __init my_oops_init(void) {
    printk("oops module init \n");
    create_oops();
    return 0;
}

static void __exit my_oops_exit(void) {
    printk("goodbye\n");
}

module_init(my_oops_init);
module_exit(my_oops_exit);
MODULE_LICENSE("GPL");

按照如下的Makefile，把oops_test.c编译成内核模块。

BASEINCLUDE ?= /home/user/txl/project/qemu_kernel/work/juno/linux    # 这里要用绝对路径

oops-objs := oops_test.o

obj-m   := oops.o

all:
        $(MAKE) -C $(BASEINCLUDE) SUBDIRS=$(PWD) modules;

clean:
        $(MAKE) -C $(BASEINCLUDE) SUBDIRS=$(PWD) clean;
        rm -rf *.ko;

使用如下的编译命令

# make ARCH=arm64 CROSS_COMPILE=aarch64-linux-gnu-

编译完成后，将oops.ko放到文件系统中。然后运行，使用insmod命令加载内核模块，oops错误信息如下。

# insmod /lib/modules/oops.ko
[   26.904616] oops: loading out-of-tree module taints kernel.
[   26.909054] oops module init
[   26.909706] Unable to handle kernel NULL pointer dereference at virtual address 0000000000000000
[   26.909884] Mem abort info:
[   26.909933]   ESR = 0x96000046
[   26.910001]   Exception class = DABT (current EL), IL = 32 bits
[   26.910080]   SET = 0, FnV = 0
[   26.910129]   EA = 0, S1PTW = 0
[   26.910183] Data abort info:
[   26.910235]   ISV = 0, ISS = 0x00000046
[   26.910290]   CM = 0, WnR = 1
[   26.910398] user pgtable: 4k pages, 48-bit VAs, pgdp = (____ptrval____)
[   26.910549] [0000000000000000] pgd=000000005ab2c003, pud=000000005ab75003, pmd=0000000000000000
[   26.910865] Internal error: Oops: 96000046 [#1] PREEMPT SMP
[   26.911043] Modules linked in: oops(O+)
[   26.911386] Process insmod (pid: 1051, stack limit = 0x(____ptrval____))
[   26.911656] CPU: 0 PID: 1051 Comm: insmod Tainted: G           O      4.19.176 #2
[   26.911795] Hardware name: linux,dummy-virt (DT)
[   26.912000] pstate: 40000005 (nZcv daif -PAN -UAO)
[   26.912376] pc : my_oops_init+0x1c/0x1000 [oops]
[   26.912483] lr : my_oops_init+0x14/0x1000 [oops]
[   26.912582] sp : ffff00000a7abb80
[   26.912642] x29: ffff00000a7abb80 x28: 0000000000000013 
[   26.912736] x27: ffff00000a7abdf0 x26: 0000000000000022 
[   26.912803] x25: 0000000000000001 x24: ffff000008eba000 
[   26.913001] x23: ffff80001cb4b900 x22: 0000000000000000 
[   26.913103] x21: ffff0000009d5000 x20: ffff000008ddd000 
[   26.913173] x19: ffff000008eba000 x18: ffffffffffffffff 
[   26.913240] x17: 0000000000000000 x16: 0000000000000000 
[   26.913337] x15: ffff000008ddd708 x14: ffff000088ec1c47 
[   26.913409] x13: ffff000008ec1c55 x12: ffff000008df5928 
[   26.913477] x11: 0000000005f5e0ff x10: ffff000008ddd970 
[   26.913570] x9 : 00000000ffffffd0 x8 : ffff000008551cc0 
[   26.913639] x7 : 0000000000000000 x6 : 00000000000000be 
[   26.913704] x5 : 0000000000000000 x4 : 0000000000000000 
[   26.913772] x3 : ffffffffffffffff x2 : b464bc6aa74cd000 
[   26.913883] x1 : 0000000000000000 x0 : 0000000000000000 
[   26.914040] Call trace:
[   26.914177]  my_oops_init+0x1c/0x1000 [oops]
[   26.914294]  do_one_initcall+0x5c/0x178
[   26.914365]  do_init_module+0x58/0x1bc
[   26.914421]  load_module+0x1ec4/0x2358
[   26.914474]  __se_sys_init_module+0x1d0/0x248
[   26.914532]  __arm64_sys_init_module+0x18/0x20
[   26.914594]  el0_svc_common.constprop.0+0x68/0x170
[   26.914655]  el0_svc_handler+0x28/0x78
[   26.914703]  el0_svc+0x8/0xc
[   26.914917] Code: 910003fd 95ff7659 d2800001 52800000 (b900003f) 
[   26.915602] ---[ end trace 3a2f3c761a2b03f1 ]---
Segmentation fault

pc指针指向出错指向的地址，另外stack也展示了出错时程序的调用关系。首先观察出错函数my_oops_init+0x1c/0x1000,其中0x1c表示指令指针在该函数第0x18字节处，该函数本身共0x1000字节。

继续分析这个问题，建设两种情况，一是有出错模块的源代码。二是没有源代码。在某些实际工作场景中。可能需要调试和分析没有源代码的oops情况。

先看有源代码的情况，通常在编译时添加在符号信息表中，下面用两种方法来分析。

（1）使用objdump工具反汇编

$ aarch64-linux-gnu-objdump -SdCg oops.o    // 使用arm64版本的objdump工具

结果如下：

oops.o：     文件格式 elf64-littleaarch64


Disassembly of section .init.text:

0000000000000000 <init_module>:
static void create_oops(void)
{
    *(int *) 0 = 0;
}

static int __init my_oops_init(void) {
   0:   a9bf7bfd        stp     x29, x30, [sp, #-16]!
    printk("oops module init \n");
   4:   90000000        adrp    x0, 0 <init_module>
   8:   91000000        add     x0, x0, #0x0
static int __init my_oops_init(void) {
   c:   910003fd        mov     x29, sp
    printk("oops module init \n"); 
  10:   94000000        bl      0 <printk>
    *(int *) 0 = 0;
  14:   d2800001        mov     x1, #0x0                        // #0 
    create_oops();
    return 0;
}
  18:   52800000        mov     w0, #0x0                        // #0 
    *(int *) 0 = 0;
  1c:   b900003f        str     wzr, [x1]
}
  20:   a8c17bfd        ldp     x29, x30, [sp], #16
  24:   d65f03c0        ret

Disassembly of section .exit.text:

0000000000000000 <cleanup_module>:

通过反汇编工具可以看出出错函数my_oops_init+0x1c/0x1000的汇编情况吗，这里把C语言和汇编语言一起显示了出来。可以看到0x14处的指令把0赋值到x1寄存器，ox1c字节处的指令是把x1寄存器的值存放到x1寄存器执行的地址中，x1寄存器的值为0，所以这里是一个写空指针的错误。

（2）使用gdb工具
可以简单地使用gdb工具，方便快捷地定位到出错的具体地方，使用gdb中的l指令加上出错函数和偏移量即可。

可能因为编译优化的关系，并没有直接定位到具体的函数中的哪一行。

(gdb) l *my_oops_init+0x1c/0x1000
0x0 is in my_oops_init (/home/user/txl/project/qemu_kernel/tmp/oops_test.c:10).
5    static void create_oops(void)
6    {
7        *(int *) 0 = 0;
8    }
9    
10    static int __init my_oops_init(void) {
11        printk("oops module init \n");
12        create_oops();
13        return 0;
14    }

如果出错的地方是内核函数，那么可以使用vmlinux文件。

下面来看没有源代码的情况。对于没有编译符号表的二进制文件，可以使用objdump工具来dump出汇编代码，例如使用aarch64-linux-gnu-objdump -d oops.o命令来dump出oops.o文件。

user@ubuntu:~/txl/project/qemu_kernel/tmp$ aarch64-linux-gnu-objdump -d oops.o

oops.o：     文件格式 elf64-littleaarch64


Disassembly of section .init.text:

0000000000000000 <init_module>:
   0:    a9bf7bfd     stp    x29, x30, [sp, #-16]!
   4:    90000000     adrp    x0, 0 <init_module>
   8:    91000000     add    x0, x0, #0x0
   c:    910003fd     mov    x29, sp
  10:    94000000     bl    0 <printk>
  14:    d2800001     mov    x1, #0x0                       // #0
  18:    52800000     mov    w0, #0x0                       // #0
  1c:    b900003f     str    wzr, [x1]
  20:    a8c17bfd     ldp    x29, x30, [sp], #16
  24:    d65f03c0     ret

Disassembly of section .exit.text:

0000000000000000 <cleanup_module>:
   0:    a9bf7bfd     stp    x29, x30, [sp, #-16]!
   4:    90000000     adrp    x0, 0 <cleanup_module>
   8:    91000000     add    x0, x0, #0x0
   c:    910003fd     mov    x29, sp
  10:    94000000     bl    0 <printk>
  14:    a8c17bfd     ldp    x29, x30, [sp], #16
  18:    d65f03c0     ret

内核提供了一个非常好用的脚本，可以快速帮助快速定位问题，该脚本位于linux内核源代码目录的scripts/decodecode，首先把出错的log保存到一个txt文件中。

user@ubuntu:~/txl/project/qemu_kernel/kernel/common$ ./scripts/decodecode < oops.txt 
[ 26.914917] Code: 910003fd 95ff7659 d2800001 52800000 (b900003f)
All code
========
   0:    fd                       std
   1:    03 00                    add    (%rax),%eax
   3:    91                       xchg   %eax,%ecx
   4:    59                       pop    %rcx
   5:    76 ff                    jbe    0x6
   7:    95                       xchg   %eax,%ebp
   8:    01 00                    add    %eax,(%rax)
   a:*    80 d2 00                 adc    $0x0,%dl        <-- trapping instruction
   d:    00 80 52 3f 00 00        add    %al,0x3f52(%rax)
  13:    b9                       .byte 0xb9

Code starting with the faulting instruction
===========================================
   0:    3f                       (bad)  
   1:    00 00                    add    %al,(%rax)
   3:    b9                       .byte 0xb9

decodecode脚本把出错的日志转换成直观有用的汇编代码，并且告知出错具体是哪个汇编语句中，这对于分析没有源代码的oops错误非常有用。

5. BUG_ON()和WARN_ON()

在内核中经常看到BUG_ON()和WARN_ON()宏，这也是内核调试常用的技巧之一。

// include/asm-generic/bug.h

#define BUG_ON(condition) do { if (unlikely(condition)) BUG(); } while (0)

#define BUG() do { \
    printk("BUG: failure at %s:%d/%s()!\n", __FILE__, __LINE__, __func__); \
    barrier_before_unreachable(); \
    panic("BUG!"); \
} while (0)

对于BUG_ON()来说，满足条件condition就会触发BUG()宏，它会使用panic()函数来主动让系统宕机。通常是一些内核的bug才会触发BUG_ON()，在实际产品中使用要小心谨慎。

WARN_ON()相对会好一点，不会触发panic()主动宕机，但会打印函数调用栈信息，提示开发者可能发生有一些不好的事情。

0
暂无标签
版权属于： adtxl
本文链接： https://adtxl.com/index.php/archives/487.html
作品采用： 《 署名-非商业性使用-相同方式共享 4.0 国际 (CC BY-NC-SA 4.0) 》许可协议授权

评论 (0)

取消