[PATCH] OSS Layer: restart stream after xrun once stream is drained.

[PATCH] OSS Layer: restart stream after xrun once stream is drained.

[Carlo Wood]

On Sat, Jul 12, 2003 at 08:56:16PM +0200, Jaroslav Kysela wrote:
> Yes, but at another level - in the OSS emulation code.
> 
> > What is the correct way to recover from this, to continue
> > recording in this case, after the xrun?
> 
> Call read() or poll(POLLIN) again. I think that your problem might be that 
> poll(POLLIN) does not trigger the input in the current ALSA code. Please, 
> try this patch with ViaVoice (the patch is also in the ALSA CVS tree):

Hi Jaroslav,

I wrote a patch for sound/core/oss/pcm_oss.c, that fixes the ViaVoice
problem.

Problem:

When an xrun happens, the stream is stopped.
The OSS layer (read1) changes the xrun state into a draining state,
but never restarts the stream.

This patch restart the stream once so much had been drained
from the stream that less than one fragement remains.
It is not safe to wait till the stream is empty (although it should
be when the application only reads full fragments) because it
might be that the application only calls read() when there is
at least one fragment ... kind of a contradiction, but then
why not like this.


--- linux-2.5.74/sound/core/oss/pcm_oss.c	2003-07-13 04:01:16.000000000 +0200
+++ linux-2.5.74-debug/sound/core/oss/pcm_oss.c	2003-07-13 04:23:52.260709528 +0200
@@ -627,8 +627,21 @@
 			}
 			continue;
 		}
-		if (ret != -ESTRPIPE)
+		if (ret != -ESTRPIPE) {
+			if (runtime->status->state == SNDRV_PCM_STATE_DRAINING) {
+				snd_pcm_status_t status;
+				memset(&status, 0, sizeof(status));
+				int err = snd_pcm_kernel_ioctl(substream, SNDRV_PCM_IOCTL_STATUS, &status);
+				if (!err && status.avail < runtime->period_size) {
+					err = snd_pcm_kernel_ioctl(substream, SNDRV_PCM_IOCTL_PREPARE, 0);
+					if (!err)
+						snd_pcm_start(substream);
+				}
+				if (err < 0)
+					ret = err;
+			}
 			break;
+		}
 	}
 	return ret;
 }


The attached test program gives, WITHOUT this patch the following output
(This test case reads SLOW, to make sure that xruns happen frequently):

gment size: 1024
Number of fragments: 32767
Number of channels: 1
Sample rate: 22050
Number of full fragments that can be read or written without blocking: 0
Total number of fragments allocated for buffering: 2
Size of a fragment in bytes: 1024
Number of bytes that can be read or written immediately without blocking: 0
space: bytes = 32, periods = 0, fragstotal = 2, fragsize = 1024
space: bytes = 1056, periods = 1, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 30635.751683
space: bytes = 928, periods = 0, fragstotal = 2, fragsize = 1024
space: bytes = 2016, periods = 1, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 16124.799227
space: bytes = 0, periods = 0, fragstotal = 2, fragsize = 1024
space: bytes = 0, periods = 0, fragstotal = 2, fragsize = 1024
space: bytes = 0, periods = 0, fragstotal = 2, fragsize = 1024
space: bytes = 0, periods = 0, fragstotal = 2, fragsize = 1024
[...]

WITH the above patch it does this:

