NetBSD Problem Report #54427

From www@netbsd.org  Thu Aug  1 16:40:56 2019
Return-Path: <www@netbsd.org>
Received: from mail.netbsd.org (mail.netbsd.org [199.233.217.200])
	(using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits))
	(Client CN "mail.NetBSD.org", Issuer "mail.NetBSD.org CA" (not verified))
	by mollari.NetBSD.org (Postfix) with ESMTPS id D8BA67A153
	for <gnats-bugs@gnats.NetBSD.org>; Thu,  1 Aug 2019 16:40:56 +0000 (UTC)
Message-Id: <20190801164055.DF5D07A1B4@mollari.NetBSD.org>
Date: Thu,  1 Aug 2019 16:40:55 +0000 (UTC)
From: coypu@sdf.org
Reply-To: coypu@sdf.org
To: gnats-bugs@NetBSD.org
Subject: panic in audio_close
X-Send-Pr-Version: www-1.0

>Number:         54427
>Category:       kern
>Synopsis:       panic in audio_close
>Confidential:   no
>Severity:       serious
>Priority:       medium
>Responsible:    kern-bug-people
>State:          closed
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Thu Aug 01 16:45:00 +0000 2019
>Closed-Date:    Sun Feb 23 07:38:27 +0000 2020
>Last-Modified:  Sat Mar 21 15:50:01 +0000 2020
>Originator:     coypu
>Release:        NetBSD 8.99.47
>Organization:
>Environment:
NetBSD planets 8.99.47 NetBSD 8.99.47 (GENERIC) #2: Tue Jun 25 05:55:09 UTC 2019  fly@ns3105053:/home/fly/obj/sys/arch/amd64/compile/GENERIC amd64

>Description:
What I was doing: using bluetooth for an audio headset.

bta2dpd -a headset /dev/pad
audioplay -d /dev/sound2 sample.wav

close the connection on the headphone side.

[ 32606.423289] pad0: outputs: 44100Hz, 16-bit, stereo
[ 32606.423289] audio2 at pad0: playback
[ 32606.423289] audio2: slinear_le:16 -> slinear_le:16 2ch 44100Hz, blk 40ms for playback
[ 32606.423289] spkr3 at audio2: PC Speaker (synthesized)
[ 32606.423289] wsbell at spkr3 not configured
[ 32640.199598] spkr3: detached
[ 32640.199598] audio2: detached
[ 32640.199598] pad0: detached
[ 32640.199598] uvm_fault(0xffffffff8171e120, 0xffff888008e89000, 1) -> e
[ 32640.199598] fatal page fault in supervisor mode
[ 32640.199598] trap type 6 code 0 rip 0xffffffff809c4208 cs 0x8 rflags 0x10282 cr2 0xffff888008e89038 ilevel 0 rsp 0xffff888069373d80
[ 32640.199598] curlwp 0xffff80af3f1ef6c0 pid 7625.1 lowest kstack 0xffff8880693702c0
[ 32640.199598] panic: trap
[ 32640.199598] cpu0: Begin traceback...
[ 32640.199598] vpanic() at netbsd:vpanic+0x160
[ 32640.199598] snprintf() at netbsd:snprintf
[ 32640.199598] startlwp() at netbsd:startlwp
[ 32640.199598] alltraps() at netbsd:alltraps+0xc3
[ 32640.199598] audio_close() at netbsd:audio_close+0x21
[ 32640.199598] audioclose() at netbsd:audioclose+0x7a
[ 32640.209604] fatal page fault in supervisor mode
[ 32640.209604] trap type 6 code 0x2 rip 0xffffffff809edfc1 cs 0x8 rflags 0x10202 cr2 0xffff888008e89050 ilevel 0x8 rsp 0xffff888064f56030
[ 32640.209604] curlwp 0xffff80afca80d060 pid 0.5 lowest kstack 0xffff888064f522c0
[ 32640.209604] Skipping crash dump on recursive panic
[ 32640.209604] panic: trap
[ 32640.209604] Faulted in mid-traceback; aborting...
[ 32640.209604] rebooting...


I guess pad disappeared before audio_close happened, destroying sc->sc_lock.

(gdb) disas *(audio_close+0x21)
Dump of assembler code for function audio_close:
   0xffffffff807a5588 <+0>:	push   %rbp
   0xffffffff807a5589 <+1>:	mov    %rsp,%rbp
   0xffffffff807a558c <+4>:	push   %r14
   0xffffffff807a558e <+6>:	push   %r13
   0xffffffff807a5590 <+8>:	push   %r12
   0xffffffff807a5592 <+10>:	push   %rbx
   0xffffffff807a5593 <+11>:	sub    $0x10,%rsp
   0xffffffff807a5597 <+15>:	mov    %rdi,%rbx
   0xffffffff807a559a <+18>:	mov    %rsi,%r12
   0xffffffff807a559d <+21>:	mov    0x180(%rdi),%rdi
   0xffffffff807a55a4 <+28>:	callq  0xffffffff809c41ff <mutex_owned>
   0xffffffff807a55a9 <+33>:	test   %eax,%eax
>How-To-Repeat:

>Fix:

>Release-Note:

