[Spice-commits] 8 commits - gtk/channel-display.c gtk/channel-display-priv.h gtk/channel-playback.c gtk/channel-playback-priv.h gtk/Makefile.am gtk/spice-pulse.c gtk/spice-session.c gtk/spice-session-priv.h spice-common

Yonit Halperin yhalperi at kemper.freedesktop.org
Mon Apr 22 13:32:31 PDT 2013


 gtk/Makefile.am             |    1 
 gtk/channel-display-priv.h  |   29 +++++++
 gtk/channel-display.c       |  161 +++++++++++++++++++++++++++++++++++++++++---
 gtk/channel-playback-priv.h |   24 ++++++
 gtk/channel-playback.c      |   64 +++++++++++++++++
 gtk/spice-pulse.c           |  142 ++++++++++++++++++++++++--------------
 gtk/spice-session-priv.h    |    4 +
 gtk/spice-session.c         |   46 ++++++++++++
 spice-common                |    2 
 9 files changed, 413 insertions(+), 60 deletions(-)

New commits:
commit 42b9f1aa911ce81ca70c000125dcbaa325470403
Author: Yonit Halperin <yhalperi at redhat.com>
Date:   Tue Feb 19 12:07:14 2013 -0500

    channel-display: trigger re-sync of audio playback latency when there are frequent video frame drops
    
    This was added in order to respond more quickly when the audio and video playback are
    not synchronized, and when the latency between the client and the server
    is high (i.e., when the server response to the status is delayed).

diff --git a/gtk/channel-display-priv.h b/gtk/channel-display-priv.h
index 49f82fe..09683be 100644
--- a/gtk/channel-display-priv.h
+++ b/gtk/channel-display-priv.h
@@ -88,6 +88,8 @@ typedef struct display_stream {
     GArray               *drops_seqs_stats_arr;
     uint32_t             num_drops_seqs;
 
+    uint32_t             playback_sync_drops_seq_len;
+
     /* playback quality report to server */
     gboolean report_is_active;
     uint32_t report_id;
diff --git a/gtk/channel-display.c b/gtk/channel-display.c
index ca77653..9e03727 100644
--- a/gtk/channel-display.c
+++ b/gtk/channel-display.c
@@ -1303,6 +1303,7 @@ static void display_update_stream_report(SpiceDisplayChannel *channel, uint32_t
     }
 }
 
+#define STREAM_PLAYBACK_SYNC_DROP_SEQ_LEN_LIMIT 5
 /* coroutine context */
 static void display_handle_stream_data(SpiceChannel *channel, SpiceMsgIn *in)
 {
@@ -1339,11 +1340,14 @@ static void display_handle_stream_data(SpiceChannel *channel, SpiceMsgIn *in)
                       mmtime - op->multi_media_time, op->multi_media_time, mmtime);
         st->arrive_late_time += mmtime - op->multi_media_time;
         st->num_drops_on_arive++;
+
         if (!st->cur_drops_seq_stats.len) {
             st->cur_drops_seq_stats.start_mm_time = op->multi_media_time;
         }
         st->cur_drops_seq_stats.len++;
+        st->playback_sync_drops_seq_len++;
     } else {
+        CHANNEL_DEBUG(channel, "video latency: %d", latency);
         spice_msg_in_ref(in);
         g_queue_push_tail(st->msgq, in);
         display_stream_schedule(st);
@@ -1354,9 +1358,14 @@ static void display_handle_stream_data(SpiceChannel *channel, SpiceMsgIn *in)
             memset(&st->cur_drops_seq_stats, 0, sizeof(st->cur_drops_seq_stats));
             st->num_drops_seqs++;
         }
+        st->playback_sync_drops_seq_len = 0;
     }
     display_update_stream_report(SPICE_DISPLAY_CHANNEL(channel), op->id,
                                  op->multi_media_time, latency);
+    if (st->playback_sync_drops_seq_len >= STREAM_PLAYBACK_SYNC_DROP_SEQ_LEN_LIMIT) {
+        spice_session_sync_playback_latency(spice_channel_get_session(channel));
+        st->playback_sync_drops_seq_len = 0;
+    }
 }
 
 /* coroutine context */
commit 9ad3b82a5e0da1bb4069b15181db5fc2d298b3d1
Author: Yonit Halperin <yhalperi at redhat.com>
Date:   Tue Feb 19 11:53:03 2013 -0500

    playback: support syncing the playback latency via session

diff --git a/gtk/channel-playback-priv.h b/gtk/channel-playback-priv.h
index dc89e2d..aa33d2c 100644
--- a/gtk/channel-playback-priv.h
+++ b/gtk/channel-playback-priv.h
@@ -20,4 +20,5 @@
 
 gboolean spice_playback_channel_is_active(SpicePlaybackChannel *channel);
 guint32 spice_playback_channel_get_latency(SpicePlaybackChannel *channel);
+void spice_playback_channel_sync_latency(SpicePlaybackChannel *channel);
 #endif
diff --git a/gtk/channel-playback.c b/gtk/channel-playback.c
index 3d959c4..f246a80 100644
--- a/gtk/channel-playback.c
+++ b/gtk/channel-playback.c
@@ -575,3 +575,12 @@ guint32 spice_playback_channel_get_latency(SpicePlaybackChannel *channel)
     }
     return channel->priv->latency;
 }
+
+G_GNUC_INTERNAL
+void spice_playback_channel_sync_latency(SpicePlaybackChannel *channel)
+{
+    g_return_if_fail(SPICE_IS_PLAYBACK_CHANNEL(channel));
+    g_return_if_fail(channel->priv->is_active);
+    SPICE_DEBUG("%s: notify latency update %u", __FUNCTION__, channel->priv->min_latency);
+    g_object_notify_main_context(G_OBJECT(SPICE_CHANNEL(channel)), "min-latency");
+}
diff --git a/gtk/spice-session-priv.h b/gtk/spice-session-priv.h
index 37f848c..5ed48dd 100644
--- a/gtk/spice-session-priv.h
+++ b/gtk/spice-session-priv.h
@@ -158,6 +158,7 @@ void spice_session_set_uuid(SpiceSession *session, guint8 uuid[16]);
 void spice_session_set_name(SpiceSession *session, const gchar *name);
 gboolean spice_session_is_playback_active(SpiceSession *session);
 guint32 spice_session_get_playback_latency(SpiceSession *session);
+void spice_session_sync_playback_latency(SpiceSession *session);
 
 G_END_DECLS
 
diff --git a/gtk/spice-session.c b/gtk/spice-session.c
index 48df59d..7c5169c 100644
--- a/gtk/spice-session.c
+++ b/gtk/spice-session.c
@@ -2104,6 +2104,21 @@ void spice_session_set_name(SpiceSession *session, const gchar *name)
 }
 
 G_GNUC_INTERNAL
