From d970d846d36924ad2caff52b50fc0240fb250171 Mon Sep 17 00:00:00 2001 From: Antonio Vicente Date: Mon, 22 Jun 2020 17:24:06 -0400 Subject: [PATCH 01/14] Run 0ms timeout timers on the next iteration of the event loop instead of the current iteration. Guarded by runtime feature "envoy.reloadable_features.activate_timers_next_event_loop" Signed-off-by: Antonio Vicente --- source/common/event/BUILD | 1 + source/common/event/libevent_scheduler.h | 43 +++ source/common/event/timer_impl.cc | 8 +- source/common/event/timer_impl.h | 5 + source/common/runtime/runtime_features.cc | 1 + .../quic_listeners/quiche/envoy_quic_alarm.cc | 3 +- test/common/event/BUILD | 1 + test/common/event/dispatcher_impl_test.cc | 347 ++++++++++++++---- test/test_common/BUILD | 1 + test/test_common/simulated_time_system.cc | 82 +++-- test/test_common/simulated_time_system.h | 10 +- .../test_common/simulated_time_system_test.cc | 72 ++-- 12 files changed, 444 insertions(+), 130 deletions(-) diff --git a/source/common/event/BUILD b/source/common/event/BUILD index 1a99e72fe7bd..23ccee3b5ff7 100644 --- a/source/common/event/BUILD +++ b/source/common/event/BUILD @@ -136,6 +136,7 @@ envoy_cc_library( ":libevent_lib", "//include/envoy/event:timer_interface", "//source/common/common:scope_tracker", + "//source/common/runtime:runtime_features_lib", ], ) diff --git a/source/common/event/libevent_scheduler.h b/source/common/event/libevent_scheduler.h index 748036114f5b..6059a0017bae 100644 --- a/source/common/event/libevent_scheduler.h +++ b/source/common/event/libevent_scheduler.h @@ -15,6 +15,49 @@ namespace Envoy { namespace Event { // Implements Scheduler based on libevent. +// +// Here is a rough summary of operations that libevent performs in each event loop iteration, in +// order. Note that the invocation order for "same-iteration" operations that execute as a group +// can be surprising and invocation order of expired timers is non-deterministic. +// Whenever possible, it is preferable to avoid making event invocation ordering assumptions. +// +// 1. Calculate the poll timeout by comparing the current time to the deadline of the closest +// timer (the one at head of the priority queue). +// 2. Run registered "prepare" callbacks. +// 3. Poll for fd events using the closest timer as timeout, add active fds to the work list. +// 4. Run registered "check" callbacks. +// 5. Check timer deadlines against current time and move expired timers from the timer priority +// queue to the work list. Expired timers are moved to the work list is a non-deterministic order. +// 6. Execute items in the work list until the list is empty. Note that additional work +// items could be added to the work list during execution of this step, more details below. +// 7. Goto 1 if the loop termination condition has not been reached +// +// The following "same-iteration" work items are added directly to the work list when they are +// scheduled so they execute in the current iteration of the event loop. Note that there are no +// ordering guarantees when mixing the mechanisms below. Specifically, it is unsafe to assume that +// calling post followed by deferredDelete will result in the post callback being invoked before the +// deferredDelete; deferredDelete will run first if there is a pending deferredDeletion at the time +// the post callback is scheduled because deferredDelete invocation is grouped. +// - Event::Dispatcher::post(cb). Post callbacks are invoked as a group. +// - Event::Dispatcher::deferredDelete(object) and Event::DeferredTaskUtil::deferredRun(...). +// The same mechanism implements both of these operations, so they are invoked as a group. +// - Event::SchedulableCallback::scheduleCallbackCurrentIteration(). Each of these callbacks is +// scheduled and invoked independently. +// - Event::FileEvent::activate() if "envoy.reloadable_features.activate_fds_next_event_loop" +// runtime feature is disabled. +// - Event::Timer::enableTimer(0) if "envoy.reloadable_features.activate_timers_next_event_loop" +// runtime feature is disabled. +// +// Event::FileEvent::activate and Event::SchedulableCallback::scheduleCallbackNextIteration are +// implemented as libevent timers with a deadline of 0. Both of these actions are moved to the work +// list while checking for expired timers during step 5. +// +// Events execute in the following order, derived from the order in which items were added to the +// work list: +// 0. Events added via event_active prior to the start of the event loop (in tests) +// 1. Fd events +// 2. Timers, FileEvent::activate and SchedulableCallback::scheduleCallbackNextIteration +// 3. "Same-iteration" work items described above, including Event::Dispatcher::post callbacks class LibeventScheduler : public Scheduler, public CallbackScheduler { public: using OnPrepareCallback = std::function; diff --git a/source/common/event/timer_impl.cc b/source/common/event/timer_impl.cc index 6c71f3cfe5ac..196887119569 100644 --- a/source/common/event/timer_impl.cc +++ b/source/common/event/timer_impl.cc @@ -3,6 +3,7 @@ #include #include "common/common/assert.h" +#include "common/runtime/runtime_features.h" #include "event2/event.h" @@ -10,7 +11,9 @@ namespace Envoy { namespace Event { TimerImpl::TimerImpl(Libevent::BasePtr& libevent, TimerCb cb, Dispatcher& dispatcher) - : cb_(cb), dispatcher_(dispatcher) { + : cb_(cb), dispatcher_(dispatcher), + activate_timers_next_event_loop_(Runtime::runtimeFeatureEnabled( + "envoy.reloadable_features.activate_timers_next_event_loop")) { ASSERT(cb_); evtimer_assign( &raw_event_, libevent.get(), @@ -44,7 +47,8 @@ void TimerImpl::enableHRTimer(const std::chrono::microseconds& d, void TimerImpl::internalEnableTimer(const timeval& tv, const ScopeTrackedObject* object) { object_ = object; - if (tv.tv_sec == 0 && tv.tv_usec == 0) { + + if (!activate_timers_next_event_loop_ && tv.tv_sec == 0 && tv.tv_usec == 0) { event_active(&raw_event_, EV_TIMEOUT, 0); } else { event_add(&raw_event_, &tv); diff --git a/source/common/event/timer_impl.h b/source/common/event/timer_impl.h index f9e980824269..307fb3fe80d7 100644 --- a/source/common/event/timer_impl.h +++ b/source/common/event/timer_impl.h @@ -70,6 +70,11 @@ class TimerImpl : public Timer, ImplBase { // example if the DispatcherImpl::post is called by two threads, they race to // both set this to null. std::atomic object_{}; + + // Latched "envoy.reloadable_features.activate_timers_next_event_loop" runtime feature. If true, + // timers scheduled with a 0 time delta are evaluated in the next iteration of the event loop + // after polling and activating new fd events. + const bool activate_timers_next_event_loop_; }; } // namespace Event diff --git a/source/common/runtime/runtime_features.cc b/source/common/runtime/runtime_features.cc index b2656438a2e1..5d0c36835792 100644 --- a/source/common/runtime/runtime_features.cc +++ b/source/common/runtime/runtime_features.cc @@ -61,6 +61,7 @@ constexpr const char* runtime_features[] = { "envoy.reloadable_features.reject_unsupported_transfer_encodings", // Begin alphabetically sorted section. "envoy.reloadable_features.activate_fds_next_event_loop", + "envoy.reloadable_features.activate_timers_next_event_loop", "envoy.deprecated_features.allow_deprecated_extension_names", "envoy.reloadable_features.disallow_unbounded_access_logs", "envoy.reloadable_features.early_errors_via_hcm", diff --git a/source/extensions/quic_listeners/quiche/envoy_quic_alarm.cc b/source/extensions/quic_listeners/quiche/envoy_quic_alarm.cc index e652b79a6120..349eb5f2a32b 100644 --- a/source/extensions/quic_listeners/quiche/envoy_quic_alarm.cc +++ b/source/extensions/quic_listeners/quiche/envoy_quic_alarm.cc @@ -18,7 +18,8 @@ void EnvoyQuicAlarm::SetImpl() { // loop. QUICHE alarm is not expected to be scheduled in current event loop. This bit is a bummer // in QUICHE, and we are working on the fix. Once QUICHE is fixed of expecting this behavior, we // no longer need to round up the duration. - // TODO(antoniovicente) improve the timer behavior in such case. + // TODO(antoniovicente) Remove the std::max(1, ...) when decommissioning the + // envoy.reloadable_features.activate_timers_next_event_loop runtime flag. timer_->enableHRTimer( std::chrono::microseconds(std::max(static_cast(1), duration.ToMicroseconds()))); } diff --git a/test/common/event/BUILD b/test/common/event/BUILD index 50a792f01804..b6032fe71825 100644 --- a/test/common/event/BUILD +++ b/test/common/event/BUILD @@ -21,6 +21,7 @@ envoy_cc_test( "//test/mocks:common_lib", "//test/mocks/stats:stats_mocks", "//test/test_common:simulated_time_system_lib", + "//test/test_common:test_runtime_lib", "//test/test_common:utility_lib", ], ) diff --git a/test/common/event/dispatcher_impl_test.cc b/test/common/event/dispatcher_impl_test.cc index a651162a3f03..2af503d12ea4 100644 --- a/test/common/event/dispatcher_impl_test.cc +++ b/test/common/event/dispatcher_impl_test.cc @@ -12,6 +12,7 @@ #include "test/mocks/common.h" #include "test/mocks/stats/mocks.h" #include "test/test_common/simulated_time_system.h" +#include "test/test_common/test_runtime.h" #include "test/test_common/utility.h" #include "gmock/gmock.h" @@ -25,6 +26,12 @@ namespace Envoy { namespace Event { namespace { +static void onWatcherReady(evwatch*, const evwatch_prepare_cb_info*, void* arg) { + // `arg` contains the ReadyWatcher passed in from evwatch_prepare_new. + auto watcher = static_cast(arg); + watcher->ready(); +} + class SchedulableCallbackImplTest : public testing::Test { protected: SchedulableCallbackImplTest() @@ -37,12 +44,6 @@ class SchedulableCallbackImplTest : public testing::Test { Api::ApiPtr api_; DispatcherPtr dispatcher_; std::vector callbacks_; - - static void onWatcherReady(evwatch*, const evwatch_prepare_cb_info*, void* arg) { - // `arg` contains the ReadyWatcher passed in from evwatch_prepare_new. - auto watcher = static_cast(arg); - watcher->ready(); - } }; TEST_F(SchedulableCallbackImplTest, ScheduleCurrentAndCancel) { @@ -472,34 +473,193 @@ TEST_F(DispatcherMonotonicTimeTest, ApproximateMonotonicTime) { dispatcher_->run(Dispatcher::RunType::Block); } -TEST(TimerImplTest, TimerEnabledDisabled) { - Api::ApiPtr api = Api::createApiForTest(); - DispatcherPtr dispatcher(api->allocateDispatcher("test_thread")); - Event::TimerPtr timer = dispatcher->createTimer([] {}); +class TimerImplTest : public testing::TestWithParam { +protected: + TimerImplTest() { + Runtime::LoaderSingleton::getExisting()->mergeValues( + {{"envoy.reloadable_features.activate_timers_next_event_loop", + activateTimersNextEventLoop() ? "true" : "false"}}); + // Watch for dispatcher prepare events. + evwatch_prepare_new(&static_cast(dispatcher_.get())->base(), onWatcherReady, + &prepare_watcher_); + } + + bool activateTimersNextEventLoop() { return GetParam(); } + + TestScopedRuntime scoped_runtime_; + Api::ApiPtr api_{Api::createApiForTest()}; + DispatcherPtr dispatcher_{api_->allocateDispatcher("test_thread")}; + ReadyWatcher prepare_watcher_; +}; + +INSTANTIATE_TEST_SUITE_P(DelayActivation, TimerImplTest, testing::Bool()); + +TEST_P(TimerImplTest, TimerEnabledDisabled) { + InSequence s; + + Event::TimerPtr timer = dispatcher_->createTimer([] {}); EXPECT_FALSE(timer->enabled()); timer->enableTimer(std::chrono::milliseconds(0)); EXPECT_TRUE(timer->enabled()); - dispatcher->run(Dispatcher::RunType::NonBlock); + EXPECT_CALL(prepare_watcher_, ready()); + dispatcher_->run(Dispatcher::RunType::NonBlock); EXPECT_FALSE(timer->enabled()); timer->enableHRTimer(std::chrono::milliseconds(0)); EXPECT_TRUE(timer->enabled()); - dispatcher->run(Dispatcher::RunType::NonBlock); + EXPECT_CALL(prepare_watcher_, ready()); + dispatcher_->run(Dispatcher::RunType::NonBlock); EXPECT_FALSE(timer->enabled()); } -// Timers scheduled at different times execute in order. -TEST(TimerImplTest, TimerOrdering) { - Api::ApiPtr api = Api::createApiForTest(); - DispatcherPtr dispatcher(api->allocateDispatcher("test_thread")); +TEST_P(TimerImplTest, ChangeTimerBackwardsBeforeRun) { + Event::TimerPtr timer = dispatcher_->createTimer([] {}); + EXPECT_FALSE(timer->enabled()); + timer->enableTimer(std::chrono::milliseconds(0)); ReadyWatcher watcher1; - Event::TimerPtr timer1 = dispatcher->createTimer([&] { watcher1.ready(); }); + Event::TimerPtr timer1 = dispatcher_->createTimer([&] { watcher1.ready(); }); ReadyWatcher watcher2; - Event::TimerPtr timer2 = dispatcher->createTimer([&] { watcher2.ready(); }); + Event::TimerPtr timer2 = dispatcher_->createTimer([&] { watcher2.ready(); }); ReadyWatcher watcher3; - Event::TimerPtr timer3 = dispatcher->createTimer([&] { watcher3.ready(); }); + Event::TimerPtr timer3 = dispatcher_->createTimer([&] { watcher3.ready(); }); + + timer1->enableTimer(std::chrono::milliseconds(0)); + timer2->enableTimer(std::chrono::milliseconds(1)); + timer3->enableTimer(std::chrono::milliseconds(2)); + timer2->enableTimer(std::chrono::milliseconds(3)); + timer1->enableTimer(std::chrono::milliseconds(4)); + + // Sleep for 5ms so timers above all trigger in the same loop iteration. + absl::SleepFor(absl::Milliseconds(5)); + + // Expect watcher3 to trigger first because the deadlines for timers 1 and 2 was moved backwards. + InSequence s; + EXPECT_CALL(prepare_watcher_, ready()); + EXPECT_CALL(watcher3, ready()); + EXPECT_CALL(watcher2, ready()); + EXPECT_CALL(watcher1, ready()); + dispatcher_->run(Dispatcher::RunType::Block); +} + +TEST_P(TimerImplTest, ChangeTimerForwardsToZeroBeforeRun) { + Event::TimerPtr timer = dispatcher_->createTimer([] {}); + EXPECT_FALSE(timer->enabled()); + timer->enableTimer(std::chrono::milliseconds(0)); + + ReadyWatcher watcher1; + Event::TimerPtr timer1 = dispatcher_->createTimer([&] { watcher1.ready(); }); + + ReadyWatcher watcher2; + Event::TimerPtr timer2 = dispatcher_->createTimer([&] { watcher2.ready(); }); + + timer1->enableTimer(std::chrono::milliseconds(2)); + timer2->enableTimer(std::chrono::milliseconds(1)); + timer1->enableTimer(std::chrono::milliseconds(0)); + + // Sleep for 5ms so timers above all trigger in the same loop iteration. + absl::SleepFor(absl::Milliseconds(5)); + + // Expect watcher1 to trigger first because timer1's deadline was moved forward. + InSequence s; + EXPECT_CALL(prepare_watcher_, ready()); + if (activateTimersNextEventLoop()) { + EXPECT_CALL(watcher1, ready()); + EXPECT_CALL(watcher2, ready()); + } else { + // Timers execute in the wrong order. + EXPECT_CALL(watcher2, ready()); + EXPECT_CALL(watcher1, ready()); + } + dispatcher_->run(Dispatcher::RunType::NonBlock); +} + +TEST_P(TimerImplTest, ChangeTimerForwardsToNonZeroBeforeRun) { + Event::TimerPtr timer = dispatcher_->createTimer([] {}); + EXPECT_FALSE(timer->enabled()); + timer->enableTimer(std::chrono::milliseconds(0)); + + ReadyWatcher watcher1; + Event::TimerPtr timer1 = dispatcher_->createTimer([&] { watcher1.ready(); }); + + ReadyWatcher watcher2; + Event::TimerPtr timer2 = dispatcher_->createTimer([&] { watcher2.ready(); }); + + timer1->enableTimer(std::chrono::milliseconds(3)); + timer2->enableTimer(std::chrono::milliseconds(2)); + timer1->enableTimer(std::chrono::milliseconds(1)); + + // Sleep for 5ms so timers above all trigger in the same loop iteration. + absl::SleepFor(absl::Milliseconds(5)); + + // Expect watcher1 to trigger first because timer1's deadline was moved forward. + InSequence s; + EXPECT_CALL(prepare_watcher_, ready()); + EXPECT_CALL(watcher1, ready()); + EXPECT_CALL(watcher2, ready()); + dispatcher_->run(Dispatcher::RunType::NonBlock); +} + +TEST_P(TimerImplTest, ChangeLargeTimerForwardToZeroBeforeRun) { + Event::TimerPtr timer = dispatcher_->createTimer([] {}); + EXPECT_FALSE(timer->enabled()); + timer->enableTimer(std::chrono::milliseconds(0)); + + ReadyWatcher watcher1; + Event::TimerPtr timer1 = dispatcher_->createTimer([&] { watcher1.ready(); }); + + ReadyWatcher watcher2; + Event::TimerPtr timer2 = dispatcher_->createTimer([&] { watcher2.ready(); }); + + timer1->enableTimer(std::chrono::seconds(2000)); + timer2->enableTimer(std::chrono::seconds(1000)); + timer1->enableTimer(std::chrono::seconds(0)); + + // Expect watcher1 to trigger because timer1's deadline was moved forward. + InSequence s; + EXPECT_CALL(prepare_watcher_, ready()); + EXPECT_CALL(watcher1, ready()); + EXPECT_CALL(prepare_watcher_, ready()); + dispatcher_->run(Dispatcher::RunType::NonBlock); +} + +TEST_P(TimerImplTest, ChangeLargeTimerForwardToNonZeroBeforeRun) { + Event::TimerPtr timer = dispatcher_->createTimer([] {}); + EXPECT_FALSE(timer->enabled()); + timer->enableTimer(std::chrono::milliseconds(0)); + + ReadyWatcher watcher1; + Event::TimerPtr timer1 = dispatcher_->createTimer([&] { watcher1.ready(); }); + + ReadyWatcher watcher2; + Event::TimerPtr timer2 = dispatcher_->createTimer([&] { watcher2.ready(); }); + + timer1->enableTimer(std::chrono::seconds(2000)); + timer2->enableTimer(std::chrono::seconds(1000)); + timer1->enableTimer(std::chrono::milliseconds(1)); + + // Sleep for 5ms so timers above all trigger in the same loop iteration. + absl::SleepFor(absl::Milliseconds(5)); + + // Expect watcher1 to trigger because timer1's deadline was moved forward. + InSequence s; + EXPECT_CALL(prepare_watcher_, ready()); + EXPECT_CALL(watcher1, ready()); + EXPECT_CALL(prepare_watcher_, ready()); + dispatcher_->run(Dispatcher::RunType::NonBlock); +} + +// Timers scheduled at different times execute in order. +TEST_P(TimerImplTest, TimerOrdering) { + ReadyWatcher watcher1; + Event::TimerPtr timer1 = dispatcher_->createTimer([&] { watcher1.ready(); }); + + ReadyWatcher watcher2; + Event::TimerPtr timer2 = dispatcher_->createTimer([&] { watcher2.ready(); }); + + ReadyWatcher watcher3; + Event::TimerPtr timer3 = dispatcher_->createTimer([&] { watcher3.ready(); }); timer1->enableTimer(std::chrono::milliseconds(0)); timer2->enableTimer(std::chrono::milliseconds(1)); @@ -514,25 +674,23 @@ TEST(TimerImplTest, TimerOrdering) { // Expect watcher calls to happen in order since timers have different times. InSequence s; + EXPECT_CALL(prepare_watcher_, ready()); EXPECT_CALL(watcher1, ready()); EXPECT_CALL(watcher2, ready()); EXPECT_CALL(watcher3, ready()); - dispatcher->run(Dispatcher::RunType::Block); + dispatcher_->run(Dispatcher::RunType::Block); } // Alarms that are scheduled to execute and are cancelled do not trigger. -TEST(TimerImplTest, TimerOrderAndDisableAlarm) { - Api::ApiPtr api = Api::createApiForTest(); - DispatcherPtr dispatcher(api->allocateDispatcher("test_thread")); - +TEST_P(TimerImplTest, TimerOrderAndDisableAlarm) { ReadyWatcher watcher3; - Event::TimerPtr timer3 = dispatcher->createTimer([&] { watcher3.ready(); }); + Event::TimerPtr timer3 = dispatcher_->createTimer([&] { watcher3.ready(); }); ReadyWatcher watcher2; - Event::TimerPtr timer2 = dispatcher->createTimer([&] { watcher2.ready(); }); + Event::TimerPtr timer2 = dispatcher_->createTimer([&] { watcher2.ready(); }); ReadyWatcher watcher1; - Event::TimerPtr timer1 = dispatcher->createTimer([&] { + Event::TimerPtr timer1 = dispatcher_->createTimer([&] { timer2->disableTimer(); watcher1.ready(); }); @@ -550,28 +708,26 @@ TEST(TimerImplTest, TimerOrderAndDisableAlarm) { // Expect watcher calls to happen in order since timers have different times. InSequence s; + EXPECT_CALL(prepare_watcher_, ready()); EXPECT_CALL(watcher1, ready()); EXPECT_CALL(watcher3, ready()); - dispatcher->run(Dispatcher::RunType::Block); + dispatcher_->run(Dispatcher::RunType::Block); } // Change the registration time for a timer that is already activated by disabling and re-enabling // the timer. Verify that execution is delayed. -TEST(TimerImplTest, TimerOrderDisableAndReschedule) { - Api::ApiPtr api = Api::createApiForTest(); - DispatcherPtr dispatcher(api->allocateDispatcher("test_thread")); - +TEST_P(TimerImplTest, TimerOrderDisableAndReschedule) { ReadyWatcher watcher4; - Event::TimerPtr timer4 = dispatcher->createTimer([&] { watcher4.ready(); }); + Event::TimerPtr timer4 = dispatcher_->createTimer([&] { watcher4.ready(); }); ReadyWatcher watcher3; - Event::TimerPtr timer3 = dispatcher->createTimer([&] { watcher3.ready(); }); + Event::TimerPtr timer3 = dispatcher_->createTimer([&] { watcher3.ready(); }); ReadyWatcher watcher2; - Event::TimerPtr timer2 = dispatcher->createTimer([&] { watcher2.ready(); }); + Event::TimerPtr timer2 = dispatcher_->createTimer([&] { watcher2.ready(); }); ReadyWatcher watcher1; - Event::TimerPtr timer1 = dispatcher->createTimer([&] { + Event::TimerPtr timer1 = dispatcher_->createTimer([&] { timer2->disableTimer(); timer2->enableTimer(std::chrono::milliseconds(0)); timer3->disableTimer(); @@ -595,30 +751,44 @@ TEST(TimerImplTest, TimerOrderDisableAndReschedule) { // timer1 is expected to run first and reschedule timers 2 and 3. timer4 should fire before // timer2 and timer3 since timer4's registration is unaffected. InSequence s; + EXPECT_CALL(prepare_watcher_, ready()); EXPECT_CALL(watcher1, ready()); - EXPECT_CALL(watcher4, ready()); - EXPECT_CALL(watcher2, ready()); - EXPECT_CALL(watcher3, ready()); - dispatcher->run(Dispatcher::RunType::Block); + if (activateTimersNextEventLoop()) { + EXPECT_CALL(watcher4, ready()); + // Sleep during prepare to ensure that enough time has elapsed before timer evaluation to ensure + // that timers 2 and 3 are picked up by the same loop iteration. Without the sleep the two + // timers could execute in different loop iterations. + EXPECT_CALL(prepare_watcher_, ready()).WillOnce(testing::InvokeWithoutArgs([]() { + absl::SleepFor(absl::Milliseconds(5)); + })); + EXPECT_CALL(watcher2, ready()); + EXPECT_CALL(watcher3, ready()); + } else { + EXPECT_CALL(watcher4, ready()); + EXPECT_CALL(watcher2, ready()); + // Sleep in prepare cb to avoid flakiness if epoll_wait returns before the timer timeout. + EXPECT_CALL(prepare_watcher_, ready()).WillOnce(testing::InvokeWithoutArgs([]() { + absl::SleepFor(absl::Milliseconds(5)); + })); + EXPECT_CALL(watcher3, ready()); + } + dispatcher_->run(Dispatcher::RunType::Block); } // Change the registration time for a timer that is already activated by re-enabling the timer // without calling disableTimer first. -TEST(TimerImplTest, TimerOrderAndReschedule) { - Api::ApiPtr api = Api::createApiForTest(); - DispatcherPtr dispatcher(api->allocateDispatcher("test_thread")); - +TEST_P(TimerImplTest, TimerOrderAndReschedule) { ReadyWatcher watcher4; - Event::TimerPtr timer4 = dispatcher->createTimer([&] { watcher4.ready(); }); + Event::TimerPtr timer4 = dispatcher_->createTimer([&] { watcher4.ready(); }); ReadyWatcher watcher3; - Event::TimerPtr timer3 = dispatcher->createTimer([&] { watcher3.ready(); }); + Event::TimerPtr timer3 = dispatcher_->createTimer([&] { watcher3.ready(); }); ReadyWatcher watcher2; - Event::TimerPtr timer2 = dispatcher->createTimer([&] { watcher2.ready(); }); + Event::TimerPtr timer2 = dispatcher_->createTimer([&] { watcher2.ready(); }); ReadyWatcher watcher1; - Event::TimerPtr timer1 = dispatcher->createTimer([&] { + Event::TimerPtr timer1 = dispatcher_->createTimer([&] { timer2->enableTimer(std::chrono::milliseconds(0)); timer3->enableTimer(std::chrono::milliseconds(1)); watcher1.ready(); @@ -641,34 +811,48 @@ TEST(TimerImplTest, TimerOrderAndReschedule) { // no effect if the time delta is 0. Expect timers 1, 2 and 4 to execute in the original order. // Timer 3 is delayed since it is rescheduled with a non-zero delta. InSequence s; + EXPECT_CALL(prepare_watcher_, ready()); EXPECT_CALL(watcher1, ready()); - EXPECT_CALL(watcher2, ready()); - EXPECT_CALL(watcher4, ready()); - EXPECT_CALL(watcher3, ready()); - dispatcher->run(Dispatcher::RunType::Block); + if (activateTimersNextEventLoop()) { + EXPECT_CALL(watcher4, ready()); + // Sleep during prepare to ensure that enough time has elapsed before timer evaluation to ensure + // that timers 2 and 3 are picked up by the same loop iteration. Without the sleep the two + // timers could execute in different loop iterations. + EXPECT_CALL(prepare_watcher_, ready()).WillOnce(testing::InvokeWithoutArgs([]() { + absl::SleepFor(absl::Milliseconds(5)); + })); + EXPECT_CALL(watcher2, ready()); + EXPECT_CALL(watcher3, ready()); + } else { + EXPECT_CALL(watcher2, ready()); + EXPECT_CALL(watcher4, ready()); + // Sleep in prepare cb to avoid flakiness if epoll_wait returns before the timer timeout. + EXPECT_CALL(prepare_watcher_, ready()).WillOnce(testing::InvokeWithoutArgs([]() { + absl::SleepFor(absl::Milliseconds(5)); + })); + EXPECT_CALL(watcher3, ready()); + } + dispatcher_->run(Dispatcher::RunType::Block); } -TEST(TimerImplTest, TimerChaining) { - Api::ApiPtr api = Api::createApiForTest(); - DispatcherPtr dispatcher(api->allocateDispatcher("test_thread")); - +TEST_P(TimerImplTest, TimerChaining) { ReadyWatcher watcher1; - Event::TimerPtr timer1 = dispatcher->createTimer([&] { watcher1.ready(); }); + Event::TimerPtr timer1 = dispatcher_->createTimer([&] { watcher1.ready(); }); ReadyWatcher watcher2; - Event::TimerPtr timer2 = dispatcher->createTimer([&] { + Event::TimerPtr timer2 = dispatcher_->createTimer([&] { watcher2.ready(); timer1->enableTimer(std::chrono::milliseconds(0)); }); ReadyWatcher watcher3; - Event::TimerPtr timer3 = dispatcher->createTimer([&] { + Event::TimerPtr timer3 = dispatcher_->createTimer([&] { watcher3.ready(); timer2->enableTimer(std::chrono::milliseconds(0)); }); ReadyWatcher watcher4; - Event::TimerPtr timer4 = dispatcher->createTimer([&] { + Event::TimerPtr timer4 = dispatcher_->createTimer([&] { watcher4.ready(); timer3->enableTimer(std::chrono::milliseconds(0)); }); @@ -679,11 +863,22 @@ TEST(TimerImplTest, TimerChaining) { EXPECT_FALSE(timer2->enabled()); EXPECT_FALSE(timer3->enabled()); EXPECT_TRUE(timer4->enabled()); + InSequence s; + EXPECT_CALL(prepare_watcher_, ready()); EXPECT_CALL(watcher4, ready()); + if (activateTimersNextEventLoop()) { + EXPECT_CALL(prepare_watcher_, ready()); + } EXPECT_CALL(watcher3, ready()); + if (activateTimersNextEventLoop()) { + EXPECT_CALL(prepare_watcher_, ready()); + } EXPECT_CALL(watcher2, ready()); + if (activateTimersNextEventLoop()) { + EXPECT_CALL(prepare_watcher_, ready()); + } EXPECT_CALL(watcher1, ready()); - dispatcher->run(Dispatcher::RunType::NonBlock); + dispatcher_->run(Dispatcher::RunType::NonBlock); EXPECT_FALSE(timer1->enabled()); EXPECT_FALSE(timer2->enabled()); @@ -691,10 +886,7 @@ TEST(TimerImplTest, TimerChaining) { EXPECT_FALSE(timer4->enabled()); } -TEST(TimerImplTest, TimerChainDisable) { - Api::ApiPtr api = Api::createApiForTest(); - DispatcherPtr dispatcher(api->allocateDispatcher("test_thread")); - +TEST_P(TimerImplTest, TimerChainDisable) { ReadyWatcher watcher; Event::TimerPtr timer1; Event::TimerPtr timer2; @@ -707,9 +899,9 @@ TEST(TimerImplTest, TimerChainDisable) { timer3->disableTimer(); }; - timer1 = dispatcher->createTimer(timer_cb); - timer2 = dispatcher->createTimer(timer_cb); - timer3 = dispatcher->createTimer(timer_cb); + timer1 = dispatcher_->createTimer(timer_cb); + timer2 = dispatcher_->createTimer(timer_cb); + timer3 = dispatcher_->createTimer(timer_cb); timer3->enableTimer(std::chrono::milliseconds(0)); timer2->enableTimer(std::chrono::milliseconds(0)); @@ -718,15 +910,14 @@ TEST(TimerImplTest, TimerChainDisable) { EXPECT_TRUE(timer1->enabled()); EXPECT_TRUE(timer2->enabled()); EXPECT_TRUE(timer3->enabled()); + InSequence s; // Only 1 call to watcher ready since the other 2 timers were disabled by the first timer. + EXPECT_CALL(prepare_watcher_, ready()); EXPECT_CALL(watcher, ready()); - dispatcher->run(Dispatcher::RunType::NonBlock); + dispatcher_->run(Dispatcher::RunType::NonBlock); } -TEST(TimerImplTest, TimerChainDelete) { - Api::ApiPtr api = Api::createApiForTest(); - DispatcherPtr dispatcher(api->allocateDispatcher("test_thread")); - +TEST_P(TimerImplTest, TimerChainDelete) { ReadyWatcher watcher; Event::TimerPtr timer1; Event::TimerPtr timer2; @@ -739,9 +930,9 @@ TEST(TimerImplTest, TimerChainDelete) { timer3.reset(); }; - timer1 = dispatcher->createTimer(timer_cb); - timer2 = dispatcher->createTimer(timer_cb); - timer3 = dispatcher->createTimer(timer_cb); + timer1 = dispatcher_->createTimer(timer_cb); + timer2 = dispatcher_->createTimer(timer_cb); + timer3 = dispatcher_->createTimer(timer_cb); timer3->enableTimer(std::chrono::milliseconds(0)); timer2->enableTimer(std::chrono::milliseconds(0)); @@ -750,9 +941,11 @@ TEST(TimerImplTest, TimerChainDelete) { EXPECT_TRUE(timer1->enabled()); EXPECT_TRUE(timer2->enabled()); EXPECT_TRUE(timer3->enabled()); + InSequence s; // Only 1 call to watcher ready since the other 2 timers were deleted by the first timer. + EXPECT_CALL(prepare_watcher_, ready()); EXPECT_CALL(watcher, ready()); - dispatcher->run(Dispatcher::RunType::NonBlock); + dispatcher_->run(Dispatcher::RunType::NonBlock); } class TimerImplTimingTest : public testing::Test { diff --git a/test/test_common/BUILD b/test/test_common/BUILD index dc4e5634d4e9..2250e9280391 100644 --- a/test/test_common/BUILD +++ b/test/test_common/BUILD @@ -280,6 +280,7 @@ envoy_cc_test( ":utility_lib", "//source/common/event:libevent_scheduler_lib", "//test/mocks/event:event_mocks", + "//test/test_common:test_runtime_lib", ], ) diff --git a/test/test_common/simulated_time_system.cc b/test/test_common/simulated_time_system.cc index ecc707b699d6..8fde69f4e013 100644 --- a/test/test_common/simulated_time_system.cc +++ b/test/test_common/simulated_time_system.cc @@ -8,6 +8,7 @@ #include "common/common/lock_guard.h" #include "common/event/real_time_system.h" #include "common/event/timer_impl.h" +#include "common/runtime/runtime_features.h" namespace Envoy { namespace Event { @@ -50,10 +51,11 @@ class UnlockGuard { // mechanism used in RealTimeSystem timers is employed for simulated alarms. class SimulatedTimeSystemHelper::Alarm : public Timer { public: - Alarm(SimulatedTimeSystemHelper& time_system, CallbackScheduler& cb_scheduler, TimerCb cb) + Alarm(SimulatedScheduler& simulated_scheduler, SimulatedTimeSystemHelper& time_system, + CallbackScheduler& cb_scheduler, TimerCb cb) : cb_(cb_scheduler.createSchedulableCallback([this, cb] { runAlarm(cb); })), - time_system_(time_system), index_(time_system.nextIndex()), armed_(false), pending_(false) { - } + simulated_scheduler_(simulated_scheduler), time_system_(time_system), + index_(time_system.nextIndex()), armed_(false), pending_(false) {} ~Alarm() override; @@ -121,6 +123,7 @@ class SimulatedTimeSystemHelper::Alarm : public Timer { } SchedulableCallbackPtr cb_; + SimulatedScheduler& simulated_scheduler_; SimulatedTimeSystemHelper& time_system_; MonotonicTime time_ ABSL_GUARDED_BY(time_system_.mutex_); const uint64_t index_; @@ -149,14 +152,19 @@ bool SimulatedTimeSystemHelper::CompareAlarms::operator()(const Alarm* a, const class SimulatedTimeSystemHelper::SimulatedScheduler : public Scheduler { public: SimulatedScheduler(SimulatedTimeSystemHelper& time_system, CallbackScheduler& cb_scheduler) - : time_system_(time_system), cb_scheduler_(cb_scheduler) {} + : time_system_(time_system), cb_scheduler_(cb_scheduler), + schedule_ready_alarms_cb_(cb_scheduler.createSchedulableCallback( + [this] { time_system_.scheduleReadyAlarms(); })) {} TimerPtr createTimer(const TimerCb& cb, Dispatcher& /*dispatcher*/) override { - return std::make_unique(time_system_, cb_scheduler_, cb); + return std::make_unique(*this, time_system_, cb_scheduler_, + cb); }; + void scheduleReadyAlarms() { schedule_ready_alarms_cb_->scheduleCallbackNextIteration(); } private: SimulatedTimeSystemHelper& time_system_; CallbackScheduler& cb_scheduler_; + SchedulableCallbackPtr schedule_ready_alarms_cb_; }; SimulatedTimeSystemHelper::Alarm::Alarm::~Alarm() { @@ -197,10 +205,11 @@ void SimulatedTimeSystemHelper::Alarm::Alarm::enableHRTimer( } armed_ = true; - if (duration.count() == 0) { + if (duration.count() == 0 && !Runtime::runtimeFeatureEnabled( + "envoy.reloadable_features.activate_timers_next_event_loop")) { activateLockHeld(); } else { - time_system_.addAlarmLockHeld(this, duration); + time_system_.addAlarmLockHeld(this, duration, simulated_scheduler_); } } @@ -329,10 +338,18 @@ int64_t SimulatedTimeSystemHelper::nextIndex() { } void SimulatedTimeSystemHelper::addAlarmLockHeld( - Alarm* alarm, const std::chrono::microseconds& duration) ABSL_NO_THREAD_SAFETY_ANALYSIS { + Alarm* alarm, const std::chrono::microseconds& duration, + SimulatedScheduler& simulated_scheduler) ABSL_NO_THREAD_SAFETY_ANALYSIS { ASSERT(&(alarm->timeSystem()) == this); alarm->setTimeLockHeld(monotonic_time_ + duration); alarms_.insert(alarm); + if (duration.count() == 0) { + // Force the event loop to check for timers that are ready to execute since we just added an 0 + // delay alarm which is ready to execution in the next iteration of the event loop. + // TODO(antoniovicente) Refactor alarm tracking so it happens per scheduler and limit wakeup to + // a single event loop. + simulated_scheduler.scheduleReadyAlarms(); + } } void SimulatedTimeSystemHelper::removeAlarmLockHeld(Alarm* alarm) { alarms_.erase(alarm); } @@ -343,33 +360,46 @@ SchedulerPtr SimulatedTimeSystemHelper::createScheduler(Scheduler& /*base_schedu } void SimulatedTimeSystemHelper::setMonotonicTimeLockHeld(const MonotonicTime& monotonic_time) { + only_one_thread_.checkOneThread(); // We don't have a MutexLock construct that allows temporarily // dropping the lock to run a callback. The main issue here is that we must // be careful not to be holding mutex_ when an exception can be thrown. // That can only happen here in alarm->activate(), which is run with the mutex // released. if (monotonic_time >= monotonic_time_) { - // Alarms is a std::set ordered by wakeup time, so pulling off begin() each - // iteration gives you wakeup order. Also note that alarms may be added - // or removed during the call to activate() so it would not be correct to - // range-iterate over the set. - while (!alarms_.empty()) { - AlarmSet::iterator pos = alarms_.begin(); - Alarm* alarm = *pos; - MonotonicTime alarm_time = alarmTimeLockHeld(alarm); - if (alarm_time > monotonic_time) { - break; - } - ASSERT(alarm_time >= monotonic_time_); - system_time_ += - std::chrono::duration_cast(alarm_time - monotonic_time_); - monotonic_time_ = alarm_time; - alarms_.erase(pos); - alarmActivateLockHeld(alarm); - } + MonotonicTime start_monotonic_time = monotonic_time_; system_time_ += std::chrono::duration_cast(monotonic_time - monotonic_time_); monotonic_time_ = monotonic_time; + scheduleReadyAlarmsLockHeld(start_monotonic_time); + } +} + +void SimulatedTimeSystemHelper::scheduleReadyAlarms() { + absl::MutexLock lock(&mutex_); + scheduleReadyAlarmsLockHeld(monotonic_time_); +} + +void SimulatedTimeSystemHelper::scheduleReadyAlarmsLockHeld(MonotonicTime start_monotonic_time) { + MonotonicTime prev_alarm_time = start_monotonic_time; + // Alarms is a std::set ordered by wakeup time, so pulling off begin() each + // iteration gives you wakeup order. Also note that alarms may be added + // or removed during the call to activate() so it would not be correct to + // range-iterate over the set. + while (!alarms_.empty()) { + AlarmSet::iterator pos = alarms_.begin(); + Alarm* alarm = *pos; + MonotonicTime alarm_time = alarmTimeLockHeld(alarm); + if (alarm_time > monotonic_time_) { + break; + } + + // Verify alarm ordering invariant. + ASSERT(alarm_time >= prev_alarm_time); + prev_alarm_time = alarm_time; + + alarms_.erase(pos); + alarmActivateLockHeld(alarm); } } diff --git a/test/test_common/simulated_time_system.h b/test/test_common/simulated_time_system.h index 521beaf3f28b..0d4bcc734a47 100644 --- a/test/test_common/simulated_time_system.h +++ b/test/test_common/simulated_time_system.h @@ -80,6 +80,13 @@ class SimulatedTimeSystemHelper : public TestTimeSystem { void setMonotonicTimeLockHeld(const MonotonicTime& monotonic_time) ABSL_EXCLUSIVE_LOCKS_REQUIRED(mutex_); + /** + * Schedule expired alarms so they execute in their event loops. + */ + void scheduleReadyAlarms(); + void scheduleReadyAlarmsLockHeld(MonotonicTime start_monotonic_time) + ABSL_EXCLUSIVE_LOCKS_REQUIRED(mutex_); + MonotonicTime alarmTimeLockHeld(Alarm* alarm) ABSL_EXCLUSIVE_LOCKS_REQUIRED(mutex_); void alarmActivateLockHeld(Alarm* alarm) ABSL_EXCLUSIVE_LOCKS_REQUIRED(mutex_); @@ -88,7 +95,8 @@ class SimulatedTimeSystemHelper : public TestTimeSystem { int64_t nextIndex(); // Adds/removes an alarm. - void addAlarmLockHeld(Alarm*, const std::chrono::microseconds& duration) + void addAlarmLockHeld(Alarm*, const std::chrono::microseconds& duration, + SimulatedScheduler& simulated_scheduler) ABSL_EXCLUSIVE_LOCKS_REQUIRED(mutex_); void removeAlarmLockHeld(Alarm*) ABSL_EXCLUSIVE_LOCKS_REQUIRED(mutex_); diff --git a/test/test_common/simulated_time_system_test.cc b/test/test_common/simulated_time_system_test.cc index 5eba67a83bb8..9ec8c4f1e0c5 100644 --- a/test/test_common/simulated_time_system_test.cc +++ b/test/test_common/simulated_time_system_test.cc @@ -6,6 +6,7 @@ #include "test/mocks/common.h" #include "test/mocks/event/mocks.h" #include "test/test_common/simulated_time_system.h" +#include "test/test_common/test_runtime.h" #include "test/test_common/utility.h" #include "event2/event.h" @@ -16,12 +17,18 @@ namespace Event { namespace Test { namespace { -class SimulatedTimeSystemTest : public testing::Test { +class SimulatedTimeSystemTest : public testing::TestWithParam { protected: SimulatedTimeSystemTest() : scheduler_(time_system_.createScheduler(base_scheduler_, base_scheduler_)), start_monotonic_time_(time_system_.monotonicTime()), - start_system_time_(time_system_.systemTime()) {} + start_system_time_(time_system_.systemTime()) { + Runtime::LoaderSingleton::getExisting()->mergeValues( + {{"envoy.reloadable_features.activate_timers_next_event_loop", + activateTimersNextEventLoop() ? "true" : "false"}}); + } + + bool activateTimersNextEventLoop() { return GetParam(); } void trackPrepareCalls() { base_scheduler_.registerOnPrepareCallback([this]() { output_.append(1, 'p'); }); @@ -58,6 +65,7 @@ class SimulatedTimeSystemTest : public testing::Test { base_scheduler_.run(Dispatcher::RunType::NonBlock); } + TestScopedRuntime scoped_runtime_; Event::MockDispatcher dispatcher_; LibeventScheduler base_scheduler_; SimulatedTimeSystem time_system_; @@ -68,7 +76,9 @@ class SimulatedTimeSystemTest : public testing::Test { SystemTime start_system_time_; }; -TEST_F(SimulatedTimeSystemTest, AdvanceTimeAsync) { +INSTANTIATE_TEST_SUITE_P(DelayTimerActivation, SimulatedTimeSystemTest, testing::Bool()); + +TEST_P(SimulatedTimeSystemTest, AdvanceTimeAsync) { EXPECT_EQ(start_monotonic_time_, time_system_.monotonicTime()); EXPECT_EQ(start_system_time_, time_system_.systemTime()); advanceMsAndLoop(5); @@ -76,7 +86,7 @@ TEST_F(SimulatedTimeSystemTest, AdvanceTimeAsync) { EXPECT_EQ(start_system_time_ + std::chrono::milliseconds(5), time_system_.systemTime()); } -TEST_F(SimulatedTimeSystemTest, TimerOrdering) { +TEST_P(SimulatedTimeSystemTest, TimerOrdering) { trackPrepareCalls(); addTask(0, '0'); @@ -91,7 +101,7 @@ TEST_F(SimulatedTimeSystemTest, TimerOrdering) { } // Timers that are scheduled to execute and but are disabled first do not trigger. -TEST_F(SimulatedTimeSystemTest, TimerOrderAndDisableTimer) { +TEST_P(SimulatedTimeSystemTest, TimerOrderAndDisableTimer) { trackPrepareCalls(); // Create 3 timers. The first timer should disable the second, so it doesn't trigger. @@ -108,7 +118,7 @@ TEST_F(SimulatedTimeSystemTest, TimerOrderAndDisableTimer) { } // Capture behavior of timers which are rescheduled without being disabled first. -TEST_F(SimulatedTimeSystemTest, TimerOrderAndRescheduleTimer) { +TEST_P(SimulatedTimeSystemTest, TimerOrderAndRescheduleTimer) { trackPrepareCalls(); // Reschedule timers 1, 2 and 4 without disabling first. @@ -128,15 +138,23 @@ TEST_F(SimulatedTimeSystemTest, TimerOrderAndRescheduleTimer) { // Timer 4 runs as part of the first wakeup since its new schedule time has a delta of 0. Timer 2 // is delayed since it is rescheduled with a non-zero delta. advanceMsAndLoop(5); - EXPECT_EQ("p0134", output_); + if (activateTimersNextEventLoop()) { + EXPECT_EQ("p013p4", output_); + } else { + EXPECT_EQ("p0134", output_); + } advanceMsAndLoop(100); - EXPECT_EQ("p0134p2", output_); + if (activateTimersNextEventLoop()) { + EXPECT_EQ("p013p4p2", output_); + } else { + EXPECT_EQ("p0134p2", output_); + } } // Disable and re-enable timers that is already pending execution and verify that execution is // delayed. -TEST_F(SimulatedTimeSystemTest, TimerOrderDisableAndRescheduleTimer) { +TEST_P(SimulatedTimeSystemTest, TimerOrderDisableAndRescheduleTimer) { trackPrepareCalls(); // Disable and reschedule timers 1, 2 and 4 when timer 0 triggers. @@ -159,13 +177,21 @@ TEST_F(SimulatedTimeSystemTest, TimerOrderDisableAndRescheduleTimer) { // because it is scheduled with zero delay. Timer 2 executes in a later iteration because it is // re-enabled with a non-zero timeout. advanceMsAndLoop(5); - EXPECT_EQ("p0314", output_); + if (activateTimersNextEventLoop()) { + EXPECT_EQ("p03p14", output_); + } else { + EXPECT_EQ("p0314", output_); + } advanceMsAndLoop(100); - EXPECT_EQ("p0314p2", output_); + if (activateTimersNextEventLoop()) { + EXPECT_EQ("p03p14p2", output_); + } else { + EXPECT_EQ("p0314p2", output_); + } } -TEST_F(SimulatedTimeSystemTest, AdvanceTimeWait) { +TEST_P(SimulatedTimeSystemTest, AdvanceTimeWait) { EXPECT_EQ(start_monotonic_time_, time_system_.monotonicTime()); EXPECT_EQ(start_system_time_, time_system_.systemTime()); @@ -187,7 +213,7 @@ TEST_F(SimulatedTimeSystemTest, AdvanceTimeWait) { EXPECT_EQ(start_system_time_ + std::chrono::milliseconds(5), time_system_.systemTime()); } -TEST_F(SimulatedTimeSystemTest, WaitFor) { +TEST_P(SimulatedTimeSystemTest, WaitFor) { EXPECT_EQ(start_monotonic_time_, time_system_.monotonicTime()); EXPECT_EQ(start_system_time_, time_system_.systemTime()); @@ -248,7 +274,7 @@ TEST_F(SimulatedTimeSystemTest, WaitFor) { thread->join(); } -TEST_F(SimulatedTimeSystemTest, Monotonic) { +TEST_P(SimulatedTimeSystemTest, Monotonic) { // Setting time forward works. time_system_.setMonotonicTime(start_monotonic_time_ + std::chrono::milliseconds(5)); EXPECT_EQ(start_monotonic_time_ + std::chrono::milliseconds(5), time_system_.monotonicTime()); @@ -258,7 +284,7 @@ TEST_F(SimulatedTimeSystemTest, Monotonic) { EXPECT_EQ(start_monotonic_time_ + std::chrono::milliseconds(5), time_system_.monotonicTime()); } -TEST_F(SimulatedTimeSystemTest, System) { +TEST_P(SimulatedTimeSystemTest, System) { // Setting time forward works. time_system_.setSystemTime(start_system_time_ + std::chrono::milliseconds(5)); EXPECT_EQ(start_system_time_ + std::chrono::milliseconds(5), time_system_.systemTime()); @@ -268,7 +294,7 @@ TEST_F(SimulatedTimeSystemTest, System) { EXPECT_EQ(start_system_time_ + std::chrono::milliseconds(3), time_system_.systemTime()); } -TEST_F(SimulatedTimeSystemTest, Ordering) { +TEST_P(SimulatedTimeSystemTest, Ordering) { addTask(5, '5'); addTask(3, '3'); addTask(6, '6'); @@ -279,7 +305,7 @@ TEST_F(SimulatedTimeSystemTest, Ordering) { EXPECT_EQ("356", output_); } -TEST_F(SimulatedTimeSystemTest, SystemTimeOrdering) { +TEST_P(SimulatedTimeSystemTest, SystemTimeOrdering) { addTask(5, '5'); addTask(3, '3'); addTask(6, '6'); @@ -293,7 +319,7 @@ TEST_F(SimulatedTimeSystemTest, SystemTimeOrdering) { EXPECT_EQ("356", output_); // callbacks don't get replayed. } -TEST_F(SimulatedTimeSystemTest, DisableTimer) { +TEST_P(SimulatedTimeSystemTest, DisableTimer) { addTask(5, '5'); addTask(3, '3'); addTask(6, '6'); @@ -305,7 +331,7 @@ TEST_F(SimulatedTimeSystemTest, DisableTimer) { EXPECT_EQ("36", output_); } -TEST_F(SimulatedTimeSystemTest, IgnoreRedundantDisable) { +TEST_P(SimulatedTimeSystemTest, IgnoreRedundantDisable) { addTask(5, '5'); timers_[0]->disableTimer(); timers_[0]->disableTimer(); @@ -313,7 +339,7 @@ TEST_F(SimulatedTimeSystemTest, IgnoreRedundantDisable) { EXPECT_EQ("", output_); } -TEST_F(SimulatedTimeSystemTest, OverrideEnable) { +TEST_P(SimulatedTimeSystemTest, OverrideEnable) { addTask(5, '5'); timers_[0]->enableTimer(std::chrono::milliseconds(6)); advanceMsAndLoop(5); @@ -322,7 +348,7 @@ TEST_F(SimulatedTimeSystemTest, OverrideEnable) { EXPECT_EQ("5", output_); } -TEST_F(SimulatedTimeSystemTest, DeleteTime) { +TEST_P(SimulatedTimeSystemTest, DeleteTime) { addTask(5, '5'); addTask(3, '3'); addTask(6, '6'); @@ -335,7 +361,7 @@ TEST_F(SimulatedTimeSystemTest, DeleteTime) { } // Regression test for issues documented in https://github.com/envoyproxy/envoy/pull/6956 -TEST_F(SimulatedTimeSystemTest, DuplicateTimer) { +TEST_P(SimulatedTimeSystemTest, DuplicateTimer) { // Set one alarm two times to test that pending does not get duplicated.. std::chrono::milliseconds delay(0); TimerPtr zero_timer = scheduler_->createTimer([this]() { output_.append(1, '2'); }, dispatcher_); @@ -371,7 +397,7 @@ TEST_F(SimulatedTimeSystemTest, DuplicateTimer) { thread->join(); } -TEST_F(SimulatedTimeSystemTest, Enabled) { +TEST_P(SimulatedTimeSystemTest, Enabled) { TimerPtr timer = scheduler_->createTimer({}, dispatcher_); timer->enableTimer(std::chrono::milliseconds(0)); EXPECT_TRUE(timer->enabled()); From bdccb5b47e54295e4808908f4ba8b007090f5aff Mon Sep 17 00:00:00 2001 From: Antonio Vicente Date: Wed, 1 Jul 2020 12:49:39 -0400 Subject: [PATCH 02/14] Attempt to fix windows tests. Signed-off-by: Antonio Vicente --- test/common/event/dispatcher_impl_test.cc | 7 +++++++ test/test_common/simulated_time_system_test.cc | 10 ++++++++++ 2 files changed, 17 insertions(+) diff --git a/test/common/event/dispatcher_impl_test.cc b/test/common/event/dispatcher_impl_test.cc index 2af503d12ea4..e37148049421 100644 --- a/test/common/event/dispatcher_impl_test.cc +++ b/test/common/event/dispatcher_impl_test.cc @@ -956,6 +956,13 @@ class TimerImplTimingTest : public testing::Test { EXPECT_TRUE(timer.enabled()); while (true) { dispatcher.run(Dispatcher::RunType::NonBlock); +#ifdef WIN32 + // The event loop runs for a single iteration in NonBlock mode on Windows. A few iterations + // are required to ensure that next iteration callbacks have a chance to run before time + // advances once again. + dispatcher.run(Dispatcher::RunType::NonBlock); + dispatcher.run(Dispatcher::RunType::NonBlock); +#endif if (timer.enabled()) { time_system.advanceTimeAsync(std::chrono::microseconds(1)); } else { diff --git a/test/test_common/simulated_time_system_test.cc b/test/test_common/simulated_time_system_test.cc index 9ec8c4f1e0c5..49dae4862945 100644 --- a/test/test_common/simulated_time_system_test.cc +++ b/test/test_common/simulated_time_system_test.cc @@ -139,6 +139,11 @@ TEST_P(SimulatedTimeSystemTest, TimerOrderAndRescheduleTimer) { // is delayed since it is rescheduled with a non-zero delta. advanceMsAndLoop(5); if (activateTimersNextEventLoop()) { +#ifdef WIN32 + // The event loop runs for a single iteration in NonBlock mode on Windows. Force it to run again + // to pick up next iteration callbacks. + advanceMsAndLoop(0); +#endif EXPECT_EQ("p013p4", output_); } else { EXPECT_EQ("p0134", output_); @@ -178,6 +183,11 @@ TEST_P(SimulatedTimeSystemTest, TimerOrderDisableAndRescheduleTimer) { // re-enabled with a non-zero timeout. advanceMsAndLoop(5); if (activateTimersNextEventLoop()) { +#ifdef WIN32 + // The event loop runs for a single iteration in NonBlock mode on Windows. Force it to run again + // to pick up next iteration callbacks. + advanceMsAndLoop(0); +#endif EXPECT_EQ("p03p14", output_); } else { EXPECT_EQ("p0314", output_); From d915c0f8f7cba1e8ab19a3ab0795361780682367 Mon Sep 17 00:00:00 2001 From: Antonio Vicente Date: Fri, 17 Jul 2020 12:32:56 -0400 Subject: [PATCH 03/14] fix format and test Signed-off-by: Antonio Vicente --- test/test_common/simulated_time_system.cc | 3 ++- test/test_common/simulated_time_system.h | 4 ++-- test/test_common/simulated_time_system_test.cc | 4 ++-- 3 files changed, 6 insertions(+), 5 deletions(-) diff --git a/test/test_common/simulated_time_system.cc b/test/test_common/simulated_time_system.cc index 4c8f20e3f767..6ca79cce7f85 100644 --- a/test/test_common/simulated_time_system.cc +++ b/test/test_common/simulated_time_system.cc @@ -54,7 +54,8 @@ class SimulatedTimeSystemHelper::Alarm : public Timer { Alarm(SimulatedScheduler& simulated_scheduler, SimulatedTimeSystemHelper& time_system, CallbackScheduler& cb_scheduler, TimerCb cb) : cb_(cb_scheduler.createSchedulableCallback([this, cb] { runAlarm(cb); })), - simulated_scheduler_(simulated_scheduler), time_system_(time_system), armed_(false), pending_(false) {} + simulated_scheduler_(simulated_scheduler), time_system_(time_system), armed_(false), + pending_(false) {} ~Alarm() override; diff --git a/test/test_common/simulated_time_system.h b/test/test_common/simulated_time_system.h index 6e191d779cdb..650933c779fc 100644 --- a/test/test_common/simulated_time_system.h +++ b/test/test_common/simulated_time_system.h @@ -111,10 +111,10 @@ class SimulatedTimeSystemHelper : public TestTimeSystem { void scheduleReadyAlarmsLockHeld(MonotonicTime start_monotonic_time) ABSL_EXCLUSIVE_LOCKS_REQUIRED(mutex_); - void alarmActivateLockHeld(Alarm* alarm) ABSL_EXCLUSIVE_LOCKS_REQUIRED(mutex_); + void alarmActivateLockHeld(Alarm& alarm) ABSL_EXCLUSIVE_LOCKS_REQUIRED(mutex_); // Adds/removes an alarm. - void addAlarmLockHeld(Alarm*, const std::chrono::microseconds& duration, + void addAlarmLockHeld(Alarm&, const std::chrono::microseconds& duration, SimulatedScheduler& simulated_scheduler) ABSL_EXCLUSIVE_LOCKS_REQUIRED(mutex_); void removeAlarmLockHeld(Alarm&) ABSL_EXCLUSIVE_LOCKS_REQUIRED(mutex_); diff --git a/test/test_common/simulated_time_system_test.cc b/test/test_common/simulated_time_system_test.cc index f108bbd46265..5bfbe433d87d 100644 --- a/test/test_common/simulated_time_system_test.cc +++ b/test/test_common/simulated_time_system_test.cc @@ -239,14 +239,14 @@ TEST_P(SimulatedTimeSystemTest, TimerOrderDisableAndRescheduleTimer) { // to pick up next iteration callbacks. advanceMsAndLoop(0); #endif - EXPECT_EQ("p03p14", output_); + EXPECT_THAT(output_, testing::AnyOf("p03p14", "p03p41")); } else { EXPECT_EQ("p0314", output_); } advanceMsAndLoop(100); if (activateTimersNextEventLoop()) { - EXPECT_EQ("p03p14p2", output_); + EXPECT_THAT(output_, testing::AnyOf("p03p14p2", "p03p41p2")); } else { EXPECT_EQ("p0314p2", output_); } From 66c95ce4dc05d8c75e65e0c8d8c2c8875aa37dbe Mon Sep 17 00:00:00 2001 From: Antonio Vicente Date: Tue, 21 Jul 2020 11:43:54 -0400 Subject: [PATCH 04/14] update stats_integration_test Signed-off-by: Antonio Vicente --- test/integration/stats_integration_test.cc | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/test/integration/stats_integration_test.cc b/test/integration/stats_integration_test.cc index 9b339b8e4dc1..0f3457e06bc2 100644 --- a/test/integration/stats_integration_test.cc +++ b/test/integration/stats_integration_test.cc @@ -408,6 +408,7 @@ TEST_P(ClusterMemoryTestRunner, MemoryLargeHostSizeWithStats) { // 2020/02/13 10042 1363 1655 Metadata object are shared across different clusters // and hosts. // 2020/04/02 10624 1380 1655 Use 100 clusters rather than 1000 to avoid timeouts + // 2020/07/21 11823 1381 1800 Adjust to fix CI. Is test flaky with 100 hosts? // Note: when adjusting this value: EXPECT_MEMORY_EQ is active only in CI // 'release' builds, where we control the platform and tool-chain. So you @@ -421,7 +422,7 @@ TEST_P(ClusterMemoryTestRunner, MemoryLargeHostSizeWithStats) { // We only run the exact test for ipv6 because ipv4 in some cases may allocate a // different number of bytes. We still run the approximate test. if (ip_version_ != Network::Address::IpVersion::v6) { - EXPECT_MEMORY_EQ(m_per_host, 1380); + EXPECT_MEMORY_EQ(m_per_host, 1381); } EXPECT_MEMORY_LE(m_per_host, 1800); // Round up to allow platform variations. } From 13b64fcfb10e5e9dc8ca7f147e8968c7a89d3d85 Mon Sep 17 00:00:00 2001 From: Antonio Vicente Date: Tue, 21 Jul 2020 12:06:47 -0400 Subject: [PATCH 05/14] rollback changes to test, test is flaky upstream. Signed-off-by: Antonio Vicente --- test/integration/stats_integration_test.cc | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/test/integration/stats_integration_test.cc b/test/integration/stats_integration_test.cc index 0f3457e06bc2..9b339b8e4dc1 100644 --- a/test/integration/stats_integration_test.cc +++ b/test/integration/stats_integration_test.cc @@ -408,7 +408,6 @@ TEST_P(ClusterMemoryTestRunner, MemoryLargeHostSizeWithStats) { // 2020/02/13 10042 1363 1655 Metadata object are shared across different clusters // and hosts. // 2020/04/02 10624 1380 1655 Use 100 clusters rather than 1000 to avoid timeouts - // 2020/07/21 11823 1381 1800 Adjust to fix CI. Is test flaky with 100 hosts? // Note: when adjusting this value: EXPECT_MEMORY_EQ is active only in CI // 'release' builds, where we control the platform and tool-chain. So you @@ -422,7 +421,7 @@ TEST_P(ClusterMemoryTestRunner, MemoryLargeHostSizeWithStats) { // We only run the exact test for ipv6 because ipv4 in some cases may allocate a // different number of bytes. We still run the approximate test. if (ip_version_ != Network::Address::IpVersion::v6) { - EXPECT_MEMORY_EQ(m_per_host, 1381); + EXPECT_MEMORY_EQ(m_per_host, 1380); } EXPECT_MEMORY_LE(m_per_host, 1800); // Round up to allow platform variations. } From 15557fae5ded352dd2a131e9c9d2dfa1b3d4b44e Mon Sep 17 00:00:00 2001 From: Antonio Vicente Date: Tue, 21 Jul 2020 16:49:28 -0400 Subject: [PATCH 06/14] address review comments Signed-off-by: Antonio Vicente --- .../test_common/simulated_time_system_test.cc | 20 +++++++++++-------- 1 file changed, 12 insertions(+), 8 deletions(-) diff --git a/test/test_common/simulated_time_system_test.cc b/test/test_common/simulated_time_system_test.cc index 5bfbe433d87d..f58918e6b7cc 100644 --- a/test/test_common/simulated_time_system_test.cc +++ b/test/test_common/simulated_time_system_test.cc @@ -17,7 +17,9 @@ namespace Event { namespace Test { namespace { -class SimulatedTimeSystemTest : public testing::TestWithParam { +enum class ActivateMode { DelayActivateTimers, EagerlyActivateTimers }; + +class SimulatedTimeSystemTest : public testing::TestWithParam { protected: SimulatedTimeSystemTest() : scheduler_(time_system_.createScheduler(base_scheduler_, base_scheduler_)), @@ -25,10 +27,10 @@ class SimulatedTimeSystemTest : public testing::TestWithParam { start_system_time_(time_system_.systemTime()) { Runtime::LoaderSingleton::getExisting()->mergeValues( {{"envoy.reloadable_features.activate_timers_next_event_loop", - activateTimersNextEventLoop() ? "true" : "false"}}); + activateMode() == ActivateMode::DelayActivateTimers ? "true" : "false"}}); } - bool activateTimersNextEventLoop() { return GetParam(); } + ActivateMode activateMode() { return GetParam(); } void trackPrepareCalls() { base_scheduler_.registerOnPrepareCallback([this]() { output_.append(1, 'p'); }); @@ -76,7 +78,9 @@ class SimulatedTimeSystemTest : public testing::TestWithParam { SystemTime start_system_time_; }; -INSTANTIATE_TEST_SUITE_P(DelayTimerActivation, SimulatedTimeSystemTest, testing::Bool()); +INSTANTIATE_TEST_SUITE_P(DelayTimerActivation, SimulatedTimeSystemTest, + testing::Values(ActivateMode::DelayActivateTimers, + ActivateMode::EagerlyActivateTimers)); TEST_P(SimulatedTimeSystemTest, AdvanceTimeAsync) { EXPECT_EQ(start_monotonic_time_, time_system_.monotonicTime()); @@ -189,7 +193,7 @@ TEST_P(SimulatedTimeSystemTest, TimerOrderAndRescheduleTimer) { // Timer 4 runs as part of the first wakeup since its new schedule time has a delta of 0. Timer 2 // is delayed since it is rescheduled with a non-zero delta. advanceMsAndLoop(5); - if (activateTimersNextEventLoop()) { + if (activateMode() == ActivateMode::DelayActivateTimers) { #ifdef WIN32 // The event loop runs for a single iteration in NonBlock mode on Windows. Force it to run again // to pick up next iteration callbacks. @@ -201,7 +205,7 @@ TEST_P(SimulatedTimeSystemTest, TimerOrderAndRescheduleTimer) { } advanceMsAndLoop(100); - if (activateTimersNextEventLoop()) { + if (activateMode() == ActivateMode::DelayActivateTimers) { EXPECT_EQ("p013p4p2", output_); } else { EXPECT_EQ("p0134p2", output_); @@ -233,7 +237,7 @@ TEST_P(SimulatedTimeSystemTest, TimerOrderDisableAndRescheduleTimer) { // because it is scheduled with zero delay. Timer 2 executes in a later iteration because it is // re-enabled with a non-zero timeout. advanceMsAndLoop(5); - if (activateTimersNextEventLoop()) { + if (activateMode() == ActivateMode::DelayActivateTimers) { #ifdef WIN32 // The event loop runs for a single iteration in NonBlock mode on Windows. Force it to run again // to pick up next iteration callbacks. @@ -245,7 +249,7 @@ TEST_P(SimulatedTimeSystemTest, TimerOrderDisableAndRescheduleTimer) { } advanceMsAndLoop(100); - if (activateTimersNextEventLoop()) { + if (activateMode() == ActivateMode::DelayActivateTimers) { EXPECT_THAT(output_, testing::AnyOf("p03p14p2", "p03p41p2")); } else { EXPECT_EQ("p0314p2", output_); From ae6b2119d112b82b4ec2056cd83efb56162bf3bc Mon Sep 17 00:00:00 2001 From: Antonio Vicente Date: Thu, 23 Jul 2020 11:55:52 -0400 Subject: [PATCH 07/14] update comment Signed-off-by: Antonio Vicente --- test/test_common/simulated_time_system_test.cc | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/test/test_common/simulated_time_system_test.cc b/test/test_common/simulated_time_system_test.cc index f58918e6b7cc..13a435148aff 100644 --- a/test/test_common/simulated_time_system_test.cc +++ b/test/test_common/simulated_time_system_test.cc @@ -195,8 +195,14 @@ TEST_P(SimulatedTimeSystemTest, TimerOrderAndRescheduleTimer) { advanceMsAndLoop(5); if (activateMode() == ActivateMode::DelayActivateTimers) { #ifdef WIN32 - // The event loop runs for a single iteration in NonBlock mode on Windows. Force it to run again - // to pick up next iteration callbacks. + // Force it to run again to pick up next iteration callbacks. + // The event loop runs for a single iteration in NonBlock mode on Windows as a hack to work + // around LEVEL trigger fd registrations constantly firing events and preventing the NonBlock + // event loop from ever reaching the no-fd event and no-expired timers termination condition. It + // is not possible to get consistent event loop behavior since the time system does not override + // the base scheduler's run behavior, and libevent does not provide a mode where it runs at most + // N iterations before breaking out of the loop for us to prefer over the single iteration mode + // used on Windows. advanceMsAndLoop(0); #endif EXPECT_EQ("p013p4", output_); From dbe5e90436d670643443ce4889b0d808711e1292 Mon Sep 17 00:00:00 2001 From: Antonio Vicente Date: Thu, 30 Jul 2020 19:52:33 -0400 Subject: [PATCH 08/14] Only read runtime feature if singleton exists Signed-off-by: Antonio Vicente --- source/common/event/timer_impl.cc | 11 +++++++++-- 1 file changed, 9 insertions(+), 2 deletions(-) diff --git a/source/common/event/timer_impl.cc b/source/common/event/timer_impl.cc index 196887119569..56137dc8b2e3 100644 --- a/source/common/event/timer_impl.cc +++ b/source/common/event/timer_impl.cc @@ -12,8 +12,15 @@ namespace Event { TimerImpl::TimerImpl(Libevent::BasePtr& libevent, TimerCb cb, Dispatcher& dispatcher) : cb_(cb), dispatcher_(dispatcher), - activate_timers_next_event_loop_(Runtime::runtimeFeatureEnabled( - "envoy.reloadable_features.activate_timers_next_event_loop")) { + activate_timers_next_event_loop_( + // Only read the runtime feature if the runtime loader singleton has already been created. + // Accessing runtime features too early in the initialization sequence triggers logging + // and the logging code itself depends on the use of timers. Attempts to log while + // initializing the logging subsystem will result in a crash. + Runtime::LoaderSingleton::getExisting() + ? Runtime::runtimeFeatureEnabled( + "envoy.reloadable_features.activate_timers_next_event_loop") + : true) { ASSERT(cb_); evtimer_assign( &raw_event_, libevent.get(), From 1c46b17143f94e6c85435b5609327d957472b1fc Mon Sep 17 00:00:00 2001 From: Antonio Vicente Date: Mon, 3 Aug 2020 17:14:22 -0400 Subject: [PATCH 09/14] release the simulated time lock before interacting with libevent Signed-off-by: Antonio Vicente --- test/test_common/simulated_time_system.cc | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/test/test_common/simulated_time_system.cc b/test/test_common/simulated_time_system.cc index 6ca79cce7f85..d2f20c0fb4c2 100644 --- a/test/test_common/simulated_time_system.cc +++ b/test/test_common/simulated_time_system.cc @@ -311,6 +311,11 @@ void SimulatedTimeSystemHelper::addAlarmLockHeld( // delay alarm which is ready to execution in the next iteration of the event loop. // TODO(antoniovicente) Refactor alarm tracking so it happens per scheduler and limit wakeup to // a single event loop. + + // We don't want to activate the alarm under lock, as it will make a libevent call, and libevent + // itself uses locks: + // https://github.com/libevent/libevent/blob/29cc8386a2f7911eaa9336692a2c5544d8b4734f/event.c#L1917 + UnlockGuard unlocker(mutex_); simulated_scheduler.scheduleReadyAlarms(); } From f91674fddb38d19a9c13119fd556ad5554762478 Mon Sep 17 00:00:00 2001 From: Antonio Vicente Date: Mon, 3 Aug 2020 17:20:25 -0400 Subject: [PATCH 10/14] remove simulated time ordering invariant checking for simulated timers. Simulated time relinquishes the lock while activating timers. That allows other threads like the watchdog to insert timers that appear to be in the past. Invariant check makes //test/server:server_test fail about 0.5% of the time under ASAN. Signed-off-by: Antonio Vicente --- test/test_common/simulated_time_system.cc | 12 +++--------- test/test_common/simulated_time_system.h | 3 +-- 2 files changed, 4 insertions(+), 11 deletions(-) diff --git a/test/test_common/simulated_time_system.cc b/test/test_common/simulated_time_system.cc index d2f20c0fb4c2..d361beddf471 100644 --- a/test/test_common/simulated_time_system.cc +++ b/test/test_common/simulated_time_system.cc @@ -350,21 +350,19 @@ void SimulatedTimeSystemHelper::setMonotonicTimeLockHeld(const MonotonicTime& mo // That can only happen here in alarm->activate(), which is run with the mutex // released. if (monotonic_time >= monotonic_time_) { - MonotonicTime start_monotonic_time = monotonic_time_; system_time_ += std::chrono::duration_cast(monotonic_time - monotonic_time_); monotonic_time_ = monotonic_time; - scheduleReadyAlarmsLockHeld(start_monotonic_time); + scheduleReadyAlarmsLockHeld(); } } void SimulatedTimeSystemHelper::scheduleReadyAlarms() { absl::MutexLock lock(&mutex_); - scheduleReadyAlarmsLockHeld(monotonic_time_); + scheduleReadyAlarmsLockHeld(); } -void SimulatedTimeSystemHelper::scheduleReadyAlarmsLockHeld(MonotonicTime start_monotonic_time) { - MonotonicTime prev_alarm_time = start_monotonic_time; +void SimulatedTimeSystemHelper::scheduleReadyAlarmsLockHeld() { // Alarms is a std::set ordered by wakeup time, so pulling off begin() each // iteration gives you wakeup order. Also note that alarms may be added // or removed during the call to activate() so it would not be correct to @@ -376,10 +374,6 @@ void SimulatedTimeSystemHelper::scheduleReadyAlarmsLockHeld(MonotonicTime start_ break; } - // Verify alarm ordering invariant. - ASSERT(alarm_time >= prev_alarm_time); - prev_alarm_time = alarm_time; - Alarm& alarm = alarm_registration.alarm_; removeAlarmLockHeld(alarm); alarmActivateLockHeld(alarm); diff --git a/test/test_common/simulated_time_system.h b/test/test_common/simulated_time_system.h index 650933c779fc..e8a369e4f9cc 100644 --- a/test/test_common/simulated_time_system.h +++ b/test/test_common/simulated_time_system.h @@ -108,8 +108,7 @@ class SimulatedTimeSystemHelper : public TestTimeSystem { * Schedule expired alarms so they execute in their event loops. */ void scheduleReadyAlarms(); - void scheduleReadyAlarmsLockHeld(MonotonicTime start_monotonic_time) - ABSL_EXCLUSIVE_LOCKS_REQUIRED(mutex_); + void scheduleReadyAlarmsLockHeld() ABSL_EXCLUSIVE_LOCKS_REQUIRED(mutex_); void alarmActivateLockHeld(Alarm& alarm) ABSL_EXCLUSIVE_LOCKS_REQUIRED(mutex_); From 01cb8977b780330020d4617f8889736fe74eb1bb Mon Sep 17 00:00:00 2001 From: Antonio Vicente Date: Mon, 3 Aug 2020 17:56:50 -0400 Subject: [PATCH 11/14] Kick CI Signed-off-by: Antonio Vicente From 73abb34927b0f6d6e68304f0c77670843c9f7fb5 Mon Sep 17 00:00:00 2001 From: Antonio Vicente Date: Tue, 4 Aug 2020 10:49:54 -0400 Subject: [PATCH 12/14] Kick CI Signed-off-by: Antonio Vicente From e8a4cb9ddaa8661c95f9cb723f503ab57f2c47b3 Mon Sep 17 00:00:00 2001 From: Antonio Vicente Date: Tue, 4 Aug 2020 18:05:36 -0400 Subject: [PATCH 13/14] Use advanceLibeventTime instead of absl::Sleep in new test cases. Signed-off-by: Antonio Vicente --- test/common/event/dispatcher_impl_test.cc | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) diff --git a/test/common/event/dispatcher_impl_test.cc b/test/common/event/dispatcher_impl_test.cc index 89c159667fc8..30fbcd32f248 100644 --- a/test/common/event/dispatcher_impl_test.cc +++ b/test/common/event/dispatcher_impl_test.cc @@ -552,8 +552,8 @@ TEST_P(TimerImplTest, ChangeTimerBackwardsBeforeRun) { timer2->enableTimer(std::chrono::milliseconds(3)); timer1->enableTimer(std::chrono::milliseconds(4)); - // Sleep for 5ms so timers above all trigger in the same loop iteration. - absl::SleepFor(absl::Milliseconds(5)); + // Advance time by 5ms so timers above all trigger in the same loop iteration. + advanceLibeventTime(absl::Milliseconds(5)); // Expect watcher3 to trigger first because the deadlines for timers 1 and 2 was moved backwards. InSequence s; @@ -575,8 +575,8 @@ TEST_P(TimerImplTest, ChangeTimerForwardsToZeroBeforeRun) { timer2->enableTimer(std::chrono::milliseconds(1)); timer1->enableTimer(std::chrono::milliseconds(0)); - // Sleep for 5ms so timers above all trigger in the same loop iteration. - absl::SleepFor(absl::Milliseconds(5)); + // Advance time by 5ms so timers above all trigger in the same loop iteration. + advanceLibeventTime(absl::Milliseconds(5)); // Expect watcher1 to trigger first because timer1's deadline was moved forward. InSequence s; @@ -603,8 +603,8 @@ TEST_P(TimerImplTest, ChangeTimerForwardsToNonZeroBeforeRun) { timer2->enableTimer(std::chrono::milliseconds(2)); timer1->enableTimer(std::chrono::milliseconds(1)); - // Sleep for 5ms so timers above all trigger in the same loop iteration. - absl::SleepFor(absl::Milliseconds(5)); + // Advance time by 5ms so timers above all trigger in the same loop iteration. + advanceLibeventTime(absl::Milliseconds(5)); // Expect watcher1 to trigger first because timer1's deadline was moved forward. InSequence s; @@ -644,8 +644,8 @@ TEST_P(TimerImplTest, ChangeLargeTimerForwardToNonZeroBeforeRun) { timer2->enableTimer(std::chrono::seconds(1000)); timer1->enableTimer(std::chrono::milliseconds(1)); - // Sleep for 5ms so timers above all trigger in the same loop iteration. - absl::SleepFor(absl::Milliseconds(5)); + // Advance time by 5ms so timers above all trigger in the same loop iteration. + advanceLibeventTime(absl::Milliseconds(5)); // Expect watcher1 to trigger because timer1's deadline was moved forward. InSequence s; From 55da79758d76f90f34a0728c364622b0820c2051 Mon Sep 17 00:00:00 2001 From: Antonio Vicente Date: Tue, 4 Aug 2020 22:20:09 -0400 Subject: [PATCH 14/14] Kick CI Signed-off-by: Antonio Vicente