Lock order reversal

From: Jon Loeliger <jdl_at_jdl.com>
Date: Mon, 11 May 2009 09:10:54 -0500
Folks,

Curious if anyone saw the lock order reversal in my
post from yesterday?  Known issues?

There appear to be 3 cases, highlighted below:

 1st 0xc39e7a60 bufwait (bufwait) _at_ /usr/src/sys/kern/vfs_bio.c:2555
 2nd 0xc3ffee00 dirhash (dirhash) _at_ /usr/src/sys/ufs/ufs/ufs_dirhash.c:275

 1st 0xc4224164 ufs (ufs) _at_ /usr/src/sys/kern/vfs_mount.c:1050
 2nd 0xc4224df4 devfs (devfs) _at_ /usr/src/sys/kern/vfs_subr.c:2101

 1st 0xc44edc2c filedesc structure (filedesc structure) _at_ /usr/src/sys/kern/kern_descrip.c:1076
 2nd 0xc4a9737c ufs (ufs) _at_ /usr/src/sys/kern/vfs_subr.c:4109

Thanks,
jdl


------- Forwarded Message

To: freebsd-current_at_freebsd.org
Date: Sun, 10 May 2009 16:34:28 -0500
From: Jon Loeliger <jdl_at_jdl.com>
Message-Id: <E1M3GfE-0007Ld-9B_at_jdl.com>
Subject: Feedback and Questions Updating to CURRENT

[snip]

First, dmesg had this to say, and appeared not to be
too pleased near the end:

(I used GENERIC, minus all the RAID options to build this kernel.)
(Oh, and I use i686 only)

----------------------------------------------------------------
Copyright (c) 1992-2009 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 #1: Sun May 10 08:52:22 CDT 2009
    jdl_at_freebie.austin.rr.com:/usr/obj/usr/src/sys/FREEBIE
WARNING: WITNESS option enabled, expect reduced performance.
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: AMD Athlon(tm) Processor (1109.89-MHz 686-class CPU)
  Origin = "AuthenticAMD"  Id = 0x642  Stepping = 2
  Features=0x183f9ff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR>
  AMD Features=0xc0440800<SYSCALL,<b18>,MMX+,3DNow!+,3DNow!>
real memory  = 536870912 (512 MB)
avail memory = 773992448 (738 MB)
kbd1 at kbdmux0
acpi0: <ASUS A7V> on motherboard
acpi0: [ITHREAD]
acpi0: Power Button (fixed)
acpi0: reservation of 0, a0000 (3) failed
acpi0: reservation of 100000, 2ff00000 (3) failed
Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
acpi_timer0: <24-bit timer at 3.579545MHz> port 0xe408-0xe40b on acpi0
acpi_button0: <Power Button> on acpi0
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
pci0: <ACPI PCI bus> on pcib0
agp0: <VIA 82C8363 (Apollo KT133x/KM133) host to PCI bridge> on hostb0
agp0: aperture size is 256M
pcib1: <PCI-PCI bridge> at device 1.0 on pci0
pci1: <PCI bus> on pcib1
vgapci0: <VGA-compatible display> mem 0xd6000000-0xd6ffffff,0xd8000000-0xdfffffff irq 11 at device 0.0 on pci1
isab0: <PCI-ISA bridge> at device 4.0 on pci0
isa0: <ISA bus> on isab0
atapci0: <VIA 82C686A UDMA66 controller> port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xd800-0xd80f at device 4.1 on pci0
ata0: <ATA channel 0> on atapci0
ata0: [ITHREAD]
ata1: <ATA channel 1> on atapci0
ata1: [ITHREAD]
rl0: <Accton MPX 5030/5038 10/100BaseTX> port 0xa400-0xa4ff mem 0xd5800000-0xd58000ff irq 9 at device 9.0 on pci0
miibus0: <MII bus> on rl0
rlphy0: <RealTek internal media interface> PHY 0 on miibus0
rlphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
rl0: Ethernet address: 00:e0:29:74:1c:4c
rl0: [ITHREAD]
pci0: <multimedia, audio> at device 13.0 (no driver attached)
atapci1: <Promise PDC20265 UDMA100 controller> port 0x9800-0x9807,0x9400-0x9403,0x9000-0x9007,0x8800-0x8803,0x8400-0x843f mem 0xd5000000-0xd501ffff irq 10 at device 17.0 on pci0
atapci1: [ITHREAD]
ata2: <ATA channel 0> on atapci1
ata2: [ITHREAD]
ata3: <ATA channel 1> on atapci1
ata3: [ITHREAD]
atrtc0: <AT realtime clock> port 0x70-0x73 irq 8 on acpi0
fdc1: <floppy drive controller> port 0x3f2-0x3f5,0x3f7 irq 6 drq 2 on acpi0
fdc1: [FILTER]
uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
uart0: [FILTER]
uart1: <16550 or compatible> port 0x2f8-0x2ff irq 3 on acpi0
uart1: [FILTER]
atkbdc0: <Keyboard controller (i8042)> port 0x60,0x64 irq 1 on acpi0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
kbd0 at atkbd0
atkbd0: [GIANT-LOCKED]
atkbd0: [ITHREAD]
psm0: <PS/2 Mouse> irq 12 on atkbdc0
psm0: [GIANT-LOCKED]
psm0: [ITHREAD]
psm0: model IntelliMouse Explorer, device ID 4
cpu0: <ACPI CPU> on acpi0
acpi_throttle0: <ACPI CPU Throttling> on cpu0
pmtimer0 on isa0
orm0: <ISA Option ROM> at iomem 0xc0000-0xcafff pnpid ORM0000 on isa0
sc0: <System console> at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
fdc0: No FDOUT register!
ppc0: parallel port not found.
Timecounter "TSC" frequency 1109893249 Hz quality 800
Timecounters tick every 1.000 msec
ad0: 39083MB <Maxtor 5T040H4 TAH71DP0> at ata0-master UDMA66
acd0: CDRW <TOSHIBA DVD-ROM SD-R1002/1030> at ata1-master PIO4
acd1: CDROM <CDU5211/YYS2> at ata1-slave PIO4
WARNING: WITNESS option enabled, expect reduced performance.
GEOM_LABEL: Label for provider ad0s1a is ufsid/49f8a3e1ab5cc6ca.
GEOM_LABEL: Label for provider ad0s1d is ufsid/49f8a3e53ba41565.
GEOM_LABEL: Label for provider ad0s1e is ufsid/49f8a3e136e4ee3d.
GEOM_LABEL: Label for provider ad0s1f is ufsid/49f8a3e175f2b211.
Trying to mount root from ufs:/dev/ad0s1a
GEOM_LABEL: Label ufsid/49f8a3e1ab5cc6ca removed.
GEOM_LABEL: Label for provider ad0s1a is ufsid/49f8a3e1ab5cc6ca.
GEOM_LABEL: Label ufsid/49f8a3e136e4ee3d removed.
GEOM_LABEL: Label for provider ad0s1e is ufsid/49f8a3e136e4ee3d.
GEOM_LABEL: Label ufsid/49f8a3e175f2b211 removed.
GEOM_LABEL: Label for provider ad0s1f is ufsid/49f8a3e175f2b211.
GEOM_LABEL: Label ufsid/49f8a3e53ba41565 removed.
GEOM_LABEL: Label for provider ad0s1d is ufsid/49f8a3e53ba41565.
GEOM_LABEL: Label ufsid/49f8a3e1ab5cc6ca removed.
GEOM_LABEL: Label ufsid/49f8a3e136e4ee3d removed.
GEOM_LABEL: Label ufsid/49f8a3e175f2b211 removed.
GEOM_LABEL: Label ufsid/49f8a3e53ba41565 removed.

