Adding a unit test for HHWheelTimer exercising the default timeout functionality.
[folly.git] / folly / io / async / test / HHWheelTimerTest.cpp
1 /*
2  * Licensed to the Apache Software Foundation (ASF) under one
3  * or more contributor license agreements. See the NOTICE file
4  * distributed with this work for additional information
5  * regarding copyright ownership. The ASF licenses this file
6  * to you under the Apache License, Version 2.0 (the
7  * "License"); you may not use this file except in compliance
8  * with the License. You may obtain a copy of the License at
9  *
10  *   http://www.apache.org/licenses/LICENSE-2.0
11  *
12  * Unless required by applicable law or agreed to in writing,
13  * software distributed under the License is distributed on an
14  * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
15  * KIND, either express or implied. See the License for the
16  * specific language governing permissions and limitations
17  * under the License.
18  */
19 #include <folly/io/async/HHWheelTimer.h>
20 #include <folly/io/async/EventBase.h>
21 #include <folly/io/async/test/UndelayedDestruction.h>
22 #include <folly/io/async/test/Util.h>
23
24 #include <gtest/gtest.h>
25 #include <vector>
26
27 using namespace folly;
28 using std::chrono::milliseconds;
29
30 typedef UndelayedDestruction<HHWheelTimer> StackWheelTimer;
31
32 class TestTimeout : public HHWheelTimer::Callback {
33  public:
34   TestTimeout() {}
35   TestTimeout(HHWheelTimer* t, milliseconds timeout) {
36     t->scheduleTimeout(this, timeout);
37   }
38
39   void timeoutExpired() noexcept override {
40     timestamps.emplace_back();
41     if (fn) {
42       fn();
43     }
44   }
45
46   void callbackCanceled() noexcept override {
47     canceledTimestamps.emplace_back();
48     if (fn) {
49       fn();
50     }
51   }
52
53   std::deque<TimePoint> timestamps;
54   std::deque<TimePoint> canceledTimestamps;
55   std::function<void()> fn;
56 };
57
58
59 class TestTimeoutDelayed : public TestTimeout {
60  protected:
61     std::chrono::milliseconds getCurTime() override {
62       return std::chrono::duration_cast<std::chrono::milliseconds>(
63         std::chrono::steady_clock::now().time_since_epoch()) -
64         milliseconds(5);
65     }
66 };
67
68 struct HHWheelTimerTest : public ::testing::Test {
69   EventBase eventBase;
70 };
71
72 /*
73  * Test firing some simple timeouts that are fired once and never rescheduled
74  */
75 TEST_F(HHWheelTimerTest, FireOnce) {
76   StackWheelTimer t(&eventBase, milliseconds(1));
77
78   const HHWheelTimer::Callback* nullCallback = nullptr;
79
80   TestTimeout t1;
81   TestTimeout t2;
82   TestTimeout t3;
83
84   ASSERT_EQ(t.count(), 0);
85
86   t.scheduleTimeout(&t1, milliseconds(5));
87   t.scheduleTimeout(&t2, milliseconds(5));
88   // Verify scheduling it twice cancels, then schedules.
89   // Should only get one callback.
90   t.scheduleTimeout(&t2, milliseconds(5));
91   t.scheduleTimeout(&t3, milliseconds(10));
92
93   ASSERT_EQ(t.count(), 3);
94
95   TimePoint start;
96   eventBase.loop();
97   TimePoint end;
98
99   ASSERT_EQ(t1.timestamps.size(), 1);
100   ASSERT_EQ(t2.timestamps.size(), 1);
101   ASSERT_EQ(t3.timestamps.size(), 1);
102
103   ASSERT_EQ(t.count(), 0);
104
105   T_CHECK_TIMEOUT(start, t1.timestamps[0], milliseconds(5));
106   T_CHECK_TIMEOUT(start, t2.timestamps[0], milliseconds(5));
107   T_CHECK_TIMEOUT(start, t3.timestamps[0], milliseconds(10));
108   T_CHECK_TIMEOUT(start, end, milliseconds(10));
109 }
110
111 /*
112  * Test scheduling a timeout from another timeout callback.
113  */
114 TEST_F(HHWheelTimerTest, TestSchedulingWithinCallback) {
115   StackWheelTimer t(&eventBase, milliseconds(10));
116   const HHWheelTimer::Callback* nullCallback = nullptr;
117
118   TestTimeout t1;
119   // Delayed to simulate the steady_clock counter lagging
120   TestTimeoutDelayed t2;
121
122   t.scheduleTimeout(&t1, milliseconds(500));
123   t1.fn = [&] { t.scheduleTimeout(&t2, milliseconds(1)); };
124   // If t is in an inconsistent state, detachEventBase should fail.
125   t2.fn = [&] { t.detachEventBase(); };
126
127   ASSERT_EQ(t.count(), 1);
128
129   eventBase.loop();
130
131   ASSERT_EQ(t.count(), 0);
132   ASSERT_EQ(t1.timestamps.size(), 1);
133   ASSERT_EQ(t2.timestamps.size(), 1);
134 }
135
136 /*
137  * Test cancelling a timeout when it is scheduled to be fired right away.
138  */
139
140 TEST_F(HHWheelTimerTest, CancelTimeout) {
141   StackWheelTimer t(&eventBase, milliseconds(1));
142
143   // Create several timeouts that will all fire in 5ms.
144   TestTimeout t5_1(&t, milliseconds(5));
145   TestTimeout t5_2(&t, milliseconds(5));
146   TestTimeout t5_3(&t, milliseconds(5));
147   TestTimeout t5_4(&t, milliseconds(5));
148   TestTimeout t5_5(&t, milliseconds(5));
149
150   // Also create a few timeouts to fire in 10ms
151   TestTimeout t10_1(&t, milliseconds(10));
152   TestTimeout t10_2(&t, milliseconds(10));
153   TestTimeout t10_3(&t, milliseconds(10));
154
155   TestTimeout t20_1(&t, milliseconds(20));
156   TestTimeout t20_2(&t, milliseconds(20));
157
158   // Have t5_1 cancel t5_2 and t5_4.
159   //
160   // Cancelling t5_2 will test cancelling a timeout that is at the head of the
161   // list and ready to be fired.
162   //
163   // Cancelling t5_4 will test cancelling a timeout in the middle of the list
164   t5_1.fn = [&] {
165     t5_2.cancelTimeout();
166     t5_4.cancelTimeout();
167   };
168
169   // Have t5_3 cancel t5_5.
170   // This will test cancelling the last remaining timeout.
171   //
172   // Then have t5_3 reschedule itself.
173   t5_3.fn = [&] {
174     t5_5.cancelTimeout();
175     // Reset our function so we won't continually reschedule ourself
176     std::function<void()> fnDtorGuard;
177     t5_3.fn.swap(fnDtorGuard);
178     t.scheduleTimeout(&t5_3, milliseconds(5));
179
180     // Also test cancelling timeouts in another timeset that isn't ready to
181     // fire yet.
182     //
183     // Cancel the middle timeout in ts10.
184     t10_2.cancelTimeout();
185     // Cancel both the timeouts in ts20.
186     t20_1.cancelTimeout();
187     t20_2.cancelTimeout();
188   };
189
190   TimePoint start;
191   eventBase.loop();
192   TimePoint end;
193
194   ASSERT_EQ(t5_1.timestamps.size(), 1);
195   T_CHECK_TIMEOUT(start, t5_1.timestamps[0], milliseconds(5));
196
197   ASSERT_EQ(t5_3.timestamps.size(), 2);
198   T_CHECK_TIMEOUT(start, t5_3.timestamps[0], milliseconds(5));
199   T_CHECK_TIMEOUT(t5_3.timestamps[0], t5_3.timestamps[1], milliseconds(5));
200
201   ASSERT_EQ(t10_1.timestamps.size(), 1);
202   T_CHECK_TIMEOUT(start, t10_1.timestamps[0], milliseconds(10));
203   ASSERT_EQ(t10_3.timestamps.size(), 1);
204   T_CHECK_TIMEOUT(start, t10_3.timestamps[0], milliseconds(10));
205
206   // Cancelled timeouts
207   ASSERT_EQ(t5_2.timestamps.size(), 0);
208   ASSERT_EQ(t5_4.timestamps.size(), 0);
209   ASSERT_EQ(t5_5.timestamps.size(), 0);
210   ASSERT_EQ(t10_2.timestamps.size(), 0);
211   ASSERT_EQ(t20_1.timestamps.size(), 0);
212   ASSERT_EQ(t20_2.timestamps.size(), 0);
213
214   T_CHECK_TIMEOUT(start, end, milliseconds(10));
215 }
216
217 /*
218  * Test destroying a HHWheelTimer with timeouts outstanding
219  */
220
221 TEST_F(HHWheelTimerTest, DestroyTimeoutSet) {
222
223   HHWheelTimer::UniquePtr t(
224     new HHWheelTimer(&eventBase, milliseconds(1)));
225
226   TestTimeout t5_1(t.get(), milliseconds(5));
227   TestTimeout t5_2(t.get(), milliseconds(5));
228   TestTimeout t5_3(t.get(), milliseconds(5));
229
230   TestTimeout t10_1(t.get(), milliseconds(10));
231   TestTimeout t10_2(t.get(), milliseconds(10));
232
233   // Have t5_2 destroy t
234   // Note that this will call destroy() inside t's timeoutExpired()
235   // method.
236   t5_2.fn = [&] {
237     t5_3.cancelTimeout();
238     t5_1.cancelTimeout();
239     t10_1.cancelTimeout();
240     t10_2.cancelTimeout();
241     t.reset();};
242
243   TimePoint start;
244   eventBase.loop();
245   TimePoint end;
246
247   ASSERT_EQ(t5_1.timestamps.size(), 1);
248   T_CHECK_TIMEOUT(start, t5_1.timestamps[0], milliseconds(5));
249   ASSERT_EQ(t5_2.timestamps.size(), 1);
250   T_CHECK_TIMEOUT(start, t5_2.timestamps[0], milliseconds(5));
251
252   ASSERT_EQ(t5_3.timestamps.size(), 0);
253   ASSERT_EQ(t10_1.timestamps.size(), 0);
254   ASSERT_EQ(t10_2.timestamps.size(), 0);
255
256   T_CHECK_TIMEOUT(start, end, milliseconds(5));
257 }
258
259 /*
260  * Test the tick interval parameter
261  */
262 TEST_F(HHWheelTimerTest, AtMostEveryN) {
263
264   // Create a timeout set with a 10ms interval, to fire no more than once
265   // every 3ms.
266   milliseconds interval(25);
267   milliseconds atMostEveryN(6);
268   StackWheelTimer t(&eventBase, atMostEveryN);
269   t.setCatchupEveryN(70);
270
271   // Create 60 timeouts to be added to ts10 at 1ms intervals.
272   uint32_t numTimeouts = 60;
273   std::vector<TestTimeout> timeouts(numTimeouts);
274
275   // Create a scheduler timeout to add the timeouts 1ms apart.
276   uint32_t index = 0;
277   StackWheelTimer ts1(&eventBase, milliseconds(1));
278   TestTimeout scheduler(&ts1, milliseconds(1));
279   scheduler.fn = [&] {
280     if (index >= numTimeouts) {
281       return;
282     }
283     // Call timeoutExpired() on the timeout so it will record a timestamp.
284     // This is done only so we can record when we scheduled the timeout.
285     // This way if ts1 starts to fall behind a little over time we will still
286     // be comparing the ts10 timeouts to when they were first scheduled (rather
287     // than when we intended to schedule them).  The scheduler may fall behind
288     // eventually since we don't really schedule it once every millisecond.
289     // Each time it finishes we schedule it for 1 millisecond in the future.
290     // The amount of time it takes to run, and any delays it encounters
291     // getting scheduled may eventually add up over time.
292     timeouts[index].timeoutExpired();
293
294     // Schedule the new timeout
295     t.scheduleTimeout(&timeouts[index], interval);
296     // Reschedule ourself
297     ts1.scheduleTimeout(&scheduler, milliseconds(1));
298     ++index;
299   };
300
301   // Go ahead and schedule the first timeout now.
302   //scheduler.fn();
303
304   TimePoint start;
305   eventBase.loop();
306   TimePoint end;
307
308   // We scheduled timeouts 1ms apart, when the HHWheelTimer is only allowed
309   // to wake up at most once every 3ms.  It will therefore wake up every 3ms
310   // and fire groups of approximately 3 timeouts at a time.
311   //
312   // This is "approximately 3" since it may get slightly behind and fire 4 in
313   // one interval, etc.  T_CHECK_TIMEOUT normally allows a few milliseconds of
314   // tolerance.  We have to add the same into our checking algorithm here.
315   for (uint32_t idx = 0; idx < numTimeouts; ++idx) {
316     ASSERT_EQ(timeouts[idx].timestamps.size(), 2);
317
318     TimePoint scheduledTime(timeouts[idx].timestamps[0]);
319     TimePoint firedTime(timeouts[idx].timestamps[1]);
320
321     // Assert that the timeout fired at roughly the right time.
322     // T_CHECK_TIMEOUT() normally has a tolerance of 5ms.  Allow an additional
323     // atMostEveryN.
324     milliseconds tolerance = milliseconds(5) + interval;
325     T_CHECK_TIMEOUT(scheduledTime, firedTime, atMostEveryN, tolerance);
326
327     // Assert that the difference between the previous timeout and now was
328     // either very small (fired in the same event loop), or larger than
329     // atMostEveryN.
330     if (idx == 0) {
331       // no previous value
332       continue;
333     }
334     TimePoint prev(timeouts[idx - 1].timestamps[1]);
335
336     auto delta = (firedTime.getTimeStart() - prev.getTimeEnd()) -
337       (firedTime.getTimeWaiting() - prev.getTimeWaiting());
338     if (delta > milliseconds(1)) {
339       T_CHECK_TIMEOUT(prev, firedTime, atMostEveryN);
340     }
341   }
342 }
343
344 /*
345  * Test an event loop that is blocking
346  */
347
348 TEST_F(HHWheelTimerTest, SlowLoop) {
349   StackWheelTimer t(&eventBase, milliseconds(1));
350
351   TestTimeout t1;
352   TestTimeout t2;
353
354   ASSERT_EQ(t.count(), 0);
355
356   eventBase.runInLoop([](){usleep(10000);});
357   t.scheduleTimeout(&t1, milliseconds(5));
358
359   ASSERT_EQ(t.count(), 1);
360
361   TimePoint start;
362   eventBase.loop();
363   TimePoint end;
364
365   ASSERT_EQ(t1.timestamps.size(), 1);
366   ASSERT_EQ(t.count(), 0);
367
368   // Check that the timeout was delayed by sleep
369   T_CHECK_TIMEOUT(start, t1.timestamps[0], milliseconds(15), milliseconds(1));
370   T_CHECK_TIMEOUT(start, end, milliseconds(15), milliseconds(1));
371
372   // Try it again, this time with catchup timing every loop
373   t.setCatchupEveryN(1);
374
375   eventBase.runInLoop([](){usleep(10000);});
376   t.scheduleTimeout(&t2, milliseconds(5));
377
378   ASSERT_EQ(t.count(), 1);
379
380   TimePoint start2;
381   eventBase.loop();
382   TimePoint end2;
383
384   ASSERT_EQ(t2.timestamps.size(), 1);
385   ASSERT_EQ(t.count(), 0);
386
387   // Check that the timeout was NOT delayed by sleep
388   T_CHECK_TIMEOUT(start2, t2.timestamps[0], milliseconds(10), milliseconds(1));
389   T_CHECK_TIMEOUT(start2, end2, milliseconds(10), milliseconds(1));
390 }
391
392 /*
393  * Test scheduling a mix of timers with default timeout and variable timeout.
394  */
395 TEST_F(HHWheelTimerTest, DefaultTimeout) {
396   milliseconds defaultTimeout(milliseconds(5));
397   StackWheelTimer t(&eventBase,
398                     milliseconds(1),
399                     AsyncTimeout::InternalEnum::NORMAL,
400                     defaultTimeout);
401
402   TestTimeout t1;
403   TestTimeout t2;
404
405   ASSERT_EQ(t.count(), 0);
406   ASSERT_EQ(t.getDefaultTimeout(), defaultTimeout);
407
408   t.scheduleTimeout(&t1);
409   t.scheduleTimeout(&t2, milliseconds(10));
410
411   ASSERT_EQ(t.count(), 2);
412
413   TimePoint start;
414   eventBase.loop();
415   TimePoint end;
416
417   ASSERT_EQ(t1.timestamps.size(), 1);
418   ASSERT_EQ(t2.timestamps.size(), 1);
419
420   ASSERT_EQ(t.count(), 0);
421
422   T_CHECK_TIMEOUT(start, t1.timestamps[0], defaultTimeout);
423   T_CHECK_TIMEOUT(start, t2.timestamps[0], milliseconds(10));
424   T_CHECK_TIMEOUT(start, end, milliseconds(10));
425 }
426
427 TEST_F(HHWheelTimerTest, lambda) {
428   StackWheelTimer t(&eventBase, milliseconds(1));
429   size_t count = 0;
430   t.scheduleTimeoutFn([&]{ count++; }, milliseconds(1));
431   eventBase.loop();
432   EXPECT_EQ(1, count);
433 }
434
435 // shouldn't crash because we swallow and log the error (you'll have to look
436 // at the console to confirm logging)
437 TEST_F(HHWheelTimerTest, lambdaThrows) {
438   StackWheelTimer t(&eventBase, milliseconds(1));
439   t.scheduleTimeoutFn([&]{ throw std::runtime_error("expected"); },
440                       milliseconds(1));
441   eventBase.loop();
442 }
443
444 TEST_F(HHWheelTimerTest, cancelAll) {
445   StackWheelTimer t(&eventBase);
446   TestTimeout tt;
447   t.scheduleTimeout(&tt, std::chrono::minutes(1));
448   EXPECT_EQ(1, t.cancelAll());
449   EXPECT_EQ(1, tt.canceledTimestamps.size());
450 }