Fragment size: 1024
Number of fragments: 32767
Number of channels: 1
Sample rate: 22050
Number of full fragments that can be read or written without blocking: 0
Total number of fragments allocated for buffering: 2
Size of a fragment in bytes: 1024
Number of bytes that can be read or written immediately without blocking: 0
space: bytes = 32, periods = 0, fragstotal = 2, fragsize = 1024
space: bytes = 1088, periods = 1, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 29704.837189
space: bytes = 928, periods = 0, fragstotal = 2, fragsize = 1024
space: bytes = 2048, periods = 2, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 14847.537252
space: bytes = 1024, periods = 1, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 15708.954795
space: bytes = 800, periods = 0, fragstotal = 2, fragsize = 1024
space: bytes = 2048, periods = 2, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 12830.954678
space: bytes = 1024, periods = 1, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 13536.438665
space: bytes = 832, periods = 0, fragstotal = 2, fragsize = 1024
space: bytes = 2048, periods = 2, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 12074.536003
space: bytes = 1024, periods = 1, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 12573.210712
space: bytes = 832, periods = 0, fragstotal = 2, fragsize = 1024
space: bytes = 2048, periods = 2, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 11650.397069
space: bytes = 1024, periods = 1, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 12040.231304
space: bytes = 928, periods = 0, fragstotal = 2, fragsize = 1024
space: bytes = 2048, periods = 2, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 11327.103292
space: bytes = 1024, periods = 1, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 11590.736089
space: bytes = 928, periods = 0, fragstotal = 2, fragsize = 1024
space: bytes = 2048, periods = 2, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 11034.144344
space: bytes = 1024, periods = 1, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 11272.664653
space: bytes = 992, periods = 0, fragstotal = 2, fragsize = 1024
space: bytes = 2048, periods = 2, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 10823.670013
space: bytes = 1024, periods = 1, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 11022.745850
space: bytes = 1024, periods = 1, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 11211.084341
space: bytes = 1056, periods = 1, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 11387.316413
space: bytes = 1056, periods = 1, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 11569.761392
space: bytes = 960, periods = 0, fragstotal = 2, fragsize = 1024
space: bytes = 2048, periods = 2, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 11186.543811
space: bytes = 1024, periods = 1, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 11377.988481
space: bytes = 864, periods = 0, fragstotal = 2, fragsize = 1024
space: bytes = 2048, periods = 2, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 11060.036340
space: bytes = 1024, periods = 1, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 11234.400773
space: bytes = 864, periods = 0, fragstotal = 2, fragsize = 1024
space: bytes = 2048, periods = 2, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 10955.674898
space: bytes = 1024, periods = 1, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 11107.524306
space: bytes = 896, periods = 0, fragstotal = 2, fragsize = 1024
space: bytes = 2048, periods = 2, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 10858.584314
space: bytes = 1024, periods = 1, fragstotal = 2, fragsize = 1024
Read 1024 bytes.  Average bytes/second read: 11011.375394
space: bytes = 864, periods = 0, fragstotal = 2, fragsize = 1024
space: bytes = 2048, periods = 2, fragstotal = 2, fragsize = 1024
[...etc...]

The real rate being 8000, we have 16 kb/s of input
from the soundcard, but only read (on average) 11 kb/s, from
which we can conclude that the stream is stopped 31% of the time.

-- 
Carlo Wood <carlo@alinoe.com>


-------------------------------------------------------
This SF.Net email sponsored by: Parasoft
Error proof Web apps, automate testing & more.
Download & eval WebKing and get a free book.
www.parasoft.com/bulletproofapps1

Re: [PATCH] OSS Layer: restart stream after xrun once stream is drained.

[Carlo Wood]

On Sun, Jul 13, 2003 at 04:38:47AM +0200, Carlo Wood wrote:
> I wrote a patch for sound/core/oss/pcm_oss.c, that fixes the ViaVoice
> problem.

Later I wrote a test case that still doesn't get fixed:

>a.out
    Size of a fragment in bytes: 1024
    Allocated fragments for buffering: 2
    Successfully caused an xrun.
    non-blocking fragments: 2
    non-blocking bytes: 2048
    Stream is not restarted after xrun.

now this is expected without my patch, but with
the patch the stream *is* set back to a RUNNING state
again successfully - nevertheless, snd_pcm_update_hw_ptr_interrupt
is not called anymore.

Is there anyone who can get the following test code to work
(by patching the ALSA kernel module, not by changing the test code! ;).

Test code:


#include <stdio.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
#include <sys/ioctl.h>
#include <unistd.h>
#include <sys/soundcard.h>
#include <time.h>

