第二章 驱动程序调测方法与技巧

转自：http://www.cnblogs.com/GoodGoodWorkDayDayUp/p/3523025.html
驱动程序开发的一个重大难点就是不易调试。本文目的就是介绍驱动开发中常用的几种直接和间接的调试手段，它们是：

利用printk查看OOP消息利用strace利用内核内置的hacking选项利用ioctl方法利用/proc 文件系统使用kgdb

一、利用printk

这是驱动开发中最朴实无华，同时也是最常用和有效的手段。scull驱动的main.c第338行如下，就是使用printk进行调试的例子，这样的例子相信大家在阅读驱动源码时随处可见。

338 // printk(KERN_ALERT “wakeup by signal in process %d\n”, current->pid);

printk的功能与我们经常在应用程序中使用的printf是一样的，不同之处在于printk可以在打印字符串前面加上内核定义的宏，例如上面例子中的KERN_ALERT（注意：宏与字符串之间没有逗号）。

#define KERN_EMERG "<0>"#define KERN_ALERT "<1>"#define KERN_CRIT "<2>"#define KERN_ERR "<3>"#define KERN_WARNING "<4>"#define KERN_NOTICE "<5>"#define KERN_INFO "<6>"#define KERN_DEBUG "<7>"#define DEFAULT_CONSOLE_LOGLEVEL 7

这个宏是用来定义需要打印的字符串的级别。值越小，级别越高。内核中有个参数用来控制是否将printk打印的字符串输出到控制台（屏幕或者/sys/log/syslog日志文件）

cat /proc/sys/kernel/printk

6 4 1 7

第一个6表示级别高于（小于）6的消息才会被输出到控制台，第二个4表示如果调用printk时没有指定消息级别（宏）则消息的级别为4，第三个1表示接受的最高（最小）级别是1，第四个7表示系统启动时第一个6原来的初值是7。

因此，如果你发现在控制台上看不到你程序中某些printk的输出，请使用echo 8 > /proc/sys/kernel/printk来解决。

我们在复杂驱动的开发过程中，为了调试会在源码中加入成百上千的printk语句。而当调试完毕形成最终产品的时候必然会将这些printk语句删除（为什么？想想你自己是驱动的使用者而不是开发者吧。记住：己所不欲，勿施于人），这个工作量是不小的。最要命的是，如果我们将调试用的printk语句删除后，用户又报告我们的驱动有bug，所以我们又不得不手工将这些上千条的printk语句再重新加上。oh，my god，杀了我吧。所以，我们需要一种能方便地打开和关闭调试信息的手段。哪里能找到这种手段呢？哈哈，远在天边，近在眼前。看看scull驱动或者leds驱动的源代码吧！

define LEDS_DEBUG

undef PDEBUG /* undef it, just in case */

ifdef LEDS_DEBUG

#ifdef __KERNEL__ /* This one if debugging is on, and kernel space */    #define PDEBUG(fmt, args...) printk( KERN_EMERG "leds: " fmt, ## args)#else /* This one for user space */    #define PDEBUG(fmt, args...) fprintf(stderr, fmt, ## args)#endif

else

#define PDEBUG(fmt, args...) /* not debugging: nothing */

endif

undef PDEBUGG

define PDEBUGG(fmt, args…) /* nothing: it’s a placeholder */

这样一来，在开发驱动的过程中，如果想打印调试消息，我们就可以用PDEBUG(“address of i_cdev is %p\n”, inode->i_cdev);，如果不想看到该调试消息，就只需要简单的将PDEBUG改为PDEBUGG即可。而当我们调试完毕形成最终产品时，只需要简单地将第1行注释掉即可。

上边那一段代码中的KERNEL是内核中定义的宏，当我们编译内核（包括模块）时，它会被定义。当然如果你不明白代码中的…和##是什么意思的话，就请认真查阅一下gcc关于预处理部分的资料吧！如果你实在太懒不愿意去查阅的话，那就充当VC工程师把上面的代码copy到你的代码中去吧。

二、查看OOP消息

OOP意为惊讶。当你的驱动有问题，内核不惊讶才怪：嘿！小子，你干吗乱来！好吧，就让我们来看看内核是如何惊讶的。

根据faulty.c编译出faulty.ko，并 insmod faulty.ko。执行echo yang >/dev/faulty，结果内核就惊讶了。内核为什么会惊讶呢？因为faulty驱动的write函数执行了(int )0 = 0，向内存0地址写入，这是内核绝对不会容许的。

