Panic under disk (ata) io from today's sources

From: Tom Judge <tom_at_tomjudge.com>
Date: Mon, 28 Apr 2008 01:10:53 -0500
Hi,

I am having trouble with a freshly installed system running CURRENT-8 
from todays sources. Back traces attached. (I have both core files 
avaliable so can gather more information on request.  Also the panics 
are quite easy to trigger so I should also be able to provide any info 
from ddb that may be required).

[root_at_ /home/tj]# uname -a
FreeBSD  8.0-CURRENT FreeBSD 8.0-CURRENT #0: Mon Apr 28 04:22:09 CDT 
2008     root_at_:/usr/obj/usr/src/sys/GENERIC  amd64

[NOTE: I just noticed the clock is +13 hours out on this system]

Both panics happened just after hundreds of the following messages 
appeared on the console:

ad6: FAILURE - load data
ad6: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data



The panics both happen under moderate disk io load.  The first is 
rsync'ing from UFS to UFS on gmirror.  The second is rsyncing from 
reiserfs to ZFS.  Could these panics be related to the recent ATA changes?

All of the panics happened when accessing drives attached to the onboard 
SATA controllers (MB is ASUS M2N-E):

pciconf -lv entries for disk controllers:

atapci0_at_pci0:0:4:0:     class=0x01018a card=0x82391043 chip=0x036e10de 
rev=0xa1 hdr=0x00
     vendor     = 'Nvidia Corp'
     device     = 'MCP55 IDE'
     class      = mass storage
     subclass   = ATA
atapci1_at_pci0:0:5:0:     class=0x010185 card=0x82391043 chip=0x037f10de 
rev=0xa3 hdr=0x00
     vendor     = 'Nvidia Corp'
     device     = 'MCP55 SATA Controller'
     class      = mass storage
     subclass   = ATA
atapci2_at_pci0:0:5:1:     class=0x010185 card=0x82391043 chip=0x037f10de 
rev=0xa3 hdr=0x00
     vendor     = 'Nvidia Corp'
     device     = 'MCP55 SATA Controller'
     class      = mass storage
     subclass   = ATA
atapci3_at_pci0:0:5:2:     class=0x010185 card=0x82391043 chip=0x037f10de 
rev=0xa3 hdr=0x00
     vendor     = 'Nvidia Corp'
     device     = 'MCP55 SATA Controller'
     class      = mass storage
     subclass   = ATA



atacontrol output:

[root_at_ /home/tj]# atacontrol list
ATA channel 0:
     Master: acd0 <TSSTcorp CDDVDW SH-S202N/SB01> ATA/ATAPI revision 7
     Slave:       no device present
ATA channel 1:
     Master:      no device present
     Slave:       no device present
ATA channel 2:
     Master:  ad4 <WDC WD5000AAKS-00A7B0/01.03B01> Serial ATA II
     Slave:       no device present
ATA channel 3:
     Master:  ad6 <WDC WD5000AAKS-00A7B0/01.03B01> Serial ATA II
     Slave:       no device present
ATA channel 4:
     Master:      no device present
     Slave:       no device present
ATA channel 5:
     Master:      no device present
     Slave:       no device present
ATA channel 6:
     Master:      no device present
     Slave:       no device present
ATA channel 7:
     Master:      no device present
     Slave:       no device present



[root_at_ /home/tj]# kgdb /boot/kernel/kernel.symbols /var/crash/vmcore.0
[GDB will not be able to debug user-mode threads: /usr/lib/libthread_db.so: Undefined symbol "ps_pglobal_lookup"]
GNU gdb 6.1.1 [FreeBSD]
Copyright 2004 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for details.
This GDB was configured as "amd64-marcel-freebsd".
Reading symbols from /boot/kernel/geom_mirror.ko...Reading symbols from /boot/kernel/geom_mirror.ko.symbols...done.
done.
Loaded symbols for /boot/kernel/geom_mirror.ko
Reading symbols from /boot/kernel/zfs.ko...Reading symbols from /boot/kernel/zfs.ko.symbols...done.
done.
Loaded symbols for /boot/kernel/zfs.ko