----------------

lock order reversal:
 1st 0xc39e7a60 bufwait (bufwait) _at_ /usr/src/sys/kern/vfs_bio.c:2555
 2nd 0xc3ffee00 dirhash (dirhash) _at_ /usr/src/sys/ufs/ufs/ufs_dirhash.c:275
KDB: stack backtrace:
db_trace_self_wrapper(c0b84a8f,df3aaa78,c08576d5,c08495db,c0b87874,...) at db_trace_self_wrapper+0x26
kdb_backtrace(c08495db,c0b87874,c3d1fae8,c3d225f8,df3aaad4,...) at kdb_backtrace+0x29
_witness_debugger(c0b87874,c3ffee00,c0ba7492,c3d225f8,c0ba712b,...) at _witness_debugger+0x25
witness_checkorder(c3ffee00,9,c0ba712b,113,0,...) at witness_checkorder+0x839
_sx_xlock(c3ffee00,0,c0ba712b,113,d33946cc,...) at _sx_xlock+0x85
ufsdirhash_acquire(0,e,c3ea0000,c39e7a00,d33946cc,...) at ufsdirhash_acquire+0x35
ufsdirhash_remove(c4035d24,d33946cc,6cc,df3aab64,df3aab60,...) at ufsdirhash_remove+0x14
ufs_dirremove(c3ec7648,c4228e0c,500800c,0,c3ec7648,...) at ufs_dirremove+0xe5
ufs_remove(df3aac34,df3aac44,0,0,c422610c,...) at ufs_remove+0x6e
VOP_REMOVE_APV(c0c7d520,df3aac34,2,df3aac00,bfbfef62,...) at VOP_REMOVE_APV+0xa5
kern_unlinkat(c3eb4d80,ffffff9c,bfbfef62,0,df3aac80,...) at kern_unlinkat+0x152
kern_unlink(c3eb4d80,bfbfef62,0,df3aad2c,c0ac2fd3,...) at kern_unlink+0x27
unlink(c3eb4d80,df3aacf8,4,c0b88129,c0c5e110,...) at unlink+0x22
syscall(df3aad38) at syscall+0x2a3
Xint0x80_syscall() at Xint0x80_syscall+0x20
- --- syscall (10, FreeBSD ELF32, unlink), eip = 0x2815e5af, esp = 0xbfbfe50c, ebp = 0xbfbfeda8 ---

----------------

