Re: kern/55018: rump_server hangs

[Martin Husemann <martin%duskware.de@localhost>]

The following reply was made to PR kern/55018; it has been noted by GNATS.

From: Martin Husemann <martin%duskware.de@localhost>
To: gnats-bugs%NetBSD.org@localhost
Cc: Jason R Thorpe <thorpej%NetBSD.org@localhost>
Subject: Re: kern/55018: rump_server hangs
Date: Thu, 16 Apr 2020 21:29:27 +0200

 I build rump userland with RUMP_LOCKDEBUG and als ran the pppoe tests with
 DEBUG=true. This gave me two interesting parts in the output:
 
 tc-so:Executing command [ rump.ping6 -c 1 -X 3 fc00::1 ]
 tc-so:Executing command [ rump.ifconfig pppoe0 down ]
 tc-se:pppoectl: rumpclient init: Socket is not connected
 tc-se:pppoectl: rumpclient init: No such file or directory
 tc-se:pppoectl: rumpclient init: No such file or directory
 tc-se:pppoectl: rumpclient init: No such file or directory
 tc-se:pppoectl: rumpclient init: No such file or directory
 tc-se:pppoectl: rumpclient init: No such file or directory
 tc-se:pppoectl: rumpclient init: No such file or directory
 [...]
 
 But a lot more interesting: rump_server dies with a locking violation:
 
 Core was generated by `rump_server'.
 Program terminated with signal SIGABRT, Aborted.
 #0  0xbbc320ec in _lwp_kill () from /usr/lib/libc.so.12
 [Current thread is 1 (process 18)]
 #0  0xbbc320ec in _lwp_kill () from /usr/lib/libc.so.12
 #1  0xbbc30b18 in abort () at /work/src/lib/libc/stdlib/abort.c:74
 #2  0xbbce73f4 in rumpuser_exit (rv=-1221267880, rv@entry=-1)
     at /work/src/lib/librumpuser/rumpuser.c:236
 #3  0xbbe472f0 in cpu_reboot (howto=<optimized out>, bootstr=<optimized out>)
     at /work/src/lib/librump/../../sys/rump/librump/rumpkern/emul.c:431
 #4  0xbbdf9ac8 in kern_reboot (howto=4, bootstr=0x0)
     at /work/src/lib/librump/../../sys/rump/../kern/kern_reboot.c:73
 #5  0xbbdf89e4 in vpanic (fmt=0xbbe51238 "LOCKDEBUG: %s error: %s,%zu: %s", 
     fmt@entry=0xbbe5b020 "mutex_enter", ap=..., ap@entry=...)
     at /work/src/lib/librump/../../sys/rump/../kern/subr_prf.c:336
 #6  0xbbdf8ad8 in panic (fmt=0xbbe51238 "LOCKDEBUG: %s error: %s,%zu: %s")
     at /work/src/lib/librump/../../sys/rump/../kern/subr_prf.c:255
 #7  0xbbde67d0 in lockdebug_abort1 (dopanic=true, s=<optimized out>, 
     msg=0xbbe5139c "spin lock held", ld=0xbbea6948 <rumpns_ld_prime+32512>, 
     line=165, func=0xbbe5b020 "mutex_enter")
     at /work/src/lib/librump/../../sys/rump/../kern/subr_lockdebug.c:785
 #8  lockdebug_abort1 (func=func@entry=0xbbe5b020 "mutex_enter", 
     line=line@entry=165, ld=0xbbea6948 <rumpns_ld_prime+32512>, 
     msg=0xbbe5139c "spin lock held", dopanic=dopanic@entry=true, s=0)
     at /work/src/lib/librump/../../sys/rump/../kern/subr_lockdebug.c:763
 #9  0xbbde76f8 in lockdebug_barrier (func=0xbbe5b020 "mutex_enter", line=165, 
     onelock=0xbbd88974, slplocks=1)
     at /work/src/lib/librump/../../sys/rump/../kern/subr_lockdebug.c:633
 #10 0xbbe3f8a8 in mutex_enter (mtx=0xbbd88974)
     at /work/src/lib/librump/../../sys/rump/librump/rumpkern/locks.c:165
 #11 0xbbe47084 in kpause (wmesg=<optimized out>, intr=<optimized out>, 
     timeo=<optimized out>, mtx=0xbbd88974)
     at /work/src/lib/librump/../../sys/rump/librump/rumpkern/emul.c:153
 #12 0xbbd4cba8 in sched_sync (arg=<optimized out>)
     at /work/src/lib/librumpvfs/../../sys/rump/../kern/vfs_subr.c:838
 #13 0xbbe42c24 in threadbouncer (arg=0xbb936680)
     at /work/src/lib/librump/../../sys/rump/librump/rumpkern/threads.c:90
 #14 0xbbcbc9a4 in pthread__create_tramp (cookie=0xbb867000)
     at /work/src/lib/libpthread/pthread.c:548
 
 
 Jason, that sounds like a real bug and should be reproducable outside of
 rump too.
 
 Martin