aout: trace more events

Specially late/early events.

src/audio_output/aout_internal.h

@@ -137,6 +137,7 @@ struct vlc_aout_stream_cfg
     const audio_sample_format_t *fmt;
     int profile;
     struct vlc_clock_t *clock;
+    const char *str_id;
     const audio_replay_gain_t *replay_gain;
 };
 

src/audio_output/dec.c

@@ -33,6 +33,7 @@
 
 #include <vlc_common.h>
 #include <vlc_aout.h>
+#include <vlc_tracer.h>
 
 #include "aout_internal.h"
 #include "clock/clock.h"
@@ -60,6 +61,8 @@ struct vlc_aout_stream
     } sync;
     vlc_tick_t original_pts;
 
+    const char *str_id;
+
     /* Original input format and profile, won't change for the lifetime of a
      * stream (between vlc_aout_stream_New() and vlc_aout_stream_Delete()). */
     int                   input_profile;
@@ -90,6 +93,12 @@ static inline audio_output_t *aout_stream_aout(vlc_aout_stream *stream)
     return &stream->instance->output;
 }
 
+static inline struct vlc_tracer *aout_stream_tracer(vlc_aout_stream *stream)
+{
+    return stream->str_id == NULL ? NULL :
+        vlc_object_get_tracer(VLC_OBJECT(aout_stream_aout(stream)));
+}
+
 static void stream_Reset(vlc_aout_stream *stream)
 {
     aout_owner_t *owner = aout_stream_owner(stream);
@@ -182,6 +191,7 @@ vlc_aout_stream * vlc_aout_stream_New(audio_output_t *p_aout,
     stream->filter_format = stream->mixer_format = stream->input_format = *p_format;
 
     stream->sync.clock = cfg->clock;
+    stream->str_id = cfg->str_id;
 
     stream->filters = NULL;
     stream->filters_cfg = AOUT_FILTERS_CFG_INIT;
@@ -197,7 +207,7 @@ vlc_aout_stream * vlc_aout_stream_New(audio_output_t *p_aout,
             aout_volume_SetFormat(stream->volume, stream->mixer_format.i_format);
 
         /* Create the audio filtering "input" pipeline */
-        stream->filters = aout_FiltersNewWithClock(VLC_OBJECT(p_aout), clock,
+        stream->filters = aout_FiltersNewWithClock(VLC_OBJECT(p_aout), cfg->clock,
                                                    &stream->filter_format,
                                                    &stream->mixer_format,
                                                    &stream->filters_cfg);
@@ -267,8 +277,13 @@ static int stream_CheckReady (vlc_aout_stream *stream)
             stream->filters = NULL;
         }
 
+        struct vlc_tracer *tracer = aout_stream_tracer(stream);
+
         if (restart & AOUT_RESTART_OUTPUT)
         {   /* Reinitializes the output */
+            if (tracer != NULL)
+                vlc_tracer_TraceEvent(tracer, "RENDER", stream->str_id, "restart");
+
             msg_Dbg (aout, "restarting output...");
             if (stream->mixer_format.i_format)
                 aout_OutputDelete (aout);
@@ -288,6 +303,8 @@ static int stream_CheckReady (vlc_aout_stream *stream)
             if (restart == AOUT_RESTART_OUTPUT)
                 status = AOUT_DEC_CHANGED;
         }
+        else if (tracer != NULL)
+            vlc_tracer_TraceEvent(tracer, "RENDER", stream->str_id, "filters_restart");
 
         msg_Dbg (aout, "restarting filters...");
         stream->sync.resamp_type = AOUT_RESAMPLING_NONE;
@@ -378,6 +395,8 @@ static void stream_RequestRetiming(vlc_aout_stream *stream, vlc_tick_t system_ts
     if (unlikely(drift == VLC_TICK_MAX) || owner->bitexact)
         return; /* cf. VLC_TICK_MAX comment in vlc_aout_stream_Play() */
 
+    struct vlc_tracer *tracer = aout_stream_tracer(stream);
+
     /* Following calculations expect an opposite drift. Indeed,
      * vlc_clock_Update() returns a positive relative time, corresponding to
      * the time when audio_ts is expected to be played (in the future when not
@@ -393,6 +412,9 @@ static void stream_RequestRetiming(vlc_aout_stream *stream, vlc_tick_t system_ts
     if (drift > (stream->sync.discontinuity ? 0
                 : lroundf(+3 * AOUT_MAX_PTS_DELAY / rate)))
     {
+        if (tracer != NULL)
+            vlc_tracer_TraceEvent(tracer, "RENDER", stream->str_id, "late_flush");
+
         if (!stream->sync.discontinuity)
             msg_Warn (aout, "playback way too late (%"PRId64"): "
                       "flushing buffers", drift);
@@ -411,8 +433,13 @@ static void stream_RequestRetiming(vlc_aout_stream *stream, vlc_tick_t system_ts
                 : lroundf(-3 * AOUT_MAX_PTS_ADVANCE / rate)))
     {
         if (!stream->sync.discontinuity)
+        {
+            if (tracer != NULL)
+                vlc_tracer_TraceEvent(tracer, "RENDER", stream->str_id, "early_silence");
+
             msg_Warn (aout, "playback way too early (%"PRId64"): "
                       "playing silence", drift);
+        }
         stream_Silence(stream, -drift, audio_ts);
 
         stream_StopResampling(stream);
@@ -427,6 +454,8 @@ static void stream_RequestRetiming(vlc_aout_stream *stream, vlc_tick_t system_ts
     if (drift > +AOUT_MAX_PTS_DELAY
      && stream->sync.resamp_type != AOUT_RESAMPLING_UP)
     {
+        if (tracer != NULL)
+            vlc_tracer_TraceEvent(tracer, "RENDER", stream->str_id, "late_upsampling");
         msg_Warn (aout, "playback too late (%"PRId64"): up-sampling",
                   drift);
         stream->sync.resamp_type = AOUT_RESAMPLING_UP;
@@ -435,6 +464,8 @@ static void stream_RequestRetiming(vlc_aout_stream *stream, vlc_tick_t system_ts
     if (drift < -AOUT_MAX_PTS_ADVANCE
      && stream->sync.resamp_type != AOUT_RESAMPLING_DOWN)
     {
+        if (tracer != NULL)
+            vlc_tracer_TraceEvent(tracer, "RENDER", stream->str_id, "early_downsampling");
         msg_Warn (aout, "playback too early (%"PRId64"): down-sampling",
                   drift);
         stream->sync.resamp_type = AOUT_RESAMPLING_DOWN;
@@ -447,6 +478,9 @@ static void stream_RequestRetiming(vlc_aout_stream *stream, vlc_tick_t system_ts
     if (llabs (drift) > 2 * stream->sync.resamp_start_drift)
     {   /* If the drift is ever increasing, then something is seriously wrong.
          * Cease resampling and hope for the best. */
+        if (tracer != NULL)
+            vlc_tracer_TraceEvent(tracer, "RENDER", stream->str_id, "timing_screwed");
+
         msg_Warn (aout, "timing screwed (drift: %"PRId64" us): "
                   "stopping resampling", drift);
         stream_StopResampling(stream);
@@ -466,6 +500,9 @@ static void stream_RequestRetiming(vlc_aout_stream *stream, vlc_tick_t system_ts
     if (!aout_FiltersAdjustResampling (stream->filters, adj))
     {   /* Everything is back to normal: stop resampling. */
         stream->sync.resamp_type = AOUT_RESAMPLING_NONE;
+
+        if (tracer != NULL)
+            vlc_tracer_TraceEvent(tracer, "RENDER", stream->str_id, "stop_resampling");
         msg_Dbg (aout, "resampling stopped (drift: %"PRId64" us)", drift);
     }
 }
@@ -632,6 +669,11 @@ void vlc_aout_stream_ChangePause(vlc_aout_stream *stream, bool paused, vlc_tick_
 
     if (stream->mixer_format.i_format)
     {
+        struct vlc_tracer *tracer = aout_stream_tracer(stream);
+        if (tracer != NULL)
+            vlc_tracer_TraceEvent(tracer, "RENDER", stream->str_id,
+                                  paused ? "paused" : "resumed");
+
         if (aout->pause != NULL)
             aout->pause(aout, paused, date);
         else if (paused)
@@ -653,6 +695,10 @@ void vlc_aout_stream_Flush(vlc_aout_stream *stream)
 {
     audio_output_t *aout = aout_stream_aout(stream);
 
+    struct vlc_tracer *tracer = aout_stream_tracer(stream);
+    if (tracer != NULL)
+        vlc_tracer_TraceEvent(tracer, "RENDER", stream->str_id, "flushed");
+
     stream_Reset(stream);
     if (stream->mixer_format.i_format)
         aout->flush(aout);
@@ -691,6 +737,11 @@ void vlc_aout_stream_Drain(vlc_aout_stream *stream)
     if (!stream->mixer_format.i_format)
         return;
 
+    struct vlc_tracer *tracer = aout_stream_tracer(stream);
+
+    if (tracer != NULL)
+        vlc_tracer_TraceEvent(tracer, "RENDER", stream->str_id, "drain");
+
     if (stream->filters)
     {
         block_t *block = aout_FiltersDrain (stream->filters);

src/input/decoder.c

@@ -387,6 +387,7 @@ static int ModuleThread_UpdateAudioFormat( decoder_t *p_dec )
                 .fmt = &format,
                 .profile = p_dec->fmt_out.i_profile,
                 .clock = p_owner->p_clock,
+                .str_id = p_owner->psz_id,
                 .replay_gain = &p_dec->fmt_out.audio_replay_gain
             };
             p_astream = vlc_aout_stream_New( p_aout, &cfg );