52 ssize_t faulty_write (struct file *filp, const char __user *buf, size_t count,
53 loff_t *pos)
54 {
55 /* make a simple fault by dereferencing a NULL pointer */
56 (int )0 = 0;
57 return 0;
58 }

1 Unable to handle kernel NULL pointer dereference at virtual address 00000000
2 pgd = c3894000
3 [00000000] *pgd=33830031, *pte=00000000, *ppte=00000000
4 Internal error: Oops: 817 [#1] PREEMPT
5 Modules linked in: faulty scull
6 CPU: 0 Not tainted (2.6.22.6 #4)
7 PC is at faulty_write+0x10/0x18 [faulty]
8 LR is at vfs_write+0xc4/0x148
9 pc : [] lr : [] psr: a0000013
10 sp : c3871f44 ip : c3871f54 fp : c3871f50
11 r10: 4021765c r9 : c3870000 r8 : 00000000
12 r7 : 00000004 r6 : c3871f78 r5 : 40016000 r4 : c38e5160
13 r3 : c3871f78 r2 : 00000004 r1 : 40016000 r0 : 00000000
14 Flags: NzCv IRQs on FIQs on Mode SVC_32 Segment user
15 Control: c000717f Table: 33894000 DAC: 00000015
16 Process sh (pid: 745, stack limit = 0xc3870258)
17 Stack: (0xc3871f44 to 0xc3872000)
18 1f40: c3871f74 c3871f54 c0088eb8 bf00608c 00000004 c38e5180 c38e5160
19 1f60: c3871f78 00000000 c3871fa4 c3871f78 c0088ffc c0088e04 00000000 00000000
20 1f80: 00000000 00000004 40016000 40215730 00000004 c002c0e4 00000000 c3871fa8
21 1fa0: c002bf40 c0088fc0 00000004 40016000 00000001 40016000 00000004 00000000
22 1fc0: 00000004 40016000 40215730 00000004 00000001 00000000 4021765c 00000000
23 1fe0: 00000000 bea60964 0000266c 401adb40 60000010 00000001 00000000 00000000
24 Backtrace:
25 [] (faulty_write+0x0/0x18 [faulty]) from [] (vfs_write+0xc4/0x148)
26 [] (vfs_write+0x0/0x148) from [] (sys_write+0x4c/0x74)
27 r7:00000000 r6:c3871f78 r5:c38e5160 r4:c38e5180
28 [] (sys_write+0x0/0x74) from [] (ret_fast_syscall+0x0/0x2c)
29 r8:c002c0e4 r7:00000004 r6:40215730 r5:40016000 r4:00000004
30 Code: e1a0c00d e92dd800 e24cb004 e3a00000 (e5800000)

1行惊讶的原因，也就是报告出错的原因；2-4行是OOP信息序号；5行是出错时内核已加载模块；6行是发生错误的CPU序号；7-15行是发生错误的位置，以及当时CPU各个寄存器的值，这最有利于我们找出问题所在地；16行是当前进程的名字及进程ID17-23行是出错时，栈内的内容24-29行是栈回溯信息，可看出直到出错时的函数递进调用关系（确保CONFIG_FRAME_POINTER被定义）30行是出错指令及其附近指令的机器码，出错指令本身在小括号中

反汇编faulty.ko（ arm-linux-objdump -D faulty.ko > faulty.dis ；cat faulty.dis）可以看到如下的语句如下：

0000007c :
7c: e1a0c00d mov ip, sp
80: e92dd800 stmdb sp!, {fp, ip, lr, pc}
84: e24cb004 sub fp, ip, #4 ; 0x4
88: e3a00000 mov r0, #0 ; 0x0
8c: e5800000 str r0, [r0]
90: e89da800 ldmia sp, {fp, sp, pc}

定位出错位置以及获取相关信息的过程：

9 pc : [] lr : [] psr: a0000013

25 [] (faulty_write+0x0/0x18 [faulty]) from [] (vfs_write+0xc4/0x148)
26 [] (vfs_write+0x0/0x148) from [] (sys_write+0x4c/0x74)

出错代码是faulty_write函数中的第5条指令（(0xbf00608c-0xbf00607c)/4+1=5），该函数的首地址是0xbf00607c，该函数总共6条指令（0x18），该函数是被0xc0088eb8的前一条指令调用的（即：函数返回地址是0xc0088eb8。这一点可以从出错时lr的值正好等于0xc0088eb8得到印证）。调用该函数的指令是vfs_write的第49条（0xc4/4=49）指令。

达到出错处的函数调用流程是：write(用户空间的系统调用)–>sys_write–>vfs_write–>faulty_write

OOP消息不仅让我定位了出错的地方，更让我惊喜的是，它让我知道了一些秘密：1、gcc中fp到底有何用处？2、为什么gcc编译任何函数的时候，总是要把3条看上去傻傻的指令放在整个函数的最开始？3、内核和gdb是如何知道函数调用栈顺序，并使用函数的名字而不是地址？ 4、我如何才能知道各个函数入栈的内容？哈哈，我渐渐喜欢上了让内核惊讶，那就再看一次内核惊讶吧。

执行 cat /dev/faulty，内核又再一次惊讶！

1 Unable to handle kernel NULL pointer dereference at virtual address 0000000b
2 pgd = c3a88000
3 [0000000b] *pgd=33a79031, *pte=00000000, *ppte=00000000
4 Internal error: Oops: 13 [#2] PREEMPT
5 Modules linked in: faulty
6 CPU: 0 Not tainted (2.6.22.6 #4)
7 PC is at vfs_read+0xe0/0x140
8 LR is at 0xffffffff
9 pc : [] lr : [] psr: 20000013
10 sp : c38d9f54 ip : 0000001c fp : ffffffff
11 r10: 00000001 r9 : c38d8000 r8 : 00000000
12 r7 : 00000004 r6 : ffffffff r5 : ffffffff r4 : ffffffff
13 r3 : ffffffff r2 : 00000000 r1 : c38d9f38 r0 : 00000004
14 Flags: nzCv IRQs on FIQs on Mode SVC_32 Segment user
15 Control: c000717f Table: 33a88000 DAC: 00000015
16 Process cat (pid: 767, stack limit = 0xc38d8258)
17 Stack: (0xc38d9f54 to 0xc38da000)
18 9f40: 00002000 c3c105a0 c3c10580
19 9f60: c38d9f78 00000000 c38d9fa4 c38d9f78 c0088f88 c0088bb4 00000000 00000000
20 9f80: 00000000 00002000 bef07c80 00000003 00000003 c002c0e4 00000000 c38d9fa8
21 9fa0: c002bf40 c0088f4c 00002000 bef07c80 00000003 bef07c80 00002000 00000000
22 9fc0: 00002000 bef07c80 00000003 00000000 00000000 00000001 00000001 00000003
23 9fe0: 00000000 bef07c6c 0000266c 401adab0 60000010 00000003 00000000 00000000
24 Backtrace: invalid frame pointer 0xffffffff
25 Code: ebffff86 e3500000 e1a07000 da000015 (e594500c)
26 Segmentation fault

不过这次惊讶却令人大为不解。OOP竟然说出错的地方在vfs_read（要知道它可是大拿们千锤百炼的内核代码），这怎么可能？哈哈，万能的内核也不能追踪函数调用栈了，这是为什么？其实问题出在faulty_read的43行，它导致入栈的r4、r5、r6、fp全部变为了0xffffffff，ip、lr的值未变，这样一来faulty_read函数能够成功返回到它的调用者——vfs_read。但是可怜的vfs_read（忠实的APTCS规则遵守者）并不知道它的r4、r5、r6已经被万恶的faulty_read改变，这样下去vfs_read命运就可想而知了——必死无疑！虽然内核很有能力，但缺少了正确的fp的帮助，它也无法追踪函数调用栈。

36 ssize_t faulty_read(struct file *filp, char __user *buf,
37 size_t count, loff_t *pos)
38 {
39 int ret;
40 char stack_buf[4];
41
42 /* Let’s try a buffer overflow */
43 memset(stack_buf, 0xff, 20);
44 if (count > 4)
45 count = 4; /* copy 4 bytes to the user */
46 ret = copy_to_user(buf, stack_buf, count);
47 if (!ret)
48 return count;
49 return ret;
50 }

00000000 :
0: e1a0c00d mov ip, sp
4: e92dd870 stmdb sp!, {r4, r5, r6, fp, ip, lr, pc}
8: e24cb004 sub fp, ip, #4 ; 0x4
c: e24dd004 sub sp, sp, #4 ; 0x4，这里为stack_buf[]在栈上分配1个字的空间，局部变量ret使用寄存器存储，因此就不在栈上分配空间了
10: e24b501c sub r5, fp, #28 ; 0x1c
14: e1a04001 mov r4, r1
18: e1a06002 mov r6, r2
1c: e3a010ff mov r1, #255 ; 0xff
20: e3a02014 mov r2, #20 ; 0x14
24: e1a00005 mov r0, r5
28: ebfffffe bl 28