Lock Order Reversal

[wallabybob]

I've just installed 2.0-BETA1 built on Sun Feb 21 05:56:33 EST 2010 FreeBSD 8.0-STABLE

The startup reports a couple of lock order reversals:

dmesg

Copyright 1992-2010 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-STABLE #1: Sun Feb 21 05:51:23 EST 2010
    sullrich@FreeBSD_8.0_pfSense_2.0-snaps.pfsense.org:/usr/obj.pfSense/usr/pfSensesrc/src/sys/pfSense_Dev.8 i386
WARNING: WITNESS option enabled, expect reduced performance.
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: VIA Samuel 2 (797.74-MHz 686-class CPU)
  Origin = "CentaurHauls"  Id = 0x673  Stepping = 3
  Features=0x803035 <fpu,de,tsc,msr,mtrr,pge,mmx>real memory  = 536870912 (512 MB)
avail memory = 469020672 (447 MB)
ipw_bss: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw/.
ipw_bss: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf.
module_register_init: MOD_LOAD (ipw_bss_fw, 0xc071d310, 0) error 1
ipw_ibss: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw/.
ipw_ibss: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf.
module_register_init: MOD_LOAD (ipw_ibss_fw, 0xc071d3d0, 0) error 1
ipw_monitor: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw/.
ipw_monitor: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf.
module_register_init: MOD_LOAD (ipw_monitor_fw, 0xc071d490, 0) error 1
wlan: mac acl policy registered
wpi: You need to read the LICENSE file in /usr/share/doc/legal/intel_wpi/.
wpi: If you agree with the license, set legal.intel_wpi.license_ack=1 in /boot/loader.conf.
module_register_init: MOD_LOAD (wpi_fw, 0xc08e30b0, 0) error 1
kbd1 at kbdmux0
cryptosoft0: <software crypto="">on motherboard
padlock0: No ACE support.
acpi0: <cle266 awrdacpi="">on motherboard
acpi0: [ITHREAD]
acpi0: Power Button (fixed)
acpi0: reservation of 0, a0000 (3) failed
acpi0: reservation of 100000, 1def0000 (3) failed
Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x4008-0x400b on acpi0
acpi_button0: <power button="">on acpi0
pcib0: <acpi host-pci="" bridge="">port 0xcf8-0xcff on acpi0
pci_link1: BIOS IRQ 5 for 0.8.INTA is invalid
pci_link1: BIOS IRQ 5 for 0.16.INTB is invalid
pci0: <acpi pci="" bus="">on pcib0
agp0: <via 862x="" (cle266)="" host="" to="" pci="" bridge="">on hostb0
agp0: aperture size is 16M
pcib1: <pci-pci bridge="">at device 1.0 on pci0
pci1: <pci bus="">on pcib1
vgapci0: <vga-compatible display="">mem 0xe8000000-0xebffffff,0xec000000-0xecffffff irq 11 at device 0.0 on pci1
ral0: <ralink technology="" rt2560="">mem 0xef000000-0xef001fff irq 7 at device 8.0 on pci0
ral0: MAC/BBP RT2560 (rev 0x04), RF RT2525
ral0: [ITHREAD]
rl0: <realtek 10="" 8139="" 100basetx="">port 0xe000-0xe0ff mem 0xef002000-0xef0020ff irq 10 at device 11.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: [ITHREAD]
uhci0: <via 83c572="" usb="" controller="">port 0xeb00-0xeb1f irq 11 at device 16.0 on pci0
uhci0: [ITHREAD]
usbus0: <via 83c572="" usb="" controller="">on uhci0
uhci1: <via 83c572="" usb="" controller="">port 0xe800-0xe81f irq 7 at device 16.1 on pci0
uhci1: [ITHREAD]
usbus1: <via 83c572="" usb="" controller="">on uhci1
uhci2: <via 83c572="" usb="" controller="">port 0xe900-0xe91f irq 7 at device 16.2 on pci0
uhci2: [ITHREAD]
usbus2: <via 83c572="" usb="" controller="">on uhci2
ehci0: <via vt6202="" usb="" 2.0="" controller="">mem 0xef003000-0xef0030ff irq 10 at device 16.3 on pci0
ehci0: [ITHREAD]
usbus3: EHCI version 1.0
usbus3: <via vt6202="" usb="" 2.0="" controller="">on ehci0
isab0: <pci-isa bridge="">at device 17.0 on pci0
isa0: <isa bus="">on isab0
atapci0: <via 8235="" udma133="" controller="">port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xea00-0xea0f at device 17.1 on pci0
ata0: <ata 0="" channel="">on atapci0
ata0: [ITHREAD]
ata1: <ata 1="" channel="">on atapci0
ata1: [ITHREAD]
vr0: <via 10="" vt6102="" rhine="" ii="" 100basetx="">port 0xe400-0xe4ff mem 0xef004000-0xef0040ff irq 11 at device 18.0 on pci0
vr0: Quirks: 0x0
vr0: Revision: 0x74
miibus1: <mii bus="">on vr0
ukphy0: <generic ieee="" 802.3u="" media="" interface="">PHY 1 on miibus1
ukphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
vr0: [ITHREAD]
acpi_tz0: <thermal zone="">on acpi0
atrtc0: <at realtime="" clock="">port 0x70-0x73 irq 8 on acpi0
uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
atpic: Mismatched config for IRQ4: trigger edge, polarity low
uart0: [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
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
ppc0: parallel port not found.
Timecounter "TSC" frequency 797737325 Hz quality 800
Timecounters tick every 1.000 msec
IPsec: Initialized Security Association Processing.
usbus0: 12Mbps Full Speed USB v1.0
usbus1: 12Mbps Full Speed USB v1.0
usbus2: 12Mbps Full Speed USB v1.0
usbus3: 480Mbps High Speed USB v2.0
ugen0.1: <via>at usbus0
uhub0: <via 1="" 9="" uhci="" root="" hub,="" class="" 0,="" rev="" 1.00="" 1.00,="" addr="">on usbus0
ugen1.1: <via>at usbus1
uhub1: <via 1="" 9="" uhci="" root="" hub,="" class="" 0,="" rev="" 1.00="" 1.00,="" addr="">on usbus1
ugen2.1: <via>at usbus2
uhub2: <via 1="" 9="" uhci="" root="" hub,="" class="" 0,="" rev="" 1.00="" 1.00,="" addr="">on usbus2
ugen3.1: <via>at usbus3
uhub3: <via 1="" 9="" ehci="" root="" hub,="" class="" 0,="" rev="" 2.00="" 1.00,="" addr="">on usbus3
ad0: DMA limited to UDMA33, device found non-ATA66 cable
ad0: 955MB <transcend 20071207="">at ata0-master UDMA33
WARNING: WITNESS option enabled, expect reduced performance.
Root mount waiting for: usbus3 usbus2 usbus1 usbus0
uhub0: 2 ports with 2 removable, self powered
uhub1: 2 ports with 2 removable, self powered
uhub2: 2 ports with 2 removable, self powered
Root mount waiting for: usbus3
Root mount waiting for: usbus3
uhub3: 6 ports with 6 removable, self powered
Trying to mount root from ufs:/dev/ad0s1a
WARNING: / was not properly dismounted
WARNING: R/W mount of / denied.  Filesystem is not clean - run fsck
WARNING: R/W mount of / denied.  Filesystem is not clean - run fsck
pflog0: promiscuous mode enabled
lock order reversal:
1st 0xc124788c pf task mtx (pf task mtx) @ /usr/pfSensesrc/src/sys/contrib/pf/net/pf_ioctl.c:1397
2nd 0xc13e97c4 ifnet_rw (ifnet_rw) @ /usr/pfSensesrc/src/sys/net/if.c:2029
KDB: stack backtrace:
X_db_sym_numargs(c0e1bde9,d51039c8,c09c7255,c09b7e6b,c0e1ed58,…) at X_db_sym_numargs+0x146
kdb_backtrace(c09b7e6b,c0e1ed58,c3563708,c35607e8,d5103a24,...) at kdb_backtrace+0x29
witness_display_spinlock(c0e1ed58,c13e97c4,c0e281a3,c35607e8,c0e28182,...) at witness_display_spinlock+0x75
witness_checkorder(c13e97c4,1,c0e28182,7ed,0,...) at witness_checkorder+0x839
_rw_rlock(c13e97c4,c0e28182,7ed,c38e8b10,3,...) at _rw_rlock+0x9c
ifunit(c38e8b10,0,c0db2e65,575,0,...) at ifunit+0x27
pfioctl(c37bee00,c0104414,c38e8b10,3,c3967b90,...) at pfioctl+0x26aa
dev2udev(c3920118,c0104414,c38e8b10,c35a4400,c3967b90,...) at dev2udev+0x898
kern_ioctl(c3967b90,8,c0104414,c38e8b10,19c0b20,...) at kern_ioctl+0x1fd
ioctl(c3967b90,d5103cf8,c,c0e34117,c1205b48,...) at ioctl+0x134
syscall(d5103d38) at syscall+0x2a3
Xint0x80_syscall() at Xint0x80_syscall+0x20
--- syscall (54, FreeBSD ELF32, ioctl), eip = 0x281d62f3, esp = 0xbfbfdd9c, ebp = 0xbfbfddd8 ---
lock order reversal:
1st 0xc3128a90 bufwait (bufwait) @ /usr/pfSensesrc/src/sys/kern/vfs_bio.c:2559
2nd 0xc38df200 dirhash (dirhash) @ /usr/pfSensesrc/src/sys/ufs/ufs/ufs_dirhash.c:285
KDB: stack backtrace:
X_db_sym_numargs(c0e1bde9,d511e75c,c09c7255,c09b7e6b,c0e1ed58,...) at X_db_sym_numargs+0x146
kdb_backtrace(c09b7e6b,c0e1ed58,c355ffc8,c3563ec0,d511e7b8,...) at kdb_backtrace+0x29
witness_display_spinlock(c0e1ed58,c38df200,c0e48318,c3563ec0,c0e47fa6,...) at witness_display_spinlock+0x75
witness_checkorder(c38df200,9,c0e47fa6,11d,0,...) at witness_checkorder+0x839
_sx_xlock(c38df200,0,c0e47fa6,11d,c3916d24,...) at _sx_xlock+0x85
ufsdirhash_enduseful(c3128a30,d511e8d0,158,ccb37ec4,d511e888,...) at ufsdirhash_enduseful+0x2f5
ufsdirhash_add(c3916d24,d511e8d0,ec4,d511e874,d511e878,...) at ufsdirhash_add+0x13
ufs_direnter(c37cf648,c3a2f96c,d511e8d0,d511ebd0,0,...) at ufs_direnter+0x729
ufs_itimes(d511ebd0,0,d511eabc,d511ea18,c0d42195,...) at ufs_itimes+0x1318
ufs_itimes(d511eabc,d511ead4,0,0,d511eba4,...) at ufs_itimes+0x15f0
VOP_CREATE_APV(c122c880,d511eabc,d511ebd0,d511ea54,0,...) at VOP_CREATE_APV+0xa5
vn_open_cred(d511eba4,d511ec5c,1a4,0,c35a4400,...) at vn_open_cred+0x215
vn_open(d511eba4,d511ec5c,1a4,c3920460,c0e12ed6,...) at vn_open+0x3b
kern_openat(c3966b90,ffffff9c,bfbfe748,0,603,...) at kern_openat+0x11f
kern_open(c3966b90,bfbfe748,0,602,1a4,...) at kern_open+0x35
open(c3966b90,d511ecf8,c,c0e1f792,c12055ec,...) at open+0x30
syscall(d511ed38) at syscall+0x2a3
Xint0x80_syscall() at Xint0x80_syscall+0x20
--- syscall (5, FreeBSD ELF32, open), eip = 0x2819b8f3, esp = 0xbfbfe70c, ebp = 0xbfbfeb58 ---
wlan0: changing name to 'ral0_wlan1'</transcend></via></via></via></via></via></via></via></via></generic></system></acpi></acpi></ps></at></keyboard></at></thermal></generic></mii></via></ata></ata></via></isa></pci-isa></via></via></via></via></via></via></via></via></realtek></mii></realtek></ralink></vga-compatible></pci></pci-pci></via></acpi></acpi></power></cle266></software></fpu,de,tsc,msr,mtrr,pge,mmx>

[wallabybob]

I've come across a couple more lock order reversals. I'll post them as issues in redmine.

[jimp]

There is nothing we can do for LORs. Those are for FreeBSD.

Many are harmless, and only show because the debugging is still on in the kernel. Check this page first before reporting any:

http://sources.zabbadoz.net/freebsd/lor.html

[wallabybob]

Thanks for the link.

Something like the second LOR is marked "Cannot deadlock" in the list on the linked page but the line numbers are quite different. I can't see anything like the first LOR in the list.

[eri--]

Even this is not harmful for now.
You can report it on FreeBSD but i already know about it and i maintain(partially) the pf(4) code in freebsd.