[gstreamer-bugs] [Bug 109041] [mad] needs to be faster on sync errors

Fri May 20 13:28:03 PDT 2005

Please DO NOT reply to this by email. All additional comments should be made in
the comments box of this bug report.

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

------- Additional Comments From Loïc Minier  2005-05-20 20:28 -------
Actually, I think I have the bug that Peter Williams describe too, and it might
deserve a newer report (if you want me to open a new one, please say so).

I noticed that Rhythmbox got stuck on a particular song, but gst-launch and the
following pipeline: gst-launch-0.8 --gst-debug-level=3 gnomevfssrc
location='foo.mp3' ! spider ! volume ! audioscale ! audioconvert ! $(gconftool-2
-g /system/gstreamer/0.8/default/audiosink)

produced a high pitched sound for a split second, and then continued fine.

There's probably a bug in Rhythmbox when the underlying GStreamer chuckles on a
song, but I think GStreamer might be the culprit, and not necessarily mad, as
madplay did go through the file, with a special error on the point where
GStreamer chuckles:
bee% madplay foo.mp3 
MPEG Audio Decoder 0.15.2 (beta) - Copyright (C) 2000-2004 Robert Leslie et al.
         Artist: Francois Perusse
          Album: 2 Minutes du peuple
          Genre: Comedy
error: frame 0: lost synchronization
error: frame 254: lost synchronization
error: frame 495: lost synchronization
error: frame 496: CRC check failed
error: frame 999: lost synchronization
995 frames decoded (0:00:25,9), -17,2 dB peak amplitude, 0 clipped samples

At the same place, the debugging output of the pipeline is like:
...
INFO  (0x8050920 - 310171:56:52.301572000)        GST_PADS( 8261)
gstpad.c(4045):gst_pad_event_default_dispatch:<audioconvert0:sink> Sending event
0x807bc78 to all internally linked pads
INFO  (0x8050920 - 310171:56:52.304901000)        GST_PADS( 8261)
gstpad.c(4045):gst_pad_event_default_dispatch:<osssink0:sink> Sending event
0x807bc78 to all internally linked pads
INFO  (0x8050920 - 310171:56:52.308191000)       GST_EVENT( 8261)
gstevent.c(96):_gst_event_free: freeing event 0x807bc78
INFO  (0x8050920 - 310171:56:58.489948000)             mad( 8261)
gstmad.c(1325):gst_mad_chain: recoverable lost sync error
INFO  (0x8050920 - 310171:56:58.490874000)             mad( 8261)
gstmad.c(1325):gst_mad_chain: recoverable lost sync error
INFO  (0x8050920 - 310171:56:58.490953000)             mad( 8261)
gstmad.c(1325):gst_mad_chain: recoverable lost sync error
INFO  (0x8050920 - 310171:56:58.491020000)             mad( 8261)
gstmad.c(1325):gst_mad_chain: recoverable lost sync error
INFO  (0x8050920 - 310171:56:58.491670000)             mad( 8261)
gstmad.c(1325):gst_mad_chain: recoverable lost sync error
INFO  (0x8050920 - 310171:56:58.491731000)             mad( 8261)
gstmad.c(1325):gst_mad_chain: recoverable lost sync error
INFO  (0x8050920 - 310171:56:58.491787000)             mad( 8261)
gstmad.c(1325):gst_mad_chain: recoverable lost sync error
INFO  (0x8050920 - 310171:56:58.534738000)             oss( 8261)
gstosssink.c(450):gst_osssink_chain:<osssink0> need sync: real
0:00:06.608979591, buffer: 0:00:09.108000000
INFO  (0x8050920 - 310171:57:01.065789000)             oss( 8261)
gstosssink.c(450):gst_osssink_chain:<osssink0> need sync: real
0:00:09.142789114, buffer: 0:00:06.643809523
...

The "lost sync error" seems to trigger a point where mad will seek further in
the stream, garbage some bytes, the ossink will empty some buffer, I get the
noise, and just a split second after that, playback continues.

The pipeline will then produce "need sync" lines all the time.

With a bigger debug level, it's harder to follow, but grepping on mad shows:
DEBUG (0x8050928 - 310172:24:11.842113000)             mad( 8947)
gstmad.c(1317):gst_mad_chain: mad_frame_decode had an error: lost synchronization
INFO  (0x8050928 - 310172:24:11.842162000)             mad( 8947)
gstmad.c(1325):gst_mad_chain: recoverable lost sync error
DEBUG (0x8050928 - 310172:24:11.842212000)             mad( 8947)
gstmad.c(1386):gst_mad_chain:<mad0> resynchronization consumes 187 bytes
DEBUG (0x8050928 - 310172:24:11.842260000)             mad( 8947)
gstmad.c(1388):gst_mad_chain:<mad0> synced to data: 0xff 0xff
DEBUG (0x8050928 - 310172:24:11.842399000)             mad( 8947)
gstmad.c(1164):gst_mad_check_caps_reset: Header changed from 44100 Hz/2 ch to
32000 Hz/2 ch, failed sync after seek ?
DEBUG (0x8050928 - 310172:24:11.842727000)             mad( 8947)
gstmad.c(1317):gst_mad_chain: mad_frame_decode had an error: lost synchronization
INFO  (0x8050928 - 310172:24:11.842773000)             mad( 8947)
gstmad.c(1325):gst_mad_chain: recoverable lost sync error
DEBUG (0x8050928 - 310172:24:11.842819000)             mad( 8947)
gstmad.c(1386):gst_mad_chain:<mad0> resynchronization consumes 23 bytes
DEBUG (0x8050928 - 310172:24:11.842866000)             mad( 8947)
gstmad.c(1388):gst_mad_chain:<mad0> synced to data: 0xff 0xfb
DEBUG (0x8050928 - 310172:24:11.842920000)             mad( 8947)
gstmad.c(1317):gst_mad_chain: mad_frame_decode had an error: bad main_data_begin
pointer

this is repeated a couple of times, and then playback continues.

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