Unread portion of the kernel message buffer:
ata
ad4: setting up DMA failed
g_vfs_done():ad4s1e[READ(offset=10519347200, length=16384)]error = 5
ad4: FAILURE - load data
ad4: setting up DMA failed
g_vfs_done():ad4s1e[READ(offset=10519347200, length=16384)]error = 5
panic: VOP_STRATEGY failed bp=0xffffffffc176b858 vp=0xffffff00a317f000
cpuid = 0
KDB: enter: panic
exclusive lockmgr bufwait r = 0 (0xffffffffc176b8f0) locked @ /usr/src/sys/kern/vfs_bio.c:1796
shared lockmgr ufs r = 0 (0xffffff00a317f098) locked @ /usr/src/sys/kern/vfs_vnops.c:530
panic: from debugger
cpuid = 0
Uptime: 9m5s
Physical memory: 4080 MB
Dumping 543 MB: 528 512 496 480 464 448 432 416 400 384 368 352 336 320 304 288 272 256 240 224 208 192 176 160 144 128 112 96 80 64 48 32 16

#0  doadump () at pcpu.h:195
195     pcpu.h: No such file or directory.
        in pcpu.h
(kgdb) bt
#0  doadump () at pcpu.h:195
#1  0xffffffff8049c673 in boot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:418
#2  0xffffffff8049caf7 in panic (fmt=Variable "fmt" is not available.
) at /usr/src/sys/kern/kern_shutdown.c:572
#3  0xffffffff801c2ce7 in db_panic (addr=Variable "addr" is not available.
) at /usr/src/sys/ddb/db_command.c:446
#4  0xffffffff801c35df in db_command (last_cmdp=0xffffffff80a7ee48, cmd_table=0x0, dopager=1) at /usr/src/sys/ddb/db_command.c:413
#5  0xffffffff801c37f0 in db_command_loop () at /usr/src/sys/ddb/db_command.c:466
#6  0xffffffff801c5129 in db_trap (type=Variable "type" is not available.
) at /usr/src/sys/ddb/db_main.c:228
#7  0xffffffff804c7d95 in kdb_trap (type=3, code=0, tf=0xffffffffd9a67630) at /usr/src/sys/kern/subr_kdb.c:510
#8  0xffffffff80767425 in trap (frame=0xffffffffd9a67630) at /usr/src/sys/amd64/amd64/trap.c:494
#9  0xffffffff8074a9ae in calltrap () at /usr/src/sys/amd64/amd64/exception.S:177
#10 0xffffffff804c7f6d in kdb_enter (why=0xffffffff80824759 "panic", msg=0xa <Address 0xa out of bounds>) at cpufunc.h:63
#11 0xffffffff8049cb06 in panic (fmt=Variable "fmt" is not available.
) at /usr/src/sys/kern/kern_shutdown.c:556
#12 0xffffffff80507d22 in bufstrategy (bo=Variable "bo" is not available.
) at /usr/src/sys/kern/vfs_bio.c:3811
#13 0xffffffff80510766 in cluster_read (vp=0xffffff00a317f000, filesize=377568, lblkno=17, size=16384, cred=Variable "cred" is not available.
) at buf.h:397
#14 0xffffffff806960bd in ffs_read (ap=Variable "ap" is not available.
) at /usr/src/sys/ufs/ffs/ffs_vnops.c:510
#15 0xffffffff8052c7d7 in vn_read (fp=0xffffff00046662d0, uio=0xffffffffd9a67b00, active_cred=Variable "active_cred" is not available.
) at vnode_if.h:341
#16 0xffffffff804db5c1 in dofileread (td=0xffffff00046d46a0, fd=3, fp=0xffffff00046662d0, auio=0xffffffffd9a67b00, offset=Variable "offset" is not available.
) at file.h:219
#17 0xffffffff804db950 in kern_readv (td=0xffffff00046d46a0, fd=3, auio=0xffffffffd9a67b00) at /usr/src/sys/kern/sys_generic.c:235
#18 0xffffffff804dba44 in read (td=Variable "td" is not available.
) at /usr/src/sys/kern/sys_generic.c:151
#19 0xffffffff80766cff in syscall (frame=0xffffffffd9a67c80) at /usr/src/sys/amd64/amd64/trap.c:843
#20 0xffffffff8074abbb in Xfast_syscall () at /usr/src/sys/amd64/amd64/exception.S:298
#21 0x000000080076ad0c in ?? ()
Previous frame inner to this frame (corrupt stack?)
(kgdb)                           root_at_ /home/tj]# kgdb /boot/kernel/kernel.symbols /var/crash/vmcore.1
[GDB will not be able to debug user-mode threads: /usr/lib/libthread_db.so: Undefined symbol "ps_pglobal_lookup"]
GNU gdb 6.1.1 [FreeBSD]
Copyright 2004 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for details.
This GDB was configured as "amd64-marcel-freebsd".
Reading symbols from /boot/kernel/zfs.ko...Reading symbols from /boot/kernel/zfs.ko.symbols...done.
done.
Loaded symbols for /boot/kernel/zfs.ko
Reading symbols from /boot/kernel/geom_mirror.ko...Reading symbols from /boot/kernel/geom_mirror.ko.symbols...done.
done.
Loaded symbols for /boot/kernel/geom_mirror.ko
Reading symbols from /boot/kernel/reiserfs.ko...Reading symbols from /boot/kernel/reiserfs.ko.symbols...done.
done.
Loaded symbols for /boot/kernel/reiserfs.ko

