Re: strace causes panic: sleeping thread

On Sat, Apr 28, 2007 at 11:28:43AM +0200, Stefan Ehmann wrote:
> I see this on freshly build CURRENT (i386):
> 
> Using strace causes an immediate panic, e.g. strace echo foo:
> 
> [GDB will not be able to debug user-mode threads: /usr/lib/libthread_db.so: 
> Undefined symbol "ps_pglobal_lookup"]
> GNU gdb 6.1.1 [FreeBSD]
> Copyright 2004 Free Software Foundation, Inc.
> GDB is free software, covered by the GNU General Public License, and you are
> welcome to change it and/or distribute copies of it under certain conditions.
> Type "show copying" to see the conditions.
> There is absolutely no warranty for GDB.  Type "show warranty" for details.
> This GDB was configured as "i386-marcel-freebsd".
> 
> Unread portion of the kernel message buffer:
> Sleeping thread (tid 100078, pid 896) owns a non-sleepable lock
> sched_switch(c2da4a20,0,1) at sched_switch+0xff
> mi_switch(1,0) at mi_switch+0x1d4
> sleepq_switch(c2f7e168) at sleepq_switch+0x8b
> sleepq_wait_sig(c2f7e168,c2da4a20,5c,0,100,...) at sleepq_wait_sig+0x1d
> _sleep(c2f7e168,c2f7e060,15c,c0759778,0,...) at _sleep+0x26e
> procfs_ioctl(c2da4a20,c2f7e000,c2b27200,40147004,c2ca3b80) at 
> procfs_ioctl+0x1f5
> pfs_ioctl(d4e18b84) at pfs_ioctl+0x60
> VOP_IOCTL_APV(c0794f60,d4e18b84) at VOP_IOCTL_APV+0x38
> vn_ioctl(c2ba2480,40147004,c2ca3b80,c2f60180,c2da4a20) at vn_ioctl+0x18d
> kern_ioctl(c2da4a20,3,40147004,c2ca3b80) at kern_ioctl+0x282
> ioctl(c2da4a20,d4e18d00) at ioctl+0xf1
> syscall(d4e18d38) at syscall+0x2a2
> Xint0x80_syscall() at Xint0x80_syscall+0x20
> --- syscall (54, FreeBSD ELF32, ioctl), eip = 0x2816474f, esp = 0xbfbfe38c, 
> ebp = 0xbfbfe418 ---
> panic: sleeping thread
> cpuid = 0
> KDB: enter: panic
> Uptime: 21s
> Physical memory: 470 MB
> Dumping 42 MB: 27 11
> 
> #0  doadump () at pcpu.h:172
> 172	pcpu.h: No such file or directory.
> 	in pcpu.h
> (kgdb) bt
> #0  doadump () at pcpu.h:172
> #1  0xc055bfe1 in boot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:409
> #2  0xc055c323 in panic (fmt=0xc07619aa "sleeping thread")
>     at /usr/src/sys/kern/kern_shutdown.c:563
> #3  0xc0584384 in propagate_priority (td=0xc2da4a20)
>     at /usr/src/sys/kern/subr_turnstile.c:205
> #4  0xc0584d90 in turnstile_wait (lock=0xc2f7e060, owner=0xc2da4a20, queue=0)
>     at /usr/src/sys/kern/subr_turnstile.c:682
> #5  0xc0552d87 in _mtx_lock_sleep (m=0xc2f7e060, tid=3269086160, opts=0, 
>     file=0x0, line=0) at /usr/src/sys/kern/kern_mutex.c:415
> #6  0xc0567658 in thread_suspend_check (return_instead=0)
>     at /usr/src/sys/kern/kern_thread.c:830
> #7  0xc0583d57 in userret (td=0xc2da4bd0, frame=0xd4e1bd38)
>     at /usr/src/sys/kern/subr_trap.c:112
> #8  0xc070d0c5 in syscall (frame=0xd4e1bd38)
>     at /usr/src/sys/i386/i386/trap.c:1078
> #9  0xc06f60c0 in Xint0x80_syscall () 
> at /usr/src/sys/i386/i386/exception.s:196
> #10 0x00000033 in ?? ()
> Previous frame inner to this frame (corrupt stack?)

This is because you do not have INVARIANTS in kernel. Then you would obtain
the "recursed on non-recursive mutex" panic.

The pfs_ioctl locks the process (pfs_ioctl()->pfs_visible()->pfind()) that
is the target of the ioctl, and then the pseudofs_ioctl() do PROC_LOCK()
again.

This is changed by rev. 1.62 of the fs/pseudofs/pseudofs_vnops.c, before it
process was held during pn_ioctl() call instead of being locked. Also, this
change seems to also take place for getextattr().

With the following patch, I was able to successfully strace ls. As a side
note, it seems that procfs ABI changed, strace built on RELENG_6 cannot run
on CURRENT.


Index: fs/pseudofs/pseudofs_vnops.c
===================================================================
RCS file: /usr/local/arch/ncvs/src/sys/fs/pseudofs/pseudofs_vnops.c,v
retrieving revision 1.63
diff -u -r1.63 pseudofs_vnops.c
--- fs/pseudofs/pseudofs_vnops.c	15 Apr 2007 20:35:18 -0000	1.63
+++ fs/pseudofs/pseudofs_vnops.c	28 Apr 2007 11:54:34 -0000
_at__at_ -265,10 +265,15 _at__at_
 	if (!pfs_visible(curthread, pn, pvd->pvd_pid, &proc))
 		PFS_RETURN (EIO);
 
-	error = pn_ioctl(curthread, proc, pn, va->a_command, va->a_data);
+	if (proc != NULL) {
+		_PHOLD(proc);
+		PROC_UNLOCK(proc);
+	}
+
+	error = (pn->pn_ioctl)(curthread, proc, pn, va->a_command, va->a_data);	 
 
 	if (proc != NULL)
-		PROC_UNLOCK(proc);
+		PRELE(proc);
 
 	PFS_RETURN (error);
 }
_at__at_ -297,13 +302,17 _at__at_
 
 	if (pn->pn_getextattr == NULL)
 		error = EOPNOTSUPP;
-	else
+	else {
+		if (proc != NULL) {
+			_PHOLD(proc);	 
+			PROC_UNLOCK(proc);	 
+		}
 		error = pn_getextattr(curthread, proc, pn,
 		    va->a_attrnamespace, va->a_name, va->a_uio,
 		    va->a_size, va->a_cred);
-
-	if (proc != NULL)
-		PROC_UNLOCK(proc);
+		if (proc != NULL)
+			PRELE(proc);
+	}
 
 	pfs_unlock(pn);
 	PFS_RETURN (error);