Date: Wed, 3 Dec 2003 08:19:54 -0500 (EST) From: Robert Watson <rwatson@FreeBSD.org> To: kirk@mckusick.com Cc: current@FreeBSD.org Subject: panic: initiate_write_inodeblock_ufs2: already started Message-ID: <Pine.NEB.3.96L.1031203081806.82018B-100000@fledge.watson.org>
next in thread | raw e-mail | index | archive | help
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 <sched_sync>, arg=3D0x0,=
=20
---Type <return> to continue, or q <return> 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 <bufdonebio>, 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 <return> to continue, or q <return> to quit---in=08 =08=08 =08
0x0 <repeats 28 times>}, 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 <return> to continue, or q <return> 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' <repeats 79 times>,=20
f_fstypename =3D "devfs\0\0\0\0\0\0\0\0\0\0",=20
f_mntfromname =3D "devfs", '\0' <repeats 82 times>,=20
f_mntonname =3D "/dev", '\0' <repeats 83 times>}, mnt_cred =3D 0xc486c8=
00,=20
mnt_data =3D 0xc486c580, mnt_time =3D 0, mnt_iosize_max =3D 65536,=20
---Type <return> to continue, or q <return> 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 <sched_sync>, 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
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?Pine.NEB.3.96L.1031203081806.82018B-100000>