stable/10 panic
John Baldwin
jhb at freebsd.org
Wed May 7 18:34:42 UTC 2014
On Tuesday, May 06, 2014 7:47:05 pm hiren panchasara wrote:
> On Tue, May 6, 2014 at 1:34 PM, John Baldwin <jhb at freebsd.org> wrote:
> > On Monday, May 05, 2014 2:46:12 pm Sean Bruno wrote:
> >> On Mon, 2014-05-05 at 13:48 -0400, John Baldwin wrote:
> >> > On Monday, April 21, 2014 12:31:32 pm Sean Bruno wrote:
> >> > > We're seeing this *a lot* on our qmail based hosts during our stable/10
> >> > > rollout. We're running stable/10 from around svn rev 261579 (mid
> >> > > february) with one or two patches strewn in.
> >> > >
> >> > > sean
> >> > >
> >> > >
> >> > > 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 "amd64-marcel-freebsd"...
> >> > >
> >> > > Unread portion of the kernel message buffer:
> >> > > panic: page fault
> >> > > cpuid = 5
> >> > > KDB: stack backtrace:
> >> > > db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame
> > 0xfffffe048b9b12a0
> >> > > kdb_backtrace() at kdb_backtrace+0x39/frame 0xfffffe048b9b1350
> >> > > vpanic() at vpanic+0x126/frame 0xfffffe048b9b1390
> >> > > panic() at panic+0x43/frame 0xfffffe048b9b13f0
> >> > > trap_fatal() at trap_fatal+0x3a2/frame 0xfffffe048b9b1450
> >> > > trap_pfault() at trap_pfault+0x22f/frame 0xfffffe048b9b14f0
> >> > > trap() at trap+0x670/frame 0xfffffe048b9b1710
> >> > > calltrap() at calltrap+0x8/frame 0xfffffe048b9b1710
> >> > > --- trap 0xc, rip = 0xffffffff805e759b, rsp = 0xfffffe048b9b17d0, rbp =
> > 0xfffffe048b9b17e0 ---
> >> > > __mtx_assert() at __mtx_assert+0x3b/frame 0xfffffe048b9b17e0
> >> > > knote() at knote+0x39/frame 0xfffffe048b9b1830
> >> > > pipeclose() at pipeclose+0xbe/frame 0xfffffe048b9b1860
> >> >
> >> > Can you show which line this is via kgdb? Can you also 'p *cpipe'
> >> > and 'p *ppipe'?
> >> >
> >>
> >>
> >> Looks like its in here:
> >> (kgdb) whe
> >> #0 doadump (textdump=1) at pcpu.h:219
> >> #1 0xffffffff805fb2a7 in kern_reboot (howto=260)
> >> at ../../../kern/kern_shutdown.c:452
> >> #2 0xffffffff805fb7b5 in vpanic (fmt=<value optimized out>, ap=<value
> >> optimized out>) at ../../../kern/kern_shutdown.c:759
> >> #3 0xffffffff805fb803 in panic (fmt=<value optimized out>)
> >> at ../../../kern/kern_shutdown.c:688
> >> #4 0xffffffff80977852 in trap_fatal (frame=<value optimized out>,
> >> eva=<value optimized out>) at ../../../amd64/amd64/trap.c:882
> >> #5 0xffffffff80977a8f in trap_pfault (frame=0x0, usermode=<value
> >> optimized out>) at ../../../amd64/amd64/trap.c:699
> >> #6 0xffffffff809772a0 in trap (frame=0xfffffe048c3df6e0)
> >> at ../../../amd64/amd64/trap.c:463
> >> #7 0xffffffff8095c7e2 in calltrap ()
> >> at ../../../amd64/amd64/exception.S:232
> >> #8 0xffffffff805e759b in __mtx_assert (c=0x18, what=4,
> >> file=0xffffffff80ca0bcb "../../../kern/kern_event.c", line=1960)
> >> at ../../../kern/kern_mutex.c:791
> >> #9 0xffffffff805c2099 in knote (list=0xfffff8003498aae0, hint=0,
> >> lockflags=1) at ../../../kern/kern_event.c:1822
> >> #10 0xffffffff806510fe in pipeclose (cpipe=0xfffff8003498aa18)
> >> at ../../../kern/sys_pipe.c:1655
> >> #11 0xffffffff80651019 in pipe_dtor (dpipe=<value optimized out>)
> >> at ../../../kern/sys_pipe.c:395
> >> #12 0xffffffff80559924 in fifo_close (ap=<value optimized out>)
> >> at ../../../fs/fifofs/fifo_vnops.c:115
> >> #13 0xffffffff80a6ba6a in VOP_CLOSE_APV (vop=<value optimized out>,
> >> a=<value optimized out>) at vnode_if.c:535
> >> #14 0xffffffff806acc09 in vn_close (vp=0xfffff8032000cce8, flags=6,
> >> file_cred=0xfffff8040400d200, td=0xfffff804044f9490) at vnode_if.h:225
> >> #15 0xffffffff806abad8 in vn_closefile (fp=0xfffff803b2f3c410,
> >> td=0xfffff804044f9490) at ../../../kern/vfs_vnops.c:1481
> >> #16 0xffffffff805b8789 in _fdrop (fp=0xfffff803b2f3c410, td=0x4) at
> >> file.h:342
> >> #17 0xffffffff805bb0e1 in closef (fp=0xfffff803b2f3c410,
> >> td=0xfffff804044f9490) at ../../../kern/kern_descrip.c:2415
> >> #18 0xffffffff805b8bf0 in closefp (fdp=0xfffff800263f5000, fd=<value
> >> optimized out>, fp=0xfffff803b2f3c410, td=0xfffff804044f9490,
> >> holdleaders=<value optimized out>) at ../../../kern/kern_descrip.c:1257
> >> #19 0xffffffff80a332b5 in ia32_syscall (frame=0xfffffe048c3dfbc0) at
> >> subr_syscall.c:135
> >> #20 0xffffffff8095cdc5 in Xint0x80_syscall () at ia32_exception.S:73
> >> #21 0x00000000210f7804 in ?? ()
> >> Previous frame inner to this frame (corrupt stack?)
> >> Current language: auto; currently minimal
> >>
> >>
> >>
> >> ----------------
> >>
> >> (kgdb) f 10
> >> #10 0xffffffff806510fe in pipeclose (cpipe=0xfffff8003498aa18)
> >> at ../../../kern/sys_pipe.c:1655
> >> 1655 ../../../kern/sys_pipe.c: No such file or directory.
> >> in ../../../kern/sys_pipe.c
> >> (kgdb) p *cpipe
> >> $1 = {pipe_buffer = {cnt = 0, in = 0, out = 0, size = 0, buffer = 0x0},
> >> pipe_map = {cnt = 0, pos = 0, npages = 0, ms = {0x0 <repeats 17
> >> times>}}, pipe_sel = {si_tdlist = {tqh_first = 0x0, tqh_last = 0x0},
> >> si_note = {kl_list = {
> >> slh_first = 0x0}, kl_lock = 0, kl_unlock = 0, kl_assert_locked =
> >> 0xffffffff805c25c0 <knlist_mtx_assert_locked>, kl_assert_unlocked =
> >> 0xffffffff805c25e0 <knlist_mtx_assert_unlocked>, kl_lockarg = 0x0},
> >> si_mtx = 0x0},
> >> pipe_atime = {tv_sec = 1399120887, tv_nsec = 0}, pipe_mtime = {tv_sec
> >> = 1399120887, tv_nsec = 0}, pipe_ctime = {tv_sec = 1399120887, tv_nsec =
> >> 0}, pipe_sigio = 0x0, pipe_peer = 0xfffff8003498a8b8, pipe_pair =
> >> 0xfffff8003498a8b8,
> >> pipe_state = 2432, pipe_busy = 0, pipe_present = 3, pipe_wgen = 0,
> >> pipe_ino = 4294967295}
> >>
> >> (kgdb) p *ppipe
> >> $2 = {pipe_buffer = {cnt = 0, in = 0, out = 0, size = 0, buffer = 0x0},
> >> pipe_map = {cnt = 0, pos = 0, npages = 0, ms = {0x0 <repeats 17
> >> times>}}, pipe_sel = {si_tdlist = {tqh_first = 0x0, tqh_last = 0x0},
> >> si_note = {kl_list = {
> >> slh_first = 0x0}, kl_lock = 0, kl_unlock = 0, kl_assert_locked =
> >> 0xffffffff805c25c0 <knlist_mtx_assert_locked>, kl_assert_unlocked =
> >> 0xffffffff805c25e0 <knlist_mtx_assert_unlocked>, kl_lockarg = 0x0},
> >> si_mtx = 0x0},
> >> pipe_atime = {tv_sec = 1399120887, tv_nsec = 0}, pipe_mtime = {tv_sec
> >> = 1399120887, tv_nsec = 0}, pipe_ctime = {tv_sec = 1399120887, tv_nsec =
> >> 0}, pipe_sigio = 0x0, pipe_peer = 0xfffff8003498a8b8, pipe_pair =
> >> 0xfffff8003498a8b8,
> >> pipe_state = 2432, pipe_busy = 0, pipe_present = 3, pipe_wgen = 0,
> >> pipe_ino = 4294967295}
> >
> > So the knlist for both of these has already been destroyed (knlist_destroy
> > clears kl_lock, but not the assert function pointers). Note that pipe_present
> > is set to PIPE_FINALIZED for both pipes here. Can you do an 'l' at frame
> > 10 to see exactly which line is being called?
>
> #10 0xffffffff806510fe in pipeclose (cpipe=0xfffff8028a6c6730) at
> ../../../kern/sys_pipe.c:1655
>
> (kgdb) frame 10
> #10 0xffffffff806510fe in pipeclose (cpipe=0xfffff8028a6c6730) at
> ../../../kern/sys_pipe.c:1655
> 1655 ../../../kern/sys_pipe.c: No such file or directory.
> in ../../../kern/sys_pipe.c
> (kgdb) l
> 1650 in ../../../kern/sys_pipe.c
> (kgdb)
>
>
> 1639. /*
> 1640. * shutdown the pipe
> 1641. */
> 1642. static void
> 1643. pipeclose(cpipe)
> 1644. struct pipe *cpipe;
> 1645. {
> 1646. struct pipepair *pp;
> 1647. struct pipe *ppipe;
> 1648.
> 1649. KASSERT(cpipe != NULL, ("pipeclose: cpipe == NULL"));
> 1650.
> 1651. PIPE_LOCK(cpipe);
> 1652. pipelock(cpipe, 0);
> 1653. pp = cpipe->pipe_pair;
> 1654.
> 1655. pipeselwakeup(cpipe);
>
> pipeclose() gets called from pipe_dtor()
Eh, so it seems like pipeclose() has been called twice on the same pipe which
should never happen.
> 384. void
> 385. pipe_dtor(struct pipe *dpipe)
> 386. {
> 387. ino_t ino;
> 388.
> 389. ino = dpipe->pipe_ino;
> 390. funsetown(&dpipe->pipe_sigio);
> 391. pipeclose(dpipe); <---------------
> 392. if (dpipe->pipe_state & PIPE_NAMED) {
> 393. dpipe = dpipe->pipe_peer;
> 394. funsetown(&dpipe->pipe_sigio);
> 395. pipeclose(dpipe);
> 396. }
> 397. if (ino != 0 && ino != (ino_t)-1)
> 398. free_unr(pipeino_unr, ino);
> 399. }
>
> (kgdb) f 11
> #11 0xffffffff80651019 in pipe_dtor (dpipe=<value optimized out>) at
> ../../../kern/sys_pipe.c:395
> 395 ../../../kern/sys_pipe.c: No such file or directory.
> in ../../../kern/sys_pipe.c
> (kgdb) p *dpipe
> $8 = {pipe_buffer = {cnt = 2160683902, in = 4294967295, out =
> 2165433456, size = 4294967295, buffer = 0xfffff803c220be70 ""},
> pipe_map = {
> cnt = 18446735278181777408, pos = 18446735295352500696, npages =
> -1841788584, ms = {0x0, 0x0, 0xfffff80125a6a798, 0x0,
> 0xfffff803c2b7b2a0,
> 0xfffff803c2b7b2c0, 0x0, 0xffffffff80c96b7e, 0x6fb0008, 0x0,
> 0xfffff80060c08490, 0x1500000000, 0x60, 0xffffffff80cb7fa9, 0x1030000,
> 0x0, 0x4}},
> pipe_sel = {si_tdlist = {tqh_first = 0xfffff801cb464068, tqh_last =
> 0xfffff8020bfa9b10}, si_note = {kl_list = {slh_first =
> 0xfffff8022bb72648},
> kl_lock = 0xffffffff80cb7fb9 <global_opts+1769>, kl_unlock =
> 0x5230000, kl_assert_locked = 0, kl_assert_unlocked = 0x1,
> kl_lockarg = 0xffffffff81105f80}, si_mtx = 0x0}, pipe_atime =
> {tv_sec = 0, tv_nsec = 0}, pipe_mtime = {tv_sec = -8788387676160,
> tv_nsec = -8788387676160}, pipe_ctime = {tv_sec = 0, tv_nsec =
> -8788387675872}, pipe_sigio = 0x0, pipe_peer = 0x0, pipe_pair = 0x0,
> pipe_state = 3410379072, pipe_busy = -2047, pipe_present = 0,
> pipe_wgen = 0, pipe_ino = 0}
> (kgdb)
This looks like complete garbage, but it should be matching 'cpipe'
from earlier. Can you 'p dpipe' at this frame?
> which gets called from fifo_cleanup()
>
> 106. static void
> 107. fifo_cleanup(struct vnode *vp)
> 108. {
> 109. struct fifoinfo *fip;
> 110.
> 111. ASSERT_VOP_ELOCKED(vp, "fifo_cleanup");
> 112. fip = vp->v_fifoinfo;
> 113. if (fip->fi_readers == 0 && fip->fi_writers == 0) {
> 114. vp->v_fifoinfo = NULL;
> 115. pipe_dtor(fip->fi_pipe); <-----------------------------
> 116. free(fip, M_VNODE);
> 117. }
> 118. }
>
> (kgdb) p *fip->fi_pipe
> $7 = {pipe_buffer = {cnt = 7562869, in = 1701147238, out = 761557858,
> size = 1970170230,
> buffer = 0x736265657266006d <Address 0x736265657266006d out of
> bounds>}, pipe_map = {cnt = 7596447167107706212, pos =
> 7022344801864938862,
> npages = 1852402688, ms = {0x78756e696c006d76, 0x696c00646961722d,
> 0x706177732d78756e, 0x697361622d736d00, 0x6d00617461642d63,
> 0x61642d6d646c2d73,
> 0x646c2d736d006174, 0x61646174656d2d6d, 0x65722d736d006174,
> 0x6e00646576726573, 0x63632d6473627465, 0x64736274656e0064,
> 0x74656e006467632d,
> 0x7366662d647362, 0x6c2d64736274656e, 0x736274656e007366,
> 0x6e00646961722d64}}, pipe_sel = {si_tdlist = {tqh_first =
> 0x77732d6473627465,
> tqh_last = 0x7261776d76007061}, si_note = {kl_list = {slh_first
> = 0x760073666d762d65}, kl_lock = 0x6d762d657261776d, kl_unlock =
> 0x6d7600676169646b,
> kl_assert_locked = 0x7365722d65726177, kl_assert_unlocked =
> 0x6d76006465767265, kl_lockarg = 0x6173762d65726177}, si_mtx =
> 0x4f4547007264686e},
> pipe_atime = {tv_sec = 2322261270122749773, tv_nsec =
> 2675249699185255283}, pipe_mtime = {tv_sec = 8245071809811652723,
> tv_nsec = 7450486642355495269},
> pipe_ctime = {tv_sec = 2406159642925495145, tv_nsec =
> 3399705548884410378}, pipe_sigio = 0x2f6d6f65672f2e2e, pipe_peer =
> 0x705f672f74726170,
> pipe_pair = 0x5f6700632e747261, pipe_state = 1953653104, pipe_busy =
> 1886547807, pipe_present = 7233896, pipe_wgen = 623407909, pipe_ino =
> 620767603}
> (kgdb)
This should also be the same pipe, but it has an even different set
of garbage. Can you 'p *fip'?
--
John Baldwin
More information about the freebsd-stable
mailing list