[Gstreamer-bugs] [Bug 142586] New: - alsasink resync is broken

[bugzilla-daemon at bugzilla.gnome.org]

http://bugzilla.gnome.org/show_bug.cgi?id=142586
GStreamer | gst-plugins | Ver: HEAD CVS

           Summary: alsasink resync is broken
           Product: GStreamer
           Version: HEAD CVS
          Platform: Other
        OS/Version: Linux
            Status: UNCONFIRMED
          Severity: normal
          Priority: Normal
         Component: gst-plugins
        AssignedTo: gstreamer-maint at bugzilla.gnome.org
        ReportedBy: rbultje at ronald.bitfreak.net
         QAContact: gstreamer-maint at bugzilla.gnome.org


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)) {

------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
You are the QA contact for the bug, or are watching the QA contact.