kern/132769: 2 LOR's with pf task mtx / ifnet and rtentry / ifnet during early boot

Wed Mar 18 01:50:03 PDT 2009

>Number:         132769
>Category:       kern
>Synopsis:       2 LOR's with pf task mtx / ifnet and  rtentry / ifnet during early boot
>Confidential:   no
>Severity:       serious
>Priority:       medium
>Responsible:    freebsd-bugs
>State:          open
>Quarter:        
>Keywords:       
>Date-Required:
>Class:          sw-bug
>Submitter-Id:   current-users
>Arrival-Date:   Wed Mar 18 08:50:03 UTC 2009
>Closed-Date:
>Last-Modified:
>Originator:     Ruben van Staveren
>Release:        FreeBSD 7.1-STABLE i386
>Organization:
>Environment:
System: FreeBSD helium.verweg.com 7.1-STABLE FreeBSD 7.1-STABLE #58: Tue Mar 17 14:39:08 CET 2009 root at helium.verweg.com:/usr/obj/usr/cvsup/7-stable/src/sys/HELIUM-SMP i386

>Description:

Still having WITNESS enabled since kern/132404 I've spotted the following ifnet
related LOR's during bootup. the pf related one is also visible in that pr.
Same configuration applies to the system, sources are of Tue Mar 17 15:43:48
CET 2009

If required, I can generate a textdump of this state.

1st

lock order reversal:
 1st 0xc099e28c pf task mtx (pf task mtx) @ /usr/cvsup/7-stable/src/sys/contrib/pf/net/pf_ioctl.c:1394
 2nd 0xc0a0c708 ifnet (ifnet) @ /usr/cvsup/7-stable/src/sys/net/if.c:1574
KDB: stack backtrace:
db_trace_self_wrapper(c0923147,e6cd4a34,c0643355,c0924722,c0a0c708,...) at db_trace_self_wrapper+0x26
kdb_backtrace(c0924722,c0a0c708,c093a967,c093a967,c092a5a0,...) at kdb_backtrace+0x29
witness_checkorder(c0a0c708,9,c092a5a0,626,201,...) at witness_checkorder+0x5e5
_mtx_lock_flags(c0a0c708,0,c092a5a0,626,c5727000,...) at _mtx_lock_flags+0x34
ifunit(c5727000,c5727000,e0,572,c0924322,...) at ifunit+0x2f
pfioctl(c47a3600,c0ec442d,c5602900,3,c4cce690,...) at pfioctl+0x27f1
devfs_ioctl_f(c4a1e04c,c0ec442d,c5602900,c44b3000,c4cce690,...) at devfs_ioctl_f+0xf5
kern_ioctl(c4cce690,3,c0ec442d,c5602900,1000000,...) at kern_ioctl+0x243
ioctl(c4cce690,e6cd4cfc,c,c09384e2,c0966f50,...) at ioctl+0x134
syscall(e6cd4d38) at syscall+0x2e3
Xint0x80_syscall() at Xint0x80_syscall+0x20
--- syscall (54, FreeBSD ELF32, ioctl), eip = 0x481abf03, esp = 0xbfbfbc3c, ebp = 0xbfbfbc58 ---

2nd

lock order reversal:
 1st 0xc568715c rtentry (rtentry) @ /usr/cvsup/7-stable/src/sys/net/route.c:1020
 2nd 0xc0a0c708 ifnet (ifnet) @ /usr/cvsup/7-stable/src/sys/net/if.c:176