+void spice_session_sync_playback_latency(SpiceSession *session)
+{
+    SpiceSessionPrivate *s = SPICE_SESSION_GET_PRIVATE(session);
+
+    g_return_if_fail(s != NULL);
+
+    if (s->playback_channel &&
+        spice_playback_channel_is_active(s->playback_channel)) {
+        spice_playback_channel_sync_latency(s->playback_channel);
+    } else {
+        SPICE_DEBUG("%s: not implemented when there isn't audio playback", __FUNCTION__);
+    }
+}
+
+G_GNUC_INTERNAL
 gboolean spice_session_is_playback_active(SpiceSession *session)
 {
     SpiceSessionPrivate *s = SPICE_SESSION_GET_PRIVATE(session);
commit efa65b49f0ab3596546497586c645f5a042dadb1
Author: Yonit Halperin <yhalperi at redhat.com>
Date:   Tue Feb 19 11:38:05 2013 -0500

    spice-pulse: adjust the playback latency when the min-latency property changes
    
    If the current latency is smaller than the new min-latency
    value, we cork the playback till the target latency is achieved.
    
    Note: I didn't modify the prebuf configuration and used
    pa_stream_prebuf, because pulse updated the prebuf only if
    I set both prebuf and tlength to be target_latency*2. Then,
    due to the tlength growth, each time the playback latency deviated
    from the target latency, an underflow occurred. Since the latency
    that is computed by the server is not exact and is based on its
    current evaluation of the bit-rate, which is dynamic, it is better not
    to change the tlength (in order to avoid unnecessary underflows).

diff --git a/gtk/spice-pulse.c b/gtk/spice-pulse.c
index 107ce7c..5e214c8 100644
--- a/gtk/spice-pulse.c
+++ b/gtk/spice-pulse.c
@@ -46,6 +46,8 @@ struct _SpicePulsePrivate {
     int                     state;
     struct stream           playback;
     struct stream           record;
+    guint                   last_delay;
+    guint                   target_delay;
 };
 
 G_DEFINE_TYPE(SpicePulse, spice_pulse, SPICE_TYPE_AUDIO)
@@ -185,7 +187,7 @@ static void pulse_flush_cb(pa_stream *pastream, int success, void *data)
     s->cork_op = NULL;
 }
 
-static void pulse_cork_cb(pa_stream *pastream, int success, void *data)
+static void pulse_cork_flush_cb(pa_stream *pastream, int success, void *data)
 {
     struct stream *s = data;
 
@@ -199,7 +201,19 @@ static void pulse_cork_cb(pa_stream *pastream, int success, void *data)
     }
 }
 
