Linux内核程序调试

发表于 | 阅读次数

Kernel Oops

当我们编写的Linux内核程序含有Bug时会出现下面所示的情况，屏幕输出内核错误信息，我们称之为Oops。此时系统需要重启才能继续使用。

注意，这里有三行十分重要。BUG指出了错误原因，IP寄存器的值则指出了错误位置相对于函数开始位置的偏移量。比如下面的出错位置在距离函数hydra_hook_func_out开始位置偏移量为0xb8的机器代码处。后文还会提到它们。Oops指出了错误代码，含义如下：

  • bit 0 == 0 means no page found, 1 means protection fault
  • bit 1 == 0 means read, 1 means write
  • bit 2 == 0 means kernel, 1 means user-mode
  • bit 3 == 0 means data, 1 means instruction

这里的错误代码 0000 意思是内核数据读错误。 #1 表示这个错误发生一次。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
[  804.963442] BUG: unable to handle kernel NULL pointer dereference at           (null)
[  804.964875] IP: [<ffffffffc07a10b8>] hydra_hook_func_out+0xb8/0x140 [hydra]
[  804.966112] PGD 7af27067 PUD 7bead067 PMD 0 
[  804.966924] Oops: 0000 [#1] SMP 
[  804.967556] Modules linked in: hydra(O) tyz_memfs(O) rfcomm bnep bluetooth snd_ens1371 snd_ac97_codec ac97_bus gameport snd_pcm vmwgfx snd_seq_midi snd_seq_midi_event snd_rawmidi coretemp snd_seq crct10dif_pclmul crc32_pclmul ghash_clmulni_intel aesni_intel snd_seq_device snd_timer aes_x86_64 ttm lrw snd gf128mul glue_helper ablk_helper cryptd vmw_balloon drm_kms_helper soundcore serio_raw drm 8250_fintek i2c_piix4 shpchp vmw_vmci parport_pc mac_hid ppdev lp parport hid_generic usbhid hid mptspi mptscsih psmouse mptbase e1000 ahci libahci scsi_transport_spi pata_acpi floppy vmw_pvscsi vmxnet3
[  804.978080] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G           O   3.19.0 #1
[  804.979272] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 07/31/2013
[  804.981242] task: ffffffff81c1c4e0 ti: ffffffff81c00000 task.ti: ffffffff81c00000
[  804.982511] RIP: 0010:[<ffffffffc07a10b8>]  [<ffffffffc07a10b8>] hydra_hook_func_out+0xb8/0x140 [hydra]
[  804.984235] RSP: 0018:ffff88007f603698  EFLAGS: 00010096
[  804.985195] RAX: 000000000000000c RBX: ffff8800641ccf00 RCX: 0000000000003162
[  804.986422] RDX: 000000000000000a RSI: ffff88007f6036a0 RDI: 0000000000000000
[  804.987635] RBP: ffff88007f6036d8 R08: 0000000000000092 R09: 296c6c756e28203a
[  804.988851] R10: 0000000000000688 R11: ffff88007f6033ee R12: ffffffff816d57f0
[  804.990152] R13: ffff88002dca4000 R14: 00000000000009f8 R15: 0000000000000282
[  804.991415] FS:  0000000000000000(0000) GS:ffff88007f600000(0000) knlGS:0000000000000000
[  804.992798] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  804.993818] CR2: 0000000000000000 CR3: 000000007a402000 CR4: 00000000001407f0
[  804.995087] Stack:
[  804.995447]  ffff88007f613e00 ffff88007f603700 ffffffff810ac912 ffff88007f603780
[  804.997277]  ffffffff816d57f0 ffff88002dca4000 0000000000000000 ffff8800641ccf00
[  804.998657]  ffff88007f603738 ffffffff816ca71a ffff88007f603787 ffffffff81d1f460
[  805.000038] Call Trace:
[  805.000466]  <IRQ> 
[  805.000821]  [<ffffffff810ac912>] ? enqueue_task_fair+0x422/0x6a0
[  805.001986]  [<ffffffff816d57f0>] ? ip_fragment+0x8a0/0x8a0
[  805.002951]  [<ffffffff816ca71a>] nf_iterate+0x9a/0xb0
[  805.003836]  [<ffffffff816d57f0>] ? ip_fragment+0x8a0/0x8a0
[  805.004836]  [<ffffffff816ca7a4>] nf_hook_slow+0x74/0x130
[  805.005768]  [<ffffffff816d57f0>] ? ip_fragment+0x8a0/0x8a0
[  805.006723]  [<ffffffff816d74c2>] ip_output+0x92/0xa0
[  805.007593]  [<ffffffff8101d2c9>] ? sched_clock+0x9/0x10
[  805.008509]  [<ffffffff816d6bd0>] ip_local_out_sk+0x30/0x40
[  805.009480]  [<ffffffff816d6d43>] ip_build_and_send_pkt+0x163/0x220
[  805.010547]  [<ffffffff816f67d5>] tcp_v4_send_synack+0x65/0xc0
[  805.011538]  [<ffffffff816f7d5d>] ? tcp_openreq_init_rwin+0xbd/0x1c0
[  805.012624]  [<ffffffff816e44c5>] tcp_conn_request+0x4f5/0x750
[  805.013620]  [<ffffffff8101c493>] ? nommu_map_page+0x43/0x80
[  805.014586]  [<ffffffff816f42fd>] tcp_v4_conn_request+0x4d/0x50
[  805.015652]  [<ffffffff81765765>] tcp_v6_conn_request+0x65/0x70
[  805.017675]  [<ffffffff816ebc10>] tcp_rcv_state_process+0x1a0/0xf30
[  805.018771]  [<ffffffff816daf26>] ? __inet_lookup_established+0x46/0x130
[  805.019921]  [<ffffffff816f59da>] tcp_v4_do_rcv+0x15a/0x380
[  805.020903]  [<ffffffff81305036>] ? security_sock_rcv_skb+0x16/0x20
[  805.021977]  [<ffffffff816acb50>] ? sk_filter+0x30/0xe0
[  805.022862]  [<ffffffff816f7158>] tcp_v4_rcv+0x7c8/0x980
[  805.023780]  [<ffffffff816cf8de>] ? ip_route_input_noref+0xaee/0xc10
[  805.024864]  [<ffffffff816d132c>] ip_local_deliver_finish+0xac/0x220
[  805.025957]  [<ffffffff816d1638>] ip_local_deliver+0x48/0x80
[  805.027618]  [<ffffffff816d0fa1>] ip_rcv_finish+0x81/0x360
[  805.028640]  [<ffffffff816d1912>] ip_rcv+0x2a2/0x3f0
[  805.029606]  [<ffffffff81697e92>] __netif_receive_skb_core+0x552/0x790
[  805.030728]  [<ffffffff8104d525>] ? ack_ioapic_level+0x75/0x130
[  805.031782]  [<ffffffff816980e8>] __netif_receive_skb+0x18/0x60
[  805.032790]  [<ffffffff81698153>] netif_receive_skb_internal+0x23/0x90
[  805.033906]  [<ffffffff81698d98>] napi_gro_receive+0xc8/0x100
[  805.034927]  [<ffffffffc04644dd>] e1000_clean_rx_irq+0x2bd/0x4f0 [e1000]
[  805.036159]  [<ffffffffc0464edb>] e1000_clean+0x25b/0x8c0 [e1000]
[  805.037208]  [<ffffffff816985a9>] net_rx_action+0x159/0x340
[  805.038163]  [<ffffffff81078bf4>] __do_softirq+0xe4/0x270
[  805.039101]  [<ffffffff81078fbd>] irq_exit+0x9d/0xb0
[  805.039948]  [<ffffffff817a664a>] do_IRQ+0x5a/0xf0
[  805.040789]  [<ffffffff817a44ad>] common_interrupt+0x6d/0x6d
[  805.041785]  <EOI> 
[  805.042139]  [<ffffffff8105a8f6>] ? native_safe_halt+0x6/0x10
[  805.043206]  [<ffffffff8101e2de>] default_idle+0x1e/0xc0
[  805.044123]  [<ffffffff8101ec5f>] arch_cpu_idle+0xf/0x20
[  805.045037]  [<ffffffff810b4a00>] cpu_startup_entry+0x370/0x3a0
[  805.046294]  [<ffffffff8178c937>] rest_init+0x77/0x80
[  805.047331]  [<ffffffff81d3a0fc>] start_kernel+0x494/0x4a1
[  805.048313]  [<ffffffff81d39a58>] ? set_init_arg+0x55/0x55
[  805.049251]  [<ffffffff81d39120>] ? early_idt_handlers+0x120/0x120
[  805.050308]  [<ffffffff81d395ee>] x86_64_start_reservations+0x2a/0x2c
[  805.051441]  [<ffffffff81d39733>] x86_64_start_kernel+0x143/0x152
[  805.052483] Code: 35 f6 32 f7 ff 49 89 c7 48 c7 c7 95 20 7a c0 31 c0 66 41 c1 c6 08 e8 cb 5c ff c0 48 8b 3d d9 32 f7 ff 48 8d 75 c8 ba 0a 00 00 00 <44> 0f be 2f 48 83 c7 02 e8 7b c7 bf c0 4c 89 fe 49 89 c4 48 c7 
[  805.057417] RIP  [<ffffffffc07a10b8>] hydra_hook_func_out+0xb8/0x140 [hydra]
[  805.058638]  RSP <ffff88007f603698>
[  805.059248] CR2: 0000000000000000
[  805.059822] ---[ end trace d6119da9259d40ec ]---
[  805.060965] Kernel panic - not syncing: Fatal exception in interrupt
[  805.062262] Kernel Offset: 0x0 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)
[  805.063971] ---[ end Kernel panic - not syncing: Fatal exception in interrupt

获取调试信息

使用printk函数和dmesg命令

这是最基本的用法，把怀疑出错的地方打印出来再检验。假如没有内核没有出错或者已经注释掉可能出错的部分，可以用此法。

使用一台额外的机器通过IPMI获取被调试机器的Oops信息

我们最好把Oops输出的信息保存下来，因为信息太多可能会导致整个屏幕显示不全，最上面的BUG、IP等最重要的信息就看不见了。虽然可以在不切换控制台窗口的前提下使用shift + pageup，shift + pagedown调整阅读位置，但我认为保存错误信息本来就有它的意义所在。

具体方法参考我的CSDN博文。我们机房的DELL R730的iDrac支持IPMI。做到此文的3.6节后，被调试机屏幕输出的信息都将出现在调试机屏幕上。

调试虚拟机中的内核

以VMware为例，虚拟机是被调试机，我们可以给它创建一个虚拟串口设备，并指出它的输出为宿主机的文本文件。Serial Device
虚拟机内核的配置参见我的CSDN博文第3.3节，注意搞清设备名是ttyS[?]。配置完成后的原理其实和IPMI一致：虚拟机屏幕上显示的内容同时也会经过串口输出到宿主机的文本文件中。

调试内核模块

得到内核Oops信息后，我们要诊断错误原因。

调试内核模块之GDB

我们可以利用gdb对内核模块进行调试，反汇编内核模块。

第一步

进入生成模块目录，注意系统崩溃的内核模块环境需要与调试环境一致。如下调试tyz_memfs.ko。这里需要开启内核调试功能，否则gdb无法进行调试。
project dir

第二步

利用gdb命令进入调试

1
gdb tyz_memfs.ko

第三步

在gdb下，反汇编某个函数disassemble，加 /m选项可以同时显示c源码和汇编代码

1
(gdb) disassemble /m add_mf_ind

相对地址后面给出了相对函数开始位置偏移量<+x>，结合Oops中IP寄存器的值，我们可以定位错误位置。
gdb1

其它

另外，我们可以使用list加地址进行调试。在能直接得到错误地址的情况下很有用。

1
(gdb) list *0x0000000000000a4d,*0x0000000000000a51

gdb2

一般来说在list后面可以跟以下这们的参数：

1
2
3
4
5
6
7
<linenum>   行号。
<+offset>   当前行号的正偏移量。
<-offset>   当前行号的负偏移量。
<filename:linenum>  哪个文件的哪一行。
<function>  函数名。
<filename:function> 哪个文件中的哪个函数。
<*address>  程序运行时的语句在内存中的地址。

调试内核模块之objdump

使用objdump -S 内核模块名同样可以反汇编调试并定位错误位置，这里不展开讲解。

参考文献