port-sparc/56078: sparc audioamd(4) KASSERT on playing audio

[Izumi Tsutsui <tsutsui%ceres.dti.ne.jp@localhost>]

>Number:         56078
>Category:       port-sparc
>Synopsis:       sparc audioamd(4) KASSERT on playing audio
>Confidential:   no
>Severity:       critical
>Priority:       medium
>Responsible:    port-sparc-maintainer
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Sun Mar 28 04:10:00 +0000 2021
>Originator:     Izumi Tsutsui
>Release:        NetBSD 9.1
>Organization:
>Environment:
System: NetBSD 9.1 NetBSD 9.1 (GENERIC) #0: Sun Oct 18 19:24:30 UTC 2020 mkrepro%mkrepro.NetBSD.org@localhost:/usr/src/sys/arch/sparc/compile/GENERIC sparc
Architecture: sparc
Machine: sparc
>Description:
audioamd(4) (at least on my SPARCclassic) gets KASSERT on playing audio:

(OCR'ed from the picture of CG3 screen; crashdump doesn't work either?)

---
# uname -a
NetBSD 9.1 NetBSD 9.1 (GENERIC) #0: Sun Oct 18 19:24:30 UTC 2020 mkrepro%mkrepro.NetBSD.org@localhost:/usr/src/sys/arch/sparc/compile/GENERIC sparc
# sysctl hw.model
hw.model = SUNW, SPARCclassic (TI, TMS390S10 @ 50 MHz, on-chip FPU)
# dmesg -t | grep audio
audioamd0 at sbus0 slot 4 offset 0x1300000 level 7 (ipl 13) softpri 4
audio0 at audioamd0: playback, capture, full duplex
audio0: slinear_be:16 -> mulaw:8 1ch 8000Hz, blk 320 bytes (40ms) for playback
audio0: slinear_be:16 <- mulaw:8 1ch 8000Hz, blk 320 bytes (40ms) for recording
# audioplay UnlimitedSpark.wav
[ 983.5083220] panic: Kernel diagnostic assertion "mutex_owned(sc->sc_intr_lock)" failed: file "/usr/src/sys/dev/audio/audio.c", line 5497
[ 983.53224601 cpu0: Begin traceback...
[ 983.5408280] 0x0(0xf04546e8, 0xf2c6de50, 0xf0549000, 0xf0549c00, 0xf0549e50, 0x104) at netbsd:kern_assert+0x38
[ 983.5883190] kern_assert(0xf04546e8, 0xf04546d8, 0xf047ab48, 0xf0479608, 0x1579, 0x41400fe5) at netbsd:audio_pintr+0x1a8
[ 983.6483100] audio_pintr(0xf0750088, 0xf0549c00, 0xf0002000, 0xf052229c, 0xf070fb20, 0xf070fb20) at netbsd:am7930swintr+0x64
[ 983.6983150] am7930swintr(0xf074a0d8, 0x0, 0x0, 0xf070f020, 0x242, 0xf074a0c8) at netbsd:softint_thread+0x130
[ 983.7683100] softint_thread(0xf049ad48, 0x0, 0xf2c60320, 0xf0002000, 0xf070fb20, 0x2000) at netbsd:lwp_trampoline+0x8
[ 983.79831201 cpu0: End traceback...
Stopped in pid 0.6 (system) at netbsd: cpu_Debugger+0x4:         or
%07, %go, %g1
db>

>How-To-Repeat:
audioplay(1) wav files on NetBSD/sparc 9.1 GENERIC as above.
(note options DIAGNOSTIC is unintentionally enabled on 9.1 GENERIC
 as noted in PR/56077)

>Fix:
The KASSERT is here:
 https://nxr.netbsd.org/xref/src/sys/dev/audio/audio.c?r=1.28.2.16#5497
---
   5490 static void
   5491 audio_pintr(void *arg)
   5492 {
   5493 	struct audio_softc *sc;
   5494 	audio_trackmixer_t *mixer;
   5495 
   5496 	sc = arg;
   5497 	KASSERT(mutex_owned(sc->sc_intr_lock));
---

audio_pintr() is called from am7930swintr() as the backtrace says:

 https://nxr.netbsd.org/xref/src/sys/arch/sparc/dev/audioamd.c?r=1.29#452
---
    452 void
    453 am7930swintr(void *sc0)
    454 {
    455 	struct audioamd_softc *sc;
    456 	struct auio *au;
    457 	bool pint;
    458 
    459 	sc = sc0;
    460 	DPRINTFN(1, ("audiointr: sc=%p\n", sc););
    461 
    462 	au = &sc->sc_au;
    463 
    464 	mutex_spin_enter(&sc->sc_am7930.sc_lock);
    465 	if (au->au_rdata > au->au_rend && sc->sc_rintr != NULL) {
    466 		(*sc->sc_rintr)(sc->sc_rarg);
    467 	}
    468 	pint = (au->au_pdata > au->au_pend && sc->sc_pintr != NULL);
    469 	if (pint)
    470 		(*sc->sc_pintr)(sc->sc_parg);
    471 
    472 	mutex_spin_exit(&sc->sc_am7930.sc_lock);
    473 }
---

Maybe "sc->sc_am7930.sc_lock" in the am7930swintr() was
typo of "sc->sc_am7930.sc_intr_lock", as a commit log in
the jmcneill-audiomp3 branch:

 http://cvsweb.netbsd.org/bsdweb.cgi/src/sys/arch/sparc/dev/audioamd.c#rev1.26.4.2
> use the sc_intr_lock when calling the rint/tint functions.

 http://cvsweb.netbsd.org/bsdweb.cgi/src/sys/arch/sparc/dev/audioamd.c.diff?r1=1.26.4.1&r2=1.26.4.2
---
--- src/sys/arch/sparc/dev/audioamd.c	2011/11/20 10:56:18	1.26.4.1
+++ src/sys/arch/sparc/dev/audioamd.c	2011/11/20 12:04:42	1.26.4.2
[snip]
@@ -477,16 +477,16 @@ am7930swintr(void *sc0)
 	DPRINTFN(1, ("audiointr: sc=%p\n", sc););
 
 	au = &sc->sc_au;
-	mutex_spin_enter(&sc->sc_lock);
+
+	mutex_spin_enter(&sc->sc_am7930.sc_lock);
 	if (au->au_rdata > au->au_rend && sc->sc_rintr != NULL) {
-		mutex_spin_exit(&sc->sc_lock);
 		(*sc->sc_rintr)(sc->sc_rarg);
-		mutex_spin_enter(&sc->sc_lock);
 	}
 	pint = (au->au_pdata > au->au_pend && sc->sc_pintr != NULL);
-	mutex_spin_exit(&sc->sc_lock);
 	if (pint)
 		(*sc->sc_pintr)(sc->sc_parg);
+
+	mutex_spin_exit(&sc->sc_am7930.sc_lock);
 }
---

The following change just works at least on my SPARCclassic:

---
Index: sys/arch/sparc/dev/audioamd.c
===================================================================
RCS file: /cvsroot/src/sys/arch/sparc/dev/audioamd.c,v
retrieving revision 1.29
diff -u -p -d -r1.29 audioamd.c
--- sys/arch/sparc/dev/audioamd.c	8 May 2019 13:40:16 -0000	1.29
+++ sys/arch/sparc/dev/audioamd.c	28 Mar 2021 03:41:59 -0000
@@ -461,7 +461,7 @@ am7930swintr(void *sc0)
 
 	au = &sc->sc_au;
 
-	mutex_spin_enter(&sc->sc_am7930.sc_lock);
+	mutex_spin_enter(&sc->sc_am7930.sc_intr_lock);
 	if (au->au_rdata > au->au_rend && sc->sc_rintr != NULL) {
 		(*sc->sc_rintr)(sc->sc_rarg);
 	}
@@ -469,7 +469,7 @@ am7930swintr(void *sc0)
 	if (pint)
 		(*sc->sc_pintr)(sc->sc_parg);
 
-	mutex_spin_exit(&sc->sc_am7930.sc_lock);
+	mutex_spin_exit(&sc->sc_am7930.sc_intr_lock);
 }
 
 

---
Izumi Tsutsui