-static void stream_cork(SpicePulse *pulse, struct stream *s)
+static void pulse_cork_cb(pa_stream *pastream, int success, void *data)
+{
+    struct stream *s = data;
+
+    SPICE_DEBUG("%s: cork started", __FUNCTION__);
+    if (!success)
+        g_warning("pulseaudio cork operation failed");
+
+    pa_operation_unref(s->cork_op);
+    s->cork_op = NULL;
+}
+
+static void stream_cork(SpicePulse *pulse, struct stream *s, gboolean with_flush)
 {
     SpicePulsePrivate *p = SPICE_PULSE_GET_PRIVATE(pulse);
     pa_operation *o = NULL;
@@ -211,7 +225,10 @@ static void stream_cork(SpicePulse *pulse, struct stream *s)
     }
 
     if (!pa_stream_is_corked(s->stream) && !s->cork_op) {
-        if (!(o = pa_stream_cork(s->stream, 1, pulse_cork_cb, s))) {
+        if (!(o = pa_stream_cork(s->stream, 1,
+                                 with_flush ? pulse_cork_flush_cb :
+                                              pulse_cork_cb,
+                                 s))) {
             g_warning("pa_stream_cork() failed: %s",
                       pa_strerror(pa_context_errno(p->context)));
         }
@@ -277,11 +294,12 @@ static void stream_underflow_cb(pa_stream *s, void *userdata)
 
 static void stream_update_latency_callback(pa_stream *s, void *userdata)
 {
+    SpicePulse *pulse = userdata;
     pa_usec_t usec;
     int negative = 0;
     SpicePulsePrivate *p;
 
-    p = SPICE_PULSE_GET_PRIVATE(userdata);
+    p = SPICE_PULSE_GET_PRIVATE(pulse);
 
     g_return_if_fail(s != NULL);
     g_return_if_fail(p != NULL);
@@ -295,8 +313,16 @@ static void stream_update_latency_callback(pa_stream *s, void *userdata)
     }
 
     g_return_if_fail(negative == FALSE);
-
+    p->last_delay = usec / PA_USEC_PER_MSEC;
     spice_playback_channel_set_delay(SPICE_PLAYBACK_CHANNEL(p->pchannel), usec / 1000);
+    if (pa_stream_is_corked(p->playback.stream)) {
+        if (p->last_delay >= p->target_delay) {
+            SPICE_DEBUG("%s: uncork playback. delay %u target %u",  __FUNCTION__, p->last_delay, p->target_delay);
+            stream_uncork(pulse, &p->playback);
+        } else {
+            SPICE_DEBUG("%s: still corked. delay %u target %u",  __FUNCTION__, p->last_delay, p->target_delay);
+        }
+    }
 }
 
 static void create_playback(SpicePulse *pulse)
@@ -317,9 +343,8 @@ static void create_playback(SpicePulse *pulse)
     pa_stream_set_underflow_callback(p->playback.stream, stream_underflow_cb, pulse);
     pa_stream_set_latency_update_callback(p->playback.stream, stream_update_latency_callback, pulse);
 
-    /* FIXME: we might want customizable latency */
     buffer_attr.maxlength = -1;
-    buffer_attr.tlength = pa_usec_to_bytes(100 * PA_USEC_PER_MSEC, &p->playback.spec);
+    buffer_attr.tlength = pa_usec_to_bytes(p->target_delay * PA_USEC_PER_MSEC, &p->playback.spec);
     buffer_attr.prebuf = -1;
     buffer_attr.minreq = -1;
     flags = PA_STREAM_ADJUST_LATENCY | PA_STREAM_AUTO_TIMING_UPDATE;
@@ -337,15 +362,18 @@ static void playback_start(SpicePlaybackChannel *channel, gint format, gint chan
     SpicePulse *pulse = data;
     SpicePulsePrivate *p = SPICE_PULSE_GET_PRIVATE(pulse);
     pa_context_state_t state;
+    guint latency;
 
     g_return_if_fail(p != NULL);
 
     p->playback.started = TRUE;
     p->playback.num_underflow = 0;
+    g_object_get(p->pchannel, "min-latency", &latency, NULL);
 
     if (p->playback.stream &&
         (p->playback.spec.rate != frequency ||
-         p->playback.spec.channels != channels)) {
+         p->playback.spec.channels != channels ||
+         p->target_delay != latency)) {
         stream_stop(pulse, &p->playback);
     }
 
@@ -353,6 +381,8 @@ static void playback_start(SpicePlaybackChannel *channel, gint format, gint chan
     p->playback.spec.format   = PA_SAMPLE_S16LE;
     p->playback.spec.rate     = frequency;
     p->playback.spec.channels = channels;
+    p->target_delay = latency;
+    p->last_delay = 0;
 
     state = pa_context_get_state(p->context);
     switch (state) {
@@ -421,7 +451,7 @@ static void playback_stop(SpicePlaybackChannel *channel, gpointer data)
     if (!p->playback.stream)
         return;
 
-    stream_cork(pulse, &p->playback);
+    stream_cork(pulse, &p->playback, TRUE);
 }
 
 static void stream_read_callback(pa_stream *s, size_t length, void *data)
@@ -629,6 +659,24 @@ static void playback_mute_changed(GObject *object, GParamSpec *pspec, gpointer d
         pa_operation_unref(op);
 }
 
+static void playback_min_latency_changed(GObject *object, GParamSpec *pspec, gpointer data)
+{
+
+    SpicePulse *pulse = data;
+    SpicePulsePrivate *p = pulse->priv;
+    guint min_latency;
+
+    g_object_get(object, "min-latency", &min_latency, NULL);
+    p->target_delay = min_latency;
+
+    if (p->last_delay < p->target_delay) {
+        spice_debug("%s: corking", __FUNCTION__);
+        stream_cork(pulse, &p->playback, FALSE);
+    } else {
+        spice_debug("%s: not corking. The current delay satisfies the requirement", __FUNCTION__);
+    }
+}
+
 static void record_mute_changed(GObject *object, GParamSpec *pspec, gpointer data)
 {
     SpicePulse *pulse = data;
@@ -711,6 +759,8 @@ static gboolean connect_channel(SpiceAudio *audio, SpiceChannel *channel)
                                       G_CALLBACK(playback_volume_changed), pulse, 0);
         spice_g_signal_connect_object(channel, "notify::mute",
                                       G_CALLBACK(playback_mute_changed), pulse, 0);
+        spice_g_signal_connect_object(channel, "notify::min-latency",
+                                      G_CALLBACK(playback_min_latency_changed), pulse, 0);
 
         return TRUE;
     }
commit d628f055e8026e42e7ffbd2bd53056aea317e47c
Author: Yonit Halperin <yhalperi at redhat.com>
Date:   Tue Feb 19 10:46:00 2013 -0500

    channel-playback: support SPICE_MSG_PLAYBACK_LATENCY
    
    Add a new property for minimum playback latency. This property is
    updated with the value from SPICE_MSG_PLAYBACK_LATENCY.
    I also increased the default latency from 100ms to 200ms in order to
    be more robust to different bandwidth settings.
    The patch also updates spice-common submodule.

diff --git a/gtk/channel-playback.c b/gtk/channel-playback.c
index 1073ef7..3d959c4 100644
--- a/gtk/channel-playback.c
+++ b/gtk/channel-playback.c
@@ -57,6 +57,7 @@ struct _SpicePlaybackChannelPrivate {
     guint8                      mute;
     gboolean                    is_active;
     guint32                     latency;
+    guint32                     min_latency;
 };
 
 G_DEFINE_TYPE(SpicePlaybackChannel, spice_playback_channel, SPICE_TYPE_CHANNEL)
@@ -67,6 +68,7 @@ enum {
     PROP_NCHANNELS,
     PROP_VOLUME,
     PROP_MUTE,
+    PROP_MIN_LATENCY,
 };
 
 /* Signals */
@@ -85,11 +87,14 @@ static void spice_playback_handle_msg(SpiceChannel *channel, SpiceMsgIn *msg);
 
 /* ------------------------------------------------------------------ */
 
+#define SPICE_PLAYBACK_DEFAULT_LATENCY_MS 200
+
 static void spice_playback_channel_reset_capabilities(SpiceChannel *channel)
 {
     if (!g_getenv("SPICE_DISABLE_CELT"))
         spice_channel_set_capability(SPICE_CHANNEL(channel), SPICE_PLAYBACK_CAP_CELT_0_5_1);
     spice_channel_set_capability(SPICE_CHANNEL(channel), SPICE_PLAYBACK_CAP_VOLUME);
+    spice_channel_set_capability(SPICE_CHANNEL(channel), SPICE_PLAYBACK_CAP_LATENCY);
 }
 
 static void spice_playback_channel_init(SpicePlaybackChannel *channel)
@@ -138,6 +143,9 @@ static void spice_playback_channel_get_property(GObject    *gobject,
     case PROP_MUTE:
         g_value_set_boolean(value, c->mute);
         break;
+    case PROP_MIN_LATENCY:
+        g_value_set_uint(value, c->min_latency);
+        break;
     default:
         G_OBJECT_WARN_INVALID_PROPERTY_ID(gobject, prop_id, pspec);
         break;
@@ -218,12 +226,21 @@ static void spice_playback_channel_class_init(SpicePlaybackChannelClass *klass)
                               FALSE,
                               G_PARAM_READWRITE |
                               G_PARAM_STATIC_STRINGS));
