Linux设备驱动调试技术 2

4.3  通过监视调试 
有时，通过监视用户空间中应用程序的运行情况，可以捕捉到一些小问题。监视程序同样也有助于确认驱动程序工作是否正常。例如，看到 scull的 read 实现如何响应不同数据量的 read 请求后，我们就可以判断它是否工作正常。

有许多方法可监视用户空间程序的工作情况。可以用调试器一步步跟踪它的函数，插入打印语句，或者在 strace状态下运行程序。在检查内核代码时，最后一项技术最值得关注，我们将在此对它进行讨论。

strace命令是一个功能非常强大的工具，它可以显示程序所调用的所有系统调用。它不仅可以显示调用，而且还能显示调用参数，以及用符号方式表示的返回值。当系统调用失败时，错误的符号值（如ENOMEM）和对应的字符串（如Out of memory）都能被显示出来。strace 有许多命令行选项；最为有用的是-t，用来显示调用发生的时间；-T，显示调用所花费的时间；-e，限定被跟踪的调用类型；-o，将输出重定向到一个文件中。默认情况下，strace将跟踪信息打印到 stderr 上。

strace从内核中接收信息。这意味着一个程序无论是否按调试方式编译（用 gcc 的-g选项）或是被去掉了符号信息都可以被跟踪。与调试器可以连接到一个运行进程并控制它一样，strace也可以跟踪一个正在运行的进程。

跟踪信息通常用于生成错误报告，然后发给应用开发人员，但是它对内核编程人员来说也同样非常有用。我们已经看到驱动程序是如何通过响应系统调用得到执行的；strace允许我们检查每次调用中输入和输出数据的一致性。

例如，下面的屏幕信息显示了 strace ls /dev > /dev/scull0命令的最后几行：

[...] 
open("/dev",O_RDONLY|O_NONBLOCK)    = 4 
fcntl(4, F_SETFD,FD_CLOEXEC)        = 0 
brk(0x8055000)                       = 0x8055000 
lseek(4, 0,SEEK_CUR)                = 0 
getdents(4, , 3933)   =1260 
[...] 
getdents(4, ,3933)    =0 
close(4)                             = 0 
fstat(1, {st_mode=S_IFCHR|0664, st_rdev=makedev(253, 0), ...}) =0 
ioctl(1, TCGETS,0xbffffa5c)         = -1 ENOTTY (Inappropriate ioctl 
                                                  for device) 
write(1, "MAKEDEV\natibm\naudio\naudio1\na"..., 4096) =4000 
write(1, "d2\nsdd3\nsdd4\nsdd5\nsdd6\nsdd7"..., 96) =96 
write(1, "4\nsde5\nsde6\nsde7\nsde8\nsde9\n"..., 3325) =3325 
close(1)                             = 0 
_exit(0)                             = ?

 

很明显，ls 完成对目标目录的检索后，在首次对 write 的调用中，它试图写入 4KB 数据。很奇怪（对于 ls来说），实际只写了4000个字节，接着它重试这一操作。然而，我们知道scull的 write 实现每次最多只写一个量子（scull中设置的量子大小为4000个字节），所以我们所预期的就是这样的部分写入。经过几个步骤之后，每件工作都顺利通过，程序正常退出。

另一个例子，让我们来对 scull 设备进行读操作（使用 wc 命令）：

[...] 
open("/dev/scull0",O_RDONLY)          = 4 
fstat(4, {st_mode=S_IFCHR|0664, st_rdev=makedev(253, 0), ...}) =0 
read(4, "MAKEDEV\natibm\naudio\naudio1\na"..., 16384) =4000 
read(4, "d2\nsdd3\nsdd4\nsdd5\nsdd6\nsdd7"..., 16384) =3421 
read(4, "",16384)                     = 0 
fstat(1, {st_mode=S_IFCHR|0600, st_rdev=makedev(3, 7), ...}) =0 
ioctl(1, TCGETS, {B38400 opost isig icanon echo ...}) =0 
write(1, "   7421 /dev/scull0\n",20)   =20 
close(4)                               = 0 
_exit(0)                               = ?

 

正如所料，read每次只能读取4000个字节，但数据总量与前面例子中写入的数量是相同的。与上面的写跟踪相对比，请读者注意本例中重试工作是如何组织的。为了快速读取数据，wc已被优化了，因而它绕过了标准库，试图通过一次系统调用读取更多的数据。可以从跟踪的 read 行中看到 wc 每次均试图读取 16KB数据。

Linux行家可以在 strace的输出中发现很多有用信息。如果觉得这些符号过于拖累的话，则可以仅限于监视文件方法（open，read 等）是如何工作的。

