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
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的協助，它也無法追蹤函數調用棧。

ssize_t faulty_read(struct file *filp, char __user *buf,
size_t count, loff_t *pos)
{
    int ret;
    char stack_buf[4];
 
    memset(stack_buf, 0xff, 20);
    if (count > 4)
        count = 4;
    ret = copy_to_user(buf, stack_buf, count);
    if (!ret)
        return count;
    return ret;
}

00000000 :
0: e1a0c00d mov ip, sp
4: e92dd870 stmdb sp!, {r4, r5, r6, fp, ip, lr, pc}
8: e24cb004 sub fp, ip, #4 ; 0×4
c: e24dd004 sub sp, sp, #4 ; 0×4，這裡為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 ; 0×14
24: e1a00005 mov r0, r5
28: ebfffffe bl 28 //這裡在調用memset
78: e89da878 ldmia sp, {r3, r4, r5, r6, fp, sp, pc}

這次OOP，讓我深刻地認識到：
核心能力超強，但它不是，也不可能是萬能的。所以即使你能力再強，也要和你的team member搞好關係，否則在關鍵時候你會倒黴的；
出錯的是faulty_read，vfs_read卻做了替罪羊。所以人不要被表面現象所迷惑，要深入看本質；
核心本來超級健壯，可是你寫的驅動是核心的組成部分，由於它出錯，結果整體崩盤。所以當你加入一個團隊的時候一定要告誡自己，雖然你的角色也許並不重要，但你的疏忽大意將足以令整個非常牛X的團隊崩盤。反過來說，當你是team leader的時候，在選團隊成員的時候一定要謹慎、謹慎、再謹慎，即使他只是一個小角色。
千萬別惹堆棧，它一旦出問題，定位錯誤將會是一件非常困難的事情。所以，千萬別惹你的領導，否則你將死得很難看。

三、利用strace

有時小問題可以通過監視程式監控使用者應用程式的行為來追蹤，同時監視程式也有助於建立對驅動正確工作的信心。例如，在看了它的讀實現如何響應不同數量資料的讀請求之後，我們能夠對scull正在正確運行感到有信心。

有幾個方法來監視使用者空間程式運行。你可以運行一個調試器來單步過它的函數，增加列印語句，或者在 strace 下運行程式。這裡，我們將討論最後一個技術，因為當真正目的是檢查核心代碼時，它是最有用的。

strace 命令是一個有力工具，它能顯示所有的使用者空間程式發出的系統調用。它不僅顯示調用，還以符號形式顯示調用的參數和傳回值。當一個系統調用失敗, 錯誤的符號值(例如, ENOMEM)和對應的字串(Out of memory) 都顯示。strace 有很多命令列選項，其中最有用的是 -t 來顯示每個調用執行的時間，-T 來顯示調用中花費的時間，-e 來限制被跟蹤調用的類型（例如strace –eread,write ls表示只監控read和write調用），以及-o 來重新導向輸出到一個檔案。預設情況下，strace 列印調用資訊到 stderr。

strace 從核心自身擷取資訊。這意味著可以跟蹤一個程式，不管它是否帶有調試支援編譯(對 gcc 是 -g 選項)以及不管它是否被strip過。此外，你也可以追蹤一個正在運行中的進程，這類似於調試器串連到一個運行中的進程並控制它。

跟蹤資訊常用來支援發給應用程式開發人員的故障報告，但是對核心程式員也是很有價值的。我們已經看到驅動代碼運行如何響應系統調用，strace 允許我們檢查每個調用的輸入和輸出資料的一致性。

例如，運行命令 strace ls /dev > /dev/scull0 將會在螢幕上顯示如下的內容：

open("/dev", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY) = 3
fstat64(3, {st_mode=S_IFDIR|0755, st_size=24576, …}) = 0
fcntl64(3, F_SETFD, FD_CLOEXEC) = 0
getdents64(3, , 4096) = 4088
[...]
getdents64(3, , 4096) = 0
close(3) = 0
[...]
fstat64(1, {st_mode=S_IFCHR|0664, st_rdev=makedev(254, 0), …}) = 0
write(1, "MAKEDEVnadmmidi0nadmmidi1nadmmid"…, 4096) = 4000
write(1, "bnptywcnptywdnptywenptywfnptyx0n"…, 96) = 96
write(1, "bnptyxcnptyxdnptyxenptyxfnptyy0n"…, 4096) = 3904
write(1, "s17nvcs18nvcs19nvcs2nvcs20nvcs21"…, 192) = 192
write(1, "nvcs47nvcs48nvcs49nvcs5nvcs50nvc"…, 673) = 673
close(1) = 0
exit_group(0) = ?

從第一個 write 調用看, 明顯地, 在 ls 結束查看目標目錄後，它試圖寫 4KB。但奇怪的是，只有 4000 位元組被成功寫入, 並且操作被重複。但當我們查看scull 中的寫實現，發現它一次最多隻允許寫一個quantum（共4000位元組），可見驅動本來就是期望部分寫。幾步之後, 所有東西清空, 程式成功退出。正是通過strace的輸出，使我們確信驅動的部分寫功能運行正確。

作為另一個例子, 讓我們讀取 scull 裝置(使用 wc scull0 命令):

[...]
open("/dev/scull0", O_RDONLY|O_LARGEFILE) = 3
fstat64(3, {st_mode=S_IFCHR|0664, st_rdev=makedev(254, 0), …}) = 0
read(3, "MAKEDEVnadmmidi0nadmmidi1nadmmid"…, 16384) = 4000
read(3, "bnptywcnptywdnptywenptywfnptyx0n"…, 16384) = 4000
read(3, "s17nvcs18nvcs19nvcs2nvcs20nvcs21"…, 16384) = 865
read(3, "", 16384) = 0
fstat64(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 1), …}) = 0
write(1, "8865 /dev/scull0n", 17) = 17
close(3) = 0
exit_group(0) = ?

如同期望的, read 一次只能擷取 4000 位元組，但是資料總量等同於前個例子寫入的。這個例子，意外的收穫是：可以肯定，wc 為快速讀進行了最佳化，它因此繞過了標準庫（沒有使用fscanf），而是直接一個系統調用以讀取更多資料。這一點，可從跟蹤到的讀的行裡看到wc一次試圖讀取16 KB的資料而確認。

四、利用ioctl方法

由於驅動中的ioctl函數可以將驅動的一些資訊返回給使用者程式，也可以讓使用者程式通過ioctl系統調用設定一些驅動的參數。所以在驅動的開發過程中，可以擴充一些ioctl的命令用於傳遞和設定調試驅動時所需各種資訊和參數，以達到調試驅動的目的。

五、利用/proc 檔案系統

/proc檔案系統用於核心向使用者空間暴露一些核心的資訊。因此出於調試的目的，我們可以在驅動代碼中增加向/proc檔案系統匯出有助於監視驅動的資訊的代碼。這樣一來，我們就可以通過查看/proc中的相關資訊來監視和調試驅動。如何在驅動中實現向/proc檔案系統匯出資訊，請參見《Linux Device Driver》的4.3節。
六、使用kgdb

kgdb是在核心源碼中打用於調試核心的補丁，然後通過相應的硬體和軟體，就可以像gdb單步調試應用程式一樣來調試核心（當然包括驅動）。至於kgdb如何使用，就請你google吧，實在不行，百度一下也可以。