+    g_object_class_install_property
+        (gobject_class, PROP_MIN_LATENCY,
+         g_param_spec_uint("min-latency",
+                           "Playback min buffer size (ms)",
+                           "Playback min buffer size (ms)",
+                           0, G_MAXUINT32, SPICE_PLAYBACK_DEFAULT_LATENCY_MS,
+                           G_PARAM_READWRITE |
+                           G_PARAM_STATIC_STRINGS));
     /**
      * SpicePlaybackChannel::playback-start:
      * @channel: the #SpicePlaybackChannel that emitted the signal
      * @format: a #SPICE_AUDIO_FMT
      * @channels: number of channels
      * @rate: audio rate
+     * @latency: minimum playback latency in ms
      *
      * Notify when the playback should start, and provide audio format
      * characteristics.
@@ -299,6 +316,7 @@ struct SPICE_PLAYBACK_START {
     gint format;
     gint channels;
     gint frequency;
+    gint latency;
 };
 
 struct SPICE_PLAYBACK_DATA {
@@ -419,6 +437,7 @@ static void playback_handle_start(SpiceChannel *channel, SpiceMsgIn *in)
     c->frame_count = 0;
     c->last_time = start->time;
     c->is_active = TRUE;
+    c->min_latency = SPICE_PLAYBACK_DEFAULT_LATENCY_MS;
 
     switch (c->mode) {
     case SPICE_AUDIO_DATA_MODE_RAW:
@@ -487,6 +506,17 @@ static void playback_handle_set_mute(SpiceChannel *channel, SpiceMsgIn *in)
     g_object_notify_main_context(G_OBJECT(channel), "mute");
 }
 
+/* coroutine context */
+static void playback_handle_set_latency(SpiceChannel *channel, SpiceMsgIn *in)
+{
+    SpicePlaybackChannelPrivate *c = SPICE_PLAYBACK_CHANNEL(channel)->priv;
+    SpiceMsgPlaybackLatency *msg = spice_msg_in_parsed(in);
+
+    c->min_latency = msg->latency_ms;
+    SPICE_DEBUG("%s: notify latency update %u", __FUNCTION__, c->min_latency);
+    g_object_notify_main_context(G_OBJECT(channel), "min-latency");
+}
+
 static const spice_msg_handler playback_handlers[] = {
     [ SPICE_MSG_PLAYBACK_DATA ]            = playback_handle_data,
     [ SPICE_MSG_PLAYBACK_MODE ]            = playback_handle_mode,
@@ -494,6 +524,7 @@ static const spice_msg_handler playback_handlers[] = {
     [ SPICE_MSG_PLAYBACK_STOP ]            = playback_handle_stop,
     [ SPICE_MSG_PLAYBACK_VOLUME ]          = playback_handle_set_volume,
     [ SPICE_MSG_PLAYBACK_MUTE ]            = playback_handle_set_mute,
+    [ SPICE_MSG_PLAYBACK_LATENCY ]         = playback_handle_set_latency,
 };
 
 /* coroutine context */
diff --git a/spice-common b/spice-common
index 7cdf8de..30e8478 160000
--- a/spice-common
+++ b/spice-common
@@ -1 +1 @@
-Subproject commit 7cdf8de00a573b6bdb4ec4582c87aa79b25796d3
+Subproject commit 30e84783cad7a5d4cd345367a267cafbfd0571af
commit edf1daf508994210f2ecdd7f1b598dc4012cdb0f
Author: Yonit Halperin <yhalperi at redhat.com>
Date:   Mon Jan 28 15:34:35 2013 -0500

    channel-display: video stream quality report
    
    Handle MSG_STREAM_ACTIVIATE_REPORT and send MSGC_STREAM_REPORT
    periodically, or when the playback is out of sync.
    The patch also updates spice-common submodule.

diff --git a/gtk/channel-display-priv.h b/gtk/channel-display-priv.h
index f57dc6e..49f82fe 100644
--- a/gtk/channel-display-priv.h
+++ b/gtk/channel-display-priv.h
@@ -88,6 +88,16 @@ typedef struct display_stream {
     GArray               *drops_seqs_stats_arr;
     uint32_t             num_drops_seqs;
 
+    /* playback quality report to server */
+    gboolean report_is_active;
+    uint32_t report_id;
+    uint32_t report_max_window;
+    uint32_t report_timeout;
+    uint64_t report_start_time;
+    uint32_t report_start_frame_time;
+    uint32_t report_num_frames;
+    uint32_t report_num_drops;
+    uint32_t report_drops_seq_len;
 } 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 224b5c5..ca77653 100644
--- a/gtk/channel-display.c
+++ b/gtk/channel-display.c
@@ -687,6 +687,7 @@ static void spice_display_channel_reset_capabilities(SpiceChannel *channel)
     spice_channel_set_capability(SPICE_CHANNEL(channel), SPICE_DISPLAY_CAP_MONITORS_CONFIG);
     spice_channel_set_capability(SPICE_CHANNEL(channel), SPICE_DISPLAY_CAP_COMPOSITE);
     spice_channel_set_capability(SPICE_CHANNEL(channel), SPICE_DISPLAY_CAP_A8_SURFACE);
+    spice_channel_set_capability(SPICE_CHANNEL(channel), SPICE_DISPLAY_CAP_STREAM_REPORT);
 }
 
 static void spice_display_channel_init(SpiceDisplayChannel *channel)
@@ -1242,6 +1243,65 @@ static gboolean display_stream_render(display_stream *st)
 
     return FALSE;
 }
+/* after a sequence of 3 drops, push a report to the server, even
+ * if the report window is bigger */
+#define STREAM_REPORT_DROP_SEQ_LEN_LIMIT 3
+
+static void display_update_stream_report(SpiceDisplayChannel *channel, uint32_t stream_id,
+                                         uint32_t frame_time, int32_t latency)
+{
+    display_stream *st = channel->priv->streams[stream_id];
+    guint64 now;
+
+    if (!st->report_is_active) {
+        return;
+    }
+    now = g_get_monotonic_time();
+
+    if (st->report_num_frames == 0) {
+        st->report_start_frame_time = frame_time;
+        st->report_start_time = now;
+    }
+    st->report_num_frames++;
+
+    if (latency < 0) { // drop
+        st->report_num_drops++;
+        st->report_drops_seq_len++;
+    } else {
+        st->report_drops_seq_len = 0;
+    }
+
+    if (st->report_num_frames >= st->report_max_window ||
+        now - st->report_start_time >= st->report_timeout ||
+        st->report_drops_seq_len >= STREAM_REPORT_DROP_SEQ_LEN_LIMIT) {
+        SpiceMsgcDisplayStreamReport report;
+        SpiceSession *session = spice_channel_get_session(SPICE_CHANNEL(channel));
+        SpiceMsgOut *msg;
+
+        report.stream_id = stream_id;
+        report.unique_id = st->report_id;
+        report.start_frame_mm_time = st->report_start_frame_time;
+        report.end_frame_mm_time = frame_time;
+        report.num_frames = st->report_num_frames;
+        report.num_drops = st-> report_num_drops;
+        report.last_frame_delay = latency;
+        if (spice_session_is_playback_active(session)) {
+            report.audio_delay = spice_session_get_playback_latency(session);
+        } else {
+            report.audio_delay = UINT_MAX;
+        }
+
+        msg = spice_msg_out_new(SPICE_CHANNEL(channel), SPICE_MSGC_DISPLAY_STREAM_REPORT);
+        msg->marshallers->msgc_display_stream_report(msg->marshaller, &report);
+        spice_msg_out_send(msg);
+
+        st->report_start_time = 0;
+        st->report_start_frame_time = 0;
+        st->report_num_frames = 0;
+        st->report_num_drops = 0;
+        st->report_drops_seq_len = 0;
+    }
+}
 
 /* coroutine context */
 static void display_handle_stream_data(SpiceChannel *channel, SpiceMsgIn *in)
