Solaris学习笔记(5)
作者: Badcoffee
Email: blog.oliver@gmail.com
Blog: http://blog.csdn.net/yayong
2007年2月
本文介绍使用kmdb和mdb调试Solaris内核的基本方法，kmdb和mdb是Solaris默认安装的内核模块调试器，可以用于调试和定位内核模块及驱动程序发生的错误。本文仅用于学习交流目的，错误再所难免，如果有勘误或疑问请与作者联系。
关键词：mdb/kmdb/panic/hung/crashdump/dump/kernel debug/Solaris/OpenSolaris
事后分析(Postmortem Debug)是目前主流的商业操作系统支持的特性之一，windows, Aix, Freebsd都支持CrashDump及事后分析，最近Linux也逐渐加入了Crashdump和分析工具的支持。了解内核开发的人都知道，很多内核的bug都是很难重现，或者说，是在某个特定条件下，在一个微小的时间窗口内才可以重现；另外，在重要的商业客户的生产环境中，不大可能提供给内核程序员调试这类crash或者hung的机会，因此，在客户提供crash dump文件基础上，进行事后分析就成了解决此类问题的唯一途径。
内核开发，测试甚至使用中可能会遇到以下两类极端情况：
系统crash － 例如，Windows的蓝屏，Unix的panic，Linux的opps；
系统hung - 例如，大家通常说的死机；
1. 系统Crash的分类
System panics & bad traps
Watchdog resets
Dropping out (to boot PROM or bootstrap level)
关于Panic
1. 为保证数据完整性，避免系统进入不可预知的错误，系统会panic()
2. panic()只会在内核空间调用，用户程序触发panic是可能的，但是只是触发而已。
3.系统也会因为检测到硬件不应该进入某种状态而panic()，叫bad trap.
panic()的主要工作
1.dump内存到device(缺省是swap区).
2.dump CPU的所有寄存器到device.
3.重新启动.
panic的过程包括
1. 打印实际panic的消息
2. 打印调用栈的backtrace
3. 内存Dump的消息
4. 尝试Reboot
2. 关于hung
系统hung的分类
1. 死锁(deadlock)问题
2. 系统资源耗尽
3. 硬件问题
发生hung怎么办？
1. 确认hung的现象，网络服务/ping/console/是否可用？
2. 尝试产生一个Crash Dump
如何产生Crash Dump?
1. SPARC系统下，尝试激活OBP用sync命令产生crash dump;
2. x86系统如果启动时加载了kmdb，可以激活kmdb产生crash dump;
x86上如何设置启动时加载kmdb?
有两种方法：
1. 修改grub的设置，加上 "-k", 然后reboot
# vi /boot/grub/menu.lst #---------- ADDED BY BOOTADM - DO NOT EDIT ----------title Solaris 10 11/06 X86root (hd0,0,a)kernel /platform/i86pc/multiboot -kmodule /platform/i86pc/boot_archive#---------------------END BOOTADM--------------------2.或者在启动后，退到console模式，运行如下命令：
Welcome to kmdb
kmdb: unable to determine terminal type: assuming `vt100'
Loaded modules: [ crypto uppc ufs unix zfs krtld s1394 sppp nca uhci lofs
genunix ip usba specfs pcplusmp nfs random sctp cpu.AuthenticAMD.15 ]
[2]> :c
进入kmdb后，内核陷入断点，要用:c来恢复系统运行。
x86下如何激活kmdb并产生crash dump？
kmdb如果已经加载，可以用SHIFT+F1+a通过键盘来激活;
如果console重定向到SP或者tip line，需要查一下发送break信号的字符序列；
kaif_enter+7: popfl
[3]>
出现提示符后，可以用$<systemdump命令产生crash dump:
nopanicdebug: 0 = 0x1
panic[cpu3]/thread=c29b9de0: BAD TRAP: type=e (#pf Page fault) rp=c29d9f1c addr=0 occurred in module "<unknown>" due to a
NULL pointer dereference
sched: #pf Page fault
Bad kernel fault at addr=0x0
pid=0, pc=0x0, sp=0x202, eflags=0x10002
cr0: 8005003b<pg,wp,ne,et,ts,mp,pe> cr4: 6f8<xmme,fxsr,pge,mce,pae,pse,de>
cr2: 0 cr3: 1238c000
gs: 1b0 fs: 0 es: 160 ds: 160
edi: c22e0c80 esi: 20 ebp: c29d9f6c esp: c29d9f54
ebx: f9 edx: 0 ecx: c22e0c11 eax: fec8b7b0
trp: e err: 10 eip: 0 cs: 158
efl: 10002 usp: 202 ss: c29d9f74
c29d9e7c unix:die+a7 (e, c29d9f1c, 0, 3)
c29d9f08 unix:trap+1058 (c29d9f1c, 0, 3)
c29d9f1c unix:cmntrap+9a (1b0, 0, 160, 160, c)
c29d9f6c 0 (c29d9f7c, fe813ced,)
c29d9f74 genunix:kdi_dvec_enter+a (c29d9f88, fe813c8f,)
c29d9f7c unix:debug_enter+32 (0)
c29d9f88 unix:abort_sequence_enter+27 (0)
c29d9fb0 asy:async_rxint+1eb (c19c3d00, f9)
c29d9fd4 asy:asyintr+97 (c19c3d00, 0)
c29b9d5c unix:cmnint+1f7 (c29b01b0, c1600000,)
c29b9db8 unix:cpu_halt+f6 (0, 0, c29b9dd8, fe8)
c29b9dc8 unix:idle+dc (0, 0)
c29b9dd8 unix:thread_start+8 ()
syncing file systems... done
dumping to /dev/dsk/c0t0d0s1, offset 860356608, content: kernel
100% done: 182452 pages dumped, compression ratio 6.00, dump succeeded
rebooting...
3. 关于savecore
savecore - 启动时将panic()例程存在dump device(swap区)上的image保存成文件，存在指定的文件系统的目录上。
用dumpadm(1M)可以查看dump device和crash dump的保存路径;
在/var/crash/<hostname>下，可以看到以下几类文件：
unix.X 和 vmunix.X － crash dump文件，其中X是数字，是dump文件的序号
bounds － 用来记录序号，确定下一次dump的序号
4. 常用kmdb和mdb命令
大部分kmdb和mdb的命令是一样的，事后分析就是用mdb来检查crash dump文件，找到系统crash或者hung的原因。
分析crash dump的第一步就是收集必要的信息：
1. 主机名(hostname)和操作系统版本
::satus
::showrev
2. 系统硬件信息(hardware configuration)
::prtconf
3. 模块或驱动信息
::modinfo
4. Crash时系统消息缓冲区的消息
该消息缓冲区是ring buffer，有很多有价值的信息，可以知道系统crash时或者之前很长一段时间的系统消息。
::msgbuf
进一步分析，可能需要查看以下几方面
1. 调用栈的backtrace
$c
::stack
::stackregs
2. 内核符号表
::nm
3. 反汇编
<内核函数>::dis
4. CPU寄存器
::regs
5. 调度队列(dispatch queue)
::cpuinfo -v
6. 物理内存及slab子系统
::memstat
::kmastat
7. 系统中所有进程
::ps
8. 所有内核线程
::threadlist
9. 线程状态
<kthread_t的地址>::thread
10. 某个内核线程调用栈
<kthread_t的地址>::findstack -v
<proc_t的地址>::walk thread |::findstack -v
11. 同步对象的状态
<mutex地址>::mutex
<读写锁的地址>::rwlock
12. 地址引用查找
<地址>::kgrep
<地址>::whatthread
5. 案例分析
刚买了台Dell OptiPlex 740，因为solaris还不支持板载的1000M网卡，所以只好到www.broadcom.com去下载了一个bcme的驱动来用。几天后，发现在家远程访问机器时，某个特定的操作会引起系统重启，通过查看系统日志发现时系统panic了；
在我的桌面机上，现在可以找到4次panic的crash dump文件：
Dump content: kernel pages
Dump device: /dev/dsk/c0d0s1 (swap)
Savecore directory: /var/crash/palace
Savecore enabled: yes
# cd /var/crash/palace
# ls
bounds unix.0 unix.1 unix.2 unix.3 vmcore.0 vmcore.1 vmcore.2 vmcore.3
用mdb打开其中一个(序号0的crash dump)来查看：
Loading modules: [ unix genunix specfs dtrace cpu.AuthenticAMD.15 uppc pcplusmp scsi_vhci ufs ip hook neti sctp arp usba fctl nca lofs zfs random sppp crypto ptm md cpc fcip fcp logindmux ipc nfs audiosup ]
首先，查看消息缓冲区，看panic之前发生了什么：
> ::msgbufMESSAGE dtrace0 is /pseudo/dtrace@0pseudo-device: zfs0zfs0 is /pseudo/zfs@0pseudo-device: devinfo0devinfo0 is /pseudo/devinfo@0xsvc0 at root: space 0 offset 0xsvc0 is /xsvc@0,0pseudo-device: rsm0rsm0 is /pseudo/rsm@0pseudo-device: pseudo1pseudo1 is /pseudo/zconsnex@1pcplusmp: asy (asy) instance 0 vector 0x4 ioapic 0x2 intin 0x4 is bound to cpu 1ISA-device: asy0panic[cpu0]/thread=ffffff0003cb9c80: BAD TRAP: type=e (#pf Page fault) rp=ffffff0003cb9000 addr=86 occurred in module "genunix" due to a NULL pointer dereference.......................................................................................................................sched: #pf Page faultBad kernel fault at addr=0x86pid=0, pc=0xfffffffffba189ff, sp=0xffffff0003cb90f0, eflags=0x10286cr0: 8005003b<pg,wp,ne,et,ts,mp,pe> cr4: 6f8<xmme,fxsr,pge,mce,pae,pse,de>cr2: 86 cr3: 2c00000 cr8: c rdi: 66 rsi: 9 rdx: 66 rcx: 9 r8: 180 r9: fffffffec02023c8 rax: 0 rbx: 18 rbp: ffffff0003cb9100 r10: 2000 r11: 1 r12: fffffffec1dc8fb0 r13: 18 r14: fffffffec1dc9298 r15: fffffffec1dc9288 fsb: 0 gsb: fffffffffbc292d0 ds: 4b es: 4b fs: 0 gs: 1c3 trp: e err: 0 rip: fffffffffba189ff cs: 30 rfl: 10286 rsp: ffffff0003cb90f0 ss: 38ffffff0003cb8ee0 unix:die+c8 ()ffffff0003cb8ff0 unix:trap+135c ()ffffff0003cb9000 unix:cmntrap+e9 ()ffffff0003cb9100 genunix:ddi_dma_unbind_handle+f ()ffffff0003cb91a0 bcme:bcme_tx_sctgth+305 ()ffffff0003cb91f0 bcme:UM_SendPacketIntel+56 ()ffffff0003cb9230 bcme:UM_SendMBLKPacket+f2 ()ffffff0003cb9280 bcme:UM_SendPacketsMP+91 ()ffffff0003cb92a0 bcme:UM_ProcessSendPackets+66 ()ffffff0003cb92d0 bcme:UM_SendPacket+9e ()ffffff0003cb92f0 bcme:t3TxPacket+bb ()ffffff0003cb9320 bcme:bcme_wput+77 ()ffffff0003cb9390 unix:putnext+22b ()ffffff0003cb9470 ip:tcp_send_data+72a ()ffffff0003cb95a0 ip:tcp_send+a7b ()ffffff0003cb9680 ip:tcp_wput_data+77f ()ffffff0003cb97e0 ip:tcp_rput_data+2b99 ()ffffff0003cb9820 ip:tcp_input+4a ()ffffff0003cb98a0 ip:squeue_enter_chain+11d ()ffffff0003cb9990 ip:ip_input+96f ()ffffff0003cb99e0 ip:ip_rput+119 ()ffffff0003cb9a50 unix:putnext+22b ()ffffff0003cb9ac0 bcme:t3SendUp+2dd ()ffffff0003cb9ae0 bcme:t3ProcessRxPacket+98 ()ffffff0003cb9b10 bcme:bcme_recv+87 ()ffffff0003cb9b40 bcme:LM_RxPackets_Service+56 ()ffffff0003cb9b60 bcme:LM_ISR_ServiceSoftInt+29 ()ffffff0003cb9bc0 bcme:bcme_intr+30e ()ffffff0003cb9c20 unix:av_dispatch_autovect+78 ()ffffff0003cb9c60 unix:dispatch_hardint+2f ()ffffff0003c05ac0 unix:switch_sp_and_call+13 ()ffffff0003c05b10 unix:do_interrupt+9b ()ffffff0003c05b20 unix:cmnint+ba ()ffffff0003c05c10 unix:mach_cpu_idle+6 ()ffffff0003c05c40 unix:cpu_idle+c8 ()ffffff0003c05c60 unix:idle+10e ()ffffff0003c05c70 unix:thread_start+8 ()syncing file systems... 4 donedumping to /dev/dsk/c0d0s1, offset 860356608, content: kernel可以从panic的调用栈看出，这个panic和网络有关，涉及的模块有unix, bcme, ip, genunix；
操作系统版本：
Hostname: palace
Release: 5.11
Kernel architecture: i86pc
Application architecture: amd64
Kernel version: SunOS 5.11 i86pc snv_57
Platform: i86pc
我们知道，这台机器是amd64 CPU, 操作系统是Solaris 11 build 57.
因为bcme是硬件驱动，因此下面的信息有助于我们了解驱动的基本情况；
网卡信息(通过vendor id和device id: pciex14e4,167a, 可以查到网卡具体型号)：
fffffffec01f09b0 pciex14e4,167a, instance #0 (driver name: bcme)网卡驱动版本(v10.0.3)：
140 fffffffff7fd2000 1d3d0 1 bcme (Broadcom GbE Driver v10.0.3)
系统panic的消息已经告诉我们这是一个bad trap：
debugging crash dump vmcore.0 (64-bit) from palace
operating system: 5.11 snv_57 (i86pc)
panic message:
BAD TRAP: type=e (#pf Page fault) rp=ffffff0003cb9000 addr=86 occurred in module "genunix" due to a NULL pointer dereference
dump content: kernel pages only
这个bad trap实际上就是Page fault时，访问了一个NULL指针，而且addr=86，已经很明显不是一个合法的地址。
让我们验证一下，首先，查看调用栈的详细信息：
ffffff0003cb9100 ddi_dma_unbind_handle+0xf(66)
ffffff0003cb91a0 bcme_tx_sctgth+0x305()
ffffff0003cb91f0 UM_SendPacketIntel+0x56()
ffffff0003cb9230 UM_SendMBLKPacket+0xf2()
ffffff0003cb9280 UM_SendPacketsMP+0x91()
ffffff0003cb92a0 UM_ProcessSendPackets+0x66()
ffffff0003cb92d0 UM_SendPacket+0x9e()
ffffff0003cb92f0 t3TxPacket+0xbb()
ffffff0003cb9320 bcme_wput+0x77()
ffffff0003cb9390 putnext+0x22b(fffffffec1954638, fffffffee22bf300)
ffffff0003cb9470 tcp_send_data+0x72a(fffffffec82452c0, fffffffee21e3650, fffffffee22bf300)
ffffff0003cb95a0 tcp_send+0xa7b(fffffffee21e3650, fffffffec82452c0, 4ec, 28, 14, 0, ffffff0003cb965c, ffffff0003cb9660,
ffffff0003cb9664, ffffff0003cb9618, 13a00be, 7fffffff)
ffffff0003cb9680 tcp_wput_data+0x77f(fffffffec82452c0, 0, 0)
ffffff0003cb97e0 tcp_rput_data+0x2b99(fffffffec82450c0, fffffffee2240f80, fffffffec1563f00)
ffffff0003cb9820 tcp_input+0x4a(fffffffec82450c0, fffffffee2240f80, fffffffec1563f00)
ffffff0003cb98a0 squeue_enter_chain+0x11d(fffffffec1563f00, fffffffee2240f80, fffffffee2240f80, 1, 1)
ffffff0003cb9990 ip_input+0x96f(fffffffec1b9f428, 0, fffffffee2240f80, 0)
ffffff0003cb99e0 ip_rput+0x119(fffffffec1954540, fffffffee2240f80)
ffffff0003cb9a50 putnext+0x22b(fffffffec19547d0, fffffffee2240f80)
ffffff0003cb9ac0 t3SendUp+0x2dd()
ffffff0003cb9ae0 t3ProcessRxPacket+0x98()
ffffff0003cb9b10 bcme_recv+0x87()
ffffff0003cb9b40 LM_RxPackets_Service+0x56()
ffffff0003cb9b60 LM_ISR_ServiceSoftInt+0x29()
ffffff0003cb9bc0 bcme_intr+0x30e()
ffffff0003cb9c20 av_dispatch_autovect+0x78(10)
ffffff0003cb9c60 dispatch_hardint+0x2f(10, 0)
ffffff0003c05ac0 switch_sp_and_call+0x13()
ffffff0003c05b10 do_interrupt+0x9b(ffffff0003c05b20, 1)
ffffff0003c05b20 _interrupt+0xba()
ffffff0003c05c10 mach_cpu_idle+6()
ffffff0003c05c40 cpu_idle+0xc8()
ffffff0003c05c60 idle+0x10e()
ffffff0003c05c70 thread_start+8()
mdb不但打出了函数名，而且有些函数的参数都得到了，其中ddi_dma_unbind_handle的参数是0x66，panic时，系统正在执行的指令时ddi_dma_unbind_handle+0xf，我们可以反汇编这个函数看看该指令是什么？
> ddi_dma_unbind_handle::dis
ddi_dma_unbind_handle: pushq %rbp
ddi_dma_unbind_handle+1: movq %rsp,%rbp
ddi_dma_unbind_handle+4: subq $0x10,%rsp
ddi_dma_unbind_handle+8: movq %rdi,-0x8(%rbp)
ddi_dma_unbind_handle+0xc: movq %rdi,%rdx
ddi_dma_unbind_handle+0xf: movq 0x20(%rdx),%rsi
ddi_dma_unbind_handle+0x13: movq 0x98(%rsi),%rdi
ddi_dma_unbind_handle+0x1a: xorl %eax,%eax
ddi_dma_unbind_handle+0x1c: call *0xe8(%rsi)
ddi_dma_unbind_handle+0x22: leave
ddi_dma_unbind_handle+0x23: ret
反汇编的结果有时会比较难看懂，好在OpenSolaris已经开放源代码了，我们可以对照代码：
ddi_dma_unbind_handle(ddi_dma_handle_t h)
{
ddi_dma_impl_t *hp = (ddi_dma_impl_t *)h;
dev_info_t *hdip, *dip;
int (*funcp)(dev_info_t *, dev_info_t *, ddi_dma_handle_t);
dip = hp->dmai_rdip;
hdip = (dev_info_t *)DEVI(dip)->devi_bus_dma_unbindhdl;
funcp = DEVI(dip)->devi_bus_dma_unbindfunc;
return ((*funcp)(hdip, dip, h));
}
不难看出，ddi_dma_unbind_handle+0xf指令正是以下这行，访问dmai_rdip成员的语句：
dip = hp->dmai_rdip;
可以用mdb验证一下：
offsetof (ddi_dma_impl_t, dmai_rdip) = 0x20
ddi_dma_unbind_handle+0xf对应的指令是：
ddi_dma_unbind_handle+0xf: movq 0x20(%rdx),%rsi
%rdx寄存器的值可以从以下命令得到：
%rax = 0x0000000000000000 %r9 = 0xfffffffec02023c8
%rbx = 0x0000000000000018 %r10 = 0x0000000000002000
%rcx = 0x0000000000000009 %r11 = 0x0000000000000001
%rdx = 0x0000000000000066 %r12 = 0xfffffffec1dc8fb0
%rsi = 0x0000000000000009 %r13 = 0x0000000000000018
%rdi = 0x0000000000000066 %r14 = 0xfffffffec1dc9298
%r8 = 0x0000000000000180 %r15 = 0xfffffffec1dc9288
%rip = 0xfffffffffba189ff ddi_dma_unbind_handle+0xf
%rbp = 0xffffff0003cb9100
%rsp = 0xffffff0003cb90f0
%rflags = 0x00010286
id=0 vip=0 vif=0 ac=0 vm=0 rf=1 nt=0 iopl=0x0
status=<of,df,IF,tf,SF,zf,af,PF,cf>
%cs = 0x0030 %ds = 0x004b %es = 0x004b
%trapno = 0xe %fs = 0x0000 %gs = 0x01c3
%err = 0x0
所以ddi_dma_unbind_handle+0xf指令实际上是去访问0x20(%rdx)对应的地址而发生的bad trap, 即addr=88:
mdb: failed to read data from target: no mapping for address
0x86:
再看一下ddi_dma_unbind_handle(9F)里的说明，这个函数几乎是所有的使用dma的驱动都需要用到的：
NAME
ddi_dma_unbind_handle - unbinds the address in a DMA handle
SYNOPSIS
#include <sys/ddi.h>
#include <sys/sunddi.h>
int ddi_dma_unbind_handle(ddi_dma_handle_t handle);
PARAMETERS
handle The DMA handle previously allocated by a call to
ddi_dma_alloc_handle(9F).
可见，在bcme驱动调用ddi_dma_unbind_handle时，传递的handle可能已经被释放，或者是一个非法的地址，可惜我没有bcme驱动的源代码，不然也许可以进一步定位错误，因为虽然mdb没有自动找到bcme函数的参数，但是因为我们有bcme的栈指针，或许可以从栈中找到已经被保存的函数参数，当然，这要对AMD64的ABI比较熟悉：
0xffffff0003cb90f0:
0xffffff0003cb90f0: 0xfffffffff7fe9d38
0xffffff0003cb90f8: 0x66
0xffffff0003cb9100: 0xffffff0003cb91a0
0xffffff0003cb9108: bcme_tx_sctgth+0x305
0xffffff0003cb9110: 0xfffffffee22bf300
0xffffff0003cb9118: 0x522
0xffffff0003cb9120: 0xfffffffec1dab000
0xffffff0003cb9128: 0xfffffffec1dc8fb0
0xffffff0003cb9130: 0
0xffffff0003cb9138: QQ_PushTail+0x57
0xffffff0003cb9140: 0xfffffffec1db39e0
0xffffff0003cb9148: 0x48a22ddc
0xffffff0003cb9150: 0x28
0xffffff0003cb9158: 0xbaddcafe00000000
0xffffff0003cb9160: 0xffffff0003cb91a0
0xffffff0003cb9168: 0x522f7fe488d
0xffffff0003cb9170: 0xfffffffee22c8880
0xffffff0003cb9178: 0xfffffffee22b6ddc
0xffffff0003cb9180: 0xfffffffec1db3d68
0xffffff0003cb9188: 0x28
0xffffff0003cb9190: 0xfffffffec1dab000
0xffffff0003cb9198: 0x3c
0xffffff0003cb91a0: 0xffffff0003cb91f0
0xffffff0003cb91a8: UM_SendPacketIntel+0x56
0xffffff0003cb91b0: 0xfffffffec1dab000
0xffffff0003cb91b8: 0xfffffffee22bf300
0xffffff0003cb91c0: 0
0xffffff0003cb91c8: 0x3c
0xffffff0003cb91d0: 0x522
0xffffff0003cb91d8: 0x3c
0xffffff0003cb91e0: 0x522
0xffffff0003cb91e8: 0xfffffffec1dab040
0xffffff0003cb91f0: 0xffffff0003cb9230
0xffffff0003cb91f8: UM_SendMBLKPacket+0xf2
0xffffff0003cb9200: 0xfffffffec1db3f30
0xffffff0003cb9208: 0xfffffffec1dab000
0xffffff0003cb9210: 0xfffffffee22bf300
0xffffff0003cb9218: 0xfffffffee22bf300
0xffffff0003cb9220: 0xfffffffec1db39f0
0xffffff0003cb9228: 0xfffffffee3be9600
0xffffff0003cb9230: 0xffffff0003cb9280
0xffffff0003cb9238: UM_SendPacketsMP+0x91
0xffffff0003cb9240: 0xfffffffec1954638
0xffffff0003cb9248: 0xfffffffee22bf300
0xffffff0003cb9250: 0xfffffffec1dab000
0xffffff0003cb9258: 0xfffffffec1db3f20
0xffffff0003cb9260: 0xfffffffee22bf300
即使没有源代码，我们也知道，这是bcme驱动的一个bug，我会设法联系broadcom公司的人报告一个bug，并且我可以提供crash dump文件供他们分析和解决这个问题。
相关文档：
Solaris学习笔记(4)
Solaris学习笔记(3)
Solaris学习笔记(2)
Solaris学习笔记(1)
X86汇编语言学习手记(3)
X86汇编语言学习手记(2)
X86汇编语言学习手记(1)
Technorati Tag: OpenSolaris
Technorati Tag: Solaris