After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 708276 - pipeline: fix potential overflow getting the new base time
pipeline: fix potential overflow getting the new base time
Status: RESOLVED INVALID
Product: GStreamer
Classification: Platform
Component: gstreamer (core)
unspecified
Other All
: Normal normal
: git master
Assigned To: GStreamer Maintainers
GStreamer Maintainers
Depends on:
Blocks:
 
 
Reported: 2013-09-18 11:20 UTC by Andoni Morales
Modified: 2013-09-28 15:49 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
pipeline: fix potential overflow getting the new base time (1.14 KB, patch)
2013-09-18 11:21 UTC, Andoni Morales
none Details | Review

Description Andoni Morales 2013-09-18 11:20:58 UTC
Clock changes where 'now' is smaller than the start_time result
in negative values for the new base time.
From gst_pipepline_update_base_time:
start_time=0:00:00.251270779, now=24:32:21.246680292, base_time 24:32:20.995409513
start_time=0:00:00.171604615, now=0:00:00.000000000, base_time 5124095:34:33.537947001
Comment 1 Andoni Morales 2013-09-18 11:21:04 UTC
Created attachment 255163 [details] [review]
pipeline: fix potential overflow getting the new base time
Comment 2 Sebastian Dröge (slomo) 2013-09-18 16:31:50 UTC
When exactly does this happen? This sounds like a non-monotonic clock and/or something broken with the start_time handling.
Comment 3 Andoni Morales 2013-09-18 16:55:43 UTC
I was happening in scenario in which a demuxer was changing state READY_TO_PAUSED synchronously when it should do it async, so the pipeline was going to PAUSED and PLAYING without any sink.
The sink was being added afterwards (when the demuxer exposes the new pad) and the pipeline goes to PAUSED than PLAYING because of buffering messages and the new base time is distributed again, this time using the audio sink's clock (I think)
I have fixed that in the demuxer, which now changes state async, but looking at the code in gstpipeline.c, there can be weird use cases in which this can still happen.
Comment 4 Sebastian Dröge (slomo) 2013-09-18 17:06:03 UTC
Ah so the clock was changing... if the clock is changing (clock-lost message) you need to go back to PAUSED (setting start_time with the new clock) and then back to PLAYING (setting base_time with new start_time and new clock).
Comment 5 Andoni Morales 2013-09-19 10:03:24 UTC
I don't have any clock lost and the clock is not the same. Also going to PAUSE/PLAY does not fixes the issue once base_time is wrong, only a seek does it, resetting start_time to 0. 

reset start_time to 0
selecting clock and base_time
Need to update start_time
Need to update clock.
start_time=0:00:00.000000000, now=1:30:36.897877665, base_time 1:30:36.897877665
start_time=0:00:00.302430723, now=1:30:37.200308388, base_time 1:30:36.897877665
start_time=0:00:00.302502953, now=1:30:37.200380618, base_time 1:30:36.897877665
selecting clock and base_time
Need to update start_time
Need to update clock.
start_time=0:00:00.302502953, now=1:30:37.213690249, base_time 1:30:36.911187296
start_time=0:00:00.587327066, now=1:30:37.498514362, base_time 1:30:36.911187296
start_time=0:00:00.588077746, now=1:30:37.499265042, base_time 1:30:36.911187296
selecting clock and base_time
Need to update start_time
Need to update clock.
start_time=0:00:00.588077746, now=0:00:00.000000000, base_time 5124095:34:33.121473870
start_time=0:00:01.580015246, now=0:00:00.991937500, base_time 5124095:34:33.121473870
start_time=0:00:01.788077746, now=0:00:01.200000000, base_time 5124095:34:33.121473870
selecting clock and base_time
Need to update start_time
Need to update clock.
start_time=0:00:01.788077746, now=0:00:01.200000000, base_time 5124095:34:33.121473870
start_time=0:00:02.234411079, now=0:00:01.646333333, base_time 5124095:34:33.121473870
start_time=0:00:02.448077746, now=0:00:01.860000000, base_time 5124095:34:33.121473870
Comment 6 Sebastian Dröge (slomo) 2013-09-28 10:25:59 UTC
Wim, what do you think about this? If I'm not mistaken the base time can be wrong with the attached patch if an overflow was prevented... as start_time was not taken into account at all.
Comment 7 Sebastian Dröge (slomo) 2013-09-28 10:26:12 UTC
Andoni, can you also provide a testcase for this?
Comment 8 Andoni Morales 2013-09-28 15:49:52 UTC
I have been able to reproduce it with a simple test case in 0.10, were the base_time is corrupted but I can't reproduce it in 1.0 were the base_time is reset to 0 correctly.And in the test case I received a clock-lost message correctly so I will close this bug.