Date: Mon, 21 Jul 2008 17:03:14 -0400 From: Andrew Gallatin <gallatin@cs.duke.edu> To: freebsd-current@freebsd.org Subject: reproducible "panic: share->excl" Message-ID: <4884F992.7090008@cs.duke.edu>
next in thread | raw e-mail | index | archive | help
I can panic today's -current reliably (or hang it with
WITNESS/INVARIENTS disabled). When it crashes, I see
the appended panic messages.
It seems to be 100% reproducible on my box (AMD64 x2,
512MB ram, UFS2). If anybody savvy in this area would
like to reproduce it, I've left the program at ~gallatin/ahunt.c
on freefall. Compile it, and run it as:
./a.out -mmbfileinit -madvise=/var/tmp/zot -random -size=95536
-touch=4096 -rewrite=2
Cheers,
Drew
PS: Here is a serial console log from the panic:
KDB: debugger backends: ddb
KDB: current backend: ddb
Copyright (c) 1992-2008 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
The Regents of the University of California. All rights reserved.
FreeBSD is a registered trademark of The FreeBSD Foundation.
FreeBSD 8.0-CURRENT #2 r180446:180672: Mon Jul 21 16:35:46 EDT 2008
gallatin@venice:/usr/src/sys/amd64/compile/WITNESS
WARNING: WITNESS option enabled, expect reduced performance.
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: AMD Athlon(tm) 64 X2 Dual Core Processor 3800+ (2050.16-MHz
K8-class CPU)
Origin = "AuthenticAMD" Id = 0x20f32 Stepping = 2
Features=0x178bfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,MMX,FXSR,SSE,SSE2,HTT>
Features2=0x1<SSE3>
AMD Features=0xe2500800<SYSCALL,NX,MMX+,FFXSR,LM,3DNow!+,3DNow!>
AMD Features2=0x3<LAHF,CMP>
Cores per package: 2
usable memory = 522149888 (497 MB)
avail memory = 502501376 (479 MB)
ACPI APIC Table: <Nvidia AWRDACPI>
FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs
cpu0 (BSP): APIC ID: 0
cpu1 (AP): APIC ID: 1
ioapic0: Changing APIC ID to 2
ioapic0 <Version 1.1> irqs 0-23 on motherboard
kbd1 at kbdmux0
ath_hal: 0.9.20.3 (AR5210, AR5211, AR5212, RF5111, RF5112, RF2413, RF5413)
acpi0: <Nvidia AWRDACPI> on motherboard
acpi0: [ITHREAD]
acpi0: Power Button (fixed)
acpi0: reservation of 0, a0000 (3) failed
acpi0: reservation of 100000, 1fde0000 (3) failed
Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x1008-0x100b on acpi0
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
pci0: <ACPI PCI bus> on pcib0
pci0: <memory> at device 0.0 (no driver attached)
isab0: <PCI-ISA bridge> at device 1.0 on pci0
isa0: <ISA bus> on isab0
pci0: <serial bus, SMBus> at device 1.1 (no driver attached)
ohci0: <OHCI (generic) USB controller> mem 0xfe02f000-0xfe02ffff irq 21
at device 2.0 on pci0
ohci0: [GIANT-LOCKED]
ohci0: [ITHREAD]
usb0: OHCI version 1.0, legacy support
usb0: <OHCI (generic) USB controller> on ohci0
usb0: USB revision 1.0
uhub0: <nVidia OHCI root hub, class 9/0, rev 1.00/1.00, addr 1> on usb0
uhub0: 10 ports with 10 removable, self powered
ehci0: <NVIDIA nForce4 USB 2.0 controller> mem 0xfeb00000-0xfeb000ff irq
22 at device 2.1 on pci0
ehci0: [GIANT-LOCKED]
ehci0: [ITHREAD]
usb1: waiting for BIOS to give up control
usb1: timed out waiting for BIOS
usb1: EHCI version 1.0
usb1: companion controller, 4 ports each: usb0
usb1: <NVIDIA nForce4 USB 2.0 controller> on ehci0
usb1: USB revision 2.0
uhub1: <nVidia EHCI root hub, class 9/0, rev 2.00/1.00, addr 1> on usb1
uhub1: 10 ports with 10 removable, self powered
atapci0: <nVidia nForce CK804 UDMA133 controller> port
0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xe800-0xe80f at device 6.0 on pci0
ata0: <ATA channel 0> on atapci0
ata0: [ITHREAD]
ata1: <ATA channel 1> on atapci0
ata1: [ITHREAD]
atapci1: <nVidia nForce CK804 SATA300 controller> port
0x9f0-0x9f7,0xbf0-0xbf3,0x970-0x977,0xb70-0xb73,0xd400-0xd40f mem
0xfe02c000-0xfe02cfff irq 23 at device 7.0 on pci0
atapci1: [ITHREAD]
ata2: <ATA channel 0> on atapci1
ata2: [ITHREAD]
ata3: <ATA channel 1> on atapci1
ata3: [ITHREAD]
atapci2: <nVidia nForce CK804 SATA300 controller> port
0x9e0-0x9e7,0xbe0-0xbe3,0x960-0x967,0xb60-0xb63,0xc000-0xc00f mem
0xfe02b000-0xfe02bfff irq 21 at device 8.0 on pci0
atapci2: [ITHREAD]
ata4: <ATA channel 0> on atapci2
ata4: [ITHREAD]
ata5: <ATA channel 1> on atapci2
ata5: [ITHREAD]
pcib1: <ACPI PCI-PCI bridge> at device 9.0 on pci0
pci1: <ACPI PCI bus> on pcib1
vgapci0: <VGA-compatible display> port 0xac00-0xacff mem
0xd8000000-0xdfffffff,0xfdfe0000-0xfdfeffff irq 18 at device 6.0 on pci1
fwohci0: <VIA Fire II (VT6306)> port 0xa800-0xa87f mem
0xfdfff000-0xfdfff7ff irq 17 at device 9.0 on pci1
fwohci0: [FILTER]
fwohci0: OHCI version 1.10 (ROM=1)
fwohci0: No. of Isochronous channels is 4.
fwohci0: EUI64 00:01:29:10:00:04:d8:01
fwohci0: Phy 1394a available S400, 2 ports.
fwohci0: Link S400, max_rec 2048 bytes.
firewire0: <IEEE1394(FireWire) bus> on fwohci0
fwe0: <Ethernet over FireWire> on firewire0
if_fwe0: Fake Ethernet address: 02:01:29:04:d8:01
fwe0: Ethernet address: 02:01:29:04:d8:01
fwip0: <IP over FireWire> on firewire0
fwip0: Firewire address: 00:01:29:10:00:04:d8:01 @ 0xfffe00000000, S400,
maxrec 2048
sbp0: <SBP-2/SCSI over FireWire> on firewire0
dcons_crom0: <dcons configuration ROM> on firewire0
dcons_crom0: bus_addr 0x1174000
fwohci0: Initiate bus reset
fwohci0: BUS reset
fwohci0: node_id=0xc800ffc0, gen=1, CYCLEMASTER mode
skc0: <Marvell Gigabit Ethernet> port 0xa400-0xa4ff mem
0xfdff8000-0xfdffbfff irq 18 at device 10.0 on pci1
skc0: Marvell Yukon Lite Gigabit Ethernet rev. (0x9)
sk0: <Marvell Semiconductor, Inc. Yukon> on skc0
sk0: Ethernet address: 00:01:29:f5:bc:3e
miibus0: <MII bus> on sk0
e1000phy0: <Marvell 88E1011 Gigabit PHY> PHY 0 on miibus0
e1000phy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX,
1000baseTX-FDX, auto
skc0: [ITHREAD]
nfe0: <NVIDIA nForce4 CK804 MCP9 Networking Adapter> port 0xbc00-0xbc07
mem 0xfe02a000-0xfe02afff irq 22 at device 10.0 on pci0
miibus1: <MII bus> on nfe0
ciphy0: <Cicada CS8201 10/100/1000TX PHY> PHY 1 on miibus1
ciphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT,
1000baseT-FDX, auto
nfe0: Ethernet address: 00:01:29:f5:6b:91
nfe0: [FILTER]
pcib2: <ACPI PCI-PCI bridge> at device 11.0 on pci0
pci2: <ACPI PCI bus> on pcib2
pcib3: <ACPI PCI-PCI bridge> at device 12.0 on pci0
pci3: <ACPI PCI bus> on pcib3
pcib4: <ACPI PCI-PCI bridge> at device 13.0 on pci0
pci4: <ACPI PCI bus> on pcib4
pcib5: <ACPI PCI-PCI bridge> at device 14.0 on pci0
pci5: <ACPI PCI bus> on pcib5
pci5: <network, ethernet> at device 0.0 (no driver attached)
cpu0: <ACPI CPU> on acpi0
powernow0: <Cool`n'Quiet K8> on cpu0
device_attach: powernow0 attach returned 6
cpu1: <ACPI CPU> on acpi0
powernow1: <Cool`n'Quiet K8> on cpu1
device_attach: powernow1 attach returned 6
acpi_button0: <Power Button> on acpi0
acpi_tz0: <Thermal Zone> on acpi0
atrtc0: <AT realtime clock> port 0x70-0x73 irq 8 on acpi0
fdc0: <floppy drive controller> port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on acpi0
fdc0: [FILTER]
sio0: <16550A-compatible COM port> port 0x3f8-0x3ff irq 4 flags 0x10 on
acpi0
sio0: type 16550A, console
sio0: [FILTER]
sio1: <Generic IRDA-compatible device> port 0x2f8-0x2ff irq 3 on acpi0
sio1: type 16550A
sio1: [FILTER]
orm0: <ISA Option ROMs> at iomem 0xc0000-0xcbfff,0xcc000-0xd37ff on isa0
atkbdc0: <Keyboard controller (i8042)> at port 0x60,0x64 on isa0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
kbd0 at atkbd0
atkbd0: [GIANT-LOCKED]
atkbd0: [ITHREAD]
ppc0: cannot reserve I/O port range
sc0: <System console> at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x100>
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
uhub2: <Mitsumi Electric Hub in Apple Extended USB Keyboard, class 9/0,
rev 1.10/1.22, addr 2> on uhub0
uhub2: 3 ports with 2 removable, bus powered
ukbd0: <Mitsumi Electric Apple Extended USB Keyboard, class 0/0, rev
1.10/1.22, addr 3> on uhub2
kbd2 at ukbd0
uhid0: <Mitsumi Electric Apple Extended USB Keyboard, class 0/0, rev
1.10/1.22, addr 3> on uhub2
ums0: <Fujitsu Takamisawa Component Apple Optical USB Mouse, class 0/0,
rev 1.10/1.06, addr 4> on uhub2
ums0: 1 buttons.
Timecounter "TSC" freqfirewire0: 1 nodes, maxhop <= 0, cable IRM = 0 (me)
firewire0: bus manager 0 (me)
uency 2050155704 Hz quality 800
Timecounters tick every 1.000 msec
acd0: DVDROM <LITE-ON DVD SOHD-16P9S/FS09> at ata0-master UDMA33
ad8: 78167MB <Maxtor 6Y080M0 YAR51HW0> at ata4-master SATA150
ad10: 114473MB <Seagate ST3120827AS 3.42> at ata5-master SATA150
GEOM_LABEL: Label for provider ad8s2 is ext2fs//1.
SMP: AP CPU #1 Launched!
WARNING: WITNESS option enabled, expect reduced performance.
lock order reversal: (sleepable after non-sleepable)
1st 0xffffff000175d028 struct mount mtx (struct mount mtx) @
kern/vfs_subr.c:343
2nd 0xffffff000175d000 vfslock (vfslock) @ kern/vfs_subr.c:370
KDB: stack backtrace:
db_trace_self_wrapper() at db_trace_self_wrapper+0x2a
witness_checkorder() at witness_checkorder+0x609
__lockmgr_args() at __lockmgr_args+0xc74
vfs_busy() at vfs_busy+0xe7
vfs_mount_alloc() at vfs_mount_alloc+0x8b
vfs_mountroot() at vfs_mountroot+0x241
start_init() at start_init+0x62
fork_exit() at fork_exit+0x12a
fork_trampoline() at fork_trampoline+0xe
--- trap 0, rip = 0, rsp = 0xfffffffe40010d30, rbp = 0 ---
lock order reversal: (sleepable after non-sleepable)
1st 0xffffff0001763470 vnode interlock (vnode interlock) @
fs/devfs/devfs_vnops.c:288
2nd 0xffffff0001763448 devfs (devfs) @ kern/vfs_subr.c:2044
KDB: stack backtrace:
db_trace_self_wrapper() at db_trace_self_wrapper+0x2a
witness_checkorder() at witness_checkorder+0x609
__lockmgr_args() at __lockmgr_args+0x502
vop_stdlock() at vop_stdlock+0x39
VOP_LOCK1_APV() at VOP_LOCK1_APV+0x9b
_vn_lock() at _vn_lock+0x47
vget() at vget+0x7b
devfs_allocv() at devfs_allocv+0x10c
devfs_root() at devfs_root+0x52
set_rootvnode() at set_rootvnode+0x2d
vfs_mountroot() at vfs_mountroot+0x2fe
start_init() at start_init+0x62
fork_exit() at fork_exit+0x12a
fork_trampoline() at fork_trampoline+0xe
--- trap 0, rip = 0, rsp = 0xfffffffe40010d30, rbp = 0 ---
Trying to mount root from ufs:/dev/ad8s3a
lock order reversal: (sleepable after non-sleepable)
1st 0xffffff00017632f0 bufobj interlock (bufobj interlock) @
kern/vfs_bio.c:2429
2nd 0xfffffffe503099e8 bufwait (bufwait) @ kern/vfs_bio.c:2443
KDB: stack backtrace:
db_trace_self_wrapper() at db_trace_self_wrapper+0x2a
witness_checkorder() at witness_checkorder+0x609
__lockmgr_args() at __lockmgr_args+0x502
getblk() at getblk+0xe3
breadn() at breadn+0x3f
bread() at bread+0x1e
ffs_blkatoff() at ffs_blkatoff+0x61
ufs_lookup() at ufs_lookup+0x5f3
vfs_cache_lookup() at vfs_cache_lookup+0xf8
VOP_LOOKUP_APV() at VOP_LOOKUP_APV+0x95
lookup() at lookup+0x4b2
namei() at namei+0x43f
kern_unlinkat() at kern_unlinkat+0x9d
vfs_mountroot_try() at vfs_mountroot_try+0x41b
vfs_mountroot() at vfs_mountroot+0x3eb
start_init() at start_init+0x62
fork_exit() at fork_exit+0x12a
fork_trampoline() at fork_trampoline+0xe
--- trap 0, rip = 0, rsp = 0xfffffffe40010d30, rbp = 0 ---
Entropy harvesting: interrupts ethernet point_to_point kickstart.
/dev/ad8s3a: FILE SYSTEM CLEAN; SKIPPING CHECKS
/dev/ad8s3a: clean, 56390 free (1062 frags, 6916 blocks, 0.8% fragmentation)
/dev/ad8s3d: FILE SYSTEM CLEAN; SKIPPING CHECKS
/dev/ad8s3d: clean, 126833 free (25 frags, 15851 blocks, 0.0% fragmentation)
/dev/ad8s3f: FILE SYSTEM CLEAN; SKIPPING CHECKS
/dev/ad8s3f: clean, 2601443 free (90875 frags, 313821 blocks, 2.3%
fragmentation)
/dev/ad8s3e: FILE SYSTEM CLEAN; SKIPPING CHECKS
/dev/ad8s3e: clean, 847205 free (28653 frags, 102319 blocks, 1.l9%
fragmentationoc)
k order reversal:
1st 0xffffff00018447f8 ufs (ufs) @ kern/vfs_subr.c:2044
2nd 0xffffffff80b0fcc0 kernel linker (kernel linker) @
kern/kern_linker.c:693
KDB: stack backtrace:
db_trace_self_wrapper() at db_trace_self_wrapper+0x2a
witness_checkorder() at witness_checkorder+0x609
_sx_xlock() at _sx_xlock+0x52
linker_file_lookup_set() at linker_file_lookup_set+0xe1
linker_file_register_sysctls() at linker_file_register_sysctls+0x20
linker_load_module() at linker_load_module+0x909
linker_load_dependencies() at linker_load_dependencies+0x1bc
link_elf_load_file() at link_elf_load_file+0xa8a
linker_load_module() at linker_load_module+0x8bf
kern_kldload() at kern_kldload+0xac
kldload() at kldload+0x84
syscall() at syscall+0x1dd
Xfast_syscall() at Xfast_syscall+0xab
--- syscall (304, FreeBSD ELF64, kldload), rip = 0x800691c5c, rsp =
0x7fffffffedd8, rbp = 0 ---
This module (opensolaris) contains code covered by the
Common Development and Distribution License (CDDL)
see http://opensolaris.org/os/licensing/opensolaris_license/
WARNING: ZFS is considered to be an experimental feature in FreeBSD.
ZFS WARNING: Recommended minimum kmem_size is 512MB; expect unstable
behavior.
Consider tuning vm.kmem_size and vm.kmem_size_max
in /boot/loader.conf.
ZFS filesystem version 6
ZFS storage pool version 6
nfe0: link state changed to DOWN
Starting Network: lo0 nfe0.
sk0: link state changed to DOWN
/etc/rc.d/power_profile: WARNING: unable to set hw.acpi.cpu.cx_lowest=C1
Waiting 30s for an interface to come up: ................nfe0: link
state changed to UP
(nfe0)
Mounting NFS file systems:.
Setting date via ntp.
21 Jul 16:46:30 ntpdate[1360]: adjust time server 152.2.21.1 offset
0.316513 sec
Recovering vi editor sessions:.
Configuring syscons: blanktime.
Mon Jul 21 16:46:32 EDT 2008
FreeBSD/amd64 (venice) (ttyd0)
login: shared lock of (lockmgr) ufs @ kern/vfs_subr.c:2044
while exclusively locked from kern/vfs_vnops.c:593
panic: share->excl
cpuid = 1
KDB: enter: panic
[thread pid 1702 tid 100149 ]
Stopped at kdb_enter+0x3d: movq $0,0x639958(%rip)
db> tr
Tracing pid 1702 tid 100149 td 0xffffff000d08f000
kdb_enter() at kdb_enter+0x3d
panic() at panic+0x176
witness_checkorder() at witness_checkorder+0x137
__lockmgr_args() at __lockmgr_args+0xc74
ffs_lock() at ffs_lock+0x8c
VOP_LOCK1_APV() at VOP_LOCK1_APV+0x9b
_vn_lock() at _vn_lock+0x47
vget() at vget+0x7b
vnode_pager_lock() at vnode_pager_lock+0x146
vm_fault() at vm_fault+0x1e2
trap_pfault() at trap_pfault+0x128
trap() at trap+0x395
calltrap() at calltrap+0x8
--- trap 0xc, rip = 0xffffffff8079f2bd, rsp = 0xfffffffe58c2f7b0, rbp =
0xfffffffe58c2f830 ---
copyin() at copyin+0x3d
ffs_write() at ffs_write+0x2f8
VOP_WRITE_APV() at VOP_WRITE_APV+0x10b
vn_write() at vn_write+0x23f
dofilewrite() at dofilewrite+0x85
--More--
kern_writev() at kern_writev+0x60
write() at write+0x54
syscall() at syscall+0x1dd
Xfast_syscall() at Xfast_syscall+0xab
--- syscall (4, FreeBSD ELF64, write), rip = 0x8007296ec, rsp =
0x7fffffffe158, rbp = 0x7fffffffe210 ---
db> show locks
exclusive sleep mutex vnode interlock r = 0 (0xffffff000d0dc0c0) locked
@ vm/vnode_pager.c:1199
exclusive sx user map r = 0 (0xffffff000d054360) locked @ vm/vm_map.c:3115
exclusive lockmgr bufwait r = 0 (0xfffffffe5047f278) locked @
kern/vfs_bio.c:1783
exclusive lockmgr ufs r = 0 (0xffffff000d0dc098) locked @
kern/vfs_vnops.c:593
db>
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?4884F992.7090008>