Skip to content

fix(test): deflake update-notifier e2e on Windows CI (grace-budget race) - #171

Merged
Mikola Lysenko (mikolalysenko) merged 1 commit into
mainfrom
fix/update-notifier-windows-flake
Aug 13, 2026
Merged

fix(test): deflake update-notifier e2e on Windows CI (grace-budget race)#171
Mikola Lysenko (mikolalysenko) merged 1 commit into
mainfrom
fix/update-notifier-windows-flake

Conversation

@mikolalysenko

@mikolalysenko Mikola Lysenko (mikolalysenko) commented Aug 13, 2026

Copy link
Copy Markdown
Collaborator

Problem

crates/socket-patch-cli/tests/update_notifier_e2e.rs flakes on test (windows-latest) (seen on two unrelated PRs). Two rows fail intermittently:

  • stale_state_rechecks reads the STALE latestSeen (the pre-seeded 3.3.0) instead of the 9.9.9 the mock serves.
  • up_to_date_prints_nothing panics inside wiremock's MockServer::dropverify (exposed_server.rs) because its expect(1) resolve mock was never hit.

Root cause — one race, both symptoms. The passive notifier runs its release check in a detached tokio task and joins it under a hard-coded 500 ms grace in update_notifier::finish. main then calls std::process::exit(code) the instant finish returns. On a fast host the loopback wiremock fetch lands its state write (and its request) in a few milliseconds and beats the ceiling. On a slow host (a loaded Windows CI runner: fsync latency, cold TLS/HTTP client init) the fetch can miss the 500 ms window — finish abandons it, std::process::exit kills the still-running task, and its post-fetch latestSeen write / expect-counted request never happens. refresh_latest writes lastCheckAt before the fetch and latestSeen after it, which is exactly why the stale row sees an advanced lastCheckAt but an unchanged latestSeen.

Note: polling the state file after the run cannot fix this — once the child has exited the write is gone, not merely late, so the file is frozen at the stale value. The wait itself has to become deterministic.

Fix

Give the e2e suite a way to await the fetch to completion instead of racing it, without changing shipped behavior.

  • crates/socket-patch-cli/src/update_notifier.rsfinish's join grace is now read from grace_budget(), which honors a SOCKET_UPDATE_GRACE_MS override and defaults to the same 500 ms (absence/empty/garbage all keep the default). Same shape as the existing SOCKET_UPDATE_TIMEOUT_MS fetch-budget hook and SOCKET_UPDATE_NOTIFIER_FORCE. Production is byte-identical. Added a pure grace_budget_from + unit test pinning the default-preservation and the override.
  • crates/socket-patch-cli/tests/update_notifier_e2e.rs — new eligible_kit_await_fetch helper (eligible_kit + SOCKET_UPDATE_GRACE_MS=30000). Applied to every row that asserts on the check's observable effect: first_eligible_run_checks_and_notices, stale_state_rechecks, up_to_date_prints_nothing, corrupt_state_recovers, future_timestamp_tolerated, and the unix-only real_tty_shows_notice_pty. grace_budget_bounds_command_latency intentionally keeps the real 500 ms ceiling (testing that cutoff is its whole point); cache-only and guard rows spawn no fetch, and dead_endpoint_never_fails_the_command only asserts on the pre-fetch write — none are touched.
  • crates/socket-patch-cli/CLI_CONTRACT.md — documents SOCKET_UPDATE_GRACE_MS in the internal env-var table.

No assertion was weakened: a loopback fetch still completes in milliseconds; only the artificial cutoff that the assertions were unknowingly racing is removed. The intent is unchanged — the stale row still proves the recheck overwrites stale state; the no-news row still proves nothing prints.