lock order reversal:
 1st 0xc4224164 ufs (ufs) _at_ /usr/src/sys/kern/vfs_mount.c:1050
 2nd 0xc4224df4 devfs (devfs) _at_ /usr/src/sys/kern/vfs_subr.c:2101
KDB: stack backtrace:
db_trace_self_wrapper(c0b84a8f,df385814,c08576d5,c08495db,c0b87874,...) at db_trace_self_wrapper+0x26
kdb_backtrace(c08495db,c0b87874,c3d22590,c3d224c0,df385870,...) at kdb_backtrace+0x29
_witness_debugger(c0b87874,c4224df4,c0b7702e,c3d224c0,c0b8e6bd,...) at _witness_debugger+0x25
witness_checkorder(c4224df4,9,c0b8e6bd,835,0,...) at witness_checkorder+0x839
__lockmgr_args(c4224df4,80100,c4224e10,0,0,...) at __lockmgr_args+0x797
vop_stdlock(df385978,c085747b,c0b7725f,80100,c4224d9c,...) at vop_stdlock+0x62
VOP_LOCK1_APV(c0c5ac80,df385978,c403ee24,c0c94700,c4224d9c,...) at VOP_LOCK1_APV+0xa5
_vn_lock(c4224d9c,80100,c0b8e6bd,835,8,...) at _vn_lock+0x5e
vget(c4224d9c,80100,c403ed80,160,c0b77181,...) at vget+0xc9
devfs_allocv(c40ee380,c402d280,df385a10,c403ed80,c0e21fb8,...) at devfs_allocv+0x11a
devfs_root(c402d280,80000,df385c2c,c403ed80,0,...) at devfs_root+0x51
vfs_donmount(c403ed80,0,c40ee480,c40ee480,bfbfde39,...) at vfs_donmount+0x14d0
nmount(c403ed80,df385cf8,c,c,c0c60390,...) at nmount+0x72
syscall(df385d38) at syscall+0x2a3
Xint0x80_syscall() at Xint0x80_syscall+0x20
- --- syscall (378, FreeBSD ELF32, nmount), eip = 0x280e3edb, esp = 0xbfbfde0c, ebp = 0xbfbfe368 ---

----------------

lock order reversal:
 1st 0xc44edc2c filedesc structure (filedesc structure) _at_ /usr/src/sys/kern/kern_descrip.c:1076
 2nd 0xc4a9737c ufs (ufs) _at_ /usr/src/sys/kern/vfs_subr.c:4109
KDB: stack backtrace:
db_trace_self_wrapper(c0b84a8f,df44aa2c,c08576d5,c08495db,c0b87874,...) at db_trace_self_wrapper+0x26
kdb_backtrace(c08495db,c0b87874,c3d1fd58,c3d22590,df44aa88,...) at kdb_backtrace+0x29
_witness_debugger(c0b87874,c4a9737c,c0b7aba2,c3d22590,c0b8e6bd,...) at _witness_debugger+0x25
witness_checkorder(c4a9737c,9,c0b8e6bd,100d,c4a97398,...) at witness_checkorder+0x839
__lockmgr_args(c4a9737c,80400,c4a97398,0,0,...) at __lockmgr_args+0x797
ffs_lock(df44ab98,c,0,80400,c4a97324,...) at ffs_lock+0x8a
VOP_LOCK1_APV(c0c7d520,df44ab98,df44aba0,c0c94700,c4a97324,...) at VOP_LOCK1_APV+0xa5
_vn_lock(c4a97324,80400,c0b8e6bd,100d,df44abf4,...) at _vn_lock+0x5e
vfs_knllock(c4a97324,0,c0b7cd90,68c,c4a66154,...) at vfs_knllock+0x29
knlist_remove_kq(0,df44ac14,c089e909,c4a542f4,c4a66154,...) at knlist_remove_kq+0xad
knlist_remove(c4a542f4,c4a66154,0,df44ac40,c07ebc85,...) at knlist_remove+0x1b
filt_vfsdetach(c4a66154,0,c0b7cd90,75c,f,...) at filt_vfsdetach+0x39
knote_fdclose(c4443240,12af,c0b7c8d3,434,c44edc2c,...) at knote_fdclose+0xf5
kern_close(c4443240,12af,df44ad2c,c0ac2fd3,c4443240,...) at kern_close+0xd2
close(c4443240,df44acf8,4,c0b88115,c0c5e0b0,...) at close+0x1a
syscall(df44ad38) at syscall+0x2a3
Xint0x80_syscall() at Xint0x80_syscall+0x20
--- syscall (6, FreeBSD ELF32, close), eip = 0x28370a73, esp = 0xbfbfe71c, ebp = 0xbfbfe738 ---

----------------

pid 1712 (perl5.8.9), uid 0: exited on signal 6 (core dumped)
pid 1713 (perl5.8.9), uid 0: exited on signal 6 (core dumped)
pid 1771 (perl5.8.9), uid 0: exited on signal 6 (core dumped)

----------------------------------------------------------------



------- End of Forwarded Message
Received on Mon May 11 2009 - 12:11:03 UTC

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