就个人观点而言，我们发现 strace 对于查找系统调用运行时的细微错误最为有用。通常应用或演示程序中的 perror调用在用于调试时信息还不够详细，而 strace 能够确切查明系统调用的哪个参数引发了错误，这一点对调试是大有帮助的。

4.4  调试系统故障 
即使采用了所有这些监视和调试技术，有时驱动程序中依然会有错误，这样的驱动程序在执行时就会产生系统故障。在出现这种情况时，获取尽可能多的信息对解决问题是至关重要的。

注意，“故障”不意味着“panic”。Linux代码非常健壮（用术语讲即为鲁棒，robust），可以很好地响应大部分错误：故障通常会导致当前进程崩溃，而系统仍会继续运行。如果在进程上下文之外发生故障，或是系统的重要组成被损害时，系统才有可能panic。但如果问题出在驱动程序中时，通常只会导致正在使用驱动程序的那个进程突然终止。唯一不可恢复的损失就是进程被终止时，为进程上下文分配的一些内存可能会丢失；例如，由驱动程序通过kmalloc 分配的动态链表可能丢失。然而，由于内核在进程中止时会对已打开的设备调用 close 操作，驱动程序仍可以释放由open 方法分配的资源。

我们已经说过，当内核行为异常时，会在控制台上打印出提示信息。下一节将解释如何解码并使用这些消息。尽管它们对于初学者来说相当晦涩，不过处理器在出错时转储出的这些数据包含了许多值得关注的信息，通常足以查明程序错误，而无需额外的测试。

4.4.1  oops消息 
大部分错误都在于 NULL指针的使用或其他不正确的指针值的使用上。这些错误通常会导致一个 oops 消息。

由处理器使用的地址都是虚拟地址，而且通过一个复杂的称为页表（见第 13章中的“页表”一节）的结构映射为物理地址。当引用一个非法指针时，页面映射机制就不能将地址映射到物理地址，此时处理器就会向操作系统发出一个“页面失效”的信号。如果地址非法，内核就无法“换页”到并不存在的地址上；如果此时处理器处于超级用户模式，系统就会产生一个“oops”。

值得注意的是，2.0 版本之后引入的第一个增强是，当向用户空间移动数据或者移出时，无效地址错误会被自动处理。Linus选择了让硬件来捕捉错误的内存引用，所以正常情况（地址都正确时）就可以更有效地得到处理。

oops 显示发生错误时处理器的状态，包括 CPU寄存器的内容、页描述符表的位置，以及其它看上去无法理解的信息。这些消息由失效处理函数（arch 
  *(int *)0 = 0; 
  return 0; 
}

 

正如读者所见，我们这使用了一个 NULL 指针。因为 0 决不会是个合法的指针值，所以错误发生，内核进入上面的 oops消息状态。这个调用进程接着就被杀掉了。在 read 实现中，faulty 模块还有更多有意思的错误状态。

char faulty_buf[1024];

ssize_t faulty_read (struct file *filp, char *buf, size_tcount, 
                  loff_t *pos) 
{ 
  int ret, ret2; 
  char stack_buf[4];

  printk(KERN_DEBUG "read: buf %p, count %li\n",buf, (long)count); 
   
  ret = copy_to_user(buf, faulty_buf,count); 
  if (!ret) return count;

  printk(KERN_DEBUG "didn't fail:retry\n"); 
   
  sprintf(stack_buf,"1234567\n"); 
  if (count > 8) count = 8; 
  ret2 = copy_to_user(buf, stack_buf,count); 
  if (!ret2) returncount; 
  return ret2; 
}

 

这段程序首先从一个全局缓冲区读取数据，但并不检查数据的长度，然后通过对一个局部缓冲区进行写入操作，制造一次缓冲区溢出。第一个操作仅在2.0 内核会导致 oops 的发生，因为后期版本能自动地处理用户拷贝函数。缓冲区溢出则会在所有版本的内核中造成 oops；然而，由于return 指令把指令指针带到了不知道的地方，所以这种错误很难跟踪，所能获得的仅是如下的信息：

EIP:   0010:[<00000000>] 
[...] 
Call Trace:[<c010b860>] 
Code:  Bad EIP value.

 

用户处理 oops消息的主要问题在于，我们很难从十六进制数值中看出什么内在的意义；为了使这些数据对程序员更有意义，需要把它们解析为符号。有两个工具可用来为开发人员完成这样的解析：klogd和 ksymoops。前者只要运行就会自行进行符号解码；后者则需要用户有目的地调用。下面的讨论，使用了在我们第一个 oops例子中通过使用NULL 指针而产生的出错信息。

