From owner-freebsd-current Mon Jan 10 13:58:52 2000 Delivered-To: freebsd-current@freebsd.org Received: from fw.wintelcom.net (ns1.wintelcom.net [209.1.153.20]) by hub.freebsd.org (Postfix) with ESMTP id 72138152F0; Mon, 10 Jan 2000 13:58:43 -0800 (PST) (envelope-from bright@fw.wintelcom.net) Received: (from bright@localhost) by fw.wintelcom.net (8.9.3/8.9.3) id OAA23384; Mon, 10 Jan 2000 14:21:56 -0800 (PST) Date: Mon, 10 Jan 2000 14:21:56 -0800 From: Alfred Perlstein To: Matthew Dillon Cc: freebsd-current@FreeBSD.ORG, mckusick@FreeBSD.ORG Subject: Re: freezing... Message-ID: <20000110142156.F9397@fw.wintelcom.net> References: <55926.947513027@critter.freebsd.dk> <200001101945.LAA29394@apollo.backplane.com> Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii X-Mailer: Mutt 1.0i In-Reply-To: <200001101945.LAA29394@apollo.backplane.com>; from dillon@apollo.backplane.com on Mon, Jan 10, 2000 at 11:45:46AM -0800 Sender: owner-freebsd-current@FreeBSD.ORG Precedence: bulk X-Loop: FreeBSD.ORG * Matthew Dillon [000110 12:11] wrote: > I've reproduced the softupdates ftruncate panic and have a core dump > to play with. I don't have a panic, but rather many processes start to get stuck in "getblk", unfortunatly they all don't stem from a common codepath, although the first process that wedged appears to have come through indir_trunc: 1442 d8ed2700 d93a0000 1001 1422 1422 004006 3 ranlib getblk cc50a85(kgdb) proc 0xd8ed2700 (kgdb) bt #0 mi_switch () at machine/globals.h:117 #1 0xc015d869 in tsleep (ident=0xcc50a850, priority=0x14, wmesg=0xc0292de1 "getblk", timo=0x0) at ../../kern/kern_synch.c:437 #2 0xc0155b06 in acquire (lkp=0xcc50a850, extflags=0x20, wanted=0x600) at ../../kern/kern_lock.c:147 #3 0xc0155dbc in lockmgr (lkp=0xcc50a850, flags=0x10022, interlkp=0xc030ba74, p=0xd8ed2700) at ../../kern/kern_lock.c:362 #4 0xc017e73e in getblk (vp=0xd66dab20, blkno=0xe565a0, size=0x2000, slpflag=0x0, slptimeo=0x0) at ../../sys/buf.h:294 #5 0xc017c72a in bread (vp=0xd66dab20, blkno=0xe565a0, size=0x2000, cred=0x0, bpp=0xd93a1bb8) at ../../kern/vfs_bio.c:498 #6 0xc02015af in indir_trunc (ip=0xd93a1bfc, dbn=0xe565a0, level=0x0, lbn=0xc, countp=0xd93a1bec) at ../../ufs/ffs/ffs_softdep.c:2040 #7 0xc02013f5 in handle_workitem_freeblocks (freeblks=0xc2315300) at ../../ufs/ffs/ffs_softdep.c:1961 #8 0xc0200e40 in softdep_setup_freeblocks (ip=0xc23ca200, length=0x0) at ../../ufs/ffs/ffs_softdep.c:1668 #9 0xc01fead6 in ffs_truncate (vp=0xd9072860, length=0x0, flags=0x0, cred=0x0, p=0xd8ed2700) at ../../ufs/ffs/ffs_inode.c:195 #10 0xc0209276 in ufs_inactive (ap=0xd93a1eb8) at ../../ufs/ufs/ufs_inode.c:84 #11 0xc020e3bd in ufs_vnoperate (ap=0xd93a1eb8) at ../../ufs/ufs/ufs_vnops.c:2283 #12 0xc0185145 in vput (vp=0xd9072860) at vnode_if.h:794 #13 0xc0188739 in unlink (p=0xd8ed2700, uap=0xd93a1f80) at ../../kern/vfs_syscalls.c:1421 #14 0xc026f7ba in syscall (frame={tf_fs = 0x2f, tf_es = 0x2f, tf_ds = 0x2f, tf_edi = 0x808b300, tf_esi = 0x8076170, tf_ebp = 0xbfbffa04, tf_isp = 0xd93a1fd4, tf_ebx = 0x8076160, tf_edx = 0x8074060, tf_ecx = 0x0, tf_eax = 0xa, tf_trapno = 0x7, tf_err = 0x2, tf_eip = 0x180c41cc, tf_cs = 0x1f, tf_eflags = 0x293, tf_esp = 0xbfbff9c8, tf_ss = 0x2f}) at ../../i386/i386/trap.c:1057 after that it starts spreading: 1478 d8ed3480 d8f32000 1001 1477 1478 004006 3 zsh getblk cc50b148 1477 d8ed3a80 d8f24000 1001 369 1477 004106 3 rxvt getblk cc50b148 1473 d8ed2a00 d8fbf000 1001 1466 1473 004006 3 cvs getblk cc4a39e8 with varied tracebacks: (kgdb) proc 0xd8ed3480 (kgdb) bt #0 mi_switch () at machine/globals.h:117 #1 0xc015d869 in tsleep (ident=0xcc50b148, priority=0x14, wmesg=0xc0292de1 "getblk", timo=0x0) at ../../kern/kern_synch.c:437 #2 0xc0155b06 in acquire (lkp=0xcc50b148, extflags=0x20, wanted=0x600) at ../../kern/kern_lock.c:147 #3 0xc0155dbc in lockmgr (lkp=0xcc50b148, flags=0x10022, interlkp=0xc030ba74, p=0xd8ed3480) at ../../kern/kern_lock.c:362 #4 0xc017e73e in getblk (vp=0xd66dcf60, blkno=0x20090, size=0x2000, slpflag=0x0, slptimeo=0x0) at ../../sys/buf.h:294 #5 0xc017c72a in bread (vp=0xd66dcf60, blkno=0x20090, size=0x2000, cred=0x0, bpp=0xd8f33dec) at ../../kern/vfs_bio.c:498 #6 0xc01fe869 in ffs_update (vp=0xd8e880e0, waitfor=0x0) at ../../ufs/ffs/ffs_inode.c:98 #7 0xc02092ca in ufs_inactive (ap=0xd8f33e40) at ../../ufs/ufs/ufs_inode.c:92 #8 0xc020e3bd in ufs_vnoperate (ap=0xd8f33e40) at ../../ufs/ufs/ufs_vnops.c:2283 #9 0xc018507d in vrele (vp=0xd8e880e0) at vnode_if.h:794 #10 0xc018bbb3 in vn_close (vp=0xd8e880e0, flags=0x1, cred=0xc2243c80, p=0xd8ed3480) at ../../kern/vfs_vnops.c:232 #11 0xc018c414 in vn_closefile (fp=0xc1fb6000, p=0xd8ed3480) at ../../kern/vfs_vnops.c:630 #12 0xc01526fd in fdrop (fp=0xc1fb6000, p=0xd8ed3480) at ../../sys/file.h:211 #13 0xc015263b in closef (fp=0xc1fb6000, p=0xd8ed3480) at ../../kern/kern_descrip.c:1003 #14 0xc0151d98 in close (p=0xd8ed3480, uap=0xd8f33f80) at ../../kern/kern_descrip.c:507 #15 0xc026f7ba in syscall (frame={tf_fs = 0x2f, tf_es = 0x2f, tf_ds = 0x2f, tf_edi = 0x80a9000, tf_esi = 0x1, tf_ebp = 0xbfbff9c8, tf_isp = 0xd8f33fd4, tf_ebx = 0x1816d3c4, tf_edx = 0x80a9138, tf_ecx = 0x2, tf_eax = 0x6, tf_trapno = 0xc, tf_err = 0x2, tf_eip = 0x1812a22c, tf_cs = 0x1f, tf_eflags = 0x283, tf_esp = 0xbfbff98c, tf_ss = 0x2f}) at ../../i386/i386/trap.c:1057 (kgdb) proc 0xd8ed3a80 (kgdb) bt #0 mi_switch () at machine/globals.h:117 #1 0xc015d869 in tsleep (ident=0xcc50b148, priority=0x14, wmesg=0xc0292de1 "getblk", timo=0x0) at ../../kern/kern_synch.c:437 #2 0xc0155b06 in acquire (lkp=0xcc50b148, extflags=0x20, wanted=0x600) at ../../kern/kern_lock.c:147 #3 0xc0155dbc in lockmgr (lkp=0xcc50b148, flags=0x10022, interlkp=0xc030ba74, p=0xd8ed3a80) at ../../kern/kern_lock.c:362 #4 0xc017e73e in getblk (vp=0xd66dcf60, blkno=0x20090, size=0x2000, slpflag=0x0, slptimeo=0x0) at ../../sys/buf.h:294 #5 0xc017c72a in bread (vp=0xd66dcf60, blkno=0x20090, size=0x2000, cred=0x0, bpp=0xd8f25dec) at ../../kern/vfs_bio.c:498 #6 0xc01fe869 in ffs_update (vp=0xd66d90e0, waitfor=0x0) at ../../ufs/ffs/ffs_inode.c:98 #7 0xc02092ca in ufs_inactive (ap=0xd8f25e40) at ../../ufs/ufs/ufs_inode.c:92 #8 0xc020e3bd in ufs_vnoperate (ap=0xd8f25e40) at ../../ufs/ufs/ufs_vnops.c:2283 #9 0xc018507d in vrele (vp=0xd66d90e0) at vnode_if.h:794 #10 0xc018bbb3 in vn_close (vp=0xd66d90e0, flags=0x1, cred=0xc2312f00, p=0xd8ed3a80) at ../../kern/vfs_vnops.c:232 #11 0xc018c414 in vn_closefile (fp=0xc200ab40, p=0xd8ed3a80) at ../../kern/vfs_vnops.c:630 #12 0xc01526fd in fdrop (fp=0xc200ab40, p=0xd8ed3a80) at ../../sys/file.h:211 #13 0xc015263b in closef (fp=0xc200ab40, p=0xd8ed3a80) at ../../kern/kern_descrip.c:1003 #14 0xc0151d98 in close (p=0xd8ed3a80, uap=0xd8f25f80) at ../../kern/kern_descrip.c:507 #15 0xc026f7ba in syscall (frame={tf_fs = 0x2f, tf_es = 0x2f, tf_ds = 0x2f, tf_edi = 0x8064800, tf_esi = 0x1, tf_ebp = 0xbfbff770, tf_isp = 0xd8f25fd4, tf_ebx = 0x181a03c4, tf_edx = 0x8064938, tf_ecx = 0x806c000, tf_eax = 0x6, tf_trapno = 0xc, tf_err = 0x2, tf_eip = 0x1815d22c, tf_cs = 0x1f, tf_eflags = 0x287, tf_esp = 0xbfbff734, tf_ss = 0x2f}) at ../../i386/i386/trap.c:1057 (kgdb) proc 0xd8ed2a00 (kgdb) bt #0 mi_switch () at machine/globals.h:117 #1 0xc015d869 in tsleep (ident=0xcc4a39e8, priority=0x14, wmesg=0xc0292de1 "getblk", timo=0x0) at ../../kern/kern_synch.c:437 #2 0xc0155b06 in acquire (lkp=0xcc4a39e8, extflags=0x20, wanted=0x600) at ../../kern/kern_lock.c:147 #3 0xc0155dbc in lockmgr (lkp=0xcc4a39e8, flags=0x10022, interlkp=0xc030ba74, p=0xd8ed2a00) at ../../kern/kern_lock.c:362 #4 0xc017e73e in getblk (vp=0xd66dcf60, blkno=0x20950, size=0x2000, slpflag=0x0, slptimeo=0x0) at ../../sys/buf.h:294 #5 0xc017c72a in bread (vp=0xd66dcf60, blkno=0x20950, size=0x2000, cred=0x0, bpp=0xd8fc0bb8) at ../../kern/vfs_bio.c:498 #6 0xc02015af in indir_trunc (ip=0xd8fc0bfc, dbn=0x20950, level=0x0, lbn=0xc, countp=0xd8fc0bec) at ../../ufs/ffs/ffs_softdep.c:2040 #7 0xc02013f5 in handle_workitem_freeblocks (freeblks=0xc230c000) at ../../ufs/ffs/ffs_softdep.c:1961 #8 0xc0200e40 in softdep_setup_freeblocks (ip=0xc2366800, length=0x0) at ../../ufs/ffs/ffs_softdep.c:1668 #9 0xc01fead6 in ffs_truncate (vp=0xd907aa00, length=0x0, flags=0x0, cred=0x0, p=0xd8ed2a00) at ../../ufs/ffs/ffs_inode.c:195 #10 0xc0209276 in ufs_inactive (ap=0xd8fc0eb8) at ../../ufs/ufs/ufs_inode.c:84 #11 0xc020e3bd in ufs_vnoperate (ap=0xd8fc0eb8) at ../../ufs/ufs/ufs_vnops.c:2283 #12 0xc0185145 in vput (vp=0xd907aa00) at vnode_if.h:794 #13 0xc0188739 in unlink (p=0xd8ed2a00, uap=0xd8fc0f80) at ../../kern/vfs_syscalls.c:1421 #14 0xc026f7ba in syscall (frame={tf_fs = 0x2f, tf_es = 0x2f, tf_ds = 0x2f, tf_edi = 0x0, tf_esi = 0x80bf180, tf_ebp = 0xbfbff71c, tf_isp = 0xd8fc0fd4, tf_ebx = 0x80bf180, tf_edx = 0x5, tf_ecx = 0x1b, tf_eax = 0xa, tf_trapno = 0xc, tf_err = 0x2, tf_eip = 0x1813f1cc, tf_cs = 0x1f, tf_eflags = 0x283, tf_esp = 0xbfbff6f0, tf_ss = 0x2f}) at ../../i386/i386/trap.c:1057 have fun, I know I am. :) it seems that ranlib is caught on someone else's buffer lock in getblk on the BUF_TIMELOCK() call, the lock looks like this: #2 0xc0155b06 in acquire (lkp=0xcc50a850, extflags=0x20, wanted=0x600) at ../../kern/kern_lock.c:147 147 error = tsleep(lkp, lkp->lk_prio, lkp->lk_wmesg, lkp->lk_timo); (kgdb) print *lkp $5 = { lk_interlock = { lock_data = 0x0 }, lk_flags = 0x200400, lk_sharecount = 0x0, lk_waitcount = 0x1, lk_exclusivecount = 0x1, lk_prio = 0x14, lk_wmesg = 0xc0292de1 "getblk", lk_timo = 0x0, lk_lockholder = 0xfffffffe } thanks, -- -Alfred Perlstein - [bright@rush.net|alfred@freebsd.org] Wintelcom systems administrator and programmer - http://www.wintelcom.net/ [bright@wintelcom.net] To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe freebsd-current" in the body of the message