GNOME Bugzilla – Bug 142586
alsasink resync is broken
Last modified: 2004-12-22 21:47:04 UTC
Just for my own memory, because I'll forget. Alsasink skips under extreme conditions, which is normal. However, it skips too much. Osssink performs as expected under the same conditions. * disable DMA * run a 2.4 kernel * start openoffice * run updatedb * have a crappy soundcard * compile three kernels plus the whole of the GNOME D&DP in parallel That should be enough, or just a subpart of those (2,3,4,5 are enough for me). Now look at the output of --gst-debug=alsa*:5. I also add a printf to the _loop() function (patch below): samplediff: 0 (maxdiscont=4410,buf=0,element=0 samplediff: -1 (maxdiscont=4410,buf=1151,element=0 Normal output, buffering... DEBUG alsa( 9464) gstalsa.c(1088):gst_alsa_start: Setting state to RUNNING samplediff: -1 (maxdiscont=4410,buf=17279,element=8249 samplediff: -1 (maxdiscont=4410,buf=18431,element=8257 Normal output, playback starts, note that sample_diff is very very low (-2<=diff<=2). Then, suddenly: samplediff: 0 (maxdiscont=4410,buf=2818944,element=2809876 samplediff: -1080883491 (maxdiscont=4410,buf=2820096,element=2809876 INFO alsa( 9464) gstalsasink.c(418):gst_alsa_sink_loop:<alsasink0> Skipping 1152 samples to resync (complete buffer): sample 2809876 expected, but got 2820096 samplediff: 1080894863 (maxdiscont=4410,buf=2821248,element=2809876 INFO alsa( 9464) gstalsasink.c(399):gst_alsa_sink_loop:<alsasink0> Allocating 524288 bytes (131072 samples) now to resync: sample 2809876 expected, but got 2821248 INFO alsa( 9464) gstalsa.c(1136):gst_alsa_xrun_recovery:<alsasink0> alsa: xrun of at least 2.368 msecs DEBUG alsa( 9464) gstalsa.c(1430):gst_alsa_stop_audio: stopping alsa, skipping pending frames it just flows over to this value, for no good reason. Indeed, after this, it is silent for a while. This seems like an signed/unsigned or 32it integer overflow somewhere. Noet that 1e9 samples means 4e9 bytes, which is G_MAXUINT (format: S16_LE 44100Hz, 2 channels). After the silence, alsa restarts and the clock is - obviously - way behind and therefore it will skip several seconds of sound: INFO alsa( 9464) gstalsa.c(1282):gst_alsa_set_hw_params: Preparing format: S16_LE 44100Hz, 2 channels DEBUG alsa( 9464) gstalsa.c(1088):gst_alsa_start: Setting state to RUNNING samplediff: -129920 (maxdiscont=4410,buf=2821248,element=2934812 INFO alsa( 9464) gstalsasink.c(418):gst_alsa_sink_loop:<alsasink0> Skipping 1152 samples to resync (complete buffer): sample 2934812 expected, but got 2821248 samplediff: -128768 (maxdiscont=4410,buf=2822400,element=2934823 INFO alsa( 9464) gstalsasink.c(418):gst_alsa_sink_loop:<alsasink0> Skipping 1152 samples to resync (complete buffer): sample 2934823 expected, but got 2822400 [..] samplediff: -5504 (maxdiscont=4410,buf=2945663,element=2946823 INFO alsa( 9464) gstalsasink.c(418):gst_alsa_sink_loop:<alsasink0> Skipping 1152 samples to resync (complete buffer): sample 2946823 expected, but got 2945663 samplediff: -4351 (maxdiscont=4410,buf=2946815,element=2946835 samplediff: -4352 (maxdiscont=4410,buf=2947967,element=2946848 After that, it resyncs correctly and plays back again for a while. This whole procedure repeats several times in mp3 playback, but I've seen it for Ogg/Vorbis files as well. If wanted, I can attach the full log, although the idea must be clear now. Patch for gstalsasink.c to get this output: Index: gstalsasink.c =================================================================== RCS file: /home/cvs/gstreamer/gst-plugins/ext/alsa/gstalsasink.c,v retrieving revision 1.17 diff -u -r1.17 gstalsasink.c --- a/gstalsasink.c 9 May 2004 00:02:26 -0000 1.17 +++ b/gstalsasink.c 15 May 2004 17:08:10 -0000 @@ -377,7 +377,8 @@ snd_pcm_delay (this->handle, &sample_diff); /* actual diff = buffer samplestamp - played - to_play */ sample_diff = samplestamp - time_sample - sample_diff; - +g_print ("samplediff: %ld (maxdiscont=%ld,buf=%lu,element=%lu\n", sample_diff, + max_discont, samplestamp, time_sample); if ((!GST_BUFFER_TIMESTAMP_IS_VALID (sink->buf[i])) || (-max_discont <= sample_diff && sample_diff <= max_discont)) {
snd_pcm_delay() is returning bogus values. I've emailed alsa-devel and will probably add an intermediate hack to work around it.
Created attachment 27745 [details] [review] Hack to work around snd_pcm_delay() bogus return values
I believe this is fixed now.