[vlc-commits] pulse: calculate the start time from the last date played

Thomas Guillem git at videolan.org
Wed Jan 23 15:34:54 CET 2019


vlc | branch: master | Thomas Guillem <thomas at gllm.fr> | Mon Jul  2 16:04:28 2018 +0200| [6c9f07a9ed0cfc923ae9bcd05c31f77048b0e109] | committer: Thomas Guillem

pulse: calculate the start time from the last date played

stream_latency_cb() is needed to re-calculate the new derrered time (or start
late in the worst case scenario) when the audio device latency changes.

This callback called stream_start() with the first played system date. The
problem is that the delta calculated from stream_start was always late. Using
the last system date seems more logical. Indeed, the delta need to be
calculated from values using the same reference point (and vlc_pa_get_latency()
is calculated from the amount of buffers played).

This issue could be easily reproduced when the first played date was more than
100ms in the future, by using --audio-desync 100 for example.

This issue was not visible in most cases, because the deferred time is small by
default (10ms) and because the stream_latency_cb is often triggered after this
time.

Here are some logs to illustrate this (I added logs that print the played block
pts, the delay since the first play and when the stream_latency_cb is called).

 * Logs without this patch when running vlc with "--audio-desync 100":

Play @110959, first play since 0us
[0000617000008d50] pulse audio output warning: cannot synchronize start
[0000617000008d50] pulse audio output warning: deferring start (110903 us)
Play @142466, first play since 493us
[0000617000008d50] pulse audio output warning: deferring start (110460 us)
Play @174193, first play since 766us
[0000617000008d50] pulse audio output warning: deferring start (110188 us)
Play @205943, first play since 1016us
[0000617000008d50] pulse audio output warning: deferring start (109937 us)
Play @237698, first play since 1261us
[0000617000008d50] pulse audio output warning: deferring start (109692 us)
Play @269435, first play since 1524us
[0000617000008d50] pulse audio output warning: deferring start (109430 us)
Play @301150, first play since 1809us
[0000617000008d50] pulse audio output warning: deferring start (109144 us)
Play @332900, first play since 2059us
[0000617000008d50] pulse audio output warning: deferring start (108895 us)
Play @364648, first play since 2311us
[0000617000008d50] pulse audio output warning: deferring start (108643 us)
Play @396354, first play since 2605us
[0000617000008d50] pulse audio output warning: deferring start (108349 us)
Play @428076, first play since 2883us
[0000617000008d50] pulse audio output warning: deferring start (108069 us)
Play @459788, first play since 3171us
[0000617000008d50] pulse audio output warning: deferring start (107783 us)
Play @491531, first play since 3428us
[0000617000008d50] pulse audio output warning: deferring start (107526 us)
Play @523276, first play since 3683us
[0000617000008d50] pulse audio output warning: deferring start (107271 us)
Play @555026, first play since 3933us
[0000617000008d50] pulse audio output warning: deferring start (107020 us)
stream_latency_cb
[0000617000008d50] pulse audio output warning: starting late (-396346 us)
starting since: 27318
[0000617000008d50] pulse audio output warning: started
[0000617000008d50] main audio output warning: playback too early (-78075): down-sampling

 * Logs with this patch when running vlc with "--audio-desync 100":

Play @110978, first play since 0us
[000055e7c506d030] pulse audio output warning: cannot synchronize start
[000055e7c506d030] pulse audio output warning: deferring start (110952 us)
Play @142708, first play since 270us
[000055e7c506d030] pulse audio output warning: deferring start (110699 us)
Play @174601, first play since 377us
[000055e7c506d030] pulse audio output warning: deferring start (110597 us)
Play @206446, first play since 532us
[000055e7c506d030] pulse audio output warning: deferring start (110443 us)
Play @238302, first play since 676us
[000055e7c506d030] pulse audio output warning: deferring start (110298 us)
Play @270173, first play since 805us
[000055e7c506d030] pulse audio output warning: deferring start (110151 us)
Play @302008, first play since 970us
[000055e7c506d030] pulse audio output warning: deferring start (110005 us)
Play @333914, first play since 1064us
[000055e7c506d030] pulse audio output warning: deferring start (109911 us)
Play @365818, first play since 1160us
[000055e7c506d030] pulse audio output warning: deferring start (109814 us)
Play @397712, first play since 1266us
[000055e7c506d030] pulse audio output warning: deferring start (109708 us)
Play @429588, first play since 1390us
[000055e7c506d030] pulse audio output warning: deferring start (109584 us)
Play @461489, first play since 1489us
[000055e7c506d030] pulse audio output warning: deferring start (109485 us)
Play @493351, first play since 1627us
[000055e7c506d030] pulse audio output warning: deferring start (109347 us)
Play @525261, first play since 1717us
[000055e7c506d030] pulse audio output warning: deferring start (109257 us)
Play @557173, first play since 1805us
[000055e7c506d030] pulse audio output warning: deferring start (109169 us)
stream_latency_cb
[000055e7c506d030] pulse audio output warning: deferring start (74793 us)
Play @555762, first play since 35216us
[000055e7c506d030] pulse audio output warning: deferring start (75748 us)
Play @587642, first play since 35336us
[000055e7c506d030] pulse audio output warning: deferring start (75637 us)
Play @619520, first play since 35458us
[000055e7c506d030] pulse audio output warning: deferring start (75516 us)
Play @651428, first play since 35550us
[000055e7c506d030] pulse audio output warning: deferring start (75425 us)
Play @683305, first play since 35673us
[000055e7c506d030] pulse audio output warning: deferring start (75302 us)
Play @715187, first play since 35791us
[000055e7c506d030] pulse audio output warning: deferring start (75183 us)
Play @747067, first play since 35911us
[000055e7c506d030] pulse audio output warning: deferring start (75063 us)
Play @778930, first play since 36048us
[000055e7c506d030] pulse audio output warning: deferring start (74926 us)
stream_latency_cb
[000055e7c506d030] pulse audio output warning: deferring start (34708 us)
[000055e7c506d030] pulse audio output warning: starting deferred
starting since: 79393
[000055e7c506d030] pulse audio output warning: started

