From owner-freebsd-stable@FreeBSD.ORG Tue May 6 23:47:07 2014 Return-Path: Delivered-To: freebsd-stable@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [8.8.178.115]) (using TLSv1 with cipher ADH-AES256-SHA (256/256 bits)) (No client certificate requested) by hub.freebsd.org (Postfix) with ESMTPS id 306B03BF; Tue, 6 May 2014 23:47:07 +0000 (UTC) Received: from mail-qa0-x22e.google.com (mail-qa0-x22e.google.com [IPv6:2607:f8b0:400d:c00::22e]) (using TLSv1 with cipher ECDHE-RSA-RC4-SHA (128/128 bits)) (Client CN "smtp.gmail.com", Issuer "Google Internet Authority G2" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id C50D42B9; Tue, 6 May 2014 23:47:06 +0000 (UTC) Received: by mail-qa0-f46.google.com with SMTP id w8so224270qac.19 for ; Tue, 06 May 2014 16:47:06 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:in-reply-to:references:date:message-id:subject:from:to :cc:content-type; bh=zyiecLXs/yMAYLqJd3uquCldzDQdttzwC+5xhTAuRu0=; b=iC7PEn3i5wMwEvUM9RNZ4Xdmq/wGxowrJI6CX0YWMjK4JLrOcIRJYmf5MRpaXyevYW skJhqAjPxyKIUsQXcIjVGr0ck5Y+pteHPROni/J1Ceb1nWT7/BixOfj74TiE60nwhhkd t3rfad9gQQxfENqjHnI/PJBp+JtnN/CNnRD66LKErfheWMj0srA31CCD8ykRQp+BKPdI Um4my7wVBm8y1uxs0tcccYwuE5bZgQ/2w7ENhvj2oNvXuaxwTMEmZ5lRHM5GQWl+LbMY 2XrGKDNFvy617miFEM2PHdM1zFvK+W+Ifvq9WWnjq6x1xsNluUzTaWCq0idEsP8bb6dJ crQw== MIME-Version: 1.0 X-Received: by 10.224.55.6 with SMTP id s6mr24390725qag.7.1399420025967; Tue, 06 May 2014 16:47:05 -0700 (PDT) Received: by 10.96.10.161 with HTTP; Tue, 6 May 2014 16:47:05 -0700 (PDT) In-Reply-To: <201405061634.34868.jhb@freebsd.org> References: <1398097892.1101.6.camel@powernoodle.corp.yahoo.com> <201405051348.13320.jhb@freebsd.org> <1399315572.77984.2.camel@powernoodle.corp.yahoo.com> <201405061634.34868.jhb@freebsd.org> Date: Tue, 6 May 2014 16:47:05 -0700 Message-ID: Subject: Re: stable/10 panic From: hiren panchasara To: John Baldwin Content-Type: text/plain; charset=UTF-8 Cc: freebsd-stable@freebsd.org X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 06 May 2014 23:47:07 -0000 On Tue, May 6, 2014 at 1:34 PM, John Baldwin 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=, ap=> optimized out>) at ../../../kern/kern_shutdown.c:759 >> #3 0xffffffff805fb803 in panic (fmt=) >> at ../../../kern/kern_shutdown.c:688 >> #4 0xffffffff80977852 in trap_fatal (frame=, >> eva=) at ../../../amd64/amd64/trap.c:882 >> #5 0xffffffff80977a8f in trap_pfault (frame=0x0, usermode=> 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=) >> at ../../../kern/sys_pipe.c:395 >> #12 0xffffffff80559924 in fifo_close (ap=) >> at ../../../fs/fifofs/fifo_vnops.c:115 >> #13 0xffffffff80a6ba6a in VOP_CLOSE_APV (vop=, >> a=) 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=> optimized out>, fp=0xfffff803b2f3c410, td=0xfffff804044f9490, >> holdleaders=) 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 > 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 , kl_assert_unlocked = >> 0xffffffff805c25e0 , 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 > 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 , kl_assert_unlocked = >> 0xffffffff805c25e0 , 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() 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=) 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 , 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) 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
}, 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) > Also, it seems like 'cpipe' > and 'pipe' might be the same. Let me know if you want to any more info. thanks for looking at this, Hiren