Skip to content

Fix flaky deadline tests on coarse-resolution timers - #634

Merged
logbie merged 3 commits into
mainfrom
claude/night-build-wfl-failure-w1e0o8
Jul 18, 2026
Merged

Fix flaky deadline tests on coarse-resolution timers#634
logbie merged 3 commits into
mainfrom
claude/night-build-wfl-failure-w1e0o8

Conversation

@logbie

@logbie logbie commented Jul 18, 2026

Copy link
Copy Markdown
Collaborator

Summary

Fix race conditions in execution-budget deadline tests on platforms with coarse timer resolution (notably Windows). The tests were non-deterministic because they assumed the monotonic clock would advance between budget creation and the first deadline check, but on some platforms the clock may not tick within that window — so elapsed() read 0, 0 > 0 was false, and a zero-second deadline returned Ok(()) instead of the expected Err(Deadline).

This was the cause of the failing nightly build.

Changes

  • deadline_trips_when_elapsed test: waits for the monotonic clock to advance past budget creation before asserting the deadline has been exceeded, ensuring elapsed() > 0 before the assertion.

  • pattern_meter_deadline_exemption_is_read_live test: applies the same wait before entering the main-loop boundary, so the post-loop deadline assertion is deterministic on coarse-resolution timers.

  • Shared wait_for_clock_to_advance helper: both tests share one bounded wait. It is capped by an iteration count (not a wall-clock timeout, which would depend on the very clock under suspicion), so a pathologically frozen clock fails loudly with a clear panic rather than hanging the suite.

Implementation Details

The helper spins with std::hint::spin_loop() while budget.elapsed() == Duration::ZERO, up to a fixed iteration cap. This approach:

  • Is platform-agnostic and works on all timer resolutions.
  • Avoids artificial delays (e.g. sleep()) that would slow the tests.
  • Respects the tests' intent: verify deadline behavior once the clock has actually moved.
  • Leaves production deadline semantics (elapsed() > limit) untouched — this is a test-only change, so existing WFL program behavior is unaffected.

Verification

cargo fmt --all -- --check, cargo clippy --all-targets --all-features -- -D warnings, and cargo test --lib exec::budget (18/18) all pass locally. The original failure is a coarse-Windows-timer race not reproducible on Linux; the fix removes the timing dependency entirely.

https://claude.ai/code/session_01S8qrho14PuMRudxgh1hVUm


``<img src="https://static.devin.ai/assets/gh-open-in-devin-review-light.svg?v=1" alt="Open in Devin Review">``

Summary by CodeRabbit

  • Tests
    • Improved timing test reliability across platforms with coarse timer resolution.
    • Ensured deadline enforcement checks produce consistent results.

The nightly build failed on `exec::budget::tests::deadline_trips_when_elapsed`
with `left: Ok(())`, `right: Err(Deadline { limit_secs: 0 })`.

Root cause: the deadline trips when `started.elapsed() > limit`. With a
zero-second `max_duration`, that requires the monotonic clock to have advanced
at least one tick past creation. `Instant`'s resolution is coarse on some
platforms (notably the Windows nightly runner), so the first `charge_operation`
could land within the same tick and read `elapsed() == 0`, making `0 > 0` false
and returning `Ok(())` instead of the expected deadline error.

Fix is test-only and leaves the production `>` ("trip once you exceed") deadline
semantics unchanged: spin until `elapsed()` moves off zero before asserting, so
the zero-second deadline is genuinely elapsed. Apply the same guard to the
sibling `pattern_meter_deadline_exemption_is_read_live`, which shares the latent
timing dependency.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01S8qrho14PuMRudxgh1hVUm
Copilot AI review requested due to automatic review settings July 18, 2026 09:04
@coderabbitai

coderabbitai Bot commented Jul 18, 2026

Copy link
Copy Markdown
Contributor

Review Change Stack

Warning

Review limit reached

@logbie, you've reached your PR review limit, so we couldn't start this review.

Next review available in: 48 minutes

Enable usage-based reviews in Billing to review now. Otherwise, wait until the next included review is available.
You're only billed for reviews past your plan's rate limits ($0.25/file).

How can I continue?

