pipe crash

From: Brian Fundakowski Feldman <green_at_FreeBSD.org>
Date: Tue, 17 Feb 2004 17:37:29 -0500
This is semi-repeatable.  While doing a ports build, during the lib-dependency
-check phase, ldconfig -r is called and hangs when the port is trying to 
check for a library, e.g. I see the output:
===>   xmms-imms-1.0 depends on shared library: id3 - found
===>   xmms-imms-1.0 depends on shared library: vorbis.3 <hang>
at which point that process is stuck in pipdwt.  I gdb'ed my kernel at this 
point and got a backtrace:

(kgdb) bt
#0  sched_switch (td=0xc2bbebd0) at ../../../kern/sched_4bsd.c:671
#1  0xc04a76ab in mi_switch (flags=0xc2bbebd0) at ../../../kern/kern_synch.c:518
#2  0xc04a6e27 in msleep (ident=0xc2803480, mtx=0xc28035d8, priority=0x14c, wmesg=0xc06306b5 "pipdwt", timo=0x0)
    at ../../../kern/kern_synch.c:254
#3  0xc04cc35a in pipe_direct_write (wpipe=0xc2803480, uio=0x0) at ../../../kern/sys_pipe.c:899
#4  0xc04cc7db in pipe_write (fp=0xc2c97d8c, uio=0xd85cec80, active_cred=0xc316a200, flags=0x0, td=0xc2bbebd0)
    at ../../../kern/sys_pipe.c:1009
#5  0xc04c929c in dofilewrite (td=0xc2bbebd0, fp=0xc2c97d8c, fd=0x0, buf=0x804f000, nbyte=0x0, offset=0x0, flags=0x0)
    at ../../../sys/file.h:249
#6  0xc04c90ce in write (td=0xc2bbebd0, uap=0xd85ced14) at ../../../kern/sys_generic.c:334
#7  0xc0603b62 in syscall (frame=
      {tf_fs = 0x2f, tf_es = 0x2f, tf_ds = 0x2f, tf_edi = 0x804f000, tf_esi = 0x4000, tf_ebp = 0xbfbfe548, tf_isp = 0xd85ced74, tf_ebx = 0x281430cc, tf_edx = 0x28142f38, tf_ecx = 0x28142f38, tf_eax = 0x4, tf_trapno = 0x0, tf_err = 0x2, tf_eip = 0x280c980f, tf_cs = 0x1f, tf_eflags = 0x216, tf_esp = 0xbfbfe52c, tf_ss = 0x2f}) at ../../../i386/i386/trap.c:1008

Now, here's the weird part:

(kgdb) p *wpipe
$1 = {pipe_buffer = {cnt = 0x0, in = 0x0, out = 0x0, size = 0x4000, buffer = 0x0}, pipe_map = {kva = 0xd8760000, 
    cnt = 0x4000, pos = 0x0, npages = 0x4, ms = {0xc11b5030, 0xc1311c78, 0xc125dcc0, 0xc12504c0, 
      0x0 <repeats 13 times>}}, pipe_sel = {si_thrlist = {tqe_next = 0x0, tqe_prev = 0x0}, si_thread = 0x0, si_note = {
      slh_first = 0x0}, si_flags = 0x0}, pipe_atime = {tv_sec = 0x40328142, tv_nsec = 0x0}, pipe_mtime = {
    tv_sec = 0x40328142, tv_nsec = 0x0}, pipe_ctime = {tv_sec = 0x40328142, tv_nsec = 0x0}, pipe_sigio = 0x0, 
  pipe_peer = 0xc280352c, pipe_pair = 0xc2803480, pipe_state = 0xc00, pipe_busy = 0x1, pipe_present = 0x0}

Notice that pipe_present is 0, somehow, though the file descriptor is quite 
alive (it's in a write() call, even, after all).  If I wake up the process 
with a ^C, then the system crashes trying to copy out the pipe contents to 
wpipe->pipe_buffer.buffer (NULL).  So wpipe is: seemingly referenced, 
!pipe_present, !PIPE_EOF, whereas the rpipe is: seemingly unreferenced 
because PIPE_EOF _is_ set on that side, and pipe_present.  This certainly 
looks like the two are just completely reversed at some point, because the 
field values in the two that I'm seeing are a hodgepodge of both.  Note that 
this is an SMP system.

Here is what the actual crash looks like, once I SIGINT:
#10 0xc06030cc in trap (frame=
      {tf_fs = 0x18, tf_es = 0x10, tf_ds = 0x10, tf_edi = 0x0, tf_esi = 0xd8760000, tf_ebp = 0xd85cebd4, tf_isp = 0xd85ceb98, tf_ebx = 0xc2803480, tf_edx = 0x4, tf_ecx = 0x1000, tf_eax = 0x278a0000, tf_trapno = 0xc, tf_err = 0x2, tf_eip = 0xc060172e, tf_cs = 0x8, tf_eflags = 0x10216, tf_esp = 0xd8760000, tf_ss = 0x4000}) at ../../../i386/i386/trap.c:420
