From f5f03e823c2d522e84fce46bc8a7d57f913032ba Mon Sep 17 00:00:00 2001 From: deadbeef Date: Mon, 6 Jun 2016 11:16:06 -0700 Subject: [PATCH] Reland of: Improving the fake clock and using it to fix a flaky STUN timeout test. When the fake clock's time is advanced, it now ensures all pending queued messages have been dispatched. This allows us to write a "SIMULATED_WAIT" macro that ticks the simulated clock by milliseconds up until the target time. Useful in this case, where we know the STUN timeout should take a total of 9500ms, but it would be overly complex to write test code that waits for each individual timeout, ensures a STUN packet has been retransmited, etc. (The test described above *should* be written, but it belongs in p2ptransportchannel_unittest.cc, not webrtcsession_unittest.cc). Review-Url: https://codereview.webrtc.org/2024813004 Cr-Commit-Position: refs/heads/master@{#13052} --- webrtc/api/webrtcsession_unittest.cc | 18 +++++----- webrtc/base/base_tests.gyp | 3 ++ webrtc/base/fakeclock.cc | 20 ++++++++--- webrtc/base/fakeclock.h | 13 +++++++ webrtc/base/gunit.h | 54 +++++++++++++++++++++++++--- webrtc/base/messagequeue.cc | 42 ++++++++++++---------- webrtc/base/messagequeue.h | 13 ++++--- webrtc/base/signalthread_unittest.cc | 3 ++ webrtc/base/timeutils.cc | 4 ++- webrtc/base/timeutils.h | 8 +++-- webrtc/base/timeutils_unittest.cc | 25 ++++++------- webrtc/webrtc_tests.gypi | 3 -- 12 files changed, 144 insertions(+), 62 deletions(-) diff --git a/webrtc/api/webrtcsession_unittest.cc b/webrtc/api/webrtcsession_unittest.cc index 088694cb16..1907b8410c 100644 --- a/webrtc/api/webrtcsession_unittest.cc +++ b/webrtc/api/webrtcsession_unittest.cc @@ -109,6 +109,8 @@ static const int kMediaContentIndex1 = 1; static const char kMediaContentName1[] = "video"; static const int kIceCandidatesTimeout = 10000; +// STUN timeout with all retransmissions is a total of 9500ms. +static const int kStunTimeout = 9500; static const char kFakeDtlsFingerprint[] = "BB:CD:72:F7:2F:D0:BA:43:F3:68:B1:0C:23:72:B6:4A:" @@ -1504,13 +1506,9 @@ TEST_F(WebRtcSessionTest, TestMultihomeCandidates) { EXPECT_EQ(8u, observer_.mline_1_candidates_.size()); } -// Crashes on Win only. See webrtc:5411. -#if defined(WEBRTC_WIN) -#define MAYBE_TestStunError DISABLED_TestStunError -#else -#define MAYBE_TestStunError TestStunError -#endif -TEST_F(WebRtcSessionTest, MAYBE_TestStunError) { +TEST_F(WebRtcSessionTest, TestStunError) { + rtc::ScopedFakeClock clock; + AddInterface(rtc::SocketAddress(kClientAddrHost1, kClientAddrPort)); AddInterface(rtc::SocketAddress(kClientAddrHost2, kClientAddrPort)); fss_->AddRule(false, @@ -1521,9 +1519,13 @@ TEST_F(WebRtcSessionTest, MAYBE_TestStunError) { SendAudioVideoStream1(); InitiateCall(); // Since kClientAddrHost1 is blocked, not expecting stun candidates for it. - EXPECT_TRUE_WAIT(observer_.oncandidatesready_, kIceCandidatesTimeout); + EXPECT_TRUE_SIMULATED_WAIT(observer_.oncandidatesready_, kStunTimeout, clock); EXPECT_EQ(6u, observer_.mline_0_candidates_.size()); EXPECT_EQ(6u, observer_.mline_1_candidates_.size()); + // Destroy session before scoped fake clock goes out of scope to avoid TSan + // warning. + session_->Close(); + session_.reset(nullptr); } TEST_F(WebRtcSessionTest, SetSdpFailedOnInvalidSdp) { diff --git a/webrtc/base/base_tests.gyp b/webrtc/base/base_tests.gyp index 2ee115b267..003a1dbf87 100644 --- a/webrtc/base/base_tests.gyp +++ b/webrtc/base/base_tests.gyp @@ -15,6 +15,8 @@ 'unittest_main.cc', # Also use this as a convenient dumping ground for misc files that are # included by multiple targets below. + 'fakeclock.cc', + 'fakeclock.h', 'fakenetwork.h', 'fakesslidentity.h', 'faketaskrunner.h', @@ -22,6 +24,7 @@ 'testbase64.h', 'testechoserver.h', 'testutils.h', + 'timedelta.h', ], 'defines': [ 'GTEST_RELATIVE_PATH', diff --git a/webrtc/base/fakeclock.cc b/webrtc/base/fakeclock.cc index e5aa3bc0a4..bcd720ff74 100644 --- a/webrtc/base/fakeclock.cc +++ b/webrtc/base/fakeclock.cc @@ -27,14 +27,24 @@ void FakeClock::SetTimeNanos(uint64_t nanos) { time_ = nanos; } // If message queues are waiting in a socket select() with a timeout provided - // by the OS, they should wake up to check if there are any messages ready to - // be dispatched based on the fake time. - MessageQueueManager::WakeAllMessageQueues(); + // by the OS, they should wake up and dispatch all messages that are ready. + MessageQueueManager::ProcessAllMessageQueues(); } void FakeClock::AdvanceTime(TimeDelta delta) { - CritScope cs(&lock_); - SetTimeNanos(time_ + delta.ToNanoseconds()); + { + CritScope cs(&lock_); + time_ += delta.ToNanoseconds(); + } + MessageQueueManager::ProcessAllMessageQueues(); +} + +ScopedFakeClock::ScopedFakeClock() { + prev_clock_ = SetClockForTesting(this); +} + +ScopedFakeClock::~ScopedFakeClock() { + SetClockForTesting(prev_clock_); } } // namespace rtc diff --git a/webrtc/base/fakeclock.h b/webrtc/base/fakeclock.h index 2b3afdde05..4aecc54cc4 100644 --- a/webrtc/base/fakeclock.h +++ b/webrtc/base/fakeclock.h @@ -19,6 +19,8 @@ namespace rtc { // Fake clock for use with unit tests, which does not tick on its own. // Starts at time 0. +// +// TODO(deadbeef): Unify with webrtc::SimulatedClock. class FakeClock : public ClockInterface { public: ~FakeClock() override {} @@ -38,6 +40,17 @@ class FakeClock : public ClockInterface { uint64_t time_ GUARDED_BY(lock_) = 0u; }; +// Helper class that sets itself as the global clock in its constructor and +// unsets it in its destructor. +class ScopedFakeClock : public FakeClock { + public: + ScopedFakeClock(); + ~ScopedFakeClock() override; + + private: + ClockInterface* prev_clock_; +}; + } // namespace rtc #endif // WEBRTC_BASE_FAKECLOCK_H_ diff --git a/webrtc/base/gunit.h b/webrtc/base/gunit.h index e705322e6f..5ba0bd916e 100644 --- a/webrtc/base/gunit.h +++ b/webrtc/base/gunit.h @@ -11,6 +11,7 @@ #ifndef WEBRTC_BASE_GUNIT_H_ #define WEBRTC_BASE_GUNIT_H_ +#include "webrtc/base/fakeclock.h" #include "webrtc/base/logging.h" #include "webrtc/base/thread.h" #if defined(GTEST_RELATIVE_PATH) @@ -20,10 +21,12 @@ #endif // Wait until "ex" is true, or "timeout" expires. -#define WAIT(ex, timeout) \ - for (int64_t start = rtc::TimeMillis(); \ - !(ex) && rtc::TimeMillis() < start + timeout;) \ - rtc::Thread::Current()->ProcessMessages(1); +#define WAIT(ex, timeout) \ + for (int64_t start = rtc::TimeMillis(); \ + !(ex) && rtc::TimeMillis() < start + timeout;) { \ + rtc::Thread::Current()->ProcessMessages(0); \ + rtc::Thread::Current()->SleepMs(1); \ + } // This returns the result of the test in res, so that we don't re-evaluate // the expression in the XXXX_WAIT macros below, since that causes problems @@ -33,7 +36,8 @@ int64_t start = rtc::TimeMillis(); \ res = (ex); \ while (!res && rtc::TimeMillis() < start + timeout) { \ - rtc::Thread::Current()->ProcessMessages(1); \ + rtc::Thread::Current()->ProcessMessages(0); \ + rtc::Thread::Current()->SleepMs(1); \ res = (ex); \ } \ } while (0) @@ -85,4 +89,44 @@ } \ } while (0) +// Wait until "ex" is true, or "timeout" expires, using fake clock where +// messages are processed every millisecond. +#define SIMULATED_WAIT(ex, timeout, clock) \ + for (int64_t start = rtc::TimeMillis(); \ + !(ex) && rtc::TimeMillis() < start + timeout;) { \ + clock.AdvanceTime(rtc::TimeDelta::FromMilliseconds(1)); \ + } + +// This returns the result of the test in res, so that we don't re-evaluate +// the expression in the XXXX_WAIT macros below, since that causes problems +// when the expression is only true the first time you check it. +#define SIMULATED_WAIT_(ex, timeout, res, clock) \ + do { \ + int64_t start = rtc::TimeMillis(); \ + res = (ex); \ + while (!res && rtc::TimeMillis() < start + timeout) { \ + clock.AdvanceTime(rtc::TimeDelta::FromMilliseconds(1)); \ + res = (ex); \ + } \ + } while (0) + +// The typical EXPECT_XXXX, but done until true or a timeout with a fake clock. +#define EXPECT_TRUE_SIMULATED_WAIT(ex, timeout, clock) \ + do { \ + bool res; \ + SIMULATED_WAIT_(ex, timeout, res, clock); \ + if (!res) { \ + EXPECT_TRUE(ex); \ + } \ + } while (0) + +#define EXPECT_EQ_SIMULATED_WAIT(v1, v2, timeout, clock) \ + do { \ + bool res; \ + SIMULATED_WAIT_(v1 == v2, timeout, res, clock); \ + if (!res) { \ + EXPECT_EQ(v1, v2); \ + } \ + } while (0) + #endif // WEBRTC_BASE_GUNIT_H_ diff --git a/webrtc/base/messagequeue.cc b/webrtc/base/messagequeue.cc index da50e2304f..4c2331bfe6 100644 --- a/webrtc/base/messagequeue.cc +++ b/webrtc/base/messagequeue.cc @@ -9,17 +9,14 @@ */ #include +#include "webrtc/base/atomicops.h" #include "webrtc/base/checks.h" #include "webrtc/base/common.h" #include "webrtc/base/logging.h" #include "webrtc/base/messagequeue.h" +#include "webrtc/base/thread.h" #include "webrtc/base/trace_event.h" -namespace { - -enum { MSG_WAKE_MESSAGE_QUEUE = 1 }; -} - namespace rtc { const int kMaxMsgLatency = 150; // 150 ms @@ -41,8 +38,7 @@ bool MessageQueueManager::IsInitialized() { return instance_ != NULL; } -MessageQueueManager::MessageQueueManager() { -} +MessageQueueManager::MessageQueueManager() {} MessageQueueManager::~MessageQueueManager() { } @@ -108,26 +104,36 @@ void MessageQueueManager::ClearInternal(MessageHandler *handler) { (*iter)->Clear(handler); } -void MessageQueueManager::WakeAllMessageQueues() { +void MessageQueueManager::ProcessAllMessageQueues() { if (!instance_) { return; } - return Instance()->WakeAllMessageQueuesInternal(); + return Instance()->ProcessAllMessageQueuesInternal(); } -void MessageQueueManager::WakeAllMessageQueuesInternal() { +void MessageQueueManager::ProcessAllMessageQueuesInternal() { #if CS_DEBUG_CHECKS // CurrentThreadIsOwner returns true by default. ASSERT(!crit_.CurrentThreadIsOwner()); // See note above. #endif - CritScope cs(&crit_); - for (MessageQueue* queue : message_queues_) { - // Posting an arbitrary message will force the message queue to wake up. - queue->Post(this, MSG_WAKE_MESSAGE_QUEUE); + // Post a delayed message at the current time and wait for it to be dispatched + // on all queues, which will ensure that all messages that came before it were + // also dispatched. + volatile int queues_not_done; + auto functor = [&queues_not_done] { AtomicOps::Decrement(&queues_not_done); }; + FunctorMessageHandler handler(functor); + { + CritScope cs(&crit_); + queues_not_done = static_cast(message_queues_.size()); + for (MessageQueue* queue : message_queues_) { + queue->PostDelayed(0, &handler); + } + } + // Note: One of the message queues may have been on this thread, which is why + // we can't synchronously wait for queues_not_done to go to 0; we need to + // process messages as well. + while (AtomicOps::AcquireLoad(&queues_not_done) > 0) { + rtc::Thread::Current()->ProcessMessages(0); } -} - -void MessageQueueManager::OnMessage(Message* pmsg) { - RTC_DCHECK(pmsg->message_id == MSG_WAKE_MESSAGE_QUEUE); } //------------------------------------------------------------------ diff --git a/webrtc/base/messagequeue.h b/webrtc/base/messagequeue.h index 3a5226cd0a..bf110376b5 100644 --- a/webrtc/base/messagequeue.h +++ b/webrtc/base/messagequeue.h @@ -37,7 +37,7 @@ class MessageQueue; // MessageQueueManager does cleanup of of message queues -class MessageQueueManager : public MessageHandler { +class MessageQueueManager { public: static void Add(MessageQueue *message_queue); static void Remove(MessageQueue *message_queue); @@ -50,21 +50,20 @@ class MessageQueueManager : public MessageHandler { static bool IsInitialized(); // Mainly for testing purposes, for use with a simulated clock. - // Posts a no-op event on all message queues so they will wake from the - // socket server select() and process messages again. - static void WakeAllMessageQueues(); + // Ensures that all message queues have processed delayed messages + // up until the current point in time. + static void ProcessAllMessageQueues(); private: static MessageQueueManager* Instance(); MessageQueueManager(); - ~MessageQueueManager() override; + ~MessageQueueManager(); void AddInternal(MessageQueue *message_queue); void RemoveInternal(MessageQueue *message_queue); void ClearInternal(MessageHandler *handler); - void WakeAllMessageQueuesInternal(); - void OnMessage(Message* pmsg) override; + void ProcessAllMessageQueuesInternal(); static MessageQueueManager* instance_; // This list contains all live MessageQueues. diff --git a/webrtc/base/signalthread_unittest.cc b/webrtc/base/signalthread_unittest.cc index bbae91daf0..0029acf5d9 100644 --- a/webrtc/base/signalthread_unittest.cc +++ b/webrtc/base/signalthread_unittest.cc @@ -140,6 +140,9 @@ class OwnerThread : public Thread, public sigslot::has_slots<> { // signal thread is still working. This may happen // when shutting down the process. TEST_F(SignalThreadTest, OwnerThreadGoesAway) { + // We don't use |thread_| for this test, so destroy it. + thread_->Destroy(true); + { std::unique_ptr owner(new OwnerThread(this)); main_thread_ = owner.get(); diff --git a/webrtc/base/timeutils.cc b/webrtc/base/timeutils.cc index ecd0911a51..3c89d808b3 100644 --- a/webrtc/base/timeutils.cc +++ b/webrtc/base/timeutils.cc @@ -32,8 +32,10 @@ namespace rtc { ClockInterface* g_clock = nullptr; -void SetClock(ClockInterface* clock) { +ClockInterface* SetClockForTesting(ClockInterface* clock) { + ClockInterface* prev = g_clock; g_clock = clock; + return prev; } uint64_t TimeNanos() { diff --git a/webrtc/base/timeutils.h b/webrtc/base/timeutils.h index 78ebacee38..113793ade3 100644 --- a/webrtc/base/timeutils.h +++ b/webrtc/base/timeutils.h @@ -39,8 +39,10 @@ class ClockInterface { // Sets the global source of time. This is useful mainly for unit tests. // -// Does not transfer ownership of the clock. -// SetClock(nullptr) should be called before the ClockInterface is deleted. +// Returns the previously set ClockInterface, or nullptr if none is set. +// +// Does not transfer ownership of the clock. SetClockForTesting(nullptr) +// should be called before the ClockInterface is deleted. // // This method is not thread-safe; it should only be used when no other thread // is running (for example, at the start/end of a unit test, or start/end of @@ -49,7 +51,7 @@ class ClockInterface { // TODO(deadbeef): Instead of having functions that access this global // ClockInterface, we may want to pass the ClockInterface into everything // that uses it, eliminating the need for a global variable and this function. -void SetClock(ClockInterface* clock); +ClockInterface* SetClockForTesting(ClockInterface* clock); // Returns the current time in milliseconds in 32 bits. uint32_t Time32(); diff --git a/webrtc/base/timeutils_unittest.cc b/webrtc/base/timeutils_unittest.cc index f183684e6c..d1cfe23821 100644 --- a/webrtc/base/timeutils_unittest.cc +++ b/webrtc/base/timeutils_unittest.cc @@ -301,7 +301,7 @@ TEST(TimeDelta, NumericOperators) { // fake clock when it's set. TEST(FakeClock, TimeFunctionsUseFakeClock) { FakeClock clock; - SetClock(&clock); + SetClockForTesting(&clock); clock.SetTimeNanos(987654321u); EXPECT_EQ(987u, Time32()); @@ -310,7 +310,7 @@ TEST(FakeClock, TimeFunctionsUseFakeClock) { EXPECT_EQ(987654321u, TimeNanos()); EXPECT_EQ(1000u, TimeAfter(13)); - SetClock(nullptr); + SetClockForTesting(nullptr); // After it's unset, we should get a normal time. EXPECT_NE(987, TimeMillis()); } @@ -348,7 +348,7 @@ TEST(FakeClock, SettingTimeWakesThreads) { int64_t real_start_time_ms = TimeMillis(); FakeClock clock; - SetClock(&clock); + SetClockForTesting(&clock); Thread worker; worker.Start(); @@ -359,24 +359,25 @@ TEST(FakeClock, SettingTimeWakesThreads) { message_handler_dispatched.Set(); }; FunctorMessageHandler handler(functor); - worker.PostDelayed(10000, &handler); + worker.PostDelayed(60000, &handler); // Wait for a bit for the worker thread to be started and enter its socket - // select(). + // select(). Otherwise this test would be trivial since the worker thread + // would process the event as soon as it was started. Thread::Current()->SleepMs(1000); // Advance the fake clock, expecting the worker thread to wake up - // and dispatch the message quickly. - clock.AdvanceTime(TimeDelta::FromSeconds(10u)); - message_handler_dispatched.Wait(Event::kForever); + // and dispatch the message instantly. + clock.AdvanceTime(TimeDelta::FromSeconds(60u)); + EXPECT_TRUE(message_handler_dispatched.Wait(0)); worker.Stop(); - SetClock(nullptr); + SetClockForTesting(nullptr); - // The message should have been dispatched long before the 10 seconds fully - // elapsed. + // The message should have been dispatched long before the 60 seconds fully + // elapsed (just a sanity check). int64_t real_end_time_ms = TimeMillis(); - EXPECT_LT(real_end_time_ms - real_start_time_ms, 2000); + EXPECT_LT(real_end_time_ms - real_start_time_ms, 10000); } } // namespace rtc diff --git a/webrtc/webrtc_tests.gypi b/webrtc/webrtc_tests.gypi index 4177cfeb5e..e9f24456ca 100644 --- a/webrtc/webrtc_tests.gypi +++ b/webrtc/webrtc_tests.gypi @@ -39,8 +39,6 @@ 'base/event_tracer_unittest.cc', 'base/event_unittest.cc', 'base/exp_filter_unittest.cc', - 'base/fakeclock.cc', - 'base/fakeclock.h', 'base/filerotatingstream_unittest.cc', 'base/fileutils_unittest.cc', 'base/helpers_unittest.cc', @@ -90,7 +88,6 @@ 'base/testclient_unittest.cc', 'base/thread_checker_unittest.cc', 'base/thread_unittest.cc', - 'base/timedelta.h', 'base/timeutils_unittest.cc', 'base/urlencode_unittest.cc', 'base/versionparsing_unittest.cc',