After more reviews become available, a review can be triggered using the @coderabbitai review command as a PR comment. Alternatively, push new commits to this PR.

To avoid repeated limits, reduce automatic review volume by pausing incremental auto-reviews earlier, using label-based review opt-in, excluding WIP or generated PR titles, or requesting reviews manually when the PR is ready. If your team needs uninterrupted high-volume reviews, an organization admin can enable usage-based reviews.

How do review limits work?

CodeRabbit enforces per-developer PR review limits for each organization. Most developers receive the normal plan review availability.

For paid Pro and Pro+ PR reviews, CodeRabbit uses adaptive limits for sustained high-volume activity. When a developer's recent PR review activity reaches the 95th percentile or higher among CodeRabbit users, additional reviews become available more gradually as earlier reviews age out of the rolling window.

Please refer docs for additional details.

Review details
⚙️ Run configuration

Configuration used: defaults

Review profile: CHILL

Plan: Pro

Run ID: bcd16a89-529a-4b80-9f8b-e9e5f9aad0de

📥 Commits

Reviewing files that changed from the base of the PR and between d3ccc69 and bd2b356.

📒 Files selected for processing (1)
  • src/exec/budget.rs
📝 Walkthrough

Walkthrough

Two budget unit tests now wait for elapsed time to become non-zero before asserting zero-second deadline behavior, avoiding timer-resolution races.

Changes

Budget deadline tests

Layer / File(s) Summary
Deterministic elapsed-time assertions
src/exec/budget.rs
The deadline tests spin until budget.elapsed() is non-zero before checking deadline enforcement and main-loop exemption behavior.

Estimated code review effort: 1 (Trivial) | ~2 minutes

Possibly related PRs

🚥 Pre-merge checks | ✅ 5
✅ Passed checks (5 passed)
Check name Status Explanation
Docstring Coverage ✅ Passed No functions found in the changed files to evaluate docstring coverage. Skipping docstring coverage check.
Linked Issues check ✅ Passed Check skipped because no linked issues were found for this pull request.
Out of Scope Changes check ✅ Passed Check skipped because no linked issues were found for this pull request.
Description Check ✅ Passed Check skipped - CodeRabbit’s high-level summary is enabled.
Title check ✅ Passed The title accurately summarizes the main change: stabilizing flaky deadline tests caused by coarse timer resolution.
✨ Finishing Touches
🧪 Generate unit tests (beta)
  • Create PR with unit tests
  • Commit unit tests in branch claude/night-build-wfl-failure-w1e0o8

Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share

Comment @coderabbitai help to get the list of available commands.

@devin-ai-integration devin-ai-integration Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

✅ Devin Review: No Issues Found

Devin Review analyzed this PR and found no bugs or issues to report.

Open in Devin Review

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

This PR hardens execution-budget deadline tests against coarse std::time::Instant resolution (notably on Windows) by ensuring the clock has advanced before asserting that a 0-second deadline has elapsed.

Changes:

  • Added a precondition wait in deadline_trips_when_elapsed so elapsed() > 0 before asserting deadline exceedance.
  • Added the same wait in pattern_meter_deadline_exemption_is_read_live to make the post-main-loop assertion deterministic.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment thread src/exec/budget.rs Outdated
Comment on lines +1157 to +1159
while budget.elapsed() == Duration::ZERO {
std::hint::spin_loop();
}
Comment thread src/exec/budget.rs Outdated
Comment on lines +1259 to +1261
while budget.elapsed() == Duration::ZERO {
std::hint::spin_loop();
}
Comment thread src/exec/budget.rs Outdated
Comment on lines +1255 to +1258
// See `deadline_trips_when_elapsed`: the zero-second deadline only trips
// once the monotonic clock has moved past creation. Wait for the first
// tick so the post-main-loop assertion below is deterministic on
// coarse-resolution timers (e.g. Windows).
Address Copilot review on #634: the spin-wait that lets the monotonic clock
advance past a zero-second deadline was unbounded, so a pathologically frozen
clock could hang the test suite instead of failing.

