Date: Fri, 14 Jan 2005 06:09:53 GMT From: Chris Jones <cdjones@novusordo.net> To: freebsd-gnats-submit@FreeBSD.org Subject: kern/76237: vinum panics on ufs_baddir, possible link to reviving stale subdisks Message-ID: <200501140609.j0E69rHY044250@www.freebsd.org> Resent-Message-ID: <200501140610.j0E6AN4h006259@freefall.freebsd.org>
next in thread | raw e-mail | index | archive | help
>Number: 76237
>Category: kern
>Synopsis: vinum panics on ufs_baddir, possible link to reviving stale subdisks
>Confidential: no
>Severity: non-critical
>Priority: medium
>Responsible: freebsd-bugs
>State: open
>Quarter:
>Keywords:
>Date-Required:
>Class: sw-bug
>Submitter-Id: current-users
>Arrival-Date: Fri Jan 14 06:10:22 GMT 2005
>Closed-Date:
>Last-Modified:
>Originator: Chris Jones
>Release: FreeBSD RELENG_5_3
>Organization:
Novus Ordo Systems
>Environment:
FreeBSD ishtar 5.3-RELEASE-p4 FreeBSD 5.3-RELEASE-p4 #1: Thu Jan 13 20:12:44 MST 2005 root@ishtar:/usr/obj/usr/src/sys/ISHTAR i386
>Description:
I've got a FreeBSD box, ishtar, which has three SATA drives connected using Silicon Image 1312A cards, without RAID enabled. Most of the drives is devoted to vinum for future use as a file server. I have two RAID-5 volume with 16 GB on each drive, for a size of 32 GB per volume.
ishtar is running the GENERIC kernel, with DDB, KDB, and BREAK_TO_DEBUGGER added. I've built & installed the new kernel, and rebuilt & installed world to ensure that everything's in sync.
I was transferring files from my laptop to ishtar using rsync; one of the disks had a DMA error and I stopped the rsync transfer:
Jan 13 21:00:30 ishtar kernel: ad6: TIMEOUT - WRITE_DMA retrying (2 retries left) LBA=38632958
Jan 13 21:00:31 ishtar kernel: ad6: FAILURE - WRITE_DMA timed out
Jan 13 21:00:31 ishtar kernel: vinum: backups.p0.s2 is stale by force
Jan 13 21:00:31 ishtar kernel: vinum: backups.p0 is degraded
Jan 13 21:00:31 ishtar kernel: fatal :backups.p0.s2 write error, block 37060031 for 65536 bytes
Jan 13 21:00:31 ishtar kernel: backups.p0.s2: user buffer block 7010656 for 65536 bytes
I did a 'vinum start backups.p0.s2' to have vinum rebuild the parity information on that subdisk. The rebuild occurred uneventfully, and I rebooted ishtar to ensure that all was well:
Jan 13 21:58:13 ishtar kernel: vinum: backups.p0.s2 is up by force
Jan 13 21:58:13 ishtar kernel: vinum: backups.p0 is up
Jan 13 21:58:13 ishtar kernel: vinum: backups.p0.s2 is up
Jan 13 21:58:44 ishtar reboot: rebooted by root
The system came up cleanly, at which point I started vinum ('vinum start'); vinum reported no errors ('vinum l'). I did not rebuild the parity data (that shouldn't be necessary when you have a stale disk that's been rebuilt, right?). I then fscked (no errors found) and mounted the volume, and restarted the rsync, which proceded uneventfully for a few minutes, until ishtar crashed with the following on the screen:
/export/backups: bad dir ino 495250 at offset 7680: mangled entry
panic: ufs_dirbad: bad dir
KDB: enter: panic
[thread 100084]
Stopped at kdb_enter+0x2b: nop
db> where
kdb_enter(c0824119) at kdb_enter+0x2b
panic(c08353ce,cbec8e00,dbd1bb08,c07550d2,c2454a64) at panic+0xbb
ufs_dirbad(c2454a64,1e00,c0835388,c1bd7640,0) at ufs_dirbad+0x3d
ufs_lookup(d8d1bb38,d8d1bb74,c0659f5a,d8d1bb38,d8d1bb50) at ufs_lookup+0x3d2
ufs_nvoperate(d8d1bb38) at ufs_vnoperate+0x13
vfs_cache_lookup(d8d1bbac,d8d1bbc8,c065eb9b,d8d1bbac,c1bd7640) at vfs_cache_lookup+0xe2
ufs_vnoperate(d8d1bbac) at ufs_vnoperate+0x13
lookup(d8d1bc30,c1bd7640,c1d88ca8,c1e4bd00,c2772200) at lookup+0x2cf
namei(d8d1bc30,bfbfe810,0,0,c1becc60) at namei+0x1c1
lstat(c1bd7640,d8d1bd14,2a2,296) at lstat+0x4a
syscall(2f,2f,2f,bfbfed5c,bfbfed3c) at syscall+0x27b
Xint0x80_syscall() at Xint0x80_syscall+0x1f
--- syscall (190, FreeBSD ELF32, lstat), eip = 0x280fb837, esp = 0xbfbfdddc, ebp = 0xbfbfddf8 ---
db> call doadump
Dumping 495 MB
.. [ dumps, halt box, reboot etc. ]
I have the crash dump saved and can make it available if required. I can also reduce the size of the kernel memory for a more manageable file. This kernel panic appears to be reproducible, although it does not occur after a specific period of time or on a specific file transfer; the LBA of the WRITE_DMA timeout is not constant.
In addition, I can reproduce PR kern/73757 with this system and provide a dump for it.
dmesg follows:
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
The Regents of the University of California. All rights reserved.
FreeBSD 5.3-RELEASE-p4 #1: Thu Jan 13 20:12:44 MST 2005
root@ishtar:/usr/obj/usr/src/sys/ISHTAR
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: AMD Athlon(tm) XP 2600+ (1908.95-MHz 686-class CPU)
Origin = "AuthenticAMD" Id = 0x6a0 Stepping = 0
Features=0x383fbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR,SSE>
AMD Features=0xc0400000<AMIE,DSP,3DNow!>
real memory = 520028160 (495 MB)
avail memory = 499208192 (476 MB)
ACPI APIC Table: <KM400A AWRDACPI>
ioapic0 <Version 0.3> irqs 0-23 on motherboard
npx0: [FAST]
npx0: <math processor> on motherboard
npx0: INT 16 interface
acpi0: <KM400A AWRDACPI> on motherboard
acpi0: Power Button (fixed)
Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x408-0x40b on acpi0
cpu0: <ACPI CPU (3 Cx states)> on acpi0
acpi_tz0: <Thermal Zone> on acpi0
acpi_button0: <Power Button> on acpi0
acpi_button1: <Sleep Button> on acpi0
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
pci0: <ACPI PCI bus> on pcib0
agp0: <VIA Generic host to PCI bridge> mem 0xe0000000-0xe3ffffff at device 0.0 on pci0
pcib1: <PCI-PCI bridge> at device 1.0 on pci0
pci1: <PCI bus> on pcib1
pci1: <display, VGA> at device 0.0 (no driver attached)
atapci0: <SiI 3112 SATA150 controller> port 0xb000-0xb00f,0xac00-0xac03,0xa800-0xa807,0xa400-0xa403,0xa000-0xa007 mem 0xeb000000-0xeb0001ff irq 16 at device 8.0 on pci0
ata2: channel #0 on atapci0
ata3: channel #1 on atapci0
atapci1: <SiI 3112 SATA150 controller> port 0xc400-0xc40f,0xc000-0xc003,0xbc00-0xbc07,0xb800-0xb803,0xb400-0xb407 mem 0xeb001000-0xeb0011ff irq 18 at device 10.0 on pci0
ata4: channel #0 on atapci1
ata5: channel #1 on atapci1
uhci0: <VIA 83C572 USB controller> port 0xc800-0xc81f irq 21 at device 16.0 on pci0
uhci0: [GIANT-LOCKED]
usb0: <VIA 83C572 USB controller> on uhci0
usb0: USB revision 1.0
uhub0: VIA UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub0: 2 ports with 2 removable, self powered
uhci1: <VIA 83C572 USB controller> port 0xcc00-0xcc1f irq 21 at device 16.1 on pci0
uhci1: [GIANT-LOCKED]
usb1: <VIA 83C572 USB controller> on uhci1
usb1: USB revision 1.0
uhub1: VIA UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub1: 2 ports with 2 removable, self powered
uhci2: <VIA 83C572 USB controller> port 0xd000-0xd01f irq 21 at device 16.2 on pci0
uhci2: [GIANT-LOCKED]
usb2: <VIA 83C572 USB controller> on uhci2
usb2: USB revision 1.0
uhub2: VIA UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub2: 2 ports with 2 removable, self powered
pci0: <serial bus, USB> at device 16.3 (no driver attached)
isab0: <PCI-ISA bridge> at device 17.0 on pci0
isa0: <ISA bus> on isab0
atapci2: <VIA 8235 UDMA133 controller> port 0xd400-0xd40f,0x376,0x170-0x177,0x3f6,0x1f0-0x1f7 at device 17.1 on pci0
ata0: channel #0 on atapci2
ata1: channel #1 on atapci2
pci0: <multimedia, audio> at device 17.5 (no driver attached)
vr0: <VIA VT6102 Rhine II 10/100BaseTX> port 0xe000-0xe0ff mem 0xeb003000-0xeb0030ff irq 23 at device 18.0 on pci0
miibus0: <MII bus> on vr0
ukphy0: <Generic IEEE 802.3u media interface> on miibus0
ukphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
vr0: Ethernet address: 00:0e:a6:57:2e:de
fdc0: <floppy drive controller> port 0x3f7,0x3f2-0x3f5 irq 6 drq 2 on acpi0
fdc0: [FAST]
sio0: <16550A-compatible COM port> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
sio0: type 16550A
ppc0: <ECP parallel printer port> port 0x778-0x77b,0x378-0x37f irq 7 drq 3 on acpi0
ppc0: SMC-like chipset (ECP/EPP/PS2/NIBBLE) in COMPATIBLE mode
ppc0: FIFO with 16/16/9 bytes threshold
ppbus0: <Parallel port bus> on ppc0
plip0: <PLIP network interface> on ppbus0
lpt0: <Printer> on ppbus0
lpt0: Interrupt-driven port
ppi0: <Parallel I/O> on ppbus0
atkbdc0: <Keyboard controller (i8042)> port 0x64,0x60 irq 1 on acpi0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
kbd0 at atkbd0
atkbd0: [GIANT-LOCKED]
orm0: <ISA Option ROM> at iomem 0xd8000-0xdc7ff on isa0
pmtimer0 on isa0
sc0: <System console> at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
sio1: configured irq 3 not in bitmap of probed irqs 0
sio1: port may not be enabled
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
Timecounter "TSC" frequency 1908948716 Hz quality 800
Timecounters tick every 10.000 msec
acd0: CDRW <8X4X32/5.AX> at ata0-master PIO4
ad4: 114473MB <ST3120026AS/3.05> [232581/16/63] at ata2-master SATA150
ad6: 38146MB <ST340014AS/8.05> [77504/16/63] at ata3-master SATA150
ad8: 114473MB <ST3120026AS/3.05> [232581/16/63] at ata4-master SATA150
Mounting root from ufs:/dev/ad6s1a
>How-To-Repeat:
>Fix:
>Release-Note:
>Audit-Trail:
>Unformatted:
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?200501140609.j0E69rHY044250>