From owner-freebsd-current@FreeBSD.ORG Wed Dec 3 05:22:43 2003 Return-Path: Delivered-To: freebsd-current@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id C357E16A4CE for ; Wed, 3 Dec 2003 05:22:43 -0800 (PST) Received: from fledge.watson.org (fledge.watson.org [204.156.12.50]) by mx1.FreeBSD.org (Postfix) with ESMTP id 179AD43FE5 for ; Wed, 3 Dec 2003 05:22:41 -0800 (PST) (envelope-from robert@fledge.watson.org) Received: from fledge.watson.org (localhost [127.0.0.1]) by fledge.watson.org (8.12.9p2/8.12.9) with ESMTP id hB3DJtMg082075; Wed, 3 Dec 2003 08:19:55 -0500 (EST) (envelope-from robert@fledge.watson.org) Received: from localhost (robert@localhost)hB3DJtLI082072; Wed, 3 Dec 2003 08:19:55 -0500 (EST) (envelope-from robert@fledge.watson.org) Date: Wed, 3 Dec 2003 08:19:54 -0500 (EST) From: Robert Watson X-Sender: robert@fledge.watson.org To: kirk@mckusick.com Message-ID: MIME-Version: 1.0 Content-Type: TEXT/PLAIN; charset=ISO-8859-1 Content-Transfer-Encoding: QUOTED-PRINTABLE cc: current@FreeBSD.org Subject: panic: initiate_write_inodeblock_ufs2: already started X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.1 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 03 Dec 2003 13:22:43 -0000 Ran into this on a box with -CURRENT from yesterday, running with MAC (although in this case I suspect it doesn't make a difference, I'm not using the multilabel/extattr code in UFS2). I have a core on disk, so please let me know what further information would be useful. This machine spends a lot of time in bgfsck these days due to a bug causing X Windows to occasionally hang when starting (interestingly, it seems to start much better when bgfsck is running, suggesting a race that's avoided by slowing the system down...)=20 Robert N M Watson FreeBSD Core Team, TrustedBSD Projects robert@fledge.watson.org Senior Research Scientist, McAfee Research Script started on Wed Dec 3 08:04:46 2003 GNU gdb 5.2.1 (FreeBSD) Copyright 2002 Free Software Foundation, Inc. GDB is free software, covered by the GNU General Public License, and you ar= e welcome to change it and/or distribute copies of it under certain condition= s. Type "show copying" to see the conditions. There is absolutely no warranty for GDB. Type "show warranty" for details. This GDB was configured as "i386-undermydesk-freebsd"... panic: initiate_write_inodeblock_ufs2: already started panic messages: --- panic: initiate_write_inodeblock_ufs2: already started cpuid =3D 0;=20 syncing disks, buffers remaining... 3834 3834 3829 3829 3829 3829 3829 3829= 3829 3829 3829 3829 3829 3829 3829 3829 3829 3829 3829 3829 3829 3829=20 giving up on 2705 buffers Uptime: 9h20m19s Dumping 511 MB [CTRL-C to abort] 16 32 48 64 80 96 112 128 144 160 176 192 208 224 240 25= 6 272 288 304 320 336 352 368 384 400 416 432 448 464 480 496 --- Reading symbols from /boot/kernel/snd_maestro3.ko...done. Loaded symbols for /boot/kernel/snd_maestro3.ko Reading symbols from /boot/kernel/snd_pcm.ko...done. Loaded symbols for /boot/kernel/snd_pcm.ko Reading symbols from /usr/obj/usr/src/sys/PAPRIKAMAC/modules/usr/src/sys/mo= dules/mac_biba/mac_biba.ko.debug...done. Loaded symbols for /usr/obj/usr/src/sys/PAPRIKAMAC/modules/usr/src/sys/modu= les/mac_biba/mac_biba.ko.debug Reading symbols from /usr/obj/usr/src/sys/PAPRIKAMAC/modules/usr/src/sys/mo= dules/mac_mls/mac_mls.ko.debug...done. Loaded symbols for /usr/obj/usr/src/sys/PAPRIKAMAC/modules/usr/src/sys/modu= les/mac_mls/mac_mls.ko.debug Reading symbols from /boot/kernel/r128.ko...done. Loaded symbols for /boot/kernel/r128.ko Reading symbols from /usr/obj/usr/src/sys/PAPRIKAMAC/modules/usr/src/sys/mo= dules/linprocfs/linprocfs.ko.debug...done. Loaded symbols for /usr/obj/usr/src/sys/PAPRIKAMAC/modules/usr/src/sys/modu= les/linprocfs/linprocfs.ko.debug Reading symbols from /usr/obj/usr/src/sys/PAPRIKAMAC/modules/usr/src/sys/mo= dules/linux/linux.ko.debug...done. Loaded symbols for /usr/obj/usr/src/sys/PAPRIKAMAC/modules/usr/src/sys/modu= les/linux/linux.ko.debug #0 doadump () at /usr/src/sys/kern/kern_shutdown.c:240 240=09=09dumping++; (kgdb) bt #0 doadump () at /usr/src/sys/kern/kern_shutdown.c:240 #1 0xc0671987 in boot (howto=3D256) at /usr/src/sys/kern/kern_shutdown.c:3= 72 #2 0xc0671d8d in panic () at /usr/src/sys/kern/kern_shutdown.c:550 #3 0xc07cf179 in initiate_write_inodeblock_ufs2 (inodedep=3D0xc58c2880, bp= =3D0x0) at /usr/src/sys/ufs/ffs/ffs_softdep.c:3902 #4 0xc07ce30d in softdep_disk_io_initiation (bp=3D0xcec33148) at /usr/src/sys/ufs/ffs/ffs_softdep.c:3468 #5 0xc0635547 in spec_xstrategy (vp=3D0xc49c4514, bp=3D0xcec33148) at /usr/src/sys/sys/buf.h:413 #6 0xc06356e2 in spec_specstrategy (ap=3D0xd7830bf0) at /usr/src/sys/fs/specfs/spec_vnops.c:534 #7 0xc0634828 in spec_vnoperate (ap=3D0x0) at /usr/src/sys/fs/specfs/spec_vnops.c:122 #8 0xc06b8324 in bwrite (bp=3D0xd7830bf0) at vnode_if.h:1141 #9 0xc06ba152 in vfs_bio_awrite (bp=3D0xcec33148) at /usr/src/sys/kern/vfs_bio.c:1715 #10 0xc06c2307 in vop_stdfsync (ap=3D0xd7830cd4) at /usr/src/sys/kern/vfs_default.c:738 #11 0xc06353e0 in spec_fsync (ap=3D0xd7830cd4) at /usr/src/sys/fs/specfs/spec_vnops.c:422 #12 0xc0634828 in spec_vnoperate (ap=3D0x0) at /usr/src/sys/fs/specfs/spec_vnops.c:122 #13 0xc06ca516 in sched_sync () at vnode_if.h:627 #14 0xc065b2f4 in fork_exit (callout=3D0xc06ca290 , arg=3D0x0,= =20 ---Type to continue, or q to quit--- frame=3D0x0) at /usr/src/sys/kern/kern_fork.c:793 (kgdb) up #1 0xc0671987 in boot (howto=3D256) at /usr/src/sys/kern/kern_shutdown.c:3= 72 372=09=09=09doadump(); (kgdb) up #2 0xc0671d8d in panic () at /usr/src/sys/kern/kern_shutdown.c:550 550=09=09boot(bootopt); (kgdb) up #3 0xc07cf179 in initiate_write_inodeblock_ufs2 (inodedep=3D0xc58c2880, bp= =3D0x0) at /usr/src/sys/ufs/ffs/ffs_softdep.c:3902 3902=09=09=09=09=09panic("softdep_write_inodeblock: lost dep3"); (kgdb) list 3897=09=09=09for (i =3D 0; i < NIADDR; i++) { 3898=09#ifdef DIAGNOSTIC 3899=09=09=09=09if (dp->di_ib[i] !=3D 0 && 3900=09=09=09=09 (deplist & ((1 << NDADDR) << i)) =3D=3D 0) { 3901=09=09=09=09=09FREE_LOCK(&lk); 3902=09=09=09=09=09panic("softdep_write_inodeblock: lost dep3"); 3903=09=09=09=09} 3904=09#endif /* DIAGNOSTIC */ 3905=09=09=09=09dp->di_ib[i] =3D 0; 3906=09=09=09} (kgdb) inspect i $1 =3D -2917476963376682880 (kgdb) inspect deplist $2 =3D 291 (kgdb) up #4 0xc07ce30d in softdep_disk_io_initiation (bp=3D0xcec33148) at /usr/src/sys/ufs/ffs/ffs_softdep.c:3468 3468=09=09=09=09=09initiate_write_inodeblock_ufs2(inodedep, bp); (kgdb) list 3463=09=09=09case D_INODEDEP: 3464=09=09=09=09inodedep =3D WK_INODEDEP(wk); 3465=09=09=09=09if (inodedep->id_fs->fs_magic =3D=3D FS_UFS1_MAGIC) 3466=09=09=09=09=09initiate_write_inodeblock_ufs1(inodedep, bp); 3467=09=09=09=09else 3468=09=09=09=09=09initiate_write_inodeblock_ufs2(inodedep, bp); 3469=09=09=09=09continue; 3470=09 3471=09=09=09case D_INDIRDEP: 3472=09=09=09=09indirdep =3D WK_INDIRDEP(wk); (kgdb) inspect inodedep $3 =3D (struct inodedep *) 0x0 (kgdb) inspect wk $4 =3D (struct worklist *) 0xc58c2880 (kgdb) inspect *wk $5 =3D {wk_list =3D {le_next =3D 0x0, le_prev =3D 0xcec332fc}, wk_type =3D = 1,=20 wk_state =3D 33293} (kgdb) inspect *wk.wk_state ---Can't read userspace from dump, or kernel process--- (kgdb) up #5 0xc0635547 in spec_xstrategy (vp=3D0xc49c4514, bp=3D0xcec33148) at /usr/src/sys/sys/buf.h:413 413=09=09=09(*bioops.io_start)(bp); (kgdb) inspect bp $6 =3D (struct buf *) 0xcec33148 (kgdb) inspect *bp $7 =3D {b_io =3D {bio_cmd =3D 2, bio_dev =3D 0xc486a300, bio_disk =3D 0x0,= =20 bio_offset =3D 12332630016, bio_bcount =3D 16384,=20 bio_data =3D 0xcf9cc000 "=A4\201\001", bio_flags =3D 4, bio_error =3D 0= ,=20 bio_resid =3D 16384, bio_done =3D 0xc06bc5c0 , bio_driver1 = =3D 0x0,=20 bio_driver2 =3D 0x0, bio_caller1 =3D 0x0, bio_caller2 =3D 0xcec33148,= =20 bio_queue =3D {tqe_next =3D 0x0, tqe_prev =3D 0x0}, bio_attribute =3D 0= x0,=20 bio_from =3D 0x0, bio_to =3D 0x0, bio_length =3D 0, bio_completed =3D 0= ,=20 bio_children =3D 203, bio_inbed =3D 0, bio_parent =3D 0x0, bio_t0 =3D {= sec =3D 0,=20 frac =3D 0}, bio_task =3D 0, bio_task_arg =3D 0x0, bio_pblkno =3D 0},= =20 b_op =3D 0xc090d1c8, b_magic =3D 280038160, b_iodone =3D 0, b_blkno =3D 2= 4087168,=20 b_offset =3D 12332630016, b_vnbufs =3D {tqe_next =3D 0xcec8c3d8,=20 tqe_prev =3D 0xced2c724}, b_left =3D 0x0, b_right =3D 0x0, b_vflags =3D= 1,=20 b_freelist =3D {tqe_next =3D 0xced292f0, tqe_prev =3D 0xc09711b0}, b_qind= ex =3D 0,=20 b_flags =3D 553779236, b_xflags =3D 2 '\002', b_lock =3D { lk_interlock =3D 0xc096ccc0, lk_flags =3D 1024, lk_sharecount =3D 0,=20 lk_waitcount =3D 0, lk_exclusivecount =3D 1, lk_prio =3D 80,=20 lk_wmesg =3D 0xc08b2022 "bufwait", lk_timo =3D 0, lk_lockholder =3D 0xf= ffffffe,=20 lk_newlock =3D 0x0}, b_bufsize =3D 16384, b_runningbufspace =3D 16384,= =20 b_kvabase =3D 0xcf9cc000 "=A4\201\001", b_kvasize =3D 16384, b_lblkno =3D= 24087168,=20 b_vp =3D 0xc49c4514, b_object =3D 0xc10396b4, b_dirtyoff =3D 0, b_dirtyen= d =3D 0,=20 b_rcred =3D 0x0, b_wcred =3D 0x0, b_saveaddr =3D 0xcf9cc000, b_pager =3D = { pg_reqpage =3D 0}, b_cluster =3D {cluster_head =3D {tqh_first =3D 0x0,= =20 tqh_last =3D 0x0}, cluster_entry =3D {tqe_next =3D 0x0, tqe_prev =3D = 0x0}},=20 b_pages =3D {0xc159fb98, 0xc12ebde0, 0xc1387228, 0xc15b4970,=20 ---Type to continue, or q to quit---in=08 =08=08 =08 0x0 }, b_npages =3D 4, b_dep =3D {lh_first =3D 0xc58c= 2880}} (kgdb) inspect *vp $8 =3D {v_interlock =3D {mtx_object =3D {lo_class =3D 0xc0907c5c,=20 lo_name =3D 0xc08b38f0 "vnode interlock",=20 lo_type =3D 0xc08b38f0 "vnode interlock", lo_flags =3D 196608, lo_lis= t =3D { tqe_next =3D 0x0, tqe_prev =3D 0x0}, lo_witness =3D 0x0}, mtx_lock = =3D 4,=20 mtx_recurse =3D 0}, v_iflag =3D 0, v_usecount =3D 27264, v_numoutput = =3D 1,=20 v_vxproc =3D 0x0, v_holdcnt =3D 151, v_cleanblkhd =3D {tqh_first =3D 0xce= d5e5b8,=20 tqh_last =3D 0xcebf8ca4}, v_cleanblkroot =3D 0xced66330, v_cleanbufcnt = =3D 150,=20 v_dirtyblkhd =3D {tqh_first =3D 0x0, tqh_last =3D 0xc49c455c},=20 v_dirtyblkroot =3D 0x0, v_dirtybufcnt =3D 0, v_vflag =3D 8, v_writecount = =3D 0,=20 v_object =3D 0xc10396b4, v_lastw =3D 0, v_cstart =3D 0, v_lasta =3D 0, v_= clen =3D 0,=20 v_un =3D {vu_mountedhere =3D 0xc486a300, vu_socket =3D 0xc486a300, vu_spe= c =3D { vu_cdev =3D 0xc486a300, vu_specnext =3D {sle_next =3D 0x0}},=20 vu_fifoinfo =3D 0xc486a300}, v_freelist =3D {tqe_next =3D 0xc49c4410,= =20 tqe_prev =3D 0xc4991cb8}, v_nmntvnodes =3D {tqe_next =3D 0xc49c4410,=20 tqe_prev =3D 0xc4946090}, v_synclist =3D {le_next =3D 0x0,=20 le_prev =3D 0xc47e6804}, v_type =3D VCHR, v_tag =3D 0xc08a73c1 "devfs",= =20 v_data =3D 0xc4968580, v_lock =3D {lk_interlock =3D 0xc096cf90,=20 lk_flags =3D 16778240, lk_sharecount =3D 0, lk_waitcount =3D 0,=20 lk_exclusivecount =3D 1, lk_prio =3D 80, lk_wmesg =3D 0xc08a73c1 "devfs= ",=20 lk_timo =3D 6, lk_lockholder =3D 0xc1d32dc0, lk_newlock =3D 0x0},=20 v_vnlock =3D 0xc49c45c0, v_op =3D 0xc480cc00, v_mount =3D 0xc481e000,=20 v_cache_src =3D {lh_first =3D 0x0}, v_cache_dst =3D {tqh_first =3D 0x0,= =20 tqh_last =3D 0xc49c45f4}, v_id =3D 339, v_dd =3D 0xc49c4514, v_ddid =3D= 0,=20 v_pollinfo =3D 0x0, v_label =3D 0xc49676b8, v_cachedfs =3D 4294967295,=20 ---Type to continue, or q to quit--- v_cachedid =3D 97} (kgdb) inspect *vp->v_mount $9 =3D {mnt_list =3D {tqe_next =3D 0xc4824800, tqe_prev =3D 0xc090e748},=20 mnt_op =3D 0xc0901420, mnt_vfc =3D 0xc0901460, mnt_vnodecovered =3D 0xc49= 45d34,=20 mnt_syncer =3D 0xc4945b2c, mnt_nvnodelist =3D {tqh_first =3D 0xc4b10924,= =20 tqh_last =3D 0xc4ff6298}, mnt_reservedvnlist =3D {tqh_first =3D 0x0,=20 tqh_last =3D 0xc481e020}, mnt_lock =3D {lk_interlock =3D 0xc096c7f8,=20 lk_flags =3D 16777216, lk_sharecount =3D 0, lk_waitcount =3D 0,=20 lk_exclusivecount =3D 0, lk_prio =3D 80, lk_wmesg =3D 0xc08b326b "vfslo= ck",=20 lk_timo =3D 0, lk_lockholder =3D 0xffffffff, lk_newlock =3D 0x0}, mnt_m= tx =3D { mtx_object =3D {lo_class =3D 0xc0907c5c,=20 lo_name =3D 0xc08b325a "struct mount mtx",=20 lo_type =3D 0xc08b325a "struct mount mtx", lo_flags =3D 196608, lo_li= st =3D { tqe_next =3D 0x0, tqe_prev =3D 0x0}, lo_witness =3D 0x0}, mtx_lock = =3D 4,=20 mtx_recurse =3D 0}, mnt_writeopcount =3D 1, mnt_flag =3D 67112960,=20 mnt_opt =3D 0xc4938260, mnt_optnew =3D 0x0, mnt_kern_flag =3D 0,=20 mnt_maxsymlinklen =3D 0, mnt_stat =3D {f_version =3D 537068824, f_type = =3D 1,=20 f_flags =3D 67112960, f_bsize =3D 512, f_iosize =3D 512, f_blocks =3D 2= ,=20 f_bfree =3D 0, f_bavail =3D 0, f_files =3D 0, f_ffree =3D 0, f_syncwrit= es =3D 0,=20 f_asyncwrites =3D 0, f_syncreads =3D 0, f_asyncreads =3D 0, f_spare =3D= {0, 0, 0,=20 0, 0, 0, 0, 0, 0, 0}, f_namemax =3D 255, f_owner =3D 0, f_fsid =3D {v= al =3D { 16842496, 1}}, f_charspare =3D '\0' ,=20 f_fstypename =3D "devfs\0\0\0\0\0\0\0\0\0\0",=20 f_mntfromname =3D "devfs", '\0' ,=20 f_mntonname =3D "/dev", '\0' }, mnt_cred =3D 0xc486c8= 00,=20 mnt_data =3D 0xc486c580, mnt_time =3D 0, mnt_iosize_max =3D 65536,=20 ---Type to continue, or q to quit--- mnt_export =3D 0x0, mnt_mntlabel =3D 0xc1d184ec, mnt_fslabel =3D 0xc1d184= d8,=20 mnt_nvnodelistsize =3D 37} (kgdb) up #6 0xc06356e2 in spec_specstrategy (ap=3D0xd7830bf0) at /usr/src/sys/fs/specfs/spec_vnops.c:534 534=09=09return spec_xstrategy(ap->a_vp, ap->a_bp); (kgdb) up #7 0xc0634828 in spec_vnoperate (ap=3D0x0) at /usr/src/sys/fs/specfs/spec_vnops.c:122 122=09=09return (VOCALL(spec_vnodeop_p, ap->a_desc->vdesc_offset, ap)); (kgdb) up #8 0xc06b8324 in bwrite (bp=3D0xd7830bf0) at vnode_if.h:1141 1141=09vnode_if.h: No such file or directory. =09in vnode_if.h (kgdb) up #9 0xc06ba152 in vfs_bio_awrite (bp=3D0xcec33148) at /usr/src/sys/kern/vfs_bio.c:1715 1715=09=09(void) BUF_WRITE(bp); (kgdb) up #10 0xc06c2307 in vop_stdfsync (ap=3D0xd7830cd4) at /usr/src/sys/kern/vfs_default.c:738 738=09=09=09=09vfs_bio_awrite(bp); (kgdb) up #11 0xc06353e0 in spec_fsync (ap=3D0xd7830cd4) at /usr/src/sys/fs/specfs/spec_vnops.c:422 422=09=09return (vop_stdfsync(ap)); (kgdb) up #12 0xc0634828 in spec_vnoperate (ap=3D0x0) at /usr/src/sys/fs/specfs/spec_vnops.c:122 122=09=09return (VOCALL(spec_vnodeop_p, ap->a_desc->vdesc_offset, ap)); (kgdb) up #13 0xc06ca516 in sched_sync () at vnode_if.h:627 627=09vnode_if.h: No such file or directory. =09in vnode_if.h (kgdb) up #14 0xc065b2f4 in fork_exit (callout=3D0xc06ca290 , arg=3D0x0,= =20 frame=3D0x0) at /usr/src/sys/kern/kern_fork.c:793 793=09=09callout(arg, frame); (kgdb) up Initial frame selected; you cannot go up. (kgdb) quit Script done on Wed Dec 3 08:06:40 2003