pipe crash
Brian Fundakowski Feldman
green at FreeBSD.org
Tue Feb 17 14:37:31 PST 2004
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. \,,,,,,,,,,,,,,,,,,,,,,\
More information about the freebsd-current
mailing list