使用 klogd 
klogd 守护进程能在 oops 消息到达记录文件之前对它们解码。很多情况下，klogd可以为开发者提供所有必要的信息用于捕捉问题的所在，可是有时开发者必须给它一定的帮助。

当 faulty 的一个oops 输出送达系统日志时，转储信息看上去会是下面的情况（注意 EIP 行和 stack跟踪记录中已经解码的符号）：

Unable to handle kernel NULL pointer dereference at virtual address\ 
  00000000 
printing eip: 
c48370c3 
*pde = 00000000 
Oops: 0002 
CPU:   0 
EIP:   0010:[faulty:faulty_write+3/576] 
EFLAGS: 00010286 
eax: ffffffea   ebx:c2c55ae0   ecx:c48370c0   edx:c2c55b00 
esi: 0804d038   edi:0804d038   ebp:c2337f8c   esp:c2337f8c 
ds: 0018   es:0018   ss:0018 
Process cat (pid: 23413,stackpage=c2337000) 
Stack: 00000001 c01356e6 c2c55ae0 0804d038 00000001 c2c55b00c2336000 \ 
         00000001 
    0804d038 bffffbd4 00000000 00000000 bffffbd4 c010b860 00000001\ 
         0804d038 
    00000001 00000001 0804d038 bffffbd4 00000004 0000002b 0000002b\ 
         00000004 
Call Trace: [sys_write+214/256][system_call+52/56]   
Code: c7 05 00 00 00 00 00 00 00 00 31 c0 89 ec 5d c3 8d b6 0000  

 

klogd 提供了大多数必要信息用于发现问题。在这个例子中，我们看到指令指针（EIP）正执行于函数 faulty_write中，因此我们就知道该从哪儿开始检查。字串 3/576 告诉我们处理器正处于函数的第3个字节上，而函数整体长度为 576个字节。注意这些数值都是十进制的，而非十六进制。

然而，当错误发生在可装载模块中时，为了获取错误相关的有用信息，开发者还必须注意一些情况。klogd在开始运行时装入所有可用符号，并随后使用这些符号。如果在 klogd 已经对自身初始化之后（一般在系统启动时），装载某个模块，那klogd 将不会有这个模块的符号信息。强制 klogd取得这些信息的办法是，发送一个 SIGUSR1 信号给 klogd进程，这种操作在时间顺序上，必须是在模块已经装入（或重新装载）之后，而在进行任何可能引起 oops 的处理之前。

还可以在运行 klogd 时加上 -p 选项，这会使它在任何发现 oops 消息的时刻重新读入符号信息。不过，klogd 的man手册不推荐这个方法，因为这使 klogd 在出问题之后再向内核查询信息。而发生错误之后，所获得的信息可能是完全错误的了。

为了使 klogd 正确地工作，必须给它提供符号表文件 System.map 的一个当前复本。通常这个文件在 /boot中；如果从一个非标准的位置编译并安装了一个内核，就需要把 System.map 拷贝到 /boot，或告知 klogd到什么位置查看。如果符号表与当前内核不匹配，klogd就会拒绝解析符号。假如一个符号被解析在系统日志中，那么就有理由确信它已被正确解析了。

使用 ksymoops 
有些时候，klogd对于跟踪目的而言仍显不足。开发者经常既需要取得十六进制地址，又要获得对应的符号，而且偏移量也常需要以十六进制的形式打印出来。除了地址解码之外，往往还需要更多的信息。对klogd 来说，在出错期间被杀掉，也是常用的事情。在这些情况下，可以调用一个更为强大的 oops 分析器，ksymoops就是这样的一个工具。

在 2.3 开发系列之前，ksymoops 是随内核源码一起发布的，位于 scripts 目录之下。它现在则在自己的FTP站点上，对它的维护是与内核相独立的。即使读者所用的仍是较早期的内核，或许还可以从ftp://ftp.ocs.com.au/pub/ksymoops 站点上获取这个工具的升级版本。

为了取得最佳的工作状态，除错误消息之外，ksymoops还需要很多信息；可以使用命令行选项告诉它在什么地方能找到这些各个方面的内容。ksymoops 需要下列内容项：

