[Spice-devel] [PATCH v2 spice-gtk 3/3] display: debug video streams frames dropping

[Yonit Halperin]

---
 gtk/channel-display-priv.h |    5 +++++
 gtk/channel-display.c      |   19 +++++++++++++++++++
 2 files changed, 24 insertions(+), 0 deletions(-)

diff --git a/gtk/channel-display-priv.h b/gtk/channel-display-priv.h
index 1969697..8aac8d8 100644
--- a/gtk/channel-display-priv.h
+++ b/gtk/channel-display-priv.h
@@ -71,6 +71,11 @@ typedef struct display_stream {
     GQueue                      *msgq;
     guint                       timeout;
     SpiceChannel                *channel;
+    uint32_t                    num_drops_arrival;
+    uint64_t                    drop_arrival_late_time;
+    uint32_t                    num_drops_play;
+    uint64_t                    drop_play_late_time;
+    uint32_t                    num_total_frames;
 } display_stream;
 
 void stream_get_dimensions(display_stream *st, int *width, int *height);
diff --git a/gtk/channel-display.c b/gtk/channel-display.c
index a8e830b..b57e04f 100644
--- a/gtk/channel-display.c
+++ b/gtk/channel-display.c
@@ -981,6 +981,8 @@ static gboolean display_stream_schedule(display_stream *st)
         st->timeout = g_timeout_add(d, (GSourceFunc)display_stream_render, st);
         return TRUE;
     } else {
+        st->num_drops_play++;
+        st->drop_play_late_time += time - op->multi_media_time;
         in = g_queue_pop_head(st->msgq);
         spice_msg_in_unref(in);
         if (g_queue_get_length(st->msgq) == 0)
@@ -1137,7 +1139,11 @@ static void display_handle_stream_data(SpiceChannel *channel, SpiceMsgIn *in)
         op->multi_media_time = mmtime + 100; /* workaround... */
     }
 
+    st->num_total_frames++;
+
     if (op->multi_media_time < mmtime) {
+        st->num_drops_arrival++;
+        st->drop_arrival_late_time += mmtime - op->multi_media_time;
         SPICE_DEBUG("stream data too late by %u ms (ts: %u, mmtime: %u), dropin",
                     mmtime - op->multi_media_time, op->multi_media_time, mmtime);
         return;
@@ -1173,6 +1179,7 @@ static void destroy_stream(SpiceChannel *channel, int id)
 {
     SpiceDisplayChannelPrivate *c = SPICE_DISPLAY_CHANNEL(channel)->priv;
     display_stream *st;
+    int num_played_frames;
 
     g_return_if_fail(c != NULL);
     g_return_if_fail(c->streams != NULL);
@@ -1181,6 +1188,18 @@ static void destroy_stream(SpiceChannel *channel, int id)
     if (!st)
         return;
 
+    num_played_frames = st->num_total_frames - st->num_drops_arrival - st->num_drops_play;
+    SPICE_DEBUG("strem id %d late-arrival drops %d (avg late time %.2f),"
+                "late-play drops %d (avg late time %.2f), played %f (%d/%d)",
+                id,
+                (int)st->num_drops_arrival,
+                st->num_drops_arrival ? (st->drop_arrival_late_time + 0.0) / st->num_drops_arrival :
+                                        0.0,
+                (int)st->num_drops_play,
+                st->num_drops_play ? (st->drop_play_late_time + 0.0) / st->num_drops_play : 0,
+                st->num_total_frames ? (num_played_frames + 0.0) / st->num_total_frames : 0,
+                num_played_frames,
+                st->num_total_frames);
     switch (st->codec) {
     case SPICE_VIDEO_CODEC_TYPE_MJPEG:
         stream_mjpeg_cleanup(st);
-- 
1.7.7.6