Lock Order Reversal



  • 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>



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


  • Rebel Alliance Developer Netgate

    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



  • 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.



  • 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.


Log in to reply