KDB: stack backtrace:
db_trace_self_wrapper(c0923147,c42a65d4,c0643355,c0924722,c0a0c708,...) at db_trace_self_wrapper+0x26
kdb_backtrace(c0924722,c0a0c708,c093a967,c093a967,c092a5a0,...) at kdb_backtrace+0x29
witness_checkorder(c0a0c708,9,c092a5a0,b0,c5729928,...) at witness_checkorder+0x5e5
_mtx_lock_flags(c0a0c708,0,c092a5a0,b0,1,...) at _mtx_lock_flags+0x34
ifnet_byindex(1,c5729940,c5729900,c42a6650,0,...) at ifnet_byindex+0x2f
sa6_recoverscope(c42a667c,0,c081f752,1c1c,0,...) at sa6_recoverscope+0x95
nd6_is_new_addr_neighbor(c4694400,d22df600,c47a374c,8,c47a3700,...) at nd6_is_new_addr_neighbor+0x55
nd6_rtrequest(b,c56870f8,c42a6794,c56870f8,c42a6760,...) at nd6_rtrequest+0x5d
rtrequest1_fib(b,c42a6794,c42a6828,0,0,...) at rtrequest1_fib+0x6fd
rtrequest_fib(b,c42a68a0,0,0,0,...) at rtrequest_fib+0x5e
rtalloc1_fib(c42a68a0,1,0,0,c42a68cc,...) at rtalloc1_fib+0x103
rtalloc1(c42a68a0,1,0,387,c44c8690,...) at rtalloc1+0x27
nd6_lookup(c42a69b8,1,c4694400,c0974e20,0,...) at nd6_lookup+0x55
nd6_cache_lladdr(c4694400,c42a69b8,c5b0205e,8,85,...) at nd6_cache_lladdr+0x7e
nd6_rs_input(c4956d00,28,10,1,1c,...) at nd6_rs_input+0x2b4
icmp6_input(c42a6c84,c42a6c6c,3a,1bc,0,...) at icmp6_input+0x19c0
ip6_input(c5acd700,0,c092b306,8c,c0a0d264,...) at ip6_input+0xe2c
netisr_processqueue(c09b9cb0,0,c092b306,f6,c4496b00,...) at netisr_processqueue+0x8b
swi_net(0,0,c091e3dc,4b6,c45056e8,...) at swi_net+0x9b
ithread_loop(c44c5700,c42a6d38,c091e1d8,322,c44c62b8,...) at ithread_loop+0x155
fork_exit(c05f0810,c44c5700,c42a6d38) at fork_exit+0x94
fork_trampoline() at fork_trampoline+0x8

Full dmesg follows

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 7.1-STABLE #58: Tue Mar 17 14:39:08 CET 2009
    root at helium.verweg.com:/usr/obj/usr/cvsup/7-stable/src/sys/HELIUM-SMP
WARNING: WITNESS option enabled, expect reduced performance.
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: Intel(R) Pentium(R) 4 CPU 3.00GHz (2993.02-MHz 686-class CPU)
  Origin = "GenuineIntel"  Id = 0xf29  Stepping = 9
  Features=0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE>
  Features2=0x4400<CNXT-ID,xTPR>
  Logical CPUs per core: 2
real memory  = 1072627712 (1022 MB)
avail memory = 1031323648 (983 MB)
ACPI APIC Table: <XPC    AWRDACPI>
FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs
 cpu0 (BSP): APIC ID:  0
 cpu1 (AP): APIC ID:  1