int main(void)
{
  int fd = open("/dev/dsp", O_RDONLY);
  if (fd == -1) { perror("open"); exit(127); }
  int res = AFMT_S16_LE;
  if (ioctl(fd, SNDCTL_DSP_SETFMT, &res) == -1) {
    perror("ioctl"); exit(127); }
  res = 0;
  if (ioctl(fd, SNDCTL_DSP_STEREO, &res) == -1) {
    perror("ioctl"); exit(127); }
  res = 22050;
  if (ioctl(fd, SOUND_PCM_READ_RATE, 0xbfffdcfc) == -1) {
    perror("ioctl"); exit(127); }
  res = 0x7fff000a;
  if (ioctl(fd, SNDCTL_DSP_SETFRAGMENT, &res) == -1) {
    perror("ioctl"); exit(127); }
  audio_buf_info info;
  if (ioctl(fd, SNDCTL_DSP_GETISPACE, &info) == -1) {
    perror("read"); exit(127); }
  printf("    Size of a fragment in bytes: %d\n", info.fragsize);
  printf("    Allocated fragments for buffering: %d\n", info.fragstotal);
  char buf[1024];
  if (read(fd, buf, sizeof(buf)) < 0) { perror("read"); exit(127); }
  static struct timespec naptime = { 0, 100000000 };
  int count = 0;
  do {
    if (ioctl(fd, SNDCTL_DSP_GETISPACE, &info) == -1) {
      perror("read"); exit(127); }
    nanosleep(&naptime, 0);
    if (++count == 20) { printf("Failed to cause an xrun.\n"); exit(127); }
  } while(info.bytes < info.fragsize * info.fragstotal);
  printf("    Successfully caused an xrun.\n");
  printf("    non-blocking fragments: %d\n", info.fragments);
  printf("    non-blocking bytes: %d\n", info.bytes);
  ssize_t bufsize = info.bytes;
  ssize_t trlen = 0;
  int nf = 0;
  for (;;)
  {
    if (ioctl(fd, SNDCTL_DSP_GETISPACE, &info) == -1) {
      perror("ioctl"); exit(127); }
    if (info.fragments > 0) {
      ssize_t rlen;
      if ((rlen = read(fd, buf, sizeof(buf))) < 0)
      { perror("read"); exit(127); }
      trlen += rlen;
      if (trlen > bufsize) {
        printf("    Read %d bytes: stream successfully restarted.\n", trlen);
	exit(0);
      }
      nf = 0;
    }
    else if (++nf > 10) {
      printf("    Stream is not restarted after xrun.\n");
      exit(1);
    }
  }
  close(fd);
  return 0;
}


Here is some debug output that I generated with added printk's:

Jul 13 17:22:27 ansset kernel: Entering snd_pcm_update_hw_ptr_interrupt
Jul 13 17:22:27 ansset kernel: snd_pcm_update_hw_ptr_interrupt: status->hw_ptr set to 1536
Jul 13 17:22:27 ansset kernel: snd_pcm_capture_avail: boundary = 1073741824, status->hw_ptr = 1536, control->appl_ptr = 512
Jul 13 17:22:27 ansset kernel: Calling snd_pcm_stop, runtime->status->state = SNDRV_PCM_STATE_RUNNING
Jul 13 17:22:27 ansset kernel: Returned from snd_pcm_stop, runtime->status->state = SNDRV_PCM_STATE_XRUN
Jul 13 17:22:27 ansset kernel: Leaving snd_pcm_update_hw_ptr_interrupt with EPIPE
...
Jul 13 17:22:27 ansset kernel: snd_pcm_oss_read3: calling snd_pcm_kernel_ioctl SNDRV_PCM_IOCTL_DRAIN
Jul 13 17:22:27 ansset kernel: snd_pcm_capture_drain: state is SNDRV_PCM_STATE_XRUN.  Calling snd_pcm_change_state.
Jul 13 17:22:27 ansset kernel: snd_pcm_capture_avail: boundary = 1073741824, status->hw_ptr = 1536, control->appl_ptr = 512
Jul 13 17:22:27 ansset kernel: snd_pcm_capture_drain: Returning from snd_pcm_change_state, state is now 5
Jul 13 17:22:27 ansset kernel: Entering snd_pcm_lib_read1
Jul 13 17:22:27 ansset kernel: state is SNDRV_PCM_STATE_DRAINING
Jul 13 17:22:27 ansset kernel: size = 512
Jul 13 17:22:27 ansset kernel: snd_pcm_capture_avail: boundary = 1073741824, status->hw_ptr = 1536, control->appl_ptr = 512
Jul 13 17:22:27 ansset kernel: Leaving snd_pcm_lib_read1; xfer = 512, err = 0
...
Jul 13 17:22:27 ansset kernel: Entering snd_pcm_lib_read1
Jul 13 17:22:27 ansset kernel: state is SNDRV_PCM_STATE_DRAINING
Jul 13 17:22:27 ansset kernel: size = 512
Jul 13 17:22:27 ansset kernel: snd_pcm_capture_avail: boundary = 1073741824, status->hw_ptr = 1536, control->appl_ptr = 1024
Jul 13 17:22:27 ansset kernel: Leaving snd_pcm_lib_read1; xfer = 512, err = 0
Jul 13 17:22:27 ansset kernel: snd_pcm_status: status->hw_ptr copied to be 1536
Jul 13 17:22:27 ansset kernel: Calling snd_pcm_capture_avail()
Jul 13 17:22:27 ansset kernel: snd_pcm_capture_avail: boundary = 1073741824, status->hw_ptr = 1536, control->appl_ptr = 1536
Jul 13 17:22:27 ansset kernel: snd_pcm_capture_avail returned status->avail = 0
Jul 13 17:22:27 ansset kernel: snd_pcm_status_user: status.avail = 0

