[Spice-devel] [PATCH spice-gtk v2 3/3] channel-display: Instrument code to get frame and queue statistics

[Victor Toso]

Hi,

On Wed, Jan 23, 2019 at 11:28:57AM +0000, Frediano Ziglio wrote:
> This patch is based on some work from Victor Toso (statistics) and
> Snir Sheriber (GStreamer probing).
> All GstBuffers are queued into decoding_queue and a probe is
> attached to the sink in order to understand when the buffers
> are decoded.
> When a buffer is decoded the time spent and queue length are
> computed.

In addition to the extra commit log message

> 
> Signed-off-by: Frediano Ziglio <fziglio at redhat.com>
> ---
>  src/channel-display-gst.c  | 45 +++++++++++++++++++++++++++++++++-----
>  src/channel-display-priv.h |  3 +++
>  src/channel-display.c      |  1 +
>  3 files changed, 43 insertions(+), 6 deletions(-)
> 
> Changes since v1:
> - use G_GUINT64_FORMAT instead of PRIu64, SPICE_DEBUG is using GLib
>   function which expects GNU formatting, it gives a warning compiling
>   for Windows
> 
> diff --git a/src/channel-display-gst.c b/src/channel-display-gst.c
> index 08c9f8fb..c15f94f2 100644
> --- a/src/channel-display-gst.c
> +++ b/src/channel-display-gst.c
> @@ -248,6 +248,12 @@ static SpiceGstFrame *get_decoded_frame(SpiceGstDecoder *decoder, GstBuffer *buf
>      if (num_frames_dropped != 0) {
>          SPICE_DEBUG("the GStreamer pipeline dropped %u frames", num_frames_dropped);
>      }
> +    if (gstframe) {
> +        const SpiceFrame *frame = gstframe->encoded_frame;
> +        uint64_t duration = g_get_monotonic_time() - frame->creation_time;
> +        SPICE_DEBUG("frame mm_time %u size %u decoded time %" G_GUINT64_FORMAT " queue %u",
> +                    frame->mm_time, frame->size, duration, decoder->decoding_queue->length);
> +    }
>      return gstframe;
>  }
>  
> @@ -391,6 +397,34 @@ static void app_source_setup(GstElement *pipeline G_GNUC_UNUSED,
>      gst_caps_unref(caps);
>      decoder->appsrc = GST_APP_SRC(gst_object_ref(source));
>  }
> +
> +static GstPadProbeReturn
> +sink_event_probe(GstPad *pad, GstPadProbeInfo *info, gpointer data)
> +{
> +    SpiceGstDecoder *decoder = (SpiceGstDecoder*)data;
> +
> +    if (info->type & GST_PAD_PROBE_TYPE_BUFFER) { // Buffer arrived
> +        GstBuffer *buffer = GST_PAD_PROBE_INFO_BUFFER(info);
> +        g_mutex_lock(&decoder->queues_mutex);
> +        SpiceGstFrame *gstframe = get_decoded_frame(decoder, buffer);
> +        if (gstframe) {
> +            free_gst_frame(gstframe);
> +        }
> +        g_mutex_unlock(&decoder->queues_mutex);
> +    }
> +    return GST_PAD_PROBE_OK;
> +}
> +
> +/* This function is called to used to set a probe on the sink */
> +static void
> +add_elem_cb(GstBin * pipeline, GstBin * bin, GstElement * element, SpiceGstDecoder *decoder)

- Why the extra space between * and the var?
- I would instead name it element_added_cb or deep_element_added_cb

> +{
> +    if (GST_IS_BASE_SINK(element) && decoder->appsink == NULL) {

Do we need the decoder->appsink check for NULL here?

> +        GstPad *pad = gst_element_get_static_pad(element, "sink");
> +        gst_pad_add_probe(pad, GST_PAD_PROBE_TYPE_BUFFER, sink_event_probe, decoder, NULL);
> +        gst_object_unref(pad);
> +    }
> +}
>  #endif
>  
>  static gboolean create_pipeline(SpiceGstDecoder *decoder)
> @@ -455,6 +489,7 @@ static gboolean create_pipeline(SpiceGstDecoder *decoder)
>  #endif
>      }
>  
> +    g_signal_connect(playbin, "deep-element-added", G_CALLBACK(add_elem_cb), decoder);
>      g_signal_connect(playbin, "source-setup", G_CALLBACK(app_source_setup), decoder);
>  
>      g_object_set(playbin,
> @@ -660,12 +695,10 @@ static gboolean spice_gst_decoder_queue_frame(VideoDecoder *video_decoder,
>      GST_BUFFER_DTS(buffer) = GST_CLOCK_TIME_NONE;
>      GST_BUFFER_PTS(buffer) = gst_clock_get_time(decoder->clock) - gst_element_get_base_time(decoder->pipeline) + ((uint64_t)MAX(0, latency)) * 1000 * 1000;
>  
> -    if (decoder->appsink != NULL) {
> -        SpiceGstFrame *gst_frame = create_gst_frame(buffer, frame);
> -        g_mutex_lock(&decoder->queues_mutex);
> -        g_queue_push_tail(decoder->decoding_queue, gst_frame);
> -        g_mutex_unlock(&decoder->queues_mutex);
> -    }
> +    SpiceGstFrame *gst_frame = create_gst_frame(buffer, frame);
> +    g_mutex_lock(&decoder->queues_mutex);
> +    g_queue_push_tail(decoder->decoding_queue, gst_frame);
> +    g_mutex_unlock(&decoder->queues_mutex);
>  
>      if (gst_app_src_push_buffer(decoder->appsrc, buffer) != GST_FLOW_OK) {
>          SPICE_DEBUG("GStreamer error: unable to push frame");
> diff --git a/src/channel-display-priv.h b/src/channel-display-priv.h
> index c5c3f5c8..495df7ac 100644
> --- a/src/channel-display-priv.h
> +++ b/src/channel-display-priv.h
> @@ -45,6 +45,9 @@ struct SpiceFrame {
>      uint8_t *data;
>      uint32_t size;
>      gpointer data_opaque;
> +
> +    /* stats */
> +    gint64 creation_time;
>  };
>  
>  typedef struct VideoDecoder VideoDecoder;
> diff --git a/src/channel-display.c b/src/channel-display.c
> index ae2c4fbc..d46b3a37 100644
> --- a/src/channel-display.c
> +++ b/src/channel-display.c
> @@ -1657,6 +1657,7 @@ static SpiceFrame *spice_frame_new(display_stream *st,
>      frame->size = data_size;
>      frame->data_opaque = in;
>      spice_msg_in_ref(in);
> +    frame->creation_time = g_get_monotonic_time();
>      return frame;
>  }
>  
> -- 
> 2.20.1
> 
> _______________________________________________
> Spice-devel mailing list
> Spice-devel at lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/spice-devel
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 833 bytes
Desc: not available
URL: <https://lists.freedesktop.org/archives/spice-devel/attachments/20190123/9a94192c/attachment.sig>