Guy Helmer
2007-Jan-31 16:44 UTC
6.2 amd64 panic: lockmgr: thread 0xffffff009f9fd000, not exclusive lock holder 0xffffff003961c000 unlocking
Does this make sense to anyone (it doesn't to me - procfs_doprofile
simply locks, calls vn_fullpath, and unlocks)? I was trying to track
down a hang by running a system under stress, and instead got this panic
as a result of a process running a perl script that looks through
/proc/; it occurred on a very busy system with lots of process churn.
Guy
Unread portion of the kernel message buffer:
panic: lockmgr: thread 0xffffff009f9fd000, not exclusive lock holder
0xffffff003961c000 unlocking
cpuid = 0
KDB: stack backtrace:
panic() at panic+0x2ae
lockmgr() at lockmgr+0x7a7
VOP_UNLOCK_APV() at VOP_UNLOCK_APV+0x49
procfs_doprocfile() at procfs_doprocfile+0x83
pfs_readlink() at pfs_readlink+0xda
VOP_READLINK_APV() at VOP_READLINK_APV+0x3d
kern_readlink() at kern_readlink+0x1a0
syscall() at syscall+0x642
Xfast_syscall() at Xfast_syscall+0xa8
--- syscall (58, FreeBSD ELF64, readlink), rip = 0x800bfcf1c, rsp =
0x7fffffffe8d8, rbp = 0x2 ---
KDB: enter: panic
Dumping 4094 MB (3 chunks)
chunk 0: 1MB (154 pages) ... ok
chunk 1: 3327MB (851552 pages) ... ok
chunk 2: 768MB (196608 pages) ...
#0 doadump () at pcpu.h:172
172 pcpu.h: No such file or directory.
in pcpu.h
(kgdb) where
#0 doadump () at pcpu.h:172
#1 0xffffffff801994b1 in db_fncall (dummy1=0, dummy2=0, dummy3=0,
dummy4=0x0)
at ../../../ddb/db_command.c:492
#2 0xffffffff80199905 in db_command_loop () at
../../../ddb/db_command.c:350
#3 0xffffffff8019b82d in db_trap (type=-1238384064, code=0)
at ../../../ddb/db_main.c:222
#4 0xffffffff80357f69 in kdb_trap (type=3, code=0, tf=0xffffffffb62fc340)
at ../../../kern/subr_kdb.c:473
#5 0xffffffff804c9c7c in trap (frame {tf_rdi = 0, tf_rsi = -2136928256,
tf_rdx = 0, tf_rcx = 1167470,
tf_r8 = 1048064, tf_r9 = 10, tf_rax = 18, tf_rbx = -2141887976, tf_rbp =
-1238383616, tf_r10 = -1238383856, tf_r11 = 4294967274, tf_r12 = 1,
tf_r13 = 256, tf_r14 = -1096833576960, tf_r15 = -1096833576960,
tf_trapno = 3, tf_addr = 0, tf_flags = 1, tf_err = 0, tf_rip =
-2143978945, tf_cs = 8, tf_rflags = 646, tf_rsp = -1238383616, tf_ss =
0}) at ../../../amd64/amd64/trap.c:442
#6 0xffffffff804b42fb in calltrap () at
../../../amd64/amd64/exception.S:168
#7 0xffffffff80357a3f in kdb_enter (msg=0x0) at cpufunc.h:63
#8 0xffffffff80338ae1 in panic (
fmt=0xffffffff80556218 "lockmgr: thread %p, not %s %p unlocking")
at ../../../kern/kern_shutdown.c:549
#9 0xffffffff80328d67 in lockmgr (lkp=0xffffff00b6159478, flags=6,
interlkp=0x40, td=0xffffff009f9fd000) at ../../../kern/kern_lock.c:373
#10 0xffffffff80514a59 in VOP_UNLOCK_APV (vop=0xffffffff806e97c0,
a=0xffffffffb62fc590) at vnode_if.c:1692
---Type <return> to continue, or q <return> to quit---
#11 0xffffffff802e5d53 in procfs_doprocfile (td=0xffffff009f9fd000,
p=0xffffff00ad340358, pn=0x0, sb=0xffffffffb62fc5e0, uio=0xffe00)
at vnode_if.h:870
#12 0xffffffff802eb11a in pfs_readlink (va=0x0) at pcpu.h:169
#13 0xffffffff805137cd in VOP_READLINK_APV (vop=0x12, a=0xffffffff80a11000)
at vnode_if.c:1481
#14 0xffffffff803af7a0 in kern_readlink (td=0xffffff009f9fd000,
path=0xffffffff80a11000 "04:59 woodcrest ph[56130]: "...,
pathseg=UIO_USERSPACE,
buf=0x7fffffffe8e0 <Address 0x7fffffffe8e0 out of bounds>,
bufseg=UIO_USERSPACE, count=1023) at vnode_if.h:772
#15 0xffffffff804ca5d2 in syscall (frame {tf_rdi = 5390024, tf_rsi =
140737488349408, tf_rdx = 1023, tf_rcx
= 0, tf_r8 = -3705797, tf_r9 = 140737488350424, tf_rax = 58, tf_rbx =
8804368, tf_rbp = 2, tf_r10 = 9341008, tf_r11 = 514, tf_r12 = 9144072,
tf_r13 = 140737488349408, tf_r14 = 0, tf_r15 = 0, tf_trapno = 22,
tf_addr = 0, tf_flags = 0, tf_err = 2, tf_rip = 34372308764, tf_cs = 43,
tf_rflags = 514, tf_rsp = 140737488349400, tf_ss = 35}) at
../../../amd64/amd64/trap.c:792
#16 0xffffffff804b4498 in Xfast_syscall ()
at ../../../amd64/amd64/exception.S:270
#17 0x0000000800bfcf1c in ?? ()
Previous frame inner to this frame (corrupt stack?)
(kgdb) frame 11
#11 0xffffffff802e5d53 in procfs_doprocfile (td=0xffffff009f9fd000,
p=0xffffff00ad340358, pn=0x0, sb=0xffffffffb62fc5e0, uio=0xffe00)
at vnode_if.h:870
870 vnode_if.h: No such file or directory.
in vnode_if.h
(kgdb) print fullpath
$1 = 0xffffff0000efeff2 "/usr/bin/file"
(kgdb) print *p->p_textvp
$1 = {v_type = VREG, v_tag = 0xffffffff8055cd4e "ufs",
v_op = 0xffffffff806f8d60, v_data = 0xffffff00b4fb6480,
v_mount = 0xffffff00123e5948, v_nmntvnodes = {tqe_next =
0xffffff00b5b169b0,
tqe_prev = 0xffffff00b45bb408}, v_un = {vu_mount = 0x0, vu_socket =
0x0,
vu_cdev = 0x0, vu_fifoinfo = 0x0}, v_hashlist = {le_next = 0x0,
le_prev = 0xffffff00b03f19f0}, v_hash = 10339468, v_cache_src = {
lh_first = 0x0}, v_cache_dst = {tqh_first = 0xffffff00b61afd68,
tqh_last = 0xffffff00b61afd88}, v_dd = 0x0, v_cstart = 0, v_lasta = 0,
v_lastw = 0, v_clen = 0, v_lock = {lk_interlock = 0xffffffff8071d3c0,
lk_flags = 262208, lk_sharecount = 0, lk_waitcount = 0,
lk_exclusivecount = 1, lk_prio = 80, lk_wmesg = 0xffffffff8055cd4e
"ufs",
lk_timo = 51, lk_lockholder = 0xffffff003961c000, lk_newlock = 0x0},
v_interlock = {mtx_object = {lo_class = 0xffffffff806dde60,
lo_name = 0xffffffff8055e550 "vnode interlock",
lo_type = 0xffffffff8055e550 "vnode interlock", lo_flags =
196608,
lo_list = {tqe_next = 0x0, tqe_prev = 0x0}, lo_witness = 0x0},
mtx_lock = 4, mtx_recurse = 0}, v_vnlock = 0xffffff00b6159478,
v_holdcnt = 8, v_usecount = 7, v_iflag = 0, v_vflag = 32, v_writecount
= 0,
v_freelist = {tqe_next = 0x0, tqe_prev = 0x0}, v_bufobj = {
bo_mtx = 0xffffff00b61594b0, bo_clean = {bv_hd = {tqh_first = 0x0,
tqh_last = 0xffffff00b6159538}, bv_root = 0x0, bv_cnt = 0},
bo_dirty = {bv_hd = {tqh_first = 0x0, tqh_last = 0xffffff00b6159558},
bv_root = 0x0, bv_cnt = 0}, bo_numoutput = 0, bo_flag = 0,
bo_ops = 0xffffffff806e8820, bo_bsize = 16384,
---Type <return> to continue, or q <return> to quit---
bo_object = 0xffffff00c276c000, bo_synclist = {le_next = 0x0,
le_prev = 0x0}, bo_private = 0xffffff00b61593e0,
__bo_vnode = 0xffffff00b61593e0}, v_pollinfo = 0x0, v_label = 0x0}
(kgdb) quit
opteron6:~ (502) exit
exit
Guy Helmer
2007-Feb-01 16:02 UTC
6.2 amd64 panic: lockmgr: thread 0xffffff009f9fd000, not exclusive lock holder 0xffffff003961c000 unlocking
Guy Helmer wrote:> Does this make sense to anyone (it doesn't to me - procfs_doprofile > simply locks, calls vn_fullpath, and unlocks)? I was trying to track > down a hang by running a system under stress, and instead got this > panic as a result of a process running a perl script that looks > through /proc/; it occurred on a very busy system with lots of process > churn.Does this change to src/sys/fs/procfs.c make sense? From my reading, it is possible for vn_lock(9) to fail... Index: procfs.c ==================================================================RCS file: /home/ncvs/src/sys/fs/procfs/procfs.c,v retrieving revision 1.12.2.1 diff -u -r1.12.2.1 procfs.c --- procfs.c 14 Jun 2006 21:20:39 -0000 1.12.2.1 +++ procfs.c 1 Feb 2007 15:19:30 -0000 @@ -69,8 +69,11 @@ { char *fullpath = "unknown"; char *freepath = NULL; + int err; - vn_lock(p->p_textvp, LK_EXCLUSIVE | LK_RETRY, td); + if ((err = vn_lock(p->p_textvp, LK_EXCLUSIVE | LK_RETRY, td)) != 0) { + return (err); + } vn_fullpath(td, p->p_textvp, &fullpath, &freepath); VOP_UNLOCK(p->p_textvp, 0, td); sbuf_printf(sb, "%s", fullpath);