Skip to content

test(release): run recovery rehearsal observation reads on an injected clock - #877

Merged
blove merged 1 commit into
mainfrom
blove/recovery-rehearsal-reader-clock-874
Oct 1, 2026
Merged

blove merged 1 commit into
mainfrom
blove/recovery-rehearsal-reader-clock-874

Conversation

@blove

@blove blove commented Sep 30, 2026

Copy link
Copy Markdown
Contributor

Refs #874. This PR does not close the issue. I confirmed the failure mechanism but did not reproduce the natural trigger, so #874 should stay open.

What I found

  • The phase-deadline theory doesn't fit. phaseDeadlineMs is 1,200,000 ms (20 minutes) and the failing case ran for 23s. The real-time limits a single observe read can hit are the 15s per-attempt race timer and the 15s HTTP timeout in runRecoveryRead.

  • The mechanism is confirmed. I held one loopback listReleaseAssets GET in audit-dispatch for 16s during the effect 9 after case. That reproduces the reported failure exactly: failed in audit-dispatch; service errors: []; ... exact value read unavailable. The underlying envelope was { status: "ERROR", code: "READ_TIMEOUT_UNSETTLED" }. In that same run, effect 9's fault had already been resumed in five-lanes, so resume() could not retry again. That matches the trace in the issue, where the failure came from the first operation() call.

  • The natural trigger is not reproduced. I ran the 64-case test under ten node -e "" spawn loops, the test(k8s-compat): size the docker smoke watchdog for a wedge, not a stopwatch #715 recipe. Ambient load average was about 147 on 10 cores. Cases slowed to 50–120s, and four hit the 120s case timeout, but no observe read ever came back non-PRESENT. Two triggers are still possible:

    1. A real stall of 15s or more on a loopback read would give READ_TIMEOUT_UNSETTLED.
    2. A wall-clock jump, such as the laptop sleeping during a 17-minute local run, would give RECOVERY_DEADLINE or TIMEOUT. Date.now deadlines include sleep time, but the test runner's monotonic duration does not, which could explain a reported 23s case that contains a 15s timeout.

    The improved diagnostic below will tell these apart next time.

  • Only observe reads ignored injected timing. The recovery writer and auditor already pass the fixture's authority clock into runRecoveryRead. Observe's readerContext always used Date.now and real timers. The writer and audit dependency snapshots also dropped any observation key they didn't list, so nothing could be injected there.

Changes

  • Diagnostic: exact ${key} read unavailable now includes the envelope status, code and operation, for example (ERROR READ_TIMEOUT_UNSETTLED) or (AMBIGUOUS NOT_FOUND_OR_HIDDEN release-assets).
  • Optional reader clock: readerContext accepts an optional complete clock (now, sleep, setTimer, clearTimer). A clock missing any of these is rejected. The clock is passed through every observe entrypoint, through routeRecoveryCandidate's internal calls, and through the writer and audit observation snapshots. When no clock is passed, behaviour is unchanged. No production caller passes one, and nothing production accepts is loosened.
  • Rehearsal: the rehearsal injects the fixture clock the writer and auditor already use. Its reader timers and its GitHub/npm reader HTTP timeouts get a 100s floor, below the 120s per-case timeout. A long stall no longer fails the arc, and a genuinely hung read still fails with the new diagnostic. With the clock injected, the 16s stall completes, and a 105s stall fails at about 108s with (ERROR READ_TIMEOUT_UNSETTLED).
  • Remaining exposure: the writer and audit runRecoveryRead calls still use the real 15s race timer, because they pass only now and sleep. They are out of scope here since the observed failure was in observe.
  • Pins: regenerated the pins for recovery/{audit,observe,writer}.mjs and the STARTING_SCRIPT_PIN_SHA256 snapshot.

No changeset: these are release-script changes only.

Verification (Node 24.20.0)

  • pnpm test:release-integrity: 33/33 pass.
  • node --test scripts/release/test/workflow-contracts.test.mjs: 166/166 pass.
  • node --test scripts/release/test/recovery-observe.test.mjs: 78/78 pass, including three new tests:
    • the diagnostic message format;
    • an injected clock taking over from a jumping Date.now;
    • an incomplete clock being rejected.
  • pnpm test:release-controller: 3986/3986 pass (18.3 min).

🤖 Generated with Claude Code

…d clock

The HTTP recovery rehearsal failed once with "exact value read unavailable"
in audit-dispatch (#874). Observation reads in recovery/observe.mjs are the
only recovery reader path that ignores injected timing: they always use
Date.now and a real 15s per-attempt read timer. Holding one loopback
listReleaseAssets response for 16s reproduces the reported failure exactly
(ERROR READ_TIMEOUT_UNSETTLED); the natural trigger was not reproduced.

- readerContext accepts an optional complete clock (now, sleep, setTimer,
  clearTimer), threaded through every observe entrypoint and the writer and
  audit observation snapshots. Omitted, production behavior is unchanged.
- The rehearsal injects the fixture clock the writer and auditor already use,
  with a 100s read-timer floor, below the 120s per-case timeout, so a hung
  read still fails loudly.
- The "read unavailable" error now names the envelope status, code and
  operation.
- Regenerate the release-script pins and the pin-file digest snapshot.

Refs #874

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@vercel

vercel Bot commented Sep 30, 2026

Copy link
Copy Markdown

The latest updates on your projects. Learn more about Vercel for GitHub.

1 Skipped Deployment
Project Deployment Actions Updated
b4-run Ignored Ignored Sep 30, 2026 8:21pm UTC

Request Review

@github-actions github-actions 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.

Automated approval: this PR received an intelligent (AI) code review. See the review comments on this PR.

@blove
blove merged commit 95e78fc into main Oct 1, 2026
30 of 31 checks passed
@blove
blove deleted the blove/recovery-rehearsal-reader-clock-874 branch October 1, 2026 04:25

This branch was previously deployed

1 inactive deployment
vercel-preview — d3a862ad Deployed Sep 30, 2026 by blove via vercel-native #2499
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