panic: initiate_write_inodeblock_ufs2: already started

From: Robert Watson <rwatson_at_FreeBSD.org>
Date: Wed, 3 Dec 2003 08:19:54 -0500 (EST)
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...) 

Robert N M Watson             FreeBSD Core Team, TrustedBSD Projects
robert_at_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 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 "i386-undermydesk-freebsd"...
panic: initiate_write_inodeblock_ufs2: already started
panic messages:
---
panic: initiate_write_inodeblock_ufs2: already started
cpuid = 0; 

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 
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 256 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/modules/mac_biba/mac_biba.ko.debug...done.
Loaded symbols for /usr/obj/usr/src/sys/PAPRIKAMAC/modules/usr/src/sys/modules/mac_biba/mac_biba.ko.debug
Reading symbols from /usr/obj/usr/src/sys/PAPRIKAMAC/modules/usr/src/sys/modules/mac_mls/mac_mls.ko.debug...done.
Loaded symbols for /usr/obj/usr/src/sys/PAPRIKAMAC/modules/usr/src/sys/modules/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/modules/linprocfs/linprocfs.ko.debug...done.
Loaded symbols for /usr/obj/usr/src/sys/PAPRIKAMAC/modules/usr/src/sys/modules/linprocfs/linprocfs.ko.debug
Reading symbols from /usr/obj/usr/src/sys/PAPRIKAMAC/modules/usr/src/sys/modules/linux/linux.ko.debug...done.
Loaded symbols for /usr/obj/usr/src/sys/PAPRIKAMAC/modules/usr/src/sys/modules/linux/linux.ko.debug
#0  doadump () at /usr/src/sys/kern/kern_shutdown.c:240
240		dumping++;
(kgdb) bt
#0  doadump () at /usr/src/sys/kern/kern_shutdown.c:240
#1  0xc0671987 in boot (howto=256) at /usr/src/sys/kern/kern_shutdown.c:372
#2  0xc0671d8d in panic () at /usr/src/sys/kern/kern_shutdown.c:550
#3  0xc07cf179 in initiate_write_inodeblock_ufs2 (inodedep=0xc58c2880, bp=0x0)
    at /usr/src/sys/ufs/ffs/ffs_softdep.c:3902
#4  0xc07ce30d in softdep_disk_io_initiation (bp=0xcec33148)
    at /usr/src/sys/ufs/ffs/ffs_softdep.c:3468
#5  0xc0635547 in spec_xstrategy (vp=0xc49c4514, bp=0xcec33148)
    at /usr/src/sys/sys/buf.h:413
#6  0xc06356e2 in spec_specstrategy (ap=0xd7830bf0)
    at /usr/src/sys/fs/specfs/spec_vnops.c:534
#7  0xc0634828 in spec_vnoperate (ap=0x0)
    at /usr/src/sys/fs/specfs/spec_vnops.c:122
#8  0xc06b8324 in bwrite (bp=0xd7830bf0) at vnode_if.h:1141
#9  0xc06ba152 in vfs_bio_awrite (bp=0xcec33148)
    at /usr/src/sys/kern/vfs_bio.c:1715
#10 0xc06c2307 in vop_stdfsync (ap=0xd7830cd4)
    at /usr/src/sys/kern/vfs_default.c:738
#11 0xc06353e0 in spec_fsync (ap=0xd7830cd4)
    at /usr/src/sys/fs/specfs/spec_vnops.c:422
#12 0xc0634828 in spec_vnoperate (ap=0x0)
    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=0xc06ca290 <sched_sync>, arg=0x0, 
---Type <return> to continue, or q <return> to quit---
    frame=0x0) at /usr/src/sys/kern/kern_fork.c:793
(kgdb) up
#1  0xc0671987 in boot (howto=256) at /usr/src/sys/kern/kern_shutdown.c:372
372			doadump();
(kgdb) up
#2  0xc0671d8d in panic () at /usr/src/sys/kern/kern_shutdown.c:550
550		boot(bootopt);
(kgdb) up
#3  0xc07cf179 in initiate_write_inodeblock_ufs2 (inodedep=0xc58c2880, bp=0x0)
    at /usr/src/sys/ufs/ffs/ffs_softdep.c:3902
