es_out: trace wake up delay for input pacing monitoring

This patch adds a new metric to track and understand the behaviour of the input pacing done from the input buffering values. The behaviour is showing correct properties currently, but as will be shown later in this commit message, this metric helps debugging pacing issues leading to screen freeze.

In the work for making clock-start distributed across every clock tracker, and because of a change removing the call to the function input_clock_ChangeSystemOrigin, the input clock wake-up delay was not computed correctly. Specifically, a huge delay of multiple hundred of millisecond was appearing at the startup of the playback for file:// media, leading to a huge gap in playback.

The problem can be revealed when tracing the input_clock_GetWakeup values. Those values are used to pace the input, and they are dates matching with up until when the input is allowed to sleep, or 0 to disable sleeping altogether. The value returned is valid up until vlc_tick_now() is bigger or a new input_clock_Update() is made.

By substracting vlc_tick_now() to this date when the value is not 0, we can get the time the input is supposed to wait before doing anything else. The graph would typically look like this when the freeze was happening at the beginning of the playback

   Input clock
     wake up
       ^
330ms -|             +----+
       |             |    |
       |             |    |
    0 -| ------------+    +--------..
       +----------------------------->t

In the current state or after proper fixes for the input pacing were done, it would display the following graph:

    Input clock
      wake up
        ^
        |
        +----------------------------->t
     0 -| ------------++--------------
        |             ||
        |             || 
-550ms -|             ++

As such, a very high value looks suspiciously wrong, and improvement could be made later to start the wake-up delay at -pts_delay immediately instead of returning 0 as long as the reference point is not registered yet in the input clock buffering subsystem.

This metric also catches additional artifacts that are generated by the input decoder waits right at the end of buffering, which might be interesting to investigate later.

In grafana, here is how the graph currently looks like:

Here is how the graph looks like with the freeze right at the beginning (after a few hundred millisecond playback).

Here is how the graph looks like without the freeze, and without the decoder wait:

For this last case, I've been running with the following patch. The usage of this is currently quite specific to my use cases, but the consequences is still interesting to gather. Using this kind of patch has a lot of consequences on what to do for clock bootstrapping in audio master, so it cannot be part of the tree right now of course.

commit 39bd3ba06a6a4c26baaa46a7ec6253e468aba783
Author: Alexandre Janniaux <ajanni@videolabs.io>
Date:   Thu Oct 31 20:07:34 2024 +0900

    input: es_out: start video before other tracks if needed

diff --git a/src/input/es_out.c b/src/input/es_out.c
index 5430fc35bc..798355344b 100644
--- a/src/input/es_out.c
+++ b/src/input/es_out.c
@@ -1313,7 +1313,7 @@ static void EsOutDecodersStopBuffering( es_out_t *out, bool b_forced )
     const vlc_tick_t i_decoder_buffering_start = vlc_tick_now();
     foreach_es_then_es_slaves(p_es)
     {
-        if( !p_es->p_dec || p_es->fmt.i_cat == SPU_ES )
+        if( !p_es->p_dec || p_es->fmt.i_cat != VIDEO_ES )
             continue;
         vlc_input_decoder_Wait( p_es->p_dec );
         if( p_es->p_dec_record )

changed milestone to %4.0

added Component::Core label

changed the description

added MRStatus::Reviewable label

added MRStatus::Accepted label and removed MRStatus::Reviewable label

MR Acceptance result

This MergeRequest has been Accepted! Congratulations.

MR acceptance checks details:

• MR should be considered mergeable by Gitlab
• Last pipeline should be successful
• No activity on MR (no thread, no vote) and last update is long enough

This message was automatically generated by homer-bot.

added 70 commits

• 29e2969c...013a7c33 - 69 commits from branch videolan:master
• 5f6060a4 - es_out: trace wake up delay for input pacing monitoring

Compare with previous version

enabled an automatic merge when all merge checks for 5f6060a4 pass

merged