GNOME Bugzilla – Bug 320984
[oggdemux] cannot handle multiple chains
Last modified: 2009-03-26 07:26:19 UTC
There's something wrong with the segment/chain start/stop/base_time calculation and the newsegment event sent in gst_ogg_pad_submit_packet(). It fails when the current chain ends and the second one starts. Here's what happens: 00:02.863218000) gstoggdemux.c(946):gst_ogg_chain_new:<oggdemux0> creating new chain 0x83a99c8 00:02.863275000) gstoggdemux.c(982):gst_ogg_chain_new_stream:<oggdemux0> creating new stream 274c3890 in chain 0x83a99c8 00:03.117275000) gstoggdemux.c(834):gst_ogg_pad_submit_packet: chain->begin_time: 0:00:00.000000000 00:03.117303000) gstoggdemux.c(836):gst_ogg_pad_submit_packet: chain->segment_start: 0:03:11.339682539 00:03.117328000) gstoggdemux.c(838):gst_ogg_pad_submit_packet: chain->segment_stop: 5124095:34:33.709551615 00:03.117353000) gstoggdemux.c(853):gst_ogg_pad_submit_packet: segment_start: 0:03:11.339682539 00:03.117377000) gstoggdemux.c(855):gst_ogg_pad_submit_packet: segment_stop: 5124095:34:33.709551615 00:03.568750000) gstoggdemux.c(772):gst_ogg_demux_chain_peer: ogg current time 0:03:11.789569160 00:03.657735000) gstoggdemux.c(772):gst_ogg_demux_chain_peer: ogg current time 0:03:12.043537414 00:03.720685000) gstoggdemux.c(772):gst_ogg_demux_chain_peer: ogg current time 0:03:12.265578231 00:03.824366000) gstoggdemux.c(772):gst_ogg_demux_chain_peer: ogg current time 0:03:12.536961451 ... snip ... 00:25.767131000) gstoggdemux.c(772):gst_ogg_demux_chain_peer: ogg current time 0:03:36.608798185 00:26.008486000) gstoggdemux.c(772):gst_ogg_demux_chain_peer: ogg current time 0:03:36.865668934 00:26.272718000) gstoggdemux.c(772):gst_ogg_demux_chain_peer: ogg current time 0:03:37.090612244 00:26.565197000) gstoggdemux.c(772):gst_ogg_demux_chain_peer: ogg current time 0:03:37.299591836 ... new chain ... 00:26.566249000) gstoggdemux.c(946):gst_ogg_chain_new:<oggdemux0> creating new chain 0x83ca5d8 00:26.566373000) gstoggdemux.c(982):gst_ogg_chain_new_stream:<oggdemux0> creating new stream 25c3718d in chain 0x83ca5d8 00:26.628672000) gstoggdemux.c(834):gst_ogg_pad_submit_packet: chain->begin_time: 0:00:25.959909297 00:26.628713000) gstoggdemux.c(836):gst_ogg_pad_submit_packet: chain->segment_start: 0:00:00.000000000 00:26.628749000) gstoggdemux.c(838):gst_ogg_pad_submit_packet: chain->segment_stop: 5124095:34:33.709551615 00:26.628858000) gstoggdemux.c(853):gst_ogg_pad_submit_packet: segment_start: 5124095:34:07.749642319 00:26.628898000) gstoggdemux.c(855):gst_ogg_pad_submit_packet: segment_stop: 5124095:34:33.709551615 00:26.855016000) gstoggdemux.c(772):gst_ogg_demux_chain_peer: ogg current time 0:00:00.400544217 00:27.079054000) gstoggdemux.c(772):gst_ogg_demux_chain_peer: ogg current time 0:00:00.613877551 00:27.325009000) gstoggdemux.c(772):gst_ogg_demux_chain_peer: ogg current time 0:00:00.828662131 00:27.381014000) gstoggdemux.c(772):gst_ogg_demux_chain_peer: ogg current time 0:00:01.102947845 00:27.387954000) gstoggdemux.c(772):gst_ogg_demux_chain_peer: ogg current time 0:00:01.326439909 00:27.399609000) gstoggdemux.c(772):gst_ogg_demux_chain_peer: ogg current time 0:00:01.477369614 00:27.408265000) gstoggdemux.c(772):gst_ogg_demux_chain_peer: ogg current time 0:00:01.708117913 Cheers -Tim
A stream dump acquired with wget can be found here: http://gstreamer.freedesktop.org/media/incoming/virginradio-three-consecutive-chains.ogg It has three consecutive chains, each only a couple of seconds long. Even using the file it borks after the first chain. According to the debug output it parses the chains fine though, so it's probably just something wrong with the start/stop times and the newsegment event. And here is the live stream URL: http://www.smgradio.com/core/audio/ogg/live.pls?service=vrbb Cheers -Tim
*** Bug 328718 has been marked as a duplicate of this bug. ***
*** Bug 329839 has been marked as a duplicate of this bug. ***
The OGG file from the above URL showed length of 24 seconds and played till about the middle when it went on silent. On reaching the 24th second the Play button was still pressed. I tried to deactivate the playback by clicking the Next button, and the Play button depressed. However, on clicking the Play button again the rhythmbox'es interface freezed forever.
(I had gstreamer0.10 plugins installed from my Debian/unstable feed).
*** Bug 330325 has been marked as a duplicate of this bug. ***
*** Bug 332199 has been marked as a duplicate of this bug. ***
*** Bug 332794 has been marked as a duplicate of this bug. ***
*** Bug 315545 has been marked as a duplicate of this bug. ***
updated title, this is a problem with chained oggs.
Ubuntu https://launchpad.net/distros/ubuntu/+source/gstreamer0.10/+bug/32858 seems to be about the same issue: "... I also tried with "gst-launch-0.10 playbin" (don't know if it is useful, I thought more useless info was better than less useful info). The file is hosted at http://gstreamer.freedesktop.org/media/small/multi.ogg, and this is the output of ogginfo: ... "
*** Bug 332475 has been marked as a duplicate of this bug. ***
*** Bug 341721 has been marked as a duplicate of this bug. ***
*** Bug 342967 has been marked as a duplicate of this bug. ***
*** Bug 346076 has been marked as a duplicate of this bug. ***
*** Bug 333815 has been marked as a duplicate of this bug. ***
*** Bug 346998 has been marked as a duplicate of this bug. ***
*** Bug 351212 has been marked as a duplicate of this bug. ***
*** Bug 356436 has been marked as a duplicate of this bug. ***
The problem isn't really with oggdemux AFAIK. It switches chains correctly (emit no-more-pads, add pad, remove pad). The problem has to do with whatever uses it (decodebin/playbin or user-defined pipeline). FWIW, gst-launch doesn't know how to handle *chains* (concept of removing/adding pads with a no-more-pads emission in between).
*** Bug 382930 has been marked as a duplicate of this bug. ***
No stream from the Czech radio (which is pretty large public radio with handful of stations all streaming preferably in OGG) works correctly and probably fails on this bug. Try for example classical music station D-dur on http://www.rozhlas.cz/audio/download/ddur_lowogg.m3u (all other versions of the same stream are on http://www.rozhlas.cz/d-dur/portal/).
*** Bug 388741 has been marked as a duplicate of this bug. ***
I have also been experiencing this bug, and can confirm that it is indeed in oggdemux - the key is in the segment_start value calculated when a new chain starts, as the OP guessed. I have taken the liberty of attaching a patch which, in my small test player (using decodebin), seems to alleviate stream hangs. Old line 1046 looks like the most likely candidate for causing breakage, as subtracting chain->begin_time from chain->segment_start is effectively subtracting something from zero (segment start times are relative to the current time, it seems, where as begin_time is absolute). However, with the patch applied, the problem becomes one of __dropping__ data. I'm not an expert on GStreamer terminology (this is the first time I've looked at the source), but it sounds to my ears as if some buffer is being prematurely flushed whenever a new chain starts. The test stream from comment #1 doesn't stop playing like it used to, but it definitely doesn't sound contiguous.
Created attachment 80854 [details] [review] Fix calculation of segment_start on new chain Prevents stream falling silent on new chain, but sounds like data from the end of the previous chain is being dropped.
Quick follow-up: switching my test app over to decodebin2 seems to fix the "dropped data" issue, playing #1's test stream seamlessly. (The reason I was using decodebin was that decodebin2 doesn't seem to issue "removed-decoded-pad" signals on new chains, yet it does issue "new-decoded-pad", and my output pipe's sink seems perfectly happy to be re-linked without explicit unlinking. Being new to using GStreamer from a developer's perspective, I'm not sure if this is correct behaviour, but certainly at some point in time I decided I would steer clear of having too much "magic" going on in the background until I had found out.)
All is still not well. It's the amazing time-travelling ogg stream! 0:02:44.101017000 5350 0x5b7be0 DEBUG oggdemux gstoggdemux.c:938:gst_ogg_demux_chain_peer:<oggdemux0> ogg current time 0:02:47.235918366 0:02:44.223709000 5350 0x5b7be0 DEBUG oggdemux gstoggdemux.c:938:gst_ogg_demux_chain_peer:<oggdemux0> ogg current time 0:02:47.259138320 0:02:44.464079000 5350 0x5b7be0 DEBUG oggdemux gstoggdemux.c:1685:gst_ogg_demux_deactivate_current_chain:<oggdemux0> deactivating chain 0x5fe4c0 0:02:44.464127000 5350 0x5b7be0 DEBUG oggdemux gstoggdemux.c:1693:gst_ogg_demux_deactivate_current_chain:<oggdemux0> removing pad <oggdemux0:serial_24c22dfd> 0:02:44.464372000 5350 0x5b7be0 DEBUG oggdemux gstoggdemux.c:2664:gst_ogg_demux_handle_page:<oggdemux0> new chain, begin time 0:02:47.259138320 0:02:44.621035000 5350 0x5b7be0 DEBUG oggdemux gstoggdemux.c:1037:gst_ogg_pad_submit_packet:<oggdemux0> chain->begin_time: 0:02:47.259138320 0:02:44.621044000 5350 0x5b7be0 DEBUG oggdemux gstoggdemux.c:1039:gst_ogg_pad_submit_packet:<oggdemux0> chain->segment_start: 0:00:00.000000000 0:02:44.621052000 5350 0x5b7be0 DEBUG oggdemux gstoggdemux.c:1041:gst_ogg_pad_submit_packet:<oggdemux0> chain->segment_stop: 99:99:99.999999999 0:02:44.621772000 5350 0x5b7be0 DEBUG oggdemux gstoggdemux.c:938:gst_ogg_demux_chain_peer:<oggdemux0> ogg current time 0:02:47.537777775 - snip - 0:02:47.583187000 5350 0x5b7be0 DEBUG oggdemux gstoggdemux.c:938:gst_ogg_demux_chain_peer:<oggdemux0> ogg current time 0:02:50.486712016 0:02:47.707447000 5350 0x5b7be0 DEBUG oggdemux gstoggdemux.c:938:gst_ogg_demux_chain_peer:<oggdemux0> ogg current time 0:05:53.041995462 0:02:47.714028000 5350 0x5b7be0 DEBUG oggdemux gstoggdemux.c:1685:gst_ogg_demux_deactivate_current_chain:<oggdemux0> deactivating chain 0x688260 0:02:47.714074000 5350 0x5b7be0 DEBUG oggdemux gstoggdemux.c:1693:gst_ogg_demux_deactivate_current_chain:<oggdemux0> removing pad <oggdemux0:serial_10bb6682> 0:02:47.714320000 5350 0x5b7be0 DEBUG oggdemux gstoggdemux.c:2664:gst_ogg_demux_handle_page:<oggdemux0> new chain, begin time 0:05:53.041995462 0:02:47.864595000 5350 0x5b7be0 DEBUG oggdemux gstoggdemux.c:1037:gst_ogg_pad_submit_packet:<oggdemux0> chain->begin_time: 0:05:53.041995462 0:02:47.864604000 5350 0x5b7be0 DEBUG oggdemux gstoggdemux.c:1039:gst_ogg_pad_submit_packet:<oggdemux0> chain->segment_start: 0:00:00.000000000 0:02:47.864612000 5350 0x5b7be0 DEBUG oggdemux gstoggdemux.c:1041:gst_ogg_pad_submit_packet:<oggdemux0> chain->segment_stop: 99:99:99.999999999 0:02:47.865339000 5350 0x5b7be0 DEBUG oggdemux gstoggdemux.c:938:gst_ogg_demux_chain_peer:<oggdemux0> ogg current time 0:05:53.356916096 0:02:48.197173000 5350 0x5b7be0 DEBUG oggdemux gstoggdemux.c:938:gst_ogg_demux_chain_peer:<oggdemux0> ogg current time 0:05:53.681995462 The "current time" claims to jump from 2:50 to 5:53 just after the snip. This happens in between tracks when streaming http://www.spogbiper.com:8000/stream.ogg after having removed the dodgy segment_start calculations; this is either messing up, or is messed up by, the next chain's begin_time (I'm having trouble following the flow control in gstoggdemux). Result is a 3 minute silence before anything is next heard. Chains in the middle of tracks - I assume triggered by new metadata - are just fine. Based on the fact that I either haven't fixed the bug at all, or that there's more than one bug at work, I'll shut up now until somebody cleverer than me chips in. :)
*** Bug 409755 has been marked as a duplicate of this bug. ***
*** Bug 434408 has been marked as a duplicate of this bug. ***
Created attachment 88141 [details] [review] patch Here's a patch that sort of fixes the problem for me. It only modifies oggdemux.c. There is still a problem, so maybe someone can pick up where I left off. Here is what I think was wrong: First, I am using the virginradio-three-consecutive-chains.ogg file from comment #1 for testing. It's made of three chains with the following start/stop timestamps and position in the total file: start stop offset 3:52.80 4:01.39 0:00.00 0:00.00 0:05.52 0:08.59 0:00.00 0:10.53 0:14.11 The total file has length 0:24.64 There were three fixes. First, a newsegment event wasn't being sent in one case when a chain was started. Second, I removed the code from the patch given above, though I didn't look into that in detail. Third, the values set in another newsegment event (when seeking) were wrong: The very first newsegment event sent happens in the seek code, I think because oggdemux seeks back to the beginning after having searched the file. The problem is that the timestamps set are as follows: 3:52.80 4:17.45 0:24.64 ie, it was sending the times for the entire file, not just the first chain. The sink element was waiting until the 24 seconds were up before running the data from the second chain. I simply changed the stop time to be based on the current chain's time. My change is incomplete - all the other values there have extra checks and a more complicated calculation, but I am not sure enough about everything going on in that code to fix it. I'll look at it when I get more time. Actually, all those seek calculations seem a bit iffy to me... maybe it's time to revisit bug 344013? The problem that remains is that there is a split-second gap in output in between the chains. The timestamps from the newsegments all align perfectly though, so I suspect that there is some computation which is taking too much time and holding up the start of the next chain. Someone with more knowledge about gstreamer should check all this.. I am a bit uncertain about a lot of it.
oops, I meant gstoggdemux.c, and 3:52.80 4:17.45 0:24.64 are start, stop and duration (not offset) values.
* ext/ogg/gstoggdemux.c: (gst_ogg_pad_submit_packet), (gst_ogg_demux_activate_chain), (gst_ogg_demux_perform_seek), (gst_ogg_demux_handle_page): Add some FIXMEs. Fix chain start/stop segment handling based on patch by <ahalda at cs dot mcgill dot ca> see #320984.
*** Bug 442348 has been marked as a duplicate of this bug. ***
*** Bug 474472 has been marked as a duplicate of this bug. ***
*** Bug 489272 has been marked as a duplicate of this bug. ***
*** Bug 501458 has been marked as a duplicate of this bug. ***
Closing this bug now as it is confirmed to be working in playbin2 (which does chained oggs)
See also http://blogs.gnome.org/uraeus/2007/12/11/the-end-of-a-bug/
I still see this bug. Try playing http://live.lora924.de:8000/loramagazin.ogg After the jingle you get, when you tune in, playback will hang. Tested with Totem (Gstreamer backend), Rhythmbox, Banshee on Ubuntu 8.10
Johannes, we said it was fixed in playbin2. So, until totem, banshee, rhythmbox switch to playbin2... you're out of luck. I suggest pushing the maintainers of those projects to switch to playbin2 ASAP. It 'kind' of works if you make playbin use decodebin2 instead of decodebin by setting the USE_DECODEBIN2 env variable to 1.
(In reply to comment #40) > Johannes, we said it was fixed in playbin2. So, until totem, banshee, rhythmbox > switch to playbin2... you're out of luck. Thanks for the info. However, I ended up here, because all the bugs about this filed against rhythmbox were marked duplicates of this or other bugs in gstreamer, which is obviously inadequate.
> Johannes, we said it was fixed in playbin2. So, until totem, banshee, rhythmbox > switch to playbin2... you're out of luck. > > I suggest pushing the maintainers of those projects to switch to playbin2 ASAP. > The documentation for playbin2 states: "At this stage, playbin2 is considered UNSTABLE. The API provided in the signals and properties may yet change in the near future. When playbin2 is stable, it will probably replace playbin". Has playbin2's status changed? I doubt there will be much success convincing maintainers to transition their projects to an unstable interface.
Speaking only for rhythmbox, obviously, the main reason I haven't put much effort into using playbin2 is that I'm more interested in the crossfading player, which doesn't use playbin at all. There's a preliminary playbin2 implementation on bug 542922 that needs a lot of work before it can replace the existing playbin player. The crossfading player will play chained oggs properly if I switch it to use decodebin2 instead of decodebin, which is a trivial change.
Jonathan, using decodebin2 should be fine. Don't forget to properly handle pads appearing/disappearing (which will happen with chained oggs).
Rhythmbox now uses decodebin2 when crossfading is enabled. I added code a while back to handle pads being removed, which made chained ogg playback work. Work on switching to playbin2 when not crossfading is continuing (slowly).