diff --git a/gst/rtpmanager/gstrtpjitterbuffer.c b/gst/rtpmanager/gstrtpjitterbuffer.c index afedd03e1d..f8bfeb90d9 100644 --- a/gst/rtpmanager/gstrtpjitterbuffer.c +++ b/gst/rtpmanager/gstrtpjitterbuffer.c @@ -7,6 +7,9 @@ * Copyright 2007 Wim Taymans * Copyright 2015 Kurento (http://kurento.org/) * @author: Miguel París + * Copyright 2016 Pexip AS + * @author: Havard Graff + * @author: Stian Selnes * * This library is free software; you can redistribute it and/or * modify it under the terms of the GNU Library General Public @@ -140,6 +143,7 @@ enum #define DEFAULT_RTX_MIN_RETRY_TIMEOUT -1 #define DEFAULT_RTX_RETRY_PERIOD -1 #define DEFAULT_RTX_MAX_RETRIES -1 +#define DEFAULT_RTX_STATS_TIMEOUT 1000 #define DEFAULT_MAX_RTCP_RTP_TIME_DIFF 1000 #define DEFAULT_MAX_DROPOUT_TIME 60000 #define DEFAULT_MAX_MISORDER_TIME 2000 @@ -166,6 +170,7 @@ enum PROP_RTX_MIN_RETRY_TIMEOUT, PROP_RTX_RETRY_PERIOD, PROP_RTX_MAX_RETRIES, + PROP_RTX_STATS_TIMEOUT, PROP_STATS, PROP_MAX_RTCP_RTP_TIME_DIFF, PROP_MAX_DROPOUT_TIME, @@ -236,6 +241,14 @@ enum } \ } G_STMT_END +#define GST_BUFFER_IS_RETRANSMISSION(buffer) \ + GST_BUFFER_FLAG_IS_SET (buffer, GST_RTP_BUFFER_FLAG_RETRANSMISSION) + +typedef struct TimerQueue +{ + GQueue *timers; + GHashTable *hashtable; +} TimerQueue; struct _GstRtpJitterBufferPrivate { @@ -274,6 +287,7 @@ struct _GstRtpJitterBufferPrivate gint rtx_min_retry_timeout; gint rtx_retry_period; gint rtx_max_retries; + guint rtx_stats_timeout; gint max_rtcp_rtp_time_diff; guint32 max_dropout_time; guint32 max_misorder_time; @@ -298,6 +312,7 @@ struct _GstRtpJitterBufferPrivate guint32 next_in_seqnum; GArray *timers; + TimerQueue *rtx_stats_timers; /* start and stop ranges */ GstClockTime npt_start; @@ -371,6 +386,7 @@ typedef struct GstClockTime rtx_retry; GstClockTime rtx_last; guint num_rtx_retry; + guint num_rtx_received; } TimerData; #define GST_RTP_JITTER_BUFFER_GET_PRIVATE(o) \ @@ -472,6 +488,12 @@ static void wait_next_timeout (GstRtpJitterBuffer * jitterbuffer); static GstStructure *gst_rtp_jitter_buffer_create_stats (GstRtpJitterBuffer * jitterbuffer); +static void update_rtx_stats (GstRtpJitterBuffer * jitterbuffer, + TimerData * timer, GstClockTime dts, gboolean success); + +static TimerQueue *timer_queue_new (void); +static void timer_queue_free (TimerQueue * queue); + static void gst_rtp_jitter_buffer_class_init (GstRtpJitterBufferClass * klass) { @@ -690,6 +712,20 @@ gst_rtp_jitter_buffer_class_init (GstRtpJitterBufferClass * klass) "The maximum number of retries to request a retransmission. " "(-1 not limited)", -1, G_MAXINT, DEFAULT_RTX_MAX_RETRIES, G_PARAM_READWRITE | G_PARAM_STATIC_STRINGS)); + /** + * GstRtpJitterBuffer::rtx-stats-timeout: + * + * The time to wait for a retransmitted packet after it has been + * considered lost in order to collect RTX statistics. + * + * Since: 1.10 + */ + g_object_class_install_property (gobject_class, PROP_RTX_STATS_TIMEOUT, + g_param_spec_uint ("rtx-stats-timeout", "RTX Statistics Timeout", + "The time to wait for a retransmitted packet after it has been " + "considered lost in order to collect statistics (ms)", + 0, G_MAXUINT, DEFAULT_RTX_STATS_TIMEOUT, + G_PARAM_READWRITE | G_PARAM_STATIC_STRINGS)); g_object_class_install_property (gobject_class, PROP_MAX_DROPOUT_TIME, g_param_spec_uint ("max-dropout-time", "Max dropout time", @@ -915,6 +951,7 @@ gst_rtp_jitter_buffer_init (GstRtpJitterBuffer * jitterbuffer) priv->rtx_min_retry_timeout = DEFAULT_RTX_MIN_RETRY_TIMEOUT; priv->rtx_retry_period = DEFAULT_RTX_RETRY_PERIOD; priv->rtx_max_retries = DEFAULT_RTX_MAX_RETRIES; + priv->rtx_stats_timeout = DEFAULT_RTX_STATS_TIMEOUT; priv->max_rtcp_rtp_time_diff = DEFAULT_MAX_RTCP_RTP_TIME_DIFF; priv->max_dropout_time = DEFAULT_MAX_DROPOUT_TIME; priv->max_misorder_time = DEFAULT_MAX_MISORDER_TIME; @@ -923,6 +960,7 @@ gst_rtp_jitter_buffer_init (GstRtpJitterBuffer * jitterbuffer) priv->last_rtptime = -1; priv->avg_jitter = 0; priv->timers = g_array_new (FALSE, TRUE, sizeof (TimerData)); + priv->rtx_stats_timers = timer_queue_new (); priv->jbuf = rtp_jitter_buffer_new (); g_mutex_init (&priv->jbuf_lock); g_cond_init (&priv->jbuf_timer); @@ -1026,6 +1064,7 @@ gst_rtp_jitter_buffer_finalize (GObject * object) priv = jitterbuffer->priv; g_array_free (priv->timers, TRUE); + timer_queue_free (priv->rtx_stats_timers); g_mutex_clear (&priv->jbuf_lock); g_cond_clear (&priv->jbuf_timer); g_cond_clear (&priv->jbuf_event); @@ -1927,6 +1966,68 @@ apply_offset (GstRtpJitterBuffer * jitterbuffer, GstClockTime timestamp) return timestamp; } +static TimerQueue * +timer_queue_new (void) +{ + TimerQueue *queue; + + queue = g_slice_new (TimerQueue); + queue->timers = g_queue_new (); + queue->hashtable = g_hash_table_new (NULL, NULL); + + return queue; +} + +static void +timer_queue_free (TimerQueue * queue) +{ + if (!queue) + return; + + g_hash_table_destroy (queue->hashtable); + g_queue_free_full (queue->timers, g_free); + g_slice_free (TimerQueue, queue); +} + +static void +timer_queue_append (TimerQueue * queue, const TimerData * timer, + GstClockTime timeout, gboolean lost) +{ + TimerData *copy; + + copy = g_memdup (timer, sizeof (*timer)); + copy->timeout = timeout; + copy->type = lost ? TIMER_TYPE_LOST : TIMER_TYPE_EXPECTED; + copy->idx = -1; + + GST_LOG ("Append rtx-stats timer #%d, %" GST_TIME_FORMAT, + copy->seqnum, GST_TIME_ARGS (copy->timeout)); + g_queue_push_tail (queue->timers, copy); + g_hash_table_insert (queue->hashtable, GINT_TO_POINTER (copy->seqnum), copy); +} + +static void +timer_queue_clear_until (TimerQueue * queue, GstClockTime timeout) +{ + TimerData *test; + + test = g_queue_peek_head (queue->timers); + while (test && test->timeout < timeout) { + GST_LOG ("Pop rtx-stats timer #%d, %" GST_TIME_FORMAT " < %" + GST_TIME_FORMAT, test->seqnum, GST_TIME_ARGS (test->timeout), + GST_TIME_ARGS (timeout)); + g_hash_table_remove (queue->hashtable, GINT_TO_POINTER (test->seqnum)); + g_free (g_queue_pop_head (queue->timers)); + test = g_queue_peek_head (queue->timers); + } +} + +static TimerData * +timer_queue_find (TimerQueue * queue, guint16 seqnum) +{ + return g_hash_table_lookup (queue->hashtable, GINT_TO_POINTER (seqnum)); +} + static TimerData * find_timer (GstRtpJitterBuffer * jitterbuffer, guint16 seqnum) { @@ -2018,7 +2119,9 @@ add_timer (GstRtpJitterBuffer * jitterbuffer, TimerType type, timer->rtx_delay = delay; timer->rtx_retry = 0; } + timer->rtx_last = GST_CLOCK_TIME_NONE; timer->num_rtx_retry = 0; + timer->num_rtx_received = 0; recalculate_timer (jitterbuffer, timer); JBUF_SIGNAL_TIMER (priv); @@ -2042,18 +2145,24 @@ reschedule_timer (GstRtpJitterBuffer * jitterbuffer, TimerData * timer, oldseq = timer->seqnum; GST_DEBUG_OBJECT (jitterbuffer, - "replace timer for seqnum %d->%d to %" GST_TIME_FORMAT, - oldseq, seqnum, GST_TIME_ARGS (timeout + delay)); + "replace timer %d for seqnum %d->%d timeout %" GST_TIME_FORMAT + "->%" GST_TIME_FORMAT, timer->type, oldseq, seqnum, + GST_TIME_ARGS (timer->timeout), GST_TIME_ARGS (timeout + delay)); timer->timeout = timeout + delay; timer->seqnum = seqnum; if (reset) { + GST_DEBUG_OBJECT (jitterbuffer, "reset rtx delay %" GST_TIME_FORMAT + "->%" GST_TIME_FORMAT, GST_TIME_ARGS (timer->rtx_delay), + GST_TIME_ARGS (delay)); timer->rtx_base = timeout; timer->rtx_delay = delay; timer->rtx_retry = 0; } - if (seqchange) + if (seqchange) { timer->num_rtx_retry = 0; + timer->num_rtx_received = 0; + } if (priv->clock_id) { /* we changed the seqnum and there is a timer currently waiting with this @@ -2089,6 +2198,9 @@ remove_timer (GstRtpJitterBuffer * jitterbuffer, TimerData * timer) GstRtpJitterBufferPrivate *priv = jitterbuffer->priv; guint idx; + if (timer->idx == -1) + return; + if (priv->clock_id && priv->timer_seqnum == timer->seqnum) unschedule_current_timer (jitterbuffer); @@ -2166,10 +2278,10 @@ already_lost (GstRtpJitterBuffer * jitterbuffer, guint16 seqnum) */ static void update_timers (GstRtpJitterBuffer * jitterbuffer, guint16 seqnum, - GstClockTime dts, gboolean do_next_seqnum) + GstClockTime dts, gboolean do_next_seqnum, gboolean is_rtx, + TimerData * timer) { GstRtpJitterBufferPrivate *priv = jitterbuffer->priv; - TimerData *timer = NULL; /* go through all timers and unschedule the ones with a large gap */ if (priv->do_retransmission && priv->rtx_delay_reorder > 0) { @@ -2184,20 +2296,13 @@ update_timers (GstRtpJitterBuffer * jitterbuffer, guint16 seqnum, GST_DEBUG_OBJECT (jitterbuffer, "%d, #%d<->#%d gap %d", test->type, test->seqnum, seqnum, gap); - if (gap == 0) { - GST_DEBUG ("found timer for current seqnum"); - /* the timer for the current seqnum */ - timer = test; - } else if (gap > priv->rtx_delay_reorder) { + if (gap > priv->rtx_delay_reorder) { /* max gap, we exceeded the max reorder distance and we don't expect the * missing packet to be this reordered */ if (test->num_rtx_retry == 0 && test->type == TIMER_TYPE_EXPECTED) reschedule_timer (jitterbuffer, test, test->seqnum, -1, 0, FALSE); } } - } else { - /* find the timer for the seqnum */ - timer = find_timer (jitterbuffer, seqnum); } do_next_seqnum = do_next_seqnum && priv->packet_spacing > 0 @@ -2205,43 +2310,23 @@ update_timers (GstRtpJitterBuffer * jitterbuffer, guint16 seqnum, if (timer && timer->type != TIMER_TYPE_DEADLINE) { if (timer->num_rtx_retry > 0) { - GstClockTime rtx_last, delay; + if (is_rtx) { + update_rtx_stats (jitterbuffer, timer, dts, TRUE); + /* don't try to estimate the next seqnum because this is a retransmitted + * packet and it probably did not arrive with the expected packet + * spacing. */ + do_next_seqnum = FALSE; + } - /* we scheduled a retry for this packet and now we have it */ - priv->num_rtx_success++; - /* all the previous retry attempts failed */ - priv->num_rtx_failed += timer->num_rtx_retry - 1; - /* number of retries before receiving the packet */ - if (priv->avg_rtx_num == 0.0) - priv->avg_rtx_num = timer->num_rtx_retry; - else - priv->avg_rtx_num = (timer->num_rtx_retry + 7 * priv->avg_rtx_num) / 8; - /* calculate the delay between retransmission request and receiving this - * packet, start with when we scheduled this timeout last */ - rtx_last = timer->rtx_last; - if (dts != GST_CLOCK_TIME_NONE && dts > rtx_last) { - /* we have a valid delay if this packet arrived after we scheduled the - * request */ - delay = dts - rtx_last; - if (priv->avg_rtx_rtt == 0) - priv->avg_rtx_rtt = delay; - else - priv->avg_rtx_rtt = (delay + 7 * priv->avg_rtx_rtt) / 8; - } else - delay = 0; - - GST_LOG_OBJECT (jitterbuffer, - "RTX success %" G_GUINT64_FORMAT ", failed %" G_GUINT64_FORMAT - ", requests %" G_GUINT64_FORMAT ", dups %" G_GUINT64_FORMAT - ", avg-num %g, delay %" GST_TIME_FORMAT ", avg-rtt %" GST_TIME_FORMAT, - priv->num_rtx_success, priv->num_rtx_failed, priv->num_rtx_requests, - priv->num_duplicates, priv->avg_rtx_num, GST_TIME_ARGS (delay), - GST_TIME_ARGS (priv->avg_rtx_rtt)); - - /* don't try to estimate the next seqnum because this is a retransmitted - * packet and it probably did not arrive with the expected packet - * spacing. */ - do_next_seqnum = FALSE; + if (!is_rtx || timer->num_rtx_retry > 1) { + /* Store timer in order to record stats when/if the retransmitted + * packet arrives. We should also store timer information if we've + * requested retransmission more than once since we may receive + * several retransmitted packets. For accuracy we should update the + * stats also when the redundant retransmitted packets arrives. */ + timer_queue_append (priv->rtx_stats_timers, timer, + dts + priv->rtx_stats_timeout * GST_MSECOND, FALSE); + } } } @@ -2254,6 +2339,12 @@ update_timers (GstRtpJitterBuffer * jitterbuffer, guint16 seqnum, delay = get_rtx_delay (priv); /* and update/install timer for next seqnum */ + GST_DEBUG_OBJECT (jitterbuffer, "Add RTX timer #%d, expected %" + GST_TIME_FORMAT ", delay %" GST_TIME_FORMAT ", packet-spacing %" + GST_TIME_FORMAT ", jitter %" GST_TIME_FORMAT, priv->next_in_seqnum, + GST_TIME_ARGS (expected), GST_TIME_ARGS (delay), + GST_TIME_ARGS (priv->packet_spacing), GST_TIME_ARGS (priv->avg_jitter)); + if (timer) { reschedule_timer (jitterbuffer, timer, priv->next_in_seqnum, expected, delay, TRUE); @@ -2592,6 +2683,7 @@ gst_rtp_jitter_buffer_chain (GstPad * pad, GstObject * parent, GstMessage *msg = NULL; gboolean estimated_dts = FALSE; guint32 packet_rate, max_dropout, max_misorder; + TimerData *timer = NULL; jitterbuffer = GST_RTP_JITTER_BUFFER_CAST (parent); @@ -2635,8 +2727,9 @@ gst_rtp_jitter_buffer_chain (GstPad * pad, GstObject * parent, } GST_DEBUG_OBJECT (jitterbuffer, - "Received packet #%d at time %" GST_TIME_FORMAT ", discont %d", seqnum, - GST_TIME_ARGS (dts), GST_BUFFER_IS_DISCONT (buffer)); + "Received packet #%d at time %" GST_TIME_FORMAT ", discont %d, rtx %d", + seqnum, GST_TIME_ARGS (dts), GST_BUFFER_IS_DISCONT (buffer), + GST_BUFFER_IS_RETRANSMISSION (buffer)); JBUF_LOCK_CHECK (priv, out_flushing); @@ -2674,7 +2767,8 @@ gst_rtp_jitter_buffer_chain (GstPad * pad, GstObject * parent, if (G_UNLIKELY (priv->eos)) goto have_eos; - calculate_jitter (jitterbuffer, dts, rtptime); + if (!GST_BUFFER_IS_RETRANSMISSION (buffer)) + calculate_jitter (jitterbuffer, dts, rtptime); if (priv->seqnum_base != -1) { gint gap; @@ -2864,6 +2958,14 @@ gst_rtp_jitter_buffer_chain (GstPad * pad, GstObject * parent, priv->next_in_seqnum = (seqnum + 1) & 0xffff; } + timer = find_timer (jitterbuffer, seqnum); + if (GST_BUFFER_IS_RETRANSMISSION (buffer)) { + if (!timer) + timer = timer_queue_find (priv->rtx_stats_timers, seqnum); + if (timer) + timer->num_rtx_received++; + } + /* let's check if this buffer is too late, we can only accept packets with * bigger seqnum than the one we last pushed. */ if (G_LIKELY (priv->last_popped_seqnum != -1)) { @@ -2872,8 +2974,19 @@ gst_rtp_jitter_buffer_chain (GstPad * pad, GstObject * parent, gap = gst_rtp_buffer_compare_seqnum (priv->last_popped_seqnum, seqnum); /* priv->last_popped_seqnum >= seqnum, we're too late. */ - if (G_UNLIKELY (gap <= 0)) + if (G_UNLIKELY (gap <= 0)) { + if (priv->do_retransmission) { + if (GST_BUFFER_IS_RETRANSMISSION (buffer) && timer) { + update_rtx_stats (jitterbuffer, timer, dts, FALSE); + /* Only count the retranmitted packet too late if it has been + * considered lost. If the original packet arrived before the + * retransmitted we just count it as a duplicate. */ + if (timer->type != TIMER_TYPE_LOST) + goto rtx_duplicate; + } + } goto too_late; + } } if (already_lost (jitterbuffer, seqnum)) @@ -2921,11 +3034,15 @@ gst_rtp_jitter_buffer_chain (GstPad * pad, GstObject * parent, * have a duplicate. */ if (G_UNLIKELY (!rtp_jitter_buffer_insert (priv->jbuf, item, &head, &percent, - gst_element_get_base_time (GST_ELEMENT_CAST (jitterbuffer))))) + gst_element_get_base_time (GST_ELEMENT_CAST (jitterbuffer))))) { + if (GST_BUFFER_IS_RETRANSMISSION (buffer) && timer) + update_rtx_stats (jitterbuffer, timer, dts, FALSE); goto duplicate; + } /* update timers */ - update_timers (jitterbuffer, seqnum, dts, do_next_seqnum); + update_timers (jitterbuffer, seqnum, dts, do_next_seqnum, + GST_BUFFER_IS_RETRANSMISSION (buffer), timer); /* we had an unhandled SR, handle it now */ if (priv->last_sr) @@ -3012,6 +3129,14 @@ duplicate: free_item (item); goto finished; } +rtx_duplicate: + { + GST_DEBUG_OBJECT (jitterbuffer, + "Duplicate RTX packet #%d detected, dropping", seqnum); + priv->num_duplicates++; + gst_buffer_unref (buffer); + goto finished; + } } static GstClockTime @@ -3375,6 +3500,55 @@ get_rtx_retry_period (GstRtpJitterBufferPrivate * priv, return rtx_retry_period; } +static void +update_rtx_stats (GstRtpJitterBuffer * jitterbuffer, TimerData * timer, + GstClockTime dts, gboolean success) +{ + GstRtpJitterBufferPrivate *priv = jitterbuffer->priv; + GstClockTime delay; + + if (success) { + /* we scheduled a retry for this packet and now we have it */ + priv->num_rtx_success++; + /* all the previous retry attempts failed */ + priv->num_rtx_failed += timer->num_rtx_retry - 1; + } else { + /* All retries failed or was too late */ + priv->num_rtx_failed += timer->num_rtx_retry; + } + + /* number of retries before (hopefully) receiving the packet */ + if (priv->avg_rtx_num == 0.0) + priv->avg_rtx_num = timer->num_rtx_retry; + else + priv->avg_rtx_num = (timer->num_rtx_retry + 7 * priv->avg_rtx_num) / 8; + + /* Calculate the delay between retransmission request and receiving this + * packet. We have a valid delay if and only if this packet is a response to + * our last request. If not we don't know if this is a response to an + * earlier request and delay could be way off. For RTT is more important + * with correct values than to update for every packet. */ + if (timer->num_rtx_retry == timer->num_rtx_received && + dts != GST_CLOCK_TIME_NONE && dts > timer->rtx_last) { + delay = dts - timer->rtx_last; + if (priv->avg_rtx_rtt == 0) + priv->avg_rtx_rtt = delay; + else + priv->avg_rtx_rtt = (delay + 7 * priv->avg_rtx_rtt) / 8; + } else { + delay = 0; + } + + GST_LOG_OBJECT (jitterbuffer, + "RTX #%d, result %d, success %" G_GUINT64_FORMAT ", failed %" + G_GUINT64_FORMAT ", requests %" G_GUINT64_FORMAT ", dups %" + G_GUINT64_FORMAT ", avg-num %g, delay %" GST_TIME_FORMAT ", avg-rtt %" + GST_TIME_FORMAT, timer->seqnum, success, priv->num_rtx_success, + priv->num_rtx_failed, priv->num_rtx_requests, priv->num_duplicates, + priv->avg_rtx_num, GST_TIME_ARGS (delay), + GST_TIME_ARGS (priv->avg_rtx_rtt)); +} + /* the timeout for when we expected a packet expired */ static gboolean do_expected_timeout (GstRtpJitterBuffer * jitterbuffer, TimerData * timer, @@ -3394,10 +3568,6 @@ do_expected_timeout (GstRtpJitterBuffer * jitterbuffer, TimerData * timer, rtx_retry_timeout = get_rtx_retry_timeout (priv); rtx_retry_period = get_rtx_retry_period (priv, rtx_retry_timeout); - GST_DEBUG_OBJECT (jitterbuffer, "timeout %" GST_TIME_FORMAT ", period %" - GST_TIME_FORMAT, GST_TIME_ARGS (rtx_retry_timeout), - GST_TIME_ARGS (rtx_retry_period)); - delay = timer->rtx_delay + timer->rtx_retry; delay_ms = GST_TIME_AS_MSECONDS (delay); @@ -3416,6 +3586,7 @@ do_expected_timeout (GstRtpJitterBuffer * jitterbuffer, TimerData * timer, "deadline", G_TYPE_UINT, priv->latency_ms, "packet-spacing", G_TYPE_UINT64, priv->packet_spacing, "avg-rtt", G_TYPE_UINT, avg_rtx_rtt_ms, NULL)); + GST_DEBUG_OBJECT (jitterbuffer, "Request RTX: %" GST_PTR_FORMAT, event); priv->num_rtx_requests++; timer->num_rtx_retry++; @@ -3506,8 +3677,13 @@ do_lost_timeout (GstRtpJitterBuffer * jitterbuffer, TimerData * timer, item = alloc_item (event, ITEM_TYPE_LOST, -1, -1, seqnum, lost_packets, -1); rtp_jitter_buffer_insert (priv->jbuf, item, &head, NULL, -1); - /* remove timer now */ + if (GST_CLOCK_TIME_IS_VALID (timer->rtx_last)) { + /* Store info to update stats if the packet arrives too late */ + timer_queue_append (priv->rtx_stats_timers, timer, + now + priv->rtx_stats_timeout * GST_MSECOND, TRUE); + } remove_timer (jitterbuffer, timer); + if (head) JBUF_SIGNAL_EVENT (priv); @@ -3608,6 +3784,11 @@ wait_next_timeout (GstRtpJitterBuffer * jitterbuffer) GST_DEBUG_OBJECT (jitterbuffer, "now %" GST_TIME_FORMAT, GST_TIME_ARGS (now)); + /* Clear expired rtx-stats timers */ + if (priv->do_retransmission) + timer_queue_clear_until (priv->rtx_stats_timers, now); + + /* Iterate "normal" timers */ len = priv->timers->len; for (i = 0; i < len;) { TimerData *test = &g_array_index (priv->timers, TimerData, i); @@ -4215,6 +4396,11 @@ gst_rtp_jitter_buffer_set_property (GObject * object, priv->rtx_max_retries = g_value_get_int (value); JBUF_UNLOCK (priv); break; + case PROP_RTX_STATS_TIMEOUT: + JBUF_LOCK (priv); + priv->rtx_stats_timeout = g_value_get_uint (value); + JBUF_UNLOCK (priv); + break; case PROP_MAX_RTCP_RTP_TIME_DIFF: JBUF_LOCK (priv); priv->max_rtcp_rtp_time_diff = g_value_get_int (value); @@ -4337,6 +4523,11 @@ gst_rtp_jitter_buffer_get_property (GObject * object, g_value_set_int (value, priv->rtx_max_retries); JBUF_UNLOCK (priv); break; + case PROP_RTX_STATS_TIMEOUT: + JBUF_LOCK (priv); + g_value_set_uint (value, priv->rtx_stats_timeout); + JBUF_UNLOCK (priv); + break; case PROP_STATS: g_value_take_boxed (value, gst_rtp_jitter_buffer_create_stats (jitterbuffer)); diff --git a/tests/check/elements/rtpjitterbuffer.c b/tests/check/elements/rtpjitterbuffer.c index 5cb8510c82..5db51baf59 100644 --- a/tests/check/elements/rtpjitterbuffer.c +++ b/tests/check/elements/rtpjitterbuffer.c @@ -5,7 +5,7 @@ * Copyright (C) 2012 Cisco Systems, Inc * Authors: Kelley Rogers * Havard Graff - * Copyright (C) 2013-2015 Pexip AS + * Copyright (C) 2013-2016 Pexip AS * Stian Selnes * Havard Graff * @@ -447,6 +447,15 @@ generate_test_buffer (guint seq_num) TRUE, seq_num, seq_num * PCMU_RTP_TS_DURATION); } +static GstBuffer * +generate_test_buffer_rtx (GstClockTime dts, guint seq_num) +{ + GstBuffer *buffer = generate_test_buffer_full (dts, TRUE, seq_num, + seq_num * PCMU_RTP_TS_DURATION); + GST_BUFFER_FLAG_SET (buffer, GST_RTP_BUFFER_FLAG_RETRANSMISSION); + return buffer; +} + static gint get_rtp_seq_num (GstBuffer * buf) { @@ -1067,7 +1076,9 @@ GST_START_TEST (test_rtx_two_missing) /* make buffer 3 */ fail_unless_equals_int (GST_FLOW_OK, - gst_harness_push (h, generate_test_buffer (3))); + gst_harness_push (h, + generate_test_buffer_rtx (gst_clock_get_time (GST_CLOCK (testclock)), + 3))); /* make more buffers */ for (i = 5; i < 15; i++) { @@ -1249,6 +1260,542 @@ GST_START_TEST (test_rtx_packet_delay) GST_END_TEST; +GST_START_TEST (test_rtx_buffer_arrives_just_in_time) +{ + GstHarness *h = gst_harness_new ("rtpjitterbuffer"); + GstTestClock *testclock; + gint latency_ms = 5 * PCMU_BUF_MS; + gint num_init_buffers = latency_ms / PCMU_BUF_MS + 1; + GstBuffer *buffer; + GstClockTime now, last_rtx_request; + + testclock = gst_harness_get_testclock (h); + gst_harness_set_src_caps (h, generate_caps ()); + g_object_set (h->element, "do-retransmission", TRUE, "latency", latency_ms, + "rtx-max-retries", 1, NULL); + + /* Push/pull buffers and advance time past buffer 0's timeout (in order to + * simplify the test) */ + for (gint i = 0; i < num_init_buffers; i++) { + gst_test_clock_set_time (testclock, i * PCMU_BUF_DURATION); + fail_unless_equals_int (GST_FLOW_OK, + gst_harness_push (h, generate_test_buffer (i))); + gst_harness_wait_for_clock_id_waits (h, 1, 60); + } + + gst_harness_crank_single_clock_wait (h); + fail_unless_equals_int64 (latency_ms * GST_MSECOND, + gst_clock_get_time (GST_CLOCK (testclock))); + + for (gint i = 0; i < num_init_buffers; i++) + gst_buffer_unref (gst_harness_pull (h)); + + /* drop reconfigure event */ + gst_event_unref (gst_harness_pull_upstream_event (h)); + + /* Crank clock to send retransmission events requesting seqnum 6 which has + * not arrived yet. */ + gst_harness_crank_single_clock_wait (h); + verify_rtx_event (gst_harness_pull_upstream_event (h), + 6, 6 * PCMU_BUF_DURATION, 10, PCMU_BUF_DURATION); + + last_rtx_request = gst_clock_get_time (GST_CLOCK (testclock)); + fail_unless_equals_int64 (last_rtx_request, 130 * GST_MSECOND); + + /* seqnum 6 arrives just before it times out and is considered lost */ + now = 200 * GST_MSECOND; + gst_test_clock_set_time (testclock, now); + fail_unless_equals_int (GST_FLOW_OK, gst_harness_push (h, + generate_test_buffer_rtx (now, 6))); + buffer = gst_harness_pull (h); + fail_unless_equals_int (6, get_rtp_seq_num (buffer)); + gst_buffer_unref (buffer); + + fail_unless (verify_jb_stats (h->element, + gst_structure_new ("application/x-rtp-jitterbuffer-stats", + "num-pushed", G_TYPE_UINT64, (guint64) num_init_buffers + 1, + "num-lost", G_TYPE_UINT64, (guint64) 0, + "rtx-count", G_TYPE_UINT64, (guint64) 1, + "rtx-success-count", G_TYPE_UINT64, (guint64) 1, + "rtx-per-packet", G_TYPE_DOUBLE, 1.0, + "rtx-rtt", G_TYPE_UINT64, (guint64) (now - last_rtx_request), + NULL))); + + gst_object_unref (testclock); + gst_harness_teardown (h); +} + +GST_END_TEST; + +GST_START_TEST (test_rtx_buffer_arrives_too_late) +{ + GstHarness *h = gst_harness_new ("rtpjitterbuffer"); + GstTestClock *testclock; + gint latency_ms = 5 * PCMU_BUF_MS; + gint num_init_buffers = latency_ms / PCMU_BUF_MS + 1; + GstClockTime now, last_rtx_request; + + testclock = gst_harness_get_testclock (h); + gst_harness_set_src_caps (h, generate_caps ()); + g_object_set (h->element, "do-retransmission", TRUE, "latency", latency_ms, + "do-lost", TRUE, "rtx-max-retries", 1, NULL); + + /* Push/pull buffers and advance time past buffer 0's timeout (in order to + * simplify the test) */ + for (gint i = 0; i < num_init_buffers; i++) { + gst_test_clock_set_time (testclock, i * PCMU_BUF_DURATION); + fail_unless_equals_int (GST_FLOW_OK, + gst_harness_push (h, generate_test_buffer (i))); + gst_harness_wait_for_clock_id_waits (h, 1, 60); + } + + gst_harness_crank_single_clock_wait (h); + fail_unless_equals_int64 (latency_ms * GST_MSECOND, + gst_clock_get_time (GST_CLOCK (testclock))); + + for (gint i = 0; i < num_init_buffers; i++) + gst_buffer_unref (gst_harness_pull (h)); + + /* drop reconfigure event */ + gst_event_unref (gst_harness_pull_upstream_event (h)); + /* drop GstEventStreamStart & GstEventCaps & GstEventSegment */ + for (gint i = 0; i < 3; i++) + gst_event_unref (gst_harness_pull_event (h)); + + /* Crank clock to send retransmission events requesting seqnum 6 which has + * not arrived yet. */ + gst_harness_crank_single_clock_wait (h); + verify_rtx_event (gst_harness_pull_upstream_event (h), + 6, 6 * PCMU_BUF_DURATION, 10, PCMU_BUF_DURATION); + + last_rtx_request = gst_clock_get_time (GST_CLOCK (testclock)); + fail_unless_equals_int64 (last_rtx_request, 130 * GST_MSECOND); + + /* seqnum 6 is considered lost */ + gst_harness_crank_single_clock_wait (h); + verify_lost_event (gst_harness_pull_event (h), 6, + 6 * PCMU_BUF_DURATION, PCMU_BUF_DURATION); + + /* seqnum 6 arrives too late */ + now = gst_clock_get_time (GST_CLOCK (testclock)); + fail_unless_equals_int (GST_FLOW_OK, gst_harness_push (h, + generate_test_buffer_rtx (now, 6))); + + fail_unless (verify_jb_stats (h->element, + gst_structure_new ("application/x-rtp-jitterbuffer-stats", + "num-pushed", G_TYPE_UINT64, (guint64) num_init_buffers, + "num-lost", G_TYPE_UINT64, (guint64) 1, + "num-late", G_TYPE_UINT64, (guint64) 1, + "num-duplicates", G_TYPE_UINT64, (guint64) 0, + "rtx-count", G_TYPE_UINT64, (guint64) 1, + "rtx-success-count", G_TYPE_UINT64, (guint64) 0, + "rtx-per-packet", G_TYPE_DOUBLE, 1.0, + "rtx-rtt", G_TYPE_UINT64, (guint64) (now - last_rtx_request), + NULL))); + + gst_object_unref (testclock); + gst_harness_teardown (h); +} + +GST_END_TEST; + +GST_START_TEST (test_rtx_original_buffer_does_not_update_rtx_stats) +{ + GstHarness *h = gst_harness_new ("rtpjitterbuffer"); + GstTestClock *testclock; + gint latency_ms = 5 * PCMU_BUF_MS; + gint num_init_buffers = latency_ms / PCMU_BUF_MS + 1; + GstBuffer *buffer; + GstClockTime now, last_rtx_request; + + testclock = gst_harness_get_testclock (h); + gst_harness_set_src_caps (h, generate_caps ()); + g_object_set (h->element, "do-retransmission", TRUE, "latency", latency_ms, + "rtx-max-retries", 1, NULL); + + /* Push/pull buffers and advance time past buffer 0's timeout (in order to + * simplify the test) */ + for (gint i = 0; i < num_init_buffers; i++) { + gst_test_clock_set_time (testclock, i * PCMU_BUF_DURATION); + fail_unless_equals_int (GST_FLOW_OK, + gst_harness_push (h, generate_test_buffer (i))); + gst_harness_wait_for_clock_id_waits (h, 1, 60); + } + + gst_harness_crank_single_clock_wait (h); + fail_unless_equals_int64 (latency_ms * GST_MSECOND, + gst_clock_get_time (GST_CLOCK (testclock))); + + for (gint i = 0; i < num_init_buffers; i++) + gst_buffer_unref (gst_harness_pull (h)); + + /* drop reconfigure event */ + gst_event_unref (gst_harness_pull_upstream_event (h)); + + /* Crank clock to send retransmission events requesting seqnum 6 which has + * not arrived yet. */ + gst_harness_crank_single_clock_wait (h); + verify_rtx_event (gst_harness_pull_upstream_event (h), + 6, 6 * PCMU_BUF_DURATION, 10, PCMU_BUF_DURATION); + + last_rtx_request = gst_clock_get_time (GST_CLOCK (testclock)); + fail_unless_equals_int64 (last_rtx_request, 130 * GST_MSECOND); + + /* ORIGINAL seqnum 6 arrives just before it times out and is considered + * lost. */ + now = 200 * GST_MSECOND; + gst_test_clock_set_time (testclock, now); + fail_unless_equals_int (GST_FLOW_OK, gst_harness_push (h, + generate_test_buffer_full (now, TRUE, 6, 6 * PCMU_RTP_TS_DURATION))); + buffer = gst_harness_pull (h); + fail_unless_equals_int (6, get_rtp_seq_num (buffer)); + gst_buffer_unref (buffer); + + /* The original buffer does not count in the RTX stats. */ + fail_unless (verify_jb_stats (h->element, + gst_structure_new ("application/x-rtp-jitterbuffer-stats", + "num-pushed", G_TYPE_UINT64, (guint64) num_init_buffers + 1, + "num-lost", G_TYPE_UINT64, (guint64) 0, + "num-late", G_TYPE_UINT64, (guint64) 0, + "num-duplicates", G_TYPE_UINT64, (guint64) 0, + "rtx-count", G_TYPE_UINT64, (guint64) 1, + "rtx-success-count", G_TYPE_UINT64, (guint64) 0, + "rtx-per-packet", G_TYPE_DOUBLE, 0.0, + "rtx-rtt", G_TYPE_UINT64, (guint64) 0, NULL))); + + /* Now the retransmitted packet arrives and stats should be updated. Note + * that the buffer arrives in time and should not be considered late, but + * a duplicate. */ + fail_unless_equals_int (GST_FLOW_OK, gst_harness_push (h, + generate_test_buffer_rtx (now, 6))); + fail_unless (verify_jb_stats (h->element, + gst_structure_new ("application/x-rtp-jitterbuffer-stats", + "num-pushed", G_TYPE_UINT64, (guint64) num_init_buffers + 1, + "num-lost", G_TYPE_UINT64, (guint64) 0, + "num-late", G_TYPE_UINT64, (guint64) 0, + "num-duplicates", G_TYPE_UINT64, (guint64) 1, + "rtx-count", G_TYPE_UINT64, (guint64) 1, + "rtx-success-count", G_TYPE_UINT64, (guint64) 0, + "rtx-per-packet", G_TYPE_DOUBLE, 1.0, + "rtx-rtt", G_TYPE_UINT64, (guint64) (now - last_rtx_request), + NULL))); + + gst_object_unref (testclock); + gst_harness_teardown (h); +} + +GST_END_TEST; + +GST_START_TEST (test_rtx_duplicate_packet_updates_rtx_stats) +{ + GstHarness *h = gst_harness_new ("rtpjitterbuffer"); + GstTestClock *testclock; + gint latency_ms = 5 * PCMU_BUF_MS; + gint num_init_buffers = latency_ms / PCMU_BUF_MS + 1; + GstClockTime now, rtx_request_6, rtx_request_7; + gint rtx_delay_ms; + + testclock = gst_harness_get_testclock (h); + gst_harness_set_src_caps (h, generate_caps ()); + g_object_set (h->element, "do-retransmission", TRUE, "latency", latency_ms, + NULL); + + /* Push/pull buffers and advance time past buffer 0's timeout (in order to + * simplify the test) */ + for (gint i = 0; i < num_init_buffers; i++) { + gst_test_clock_set_time (testclock, i * PCMU_BUF_DURATION); + fail_unless_equals_int (GST_FLOW_OK, + gst_harness_push (h, generate_test_buffer (i))); + gst_harness_wait_for_clock_id_waits (h, 1, 60); + } + + gst_harness_crank_single_clock_wait (h); + fail_unless_equals_int64 (latency_ms * GST_MSECOND, + gst_clock_get_time (GST_CLOCK (testclock))); + + for (gint i = 0; i < num_init_buffers; i++) + gst_buffer_unref (gst_harness_pull (h)); + + /* Drop reconfigure event */ + gst_event_unref (gst_harness_pull_upstream_event (h)); + + /* Push packet 8 so that 6 and 7 is missing */ + fail_unless_equals_int (GST_FLOW_OK, + gst_harness_push (h, generate_test_buffer (8))); + + /* Wait for NACKs on 6 and 7 */ + gst_harness_crank_single_clock_wait (h); + rtx_delay_ms = 10; + verify_rtx_event (gst_harness_pull_upstream_event (h), + 6, 6 * PCMU_BUF_DURATION, rtx_delay_ms, PCMU_BUF_DURATION); + rtx_request_6 = gst_clock_get_time (GST_CLOCK (testclock)); + fail_unless_equals_int64 (rtx_request_6, + 6 * PCMU_BUF_DURATION + rtx_delay_ms * GST_MSECOND); + + gst_harness_crank_single_clock_wait (h); + verify_rtx_event (gst_harness_pull_upstream_event (h), + 7, 7 * PCMU_BUF_DURATION, 0, PCMU_BUF_DURATION); + rtx_request_7 = gst_clock_get_time (GST_CLOCK (testclock)); + fail_unless_equals_int64 (rtx_request_7, + 7 * PCMU_BUF_DURATION); + + /* Original packet 7 arrives */ + now = 150 * GST_MSECOND; + gst_test_clock_set_time (testclock, now); + fail_unless_equals_int (GST_FLOW_OK, gst_harness_push (h, + generate_test_buffer_full (now, TRUE, 7, 7 * PCMU_RTP_TS_DURATION))); + + /* We're still waiting for packet 6, so 7 should not be pushed */ + gst_harness_wait_for_clock_id_waits (h, 1, 60); + fail_unless_equals_int (gst_harness_buffers_in_queue (h), 0); + + /* The original buffer does not count in the RTX stats. */ + fail_unless (verify_jb_stats (h->element, + gst_structure_new ("application/x-rtp-jitterbuffer-stats", + "num-lost", G_TYPE_UINT64, (guint64) 0, + "num-late", G_TYPE_UINT64, (guint64) 0, + "num-duplicates", G_TYPE_UINT64, (guint64) 0, + "rtx-count", G_TYPE_UINT64, (guint64) 2, + "rtx-success-count", G_TYPE_UINT64, (guint64) 0, + "rtx-per-packet", G_TYPE_DOUBLE, 0.0, + "rtx-rtt", G_TYPE_UINT64, (guint64) 0, NULL))); + + /* Push RTX packet 7. Should be dropped as duplicate but update RTX stats. */ + now = 160 * GST_MSECOND; + gst_test_clock_set_time (testclock, now); + fail_unless_equals_int (GST_FLOW_OK, gst_harness_push (h, + generate_test_buffer_rtx (now, 7))); + gst_harness_wait_for_clock_id_waits (h, 1, 60); + fail_unless_equals_int (gst_harness_buffers_in_queue (h), 0); + + /* Check RTX stats with updated num-duplicates and rtx-rtt fields */ + fail_unless (verify_jb_stats (h->element, + gst_structure_new ("application/x-rtp-jitterbuffer-stats", + "num-pushed", G_TYPE_UINT64, (guint64) num_init_buffers, + "num-lost", G_TYPE_UINT64, (guint64) 0, + "num-late", G_TYPE_UINT64, (guint64) 0, + "num-duplicates", G_TYPE_UINT64, (guint64) 1, + "rtx-count", G_TYPE_UINT64, (guint64) 2, + "rtx-success-count", G_TYPE_UINT64, (guint64) 0, + "rtx-per-packet", G_TYPE_DOUBLE, 1.0, + "rtx-rtt", G_TYPE_UINT64, (guint64) (now - rtx_request_7), + NULL))); + + /* RTX packet 6 arrives, both 6, 7 and 8 is ready to be pulled */ + fail_unless_equals_int (GST_FLOW_OK, gst_harness_push (h, + generate_test_buffer_rtx (now, 6))); + + for (gint i = 6; i <= 8; i++) { + GstBuffer *buf = gst_harness_pull (h); + fail_unless_equals_int (i, get_rtp_seq_num (buf)); + gst_buffer_unref (buf); + } + + /* RTX stats is updated with success count increased. */ + fail_unless (verify_jb_stats (h->element, + gst_structure_new ("application/x-rtp-jitterbuffer-stats", + "num-pushed", G_TYPE_UINT64, (guint64) num_init_buffers + 3, + "num-lost", G_TYPE_UINT64, (guint64) 0, + "num-late", G_TYPE_UINT64, (guint64) 0, + "num-duplicates", G_TYPE_UINT64, (guint64) 1, + "rtx-count", G_TYPE_UINT64, (guint64) 2, + "rtx-success-count", G_TYPE_UINT64, (guint64) 1, + "rtx-per-packet", G_TYPE_DOUBLE, 1.0, + "rtx-rtt", G_TYPE_UINT64, (guint64) + /* Use the rtx-rtt formula. Can be subject to change though. */ + ((now - rtx_request_6) + 7 * (now - rtx_request_7)) / 8, NULL))); + + gst_object_unref (testclock); + gst_harness_teardown (h); +} + +GST_END_TEST; + +GST_START_TEST (test_rtx_buffer_arrives_after_lost_updates_rtx_stats) +{ + GstHarness *h = gst_harness_new ("rtpjitterbuffer"); + GstTestClock *testclock; + gint latency_ms = 5 * PCMU_BUF_MS; + gint num_init_buffers = latency_ms / PCMU_BUF_MS + 1; + GstClockTime now, last_rtx_request; + + testclock = gst_harness_get_testclock (h); + gst_harness_set_src_caps (h, generate_caps ()); + g_object_set (h->element, "do-retransmission", TRUE, "latency", latency_ms, + "do-lost", TRUE, "rtx-max-retries", 1, NULL); + + /* Push/pull buffers and advance time past buffer 0's timeout (in order to + * simplify the test) */ + for (gint i = 0; i < num_init_buffers; i++) { + gst_test_clock_set_time (testclock, i * PCMU_BUF_DURATION); + fail_unless_equals_int (GST_FLOW_OK, + gst_harness_push (h, generate_test_buffer (i))); + gst_harness_wait_for_clock_id_waits (h, 1, 60); + } + + gst_harness_crank_single_clock_wait (h); + fail_unless_equals_int64 (latency_ms * GST_MSECOND, + gst_clock_get_time (GST_CLOCK (testclock))); + + for (gint i = 0; i < num_init_buffers; i++) + gst_buffer_unref (gst_harness_pull (h)); + + /* drop reconfigure event */ + gst_event_unref (gst_harness_pull_upstream_event (h)); + /* drop GstEventStreamStart & GstEventCaps & GstEventSegment */ + for (gint i = 0; i < 3; i++) + gst_event_unref (gst_harness_pull_event (h)); + + /* Crank clock to send retransmission events requesting seqnum 6 which has + * not arrived yet. */ + gst_harness_crank_single_clock_wait (h); + verify_rtx_event (gst_harness_pull_upstream_event (h), + 6, 6 * PCMU_BUF_DURATION, 10, PCMU_BUF_DURATION); + + last_rtx_request = gst_clock_get_time (GST_CLOCK (testclock)); + fail_unless_equals_int64 (last_rtx_request, 130 * GST_MSECOND); + + /* seqnum 6 is considered lost */ + gst_harness_crank_single_clock_wait (h); + verify_lost_event (gst_harness_pull_event (h), 6, + 6 * PCMU_BUF_DURATION, PCMU_BUF_DURATION); + + /* seqnum 6 arrives too late */ + now = gst_clock_get_time (GST_CLOCK (testclock)); + fail_unless_equals_int (GST_FLOW_OK, gst_harness_push (h, + generate_test_buffer_rtx (now, 6))); + + fail_unless (verify_jb_stats (h->element, + gst_structure_new ("application/x-rtp-jitterbuffer-stats", + "num-pushed", G_TYPE_UINT64, (guint64) num_init_buffers, + "num-lost", G_TYPE_UINT64, (guint64) 1, + "num-late", G_TYPE_UINT64, (guint64) 1, + "num-duplicates", G_TYPE_UINT64, (guint64) 0, + "rtx-count", G_TYPE_UINT64, (guint64) 1, + "rtx-success-count", G_TYPE_UINT64, (guint64) 0, + "rtx-per-packet", G_TYPE_DOUBLE, 1.0, + "rtx-rtt", G_TYPE_UINT64, (guint64) (now - last_rtx_request), + NULL))); + + gst_object_unref (testclock); + gst_harness_teardown (h); +} + +GST_END_TEST; + +GST_START_TEST (test_rtx_rtt_larger_than_retry_timeout) +{ + /* When RTT is larger than retry period we will send two or more requests + * before receiving any retransmission packets */ + GstHarness *h = gst_harness_new ("rtpjitterbuffer"); + GstTestClock *testclock; + gint latency_ms = 100; + gint num_init_buffers = latency_ms / PCMU_BUF_MS + 1; + gint rtx_retry_timeout_ms = 20; + gint rtx_delay_ms = 10; + gint rtt = rtx_retry_timeout_ms * GST_MSECOND + 1; + GstClockTime now, first_request, second_request; + + testclock = gst_harness_get_testclock (h); + gst_harness_set_src_caps (h, generate_caps ()); + g_object_set (h->element, "do-retransmission", TRUE, "latency", latency_ms, + "rtx-retry-timeout", rtx_retry_timeout_ms, NULL); + + /* Push/pull buffers and advance time past buffer 0's timeout (in order to + * simplify the test) */ + for (gint i = 0; i < num_init_buffers; i++) { + gst_test_clock_set_time (testclock, i * PCMU_BUF_DURATION); + fail_unless_equals_int (GST_FLOW_OK, + gst_harness_push (h, generate_test_buffer (i))); + gst_harness_wait_for_clock_id_waits (h, 1, 60); + } + + gst_harness_crank_single_clock_wait (h); + fail_unless_equals_int64 (latency_ms * GST_MSECOND, + gst_clock_get_time (GST_CLOCK (testclock))); + + for (gint i = 0; i < num_init_buffers; i++) + gst_buffer_unref (gst_harness_pull (h)); + + /* Drop reconfigure event */ + gst_event_unref (gst_harness_pull_upstream_event (h)); + + /* Wait for first NACK on 6 */ + gst_harness_crank_single_clock_wait (h); + verify_rtx_event (gst_harness_pull_upstream_event (h), + 6, 6 * PCMU_BUF_DURATION, rtx_delay_ms, PCMU_BUF_DURATION); + first_request = gst_clock_get_time (GST_CLOCK (testclock)); + fail_unless_equals_int64 (first_request, + 6 * PCMU_BUF_DURATION + rtx_delay_ms * GST_MSECOND); + + /* Packet 7 arrives in time (so that we avoid its EXPECTED timers to + * interfer with our test) */ + gst_test_clock_set_time (testclock, 7 * PCMU_BUF_DURATION); + fail_unless_equals_int (GST_FLOW_OK, + gst_harness_push (h, generate_test_buffer (7))); + + /* Simulating RTT > rtx-retry-timeout, we send a new NACK before receiving + * the RTX packet. Wait for second NACK on 6 */ + gst_harness_crank_single_clock_wait (h); + verify_rtx_event (gst_harness_pull_upstream_event (h), + 6, 6 * PCMU_BUF_DURATION, rtx_delay_ms, PCMU_BUF_DURATION); + second_request = gst_clock_get_time (GST_CLOCK (testclock)); + fail_unless_equals_int64 (second_request, + 6 * PCMU_BUF_DURATION + (rtx_delay_ms + rtx_retry_timeout_ms) * GST_MSECOND); + + /* The first retransmitted packet arrives */ + now = first_request + rtt; + gst_test_clock_set_time (testclock, now); + fail_unless_equals_int (GST_FLOW_OK, gst_harness_push (h, + generate_test_buffer_rtx (now, 6))); + + /* Pull packet 6 and 7 */ + gst_buffer_unref (gst_harness_pull (h)); + gst_buffer_unref (gst_harness_pull (h)); + + /* Stats should be updated. Note that RTT is not updated since we cannot be + * sure whether the RTX packet is in response to the first or second NACK. */ + fail_unless (verify_jb_stats (h->element, + gst_structure_new ("application/x-rtp-jitterbuffer-stats", + "num-pushed", G_TYPE_UINT64, (guint64) num_init_buffers + 2, + "num-lost", G_TYPE_UINT64, (guint64) 0, + "num-late", G_TYPE_UINT64, (guint64) 0, + "num-duplicates", G_TYPE_UINT64, (guint64) 0, + "rtx-count", G_TYPE_UINT64, (guint64) 2, + "rtx-success-count", G_TYPE_UINT64, (guint64) 1, + "rtx-per-packet", G_TYPE_DOUBLE, 2.0, + "rtx-rtt", G_TYPE_UINT64, (guint64) 0, NULL))); + + /* Packet 8 arrives in time */ + gst_test_clock_set_time (testclock, 8 * PCMU_BUF_DURATION); + fail_unless_equals_int (GST_FLOW_OK, + gst_harness_push (h, generate_test_buffer (8))); + gst_buffer_unref (gst_harness_pull (h)); + + /* Now the second retransmitted packet arrives */ + now = second_request + rtt; + gst_test_clock_set_time (testclock, now); + fail_unless_equals_int (GST_FLOW_OK, gst_harness_push (h, + generate_test_buffer_rtx (now, 6))); + + /* The stats is updated with the correct RTT. */ + fail_unless (verify_jb_stats (h->element, + gst_structure_new ("application/x-rtp-jitterbuffer-stats", + "num-pushed", G_TYPE_UINT64, (guint64) num_init_buffers + 3, + "num-lost", G_TYPE_UINT64, (guint64) 0, + "num-late", G_TYPE_UINT64, (guint64) 0, + "num-duplicates", G_TYPE_UINT64, (guint64) 1, + "rtx-count", G_TYPE_UINT64, (guint64) 2, + "rtx-success-count", G_TYPE_UINT64, (guint64) 1, + "rtx-per-packet", G_TYPE_DOUBLE, 2.0, + "rtx-rtt", G_TYPE_UINT64, (guint64) rtt, NULL))); + + gst_object_unref (testclock); + gst_harness_teardown (h); +} + +GST_END_TEST; + GST_START_TEST (test_gap_exceeds_latency) { GstHarness *h = gst_harness_new ("rtpjitterbuffer"); @@ -1378,11 +1925,10 @@ GST_START_TEST (test_gap_exceeds_latency) fail_unless (verify_jb_stats (h->element, gst_structure_new ("application/x-rtp-jitterbuffer-stats", "num-pushed", G_TYPE_UINT64, (guint64) 11, - "num-lost", G_TYPE_UINT64, (guint64)7, - "rtx-count", G_TYPE_UINT64, (guint64)21, - "rtx-success-count", G_TYPE_UINT64, (guint64)5, - "rtx-rtt", G_TYPE_UINT64, (guint64)0, - NULL))); + "num-lost", G_TYPE_UINT64, (guint64) 7, + "rtx-count", G_TYPE_UINT64, (guint64) 21, + "rtx-success-count", G_TYPE_UINT64, (guint64) 0, + "rtx-rtt", G_TYPE_UINT64, (guint64) 0, NULL))); gst_object_unref (testclock); gst_harness_teardown (h); @@ -1615,6 +2161,40 @@ GST_START_TEST (test_considered_lost_packet_in_large_gap_arrives) GST_END_TEST; +GST_START_TEST (test_performance) +{ + GstHarness *h = + gst_harness_new_parse + ("rtpjitterbuffer do-lost=1 do-retransmission=1 latency=1000"); + GTimer *timer = g_timer_new (); + const gdouble test_duration = 2.0; + guint buffers_pushed = 0; + guint buffers_received; + + gst_harness_set_src_caps (h, generate_caps ()); + gst_harness_use_systemclock (h); + + while (g_timer_elapsed (timer, NULL) < test_duration) { + /* Simulate 1ms packets */ + guint n = buffers_pushed * 2; // every packet also produces a gap + guint16 seqnum = n & 0xffff; + guint32 rtp_ts = n * 8; + GstClockTime dts = n * GST_MSECOND; + gst_harness_push (h, generate_test_buffer_full (dts, TRUE, seqnum, rtp_ts)); + buffers_pushed++; + g_usleep (G_USEC_PER_SEC / 10000); + } + g_timer_destroy (timer); + + buffers_received = gst_harness_buffers_received (h); + GST_INFO ("Pushed %d, received %d (%.1f%%)", buffers_pushed, buffers_received, + 100.0 * buffers_received / buffers_pushed); + + gst_harness_teardown (h); +} + +GST_END_TEST; + static Suite * rtpjitterbuffer_suite (void) { @@ -1627,15 +2207,24 @@ rtpjitterbuffer_suite (void) tcase_add_test (tc_chain, test_push_unordered); tcase_add_test (tc_chain, test_basetime); tcase_add_test (tc_chain, test_clear_pt_map); + tcase_add_test (tc_chain, test_only_one_lost_event_on_large_gaps); tcase_add_test (tc_chain, test_two_lost_one_arrives_in_time); tcase_add_test (tc_chain, test_late_packets_still_makes_lost_events); tcase_add_test (tc_chain, test_all_packets_are_timestamped_zero); tcase_add_loop_test (tc_chain, test_num_late_when_considered_lost_arrives, 0, 2); + tcase_add_test (tc_chain, test_rtx_expected_next); tcase_add_test (tc_chain, test_rtx_two_missing); tcase_add_test (tc_chain, test_rtx_packet_delay); + tcase_add_test (tc_chain, test_rtx_buffer_arrives_just_in_time); + tcase_add_test (tc_chain, test_rtx_buffer_arrives_too_late); + tcase_add_test (tc_chain, test_rtx_original_buffer_does_not_update_rtx_stats); + tcase_add_test (tc_chain, test_rtx_duplicate_packet_updates_rtx_stats); + tcase_add_test (tc_chain, test_rtx_buffer_arrives_after_lost_updates_rtx_stats); + tcase_add_test (tc_chain, test_rtx_rtt_larger_than_retry_timeout); + tcase_add_test (tc_chain, test_gap_exceeds_latency); tcase_add_test (tc_chain, test_deadline_ts_offset); tcase_add_test (tc_chain, test_dts_gap_larger_than_latency); @@ -1645,6 +2234,8 @@ rtpjitterbuffer_suite (void) test_considered_lost_packet_in_large_gap_arrives, 0, G_N_ELEMENTS (test_considered_lost_packet_in_large_gap_arrives_input)); + tcase_add_test (tc_chain, test_performance); + return s; }