<div dir="ltr"><div><div>Hi, </div>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) </div>Imho, there should be also a base mm time after migration completes, so that the client always has at least a monotonic mm time. <div class="gmail_extra"><div class="gmail_quote"> On Tue, Apr 30, 2013 at 12:19 AM, Yonit Halperin <<a href="mailto:yhalperi@redhat.com" target="_blank">yhalperi@redhat.com</a>> wrote: <blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"> 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__); </blockquote><div> </div><div>We use g_log functions or SPICE_DEBUG in spice-gtk. </div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"> + if (st->timeout) { + return TRUE; + } </blockquote><div> </div><div>This style change isn't necessary. </div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"> 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); + </blockquote><div> </div><div>extra line </div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"> 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); </blockquote><div> </div><div>Why call "tail" the "head"? </div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"> + 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) { </blockquote><div> </div><div>I think this check should be made on the tail, indeed. Perhaps you changed it? Why? </div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"> + 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) { </blockquote><div> </div><div>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? </div><div> </div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"> + 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 <a href="mailto:Spice-devel@lists.freedesktop.org" target="_blank">Spice-devel@lists.freedesktop.org</a> <a href="http://lists.freedesktop.org/mailman/listinfo/spice-devel" target="_blank">http://lists.freedesktop.org/mailman/listinfo/spice-devel</a> </blockquote></div> -- Marc-André Lureau </div></div>