#11 0xc060172e in generic_bcopy () at {standard input}:221
#12 0xc04cc414 in pipe_direct_write (wpipe=0xc2803480, uio=0x0) at ../../../kern/sys_pipe.c:909
#13 0xc04cc7db in pipe_write (fp=0xc2c97d8c, uio=0xd85cec80, active_cred=0xc316a200, flags=0x0, td=0xc2bbebd0)
    at ../../../kern/sys_pipe.c:1009
#14 0xc04c929c in dofilewrite (td=0xc2bbebd0, fp=0xc2c97d8c, fd=0x0, buf=0x804f000, nbyte=0x0, offset=0x0, flags=0x0)
    at ../../../sys/file.h:249
#15 0xc04c90ce in write (td=0xc2bbebd0, uap=0xd85ced14) at ../../../kern/sys_generic.c:334

Here's the related process, which spawned the pipeline:
root    1322  0.0  0.2  1688 1080  p7  I+    4:01PM   0:00.05  (sh)
root    1336  0.0  0.1  1256  688  p7  I+    4:01PM   0:00.02 /sbin/ldconfig -r

#0  sched_switch (td=0xc2fddd20) at ../../../kern/sched_4bsd.c:671
#1  0xc04a76ab in mi_switch (flags=0xc2fddd20) at ../../../kern/kern_synch.c:518
#2  0xc04a6e27 in msleep (ident=0xc2fdc528, mtx=0xc2fdc594, priority=0x15c, wmesg=0xc062ca11 "wait", timo=0x0)
    at ../../../kern/kern_synch.c:254
#3  0xc048915c in wait1 (td=0xc2fddd20, uap=0xd86c1d14, compat=0x0) at ../../../kern/kern_exit.c:772
#4  0xc04887d0 in wait4 (td=0x0, uap=0x0) at ../../../kern/kern_exit.c:555

Finally, here are the two pipes:
(kgdb) p *wpipe
$1 = {pipe_buffer = {cnt = 0x4000, in = 0x4000, out = 0x0, size = 0x4000, buffer = 0x0}, pipe_map = {kva = 0xd8760000,
    cnt = 0x4000, pos = 0x0, npages = 0x4, ms = {0xc11b5030, 0xc1311c78, 0xc125dcc0, 0xc12504c0,
      0x0 <repeats 13 times>}}, pipe_sel = {si_thrlist = {tqe_next = 0x0, tqe_prev = 0x0}, si_thread = 0x0, si_note = {
      slh_first = 0x0}, si_flags = 0x0}, pipe_atime = {tv_sec = 0x40328142, tv_nsec = 0x0}, pipe_mtime = {
    tv_sec = 0x40328142, tv_nsec = 0x0}, pipe_ctime = {tv_sec = 0x40328142, tv_nsec = 0x0}, pipe_sigio = 0x0,
  pipe_peer = 0xc280352c, pipe_pair = 0xc2803480, pipe_state = 0x900, pipe_busy = 0x1, pipe_present = 0x0}
(kgdb) p *wpipe->pipe_peer
$2 = {pipe_buffer = {cnt = 0x0, in = 0x0, out = 0x0, can not access 0xd3595000, invalid address (d3595000)
can not access 0xd3595000, invalid address (d3595000)
can not access 0xd3595000, invalid address (d3595000)
can not access 0xd3595000, invalid address (d3595000)
can not access 0xd3595000, invalid address (d3595000)
can not access 0xd3595000, invalid address (d3595000)
size = 0x4000,
    buffer = 0xd3595000 <Address 0xd3595000 out of bounds>}, pipe_map = {kva = 0x0, 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 = {slh_first = 0x0}, si_flags = 0x0}, pipe_atime = {tv_sec = 0x40328142, tv_nsec = 0x0},
  pipe_mtime = {tv_sec = 0x40328142, tv_nsec = 0x0}, pipe_ctime = {tv_sec = 0x40328142, tv_nsec = 0x0},
  pipe_sigio = 0x0, pipe_peer = 0xc2803480, pipe_pair = 0xc2803480, pipe_state = 0x880, pipe_busy = 0x0,
  pipe_present = 0x1}

Does anyone have any clues?

-- 
Brian Fundakowski Feldman                           \'[ FreeBSD ]''''''''''\
  <> green_at_FreeBSD.org                               \  The Power to Serve! \
 Opinions expressed are my own.                       \,,,,,,,,,,,,,,,,,,,,,,\




-- 
Brian Fundakowski Feldman                           \'[ FreeBSD ]''''''''''\
  <> green_at_FreeBSD.org                               \  The Power to Serve! \
 Opinions expressed are my own.                       \,,,,,,,,,,,,,,,,,,,,,,\




-- 
Brian Fundakowski Feldman                           \'[ FreeBSD ]''''''''''\
  <> green_at_FreeBSD.org                               \  The Power to Serve! \
 Opinions expressed are my own.                       \,,,,,,,,,,,,,,,,,,,,,,\
Received on Tue Feb 17 2004 - 13:37:31 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:37:43 UTC