7-STABLE panic: mtx_lock() of spin mutex %s @ %s:%d

Florian Smeets flo at kasimir.com
Mon Nov 26 16:17:54 PST 2007


i was able to reproduce a hang on a 7-STABLE (csuped just after Scotts 
critical section MFC) firewall which runs mpd4 from ports and uses pf 
for packet filtering. Sometimes when i restart mpd4 the box just hangs. 
I have a up-script which calls /sbin/pfctl -f /etc/pf.conf.

After adding witness and invariants instead of the hang i get this LOR:

Nov 26 18:06:39 fw-a kernel: lock order reversal:
Nov 26 18:06:39 fw-a kernel: 1st 0xc0762a8c pf task mtx (pf task mtx) @ 
Nov 26 18:06:39 fw-a kernel: 2nd 0xc07c470c ifnet (ifnet) @ 
Nov 26 18:06:39 fw-a kernel: KDB: stack backtrace:
Nov 26 18:06:39 fw-a kernel: 
at db_trace_self_wrapper+0x26
Nov 26 18:06:39 fw-a kernel: 
kdb_backtrace(c07098ff,c07c470c,c0710de4,c0710de4,c0710c3d,...) at 
Nov 26 18:06:39 fw-a kernel: 
witness_checkorder(c07c470c,9,c0710c3d,5d6,0,...) at 
Nov 26 18:06:39 fw-a kernel: 
_mtx_lock_flags(c07c470c,0,c0710c3d,5d6,c205e520,...) at 
Nov 26 18:06:39 fw-a kernel: 
ifunit(c205e520,0,c06f5a82,518,ccdb7ab8,...) at ifunit+0x2f
Nov 26 18:06:39 fw-a kernel: 
pfioctl(c1d82600,c0104414,c205e520,3,c224da50,...) at pfioctl+0x2341
Nov 26 18:06:39 fw-a kernel: 
devfs_ioctl_f(c1e55ca8,c0104414,c205e520,c1c97c00,c224da50,...) at 
Nov 26 18:06:39 fw-a kernel: 
kern_ioctl(c224da50,3,c0104414,c205e520,1000000,...) at kern_ioctl+0x243
Nov 26 18:06:39 fw-a kernel: 
ioctl(c224da50,ccdb7cfc,c,c072bdfe,c0739810,...) at ioctl+0x134
Nov 26 18:06:39 fw-a kernel: syscall(ccdb7d38) at syscall+0x2b3
Nov 26 18:06:39 fw-a kernel: Xint0x80_syscall() at Xint0x80_syscall+0x20
Nov 26 18:06:39 fw-a kernel: --- syscall (54, FreeBSD ELF32, ioctl), eip 
= 0x281a6d43, esp = 0xbfbfde4c, ebp = 0xbfbfde78 ---

and shortly after that this page fault:

Fatal trap 12: page fault while in kernel mode
fault virtual address	= 0xdeadc0de
fault code		= supervisor read, page not present
instruction pointer	= 0x20:0xc059e4a8
stack pointer	        = 0x28:0xccd41890
frame pointer	        = 0x28:0xccd41890
code segment		= base 0x0, limit 0xfffff, type 0x1b
			= DPL 0, pres 1, def32 1, gran 1
processor eflags	= interrupt enabled, resume, IOPL = 0
current process		= 1474 (pfctl)
Physical memory: 245 MB
Dumping 60 MB: 45 29 13

#0  doadump () at pcpu.h:195
195	pcpu.h: No such file or directory.
	in pcpu.h