3902					panic("softdep_write_inodeblock: lost dep3");
(kgdb) list
3897			for (i = 0; i < NIADDR; i++) {
3898	#ifdef DIAGNOSTIC
3899				if (dp->di_ib[i] != 0 &&
3900				    (deplist & ((1 << NDADDR) << i)) == 0) {
3901					FREE_LOCK(&lk);
3902					panic("softdep_write_inodeblock: lost dep3");
3903				}
3904	#endif /* DIAGNOSTIC */
3905				dp->di_ib[i] = 0;
3906			}
(kgdb) inspect i
$1 = -2917476963376682880
(kgdb) inspect deplist
$2 = 291
(kgdb) up
#4  0xc07ce30d in softdep_disk_io_initiation (bp=0xcec33148)
    at /usr/src/sys/ufs/ffs/ffs_softdep.c:3468
3468					initiate_write_inodeblock_ufs2(inodedep, bp);
(kgdb) list
3463			case D_INODEDEP:
3464				inodedep = WK_INODEDEP(wk);
3465				if (inodedep->id_fs->fs_magic == FS_UFS1_MAGIC)
3466					initiate_write_inodeblock_ufs1(inodedep, bp);
3467				else
3468					initiate_write_inodeblock_ufs2(inodedep, bp);
3469				continue;
3470	
3471			case D_INDIRDEP:
3472				indirdep = WK_INDIRDEP(wk);
(kgdb) inspect inodedep
$3 = (struct inodedep *) 0x0
(kgdb) inspect wk
$4 = (struct worklist *) 0xc58c2880
(kgdb) inspect *wk
$5 = {wk_list = {le_next = 0x0, le_prev = 0xcec332fc}, wk_type = 1, 
  wk_state = 33293}
(kgdb) inspect *wk.wk_state
---Can't read userspace from dump, or kernel process---

(kgdb) up
#5  0xc0635547 in spec_xstrategy (vp=0xc49c4514, bp=0xcec33148)
    at /usr/src/sys/sys/buf.h:413
413			(*bioops.io_start)(bp);
(kgdb) inspect bp
$6 = (struct buf *) 0xcec33148
(kgdb) inspect *bp
$7 = {b_io = {bio_cmd = 2, bio_dev = 0xc486a300, bio_disk = 0x0, 
    bio_offset = 12332630016, bio_bcount = 16384, 
    bio_data = 0xcf9cc000 "¤\201\001", bio_flags = 4, bio_error = 0, 
    bio_resid = 16384, bio_done = 0xc06bc5c0 <bufdonebio>, bio_driver1 = 0x0, 
    bio_driver2 = 0x0, bio_caller1 = 0x0, bio_caller2 = 0xcec33148, 
    bio_queue = {tqe_next = 0x0, tqe_prev = 0x0}, bio_attribute = 0x0, 
    bio_from = 0x0, bio_to = 0x0, bio_length = 0, bio_completed = 0, 
    bio_children = 203, bio_inbed = 0, bio_parent = 0x0, bio_t0 = {sec = 0, 
      frac = 0}, bio_task = 0, bio_task_arg = 0x0, bio_pblkno = 0}, 
  b_op = 0xc090d1c8, b_magic = 280038160, b_iodone = 0, b_blkno = 24087168, 
  b_offset = 12332630016, b_vnbufs = {tqe_next = 0xcec8c3d8, 
    tqe_prev = 0xced2c724}, b_left = 0x0, b_right = 0x0, b_vflags = 1, 
  b_freelist = {tqe_next = 0xced292f0, tqe_prev = 0xc09711b0}, b_qindex = 0, 
  b_flags = 553779236, b_xflags = 2 '\002', b_lock = {
    lk_interlock = 0xc096ccc0, lk_flags = 1024, lk_sharecount = 0, 
    lk_waitcount = 0, lk_exclusivecount = 1, lk_prio = 80, 
    lk_wmesg = 0xc08b2022 "bufwait", lk_timo = 0, lk_lockholder = 0xfffffffe, 
    lk_newlock = 0x0}, b_bufsize = 16384, b_runningbufspace = 16384, 
  b_kvabase = 0xcf9cc000 "¤\201\001", b_kvasize = 16384, b_lblkno = 24087168, 
  b_vp = 0xc49c4514, b_object = 0xc10396b4, b_dirtyoff = 0, b_dirtyend = 0, 
  b_rcred = 0x0, b_wcred = 0x0, b_saveaddr = 0xcf9cc000, b_pager = {
    pg_reqpage = 0}, b_cluster = {cluster_head = {tqh_first = 0x0, 
      tqh_last = 0x0}, cluster_entry = {tqe_next = 0x0, tqe_prev = 0x0}}, 
  b_pages = {0xc159fb98, 0xc12ebde0, 0xc1387228, 0xc15b4970, 
---Type <return> to continue, or q <return> to quit---in  
    0x0 <repeats 28 times>}, b_npages = 4, b_dep = {lh_first = 0xc58c2880}}
