From 1a4393fb4d29a296b8c131041b46f25de8698c1b Mon Sep 17 00:00:00 2001 From: Havard Graff Date: Thu, 3 Nov 2016 15:03:59 +0100 Subject: [PATCH] rtpjitterbuffer: fix timer-reuse bug When doing rtx, the jitterbuffer will always add an rtx-timer for the next sequence number. In the case of the packet corresponding to that sequence number arriving, that same timer will be reused, and simply moved on to wait for the following sequence number etc. Once an rtx-timer expires (after all retries), it will be rescheduled as a lost-timer instead for the same sequence number. Now, if this particular sequence-number now arrives (after the timer has become a lost-timer), the reuse mechanism *should* now set a new rtx-timer for the next sequence number, but the bug is that it does not change the timer-type, and hence schedules a lost-timer for that following sequence number, with the result that you will have a very early lost-event for a packet that might still arrive, and you will never be able to send any rtx for this packet. Found by Erlend Graff - erlend@pexip.com https://bugzilla.gnome.org/show_bug.cgi?id=773891 --- gst/rtpmanager/gstrtpjitterbuffer.c | 1 + tests/check/elements/rtpjitterbuffer.c | 62 +++++++++++++++++++++++++- 2 files changed, 61 insertions(+), 2 deletions(-) diff --git a/gst/rtpmanager/gstrtpjitterbuffer.c b/gst/rtpmanager/gstrtpjitterbuffer.c index c85400c40b..a6e0b3af85 100644 --- a/gst/rtpmanager/gstrtpjitterbuffer.c +++ b/gst/rtpmanager/gstrtpjitterbuffer.c @@ -2372,6 +2372,7 @@ update_timers (GstRtpJitterBuffer * jitterbuffer, guint16 seqnum, GST_TIME_ARGS (priv->packet_spacing), GST_TIME_ARGS (priv->avg_jitter)); if (timer) { + timer->type = TIMER_TYPE_EXPECTED; reschedule_timer (jitterbuffer, timer, priv->next_in_seqnum, expected, delay, TRUE); } else { diff --git a/tests/check/elements/rtpjitterbuffer.c b/tests/check/elements/rtpjitterbuffer.c index 66b570cc6a..095fb1648d 100644 --- a/tests/check/elements/rtpjitterbuffer.c +++ b/tests/check/elements/rtpjitterbuffer.c @@ -1683,6 +1683,11 @@ GST_START_TEST (test_rtx_original_buffer_does_not_update_rtx_stats) fail_unless_equals_int (6, get_rtp_seq_num (buffer)); gst_buffer_unref (buffer); + /* due to the advance in time, we will now also have sent + an rtx-request for 7 */ + verify_rtx_event (gst_harness_pull_upstream_event (h), + 7, 7 * PCMU_BUF_DURATION, 10, PCMU_BUF_DURATION); + /* 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", @@ -1690,7 +1695,7 @@ GST_START_TEST (test_rtx_original_buffer_does_not_update_rtx_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) 1, + "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))); @@ -1706,7 +1711,7 @@ GST_START_TEST (test_rtx_original_buffer_does_not_update_rtx_stats) "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-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 - last_rtx_request), @@ -2252,6 +2257,58 @@ arrival(dts): 3 5 5 GST_END_TEST; +GST_START_TEST (test_rtx_timer_reuse) +{ + 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; + + 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)); + + /* crank to timeout the only rtx-request, and the timer will + * now reschedule as a lost-timer internally */ + 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); + + /* but now buffer 6 arrives, and this should now reuse the lost-timer + * for 6, as an expected-timer for 7 */ + fail_unless_equals_int (GST_FLOW_OK, + gst_harness_push (h, generate_test_buffer (6))); + + /* now crank to timeout the expected-timer for 7 and verify */ + gst_harness_crank_single_clock_wait (h); + verify_rtx_event (gst_harness_pull_upstream_event (h), + 7, 7 * PCMU_BUF_DURATION, 10, PCMU_BUF_DURATION); + + gst_object_unref (testclock); + gst_harness_teardown (h); +} + +GST_END_TEST; GST_START_TEST (test_gap_exceeds_latency) { @@ -2701,6 +2758,7 @@ rtpjitterbuffer_suite (void) tcase_add_test (tc_chain, test_rtx_no_request_if_time_past_retry_period); tcase_add_test (tc_chain, test_rtx_same_delay_and_retry_timeout); tcase_add_test (tc_chain, test_rtx_with_backwards_rtptime); + tcase_add_test (tc_chain, test_rtx_timer_reuse); tcase_add_test (tc_chain, test_gap_exceeds_latency); tcase_add_test (tc_chain, test_deadline_ts_offset);