Date: Fri, 09 Jan 2009 17:49:02 -0500 From: Joe Marcus Clarke <marcus@FreeBSD.org> To: Richard Todd <rmtodd@ichotolot.servalan.com> Cc: freebsd-current@FreeBSD.org Subject: Re: Recent changes to pseudofs causing panics -- leaking a vnode lock? Message-ID: <1231541342.56664.19.camel@shumai.marcuscom.com> In-Reply-To: <20090109004853.GA34384@ichotolot.servalan.com> References: <20090109004853.GA34384@ichotolot.servalan.com>
next in thread | previous in thread | raw e-mail | index | archive | help
--=-nobRallXHZu+eaWhGxwh
Content-Type: text/plain
Content-Transfer-Encoding: quoted-printable
On Thu, 2009-01-08 at 18:48 -0600, Richard Todd wrote:
> I've noticed that ever since updating to a kernel after the recent change=
s
> to the pseudofs code late last month, that I've occasionally gotten the=20
> following sort of panic:
>=20
> System call readlink returning with the following locks held:
> exclusive lockmgr pseudofs (pseudofs) r =3D 0 (0xffffff00ba581cc8) locked=
@ /usr/src/sys/fs/pseudofs/pseudofs_vncache.c:193
> panic: witness_warn
>=20
> The line in question is the one I marked by an arrow in this chunk of the=
=20
> pfs_vncache_alloc code:=20
> if ((pn->pn_flags & PFS_PROCDEP) !=3D 0)
> (*vpp)->v_vflag |=3D VV_PROCDEP;
> pvd->pvd_vnode =3D *vpp;
> VN_LOCK_AREC(*vpp);
> vn_lock(*vpp, LK_EXCLUSIVE | LK_RETRY); <=3D=3D=3D=3D this lock h=
ere
> error =3D insmntque(*vpp, mp);
>=20
> So somehow, a vnode is getting locked here and not getting unlocked.
> I suspect the code in the retry2: loop later, simply because that's
> the code that got added in the late December commits, but I'm not
> clear on how exactly. I've tried littering the code with extra
> printfs to try to clarify what's going on, but alas, I'm still not
> really sure what's going on. I do have a good coredump that I can get
> info out of, if someone can suggest to me what would be useful things
> to dump. Anyway, here's the patch for the debugging printfs I added,
> and the console messages produced by those printfs from the most
> recent coredump/panic. The console msgs do seem to indicate some sort
> of race condition going on, though, as they seem to show two or more proc=
esses
> simultaneously hitting the pseudofs code and hitting my debugging print
> statements (alas, making the console log rather a confused mess.)
I believe I have fixed this in HEAD. Kib gave his review and approval,
and the fix really should prevent this hang. Please report back if you
still see the problem.
Joe
>=20
> The debugging additions:
> Index: pseudofs_vncache.c
> =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
> RCS file: /usr/FreeBSDCVS/src/sys/fs/pseudofs/pseudofs_vncache.c,v
> retrieving revision 1.44
> diff -u -r1.44 pseudofs_vncache.c
> --- pseudofs_vncache.c 29 Dec 2008 13:25:58 -0000 1.44
> +++ pseudofs_vncache.c 8 Jan 2009 02:22:50 -0000
> @@ -129,6 +129,7 @@
> mtx_unlock(&pfs_vncache_mutex);
> if (vget(vp, LK_EXCLUSIVE | LK_INTERLOCK, curthread) =3D=3D 0) {
> ++pfs_vncache_hits;
> + vprint("XXX vncache 6", vp);
> *vpp =3D vp;
> /*
> * Some callers cache_enter(vp) later, so
> @@ -191,7 +192,9 @@
> pvd->pvd_vnode =3D *vpp;
> VN_LOCK_AREC(*vpp);
> vn_lock(*vpp, LK_EXCLUSIVE | LK_RETRY);
> + printf("XXX vncache 1 *vpp=3D%p\n", *vpp);
> error =3D insmntque(*vpp, mp);
> + printf("XXX vncache 2 *vpp=3D%p\n", *vpp);
> if (error !=3D 0) {
> *vpp =3D NULLVP;
> return (error);
> @@ -211,11 +214,14 @@
> mtx_unlock(&pfs_vncache_mutex);
> if (vget(vp, LK_EXCLUSIVE | LK_INTERLOCK, curthread) =3D=3D 0) {
> ++pfs_vncache_hits;
> + vprint("XXX vncache 3", *vpp);
> vgone(*vpp);
> + vprint("XXX vncache 4", *vpp);
> *vpp =3D vp;
> cache_purge(vp);
> return (0);
> }
> + vprint("XXX vncache 5", *vpp);
> goto retry2;
> }
> }
> Index: pseudofs_vnops.c
> =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
> RCS file: /usr/FreeBSDCVS/src/sys/fs/pseudofs/pseudofs_vnops.c,v
> retrieving revision 1.72
> diff -u -r1.72 pseudofs_vnops.c
> --- pseudofs_vnops.c 30 Dec 2008 21:49:39 -0000 1.72
> +++ pseudofs_vnops.c 6 Jan 2009 23:12:40 -0000
> @@ -369,6 +369,7 @@
> VOP_UNLOCK(vp, 0);
> =20
> error =3D pfs_vncache_alloc(mp, dvp, pn, pid);
> + vprint("XXX vptocnp", *dvp);
> if (error) {
> vn_lock(vp, locked | LK_RETRY);
> vfs_unbusy(mp);
> @@ -502,6 +503,7 @@
> }
> =20
> error =3D pfs_vncache_alloc(vn->v_mount, vpp, pn, pid);
> + vprint("XXX lookup", *vpp);
> if (error)
> goto failed;
> =20
> and the msgs from the most recent coredump:
> Script started on Thu Jan 8 18:34:33 2009
> You have mail.
> ichotolot# kgdb kernel.debug /var/crash/vmcore.206=20
> 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 conditi=
ons.
> Type "show copying" to see the conditions.
> There is absolutely no warranty for GDB. Type "show warranty" for detail=
s.
> This GDB was configured as "amd64-marcel-freebsd"...
>=20
> Unread portion of the kernel message buffer:
> XXX vncache 1 *vpp=3D0xffffff00b0173c30
> XXX vncache 2 *vpp=3D0xffffff00b0173c30
> XXX vncache 1 *vpp=3D0xffffff000d420270XXX vncache 1 *vp
> p=3D0xffXfXfX fvfn0cache 2 *vp0c6886750p=3D0xffffff000d420270
> XXX vncache 2 *vpp=3D0xffffff00c6886750
>=20
> XXX lookup
> 0xffffff00c6886750: tag pseudofs, type VLNK
> usecount 1, writecount 0, refcount 1 mountedhere 0
> flags ()
> lock type pseudofs: EXCL by thread 0xffffff00c873e390 (pid 18861)
> #0 0xffffffff80514c28 at __lockmgr_args+0x758
> #1 0xffffffff805a4409 at vop_stdlock+0x39
> #2 0xffffffff808369db at VOP_LOCK1_APV+0x9b
> #3 0xffffffff805bfae7 at _vn_lock+0x57
> #4 0xffffffff804ce120 at pfs_vncache_alloc+0x1f0
> #5 0xffffffff804cf473 at pfs_lookup+0x273
> #6 0xffffffff8083543f at VOP_CACHEDLOOKUP_APV+0xaf
> #7 0xffffffff805a2220 at vfs_cache_lookup+0xf0
> #8 0xffffffff808378a7 at VOP_LOOKUP_APV+0xb7
> #9 0xffffffff805a83d3 at lookup+0x513
> #10 0xffffffff805a928e at namei+0x53e
> #11 0xffffffff805b6ffa at kern_readlinkat+0x7a
> #12 0xffffffff805b7121 at kern_readlink+0x21
> #13 0xffffffff807f16b7 at syscall+0x1e7
> #14 0xffffffff807d41bb at Xfast_syscall+0xab
>=20
> XXX vncache 3
> 0xffffff000d420270: tag pseudofs, type VDIR
> usecount 1, writecount 0, refcount 1 mountedhere 0
> flags (VV_ROOT)
> lock type pseudofs: EXCL by thread 0xffffff0082999390 (pid 18860)
> #0 0xffffffff80514c28 at __lockmgr_args+0x758
> #1 0xffffffff805a4409 at vop_stdlock+0x39
> #2 0xffffffff808369db at VOP_LOCK1_APV+0x9b
> #3 0xffffffff805bfae7 at _vn_lock+0x57
> #4 0xffffffff804ce120 at pfs_vncache_alloc+0x1f0
> #5 0xffffffff805a885f at lookup+0x99f
> #6 0xffffffff805a928e at namei+0x53e
> #7 0xffffffff805b6ffa at kern_readlinkat+0x7a
> #8 0xffffffff805b7121 at kern_readlink+0x21
> #9 0xffffffff807f16b7 at syscall+0x1e7
> #10 0xffffffff807d41bb at Xfast_syscall+0xab
>=20
> XXX vncache 4
> 0xffffff000d420270: tag none, type VBAD
> usecount 1, writecount 0, refcount 1 mountedhere 0
> flags (VV_ROOT|VI_DOOMED)
> lock type pseudofs: EXCL by thread 0xffffff0082999390 (pid 18860)
> #0 0xffffffff80514c28 at __lockmgr_args+0x758
> #1 0xffffffff805a4409 at vop_stdlock+0x39
> #2 0xffffffff808369db at VOP_LOCK1_APV+0x9b
> #3 0xffffffff805bfae7 at _vn_lock+0x57
> #4 0xffffffff804ce120 at pfs_vncache_alloc+0x1f0
> #5 0xffffffff805a885f at lookup+0x99f
> #6 0xffffffff805a928e at namei+0x53e
> #7 0xffffffff805b6ffa at kern_readlinkat+0x7a
> #8 0xffffffff805b7121 at kern_readlink+0x21
> #9 0xffffffff807f16b7 at syscall+0x1e7
> #10 0xffffffff807d41bb at Xfast_syscall+0xab
>=20
> XXX vncache 6
> 0xffffff00c6886750: tag pseudofs, type VLNK
> usecount 1, writecount 0, refcount 1 mountedhere 0
> flags ()
> lock type pseudofs: EXCL by thread 0xffffff0082999390 (pid 18860)
> #0 0xffffffff80514c28 at __lockmgr_args+0x758
> #1 0xffffffff805a4409 at vop_stdlock+0x39
> #2 0xffffffff808369db at VOP_LOCK1_APV+0x9b
> #3 0xffffffff805bfae7 at _vn_lock+0x57
> #4 0xffffffff805b3fdb at vget+0x8b
> #5 0xffffffff804cdfe8 at pfs_vncache_alloc+0xb8
> #6 0xffffffff804cf473 at pfs_lookup+0x273
> #7 0xffffffff8083543f at VOP_CACHEDLOOKUP_APV+0xaf
> #8 0xffffffff805a2220 at vfs_cache_lookup+0xf0
> #9 0xffffffff808378a7 at VOP_LOOKUP_APV+0xb7
> #10 0xffffffff805a83d3 at lookup+0x513
> #11 0xffffffff805a928e at namei+0x53e
> #12 0xffffffff805b6ffa at kern_readlinkat+0x7a
> #13 0xffffffff805b7121 at kern_readlink+0x21
> #14 0xffffffff807f16b7 at syscall+0x1e7
> #15 0xffffffff807d41bb at Xfast_syscall+0xab
>=20
> XXX lookup
> 0xffffff00c6886750: tag pseudofs, type VLNK
> usecount 1, writecount 0, refcount 1 mountedhere 0
> flags ()
> lock type pseudofs: EXCL by thread 0xffffff0082999390 (pid 18860)
> #0 0xffffffff80514c28 at __lockmgr_args+0x758
> #1 0xffffffff805a4409 at vop_stdlock+0x39
> #2 0xffffffff808369db at VOP_LOCK1_APV+0x9b
> #3 0xffffffff805bfae7 at _vn_lock+0x57
> #4 0xffffffff805b3fdb at vget+0x8b
> #5 0xffffffff804cdfe8 at pfs_vncache_alloc+0xb8
> #6 0xffffffff804cf473 at pfs_lookup+0x273
> #7 0xffffffff8083543f at VOP_CACHEDLOOKUP_APV+0xaf
> #8 0xffffffff805a2220 at vfs_cache_lookup+0xf0
> #9 0xffffffff808378a7 at VOP_LOOKUP_APV+0xb7
> #10 0xffffffff805a83d3 at lookup+0x513
> #11 0xffffffff805a928e at namei+0x53e
> #12 0xffffffff805b6ffa at kern_readlinkat+0x7a
> #13 0xffffffff805b7121 at kern_readlink+0x21
> #14 0xffffffff807f16b7 at syscall+0x1e7
> #15 0xffffffff807d41bb at Xfast_syscall+0xab
>=20
> XXX vncache 1 *vpp=3D0xffffff007af74270
> XXX vncache 2 *vpp=3D0xffffff007af74270
> XXX lookup
> 0xffffff007af74270: tag pseudofs, type VDIR
> usecount 1, writecount 0, refcount 1 mountedhere 0
> flags (VV_PROCDEP)
> lock type pseudofs: EXCL by thread 0xffffff00c873e390 (pid 18861)
> #0 0xffffffff80514c28 at __lockmgr_args+0x758
> #1 0xffffffff805a4409 at vop_stdlock+0x39
> #2 0xffffffff808369db at VOP_LOCK1_APV+0x9b
> #3 0xffffffff805bfae7 at _vn_lock+0x57
> #4 0xffffffff804ce120 at pfs_vncache_alloc+0x1f0
> #5 0xffffffff804cf473 at pfs_lookup+0x273
> #6 0xffffffff8083543f at VOP_CACHEDLOOKUP_APV+0xaf
> #7 0xffffffff805a2220 at vfs_cache_lookup+0xf0
> #8 0xffffffff808378a7 at VOP_LOOKUP_APV+0xb7
> #9 0xffffffff805a83d3 at lookup+0x513
> #10 0xffffffff805a928e at namei+0x53e
> #11 0xffffffff805b6ffa at kern_readlinkat+0x7a
> #12 0xffffffff805b7121 at kern_readlink+0x21
> #13 0xffffffff807f16b7 at syscall+0x1e7
> #14 0xffffffff807d41bb at Xfast_syscall+0xab
>=20
> XXX vncache 1 *vpp=3D0xffffff00cd4719c0
> XXX vncache 2 *vpp=3D0xffffff00cd4719c0
> XXX lookup
> 0xffffff00cd4719c0: tag pseudofs, type VLNK
> usecount 1, writecount 0, refcount 1 mountedhere 0
> flags (VV_PROCDEP)
> lock type pseudofs: EXCL by thread 0xffffff00c873e390 (pid 18861)
> #0 0xffffffff80514c28 at __lockmgr_args+0x758
> #1 0xffffffff805a4409 at vop_stdlock+0x39
> #2 0xffffffff808369db at VOP_LOCK1_APV+0x9b
> #3 0xffffffff805bfae7 at _vn_lock+0x57
> #4 0xffffffff804ce120 at pfs_vncache_alloc+0x1f0
> #5 0xffffffff804cf473 at pfs_lookup+0x273
> #6 0xffffffff8083543f at VOP_CACHEDLOOKUP_APV+0xaf
> #7 0xffffffff805a2220 at vfs_cache_lookup+0xf0
> #8 0xffffffff808378a7 at VOP_LOOKUP_APV+0xb7
> #9 0xffffffff805a83d3 at lookup+0x513
> #10 0xffffffff805a928e at namei+0x53e
> #11 0xffffffff805b6ffa at kern_readlinkat+0x7a
> #12 0xffffffff805b7121 at kern_readlink+0x21
> #13 0xffffffff807f16b7 at syscall+0x1e7
> #14 0xffffffff807d41bb at Xfast_syscall+0xab
>=20
> XXX vncache 6
> 0xffffff00b0173c30: tag pseudofs, type VDIR
> usecount 2, writecount 0, refcount 3 mountedhere 0
> flags (VV_ROOT)
> lock type pseudofs: EXCL by thread 0xffffff00c625bab0 (pid 18865)
> #0 0xffffffff80514c28 at __lockmgr_args+0x758
> #1 0xffffffff805a4409 at vop_stdlock+0x39
> #2 0xffffffff808369db at VOP_LOCK1_APV+0x9b
> #3 0xffffffff805bfae7 at _vn_lock+0x57
> #4 0xffffffff805b3fdb at vget+0x8b
> #5 0xffffffff804cdfe8 at pfs_vncache_alloc+0xb8
> #6 0xffffffff805a885f at lookup+0x99f
> #7 0xffffffff805a928e at namei+0x53e
> #8 0xffffffff805b6ffa at kern_readlinkat+0x7a
> #9 0xffffffff805b7121 at kern_readlink+0x21
> #10 0xffffffff807f16b7 at syscall+0x1e7
> #11 0xffffffff807d41bb at Xfast_syscall+0xab
>=20
> XXX vncache 6
> 0xffffff00c6886750: tag pseudofs, type VLNK
> usecount 1, writecount 0, refcount 1 mountedhere 0
> flags ()
> lock type pseudofs: EXCL by thread 0xffffff00c625bab0 (pid 18865)
> #0 0xffffffff80514c28 at __lockmgr_args+0x758
> #1 0xffffffff805a4409 at vop_stdlock+0x39
> #2 0xffffffff808369db at VOP_LOCK1_APV+0x9b
> #3 0xffffffff805bfae7 at _vn_lock+0x57
> #4 0xffffffff805b3fdb at vget+0x8b
> #5 0xffffffff804cdfe8 at pfs_vncache_alloc+0xb8
> #6 0xffffffff804cf473 at pfs_lookup+0x273
> #7 0xffffffff8083543f at VOP_CACHEDLOOKUP_APV+0xaf
> #8 0xffffffff805a2220 at vfs_cache_lookup+0xf0
> #9 0xffffffff808378a7 at VOP_LOOKUP_APV+0xb7
> #10 0xffffffff805a83d3 at lookup+0x513
> #11 0xffffffff805a928e at namei+0x53e
> #12 0xffffffff805b6ffa at kern_readlinkat+0x7a
> #13 0xffffffff805b7121 at kern_readlink+0x21
> #14 0xffffffff807f16b7 at syscall+0x1e7
> #15 0xffffffff807d41bb at Xfast_syscall+0xab
>=20
> XXX lookup
> 0xffffff00c6886750: tag pseudofs, type VLNK
> usecount 1, writecount 0, refcount 1 mountedhere 0
> flags ()
> lock type pseudofs: EXCL by thread 0xffffff00c625bab0 (pid 18865)
> #0 0xffffffff80514c28 at __lockmgr_args+0x758
> #1 0xffffffff805a4409 at vop_stdlock+0x39
> #2 0xffffffff808369db at VOP_LOCK1_APV+0x9b
> #3 0xffffffff805bfae7 at _vn_lock+0x57
> #4 0xffffffff805b3fdb at vget+0x8b
> #5 0xffffffff804cdfe8 at pfs_vncache_alloc+0xb8
> #6 0xffffffff804cf473 at pfs_lookup+0x273
> #7 0xffffffff8083543f at VOP_CACHEDLOOKUP_APV+0xaf
> #8 0xffffffff805a2220 at vfs_cache_lookup+0xf0
> #9 0xffffffff808378a7 at VOP_LOOKUP_APV+0xb7
> #10 0xffffffff805a83d3 at lookup+0x513
> #11 0xffffffff805a928e at namei+0x53e
> #12 0xffffffff805b6ffa at kern_readlinkat+0x7a
> #13 0xffffffff805b7121 at kern_readlink+0x21
> #14 0xffffffff807f16b7 at syscall+0x1e7
> #15 0xffffffff807d41bb at Xfast_syscall+0xab
>=20
> XXX vncache 1 *vpp=3D0xffffff0053e7a750
> XXX vncache 2 *vpp=3D0xffffff0053e7a750
> XXX lookup
> 0xffffff0053e7a750: tag pseudofs, type VDIR
> usecount 1, writecount 0, refcount 1 mountedhere 0
> flags (VV_PROCDEP)
> lock type pseudofs: EXCL by thread 0xffffff0082999390 (pid 18860)
> #0 0xffffffff80514c28 at __lockmgr_args+0x758
> #1 0xffffffff805a4409 at vop_stdlock+0x39
> #2 0xffffffff808369db at VOP_LOCK1_APV+0x9b
> #3 0xffffffff805bfae7 at _vn_lock+0x57
> #4 0xffffffff804ce120 at pfs_vncache_alloc+0x1f0
> #5 0xffffffff804cf473 at pfs_lookup+0x273
> #6 0xffffffff8083543f at VOP_CACHEDLOOKUP_APV+0xaf
> #7 0xffffffff805a2220 at vfs_cache_lookup+0xf0
> #8 0xffffffff808378a7 at VOP_LOOKUP_APV+0xb7
> #9 0xffffffff805a83d3 at lookup+0x513
> #10 0xffffffff805a928e at namei+0x53e
> #11 0xffffffff805b6ffa at kern_readlinkat+0x7a
> #12 0xffffffff805b7121 at kern_readlink+0x21
> #13 0xffffffff807f16b7 at syscall+0x1e7
> #14 0xffffffff807d41bb at Xfast_syscall+0xab
>=20
> XXX vncache 1 *vpp=3D0xffffff00429cb4e0XXX vncache 1 *vpp=3D0xffffff007a9=
2a750
> XXX vncache 2 *vpp=3D0xffffff00429cb4e0
> XXX vncache 2 *vpp=3D0xffffff007a92a750
> XXX lookup
> XXX lookup
> 0xffffff00429cb4e0:=20
> 0xffffff007a92a750: tag pseudofs, type VLNKtag pseudofs, type VDIR
> usecount 1, writecount 0, refcount 1 mountedhere 0
> usecount 1, writecount 0, refcount 1 mountedhere 0
> flags (VV_PROCDEP)
> flags (VV_PROCDEP)
> =20
> lock type ps eudofs: EXCL by thrleoacdk type0 pseudofs: EXCL by xft=
fhfrfefafd0 0829099x3f9f0 f(pid 18860)fff00c625bab0 (pid 18865)
>=20
> #0 0xffffffff80514c28 at __lockmgr_args+0x758#0=20
> 0xffffffff80514c28 at __lockmgr_args+0x758
> #1 0xffffffff805a4409 at vop_stdlock+0x39
> #1 0xffffffff805a4409 at vop_stdlock+0x39
> #2 0xffffffff808369db at VOP_LOCK1_APV+0x9b#2=20
> 0xffffffff808369db at VOP_LOCK1_APV+0x9b
> #3 0xffffffff805bfae7 at _vn_lock+0x57
> #3 0xffffffff805bfae7 at _vn_lock+0x57
> #4 0xffffffff804ce120 at pfs_vncache_alloc+0x1f0
> #4 0xffffffff804ce120 at pfs_vncache_alloc+0x1f0
> #5 0x#f5f ffff0fxff8f0f4fcff473 at pfs_lookffufp8+004xc2f7473 at pfs_look=
up+30x273
>=20
> #6 0xffffffff8083543f at VOP_CACHEDLOOKUP_APV+0xaf#6 0xffffffff8083543f a=
t VOP_CACHEDLOOKUP_APV+0xaf
>=20
> #7 0xffffffff805a2220 at vfs_cache_lookup+0xf0#7 0xffffffff805a2220 at vf
> s_cache_lookup+0xf0
> #8 0xffffffff808378a7 at VOP_LOOKUP_APV+0xb7#8 0xffffffff808378
> a7 at VOP_LOOKUP_APV+0xb7
> #9 0xffffffff805a83d3 at lookup+0x513
> #9 0xffffffff805a83d3 at lookup+0x513
> #10 0xffffff#ff8105a928e at namei+00 x53e0xffffffff805a928e at namei+0x53=
e
>=20
> #11 0xffffffff805b6ffa at kern_readlinkat+0x7a#11 0xffffffff805b6ffa at k=
ern_readlinkat+0x7a
>=20
> #12 0xffffffff805b7121 at kern_readlink+0x21#12 0xffffffff805b7121 at ker
> n_readlink+0x21
> #13 0xffffffff807f16b7 at syscall+0x1e7
> #13 0xffffffff807f16b7 at syscall+0x1e7
> #14 0xffffffff807d41bb at Xfast_syscall+0xab
>=20
> XXX vncache 1 *vpp=3D0xffffff007a357750#14 0xffffffff807d41bb at Xfast_sy=
scall+0xab
> XXX vncache 2 *vpp=3D0xffffff007a357750
>=20
> XXX looku
> p
> 0xffffff007a357750: tag pseudofs, type VLNKSystem call readlink returning
> usecount 1, writecount 0, refcount 1 mountedhere 0 with the following
> flags (VV_PROCDEP) locks held:
> exclusive lockmgr pseudofs
> lock type pseudofs: EXCL by thread 0xffffff00c625b a(b0 (ppid seu1d8=
865)ofs)
> r =3D 0 (0xffffff000d420308) locked @ /usr/src/sys/fs/pseudofs/pseudofs_=
vncache.c:194
> panic: witness_warn
> cpuid =3D 0
> KDB: enter: panic
> Physical memory: 4012 MB
> Dumping 2401 MB: 2386 2370 2354 2338 2322 2306 2290 2274 2258 2242 2226 2=
210 2194 2178 2162 2146 2130 2114 2098 2082 2066 2050 2034 2018 2002 1986 1=
970 1954 1938 1922 1906 1890 1874 1858 1842 1826 1810 1794 1778 1762 1746 1=
730 1714 1698 1682 1666 1650 1634 1618 1602 1586 1570 1554 1538 1522 1506 1=
490 1474 1458 1442 1426 1410 1394 1378 1362 1346 1330 1314 1298 1282 1266 1=
250 1234 1218 1202 1186 1170 1154 1138 1122 1106 1090 1074 1058 1042 1026 1=
010 994 978 962 946 930 914 898 882 866 850 834 818 802 786 770 754 738 722=
706 690 674 658 642 626 610 594 578 562 546 530 514 498 482 466 450 434 41=
8 402 386 370 354 338 322 306 290 274 258 242 226 210 194 178 162 146 130 1=
14 98 82 66 50 34 18 2
>=20
> 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/modules/cpu.ko...done.
> Loaded symbols for /boot/modules/cpu.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:196
> 196 __asm __volatile("movq %%gs:0,%0" : "=3Dr" (td));
> (kgdb) =08 =08p =08 =08=08 =08=08 =08=07bt
> #0 doadump () at pcpu.h:196
> #1 0xffffffff801c752c in db_fncall (dummy1=3DVariable "dummy1" is not av=
ailable.
> )
> at /usr/src/sys/ddb/db_command.c:548
> #2 0xffffffff801c7861 in db_command (last_cmdp=3D0xffffffff80b547a0, cmd=
_table=3DVariable "cmd_table" is not available.
> )
> at /usr/src/sys/ddb/db_command.c:445
> #3 0xffffffff801c7ab0 in db_command_loop ()
> at /usr/src/sys/ddb/db_command.c:498
> #4 0xffffffff801c9a59 in db_trap (type=3DVariable "type" is not availabl=
e.
> ) at /usr/src/sys/ddb/db_main.c:229
> #5 0xffffffff80558fd5 in kdb_trap (type=3D3, code=3D0, tf=3D0xffffffff2d=
73e840)
> at /usr/src/sys/kern/subr_kdb.c:534
> #6 0xffffffff807f1e14 in trap (frame=3D0xffffffff2d73e840)
> at /usr/src/sys/amd64/amd64/trap.c:533
> #7 0xffffffff807d3fae in calltrap ()
> at /usr/src/sys/amd64/amd64/exception.S:217
> #8 0xffffffff805591ad in kdb_enter (why=3D0xffffffff808d5179 "panic",=20
> msg=3D0x1 <Address 0x1 out of bounds>) at cpufunc.h:63
> #9 0xffffffff80529c5b in panic (fmt=3DVariable "fmt" is not available.
> ) at /usr/src/sys/kern/kern_shutdown.c:559
> #10 0xffffffff8056c41e in witness_warn (flags=3DVariable "flags" is not a=
vailable.
> )
> at /usr/src/sys/kern/subr_witness.c:1655
> #11 0xffffffff807f175e in syscall (frame=3D0xffffffff2d73ec90)
> at /usr/src/sys/amd64/amd64/trap.c:965
> #12 0xffffffff807d41bb in Xfast_syscall ()
> at /usr/src/sys/amd64/amd64/exception.S:338
> #13 0x0000000018c1ec1c in ?? ()
> Previous frame inner to this frame (corrupt stack?)
> (kgdb) fr 11
> #11 0xffffffff807f175e in syscall (frame=3D0xffffffff2d73ec90)
> at /usr/src/sys/amd64/amd64/trap.c:965
> 965 WITNESS_WARN(WARN_PANIC, NULL, "System call %s returning"=
,
> (kgdb) p td
> $1 =3D (struct thread *) 0xffffff0082999390
> (kgdb) p td->td_proc
> $2 =3D (struct proc *) 0xffffff0082ae4880
> (kgdb) p td->td_proc[0]
> $3 =3D {p_list =3D {le_next =3D 0xffffff00c82e6440, le_prev =3D 0xffffff0=
07ac31000},=20
> p_threads =3D {tqh_first =3D 0xffffff0082999390, tqh_last =3D 0xffffff0=
0829993a0},=20
> p_slock =3D {lock_object =3D {lo_name =3D 0xffffffff808d3982 "process s=
lock",=20
> lo_flags =3D 720896, lo_data =3D 0, lo_witness =3D 0x0}, mtx_lock =
=3D 4},=20
> p_ucred =3D 0xffffff0010b4ec00, p_fd =3D 0xffffff00bdaac400, p_fdtol =
=3D 0x0,=20
> p_stats =3D 0xffffff0082a83c00, p_limit =3D 0xffffff000ef56c00, p_limco=
=3D {
> c_links =3D {sle =3D {sle_next =3D 0x0}, tqe =3D {tqe_next =3D 0x0,=20
> tqe_prev =3D 0x0}}, c_time =3D 0, c_arg =3D 0x0, c_func =3D 0,=20
> c_lock =3D 0xffffff0082ae4978, c_flags =3D 0, c_cpu =3D 0},=20
> p_sigacts =3D 0xffffff00290e1000, p_flag =3D 268451840, p_state =3D PRS=
_NORMAL,=20
> p_pid =3D 18860, p_hash =3D {le_next =3D 0x0, le_prev =3D 0xfffffffe402=
3fd60},=20
> p_pglist =3D {le_next =3D 0x0, le_prev =3D 0xffffff007ac57948},=20
> p_pptr =3D 0xffffff007ac57880, p_sibling =3D {le_next =3D 0x0,=20
> le_prev =3D 0xffffff007ac57970}, p_children =3D {lh_first =3D 0x0}, p=
_mtx =3D {
> lock_object =3D {lo_name =3D 0xffffffff808d3975 "process lock",=20
> lo_flags =3D 21168128, lo_data =3D 0, lo_witness =3D 0xfffffffe4021=
a400},=20
> mtx_lock =3D 4}, p_ksi =3D 0xffffff000515e000, p_sigqueue =3D {sq_sig=
nals =3D {
> __bits =3D {0, 0, 0, 0}}, sq_kill =3D {__bits =3D {0, 0, 0, 0}}, sq=
_list =3D {
> tqh_first =3D 0x0, tqh_last =3D 0xffffff0082ae49c0},=20
> sq_proc =3D 0xffffff0082ae4880, sq_flags =3D 1}, p_oppid =3D 0,=20
> p_vmspace =3D 0xffffff0082315d38, p_swtick =3D 10457673, p_realtimer =
=3D {
> it_interval =3D {tv_sec =3D 0, tv_usec =3D 0}, it_value =3D {tv_sec =
=3D 0,=20
> tv_usec =3D 0}}, p_ru =3D {ru_utime =3D {tv_sec =3D 0, tv_usec =3D =
0}, ru_stime =3D {
> tv_sec =3D 0, tv_usec =3D 0}, ru_maxrss =3D 0, ru_ixrss =3D 0, ru_i=
drss =3D 0,=20
> ru_isrss =3D 0, ru_minflt =3D 0, ru_majflt =3D 0, ru_nswap =3D 0, ru_=
inblock =3D 0,=20
> ru_oublock =3D 0, ru_msgsnd =3D 0, ru_msgrcv =3D 0, ru_nsignals =3D 0=
,=20
> ru_nvcsw =3D 0, ru_nivcsw =3D 0}, p_rux =3D {rux_runtime =3D 0, rux_u=
ticks =3D 0,=20
> rux_sticks =3D 0, rux_iticks =3D 0, rux_uu =3D 0, rux_su =3D 0, rux_t=
u =3D 0},=20
> p_crux =3D {rux_runtime =3D 0, rux_uticks =3D 0, rux_sticks =3D 0, rux_=
iticks =3D 0,=20
> rux_uu =3D 0, rux_su =3D 0, rux_tu =3D 0}, p_profthreads =3D 0, p_exi=
tthreads =3D 0,=20
> p_traceflag =3D 0, p_tracevp =3D 0x0, p_tracecred =3D 0x0,=20
> p_textvp =3D 0xffffff001b02a750, p_lock =3D 0 '\0', p_sigiolst =3D {
> slh_first =3D 0x0}, p_sigparent =3D 20, p_sig =3D 0, p_code =3D 0, p_=
stops =3D 0,=20
> p_stype =3D 0, p_step =3D 0 '\0', p_pfsflags =3D 0 '\0', p_nlminfo =3D =
0x0,=20
> p_aioinfo =3D 0x0, p_singlethread =3D 0x0, p_suspcount =3D 0, p_xthread=
=3D 0x0,=20
> p_boundary_count =3D 0, p_pendingcnt =3D 0, p_itimers =3D 0x0,=20
> p_magic =3D 3203398350, p_osrel =3D 800054,=20
> p_comm =3D "perl\000l", '\0' <repeats 13 times>, p_pgrp =3D 0xffffff000=
b06ec00,=20
> p_sysent =3D 0xffffffff80b30320, p_args =3D 0xffffff00bdceda80,=20
> p_cpulimit =3D 9223372036854775807, p_nice =3D 0 '\0', p_fibnum =3D 0,=20
> p_xstat =3D 0, p_klist =3D {kl_list =3D {slh_first =3D 0x0},=20
> kl_lock =3D 0xffffffff805008a0 <knlist_mtx_lock>,=20
> kl_unlock =3D 0xffffffff805008c0 <knlist_mtx_unlock>,=20
> kl_locked =3D 0xffffffff80501ba0 <knlist_mtx_locked>,=20
> kl_lockarg =3D 0xffffff0082ae4978}, p_numthreads =3D 1,=20
> p_md =3D <incomplete type>, p_itcallout =3D {c_links =3D {sle =3D {sle_=
next =3D 0x0},=20
> tqe =3D {tqe_next =3D 0x0, tqe_prev =3D 0x0}}, c_time =3D 0, c_arg =
=3D 0x0,=20
> c_func =3D 0, c_lock =3D 0x0, c_flags =3D 16, c_cpu =3D 0}, p_acflag =
=3D 0,=20
> p_peers =3D 0x0, p_leader =3D 0xffffff0082ae4880, p_emuldata =3D 0x0,=20
> p_label =3D 0x0, p_sched =3D 0xffffff0082ae4cc0, p_ktr =3D {stqh_first =
=3D 0x0,=20
> stqh_last =3D 0xffffff0082ae4c90}, p_mqnotifier =3D {lh_first =3D 0x0=
},=20
> p_dtrace =3D 0x0, p_pwait =3D {cv_description =3D 0xffffffff808d42c2 "p=
pwait",=20
> cv_waiters =3D 0}}
> (kgdb) =08 =08=07p *td
> $4 =3D {td_lock =3D 0xffffffff80b91680, td_proc =3D 0xffffff0082ae4880, t=
d_plist =3D {
> tqe_next =3D 0x0, tqe_prev =3D 0xffffff0082ae4890}, td_runq =3D {
> tqe_next =3D 0xffffff000549d720, tqe_prev =3D 0xffffffff80b918c8}, td=
_slpq =3D {
> tqe_next =3D 0x0, tqe_prev =3D 0xffffff000721e190}, td_lockq =3D {
> tqe_next =3D 0x0, tqe_prev =3D 0xffffffff2cb3f750},=20
> td_cpuset =3D 0xffffff000288cdc8, td_sel =3D 0xffffff0082f7bb00,=20
> td_sleepqueue =3D 0xffffff000721e190, td_turnstile =3D 0xffffff00054699=
00,=20
> td_umtxq =3D 0xffffff008284b500, td_tid =3D 100316, td_sigqueue =3D {sq=
_signals =3D {
> __bits =3D {0, 0, 0, 0}}, sq_kill =3D {__bits =3D {0, 0, 0, 0}}, sq=
_list =3D {
> tqh_first =3D 0x0, tqh_last =3D 0xffffff0082999430},=20
> sq_proc =3D 0xffffff0082ae4880, sq_flags =3D 1}, td_flags =3D 4,=20
> td_inhibitors =3D 0, td_pflags =3D 0, td_dupfd =3D 0, td_sqqueue =3D 0,=
=20
> td_wchan =3D 0x0, td_wmesg =3D 0x0, td_lastcpu =3D 0 '\0', td_oncpu =3D=
0 '\0',=20
> td_owepreempt =3D 0 '\0', td_tsqueue =3D 0 '\0', td_locks =3D 1, td_rw_=
rlocks =3D 0,=20
> td_lk_slocks =3D 0, td_blocked =3D 0x0, td_lockname =3D 0x0, td_contest=
ed =3D {
> lh_first =3D 0x0}, td_sleeplocks =3D 0xffffffff80cebd40,=20
> td_intr_nesting_level =3D 0, td_pinned =3D 1, td_ucred =3D 0xffffff0010=
b4ec00,=20
> td_estcpu =3D 0, td_slptick =3D 0, td_ru =3D {ru_utime =3D {tv_sec =3D =
0,=20
> tv_usec =3D 0}, ru_stime =3D {tv_sec =3D 0, tv_usec =3D 0}, ru_maxr=
ss =3D 2044,=20
> ru_ixrss =3D 48, ru_idrss =3D 3352, ru_isrss =3D 512, ru_minflt =3D 1=
86,=20
> ru_majflt =3D 0, ru_nswap =3D 0, ru_inblock =3D 0, ru_oublock =3D 0,=20
> ru_msgsnd =3D 0, ru_msgrcv =3D 0, ru_nsignals =3D 0, ru_nvcsw =3D 13,=
=20
> ru_nivcsw =3D 13}, td_incruntime =3D 61985988, td_runtime =3D 6198598=
8,=20
> td_pticks =3D 3, td_sticks =3D 4, td_iticks =3D 0, td_uticks =3D 0, td_=
uuticks =3D 0,=20
> td_usticks =3D 0, td_intrval =3D 0, td_oldsigmask =3D {__bits =3D {0, 0=
, 0, 0}},=20
> td_sigmask =3D {__bits =3D {0, 0, 0, 0}}, td_generation =3D 26, td_sigs=
tk =3D {
> ss_sp =3D 0x0, ss_size =3D 0, ss_flags =3D 4}, td_xsig =3D 0, td_prof=
il_addr =3D 0,=20
> td_profil_ticks =3D 0, td_name =3D "perl\000l", '\0' <repeats 13 times>=
,=20
> td_fpop =3D 0x0, td_dbgflags =3D 0, td_osd =3D {osd_nslots =3D 0, osd_s=
lots =3D 0x0,=20
> osd_next =3D {le_next =3D 0x0, le_prev =3D 0x0}}, td_rqindex =3D 32 '=
',=20
> td_base_pri =3D 128 '\200', td_priority =3D 128 '\200', td_pri_class =
=3D 3 '\003',=20
> td_user_pri =3D 129 '\201', td_base_user_pri =3D 129 '\201',=20
> td_pcb =3D 0xffffffff2d73ed50, td_state =3D TDS_RUNNING, td_retval =3D =
{23, 1023},=20
> td_slpcallout =3D {c_links =3D {sle =3D {sle_next =3D 0x0}, tqe =3D {tq=
e_next =3D 0x0,=20
> tqe_prev =3D 0xffffffff0031d340}}, c_time =3D 9773098,=20
> c_arg =3D 0xffffff0082999390, c_func =3D 0xffffffff80561850 <sleepq_t=
imeout>,=20
> c_lock =3D 0x0, c_flags =3D 16, c_cpu =3D 0}, td_frame =3D 0xffffffff=
2d73ec90,=20
> td_kstack_obj =3D 0xffffff00c83a7c80, td_kstack =3D 1844674407017714073=
6,=20
> td_kstack_pages =3D 4, td_altkstack_obj =3D 0x0, td_altkstack =3D 0,=20
> td_altkstack_pages =3D 0, td_critnest =3D 1, td_md =3D {md_spinlock_cou=
nt =3D 0,=20
> md_saved_flags =3D 70}, td_sched =3D 0xffffff00829996f0, td_ar =3D 0x=
0,=20
> td_syscalls =3D 1517973, td_lprof =3D {{lh_first =3D 0x0}, {lh_first =
=3D 0x0}},=20
> td_dtrace =3D 0x0, td_errno =3D 0}
> (kgdb) p td=08 =08=08 =08*td->td_lock
> $5 =3D {lock_object =3D {lo_name =3D 0xffffffff80b922d8 "sched lock 0",=20
> lo_flags =3D 720896, lo_data =3D 0, lo_witness =3D 0x0}, mtx_lock =3D=
4}
> (kgdb) q
> ichotolot#=20
>=20
> _______________________________________________
> freebsd-current@freebsd.org mailing list
> http://lists.freebsd.org/mailman/listinfo/freebsd-current
> To unsubscribe, send any mail to "freebsd-current-unsubscribe@freebsd.org=
"
--=20
Joe Marcus Clarke
FreeBSD GNOME Team :: gnome@FreeBSD.org
FreeNode / #freebsd-gnome
http://www.FreeBSD.org/gnome
--=-nobRallXHZu+eaWhGxwh
Content-Type: application/pgp-signature; name=signature.asc
Content-Description: This is a digitally signed message part
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (FreeBSD)
iEYEABECAAYFAkln1F0ACgkQb2iPiv4Uz4cNIwCfRhCIns5QLLoZiaRvVwTihsgb
dxkAn0JVn7yk0H44B+SeHT1HtVrZUlND
=ZAy3
-----END PGP SIGNATURE-----
--=-nobRallXHZu+eaWhGxwh--
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?1231541342.56664.19.camel>