You can see, with this patch, that the resampler is not triggered anymore and
that the stream really start after 100ms (79393 + pulse latency).

In both case, audio and video have the same delay, but in the first case,
the core had to correct it (by playing silence or with the resampler).

> http://git.videolan.org/gitweb.cgi/vlc.git/?a=commit;h=6c9f07a9ed0cfc923ae9bcd05c31f77048b0e109
---

 modules/audio_output/pulse.c | 22 +++++++++-------------
 1 file changed, 9 insertions(+), 13 deletions(-)

diff --git a/modules/audio_output/pulse.c b/modules/audio_output/pulse.c
index 2753fb87fd..5075dd92ce 100644
--- a/modules/audio_output/pulse.c
+++ b/modules/audio_output/pulse.c
@@ -68,8 +68,7 @@ typedef struct
     pa_threaded_mainloop *mainloop; /**< PulseAudio thread */
     pa_time_event *trigger; /**< Deferred stream trigger */
     pa_cvolume cvolume; /**< actual sink input volume */
-    vlc_tick_t first_pts; /**< Play stream timestamp of buffer start */
-    vlc_tick_t first_date; /**< Play system timestamp of buffer start */
+    vlc_tick_t last_date; /**< Play system timestamp of last buffer */
 
     pa_volume_t volume_force; /**< Forced volume (stream must be NULL) */
     pa_stream_flags_t flags_force; /**< Forced flags (stream must be NULL) */
@@ -227,7 +226,7 @@ static void stream_start(pa_stream *s, audio_output_t *aout, vlc_tick_t date)
     aout_sys_t *sys = aout->sys;
     vlc_tick_t delta;
 
-    assert (sys->first_pts != VLC_TICK_INVALID);
+    assert (sys->last_date != VLC_TICK_INVALID);
 
     if (sys->trigger != NULL) {
         vlc_pa_rttime_free(sys->mainloop, sys->trigger);
@@ -258,10 +257,10 @@ static void stream_latency_cb(pa_stream *s, void *userdata)
     aout_sys_t *sys = aout->sys;
 
     /* This callback is _never_ called while paused. */
-    if (sys->first_pts == VLC_TICK_INVALID)
+    if (sys->last_date == VLC_TICK_INVALID)
         return; /* nothing to do if buffers are (still) empty */
     if (pa_stream_is_corked(s) > 0)
-        stream_start(s, aout, sys->first_date);
+        stream_start(s, aout, sys->last_date);
 }
 
 
@@ -331,7 +330,7 @@ static void stream_overflow_cb(pa_stream *s, void *userdata)
     if (unlikely(op == NULL))
         return;
     pa_operation_unref(op);
-    sys->first_pts = VLC_TICK_INVALID;
+    sys->last_date = VLC_TICK_INVALID;
 }
 
 static void stream_started_cb(pa_stream *s, void *userdata)
@@ -504,10 +503,7 @@ static void Play(audio_output_t *aout, block_t *block, vlc_tick_t date)
      * will take place, and sooner or later a deadlock. */
     pa_threaded_mainloop_lock(sys->mainloop);
 
-    if (sys->first_pts == VLC_TICK_INVALID) {
-        sys->first_pts = block->i_pts;
-        sys->first_date = date;
-    }
+    sys->last_date = date;
 
     if (pa_stream_is_corked(s) > 0)
         stream_start(s, aout, date);
@@ -543,7 +539,7 @@ static void Pause(audio_output_t *aout, bool paused, vlc_tick_t date)
         stream_stop(s, aout);
     } else {
         pa_stream_set_latency_update_callback(s, stream_latency_cb, aout);
-        if (likely(sys->first_pts != VLC_TICK_INVALID))
+        if (likely(sys->last_date != VLC_TICK_INVALID))
             stream_start_now(s, aout);
     }
 
@@ -576,7 +572,7 @@ static void Flush(audio_output_t *aout, bool wait)
         op = pa_stream_flush(s, NULL, NULL);
     if (op != NULL)
         pa_operation_unref(op);
-    sys->first_pts = VLC_TICK_INVALID;
+    sys->last_date = VLC_TICK_INVALID;
     stream_stop(s, aout);
 
     pa_threaded_mainloop_unlock(sys->mainloop);
@@ -807,7 +803,7 @@ static int Start(audio_output_t *aout, audio_sample_format_t *restrict fmt)
 
     sys->trigger = NULL;
     pa_cvolume_init(&sys->cvolume);
-    sys->first_pts = VLC_TICK_INVALID;
+    sys->last_date = VLC_TICK_INVALID;
 
     pa_format_info *formatv = pa_format_info_new();
     formatv->encoding = encoding;



More information about the vlc-commits mailing list