Unread portion of the kernel message buffer:
a
ad14: setting up DMA failed
g_vfs_done():ad14s1[READ(offset=98303832064, length=4096)]error = 5
ad14: FAILURE - load data
ad14: setting up DMA failed
g_vfs_done():ad14s1[READ(offset=98303836160, length=4096)]error = 5
ad6: FAILURE - load data
ad6: setting up DMA failed
ad14: FAILURE - load data
ad14: setting up DMA failed
g_vfs_done():ad14s1[READ(offset=813637632, length=4096)]error = 5
System call lstat returning with the following locks heldad6: FAILU:RE
 e-x cllouasdi vdea tlaoc
kamdg6r:  bsueftwtaiintg  ru p=  D0M A( 0fxafiflfefdff
ffc13b6980) locked _at_ /usr/srcad6: F/AsIyLsU/RkEe r-n /lvofasd_ bdiaot.ac:
1a7d966:
speatntiicn:g  wuipt nDeMsAs _fwaairlned
c
paudi6d:  =F A1IL
UKRDEB :-  elnotaedr data
ad6: setting up DMA failed
ad6: FAILURE - load data
ad6: setting up DMA failed
ad6: FAILURE - load data
ad6: setting up DMA failed
ad6: FAILURE - load data
ad6: setting up DMA failed
ad6: FAILURE - load data
ad6: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
GEOM_MIRROR: Request failed (error=5). ad4s1[WRITE(offset=33361485824, length=16384)]
GEOM_MIRROR: Device os0: provider ad4s1 disconnected.
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
ad4: FAILURE - load data
ad4: setting up DMA failed
panic: bufwrite: buffer is not busy???
cpuid = 1
KDB: enter: panic
panic: from debugger
cpuid = 1
KDB: stack backtrace:
panic: from debugger
cpuid = 1
KDB: stack backtrace:
Physical memory: 4080 MB
Dumping 961 MB: 946 930 914 898 882 866 850 834 818 802 786 770 754 738 722 706 690 674 658 642 626 610 594 578 562 546 530 514 498 482 466 450 434 418 402 386 370 354 338 322 306 290 274 258 242 226 210 194 178 162 146 130 114 98 82 66 50 34 18 2

#0  doadump () at pcpu.h:195
195     pcpu.h: No such file or directory.
        in pcpu.h