System.map 文件这个映射文件必须与 oops 发生时正在运行的内核相一致。默认为/usr/src/linux/System.map。 
模块列表ksymoops 需要知道 oops 发生时都装入了哪些模块，以便获得它们的符号信息。如果未提供这个列表，ksymoops会查看 /proc/modules。 
在 oops 发生时已定义好的内核符号表默认从 /proc/ksyms中取得该符号表。 
当前正运行的内核映像的复本注意，ksymoops 需要的是一个直接的内核映像，而不是象 vmlinuz、zImage 或bzImage这样被大多数系统所使用的压缩版本。默认是不使用内核映像，因为大多数人都不会保存这样的一个内核。如果手边就有这样一个符合要求的内核的话，就应该采用-v 选项告知 ksymoops 它的位置。 
已装载的任何内核模块的目标文件位置ksymoops 将在标准目录路径寻找这些模块，不过在开发中，几乎总要采用 -o 选项告知ksymoops 这些模块的存放位置。

虽然 ksymoops 会访问 /proc 中的文件来取得它所需的信息，但这样获得的结果是不可靠的。在 oops 发生和ksymoops 运行的时间间隙中，系统几乎一定会重新启动，这样取自 /proc的信息就可能与故障发生时的实际状态不符合。只要有可能，最好在引起 oops 发生之前，保存 /proc/modules 和/proc/ksyms 的复本。

我们强烈建议驱动程序开发人员阅读 ksymoops 的手册页，这是一个很好的资料文档。

这个工具命令行中的最后一个参数是 oops 消息的位置；如果缺少这个参数，ksymoops 会按Unix的惯例去读取标准输入设备。运气好的话，消息可以从系统日志中重新恢复；在发生很严重的崩溃情况时，我们可能不得不将这些消息从屏幕上抄下来，然后再敲进去（除非用的是串口控制台，这对内核开发人员来说，是非常棒的工具）。

注意，当 oops 消息已经被 klogd 处理过时，ksymoops 将会陷于混乱。如果 klogd 已经运行，而且 oops发生后系统仍在运行，那么经常可以通过调用 dmesg 命令来获得一个干净的 oops 消息。

如果没有明确地提供全部的上述信息，ksymoops会发出警告。对于载入模块未作符号定义这类的情况，它同样会发出警告。一个不作任何警告的 ksymoops 是很少见的。

ksymoops 的输出类似如下：

>>EIP; c48370c3<[faulty]faulty_write+3/20>  <===== 
Trace; c01356e6<sys_write+d6/100> 
Trace; c010b860<system_call+34/38> 
Code;  c48370c3<[faulty]faulty_write+3/20> 
00000000<_EIP>: 
Code;  c48370c3<[faulty]faulty_write+3/20>  <===== 
 0:   c7 05 0000 00   movl  $0x0,0x0  <===== 
Code;  c48370c8<[faulty]faulty_write+8/20> 
 5:   00 00 0000 00 
Code;  c48370cd<[faulty]faulty_write+d/20> 
 a:   31c0            xorl  �x,�x 
Code;  c48370cf<[faulty]faulty_write+f/20> 
 c:   89ec            movl  �p,%esp 
Code;  c48370d1<[faulty]faulty_write+11/20> 
 e:  5d               popl  �p 
Code;  c48370d2<[faulty]faulty_write+12/20> 
 f:  c3               ret     
Code;  c48370d3<[faulty]faulty_write+13/20> 
10:   8d b6 00 0000   leal  0x0(%esi),%esi 
Code;  c48370d8<[faulty]faulty_write+18/20> 
15:   00

 

正如上面所看到的，ksymoops 提供的 EIP 和内核堆栈信息与 klogd所做的很相似，不过要更为准确，而且是十六进制形式的。可以注意到，faulty_write 函数的长度被正确地报告为0x20个字节。这是因为 ksymoops 读取了模块的目标文件，并从中获得了全部的有用信息。

而且在这个例子中，还可以得到错误发生处代码的汇编语言形式的转储输出。这些信息常被用于确切地判断发生了些什么事情；这里很明显，错误在于一个向0 地址写入数据 0 的指令。

ksymoops 的一个有趣特点是，它可以移植到几乎所有 Linux 可以运行的平台上，而且还利用了 bfd（二进制格式描述）库同时支持多种计算机结构。走出 PC 的世界，我们可以看到 SPARC64 平台上显示的 oops消息是何等的相似（为了便于排版有几行被打断了）：

Unable to handle kernel NULL pointerdereference 
tsk->mm->context =0000000000000734 
tsk->mm->pgd =fffff80003499000 
           \/ ____ \/ 
           "@'/ .. \`@" 
          /_| \_ _/ |_\ 
             \_ _ _/ 
