From 105f2620b98bfd4e5d7ed576b5cc4b2317dcf634 Mon Sep 17 00:00:00 2001 From: Chris Wilson Date: Tue, 20 Jun 2017 21:02:42 +0100 Subject: Reduce precision of common timer test Ideally timers would be perfectly accurate and we could sleep for 1.0 seconds, but on OSX in particular they could fire 50-100 ms late (I've seen 4 ms in practice) and we don't want the tests to fail because of this, because we don't really need that kind of precision in practice. So we reduce the timer intervals by 100ms to be safe. Increase logging level and add timestamps in testcommon. Should help to debug frequent test failures such as Condition [t2.HasExpired()] on OSX hosts on Travis. Add a SettingsGuard to the Console logger for its specific settings, such as showing times and microseconds. (cherry picked from commit a5e6cff1d435329b0121417ed9509e315ce0edd5) (cherry picked from commit 8d02eebce553ed822e0fcd60d6e319384e15ba4b) --- test/common/testcommon.cpp | 95 ++++++++++++++++++++++++++-------------------- 1 file changed, 54 insertions(+), 41 deletions(-) (limited to 'test/common') diff --git a/test/common/testcommon.cpp b/test/common/testcommon.cpp index fbdf8d9c..bd75ac37 100644 --- a/test/common/testcommon.cpp +++ b/test/common/testcommon.cpp @@ -344,47 +344,60 @@ int test(int argc, const char *argv[]) Timers::Init(); - Timer t0(0, "t0"); // should never expire - Timer t1(1000, "t1"); - Timer t2(2000, "t2"); - Timer t3(3000, "t3"); - - TEST_THAT(!t0.HasExpired()); - TEST_THAT(!t1.HasExpired()); - TEST_THAT(!t2.HasExpired()); - TEST_THAT(!t3.HasExpired()); - - safe_sleep(1); - TEST_THAT(!t0.HasExpired()); - TEST_THAT(t1.HasExpired()); - TEST_THAT(!t2.HasExpired()); - TEST_THAT(!t3.HasExpired()); - - safe_sleep(1); - TEST_THAT(!t0.HasExpired()); - TEST_THAT(t1.HasExpired()); - TEST_THAT(t2.HasExpired()); - TEST_THAT(!t3.HasExpired()); - - // Try both ways of resetting an existing timer. - t1 = Timer(1000, "t1a"); - t2.Reset(2000); - TEST_THAT(!t0.HasExpired()); - TEST_THAT(!t1.HasExpired()); - TEST_THAT(!t2.HasExpired()); - TEST_THAT(!t3.HasExpired()); - - safe_sleep(1); - TEST_THAT(!t0.HasExpired()); - TEST_THAT(t1.HasExpired()); - TEST_THAT(!t2.HasExpired()); - TEST_THAT(t3.HasExpired()); - - safe_sleep(1); - TEST_THAT(!t0.HasExpired()); - TEST_THAT(t1.HasExpired()); - TEST_THAT(t2.HasExpired()); - TEST_THAT(t3.HasExpired()); + // Ideally timers would be perfectly accurate and we could sleep for 1.0 seconds, but + // on OSX in particular they could fire 50-100 ms late (I've seen 4 ms in practice) + // and we don't want the tests to fail because of this, because we don't really need + // that kind of precision in practice. So we reduce the timer intervals by 100ms to + // be safe. + + { + Logger::LevelGuard temporary_verbosity(Logging::GetConsole(), Log::TRACE); + Console::SettingsGuard save_old_settings; + Console::SetShowTime(true); + Console::SetShowTimeMicros(true); + + Timer t0(0, "t0"); // should never expire + Timer t1(900, "t1"); + Timer t2(1900, "t2"); + Timer t3(2900, "t3"); + + TEST_THAT(!t0.HasExpired()); + TEST_THAT(!t1.HasExpired()); + TEST_THAT(!t2.HasExpired()); + TEST_THAT(!t3.HasExpired()); + safe_sleep(1); + + TEST_THAT(!t0.HasExpired()); + TEST_THAT(t1.HasExpired()); + TEST_THAT(!t2.HasExpired()); + TEST_THAT(!t3.HasExpired()); + + safe_sleep(1); + TEST_THAT(!t0.HasExpired()); + TEST_THAT(t1.HasExpired()); + TEST_THAT(t2.HasExpired()); + TEST_THAT(!t3.HasExpired()); + + // Try both ways of resetting an existing timer. + t1 = Timer(900, "t1a"); + t2.Reset(1900); + TEST_THAT(!t0.HasExpired()); + TEST_THAT(!t1.HasExpired()); + TEST_THAT(!t2.HasExpired()); + TEST_THAT(!t3.HasExpired()); + + safe_sleep(1); + TEST_THAT(!t0.HasExpired()); + TEST_THAT(t1.HasExpired()); + TEST_THAT(!t2.HasExpired()); + TEST_THAT(t3.HasExpired()); + + safe_sleep(1); + TEST_THAT(!t0.HasExpired()); + TEST_THAT(t1.HasExpired()); + TEST_THAT(t2.HasExpired()); + TEST_THAT(t3.HasExpired()); + } // Leave timers initialised for rest of test. // Test main() will cleanup after test finishes. -- cgit v1.2.3