(kgdb) bt
#0  doadump () at pcpu.h:195
#1  0xffffffff801c30ac in db_fncall (dummy1=Variable "dummy1" is not available.
) at /usr/src/sys/ddb/db_command.c:516
#2  0xffffffff801c35df in db_command (last_cmdp=0xffffffff80a7ee48, cmd_table=0x0, dopager=1) at /usr/src/sys/ddb/db_command.c:413
#3  0xffffffff801c37f0 in db_command_loop () at /usr/src/sys/ddb/db_command.c:466
#4  0xffffffff801c5129 in db_trap (type=Variable "type" is not available.
) at /usr/src/sys/ddb/db_main.c:228
#5  0xffffffff804c7d95 in kdb_trap (type=3, code=0, tf=0xffffffffd76928c0) at /usr/src/sys/kern/subr_kdb.c:510
#6  0xffffffff80767425 in trap (frame=0xffffffffd76928c0) at /usr/src/sys/amd64/amd64/trap.c:494
#7  0xffffffff8074a9ae in calltrap () at /usr/src/sys/amd64/amd64/exception.S:177
#8  0xffffffff804c7f6d in kdb_enter (why=0xffffffff80824759 "panic", msg=0xa <Address 0xa out of bounds>) at cpufunc.h:63
#9  0xffffffff8049cb06 in panic (fmt=Variable "fmt" is not available.
) at /usr/src/sys/kern/kern_shutdown.c:556
#10 0xffffffff80691b20 in ffs_bufwrite (bp=0xffffffffc1883660) at /usr/src/sys/ufs/ffs/ffs_vfsops.c:1724
#11 0xffffffff8050884b in vfs_bio_awrite (bp=0xffffffffc1883660) at buf.h:385
#12 0xffffffff805111c8 in vop_stdfsync (ap=0xffffffffd7692bc0) at /usr/src/sys/kern/vfs_default.c:475
#13 0xffffffff8052025b in sched_sync () at vnode_if.h:535
#14 0xffffffff8047dc4a in fork_exit (callout=0xffffffff8051fd10 <sched_sync>, arg=0x0, frame=0xffffffffd7692c80) at /usr/src/sys/kern/kern_fork.c:789
#15 0xffffffff8074ad6e in fork_trampoline () at /usr/src/sys/amd64/amd64/exception.S:481
#16 0x0000000000000000 in ?? ()
#17 0x0000000000000000 in ?? ()
#18 0x0000000000000001 in ?? ()
#19 0x0000000000000000 in ?? ()
#20 0x0000000000000000 in ?? ()
#21 0x0000000000000000 in ?? ()
#22 0x0000000000000000 in ?? ()
#23 0x0000000000000000 in ?? ()
#24 0x0000000000000000 in ?? ()
#25 0x0000000000000000 in ?? ()
#26 0x0000000000000000 in ?? ()
#27 0x0000000000000000 in ?? ()
#28 0x0000000000000000 in ?? ()
#29 0x0000000000000000 in ?? ()
#30 0x0000000000000000 in ?? ()
#31 0x0000000000000000 in ?? ()
#32 0x0000000000000000 in ?? ()
#33 0x0000000000000000 in ?? ()
#34 0x0000000000000000 in ?? ()
#35 0x0000000000000000 in ?? ()
#36 0x0000000000000000 in ?? ()
#37 0x0000000000000000 in ?? ()
#38 0x0000000000000000 in ?? ()
#39 0x0000000000000000 in ?? ()
#40 0x0000000000efe000 in ?? ()
#41 0x0000000000000104 in ?? ()
#42 0xffffffff80ac5d78 in sleepq_chains ()
#43 0xffffffff80ab8440 in tdq_cpu ()
#44 0x0000000000000c80 in ?? ()
#45 0xffffffffd7692a40 in ?? ()
#46 0xffffffffd76929f8 in ?? ()
#47 0xffffff00047b3000 in ?? ()
#48 0xffffffff804bbe11 in sched_switch (td=0x0, newtd=Variable "newtd" is not available.
) at /usr/src/sys/kern/sched_ule.c:1826
Previous frame inner to this frame (corrupt stack?)
(kgdb)                                            
Received on Mon Apr 28 2008 - 04:42:33 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:39:30 UTC