> > The client is in a better position than the server to pick the minimum > lag needed to compensate for frame arrival time jitter and ensure > smooth video playback. > To do so: > - It ignores the lag specified by the server through the mmtime clock > adjustments (but this lag is still tracked for the stream reports). > - It performs its own frame mmtime conversion to the local monotonic > clock spice_session_get_client_time() since the server-controlled > mmtime clock cannot be relied on. This conversion uses data from all The "since the server-controlled mmtime clock cannot be relied on" could be confusing. In a relative, not absolute way is reliable. But I suppose what you are meaning here is that you rely on the mmtimes from the frames, not the "server_time". > streams but is global so all streams ihave a common time reference. typo: "ihave" > - This is also where mmtime clock changes caused by server migration > are handled. "To do so this is also where mmtime clock changes caused by server migration are handled." ? > - It tracks the margin between the converted time-to-display frame > timestamp and the curren time and adds a delay to ensure this margin typo: "curren" > remains positive. > - This delay introduces the video stream lag. It is continuously > adjusted to either be as low as possible, or match the audio > playback delay for proper lip sync. > - Delay adjustments are gradual, speeding up or slowing down video > playback until the average margin matches the target lag. > - Changes in the average margin are tracked (see margin_spread) to > avoid nudging the delay in response to minor random variations. > > Signed-off-by: Francois Gouget <fgouget@xxxxxxxxxxxxxxx> > --- > src/channel-display-gst.c | 22 ++--- > src/channel-display-mjpeg.c | 14 +-- > src/channel-display-priv.h | 18 +++- > src/channel-display.c | 178 ++++++++++++++++++++++++++++++++---- > src/spice-session-priv.h | 1 + > src/spice-session.c | 46 ++++++++++ > 6 files changed, 240 insertions(+), 39 deletions(-) > > diff --git a/src/channel-display-gst.c b/src/channel-display-gst.c > index 6fccf621..673f4177 100644 > --- a/src/channel-display-gst.c > +++ b/src/channel-display-gst.c > @@ -50,7 +50,7 @@ typedef struct SpiceGstDecoder { > > /* ---------- Decoding and display queues ---------- */ > > - uint32_t last_mm_time; > + uint32_t last_frame_time; > > GMutex queues_mutex; > GQueue *decoding_queue; > @@ -297,8 +297,8 @@ static void schedule_frame(SpiceGstDecoder *decoder) > break; > } > > - if (spice_mmtime_diff(gstframe->encoded_frame->mm_time, now) >= 0) { > - decoder->timer_id = > g_timeout_add(gstframe->encoded_frame->mm_time - now, > + if (spice_mmtime_diff(gstframe->encoded_frame->time, now) >= 0) { > + decoder->timer_id = g_timeout_add(gstframe->encoded_frame->time > - now, > display_frame, decoder); > } else if (decoder->display_frame && !decoder->pending_samples) { > /* Still attempt to display the least out of date frame so the > @@ -307,8 +307,8 @@ static void schedule_frame(SpiceGstDecoder *decoder) > decoder->timer_id = g_timeout_add(0, display_frame, decoder); > } else { > SPICE_DEBUG("%s: rendering too late by %u ms (ts: %u, mmtime: > %u), dropping", > - __FUNCTION__, now - > gstframe->encoded_frame->mm_time, > - gstframe->encoded_frame->mm_time, now); > + __FUNCTION__, now - gstframe->encoded_frame->time, > + gstframe->encoded_frame->time, now); > stream_dropped_frame_on_playback(decoder->base.stream); > decoder->display_frame = NULL; > free_gst_frame(gstframe); > @@ -449,9 +449,9 @@ sink_event_probe(GstPad *pad, GstPadProbeInfo *info, > gpointer data) > * or more frame intervals. > */ > record(frames_stats, > - "frame mm_time %u size %u creation time %" PRId64 > + "frame time %u size %u creation time %" PRId64 > " decoded time %" PRId64 " queue %u before %u", > - frame->mm_time, frame->size, frame->creation_time, > duration, > + frame->time, frame->size, frame->creation_time, duration, Here we really need the original server mmtime, not hard to fix this, just add again the mm_time with the initial server value but use just "time" field for everything else > decoder->decoding_queue->length, gstframe->queue_len); > > if (!decoder->appsink) { > @@ -689,13 +689,13 @@ static gboolean > spice_gst_decoder_queue_frame(VideoDecoder *video_decoder, > return TRUE; > } > > - if (spice_mmtime_diff(frame->mm_time, decoder->last_mm_time) < 0) { > + if (spice_mmtime_diff(frame->time, decoder->last_frame_time) < 0) { > SPICE_DEBUG("new-frame-time < last-frame-time (%u < %u):" > " resetting stream", > - frame->mm_time, decoder->last_mm_time); > + frame->time, decoder->last_frame_time); > /* Let GStreamer deal with the frame anyway */ > } > - decoder->last_mm_time = frame->mm_time; > + decoder->last_frame_time = frame->time; > > if (margin < 0 && > decoder->base.codec_type == SPICE_VIDEO_CODEC_TYPE_MJPEG) { > @@ -778,7 +778,7 @@ VideoDecoder* create_gstreamer_decoder(int codec_type, > display_stream *stream) > decoder->base.queue_frame = spice_gst_decoder_queue_frame; > decoder->base.codec_type = codec_type; > decoder->base.stream = stream; > - decoder->last_mm_time = stream_get_time(stream); > + decoder->last_frame_time = stream_get_time(stream); > g_mutex_init(&decoder->queues_mutex); > decoder->decoding_queue = g_queue_new(); > > diff --git a/src/channel-display-mjpeg.c b/src/channel-display-mjpeg.c > index 647d31b0..d3ab77c8 100644 > --- a/src/channel-display-mjpeg.c > +++ b/src/channel-display-mjpeg.c > @@ -181,16 +181,16 @@ static void mjpeg_decoder_schedule(MJpegDecoder > *decoder) > decoder->cur_frame = NULL; > do { > if (frame) { > - if (spice_mmtime_diff(time, frame->mm_time) <= 0) { > - guint32 d = frame->mm_time - time; > + if (spice_mmtime_diff(time, frame->time) <= 0) { > + guint32 d = frame->time - time; > decoder->cur_frame = frame; > decoder->timer_id = g_timeout_add(d, > mjpeg_decoder_decode_frame, decoder); > break; > } > > SPICE_DEBUG("%s: rendering too late by %u ms (ts: %u, mmtime: > %u), dropping ", > - __FUNCTION__, time - frame->mm_time, > - frame->mm_time, time); > + __FUNCTION__, time - frame->time, > + frame->time, time); > stream_dropped_frame_on_playback(decoder->base.stream); > spice_frame_free(frame); > } > @@ -226,12 +226,12 @@ static gboolean mjpeg_decoder_queue_frame(VideoDecoder > *video_decoder, > > last_frame = g_queue_peek_tail(decoder->msgq); > if (last_frame) { > - if (spice_mmtime_diff(frame->mm_time, last_frame->mm_time) < 0) { > + if (spice_mmtime_diff(frame->time, last_frame->time) < 0) { > /* This should really not happen */ > SPICE_DEBUG("new-frame-time < last-frame-time (%u < %u):" > " resetting stream", > - frame->mm_time, > - last_frame->mm_time); > + frame->time, > + last_frame->time); > mjpeg_decoder_drop_queue(decoder); > } > } > diff --git a/src/channel-display-priv.h b/src/channel-display-priv.h > index 495df7ac..badd9d42 100644 > --- a/src/channel-display-priv.h > +++ b/src/channel-display-priv.h > @@ -39,7 +39,7 @@ typedef struct display_stream display_stream; > > typedef struct SpiceFrame SpiceFrame; > struct SpiceFrame { > - uint32_t mm_time; > + uint32_t time; > SpiceRect dest; > > uint8_t *data; > @@ -124,8 +124,22 @@ struct display_stream { > > SpiceChannel *channel; > > - /* stats */ > uint32_t first_frame_mm_time; should this field be moved to "stats" section ? > + uint32_t last_frame_mm_time; > + uint32_t last_frame_time; > + > + /* Lag management (see display_handle_stream_data()) */ > + uint32_t delay; > + uint32_t margin_eval_start; "eval" meaning "evaluation" ? > + uint32_t margin_eval_count; > + int32_t min_margin; > + int32_t min_margin_next; > + float avg_margin; > + int32_t min_avg_margin; > + int32_t max_avg_margin; > + uint32_t margin_spread; I think these fields deserve some more documentation, many seems so similar and are not clear. Sure you need them all? For instance what the difference between "min_margin" and "min_margin_next" and why you need both? Why "avg_margin" is float but "min_avg_margin/max_avg_margin" are not? >From comment in the code is a rounding issue but than you could change avg_margin formulae (see below). > + > + /* stats */ > uint32_t arrive_late_count; > uint64_t arrive_late_time; > uint32_t num_drops_on_playback; > diff --git a/src/channel-display.c b/src/channel-display.c > index b26326d6..815242de 100644 > --- a/src/channel-display.c > +++ b/src/channel-display.c > @@ -20,6 +20,7 @@ > #ifdef HAVE_SYS_TYPES_H > #include <sys/types.h> > #endif > +#include <math.h> /* for ceilf() */ > > #include "spice-client.h" > #include "spice-common.h" > @@ -1378,8 +1379,7 @@ static uint32_t spice_msg_in_frame_data(SpiceMsgIn > *frame_msg, uint8_t **data) > G_GNUC_INTERNAL > guint32 stream_get_time(display_stream *st) > { > - SpiceSession *session = spice_channel_get_session(st->channel); > - return session ? spice_session_get_mm_time(session) : 0; > + return g_get_monotonic_time() / 1000; > } > > /* coroutine or main context */ > @@ -1643,7 +1643,7 @@ static void display_stream_stats_save(display_stream > *st, > > static SpiceFrame *spice_frame_new(display_stream *st, > SpiceMsgIn *in, > - guint32 frame_mmtime) > + guint32 frame_time) > { > SpiceFrame *frame; > guint8 *data_ptr; > @@ -1651,7 +1651,7 @@ static SpiceFrame *spice_frame_new(display_stream *st, > guint32 data_size = spice_msg_in_frame_data(in, &data_ptr); > > frame = g_new(SpiceFrame, 1); > - frame->mm_time = frame_mmtime; > + frame->time = frame_time; Here and above add again the old "mm_time" for logging (I can post a follow up if you like). > frame->dest = *dest_rect; > frame->data = data_ptr; > frame->size = data_size; > @@ -1672,44 +1672,184 @@ void spice_frame_free(SpiceFrame *frame) > g_free(frame); > } > > +/* Pick an initial value likely to cover the network jitter and not to cause > + * a significant lag. The delay will be adjusted from there. > + */ > +#define INITIAL_DELAY 40 > + > +/* Collect data on a long enough period to capture rare events, but short > + * enough so that the algorithm is still responsive to changes. > + */ > +#define MARGIN_EVAL_TIME (1 * 1000) > + > +/* Make sure we have enough data points even if the framerate is very low. > */ > +#define MARGIN_EVAL_COUNT 20 > + > /* coroutine context */ > static void display_handle_stream_data(SpiceChannel *channel, SpiceMsgIn > *in) > { > + SpiceSession *session = spice_channel_get_session(channel); > SpiceDisplayChannelPrivate *c = SPICE_DISPLAY_CHANNEL(channel)->priv; > SpiceStreamDataHeader *op = spice_msg_in_parsed(in); > display_stream *st = get_stream_by_id(channel, op->id); > - guint32 mmtime; > - int32_t margin, margin_report; > + guint32 current_mmtime, frame_interval; > + guint32 stream_time, frame_time; > + gint32 mmtime_margin, margin; > SpiceFrame *frame; > > g_return_if_fail(st != NULL); > - mmtime = stream_get_time(st); > + > + current_mmtime = spice_session_get_mm_time(session); > > if (spice_msg_in_type(in) == SPICE_MSG_DISPLAY_STREAM_DATA_SIZED) { > CHANNEL_DEBUG(channel, "stream %u contains sized data", op->id); > } > > + frame_interval = 0; > + mmtime_margin = 400; /* server's default mm_time offset */ This values, which is used just for the report was simply: "margin_report = op->multi_media_time - mmtime;" the computation got quite complicated even if the purpose of this patch is not much about changing streaming reports. > if (op->multi_media_time == 0) { > - g_critical("Received frame with invalid 0 timestamp! perhaps wrong > graphic driver?"); > - op->multi_media_time = mmtime + 100; /* workaround... */ > - } > + g_critical("Received frame with invalid 0 timestamp! Perhaps wrong > graphic driver?"); > + op->multi_media_time = current_mmtime; /* workaround... */ > + frame_interval = spice_mmtime_diff(op->multi_media_time, > st->last_frame_mm_time); > + } else if (st->last_frame_mm_time == 0) { > + /* First frame so frame_interval is unknown */ > + mmtime_margin = spice_mmtime_diff(op->multi_media_time, > current_mmtime); > + } else if (op->multi_media_time < st->last_frame_mm_time) { Here spice_mmtime_diff should be used > + /* This can happen when migrating from a server with a high mm_time > + * (i.e. high uptime) to one with a low mm_time: > + * - server A sends a frame with A_mm_time > + * - client receives the frame and sets last_frame_mm_time = > A_mm_time > + * - server B sends a frame with B_mm_time > + * - client receives server B's frame with B_mm_time << A_mm_time > + * Also note that although server B would normally send an mm_time > + * reset message, there is no guarantee it will be received before > + * server B's first frame so it's not much help. > + */ > + SPICE_DEBUG("%u got an out of order frame -%u", op->id, > + st->last_frame_mm_time - op->multi_media_time); > + st->last_frame_mm_time = op->multi_media_time; > + } else if (op->multi_media_time > st->last_frame_mm_time + 1000) { Here too. > + /* Streams are supposed to send at least 1 frame per second. > + * So it's more likely that we got migrated from a server with a low > + * mm_time (i.e. low uptime) to one with a high mm_time. See the > case > + * above for details. In such a case simply reinitialize the stream. > + */ > + SPICE_DEBUG("%u got an abnormally long mm_time frame interval %u", > op->id, > + op->multi_media_time - st->last_frame_mm_time); > + st->last_frame_time = 0; > + } else { > + mmtime_margin = spice_mmtime_diff(op->multi_media_time, > current_mmtime); > + frame_interval = spice_mmtime_diff(op->multi_media_time, > st->last_frame_mm_time); > + } > + display_stream_stats_save(st, op->multi_media_time, current_mmtime); > + st->last_frame_mm_time = op->multi_media_time; > + > + /* Compute the local frame mmtime */ > + stream_time = stream_get_time(st); > + frame_time = spice_session_get_client_time(session, > op->multi_media_time); > + guint32 target_lag = spice_session_get_playback_latency(session); > + if (st->last_frame_time == 0) { > + margin = spice_mmtime_diff(frame_time, stream_time); > + st->delay = MAX(target_lag - margin, INITIAL_DELAY); > + frame_time += st->delay; > + margin += st->delay; > + > + st->margin_eval_start = stream_time; > + st->margin_eval_count = 0; > + st->min_margin = 0; /* Force wait before reducing the delay */ I suppose margin is never negative otherwise you would have a minimum that is bigger then the real minimum. > + st->min_margin_next = margin; > + st->avg_margin = margin; > + st->max_avg_margin = st->min_avg_margin = margin; > + st->margin_spread = st->delay; > + } else { > + frame_time = MAX(frame_time + st->delay, > + st->last_frame_time + (frame_interval + 3) / 4); > + margin = spice_mmtime_diff(frame_time, stream_time); > + > + /* Note that when using integers the moving average can stabilize up > to > + * weight/2-1 away from the true average (where weight=16 here) due > + * to the rounding errors (e.g. consider 1 16 16...). > + * So use a float for avg_margin. Why not "(st->avg_margin * 15 + margin + 8) / 16" ? > + */ > + st->avg_margin = (st->avg_margin * 15 + margin) / 16; > + if (st->avg_margin < st->min_avg_margin) { > + st->min_avg_margin = st->avg_margin; > + } else if (st->avg_margin > st->max_avg_margin) { > + st->max_avg_margin = ceilf(st->avg_margin); > + } > + > + if (margin < st->min_margin_next) { > + st->min_margin_next = margin; > + /* Take into account signs that the situation worsened without > + * delay. > + */ > + st->min_margin = MIN(st->min_margin, st->min_margin_next); > + } > > - margin = margin_report = op->multi_media_time - mmtime; > - if (margin > 0) { > - SpiceSession *s = spice_channel_get_session(channel); > + /* Only replace the current min_margin and margin_spread estimates > once > + * enough data has been collected for the *_next values, both in > term > + * of elapsed time and number of frames. > + */ > + st->margin_eval_count++; > + if (stream_time - st->margin_eval_start > MARGIN_EVAL_TIME && > + st->margin_eval_count >= MARGIN_EVAL_COUNT) { > + st->min_margin = st->min_margin_next; > + > + st->margin_eval_start = stream_time; > + st->margin_eval_count = 1; > + st->min_margin_next = margin; > + > + st->margin_spread = (st->max_avg_margin - st->min_avg_margin + > 1) / 2; > + st->min_avg_margin = st->avg_margin; > + st->max_avg_margin = ceilf(st->avg_margin); Why do you need ceilf here? You are just restarting the min/max computation. > + } > > - if (st->surface->streaming_mode && > !spice_session_is_playback_active(s)) { > - CHANNEL_DEBUG(channel, "video margin: %d, set to 0 since there > is no playback", margin); > - margin = 0; > + if (margin < 0) { > + gint32 nudge = -margin; > + margin += nudge; > + st->delay += nudge; > + frame_time = stream_time + (frame_interval + 3) / 4; > + > + /* The delay nudge also impacts the margin history */ > + st->min_margin_next += nudge; > + st->min_margin = margin; > + st->avg_margin += nudge; > + st->min_avg_margin += nudge; > + st->max_avg_margin += nudge; > + } else { > + /* Try to match the target lag without making needless > adjustments > + * for minor offsets. > + */ > + gint32 nudge = 0; > + if (st->avg_margin + st->margin_spread < target_lag) { > + nudge = MIN((frame_interval + 3) / 4, > + target_lag - st->avg_margin); > + } else if (st->min_margin > 0 && > + st->avg_margin > target_lag + st->margin_spread) { > + nudge = -MIN((frame_interval + 3) / 4, > + MIN(st->avg_margin - target_lag, > + st->min_margin)); > + } > + if (nudge) { > + st->delay += nudge; > + frame_time += nudge; > + > + /* The delay nudge also impacts the margin history */ > + st->min_margin_next += nudge; > + st->min_margin += nudge; > + st->avg_margin += nudge; > + st->min_avg_margin += nudge; > + st->max_avg_margin += nudge; > + } > } > } I will have to read all these formulaes again but looks like you have part of the code which is doing some smooth changes but at some intervals you do some bigger adjustments. It looks quite complicated and it seems hard to see if it's good or not. Not sure if it would be possible to encapsulate all that complexity and have some tests. What the cases you have in mind to resolv? Just ignoring peaks? > - display_stream_stats_save(st, op->multi_media_time, mmtime); > + st->last_frame_time = frame_time; > > /* Let the video decoder queue the frames so it can optimize their > * decoding and best decide if/when to drop them when they are late, > * taking into account the impact on later frames. > */ > - frame = spice_frame_new(st, in, op->multi_media_time); > + frame = spice_frame_new(st, in, frame_time); > if (!st->video_decoder->queue_frame(st->video_decoder, frame, margin)) { > destroy_stream(channel, op->id); > report_invalid_stream(channel, op->id); > @@ -1718,7 +1858,7 @@ static void display_handle_stream_data(SpiceChannel > *channel, SpiceMsgIn *in) > > if (c->enable_adaptive_streaming) { > display_update_stream_report(SPICE_DISPLAY_CHANNEL(channel), op->id, > - op->multi_media_time, margin_report); > + op->multi_media_time, mmtime_margin); > 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; > diff --git a/src/spice-session-priv.h b/src/spice-session-priv.h > index 6ece7e01..794d86a7 100644 > --- a/src/spice-session-priv.h > +++ b/src/spice-session-priv.h > @@ -50,6 +50,7 @@ GSocketConnection* > spice_session_channel_open_host(SpiceSession *session, SpiceC > void spice_session_channel_new(SpiceSession *session, SpiceChannel > *channel); > void spice_session_channel_migrate(SpiceSession *session, SpiceChannel > *channel); > > +guint32 spice_session_get_client_time(SpiceSession *session, guint32 > src_time); > void spice_session_set_mm_time(SpiceSession *session, guint32 time); > guint32 spice_session_get_mm_time(SpiceSession *session); > > diff --git a/src/spice-session.c b/src/spice-session.c > index 04ba124a..4e5a7823 100644 > --- a/src/spice-session.c > +++ b/src/spice-session.c > @@ -102,6 +102,7 @@ struct _SpiceSessionPrivate { > guint channels_destroying; > gboolean client_provided_sockets; > guint64 mm_time_offset; > + gint64 client_time_offset; This should be just 32 bit. > SpiceSession *migration; > GList *migration_left; > SpiceSessionMigration migration_state; > @@ -129,6 +130,10 @@ struct _SpiceSessionPrivate { > PhodavServer *webdav; > }; > > +/* Initialize the client_time_offset to an unlikely value. > + * See spice_session_get_client_time(). > + */ > +# define UNSET_CLIENT_TIME_OFFSET 0xd1ceca5e > > /** > * SECTION:spice-session > @@ -292,6 +297,7 @@ static void spice_session_init(SpiceSession *session) > SPICE_DEBUG("Supported channels: %s", channels); > g_free(channels); > > + s->client_time_offset = UNSET_CLIENT_TIME_OFFSET; > s->images = cache_image_new((GDestroyNotify)pixman_image_unref); > s->glz_window = glz_decoder_window_new(); > update_proxy(session, NULL); > @@ -2385,6 +2391,46 @@ int spice_session_get_connection_id(SpiceSession > *session) > return s->connection_id; > } > > +G_GNUC_INTERNAL > +guint32 spice_session_get_client_time(SpiceSession *session, guint32 mmtime) > +{ I agree with Snir that a "get" function doing so much stuff is confusing, maybe a "spice_session_adjust_to_client_time" or a "spice_session_mmtime2client_time". > + g_return_val_if_fail(SPICE_IS_SESSION(session), g_get_monotonic_time()); > + I suppose here should be "g_get_monotonic_time() / 1000", that is next "now" value. > + SpiceSessionPrivate *s = session->priv; > + > + guint32 now = g_get_monotonic_time() / 1000; > + gint64 new_offset = now - mmtime; This should be an unsigned 32 bit, all arithmetic are modulo 2**32. > + > + if (s->client_time_offset == UNSET_CLIENT_TIME_OFFSET) { > + /* Initialize the time offset. > + * Note that UNSET_CLIENT_TIME_OFFSET can be any value including 0 > + * which is common on low-latency LANs. But an unlikely one helps > when > + * adding a trace in this codepath. > + */ > + s->client_time_offset = new_offset; > + return now; > + } > + if (new_offset < s->client_time_offset - 1000 || > + new_offset > s->client_time_offset + 1000) { > + /* The change in offset was likely caused by a server migration. > + * Reset the time offset. > + */ Was this tested? Is there no other event to specifically detect migration? We (the client) needs to reconnect during migration so surely there's another event during this change. > + s->client_time_offset = new_offset; > + return now; > + } > + if (new_offset < s->client_time_offset) { > + /* The previous message we used to compute the offset was probably > + * delayed resulting in a too large offset. Eventually the offset > + * should settle to the true clock offset plus the network latency, > + * excluding the network jitter. > + */ A bit OT: maybe would be great to have the "client time" when we start receiving the message from the server instead of taking the time after the full message arrives. Should be more consistent with server mmtime changes (server timestamp messages before sending). > + s->client_time_offset = new_offset; > + return now; > + } > + > + return mmtime + s->client_time_offset; > +} > + > G_GNUC_INTERNAL > guint32 spice_session_get_mm_time(SpiceSession *session) > { Frediano _______________________________________________ Spice-devel mailing list Spice-devel@xxxxxxxxxxxxxxxxxxxxx https://lists.freedesktop.org/mailman/listinfo/spice-devel