Solaris学习笔记(5) - 下

5. 案例分析

刚买了台Dell OptiPlex 740，因为solaris还不支持板载的1000M网卡，所以只好到www.broadcom.com去下载了一个bcme的驱动来用。几天后，发现在家远程访问机器时，某个特定的操作会引起系统重启，通过查看系统日志发现时系统panic了；

在我的桌面机上，现在可以找到4次panic的crash dump文件：

用mdb打开其中一个(序号0的crash dump)来查看：

首先，查看消息缓冲区，看panic之前发生了什么：

> ::msgbuf
MESSAGE                                                               
dtrace0 is /pseudo/dtrace@0
pseudo-device: zfs0
zfs0 is /pseudo/zfs@0
pseudo-device: devinfo0
devinfo0 is /pseudo/devinfo@0
xsvc0 at root: space 0 offset 0
xsvc0 is /xsvc@0,0
pseudo-device: rsm0
rsm0 is /pseudo/rsm@0
pseudo-device: pseudo1
pseudo1 is /pseudo/zconsnex@1
pcplusmp: asy (asy) instance 0 vector 0x4 ioapic 0x2 intin 0x4 is bound to cpu 1
ISA-device: asy0
panic[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 fault
Bad kernel fault at addr=0x86
pid=0, pc=0xfffffffffba189ff, sp=0xffffff0003cb90f0, eflags=0x10286
cr0: 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:               38

ffffff0003cb8ee0 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
 done
dumping to /dev/dsk/c0d0s1, offset 860356608, content: kernel

可以从panic的调用栈看出，这个panic和网络有关，涉及的模块有unix, bcme, ip, genunix；

操作系统版本：

我们知道，这台机器是amd64 CPU, 操作系统是Solaris 11 build 57.

因为bcme是硬件驱动，因此下面的信息有助于我们了解驱动的基本情况；

网卡信息(通过vendor id和device id: pciex14e4,167a, 可以查到网卡具体型号)：

> ::prtconf ! grep bcme
            fffffffec01f09b0 pciex14e4,167a, instance #0 (driver name: bcme)

网卡驱动版本(v10.0.3)：

系统panic的消息已经告诉我们这是一个bad trap：

这个bad trap实际上就是Page fault时，访问了一个NULL指针，而且addr=86，已经很明显不是一个合法的地址。

让我们验证一下，首先，查看调用栈的详细信息：

mdb不但打出了函数名，而且有些函数的参数都得到了，其中ddi_dma_unbind_handle的参数是0x66，panic时，系统正在执行的指令时ddi_dma_unbind_handle+0xf，我们可以反汇编这个函数看看该指令是什么？

反汇编的结果有时会比较难看懂，好在OpenSolaris已经开放源代码了，我们可以对照代码：

http://cvs.opensolaris.org/source/xref/onnv/onnv-gate/usr/src/uts/common/os/sunddi.c#ddi_dma_unbind_handle

不难看出，ddi_dma_unbind_handle+0xf指令正是以下这行，访问dmai_rdip成员的语句：

dip = hp->dmai_rdip;

可以用mdb验证一下：

ddi_dma_unbind_handle+0xf对应的指令是：

ddi_dma_unbind_handle+0xf:      movq   0x20(%rdx),%rsi

%rdx寄存器的值可以从以下命令得到：

所以ddi_dma_unbind_handle+0xf指令实际上是去访问0x20(%rdx)对应的地址而发生的bad trap, 即addr=88:

再看一下ddi_dma_unbind_handle(9F)里的说明，这个函数几乎是所有的使用dma的驱动都需要用到的：

可见，在bcme驱动调用ddi_dma_unbind_handle时，传递的handle可能已经被释放，或者是一个非法的地址，可惜我没有bcme驱动的源代码，不然也许可以进一步定位错误，因为虽然mdb没有自动找到bcme函数的参数，但是因为我们有bcme的栈指针，或许可以从栈中找到已经被保存的函数参数，当然，这要对AMD64的ABI比较熟悉：

即使没有源代码，我们也知道，这是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