panic: mutex tty owned at ../../../kern/kern_event.c:1487

[John-Mark Gurney]

Dan Nelson wrote this message on Sat, Apr 23, 2005 at 12:28 -0500:
> Got the following on a 2004-04-21 -stable kernel:
> 
> panic messages:
> ---
> panic: mutex tty owned at ../../../kern/kern_event.c:1487
> cpuid = 0

[...]

> #0  doadump () at pcpu.h:159
> #1  0xc05b44aa in boot (howto=260) at ../../../kern/kern_shutdown.c:410
> #2  0xc05b4884 in panic (fmt=0xc07aed2c "mutex %s owned at %s:%d") at ../../../kern/kern_shutdown.c:566
> #3  0xc05aac23 in _mtx_assert (m=0xc383c910, what=0, file=0xc07acb39 "../../../kern/kern_event.c", line=1487) at ../../../kern/kern_mutex.c:753
> #4  0xc0596aad in knote (list=0xc383c880, hint=0, islocked=0) at ../../../kern/kern_event.c:1487
> #5  0xc05eb699 in ttwakeup (tp=0xc383c800) at ../../../kern/tty.c:2374
> #6  0xc05e83b4 in ttyinput (c=13, tp=0xc383c800) at ../../../kern/tty.c:601
> #7  0xc05ea23c in ttypend (tp=0xc383c800) at ../../../kern/tty.c:1658
> #8  0xc05e9c5b in ttnread (tp=0xc383c800) at ../../../kern/tty.c:1352
> #9  0xc05e9b80 in filt_ttyread (kn=0xc2803374, hint=0) at ../../../kern/tty.c:1313
> #10 0xc0596b3c in knote (list=0xc383c880, hint=0, islocked=0) at ../../../kern/kern_event.c:1504
> #11 0xc05eb699 in ttwakeup (tp=0xc383c800) at ../../../kern/tty.c:2374
> #12 0xc05e937b in ttioctl (tp=0xc383c800, cmd=2150396949, data=0xc39864c0, flag=3) at ../../../kern/tty.c:1064
> #13 0xc05ec6f5 in ttyioctl (dev=0x0, cmd=2150396949, data=0xc39864c0 "\006\t", flag=3, td=0x0) at ../../../kern/tty.c:2917
> #14 0xc05ef0f8 in ptyioctl (dev=0xc2bce300, cmd=2150396949, data=0xc39864c0 "\006\t", flag=0, td=0x0) at ../../../kern/tty_pty.c:623
> #15 0xc056da0c in spec_ioctl (ap=0xe97b7c00) at ../../../fs/specfs/spec_vnops.c:357
> #16 0xc056d038 in spec_vnoperate (ap=0x0) at ../../../fs/specfs/spec_vnops.c:118
> #17 0xc06233e4 in vn_ioctl (fp=0xc3968198, com=2150396949, data=0xc39864c0, active_cred=0xc3a00a00, td=0xc3d05780) at vnode_if.h:503
> #18 0xc05dbae8 in ioctl (td=0xc3d05780, uap=0xe97b7d14) at file.h:257
> #19 0xc07535e0 in syscall (frame={tf_fs = 47, tf_es = 47, tf_ds = 47, tf_edi = 1, tf_esi = 1, tf_ebp = -1079060792, tf_isp = -377782924, tf_ebx = 674260420, tf_edx = 140677888, tf_ecx = -2144570347, tf_eax = 54, tf_trapno = 12, tf_err = 2, tf_eip = 673731391, tf_cs = 31, tf_eflags = 582, tf_esp = -1079060884, tf_ss = 47}) at ../../../i386/i386/trap.c:1001
> #20 0xc073e38f in Xint0x80_syscall () at ../../../i386/i386/exception.s:201
> #21 0x0000002f in ?? ()
> [garbage]
> #48 0xc3585900 in ?? ()
> #49 0xc05c6f90 in sched_switch (td=0x1, newtd=0x283065c4, flags=---Can't read userspace from dump, or kernel process---
> 
> ) at ../../../kern/sched_4bsd.c:881
> gdbcom:2: Error in sourced command file:
> Previous frame inner to this frame (corrupt stack?)

ok, how wonderful...  we've recursed in the tty code...  someone needs
to fix filt_ttyread so that it doesn't process characters... filt_ttyread
should be completely with out side effects, and simply return the
current state of the tty descriptor...  (filt_ttyread gets called from
places where going off and doing lots of work is not good)...

in the back trace below, it tried to process characters, which then
tried to notify kqueue again, and lock the tty lock, which doesn't work...

One easy fix is to fix ttnread to not call ttypend on calls from
filt_ttyread via a flag...

I can whip up a patch if you want to try it (and can easily reproduce)...

-- 
  John-Mark Gurney				Voice: +1 415 225 5579

     "All that I will do, has been done, All that I have, has not."