From 731d1cabeb6a06ca3c72f8c6d0b42fef57622813 Mon Sep 17 00:00:00 2001 From: Danil Chapovalov Date: Tue, 7 Nov 2017 12:39:00 +0100 Subject: [PATCH] Reduce flakiness of asynchronous RtcpTransceiver tests Restructure tests to never wait for no packets, Greatly increase wait timeout. (Reduce expectation of synchronous primitives precision) Bug: webrtc:8494 Change-Id: I9a80fda3a2bf527d8b7337ecabaf625e543b8c62 Reviewed-on: https://webrtc-review.googlesource.com/20502 Reviewed-by: Niels Moller Commit-Queue: Danil Chapovalov Cr-Commit-Position: refs/heads/master@{#20584} --- .../source/rtcp_transceiver_impl_unittest.cc | 90 ++++++++++++------- 1 file changed, 58 insertions(+), 32 deletions(-) diff --git a/modules/rtp_rtcp/source/rtcp_transceiver_impl_unittest.cc b/modules/rtp_rtcp/source/rtcp_transceiver_impl_unittest.cc index 9e9464468b..d712225d03 100644 --- a/modules/rtp_rtcp/source/rtcp_transceiver_impl_unittest.cc +++ b/modules/rtp_rtcp/source/rtcp_transceiver_impl_unittest.cc @@ -38,6 +38,15 @@ class MockReceiveStatisticsProvider : public webrtc::ReceiveStatisticsProvider { MOCK_METHOD1(RtcpReportBlocks, std::vector(size_t)); }; +// Since some tests will need to wait for this period, make it small to avoid +// slowing tests too much. As long as there are test bots with high scheduler +// granularity, small period should be ok. +constexpr int kReportPeriodMs = 10; +// On some systems task queue might be slow, instead of guessing right +// grace period, use very large timeout, 100x larger expected wait time. +// Use finite timeout to fail tests rather than hang them. +constexpr int kAlmostForeverMs = 1000; + // Helper to wait for an rtcp packet produced on a different thread/task queue. class FakeRtcpTransport : public webrtc::Transport { public: @@ -51,16 +60,21 @@ class FakeRtcpTransport : public webrtc::Transport { return true; } - // Returns true if packet was received by this transport before timeout, - bool WaitPacket(int64_t timeout_ms) { return sent_rtcp_.Wait(timeout_ms); } + // Returns true when packet was received by the transport. + bool WaitPacket() { + // Normally packet should be sent fast, long before the timeout. + bool packet_sent = sent_rtcp_.Wait(kAlmostForeverMs); + // Disallow tests to wait almost forever for no packets. + EXPECT_TRUE(packet_sent); + // Return wait result even though it is expected to be true, so that + // individual tests can EXPECT on it for better error message. + return packet_sent; + } private: rtc::Event sent_rtcp_; }; -// Posting delayed tasks doesn't promise high precision. -constexpr int64_t kTaskQueuePrecisionMs = 15; - TEST(RtcpTransceiverImplTest, DelaysSendingFirstCompondPacket) { rtc::TaskQueue queue("rtcp"); FakeRtcpTransport transport; @@ -72,8 +86,7 @@ TEST(RtcpTransceiverImplTest, DelaysSendingFirstCompondPacket) { int64_t started_ms = rtc::TimeMillis(); queue.PostTask([&] { rtcp_transceiver.emplace(config); }); - EXPECT_TRUE(transport.WaitPacket(config.initial_report_delay_ms + - kTaskQueuePrecisionMs)); + EXPECT_TRUE(transport.WaitPacket()); EXPECT_GE(rtc::TimeMillis() - started_ms, config.initial_report_delay_ms); @@ -83,7 +96,7 @@ TEST(RtcpTransceiverImplTest, DelaysSendingFirstCompondPacket) { rtcp_transceiver.reset(); done.Set(); }); - ASSERT_TRUE(done.Wait(/*milliseconds=*/100)); + ASSERT_TRUE(done.Wait(kAlmostForeverMs)); } TEST(RtcpTransceiverImplTest, PeriodicallySendsPackets) { @@ -92,19 +105,22 @@ TEST(RtcpTransceiverImplTest, PeriodicallySendsPackets) { RtcpTransceiverConfig config; config.outgoing_transport = &transport; config.initial_report_delay_ms = 0; - config.report_period_ms = 10; + config.report_period_ms = kReportPeriodMs; config.task_queue = &queue; rtc::Optional rtcp_transceiver; - queue.PostTask([&] { rtcp_transceiver.emplace(config); }); + int64_t time_just_before_1st_packet_ms = 0; + queue.PostTask([&] { + // Because initial_report_delay_ms is set to 0, time_just_before_the_packet + // should be very close to the time_of_the_packet. + time_just_before_1st_packet_ms = rtc::TimeMillis(); + rtcp_transceiver.emplace(config); + }); - EXPECT_TRUE(transport.WaitPacket(config.initial_report_delay_ms + - kTaskQueuePrecisionMs)); - int64_t time_of_1st_packet_ms = rtc::TimeMillis(); - EXPECT_TRUE( - transport.WaitPacket(config.report_period_ms + kTaskQueuePrecisionMs)); - int64_t time_of_2nd_packet_ms = rtc::TimeMillis(); + EXPECT_TRUE(transport.WaitPacket()); + EXPECT_TRUE(transport.WaitPacket()); + int64_t time_just_after_2nd_packet_ms = rtc::TimeMillis(); - EXPECT_GE(time_of_2nd_packet_ms - time_of_1st_packet_ms, + EXPECT_GE(time_just_after_2nd_packet_ms - time_just_before_1st_packet_ms, config.report_period_ms); // Cleanup. @@ -113,7 +129,7 @@ TEST(RtcpTransceiverImplTest, PeriodicallySendsPackets) { rtcp_transceiver.reset(); done.Set(); }); - ASSERT_TRUE(done.Wait(/*milliseconds=*/100)); + ASSERT_TRUE(done.Wait(kAlmostForeverMs)); } TEST(RtcpTransceiverImplTest, SendCompoundPacketDelaysPeriodicSendPackets) { @@ -122,24 +138,34 @@ TEST(RtcpTransceiverImplTest, SendCompoundPacketDelaysPeriodicSendPackets) { RtcpTransceiverConfig config; config.outgoing_transport = &transport; config.initial_report_delay_ms = 0; - config.report_period_ms = 10; + config.report_period_ms = kReportPeriodMs; config.task_queue = &queue; rtc::Optional rtcp_transceiver; queue.PostTask([&] { rtcp_transceiver.emplace(config); }); // Wait for first packet. - EXPECT_TRUE(transport.WaitPacket(config.initial_report_delay_ms + - kTaskQueuePrecisionMs)); - // Wait half-period time for next one - it shouldn't be sent. - EXPECT_FALSE(transport.WaitPacket(config.report_period_ms / 2)); - // Send packet now. - queue.PostTask([&] { rtcp_transceiver->SendCompoundPacket(); }); - EXPECT_TRUE(transport.WaitPacket(/*timeout_ms=*/1)); - int64_t time_of_non_periodic_packet_ms = rtc::TimeMillis(); - // Next packet should be sent at least after period_ms. - EXPECT_TRUE( - transport.WaitPacket(config.report_period_ms + kTaskQueuePrecisionMs)); - EXPECT_GE(rtc::TimeMillis() - time_of_non_periodic_packet_ms, + EXPECT_TRUE(transport.WaitPacket()); + // Send non periodic one after half period. + rtc::Event non_periodic(false, false); + int64_t time_of_non_periodic_packet_ms = 0; + queue.PostDelayedTask( + [&] { + time_of_non_periodic_packet_ms = rtc::TimeMillis(); + rtcp_transceiver->SendCompoundPacket(); + non_periodic.Set(); + }, + config.report_period_ms / 2); + // Though non-periodic packet is scheduled just in between periodic, due to + // small period and task queue flakiness it migth end-up 1ms after next + // periodic packet. To be sure duration after non-periodic packet is tested + // wait for transport after ensuring non-periodic packet was sent. + EXPECT_TRUE(non_periodic.Wait(kAlmostForeverMs)); + EXPECT_TRUE(transport.WaitPacket()); + // Wait for next periodic packet. + EXPECT_TRUE(transport.WaitPacket()); + int64_t time_of_last_periodic_packet_ms = rtc::TimeMillis(); + + EXPECT_GE(time_of_last_periodic_packet_ms - time_of_non_periodic_packet_ms, config.report_period_ms); // Cleanup. @@ -148,7 +174,7 @@ TEST(RtcpTransceiverImplTest, SendCompoundPacketDelaysPeriodicSendPackets) { rtcp_transceiver.reset(); done.Set(); }); - ASSERT_TRUE(done.Wait(/*milliseconds=*/100)); + ASSERT_TRUE(done.Wait(kAlmostForeverMs)); } TEST(RtcpTransceiverImplTest, SendsMinimalCompoundPacket) {