panic in vfs_subr.c / ffs_inode.c / ufs_inode.c / ...

From: Thierry Herbelot <thierry_at_herbelot.com>
Date: Mon, 18 Jul 2005 14:29:16 +0200
Hello,

With a recent i386 GENERIC -current running on an SMP machine, I get this 
panic : bp 0xc2f038a8 wrong b_bufobj 0xc14972e0 should be 0xc1ec7500

I was rebuilding the world when the machine panic'ed.

	TfH

PS : on http://herbelot.tfh.free.fr/panic_vfs/
MD5 : md5 sums of the other 3 files
kernel.debug.gz (10M) : compressed debug kernel
sys.tbz (16M) : compressed archive of the source used for the kernel
vmcore.156.gz (23M)  : compressed memory dump

PS2 : Here follows a log :

Copyright (c) 1992-2005 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
        The Regents of the University of California. All rights reserved.
FreeBSD 7.0-CURRENT #724: Mon Jul 18 08:01:16 CEST 2005
    XXX_at_YYY:/usr/obj_ini/usr/src/sys/GENERIC
WARNING: WITNESS option enabled, expect reduced performance.
MPTable: <OEM00000 PROD00000000>
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: Pentium II/Pentium II Xeon/Celeron (334.09-MHz 686-class CPU)
  Origin = "GenuineIntel"  Id = 0x665  Stepping = 5
  
Features=0x183fbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR>
real memory  = 100663296 (96 MB)
avail memory = 88854528 (84 MB)
...

panic: bp 0xc2f038a8 wrong b_bufobj 0xc14972e0 should be 0xc1ec7500
cpuid = 1
KDB: enter: panic
[thread pid 50 tid 100038 ]
Stopped at      kdb_enter+0x2b: nop
db> where
Tracing pid 50 tid 100038 td 0xc12aaa80
kdb_enter(c0855ca9) at kdb_enter+0x2b
panic(c085d895,c2f038a8,c14972e0,c1ec7500,23) at panic+0x127
flushbuflist(c1ec7504,4,c1ec7500,0,0) at flushbuflist+0x10d
bufobj_invalbuf(c1ec7500,4,c12aaa80,0,0) at bufobj_invalbuf+0x111
vinvalbuf(c1ec7440,4,c12aaa80,0,0,c167a738,0,0,800) at vinvalbuf+0x1d
ffs_truncate(c1ec7440,0,0,c00,0) at ffs_truncate+0x56a
ufs_inactive(c722bc10) at ufs_inactive+0x99
VOP_INACTIVE_APV(c08f45e0,c722bc10) at VOP_INACTIVE_APV+0x7e
vinactive(c1ec7440,c12aaa80) at vinactive+0x72
vput(c1ec7440,c097a6e0,0,c086d7fe,d4c) at vput+0x154
handle_workitem_remove(c18e92c0,0) at handle_workitem_remove+0x10b
process_worklist_item(0,0) at process_worklist_item+0x181
softdep_process_worklist(0) at softdep_process_worklist+0xf4
sched_sync(0,c722bd38,0,c0684b80,0) at sched_sync+0x25e
fork_exit(c0684b80,0,c722bd38) at fork_exit+0xa0
fork_trampoline() at fork_trampoline+0x8
--- trap 0x1, eip = 0, esp = 0xc722bd6c, ebp = 0 ---
db> call doadump
Dumping 95 MB (2 chunks)
  chunk 0: 1MB (159 pages) ... ok
  chunk 1: 95MB (24320 pages) 80 64 48 32 16 ... ok

Dump complete
= 0xf
db>

--------------------

# kgdb kernel.debug /files3/tmp/vmcore.156
[GDB will not be able to debug user-mode threads: /usr/lib/libthread_db.so: 
Undefined symbol "ps_pglobal_lookup"]
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 "i386-marcel-freebsd".
#0  doadump () at pcpu.h:165
165             __asm __volatile("movl %%fs:0,%0" : "=r" (td));
(kgdb) where
#0  doadump () at pcpu.h:165
#1  0xc0468e93 in db_fncall (dummy1=0, dummy2=0, dummy3=-1067147741, 
dummy4=0xc722b7c4 "ø·\"Ç")    at /usr/src/sys/ddb/db_command.c:489
#2  0xc0468c98 in db_command (last_cmdp=0xc0903e64, cmd_table=0x0, 
aux_cmd_tablep=0xc0881314,    aux_cmd_tablep_end=0xc0881330) 
at /usr/src/sys/ddb/db_command.c:349
#3  0xc0468d60 in db_command_loop () at /usr/src/sys/ddb/db_command.c:455
#4  0xc046a901 in db_trap (type=3, code=0) at /usr/src/sys/ddb/db_main.c:221
#5  0xc064a0bc in kdb_trap (type=3, code=0, tf=0xc722b908) 
at /usr/src/sys/kern/subr_kdb.c:473
#6  0xc07ed490 in trap (frame=
      {tf_fs = -954073080, tf_es = -1067188184, tf_ds = -1065025496, tf_edi = 
-1064970091, tf_esi = 1, tf_ebp = -954025656, tf_isp = -954025676, tf_ebx = 
-954025612, tf_edx = 0, tf_ecx = -1056755712, tf_eax = 18, tf_trapno = 3, 
tf_err = 0, tf_eip = -1067147741, tf_cs = 32, tf_eflags = 646, tf_esp = 
-954025624, tf_ss = -1067245029}) at /usr/src/sys/i386/i386/trap.c:601
#7  0xc07daf4a in calltrap () at /usr/src/sys/i386/i386/exception.s:139
#8  0xc7220008 in ?? ()
#9  0xc0640028 in link_elf_init (arg=0xc0855ca9) 
at /usr/src/sys/kern/link_elf.c:284
#10 0xc063221b in panic (fmt=0x286 <Address 0x286 out of bounds>)
    at /usr/src/sys/kern/kern_shutdown.c:537
#11 0xc0683e41 in flushbuflist (bufv=0x0, flags=4, bo=0xc1ec7500, slpflag=0, 
slptimeo=0)    at /usr/src/sys/kern/vfs_subr.c:1057
#12 0xc0683b31 in bufobj_invalbuf (bo=0xc1ec7500, flags=4, td=0xc12aaa80, 
slpflag=0,    slptimeo=0) at /usr/src/sys/kern/vfs_subr.c:966
#13 0xc0683d31 in vinvalbuf (vp=0xc1ec7440, flags=4, td=0xc12aaa80, slpflag=0, 
slptimeo=0)    at /usr/src/sys/kern/vfs_subr.c:1024
#14 0xc075c0de in ffs_truncate (vp=0xc1ec7440, length=0, flags=3072, cred=0x0, 
td=0xc12aaa80)    at /usr/src/sys/ufs/ffs/ffs_inode.c:279
---Type <return> to continue, or q <return> to quit---
#15 0xc0773959 in ufs_inactive (ap=0x0) at /usr/src/sys/ufs/ufs/ufs_inode.c:95
#16 0xc07fda86 in VOP_INACTIVE_APV (vop=0x0, a=0xc722bc10) at vnode_if.c:1535
#17 0xc068581e in vinactive (vp=0xc1ec7440, td=0x0) at vnode_if.h:795
#18 0xc0685680 in vput (vp=0xc1ec7440) at /usr/src/sys/kern/vfs_subr.c:2047
#19 0xc076716f in handle_workitem_remove (dirrem=0xc18e92c0, xp=0x0)
    at /usr/src/sys/ufs/ffs/ffs_softdep.c:3405
#20 0xc07631c1 in process_worklist_item (matchmnt=0x0, flags=0)
    at /usr/src/sys/ufs/ffs/ffs_softdep.c:825
#21 0xc0762f28 in softdep_process_worklist (matchmnt=0x0)
    at /usr/src/sys/ufs/ffs/ffs_softdep.c:700
#22 0xc0684dde in sched_sync () at /usr/src/sys/kern/vfs_subr.c:1621
#23 0xc061eea4 in fork_exit (callout=0xc0684b80 <sched_sync>, arg=0x0, 
frame=0xc722bd38)
    at /usr/src/sys/kern/kern_fork.c:789
#24 0xc07dafac in fork_trampoline () at /usr/src/sys/i386/i386/exception.s:208
(kgdb) frame 11
#11 0xc0683e41 in flushbuflist (bufv=0x0, flags=4, bo=0xc1ec7500, slpflag=0, 
slptimeo=0)
    at /usr/src/sys/kern/vfs_subr.c:1057
1057                    KASSERT(bp->b_bufobj == bo,
(kgdb) list
1052                        "flushbuf", slpflag, slptimeo);
1053                    if (error) {
1054                            BO_LOCK(bo);
1055                            return (error != ENOLCK ? error : EAGAIN);
1056                    }
1057                    KASSERT(bp->b_bufobj == bo,
1058                        ("bp %p wrong b_bufobj %p should be %p",
1059                        bp, bp->b_bufobj, bo));
1060                    if (bp->b_bufobj != bo) {       /* XXX: necessary ? */
1061                            BUF_UNLOCK(bp);
(kgdb) print *bp
$1 = {b_bufobj = 0xc14972e0, b_bcount = 4096, b_caller1 = 0x0, b_data = 
0xc399d000 "ÌK",  b_error = 0, b_iocmd = 1 '\001', b_ioflags = 0 '\0', 
b_iooffset = 3853975552, b_resid = 0,  b_iodone = 0, b_blkno = 0, b_offset = 
0, b_bobufs = {tqe_next = 0x0, tqe_prev = 0xc14972e4},  b_left = 0x0, b_right 
= 0x0, b_vflags = 0, b_freelist = {tqe_next = 0x0,    tqe_prev = 0xc2eea934}, 
b_qindex = 1, b_flags = 536870944, b_xflags = 2 '\002', b_lock = 
{    lk_interlock = 0xc091e11c, lk_flags = 262144, lk_sharecount = 0, 
lk_waitcount = 0,    lk_exclusivecount = 1, lk_prio = 80, lk_wmesg = 
0xc085ee56 "flushbuf", lk_timo = 0,    lk_lockholder = 0xc12aaa80, lk_newlock 
= 0x0}, b_bufsize = 4096, b_runningbufspace = 0,  b_kvabase = 0xc399d000 
"ÌK", b_kvasize = 16384, b_lblkno = 0, b_vp = 0xc1497220,  b_dirtyoff = 0, 
b_dirtyend = 0, b_rcred = 0x0, b_wcred = 0x0, b_saveaddr = 0xc399d000,
  b_pager = {pg_reqpage = 0}, b_cluster = {cluster_head = {tqh_first = 
0xc2f1ff80,      tqh_last = 0xc2eea9a0}, cluster_entry = {tqe_next = 
0xc2f1ff80, tqe_prev = 0xc2eea9a0}},  b_pages = {0xc114cc90, 0x0 <repeats 31 
times>}, b_npages = 1, b_dep = {lh_first = 0x0}}
(kgdb)frame 14
#14 0xc075c0de in ffs_truncate (vp=0xc1ec7440, length=0, flags=3072, cred=0x0, 
td=0xc12aaa80)
    at /usr/src/sys/ufs/ffs/ffs_inode.c:279
279                             vinvalbuf(vp, needextclean ? 0 : V_NORMAL, td, 
0, 0);
(kgdb) list
274                             (void) chkdq(ip, -datablocks, NOCRED, 0);
275     #endif
276                             softdep_setup_freeblocks(ip, length, 
needextclean ?
277                                 IO_EXT | IO_NORMAL : IO_NORMAL);
278                             ASSERT_VOP_LOCKED(vp, "ffs_truncate1");
279                             vinvalbuf(vp, needextclean ? 0 : V_NORMAL, td, 
0, 0);
280                             vnode_pager_setsize(vp, 0);
281                             ip->i_flag |= IN_CHANGE | IN_UPDATE;
282                             return (ffs_update(vp, 0));
283                     }
(kgdb) print *vp
$2 = {v_type = VREG, v_tag = 0xc085cc57 "ufs", v_op = 0xc08f45e0, v_data = 
0xc167a738,  v_mount = 0xc1452000, v_nmntvnodes = {tqe_next = 0xc199b330, 
tqe_prev = 0xc14f2784}, v_un = {    vu_mount = 0x0, vu_socket = 0x0, vu_cdev 
= 0x0, vu_fifoinfo = 0x0}, v_hashlist = {    le_next = 0xc1e89990, le_prev = 
0xc13d70c4}, v_hash = 13602, v_cache_src = {    lh_first = 0x0}, v_cache_dst 
= {tqh_first = 0x0, tqh_last = 0xc1ec7470}, v_dd = 0x0,  v_cstart = 0, 
v_lasta = 0, v_lastw = 0, v_clen = 0, v_lock = {lk_interlock = 0xc091ed34,
    lk_flags = 262208, lk_sharecount = 0, lk_waitcount = 0, lk_exclusivecount 
= 1,    lk_prio = 80, lk_wmesg = 0xc085cc57 "ufs", lk_timo = 51, 
lk_lockholder = 0xc12aaa80,    lk_newlock = 0x0}, v_interlock = {mtx_object = 
{lo_class = 0xc08ba7c4,      lo_name = 0xc0859545 "vnode interlock", lo_type 
= 0xc0859545 "vnode interlock",      lo_flags = 196608, lo_list = {tqe_next = 
0xc14f218c, tqe_prev = 0xc14f27fc},      lo_witness = 0xc092fec8}, mtx_lock = 
4, mtx_recurse = 0}, v_vnlock = 0xc1ec7498,  v_holdcnt = 20, v_usecount = 0, 
v_iflag = 2048, v_vflag = 0, v_writecount = 0, v_freelist = {    tqe_next = 
0x0, tqe_prev = 0x0}, v_bufobj = {bo_mtx = 0xc1ec74bc, bo_clean = {bv_hd = 
{       tqh_first = 0xc2f1ff80, tqh_last = 0xc2ed8128}, bv_root = 0xc2ef0528, 
bv_cnt = 18},    bo_dirty = {bv_hd = {tqh_first = 0x0, tqh_last = 
0xc1ec7514}, bv_root = 0x0, bv_cnt = 0},    bo_numoutput = 0, bo_flag = 0, 
bo_ops = 0xc08c1564, bo_bsize = 16384,    bo_object = 0xc1e8e7bc, bo_synclist 
= {le_next = 0x0, le_prev = 0x0},    bo_private = 0xc1ec7440, __bo_vnode = 
0xc1ec7440}, v_pollinfo = 0x0, v_label = 0x0}
(kgdb) 

--------------------

# ident kernel.debug | grep vfs_subr.c
     $FreeBSD: src/sys/kern/vfs_subr.c,v 1.635 2005/07/05 15:57:55 pjd Exp $
# ident kernel.debug | grep ffs_inode.c
     $FreeBSD: src/sys/ufs/ffs/ffs_inode.c,v 1.106 2005/04/05 08:49:41 jeff 
Exp $
# ident kernel.debug | grep ufs_inode.c
     $FreeBSD: src/sys/ufs/ufs/ufs_inode.c,v 1.63 2005/03/17 11:58:43 jeff Exp 
$
# ident kernel.debug | grep ffs_softdep.c
     $FreeBSD: src/sys/ufs/ffs/ffs_softdep.c,v 1.181 2005/05/03 11:03:29 jeff 
Exp $
# ident kernel.debug | grep kern_fork.c
     $FreeBSD: src/sys/kern/kern_fork.c,v 1.252 2005/07/01 16:28:30 ssouhlal 
Exp $

--------------------
/etc/fstab :

# Device                Mountpoint      FStype  Options         Dump    Pass#
/dev/ad0s2b             none            swap    sw              0       0
/dev/ad8s2b             none            swap    sw              0       0
/dev/ad10s2b            none            swap    sw              0       0

# partitions on an ad8/ad10 geom mirror
/dev/mirror/gm0s1a      /               ufs     rw              1       1
/dev/mirror/gm0s1d      /tmp            ufs     rw              2       2
/dev/mirror/gm0s1f      /usr            ufs     rw              2       2
/dev/mirror/gm0s1e      /var            ufs     rw              2       2
Received on Mon Jul 18 2005 - 10:29:31 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:38:39 UTC