Race in pipe tear-down, perhaps kqueue-related? (was: Re: Fatal trap , 12: page fault in kern/kern_mutex.c:744)

From: Robert Watson <rwatson_at_FreeBSD.org>
Date: Fri, 12 Nov 2004 12:10:14 +0000 (GMT)
On Fri, 12 Nov 2004, Peter Holm wrote:

> GENERIC HEAD from Nov 11 08:05 UTC
> http://www.holm.cc/stress/log/cons87.html

This looks like a bug in the pipe code where-in a partially initialized
pipe is free'd due to memory allocation problems (hitting a resource
limit).  pipeclose() is called when pipe_create() fails on one of the two
pipe endpoints, but it looks like pipeclose() is unprepared for the
eventuality that this is the case, as it attempts to generate wakeup
events on the pipe endpoint using pipeselwakeup(), which is not the right
thing to do while the pipe is not yet initialized.  Maybe we need a
special pipeclose() tear-down path that doesn't assume the pipe has
already been fully initialized?

Robert N M Watson             FreeBSD Core Team, TrustedBSD Projects
robert_at_fledge.watson.org      Principal Research Scientist, McAfee Research



> GENERIC HEAD from Nov 11 08:05 UTC
> 
> GDB: no debug ports present
> KDB: debugger backends: ddb
> KDB: current backend: ddb
> Copyright (c) 1992-2004 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 6.0-CURRENT #1: Thu Nov 11 09:37:26 CET 2004
>     pho_at_current.osted.lan:/usr/src/sys/i386/compile/PHO
> WARNING: WITNESS option enabled, expect reduced performance.
> Timecounter "i8254" frequency 1193182 Hz quality 0
> CPU: Intel(R) Celeron(R) CPU 1.80GHz (1799.14-MHz 686-class CPU)
>   Origin = "GenuineIntel"  Id = 0xf13  Stepping = 3
>   Features=0x3febfbff<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>
> real memory  = 267583488 (255 MB)
> avail memory = 252452864 (240 MB)
> :
> Mounting root from ufs:/dev/ad0s1a
> WARNING: / was not properly dismounted
> kern.ipc.maxpipekva exceeded; see tuning(7)
> lock order reversal
>  1st 0xc27318d8 pipe mutex (pipe mutex) _at_ kern/sys_pipe.c:1472
>  2nd 0xc1c93878 user map (user map) _at_ vm/vm_map.c:2994
> KDB: stack backtrace:
> witness_checkorder(c1c93878,9,c0825a5e,bb2,d021bb6c) at witness_checkorder+0x500
> _sx_xlock(c1c93878,c0825a5e,bb2,1000001,d021bb6c) at _sx_xlock+0x3a
> vm_map_lookup(d021bb6c,0,1,d021bb70,d021bb60,d021bb64,d021bb47,d021bb48) at vm_map_lookup+0x24
> vm_fault(c1c93834,0,1,0,c2688480) at vm_fault+0x62
> trap_pfault(1c,1c,0,0,0) at trap_pfault+0x126
> trap(18,c0810010,10,c080b507,5ab) at trap+0x318
> calltrap() at calltrap+0x5
> --- trap 0xc, eip = 0xc060369c, esp = 0xd021bc74, ebp = 0xd021bc80 ---
> _mtx_assert(0,1,c080b507,5ab,c273189c) at _mtx_assert+0x38
> knote(c273189c,0,1) at knote+0x2a
> pipeclose(c21b2200,d021bd40,0,c2688480,0) at pipeclose+0x3a3
> pipe(c2688480,d021bd14,0,8,292) at pipe+0x50
> syscall(2f,2f,2f,bfbfec58,bfbfec48) at syscall+0x128
> Xint0x80_syscall() at Xint0x80_syscall+0x1f
> --- syscall (42, FreeBSD ELF32, pipe), eip = 0x28099051, esp = 0xbfbfeb90, ebp = 0xbfbfec00 ---
> 
> 
> Fatal trap 12: page fault while in kernel mode
> cpuid = 0; apic id = 00
> fault virtual address   = 0x1c
> fault code              = supervisor read, page not present
> instruction pointer     = 0x8:0xc060369c
> stack pointer           = 0x10:0xd021bc74
> frame pointer           = 0x10:0xd021bc80
> 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         = 13574 (syscall)
> [thread 101293]
> Stopped at      _mtx_assert+0x38:       movl    0x1c(%ebx),%eax
> db> bt
> No such command
> db> trace
> _mtx_assert(0,1,c080b507,5ab,c273189c) at _mtx_assert+0x38
> knote(c273189c,0,1) at knote+0x2a
> pipeclose(c21b2200,d021bd40,0,c2688480,0) at pipeclose+0x3a3
> pipe(c2688480,d021bd14,0,8,292) at pipe+0x50
> syscall(2f,2f,2f,bfbfec58,bfbfec48) at syscall+0x128
> Xint0x80_syscall() at Xint0x80_syscall+0x1f
> --- syscall (42, FreeBSD ELF32, pipe), eip = 0x28099051, esp = 0xbfbfeb90, ebp = 0xbfbfec00 ---
> db> call doadump
> Dumping 255 MB
>  16 32 48 64 80 96 112 128 144 160 176 192 208 224 240
> Dump complete
> 0
> db> reset
> 
> #22 0xc060369c in _mtx_assert (m=0x0, what=0x0,
>     file=0xc080b507 "../../../kern/kern_event.c", line=0x5ab)
>     at ../../../kern/kern_mutex.c:762
> #23 0xc05f2a02 in knote (list=0xc273189c, hint=0x0, islocked=0x1)
>     at ../../../kern/kern_event.c:1451
> #24 0xc06304df in pipeclose (cpipe=0xc2731780) at ../../../kern/sys_pipe.c:545
> #25 0xc06305cc in pipe (td=0xc2688480, uap=0xd021bd14) at ../../../kern/sys_pipe.c:356
> #26 0xc07a4b60 in syscall (frame=
>       {tf_fs = 0x2f, tf_es = 0x2f, tf_ds = 0x2f, tf_edi = 0xbfbfec58, tf_esi = 0xbfbfec48, tf_ebp = 0xbfbfec00, tf_isp = 0xd021bd74, tf_ebx = 0x3, tf_edx = 0x41949b7d, tf_ecx = 0x8048a36, tf_eax = 0x2a, tf_trapno = 0x0, tf_err = 0x2, tf_eip = 0x28099051
, tf_cs = 0x1f, tf_eflags = 0x292, tf_esp = 0xbfbfeb90, tf_ss = 0x2f}) at ../../../i386/i386/trap.c:1001
> #27 0xc079329f in Xint0x80_syscall () at ../../../i386/i386/exception.s:201
> #28 0x0000002f in ?? ()
> :
> #55 0xc1524180 in ?? ()
> #56 0xc061adcf in sched_switch (td=0xbfbfec48, newtd=0x3, flags=Cannot access memory at address 0xbfbfec10
> )
>     at ../../../kern/sched_4bsd.c:865
> Previous frame inner to this frame (corrupt stack?)
> (kgdb) frame 23
> #23 0xc05f2a02 in knote (list=0xc273189c, hint=0x0, islocked=0x1)
>     at ../../../kern/kern_event.c:1451
> 1451            mtx_assert(list->kl_lock, islocked ? MA_OWNED : MA_NOTOWNED);
> (kgdb) p *list
> $1 = {kl_lock = 0x0, kl_list = {slh_first = 0x0}}
> (kgdb) up
> #24 0xc06304df in pipeclose (cpipe=0xc2731780) at ../../../kern/sys_pipe.c:545
> 545             KNOTE_LOCKED(&cpipe->pipe_sel.si_note, 0);
> (kgdb) p cpipe
> $2 = (struct pipe *) 0xc2731780
> (kgdb) p *cpipe
> $3 = {pipe_buffer = {cnt = 0x0, in = 0x0, out = 0x0, size = 0x0, buffer = 0x0},
>   pipe_map = {cnt = 0x0, pos = 0x0, npages = 0x0, ms = {0x0 <repeats 17 times>}},
>   pipe_sel = {si_thrlist = {tqe_next = 0x0, tqe_prev = 0x0}, si_thread = 0x0, si_note = {
>       kl_lock = 0xc27318d8, kl_list = {slh_first = 0x0}}, si_flags = 0x0}, pipe_atime = {
>     tv_sec = 0x41949b7d, tv_nsec = 0x0}, pipe_mtime = {tv_sec = 0x41949b7d,
>     tv_nsec = 0x0}, pipe_ctime = {tv_sec = 0x41949b7d, tv_nsec = 0x0}, pipe_sigio = 0x0,
>   pipe_peer = 0xc273182c, pipe_pair = 0xc2731780, pipe_state = 0x180, pipe_busy = 0x0,
>   pipe_present = 0x1}
Received on Fri Nov 12 2004 - 11:11:30 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:38:22 UTC