fix(mount): bound the relayfile change feed so a hung tail read cannot wedge the readiness sweep - #368
Conversation
…t wedge the sweep #354 bounded every relayfile read except the two the discovery sweep makes first. `getEventHighWatermark()` and `getEvents()` went straight to the SDK with no deadline and no signal, and per `relayfile-operation-timeout.ts` the SDK attaches an `AbortSignal` to its `fetch` only when the caller supplies one — so both were bare `fetch()` calls that can wait forever. That is the deployed wedge. `#prepareDiscoverySession` calls `#discoveryHighWatermark()` -> `mount.getEventHighWatermark()` as the FIRST network read after `#runOnceWithDiscoveryFence` claims the discovery lease, before `#performRunOnce` logs anything. On the live instance (0.1.74, boot 2026-08-25T06:13:07Z) the sweep that started 06:17:21.603Z was still in flight 24 minutes later with `consecutiveFailures: 0`, and the daemon's own output ring over that window contains no `run-once started`, no ready-issue read progress, and no discovery-phase `listTree` — only the live event drain's. The sweep never reached enumeration, and 24 minutes is well past the 5-minute budget every `#bounded` call already carries, so the await it was held on had to be one outside that wrapper. There are exactly two. The sweep's own 90-minute deadline cannot substitute. It rejects the wait and leaves `runOnce()` running, so the next cycle coalesces onto the same wedged promise; a per-call rejection unwinds the pass and releases the discovery lease instead. Both feed methods now go through the existing `#bounded()` helper. The cursor-paged `getEvents` gets real cancellation — `GetEventsOptions` carries a `signal`. `listLastNChanges` cannot: its `ProactiveRequestContext` has no signal field, so it is bounded by `withRelayfileCallDeadline`'s race, the abandoned-wait backstop that module documents for exactly this case. Weaker (the socket stays live) but it is the half that matters: the rejection unwinds the sweep. Tests, must-fire and must-not-fire for each: - must-fire: with a 25 ms budget and a change feed that never answers, `getEventHighWatermark()`, `getEvents({ last })` and `getEvents({ cursor })` each reject as `RelayfileOperationTimeoutError` naming the operation, and the cursor path's signal is `aborted`. Verified fail-first: with the fix reverted all three fail by TIMING OUT at vitest's 5 s default — the production mechanism, not an assertion detail. - must-not-fire: a served read under a 60 s budget still returns its watermark and still makes exactly one call; with `operationTimeoutMs: 0` the hung read stays pending, so the rejections above are attributable to the budget and not to the wrapper. Not fixed here, and filed as separate defects on factory-cloud#55: `confirmWrite`'s `getOp` loop checks its deadline BETWEEN calls, so it can never interrupt one; and a `503 agent_host_unavailable` release against a host node offline for days is retried every second forever. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Session-Id: 6534f313-3c75-412b-bfd4-6ac9b59b9405
|
@coderabbitai review Requested for exact head |
|
No actionable comments were generated in the recent review. 🎉 ℹ️ Recent review info⚙️ Run configurationConfiguration used: Organization UI Review profile: CHILL Plan: Pro Plus Run ID: 📒 Files selected for processing (2)
Included review availability: Your plan provides up to 1 included review per hour; 0 remain after this review. 📝 WalkthroughWalkthroughThe change-feed client now applies operation deadlines to tail, high-watermark, and cursor reads. Tests cover signal propagation, timeout handling, transport cancellation, successful reads, and unbounded operation. ChangesChange-feed deadline handling
Estimated code review effort: 2 (Simple) | ~10 minutes Merge Risk: ⚪ Minimal · up to This localized change bounds change-feed reads and includes passing targeted tests and type checking; no actionable merge-blocking risk remains after normal checks and review. Suggested reviewers: Poem
🚥 Pre-merge checks | ✅ 5✅ Passed checks (5 passed)
Full details: Docstring CoverageExplanation No functions found in the changed files to evaluate docstring coverage. Skipping docstring coverage check. Docstring coverage is scoped to functions touched by this diff. Analyzed 0 functions across 2 files. ✨ Finishing Touches📝 Generate docstrings
🧪 Generate unit tests (beta)
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. Comment |
Corrections to two things said off my working tree — both matter operationally1. Your reading of the change is right. 2. factory-cloud#56 does NOT put anything on
// AUTHENTICATED only. See container/dispatch-contract.mjs for why the
// repo list must never join the public `/healthz` projection above.
dispatchContract: await readDispatchContract(),Confirmed empirically. The #56 deploy rebooted the container at And So build identity still rests on the chain I put on Also worth recording, since it is the trap I nearly fell into: on factory-cloud#55 I show Live evidence has resetThe #56 deploy replaced the container, so the 06:13:07Z wedge I diagnosed is gone and the |
Three notes on the production evidence read1. The mount is healthy. This PR is not a claim that it is broken — say so explicitly.
The transport is fine. One specific pair of calls on it never returns while its siblings 2. Worth saying before the next
For the 06:13 boot that was The corollary is the reason this PR matters: after it lands, that same wedge produces 3. One correction: the missing Your caveat is the right one, and it is already settled — I checked it against the The fields are absent for the reason #363's own comment gives at (The trap worth recording: 4. |
![cubic-dev-ai[bot]](https://avatars.githubusercontent.com/in/1082092?s=60&v=4){kind=small}
CI green at this PR's head — and a prediction that came true in production
All three equal. Not a review. The green The wedge reappeared on the new boot, on scheduleI predicted in the first comment Two sweeps complete cheaply ( Two things that follow, both worth having on the record before the next
Ready for the gate. Do not merge — factory-lead holds it. |
The wedge, measured for 10 minutes on the post-#56 bootCompleting the sampler from the previous comment. Boot The wedged pass started at Making "advances with wall clock" quantitative rather than asserted — per-sample deltas Over the nine samples, in-flight advanced 540,600 ms against ~540.6 s of wall clock. Note the two cheap passes before it ( Nothing here changes the diagnosis or the fix; it removes the last bit of hand-waving from |
1 participant
Do not merge — factory-lead holds the gate
This is the deployed dispatch wedge. #354 bounded every relayfile read except the two
the discovery sweep makes first: the change-log tail reads.
The defect
src/mount/relayfile-cloud-mount-client.ts, before this change:No
#bounded, norelayfileCallDeadline, nowithRelayfileCallDeadline, noAbortSignal. Permount/relayfile-operation-timeout.ts:3-8, the SDK "attaches anAbortSignalto itsfetchonly when the caller supplies one" — so each of these is abare
fetch()that can wait forever.grep -c '#bounded('on the shippeddist/mount/relayfile-cloud-mount-client.jsin@agent-relay/factory@0.1.74returns5:
readFile,writeFile.readRevision,deleteFile.readCurrent,ensureSubRoot— plus
listTreeusing the deadline primitives directly. The event feed was missed.Why this is the wedge, not a theoretical hole
#prepareDiscoverySession(orchestrator/factory.ts:3860) calls#discoveryHighWatermark()(:3865→:3958) →mount.getEventHighWatermark()as thefirst network read after
#runOnceWithDiscoveryFenceclaims the discovery lease, andbefore
#performRunOncelogs anything at all.Measured on the live instance (
@agent-relay/factory@0.1.74, boot2026-08-25T06:13:07Z,deploy run
32815029701/e19dcf4):06:17:21.603Zwas still in flight at06:41:18Z—inFlightMs: 1426351(23.8 min),missedPasses: 23,consecutiveFailures: 0./evidence, Release-on-question, wake-on-reply: don't hold an agent's session while a human answers #77) there isno
run-once started, no ready-issue read progress, and everylistTreecarries
phase: "dependency PR probe resolution"— the live event drain — never adiscovery phase. The sweep never reached enumeration.
#boundedcall already carries(
DEFAULT_RELAYFILE_OPERATION_TIMEOUT_MS, no config override), so the await it was heldon had to be one outside that wrapper. There are exactly two, and they are both here.
The ~4.3-minutes-after-every-boot signature follows from
DISCOVERY_SWEEP_LEASE_MS = 5 * 60_000(factory.ts:506): the dead container's leaseoutlives its process, so the first couple of sweeps return
discoveryDeferred: "sweep-in-flight"inlastDurationMs: 735, and the pass that finally reclaims the leaseis the one that hangs.
Full await audit, and the build-identity proof, on
factory-cloud#55.
THIS IS A DEADLINE, NOT A CANCELLATION — read this before extending it
Say it plainly so nobody later mistakes one for the other:
getEvents(cursor-paged) gets real cancellation.GetEventsOptionscarries asignal, so the abort reaches the transport, same aslistTree.listLastNChangesdoes not, and cannot. ItsProactiveRequestContextis{ workspaceId, token? }— there is nosignalfield to pass. It is bounded bywithRelayfileCallDeadline's race instead: the abandoned-wait backstop that moduledocuments for "mount implementations that cannot honour a signal". That is genuinely
weaker than
listTree's cancellation — the socket and the SDK's own retry loop staylive, and a read the SDK has cached as in-flight is not torn down.
The half that matters here is the other one. The rejection unwinds the sweep, which
releases the discovery lease, so the next cycle starts clean instead of coalescing onto a
wedged
runOnce(). That coalescing is the whole reason the existing 90-minute sweepdeadline cannot recover this:
#runOnceWithReadinessDeadline(factory.ts:2200) rejectsthe wait and leaves
runOnce()running, andrunOnce()(:2988) hands the next passthe same wedged
#runOnceInFlightpromise — which is the mechanism behinddiscoveryDeferred: "sweep-in-flight"and behind an occupant reaching 4.14 days.consecutiveFailurescan therefore rise at most 1 per 90 minutes, sofailureThreshold: 3is 4.5 hours away, and evendegradedonly reports —isDeploymentHealthystill answersok: true, so nothing replaces the container.Getting real cancellation for the tail read needs a
signalon the SDK'sProactiveRequestContext; that is an upstream@relayfile/sdkchange and is deliberatelynot in this PR.
Tests — must-fire and must-not-fire for each
Must-fire (25 ms budget, change feed that never answers):
bounds the discovery high-watermark read that wedged the sweepgetEventHighWatermark()rejectsRelayfileOperationTimeoutError,operation: 'listLastNChanges',timeoutMs: 25bounds the change-log tail read behind a provider-filtered getEventsgetEvents({ last })rejects the same waycancels a cursor-paged getEvents at the transportgetEvents({ cursor })rejects andclient.seenSignal.aborted === trueVerified fail-first, by reverting only the source file and re-running: all three fail,
and they fail by
Error: Test timed out in 5000ms— the call never returns. Thatfailure mode is the production defect, not an assertion detail.
Must-not-fire — so the bound cannot be satisfied by deleting it, and so the rejections
above are attributable to the budget rather than to the wrapper:
leaves a served change-feed read alone under a generous budget'11'and still makes exactly one call,{ limit: 10, context: { workspaceId: 'rw_test' } }leaves the change-feed read unbounded when no budget is configuredoperationTimeoutMs: 0: the hung read is still'pending'after 50 msBoth pass with and without the change, which is what makes them controls.
One pre-existing assertion moved with the behaviour:
delegates readFile/listTree/getEvents with the configured workspace idnow expects thegetEventsoptions to carrysignal: expect.any(AbortSignal)withaborted === false,exactly as its
listTreesibling already did.Local:
npx vitest run src/mount/relayfile-cloud-mount-client.test.ts→ 79 passed,exit 0.
npx tsc --noEmit -p tsconfig.build.json→ exit 0.Deliberately NOT in this PR
Two separate defects found while diagnosing, both written up on factory-cloud#55:
confirmWrite'sgetOploop (relayfile-cloud-mount-client.ts:1053-1058) —const deadline = Date.now() + 90_000; for(;;) { await this.#client.getOp(...) }. Thedeadline is evaluated between calls, so it can never interrupt one. Same class of
bug, different call path, not on the reconcile path.
The dead-host release loop.
/evidenceshows three agents retried every second,forever, against
RelayError 503 rawCode=agent_host_unavailable retryable=true, on anode whose
lastHeartbeatAtis 2.9 days old. 27 identical cycles in 15.7 minutes,zero progress. It is generating essentially all of the daemon's log volume. It is
timer-driven and does not block the sweep, so it is not this outage — but a
permanently-dead host node needs a cap or a terminal classification, the way fix(factory): treat 404 agent_not_found on release as terminal success #365
terminalised a 404.
#runOnceWithDiscoveryFence's Relayfile-overload backoff (factory.ts:3049,await this.#clock.sleep(delayMs)) is unbounded by construction. Not the culprit here— it logs a
warnthat would still be in the ring — but it is a real third hole.Reported by
wedge-layer2tofactory-lead.Summary by cubic
Bounds the relayfile change feed reads so a hung tail read can’t wedge the discovery sweep. Previously
getEventsandgetEventHighWatermarkissued uncancelled, unbounded calls; now they respect the per-call timeout and unwind the sweep on timeout instead of hanging indefinitely.getEventsruns through the existing#boundedhelper and passes asignalso the SDK can cancel in-flight requests.listLastNChangesis wrapped in a new#boundedListLastNChangeshelper; it’s deadline-bounded via a race (no transport cancel in the SDK context).signal: AbortSignalon change-feed calls.operationTimeoutMs: 0keeps the feed unbounded, and healthy reads under generous budgets are unaffected.Written for commit 71e5c87. Summary will update on new commits.