NetBSD Problem Report #50613

From o.vd.linden@quicknet.nl  Sat Jan  2 23:08:24 2016
Return-Path: <o.vd.linden@quicknet.nl>
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 "Postmaster NetBSD.org" (verified OK))
	by mollari.NetBSD.org (Postfix) with ESMTPS id 8AD517ABE7
	for <gnats-bugs@gnats.NetBSD.org>; Sat,  2 Jan 2016 23:08:24 +0000 (UTC)
Message-Id: <20160102230816.GA1444@sheep>
Date: Sun, 3 Jan 2016 00:08:16 +0100
From: Onno van der Linden <o.vd.linden@quicknet.nl>
To: gnats-bugs@netbsd.org
Subject: unpausing audio(4) causes already written data to be dropped

>Number:         50613
>Category:       kern
>Synopsis:       unpausing audio(4) causes already written data to be dropped
>Confidential:   no
>Severity:       serious
>Priority:       medium
>Responsible:    nat
>State:          closed
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Sat Jan 02 23:10:00 +0000 2016
>Closed-Date:    Mon Jan 23 21:19:18 +0000 2017
>Last-Modified:  Mon Jan 23 21:19:18 +0000 2017
>Originator:     Onno van der Linden
>Release:        NetBSD 7.99.25
>Organization:

>Environment:
	<The following information is extracted from your kernel. Please>
	<append output of "ldd", "ident" where relevant (multiple lines).>
System: NetBSD sheep 7.99.25 NetBSD 7.99.25 (SHEEP) #8: Sat Jan 2 18:34:49 MET 2016 onno@sheep:/usr/src/sys/arch/i386/compile/SHEEP i386
Architecture: i386
Machine: i386
>Description:
Writing several buffers to the audio device in a paused state and
unpausing after the kernel internal audio buffers are full will cause
the previously written buffers to be dropped.
>How-To-Repeat:
Port sndio-1.0.1 to NetBSD (pkgsrc-wip and a patch for libsndio/sio_sun.c from me) ,run the daemon on a kernel compiled with AUDIO_DEBUG=3 , play a wav with aucat from the same package and in /var/log/messages I see:

Jan  1 10:21:02 sheep /netbsd: audio_write: sc=0xc2c30800 count=3840 used=26880(hi=30720)
--- Notice the used=26880, 7 blocks have already been written to /dev/audio,
--- but the output hasn't started yet because the device is still paused
Jan  1 10:21:02 sheep /netbsd: audio_poll: events=0x1c mode=5
--- Here comes the call from sio_sun_autostart() to unpause
Jan  1 10:21:02 sheep /netbsd: audio_ioctl(136,'A',22)
Jan  1 10:21:02 sheep /netbsd: AUDIO_SETINFO mode=0x5
Jan  1 10:21:02 sheep /netbsd: audiosetinfo sc=0xc2c30800 ai=0xc2df2058
--- But before audio output is started, the ringbuffer gets a reset
--- which means that all the blocks written before in pause mode are lost
Jan  1 10:21:02 sheep /netbsd: audio_initbufs: mode=0x5
Jan  1 10:21:02 sheep /netbsd: audio_init_ringbuffer: MI blksize=3840
Jan  1 10:21:02 sheep /netbsd: audio_init_ringbuffer: final blksize=3840
Jan  1 10:21:02 sheep /netbsd: audio_init_ringbuffer: MI blksize=3840
Jan  1 10:21:02 sheep /netbsd: audio_init_ringbuffer: final blksize=3840
Jan  1 10:21:02 sheep /netbsd: audiostartp: start=0xda69c000 used=0(hi=30720 blk=3840) mmapped=0
--- Because of the used=0 audiostartp only does a "wakeup and return"
--- And now sndiod has a complete different view from the kernel resulting
--- in a watchdog timeout message from sndiod

>Fix:

The cause for this is the 1.196 commit (Sat Jun 11 08:14:19 2005 UTC)
saying 
"Make sure buffer sizes are initialized correctly even when the pause state
is explicitly set. Without this, the machine would crash in the audio interupt
when the driver needs to divide by the block size (e.g., cs4281.c/cs4280.c).
Idea for the fix by yamt."

