GNOME Bugzilla – Bug 734659
qtdemux: Does not properly update base time for non-flushing seeks
Last modified: 2015-11-24 06:27:01 UTC
Trying to do video looping through a non-flushing segment seek. The video might play a couple of frames on the first loop but then skips frames because frame timestamp (~0.0) and QoS earliest_time is much greater.
QoS is on running time, which would still be increasing all the time when looping. Do you have a testcase?
Created attachment 283177 [details] [review] reset qos earliest time This patch resets earliest time if segment-done was received before. All this part is new to me so I'm probably sure this is not the way to fix this. I think there's also an issue in basesink because it the new QoS message timestamp is not reset to the new segment.
(In reply to comment #1) > QoS is on running time, which would still be increasing all the time when > looping. Do you have a testcase? I see. No, no test case that I can share yet. So, if QoS is on running time is it possible to do any looping? How will it get reset?
It does not need to be reset, it will just continue running. What will reset is the buffer timestamps and the stream time. Basically what needs to happen when looping over the same file is that the segments are correct. The first segment should have segment.base=0, the second one segment.base=running_time_of_end_of_first_segment, the third one ... It's the job of the demuxer (or whatever element is handling the seek) to do that. Bug #734470 might help, that's not specifically for looping but solving the same problem.
This is a sample looping player with a video file as well. This is similar to my app, but not exactly. http://hacks-galore.org/aleix/files/looping-player.tar.gz I initially was expecting GST_MESSAGE_SEGMENT_DONE at the end of the playback. When getting the message a new seek is performed and the same process again. The result is that the video stops because frames are discarded by QoS.
Can you provide the segment events that are sent from the demuxer here?
(In reply to comment #6) > Can you provide the segment events that are sent from the demuxer here? I have modified qtdemux so it prints the base time as well. These are the event segments that qtdemux generates. Base time is always 0, and as you said it seems it should be always increasing. There is some logic there to increase the base time, but it's overwritten a few lines below. 0:00:00.036780414 44722 0x7fdd080ee850 DEBUG qtdemux qtdemux.c:3499:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:00.000000000 0:00:00.098280292 44722 0x7fdd080ee850 DEBUG qtdemux qtdemux.c:3499:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:00.000000000 0:00:02.522844872 44722 0x7fdd080ee850 DEBUG qtdemux qtdemux.c:3499:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:00.000000000 0:00:05.196272448 44722 0x7fdd080ee850 DEBUG qtdemux qtdemux.c:3499:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:00.000000000 0:00:05.637909482 44722 0x7fdd080ee850 DEBUG qtdemux qtdemux.c:3499:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:00.000000000 0:00:06.065238331 44722 0x7fdd080ee850 DEBUG qtdemux qtdemux.c:3499:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:00.000000000 0:00:06.478601272 44722 0x7fdd080ee850 DEBUG qtdemux qtdemux.c:3499:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:00.000000000 0:00:06.913437224 44722 0x7fdd080ee850 DEBUG qtdemux qtdemux.c:3499:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:00.000000000 0:00:07.337089850 44722 0x7fdd080ee850 DEBUG qtdemux qtdemux.c:3499:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:00.000000000 0:00:07.751358037 44722 0x7fdd080ee850 DEBUG qtdemux qtdemux.c:3499:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:00.000000000 0:00:08.191993368 44722 0x7fdd080ee850 DEBUG qtdemux qtdemux.c:3499:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:00.000000000 0:00:08.594817138 44722 0x7fdd080ee850 DEBUG qtdemux qtdemux.c:3499:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:00.000000000 0:00:09.025289771 44722 0x7fdd080ee850 DEBUG qtdemux qtdemux.c:3499:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:00.000000000
Does it work if you comment out that line that resets the base to 0? The code there looks quite suspicious and I don't know what it's supposed to do :) In theory gst_segment_seek() should've done the right thing there already.
(In reply to comment #8) > Does it work if you comment out that line that resets the base to 0? The code > there looks quite suspicious and I don't know what it's supposed to do :) > > In theory gst_segment_seek() should've done the right thing there already. No, it doesn't. Also, gst_qtdemux_activate_segment is called always a first time and then, also, when seeking. So, the first time the function is called base time will be 0. Then, if we do a seek, a new segment will be generated with base time increased. I'm not sure this is correct. Shouldn't my first seek have a 0 base time?
No, unless your first seek is a flushing seek.
(In reply to comment #10) > No, unless your first seek is a flushing seek. OK. No, it's not a flush seek.
Created attachment 283279 [details] [review] update segment base time This patch updates the base time with the end running time of the last segment. This does generate segment events properly but looping doesn't work properly yet. Disabling QoS, looping does "kind of" work. First, the frames are played correctly. Then, it seems to stop. After the segment "duration" a new loop is done, but this time the frames are played really fast and stopped again and this is done repeatedly (frames playing fast, delay until end of segment and frames playing fast again...). Without this patch (and without QoS), as similar thing happened. Frames played really fast over and over again (instead of waiting for segment duration). Now it seems that the only missing thing is to synchronize the frames.
What are the segments that are produced by qtdemux now?
(In reply to comment #13) > What are the segments that are produced by qtdemux now? 0:00:00.137185423 11583 0x7f3ae00d3050 DEBUG qtdemux qtdemux.c:3496:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:00.000000000 0:00:00.235022197 11583 0x7f3ae00d3050 DEBUG qtdemux qtdemux.c:3496:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:02.235566666 0:00:04.896469844 11583 0x7f3ae00d3050 DEBUG qtdemux qtdemux.c:3496:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:07.240566666 0:00:12.574394269 11583 0x7f3ae00d3050 DEBUG qtdemux qtdemux.c:3496:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:12.245566666 0:00:17.644325148 11583 0x7f3ae00d3050 DEBUG qtdemux qtdemux.c:3496:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:17.250566666 0:00:22.615253463 11583 0x7f3ae00d3050 DEBUG qtdemux qtdemux.c:3496:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:22.255566666
The second one looks wrong. Why does it start with a base of 2.23 seconds instead of 5.0 seconds?
Created attachment 283286 [details] [review] update segment base time based on stop time This new patch generates these segments. For the non-QoS I still get a fast playback then a delay until the segment is done and the a fast playback again. Looking into this. 0:00:00.136885692 12703 0x7f7ea40d3050 DEBUG qtdemux qtdemux.c:3499:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:00.000000000 0:00:00.229184552 12703 0x7f7ea40d3050 DEBUG qtdemux qtdemux.c:3499:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:05.005000000 0:00:07.679243784 12703 0x7f7ea40d3050 DEBUG qtdemux qtdemux.c:3499:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:10.010000000 0:00:15.335373497 12703 0x7f7ea40d3050 DEBUG qtdemux qtdemux.c:3499:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:15.015000000 0:00:20.388722027 12703 0x7f7ea40d3050 DEBUG qtdemux qtdemux.c:3499:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:20.020000000 0:00:25.418155175 12703 0x7f7ea40d3050 DEBUG qtdemux qtdemux.c:3499:gst_qtdemux_activate_segment:<qtdemux0> newsegment 0 from 0:00:00.000000000 to 0:00:05.005000000, time 0:00:00.000000000, base 0:00:25.025000000
Even using the stop time to compute the base time is not right. I finally got the looping work. I had to comment (I know it's not right) this part in videodecoder: /* if (GST_CLOCK_TIME_IS_VALID (priv->last_timestamp_out)) { */ /* if (frame->pts < priv->last_timestamp_out) { */ /* GST_WARNING_OBJECT (decoder, */ /* "decreasing timestamp (%" GST_TIME_FORMAT " < %" */ /* GST_TIME_FORMAT ")", */ /* GST_TIME_ARGS (frame->pts), GST_TIME_ARGS (priv->last_timestamp_out)); */ /* priv->reordered_output = TRUE; */ /* /\* make it a bit less weird downstream *\/ */ /* frame->pts = priv->last_timestamp_out; */ /* } */ /* } */ This also solves the problem with and without QoS. I'm now investigating why this is happening.
See bug #734617 The problem is that it's not resetting last_timestamp_out. That part of the patch in that bug should fix it, the other parts should not be merged yet.
(In reply to comment #18) > See bug #734617 > > The problem is that it's not resetting last_timestamp_out. That part of the > patch in that bug should fix it, the other parts should not be merged yet. Should we create a separate bug for only that part and merge it?
Created attachment 283295 [details] [review] update segment base time based on stream segment position This patch and last_timestamp_out update from bug 734617 solves non-flushing seeks.
Created attachment 283375 [details] [review] update segment base time based on stream's segment position Same patch as before but removing qtdemux->segment_bsae which is not used anymore.
The patch in comment 21 doesn't work if looping starts, for example, in the middle of the segment.
(In reply to comment #22) > The patch in comment 21 doesn't work if looping starts, for example, in the > middle of the segment. Sorry, actually, what doesn't work is if the non-flushing seek segment stop is different than the end of the stream. Segment start can be whatever you want.
Created attachment 283388 [details] [review] update stream segment base time and eos stream if segment end is reached OK. One more patch. there was another issue were qtdemux was not checking the end of a strem segment it was only checking the global qtdemux segment. So, when performing non-flushing seeks with a segment with a stop value below the qtdemux segment stop, it was not working.
Sebastian, did you have any chance to look at the patch?
Review of attachment 283388 [details] [review]: ::: gst/isomp4/qtdemux.c @@ +3483,3 @@ + stream->segment.base = + gst_segment_to_running_time (&stream->segment, GST_FORMAT_TIME, + stream->segment.position); Using the stream position here can cause small de-sync of the streams as the base for one will be different from the other streams because their positions don't match. Unless I'm missing something, we should use the largest of the positions of all streams and use the same base for all stream segments. @@ +3494,3 @@ + ", base %" GST_TIME_FORMAT, seg_idx, GST_TIME_ARGS (start), + GST_TIME_ARGS (stop), GST_TIME_ARGS (time), + GST_TIME_ARGS (stream->segment.base)); There is a GST_FORMAT_SEGMENT that could simplify this statement.
Created attachment 285192 [details] [review] update segment base time for non-flushing seeks Thiago, thank you for the review! I think I have addressed the two comments. I don't know if this is even possible, but I have one concern: if there are video and audio streams and one stream segment (let's say video) is activated twice consecutively before the other had the chance to be activated. I think this patch would fail, because in the second activation the largest position would be the audio one (as it was not activated the first time). Let me know if this has any chance to happen and I'll try to think of another way to fix it. Thanks!
Review of attachment 285192 [details] [review]: Looks good, just needs a simplification. Also it would be good to test if this doesn't break the heavily edited samples from https://bugzilla.gnome.org/show_bug.cgi?id=345830 ::: gst/isomp4/qtdemux.c @@ +3500,3 @@ + } + } + stream->max_segment_position = -1; Sorry for not mentioning this earlier, but there is already a position tracking in qtdemux for all streams: qtdemux->segment.position This is actually what is used to answer the POSITION query. So you can simplify it here and use that. @@ +6211,3 @@ stream->stps_present = FALSE; if ((stream->stss_present = + !!qtdemux_tree_get_child_by_type_full (stbl, FOURCC_stss, Those changes seem to be caused by gst-indent not being consistent, they should be removed from this patch.
(In reply to comment #28) > Review of attachment 285192 [details] [review]: > > Looks good, just needs a simplification. > > Also it would be good to test if this doesn't break the heavily edited samples > from https://bugzilla.gnome.org/show_bug.cgi?id=345830 I am trying the videos and they don't work with this patch. > > Sorry for not mentioning this earlier, but there is already a position tracking > in qtdemux for all streams: qtdemux->segment.position > > This is actually what is used to answer the POSITION query. So you can simplify > it here and use that. > Not sure if I understand. Does qtdemux->segment.position *always* has the latest position for all streams? If so, this should work? stream->segment.base = gst_segment_to_running_time (&stream->segment, GST_FORMAT_TIME, qtdemux->segment.position); It doesn't work actually. So, in my patch I just used qtdemux->segment.position to save the largest position in each stream. But that doesn't work either. Audio loses synchronization after a while. Now that I have videos with multiple segments I will try to fix it properly. > @@ +6211,3 @@ > stream->stps_present = FALSE; > if ((stream->stss_present = > + !!qtdemux_tree_get_child_by_type_full (stbl, FOURCC_stss, > > Those changes seem to be caused by gst-indent not being consistent, they should > be removed from this patch. Yes, sorry. I just removed them
Created attachment 285306 [details] [review] update segment base time based on stream's segment position This patch: - plays correctly the files with multiple segments from bug 345830. - loops correctly with non-flushing seeks when looping the whole file. If I loop only until the middle of the video, then it doesn't work. I am starting to understand a little bit how the segment works, but sincerely, not fully yet.
Created attachment 285307 [details] [review] update segment base time Sorry, forgot to remove old variables. This one better.
(In reply to comment #30) > > If I loop only until the middle of the video, then it doesn't work. > Only true for multiple segments. Looping in a file with one segment per stream, works great. All in all, I think this is better than what we had until now.
Sorry it took so long to handle this. It seems some fixes to dash seeking/playback ended up fixing this as well. Your sample application with the sample file works correctly now. Marking as fixed but I can't pinpoint the exact commit that fixed it. Please reopen if it still fails for you somehow with latest git master.
Just updated to git master and the looping-player still fails. It's supposed to loop but it stops whenever the segment is done. Unless there's something wrong with the way I'm trying to loop, which is basically sending a seek event after segment is done.
Did you update gst-plugins-good? Is this using the same looping player and sample in the tarball you provided in this bug?
There's also -good/tests/icles/test-segment-seeks, which works nicely for me.
Sorry. The looping player works great now. It was too late last night (that's why I didn't reopen) and as you guessed didn't pull gst-plugins-good, actually none of them (I have a script...). I'll try to bisect and find the commit that fixed this, as I need to backport it to 1.6. Thanks!
Great, please put the commits you backport here to have this working in case any other people would also need this feature. Thanks for testing!
This is the commit that fixed the looping. http://cgit.freedesktop.org/gstreamer/gst-plugins-good/commit/gst/isomp4/qtdemux.c?id=9a9d4ecceabd0de3632f588ce5d89d7ba78b5490 You also need this extra one, otherwise the stream gets stuck for a few a while: http://cgit.freedesktop.org/gstreamer/gst-plugins-good/commit/gst/isomp4/qtdemux.c?id=bf95f93c0189aa04f18e264b86b6527e431c5d53 Both commits are included in 1.6, but not in 1.4.x. I have verified it and the looping player works in 1.6.1.
Btw, both commits can be applied to the 1.4 branch without issues and looping player works.