GNOME Bugzilla – Bug 754438
oggdemux misbehaviour when seeking
Last modified: 2018-11-03 11:41:14 UTC
This code: gst_init (&argc, &argv); GstElement* elm = gst_parse_launch( "souphttpsrc location=http://www.leanbackplayer.com/videos/360p/elephants_dream_640x360_2.30.ogv " "! decodebin name=db " "db. ! autovideosink " "db. ! autoaudiosink ", NULL); gst_element_set_state(elm, GST_STATE_PLAYING); usleep(1000000 * 3); gst_element_seek_simple(elm, GST_FORMAT_TIME, GST_SEEK_FLAG_FLUSH|GST_SEEK_FLAG_ACCURATE, 15*GST_SECOND); usleep(1000000 * 10); gst_element_set_state(elm, GST_STATE_NULL); gst_object_unref(elm); After the seek, the playback stalls, and only the seek destination frame is being shown. If I add queue2 before the decodebin, it still is broken this way on gstreamer 1.4.5, but works on gstreamer 0.10.36 (without the queue, it won't play at all on gstreamer 0.10).
The "No chain to seek on" log seems to indicate the problem. 0:00:03.084814404 18490 0x2519d20 WARN oggdemux gstoggdemux.c:3512:gst_ogg_demux_perform_seek_push:<oggdemux0> No chain to seek on 0:00:04.626147905 18490 0x7f63dc002720 WARN theoradec gsttheoradec.c:786:theora_dec_decode_buffer:<theoradec0> Ignoring header 0:00:04.626200887 18490 0x7f63dc002720 WARN theoradec gsttheoradec.c:786:theora_dec_decode_buffer:<theoradec0> Ignoring header 0:00:04.626198969 18490 0x7f63dc143540 WARN vorbisdec gstvorbisdec.c:580:vorbis_dec_handle_frame:<vorbisdec0> Already initialized, so ignoring header packet 0:00:04.626243224 18490 0x7f63dc143540 WARN vorbisdec gstvorbisdec.c:580:vorbis_dec_handle_frame:<vorbisdec0> Already initialized, so ignoring header packet 0:00:04.626249269 18490 0x7f63dc002720 WARN theoradec gsttheoradec.c:786:theora_dec_decode_buffer:<theoradec0> Ignoring header 0:00:04.626257777 18490 0x7f63dc143540 WARN vorbisdec gstvorbisdec.c:580:vorbis_dec_handle_frame:<vorbisdec0> Already initialized, so ignoring header packet 0:00:04.626300017 18490 0x7f63dc002720 WARN theoradec gsttheoradec.c:732:theora_handle_data_packet:<theoradec0> dropping frame because we need a keyframe 0:00:04.626325649 18490 0x7f63dc002720 WARN theoradec gsttheoradec.c:732:theora_handle_data_packet:<theoradec0> dropping frame because we need a keyframe 0:00:04.626344606 18490 0x7f63dc002720 WARN theoradec gsttheoradec.c:732:theora_handle_data_packet:<theoradec0> dropping frame because we need a keyframe 0:00:04.626362538 18490 0x7f63dc002720 WARN theoradec gsttheoradec.c:732:theora_handle_data_packet:<theoradec0> dropping frame because we need a keyframe 0:00:04.626380526 18490 0x7f63dc002720 WARN theoradec gsttheoradec.c:732:theora_handle_data_packet:<theoradec0> dropping frame because we need a keyframe 0:00:04.626557330 18490 0x7f63dc002720 WARN theoradec gsttheoradec.c:732:theora_handle_data_packet:<theoradec0> dropping frame because we need a keyframe 0:00:04.727869342 18490 0x7f63dc13f4f0 WARN pulse pulsesink.c:714:gst_pulsering_stream_overflow_cb:<autoaudiosink0-actual-sink-pulse> Got overflow 0:00:04.739922908 18490 0x7f63dc13f4f0 WARN pulse pulsesink.c:714:gst_pulsering_stream_overflow_cb:<autoaudiosink0-actual-sink-pulse> Got overflow
It already stalls at startup here. I also get: 0:00:00.902556816 5943 0x23d92d0 WARN oggdemux gstoggdemux.c:2418:gst_ogg_demux_sink_event:<oggdemux0> EOS while trying to retrieve chain, seeking disabled (I added queues before both sinks, same result, but I'm not sure why it'd work for you without them).
As I've said, I've added the queue2 before the decodebin, not before sinks. It fixed the problem on gstreamer 0.10, but not on 1.x. I don't know what may be wrong, if using totem, seeking that file works. But totem is creating much more complex pipeline.
I did not try with a queue2, but it should work without one. The queues before sinks are so it can normally preroll (ie, both sinks have a buffer, which means decodebin can send the first one without blocking).
The queues before the sinks are not needed, and both sinks should still preroll, as the decodebin inserts multiqueue after the demuxer. Or was it only in 0.10?
Created attachment 324745 [details] [review] fix oggdemux seeking Once this is fixed, there is also a problem with Theora not decoding for a while because of missing keyframes. This may be related, or a different bug, not sure.
See bug #706063 which sounds like the no keyframes problem you mention.
Created attachment 325137 [details] [review] fix setting start time after seek That fixes the theoradec gets no keyframe problem.
Review of attachment 325137 [details] [review]: ::: ext/ogg/gstoggdemux.c @@ +1958,2 @@ ogg = pad->ogg; + if (ogg->discard_till_flush) What if this boolean is just set after the line? Don't we have to discard buffers that are queued up already when receiving FLUSH_STOP or something? This seems racy
I don't think it can. It can only be set in the streaming thread, or the flush start/stop sink event handler, which can't be called concurently to the streaming data AFAIK. The test is done in the streaming thread too.
FLUSH_START is called from a non-streaming thread, nothing should be done in a FLUSH_START handler other than forward the event.
Then I don't understand the patch :) It would push those buffers then but get GST_FLOW_FLUSHING and all would be good
Hmm, that's true or it woudn't be able to break prerolling sinks, I didn't think hard enough there.
Created attachment 325346 [details] [review] fix setting start time after seek Since this flag is intended to disregard data coming between a seek triggered from the streaming thread and the flush stop, it doesn't need to be set on the flush start, which removes the race.
This still seems racy. You somehow need to make sure that when the flushing seek happens the streaming thread gets shut down completely, no data is queued up anymore... and then you can do your seek magic and consider the next timestamp you see.
When a flushing seek happens, there is some code that sends a flush start, a flush stop, and data, no ? So the flush stop must come before the new data. When the seek is requested, the caller returns GST_FLOW_SKIP_PUSH, which will cause gst_ogg_pad_submit_page to early out, and future calls to this will early out till the flush stop, which is serialized, so can't become overlapped with the data, right ? I may be missing something here, but I'm not sure what.
So the GST_FLOW_SKIP_PUSH is just an optimization and everything works without that too?
It wouldn't work, since it'd set the start time to near the end of the logical stream (at least in some cases). Which is what this patch is trying to fix, even if apparently badly :)
So in that case it seems like this SKIP_PUSH part of the patch is racy. You could be exactly one line below when the event arrives and nothing would happen differently than without your patch. The bigger question is why it is still handling data at this point.
Can a flush stop *really* come through while you're busy in the streaming thread ? I see it for a flush start, but a flush stop ? > The bigger question is why it is still handling data at this point. What point ? I'm tempted to say the following, but I'm guessing that I'm missing your point, so it's unlikely to be responsive, but here goes: The request for a flushing seek is triggered by oggdemux from within the processing of data in the streaming thread. It happens when the data being processed is deemed to be too close to the end of the stream (itself being a hack, but whatever). At that point, it needs to cancel all the rest of the data it's got coming at it, until a flush stop signals that new data from there on is from the seeked to place (and thus picking a timestamp from there is known to be from the right place).
(In reply to Vincent Penquerc'h from comment #20) > Can a flush stop *really* come through while you're busy in the streaming > thread ? I see it for a flush start, but a flush stop ? That's exactly my point. Why would your code be inside the streaming thread at all? The streaming thread is supposed to be shut down before the flush-stop is sent. And after it starts again there should only be the new data. > > The bigger question is why it is still handling data at this point. > > What point ? I'm tempted to say the following, but I'm guessing that I'm > missing your point, so it's unlikely to be responsive, but here goes: > > The request for a flushing seek is triggered by oggdemux from within the > processing of data in the streaming thread. It happens when the data being > processed is deemed to be too close to the end of the stream (itself being a > hack, but whatever). At that point, it needs to cancel all the rest of the > data it's got coming at it, until a flush stop signals that new data from > there on is from the seeked to place (and thus picking a timestamp from > there is known to be from the right place). You mean oggdemux seeks (i.e. does a stream event) from its own streaming thread? That's not allowed
(In reply to Sebastian Dröge (slomo) from comment #21) > (In reply to Vincent Penquerc'h from comment #20) > > Can a flush stop *really* come through while you're busy in the streaming > > thread ? I see it for a flush start, but a flush stop ? > > That's exactly my point. Why would your code be inside the streaming thread > at all? The streaming thread is supposed to be shut down before the > flush-stop is sent. And after it starts again there should only be the new > data. While would the code be inside the streaming at all ? It is in the streaming thread when executing code like gst_ogg_demux_seek_back_after_push_duration_check_unlock, which sets up the flushing seek. After it starts again, there will be new data, yes. And just before that, the flush stop event will have arrived, and so the discard_till_flush flag will have been reset, as I want/expect. > You mean oggdemux seeks (i.e. does a stream event) from its own streaming > thread? That's not allowed Well, not directly. It creates a seek event in the streaming thread, and saves it in the object. It will be sent by.... I forget... looks like a separate thread that's spawned for that at pad activation.
-- GitLab Migration Automatic Message -- This bug has been migrated to freedesktop.org's GitLab instance and has been closed from further activity. You can subscribe and participate further through the new bug through this link to our GitLab instance: https://gitlab.freedesktop.org/gstreamer/gst-plugins-base/issues/220.