Hi,
Thanks for tracking this down. First, the patch doesn't compile.
This is indeed what I imagined, that the mm time is not monotonic over
migrations on different machines (iirc, I was told the stream were stopped
before migration)
Imho, there should be also a base mm time after migration completes, so
that the client always has at least a monotonic mm time.
On Tue, Apr 30, 2013 at 12:19 AM, Yonit Halperin <yhalp...@redhat.com>wrote:
> rhbz#951664
>
> When the src and dst server have different mm-times, we can
> hit a case when for a short period of time the session mm-time and
> the video mm-time are not synced. If the video mm-time is much
> bigger than the session mm-time, the next stream rendering will be
> scheduled to (video-mm-time - session-mm-time), and even after
> the different mm-times would be synced, the video won't be rendered
> till the rendering timeout that was scheduled based on a wrong mm-time,
> takes place.
> This patch protects from such cases. You can find more details in the
> code comments.
> ---
> gtk/channel-display.c | 104
> ++++++++++++++++++++++++++++++++++++++++++++++++--
> 1 file changed, 101 insertions(+), 3 deletions(-)
>
> diff --git a/gtk/channel-display.c b/gtk/channel-display.c
> index 9e03727..d8457e9 100644
> --- a/gtk/channel-display.c
> +++ b/gtk/channel-display.c
> @@ -116,6 +116,7 @@ static gboolean display_stream_render(display_stream
> *st);
> static void spice_display_channel_reset(SpiceChannel *channel, gboolean
> migrating);
> static void spice_display_channel_reset_capabilities(SpiceChannel
> *channel);
> static void destroy_canvas(display_surface *surface);
> +static void _msg_in_unref_func(gpointer data, gpointer user_data);
>
> /* ------------------------------------------------------------------ */
>
> @@ -1089,20 +1090,27 @@ static gboolean
> display_stream_schedule(display_stream *st)
> guint32 time, d;
> SpiceStreamDataHeader *op;
> SpiceMsgIn *in;
> - if (st->timeout)
> - return TRUE;
>
> + spice_debug("%s", __FUNCTION__);
>
We use g_log functions or SPICE_DEBUG in spice-gtk.
> + if (st->timeout) {
> + return TRUE;
> + }
>
This style change isn't necessary.
> 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);
>
> op = spice_msg_in_parsed(in);
> +
>
extra line
if (time < op->multi_media_time) {
> d = op->multi_media_time - time;
> SPICE_DEBUG("scheduling next stream render in %u ms", d);
> st->timeout = g_timeout_add(d,
> (GSourceFunc)display_stream_render, st);
> + st->timeout_monotonic_expiry = g_get_monotonic_time()/1000 + d;
> return TRUE;
> } else {
> + SPICE_DEBUG("%s: rendering too late by %u ms (ts: %u, mmtime:
> %u), droping ",
> + __FUNCTION__, time - op->multi_media_time,
> + op->multi_media_time, time);
> in = g_queue_pop_head(st->msgq);
> spice_msg_in_unref(in);
> st->num_drops_on_playback++;
> @@ -1303,7 +1311,95 @@ static void
> display_update_stream_report(SpiceDisplayChannel *channel, uint32_t
> }
> }
>
> +#define MM_TIME_RESET_TEST_DELTA_THRESH 200 // milliseconds
> +
> +/*
> + * Migration can occur between 2 spice-servers with different mm-times.
> + * Then, the following cases can happen after migration completes:
> + * (We refer to src/dst-time as the mm-times on the src/dst servers):
> + *
> + * (case 1) Frames with time ~= dst-time arrive to the client before the
> + * playback-channel updates the session's mm-time (i.e., the
> mm_time
> + * of the session is still based on the src-time).
> + * (a) If src-time < dst-time:
> + * display_stream_schedule schedules the next rendering to
> + * ~(dst-time - src-time) milliseconds from now.
> + * Since we assume monotonic mm_time, display_stream_schedule,
> + * returns immediately when a rendering timeout
> + * has already been set, and doesn't update the timeout,
> + * even after the mm_time is updated.
> + * When src-time << dst-time, a significant video frames loss
> will occur.
> + * (b) If src-time > dst-time
> + * Frames will be dropped till the mm-time will be updated.
> + * (case 2) mm-time is synced with dst-time, but frames that were in the
> command
> + * ring during migration still arrive (such frames hold src-time).
> + * (a) If src-time < dst-time
> + * The frames that hold src-time will be dropped, since their
> + * mm_time < session-mm_time. But all the new frames that are
> generated in
> + * the driver after migration, will be rendered appropriately.
> + * (b) If src-time > dst-time
> + * Similar consequences as in 1 (a)
> + * case 2 is less likely, since at takes at least 20 frames till the
> dst-server re-identifies
> + * the video stream and starts sending stream data
> + *
> + * display_stream_test_mm_time_reset tests for cases (1.a) and (2.b), and
> when
> + * they are encountered, it resets the stream.
> + */
> +static void display_stream_test_mm_time_reset(display_stream *st,
> SpiceMsgIn *new_frame_msg, guint32 mm_time)
> +{
> + SpiceStreamDataHeader *new_op;
> + SpiceMsgIn *tail_msg;
> + SpiceStreamDataHeader *tail_op;
> +
> + SPICE_DEBUG("%s", __FUNCTION__);
> + g_return_if_fail(new_frame_msg != NULL);
> + tail_msg = g_queue_peek_head(st->msgq);
>
Why call "tail" the "head"?
+ if (!tail_msg) {
> + return;
> + }
> + tail_op = spice_msg_in_parsed(tail_msg);
> + new_op = spice_msg_in_parsed(new_frame_msg);
> +
> + // case (2.b) (see the comments above).
> + if (new_op->multi_media_time < tail_op->multi_media_time) {
>
I think this check should be made on the tail, indeed. Perhaps you changed
it? Why?
> + SPICE_DEBUG("new-frame-time < tail-frame-time (%u < %u):"
> + " reseting stream",
> + new_op->multi_media_time,
> + tail_op->multi_media_time);
> + if (st->timeout != 0) {
> + g_source_remove(st->timeout);
> + st->timeout = 0;
> + }
> + g_queue_foreach(st->msgq, _msg_in_unref_func, NULL);
> + g_queue_clear(st->msgq);
> + } else if (st->timeout) {
> + SpiceMsgIn *head_msg;
> + SpiceStreamDataHeader *head_op;
> + guint32 head_render_time;
> +
> + head_msg = g_queue_peek_head(st->msgq);
> + g_return_if_fail(head_msg != NULL);
> + head_op = spice_msg_in_parsed(head_msg);
> +
> + head_render_time = g_get_monotonic_time()/1000;
> + if (mm_time < head_op->multi_media_time) {
> + head_render_time += head_op->multi_media_time - mm_time;
> + }
> + // case (1.a)
> + if (head_render_time + MM_TIME_RESET_TEST_DELTA_THRESH <
> st->timeout_monotonic_expiry) {
>
I don't understand how you check that the mm time has moved forward (by
comparing againt current monotonic time + threshold). A naive approach
would instead just find large discontinuities in the queued frames.
Since the clock is given by the audio playback, shouldn' t the
discontinuity be triggered there, and flush & re-scheduling the frame by
some signal handler?
> + SPICE_DEBUG("mm-time has moved forward: rescheduling "
> + "stream rendering (old-timout %u new-timeout %u
> diff %u",
> + st->timeout_monotonic_expiry,
> + head_render_time,
> + st->timeout_monotonic_expiry - head_render_time);
> + g_source_remove(st->timeout);
> + st->timeout = 0;
> + }
> + }
> +}
> +
> #define STREAM_PLAYBACK_SYNC_DROP_SEQ_LEN_LIMIT 5
> +
> /* coroutine context */
> static void display_handle_stream_data(SpiceChannel *channel, SpiceMsgIn
> *in)
> {
> @@ -1349,8 +1445,10 @@ static void display_handle_stream_data(SpiceChannel
> *channel, SpiceMsgIn *in)
> } else {
> CHANNEL_DEBUG(channel, "video latency: %d", latency);
> spice_msg_in_ref(in);
> + display_stream_test_mm_time_reset(st, in, mmtime);
> g_queue_push_tail(st->msgq, in);
> - display_stream_schedule(st);
> + while (!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;
> --
> 1.8.1.4
>
> _______________________________________________
> Spice-devel mailing list
> Spice-devel@lists.freedesktop.org
> http://lists.freedesktop.org/mailman/listinfo/spice-devel
>
--
Marc-André Lureau
_______________________________________________
Spice-devel mailing list
Spice-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/spice-devel