@@ -1250,6 +1310,7 @@ static void display_handle_stream_data(SpiceChannel *channel, SpiceMsgIn *in)
     SpiceStreamDataHeader *op = spice_msg_in_parsed(in);
     display_stream *st;
     guint32 mmtime;
+    int32_t latency;
 
     g_return_if_fail(c != NULL);
     g_return_if_fail(c->streams != NULL);
@@ -1271,7 +1332,9 @@ static void display_handle_stream_data(SpiceChannel *channel, SpiceMsgIn *in)
         st->first_frame_mm_time = op->multi_media_time;
     }
     st->num_input_frames++;
-    if (op->multi_media_time < mmtime) {
+
+    latency = op->multi_media_time - mmtime;
+    if (latency < 0) {
         CHANNEL_DEBUG(channel, "stream data too late by %u ms (ts: %u, mmtime: %u), dropin",
                       mmtime - op->multi_media_time, op->multi_media_time, mmtime);
         st->arrive_late_time += mmtime - op->multi_media_time;
@@ -1280,19 +1343,20 @@ static void display_handle_stream_data(SpiceChannel *channel, SpiceMsgIn *in)
             st->cur_drops_seq_stats.start_mm_time = op->multi_media_time;
         }
         st->cur_drops_seq_stats.len++;
-        return;
-    }
-
-    spice_msg_in_ref(in);
-    g_queue_push_tail(st->msgq, in);
-    display_stream_schedule(st);
-    if (st->cur_drops_seq_stats.len) {
-        st->cur_drops_seq_stats.duration = op->multi_media_time -
-                                           st->cur_drops_seq_stats.start_mm_time;
-        g_array_append_val(st->drops_seqs_stats_arr, st->cur_drops_seq_stats);
-        memset(&st->cur_drops_seq_stats, 0, sizeof(st->cur_drops_seq_stats));
-        st->num_drops_seqs++;
+    } else {
+        spice_msg_in_ref(in);
+        g_queue_push_tail(st->msgq, in);
+        display_stream_schedule(st);
+        if (st->cur_drops_seq_stats.len) {
+            st->cur_drops_seq_stats.duration = op->multi_media_time -
+                                               st->cur_drops_seq_stats.start_mm_time;
+            g_array_append_val(st->drops_seqs_stats_arr, st->cur_drops_seq_stats);
+            memset(&st->cur_drops_seq_stats, 0, sizeof(st->cur_drops_seq_stats));
+            st->num_drops_seqs++;
+        }
     }
+    display_update_stream_report(SPICE_DISPLAY_CHANNEL(channel), op->id,
+                                 op->multi_media_time, latency);
 }
 
 /* coroutine context */
@@ -1411,6 +1475,31 @@ static void display_handle_stream_destroy_all(SpiceChannel *channel, SpiceMsgIn
     clear_streams(channel);
 }
 
+/* coroutine context */
+static void display_handle_stream_activate_report(SpiceChannel *channel, SpiceMsgIn *in)
+{
+    SpiceDisplayChannelPrivate *c = SPICE_DISPLAY_CHANNEL(channel)->priv;
+    SpiceMsgDisplayStreamActivateReport *op = spice_msg_in_parsed(in);
+    display_stream *st;
+
+    g_return_if_fail(c != NULL);
+    g_return_if_fail(c->streams != NULL);
+    g_return_if_fail(c->nstreams > op->stream_id);
+
+    st = c->streams[op->stream_id];
+    g_return_if_fail(st != NULL);
+
+    st->report_is_active = TRUE;
+    st->report_id = op->unique_id;
+    st->report_max_window = op->max_window_size;
+    st->report_timeout = op->timeout_ms * 1000;
+    st->report_start_time = 0;
+    st->report_start_frame_time = 0;
+    st->report_num_frames = 0;
+    st->report_num_drops = 0;
+    st->report_drops_seq_len = 0;
+}
+
 /* ------------------------------------------------------------------ */
 
 /* coroutine context */
