驅動調試方法

內核打印函數printk

調試內核、驅動最簡單的方法就是使用printk函數打印信息；

printk函數的打印級別

printk函數與用戶空間的printf函數格式完全相同，它所打印的字符串頭部可以加入“ ”樣式的字符，其中n為0~7，表示這條信息的打印級別；

在內核代碼：include/linux/kernel.h中，下面幾個宏控制了printk函數所能輸出的信息的記錄級別：

#define console_loglevel (console_printk[0])
#define default_message_loglevel (console_printk[1])
#define minimum_console_loglevel (console_printk[2])
#define default_console_loglevel (console_printk[3])

分別說明以上各宏的含義：

1. 對於printk(" "....)，只有n小於console_loglevel時，這個信息才會被打印；
2. 假設default_message_loglevel的值等於4，如果printk的參數開頭沒有“ ”樣式的字符，則在printk函數中進一步處理前會自動加上“<4>”；
3. minimum_console_loglevel是一個預設值，平時不起作用，當通過其他方式來設置console_loglevel的值時，這個值不能小於minimum_console_loglevel；
4. default_console_loglevel是一個預設值，平時不起作用，它表示設置console_loglevel時的默認值，通過其他某種方式來設置console_loglevel的值時會用到這個值；

在用戶空間修改printk函數的打印級別

當掛接proc文件系統后，讀取/proc/sys/kernel/printk文件就可以得到console_loglevel、default_message_loglevel、minimum_console_loglevel以及default_console_loglevel各自的值；

比如執行命令：

cat /proc/sys/kernel/printk
7       4       1       7   //console_loglevel=7,default_message_loglevel=4
                            //minimum_console_loglevel=1,default_console_loglevel=7
/* 可以使用下面的命令修改console_loglevel=1，這樣所有的printk信息都不會被打印 */
echo "1 4 1 7" > /proc/sys/kernel/printk

啟動時打印信息需要耗費一定的時間，可以在傳入內核的啟動參數中設置loglevel=0，來修改打印級別，這樣會屏蔽所有的打印信息(關於內核啟動參數的設置可參考內核源碼目錄下的kernel-parameters.txt文件)；

具體的打印級別有如下幾種：

在內核代碼：/include/linux/kernel.h；

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

log_buf[]中存放着所有的內核打印信息，至於這些信息是否打印出去要看對應的級別，可以使用dmesg命令打印出，臨時log_buf[]中的數據打印出來，重現內核的輸出信息；

Oops信息及棧回溯

當內核出錯時(比如訪問了非法地址)打印出來的信息被稱為Oops信息；

Oops信息

Unable to handle kernel paging request at virtual address 56000050
pgd = c3ca0000
[56000050] *pgd=00000000
Internal error: Oops: 5 [#1]
Modules linked in: jz2440_leds
CPU: 0    Not tainted  (2.6.22.6 #4)
PC is at jz2440_led_drv_open+0x3c/0xd0 [jz2440_leds]
LR is at chrdev_open+0x14c/0x164
pc : [<bf00003c>]    lr : [<c008d888>]    psr: 80000013
sp : c073be88  ip : c073be98  fp : c073be94
r10: 00000000  r9 : c073a000  r8 : c04debe0
r7 : 00000000  r6 : 00000000  r5 : c3ea30c0  r4 : c06f06c0
r3 : 00000000  r2 : 56000050  r1 : bf000bc4  r0 : c3ea30c0
Flags: Nzcv  IRQs on  FIQs on  Mode SVC_32  Segment user
Control: c000717f  Table: 33ca0000  DAC: 00000015
Process ledtest (pid: 801, stack limit = 0xc073a258)
Stack: (0xc073be88 to 0xc073c000)
be80:                   c073bebc c073be98 c008d888 bf000010 00000000 c04debe0
bea0: c3ea30c0 c008d73c c0474da0 c3ee1dac c073bee4 c073bec0 c0089e48 c008d74c
bec0: c04debe0 c073bf04 00000003 ffffff9c c002c044 c3d06000 c073befc c073bee8
bee0: c0089f64 c0089d58 00000000 00000002 c073bf68 c073bf00 c0089fb8 c0089f40
bf00: c073bf04 c3ee1dac c0474da0 00000000 00000000 c3ca1000 00000101 00000001
bf20: 00000000 c073a000 c046d508 c046d500 ffffffe8 c3d06000 c073bf68 c073bf48
bf40: c008a16c c009fc70 00000003 00000000 c04debe0 00000002 00000004 c073bf94
bf60: c073bf6c c008a2f4 c0089f88 000085a0 becbced4 000086e8 0000874c 00000005
bf80: c002c044 4013365c c073bfa4 c073bf98 c008a3a8 c008a2b0 00000000 c073bfa8
bfa0: c002bea0 c008a394 becbced4 000086e8 becbcf92 00000002 00000004 becbcf92
bfc0: becbced4 000086e8 0000874c 00000003 000085a0 00000000 4013365c becbcea8
bfe0: 00000000 becbce80 0000266c 400c98e0 60000010 becbcf92 00000000 00000000
Backtrace:
[<bf000000>] (jz2440_led_drv_open+0x0/0xd0 [jz2440_leds]) from [<c008d888>] (chrdev_open+0x14c/0x164)
[<c008d73c>] (chrdev_open+0x0/0x164) from [<c0089e48>] (__dentry_open+0x100/0x1e8)
 r8:c3ee1dac r7:c0474da0 r6:c008d73c r5:c3ea30c0 r4:c04debe0
[<c0089d48>] (__dentry_open+0x0/0x1e8) from [<c0089f64>] (nameidata_to_filp+0x34/0x48)
[<c0089f30>] (nameidata_to_filp+0x0/0x48) from [<c0089fb8>] (do_filp_open+0x40/0x48)
 r4:00000002
[<c0089f78>] (do_filp_open+0x0/0x48) from [<c008a2f4>] (do_sys_open+0x54/0xe4)
 r5:00000004 r4:00000002
[<c008a2a0>] (do_sys_open+0x0/0xe4) from [<c008a3a8>] (sys_open+0x24/0x28)
[<c008a384>] (sys_open+0x0/0x28) from [<c002bea0>] (ret_fast_syscall+0x0/0x2c)
Code: bf00007c bf0000a0 e59f1090 e5912000 (e5923000)
Segmentation fault

上述Oops信息主要有：

1. 一段文本描述信息；

   比如類似“Unable to handle kernel paging request at virtual address 56000050”的信息，說明了發生的是哪類錯誤；

2. Oops信息的序號；

   比如第1次、第2次等，類似“Internal error: Oops: 5 [#1]”，括號內的數字表示序號；

3. 內核加載模塊的名稱，也可能沒有，以“Modules linked in”開頭的，類似“Modules linked in: jz2440_leds”；

4. 發生錯誤的CPU的序號，對於單處理器的系統，序號為0，比如：

   “CPU: 0 Not tainted (2.6.22.6 #4)”

5. 發生錯誤時CPU的各個寄存器值，如下：

   pc : [<bf00003c>]    lr : [<c008d888>]    psr: 80000013
   sp : c073be88  ip : c073be98  fp : c073be94
   r10: 00000000  r9 : c073a000  r8 : c04debe0
   r7 : 00000000  r6 : 00000000  r5 : c3ea30c0  r4 : c06f06c0
   r3 : 00000000  r2 : 56000050  r1 : bf000bc4  r0 : c3ea30c0
   

6. 當前進程的名字及進程ID，比如“Process ledtest (pid: 801, stack limit = 0xc073a258)”；

   這並不是說發生錯誤的就是這個進程，而是表示發生錯誤時，當前進程是它，錯誤可能發生在內核代碼、驅動程序，也可能就是這個進程的錯誤；

7. 棧信息；

   Stack: (0xc073be88 to 0xc073c000)
   be80:                   c073bebc c073be98 c008d888 bf000010 00000000 c04debe0
   bea0: c3ea30c0 c008d73c c0474da0 c3ee1dac c073bee4 c073bec0 c0089e48 c008d74c
   bec0: c04debe0 c073bf04 00000003 ffffff9c c002c044 c3d06000 c073befc c073bee8
   bee0: c0089f64 c0089d58 00000000 00000002 c073bf68 c073bf00 c0089fb8 c0089f40
   bf00: c073bf04 c3ee1dac c0474da0 00000000 00000000 c3ca1000 00000101 00000001
   bf20: 00000000 c073a000 c046d508 c046d500 ffffffe8 c3d06000 c073bf68 c073bf48
   bf40: c008a16c c009fc70 00000003 00000000 c04debe0 00000002 00000004 c073bf94
   bf60: c073bf6c c008a2f4 c0089f88 000085a0 becbced4 000086e8 0000874c 00000005
   bf80: c002c044 4013365c c073bfa4 c073bf98 c008a3a8 c008a2b0 00000000 c073bfa8
   bfa0: c002bea0 c008a394 becbced4 000086e8 becbcf92 00000002 00000004 becbcf92
   bfc0: becbced4 000086e8 0000874c 00000003 000085a0 00000000 4013365c becbcea8
   bfe0: 00000000 becbce80 0000266c 400c98e0 60000010 becbcf92 00000000 00000000
   

8. 棧回溯信息，可以看到函數的調用關系，如下：

   Backtrace:
   [<bf000000>] (jz2440_led_drv_open+0x0/0xd0 [jz2440_leds]) from [<c008d888>] (chrdev_open+0x14c/0x164)
   [<c008d73c>] (chrdev_open+0x0/0x164) from [<c0089e48>] (__dentry_open+0x100/0x1e8)
    r8:c3ee1dac r7:c0474da0 r6:c008d73c r5:c3ea30c0 r4:c04debe0
   [<c0089d48>] (__dentry_open+0x0/0x1e8) from [<c0089f64>] (nameidata_to_filp+0x34/0x48)
   [<c0089f30>] (nameidata_to_filp+0x0/0x48) from [<c0089fb8>] (do_filp_open+0x40/0x48)
    r4:00000002
   [<c0089f78>] (do_filp_open+0x0/0x48) from [<c008a2f4>] (do_sys_open+0x54/0xe4)
    r5:00000004 r4:00000002
   [<c008a2a0>] (do_sys_open+0x0/0xe4) from [<c008a3a8>] (sys_open+0x24/0x28)
   [<c008a384>] (sys_open+0x0/0x28) from [<c002bea0>] (ret_fast_syscall+0x0/0x2c)
   

9. 出錯指令附近的指令的機器碼，比如(出錯指令在小括號內)：

   Code: bf00007c bf0000a0 e59f1090 e5912000 (e5923000)
   

分析Oops信息

• 從文本描述可直接看出錯誤原因，“Unable to handle kernel paging request at virtual address 56000050”，可知無法在虛擬地址56000050處理內核分頁請求；

• 根據棧回溯找出函數調用關系

  內核崩潰時，可以從pc寄存器得知崩潰發生時的函數、出錯指令，但是很多情況下，錯誤有可能時它的調用者引入的，所以找出函數的調用關系也是很重要的；

  由於內核配置了CONFIG_FRAME_POINTER，當出現Oops信息時，會打印棧回溯信息；

  部分回溯信息如下：

  [<bf000000>] (jz2440_led_drv_open+0x0/0xd0 [jz2440_leds]) from [<c008d888>] (chrdev_open+0x14c/0x164)
  

  這行信息為兩部分，表示后面的chrdev_open函數調用了前面的jz2440_led_drv_open函數；

  前半部分含義為：“bf000000”是jz2440_led_drv_open函數首地址偏移0的地址，這個函數大小為0xd0；

  后半部分含義為：“c008d888”是chrdev_open函數首地址偏移0x14c的地址，這個函數大小為0x164；

  另外后半部分的“[ ] ”表示jz2440_led_drv_open執行后的返回地址；

  對於類似下面的棧回溯信息，其中寄存器值就表示jz2440_led_drv_open剛被調用時這些寄存器的值：

  pc : [<bf00003c>]    lr : [<c008d888>]    psr: 80000013
  sp : c073be88  ip : c073be98  fp : c073be94
  r10: 00000000  r9 : c073a000  r8 : c04debe0
  r7 : 00000000  r6 : 00000000  r5 : c3ea30c0  r4 : c06f06c0
  r3 : 00000000  r2 : 56000050  r1 : bf000bc4  r0 : c3ea30c0
  

  從上面的棧回溯信息可以知道內核出錯時的函數調用關系如下，最后在jz2440_led_drv_open函數內部崩潰：

  ret_fast_syscall ->
  	sys_open ->
  		do_sys_open ->
  			do_filp_open ->
  				nameidata_to_filp ->
  					__dentry_open ->
  						chrdev_open ->
  							jz2440_led_drv_open
  

• 根據PC寄存器的值確定出錯位置；

  PC is at jz2440_led_drv_open+0x3c/0xd0 [jz2440_leds]
  LR is at chrdev_open+0x14c/0x164
  pc : [<bf00003c>]    lr : [<c008d888>]    psr: 80000013
  

  "PC is at jz2440_led_drv_open+0x3c/0xd0"表示出錯指令為jz2440_led_drv_open函數中偏移為0x3c的指令；

  “pc : [ ]”表示出錯指令的地址為0xbf00003c；

  先判斷這個指令地址屬於內核還是外加模塊的？

  • 先查看內核編譯之后內核源碼目錄下的System.map文件來確定內核的函數的地址范圍為c0004000~c03cecb4，所以0xbf00003c不屬於內核而是外加模塊的；

  • 查看cat /proc/kallsyms(所有內核函數、加載函數的地址)找到一個相近的地址來確定屬於哪個模塊；

    由於這個文件比較大，所以可以cat /proc/kallsyms > kallsyms.txt，導出到kallsyms.txt查看；

    可以找到“bf000000 t jz2440_led_drv_open [jz2440_leds]”，可以確定是在jz2440_leds.ko這個模塊中；

  • 找到對應的jz2440_leds.ko文件，反匯編"arm-linux-objdump -D jz2440_leds.ko > jz2440_leds.dis",查看反匯編文件找到對應的函數，再根據目前的PC指代的地址和找到的相近的地址算出偏移值，最終可定位到哪條語句發生了錯誤；

• 使用Oops信息手工進行棧回溯；

  一個程序包含代碼段、數據段、BBS段、堆、棧；其中數據段用來存儲初始值不為0的全局數據，BSS段用來存儲初始值為0的全局數據，堆用於動態內存分配，棧用於實現函數調用、存儲局部變量；

  被調用函數在執行之前，它將一些寄存器的值保存在堆棧中，其中包括返回地址寄存器lr，如果知道了所保存的lr寄存器的值，那么就可以知道它的調用者是誰，在棧信息中，一個函數一個函數地往上找出所有保存lr的值，就可以知道各個調用函數，這就是棧回溯的原理；