2 * Copyright 2016 Facebook, Inc.
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
8 * http://www.apache.org/licenses/LICENSE-2.0
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
16 #include <folly/Random.h>
17 #include <folly/io/async/EventBase.h>
18 #include <folly/io/async/HHWheelTimer.h>
19 #include <folly/io/async/test/UndelayedDestruction.h>
20 #include <folly/io/async/test/Util.h>
21 #include <folly/portability/GTest.h>
26 using namespace folly;
27 using std::chrono::milliseconds;
29 typedef UndelayedDestruction<HHWheelTimer> StackWheelTimer;
31 class TestTimeout : public HHWheelTimer::Callback {
34 TestTimeout(HHWheelTimer* t, milliseconds timeout) {
35 t->scheduleTimeout(this, timeout);
38 void timeoutExpired() noexcept override {
39 timestamps.emplace_back();
45 void callbackCanceled() noexcept override {
46 canceledTimestamps.emplace_back();
52 std::deque<TimePoint> timestamps;
53 std::deque<TimePoint> canceledTimestamps;
54 std::function<void()> fn;
57 class TestTimeoutDelayed : public TestTimeout {
59 std::chrono::milliseconds getCurTime() override {
60 return std::chrono::duration_cast<std::chrono::milliseconds>(
61 std::chrono::steady_clock::now().time_since_epoch()) -
66 struct HHWheelTimerTest : public ::testing::Test {
70 /* Test takes ~2.5 minutes to run */
71 TEST_F(HHWheelTimerTest, Level2) {
72 HHWheelTimer& t = eventBase.timer();
77 ASSERT_EQ(t.count(), 0);
79 t.scheduleTimeout(&t1, milliseconds(605 * 256));
80 t.scheduleTimeout(&t2, milliseconds(300 * 256));
82 ASSERT_EQ(t.count(), 2);
88 ASSERT_EQ(t1.timestamps.size(), 1);
89 ASSERT_EQ(t2.timestamps.size(), 1);
90 ASSERT_EQ(t.count(), 0);
92 // Check that the timeout was delayed by sleep
96 milliseconds(605 * 256),
97 milliseconds(256 * 256));
101 milliseconds(300 * 256),
102 milliseconds(256 * 256));
106 * Test the tick interval parameter
108 TEST_F(HHWheelTimerTest, AtMostEveryN) {
109 // Create a timeout set with a 10ms interval, to fire no more than once
111 milliseconds interval(10);
112 milliseconds atMostEveryN(3);
113 StackWheelTimer t(&eventBase, atMostEveryN);
115 // Create 60 timeouts to be added to ts1 at 1ms intervals.
116 uint32_t numTimeouts = 60;
117 std::vector<TestTimeout> timeouts(numTimeouts);
119 // Create a scheduler timeout to add the timeouts 1ms apart.
121 StackWheelTimer ts1(&eventBase, milliseconds(1));
122 TestTimeout scheduler(&ts1, milliseconds(1));
124 if (index >= numTimeouts) {
127 // Call timeoutExpired() on the timeout so it will record a timestamp.
128 // This is done only so we can record when we scheduled the timeout.
129 // This way if ts1 starts to fall behind a little over time we will still
130 // be comparing the ts1 timeouts to when they were first scheduled (rather
131 // than when we intended to schedule them). The scheduler may fall behind
132 // eventually since we don't really schedule it once every millisecond.
133 // Each time it finishes we schedule it for 1 millisecond in the future.
134 // The amount of time it takes to run, and any delays it encounters
135 // getting scheduled may eventually add up over time.
136 timeouts[index].timeoutExpired();
138 // Schedule the new timeout
139 t.scheduleTimeout(&timeouts[index], interval);
140 // Reschedule ourself
141 ts1.scheduleTimeout(&scheduler, milliseconds(1));
149 // This should take roughly 60 + 10 ms to finish. If it takes more than
150 // 250 ms to finish the system is probably heavily loaded, so skip.
151 if (std::chrono::duration_cast<std::chrono::milliseconds>(
152 end.getTime() - start.getTime())
154 LOG(WARNING) << "scheduling all timeouts takes too long";
158 // We scheduled timeouts 1ms apart, when the HHWheelTimer is only allowed
159 // to wake up at most once every 3ms. It will therefore wake up every 3ms
160 // and fire groups of approximately 3 timeouts at a time.
162 // This is "approximately 3" since it may get slightly behind and fire 4 in
163 // one interval, etc. T_CHECK_TIMEOUT normally allows a few milliseconds of
164 // tolerance. We have to add the same into our checking algorithm here.
165 for (uint32_t idx = 0; idx < numTimeouts; ++idx) {
166 ASSERT_EQ(timeouts[idx].timestamps.size(), 2);
168 TimePoint scheduledTime(timeouts[idx].timestamps[0]);
169 TimePoint firedTime(timeouts[idx].timestamps[1]);
171 // Assert that the timeout fired at roughly the right time.
172 // T_CHECK_TIMEOUT() normally has a tolerance of 5ms. Allow an additional
174 milliseconds tolerance = milliseconds(5) + interval;
175 T_CHECK_TIMEOUT(scheduledTime, firedTime, atMostEveryN, tolerance);
177 // Assert that the difference between the previous timeout and now was
178 // either very small (fired in the same event loop), or larger than
184 TimePoint prev(timeouts[idx - 1].timestamps[1]);
186 auto delta = (firedTime.getTimeStart() - prev.getTimeEnd()) -
187 (firedTime.getTimeWaiting() - prev.getTimeWaiting());
188 if (delta > milliseconds(1)) {
189 T_CHECK_TIMEOUT(prev, firedTime, atMostEveryN);
195 * Test an event loop that is blocking
198 TEST_F(HHWheelTimerTest, SlowLoop) {
199 StackWheelTimer t(&eventBase, milliseconds(1));
204 ASSERT_EQ(t.count(), 0);
206 eventBase.runInLoop([]() {
208 std::this_thread::sleep_for(std::chrono::microseconds(10000));
210 t.scheduleTimeout(&t1, milliseconds(5));
212 ASSERT_EQ(t.count(), 1);
218 ASSERT_EQ(t1.timestamps.size(), 1);
219 ASSERT_EQ(t.count(), 0);
221 // Check that the timeout was delayed by sleep
222 T_CHECK_TIMEOUT(start, t1.timestamps[0], milliseconds(10), milliseconds(1));
223 T_CHECK_TIMEOUT(start, end, milliseconds(10), milliseconds(1));
225 eventBase.runInLoop([]() {
227 std::this_thread::sleep_for(std::chrono::microseconds(10000));
229 t.scheduleTimeout(&t2, milliseconds(5));
231 ASSERT_EQ(t.count(), 1);
237 ASSERT_EQ(t2.timestamps.size(), 1);
238 ASSERT_EQ(t.count(), 0);
240 // Check that the timeout was NOT delayed by sleep
241 T_CHECK_TIMEOUT(start2, t2.timestamps[0], milliseconds(10), milliseconds(1));
242 T_CHECK_TIMEOUT(start2, end2, milliseconds(10), milliseconds(1));
246 * Test upper timer levels. Slow by necessity :/
249 TEST_F(HHWheelTimerTest, Level1) {
250 HHWheelTimer& t = eventBase.timer();
255 ASSERT_EQ(t.count(), 0);
257 t.scheduleTimeout(&t1, milliseconds(605));
258 t.scheduleTimeout(&t2, milliseconds(300));
260 ASSERT_EQ(t.count(), 2);
266 ASSERT_EQ(t1.timestamps.size(), 1);
267 ASSERT_EQ(t2.timestamps.size(), 1);
268 ASSERT_EQ(t.count(), 0);
270 // Check that the timeout was delayed by sleep
272 start, t1.timestamps[0], milliseconds(605), milliseconds(256));
274 start, t2.timestamps[0], milliseconds(300), milliseconds(256));
277 TEST_F(HHWheelTimerTest, Stress) {
278 StackWheelTimer t(&eventBase, milliseconds(1));
280 long timeoutcount = 10000;
281 TestTimeout timeouts[10000];
282 long runtimeouts = 0;
283 for (long i = 0; i < timeoutcount; i++) {
284 long timeout = Random::rand32(1, 10000);
285 if (Random::rand32(3)) {
286 // NOTE: hhwheel timer runs before eventbase runAfterDelay,
287 // so runAfterDelay cancelTimeout() must run at least one timerwheel
288 // before scheduleTimeout, to ensure it runs first.
290 t.scheduleTimeout(&timeouts[i], std::chrono::milliseconds(timeout));
291 eventBase.runAfterDelay(
293 timeouts[i].fn = nullptr;
294 timeouts[i].cancelTimeout();
296 LOG(INFO) << "Ran " << runtimeouts << " timeouts, cancelled";
299 timeouts[i].fn = [&, i, timeout]() {
300 LOG(INFO) << "FAIL:timer " << i << " still fired in " << timeout;
304 t.scheduleTimeout(&timeouts[i], std::chrono::milliseconds(timeout));
305 timeouts[i].fn = [&, i]() {
307 long newtimeout = Random::rand32(1, 10000);
308 t.scheduleTimeout(&timeouts[i], std::chrono::milliseconds(newtimeout));
310 /* sleep override */ usleep(1000);
311 LOG(INFO) << "Ran " << runtimeouts << " timeouts of " << timeoutcount;
312 timeouts[i].fn = [&, i]() {
314 LOG(INFO) << "Ran " << runtimeouts << " timeouts of " << timeoutcount;
320 LOG(INFO) << "RUNNING TEST";
323 EXPECT_EQ(runtimeouts, timeoutcount);