@@ -1632,6 +1721,7 @@ static const spice_msg_handler display_handlers[] = {
     [ SPICE_MSG_DISPLAY_STREAM_DESTROY ]     = display_handle_stream_destroy,
     [ SPICE_MSG_DISPLAY_STREAM_DESTROY_ALL ] = display_handle_stream_destroy_all,
     [ SPICE_MSG_DISPLAY_STREAM_DATA_SIZED ]  = display_handle_stream_data,
+    [ SPICE_MSG_DISPLAY_STREAM_ACTIVATE_REPORT ] = display_handle_stream_activate_report,
 
     [ SPICE_MSG_DISPLAY_DRAW_FILL ]          = display_handle_draw_fill,
     [ SPICE_MSG_DISPLAY_DRAW_OPAQUE ]        = display_handle_draw_opaque,
diff --git a/spice-common b/spice-common
index 5ebeee5..7cdf8de 160000
--- a/spice-common
+++ b/spice-common
@@ -1 +1 @@
-Subproject commit 5ebeee51146f9441474377e77bbc15ec69530d54
+Subproject commit 7cdf8de00a573b6bdb4ec4582c87aa79b25796d3
commit ce9e5deaee7a7e8bd2da8891ea6a2ff1c19e599d
Author: Yonit Halperin <yhalperi at redhat.com>
Date:   Tue Feb 19 09:32:15 2013 -0500

    channel-playback: provide access to playback properties via the session
    
    Support checking whether an audio playback is active and what its latency
    is.

diff --git a/gtk/Makefile.am b/gtk/Makefile.am
index 4bf2eee..8d26132 100644
--- a/gtk/Makefile.am
+++ b/gtk/Makefile.am
@@ -235,6 +235,7 @@ libspice_client_glib_2_0_la_SOURCES =			\
 	channel-inputs.c				\
 	channel-main.c					\
 	channel-playback.c				\
+	channel-playback-priv.h				\
 	channel-port.c					\
 	channel-record.c				\
 	channel-smartcard.c				\
diff --git a/gtk/channel-playback-priv.h b/gtk/channel-playback-priv.h
new file mode 100644
index 0000000..dc89e2d
--- /dev/null
+++ b/gtk/channel-playback-priv.h
@@ -0,0 +1,23 @@
+/* -*- Mode: C; c-basic-offset: 4; indent-tabs-mode: nil -*- */
+/*
+   Copyright (C) 2013 Red Hat, Inc.
+
+   This library is free software; you can redistribute it and/or
+   modify it under the terms of the GNU Lesser General Public
+   License as published by the Free Software Foundation; either
+   version 2.1 of the License, or (at your option) any later version.
+
+   This library is distributed in the hope that it will be useful,
+   but WITHOUT ANY WARRANTY; without even the implied warranty of
+   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
+   Lesser General Public License for more details.
+
+   You should have received a copy of the GNU Lesser General Public
+   License along with this library; if not, see <http://www.gnu.org/licenses/>.
+*/
+#ifndef __SPICE_CLIENT_PLAYBACK_CHANNEL_PRIV_H__
+#define __SPICE_CLIENT_PLAYBACK_CHANNEL_PRIV_H__
+
+gboolean spice_playback_channel_is_active(SpicePlaybackChannel *channel);
+guint32 spice_playback_channel_get_latency(SpicePlaybackChannel *channel);
+#endif
diff --git a/gtk/channel-playback.c b/gtk/channel-playback.c
index 5aa8454..1073ef7 100644
--- a/gtk/channel-playback.c
+++ b/gtk/channel-playback.c
@@ -55,6 +55,8 @@ struct _SpicePlaybackChannelPrivate {
     guint8                      nchannels;
     guint16                     *volume;
     guint8                      mute;
+    gboolean                    is_active;
+    guint32                     latency;
 };
 
 G_DEFINE_TYPE(SpicePlaybackChannel, spice_playback_channel, SPICE_TYPE_CHANNEL)
@@ -416,6 +418,7 @@ static void playback_handle_start(SpiceChannel *channel, SpiceMsgIn *in)
 
     c->frame_count = 0;
     c->last_time = start->time;
+    c->is_active = TRUE;
 
     switch (c->mode) {
     case SPICE_AUDIO_DATA_MODE_RAW:
@@ -450,7 +453,10 @@ static void playback_handle_start(SpiceChannel *channel, SpiceMsgIn *in)
 /* coroutine context */
 static void playback_handle_stop(SpiceChannel *channel, SpiceMsgIn *in)
 {
+    SpicePlaybackChannelPrivate *c = SPICE_PLAYBACK_CHANNEL(channel)->priv;
+
     emit_main_context(channel, SPICE_PLAYBACK_STOP);
+    c->is_active = FALSE;
 }
 
 /* coroutine context */
@@ -517,6 +523,24 @@ void spice_playback_channel_set_delay(SpicePlaybackChannel *channel, guint32 del
     CHANNEL_DEBUG(channel, "playback set_delay %u ms", delay_ms);
 
     c = channel->priv;
+    c->latency = delay_ms;
     spice_session_set_mm_time(spice_channel_get_session(SPICE_CHANNEL(channel)),
                               c->last_time - delay_ms);
 }
+
+G_GNUC_INTERNAL
+gboolean spice_playback_channel_is_active(SpicePlaybackChannel *channel)
+{
+    g_return_val_if_fail(SPICE_IS_PLAYBACK_CHANNEL(channel), FALSE);
+    return channel->priv->is_active;
+}
+
+G_GNUC_INTERNAL
+guint32 spice_playback_channel_get_latency(SpicePlaybackChannel *channel)
+{
+    g_return_val_if_fail(SPICE_IS_PLAYBACK_CHANNEL(channel), 0);
+    if (!channel->priv->is_active) {
+        return 0;
+    }
+    return channel->priv->latency;
+}
diff --git a/gtk/spice-session-priv.h b/gtk/spice-session-priv.h
index de4e40c..37f848c 100644
--- a/gtk/spice-session-priv.h
+++ b/gtk/spice-session-priv.h
@@ -107,6 +107,7 @@ struct _SpiceSessionPrivate {
     SpiceDesktopIntegration *desktop_integration;
     SpiceGtkSession   *gtk_session;
     SpiceUsbDeviceManager *usb_manager;
+    SpicePlaybackChannel *playback_channel;
 };
 
 SpiceSession *spice_session_new_from_session(SpiceSession *session);
@@ -155,6 +156,8 @@ gboolean spice_session_migrate_after_main_init(SpiceSession *session);
 SpiceChannel* spice_session_lookup_channel(SpiceSession *session, gint id, gint type);
 void spice_session_set_uuid(SpiceSession *session, guint8 uuid[16]);
 void spice_session_set_name(SpiceSession *session, const gchar *name);
+gboolean spice_session_is_playback_active(SpiceSession *session);
+guint32 spice_session_get_playback_latency(SpiceSession *session);
 
 G_END_DECLS
 
diff --git a/gtk/spice-session.c b/gtk/spice-session.c
index e60e904..48df59d 100644
--- a/gtk/spice-session.c
+++ b/gtk/spice-session.c
@@ -29,6 +29,7 @@
 #include "glib-compat.h"
 #include "wocky-http-proxy.h"
 #include "spice-proxy.h"
+#include "channel-playback-priv.h"
 
 struct channel {
     SpiceChannel      *channel;
@@ -1836,6 +1837,9 @@ void spice_session_channel_new(SpiceSession *session, SpiceChannel *channel)
 
         CHANNEL_DEBUG(channel, "new main channel, switching");
         s->cmain = channel;
+    } else if (SPICE_IS_PLAYBACK_CHANNEL(channel)) {
+        g_warn_if_fail(s->playback_channel == NULL);
+        s->playback_channel = SPICE_PLAYBACK_CHANNEL(channel);
     }
 
     g_signal_emit(session, signals[SPICE_SESSION_CHANNEL_NEW], 0, channel);
@@ -2098,3 +2102,30 @@ void spice_session_set_name(SpiceSession *session, const gchar *name)
 
     g_object_notify(G_OBJECT(session), "name");
 }
+
+G_GNUC_INTERNAL
+gboolean spice_session_is_playback_active(SpiceSession *session)
+{
+    SpiceSessionPrivate *s = SPICE_SESSION_GET_PRIVATE(session);
+
+    g_return_val_if_fail(s != NULL, FALSE);
+
+    return (s->playback_channel &&
+        spice_playback_channel_is_active(s->playback_channel));
+}
+
+G_GNUC_INTERNAL
+guint32 spice_session_get_playback_latency(SpiceSession *session)
+{
+    SpiceSessionPrivate *s = SPICE_SESSION_GET_PRIVATE(session);
+
+    g_return_val_if_fail(s != NULL, 0);
+
+    if (s->playback_channel &&
+        spice_playback_channel_is_active(s->playback_channel)) {
+        return spice_playback_channel_get_latency(s->playback_channel);
+    } else {
+        SPICE_DEBUG("%s: not implemented when there isn't audio playback", __FUNCTION__);
+        return 0;
+    }
+}
commit 54bd520f342f83bbc3beffaef59c8f943e348684
Author: Yonit Halperin <yhalperi at redhat.com>
Date:   Mon Jan 28 15:55:22 2013 -0500

    spice-pulse: update the playback latency automatically when it changes

diff --git a/gtk/spice-pulse.c b/gtk/spice-pulse.c
index 295ea4f..107ce7c 100644
--- a/gtk/spice-pulse.c
+++ b/gtk/spice-pulse.c
@@ -275,6 +275,30 @@ static void stream_underflow_cb(pa_stream *s, void *userdata)
 #endif
 }
 