Possible fix below but I wonder if it's really necessary.
Isn't audio_attach_mi() already setting the blocksize ?
Or is there a window of opportunity between enabling the
interrupt and audio_attach_mi() ?
audio_attach_mi() did exist when the 1.196 fix was made
so I might be wrong.


--- /usr/src/sys/dev/audio.c.orig	2015-12-31 16:27:13.000000000 +0100
+++ /usr/src/sys/dev/audio.c	2016-01-01 14:29:48.000000000 +0100
@@ -3579,7 +3579,7 @@
 	int oldpblksize, oldrblksize;
 	u_int gain;
 	bool rbus, pbus;
-	bool cleared, modechange, pausechange;
+	bool cleared, modechange, pausechange, initbufs;
 	u_char balance;

 	KASSERT(mutex_owned(sc->sc_lock));
@@ -3597,6 +3597,7 @@
 	cleared = false;
 	modechange = false;
 	pausechange = false;
+	initbufs = true;

 	pp = sc->sc_pparams;	/* Temporary encoding storage in */
 	rp = sc->sc_rparams;	/* case setting the modes fails. */
@@ -3830,11 +3831,15 @@
 		sc->sc_pr.pause = p->pause;
 		pbus = !p->pause;
 		pausechange = true;
+		if (sc->sc_pr.maxblks > 0)
+			initbufs = false;
 	}
 	if (SPECIFIED_CH(r->pause)) {
 		sc->sc_rr.pause = r->pause;
 		rbus = !r->pause;
 		pausechange = true;
+		if (sc->sc_rr.maxblks > 0)
+			initbufs = false;
 	}

 	if (SPECIFIED(ai->blocksize)) {
@@ -3898,7 +3903,7 @@
 		int init_error;

 		mutex_enter(sc->sc_intr_lock);
-		init_error = audio_initbufs(sc);
+		init_error = initbufs ? audio_initbufs(sc): 0;
 		if (init_error) goto err;
 		if (sc->sc_pr.blksize != oldpblksize ||
 		    sc->sc_rr.blksize != oldrblksize ||

>Release-Note:

>Audit-Trail:
From: Onno van der Linden <o.vd.linden@quicknet.nl>
To: gnats-bugs@NetBSD.org
Cc: 
Subject: Re: kern/50613: unpausing audio(4) causes already written data to be
 dropped
Date: Mon, 4 Jan 2016 21:27:26 +0100

 And a test case

 #include <sys/audioio.h>
 #include <stdio.h>
 #include <fcntl.h>
 #include <string.h>

 main()
 {
         int     fd;
         char    buf[1024];
 	unsigned long	wseek;
         audio_offset_t  ao;
         struct audio_info       ai;

         memset(buf,'\0',sizeof buf);
         AUDIO_INITINFO(&ai);
         fd=open("/dev/audio",O_WRONLY,0);
         ai.play.pause=1;
         ai.blocksize=1024;
         ioctl(fd, AUDIO_SETINFO, &ai);
         ioctl(fd, AUDIO_GETOOFFS, &ao);
         printf("After open/pause samples=%u deltablks=%u offset=%u\n",ao.samples,ao.deltablks, ao.offset);
         write(fd,buf,sizeof buf);
         ioctl(fd, AUDIO_GETOOFFS, &ao);
         printf("After write samples=%u deltablks=%u offset=%u\n",ao.samples,ao.deltablks, ao.offset);
         AUDIO_INITINFO(&ai);
         ai.play.pause=0;
         ioctl(fd, AUDIO_SETINFO, &ai);
         ioctl(fd, AUDIO_GETOOFFS, &ao);
         printf("After unpause samples=%u deltablks=%u offset=%u\n",ao.samples,ao.deltablks, ao.offset);
         write(fd,buf,sizeof buf);
         ioctl(fd, AUDIO_DRAIN);
         ioctl(fd, AUDIO_GETOOFFS, &ao);
         printf("After write samples=%u deltablks=%u offset=%u\n",ao.samples,ao.deltablks, ao.offset);
         close(fd);
 }

 Run straight after booting an unpatched kernel:

 After open/pause samples=0 deltablks=0 offset=1024 
 After write samples=1024 deltablks=1 offset=2048
 After unpause samples=0 deltablks=0 offset=2048 
 After write samples=1024 deltablks=1 offset=3072


 Run straight after booting a kernel with the patch:
 After open/pause samples=0 deltablks=0 offset=1024 
 After write samples=1024 deltablks=1 offset=2048
 After unpause samples=1024 deltablks=0 offset=2048 
 After write samples=2048 deltablks=1 offset=3072

 samples=0 after unpause vs. samples=1024 after unpause

From: Kamil Rytarowski <n54@gmx.com>
To: gnats-bugs@NetBSD.org
Cc: 
Subject: Re: kern/50613: unpausing audio(4) causes already written data to be
 dropped
Date: Mon, 4 Jan 2016 22:57:33 +0100

 -----BEGIN PGP SIGNED MESSAGE-----
 Hash: SHA256

 On 04.01.2016 22:50, Onno van der Linden wrote:
 > The following reply was made to PR kern/50613; it has been noted
 > by GNATS.
 > 
 > From: Onno van der Linden <o.vd.linden@quicknet.nl> To: 
 > gnats-bugs@NetBSD.org Cc: Subject: Re: kern/50613: unpausing 
 > audio(4) causes already written data to be dropped Date: Mon, 4
 > Jan 2016 21:27:26 +0100
 > 
 > And a test case
 > 
 > #include <sys/audioio.h> #include <stdio.h> #include <fcntl.h> 
 > #include <string.h>
 > 
 > main() { int     fd; char    buf[1024]; unsigned long	wseek; 
 > audio_offset_t  ao; struct audio_info       ai;
 > 
 > memset(buf,'\0',sizeof buf); AUDIO_INITINFO(&ai); 
 > fd=open("/dev/audio",O_WRONLY,0); ai.play.pause=1; 
 > ai.blocksize=1024; ioctl(fd, AUDIO_SETINFO, &ai); ioctl(fd, 
 > AUDIO_GETOOFFS, &ao); printf("After open/pause samples=%u 
 > deltablks=%u offset=%u\n",ao.samples,ao.deltablks, ao.offset); 
 > write(fd,buf,sizeof buf); ioctl(fd, AUDIO_GETOOFFS, &ao); 
 > printf("After write samples=%u deltablks=%u 
 > offset=%u\n",ao.samples,ao.deltablks, ao.offset); 
 > AUDIO_INITINFO(&ai); ai.play.pause=0; ioctl(fd, AUDIO_SETINFO, 
 > &ai); ioctl(fd, AUDIO_GETOOFFS, &ao); printf("After unpause 
 > samples=%u deltablks=%u offset=%u\n",ao.samples,ao.deltablks, 
 > ao.offset); write(fd,buf,sizeof buf); ioctl(fd, AUDIO_DRAIN); 
 > ioctl(fd, AUDIO_GETOOFFS, &ao); printf("After write samples=%u 
 > deltablks=%u offset=%u\n",ao.samples,ao.deltablks, ao.offset); 
 > close(fd); }
 > 
 > Run straight after booting an unpatched kernel:
 > 
 > After open/pause samples=0 deltablks=0 offset=1024 After write 
 > samples=1024 deltablks=1 offset=2048 After unpause samples=0 
 > deltablks=0 offset=2048 After write samples=1024 deltablks=1 
 > offset=3072
 > 
 > 
 > Run straight after booting a kernel with the patch: After 
 > open/pause samples=0 deltablks=0 offset=1024 After write 
 > samples=1024 deltablks=1 offset=2048 After unpause samples=1024 
 > deltablks=0 offset=2048 After write samples=2048 deltablks=1 
 > offset=3072
 > 
 > samples=0 after unpause vs. samples=1024 after unpause
 > 
 > 


 Thank you. If that's not too much. Can you try to write a new test or
 set of tests to ensure it works and will work in the future for everybod
 y?

 This patch makes sense.
 -----BEGIN PGP SIGNATURE-----
 Version: GnuPG v2

 iQIcBAEBCAAGBQJWiurLAAoJEEuzCOmwLnZsnn8QAMM5REaue6Mu0brWL8j9Yk51
 K5aPxO3eyFKtYI54YgX2KOowG0PPdrjAMsR8HGrQlhD2ego50k7m9E8rxxQ0I3fc
 36V8HIcouG6U4MgK4JN3e5FqlHH9fniEwVkkZ+EW09zVXkB+FEy/2/JyZh7V9fwo
 VSsN7yK71q8zev7mVjkoxnd6jNW9MoP/VKMyxg/ffaNkeqZqmuJ4q8A2JiGoiR81
 3kxrodD5JkBeSqjD1N52iptf0aFviCsGq8cfxIG+xtrfPUP6L9z/y+iDoy3a8ReD
 DhcRrYVsUozHFBlaIhTGjh2UVOX0zWNl0ReXdJGeyyo+c/44xkZIpsN+5dGFPiFP
 YIcY7BdMca989Mva0EI7qIE8kfueP2ItiMQa1TknVyD1QnDruJ+xPgP1emkO8CGi
 RGkNfWeM5ng2/YhxDKRUYlVSsbDTGoTxeCrwbLMgcnNDGtSOq4IiyelV8LC5b4kG
 I1jTb8fkOJd0JqnwMDEi3NVBZ8LtMhadMejiMwUWV94AHSFoRZuJ7gQ4JyBp5noh
 14CiQRDbbYuybAAMWQUNbGwt8x3Hd5KY/FYWqLbMI2lEERLiTy8Xg6LWzqQsey7i
 BJTRBoL/xiIEE6ZF+rUNsBGvJYVnEH1luHjcpC7kbmPCDzOD+uNRiVxH2erfv/JL
 SKLXKgZTYSnLReur41Qq
 =fZra
 -----END PGP SIGNATURE-----

From: Onno van der Linden <o.vd.linden@quicknet.nl>
To: gnats-bugs@netbsd.org
Cc: 
Subject: Re: kern/50613
Date: Fri, 20 May 2016 21:12:33 +0200

 Here's a simple test script that demonstrates the bug

 #!/bin/sh
 exec 3>/dev/audio
 audioctl -wn play.pause=1 blocksize=1024
 head -c 1024 /dev/zero >&3
 paused=$(audioctl -n play.samples)
 audioctl -wn play.pause=0
 unpaused=$(audioctl -n play.samples)
 if test "$paused" = "$unpaused"
 then
 	echo okay
 else
 	echo failed
 fi


 Onno

From: "Nathanial Sloss" <nat@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc: 
Subject: PR/50613 CVS commit: src/sys/dev
Date: Sun, 11 Dec 2016 07:36:30 +0000

 Module Name:	src
 Committed By:	nat
 Date:		Sun Dec 11 07:36:30 UTC 2016

 Modified Files:
 	src/sys/dev: audio.c

 Log Message:
 PR 50613: Onno van der Linden: unpausing audio(4) causes already written
           data to be dropped.
 Applied patch prepared by Onno.


 To generate a diff of this commit:
 cvs rdiff -u -r1.275 -r1.276 src/sys/dev/audio.c

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

Responsible-Changed-From-To: kern-bug-people->nat
Responsible-Changed-By: nat@NetBSD.org
Responsible-Changed-When: Mon, 23 Jan 2017 20:08:38 +0000
Responsible-Changed-Why:
I'll handle this.


From: Onno van der Linden <o.vd.linden@quicknet.nl>
To: gnats-bugs@NetBSD.org
Cc: 
Subject: Re: kern/50613 (unpausing audio(4) causes already written data to be
 dropped)
Date: Mon, 23 Jan 2017 21:19:35 +0100

 On Mon, Jan 23, 2017 at 08:08:38PM +0000, nat@NetBSD.org wrote:
 > Synopsis: unpausing audio(4) causes already written data to be dropped
 > 
 > Responsible-Changed-From-To: kern-bug-people->nat
 > Responsible-Changed-By: nat@NetBSD.org
 > Responsible-Changed-When: Mon, 23 Jan 2017 20:08:38 +0000
 > Responsible-Changed-Why:
 > I'll handle this.

 Sorry, should have replied to GNATS that it could be closed
 because you applied the fix a couple of months ago.

 Onno

State-Changed-From-To: open->closed
State-Changed-By: nat@NetBSD.org
State-Changed-When: Mon, 23 Jan 2017 21:19:18 +0000
State-Changed-Why:
Submitter has confirmed that it has been fixed.


>Unformatted:
 	<Please check that the above is correct for the bug being reported,>
 	<and append source date of snapshot, if applicable (one line).>

Home	PR Database Search