[start of effect of my patch]

Jul 13 17:22:27 ansset kernel: snd_pcm_oss_read3: calling snd_pcm_kernel_ioctl(SNDRV_PCM_IOCTL_PREPARE)
Jul 13 17:22:27 ansset kernel: snd_pcm_lib_ioctl_reset: status->hw_ptr set to 0
Jul 13 17:22:27 ansset kernel: snd_pcm_oss_read3: state now SNDRV_PCM_STATE_RUNNING
Jul 13 17:22:27 ansset kernel: snd_pcm_update_hw_ptr: status->hw_ptr set to 0
Jul 13 17:22:27 ansset kernel: snd_pcm_capture_avail: boundary = 1073741824, status->hw_ptr = 0, control->appl_ptr = 0
Jul 13 17:22:27 ansset kernel: snd_pcm_status: status->hw_ptr copied to be 0
Jul 13 17:22:27 ansset kernel: snd_pcm_capture_avail: boundary = 1073741824, status->hw_ptr = 0, control->appl_ptr = 0
Jul 13 17:22:27 ansset kernel: snd_pcm_capture_avail returned status->avail = 0
Jul 13 17:22:27 ansset kernel: snd_pcm_status_user: status.avail = 0
Jul 13 17:22:27 ansset kernel: space: bytes = 0, periods = 0, fragstotal = 2, fragsize = 1024

[end of patch effects]

...

but snd_pcm_update_hw_ptr_interrupt is never called anymore,
it only repeats

Jul 13 17:22:27 ansset kernel: snd_pcm_update_hw_ptr: status->hw_ptr set to 0
Jul 13 17:22:27 ansset kernel: snd_pcm_capture_avail: boundary = 1073741824, status->hw_ptr = 0, control->appl_ptr = 0
Jul 13 17:22:27 ansset kernel: snd_pcm_status: status->hw_ptr copied to be 0
Jul 13 17:22:27 ansset kernel: Calling snd_pcm_capture_avail()
Jul 13 17:22:27 ansset kernel: snd_pcm_capture_avail: boundary = 1073741824, status->hw_ptr = 0, control->appl_ptr = 0
Jul 13 17:22:27 ansset kernel: snd_pcm_capture_avail returned status->avail = 0
Jul 13 17:22:27 ansset kernel: snd_pcm_status_user: status.avail = 0
Jul 13 17:22:27 ansset kernel: space: bytes = 0, periods = 0, fragstotal = 2, fragsize = 1024

after that.

-- 
Carlo Wood <carlo@alinoe.com>


-------------------------------------------------------
This SF.Net email sponsored by: Parasoft
Error proof Web apps, automate testing & more.
Download & eval WebKing and get a free book.
www.parasoft.com/bulletproofapps1