<!DOCTYPE html>
<html>
<head>
<title></title>
<style type="text/css">p.MsoNormal,p.MsoNoSpacing{margin:0}</style>
</head>
<body><div><br></div>
<div>On Mon, Jul 2, 2018, at 18:05, Rémi Denis-Courmont wrote:<br></div>
<blockquote type="cite"><div>You need to start with the PTS of the first block in queue, not the last block. This does not look right.<br></div>
</blockquote><div><br></div>
<div>So I really don't understand what this latency callback is doing.<br></div>
<div><br></div>
<div>I'll try to explain what I understand. Here a log of pulse audio starting on the clock branch with a first played system date that is more than 200ms in the future (on current master, it's only 33ms).<br></div>
<div><div><div><br></div>
</div>
<div>Play: pts: 23220 length: 23219 date: 27747186134<br></div>
<div>[0000555823192b90] pulse audio output debug: cannot synchronize start<br></div>
<div>stream_start: date: 27747186134 pa_latency: 0<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (222587 us)<br></div>
<div><br></div>
<div>Play: pts: 46440 length: 23219 date: 27747209354<br></div>
<div>stream_start: date: 27747209354 pa_latency: 23219<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (222476 us)<br></div>
<div><br></div>
<div>Play: pts: 69660 length: 23219 date: 27747232574<br></div>
<div>stream_start: date: 27747232574 pa_latency: 46439<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (222429 us)<br></div>
<div><br></div>
<div>Play: pts: 92880 length: 23219 date: 27747255794<br></div>
<div>stream_start: date: 27747255794 pa_latency: 69659<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (222385 us)<br></div>
<div><br></div>
<div>Play: pts: 116100 length: 23219 date: 27747279014<br></div>
<div>stream_start: date: 27747279014 pa_latency: 92879<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (222343 us)<br></div>
<div><br></div>
<div>Play: pts: 139320 length: 23219 date: 27747302234<br></div>
<div>stream_start: date: 27747302234 pa_latency: 116099<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (222296 us)<br></div>
<div><br></div>
<div>Play: pts: 162540 length: 23219 date: 27747325454<br></div>
<div>stream_start: date: 27747325454 pa_latency: 139319<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (222253 us)<br></div>
<div><br></div>
<div>Play: pts: 185760 length: 23219 date: 27747348674<br></div>
<div>stream_start: date: 27747348674 pa_latency: 162539<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (222208 us)<br></div>
<div><br></div>
<div>Play: pts: 208980 length: 23219 date: 27747371894<br></div>
<div>stream_start: date: 27747371894 pa_latency: 185759<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (222156 us)<br></div>
<div><br></div>
<div>Play: pts: 232200 length: 23219 date: 27747395114<br></div>
<div>stream_start: date: 27747395114 pa_latency: 208979<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (222092 us)<br></div>
<div><br></div>
<div>Play: pts: 255420 length: 23219 date: 27747418334<br></div>
<div>stream_start: date: 27747418334 pa_latency: 232199<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (222026 us)<br></div>
<div><br></div>
<div>Play: pts: 278640 length: 23219 date: 27747441554<br></div>
<div>stream_start: date: 27747441554 pa_latency: 255419<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (221962 us)<br></div>
<div><br></div>
<div>Play: pts: 301860 length: 23219 date: 27747464774<br></div>
<div>stream_start: date: 27747464774 pa_latency: 278639<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (221916 us)<br></div>
<div><br></div>
<div>Play: pts: 325080 length: 23219 date: 27747487994<br></div>
<div>stream_start: date: 27747487994 pa_latency: 301859<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (221848 us)<br></div>
<div><br></div>
<div>Play: pts: 348300 length: 23219 date: 27747511214<br></div>
<div>stream_start: date: 27747511214 pa_latency: 325079<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (221802 us)<br></div>
<div><br></div>
<div>Play: pts: 371520 length: 23219 date: 27747534434<br></div>
<div>stream_start: date: 27747534434 pa_latency: 348299<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (221756 us)<br></div>
<div><br></div>
<div>Play: pts: 394740 length: 23219 date: 27747557654<br></div>
<div>stream_start: date: 27747557654 pa_latency: 371519<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (221713 us)<br></div>
<div><br></div>
<div>Play: pts: 417960 length: 23219 date: 27747580874<br></div>
<div>stream_start: date: 27747580874 pa_latency: 394739<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (221667 us)<br></div>
<div><br></div>
<div>Play: pts: 441180 length: 23219 date: 27747604094<br></div>
<div>stream_start: date: 27747604094 pa_latency: 417959<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (221623 us)<br></div>
<div><br></div>
<div>Play: pts: 464400 length: 23219 date: 27747627314<br></div>
<div>stream_start: date: 27747627314 pa_latency: 441179<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (221558 us)<br></div>
<div><br></div>
<div>Play: pts: 487620 length: 23219 date: 27747650534<br></div>
<div>stream_start: date: 27747650534 pa_latency: 464399<br></div>
<div>[0000555823192b90] pulse audio output debug: deferring start (221510 us)<br></div>
<div><br></div>
<div>stream_latency_cb: first_date: 27747186134<br></div>
<div>stream_start: date: 27747186134 pa_latency: 487619<br></div>
<div>[0000555823192b90] pulse audio output warning: starting late (-293433 us)<br></div>
<div><br></div>
<div><br></div>
<div>When the callback is received, the pa_latency value is changed from 464399 to 487619 (without any new buffer played) because PulseAudio notify us of a new hw latency. stream_start() will redo the delta calculation with this new pa_latency value but will compare it to the first_date (27747186134), therefore the result will be inevitably late. This new delta calculation should be done with the last date played (27747650534) since the pa_latency take into account the hw latency and all buffers already played.<br></div>
<div><br></div>
<div><br></div>
</div>
<blockquote type="cite"><div><br></div>
<div><div>Le 2 juillet 2018 17:31:59 GMT+03:00, Thomas Guillem <thomas@gllm.fr> a écrit :<br></div>
<blockquote style="margin-top:0pt;margin-right:0pt;margin-bottom:0pt;margin-left:0.8ex;border-left-color:rgb(204, 204, 204);border-left-style:solid;border-left-width:1px;padding-left:1ex;"><pre><div>If I understand correctly, stream_latency_cb() is needed to re-calculate the<br></div>
<div>
<br></div>
<div>new derrered time (or start late in the worst case scenario) when the audio<br></div>
<div>
<br></div>
<div>device latency changes.<br></div>
<div>
<br></div>
<div><br></div>
<div>
<br></div>
<div>This callback called stream_start() with the first played system date. The<br></div>
<div>
<br></div>
<div>problem is that the delta calculated from stream_start was always late. Using<br></div>
<div>
<br></div>
<div>the last system date seems more logical. Indeed, the delta need to be<br></div>
<div>
<br></div>
<div>calculated from values using the same reference point (and vlc_pa_get_latency()<br></div>
<div>
<br></div>
<div>is calculated from the amount of buffers played).<br></div>
<div>
<br></div>
<div><br></div>
<div>
<br></div>
<div>This issue can be reproduced when the first played date is more than 100ms in<br></div>
<div>
<br></div>
<div>the future.<br></div>
<div>
<br></div>
<div>---<br></div>
<div>
<br></div>
<div> modules/audio_output/pulse.c | 22 +++++++++-------------<br></div>
<div>
<br></div>
<div> 1 file changed, 9 insertions(+), 13 deletions(-)<br></div>
<div>
<br></div>
<div><br></div>
<div>
<br></div>
<div>diff --git a/modules/audio_output/pulse.c b/modules/audio_output/pulse.c<br></div>
<div>
<br></div>
<div>index f999eb534b..a275c9f5e6 100644<br></div>
<div>
<br></div>
<div>--- a/modules/audio_output/pulse.c<br></div>
<div>
<br></div>
<div>+++ b/modules/audio_output/pulse.c<br></div>
<div>
<br></div>
<div>@@ -68,8 +68,7 @@ typedef struct<br></div>
<div>
<br></div>
<div> pa_threaded_mainloop *mainloop; /**< PulseAudio thread */<br></div>
<div>
<br></div>
<div> pa_time_event *trigger; /**< Deferred stream trigger */<br></div>
<div>
<br></div>
<div> pa_cvolume cvolume; /**< actual sink input volume */<br></div>
<div>
<br></div>
<div>- vlc_tick_t first_pts; /**< Play stream timestamp of buffer start */<br></div>
<div>
<br></div>
<div>- vlc_tick_t first_date; /**< Play system timestamp of buffer start */<br></div>
<div>
<br></div>
<div>+ vlc_tick_t last_date; /**< Play system timestamp of last buffer */<br></div>
<div>
<br></div>
<div> <br></div>
<div>
<br></div>
<div> pa_volume_t volume_force; /**< Forced volume (stream must be NULL) */<br></div>
<div>
<br></div>
<div> pa_stream_flags_t flags_force; /**< Forced flags (stream must be NULL) */<br></div>
<div>
<br></div>
<div>@@ -227,7 +226,7 @@ static void stream_start(pa_stream *s, audio_output_t *aout, vlc_tick_t date)<br></div>
<div>
<br></div>
<div> aout_sys_t *sys = aout->sys;<br></div>
<div>
<br></div>
<div> vlc_tick_t delta;<br></div>
<div>
<br></div>
<div> <br></div>
<div>
<br></div>
<div>- assert (sys->first_pts != VLC_TS_INVALID);<br></div>
<div>
<br></div>
<div>+ assert (sys->last_date != VLC_TS_INVALID);<br></div>
<div>
<br></div>
<div> <br></div>
<div>
<br></div>
<div> if (sys->trigger != NULL) {<br></div>
<div>
<br></div>
<div> vlc_pa_rttime_free(sys->mainloop, sys->trigger);<br></div>
<div>
<br></div>
<div>@@ -258,10 +257,10 @@ static void stream_latency_cb(pa_stream *s, void *userdata)<br></div>
<div>
<br></div>
<div> aout_sys_t *sys = aout->sys;<br></div>
<div>
<br></div>
<div> <br></div>
<div>
<br></div>
<div> /* This callback is _never_ called while paused. */<br></div>
<div>
<br></div>
<div>- if (sys->first_pts == VLC_TS_INVALID)<br></div>
<div>
<br></div>
<div>+ if (sys->last_date == VLC_TS_INVALID)<br></div>
<div>
<br></div>
<div> return; /* nothing to do if buffers are (still) empty */<br></div>
<div>
<br></div>
<div> if (pa_stream_is_corked(s) > 0)<br></div>
<div>
<br></div>
<div>- stream_start(s, aout, sys->first_date);<br></div>
<div>
<br></div>
<div>+ stream_start(s, aout, sys->last_date);<br></div>
<div>
<br></div>
<div> }<br></div>
<div>
<br></div>
<div> <br></div>
<div>
<br></div>
<div> <br></div>
<div>
<br></div>
<div>@@ -331,7 +330,7 @@ static void stream_overflow_cb(pa_stream *s, void *userdata)<br></div>
<div>
<br></div>
<div> if (unlikely(op == NULL))<br></div>
<div>
<br></div>
<div> return;<br></div>
<div>
<br></div>
<div> pa_operation_unref(op);<br></div>
<div>
<br></div>
<div>- sys->first_pts = VLC_TS_INVALID;<br></div>
<div>
<br></div>
<div>+ sys->last_date = VLC_TS_INVALID;<br></div>
<div>
<br></div>
<div> }<br></div>
<div>
<br></div>
<div> <br></div>
<div>
<br></div>
<div> static void stream_started_cb(pa_stream *s, void *userdata)<br></div>
<div>
<br></div>
<div>@@ -504,10 +503,7 @@ static void Play(audio_output_t *aout, block_t *block, vlc_tick_t date)<br></div>
<div>
<br></div>
<div> * will take place, and sooner or later a deadlock. */<br></div>
<div>
<br></div>
<div> pa_threaded_mainloop_lock(sys->mainloop);<br></div>
<div>
<br></div>
<div> <br></div>
<div>
<br></div>
<div>- if (sys->first_pts == VLC_TS_INVALID) {<br></div>
<div>
<br></div>
<div>- sys->first_pts = block->i_pts;<br></div>
<div>
<br></div>
<div>- sys->first_date = date;<br></div>
<div>
<br></div>
<div>- }<br></div>
<div>
<br></div>
<div>+ sys->last_date = date;<br></div>
<div>
<br></div>
<div> <br></div>
<div>
<br></div>
<div> if (pa_stream_is_corked(s) > 0)<br></div>
<div>
<br></div>
<div> stream_start(s, aout, date);<br></div>
<div>
<br></div>
<div>@@ -543,7 +539,7 @@ static void Pause(audio_output_t *aout, bool paused, vlc_tick_t date)<br></div>
<div>
<br></div>
<div> stream_stop(s, aout);<br></div>
<div>
<br></div>
<div> } else {<br></div>
<div>
<br></div>
<div> pa_stream_set_latency_update_callback(s, stream_latency_cb, aout);<br></div>
<div>
<br></div>
<div>- if (likely(sys->first_pts != VLC_TS_INVALID))<br></div>
<div>
<br></div>
<div>+ if (likely(sys->last_date != VLC_TS_INVALID))<br></div>
<div>
<br></div>
<div> stream_start_now(s, aout);<br></div>
<div>
<br></div>
<div> }<br></div>
<div>
<br></div>
<div> <br></div>
<div>
<br></div>
<div>@@ -576,7 +572,7 @@ static void Flush(audio_output_t *aout, bool wait)<br></div>
<div>
<br></div>
<div> op = pa_stream_flush(s, NULL, NULL);<br></div>
<div>
<br></div>
<div> if (op != NULL)<br></div>
<div>
<br></div>
<div> pa_operation_unref(op);<br></div>
<div>
<br></div>
<div>- sys->first_pts = VLC_TS_INVALID;<br></div>
<div>
<br></div>
<div>+ sys->last_date = VLC_TS_INVALID;<br></div>
<div>
<br></div>
<div> stream_stop(s, aout);<br></div>
<div>
<br></div>
<div> <br></div>
<div>
<br></div>
<div> pa_threaded_mainloop_unlock(sys->mainloop);<br></div>
<div>
<br></div>
<div>@@ -807,7 +803,7 @@ static int Start(audio_output_t *aout, audio_sample_format_t *restrict fmt)<br></div>
<div>
<br></div>
<div> <br></div>
<div>
<br></div>
<div> sys->trigger = NULL;<br></div>
<div>
<br></div>
<div> pa_cvolume_init(&sys->cvolume);<br></div>
<div>
<br></div>
<div>- sys->first_pts = VLC_TS_INVALID;<br></div>
<div>
<br></div>
<div>+ sys->last_date = VLC_TS_INVALID;<br></div>
<div>
<br></div>
<div> <br></div>
<div>
<br></div>
<div> pa_format_info *formatv = pa_format_info_new();<br></div>
<div>
<br></div>
<div> formatv->encoding = encoding;<br></div>
<div>
<br></div>
</pre></blockquote></div>
<div><br></div>
<div>--<br></div>
<div>Envoyé de mon appareil Android avec Courriel K-9 Mail. Veuillez excuser ma brièveté. <br></div>
<div><u>_______________________________________________</u><br></div>
<div>vlc-devel mailing list<br></div>
<div>To unsubscribe or modify your subscription options:<br></div>
<div><a href="https://mailman.videolan.org/listinfo/vlc-devel">https://mailman.videolan.org/listinfo/vlc-devel</a><br></div>
</blockquote><div><br></div>
</body>
</html>