ls(16740): Oops 
TSTATE: 0000004400009601 TPC: 0000000001000128 TNPC:0000000000457fbc \ 
Y: 00800000 
g0: 000000007002ea88 g1: 0000000000000004 g2: 0000000070029fb0\ 
g3: 0000000000000018 
g4: fffff80000000000 g5: 0000000000000001 g6: fffff8000119c000\ 
g7: 0000000000000001 
o0: 0000000000000000 o1: 000000007001a000 o2: 0000000000000178\ 
o3: fffff8001224f168 
o4: 0000000001000120 o5: 0000000000000000 sp: fffff8000119f621\ 
ret_pc: 0000000000457fb4 
l0: fffff800122376c0 l1: ffffffffffffffea l2: 000000000002c400\ 
l3: 000000000002c400 
l4: 0000000000000000 l5: 0000000000000000 l6: 0000000000019c00\ 
l7: 0000000070028cbc 
i0: fffff8001224f140 i1: 000000007001a000 i2: 0000000000000178\ 
i3: 000000000002c400 
i4: 000000000002c400 i5: 000000000002c000 i6: fffff8000119f6e1\ 
i7: 0000000000410114 
Caller[0000000000410114] 
Caller[000000007007cba4] 
Instruction DUMP: 01000000 90102000 81c3e008<c0202000>\ 
30680005 01000000 01000000 01000000 01000000

 

请注意，指令转储并不是从引起错误的那个指令开始，而是之前的三条指令：这是因为 RISC平台以并行的方式执行多条指令，这样可能产生延期的异常，因此必须能回溯最后的几条指令。

下面是当从 TSTATE 行开始输入数据时，ksymoops 所打印出的信息：

>>TPC; 0000000001000128<[faulty].text.start+88/a0>  <===== 
>>O7; 0000000000457fb4<sys_write+114/160> 
>>I7; 0000000000410114<linux_sparc_syscall+34/40> 
Trace; 0000000000410114<linux_sparc_syscall+34/40> 
Trace; 000000007007cba4<END_OF_CODE+6f07c40d/????> 
Code;  000000000100011c<[faulty].text.start+7c/a0> 
0000000000000000<_TPC>: 
Code;  000000000100011c<[faulty].text.start+7c/a0> 
 0:   01 00 0000      nop 
Code;  0000000001000120<[faulty].text.start+80/a0> 
 4:   90 10 2000      clr %o0    ! 0<_TPC> 
Code;  0000000001000124<[faulty].text.start+84/a0> 
 8:   81 c3 e008      retl 
Code;  0000000001000128<[faulty].text.start+88/a0>  <===== 
 c:   c0 20 2000      clr  [ %g0 ]  <===== 
Code;  000000000100012c<[faulty].text.start+8c/a0> 
10:   30 68 0005      b,a   %xcc, 24<_TPC+0x24>\ 
                     0000000001000140<[faulty]faulty_write+0/20> 
Code;  0000000001000130<[faulty].text.start+90/a0> 
14:   01 00 0000      nop 
Code;  0000000001000134<[faulty].text.start+94/a0> 
18:   01 00 0000      nop 
Code;  0000000001000138<[faulty].text.start+98/a0> 
1c:   01 00 0000      nop 
Code;  000000000100013c<[faulty].text.start+9c/a0> 
20:   01 00 0000      nop

 

要打印出上面显示的反汇编代码，我们就必须告知 ksymoops 目标文件的格式和结构(之所以需要这些信息，是因为 SPARC64用户空间的本地结构是32位的)。本例中，使用选项 -t elf64-sparc -a sparc:v9 可进行这样的设置。

读者可能会抱怨对调用的跟踪并没带回什么值得注意的信息；然而，SPARC 处理器并不会把所有的调用跟踪记录保存到堆栈中：07 和 I7寄存器保存了最后调用的两个函数的指令指针，这就是它们出现在调用跟踪记录边上的原因。在这个例子中，我们可以看到，故障指令位于一个由sys_write 调用的函数中。

要注意的是，无论平台/结构是怎样的一种配合情况，用来显示反汇编代码的格式与 objdump 程序所使用的格式是一样的。objdump是个很强大的工具；如果想查看发生故障的完整函数，可以调用命令： objdump -d faulty.o（再次重申，对于 SPARC64平台，需要使用特殊选项：--target elf64-sparc-architecture sparc:v9）。

关于 objdump 和它的命令行选项的更多信息，可以参阅这个命令的手册页帮助。

学习对 oops消息进行解码，需要一定的实践经验，并且了解所使用的目标处理器，以及汇编语言的表达习惯等。这样的准备是值得的，因为花费在学习上的时间很快会得到回报。即使之前读者已经具备了非Unix 操作系统中PC 汇编语言的专门知识，仍有必要花些时间对此进行学习，因为Unix 的语法与 Intel 的语法并不一样。（在as 命令 infor 页的“i386-specific”一章中，对这种差异进行了很好的描述。）