Skip site navigation (1)Skip section navigation (2)
Date:      Tue, 27 Nov 2007 00:50:40 +0100
From:      Florian Smeets <flo@kasimir.com>
To:        freebsd-pf@freebsd.org
Subject:   7-STABLE panic: mtx_lock() of spin mutex %s @ %s:%d
Message-ID:  <474B5BD0.6040004@kasimir.com>

next in thread | raw e-mail | index | archive | help
Hi

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) @ 
/usr/src/sys/contrib/pf/net/pf_ioctl.c:1304
Nov 26 18:06:39 fw-a kernel: 2nd 0xc07c470c ifnet (ifnet) @ 
/usr/src/sys/net/if.c:1494
Nov 26 18:06:39 fw-a kernel: KDB: stack backtrace:
Nov 26 18:06:39 fw-a kernel: 
db_trace_self_wrapper(c0707544,ccdb7a3c,c054c0ae,c07098ff,c07c470c,...) 
at db_trace_self_wrapper+0x26
Nov 26 18:06:39 fw-a kernel: 
kdb_backtrace(c07098ff,c07c470c,c0710de4,c0710de4,c0710c3d,...) at 
kdb_backtrace+0x29
Nov 26 18:06:39 fw-a kernel: 
witness_checkorder(c07c470c,9,c0710c3d,5d6,0,...) at 
witness_checkorder+0x6de
Nov 26 18:06:39 fw-a kernel: 
_mtx_lock_flags(c07c470c,0,c0710c3d,5d6,c205e520,...) at 
_mtx_lock_flags+0xbc
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 
devfs_ioctl_f+0xc9
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;
40	
41		for (s = str; *s; ++s);
42		return(s - str);
43	}
44	
(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 
/usr/src/sys/ddb/db_main.c:222
#4  0xc053bbe4 in kdb_trap (type=12, code=0, tf=0xccd41850) at 
/usr/src/sys/kern/subr_kdb.c:502
#5  0xc06d02df in trap_fatal (frame=0xccd41850, eva=3735929054) at 
/usr/src/sys/i386/i386/trap.c:863
#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 
/usr/src/sys/i386/i386/trap.c:463
#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 
/usr/src/sys/kern/kern_mutex.c:180
#14 0xc0437b83 in priq_class_destroy (cl=0xc22138c0) at 
/usr/src/sys/contrib/altq/altq/altq_priq.c:416
#15 0xc0437c7d in priq_remove_altq (a=0xc2048a80) at 
/usr/src/sys/contrib/altq/altq/altq_priq.c:252
#16 0xc0438635 in altq_remove (a=0xc2048a80) at 
/usr/src/sys/contrib/altq/altq/altq_subr.c:650
#17 0xc04508ee in pf_commit_altq (ticket=5) at 
/usr/src/sys/contrib/pf/net/pf_ioctl.c:867
#18 0xc0456341 in pfioctl (dev=0xc1d82600, cmd=3222029394, 
addr=0xc22d32e0 "\a", flags=3, td=0xc2014a50) at 
/usr/src/sys/contrib/pf/net/pf_ioctl.c:3170
#19 0xc04bcfe9 in devfs_ioctl_f (fp=0xc20270d8, com=3222029394, 
data=0xc22d32e0, cred=0xc200bd00, td=0xc2014a50) at 
/usr/src/sys/fs/devfs/devfs_vnops.c:494
#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 
/usr/src/sys/kern/sys_generic.c:570
#22 0xc06d07f3 in syscall (frame=0xccd41d38) at 
/usr/src/sys/i386/i386/trap.c:1008
#23 0xc06b9770 in Xint0x80_syscall () at 
/usr/src/sys/i386/i386/exception.s:196
#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 
/usr/src/sys/kern/kern_mutex.c:180
180		KASSERT(LOCK_CLASS(&m->lock_object) == &lock_class_mtx_sleep,
(kgdb) list
175	{
176	
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 | 
LOP_EXCLUSIVE,
184		    file, line);
(kgdb)


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?

Cheers
Florian



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?474B5BD0.6040004>