Stop UniFFI tests depending on wall-clock timing and thread scheduling - #294
Draft
SalvatoreT wants to merge 3 commits into
Draft
Stop UniFFI tests depending on wall-clock timing and thread scheduling#294SalvatoreT wants to merge 3 commits into
SalvatoreT wants to merge 3 commits into
Conversation
The test has one coroutine busy-wait while another calls incrementIfBusy a fixed 100 times, then asserts the second one saw the first as busy at least once. Those 100 calls are fast. On a loaded runner they can all finish before the busy-waiting coroutine is scheduled at all, leaving count at 0 and failing an assertion about UniFFI locking that has nothing to do with locking. It fails on main, and on PRs whose diffs cannot reach this code. Poll until the busy window is actually observed instead of counting iterations. The loop exits as soon as count goes above 0, so the normal case still takes microseconds, and a starved machine waits as long as it needs to. The busy-waiting side only starts once the incrementing side signals it is running, which removes the case where the incrementer has not started at all by the time the window closes. A thread that is running but starved for the entire window could still fail, so this narrows the race rather than closing it outright. The test still catches what it was written for. If UniFFI serialized access to the counter, the first incrementIfBusy would block for the whole busy wait and return with is_busy already cleared, so count stays 0, the loop ends, and the assertion fails. Confirmed by forcing the interleaving rather than waiting for a race. Delaying the busy-waiting coroutine by 200 ms reproduces the CI failure exactly on the old code, AssertionError at CoverallTest.kt:530, and passes on the new. Wrapping both calls in a shared lock to stand in for serialized access still fails, so the assertion has not gone vacuous. Six runs under 72 spinners on 12 cores all pass. Four copies of this test exist and all four now match. The one CI reported is coverall-jvm. Also unified the KMP copy's busy wait from 1000 ms down to 300 ms, since the duration no longer sets the margin. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
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>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Four tests across two fixtures assert on wall-clock time or on thread scheduling. All four flake on loaded CI runners, and two of them are failing right now. This replaces those assumptions with ones that hold regardless of how busy the machine is.
None of these are UniFFI bugs. Each test is guarding something real, and each still fails when that real thing breaks.
CoverallTest.threadSafe
One coroutine busy-waits while another calls
incrementIfBusya fixed 100 times, then the test asserts the second one saw the first as busy at least once. Those 100 calls are fast. On a loaded runner they can all finish before the busy-waiting coroutine is scheduled at all, leavingcountat 0 and failing an assertion about UniFFI locking for reasons that have nothing to do with locking.It fails on
maininuniffi-tests-gir, windows, and on pull requests whose diffs cannot reach this code.Poll until the busy window is actually observed instead of counting iterations:
The loop exits as soon as
countgoes above 0, so the normal case still takes microseconds and a starved machine waits as long as it needs to. Busy-waiting starts only once the incrementing side signals it is running, which removes the case where the incrementer had not started at all by the time the window closed. A thread that is running but starved for the whole window could still fail, so this narrows the race rather than closing it.Serialization is still caught. If UniFFI serialized access to the counter, the first
incrementIfBusywould block for the entire busy wait and return withis_busyalready cleared, socountstays 0 and the assertion fails.Four copies of this test exist and all four now match. The one CI reports is
coverall-jvm. The KMP copy's busy wait is unified from 1000 ms down to 300 ms to match the others, since the duration no longer sets the margin. JS, WASM-JS and WASM-WASI setuniffiSupported = falseand return before any of this runs, so the loop only executes on the JVM and Native three-thread pools.FuturesTest.testBrokenSleep
Nominal 500 ms across four awaits, required 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
mainas 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, costing about 5 ms locally and roughly 125 ms per await on a shared macOS runner.
testSleepWithRepeatshows 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, because 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::sleepis an at-least guarantee andmeasureTimeis monotonic. 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 byrunTest's own timeout.These bounds are weaker than ones the file already relies on.
assertApproximateTimeasserts an exact nominal lower bound with no slack on eight other tests, on these same platforms.FuturesTest.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_resourcereturnsResult<(), AsyncError>and throwsAsyncError.Timeoutagainst 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.FuturesTest.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)insiderunTest, 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 ontoDispatchers.Defaultmakes 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.Timeoutfrom 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
Every change was checked in both directions, because a test that cannot fail is worse than a flaky one.
threadSafe: delaying the busy-waiting coroutine by 200 ms reproduces the CI failure exactly on the old code,AssertionError at CoverallTest.kt:530, and passes on the new. Wrapping both calls in a shared lock to stand in for serialized access still fails.testBrokenSleep: shortening one sleep to simulate a future completing early still trips the new lower bound.testFutureWithLockButNotCancelled: releasing the shared resource immediately still trips its lower bound.Locally everything passes on
coverall-jvm:test,coverall:jvmTest,futures:jvmTestandfutures:macosArm64Test, plus both Android variants compile.threadSafealso survives six runs under 72 spinners on 12 cores. On CI,uniffi-tests-girpasses on both Windows and macOS.For context on why the futures failures do not reproduce on a laptop: the old
testBrokenSleepmeasured 523 ms here unloaded and 524 ms under 96 spinners. Load barely moves it, because the cost is per-await timer and FFI latency on virtualized runners rather than CPU starvation.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.Note
The three cmake failures on Windows are a separate problem with a separate fix in #293. Until that lands, this branch's own CI will still show them.
Written with AI assistance (Claude Code) and pending human review, per CONTRIBUTING.md.
🤖 Generated with Claude Code