From 4413b01379ecd3b0561191f851034352a446342b Mon Sep 17 00:00:00 2001 From: Ed Savage Date: Tue, 22 Sep 2026 10:46:07 +1200 Subject: [PATCH] [ML] Make CMonotonicTimeTest robust to sleep overshoot on CI (#3201) The millisecond and nanosecond timer tests slept for one second and then asserted the monotonic timer had advanced by a value within a fixed [900, 1200]ms window. This really tested the accuracy of sleep_for rather than the timer: on oversubscribed CI machines (e.g. the macOS Orka VMs) the sleep can overshoot substantially, which intermittently pushed the measured interval past the 1200ms upper bound and failed the build. Measure the elapsed interval independently with std::chrono::steady_clock around the same sleep and assert the monotonic timer agrees with that reference to within 5%. This validates what we actually care about - that the timer tracks real elapsed time - and is immune to how long the machine actually slept for. (cherry picked from commit d6a62eb0ff0abecea82ea25370202e464d03d0df) --- lib/core/unittest/CMonotonicTimeTest.cc | 98 +++++++++++++++++++++---- 1 file changed, 82 insertions(+), 16 deletions(-) diff --git a/lib/core/unittest/CMonotonicTimeTest.cc b/lib/core/unittest/CMonotonicTimeTest.cc index 7833cb75b5..8686bc465d 100644 --- a/lib/core/unittest/CMonotonicTimeTest.cc +++ b/lib/core/unittest/CMonotonicTimeTest.cc @@ -15,48 +15,114 @@ #include #include +#include +#include #include BOOST_AUTO_TEST_SUITE(CMonotonicTimeTest) +// These tests sleep for a nominal one second and then make two independent +// checks on what CMonotonicTime measured over that interval: +// +// 1. A cross-domain lower bound. We assert the timer advanced by at least +// (close to) the requested sleep duration. std::this_thread::sleep_for +// guarantees it sleeps for *at least* the requested time, so a reading +// well below one second means the monotonic clock is running too slowly +// or has stalled. This is our only genuinely independent check that the +// clock ticks at roughly real-time rate, because it compares against a +// different clock domain (the scheduler's sleep timer) rather than +// against another reading of the same underlying counter. +// +// 2. A cross-clock consistency check. We measure the same interval with +// std::chrono::steady_clock and assert CMonotonicTime agrees with it to +// within a small tolerance. The two clocks should agree because they +// observe the same elapsed real time - on most platforms via the same +// underlying counter (macOS mach_absolute_time; the CLOCK_MONOTONIC +// nanosecond paths on Linux), though the coarse millisecond paths read a +// different source (Linux CLOCK_MONOTONIC_COARSE, Windows GetTickCount64). +// This is therefore not an independent re-check of the clock's real-time +// fidelity (that is covered by check 1); what it validates is +// CMonotonicTime's own unit-scaling arithmetic (the mach_timebase / +// QueryPerformanceFrequency / timespec conversions), which is the part of +// this class we can actually break. +// +// Crucially there is NO upper bound on the elapsed time relative to the +// nominal sleep duration. sleep_for only promises a *minimum* sleep and can +// overshoot arbitrarily when the machine is loaded or oversubscribed - on +// shared CI hosts (notably the macOS Orka VMs) the thread simply is not +// rescheduled promptly. Such overshoot is a property of the scheduler, not a +// timer defect, so any assertion of the form "diff < someConstant" is +// inherently flaky. A previous version of this test asserted diff < 1200ms and +// failed intermittently for exactly this reason (the timer correctly reported +// ~1293ms because that much wall-clock time had genuinely elapsed). Check 2 +// still bounds diff from above, but only against the *actual* elapsed time +// measured over the same window, so overshoot cannot cause a failure. + +namespace { +// Tolerance for how closely the monotonic timer must track the independently +// measured reference interval (check 2 above). This is deliberately small +// because we are comparing two measurements of the *same* elapsed period; it +// is sized to comfortably exceed the coarsest platform timer's granularity +// (Windows GetTickCount64 is only accurate to ~15ms, i.e. ~1.5% of a one +// second interval), so the nominal one second interval must stay large +// relative to that granularity. +const double MONOTONIC_TIMER_TOLERANCE{0.05}; +} + BOOST_AUTO_TEST_CASE(testMilliseconds) { ml::core::CMonotonicTime monoTime; + auto referenceStart = std::chrono::steady_clock::now(); std::uint64_t start(monoTime.milliseconds()); std::this_thread::sleep_for(std::chrono::seconds(1)); std::uint64_t end(monoTime.milliseconds()); + auto referenceEnd = std::chrono::steady_clock::now(); std::uint64_t diff(end - start); - LOG_DEBUG(<< "During 1 second the monotonic millisecond timer advanced by " - << diff << " milliseconds"); - - // Allow 10% margin of error - this is as much for the sleep as the timer - BOOST_TEST_REQUIRE(diff > 900); - // Allow 20% margin of error - sleep seems to sleep too long under Jenkins - // on Apple M1 - BOOST_TEST_REQUIRE(diff < 1200); + std::uint64_t reference(static_cast( + std::chrono::duration_cast(referenceEnd - referenceStart) + .count())); + LOG_DEBUG(<< "The monotonic millisecond timer advanced by " << diff << " milliseconds; reference clock advanced by " + << reference << " milliseconds"); + + // Check 1: cross-domain lower bound (allow a 10% margin below the one + // second sleep). Deliberately no upper bound - see the note above. + BOOST_TEST_REQUIRE(diff > 900U); + + // Check 2: agreement with the independent reference over the same interval. + double allowedError{static_cast(reference) * MONOTONIC_TIMER_TOLERANCE}; + BOOST_TEST_REQUIRE(std::abs(static_cast(diff) - + static_cast(reference)) < allowedError); } BOOST_AUTO_TEST_CASE(testNanoseconds) { ml::core::CMonotonicTime monoTime; + auto referenceStart = std::chrono::steady_clock::now(); std::uint64_t start(monoTime.nanoseconds()); std::this_thread::sleep_for(std::chrono::seconds(1)); std::uint64_t end(monoTime.nanoseconds()); + auto referenceEnd = std::chrono::steady_clock::now(); std::uint64_t diff(end - start); - LOG_DEBUG(<< "During 1 second the monotonic nanosecond timer advanced by " - << diff << " nanoseconds"); - - // Allow 10% margin of error - this is as much for the sleep as the timer - BOOST_TEST_REQUIRE(diff > 900000000); - // Allow 20% margin of error - sleep seems to sleep too long under Jenkins - // on Apple M1 - BOOST_TEST_REQUIRE(diff < 1200000000); + std::uint64_t reference(static_cast( + std::chrono::duration_cast(referenceEnd - referenceStart) + .count())); + LOG_DEBUG(<< "The monotonic nanosecond timer advanced by " << diff << " nanoseconds; reference clock advanced by " + << reference << " nanoseconds"); + + // Check 1: cross-domain lower bound (allow a 10% margin below the one + // second sleep). Deliberately no upper bound - see the note above. + BOOST_TEST_REQUIRE(diff > 900000000U); + + // Check 2: agreement with the independent reference over the same interval. + double allowedError{static_cast(reference) * MONOTONIC_TIMER_TOLERANCE}; + BOOST_TEST_REQUIRE(std::abs(static_cast(diff) - + static_cast(reference)) < allowedError); } BOOST_AUTO_TEST_SUITE_END()