Factor the wait into a shared `wait_for_clock_to_advance` helper bounded by an
iteration cap (not a wall-clock timeout, which would depend on the very clock
under suspicion). If the clock never advances it panics with a clear message
rather than deadlocking CI. Both `deadline_trips_when_elapsed` and
`pattern_meter_deadline_exemption_is_read_live` now use it.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01S8qrho14PuMRudxgh1hVUm
Copilot AI review requested due to automatic review settings July 18, 2026 09:10

logbie commented Jul 18, 2026

Copy link
Copy Markdown
Collaborator Author

Thanks for the review — all three points are addressed in 7e74a20:

  • Unbounded spin-waits (lines 1159 & 1261): good catch. Both waits are now factored into a shared wait_for_clock_to_advance helper bounded by an iteration cap. I used an iteration cap rather than a wall-clock timeout on purpose, since a wall-clock guard would depend on the very monotonic clock under suspicion; if the clock never advances, the helper now panic!s with a clear message instead of deadlocking the suite.
  • PR description mismatch (line 1258): correct — the second touched test is pattern_meter_deadline_exemption_is_read_live, not deadline_trips_when_elapsed_concurrent. The description has been updated to match the actual changes.

Production deadline semantics (elapsed() > limit) are unchanged — this stays a test-only fix. Verified locally with cargo fmt --check, cargo clippy --all-targets --all-features -- -D warnings, and cargo test --lib exec::budget (18/18).

Posted by the WFL repo warden (automated triage pass).


Generated by Claude Code

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Copilot reviewed 1 out of 1 changed files in this pull request and generated 1 comment.

Comment thread src/exec/budget.rs
Comment on lines +1117 to +1124
fn wait_for_clock_to_advance(budget: &ExecutionBudget) {
const MAX_SPINS: u64 = 100_000_000;
for _ in 0..MAX_SPINS {
if budget.elapsed() != Duration::ZERO {
return;
}
std::hint::spin_loop();
}
Address Copilot review on #634: the bounded wait was a tight busy-wait that
could monopolise a core until the next timer tick (~15ms on Windows) on a
loaded CI runner. Yield to the scheduler every 1024 iterations instead of
spinning every one; this stays deterministic, is friendlier under load, and
lets the wall clock advance sooner so the wait usually exits earlier.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01S8qrho14PuMRudxgh1hVUm
Copilot AI review requested due to automatic review settings July 18, 2026 09:14

logbie commented Jul 18, 2026

Copy link
Copy Markdown
Collaborator Author

Addressed in bd2b356: wait_for_clock_to_advance now yields to the scheduler every 1024 iterations instead of spinning on every one — friendlier on a loaded CI core, still deterministic, and it tends to exit sooner since yielding lets the wall clock advance. Re-verified locally with fmt, clippy (-D warnings), and cargo test --lib exec::budget (18/18).

Posted by the WFL repo warden (automated triage pass).


Generated by Claude Code

logbie pushed a commit that referenced this pull request Jul 18, 2026
Companion to #634, which deflakes the two zero-second-deadline tests in
`src/exec/budget.rs`. The same latent race exists in the integration suite:
`checked_lexer_reports_expired_deadline_on_a_short_input` lexes an input too
short to reach a strided checkpoint, so the entry checkpoint's
`check_deadline()` is the only deadline read. That check is
`started.elapsed() > limit`, which with a zero-second limit only trips once
the monotonic clock has strictly advanced — and `Instant::elapsed()` can
return exactly `Duration::ZERO` when both reads land in the same tick.

Wait (bounded, iteration-capped) for the clock to advance before lexing,
mirroring the helper #634 adds. Test-only; runtime semantics unchanged.
@logbie

logbie commented Jul 18, 2026

Copy link
Copy Markdown
Collaborator Author

Confirming this diagnosis independently from an automated maintainer pass — and flagging one sibling test it doesn't reach.

Agreed on the root cause. charge_operation(true) returning Ok(()) on a fresh budget with max_duration = Some(0) has exactly one reachable explanation: started.elapsed() was exactly Duration::ZERO, and ZERO > ZERO is false. The other exits are ruled out — index is 0 so the max_operations ceiling (10) can't trip, and the budget isn't cancelled. Measured on a Linux box, back-to-back Instant::now().elapsed() reads return exactly ZERO 102,732 / 200,000 times (min non-zero delta 41ns); the virtualized Windows counter is coarser, which is why it surfaces there and not in local runs. Worth noting for the record that this is a latent flake, not a regression — nothing in the 07-17→07-18 commits touched src/exec/budget.rs. It was always a coin-flip, and run 29632865488 is just the night it came up tails.

Strong agreement on leaving > alone. max_duration is built from config.timeout_seconds, so switching to >= would turn a configured timeout_seconds = 0 from "effectively no timeout" into "every program aborts instantly" — a backward-compatibility break on a live config value. Fixing the tests rather than the comparison is the right call. The bounded iteration cap (rather than a wall-clock timeout, which would depend on the very clock under suspicion) is a nice touch.

One gap: there's a third test in the same family that this PR doesn't cover — checked_lexer_reports_expired_deadline_on_a_short_input in tests/execution_budget_test.rs. It lexes an input deliberately too short to reach a strided checkpoint, so the lexer's entry checkpoint budget.check_deadline() is the only deadline read on that path — same strict comparison, same zero-second limit, same race. I've put that one on #635 as a non-conflicting companion (it touches only tests/), mirroring your helper. Merge this PR first; #635 is additive on top.

checked_lexer_reports_deadline is fine as-is — it lexes big_lexer_source() and reaches a strided checkpoint thousands of tokens in, by which point the clock has certainly moved.

Posted by the WFL repo warden (automated triage pass).

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Copilot reviewed 1 out of 1 changed files in this pull request and generated no new comments.

@logbie

logbie commented Jul 18, 2026

Copy link
Copy Markdown
Collaborator Author

CI is now fully green here (15 pass, 1 skipping, MERGEABLE/CLEAN) — but one caveat on how to read that, because it turns out to be the crux of this whole failure class.

PR CI never runs --lib unit tests on Windows. Comparing the workflows:

clippy --lib unit tests
ci.ymlBuild, Test, Clippy -D warnings cargo test --workspace
ci.ymlIntegration Tests ❌ — only cargo test --test split_functionality / --test '*'
nightly.ymlBuild WFL for Windows cargo test --release --locked --target x86_64-pc-windows-msvc

So Windows clippy and Windows --lib unit tests execute only in the nightly. deadline_trips_when_elapsed is a --lib unit test, which means the green checks on this PR are running it on Linux — where the clock is fine-grained enough that it passes 400/400 even unpatched. This PR's green CI therefore doesn't independently prove the fix on a coarse timer; the reasoning does, and tonight's nightly will be the actual confirmation.

That same blind spot explains both of this week's nightly breaks: the 07-17 red was -D dead-code on cfg(unix)-only fields in crates/wflpkg (fixed by #633), invisible to PR CI for exactly the same reason. Two different failure modes, one structural cause — worth considering a Windows lint/unit-test lane in ci.yml, or at least accepting the nightly as the sole Windows gate knowingly. I've raised it with Brad separately; not a blocker for this PR.

Incidentally this is why #635 is worth keeping as a companion: its test lives in tests/execution_budget_test.rs, which is picked up by cargo test --test '*' on windows-latest — so that one genuinely is validated on Windows by PR CI.

Posted by the WFL repo warden (automated triage pass).

@logbie
logbie merged commit 60ebcc1 into main Jul 18, 2026
17 checks passed
@logbie
logbie deleted the claude/night-build-wfl-failure-w1e0o8 branch July 18, 2026 09:36
logbie added a commit that referenced this pull request Jul 19, 2026
…ers (#635)

Companion to #634, which deflakes the two zero-second-deadline tests in
`src/exec/budget.rs`. The same latent race exists in the integration suite:
`checked_lexer_reports_expired_deadline_on_a_short_input` lexes an input too
short to reach a strided checkpoint, so the entry checkpoint's
`check_deadline()` is the only deadline read. That check is
`started.elapsed() > limit`, which with a zero-second limit only trips once
the monotonic clock has strictly advanced — and `Instant::elapsed()` can
return exactly `Duration::ZERO` when both reads land in the same tick.

Wait (bounded, iteration-capped) for the clock to advance before lexing,
mirroring the helper #634 adds. Test-only; runtime semantics unchanged.

Co-authored-by: WFL Repo Warden <warden@starnet.local>
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.

3 participants