Skip to content

Fix FuturesTest's wall-clock timing assumptions - #295

Closed
SalvatoreT wants to merge 2 commits into
mainfrom
salvatoret/fix-flaky-futures-timing
Closed

Fix FuturesTest's wall-clock timing assumptions#295
SalvatoreT wants to merge 2 commits into
mainfrom
salvatoret/fix-flaky-futures-timing

Conversation

@SalvatoreT

Copy link
Copy Markdown
Contributor

FuturesTest asserts on wall-clock time in ways that break on shared runners. testBrokenSleep is already failing on macOS; the other two changes here are the same problem caught before it lands.

testBrokenSleep

The test slept a nominal 500 ms across four awaits and required the total to land in [500, 1000]. On the macOS runners it came in at 1001 ms and 1008 ms, failing by 1 ms and 8 ms. It has been failing since at least 2026-07-22, on main as well as on pull requests.

The overhead is structural rather than contention. Each awaited Rust timer spawns a thread and resumes back through the FFI, which costs about 5 ms locally and roughly 125 ms per await on a shared macOS runner. testSleepWithRepeat shows the same effect independently in the same job: 65 sequential 20 ms sleeps, nominal 1.3 s, actual 6.9 s. Raising the cap only moves the cliff, since that cost has no upper bound on a shared VM.

What the test is for is that a waker firing a second time does not corrupt its own future or let a later one finish early. That is a lower bound, and lower bounds do not care how loaded the machine is: thread::sleep is an at-least guarantee and measureTime is monotonic. So each step now asserts it took at least as long as it slept, and the upper bound is gone. A future that never completes is still caught by runTest's own timeout.

These bounds are weaker than ones the file already relies on. assertApproximateTime asserts an exact nominal lower bound with no slack on eight other tests, across these same platforms.

testFutureWithLockButNotCancelled

Next in line to flake: nominal 100 ms, window [100, 600], and CI was already spending 488 ms of it. The upper bound was never the detector. use_shared_resource returns Result<(), AsyncError> and throws AsyncError.Timeout against its own 1000 ms budget if the resource is not released, so the exception is what catches a real fault. Same treatment: keep the lower bound, drop the window.

testFutureWithLockAndCancelled

A different problem in the same file. The test launches a job, waits for it to take the lock, then cancels it. That wait was a plain delay(50) inside runTest, which runs on the virtual clock and returns in about 3 ms, measured. The job was being cancelled before it ever took the lock, so the test had not been exercising the case it describes. Moving the wait onto Dispatchers.Default makes it real, which took the test from 1-15 ms to 68 ms.

Its wall-clock cap is removed rather than widened, for the same reason as its sibling: an unreleased lock surfaces as AsyncError.Timeout from the second acquire, and any cap large enough to be safe today is still a cliff on a runner that spent 388 ms of overhead on a single call in this very file.

Testing

All three pass locally on jvmTest and macosArm64Test, and uniffi-tests-gir, macos passes on CI. Each was also checked in the failing direction: shortening a sleep to simulate a future completing early trips the new lower bound, and releasing the shared resource immediately trips the other one. The old testBrokenSleep measured 523 ms locally unloaded and 524 ms under 96 spinners on 12 cores, which is why this reproduces on CI runners and not on a laptop.

What this gives up

A future that completes late but eventually, say after five seconds, is now caught by runTest's 60 s timeout rather than by a 1000 ms cap. That trade is deliberate.


Written with AI assistance (Claude Code) and pending human review, per CONTRIBUTING.md.

🤖 Generated with Claude Code

SalvatoreT and others added 2 commits August 2, 2026 20:46
The test slept for a nominal 500 ms across four awaits and required the
total to land in [500, 1000]. On the macOS runners it came in at 1001 ms
and 1008 ms on the two most recent PR runs, failing by 1 ms and 8 ms.

The overhead is structural, not contention. Each awaited Rust timer
spawns a thread and resumes back through the FFI. Locally that costs
about 5 ms; on the shared macOS runners the same four awaits account for
roughly 500 ms, or about 125 ms each. testSleepWithRepeat shows the same
effect independently in the same job: 65 sequential 20 ms sleeps, nominal
1.3 s, actual 6.9 s, so about 86 ms per await there. Either way the
per-await cost dwarfs the sleeps, and raising the cap only moves the
cliff since that cost has no upper bound on a shared VM.

What the test is really for is that a waker firing a second time does not
corrupt its own future or let a later one finish early. That is a lower
bound, and lower bounds do not care how loaded the machine is:
thread::sleep is an at-least guarantee and measureTime is monotonic. So
assert each step took at least as long as it slept, and drop the upper
bound. These bounds are weaker than ones the file already relies on:
assertApproximateTime asserts an exact nominal lower bound with no slack
on eight other tests, across the same platforms.

Also added the shouldBe true checks the previous version dropped.

What this gives up: a future that completes late but eventually, say
after five seconds, is now caught by runTest's 60 s timeout rather than
by a 1000 ms cap. That trade is deliberate.

Verified locally. The rewritten test passes on both jvmTest and
macosArm64Test. Shortening one sleep to simulate a future completing
early still fails it, so the assertions have not gone slack.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Two follow-ups in the same file, both found while tracking down the
testBrokenSleep failure.

testFutureWithLockButNotCancelled was next in line to flake. It sleeps a
nominal 100 ms and allowed [100, 600]; CI was already spending 488 ms of
that, 81% of the budget. The upper bound was never the thing catching a
real fault anyway: use_shared_resource returns Result<(), AsyncError> and
throws AsyncError.Timeout against its own 1000 ms budget if the resource
is not released, so the exception is the detector and the clock only has
to confirm the first call actually held the lock. Same treatment as
testBrokenSleep: keep the lower bound, drop the window.

testFutureWithLockAndCancelled had a subtler problem. It launches a job,
waits for it to take the lock, then cancels it. The wait was a plain
delay(50) inside runTest, which runs on the virtual clock and returns in
about 3 ms, measured. So the job was being cancelled before it ever took
the lock and the test had not been exercising the case it describes.
Moving the wait onto Dispatchers.Default makes it real, which took the
test from 1-15 ms to 68 ms.

Its wall-clock cap is gone rather than widened. The same reasoning
applies as for its sibling: an unreleased lock surfaces as
AsyncError.Timeout from the second acquire, so the cap was not the
detector, and any cap large enough to be safe today is still a cliff on a
runner that spent 388 ms of overhead on a single call in this very file.

Both verified locally on jvmTest and macosArm64Test, and the surviving
assertion still fails when it should: releasing the shared resource
immediately trips the new lower bound.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
@SalvatoreT

Copy link
Copy Markdown
Contributor Author

Folded into #294, which now covers both this and CoverallTest.threadSafe. Same commits (cdc4c3e, 9679f6e), same class of bug: tests asserting on wall-clock time or thread scheduling rather than on the invariant they actually guard.

Nothing is lost by closing this. #294 carries the full rationale for all four tests.

@SalvatoreT SalvatoreT closed this Aug 3, 2026
@SalvatoreT
SalvatoreT deleted the salvatoret/fix-flaky-futures-timing branch August 3, 2026 06:07
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant