Hi. I updated my main -current box to the current sources as of yesterday, and I've managed to twice get the "wrong vnode panic" out of the cache_enter code. As you can see from the backtrace down at cache_enter at frame 11, the code is apparently expecting vp to point to a VDIR vnode, but instead it's pointing to a VLNK. (I've got another, similar, dump where vp is pointing to a VREG node.) In both cases, I was running tinderbox to build packages, with resulting heavy use of both zfs (the underlying filesystem) and nullfs, if that's relevant. Script started on Wed May 6 17:41:35 2009 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 "amd64-marcel-freebsd"... Unread portion of the kernel message buffer: panic: wrong vnode type 0xffffff011885b4e0 cpuid = 0 KDB: enter: panic exclusive rw Name Cache (Name Cache) r = 0 (0xffffffff80db98e0) locked _at_ /usr/src/sys/kern/vfs_cache.c:674 shared lockmgr zfs (zfs) r = 0 (0xffffff010c019098) locked _at_ /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_vnops.c:1201 exclusive lockmgr zfs (zfs) r = 0 (0xffffff011885b578) locked _at_ /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_vnops.c:1199 exclusive rw Name Cache (Name Cache) r = 0 (0xffffffff80db98e0) locked _at_ /usr/src/sys/kern/vfs_cache.c:674 shared lockmgr zfs (zfs) r = 0 (0xffffff010c019098) locked _at_ /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_vnops.c:1201 exclusive lockmgr zfs (zfs) r = 0 (0xffffff011885b578) locked _at_ /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_vnops.c:1199 exclusive sx so_rcv_sx (so_rcv_sx) r = 0 (0xffffff010c479b10) locked _at_ /usr/src/sys/kern/uipc_sockbuf.c:148 exclusive sx so_rcv_sx (so_rcv_sx) r = 0 (0xffffff006a338378) locked _at_ /usr/src/sys/kern/uipc_sockbuf.c:148 exclusive lockmgr bufwait (bufwait) r = 0 (0xffffffff003abe48) locked _at_ /usr/src/sys/vm/vm_pager.c:310 exclusive sx so_rcv_sx (so_rcv_sx) r = 0 (0xffffff006a338b10) locked _at_ /usr/src/sys/kern/uipc_sockbuf.c:148 exclusive sx so_rcv_sx (so_rcv_sx) r = 0 (0xffffff00ad503600) locked _at_ /usr/src/sys/kern/uipc_sockbuf.c:148 0xffffff010c019000: tag zfs, type VDIR usecount 5, writecount 0, refcount 6 mountedhere 0 flags () v_object 0xffffff00bd665708 ref 0 pages 0 lock type zfs: SHARED (count 1) #0 0xffffffff8054a4fa at __lockmgr_args+0x51a #1 0xffffffff805dbad9 at vop_stdlock+0x39 #2 0xffffffff8088a47b at VOP_LOCK1_APV+0x9b #3 0xffffffff805f7cb7 at _vn_lock+0x57 #4 0xffffffff81049b53 at zfs_lookup+0x303 #5 0xffffffff81049f51 at zfs_freebsd_lookup+0x81 #6 0xffffffff80888fef at VOP_CACHEDLOOKUP_APV+0xaf #7 0xffffffff805d9880 at vfs_cache_lookup+0xf0 #8 0xffffffff8088b347 at VOP_LOOKUP_APV+0xb7 #9 0xffffffff805e0324 at lookup+0x4d4 #10 0xffffffff805e1285 at namei+0x545 #11 0xffffffff805f78e2 at vn_open_cred+0x1b2 #12 0xffffffff805dc184 at vop_stdvptocnp+0x174 #13 0xffffffff80889139 at VOP_VPTOCNP_APV+0xb9 #14 0xffffffff805d86fb at vn_vptocnp+0xdb #15 0xffffffff805d8a54 at vn_fullpath1+0x244 #16 0xffffffff805d8eb4 at kern___getcwd+0xd4 #17 0xffffffff808419d7 at syscall+0x1e7 0xffffff011885b4e0: tag zfs, type VLNK usecount 1, writecount 0, refcount 1 mountedhere 0 flags () lock type zfs: EXCL by thread 0xffffff0051e05000 (pid 55596) #0 0xffffffff8054a738 at __lockmgr_args+0x758 #1 0xffffffff805dbad9 at vop_stdlock+0x39 #2 0xffffffff8088a47b at VOP_LOCK1_APV+0x9b #3 0xffffffff805f7cb7 at _vn_lock+0x57 #4 0xffffffff81049b28 at zfs_lookup+0x2d8 #5 0xffffffff81049f51 at zfs_freebsd_lookup+0x81 #6 0xffffffff80888fef at VOP_CACHEDLOOKUP_APV+0xaf #7 0xffffffff805d9880 at vfs_cache_lookup+0xf0 #8 0xffffffff8088b347 at VOP_LOOKUP_APV+0xb7 #9 0xffffffff805e0324 at lookup+0x4d4 #10 0xffffffff805e1285 at namei+0x545 #11 0xffffffff805f78e2 at vn_open_cred+0x1b2 #12 0xffffffff805dc184 at vop_stdvptocnp+0x174 #13 0xffffffff80889139 at VOP_VPTOCNP_APV+0xb9 #14 0xffffffff805d86fb at vn_vptocnp+0xdb #15 0xffffffff805d8a54 at vn_fullpath1+0x244 #16 0xffffffff805d8eb4 at kern___getcwd+0xd4 #17 0xffffffff808419d7 at syscall+0x1e7 Physical memory: 4012 MB Dumping 2299 MB: 2284 2268 2252 2236 2220 2204 2188 2172 2156 2140 2124 2108 2092 2076 2060 2044 2028 2012 1996 1980 1964 1948 1932 1916 1900 1884 1868 1852 1836 1820 1804 1788 1772 1756 1740 1724 1708 1692 1676 1660 1644 1628 1612 1596 1580 1564 1548 1532 1516 1500 1484 1468 1452 1436 1420 1404 1388 1372 1356 1340 1324 1308 1292 1276 1260 1244 1228 1212 1196 1180 1164 1148 1132 1116 1100 1084 1068 1052 1036 1020 1004 988 972 956 940 924 908 892 876 860 844 828 812 796 780 764 748 732 716 700 684 668 652 636 620 604 588 572 556 540 524 508 492 476 460 444 428 412 396 380 364 348 332 316 300 284 268 252 236 220 204 188 172 156 140 124 108 92 76 60 44 28 12 Reading symbols from /boot/kernel/zfs.ko...done. Loaded symbols for /boot/kernel/zfs.ko Reading symbols from /boot/kernel/opensolaris.ko...done. Loaded symbols for /boot/kernel/opensolaris.ko Reading symbols from /boot/kernel/geom_mirror.ko...done. Loaded symbols for /boot/kernel/geom_mirror.ko Reading symbols from /boot/kernel/snd_hda.ko...done. Loaded symbols for /boot/kernel/snd_hda.ko Reading symbols from /boot/kernel/sound.ko...done. Loaded symbols for /boot/kernel/sound.ko Reading symbols from /boot/kernel/coretemp.ko...done. Loaded symbols for /boot/kernel/coretemp.ko Reading symbols from /boot/kernel/atapicam.ko...done. Loaded symbols for /boot/kernel/atapicam.ko Reading symbols from /boot/kernel/tmpfs.ko...done. Loaded symbols for /boot/kernel/tmpfs.ko Reading symbols from /boot/kernel/linux.ko...done. Loaded symbols for /boot/kernel/linux.ko Reading symbols from /usr/local/modules/fuse.ko...done. Loaded symbols for /usr/local/modules/fuse.ko Reading symbols from /boot/kernel/green_saver.ko...done. Loaded symbols for /boot/kernel/green_saver.ko Reading symbols from /boot/kernel/radeon.ko...done. Loaded symbols for /boot/kernel/radeon.ko Reading symbols from /boot/kernel/drm.ko...done. Loaded symbols for /boot/kernel/drm.ko Reading symbols from /boot/kernel/nullfs.ko...done. Loaded symbols for /boot/kernel/nullfs.ko Reading symbols from /boot/kernel/linprocfs.ko...done. Loaded symbols for /boot/kernel/linprocfs.ko #0 doadump () at pcpu.h:223 223 __asm __volatile("movq %%gs:0,%0" : "=r" (td)); (kgdb) bt #0 doadump () at pcpu.h:223 #1 0xffffffff801cc59c in db_fncall (dummy1=Variable "dummy1" is not available. ) at /usr/src/sys/ddb/db_command.c:548 #2 0xffffffff801cc84d in db_command (last_cmdp=0xffffffff80bc36a0, cmd_table=Variable "cmd_table" is not available. ) at /usr/src/sys/ddb/db_command.c:445 #3 0xffffffff801d1043 in db_script_exec ( scriptname=0xffffffff2d7d9d50 "kdb.enter.panic", warnifnotfound=0) at /usr/src/sys/ddb/db_script.c:302 #4 0xffffffff801d1112 in db_script_kdbenter (eventname=Variable "eventname" is not available. ) at /usr/src/sys/ddb/db_script.c:324 #5 0xffffffff801ceac4 in db_trap (type=Variable "type" is not available. ) at /usr/src/sys/ddb/db_main.c:228 #6 0xffffffff8058f5d5 in kdb_trap (type=3, code=0, tf=0xffffffff2d7d9f70) at /usr/src/sys/kern/subr_kdb.c:534 #7 0xffffffff80842125 in trap (frame=0xffffffff2d7d9f70) at /usr/src/sys/amd64/amd64/trap.c:606 #8 0xffffffff8081cef3 in calltrap () at /usr/src/sys/amd64/amd64/exception.S:223 #9 0xffffffff8058f7ad in kdb_enter (why=0xffffffff80946c99 "panic", msg=0xa <Address 0xa out of bounds>) at cpufunc.h:63 #10 0xffffffff8055fe5b in panic (fmt=Variable "fmt" is not available. ) at /usr/src/sys/kern/kern_shutdown.c:559 #11 0xffffffff805d8542 in cache_enter (dvp=0xffffff010c019000, vp=0xffffff011885b4e0, cnp=0xffffffff2d7da908) at /usr/src/sys/kern/vfs_cache.c:702 #12 0xffffffff81049b95 in zfs_lookup (dvp=0xffffff010c019000, nm=0xffffffff2d7da230 "..", vpp=0xffffffff2d7da8e0, cnp=0xffffffff2d7da908, nameiop=0, cr=0xffffff0032a08a00, td=0xffffff0051e05000, flags=0) at /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_vnops.c:1221 #13 0xffffffff81049f51 in zfs_freebsd_lookup (ap=0xffffffff2d7da390) at /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_vnops.c:3988 #14 0xffffffff80888fef in VOP_CACHEDLOOKUP_APV (vop=0xffffffff810b22e0, a=0xffffffff2d7da390) at vnode_if.c:187 #15 0xffffffff805d9880 in vfs_cache_lookup (ap=Variable "ap" is not available. ) at vnode_if.h:80 #16 0xffffffff8088b347 in VOP_LOOKUP_APV (vop=0xffffffff810b22e0, a=0xffffffff2d7da460) at vnode_if.c:123 #17 0xffffffff805e0324 in lookup (ndp=0xffffffff2d7da8b0) at vnode_if.h:54 #18 0xffffffff805e1285 in namei (ndp=0xffffffff2d7da8b0) at /usr/src/sys/kern/vfs_lookup.c:256 #19 0xffffffff805f78e2 in vn_open_cred (ndp=0xffffffff2d7da8b0, flagp=0xffffffff2d7da9b8, cmode=0, cred=0xffffff0032a08a00, fp=0x0) at /usr/src/sys/kern/vfs_vnops.c:189 #20 0xffffffff805dc184 in vop_stdvptocnp (ap=Variable "ap" is not available. ) at /usr/src/sys/kern/vfs_default.c:707 #21 0xffffffff80889139 in VOP_VPTOCNP_APV (vop=0xffffffff80b7f560, a=0xffffffff2d7daa30) at vnode_if.c:3353 #22 0xffffffff805d86fb in vn_vptocnp (vp=0xffffffff2d7daab0, ---Type <return> to continue, or q <return> to quit--- bp=0xffffffff2d7daac0, buf=0xffffff00059ed800 'p' <repeats 200 times>..., buflen=0xffffffff2d7daaac) at vnode_if.h:1512 #23 0xffffffff805d8a54 in vn_fullpath1 (td=Variable "td" is not available. ) at /usr/src/sys/kern/vfs_cache.c:1168 #24 0xffffffff805d8eb4 in kern___getcwd (td=0xffffff0051e05000, buf=0x7fffffffe390 <Address 0x7fffffffe390 out of bounds>, bufseg=UIO_USERSPACE, buflen=1024) at /usr/src/sys/kern/vfs_cache.c:936 #25 0xffffffff808419d7 in syscall (frame=0xffffffff2d7dac90) at /usr/src/sys/amd64/amd64/trap.c:977 #26 0xffffffff8081d180 in Xfast_syscall () at /usr/src/sys/amd64/amd64/exception.S:364 #27 0x000000001892dcec in ?? () Previous frame inner to this frame (corrupt stack?) (kgdb) fr 11 #11 0xffffffff805d8542 in cache_enter (dvp=0xffffff010c019000, vp=0xffffff011885b4e0, cnp=0xffffffff2d7da908) at /usr/src/sys/kern/vfs_cache.c:702 702 KASSERT(vp == NULL || vp->v_type == VDIR, (kgdb) p *vp $1 = {v_type = VLNK, v_tag = 0xffffffff810ad73d "zfs", v_op = 0xffffffff810b22e0, v_data = 0xffffff006cfe9178, v_mount = 0xffffff00058e9388, v_nmntvnodes = {tqe_next = 0xffffff00c6b53750, tqe_prev = 0xffffff00c6b60c58}, v_un = {vu_mount = 0x0, vu_socket = 0x0, vu_cdev = 0x0, vu_fifoinfo = 0x0, vu_yield = 0}, v_hashlist = { le_next = 0x0, le_prev = 0x0}, v_hash = 0, v_cache_src = {lh_first = 0x0}, v_cache_dst = {tqh_first = 0xffffff00a6675770, tqh_last = 0xffffff00a6675790}, v_cache_dd = 0x0, v_cstart = 0, v_lasta = 0, v_lastw = 0, v_clen = 0, v_lock = {lock_object = { lo_name = 0xffffffff810ad73d "zfs", lo_flags = 91947009, lo_data = 0, lo_witness = 0xfffffffe40223200}, lk_lock = 18446742975571578880, lk_timo = 16, lk_pri = 80, lk_stack = {depth = 18, pcs = { 18446744071567615800, 18446744071568210649, 18446744071571022971, 18446744071568325815, 18446744071579147048, 18446744071579148113, 18446744071571017711, 18446744071568201856, 18446744071571026759, 18446744071568229156, 18446744071568233093, 18446744071568324834, 18446744071568212356, 18446744071571018041, 18446744071568197371, 18446744071568198228, 18446744071568199348, 18446744071570725335}}}, v_interlock = {lock_object = { lo_name = 0xffffffff8094debe "vnode interlock", lo_flags = 16973824, lo_data = 0, lo_witness = 0xfffffffe4021b680}, mtx_lock = 4}, v_vnlock = 0xffffff011885b578, v_holdcnt = 1, v_usecount = 1, v_iflag = 0, v_vflag = 0, v_writecount = 0, v_freelist = {tqe_next = 0xffffff00c6b53750, tqe_prev = 0xffffff00c6b60dd0}, v_bufobj = {bo_mtx = {lock_object = { lo_name = 0xffffffff80956a86 "bufobj interlock", lo_flags = 16973824, lo_data = 0, lo_witness = 0xfffffffe40220c80}, mtx_lock = 4}, bo_clean = {bv_hd = {tqh_first = 0x0, tqh_last = 0xffffff011885b6b0}, bv_root = 0x0, bv_cnt = 0}, bo_dirty = {bv_hd = {tqh_first = 0x0, tqh_last = 0xffffff011885b6d0}, bv_root = 0x0, bv_cnt = 0}, bo_numoutput = 0, bo_flag = 0, bo_ops = 0xffffffff80b7d9e0, bo_bsize = 131072, bo_object = 0x0, bo_synclist = {le_next = 0x0, le_prev = 0x0}, bo_private = 0xffffff011885b4e0, __bo_vnode = 0xffffff011885b4e0}, v_pollinfo = 0x0, v_label = 0x0, v_lockf = 0x0} (kgdb) l 697 if (dvp->v_cache_dd != NULL) { 698 CACHE_WUNLOCK(); 699 cache_free(ncp); 700 return; 701 } 702 KASSERT(vp == NULL || vp->v_type == VDIR, 703 ("wrong vnode type %p", vp)); 704 dvp->v_cache_dd = ncp; 705 } 706 (kgdb) fr 12 #12 0xffffffff81049b95 in zfs_lookup (dvp=0xffffff010c019000, nm=0xffffffff2d7da230 "..", vpp=0xffffffff2d7da8e0, cnp=0xffffffff2d7da908, nameiop=0, cr=0xffffff0032a08a00, td=0xffffff0051e05000, flags=0) at /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_vnops.c:1221 1221 cache_enter(dvp, *vpp, cnp); (kgdb) l 1216 * Insert name into cache if appropriate. 1217 */ 1218 if (error == 0 && (cnp->cn_flags & MAKEENTRY)) { 1219 if (!(cnp->cn_flags & ISLASTCN) || 1220 (nameiop != DELETE && nameiop != RENAME)) { 1221 cache_enter(dvp, *vpp, cnp); 1222 } 1223 } 1224 #endif 1225 (kgdb) p *dvp $2 = {v_type = VDIR, v_tag = 0xffffffff810ad73d "zfs", v_op = 0xffffffff810b22e0, v_data = 0xffffff00b7a99bc0, v_mount = 0xffffff00058e9388, v_nmntvnodes = {tqe_next = 0xffffff001fee1270, tqe_prev = 0xffffff00c1c9c508}, v_un = {vu_mount = 0x0, vu_socket = 0x0, vu_cdev = 0x0, vu_fifoinfo = 0x0, vu_yield = 0}, v_hashlist = { le_next = 0x0, le_prev = 0x0}, v_hash = 0, v_cache_src = {lh_first = 0x0}, v_cache_dst = {tqh_first = 0x0, tqh_last = 0xffffff010c019060}, v_cache_dd = 0x0, v_cstart = 0, v_lasta = 0, v_lastw = 0, v_clen = 0, v_lock = {lock_object = {lo_name = 0xffffffff810ad73d "zfs", lo_flags = 91947009, lo_data = 0, lo_witness = 0xfffffffe40223200}, lk_lock = 9, lk_timo = 16, lk_pri = 80, lk_stack = {depth = 18, pcs = { 18446744071567615226, 18446744071568210649, 18446744071571022971, 18446744071568325815, 18446744071579147091, 18446744071579148113, 18446744071571017711, 18446744071568201856, 18446744071571026759, 18446744071568229156, 18446744071568233093, 18446744071568324834, 18446744071568212356, 18446744071571018041, 18446744071568197371, 18446744071568198228, 18446744071568199348, 18446744071570725335}}}, v_interlock = {lock_object = { lo_name = 0xffffffff8094debe "vnode interlock", lo_flags = 16973824, lo_data = 0, lo_witness = 0xfffffffe4021b680}, mtx_lock = 4}, v_vnlock = 0xffffff010c019098, v_holdcnt = 6, v_usecount = 5, v_iflag = 0, v_vflag = 0, v_writecount = 0, v_freelist = {tqe_next = 0x0, tqe_prev = 0xffffff010c0701a0}, v_bufobj = {bo_mtx = {lock_object = { lo_name = 0xffffffff80956a86 "bufobj interlock", lo_flags = 16973824, lo_data = 0, lo_witness = 0xfffffffe40220c80}, mtx_lock = 4}, bo_clean = {bv_hd = {tqh_first = 0x0, tqh_last = 0xffffff010c0191d0}, bv_root = 0x0, bv_cnt = 0}, bo_dirty = {bv_hd = {tqh_first = 0x0, tqh_last = 0xffffff010c0191f0}, bv_root = 0x0, bv_cnt = 0}, bo_numoutput = 0, bo_flag = 0, bo_ops = 0xffffffff80b7d9e0, bo_bsize = 131072, bo_object = 0xffffff00bd665708, bo_synclist = { le_next = 0x0, le_prev = 0x0}, bo_private = 0xffffff010c019000, __bo_vnode = 0xffffff010c019000}, v_pollinfo = 0x0, v_label = 0x0, v_lockf = 0x0} (kgdb) p **vpp $3 = {v_type = VLNK, v_tag = 0xffffffff810ad73d "zfs", v_op = 0xffffffff810b22e0, v_data = 0xffffff006cfe9178, v_mount = 0xffffff00058e9388, v_nmntvnodes = {tqe_next = 0xffffff00c6b53750, tqe_prev = 0xffffff00c6b60c58}, v_un = {vu_mount = 0x0, vu_socket = 0x0, vu_cdev = 0x0, vu_fifoinfo = 0x0, vu_yield = 0}, v_hashlist = { le_next = 0x0, le_prev = 0x0}, v_hash = 0, v_cache_src = {lh_first = 0x0}, v_cache_dst = {tqh_first = 0xffffff00a6675770, tqh_last = 0xffffff00a6675790}, v_cache_dd = 0x0, v_cstart = 0, v_lasta = 0, v_lastw = 0, v_clen = 0, v_lock = {lock_object = { lo_name = 0xffffffff810ad73d "zfs", lo_flags = 91947009, lo_data = 0, lo_witness = 0xfffffffe40223200}, lk_lock = 18446742975571578880, lk_timo = 16, lk_pri = 80, lk_stack = {depth = 18, pcs = { 18446744071567615800, 18446744071568210649, 18446744071571022971, 18446744071568325815, 18446744071579147048, 18446744071579148113, 18446744071571017711, 18446744071568201856, 18446744071571026759, 18446744071568229156, 18446744071568233093, 18446744071568324834, 18446744071568212356, 18446744071571018041, 18446744071568197371, 18446744071568198228, 18446744071568199348, 18446744071570725335}}}, v_interlock = {lock_object = { lo_name = 0xffffffff8094debe "vnode interlock", lo_flags = 16973824, lo_data = 0, lo_witness = 0xfffffffe4021b680}, mtx_lock = 4}, v_vnlock = 0xffffff011885b578, v_holdcnt = 1, v_usecount = 1, v_iflag = 0, v_vflag = 0, v_writecount = 0, v_freelist = {tqe_next = 0xffffff00c6b53750, tqe_prev = 0xffffff00c6b60dd0}, v_bufobj = {bo_mtx = {lock_object = { lo_name = 0xffffffff80956a86 "bufobj interlock", lo_flags = 16973824, lo_data = 0, lo_witness = 0xfffffffe40220c80}, mtx_lock = 4}, bo_clean = {bv_hd = {tqh_first = 0x0, tqh_last = 0xffffff011885b6b0}, bv_root = 0x0, bv_cnt = 0}, bo_dirty = {bv_hd = {tqh_first = 0x0, tqh_last = 0xffffff011885b6d0}, bv_root = 0x0, bv_cnt = 0}, bo_numoutput = 0, bo_flag = 0, bo_ops = 0xffffffff80b7d9e0, bo_bsize = 131072, bo_object = 0x0, bo_synclist = {le_next = 0x0, le_prev = 0x0}, bo_private = 0xffffff011885b4e0, __bo_vnode = 0xffffff011885b4e0}, v_pollinfo = 0x0, v_label = 0x0, v_lockf = 0x0} (kgdb) q Script done on Wed May 6 17:42:37 2009Received on Wed May 06 2009 - 21:46:32 UTC
This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:39:47 UTC