Recover a replication leg wedged at connected:true with no receive progress - #815
Recover a replication leg wedged at connected:true with no receive progress#815kriszyp wants to merge 2 commits into
Conversation
A subscription that parks at connected:true + RECEIVING_STATUS_WAITING with no receive progress is invisible to both main-thread reconcile nets: findWedgedNodeUrls requires connected !== true, and isReceiveStalled requires RECEIVING_STATUS_RECEIVING, while a steady-state subscription that stops receiving parks at WAITING rather than Receiving. In the field that left one user database dead on two nodes for ~21 hours with cluster_status green on every leg and the system database still replicating over the same peer pair. The status check cannot simply be relaxed: WAITING with an old lastReceivedTime is equally the signature of a healthy idle leg. The receiver cannot discriminate locally either, since no shared-status position advertises the sender's head and pongs keep liveness fresh on a wedged-but-open socket. The sending session can, and holds every fact it needs as plain locals: the last sequence it handed to ws.send in a confirmable frame, the peer's latest COMMITTED_UPDATE and when that last changed, and when its send path last advanced. Two shapes close the socket — a peer that has not confirmed data we sent it for the whole threshold, and a send path that has produced nothing for the whole threshold while a fresh read of this peer's own send range still finds entries past the cursor. That re-read is what keeps the second shape off a node which is merely receiving from a third peer, whose store grows with logs the subscription excludes; it uses the loop's exact scope and cursor, is deliberately not the loop's reusable iterable, and runs only once the progress clock has already elapsed. Evaluated on the session's existing back-pressure interval rather than a new timer, and actuated by closing its own socket so the peer reconnects through its ordinary close-handler scheduleReconnect path. The threshold sits above RECEIVE_STALL_THRESHOLD_MS so it orders behind the blob-gap escalation budget instead of racing it. Refs #810 Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01B99rVzH318au3uxfxCyeaM
…lence a table The field signature of the decode drop behind harper-pro#810 was an EMPTY typedStructs on the receiver's decoder. That is not a single unlucky record: under it every later record of that table fails value-decode the same way for the life of the connection, silently, while the leg keeps looking healthy. Only a fresh subscription repairs it, because that is what makes the sender re-send TABLE_FIXED_STRUCTURE. This does not recover the dropped record, and is not meant to. The frame's resume cursor has already advanced past it when the close fires, so the resubscribe resumes after it — that is harper-pro#545's decided disposition (skip-and-advance, to escape the #521 decode/close/resume loop), and holding the pre-frame cursor for a bounded retry is #717's lane. What this bounds is the loss after the record. Fired from the frame's own end_txn onCommit, so it is never mid-frame, never before the cursor that frame advanced is persisted, and at most once per frame. Copy frames are excluded: a copy stages its cursor from the last successfully decoded record, so closing after a dropped copy record would resume before it and re-deliver the same poison record — reinstating exactly the loop #545 removed. The permanent skip-missing-structure class (harper#1163) is excluded too, since a re-copy re-ships the same bytes. Refs #810 Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01B99rVzH318au3uxfxCyeaM
There was a problem hiding this comment.
Code Review
This pull request introduces unconfirmed-send stall detection and recovery for replication connections (harper-pro#810) to handle cases where a subscription is wedged in a waiting state with no progress. It adds mechanisms to detect when a peer is not confirming or when the send path has stopped, and rate-limits decode-drop structure resyncs to avoid infinite reconnect loops. Additionally, comprehensive integration and unit tests are added, and the design documentation is updated. The reviewer identified a critical issue in noteSequenceSent where unconfirmedFirstOwedAt is not initialized alongside unconfirmedSince, which prevents the grace period from engaging during active blob transfers or back-pressure pauses.
| if (sequenceId > lastConfirmableSequenceSent) lastConfirmableSequenceSent = sequenceId; | ||
| // Start the clock when the peer first owes us something, so the grace period measures how long it | ||
| // has owed rather than how long the session has existed. | ||
| if (unconfirmedSince === 0 && lastConfirmableSequenceSent > lastConfirmationReceived) unconfirmedSince = Date.now(); |
There was a problem hiding this comment.
In noteSequenceSent, unconfirmedSince is initialized to Date.now(), but unconfirmedFirstOwedAt is left at 0. Because checkUnconfirmedSendStall requires unconfirmedFirstOwedAt > 0 to extend the confirmation clock during active blob transfers or back-pressure pauses, this omission prevents the grace period from ever engaging for stalls initiated by sending a sequence.
Initialize unconfirmedFirstOwedAt alongside unconfirmedSince here, matching the initialization pattern in the COMMITTED_UPDATE handler.
if (unconfirmedSince === 0 && lastConfirmableSequenceSent > lastConfirmationReceived) unconfirmedSince = unconfirmedFirstOwedAt = Date.now();
A replication subscription that parks at
connected: true+RECEIVING_STATUS_WAITINGwith no receive progress is invisible to both main-thread reconcile nets, so the wedge is permanent until someone restarts the node. In the field it left one user database dead on two nodes for ~21 hours whilecluster_statusreportedconnected: trueon every leg and thesystemdatabase kept replicating over the same peer pair. The sending session now detects that state itself and closes its own socket, so the peer reconnects and resubscribes on its ordinary retry path.The status check cannot simply be relaxed:
WAITINGwith an oldlastReceivedTimeis equally the signature of a healthy idle leg, and the receiver has nothing local to tell them apart — no shared-status position advertises the sender's head, and pongs keep liveness fresh on a wedged-but-open socket. The sender does, from two clocks it keeps as plain locals.unconfirmedSincestarts when the peer first falls behind what we sent it and clears when it catches up, so it measures how long the peer has owed us rather than how long the session has existed — a base copy emits no confirmable frame until it completes, and a clock started at subscription setup would already be expired when that final frame lands.sendProgressAtmarks every point the send path demonstrably advances: a frame on the wire, a blob chunk, a copy pacer yield through a withheld stretch, the throttled sequence update that a run of filtered records produces. All of those produce no confirmations and would otherwise read as a stopped sender.Two shapes close the socket.
peer-not-confirmingfires when the peer has owed us a confirmation for the whole threshold.send-path-stoppedfires when the send path has produced nothing for the whole threshold and a fresh read of this peer's own send range still finds entries past the cursor — the range re-read is what keeps it off a node that is merely receiving from a third peer, whose store grows with logs that subscription excludes.A second, separately backportable commit handles the trigger the issue reported: on an undecodable record the receiver forces one resubscribe from that frame's own commit, so the sender re-sends
TABLE_FIXED_STRUCTURE. It does not recover the dropped record and is not meant to, and it is rate-limited per connection so a decode class no resubscribe can repair cannot flap the leg.Root cause of the incident
The reported trigger is not what caused the silence. Replaying the incident sequence end to end on a two-node cluster — a live non-copy decode drop on the receiver, a hard
SIGKILLand restart of the sender, then writes — the receiver recovers and takes the post-crash writes. The decode failure is a sibling symptom of the sender crash.The silence is the sender's transaction-log stream stopping at a corrupt frame.
endIteratorOnCorruptFramelatchesstoppedpermanently, and the send loop reuses oneauditLogIterablefor the whole session on RocksDB, so every later wake drains an already-done iterator: no frames go out, the keepalive keeps the socket alive, the receiver parks atconnected:true/WAITING, andsystemis unaffected because it has its own log and its own connection. That is already characterised end to end inintegrationTests/cluster/txnlogTearReplication.test.mjs(harper#2016 / harper#2063, whose field incident "ran 11 days withcluster_statusreportingconnected: truethroughout").No fix for that here, deliberately: harper#2087 made stop-at-the-break the intended policy (fail-stop / quarantine, re-scope tracked by harper-pro#803), and the latch lives in core, a pinned submodule. The harper-pro gap this closes is that a permanently-stopped stream was indistinguishable from an idle one and unbounded in duration.
For the human reviewer
Detection is session-local, against the issue's stated direction. harper-pro#810's hand-off asks for a main-thread reconcile derivation beside
findStalledReceivingNodeUrlsand explicitly rejects anything session-local, on the harper-pro#431 direction that recovery is level-triggered truth on the main thread. Two planning rounds returnedbetter-alternative-existsnaming the same alternative, and I built the main-thread version first: the decisive facts against it were that the main thread cannot reproduce a subscription's log scope (it does not hold the peer's excluded-node list), and that carrying the session's facts through shared memory loses session identity across a reconnect, where a predecessor and its replacement briefly overlap. @kriszyp ruled to adopt the session-local placement. Reversible, but it is a rewrite of the detection half — worth confirming you still want it now that it is concrete.A persistent mid-log transaction-log tear is deliberately NOT recovered. The
send-path-stoppedshape fires only when a fresh re-read of the peer's send range finds work; a tear stops that re-read at the same frame, so it reads as "no work" and withholds the close. That is the right posture given harper#2087 made stop-at-the-break the intended policy and reopening cannot cross the break — but it does mean the exact incident's own log state ends up surfaced by the other shape (the peer stops confirming) rather than by this one. The alternative is to fire anyway, which reconnects a leg that cannot be repaired once per threshold, forever. A "no" here costs a reconnect loop on unrecoverable legs.Threshold is 20 minutes, not 15. Chosen so this orders strictly behind PR Bound a held source-503 blob gap across reconnects with an escalation budget #797's blob-gap escalation budget rather than racing it: a receiver holding a blob gap legitimately stops confirming because it clamps to its durable blob watermark. The cost is 20 minutes of stale reads before recovery in the worst case. Matching 15 would make the two nets simultaneous.
The decode-drop commit does not recover the dropped record. By the time the resubscribe fires, that frame's resume cursor has been persisted past the record, so the peer never sees it again. This is deliberate — harper-pro#545 chose skip-and-advance precisely to escape the fix(replication): close on per-record value-decode failure instead of skipping past it (#440) #521 decode/close/resume loop, and holding the pre-frame cursor for a bounded retry is PR fix(replication): hold and reconnect on a sync blob-setup fault instead of skipping the record as undecodable #717's lane — but it means the trade is "one record lost instead of every later record of that table". If you would rather have the record, that is a different change in a different PR.
The decode-drop resync is bounded by time, not by cause. It fires for the whole residual decode-failure bucket, but only a structure fork is actually repaired by re-sending
TABLE_FIXED_STRUCTURE. I could not find a signal that separates the two at the drop site — the field signature (an emptytypedStructs) is one instance of the class, not the class — so instead the close is rate-limited to one per connection per 5 minutes, which caps an unrepairable decode class at one reconnect per interval rather than one per frame. If you would rather it only fire on a recognisable fork signature, that is a narrowing I can add once we know what to key on.No kill switch or config knob. The planning review asked for one plus counters and a canary rollout. No existing recovery net in this file carries a config kill switch, and adding one is new user-facing config surface for a check that fires at most once per session. Observability is the distinct fire log line carrying the truth snapshot, matching the other nets. Say if you want the knob.
shouldCloseOnRecordDecodeFailureis now documented as dead code rather than deleted. It has had no production caller since fix(replication): classify undecodable records + hold on unknown table id (#537) #545 and its doc described the pre-fix(replication): classify undecodable records + hold on unknown table id (#537) #545 control flow, which is actively misleading next to this change. I corrected the doc and left the function and its tests alone rather than widening this diff into another change's lane; deleting it is a one-line follow-up if you prefer.Offered scope lever: drop
peer-not-confirmingto a follow-up. Eight review rounds ran; rounds 5, 6 and 7 each found a consequence of the previous round's fix, and every one of them was in this shape and its interactions with blobs, back-pressure, base copies and confirmation clamping.send-path-stoppedhas been stable since round 5 and is the shape that covers the diagnosed root cause and the reported incident. Cuttingpeer-not-confirmingwould delete that entire interaction surface — the blob and back-pressure guard, the grace cap, the threshold ordering floor againstreplication_blobTimeout, and one test hook — and the issue itself assigns receive-side gap detection to the W2 follow-up (harper-pro#432). It is a small deletion, not a rewrite. I built and tested it because it was in scope; I would not argue against removing it.Open items from the last round, none blocking, my assessment on each.
decodeDropResyncByPeerhas no eviction: it is keyed by (database, peer) and only gains an entry when a decode drop actually occurs, so it is bounded by real topology rather than unbounded, but a cap or aremove_nodehook would close it. No test exercises the blob or back-pressure grace path, because the cluster tests use a blob-free table — a real coverage gap, and a blob-based cluster case is a meaningful harness effort rather than a small addition. Two further claims I checked and did not act on:noteSendProgressis per frame and per blob chunk, not per record (the per-record stamps were removed in round 2), and there is nounconfirmedFirstOwedAtinitialisation gap — it is assigned together withunconfirmedSinceat both sites that set it.The second commit is a clean backport candidate. It is self-contained and touches only the receive path, so it would cherry-pick to v5.1/v5.2 on its own. I milestoned the PR for the
mainline only, since the issue carries no milestone and backporting is a customer-need call rather than mine.Review coverage, stated plainly
Eight pre-push rounds ran. The graded reviewer timed out on all eight, and the same-family fallback was out of budget every time, so no round ever produced a graded artifact. The Cursor legs contributed in rounds 1 and 2 and were then pruned by a per-branch round cap. Harper domain adjudication ran in rounds 1, 2, 5, 6 and 7, and timed out in 3, 4 and 8. The receipt on this head therefore rests on one outside leg without adjudication, and the review-need grade of 4 is correct rather than pessimistic.
What the rounds did find is worth the reviewer's time: ten defects, of which nine were ways this recovery net would itself have closed a healthy replication leg — a long base copy torn down mid-copy and again at completion, a withheld-record walk read as a stopped sender, a large blob transfer interrupted and restarted indefinitely, a peer holding the clock open by repeating one confirmation, a stray transaction log answering from already-sent history, a livelock after blob completion, an unrepairable decode fault flapping the subscription forever, and a bound that never engaged on server-side sessions. A safety net that fires on healthy legs is worse than no net, so that is the risk this change carries and where a human reviewer should push hardest.
Verification
Route: new cluster integration tests, paired with a negative control that stands in for the pre-fix build, plus unit tests for the pure decision and a regression run of the suite this change sits next to.
unitTests/replication/unconfirmedSendStall.test.mjs— 13 cases overunconfirmedSendStallReason: both fire shapes, a peer that has never confirmed anything at all, a quiet source, a sender working through records this peer filters out, a long base copy, a leg we have never sent to, and that the storage re-read is never reached until the progress clock has elapsed. Replication unit suite: 639 passing on the rebased tree.integrationTests/cluster/unconfirmedSendWedgeRecovery.test.mjs— 3/3. The first test is the fails-on-base control: the same injected wedge with the threshold set beyond the window, asserting the row written into the wedge never arrives AND thatcluster_statusstill reportsconnected: truewithlastReceivedStatus: "Waiting"— the silent-and-green signature from the incident. The second covers the other stall shape, where the subscriber applies records normally but never acknowledges them. The third runs the wedge with a short threshold: the sending session closes its own socket and the peer converges, then a further live write replicates over the reconnected leg.integrationTests/cluster/decodeDropStructureResync.test.mjs— 1/1. A poison record inside the base copy must NOT resubscribe (the copy exclusion), a poison record on a live frame must, the dropped record is not re-delivered, and the table keeps flowing afterwards.integrationTests/cluster/decodeDropRecovery.test.mjs— 1/1, unchanged. The existing #537/#545 guard still passes because every drop it injects is a copy frame.npm run buildreports 32 TypeScript errors; 31 are present on a cleanorigin/maintree and the 32nd is incore/dataLayer/rocksdbBackup.ts, a file this branch does not touch.Refs #810
Complexity: complicated
Review-Coverage: authored=claude; ran=gemini; blocked=codex(timeout),claude(fallback)(out-of-budget),domain(timeout); declined=cursor-grok,cursor-composer; rounds=8 @ 84c43af
Human-Review-Need: 4 @ 84c43af