>Audit-Trail:
From: Tetsuya Isaki <isaki@pastel-flower.jp>
To: gnats-bugs@netbsd.org
Cc: kern-bug-people@netbsd.org,
	gnats-admin@netbsd.org,
	netbsd-bugs@netbsd.org
Subject: Re: kern/54427: panic in audio_close
Date: Fri, 02 Aug 2019 12:23:25 +0900

 At Thu,  1 Aug 2019 16:45:00 +0000 (UTC),
 coypu@sdf.org wrote:
 > >Description:
 > What I was doing: using bluetooth for an audio headset.
 > 
 > bta2dpd -a headset /dev/pad
 > audioplay -d /dev/sound2 sample.wav

 Yeah this is reproducible easily and I've stucked.

 -----
 #include <err.h>
 #include <fcntl.h>
 #include <stdio.h>
 #include <unistd.h>
 int main(int ac, char *av[])
 {
 	const char *devaudio = "/dev/audio1";	/* set your device */
 	int fdpad;
 	int fdaudio;
 	int r;

 	fdpad = open("/dev/pad", O_RDONLY);
 	if (fdpad == -1)
 		err(1, "open: dev/pad");


 	fdaudio = open(devaudio, O_WRONLY);
 	if (fdaudio == -1)
 		err(1, "open: dev/audio");

 	close(fdpad);
 	close(fdaudio);
 	return 0;
 }
 -----

 First, when pad is closed, audiodetach is called from pad_close
 but it doesn't close any associated audio descriptors.
 When audio is closed then, pad(lower layer)'s resources are
 no longer available.

 I wonder why this code does not close descriptors...

 sys/dev/audio/audio.c:
    1219 audiodetach(device_t self, int flags)
    1220 {
       :
    1252     /*
    1253      * Nuke the vnodes for any open instances (calls close).
    1254      * Will wait until any activity on the device nodes has ceased.
    1255      */
    1256     mn = device_unit(self);
    1257     vdevgone(maj, mn | SOUND_DEVICE,    mn | SOUND_DEVICE, VCHR);
    1258     vdevgone(maj, mn | AUDIO_DEVICE,    mn | AUDIO_DEVICE, VCHR);
    1259     vdevgone(maj, mn | AUDIOCTL_DEVICE, mn | AUDIOCTL_DEVICE, VCHR);
    1260     vdevgone(maj, mn | MIXER_DEVICE,    mn | MIXER_DEVICE, VCHR);

 ---
 Tetsuya Isaki <isaki@pastel-flower.jp / isaki@NetBSD.org>

From: "Tetsuya Isaki" <isaki@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc: 
Subject: PR/54427 CVS commit: src/sys/dev/audio
Date: Sun, 23 Feb 2020 07:17:01 +0000

 Module Name:	src
 Committed By:	isaki
 Date:		Sun Feb 23 07:17:01 UTC 2020

 Modified Files:
 	src/sys/dev/audio: audio.c audiodef.h audiovar.h

 Log Message:
 Prevent a race between audiodetach and fileops methods using psref(9).
 Fix PR kern/54427.
 Thank you so much riastradh@


 To generate a diff of this commit:
 cvs rdiff -u -r1.55 -r1.56 src/sys/dev/audio/audio.c
 cvs rdiff -u -r1.9 -r1.10 src/sys/dev/audio/audiodef.h
 cvs rdiff -u -r1.7 -r1.8 src/sys/dev/audio/audiovar.h

 Please note that diffs are not public domain; they are subject to the
 copyright notices on the relevant files.

State-Changed-From-To: open->closed
State-Changed-By: isaki@NetBSD.org
State-Changed-When: Sun, 23 Feb 2020 07:38:27 +0000
State-Changed-Why:
Fixed in -current.  Thank you for reporting.
I will pullup netbsd-9 later.


From: "Martin Husemann" <martin@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc: 
Subject: PR/54427 CVS commit: [netbsd-9] src/sys/dev/audio
Date: Sat, 21 Mar 2020 15:47:01 +0000

 Module Name:	src
 Committed By:	martin
 Date:		Sat Mar 21 15:47:01 UTC 2020

 Modified Files:
 	src/sys/dev/audio [netbsd-9]: audio.c audiodef.h audiovar.h

 Log Message:
 Pull up following revision(s) (requested by isaki in ticket #794):

 	sys/dev/audio/audiodef.h: revision 1.10
 	sys/dev/audio/audio.c: revision 1.56 (via patch)
 	sys/dev/audio/audio.c: revision 1.57
 	sys/dev/audio/audiovar.h: revision 1.8
 	sys/dev/audio/audio.c: revision 1.38

 Remove obsoleted comment.

 Prevent a race between audiodetach and fileops methods using psref(9).
 Fix PR kern/54427.
 Thank you so much riastradh@

 Release memories on audiobellclose.
 It's rest of the last commit.


 To generate a diff of this commit:
 cvs rdiff -u -r1.28.2.8 -r1.28.2.9 src/sys/dev/audio/audio.c
 cvs rdiff -u -r1.7.2.2 -r1.7.2.3 src/sys/dev/audio/audiodef.h
 cvs rdiff -u -r1.4.2.1 -r1.4.2.2 src/sys/dev/audio/audiovar.h

 Please note that diffs are not public domain; they are subject to the
 copyright notices on the relevant files.

>Unformatted:

Home	PR Database Search