Linux系統驅動開發調試技術指南

 　　一、使用printk

　　這是驅動開發中最樸實無華，同時也是最常用和有效的手段。scull驅動的main.c第338行如下，就是使用printk進行調試的例子，這樣的例子相信大家在閱讀驅動源碼時隨處可見。

　　printk(KERN_ALERT "wakeup by signal in process %dn", current->;pid);

　　printk的功能與我們經常在應用程序中使用的printf是一樣的，不同之處在於printk可以在打印字符串前面加上內核定義的宏，例如上面例子中的KERN_ALERT(注意：宏與字符串之間沒有逗號):

　　#define KERN_EMERG ""

　　#define KERN_ALERT ""

　　#define KERN_CRIT ""

　　#define KERN_ERR ""

　　#define KERN_WARNING ""

　　#define KERN_NOTICE ""

　　#define KERN_INFO ""

　　#define KERN_DEBUG ""

　　#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語句再重新加上。OMG，殺了我吧。所以，我們需要一種能方便地打開和關閉調試信息的手段。哪裡能找到這種手段呢?哈哈，遠在天邊，近在眼前。看看scull驅動或者leds驅動的源代碼吧!

　　#define LEDS_DEBUG

　　#undef PDEBUG

　　#ifdef LEDS_DEBUG

　　#ifdef __KERNEL__

　　#define PDEBUG(fmt, args…) printk( KERN_EMERG "leds: " fmt, ## args)

　　#else

　　#define PDEBUG(fmt, args…) fprintf(stderr, fmt, ## args)

　　#endif

　　#else

　　#define PDEBUG(fmt, args…)

　　#endif

　　#undef PDEBUGG

　　#define PDEBUGG(fmt, args…)

　　這樣一來，在開發驅動的過程中，如果想打印調試消息，我們就可以用 PDEBUG("address of i_cdev is %pn", 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地址寫入，這是內核絕對不會容許的。

　　ssize_t faulty_write (struct file *filp, const char __user *buf, size_t count, loff_t *pos)

　　{

　　*(int *)0 = 0;

　　return 0;

　　}

　　Unable to handle kernel NULL pointer dereference at virtual address 00000000

　　pgd = c3894000

　　[00000000] *pgd=33830031, *pte=00000000, *ppte=00000000

　　Internal error: Oops: 817 [#1] PREEMPT

　　Modules linked in: faulty scull

　　CPU: 0 Not tainted (2.6.22.6 #4)

　　PC is at faulty_write+0×10/0×18 [faulty]

　　LR is at vfs_write+0xc4/0×148

　　pc : [] lr : [] psr: a0000013

　　sp : c3871f44 ip : c3871f54 fp : c3871f50

　　r10: 4021765c r9 : c3870000 r8 : 00000000

　　r7 : 00000004 r6 : c3871f78 r5 : 40016000 r4 : c38e5160

　　r3 : c3871f78 r2 : 00000004 r1 : 40016000 r0 : 00000000

　　Flags: NzCv IRQs on FIQs on Mode SVC_32 Segment user

　　Control: c000717f Table: 33894000 DAC: 00000015

　　Process sh (pid: 745, stack limit = 0xc3870258)

　　Stack: (0xc3871f44 to 0xc3872000)

　　1f40: c3871f74 c3871f54 c0088eb8 bf00608c 00000004 c38e5180 c38e5160

　　1f60: c3871f78 00000000 c3871fa4 c3871f78 c0088ffc c0088e04 00000000 00000000

　　1f80: 00000000 00000004 40016000 40215730 00000004 c002c0e4 00000000 c3871fa8

　　1fa0: c002bf40 c0088fc0 00000004 40016000 00000001 40016000 00000004 00000000

　　1fc0: 00000004 40016000 40215730 00000004 00000001 00000000 4021765c 00000000

　　1fe0: 00000000 bea60964 0000266c 401adb40 60000010 00000001 00000000 00000000

　　Backtrace:

　　[] (faulty_write+0×0/0×18 [faulty]) from [] (vfs_write+0xc4/0×148)

　　[] (vfs_write+0×0/0×148) from [] (sys_write+0x4c/0×74)

　　r7:00000000 r6:c3871f78 r5:c38e5160 r4:c38e5180

　　[] (sys_write+0×0/0×74) from [] (ret_fast_syscall+0×0/0x2c)

　　r8:c002c0e4 r7:00000004 r6:40215730 r5:40016000 r4:00000004

　　Code: e1a0c00d e92dd800 e24cb004 e3a00000 (e5800000)

　　1行驚訝的原因，也就是報告出錯的原因;

　　2-4行是OOP信息序號;

　　5行是出錯時內核已加載模塊;

　　6行是發生錯誤的CPU序號;

　　7-15行是發生錯誤的位置，以及當時CPU各個寄存器的值，這最有利於我們找出問題所在地;

　　16行是當前進程的名字及進程ID

　　17-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 ; 0×4

　　88: e3a00000 mov r0, #0 ; 0×0

　　8c: e5800000 str r0, [r0]

　　90: e89da800 ldmia sp, {fp, sp, pc}

　　定位出錯位置以及獲取相關信息的過程：

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

　　25 [] (faulty_write+0×0/0×18 [faulty]) from [] (vfs_write+0xc4/0×148)

　　26 [] (vfs_write+0×0/0×148) from [] (sys_write+0x4c/0×74)

　　出錯代碼是 faulty_write 函數中的第5條指令((0xbf00608c-0xbf00607c)/4+1=5)，該函數的首地址是0xbf00607c，該函數總共6條指令(0×18)，該函數是被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/0×140

　　8 LR is at 0xffffffff