(kgdb) inspect *vp
$8 = {v_interlock = {mtx_object = {lo_class = 0xc0907c5c, 
      lo_name = 0xc08b38f0 "vnode interlock", 
      lo_type = 0xc08b38f0 "vnode interlock", lo_flags = 196608, lo_list = {
        tqe_next = 0x0, tqe_prev = 0x0}, lo_witness = 0x0}, mtx_lock = 4, 
    mtx_recurse = 0}, v_iflag = 0, v_usecount = 27264, v_numoutput = 1, 
  v_vxproc = 0x0, v_holdcnt = 151, v_cleanblkhd = {tqh_first = 0xced5e5b8, 
    tqh_last = 0xcebf8ca4}, v_cleanblkroot = 0xced66330, v_cleanbufcnt = 150, 
  v_dirtyblkhd = {tqh_first = 0x0, tqh_last = 0xc49c455c}, 
  v_dirtyblkroot = 0x0, v_dirtybufcnt = 0, v_vflag = 8, v_writecount = 0, 
  v_object = 0xc10396b4, v_lastw = 0, v_cstart = 0, v_lasta = 0, v_clen = 0, 
  v_un = {vu_mountedhere = 0xc486a300, vu_socket = 0xc486a300, vu_spec = {
      vu_cdev = 0xc486a300, vu_specnext = {sle_next = 0x0}}, 
    vu_fifoinfo = 0xc486a300}, v_freelist = {tqe_next = 0xc49c4410, 
    tqe_prev = 0xc4991cb8}, v_nmntvnodes = {tqe_next = 0xc49c4410, 
    tqe_prev = 0xc4946090}, v_synclist = {le_next = 0x0, 
    le_prev = 0xc47e6804}, v_type = VCHR, v_tag = 0xc08a73c1 "devfs", 
  v_data = 0xc4968580, v_lock = {lk_interlock = 0xc096cf90, 
    lk_flags = 16778240, lk_sharecount = 0, lk_waitcount = 0, 
    lk_exclusivecount = 1, lk_prio = 80, lk_wmesg = 0xc08a73c1 "devfs", 
    lk_timo = 6, lk_lockholder = 0xc1d32dc0, lk_newlock = 0x0}, 
  v_vnlock = 0xc49c45c0, v_op = 0xc480cc00, v_mount = 0xc481e000, 
  v_cache_src = {lh_first = 0x0}, v_cache_dst = {tqh_first = 0x0, 
    tqh_last = 0xc49c45f4}, v_id = 339, v_dd = 0xc49c4514, v_ddid = 0, 
  v_pollinfo = 0x0, v_label = 0xc49676b8, v_cachedfs = 4294967295, 
---Type <return> to continue, or q <return> to quit---
  v_cachedid = 97}
