From: Jan Schmidt <jan@centricular.com>
Date: Thu, 16 Mar 2017 02:56:10 +0000 (+1100)
Subject: videodecoder: Add debug output tracking decode-after-flush
X-Git-Tag: 1.19.3~511^2~2324
X-Git-Url: http://review.tizen.org/git/?a=commitdiff_plain;h=2d3e69dca3d0821edfa534276659b40d45afee01;p=platform%2Fupstream%2Fgstreamer.git

videodecoder: Add debug output tracking decode-after-flush

Track how long it takes to generate the first buffer after a flush
as a simple measure of how efficient the decoder is at skipping /
rushing to get to the first decode.
---

diff --git a/gst-libs/gst/video/gstvideodecoder.c b/gst-libs/gst/video/gstvideodecoder.c
index 3702243..0a21e46 100644
--- a/gst-libs/gst/video/gstvideodecoder.c
+++ b/gst-libs/gst/video/gstvideodecoder.c
@@ -401,6 +401,12 @@ struct _GstVideoDecoderPrivate
 
   /* flags */
   gboolean use_default_pad_acceptcaps;
+
+#ifndef GST_DISABLE_DEBUG
+  /* Diagnostic time for reporting the time
+   * from flush to first output */
+  GstClockTime last_reset_time;
+#endif
 };
 
 static GstElementClass *parent_class = NULL;
@@ -2080,6 +2086,10 @@ gst_video_decoder_reset (GstVideoDecoder * decoder, gboolean full,
   priv->time = 0;
   GST_OBJECT_UNLOCK (decoder);
 
+#ifndef GST_DISABLE_DEBUG
+  priv->last_reset_time = gst_util_get_timestamp ();
+#endif
+
   GST_VIDEO_DECODER_STREAM_UNLOCK (decoder);
 }
 
@@ -3176,6 +3186,17 @@ gst_video_decoder_clip_and_push_buf (GstVideoDecoder * decoder, GstBuffer * buf)
   if (G_UNLIKELY (priv->error_count))
     priv->error_count = 0;
 
+#ifndef GST_DISABLE_DEBUG
+  if (G_UNLIKELY (priv->last_reset_time != GST_CLOCK_TIME_NONE)) {
+    GstClockTime elapsed = gst_util_get_timestamp () - priv->last_reset_time;
+
+    /* First buffer since reset, report how long we took */
+    GST_INFO_OBJECT (decoder, "First buffer since flush took %" GST_TIME_FORMAT
+        " to produce", GST_TIME_ARGS (elapsed));
+    priv->last_reset_time = GST_CLOCK_TIME_NONE;
+  }
+#endif
+
   ret = gst_pad_push (decoder->srcpad, buf);
 
 done: