rtpjitterbuffer: don't send multiple instant RTX for the same packet

Due to us not properly acknowleding the time when the last RTX was sent
when scheduling a new one, it can easily happen that due to the packet
you are requesting have a PTS that is slightly old (but not too old when
adding the latency of the jitterbuffer), both its calculated second and
third (etc.) timeout could already have passed. This would lead to a burst
of RTX requests, which acts completely against its purpose, potentially
spending a lot more bandwidth than needed.

This has been properly reproduced in the test:
test_rtx_not_bursting_requests

The good news is that slightly re-thinking the logic concerning
re-requesting RTX, made it a lot simpler to understand, and allows us
to remove two members of the RtpTimer which no longer serves any purpose
due to the refactoring. If desirable the whole "delay" concept can actually
be removed completely from the timers, and simply just added to the timeout
by the caller of the API. But that can be a change for a another time.

The only external change (other than the improved behavior around bursting
RTX) is that the "delay" field now stricly represents the delay between
the PTS of the RTX-requested packet and the time it is requested on,
whereas before this calculation was more about the theoretical calculated
delay. This is visible in three other RTX-tests where the delay had
to be adjusted slightly. I am confident however that this change is
correct.

Part-of: <https://gitlab.freedesktop.org/gstreamer/gst-plugins-good/-/merge_requests/789>

diff --git a/gst/rtpmanager/gstrtpjitterbuffer.c b/gst/rtpmanager/gstrtpjitterbuffer.c
index f9c3aef..8046988 100644 (file)
--- a/gst/rtpmanager/gstrtpjitterbuffer.c
+++ b/gst/rtpmanager/gstrtpjitterbuffer.c
@@ -3777,6 +3777,7 @@ do_expected_timeout (GstRtpJitterBuffer * jitterbuffer, RtpTimer * timer,
   GstClockTime rtx_retry_timeout;
   GstClock *clock;
   GstClockTimeDiff offset = 0;
+  GstClockTime timeout;
 
   GST_DEBUG_OBJECT (jitterbuffer, "expected %d didn't arrive, now %"
       GST_TIME_FORMAT, timer->seqnum, GST_TIME_ARGS (now));
@@ -3784,7 +3785,8 @@ do_expected_timeout (GstRtpJitterBuffer * jitterbuffer, RtpTimer * timer,
   rtx_retry_timeout = get_rtx_retry_timeout (priv);
   rtx_retry_period = get_rtx_retry_period (priv, rtx_retry_timeout);
 
-  delay = timer->rtx_delay + timer->rtx_retry;
+  /* delay expresses how late this packet is currently */
+  delay = now - timer->rtx_base;
 
   delay_ms = GST_TIME_AS_MSECONDS (delay);
   rtx_retry_timeout_ms = GST_TIME_AS_MSECONDS (rtx_retry_timeout);
@@ -3819,28 +3821,33 @@ do_expected_timeout (GstRtpJitterBuffer * jitterbuffer, RtpTimer * timer,
   }
   GST_OBJECT_UNLOCK (jitterbuffer);
 
-  /* calculate the timeout for the next retransmission attempt */
-  timer->rtx_retry += rtx_retry_timeout;
-  GST_DEBUG_OBJECT (jitterbuffer, "timer #%i base %" GST_TIME_FORMAT ", delay %"
-      GST_TIME_FORMAT ", retry %" GST_TIME_FORMAT ", num_retry %u",
-      timer->seqnum, GST_TIME_ARGS (timer->rtx_base),
-      GST_TIME_ARGS (timer->rtx_delay), GST_TIME_ARGS (timer->rtx_retry),
-      timer->num_rtx_retry);
+  /*
+     Calculate the timeout for the next retransmission attempt:
+     We have just successfully sent one RTX request, and we need to
+     find out when to schedule the next one.
+
+     The rtx_retry_timeout tells us the logical timeout between RTX
+     requests based on things like round-trip time, jitter and packet spacing,
+     and is how long we are going to wait before attempting another RTX packet
+   */
+  timeout = timer->rtx_last + rtx_retry_timeout;
+  GST_DEBUG_OBJECT (jitterbuffer,
+      "timer #%i new timeout %" GST_TIME_FORMAT ", rtx retry timeout%"
+      GST_TIME_FORMAT ", num_retry %u", timer->seqnum, GST_TIME_ARGS (timeout),
+      GST_TIME_ARGS (rtx_retry_timeout), timer->num_rtx_retry);
   if ((priv->rtx_max_retries != -1
           && timer->num_rtx_retry >= priv->rtx_max_retries)
-      || (timer->rtx_retry + timer->rtx_delay > rtx_retry_period)
-      || (timer->rtx_base + rtx_retry_period < now)) {
+      || (timeout > timer->rtx_base + rtx_retry_period)) {
     GST_DEBUG_OBJECT (jitterbuffer, "reschedule #%i as LOST timer",
         timer->seqnum);
     /* too many retransmission request, we now convert the timer
      * to a lost timer, leave the num_rtx_retry as it is for stats */
     timer->type = RTP_TIMER_LOST;
-    timer->rtx_delay = 0;
-    timer->rtx_retry = 0;
+    timeout = timer->rtx_base;
     offset = timeout_offset (jitterbuffer);
   }
   rtp_timer_queue_update_timer (priv->timers, timer, timer->seqnum,
-      timer->rtx_base + timer->rtx_retry, timer->rtx_delay, offset, FALSE);
+      timeout, 0, offset, FALSE);
 
   return FALSE;
 }

diff --git a/gst/rtpmanager/rtptimerqueue.c b/gst/rtpmanager/rtptimerqueue.c
index 446a70e..7b13657 100644 (file)
--- a/gst/rtpmanager/rtptimerqueue.c
+++ b/gst/rtpmanager/rtptimerqueue.c
@@ -582,8 +582,6 @@ rtp_timer_queue_set_timer (RtpTimerQueue * queue, RtpTimerType type,
   if (!timer->queued || timer->seqnum != seqnum) {
     if (type == RTP_TIMER_EXPECTED) {
       timer->rtx_base = timeout;
-      timer->rtx_delay = delay;
-      timer->rtx_retry = 0;
     }
 
     timer->rtx_last = GST_CLOCK_TIME_NONE;
@@ -702,11 +700,9 @@ rtp_timer_queue_update_timer (RtpTimerQueue * queue, RtpTimer * timer,
   g_return_if_fail (timer != NULL);
 
   if (reset) {
-    GST_DEBUG ("reset rtx delay %" GST_TIME_FORMAT "->%" GST_TIME_FORMAT,
-        GST_TIME_ARGS (timer->rtx_delay), GST_TIME_ARGS (delay));
+    GST_DEBUG ("reset rtx base %" GST_TIME_FORMAT "->%" GST_TIME_FORMAT,
+        GST_TIME_ARGS (timer->rtx_base), GST_TIME_ARGS (timeout));
     timer->rtx_base = timeout;
-    timer->rtx_delay = delay;
-    timer->rtx_retry = 0;
   }
 
   if (timer->seqnum != seqnum) {

diff --git a/gst/rtpmanager/rtptimerqueue.h b/gst/rtpmanager/rtptimerqueue.h
index 969cbd3..283f228 100644 (file)
--- a/gst/rtpmanager/rtptimerqueue.h
+++ b/gst/rtpmanager/rtptimerqueue.h
@@ -65,8 +65,6 @@ typedef struct
   GstClockTimeDiff offset;
   GstClockTime duration;
   GstClockTime rtx_base;
-  GstClockTime rtx_delay;
-  GstClockTime rtx_retry;
   GstClockTime rtx_last;
   guint num_rtx_retry;
   guint num_rtx_received;

diff --git a/tests/check/elements/rtpjitterbuffer.c b/tests/check/elements/rtpjitterbuffer.c
index 99cc57c..6097ef1 100644 (file)
--- a/tests/check/elements/rtpjitterbuffer.c
+++ b/tests/check/elements/rtpjitterbuffer.c
@@ -1318,6 +1318,46 @@ GST_START_TEST (test_rtx_expected_next)
 
 GST_END_TEST;
 
+GST_START_TEST (test_rtx_not_bursting_requests)
+{
+  GstHarness *h = gst_harness_new ("rtpjitterbuffer");
+  gint latency_ms = 200;
+  guint next_seqnum;
+  guint missing_seqnum;
+  GstClockTime now;
+
+  g_object_set (h->element,
+      "do-lost", TRUE,
+      "do-retransmission", TRUE,
+      "rtx-next-seqnum", FALSE, "rtx-max-retries", 3, NULL);
+
+  next_seqnum = construct_deterministic_initial_state (h, latency_ms);
+  now = gst_clock_get_time (GST_ELEMENT_CLOCK (h->element));
+
+  /* skip a packet and move the time for the next one
+     quite a bit forward */
+  missing_seqnum = next_seqnum;
+  next_seqnum++;
+  now += 150 * GST_MSECOND;
+  gst_harness_set_time (h, now);
+
+  push_test_buffer_now (h, next_seqnum, next_seqnum * TEST_RTP_TS_DURATION,
+      FALSE);
+
+  /* note the delay here is 130. This is because we advanced the clock 150,
+     and 20 of those were the duration of the missing seqnum, so this
+     RTX event is in effect 130ms "late" compared to its ideal time */
+  verify_rtx_event (h, missing_seqnum,
+      missing_seqnum * TEST_BUF_DURATION, 130, TEST_BUF_DURATION);
+
+  /* verify we have not sent any other rtx events */
+  fail_unless_equals_int (0, gst_harness_upstream_events_in_queue (h));
+
+  gst_harness_teardown (h);
+}
+
+GST_END_TEST;
+
 GST_START_TEST (test_rtx_next_seqnum_disabled)
 {
   GstHarness *h = gst_harness_new ("rtpjitterbuffer");
@@ -1623,7 +1663,7 @@ GST_START_TEST (test_rtx_original_buffer_does_not_update_rtx_stats)
      an rtx-request for 7 */
   next_seqnum++;
   verify_rtx_event (h, next_seqnum,
-      next_seqnum * TEST_BUF_DURATION, rtx_delay_ms, TEST_BUF_DURATION);
+      next_seqnum * TEST_BUF_DURATION, 60, TEST_BUF_DURATION);
 
   /* The original buffer does not count in the RTX stats. */
   fail_unless (verify_jb_stats (h->element,
@@ -1950,7 +1990,7 @@ GST_START_TEST (test_rtx_no_request_if_time_past_retry_period)
    * late and unnecessary. However, in order to keep things simple (for now)
    * we just keep the already scehduled EXPECTED timer, but refrain from
    * scheduled another EXPECTED timer */
-  verify_rtx_event (h, 2, 2 * TEST_BUF_DURATION, 10, TEST_BUF_DURATION);
+  verify_rtx_event (h, 2, 2 * TEST_BUF_DURATION, 120, TEST_BUF_DURATION);
 
   /* "crank" to reach the DEADLINE for packet 0 */
   gst_harness_crank_single_clock_wait (h);
@@ -2067,7 +2107,7 @@ GST_START_TEST (test_rtx_with_backwards_rtptime)
   gst_harness_set_time (h, 6 * TEST_BUF_DURATION + 15 * GST_MSECOND);
   gst_harness_crank_single_clock_wait (h);
   verify_rtx_event (h, 6, 5 * TEST_BUF_DURATION + 15 * GST_MSECOND,
-      17, 35 * GST_MSECOND);
+      20, 35 * GST_MSECOND);
 
   fail_unless (verify_jb_stats (h->element,
           gst_structure_new ("application/x-rtp-jitterbuffer-stats",
@@ -3180,6 +3220,8 @@ rtpjitterbuffer_suite (void)
       test_loss_equidistant_spacing_with_parameter_packets);
 
   tcase_add_test (tc_chain, test_rtx_expected_next);
+  tcase_add_test (tc_chain, test_rtx_not_bursting_requests);
+
   tcase_add_test (tc_chain, test_rtx_next_seqnum_disabled);
   tcase_add_test (tc_chain, test_rtx_two_missing);
   tcase_add_test (tc_chain, test_rtx_buffer_arrives_just_in_time);

diff --git a/tests/check/elements/rtptimerqueue.c b/tests/check/elements/rtptimerqueue.c
index a39da7f..30a9dd6 100644 (file)
--- a/tests/check/elements/rtptimerqueue.c
+++ b/tests/check/elements/rtptimerqueue.c
@@ -37,8 +37,6 @@ GST_START_TEST (test_timer_queue_set_timer)
   fail_unless_equals_uint64 (3 * GST_SECOND, timer10->timeout);
   fail_unless_equals_uint64 (5 * GST_SECOND, timer10->duration);
   fail_unless_equals_uint64 (1 * GST_SECOND, timer10->rtx_base);
-  fail_unless_equals_uint64 (2 * GST_SECOND, timer10->rtx_delay);
-  fail_unless_equals_uint64 (0, timer10->rtx_retry);
   fail_unless_equals_uint64 (GST_CLOCK_TIME_NONE, timer10->rtx_last);
   fail_unless_equals_int (0, timer10->num_rtx_retry);
   fail_unless_equals_int (0, timer10->num_rtx_received);
@@ -52,8 +50,6 @@ GST_START_TEST (test_timer_queue_set_timer)
   fail_unless_equals_uint64 (2 * GST_SECOND, timer0->timeout);
   fail_unless_equals_uint64 (0, timer0->duration);
   fail_unless_equals_uint64 (0, timer0->rtx_base);
-  fail_unless_equals_uint64 (0, timer0->rtx_delay);
-  fail_unless_equals_uint64 (0, timer0->rtx_retry);
   fail_unless_equals_uint64 (GST_CLOCK_TIME_NONE, timer0->rtx_last);
   fail_unless_equals_int (0, timer0->num_rtx_retry);
   fail_unless_equals_int (0, timer0->num_rtx_received);