[Spice-devel] [RFC PATCH spice-gtk] channel-display: protect video streaming from temporally unsynced mm_time (migration related)
Yonit Halperin
yhalperi at redhat.com
Tue Apr 30 05:52:14 PDT 2013
On 04/30/2013 07:59 AM, Marc-André Lureau wrote:
> Hi,
>
> Thanks for tracking this down. First, the patch doesn't compile.
>
Sorry, forgot to add channel-display-priv.h to the patch
> 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)
>
With a recently added patch to the server, the streams are stopped, but
it still doesn't solve the problem. There is still a race between
setting the mm-time by the playback-channel to the display-channel
receiving frames with updated mm-time. In addition, there can be frames
with the old mm-time in cmd-ring (ones that were created by the driver
before the 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.
>
Yes, as I mentioned in the cover letter, I will send a patch for
spice-server to send the MM_TIME after migration, but there will still
be a race between the display channel and main channel.
>
> On Tue, Apr 30, 2013 at 12:19 AM, Yonit Halperin <yhalperi at redhat.com
> <mailto:yhalperi at 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"?
a mistake, should peek at tail.
>
> + 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.
In the case I try to handle, there may be no large discontinuity in the
queued frames (the stream is stopped before migration, and the new
stream holds only new frames).
I compare the time the rendering was scheduled to, to the time it should
actually be according to the current clock.
>
> 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?
We can do that, however, not from the playback, but rather from the session
(when there is no playback, the mm-time is set from the main_channel).
>
>
> + 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 at lists.freedesktop.org
> <mailto:Spice-devel at lists.freedesktop.org>
> http://lists.freedesktop.org/mailman/listinfo/spice-devel
>
>
>
>
> --
> Marc-André Lureau
More information about the Spice-devel
mailing list