WITNESS: spin lock cpuset not in order list
WITNESS: spin lock intrcnt not in order list
ioapic0: Changing APIC ID to 2
ioapic0 <Version 1.1> irqs 0-23 on motherboard
kbd1 at kbdmux0
WITNESS: spin lock ctl.rm_mtx not in order list
cryptosoft0: <software crypto> on motherboard
acpi0: <XPC AWRDACPI> on motherboard
acpi0: Overriding SCI Interrupt from IRQ 9 to IRQ 21
acpi0: [ITHREAD]
acpi0: Power Button (fixed)
acpi0: reservation of 0, a0000 (3) failed
acpi0: reservation of 100000, 3fdf0000 (3) failed
Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
acpi_timer0: <32-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
pci0: <ACPI PCI bus> on pcib0
agp0: <ATI RS300_200 AGP bridge> on hostb0
pcib1: <ACPI PCI-PCI bridge> at device 1.0 on pci0
pci1: <ACPI PCI bus> on pcib1
vgapci0: <VGA-compatible display> mem 0xe4000000-0xe4ffffff,0xd0000000-0xdfffffff,0xe5000000-0xe5ffffff irq 16 at device 5.0 on pci1
nvidia0: <GeForce 6200 A-LE> on vgapci0
vgapci0: child nvidia0 requested pci_enable_busmaster
vgapci0: child nvidia0 requested pci_enable_io
vgapci0: child nvidia0 requested pci_enable_io
nvidia0: [GIANT-LOCKED]
nvidia0: [ITHREAD]
WITNESS: spin lock dev.rm_mtx not in order list
ohci0: <OHCI (generic) USB controller> mem 0xe7100000-0xe7100fff irq 19 at device 19.0 on pci0
ohci0: [GIANT-LOCKED]
ohci0: [ITHREAD]
usb0: OHCI version 1.0, legacy support
usb0: SMM does not respond, resetting
usb0: <OHCI (generic) USB controller> on ohci0
usb0: USB revision 1.0
uhub0: <ATI OHCI root hub, class 9/0, rev 1.00/1.00, addr 1> on usb0
uhub0: 3 ports with 3 removable, self powered
ohci1: <OHCI (generic) USB controller> mem 0xe7101000-0xe7101fff irq 19 at device 19.1 on pci0
ohci1: [GIANT-LOCKED]
ohci1: [ITHREAD]
usb1: OHCI version 1.0, legacy support
usb1: SMM does not respond, resetting
usb1: <OHCI (generic) USB controller> on ohci1
usb1: USB revision 1.0
uhub1: <ATI OHCI root hub, class 9/0, rev 1.00/1.00, addr 1> on usb1
uhub1: 3 ports with 3 removable, self powered
ehci0: <ATI SB200 USB 2.0 controller> mem 0xe7102000-0xe7102fff irq 19 at device 19.2 on pci0
ehci0: [GIANT-LOCKED]
ehci0: [ITHREAD]
usb2: EHCI version 1.0
usb2: companion controllers, 3 ports each: usb0 usb1
usb2: <ATI SB200 USB 2.0 controller> on ehci0
usb2: USB revision 2.0
uhub2: <ATI EHCI root hub, class 9/0, rev 2.00/1.00, addr 1> on usb2
uhub2: 6 ports with 6 removable, self powered
umass0: <Ltd Winter Ver1.3, class 0/0, rev 2.00/0.05, addr 2> on uhub2
pci0: <serial bus, SMBus> at device 20.0 (no driver attached)
atapci0: <ATI IXP200 UDMA100 controller> port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xf000-0xf00f at device 20.1 on pci0
ata0: <ATA channel 0> on atapci0
ata0: [ITHREAD]
ata1: <ATA channel 1> on atapci0
ata1: [ITHREAD]
isab0: <PCI-ISA bridge> at device 20.3 on pci0
isa0: <ISA bus> on isab0
pcib2: <ACPI PCI-PCI bridge> at device 20.4 on pci0
pci2: <ACPI PCI bus> on pcib2
atapci1: <SiI SiI 3512 SATA150 controller> port 0xc000-0xc007,0xc400-0xc403,0xc800-0xc807,0xcc00-0xcc03,0xd000-0xd00f mem 0xe7082000-0xe70821ff irq 17 at device 5.0 on pci2
atapci1: [ITHREAD]
ata2: <ATA channel 0> on atapci1
ata2: [ITHREAD]
ata3: <ATA channel 1> on atapci1
ata3: [ITHREAD]
bfe0: <Broadcom BCM4401 Fast Ethernet> mem 0xe7080000-0xe7081fff irq 18 at device 6.0 on pci2
miibus0: <MII bus> on bfe0
bmtphy0: <BCM4401 10/100baseTX PHY> PHY 1 on miibus0
bmtphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
bfe0: Ethernet address: 00:30:1b:b3:10:71
bfe0: [ITHREAD]
fwohci0: <VIA Fire II (VT6306)> port 0xd400-0xd47f mem 0xe7083000-0xe70837ff irq 19 at device 11.0 on pci2
fwohci0: [FILTER]
fwohci0: OHCI version 1.0 (ROM=1)
fwohci0: No. of Isochronous channels is 4.
fwohci0: EUI64 00:30:1b:b3:00:00:10:d5
fwohci0: Phy 1394a available S400, 2 ports.
fwohci0: Link S400, max_rec 2048 bytes.
firewire0: <IEEE1394(FireWire) bus> on fwohci0
dcons_crom0: <dcons configuration ROM> on firewire0
dcons_crom0: bus_addr 0x1488000
fwe0: <Ethernet over FireWire> on firewire0
if_fwe0: Fake Ethernet address: 02:30:1b:00:10:d5
fwe0: Ethernet address: 02:30:1b:00:10:d5
fwip0: <IP over FireWire> on firewire0
fwip0: Firewire address: 00:30:1b:b3:00:00:10:d5 @ 0xfffe00000000, S400, maxrec 2048
sbp0: <SBP-2/SCSI over FireWire> on firewire0
fwohci0: Initiate bus reset
fwohci0: BUS reset
fwohci0: node_id=0xc800ffc0, gen=1, CYCLEMASTER mode
pcm0: <ATI IXP 200> mem 0xe7105000-0xe71050ff irq 17 at device 20.5 on pci0
pcm0: [ITHREAD]
acpi_tz0: <Thermal Zone> on acpi0
sio0: <16550A-compatible COM port> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
sio0: type 16550A
sio0: [FILTER]
cpu0: <ACPI CPU> on acpi0
p4tcc0: <CPU Frequency Thermal Control> on cpu0
cpu1: <ACPI CPU> on acpi0
p4tcc1: <CPU Frequency Thermal Control> on cpu1
pmtimer0 on isa0
atkbdc0: <Keyboard controller (i8042)> at port 0x60,0x64 on isa0
atkbd0: <AT Keyboard> flags 0x1 irq 1 on atkbdc0
device_attach: atkbd0 attach returned 6
ppc0: parallel port not found.
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
ukbd0: <Logitech USB Receiver, class 0/0, rev 1.10/17.00, addr 2> on uhub0
kbd0 at ukbd0
ums0: <Logitech USB Receiver, class 0/0, rev 1.10/17.00, addr 2> on uhub0
ums0: 16 buttons and Z dir.
NULL mp in getnewvnode()
Timecounters tick every 1.000 msec
IPsec: Initialized Security Association Processing.
firewire0: 1 nodes, maxhop <= 0, cable IRM = 0 (me)
firewire0: bus manager 0 (me)
ad0: 157066MB <Hitachi HDS722516VLAT80 V34OA6EA> at ata0-master UDMA100
acd0: DVDR <NEC DVD RW ND-3500AG/2.16> at ata1-master UDMA33
pcm0: <Avance Logic ALC650 AC97 Codec>
GEOM_LABEL: Label for provider ad0s1a is ufs/root.
GEOM_LABEL: Label for provider ad0s1d is ufs/var.
GEOM_LABEL: Label for provider ad0s1e is ufs/usr.
GEOM_LABEL: Label for provider ad0s1f is ufs/jail.
(probe8:ata1:0:0:0): TEST UNIT READY. CDB: 0 0 0 0 0 0 
(probe8:ata1:0:0:0): CAM Status: SCSI Status Error
(probe8:ata1:0:0:0): SCSI Status: Check Condition
(probe8:ata1:0:0:0): NOT READY asc:3a,0
(probe8:ata1:0:0:0): Medium not present sks:0x80,0xffff
(probe8:ata1:0:0:0): Unretryable error
(probe0:umass-sim0:0:0:0): TEST UNIT READY. CDB: 0 0 0 0 0 0 
(probe0:umass-sim0:0:0:0): CAM Status: SCSI Status Error
(probe0:umass-sim0:0:0:0): SCSI Status: Check Condition
(probe0:umass-sim0:0:0:0): NOT READY asc:3a,0
(probe0:umass-sim0:0:0:0): Medium not present
(probe0:umass-sim0:0:0:0): Unretryable error
(probe0:umass-sim0:0:0:1): TEST UNIT READY. CDB: 0 20 0 0 0 0 
(probe0:umass-sim0:0:0:1): CAM Status: SCSI Status Error
(probe0:umass-sim0:0:0:1): SCSI Status: Check Condition
(probe0:umass-sim0:0:0:1): NOT READY asc:3a,0
(probe0:umass-sim0:0:0:1): Medium not present
(probe0:umass-sim0:0:0:1): Unretryable error
SMP: AP CPU #1 Launched!
WARNING: WITNESS option enabled, expect reduced performance.
cd0 at ata1 bus 0 target 0 lun 0
cd0: <_NEC DVD_RW ND-3500AG 2.16> Removable CD-ROM SCSI-0 device 
cd0: 33.000MB/s transfers
cd0: Attempt to query device size failed: NOT READY, Medium not present
da0 at umass-sim0 bus 0 target 0 lun 0
da0: <USB2.0 CardReader CF RW 0.0>> Removable Direct Access SCSI-0 device 
da0: 40.000MB/s transfers
da0: Attempt to query device size failed: NOT READY, Medium not present
da1 at umass-sim0 bus 0 target 0 lun 1
da1: <USB2.0 CardReader Combo 0.0>> Removable Direct Access SCSI-0 device 
da1: 40.000MB/s transfers
da1: Attempt to query device size failed: NOT READY, Medium not present
Trying to mount root from ufs:/dev/vol/root
GEOM_LABEL: Label ufs/root removed.
GEOM_LABEL: Label for provider ad0s1a is ufs/root.
GEOM_LABEL: Label ufs/usr removed.
GEOM_LABEL: Label ufs/jail removed.
GEOM_LABEL: Label for provider ad0s1f is ufs/jail.
GEOM_LABEL: Label for provider ad0s1e is ufs/usr.
GEOM_LABEL: Label ufs/var removed.
GEOM_LABEL: Label for provider ad0s1d is ufs/var.
GEOM_LABEL: Label ufs/root removed.
GEOM_LABEL: Label ufs/usr removed.
GEOM_LABEL: Label ufs/jail removed.
GEOM_LABEL: Label ufs/var removed.
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 filesystem version 6
ZFS storage pool version 6
lock order reversal:
 1st 0xc099e28c pf task mtx (pf task mtx) @ /usr/cvsup/7-stable/src/sys/contrib/pf/net/pf_ioctl.c:1394
 2nd 0xc0a0c708 ifnet (ifnet) @ /usr/cvsup/7-stable/src/sys/net/if.c:1574