Test

  • cargo test -p socket-patch-cli --test update_notifier_e2e35 passed locally (macOS).

  • cargo test -p socket-patch-cli --lib update_notifier → new grace_budget unit test green.

  • cargo build -p socket-patch-cli + cargo clippy -p socket-patch-cli --tests → clean.

  • Deterministic repro of the race (macOS stand-in for slow Windows): injecting a 700 ms metadata delay into stale_state_rechecks fails under the old 500 ms grace with exactly the reported symptom —

    assertion `left == right` failed: the re-check must overwrite the stale latestSeen:
    {"schemaVersion":1,"lastCheckAt":1786645841,"latestSeen":"3.3.0","lastNotifiedAt":null}
      left: String("3.3.0")   right: "9.9.9"
    

    and passes under the lifted ceiling. (Experiment reverted; not part of the diff.)

🤖 Generated with Claude Code


Note

Low Risk
Default grace remains 500 ms; only test env overrides and e2e wiring change. No user-facing behavior change unless SOCKET_UPDATE_GRACE_MS is set.

Overview
Fixes intermittent update_notifier_e2e failures on slow Windows CI by removing a race between the passive update check and process exit.

Problem: finish joined the background release-metadata fetch with a fixed 500 ms grace, then main exited immediately—killing a still-running fetch. On loaded runners the loopback check could miss that window, so latestSeen never updated and wiremock expect(1) mocks were never hit (stale_state_rechecks, up_to_date_prints_nothing).

Changes:

  • update_notifier.rs — Grace is read via grace_budget() / grace_budget_from() from SOCKET_UPDATE_GRACE_MS, defaulting to 500 ms when unset, empty, or invalid (production behavior unchanged).
  • update_notifier_e2e.rseligible_kit_await_fetch adds SOCKET_UPDATE_GRACE_MS=30000 for tests that assert on fetch side effects; grace_budget_bounds_command_latency still uses the real 500 ms ceiling.
  • CLI_CONTRACT.md — Documents the internal test hook env var.

Assertions are not weakened—only the artificial cutoff that tests were racing is lifted for determinism.

Reviewed by Cursor Bugbot for commit 7addae3. Configure here.

The passive update notifier runs its release check in a detached tokio
task and joins it under a 500 ms grace in `finish`; `main` then calls
`std::process::exit` the instant `finish` returns. On a fast host the
loopback wiremock fetch lands its state write / request in a few
milliseconds and wins the race, but on a slow one (a loaded Windows CI
runner: fsync latency, a cold TLS/HTTP client) the fetch can miss the
500 ms window, the task is killed at exit, and its `latestSeen` write or
its `expect`-counted request never happens.

That is the observed flake: `stale_state_rechecks` intermittently reads
the STALE version (the post-fetch write was killed after the pre-fetch
`lastCheckAt` write already landed), and `up_to_date_prints_nothing`
panics in wiremock's `Drop`/`verify` because the `expect(1)` resolve
mock was never hit. Polling the state file after the child exits cannot
recover it — the child is dead and the write is gone, not merely late.

Make the wait deterministic instead of racing it: add a
`SOCKET_UPDATE_GRACE_MS` test hook (same shape as `SOCKET_UPDATE_TIMEOUT_MS`)
that lets the e2e suite lift the join ceiling so `finish` awaits the
fetch to completion. Production keeps the tight 500 ms default, so
shipped behavior is byte-identical. Every row that asserts on the
fetch's observable effect now uses a new `eligible_kit_await_fetch`
helper; `grace_budget_bounds_command_latency` deliberately keeps the
real 500 ms ceiling since testing that cutoff is its whole point.

Verified by reproducing the exact failure deterministically on macOS
(inject a 700 ms metadata delay: fails "reads STALE 3.3.0" under the old
500 ms grace, passes under the lifted ceiling).

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
@mikolalysenko
Mikola Lysenko (mikolalysenko) merged commit ee88c5d into main Aug 13, 2026
62 checks passed
@mikolalysenko
Mikola Lysenko (mikolalysenko) deleted the fix/update-notifier-windows-flake branch August 13, 2026 21:22
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.

2 participants