(kgdb) list *0xc059e4a8
0xc059e4a8 is in strlen (/usr/src/sys/libkern/strlen.c:41).
36	strlen(str)
37		const char *str;
38	{
39		register const char *s;
41		for (s = str; *s; ++s);
42		return(s - str);
43	}
(kgdb) bt
#0  doadump () at pcpu.h:195
#1  0xc046dc59 in db_fncall (dummy1=-858515768, dummy2=0, dummy3=12, 
dummy4=0xccd41634 "") at /usr/src/sys/ddb/db_command.c:486
#2  0xc046e1c5 in db_command_loop () at /usr/src/sys/ddb/db_command.c:401
#3  0xc046f935 in db_trap (type=12, code=0) at 
#4  0xc053bbe4 in kdb_trap (type=12, code=0, tf=0xccd41850) at 
#5  0xc06d02df in trap_fatal (frame=0xccd41850, eva=3735929054) at 
#6  0xc06d0513 in trap_pfault (frame=0xccd41850, usermode=0, 
eva=3735929054) at /usr/src/sys/i386/i386/trap.c:785
#7  0xc06d0eb5 in trap (frame=0xccd41850) at 
#8  0xc06b970b in calltrap () at /usr/src/sys/i386/i386/exception.s:139
#9  0xc059e4a8 in strlen (str=0xdeadc0de <Address 0xdeadc0de out of 
bounds>) at /usr/src/sys/libkern/strlen.c:41
#10 0xc053e4e5 in kvprintf (fmt=0xc0703a1c " @ %s:%d", func=0xc053d9a0 
<snprintf_func>, arg=0xccd419d0, radix=10, ap=0xccd41a0c " Mo??\001")
     at /usr/src/sys/kern/subr_prf.c:750
#11 0xc053ed2b in vsnprintf (str=0xc0779380 "mtx_lock() of spin mutex ", 
size=256, format=0xc0703a01 "mtx_lock() of spin mutex %s @ %s:%d",
     ap=0xccd41a08 "???? Mo??\001") at /usr/src/sys/kern/subr_prf.c:483
#12 0xc05152f3 in panic (fmt=0xc0703a01 "mtx_lock() of spin mutex %s @ 
%s:%d") at /usr/src/sys/kern/kern_shutdown.c:530
#13 0xc0509eba in _mtx_lock_flags (m=0xc1d3ad0c, opts=0, file=0xc06f4d20 
"/usr/src/sys/contrib/altq/altq/altq_priq.c", line=416) at 
#14 0xc0437b83 in priq_class_destroy (cl=0xc22138c0) at 
#15 0xc0437c7d in priq_remove_altq (a=0xc2048a80) at 
#16 0xc0438635 in altq_remove (a=0xc2048a80) at 
#17 0xc04508ee in pf_commit_altq (ticket=5) at 
#18 0xc0456341 in pfioctl (dev=0xc1d82600, cmd=3222029394, 
addr=0xc22d32e0 "\a", flags=3, td=0xc2014a50) at 
#19 0xc04bcfe9 in devfs_ioctl_f (fp=0xc20270d8, com=3222029394, 
data=0xc22d32e0, cred=0xc200bd00, td=0xc2014a50) at 
#20 0xc054d563 in kern_ioctl (td=0xc2014a50, fd=3, com=3222029394, 
data=0xc22d32e0 "\a") at file.h:266
#21 0xc054d6c4 in ioctl (td=0xc2014a50, uap=0xccd41cfc) at 
#22 0xc06d07f3 in syscall (frame=0xccd41d38) at 
#23 0xc06b9770 in Xint0x80_syscall () at 
#24 0x00000033 in ?? ()
Previous frame inner to this frame (corrupt stack?)
(kgdb) frame 13
#13 0xc0509eba in _mtx_lock_flags (m=0xc1d3ad0c, opts=0, file=0xc06f4d20 
"/usr/src/sys/contrib/altq/altq/altq_priq.c", line=416) at 
180		KASSERT(LOCK_CLASS(&m->lock_object) == &lock_class_mtx_sleep,
(kgdb) list
175	{
177		MPASS(curthread != NULL);
178		KASSERT(m->mtx_lock != MTX_DESTROYED,
179		    ("mtx_lock() of destroyed mutex @ %s:%d", file, line));
180		KASSERT(LOCK_CLASS(&m->lock_object) == &lock_class_mtx_sleep,
181		    ("mtx_lock() of spin mutex %s @ %s:%d", m->lock_object.lo_name,
182		    file, line));
183		WITNESS_CHECKORDER(&m->lock_object, opts | LOP_NEWORDER | 
184		    file, line);

As the panic/page fault seems to be connected to the altq/priq rules i 
have added the definition of the altq part

altq on $ext_if priq bandwidth 960Kb qlimit 250 queue { std_out, 
smtp_out, ssh_out, tcp_ack_out }

queue smtp_out     priq(default) qlimit 250
queue std_out    priority 2 qlimit 250
queue ssh_out     priority 5 qlimit 250
queue tcp_ack_out priority 6 qlimit 250

And of course there are some pass rules which add packets to the queues.

Is there anything else needed from the core dump?


More information about the freebsd-pf mailing list