KDB: stack backtrace:
db_trace_self_wrapper(c0923147,e6cd4a34,c0643355,c0924722,c0a0c708,...) at db_trace_self_wrapper+0x26
kdb_backtrace(c0924722,c0a0c708,c093a967,c093a967,c092a5a0,...) at kdb_backtrace+0x29
witness_checkorder(c0a0c708,9,c092a5a0,626,201,...) at witness_checkorder+0x5e5
_mtx_lock_flags(c0a0c708,0,c092a5a0,626,c5727000,...) at _mtx_lock_flags+0x34
ifunit(c5727000,c5727000,e0,572,c0924322,...) at ifunit+0x2f
pfioctl(c47a3600,c0ec442d,c5602900,3,c4cce690,...) at pfioctl+0x27f1
devfs_ioctl_f(c4a1e04c,c0ec442d,c5602900,c44b3000,c4cce690,...) at devfs_ioctl_f+0xf5
kern_ioctl(c4cce690,3,c0ec442d,c5602900,1000000,...) at kern_ioctl+0x243
ioctl(c4cce690,e6cd4cfc,c,c09384e2,c0966f50,...) at ioctl+0x134
syscall(e6cd4d38) at syscall+0x2e3
Xint0x80_syscall() at Xint0x80_syscall+0x20
--- syscall (54, FreeBSD ELF32, ioctl), eip = 0x481abf03, esp = 0xbfbfbc3c, ebp = 0xbfbfbc58 ---

>How-To-Repeat:

Run with pf enabled, configuration is at http://ruben.is.verweg.com/stuff/freebsd/pf-helium.conf

>Fix:

>Release-Note:
>Audit-Trail:
>Unformatted: