NetBSD Problem Report #45686

From njoly@lanfeust.sis.pasteur.fr  Mon Dec  5 18:27:55 2011
Return-Path: <njoly@lanfeust.sis.pasteur.fr>
Received: from mail.netbsd.org (mail.netbsd.org [204.152.190.11])
	by www.NetBSD.org (Postfix) with ESMTP id D6E0C63B9C6
	for <gnats-bugs@gnats.NetBSD.org>; Mon,  5 Dec 2011 18:27:54 +0000 (UTC)
Message-Id: <20111205182749.B429CDC9BD@lanfeust.sis.pasteur.fr>
Date: Mon,  5 Dec 2011 19:27:49 +0100 (CET)
From: njoly@pasteur.fr
Reply-To: njoly@pasteur.fr
To: gnats-bugs@gnats.NetBSD.org
Subject: rump_server & rump.powerd LOCKDEBUG panic
X-Send-Pr-Version: 3.95

>Number:         45686
>Category:       bin
>Synopsis:       rump_server & rump.powerd LOCKDEBUG panic
>Confidential:   no
>Severity:       serious
>Priority:       medium
>Responsible:    bin-bug-people
>State:          closed
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Mon Dec 05 18:30:01 +0000 2011
>Closed-Date:    Sun Jan 24 14:30:44 +0000 2021
>Last-Modified:  Sun Jan 24 14:30:44 +0000 2021
>Originator:     Nicolas Joly
>Release:        NetBSD 5.99.58
>Organization:
Insitut Pasteur
>Environment:
System: NetBSD lanfeust.sis.pasteur.fr 5.99.58 NetBSD 5.99.58 (LANFEUST) #3: Sat Dec 3 22:20:39 CET 2011 njoly@lanfeust.sis.pasteur.fr:/local/src/NetBSD/obj.amd64/sys/arch/amd64/compile/LANFEUST amd64
Architecture: x86_64
Machine: amd64
>Description:
rump LOCKDEBUG pacic occurs when stopping rump.powerd previously connected to
a rump_server.

1) Launch the rump_server in a terminal.

njoly@lanfeust [/tmp/xx]> RUMP_SERVER="unix://socktest" 
njoly@lanfeust [/tmp/xx]> export RUMP_SERVER
njoly@lanfeust [/tmp/xx]> rump_server -s -l rumpvfs -l rumpdev -l rumpdev_sysmon ${RUMP_SERVER}
[...WAIT...]

2) Start and stop rump.powerd from a 2nd terminal

njoly@lanfeust [/tmp/xx]> RUMP_SERVER="unix://socktest" 
njoly@lanfeust [/tmp/xx]> export RUMP_SERVER
njoly@lanfeust [/tmp/xx]> rump.powerd -n -d
^C
njoly@lanfeust [/tmp/xx]> 

3) See a panic message in the 1st terminal.

[...WAIT...]
mutex error: lockdebug_unlocked: not locked

lock address : 0x000000007ff1ac10 type     :     sleep/adaptive
initialized  : 0x00007f7ff7875be1
shared holds :                  0 exclusive:                  0
shares wanted:                  0 exclusive:                255
current cpu  :                  0 last held:                  0
current lwp  : 0x000000007ff1a600 last held: 000000000000000000
last locked  : 0x00007f7ff788210d unlocked*: 0x00007f7ff788210d


panic: LOCKDEBUG
rump kernel halting...
halted
zsh: abort (core dumped)  rump_server -s -l rumpvfs -l rumpdev -l rumpdev_sysmon ${RUMP_SERVER}

Here follow the corresponding backtrace.

(gdb) bt
#0  0x00007f7ff64ebd5a in _lwp_kill () from /usr/lib/libc.so.12
#1  0x00007f7ff64eb692 in abort () at /local/src/NetBSD/src/lib/libc/stdlib/abort.c:74
#2  0x00007f7ff740983c in rumpuser_exit (rv=63)
    at /local/src/NetBSD/src/lib/librumpuser/rumpuser.c:541
#3  0x00007f7ff7885527 in cpu_reboot (howto=<optimized out>, bootstr=<optimized out>)
    at /local/src/NetBSD/src/lib/librump/../../sys/rump/librump/rumpkern/rump.c:557
#4  0x00007f7ff785defe in vpanic (fmt=0x7f7ff788e0d3 "LOCKDEBUG", ap=0x7f7fe63ff3d0)
    at /local/src/NetBSD/src/lib/librump/../../sys/rump/../kern/subr_prf.c:308
#5  0x00007f7ff785e003 in panic (fmt=0x3f <Address 0x3f out of bounds>)
    at /local/src/NetBSD/src/lib/librump/../../sys/rump/../kern/subr_prf.c:205
#6  0x00007f7ff784ba5a in lockdebug_abort1 (ld=0x7ff28440, s=0, func=<optimized out>, 
    msg=<optimized out>, dopanic=true)
    at /local/src/NetBSD/src/lib/librump/../../sys/rump/../kern/subr_lockdebug.c:784
#7  0x00007f7ff7881cdf in mutex_exit (mtx=0x7ff1ac10)
    at /local/src/NetBSD/src/lib/librump/../../sys/rump/librump/rumpkern/locks.c:135
#8  0x00007f7ff7881dab in docvwait (cv=0x7ff1ac58, mtx=0x7ff1ac10, ts=<optimized out>)
    at /local/src/NetBSD/src/lib/librump/../../sys/rump/librump/rumpkern/locks.c:315
#9  0x00007f7ff788210d in cv_timedwait (cv=0x7ff1ac58, mtx=<optimized out>, ticks=0)
    at /local/src/NetBSD/src/lib/librump/../../sys/rump/librump/rumpkern/locks.c:363
#10 0x00007f7ff787691f in kqueue_scan (kevbuf=0x7f7fe63ff660, retval=0x7f7fe63ff880, tsp=0x0, 
    ulistp=0x7f7fffffd840, maxevents=16, fp=<optimized out>, keops=<optimized out>, 
    kevcnt=<optimized out>)
t /local/src/NetBSD/src/lib/librump/../../sys/rump/../kern/kern_event.c:1161
#11 kevent1 (retval=0x7f7fe63ff880, fd=0, changelist=0x7f7fe63ff660, nchanges=0, 
    eventlist=0x7f7fffffd840, nevents=16, timeout=0x0, keops=0x7f7ff7ab3d40)
    at /local/src/NetBSD/src/lib/librump/../../sys/rump/../kern/kern_event.c:881
#12 0x00007f7ff7876bfb in sys___kevent50 (l=<optimized out>, uap=<optimized out>, 
    retval=<optimized out>)
    at /local/src/NetBSD/src/lib/librump/../../sys/rump/../kern/kern_event.c:802
#13 0x00007f7ff788515d in sy_call (rval=0x7f7fe63ff880, uap=0x7f7ff7701230, l=0x7ff1a600, 
    sy=0x7f7ff7aba5b0) at /local/src/NetBSD/src/lib/librump/../../sys/rump/../sys/syscallvar.h:61
#14 rump_proxy_syscall (num=<optimized out>, arg=0x7f7ff7701230, retval=0x7f7fe63ff880)
    at /local/src/NetBSD/src/lib/librump/../../sys/rump/librump/rumpkern/rump.c:740
#15 0x00007f7ff7406b01 in rumpsyscall (retval=0x7f7fe63ff880, data=0x7f7ff7701230, sysnum=435)
    at /local/src/NetBSD/src/lib/librumpuser/rumpuser_sp.c:223
#16 serv_handlesyscall (data=0x7f7ff7701230 "", spc=0x7f7ff760c9a8, rhdr=<optimized out>)
    at /local/src/NetBSD/src/lib/librumpuser/rumpuser_sp.c:635
#17 serv_workbouncer (arg=<optimized out>) at /local/src/NetBSD/src/lib/librumpuser/rumpuser_sp.c:717
#18 0x00007f7ff7009cd5 in pthread__create_tramp (cookie=0x7f7fe6000000)
    at /local/src/NetBSD/src/lib/libpthread/pthread.c:492
#19 0x00007f7ff6476420 in ___lwp_park50 () from /usr/lib/libc.so.12
#20 0x00007f7fe6400000 in ?? ()
#21 0x00007f7ff7fe32c0 in ?? ()
#22 0x0000000111110001 in ?? ()
#23 0x0000000033330003 in ?? ()
#24 0x0000000000000000 in ?? ()

>How-To-Repeat:
Repeat the testcase on a RUMPLOCKDEBUG=yes rump build.
>Fix:

>Release-Note:

>Audit-Trail:

State-Changed-From-To: open->feedback
State-Changed-By: jdolecek@NetBSD.org
State-Changed-When: Sun, 24 Jan 2021 13:20:25 +0000
State-Changed-Why:
Any chance to check if this still happens? This looks like locking bug
in kqueue_scan(), and code around the cv_timedwait_sig() looks like
it's now impossible to trigger.


State-Changed-From-To: feedback->closed
State-Changed-By: jdolecek@NetBSD.org
State-Changed-When: Sun, 24 Jan 2021 14:30:44 +0000
State-Changed-Why:
Sadly no chance for feeedback.


>Unformatted:

Home	PR Database Search