(kgdb) inspect *vp->v_mount
$9 = {mnt_list = {tqe_next = 0xc4824800, tqe_prev = 0xc090e748}, 
  mnt_op = 0xc0901420, mnt_vfc = 0xc0901460, mnt_vnodecovered = 0xc4945d34, 
  mnt_syncer = 0xc4945b2c, mnt_nvnodelist = {tqh_first = 0xc4b10924, 
    tqh_last = 0xc4ff6298}, mnt_reservedvnlist = {tqh_first = 0x0, 
    tqh_last = 0xc481e020}, mnt_lock = {lk_interlock = 0xc096c7f8, 
    lk_flags = 16777216, lk_sharecount = 0, lk_waitcount = 0, 
    lk_exclusivecount = 0, lk_prio = 80, lk_wmesg = 0xc08b326b "vfslock", 
    lk_timo = 0, lk_lockholder = 0xffffffff, lk_newlock = 0x0}, mnt_mtx = {
    mtx_object = {lo_class = 0xc0907c5c, 
      lo_name = 0xc08b325a "struct mount mtx", 
      lo_type = 0xc08b325a "struct mount mtx", lo_flags = 196608, lo_list = {
        tqe_next = 0x0, tqe_prev = 0x0}, lo_witness = 0x0}, mtx_lock = 4, 
    mtx_recurse = 0}, mnt_writeopcount = 1, mnt_flag = 67112960, 
  mnt_opt = 0xc4938260, mnt_optnew = 0x0, mnt_kern_flag = 0, 
  mnt_maxsymlinklen = 0, mnt_stat = {f_version = 537068824, f_type = 1, 
    f_flags = 67112960, f_bsize = 512, f_iosize = 512, f_blocks = 2, 
    f_bfree = 0, f_bavail = 0, f_files = 0, f_ffree = 0, f_syncwrites = 0, 
    f_asyncwrites = 0, f_syncreads = 0, f_asyncreads = 0, f_spare = {0, 0, 0, 
      0, 0, 0, 0, 0, 0, 0}, f_namemax = 255, f_owner = 0, f_fsid = {val = {
        16842496, 1}}, f_charspare = '\0' <repeats 79 times>, 
    f_fstypename = "devfs\0\0\0\0\0\0\0\0\0\0", 
    f_mntfromname = "devfs", '\0' <repeats 82 times>, 
    f_mntonname = "/dev", '\0' <repeats 83 times>}, mnt_cred = 0xc486c800, 
  mnt_data = 0xc486c580, mnt_time = 0, mnt_iosize_max = 65536, 
---Type <return> to continue, or q <return> to quit---
  mnt_export = 0x0, mnt_mntlabel = 0xc1d184ec, mnt_fslabel = 0xc1d184d8, 
  mnt_nvnodelistsize = 37}
(kgdb) up
#6  0xc06356e2 in spec_specstrategy (ap=0xd7830bf0)
    at /usr/src/sys/fs/specfs/spec_vnops.c:534
534		return spec_xstrategy(ap->a_vp, ap->a_bp);
(kgdb) up
#7  0xc0634828 in spec_vnoperate (ap=0x0)
    at /usr/src/sys/fs/specfs/spec_vnops.c:122
122		return (VOCALL(spec_vnodeop_p, ap->a_desc->vdesc_offset, ap));
(kgdb) up
#8  0xc06b8324 in bwrite (bp=0xd7830bf0) at vnode_if.h:1141
1141	vnode_if.h: No such file or directory.
	in vnode_if.h
(kgdb) up
#9  0xc06ba152 in vfs_bio_awrite (bp=0xcec33148)
    at /usr/src/sys/kern/vfs_bio.c:1715
1715		(void) BUF_WRITE(bp);
(kgdb) up
#10 0xc06c2307 in vop_stdfsync (ap=0xd7830cd4)
    at /usr/src/sys/kern/vfs_default.c:738
738				vfs_bio_awrite(bp);
(kgdb) up
#11 0xc06353e0 in spec_fsync (ap=0xd7830cd4)
    at /usr/src/sys/fs/specfs/spec_vnops.c:422
422		return (vop_stdfsync(ap));
(kgdb) up
#12 0xc0634828 in spec_vnoperate (ap=0x0)
    at /usr/src/sys/fs/specfs/spec_vnops.c:122
122		return (VOCALL(spec_vnodeop_p, ap->a_desc->vdesc_offset, ap));
(kgdb) up
#13 0xc06ca516 in sched_sync () at vnode_if.h:627
627	vnode_if.h: No such file or directory.
	in vnode_if.h
(kgdb) up
#14 0xc065b2f4 in fork_exit (callout=0xc06ca290 <sched_sync>, arg=0x0, 
    frame=0x0) at /usr/src/sys/kern/kern_fork.c:793
793		callout(arg, frame);
(kgdb) up
Initial frame selected; you cannot go up.
(kgdb) quit

Script done on Wed Dec  3 08:06:40 2003
Received on Wed Dec 03 2003 - 04:22:43 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:37:32 UTC