+static void stream_update_latency_callback(pa_stream *s, void *userdata)
+{
+    pa_usec_t usec;
+    int negative = 0;
+    SpicePulsePrivate *p;
+
+    p = SPICE_PULSE_GET_PRIVATE(userdata);
+
+    g_return_if_fail(s != NULL);
+    g_return_if_fail(p != NULL);
+
+    if (!p->playback.stream || !p->playback.started)
+        return;
+
+    if (pa_stream_get_latency(s, &usec, &negative) < 0) {
+        g_warning("Failed to get latency: %s", pa_strerror(pa_context_errno(p->context)));
+        return;
+    }
+
+    g_return_if_fail(negative == FALSE);
+
+    spice_playback_channel_set_delay(SPICE_PLAYBACK_CHANNEL(p->pchannel), usec / 1000);
+}
+
 static void create_playback(SpicePulse *pulse)
 {
     SpicePulsePrivate *p = SPICE_PULSE_GET_PRIVATE(pulse);
@@ -291,13 +315,14 @@ static void create_playback(SpicePulse *pulse)
                                        &p->playback.spec, NULL);
     pa_stream_set_state_callback(p->playback.stream, stream_state_callback, pulse);
     pa_stream_set_underflow_callback(p->playback.stream, stream_underflow_cb, pulse);
+    pa_stream_set_latency_update_callback(p->playback.stream, stream_update_latency_callback, pulse);
 
     /* FIXME: we might want customizable latency */
     buffer_attr.maxlength = -1;
     buffer_attr.tlength = pa_usec_to_bytes(100 * PA_USEC_PER_MSEC, &p->playback.spec);
     buffer_attr.prebuf = -1;
     buffer_attr.minreq = -1;
-    flags = PA_STREAM_ADJUST_LATENCY;
+    flags = PA_STREAM_ADJUST_LATENCY | PA_STREAM_AUTO_TIMING_UPDATE;
 
     if (pa_stream_connect_playback(p->playback.stream,
                                    NULL, &buffer_attr, flags, NULL, NULL) < 0) {
@@ -399,46 +424,6 @@ static void playback_stop(SpicePlaybackChannel *channel, gpointer data)
     stream_cork(pulse, &p->playback);
 }
 
-static void stream_update_timing_callback(pa_stream *s, int success, void *userdata)
-{
-    pa_usec_t usec;
-    int negative = 0;
-    SpicePulsePrivate *p;
-
-    p = SPICE_PULSE_GET_PRIVATE(userdata);
-
-    g_return_if_fail(s != NULL);
-    g_return_if_fail(p != NULL);
-
-    if (!p->playback.stream || !p->playback.started)
-        return;
-
-    if (!success ||
-        pa_stream_get_latency(s, &usec, &negative) < 0) {
-        g_warning("Failed to get latency: %s", pa_strerror(pa_context_errno(p->context)));
-        return;
-    }
-
-    g_return_if_fail(negative == FALSE);
-
-    spice_playback_channel_set_delay(SPICE_PLAYBACK_CHANNEL(p->pchannel), usec / 1000);
-}
-
-static void playback_get_delay(SpicePlaybackChannel *channel, gpointer data)
-{
-    SpicePulse *pulse = data;
-    SpicePulsePrivate *p = pulse->priv;
-
-    if (p->playback.stream && pa_stream_get_state(p->playback.stream) == PA_STREAM_READY) {
-        pa_operation *o;
-        if (!(o = pa_stream_update_timing_info(p->playback.stream, stream_update_timing_callback, data)))
-            g_warning("pa_stream_update_timing_info() failed: %s",
-                      pa_strerror(pa_context_errno(p->context)));
-        else
-            pa_operation_unref(o);
-    }
-}
-
 static void stream_read_callback(pa_stream *s, size_t length, void *data)
 {
     SpicePulse *pulse = data;
@@ -716,8 +701,6 @@ static gboolean connect_channel(SpiceAudio *audio, SpiceChannel *channel)
         p->pchannel = g_object_ref(channel);
         spice_g_signal_connect_object(channel, "playback-start",
                                       G_CALLBACK(playback_start), pulse, 0);
-        spice_g_signal_connect_object(channel, "playback-get-delay",
-                                      G_CALLBACK(playback_get_delay), pulse, 0);
         spice_g_signal_connect_object(channel, "playback-data",
                                       G_CALLBACK(playback_data), pulse, 0);
         spice_g_signal_connect_object(channel, "playback-stop",
commit a88cf1d49e25aff6f26999534eba29dd11164683
Author: Yonit Halperin <yhalperi at redhat.com>
Date:   Mon Jan 28 14:01:11 2013 -0500

    channel-display: collect and print video stream stats
    
    also prints the number of underflows during a spice-pulse audio playback

diff --git a/gtk/channel-display-priv.h b/gtk/channel-display-priv.h
index ff0f484..f57dc6e 100644
--- a/gtk/channel-display-priv.h
+++ b/gtk/channel-display-priv.h
@@ -50,6 +50,12 @@ typedef struct display_surface {
     SpiceJpegDecoder            *jpeg_decoder;
 } display_surface;
 
+typedef struct drops_sequence_stats {
+    uint32_t len;
+    uint32_t start_mm_time;
+    uint32_t duration;
+} drops_sequence_stats;
+
 typedef struct display_stream {
     SpiceMsgIn                  *msg_create;
     SpiceMsgIn                  *msg_clip;
@@ -71,6 +77,17 @@ typedef struct display_stream {
     GQueue                      *msgq;
     guint                       timeout;
     SpiceChannel                *channel;
+
+    /* stats */
+    uint32_t             first_frame_mm_time;
+    uint32_t             num_drops_on_arive;
+    uint64_t             arrive_late_time;
+    uint32_t             num_drops_on_playback;
+    uint32_t             num_input_frames;
+    drops_sequence_stats cur_drops_seq_stats;
+    GArray               *drops_seqs_stats_arr;
+    uint32_t             num_drops_seqs;
+
 } 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 2b44b43..224b5c5 100644
--- a/gtk/channel-display.c
+++ b/gtk/channel-display.c
@@ -1070,6 +1070,7 @@ static void display_handle_stream_create(SpiceChannel *channel, SpiceMsgIn *in)
     st->surface = find_surface(c, op->surface_id);
     st->msgq = g_queue_new();
     st->channel = channel;
+    st->drops_seqs_stats_arr = g_array_new(FALSE, FALSE, sizeof(drops_sequence_stats));
 
     region_init(&st->region);
     display_update_stream_region(st);
@@ -1087,12 +1088,10 @@ static gboolean display_stream_schedule(display_stream *st)
     guint32 time, d;
     SpiceStreamDataHeader *op;
     SpiceMsgIn *in;
-
     if (st->timeout)
         return TRUE;
 
     time = spice_session_get_mm_time(spice_channel_get_session(st->channel));
-
     in = g_queue_peek_head(st->msgq);
     g_return_val_if_fail(in != NULL, TRUE);
 
@@ -1105,6 +1104,7 @@ static gboolean display_stream_schedule(display_stream *st)
     } else {
         in = g_queue_pop_head(st->msgq);
         spice_msg_in_unref(in);
+        st->num_drops_on_playback++;
         if (g_queue_get_length(st->msgq) == 0)
             return TRUE;
     }
@@ -1267,15 +1267,32 @@ static void display_handle_stream_data(SpiceChannel *channel, SpiceMsgIn *in)
         op->multi_media_time = mmtime + 100; /* workaround... */
     }
 
+    if (!st->num_input_frames) {
+        st->first_frame_mm_time = op->multi_media_time;
+    }
+    st->num_input_frames++;
     if (op->multi_media_time < mmtime) {
         CHANNEL_DEBUG(channel, "stream data too late by %u ms (ts: %u, mmtime: %u), dropin",
                       mmtime - op->multi_media_time, op->multi_media_time, mmtime);
+        st->arrive_late_time += mmtime - op->multi_media_time;
+        st->num_drops_on_arive++;
+        if (!st->cur_drops_seq_stats.len) {
+            st->cur_drops_seq_stats.start_mm_time = op->multi_media_time;
+        }
+        st->cur_drops_seq_stats.len++;
         return;
     }
 
     spice_msg_in_ref(in);
     g_queue_push_tail(st->msgq, in);
     display_stream_schedule(st);
+    if (st->cur_drops_seq_stats.len) {
+        st->cur_drops_seq_stats.duration = op->multi_media_time -
+                                           st->cur_drops_seq_stats.start_mm_time;
+        g_array_append_val(st->drops_seqs_stats_arr, st->cur_drops_seq_stats);
+        memset(&st->cur_drops_seq_stats, 0, sizeof(st->cur_drops_seq_stats));
+        st->num_drops_seqs++;
+    }
 }
 
 /* coroutine context */
@@ -1309,6 +1326,8 @@ static void destroy_stream(SpiceChannel *channel, int id)
 {
     SpiceDisplayChannelPrivate *c = SPICE_DISPLAY_CHANNEL(channel)->priv;
     display_stream *st;
+    uint64_t drops_duration_total = 0;
+    int i;
 
     g_return_if_fail(c != NULL);
     g_return_if_fail(c->streams != NULL);
@@ -1318,6 +1337,33 @@ static void destroy_stream(SpiceChannel *channel, int id)
     if (!st)
         return;
 
+    CHANNEL_DEBUG(channel, "%s: id %d #frames-in %d #drops-on-arive %d (%.2f) avg-late-time %.2f"
+        " #drops-on-playback %d (%.2f)", __FUNCTION__,
+        id,
+        st->num_input_frames,
+        st->num_drops_on_arive, st->num_drops_on_arive / ((double)st->num_input_frames),
+        st->num_drops_on_arive ? st->arrive_late_time / ((double)st->num_drops_on_arive): 0,
+        st->num_drops_on_playback,
+        st->num_drops_on_playback / ((double)st->num_input_frames));
+    if (st->num_drops_seqs) {
+        CHANNEL_DEBUG(channel, "%s: #drops sequences %u ==>", __FUNCTION__, st->num_drops_seqs);
+    }
+    for (i = 0; i < st->num_drops_seqs; i++) {
+            drops_sequence_stats *stats = &g_array_index(st->drops_seqs_stats_arr,
+                                                         drops_sequence_stats,
+                                                         i);
+            drops_duration_total += stats->duration;
+            CHANNEL_DEBUG(channel, "%s: \t len %u start-ms %u duration-ms %u", __FUNCTION__,
+                                   stats->len,
+                                   stats->start_mm_time - st->first_frame_mm_time,
+                                   stats->duration);
+    }
+    if (st->num_drops_seqs) {
+        CHANNEL_DEBUG(channel, "%s: drops total duration %lu ==>", __FUNCTION__, drops_duration_total);
+    }
+
+    g_array_free(st->drops_seqs_stats_arr, TRUE);
+
     switch (st->codec) {
     case SPICE_VIDEO_CODEC_TYPE_MJPEG:
         stream_mjpeg_cleanup(st);
diff --git a/gtk/spice-pulse.c b/gtk/spice-pulse.c
index 6a977c4..295ea4f 100644
--- a/gtk/spice-pulse.c
+++ b/gtk/spice-pulse.c
@@ -34,6 +34,7 @@ struct stream {
     pa_operation            *uncork_op;
     pa_operation            *cork_op;
     gboolean                started;
+    guint                   num_underflow;
 };
 
 struct _SpicePulsePrivate {
@@ -251,8 +252,13 @@ static void stream_state_callback(pa_stream *s, void *userdata)
 
 static void stream_underflow_cb(pa_stream *s, void *userdata)
 {
+    SpicePulsePrivate *p;
+
     SPICE_DEBUG("PA stream underflow!!");
 
+    p = SPICE_PULSE_GET_PRIVATE(userdata);
+    g_return_if_fail(p != NULL);
+    p->playback.num_underflow++;
 #ifdef PULSE_ADJUST_LATENCY
     const pa_buffer_attr *buffer_attr;
     pa_buffer_attr new_buffer_attr;
@@ -310,6 +316,7 @@ static void playback_start(SpicePlaybackChannel *channel, gint format, gint chan
     g_return_if_fail(p != NULL);
 
     p->playback.started = TRUE;
+    p->playback.num_underflow = 0;
 
     if (p->playback.stream &&
         (p->playback.spec.rate != frequency ||
@@ -383,7 +390,7 @@ static void playback_stop(SpicePlaybackChannel *channel, gpointer data)
     SpicePulse *pulse = data;
     SpicePulsePrivate *p = pulse->priv;
 
-    SPICE_DEBUG("%s", __FUNCTION__);
+    SPICE_DEBUG("%s: #underflow %u", __FUNCTION__, p->playback.num_underflow);
 
     p->playback.started = FALSE;
     if (!p->playback.stream)


More information about the Spice-commits mailing list