From f214bd289a4889f9ea936b0efa5b54c48b934f66 Mon Sep 17 00:00:00 2001 From: Kris Zyp Date: Tue, 1 Sep 2026 18:35:46 -0600 Subject: [PATCH 01/13] Impose a uniform backoff discipline on replication retries MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Replication had no jitter anywhere in production code and a different retry policy at every site, from a flat 200ms subscription-setup delay to jitterless exponentials. The subscription-setup site had no dedup, no cap, and a non-unref'd timer, so whatever re-drove onNodeUpdate amplified 1:1 into main-thread timers, worker-side WebSocket/TLS setup, and "Setting up subscription with leader" warns — ~1,400 lines/s/node in the field, ending in an OOM kill (harper-pro#327). Add replication/backoff.ts: one createBackoff schedule with an exponential ceiling, full jitter, an optional per-site floor, an optional wall-clock budget, and injectable RNG/clock. Adopt it at the subscription-setup scheduler, scheduleReconnect, the wedge and receive-stall re-drives, the hdb_nodes watcher restart, the send-auth reprobe, the clone JWT/version retries, and the blob-repair sweep. The subscription-setup scheduler additionally enforces at most one pending setup per (peer URL, database), keyed in its own map because the stale-worker path deletes and recreates the connectionReplicationMap entry. Its dispatch re-reads the live entry at fire time rather than capturing a payload, so a deduped update is never lost and no closure is allocated per suppressed event, and the setup is cancelled on connect, unsubscribe, and node deletion. Also fix the hdb_nodes watcher's premature backoff reset: the success marker was set the instant subscribe() resolved, so a subscribe-then- immediately-throw cycle reset the delay on every pass and never escalated. It now resets only after an iteration survives a healthy- uptime threshold. Refs #327 Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01LHXY4wfz8qJ4ryA5gKPAme --- cloneNode/cloneNode.ts | 10 +- cloneNode/jwtKeyClone.ts | 9 +- replication/DESIGN.md | 48 ++++- replication/backoff.ts | 92 +++++++++ replication/blobRepair.ts | 28 ++- replication/knownNodes.ts | 29 ++- replication/replicationConnection.ts | 66 ++++-- replication/subscriptionManager.ts | 188 ++++++++++++++++-- unitTests/replication/backoff.test.mjs | 114 +++++++++++ .../connectReschedulesOnRejection.test.mjs | 6 +- unitTests/replication/forceReconnect.test.mjs | 15 +- .../replication/nodeUpdateWatcher.test.mjs | 70 +++++++ .../replication/reconnectJitter.test.mjs | 129 ++++++++++++ .../subscribeSetupScheduler.test.mjs | 177 +++++++++++++++++ 14 files changed, 923 insertions(+), 58 deletions(-) create mode 100644 replication/backoff.ts create mode 100644 unitTests/replication/backoff.test.mjs create mode 100644 unitTests/replication/reconnectJitter.test.mjs create mode 100644 unitTests/replication/subscribeSetupScheduler.test.mjs diff --git a/cloneNode/cloneNode.ts b/cloneNode/cloneNode.ts index 6758bd743..5ce2dad34 100644 --- a/cloneNode/cloneNode.ts +++ b/cloneNode/cloneNode.ts @@ -40,6 +40,7 @@ import { import { fetchJWTKeyWithRetry } from './jwtKeyClone.ts'; import { monitorSyncLoop } from './syncMonitor.ts'; import { cloneAttemptPath as cloneAttemptFilePath } from './cloneAttempt.ts'; +import { createBackoff } from '../replication/backoff.ts'; import { isExplicitDatabaseSubscription, isReplicatedDatabase as isReplicatedDatabaseUnder, @@ -98,6 +99,8 @@ import { const DEFAULT_SYNC_TIMEOUT_MS = 300000; const DEFAULT_SYNC_CHECK_INTERVAL_MS = 3000; +const VERSION_PROBE_RETRY_DELAY_MS = 1000; +const VERSION_PROBE_MAX_DELAY_MS = 4000; // Floor for the size-derived sync-wait ceiling, which guarantees the wait terminates even when data // keeps arriving without ever converging (arrivals slide the stall deadline). const MIN_MAX_CLONE_DURATION_MS = 3600000; @@ -707,6 +710,11 @@ async function monitorSync( if (!systemSocketRequired) { log(`'${SYSTEM_SCHEMA_NAME}' is not in this node's replication.databases; not requiring its socket`, 'debug'); } + const versionProbeBackoff = createBackoff({ + initialMs: VERSION_PROBE_RETRY_DELAY_MS, + maxMs: VERSION_PROBE_MAX_DELAY_MS, + minMs: VERSION_PROBE_RETRY_DELAY_MS, + }); for (let attempt = 1; systemSocketRequired && attempt <= 3; attempt++) { try { const registration: any = await leaderRequest({ operation: 'registration_info' }); @@ -716,7 +724,7 @@ async function monitorSync( break; } catch (err) { log(`Leader version probe failed (attempt ${attempt}/3): ${err}`); - if (attempt < 3) await sleep(1000); + if (attempt < 3) await sleep(versionProbeBackoff.nextDelay()); } } diff --git a/cloneNode/jwtKeyClone.ts b/cloneNode/jwtKeyClone.ts index 71e3c22fc..b4caa7c6d 100644 --- a/cloneNode/jwtKeyClone.ts +++ b/cloneNode/jwtKeyClone.ts @@ -1,4 +1,5 @@ import { setTimeout as sleep } from 'node:timers/promises'; +import { createBackoff } from '../replication/backoff.ts'; /** * Helpers for cloning the leader's JWT signing keys onto a new node. All nodes in a cluster must @@ -10,6 +11,7 @@ import { setTimeout as sleep } from 'node:timers/promises'; export const JWT_KEY_CLONE_RETRIES = 3; export const JWT_KEY_CLONE_RETRY_DELAY_MS = 250; +export const JWT_KEY_CLONE_MAX_DELAY_MS = 1000; /** * Extracts JWT key material from a `get_key` response. The operations layer wraps a bare string return @@ -35,6 +37,11 @@ export async function fetchJWTKeyWithRetry( delayMs: number = JWT_KEY_CLONE_RETRY_DELAY_MS ): Promise { let lastError: unknown; + const backoff = createBackoff({ + initialMs: delayMs, + maxMs: Math.max(delayMs, JWT_KEY_CLONE_MAX_DELAY_MS), + minMs: delayMs, + }); for (let attempt = 1; attempt <= retries; attempt++) { try { const key = extractKeyMaterial(await requestKey()); @@ -43,7 +50,7 @@ export async function fetchJWTKeyWithRetry( } catch (err) { lastError = err; } - if (attempt < retries) await sleep(delayMs); + if (attempt < retries) await sleep(backoff.nextDelay()); } throw new Error(`Unable to clone JWT key '${keyName}' from leader after ${retries} attempts`, { cause: lastError }); } diff --git a/replication/DESIGN.md b/replication/DESIGN.md index 23248766b..6780d19dd 100644 --- a/replication/DESIGN.md +++ b/replication/DESIGN.md @@ -10,10 +10,11 @@ Real-time, peer-to-peer replication of table data across cluster nodes via persi --- -## Files (6 total, ~4200 lines) +## Files (7 total, ~4200 lines) | File | Purpose | | -------------------------- | --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | +| `backoff.ts` | The one retry schedule (`createBackoff`): exponential ceiling, full jitter, floor, wall-clock budget. See "Backoff discipline". | | `replicationConnection.ts` | The protocol engine. Defines `NodeReplicationConnection`, encodes/decodes the binary frame format, drives audit-record forwarding, manages blobs, and writes shared latency/back-pressure counters. **The big file.** | | `replicator.ts` | Setup module: `start()`, per-database/per-table `Replicator` resource class, retrieval-connection pool, operation forwarding, mTLS config. | | `subscriptionManager.ts` | Main-thread orchestration. Delegates subscription work to worker threads; routes around disconnects. | @@ -96,6 +97,47 @@ Schema (defined in that function): `name` (PK), `subscriptions[]`, `system_info` **Node discovery & TLS** — `hdb_nodes` subscriptions, `setNode.ts` for member ops, `buildReplicationMtlsConfig()` (`replicator.ts`), `monitorNodeCAs()` (`replicator.ts`). +**Retry pacing** — `createBackoff` (`backoff.ts`) is the one schedule every retry site uses; see below. + +--- + +## Backoff discipline (harper-pro#327) + +Every retry/reconnect initiation site paces attempts through **one** utility, `createBackoff` in +`backoff.ts`: an exponential ceiling with **full jitter** (uniform draw across the window), an optional +per-site floor, an optional wall-clock budget, and injectable RNG/clock so every bound is +deterministically testable. Before this there was no jitter anywhere in production code — a fleet +reacting to one event retried in lockstep — and the delays themselves ranged from flat 200 ms to +jitterless doubling. + +The invariant the discipline enforces: **at most one pending attempt per target, on a bounded, capped, +decorrelated schedule.** Pacing alone is not enough; the storm surface below needed the dedup too. + +| Site | Schedule | Reset signal | +| ------------------------------------------------------------------------------- | ------------------------------------------------------------------------------------------------------------------------------------ | ------------------------------------------------------------------------------- | +| `createSubscribeSetupScheduler` (`subscriptionManager.ts`) — subscription setup | floor `NODE_SUBSCRIBE_DELAY`, ceiling `2 × NODE_SUBSCRIBE_DELAY` → 30 s, plus the caller's `RECONNECT_STAGGER_MS` stagger | `connectedToNode` (also cancels the pending setup) | +| `NodeReplicationConnection.scheduleReconnect` | floor `MIN_RETRY_TIME` 100 ms, ceiling `INITIAL_RETRY_TIME` 500 ms → 30 s | `onFrameSent` — first frame actually sent, **not** socket open (harper-pro#339) | +| `reconcileWorkers` wedge / receive-stall re-drives | fixed window (decorrelation only; the re-drives are already throttled by the `disconnectedAt` / `receiveStallReconnectAt` re-stamps) | n/a | +| `runNodeUpdateWatcher` (`knownNodes.ts`) — hdb_nodes watcher restart | floor/ceiling 1 s → 30 s | an iteration that survived `NODE_WATCHER_HEALTHY_UPTIME_MS` | +| `shouldCloseSendAuthWatch` reprobe (`replicationConnection.ts`) | 500 ms → 5 s under a 30 s wall-clock budget, then fails closed | n/a (one-shot loop) | +| `fetchJWTKeyWithRetry`, the clone version probe (`cloneNode/`) | 250 ms → 1 s / 1 s → 4 s, attempt count unchanged | n/a | +| `repairBlobs` (`blobRepair.ts`) — per-record | 50 ms → 1 s, only on a record no peer could repair | a repaired record | + +**The subscription-setup scheduler is the one with dedup.** `onDatabase` used to turn every qualifying +node update straight into a retained (not unref'd) 200 ms `setTimeout` plus a `subscribe-to-node` +message, so whatever re-drove `onNodeUpdate` amplified 1:1 into main-thread timers, worker-side +WebSocket/TLS setup, and `Setting up subscription with leader` warns — ~1,400 lines/s/node in the field, +ending in an OOM kill. The scheduler holds one armed setup per **(peer URL, database)** in its own map +(_not_ on the `connectionReplicationMap` entry, which the stale-worker path deletes and recreates), and +its dispatch re-reads the live entry at fire time rather than capturing a payload — so a deduped update +is never lost, no closure is allocated per suppressed event, and a setup cannot fire after an +unsubscribe or a node deletion. The warn moved inside the "actually armed" branch: it now describes an +attempt, not an event. + +**What is deliberately NOT on this schedule:** the receive/copy watchdogs and their thresholds (they +_detect_ stalls; this discipline paces _retries_), `blobGapReconnectTimer`, the in-place +`BLOB_SEND_RETRY_DELAYS_MS` 503 retries, `PING_INTERVAL`/`PING_TIMEOUT`, and `RECONCILE_INTERVAL_MS`. + --- ## Non-obvious behaviors @@ -172,7 +214,9 @@ Most replication behavior is exercised via integration tests that spin up multi- | ----------------------------------------- | ----------------------------------------------------------------------------------------------------------- | | Where does a remote message get decoded? | `replicationConnection.ts → replicateOverWS` | | Where do cache-miss fetches pick a peer? | `replicator.ts → Replicator.load` (declared inside `setReplicator`) | -| Where is the connection retry loop? | `replicationConnection.ts → NodeReplicationConnection` (uses `INITIAL_RETRY_TIME`) | +| Where is the connection retry loop? | `replicationConnection.ts → NodeReplicationConnection.scheduleReconnect` (uses `INITIAL_RETRY_TIME`) | +| Where is the retry/backoff schedule? | `backoff.ts → createBackoff`; adopting sites listed under "Backoff discipline" | +| Why is a subscribe setup not firing? | `subscriptionManager.ts → createSubscribeSetupScheduler` — one armed setup per (url, database) | | Where is mTLS configured? | `replicator.ts → buildReplicationMtlsConfig` | | Where is a new cluster member added? | `setNode.ts` (the whole file is one operation) | | Where are protocol message types defined? | `replicationConnection.ts` — top-level consts (`SUBSCRIPTION_REQUEST` … `SUBSCRIPTION_UPDATE`) | diff --git a/replication/backoff.ts b/replication/backoff.ts new file mode 100644 index 000000000..3b3779a89 --- /dev/null +++ b/replication/backoff.ts @@ -0,0 +1,92 @@ +/** + * The one backoff schedule replication retries use. Before harper-pro#327 every retry site rolled its + * own pacing — flat delays at the subscription-setup scheduler, jitterless exponentials at the + * connection and hdb_nodes-watcher layers — and a `grep` for jitter found none in production code, so + * a fleet reacting to one event retried in lockstep and a fast failure loop retried at a fixed rate + * forever. + * + * Full jitter (uniform over the whole window) rather than equal/decorrelated jitter: on these cold + * error paths, spreading a fleet's retries matters more than a tight worst-case delay. `minMs` is the + * escape hatch for sites where a near-zero draw would itself be harmful — the reconnect path + * accumulates native TLS state per dial (harper-pro#339), so it floors the window rather than + * accepting an occasional `setTimeout(0)` re-dial. + * + * `budgetMs` is a wall-clock deadline, not a sum of requested sleeps: a resolver hang or an + * event-loop stall must not extend a bounded grace period past what it advertises (the send-auth + * reprobe fails closed at its deadline, so an overrun delays enforcing a revocation). `maxAttempts` + * is defense in depth for the same sites, and stands on its own when `now` never advances. + */ + +export interface BackoffOptions { + /** Ceiling for the first attempt; doubles (or `factor`s) from there. */ + initialMs: number; + /** Upper bound on the ceiling. */ + maxMs: number; + /** Lower bound on every returned delay. Defaults to 0 (pure full jitter). */ + minMs?: number; + factor?: number; + jitter?: 'full' | 'none'; + /** Wall-clock budget, measured from creation/`reset()`. Without it the schedule never exhausts. */ + budgetMs?: number; + maxAttempts?: number; + random?: () => number; + /** Monotonic clock. Injected for tests; `Date.now` would let a wall-clock jump extend a budget. */ + now?: () => number; +} + +export interface Backoff { + /** The delay to wait before the next attempt, and advances the schedule. */ + nextDelay(): number; + /** Back to the first attempt, and restarts the budget clock. Call on real progress, not on setup. */ + reset(): void; + /** How many delays have been handed out since the last reset. */ + readonly attempts: number; + /** The ceiling the next `nextDelay()` will draw under. */ + readonly ceiling: number; + /** True once the budget deadline has passed or `maxAttempts` delays have been handed out. */ + readonly exhausted: boolean; +} + +export function createBackoff(options: BackoffOptions): Backoff { + const { + initialMs, + maxMs, + minMs = 0, + factor = 2, + jitter = 'full', + budgetMs, + maxAttempts, + random = Math.random, + now = () => performance.now(), + } = options; + let attempts = 0; + let deadline = budgetMs === undefined ? undefined : now() + budgetMs; + + function ceilingFor(attempt: number): number { + return Math.max(minMs, Math.min(initialMs * factor ** attempt, maxMs)); + } + + return { + get attempts() { + return attempts; + }, + get ceiling() { + return ceilingFor(attempts); + }, + get exhausted() { + if (maxAttempts !== undefined && attempts >= maxAttempts) return true; + return deadline !== undefined && now() >= deadline; + }, + nextDelay() { + const ceiling = ceilingFor(attempts); + attempts++; + let delay = jitter === 'full' ? minMs + Math.floor(random() * (ceiling - minMs)) : ceiling; + if (deadline !== undefined) delay = Math.max(0, Math.min(delay, deadline - now())); + return delay; + }, + reset() { + attempts = 0; + if (budgetMs !== undefined) deadline = now() + budgetMs; + }, + }; +} diff --git a/replication/blobRepair.ts b/replication/blobRepair.ts index 9de91998a..5f183e195 100644 --- a/replication/blobRepair.ts +++ b/replication/blobRepair.ts @@ -4,9 +4,21 @@ import { databases } from '../core/resources/databases.ts'; import { server } from '../core/server/Server.ts'; import harperLogger from '../core/utility/logging/harper_logger.js'; import type { Logger } from '../core/utility/logging/logger.ts'; +import { setTimeout as sleep } from 'node:timers/promises'; +import { createBackoff } from './backoff.ts'; const logger = harperLogger.forComponent('blob-repair').conditional as Logger; +// Paces a sweep whose peers cannot serve anything: without it the per-record loop spins as fast as the +// incomplete-blob cursor yields. Capped low (not at the 30s replication cap) because the delay is paid +// per unrepairable record while the cursor stays open, so a big backlog must still finish in hours. +const REPAIR_RETRY_INITIAL_MS = 50; +const REPAIR_RETRY_MAX_MS = 1000; +// One sweep per database per thread. `repair_blob_data` is fire-and-forget, so repeated calls landing on +// the same thread used to stack concurrent sweeps over the same records, wasting peer fetches and +// defeating the pacing above. Calls routed to different threads are still independent. +const sweepsInFlight = new Set(); + export async function allBlobsAreComplete( blobs: any[], checkBlob: (blob: any) => Promise = isBlobComplete @@ -15,15 +27,18 @@ export async function allBlobsAreComplete( } export async function repairBlobs( - dbName: string + dbName: string, + deps: { sleep?: (ms: number) => Promise } = {} ): Promise<{ checked: number; repaired: number; failed: number; noConnection: number }> { const database = (databases as any)[dbName]; if (!database) throw new Error(`Unknown database '${dbName}'`); + const pause = deps.sleep ?? sleep; let checked = 0; let repaired = 0; let failed = 0; let noConnection = 0; + const backoff = createBackoff({ initialMs: REPAIR_RETRY_INITIAL_MS, maxMs: REPAIR_RETRY_MAX_MS }); for await (const { tableName, table, recordId } of findIncompleteBlobRefs(database, dbName)) { checked++; @@ -70,9 +85,12 @@ export async function repairBlobs( } } - if (!peerRepaired) { + if (peerRepaired) { + backoff.reset(); + } else { failed++; logger.warn?.('Could not repair blob for record', recordId, 'in', tableName, '— no peer had a complete copy'); + await pause(backoff.nextDelay()); } } @@ -86,8 +104,12 @@ server.registerOperation?.({ if (!request.database) throw new Error('Must provide "database" name for blob repair'); const dbName = request.database; if (!(databases as any)[dbName]) throw new Error(`Unknown database '${dbName}'`); + if (sweepsInFlight.has(dbName)) return { message: `Blob repair already running for '${dbName}'` }; + sweepsInFlight.add(dbName); // fire and forget — repair can take hours on large datasets - repairBlobs(dbName).catch((err) => logger.error?.('Blob repair failed', dbName, err)); + repairBlobs(dbName) + .catch((err) => logger.error?.('Blob repair failed', dbName, err)) + .finally(() => sweepsInFlight.delete(dbName)); return { message: 'Blob repair started, check logs for progress' }; }, httpMethod: 'POST', diff --git a/replication/knownNodes.ts b/replication/knownNodes.ts index 907c298ea..3bd79a2c9 100644 --- a/replication/knownNodes.ts +++ b/replication/knownNodes.ts @@ -12,6 +12,7 @@ import * as env from '../core/utility/environment/environmentManager.js'; import { CONFIG_PARAMS } from '../core/utility/hdbTerms.ts'; import { logger } from '../core/utility/logging/logger.ts'; import { isExplicitDatabaseSubscription, isReplicatedDatabase } from './replicatedDatabases.ts'; +import { createBackoff } from './backoff.ts'; type MaybePromise = T | Promise; @@ -122,12 +123,20 @@ const NODE_WATCHER_RESTART_DELAY_MS = 1000; // Cap the exponential backoff so a persistent failure (subscribe throws every time) // doesn't run a tight 1s log+retry loop forever — back off up to 30s instead. const NODE_WATCHER_MAX_DELAY_MS = 30_000; +// How long an iteration has to survive before it counts as a healthy run that clears the backoff. +// Resolving `subscribe()` is not progress, and neither is receiving an event: a subscription that +// replays one row and immediately throws does both on every cycle, which is exactly the shape that +// used to pin the restart delay at 1s forever (harper-pro#327). +const NODE_WATCHER_HEALTHY_UPTIME_MS = 10_000; type WatcherOptions = { subscribe?: () => Promise> | AsyncIterable; processEvent?: (event: any, listener: (node: any, id: string) => void) => Promise | void; restartDelayMs?: number; maxDelayMs?: number; maxRestarts?: number; + healthyUptimeMs?: number; + now?: () => number; + random?: () => number; }; // Generation tokens guarding against duplicate node-update watchers (harper-pro#460). A @@ -168,20 +177,26 @@ export async function runNodeUpdateWatcher( const restartDelayMs = options.restartDelayMs ?? NODE_WATCHER_RESTART_DELAY_MS; const maxDelayMs = options.maxDelayMs ?? NODE_WATCHER_MAX_DELAY_MS; const maxRestarts = options.maxRestarts ?? Infinity; + const healthyUptimeMs = options.healthyUptimeMs ?? NODE_WATCHER_HEALTHY_UPTIME_MS; + const now = options.now ?? (() => performance.now()); const key = options.key ?? DEFAULT_WATCHER_KEY; // Supersede any watcher already running for this key so a reload doesn't stack a second loop // (harper-pro#460). Distinct keys (subscription vs confirmation) run concurrently and untouched. stopNodeUpdateWatcher(key); const generation = watcherGenerations.get(key) ?? 0; let restarts = 0; - let consecutiveFailures = 0; + const backoff = createBackoff({ + initialMs: restartDelayMs, + maxMs: maxDelayMs, + minMs: Math.min(restartDelayMs, maxDelayMs), + random: options.random, + }); const isCurrent = () => generation === (watcherGenerations.get(key) ?? 0); while (restarts < maxRestarts && isCurrent()) { - let iteratedSuccessfully = false; + const startedAt = now(); try { const events = await subscribe(); if (!isCurrent()) break; // superseded while awaiting subscribe - iteratedSuccessfully = true; // we got past subscribe — any later throw is a fresh failure const iterator = events[Symbol.asyncIterator](); watcherIterators.set(key, iterator); try { @@ -207,12 +222,12 @@ export async function runNodeUpdateWatcher( if (!isCurrent()) break; // superseded watcher; iterator.return rejected logger.error?.('hdb_nodes watcher failed; restarting', error); } - // Successful subscribe → reset backoff so a fresh failure restarts quickly. - consecutiveFailures = iteratedSuccessfully ? 0 : consecutiveFailures + 1; + // A watcher that stayed up long enough to have done real work restarts quickly; anything shorter + // is a failure cycle and keeps escalating toward the cap. + if (now() - startedAt >= healthyUptimeMs) backoff.reset(); restarts++; if (restarts >= maxRestarts || !isCurrent()) return; - const delay = Math.min(restartDelayMs * Math.pow(2, Math.min(consecutiveFailures, 5)), maxDelayMs); - await new Promise((resolve) => setTimeout(resolve, delay)); + await new Promise((resolve) => setTimeout(resolve, backoff.nextDelay())); } } /** diff --git a/replication/replicationConnection.ts b/replication/replicationConnection.ts index 0cb3401e1..93651cb88 100644 --- a/replication/replicationConnection.ts +++ b/replication/replicationConnection.ts @@ -101,6 +101,7 @@ import { PassThrough } from 'node:stream'; import { getLastVersion } from 'lmdb'; import { FrameWriter } from './frameWriter.ts'; import { cloneAttemptSource } from '../cloneNode/cloneAttempt.ts'; +import { createBackoff, type Backoff } from './backoff.ts'; const logger = forComponent('replication').conditional as Logger; // msgpackr v2 removed the built-in `randomAccessStructure` option; that random-access @@ -534,8 +535,13 @@ const PAUSE_STALL_THRESHOLD_MS = Math.max( // base-copy resync re-encodes the row against local structures), so a decode blip never de-authorizes // a healthy peer, while still bounding how long a revocation carried by an undecodable write can go // unenforced. Only reached on a genuine decode failure — a decodable row is evaluated on the first probe. -const SEND_AUTH_REPROBE_INTERVAL_MS = 500; -const SEND_AUTH_REPROBE_ATTEMPTS = 60; +const SEND_AUTH_REPROBE_INITIAL_MS = 500; +const SEND_AUTH_REPROBE_MAX_MS = 5_000; +// The grace period is a wall-clock deadline, not a sum of sleeps: a resolver hang or event-loop stall +// must not extend how long a revocation carried by an undecodable write can go unenforced. +const SEND_AUTH_REPROBE_BUDGET_MS = 30_000; +// Defense in depth for the deadline, and the whole bound when the clock does not advance (tests). +const SEND_AUTH_REPROBE_ATTEMPTS = 120; /** * Decide whether the dynamic send-authorization watch (the per-subscriber `getHDBNodeTable().subscribe` @@ -573,17 +579,25 @@ export async function shouldCloseSendAuthWatch( isClosed: () => boolean; onReprobeTimeout?: () => void; resolve?: (name: string) => any; - sleep?: () => Promise; + sleep?: (ms: number) => Promise; reprobeAttempts?: number; + reprobeBudgetMs?: number; + now?: () => number; } ): Promise { const resolve = deps.resolve ?? resolveNodeForSendAuth; - const sleep = deps.sleep ?? (() => new Promise((r) => setTimeout(r, SEND_AUTH_REPROBE_INTERVAL_MS).unref())); - const reprobeAttempts = deps.reprobeAttempts ?? SEND_AUTH_REPROBE_ATTEMPTS; + const sleep = deps.sleep ?? ((ms: number) => new Promise((r) => setTimeout(r, ms).unref())); + const backoff = createBackoff({ + initialMs: SEND_AUTH_REPROBE_INITIAL_MS, + maxMs: SEND_AUTH_REPROBE_MAX_MS, + budgetMs: deps.reprobeBudgetMs ?? SEND_AUTH_REPROBE_BUDGET_MS, + maxAttempts: deps.reprobeAttempts ?? SEND_AUTH_REPROBE_ATTEMPTS, + now: deps.now, + }); let node = isGenuineNodeDeletion(event.type) ? undefined : resolve(name); - for (let attempt = 0; node === SEND_AUTH_UNCHANGED && attempt < reprobeAttempts && !deps.isClosed(); attempt++) { - await sleep(); + while (node === SEND_AUTH_UNCHANGED && !backoff.exhausted && !deps.isClosed()) { + await sleep(backoff.nextDelay()); node = resolve(name); } if (node === SEND_AUTH_UNCHANGED) { @@ -2441,6 +2455,11 @@ export async function createWebSocket( } const INITIAL_RETRY_TIME = 500; +const MAX_RETRY_TIME = 30_000; +// Floor under the jittered reconnect delay. Full jitter can draw ~0, and every dial allocates native TLS +// state that a CPU-saturated process GCs slower than it can be produced (harper-pro#339) — so the window +// is decorrelated, never opened all the way to an immediate re-dial. +const MIN_RETRY_TIME = 100; /** * This represents a persistent connection to a node for replication, which handles * sockets that may be disconnected and reconnected @@ -2448,7 +2467,9 @@ const INITIAL_RETRY_TIME = 500; export class NodeReplicationConnection extends EventEmitter { socket: WebSocket; startTime: number; - retryTime = INITIAL_RETRY_TIME; + // Created on the first failure so a healthy connection allocates nothing extra. + retryBackoff: Backoff; + random = Math.random; // injectable so the jittered reconnect schedule is deterministically testable retries = 0; isConnected = true; // we start out assuming we will be connected isFinished = false; @@ -2670,23 +2691,34 @@ export class NodeReplicationConnection extends EventEmitter { scheduleReconnect() { this.reconnectScheduled = true; this.resetSession(); - setTimeout(() => { - this.connect(); - }, this.retryTime).unref(); - // Double the interval each retry, capped at 30 s. The previous ~0.4%/retry + // Double the ceiling each retry, capped at 30 s. The previous ~0.4%/retry // growth took >1000 retries to reach any meaningful delay, so rapid // reconnects to a dead peer (symphony accepts the TLS handshake then drops // it) would still accumulate unreleased native TLS state faster than V8 can // GC under CPU-saturated bulk-write conditions, leading to OOM (#339). - // Doubling reaches 30 s in ~6 retries (~62 s total) and resets on success. - this.retryTime = Math.min(this.retryTime << 1, 30_000); + // Doubling reaches 30 s in ~6 retries and resets on success. The delay is drawn + // uniformly under that ceiling so a fleet restarting together does not re-dial in + // lockstep — every node used to pick the identical instant. + this.retryBackoff ??= createBackoff({ + initialMs: INITIAL_RETRY_TIME, + maxMs: MAX_RETRY_TIME, + minMs: MIN_RETRY_TIME, + random: this.random, + }); + setTimeout(() => { + this.connect(); + }, this.retryBackoff.nextDelay()).unref(); + } + /** The ceiling the next reconnect will be drawn under; the initial value means "not backed off". */ + get retryTime(): number { + return this.retryBackoff?.ceiling ?? INITIAL_RETRY_TIME; } // Called by replicateOverWS after a frame is actually sent: real progress, so it is safe to reset the // backoff. Gated on a non-zero retries so the healthy hot path (already reset) does nothing. onFrameSent() { - if (this.retries !== 0 || this.retryTime !== INITIAL_RETRY_TIME) { + if (this.retries !== 0 || this.retryBackoff?.attempts) { this.retries = 0; - this.retryTime = INITIAL_RETRY_TIME; + this.retryBackoff?.reset(); } } // Retire the live replicateOverWS instance: the single enforcement point for "at most one live session @@ -4678,7 +4710,7 @@ export function replicateOverWS(ws: WebSocket, options: any, authorization: any) onReprobeTimeout: () => logger.warn?.( connectionId, - `hdb_nodes row for ${authorization.name} did not decode within ${SEND_AUTH_REPROBE_ATTEMPTS * SEND_AUTH_REPROBE_INTERVAL_MS}ms; failing closed so a revocation carried by an undecodable write cannot be missed` + `hdb_nodes row for ${authorization.name} did not decode within ${SEND_AUTH_REPROBE_BUDGET_MS}ms; failing closed so a revocation carried by an undecodable write cannot be missed` ), }); if (shouldClose) { diff --git a/replication/subscriptionManager.ts b/replication/subscriptionManager.ts index 935f217b8..47fce452d 100644 --- a/replication/subscriptionManager.ts +++ b/replication/subscriptionManager.ts @@ -35,6 +35,7 @@ import { type ConnectionTruth, } from './replicationConnection.ts'; import * as logger from '../core/utility/logging/harper_logger.js'; +import { createBackoff, type Backoff } from './backoff.ts'; import lodash from 'lodash'; const { cloneDeep } = lodash; import * as env from '../core/utility/environment/environmentManager.js'; @@ -94,6 +95,11 @@ const NODE_SUBSCRIBE_DELAY = 200; // delay before sending node subscribe to othe // replicateOverWS instance + TLS buffer). Stagger them so at most ~1 new connection starts // per RECONNECT_STAGGER_MS, keeping peak concurrent connection setup bounded. const RECONNECT_STAGGER_MS = 50; +// Ceiling the subscription-setup backoff starts at, and the cap it grows to. The floor stays +// NODE_SUBSCRIBE_DELAY: that delay exists to let operations complete first, which is unrelated to retry +// pacing, so jitter is drawn above it rather than through it. See createSubscribeSetupScheduler. +const NODE_SUBSCRIBE_INITIAL_CEILING_MS = 2 * NODE_SUBSCRIBE_DELAY; +const NODE_SUBSCRIBE_MAX_DELAY_MS = 30_000; // Cadence of the per-process safety-net reconcile that rebinds subscriptions whose // worker no longer exists. Pure read-side filter against `workers` and // `connectionReplicationMap` on each tick when nothing is wrong, so a short interval @@ -126,6 +132,127 @@ const RECEIVE_STALL_THRESHOLD_MS = 15 * 60_000; const workersWithExitHandler = new WeakSet(); const connectionReplicationMap = new Map(); +interface SubscribeSchedule { + timer?: ReturnType; + backoff: Backoff; +} + +export interface SubscribeSetupScheduler { + /** Arm a setup for this pair, or return undefined when one is already pending (deduped). */ + schedule(url: string, database: string, staggerMs?: number): number | undefined; + /** The pair reached 'open': drop the pending setup and the escalated delay. */ + noteConnected(url: string, database: string): void; + cancel(url: string, database: string): void; + cancelUrl(url: string): void; + pendingCount(): number; +} + +/** + * Admission control for subscription setup: **at most one pending setup per (peer URL, database)**, + * on an escalating jittered schedule that resets when the pair connects. + * + * harper-pro#327: `onDatabase` used to turn every qualifying node update straight into a retained + * (not unref'd) 200 ms `setTimeout` plus a `subscribe-to-node` message, so whatever re-drove + * `onNodeUpdate` amplified 1:1 into main-thread timers, worker-side WebSocket/TLS setup, and + * `Setting up subscription with leader` warns — measured at ~1,400 lines/s/node and ending in an OOM + * kill. The upstream re-drive rate is not something this module controls (peers, the 5s reconcile, + * `deploy_component` reloads and a churning `databases` object all feed it), so the bound has to live + * at the decision to schedule. + * + * Keyed by (url, database) in its own map rather than on the `connectionReplicationMap` entry, + * because the stale-worker path in `onDatabase` deletes and recreates that entry — per-entry state + * would be wiped on exactly the path that most needs the dedup. `dispatch` re-reads the live entry at + * fire time instead of capturing a payload, so a deduped update is never lost (the entry already + * holds the newest `nodes`/`worker`) and no closure is allocated per suppressed event. + */ +export function createSubscribeSetupScheduler(deps: { + dispatch: (url: string, database: string) => void; + random?: () => number; + initialMs?: number; + maxMs?: number; + minMs?: number; +}): SubscribeSetupScheduler { + const { + dispatch, + random, + initialMs = NODE_SUBSCRIBE_INITIAL_CEILING_MS, + maxMs = NODE_SUBSCRIBE_MAX_DELAY_MS, + minMs = NODE_SUBSCRIBE_DELAY, + } = deps; + const schedules = new Map>(); + + function drop(url: string, database: string) { + const forUrl = schedules.get(url); + const schedule = forUrl?.get(database); + if (!schedule) return; + clearTimeout(schedule.timer); + forUrl!.delete(database); + if (forUrl!.size === 0) schedules.delete(url); + } + + return { + schedule(url, database, staggerMs = 0) { + let forUrl = schedules.get(url); + if (!forUrl) schedules.set(url, (forUrl = new Map())); + let schedule = forUrl.get(database); + if (!schedule) { + schedule = { backoff: createBackoff({ initialMs, maxMs, minMs, random }) }; + forUrl.set(database, schedule); + } else if (schedule.timer) return undefined; + const delay = schedule.backoff.nextDelay() + staggerMs; + schedule.timer = setTimeout(() => { + schedule.timer = undefined; + // A synchronous throw here (postMessage on an uncloneable payload) would take the process + // down, and this is the recovery path. + try { + dispatch(url, database); + } catch (error) { + logger.error('Error dispatching subscription setup for', database, url, error); + } + }, delay); + schedule.timer.unref?.(); + return delay; + }, + noteConnected(url, database) { + drop(url, database); + }, + cancel(url, database) { + drop(url, database); + }, + cancelUrl(url) { + const forUrl = schedules.get(url); + if (!forUrl) return; + for (const schedule of forUrl.values()) clearTimeout(schedule.timer); + schedules.delete(url); + }, + pendingCount() { + let count = 0; + for (const forUrl of schedules.values()) for (const schedule of forUrl.values()) if (schedule.timer) count++; + return count; + }, + }; +} + +/** + * Send the subscribe-to-node the scheduler armed, from the entry's *current* state. The entry can have + * been unsubscribed, deleted, or reassigned to another worker during the (now up to 30s) wait. A pair + * that connected in the meantime has already had this setup cancelled by `noteConnected`; we + * deliberately do not re-check `connected` here, because a re-subscribe after an unsubscribe is + * legitimately scheduled while the closing connection still reads connected:true. + */ +function dispatchSubscribeSetup(url: string, database: string) { + const entry = connectionReplicationMap.get(url)?.get(database); + if (!entry || entry.unsubscribed) return; + const nodes = entry.nodes; + if (!nodes?.[0]) return; + const request = { ...nodes[0], type: 'subscribe-to-node', database, nodes }; + if (entry.worker) { + entry.worker.postMessage(request); + } else subscribeToNode(request); +} + +const subscribeSetupScheduler = createSubscribeSetupScheduler({ dispatch: dispatchSubscribeSetup }); + // Resolve an auditStore for a database (any table's will do — the per-(db, peer) shared-memory status // buffer is keyed by database, not table) so the main thread can read the authoritative connection truth // written by the owning worker. See W1 (harper-pro#431). @@ -682,6 +809,7 @@ export async function startOnMainThread(options) { } dbReplicationWorkers.iterator?.remove(); connectionReplicationMap.delete(url); + subscribeSetupScheduler.cancelUrl(url); return; } if (isSelf) return; @@ -861,7 +989,6 @@ export async function startOnMainThread(options) { .filter((nodeName) => nodeName !== getThisNodeName()) // find the first node that is not this one )[0]; // try to find the first node const nodeName = nodes[0].name ?? (nodes[0].url && new URL(nodes[0].url).hostname); - logger.warn(`Setting up subscription with leader ${leaderName} for node ${nodeName}`); // isLeader is true only if: // 1. it was explicitly persisted (e.g. by add_node { isLeader: true }), OR // 2. there is no leader candidate at all, OR @@ -871,21 +998,16 @@ export async function startOnMainThread(options) { nodes[0].isLeader = nodes[0].isLeader || !leaderName || (hasExplicitLeader && nodeName === leaderName); nodes[0].url ??= getNodeURL(nodes[0]); // Stagger the subscribe when reassigning (subscribeStagger set) so N databases on one peer - // don't dial N catchup connections simultaneously; otherwise use the flat delay. See #446. - const subscribeDelay = subscribeStagger - ? NODE_SUBSCRIBE_DELAY + subscribeStagger.count++ * RECONNECT_STAGGER_MS - : NODE_SUBSCRIBE_DELAY; - setTimeout(() => { - const request = { - ...nodes[0], - type: 'subscribe-to-node', - database: databaseName, - nodes, - }; - if (worker) { - worker.postMessage(request); - } else subscribeToNode(request); - }, subscribeDelay); + // don't dial N catchup connections simultaneously. See #446. + const staggerMs = subscribeStagger ? subscribeStagger.count++ * RECONNECT_STAGGER_MS : 0; + const subscribeDelay = subscribeSetupScheduler.schedule(getNodeURL(node), databaseName, staggerMs); + // undefined means a setup for this (url, database) is already pending: the entry it will + // read has just been refreshed above, so there is nothing more to do — and nothing to log. + // The warn belongs to an armed setup, not to an event, or a re-drive storm reproduces the + // 165k-line logs of harper-pro#327 even though the work itself is now bounded. + if (subscribeDelay !== undefined) { + logger.warn(`Setting up subscription with leader ${leaderName} for node ${nodeName} in ${subscribeDelay}ms`); + } } else { logger.info('Node no longer should be used, unsubscribing from node', { replicates: node.replicates, @@ -924,6 +1046,9 @@ export async function startOnMainThread(options) { // Keep the entry for URL/iterator cleanup, but bypass the reuse fast path after an // explicit unsubscribe so restoring membership can schedule subscribe-to-node again. if (existingEntry) existingEntry.unsubscribed = true; + // A setup armed for this pair can now be up to 30s from firing; without this it would + // re-subscribe right after we told the worker to unsubscribe. + subscribeSetupScheduler.cancel(getNodeURL(node), databaseName); const request = { type: 'unsubscribe-from-node', database: databaseName, @@ -1037,6 +1162,8 @@ export async function startOnMainThread(options) { return; } mainWorkerEntry.connected = true; + // Real progress for this pair: drop the escalated setup backoff and any setup still pending. + subscribeSetupScheduler.noteConnected(connection.url, connection.database); mainWorkerEntry.disconnectedAt = undefined; mainWorkerEntry.latency = connection.latency; const restoredNode = mainWorkerEntry.nodes[0]; @@ -1181,6 +1308,13 @@ export async function startOnMainThread(options) { getReceiveStatus ); if (staleNodeUrls.size === 0 && wedgedNodeUrls.size === 0 && stalledByUrl.size === 0) return; + // Decorrelation only, no escalation: these re-drives are already throttled by the disconnectedAt / + // receiveStallReconnectAt re-stamps, so the ceiling is fixed and every draw lands in the same window. + const reDriveBackoff = createBackoff({ + initialMs: NODE_SUBSCRIBE_INITIAL_CEILING_MS, + maxMs: NODE_SUBSCRIBE_INITIAL_CEILING_MS, + minMs: NODE_SUBSCRIBE_DELAY, + }); if (staleNodeUrls.size > 0) logger.warn( 'Reconciling replication subscriptions for nodes pointing at exited workers:', @@ -1259,10 +1393,17 @@ export async function startOnMainThread(options) { ); entry.lastRecovery = { mechanism: 'wedge-reconcile', at: reconcileNow }; // Stagger reconnects (RECONNECT_STAGGER_MS apart) so opening N TLS connections - // simultaneously does not spike memory when there are many databases. - const delay = NODE_SUBSCRIBE_DELAY + reconnectCount * RECONNECT_STAGGER_MS; + // simultaneously does not spike memory when there are many databases; jitter the base so + // every node in a fleet reacting to the same peer outage doesn't fire on the same tick. + const delay = reDriveBackoff.nextDelay() + reconnectCount * RECONNECT_STAGGER_MS; reconnectCount++; - setTimeout(() => worker.postMessage(request), delay).unref(); + setTimeout(() => { + // The stamp is our claim on this entry: connectedToNode clears disconnectedAt and a later + // reconcile re-stamps it, either of which means this re-drive is stale and would interrupt + // a connection that has already recovered or been re-driven. + if (entries.get(databaseName) !== entry || entry.disconnectedAt !== reconcileNow) return; + worker.postMessage(request); + }, delay).unref(); } if (reconnectCount > 0) logger.warn( @@ -1298,9 +1439,14 @@ export async function startOnMainThread(options) { database: databaseName, nodes, }; - const delay = NODE_SUBSCRIBE_DELAY + reconnectCount * RECONNECT_STAGGER_MS; + const delay = reDriveBackoff.nextDelay() + reconnectCount * RECONNECT_STAGGER_MS; reconnectCount++; - setTimeout(() => worker.postMessage(request), delay).unref(); + setTimeout(() => { + // Same staleness claim as the wedge path: a newer reconcile re-stamping + // receiveStallReconnectAt owns the kick from then on. + if (entries?.get(databaseName) !== entry || entry.receiveStallReconnectAt !== now) return; + worker.postMessage(request); + }, delay).unref(); } if (reconnectCount > 0) logger.warn( diff --git a/unitTests/replication/backoff.test.mjs b/unitTests/replication/backoff.test.mjs new file mode 100644 index 000000000..db9c8f50e --- /dev/null +++ b/unitTests/replication/backoff.test.mjs @@ -0,0 +1,114 @@ +/** + * Coverage for the shared replication backoff schedule (harper-pro#327). Every assertion that + * involves jitter injects the RNG, so the bounds are exact rather than statistical. + */ + +import { expect } from 'chai'; +import { createBackoff } from '#src/replication/backoff'; + +describe('createBackoff', () => { + it('doubles the ceiling per attempt and caps it', () => { + const backoff = createBackoff({ initialMs: 500, maxMs: 4000, jitter: 'none' }); + expect([ + backoff.nextDelay(), + backoff.nextDelay(), + backoff.nextDelay(), + backoff.nextDelay(), + backoff.nextDelay(), + ]).to.deep.equal([500, 1000, 2000, 4000, 4000]); + }); + + it('honours a non-default factor', () => { + const backoff = createBackoff({ initialMs: 100, maxMs: 10_000, factor: 3, jitter: 'none' }); + expect([backoff.nextDelay(), backoff.nextDelay(), backoff.nextDelay()]).to.deep.equal([100, 300, 900]); + }); + + it('draws full jitter across the whole window, never reaching the ceiling', () => { + const draws = [0, 0.5, 0.999999]; + let i = 0; + const backoff = createBackoff({ initialMs: 1000, maxMs: 1000, random: () => draws[i++] }); + expect([backoff.nextDelay(), backoff.nextDelay(), backoff.nextDelay()]).to.deep.equal([0, 500, 999]); + }); + + it('floors the jitter window at minMs', () => { + const backoff = createBackoff({ initialMs: 1000, maxMs: 1000, minMs: 400, random: () => 0 }); + expect(backoff.nextDelay(), 'a zero draw still waits the floor').to.equal(400); + expect(createBackoff({ initialMs: 1000, maxMs: 1000, minMs: 400, random: () => 0.5 }).nextDelay()).to.equal(700); + }); + + it('keeps the ceiling above minMs even when maxMs is lower', () => { + const backoff = createBackoff({ initialMs: 10, maxMs: 10, minMs: 250, random: () => 0.9 }); + expect(backoff.nextDelay()).to.equal(250); + }); + + it('decorrelates two schedules with identical failure timing', () => { + const a = createBackoff({ initialMs: 500, maxMs: 30_000, random: () => 0.1 }); + const b = createBackoff({ initialMs: 500, maxMs: 30_000, random: () => 0.9 }); + const aDelays = [a.nextDelay(), a.nextDelay(), a.nextDelay()]; + const bDelays = [b.nextDelay(), b.nextDelay(), b.nextDelay()]; + expect(aDelays).to.not.deep.equal(bDelays); + for (let i = 0; i < aDelays.length; i++) expect(aDelays[i]).to.be.below(bDelays[i]); + }); + + it('reset() returns to the first ceiling', () => { + const backoff = createBackoff({ initialMs: 500, maxMs: 30_000, jitter: 'none' }); + backoff.nextDelay(); + backoff.nextDelay(); + expect(backoff.attempts).to.equal(2); + expect(backoff.ceiling).to.equal(2000); + backoff.reset(); + expect(backoff.attempts).to.equal(0); + expect(backoff.nextDelay()).to.equal(500); + }); + + it('is never exhausted without a budget or attempt cap', () => { + const backoff = createBackoff({ initialMs: 1, maxMs: 2 }); + for (let i = 0; i < 1000; i++) backoff.nextDelay(); + expect(backoff.exhausted).to.equal(false); + }); + + it('exhausts on the wall-clock deadline, not on the sum of requested sleeps', () => { + // The delays are never actually awaited here: what exhausts the budget is the clock passing the + // deadline. This is the send-auth reprobe's guarantee — an event-loop stall or a slow resolver + // cannot extend the grace period past what it advertises. + let clock = 0; + const backoff = createBackoff({ initialMs: 500, maxMs: 5000, budgetMs: 30_000, now: () => clock }); + expect(backoff.exhausted).to.equal(false); + backoff.nextDelay(); + clock = 29_999; + expect(backoff.exhausted).to.equal(false); + clock = 30_000; + expect(backoff.exhausted).to.equal(true); + }); + + it('clamps the last delay so it cannot overshoot the deadline', () => { + let clock = 0; + const backoff = createBackoff({ + initialMs: 5000, + maxMs: 5000, + budgetMs: 1000, + random: () => 0.999999, + now: () => clock, + }); + clock = 700; + expect(backoff.nextDelay()).to.equal(300); + }); + + it('restarts the budget clock on reset()', () => { + let clock = 0; + const backoff = createBackoff({ initialMs: 10, maxMs: 10, budgetMs: 100, now: () => clock }); + clock = 150; + expect(backoff.exhausted).to.equal(true); + backoff.reset(); + expect(backoff.exhausted).to.equal(false); + }); + + it('exhausts on maxAttempts even when the clock never advances', () => { + const backoff = createBackoff({ initialMs: 10, maxMs: 10, budgetMs: 30_000, maxAttempts: 3, now: () => 0 }); + backoff.nextDelay(); + backoff.nextDelay(); + expect(backoff.exhausted).to.equal(false); + backoff.nextDelay(); + expect(backoff.exhausted).to.equal(true); + }); +}); diff --git a/unitTests/replication/connectReschedulesOnRejection.test.mjs b/unitTests/replication/connectReschedulesOnRejection.test.mjs index c975d4c0c..b101b8434 100644 --- a/unitTests/replication/connectReschedulesOnRejection.test.mjs +++ b/unitTests/replication/connectReschedulesOnRejection.test.mjs @@ -38,7 +38,11 @@ describe('NodeReplicationConnection connect() reschedules when createWebSocket r // url = null makes createWebSocket reject (TypeError: Invalid URL) before any socket exists or any // listener is attached — the exact pre-'open' rejection shape of the #466 wedge. function makeRejectingConnection() { - return new NodeReplicationConnection(null, null, 'db', 'peer'); + const connection = new NodeReplicationConnection(null, null, 'db', 'peer'); + // The retry delay is drawn uniformly under the ceiling (harper-pro#327). Pin the draw to the top of + // the window so a single tick advances past exactly one retry. + connection.random = () => 0.999999; + return connection; } it('a createWebSocket rejection leaves reconnectScheduled=true with a pending retry, not a permanent stuck state', async () => { diff --git a/unitTests/replication/forceReconnect.test.mjs b/unitTests/replication/forceReconnect.test.mjs index df2856b15..cd4e0d1da 100644 --- a/unitTests/replication/forceReconnect.test.mjs +++ b/unitTests/replication/forceReconnect.test.mjs @@ -94,16 +94,21 @@ describe('NodeReplicationConnection.forceReconnect', () => { expect(conn.socket.terminate.callCount).to.equal(0); }); - it('backs off the retry interval on repeated wedges (mirrors the close-handler backoff)', () => { + it('backs off the retry ceiling on repeated wedges (mirrors the close-handler backoff)', () => { const conn = makeConnection(); + // The delay is drawn uniformly under the ceiling (harper-pro#327); pin the draw to the top of the + // window so the doubling is observable as a wait rather than as a distribution. + conn.random = () => 0.999999; - conn.forceReconnect(); // retryTime 500 -> 1000 + conn.forceReconnect(); // ceiling 500 -> 1000, draws 499 + expect(conn.retryTime).to.equal(1000); clock.tick(500); expect(conn.connect.callCount).to.equal(1); - conn.forceReconnect(); // retryTime 1000 -> 2000 - clock.tick(999); - expect(conn.connect.callCount, 'second reconnect waits the doubled interval').to.equal(1); + conn.forceReconnect(); // ceiling 1000 -> 2000, draws 999 + expect(conn.retryTime).to.equal(2000); + clock.tick(998); + expect(conn.connect.callCount, 'second reconnect waits the doubled ceiling').to.equal(1); clock.tick(1); expect(conn.connect.callCount).to.equal(2); }); diff --git a/unitTests/replication/nodeUpdateWatcher.test.mjs b/unitTests/replication/nodeUpdateWatcher.test.mjs index 5c2759cc2..a54ef8d7b 100644 --- a/unitTests/replication/nodeUpdateWatcher.test.mjs +++ b/unitTests/replication/nodeUpdateWatcher.test.mjs @@ -11,11 +11,29 @@ * - the loop restarts after the events iterable ends normally * - a per-event processor throw does NOT tear down the loop (continues consuming) * - the optional `maxRestarts` knob is observed (used here to bound the test) + * - the restart backoff escalates on a failure cycle and only resets on a healthy run (harper-pro#327) */ import { expect } from 'chai'; import { runNodeUpdateWatcher } from '#src/replication/knownNodes'; +// The restart delay is awaited through a bare setTimeout inside the watcher, so the delays it asks for +// are the only observable of its backoff. +function captureTimerDelays() { + const realSetTimeout = globalThis.setTimeout; + const values = []; + globalThis.setTimeout = (fn, ms) => { + values.push(ms); + return realSetTimeout(fn, ms); + }; + return { + values, + restore() { + globalThis.setTimeout = realSetTimeout; + }, + }; +} + function makeAsyncIterableFromArray(items) { return { [Symbol.asyncIterator]() { @@ -95,6 +113,58 @@ describe('runNodeUpdateWatcher restart loop', () => { expect(subscribeCalls).to.equal(2); }); + // harper-pro#327: the marker used to be set the instant subscribe() resolved, so a subscription that + // resolved and then immediately threw counted as a success on every pass, reset the backoff, and + // pinned the restart at restartDelayMs forever. Against that code the delays below are [4, 4, 4, 4]. + it('escalates when subscribe() resolves and iteration immediately throws', async () => { + const delays = captureTimerDelays(); + try { + await runNodeUpdateWatcher(() => {}, { + subscribe: async () => ({ + [Symbol.asyncIterator]: () => ({ + next: async () => { + throw new Error('stream died immediately'); + }, + }), + }), + restartDelayMs: 4, + maxDelayMs: 256, + random: () => 0.999999, + maxRestarts: 5, + }); + } finally { + delays.restore(); + } + + expect(delays.values).to.deep.equal([4, 7, 15, 31]); + }); + + it('resets the backoff once an iteration survives the healthy-uptime threshold', async () => { + let subscribeCalls = 0; + let fakeNow = 0; + const delays = captureTimerDelays(); + try { + await runNodeUpdateWatcher(() => {}, { + subscribe: async () => { + subscribeCalls++; + fakeNow += 60_000; // every run stays up well past healthyUptimeMs + return makeAsyncIterableFromArray([]); + }, + restartDelayMs: 4, + maxDelayMs: 256, + healthyUptimeMs: 10_000, + now: () => fakeNow, + random: () => 0.999999, + maxRestarts: 4, + }); + } finally { + delays.restore(); + } + + expect(subscribeCalls).to.equal(4); + expect(delays.values, 'a healthy run never escalates').to.deep.equal([4, 4, 4]); + }); + it('forwards events to the listener via the default processEvent path', async () => { // Smoke test the default processor at the parameter-passing level using an // injected subscribe that yields a single put event for a foreign node. diff --git a/unitTests/replication/reconnectJitter.test.mjs b/unitTests/replication/reconnectJitter.test.mjs new file mode 100644 index 000000000..dca7ad6ee --- /dev/null +++ b/unitTests/replication/reconnectJitter.test.mjs @@ -0,0 +1,129 @@ +/** + * Coverage for the jittered reconnect schedule (harper-pro#327). `scheduleReconnect` used to wait + * exactly `retryTime` (500ms doubling to a 30s cap), so every node reacting to the same peer outage + * re-dialed on the same instant — a whole fleet restarting together retried in lockstep, and no + * production retry path in the repo had jitter at all. The ceiling schedule is unchanged; only the + * draw under it is new, floored so a near-zero draw cannot become an immediate re-dial (each dial + * allocates native TLS state, harper-pro#339). + * + * `null` for the url makes createWebSocket reject before any socket or listener exists, which is the + * cheapest way to drive the real scheduleReconnect path without a peer. + */ + +import { expect } from 'chai'; +import sinon from 'sinon'; +import { NodeReplicationConnection } from '#src/replication/replicationConnection'; + +const INITIAL_RETRY_TIME = 500; +const MIN_RETRY_TIME = 100; +const MAX_RETRY_TIME = 30_000; + +function captureTimerDelays() { + const realSetTimeout = globalThis.setTimeout; + const values = []; + globalThis.setTimeout = (fn, ms) => { + values.push(ms); + return realSetTimeout(fn, ms); + }; + return { + values, + restore() { + globalThis.setTimeout = realSetTimeout; + }, + }; +} + +function scheduleDelays(connection, attempts) { + const timers = captureTimerDelays(); + try { + for (let i = 0; i < attempts; i++) { + connection.reconnectScheduled = false; // the real clear happens when connect() installs a socket + connection.scheduleReconnect(); + } + } finally { + timers.restore(); + } + return timers.values; +} + +describe('NodeReplicationConnection reconnect jitter (harper-pro#327)', () => { + let clock; + + beforeEach(() => { + clock = sinon.useFakeTimers(); + }); + + afterEach(() => { + // clock.restore() only — a sandbox-wide sinon.restore() here re-restores the stale + // globalThis.setTimeout that receiveWatchdog.test.mjs's manually-restored spy left registered, + // which silently breaks real timers for every file that runs after this one. + clock.restore(); + }); + + function makeConnection(random) { + const connection = new NodeReplicationConnection(null, null, 'db', 'peer'); + connection.random = random; + return connection; + } + + it('two connections failing on identical timing get decorrelated delays', () => { + const early = scheduleDelays( + makeConnection(() => 0.1), + 6 + ); + const late = scheduleDelays( + makeConnection(() => 0.9), + 6 + ); + + expect(early).to.not.deep.equal(late); + for (let i = 0; i < early.length; i++) expect(early[i]).to.be.below(late[i]); + }); + + it('keeps the unchanged 500ms → 30s ceiling schedule, drawing inside it', () => { + const connection = makeConnection(() => 0.999999); + const ceilings = []; + const timers = captureTimerDelays(); + try { + for (let i = 0; i < 8; i++) { + connection.reconnectScheduled = false; + connection.scheduleReconnect(); + ceilings.push(connection.retryTime); + } + } finally { + timers.restore(); + } + + expect(ceilings).to.deep.equal([1000, 2000, 4000, 8000, 16_000, 30_000, 30_000, 30_000]); + for (const delay of timers.values) { + expect(delay).to.be.at.least(MIN_RETRY_TIME); + expect(delay).to.be.below(MAX_RETRY_TIME); + } + }); + + it('never re-dials immediately, even on a zero draw', () => { + expect( + scheduleDelays( + makeConnection(() => 0), + 4 + ) + ).to.deep.equal([MIN_RETRY_TIME, MIN_RETRY_TIME, MIN_RETRY_TIME, MIN_RETRY_TIME]); + }); + + it('retryTime reads as the initial interval before any failure', () => { + expect(makeConnection(Math.random).retryTime).to.equal(INITIAL_RETRY_TIME); + }); + + it('onFrameSent resets the ceiling and the retry counter', () => { + const connection = makeConnection(() => 0.5); + scheduleDelays(connection, 3); + connection.retries = 7; + expect(connection.retryTime).to.equal(4000); + + connection.onFrameSent(); + + expect(connection.retries).to.equal(0); + expect(connection.retryTime).to.equal(INITIAL_RETRY_TIME); + expect(scheduleDelays(connection, 1)[0]).to.equal(MIN_RETRY_TIME + Math.floor(0.5 * (500 - MIN_RETRY_TIME))); + }); +}); diff --git a/unitTests/replication/subscribeSetupScheduler.test.mjs b/unitTests/replication/subscribeSetupScheduler.test.mjs new file mode 100644 index 000000000..9f7fd27b3 --- /dev/null +++ b/unitTests/replication/subscribeSetupScheduler.test.mjs @@ -0,0 +1,177 @@ +/** + * Regression coverage for harper-pro#327: subscription setup used to be scheduled with a flat 200ms + * `setTimeout` per qualifying node update — no dedup, no cap, not unref'd — so whatever re-drove + * `onNodeUpdate` amplified 1:1 into main-thread timers, worker-side WebSocket/TLS setup, and + * `Setting up subscription with leader` warns. Measured in the field at ~1,400 lines/s/node, ending in + * an OOM kill (165k lines on the 5.0.31 rig; 116k on merged main for the boot-time DNS variant). + * + * The storm test below drives input continuously *across* timer firings, which is the shape of the + * incident — a one-shot burst would only prove coalescing. Against the old flat-200ms behavior the + * same input produces one dispatch per event (60,000 of them) and 60,000 live timers, so the + * dispatch-count and pendingCount assertions both go red. + */ + +import { expect } from 'chai'; +import sinon from 'sinon'; +import { createSubscribeSetupScheduler } from '#src/replication/subscriptionManager'; + +const URL_A = 'wss://peer-a:9933'; +const URL_B = 'wss://peer-b:9933'; +// Mirrors the production constants: floor NODE_SUBSCRIBE_DELAY, first ceiling 2x that, cap 30s. +const MIN_DELAY = 200; +const MAX_DELAY = 30_000; + +function makeScheduler(random) { + const dispatches = []; + const scheduler = createSubscribeSetupScheduler({ + dispatch: (url, database) => dispatches.push({ url, database, at: Date.now() }), + random, + }); + return { scheduler, dispatches }; +} + +describe('subscription-setup scheduler (harper-pro#327)', () => { + let clock; + + beforeEach(() => { + clock = sinon.useFakeTimers(); + }); + + afterEach(() => { + // clock.restore() only — a sandbox-wide sinon.restore() here re-restores the stale + // globalThis.setTimeout that receiveWatchdog.test.mjs's manually-restored spy left registered, + // which silently breaks real timers for every file that runs after this one. + clock.restore(); + }); + + it('bounds a 60s re-drive storm to a handful of setups with one pending timer throughout', () => { + const { scheduler, dispatches } = makeScheduler(() => 0.5); + let maxPending = 0; + + // 60,000 qualifying updates spread over 60s of simulated time (~1,000/s, the observed storm rate). + for (let i = 0; i < 60_000; i++) { + scheduler.schedule(URL_A, 'data'); + maxPending = Math.max(maxPending, scheduler.pendingCount()); + clock.tick(1); + } + + // Ceilings double 400 → 30,000; each delay is 200 + 0.5 * (ceiling - 200). + expect(dispatches.map((d) => d.at)).to.deep.equal([300, 800, 1700, 3400, 6700, 13_200, 26_100, 41_200, 56_300]); + expect(maxPending, 'never more than one pending setup for the pair').to.equal(1); + expect(scheduler.pendingCount(), 'exactly one still armed at the end').to.equal(1); + }); + + it('keeps every delay inside the floor and the cap', () => { + const draws = [0, 0.999999, 0.25, 0, 0.999999, 0.5, 0.75, 0, 0.999999, 0.999999, 0.999999, 0.999999]; + let i = 0; + const { scheduler } = makeScheduler(() => draws[i++ % draws.length]); + for (let attempt = 0; attempt < 40; attempt++) { + const delay = scheduler.schedule(URL_A, 'data'); + expect(delay).to.be.at.least(MIN_DELAY); + expect(delay).to.be.below(MAX_DELAY); + clock.tick(delay); + } + }); + + it('returns undefined instead of arming a second timer for the same pair', () => { + const { scheduler, dispatches } = makeScheduler(() => 0.5); + expect(scheduler.schedule(URL_A, 'data')).to.equal(300); + expect(scheduler.schedule(URL_A, 'data'), 'deduped').to.equal(undefined); + expect(scheduler.schedule(URL_A, 'data'), 'still deduped').to.equal(undefined); + clock.tick(60_000); + expect(dispatches.length).to.equal(1); + }); + + it('tracks (url, database) pairs independently', () => { + const { scheduler, dispatches } = makeScheduler(() => 0.5); + expect(scheduler.schedule(URL_A, 'data')).to.equal(300); + expect(scheduler.schedule(URL_A, 'other')).to.equal(300); + expect(scheduler.schedule(URL_B, 'data')).to.equal(300); + expect(scheduler.pendingCount()).to.equal(3); + clock.tick(300); + expect(dispatches).to.deep.equal([ + { url: URL_A, database: 'data', at: 300 }, + { url: URL_A, database: 'other', at: 300 }, + { url: URL_B, database: 'data', at: 300 }, + ]); + }); + + it('decorrelates two peers failing on identical timing', () => { + const a = createSubscribeSetupScheduler({ dispatch: () => {}, random: () => 0.1 }); + const b = createSubscribeSetupScheduler({ dispatch: () => {}, random: () => 0.9 }); + const aDelays = []; + const bDelays = []; + for (let attempt = 0; attempt < 5; attempt++) { + aDelays.push(a.schedule(URL_A, 'data')); + bDelays.push(b.schedule(URL_A, 'data')); + clock.tick(MAX_DELAY + MIN_DELAY); + } + expect(aDelays).to.not.deep.equal(bDelays); + for (let i = 0; i < aDelays.length; i++) expect(aDelays[i]).to.be.below(bDelays[i]); + }); + + it('adds the caller-supplied stagger on top of the backoff', () => { + const { scheduler } = makeScheduler(() => 0.5); + expect(scheduler.schedule(URL_A, 'data', 150)).to.equal(450); + }); + + it('noteConnected drops the pending setup and the escalated delay', () => { + const { scheduler, dispatches } = makeScheduler(() => 0.5); + scheduler.schedule(URL_A, 'data'); + clock.tick(300); + scheduler.schedule(URL_A, 'data'); // second attempt: escalated to 500 + expect(scheduler.pendingCount()).to.equal(1); + + scheduler.noteConnected(URL_A, 'data'); + expect(scheduler.pendingCount(), 'the armed setup is cancelled, not just reset').to.equal(0); + clock.tick(60_000); + expect(dispatches.length, 'the cancelled setup never fired').to.equal(1); + + expect(scheduler.schedule(URL_A, 'data'), 'back to the first ceiling after success').to.equal(300); + }); + + it('cancel() and cancelUrl() disarm pending setups', () => { + const { scheduler, dispatches } = makeScheduler(() => 0.5); + scheduler.schedule(URL_A, 'data'); + scheduler.schedule(URL_A, 'other'); + scheduler.schedule(URL_B, 'data'); + + scheduler.cancel(URL_A, 'data'); + expect(scheduler.pendingCount()).to.equal(2); + scheduler.cancelUrl(URL_A); + expect(scheduler.pendingCount()).to.equal(1); + + clock.tick(60_000); + expect(dispatches).to.deep.equal([{ url: URL_B, database: 'data', at: 300 }]); + }); + + it('a throwing dispatch is contained instead of taking the process down', () => { + const scheduler = createSubscribeSetupScheduler({ + dispatch: () => { + throw new Error('uncloneable payload'); + }, + random: () => 0.5, + }); + scheduler.schedule(URL_A, 'data'); + expect(() => clock.tick(300)).to.not.throw(); + expect(scheduler.pendingCount(), 'ownership released so the pair can be re-armed').to.equal(0); + expect(scheduler.schedule(URL_A, 'data')).to.equal(500); + }); +}); + +// Real Node timers, deliberately: hasRef() is what proves the process can still exit with a setup +// pending, and a faked timer has no such thing. +describe('subscription-setup scheduler timer refs', () => { + it("unref's the setup timer so a pending retry cannot hold the process open", () => { + const realSetTimeout = globalThis.setTimeout; + let armed; + globalThis.setTimeout = (fn, ms) => (armed = realSetTimeout(fn, ms)); + try { + createSubscribeSetupScheduler({ dispatch: () => {}, random: () => 0.5 }).schedule(URL_A, 'data'); + } finally { + globalThis.setTimeout = realSetTimeout; + } + expect(armed.hasRef()).to.equal(false); + clearTimeout(armed); + }); +}); From d2bb0c1bcfda3b04d5505ba19627d9cdf59eba66 Mon Sep 17 00:00:00 2001 From: Kris Zyp Date: Tue, 1 Sep 2026 19:32:25 -0600 Subject: [PATCH 02/13] fix: carry the enriched payload on the armed subscription setup MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The deduped scheduling path read `entry.nodes` at fire time, but `onDatabase` replaces that array on its early-return path *without* running the leader/url enrichment — so a node update arriving between arming and firing left the setup posting a request with no url, and the worker logged "Failed to create web socket to undefined" and never connected (caught by selectiveTableSubscription.test.mjs). The schedule now carries the payload of the call that armed or last refreshed it; only calls that did enrich reach the scheduler, so "newest payload wins" holds without the clobber. Also resolve `nodes[0].url` where the payload is built rather than at the scheduling site, so the wedge re-drive — which posts from `entry.nodes` — cannot inherit the same urlless array. Refs #327 Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01LHXY4wfz8qJ4ryA5gKPAme --- replication/subscriptionManager.ts | 73 +++++++++++-------- .../subscribeSetupScheduler.test.mjs | 64 ++++++++++------ 2 files changed, 83 insertions(+), 54 deletions(-) diff --git a/replication/subscriptionManager.ts b/replication/subscriptionManager.ts index 47fce452d..73dfe0230 100644 --- a/replication/subscriptionManager.ts +++ b/replication/subscriptionManager.ts @@ -135,11 +135,15 @@ const connectionReplicationMap = new Map(); interface SubscribeSchedule { timer?: ReturnType; backoff: Backoff; + nodes?: any[]; } export interface SubscribeSetupScheduler { - /** Arm a setup for this pair, or return undefined when one is already pending (deduped). */ - schedule(url: string, database: string, staggerMs?: number): number | undefined; + /** + * Arm a setup for this pair with `nodes` as its payload, or return undefined when one is already + * pending (deduped) — the payload is refreshed either way, so the newest one is what fires. + */ + schedule(url: string, database: string, nodes: any[], staggerMs?: number): number | undefined; /** The pair reached 'open': drop the pending setup and the escalated delay. */ noteConnected(url: string, database: string): void; cancel(url: string, database: string): void; @@ -161,12 +165,14 @@ export interface SubscribeSetupScheduler { * * Keyed by (url, database) in its own map rather than on the `connectionReplicationMap` entry, * because the stale-worker path in `onDatabase` deletes and recreates that entry — per-entry state - * would be wiped on exactly the path that most needs the dedup. `dispatch` re-reads the live entry at - * fire time instead of capturing a payload, so a deduped update is never lost (the entry already - * holds the newest `nodes`/`worker`) and no closure is allocated per suppressed event. + * would be wiped on exactly the path that most needs the dedup. The payload is carried on the + * schedule (not read back off the entry at fire time): `onDatabase` replaces `entry.nodes` on its + * early-return path *without* running the leader/url enrichment, so the entry's array is not + * necessarily the one a setup should be sent with. Only a call that did enrich reaches this + * scheduler, so refreshing here on a deduped call keeps "newest payload wins" without losing it. */ export function createSubscribeSetupScheduler(deps: { - dispatch: (url: string, database: string) => void; + dispatch: (url: string, database: string, nodes: any[]) => void; random?: () => number; initialMs?: number; maxMs?: number; @@ -191,21 +197,25 @@ export function createSubscribeSetupScheduler(deps: { } return { - schedule(url, database, staggerMs = 0) { + schedule(url, database, nodes, staggerMs = 0) { let forUrl = schedules.get(url); if (!forUrl) schedules.set(url, (forUrl = new Map())); let schedule = forUrl.get(database); if (!schedule) { schedule = { backoff: createBackoff({ initialMs, maxMs, minMs, random }) }; forUrl.set(database, schedule); - } else if (schedule.timer) return undefined; + } + schedule.nodes = nodes; + if (schedule.timer) return undefined; const delay = schedule.backoff.nextDelay() + staggerMs; schedule.timer = setTimeout(() => { schedule.timer = undefined; + const pending = schedule.nodes; + schedule.nodes = undefined; // A synchronous throw here (postMessage on an uncloneable payload) would take the process // down, and this is the recovery path. try { - dispatch(url, database); + if (pending) dispatch(url, database, pending); } catch (error) { logger.error('Error dispatching subscription setup for', database, url, error); } @@ -234,17 +244,16 @@ export function createSubscribeSetupScheduler(deps: { } /** - * Send the subscribe-to-node the scheduler armed, from the entry's *current* state. The entry can have - * been unsubscribed, deleted, or reassigned to another worker during the (now up to 30s) wait. A pair - * that connected in the meantime has already had this setup cancelled by `noteConnected`; we - * deliberately do not re-check `connected` here, because a re-subscribe after an unsubscribe is - * legitimately scheduled while the closing connection still reads connected:true. + * Send the subscribe-to-node the scheduler armed. The entry can have been unsubscribed, deleted, or + * reassigned to another worker during the (now up to 30s) wait, so ownership is re-checked against + * live state and the message goes to the entry's current worker. A pair that connected in the + * meantime has already had this setup cancelled by `noteConnected`; we deliberately do not re-check + * `connected` here, because a re-subscribe after an unsubscribe is legitimately scheduled while the + * closing connection still reads connected:true. */ -function dispatchSubscribeSetup(url: string, database: string) { +function dispatchSubscribeSetup(url: string, database: string, nodes: any[]) { const entry = connectionReplicationMap.get(url)?.get(database); - if (!entry || entry.unsubscribed) return; - const nodes = entry.nodes; - if (!nodes?.[0]) return; + if (!entry || entry.unsubscribed || !nodes[0]) return; const request = { ...nodes[0], type: 'subscribe-to-node', database, nodes }; if (entry.worker) { entry.worker.postMessage(request); @@ -918,6 +927,11 @@ export async function startOnMainThread(options) { } // Use the enriched payload (nodes[0]) so the receive gate sees configRouteReplicates. const shouldSubscribe = shouldReplicateFromNode(nodes[0] as any, databaseName); + // Resolve the URL here rather than at the subscribe-scheduling site below: this array becomes + // `entry.nodes`, and the early-return path replaces it without ever reaching that site — which + // left the wedge re-drive posting a request with no url ("Failed to create web socket to + // undefined"). Placed after shouldReplicateFromNode so its verdict is unchanged. + nodes[0].url ??= getNodeURL(nodes[0] as any); const httpWorkers = workers.filter((worker) => worker.name === 'http'); // Defensively detect entries that point at a worker no longer in the http pool. // This happens when the worker.on('exit') handler below never fired (hung WebSocket @@ -996,13 +1010,12 @@ export async function startOnMainThread(options) { // We deliberately do NOT honour nodeName === leaderName when leaderName came // from the "first other node in hdb_nodes" fallback — that's just a guess. nodes[0].isLeader = nodes[0].isLeader || !leaderName || (hasExplicitLeader && nodeName === leaderName); - nodes[0].url ??= getNodeURL(nodes[0]); // Stagger the subscribe when reassigning (subscribeStagger set) so N databases on one peer // don't dial N catchup connections simultaneously. See #446. const staggerMs = subscribeStagger ? subscribeStagger.count++ * RECONNECT_STAGGER_MS : 0; - const subscribeDelay = subscribeSetupScheduler.schedule(getNodeURL(node), databaseName, staggerMs); - // undefined means a setup for this (url, database) is already pending: the entry it will - // read has just been refreshed above, so there is nothing more to do — and nothing to log. + const subscribeDelay = subscribeSetupScheduler.schedule(getNodeURL(node), databaseName, nodes, staggerMs); + // undefined means a setup for this (url, database) is already pending: it has just taken + // this call's payload, so there is nothing more to do — and nothing to log. // The warn belongs to an armed setup, not to an event, or a re-drive storm reproduces the // 165k-line logs of harper-pro#327 even though the work itself is now bounded. if (subscribeDelay !== undefined) { @@ -1095,15 +1108,13 @@ export async function startOnMainThread(options) { return; } const mainNode: any = existingWorkerEntry.nodes[0]; - if ( - !( - mainNode.replicates === true || - mainNode.replicates?.sends || - mainNode.replicates?.sendsTo?.length || - mainNode.replicates?.receivesFrom?.length || - mainNode.subscriptions?.length - ) - ) { + if (!( + mainNode.replicates === true || + mainNode.replicates?.sends || + mainNode.replicates?.sendsTo?.length || + mainNode.replicates?.receivesFrom?.length || + mainNode.subscriptions?.length + )) { // no replication, so just return return; } diff --git a/unitTests/replication/subscribeSetupScheduler.test.mjs b/unitTests/replication/subscribeSetupScheduler.test.mjs index 9f7fd27b3..16c2c79db 100644 --- a/unitTests/replication/subscribeSetupScheduler.test.mjs +++ b/unitTests/replication/subscribeSetupScheduler.test.mjs @@ -21,10 +21,12 @@ const URL_B = 'wss://peer-b:9933'; const MIN_DELAY = 200; const MAX_DELAY = 30_000; +const NODES = [{ name: 'peer-a', url: URL_A }]; + function makeScheduler(random) { const dispatches = []; const scheduler = createSubscribeSetupScheduler({ - dispatch: (url, database) => dispatches.push({ url, database, at: Date.now() }), + dispatch: (url, database, nodes) => dispatches.push({ url, database, nodes, at: Date.now() }), random, }); return { scheduler, dispatches }; @@ -50,7 +52,7 @@ describe('subscription-setup scheduler (harper-pro#327)', () => { // 60,000 qualifying updates spread over 60s of simulated time (~1,000/s, the observed storm rate). for (let i = 0; i < 60_000; i++) { - scheduler.schedule(URL_A, 'data'); + scheduler.schedule(URL_A, 'data', NODES); maxPending = Math.max(maxPending, scheduler.pendingCount()); clock.tick(1); } @@ -66,7 +68,7 @@ describe('subscription-setup scheduler (harper-pro#327)', () => { let i = 0; const { scheduler } = makeScheduler(() => draws[i++ % draws.length]); for (let attempt = 0; attempt < 40; attempt++) { - const delay = scheduler.schedule(URL_A, 'data'); + const delay = scheduler.schedule(URL_A, 'data', NODES); expect(delay).to.be.at.least(MIN_DELAY); expect(delay).to.be.below(MAX_DELAY); clock.tick(delay); @@ -75,21 +77,21 @@ describe('subscription-setup scheduler (harper-pro#327)', () => { it('returns undefined instead of arming a second timer for the same pair', () => { const { scheduler, dispatches } = makeScheduler(() => 0.5); - expect(scheduler.schedule(URL_A, 'data')).to.equal(300); - expect(scheduler.schedule(URL_A, 'data'), 'deduped').to.equal(undefined); - expect(scheduler.schedule(URL_A, 'data'), 'still deduped').to.equal(undefined); + expect(scheduler.schedule(URL_A, 'data', NODES)).to.equal(300); + expect(scheduler.schedule(URL_A, 'data', NODES), 'deduped').to.equal(undefined); + expect(scheduler.schedule(URL_A, 'data', NODES), 'still deduped').to.equal(undefined); clock.tick(60_000); expect(dispatches.length).to.equal(1); }); it('tracks (url, database) pairs independently', () => { const { scheduler, dispatches } = makeScheduler(() => 0.5); - expect(scheduler.schedule(URL_A, 'data')).to.equal(300); - expect(scheduler.schedule(URL_A, 'other')).to.equal(300); - expect(scheduler.schedule(URL_B, 'data')).to.equal(300); + expect(scheduler.schedule(URL_A, 'data', NODES)).to.equal(300); + expect(scheduler.schedule(URL_A, 'other', NODES)).to.equal(300); + expect(scheduler.schedule(URL_B, 'data', NODES)).to.equal(300); expect(scheduler.pendingCount()).to.equal(3); clock.tick(300); - expect(dispatches).to.deep.equal([ + expect(dispatches.map(({ url, database, at }) => ({ url, database, at }))).to.deep.equal([ { url: URL_A, database: 'data', at: 300 }, { url: URL_A, database: 'other', at: 300 }, { url: URL_B, database: 'data', at: 300 }, @@ -102,24 +104,38 @@ describe('subscription-setup scheduler (harper-pro#327)', () => { const aDelays = []; const bDelays = []; for (let attempt = 0; attempt < 5; attempt++) { - aDelays.push(a.schedule(URL_A, 'data')); - bDelays.push(b.schedule(URL_A, 'data')); + aDelays.push(a.schedule(URL_A, 'data', NODES)); + bDelays.push(b.schedule(URL_A, 'data', NODES)); clock.tick(MAX_DELAY + MIN_DELAY); } expect(aDelays).to.not.deep.equal(bDelays); for (let i = 0; i < aDelays.length; i++) expect(aDelays[i]).to.be.below(bDelays[i]); }); + // The regression that made the deduped path lose the enriched payload: onDatabase replaces + // entry.nodes on its early-return path without running the leader/url enrichment, so the setup has + // to carry the payload of the call that armed or last refreshed it, not whatever the entry holds. + it('fires with the newest payload a deduped call supplied', () => { + const { scheduler, dispatches } = makeScheduler(() => 0.5); + const first = [{ name: 'peer-a', url: URL_A }]; + const second = [{ name: 'peer-a', url: URL_A, isLeader: true }]; + scheduler.schedule(URL_A, 'data', first); + expect(scheduler.schedule(URL_A, 'data', second)).to.equal(undefined); + clock.tick(300); + expect(dispatches.length).to.equal(1); + expect(dispatches[0].nodes).to.equal(second); + }); + it('adds the caller-supplied stagger on top of the backoff', () => { const { scheduler } = makeScheduler(() => 0.5); - expect(scheduler.schedule(URL_A, 'data', 150)).to.equal(450); + expect(scheduler.schedule(URL_A, 'data', NODES, 150)).to.equal(450); }); it('noteConnected drops the pending setup and the escalated delay', () => { const { scheduler, dispatches } = makeScheduler(() => 0.5); - scheduler.schedule(URL_A, 'data'); + scheduler.schedule(URL_A, 'data', NODES); clock.tick(300); - scheduler.schedule(URL_A, 'data'); // second attempt: escalated to 500 + scheduler.schedule(URL_A, 'data', NODES); // second attempt: escalated to 500 expect(scheduler.pendingCount()).to.equal(1); scheduler.noteConnected(URL_A, 'data'); @@ -127,14 +143,14 @@ describe('subscription-setup scheduler (harper-pro#327)', () => { clock.tick(60_000); expect(dispatches.length, 'the cancelled setup never fired').to.equal(1); - expect(scheduler.schedule(URL_A, 'data'), 'back to the first ceiling after success').to.equal(300); + expect(scheduler.schedule(URL_A, 'data', NODES), 'back to the first ceiling after success').to.equal(300); }); it('cancel() and cancelUrl() disarm pending setups', () => { const { scheduler, dispatches } = makeScheduler(() => 0.5); - scheduler.schedule(URL_A, 'data'); - scheduler.schedule(URL_A, 'other'); - scheduler.schedule(URL_B, 'data'); + scheduler.schedule(URL_A, 'data', NODES); + scheduler.schedule(URL_A, 'other', NODES); + scheduler.schedule(URL_B, 'data', NODES); scheduler.cancel(URL_A, 'data'); expect(scheduler.pendingCount()).to.equal(2); @@ -142,7 +158,9 @@ describe('subscription-setup scheduler (harper-pro#327)', () => { expect(scheduler.pendingCount()).to.equal(1); clock.tick(60_000); - expect(dispatches).to.deep.equal([{ url: URL_B, database: 'data', at: 300 }]); + expect(dispatches.map(({ url, database, at }) => ({ url, database, at }))).to.deep.equal([ + { url: URL_B, database: 'data', at: 300 }, + ]); }); it('a throwing dispatch is contained instead of taking the process down', () => { @@ -152,10 +170,10 @@ describe('subscription-setup scheduler (harper-pro#327)', () => { }, random: () => 0.5, }); - scheduler.schedule(URL_A, 'data'); + scheduler.schedule(URL_A, 'data', NODES); expect(() => clock.tick(300)).to.not.throw(); expect(scheduler.pendingCount(), 'ownership released so the pair can be re-armed').to.equal(0); - expect(scheduler.schedule(URL_A, 'data')).to.equal(500); + expect(scheduler.schedule(URL_A, 'data', NODES)).to.equal(500); }); }); @@ -167,7 +185,7 @@ describe('subscription-setup scheduler timer refs', () => { let armed; globalThis.setTimeout = (fn, ms) => (armed = realSetTimeout(fn, ms)); try { - createSubscribeSetupScheduler({ dispatch: () => {}, random: () => 0.5 }).schedule(URL_A, 'data'); + createSubscribeSetupScheduler({ dispatch: () => {}, random: () => 0.5 }).schedule(URL_A, 'data', NODES); } finally { globalThis.setTimeout = realSetTimeout; } From 2c3902cb1a7572044162818f5b88d3125f68ec2c Mon Sep 17 00:00:00 2001 From: Kris Zyp Date: Tue, 1 Sep 2026 20:01:35 -0600 Subject: [PATCH 03/13] Address pre-push review: fail-closed deadline, equal jitter, owned recovery timers MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit From the independent pre-push review of the previous two commits: - send-auth reprobe (blocker): checking the budget only at the top of the loop let a row that became decodable *after* an event-loop stall pushed us past the 30s deadline still authorize the peer — the loop exits on a non-UNCHANGED row without consulting the deadline. It now fails closed on the elapsed time before trusting the next read. The backoff is also built lazily, so an ordinary decodable authorization event allocates nothing and never reads the clock. - scheduleReconnect: a fixed 100ms floor under full jitter did not preserve the #339 dial-rate guard, which is ceiling-relative by nature. Added `jitter: 'equal'` to the utility (draw from the top half of the window) and used it here, so the minimum dial interval stays proportional as the ceiling escalates. Full jitter stays the default everywhere the invariant is latency rather than rate. - subscription setup: `onDatabase`'s early-return path builds a fresh payload but never reaches the scheduler, so an armed setup could still dispatch pre-update routing state. It now calls `refreshPending`, and carries `isLeader` forward onto the replacement array so neither that path nor the wedge re-drive loses the leader decision. - wedge / receive-stall re-drives: each entry now owns a single `reDriveTimer` that a later decision replaces and connect/unsubscribe/ delete disarm, so a sweep staggered across many databases cannot stack waves or fire after an unsubscribe. The stall kick additionally re-reads the receive watermark at fire time, so a copy that resumed during the delay is not reconnected. - a same-name node moving to a new URL now cancels any setup armed for the address it left. Refs #327 Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01LHXY4wfz8qJ4ryA5gKPAme --- replication/DESIGN.md | 35 ++++---- replication/backoff.ts | 30 +++---- replication/replicationConnection.ts | 36 ++++---- replication/subscriptionManager.ts | 90 ++++++++++++++----- unitTests/replication/backoff.test.mjs | 12 +++ unitTests/replication/forceReconnect.test.mjs | 4 +- .../replication/reconnectJitter.test.mjs | 27 +++--- .../shouldCloseSendAuthWatch.test.mjs | 36 ++++++++ .../subscribeSetupScheduler.test.mjs | 35 ++++++-- 9 files changed, 213 insertions(+), 92 deletions(-) diff --git a/replication/DESIGN.md b/replication/DESIGN.md index 6780d19dd..27976c73e 100644 --- a/replication/DESIGN.md +++ b/replication/DESIGN.md @@ -104,8 +104,9 @@ Schema (defined in that function): `name` (PK), `subscriptions[]`, `system_info` ## Backoff discipline (harper-pro#327) Every retry/reconnect initiation site paces attempts through **one** utility, `createBackoff` in -`backoff.ts`: an exponential ceiling with **full jitter** (uniform draw across the window), an optional -per-site floor, an optional wall-clock budget, and injectable RNG/clock so every bound is +`backoff.ts`: an exponential ceiling with **full jitter** (uniform draw across the window) by default, +`'equal'` jitter (the top half of the window) for a site whose invariant is a rate rather than a +latency bound, an optional fixed floor, an optional wall-clock budget, and injectable RNG/clock so every bound is deterministically testable. Before this there was no jitter anywhere in production code — a fleet reacting to one event retried in lockstep — and the delays themselves ranged from flat 200 ms to jitterless doubling. @@ -113,15 +114,15 @@ jitterless doubling. The invariant the discipline enforces: **at most one pending attempt per target, on a bounded, capped, decorrelated schedule.** Pacing alone is not enough; the storm surface below needed the dedup too. -| Site | Schedule | Reset signal | -| ------------------------------------------------------------------------------- | ------------------------------------------------------------------------------------------------------------------------------------ | ------------------------------------------------------------------------------- | -| `createSubscribeSetupScheduler` (`subscriptionManager.ts`) — subscription setup | floor `NODE_SUBSCRIBE_DELAY`, ceiling `2 × NODE_SUBSCRIBE_DELAY` → 30 s, plus the caller's `RECONNECT_STAGGER_MS` stagger | `connectedToNode` (also cancels the pending setup) | -| `NodeReplicationConnection.scheduleReconnect` | floor `MIN_RETRY_TIME` 100 ms, ceiling `INITIAL_RETRY_TIME` 500 ms → 30 s | `onFrameSent` — first frame actually sent, **not** socket open (harper-pro#339) | -| `reconcileWorkers` wedge / receive-stall re-drives | fixed window (decorrelation only; the re-drives are already throttled by the `disconnectedAt` / `receiveStallReconnectAt` re-stamps) | n/a | -| `runNodeUpdateWatcher` (`knownNodes.ts`) — hdb_nodes watcher restart | floor/ceiling 1 s → 30 s | an iteration that survived `NODE_WATCHER_HEALTHY_UPTIME_MS` | -| `shouldCloseSendAuthWatch` reprobe (`replicationConnection.ts`) | 500 ms → 5 s under a 30 s wall-clock budget, then fails closed | n/a (one-shot loop) | -| `fetchJWTKeyWithRetry`, the clone version probe (`cloneNode/`) | 250 ms → 1 s / 1 s → 4 s, attempt count unchanged | n/a | -| `repairBlobs` (`blobRepair.ts`) — per-record | 50 ms → 1 s, only on a record no peer could repair | a repaired record | +| Site | Schedule | Reset signal | +| ------------------------------------------------------------------------------- | ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | -------------------------------------------------------------- | +| `createSubscribeSetupScheduler` (`subscriptionManager.ts`) — subscription setup | floor `NODE_SUBSCRIBE_DELAY`, ceiling `2 × NODE_SUBSCRIBE_DELAY` → 30 s, plus the caller's `RECONNECT_STAGGER_MS` stagger | `connectedToNode` (also cancels the pending setup) | +| `NodeReplicationConnection.scheduleReconnect` | ceiling `INITIAL_RETRY_TIME` 500 ms → 30 s, **equal** jitter (top half): this site's invariant is a dial rate, and only a ceiling-relative floor keeps the minimum interval proportional as the ceiling escalates (harper-pro#339) | `onFrameSent` — first frame actually sent, **not** socket open | +| `reconcileWorkers` wedge / receive-stall re-drives | fixed window (decorrelation only; the re-drives are already throttled by the `disconnectedAt` / `receiveStallReconnectAt` re-stamps), one owned `entry.reDriveTimer` per entry | n/a — disarmed on connect, unsubscribe, and delete | +| `runNodeUpdateWatcher` (`knownNodes.ts`) — hdb_nodes watcher restart | floor/ceiling 1 s → 30 s | an iteration that survived `NODE_WATCHER_HEALTHY_UPTIME_MS` | +| `shouldCloseSendAuthWatch` reprobe (`replicationConnection.ts`) | 500 ms → 5 s under a 30 s wall-clock budget, then fails closed | n/a (one-shot loop) | +| `fetchJWTKeyWithRetry`, the clone version probe (`cloneNode/`) | 250 ms → 1 s / 1 s → 4 s, attempt count unchanged | n/a | +| `repairBlobs` (`blobRepair.ts`) — per-record | 50 ms → 1 s, only on a record no peer could repair | a repaired record | **The subscription-setup scheduler is the one with dedup.** `onDatabase` used to turn every qualifying node update straight into a retained (not unref'd) 200 ms `setTimeout` plus a `subscribe-to-node` @@ -129,10 +130,14 @@ message, so whatever re-drove `onNodeUpdate` amplified 1:1 into main-thread time WebSocket/TLS setup, and `Setting up subscription with leader` warns — ~1,400 lines/s/node in the field, ending in an OOM kill. The scheduler holds one armed setup per **(peer URL, database)** in its own map (_not_ on the `connectionReplicationMap` entry, which the stale-worker path deletes and recreates), and -its dispatch re-reads the live entry at fire time rather than capturing a payload — so a deduped update -is never lost, no closure is allocated per suppressed event, and a setup cannot fire after an -unsubscribe or a node deletion. The warn moved inside the "actually armed" branch: it now describes an -attempt, not an event. +the armed setup carries the payload of the call that armed or last refreshed it — reading `entry.nodes` +at fire time is _not_ safe, because `onDatabase`'s early-return path replaces that array without +running the leader/url enrichment (that path calls `refreshPending` instead). A setup is cancelled on +connect, on unsubscribe, on node deletion, and on a same-name URL migration, all of which became +reachable once a pending timer could live 30 s instead of 200 ms. The wedge/stall recovery kicks are +owned the same way — one `entry.reDriveTimer` per entry, so a staggered sweep that outruns the +reconcile window that started it replaces its predecessor instead of stacking another wave. The warn +moved inside the "actually armed" branch: it now describes an attempt, not an event. **What is deliberately NOT on this schedule:** the receive/copy watchdogs and their thresholds (they _detect_ stalls; this discipline paces _retries_), `blobGapReconnectTimer`, the in-place diff --git a/replication/backoff.ts b/replication/backoff.ts index 3b3779a89..f9896cc41 100644 --- a/replication/backoff.ts +++ b/replication/backoff.ts @@ -1,20 +1,16 @@ /** - * The one backoff schedule replication retries use. Before harper-pro#327 every retry site rolled its - * own pacing — flat delays at the subscription-setup scheduler, jitterless exponentials at the - * connection and hdb_nodes-watcher layers — and a `grep` for jitter found none in production code, so - * a fleet reacting to one event retried in lockstep and a fast failure loop retried at a fixed rate - * forever. + * The one backoff schedule replication retries use; the adopting sites and their parameters are in + * `DESIGN.md` under "Backoff discipline". * - * Full jitter (uniform over the whole window) rather than equal/decorrelated jitter: on these cold - * error paths, spreading a fleet's retries matters more than a tight worst-case delay. `minMs` is the - * escape hatch for sites where a near-zero draw would itself be harmful — the reconnect path - * accumulates native TLS state per dial (harper-pro#339), so it floors the window rather than - * accepting an occasional `setTimeout(0)` re-dial. + * Full jitter (uniform over the whole window) is the default because decorrelating a fleet's retries + * matters more than a tight worst-case delay on these cold error paths. `'equal'` (the top half of the + * window) is for a site whose invariant is a *rate* bound rather than a latency bound: only a + * ceiling-relative floor keeps the minimum interval proportional as the ceiling escalates. `minMs` is + * the fixed-floor variant, for a site with a lower bound of its own. * - * `budgetMs` is a wall-clock deadline, not a sum of requested sleeps: a resolver hang or an - * event-loop stall must not extend a bounded grace period past what it advertises (the send-auth - * reprobe fails closed at its deadline, so an overrun delays enforcing a revocation). `maxAttempts` - * is defense in depth for the same sites, and stands on its own when `now` never advances. + * `budgetMs` is a deadline read off an injected monotonic clock, not a sum of requested sleeps: a + * resolver hang or an event-loop stall must not extend a bounded grace period past what it advertises. + * `maxAttempts` is the bound that still holds when the clock does not advance. */ export interface BackoffOptions { @@ -25,7 +21,8 @@ export interface BackoffOptions { /** Lower bound on every returned delay. Defaults to 0 (pure full jitter). */ minMs?: number; factor?: number; - jitter?: 'full' | 'none'; + /** 'full': uniform over [minMs, ceiling). 'equal': uniform over the top half. 'none': the ceiling. */ + jitter?: 'full' | 'equal' | 'none'; /** Wall-clock budget, measured from creation/`reset()`. Without it the schedule never exhausts. */ budgetMs?: number; maxAttempts?: number; @@ -80,7 +77,8 @@ export function createBackoff(options: BackoffOptions): Backoff { nextDelay() { const ceiling = ceilingFor(attempts); attempts++; - let delay = jitter === 'full' ? minMs + Math.floor(random() * (ceiling - minMs)) : ceiling; + const floor = jitter === 'equal' ? Math.max(minMs, ceiling / 2) : minMs; + let delay = jitter === 'none' ? ceiling : floor + Math.floor(random() * (ceiling - floor)); if (deadline !== undefined) delay = Math.max(0, Math.min(delay, deadline - now())); return delay; }, diff --git a/replication/replicationConnection.ts b/replication/replicationConnection.ts index 93651cb88..7f78b99f9 100644 --- a/replication/replicationConnection.ts +++ b/replication/replicationConnection.ts @@ -587,17 +587,25 @@ export async function shouldCloseSendAuthWatch( ): Promise { const resolve = deps.resolve ?? resolveNodeForSendAuth; const sleep = deps.sleep ?? ((ms: number) => new Promise((r) => setTimeout(r, ms).unref())); - const backoff = createBackoff({ - initialMs: SEND_AUTH_REPROBE_INITIAL_MS, - maxMs: SEND_AUTH_REPROBE_MAX_MS, - budgetMs: deps.reprobeBudgetMs ?? SEND_AUTH_REPROBE_BUDGET_MS, - maxAttempts: deps.reprobeAttempts ?? SEND_AUTH_REPROBE_ATTEMPTS, - now: deps.now, - }); let node = isGenuineNodeDeletion(event.type) ? undefined : resolve(name); - while (node === SEND_AUTH_UNCHANGED && !backoff.exhausted && !deps.isClosed()) { + // Built only once a row actually comes back undecodable, so the ordinary decodable event — every + // authorization change on a healthy cluster — allocates nothing and never reads the clock. + let backoff; + while (node === SEND_AUTH_UNCHANGED && !deps.isClosed()) { + backoff ??= createBackoff({ + initialMs: SEND_AUTH_REPROBE_INITIAL_MS, + maxMs: SEND_AUTH_REPROBE_MAX_MS, + budgetMs: deps.reprobeBudgetMs ?? SEND_AUTH_REPROBE_BUDGET_MS, + maxAttempts: deps.reprobeAttempts ?? SEND_AUTH_REPROBE_ATTEMPTS, + now: deps.now, + }); + if (backoff.exhausted) break; await sleep(backoff.nextDelay()); + // Re-check before trusting the next read, not just at the top of the loop: the grace period is + // advertised as a deadline, so a row that only becomes decodable after an event-loop stall + // pushed us past it must not authorize. Fail closed on the elapsed time, not on the row. + if (backoff.exhausted) break; node = resolve(name); } if (node === SEND_AUTH_UNCHANGED) { @@ -2456,10 +2464,6 @@ export async function createWebSocket( const INITIAL_RETRY_TIME = 500; const MAX_RETRY_TIME = 30_000; -// Floor under the jittered reconnect delay. Full jitter can draw ~0, and every dial allocates native TLS -// state that a CPU-saturated process GCs slower than it can be produced (harper-pro#339) — so the window -// is decorrelated, never opened all the way to an immediate re-dial. -const MIN_RETRY_TIME = 100; /** * This represents a persistent connection to a node for replication, which handles * sockets that may be disconnected and reconnected @@ -2697,12 +2701,14 @@ export class NodeReplicationConnection extends EventEmitter { // it) would still accumulate unreleased native TLS state faster than V8 can // GC under CPU-saturated bulk-write conditions, leading to OOM (#339). // Doubling reaches 30 s in ~6 retries and resets on success. The delay is drawn - // uniformly under that ceiling so a fleet restarting together does not re-dial in - // lockstep — every node used to pick the identical instant. + // uniformly over the TOP HALF of that ceiling ('equal', not the discipline's default + // full jitter): decorrelating a fleet that restarts together is worth having, but this + // site's invariant is a dial *rate*, and a ceiling-relative floor is what keeps the + // minimum dial interval proportional as the ceiling escalates. this.retryBackoff ??= createBackoff({ initialMs: INITIAL_RETRY_TIME, maxMs: MAX_RETRY_TIME, - minMs: MIN_RETRY_TIME, + jitter: 'equal', random: this.random, }); setTimeout(() => { diff --git a/replication/subscriptionManager.ts b/replication/subscriptionManager.ts index 73dfe0230..aa91ac66b 100644 --- a/replication/subscriptionManager.ts +++ b/replication/subscriptionManager.ts @@ -66,6 +66,11 @@ type ConnectedWorkerStatus = { // last shared-memory truth correction applied to it. Logged with each subsequent fire so the // watchdog-demotion soak can tell "sole detector" fires from ones where another layer (or the // truth-driven path) had already engaged. Telemetry only — never consulted for recovery decisions. + // The single recovery timer the reconcile has armed for this entry (wedge re-drive or stall kick). + // Owned rather than fire-and-forget: with many databases a staggered sweep can outrun the reconcile + // window that started it, so each new decision replaces the entry's pending one instead of stacking + // another wave, and connect/unsubscribe/delete can disarm it. + reDriveTimer?: ReturnType; lastRecovery?: { mechanism: string; at: number }; lastTruthCorrection?: { direction: 'down' | 'up'; at: number }; }; @@ -144,6 +149,8 @@ export interface SubscribeSetupScheduler { * pending (deduped) — the payload is refreshed either way, so the newest one is what fires. */ schedule(url: string, database: string, nodes: any[], staggerMs?: number): number | undefined; + /** Replace the payload of an already-armed setup without arming one. */ + refreshPending(url: string, database: string, nodes: any[]): void; /** The pair reached 'open': drop the pending setup and the escalated delay. */ noteConnected(url: string, database: string): void; cancel(url: string, database: string): void; @@ -153,23 +160,16 @@ export interface SubscribeSetupScheduler { /** * Admission control for subscription setup: **at most one pending setup per (peer URL, database)**, - * on an escalating jittered schedule that resets when the pair connects. + * on an escalating jittered schedule that resets when the pair connects. harper-pro#327 — see + * DESIGN.md, "Backoff discipline", for the incident and the rest of the sites. * - * harper-pro#327: `onDatabase` used to turn every qualifying node update straight into a retained - * (not unref'd) 200 ms `setTimeout` plus a `subscribe-to-node` message, so whatever re-drove - * `onNodeUpdate` amplified 1:1 into main-thread timers, worker-side WebSocket/TLS setup, and - * `Setting up subscription with leader` warns — measured at ~1,400 lines/s/node and ending in an OOM - * kill. The upstream re-drive rate is not something this module controls (peers, the 5s reconcile, - * `deploy_component` reloads and a churning `databases` object all feed it), so the bound has to live - * at the decision to schedule. - * - * Keyed by (url, database) in its own map rather than on the `connectionReplicationMap` entry, - * because the stale-worker path in `onDatabase` deletes and recreates that entry — per-entry state - * would be wiped on exactly the path that most needs the dedup. The payload is carried on the - * schedule (not read back off the entry at fire time): `onDatabase` replaces `entry.nodes` on its - * early-return path *without* running the leader/url enrichment, so the entry's array is not - * necessarily the one a setup should be sent with. Only a call that did enrich reaches this - * scheduler, so refreshing here on a deduped call keeps "newest payload wins" without losing it. + * Keyed in its own map rather than on the `connectionReplicationMap` entry, because the stale-worker + * path in `onDatabase` deletes and recreates that entry — per-entry state would be wiped on exactly + * the path that most needs the dedup. The payload rides on the schedule rather than being read back + * off the entry at fire time: `onDatabase` replaces `entry.nodes` on its early-return path *without* + * running the leader/url enrichment, so the entry's array is not necessarily the one a setup should be + * sent with. That path calls `refreshPending` instead, which is what keeps "newest payload wins" true + * without arming anything. */ export function createSubscribeSetupScheduler(deps: { dispatch: (url: string, database: string, nodes: any[]) => void; @@ -223,6 +223,10 @@ export function createSubscribeSetupScheduler(deps: { schedule.timer.unref?.(); return delay; }, + refreshPending(url, database, nodes) { + const schedule = schedules.get(url)?.get(database); + if (schedule?.timer) schedule.nodes = nodes; + }, noteConnected(url, database) { drop(url, database); }, @@ -811,7 +815,9 @@ export async function startOnMainThread(options) { } } if (!dbReplicationWorkers || !url) return; - for (const [database, { worker, nodes }] of dbReplicationWorkers) { + for (const [database, entry] of dbReplicationWorkers) { + const { worker, nodes } = entry; + clearTimeout(entry.reDriveTimer); dbReplicationWorkers.delete(database); logger.warn('Node was deleted, unsubscribing from node', hostname, database, url); worker?.postMessage({ type: 'unsubscribe-from-node', node: hostname, nodes, database, url }); @@ -849,6 +855,10 @@ export async function startOnMainThread(options) { break; } } + // A node that moved to a new URL leaves its old URL's entry behind (pre-existing); at least do + // not let a setup armed for the address it left fire against it. + const previousUrl = nodeMap.get(node.name) && getNodeURL(nodeMap.get(node.name)); + if (previousUrl && previousUrl !== getNodeURL(node)) subscribeSetupScheduler.cancelUrl(previousUrl); nodeMap.set(node.name, node); } const databases = getDatabases(); @@ -947,6 +957,10 @@ export async function startOnMainThread(options) { } if (existingEntry) { worker = existingEntry.worker; + // isLeader is only decided on the scheduling path below, so a payload built here would drop + // it — and this array becomes `entry.nodes`, which the wedge re-drive posts from. Same + // OR-accumulation the scheduling path uses. + nodes[0].isLeader = nodes[0].isLeader || existingEntry.nodes?.[0]?.isLeader; existingEntry.nodes = nodes; // Normally an existing subscribed entry is left alone. Only the wedge reconcile passes // forceResubscribe for a connection that has been connected:false past the threshold: that @@ -959,6 +973,9 @@ export async function startOnMainThread(options) { !existingEntry.unsubscribed && !(forceResubscribe && existingEntry.connected === false) ) { + // Nothing new to send for an already-subscribed entry, but an armed setup would otherwise + // still be holding the payload from before this update. + subscribeSetupScheduler.refreshPending(getNodeURL(node), databaseName, nodes); return; } if (shouldSubscribe && existingEntry.unsubscribed) { @@ -1060,8 +1077,12 @@ export async function startOnMainThread(options) { // explicit unsubscribe so restoring membership can schedule subscribe-to-node again. if (existingEntry) existingEntry.unsubscribed = true; // A setup armed for this pair can now be up to 30s from firing; without this it would - // re-subscribe right after we told the worker to unsubscribe. + // re-subscribe right after we told the worker to unsubscribe. Same for a recovery kick. subscribeSetupScheduler.cancel(getNodeURL(node), databaseName); + if (existingEntry) { + clearTimeout(existingEntry.reDriveTimer); + existingEntry.reDriveTimer = undefined; + } const request = { type: 'unsubscribe-from-node', database: databaseName, @@ -1173,8 +1194,11 @@ export async function startOnMainThread(options) { return; } mainWorkerEntry.connected = true; - // Real progress for this pair: drop the escalated setup backoff and any setup still pending. + // Real progress for this pair: drop the escalated setup backoff, any setup still pending, and any + // recovery kick armed for a connection that has since come back. subscribeSetupScheduler.noteConnected(connection.url, connection.database); + clearTimeout(mainWorkerEntry.reDriveTimer); + mainWorkerEntry.reDriveTimer = undefined; mainWorkerEntry.disconnectedAt = undefined; mainWorkerEntry.latency = connection.latency; const restoredNode = mainWorkerEntry.nodes[0]; @@ -1319,6 +1343,18 @@ export async function startOnMainThread(options) { getReceiveStatus ); if (staleNodeUrls.size === 0 && wedgedNodeUrls.size === 0 && stalledByUrl.size === 0) return; + // One armed recovery per entry: a sweep staggered across many databases can still be firing when the + // next reconcile decides again, and a superseded wave's timers would otherwise be retained until + // they no-op. + const armReDrive = (entry: any, delay: number, fire: () => void) => { + clearTimeout(entry.reDriveTimer); + const timer = setTimeout(() => { + entry.reDriveTimer = undefined; + fire(); + }, delay); + timer.unref(); + return timer; + }; // Decorrelation only, no escalation: these re-drives are already throttled by the disconnectedAt / // receiveStallReconnectAt re-stamps, so the ceiling is fixed and every draw lands in the same window. const reDriveBackoff = createBackoff({ @@ -1408,13 +1444,14 @@ export async function startOnMainThread(options) { // every node in a fleet reacting to the same peer outage doesn't fire on the same tick. const delay = reDriveBackoff.nextDelay() + reconnectCount * RECONNECT_STAGGER_MS; reconnectCount++; - setTimeout(() => { + entry.reDriveTimer = armReDrive(entry, delay, () => { // The stamp is our claim on this entry: connectedToNode clears disconnectedAt and a later // reconcile re-stamps it, either of which means this re-drive is stale and would interrupt // a connection that has already recovered or been re-driven. if (entries.get(databaseName) !== entry || entry.disconnectedAt !== reconcileNow) return; + if (entry.unsubscribed) return; // forceReconnect would reopen work we just told the worker to drop worker.postMessage(request); - }, delay).unref(); + }); } if (reconnectCount > 0) logger.warn( @@ -1444,6 +1481,8 @@ export async function startOnMainThread(options) { entry.lastRecovery = { mechanism: 'receive-stall-net', at: now }; // Throttle clock so this entry is not re-kicked until the threshold elapses again. entry.receiveStallReconnectAt = now; + // Watermark this decision was made against, so progress arriving during the delay cancels it. + const stalledAtWatermark = getReceiveStatus(databaseName, nodes[0]?.name)?.lastReceivedTime; const request = { ...nodes[0], type: 'force-reconnect-node', @@ -1452,12 +1491,17 @@ export async function startOnMainThread(options) { }; const delay = reDriveBackoff.nextDelay() + reconnectCount * RECONNECT_STAGGER_MS; reconnectCount++; - setTimeout(() => { + entry.reDriveTimer = armReDrive(entry, delay, () => { // Same staleness claim as the wedge path: a newer reconcile re-stamping // receiveStallReconnectAt owns the kick from then on. if (entries?.get(databaseName) !== entry || entry.receiveStallReconnectAt !== now) return; + if (entry.unsubscribed) return; + // A stagger that runs long enough for the copy to resume makes this kick a reconnect of a + // healthy connection; the watermark is the only thing that distinguishes the two. + const current = getReceiveStatus(databaseName, nodes[0]?.name)?.lastReceivedTime; + if (stalledAtWatermark != null && current != null && current > stalledAtWatermark) return; worker.postMessage(request); - }, delay).unref(); + }); } if (reconnectCount > 0) logger.warn( diff --git a/unitTests/replication/backoff.test.mjs b/unitTests/replication/backoff.test.mjs index db9c8f50e..b24fca544 100644 --- a/unitTests/replication/backoff.test.mjs +++ b/unitTests/replication/backoff.test.mjs @@ -30,6 +30,18 @@ describe('createBackoff', () => { expect([backoff.nextDelay(), backoff.nextDelay(), backoff.nextDelay()]).to.deep.equal([0, 500, 999]); }); + it('equal jitter draws only from the top half of the window, so the floor scales with the ceiling', () => { + const low = createBackoff({ initialMs: 500, maxMs: 30_000, jitter: 'equal', random: () => 0 }); + expect([low.nextDelay(), low.nextDelay(), low.nextDelay()]).to.deep.equal([250, 500, 1000]); + const high = createBackoff({ initialMs: 500, maxMs: 30_000, jitter: 'equal', random: () => 0.999999 }); + expect([high.nextDelay(), high.nextDelay(), high.nextDelay()]).to.deep.equal([499, 999, 1999]); + }); + + it('equal jitter still respects an explicit minMs floor above the half-ceiling', () => { + const backoff = createBackoff({ initialMs: 400, maxMs: 400, minMs: 300, jitter: 'equal', random: () => 0 }); + expect(backoff.nextDelay()).to.equal(300); + }); + it('floors the jitter window at minMs', () => { const backoff = createBackoff({ initialMs: 1000, maxMs: 1000, minMs: 400, random: () => 0 }); expect(backoff.nextDelay(), 'a zero draw still waits the floor').to.equal(400); diff --git a/unitTests/replication/forceReconnect.test.mjs b/unitTests/replication/forceReconnect.test.mjs index cd4e0d1da..5f1682447 100644 --- a/unitTests/replication/forceReconnect.test.mjs +++ b/unitTests/replication/forceReconnect.test.mjs @@ -96,9 +96,7 @@ describe('NodeReplicationConnection.forceReconnect', () => { it('backs off the retry ceiling on repeated wedges (mirrors the close-handler backoff)', () => { const conn = makeConnection(); - // The delay is drawn uniformly under the ceiling (harper-pro#327); pin the draw to the top of the - // window so the doubling is observable as a wait rather than as a distribution. - conn.random = () => 0.999999; + conn.random = () => 0.999999; // pin the draw so the doubled ceiling is observable as a wait conn.forceReconnect(); // ceiling 500 -> 1000, draws 499 expect(conn.retryTime).to.equal(1000); diff --git a/unitTests/replication/reconnectJitter.test.mjs b/unitTests/replication/reconnectJitter.test.mjs index dca7ad6ee..cecbceeae 100644 --- a/unitTests/replication/reconnectJitter.test.mjs +++ b/unitTests/replication/reconnectJitter.test.mjs @@ -1,10 +1,9 @@ /** * Coverage for the jittered reconnect schedule (harper-pro#327). `scheduleReconnect` used to wait - * exactly `retryTime` (500ms doubling to a 30s cap), so every node reacting to the same peer outage - * re-dialed on the same instant — a whole fleet restarting together retried in lockstep, and no - * production retry path in the repo had jitter at all. The ceiling schedule is unchanged; only the - * draw under it is new, floored so a near-zero draw cannot become an immediate re-dial (each dial - * allocates native TLS state, harper-pro#339). + * exactly `retryTime`, so every node reacting to the same peer outage re-dialed on the same instant. + * The ceiling schedule is unchanged; the draw is equal jitter (the top half of the window) rather than + * the discipline's default full jitter, because this site's invariant is a dial *rate* — every dial + * allocates native TLS state (harper-pro#339) — so its floor has to scale with the ceiling. * * `null` for the url makes createWebSocket reject before any socket or listener exists, which is the * cheapest way to drive the real scheduleReconnect path without a peer. @@ -15,7 +14,6 @@ import sinon from 'sinon'; import { NodeReplicationConnection } from '#src/replication/replicationConnection'; const INITIAL_RETRY_TIME = 500; -const MIN_RETRY_TIME = 100; const MAX_RETRY_TIME = 30_000; function captureTimerDelays() { @@ -95,19 +93,22 @@ describe('NodeReplicationConnection reconnect jitter (harper-pro#327)', () => { } expect(ceilings).to.deep.equal([1000, 2000, 4000, 8000, 16_000, 30_000, 30_000, 30_000]); - for (const delay of timers.values) { - expect(delay).to.be.at.least(MIN_RETRY_TIME); - expect(delay).to.be.below(MAX_RETRY_TIME); - } + // Every draw sits in the top half of the ceiling it was drawn under, so the minimum interval + // between dials never falls below half of what the jitterless schedule guaranteed. + const ceilingFor = (i) => Math.min(INITIAL_RETRY_TIME * 2 ** i, MAX_RETRY_TIME); + timers.values.forEach((delay, i) => { + expect(delay).to.be.at.least(ceilingFor(i) / 2); + expect(delay).to.be.below(ceilingFor(i)); + }); }); - it('never re-dials immediately, even on a zero draw', () => { + it('a zero draw still waits half the ceiling, so the dial rate stays bounded as it escalates', () => { expect( scheduleDelays( makeConnection(() => 0), 4 ) - ).to.deep.equal([MIN_RETRY_TIME, MIN_RETRY_TIME, MIN_RETRY_TIME, MIN_RETRY_TIME]); + ).to.deep.equal([250, 500, 1000, 2000]); }); it('retryTime reads as the initial interval before any failure', () => { @@ -124,6 +125,6 @@ describe('NodeReplicationConnection reconnect jitter (harper-pro#327)', () => { expect(connection.retries).to.equal(0); expect(connection.retryTime).to.equal(INITIAL_RETRY_TIME); - expect(scheduleDelays(connection, 1)[0]).to.equal(MIN_RETRY_TIME + Math.floor(0.5 * (500 - MIN_RETRY_TIME))); + expect(scheduleDelays(connection, 1)[0], 'drawing under the initial ceiling again').to.equal(375); }); }); diff --git a/unitTests/replication/shouldCloseSendAuthWatch.test.mjs b/unitTests/replication/shouldCloseSendAuthWatch.test.mjs index 6e92734c8..0fcbe1f96 100644 --- a/unitTests/replication/shouldCloseSendAuthWatch.test.mjs +++ b/unitTests/replication/shouldCloseSendAuthWatch.test.mjs @@ -88,6 +88,42 @@ describe('shouldCloseSendAuthWatch', () => { expect(timedOut).to.equal(true); }); + // harper-pro#327: the grace period is advertised as a 30s deadline, so a row that only becomes + // decodable after the loop was suspended past it must not authorize. Checking `exhausted` only at the + // top of the loop was not enough — the loop exits on a non-UNCHANGED row without ever consulting it. + it('fails closed on a row that only resolves after the budget deadline passed', async () => { + let clock = 0; + let timedOut = false; + let resolved = 0; + const shouldClose = await shouldCloseSendAuthWatch({ type: 'put' }, 'node-a', 'data', { + isClosed: neverClosed, + // An event-loop stall: the sleep returns long after the delay it was asked for. + sleep: async () => { + clock += 45_000; + }, + now: () => clock, + reprobeBudgetMs: 30_000, + resolve: () => (resolved++ === 0 ? SEND_AUTH_UNCHANGED : { name: 'node-a', replicates: true }), + onReprobeTimeout: () => { + timedOut = true; + }, + }); + expect(shouldClose, 'the late authorizing row is not consulted').to.equal(true); + expect(timedOut).to.equal(true); + expect(resolved, 'no probe after the deadline').to.equal(1); + }); + + it('does not read the clock at all for an immediately decodable row', async () => { + const shouldClose = await shouldCloseSendAuthWatch({ type: 'put' }, 'node-a', 'data', { + isClosed: neverClosed, + now: () => { + throw new Error('the backoff must not be built for a decodable row'); + }, + resolve: () => ({ name: 'node-a', replicates: true }), + }); + expect(shouldClose).to.equal(false); + }); + it('does not close if the connection closes while the reprobe loop is still suspended', async () => { let closed = false; let timedOut = false; diff --git a/unitTests/replication/subscribeSetupScheduler.test.mjs b/unitTests/replication/subscribeSetupScheduler.test.mjs index 16c2c79db..1ba780604 100644 --- a/unitTests/replication/subscribeSetupScheduler.test.mjs +++ b/unitTests/replication/subscribeSetupScheduler.test.mjs @@ -1,14 +1,12 @@ /** * Regression coverage for harper-pro#327: subscription setup used to be scheduled with a flat 200ms * `setTimeout` per qualifying node update — no dedup, no cap, not unref'd — so whatever re-drove - * `onNodeUpdate` amplified 1:1 into main-thread timers, worker-side WebSocket/TLS setup, and - * `Setting up subscription with leader` warns. Measured in the field at ~1,400 lines/s/node, ending in - * an OOM kill (165k lines on the 5.0.31 rig; 116k on merged main for the boot-time DNS variant). + * `onNodeUpdate` amplified 1:1 into main-thread timers, worker-side WebSocket/TLS setup, and warn + * lines, ending in an OOM kill. * - * The storm test below drives input continuously *across* timer firings, which is the shape of the - * incident — a one-shot burst would only prove coalescing. Against the old flat-200ms behavior the - * same input produces one dispatch per event (60,000 of them) and 60,000 live timers, so the - * dispatch-count and pendingCount assertions both go red. + * The storm test drives input continuously *across* timer firings, which is the shape of the incident; + * a one-shot burst would only prove coalescing. Against the flat-200ms behavior the same input + * produces one dispatch per event and one live timer per event, so both assertions go red. */ import { expect } from 'chai'; @@ -126,6 +124,29 @@ describe('subscription-setup scheduler (harper-pro#327)', () => { expect(dispatches[0].nodes).to.equal(second); }); + // onDatabase's early-return path (an already-subscribed, still-desired entry) never reaches + // schedule(), but it does build a fresh payload — so the armed setup has to be told about it or it + // dispatches routing/exclusion state from before the update. + it('refreshPending replaces the payload of an armed setup without arming one', () => { + const { scheduler, dispatches } = makeScheduler(() => 0.5); + const armed = [{ name: 'peer-a', url: URL_A }]; + const refreshed = [{ name: 'peer-a', url: URL_A, routeReplicates: { receives: true } }]; + scheduler.schedule(URL_A, 'data', armed); + scheduler.refreshPending(URL_A, 'data', refreshed); + expect(scheduler.pendingCount(), 'no second timer').to.equal(1); + clock.tick(300); + expect(dispatches.length).to.equal(1); + expect(dispatches[0].nodes).to.equal(refreshed); + }); + + it('refreshPending on a pair with nothing armed does not arm one', () => { + const { scheduler, dispatches } = makeScheduler(() => 0.5); + scheduler.refreshPending(URL_A, 'data', NODES); + expect(scheduler.pendingCount()).to.equal(0); + clock.tick(60_000); + expect(dispatches).to.deep.equal([]); + }); + it('adds the caller-supplied stagger on top of the backoff', () => { const { scheduler } = makeScheduler(() => 0.5); expect(scheduler.schedule(URL_A, 'data', NODES, 150)).to.equal(450); From 34070867272efb2ab3eb588f4e4f441580cf7efb Mon Sep 17 00:00:00 2001 From: Kris Zyp Date: Wed, 2 Sep 2026 07:26:23 -0600 Subject: [PATCH 04/13] Harden replication retry admission and jitter Bound worker-side pre-readiness subscription work, retain self-catchup state until dispatch, and make exhausted backoffs fail closed. Align reconnect and watcher jitter with the full-jitter policy and extend regression coverage. Co-Authored-By: GPT-5 Codex --- cloneNode/cloneNode.ts | 5 +- cloneNode/jwtKeyClone.ts | 5 +- replication/DESIGN.md | 40 +++-- replication/backoff.ts | 35 ++-- replication/blobRepair.ts | 3 +- replication/knownNodes.ts | 5 +- replication/replicationConnection.ts | 16 +- replication/replicator.ts | 12 +- replication/subscriptionManager.ts | 170 ++++++++++++++---- unitTests/replication/backoff.test.mjs | 72 +++----- .../replication/nodeUpdateWatcher.test.mjs | 17 +- .../replication/reconnectJitter.test.mjs | 40 ++--- .../subscribeSetupScheduler.test.mjs | 142 ++++++++++----- .../workerSubscriptionAdmission.test.mjs | 108 +++++++++++ 14 files changed, 473 insertions(+), 197 deletions(-) create mode 100644 unitTests/replication/workerSubscriptionAdmission.test.mjs diff --git a/cloneNode/cloneNode.ts b/cloneNode/cloneNode.ts index 5ce2dad34..bba537291 100644 --- a/cloneNode/cloneNode.ts +++ b/cloneNode/cloneNode.ts @@ -724,7 +724,10 @@ async function monitorSync( break; } catch (err) { log(`Leader version probe failed (attempt ${attempt}/3): ${err}`); - if (attempt < 3) await sleep(versionProbeBackoff.nextDelay()); + if (attempt < 3) { + const delay = versionProbeBackoff.nextDelay(); + if (delay !== undefined) await sleep(delay); + } } } diff --git a/cloneNode/jwtKeyClone.ts b/cloneNode/jwtKeyClone.ts index b4caa7c6d..79a72beb6 100644 --- a/cloneNode/jwtKeyClone.ts +++ b/cloneNode/jwtKeyClone.ts @@ -50,7 +50,10 @@ export async function fetchJWTKeyWithRetry( } catch (err) { lastError = err; } - if (attempt < retries) await sleep(backoff.nextDelay()); + if (attempt < retries) { + const delay = backoff.nextDelay(); + if (delay !== undefined) await sleep(delay); + } } throw new Error(`Unable to clone JWT key '${keyName}' from leader after ${retries} attempts`, { cause: lastError }); } diff --git a/replication/DESIGN.md b/replication/DESIGN.md index 27976c73e..039ffb178 100644 --- a/replication/DESIGN.md +++ b/replication/DESIGN.md @@ -105,24 +105,24 @@ Schema (defined in that function): `name` (PK), `subscriptions[]`, `system_info` Every retry/reconnect initiation site paces attempts through **one** utility, `createBackoff` in `backoff.ts`: an exponential ceiling with **full jitter** (uniform draw across the window) by default, -`'equal'` jitter (the top half of the window) for a site whose invariant is a rate rather than a -latency bound, an optional fixed floor, an optional wall-clock budget, and injectable RNG/clock so every bound is -deterministically testable. Before this there was no jitter anywhere in production code — a fleet +an optional fixed floor, an optional wall-clock/attempt budget, and injectable RNG/clock so every bound is +deterministically testable. An exhausted schedule returns no delay rather than `0`, so a missed exhaustion +check cannot create a busy loop. Before this there was no jitter anywhere in production code — a fleet reacting to one event retried in lockstep — and the delays themselves ranged from flat 200 ms to jitterless doubling. The invariant the discipline enforces: **at most one pending attempt per target, on a bounded, capped, decorrelated schedule.** Pacing alone is not enough; the storm surface below needed the dedup too. -| Site | Schedule | Reset signal | -| ------------------------------------------------------------------------------- | ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | -------------------------------------------------------------- | -| `createSubscribeSetupScheduler` (`subscriptionManager.ts`) — subscription setup | floor `NODE_SUBSCRIBE_DELAY`, ceiling `2 × NODE_SUBSCRIBE_DELAY` → 30 s, plus the caller's `RECONNECT_STAGGER_MS` stagger | `connectedToNode` (also cancels the pending setup) | -| `NodeReplicationConnection.scheduleReconnect` | ceiling `INITIAL_RETRY_TIME` 500 ms → 30 s, **equal** jitter (top half): this site's invariant is a dial rate, and only a ceiling-relative floor keeps the minimum interval proportional as the ceiling escalates (harper-pro#339) | `onFrameSent` — first frame actually sent, **not** socket open | -| `reconcileWorkers` wedge / receive-stall re-drives | fixed window (decorrelation only; the re-drives are already throttled by the `disconnectedAt` / `receiveStallReconnectAt` re-stamps), one owned `entry.reDriveTimer` per entry | n/a — disarmed on connect, unsubscribe, and delete | -| `runNodeUpdateWatcher` (`knownNodes.ts`) — hdb_nodes watcher restart | floor/ceiling 1 s → 30 s | an iteration that survived `NODE_WATCHER_HEALTHY_UPTIME_MS` | -| `shouldCloseSendAuthWatch` reprobe (`replicationConnection.ts`) | 500 ms → 5 s under a 30 s wall-clock budget, then fails closed | n/a (one-shot loop) | -| `fetchJWTKeyWithRetry`, the clone version probe (`cloneNode/`) | 250 ms → 1 s / 1 s → 4 s, attempt count unchanged | n/a | -| `repairBlobs` (`blobRepair.ts`) — per-record | 50 ms → 1 s, only on a record no peer could repair | a repaired record | +| Site | Schedule | Reset signal | +| ------------------------------------------------------------------------------- | -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | -------------------------------------------------------------- | +| `createSubscribeSetupScheduler` (`subscriptionManager.ts`) — subscription setup | floor `NODE_SUBSCRIBE_DELAY`, ceiling `2 × NODE_SUBSCRIBE_DELAY` → 30 s, plus the caller's `RECONNECT_STAGGER_MS` stagger | `connectedToNode` (also cancels the pending setup) | +| `NodeReplicationConnection.scheduleReconnect` | fixed 500 ms floor, ceiling `INITIAL_RETRY_TIME` 500 ms → 30 s, full jitter; the floor preserves the hard minimum from the TLS-state incident while the remaining window decorrelates fleet redials (harper-pro#339) | `onFrameSent` — first frame actually sent, **not** socket open | +| `reconcileWorkers` wedge / receive-stall re-drives | fixed window (decorrelation only; the re-drives are already throttled by the `disconnectedAt` / `receiveStallReconnectAt` re-stamps), one owned `entry.reDriveTimer` per entry | n/a — disarmed on connect, unsubscribe, and delete | +| `runNodeUpdateWatcher` (`knownNodes.ts`) — hdb_nodes watcher restart | full-jitter ceiling 1 s → 30 s | an iteration that survived `NODE_WATCHER_HEALTHY_UPTIME_MS` | +| `shouldCloseSendAuthWatch` reprobe (`replicationConnection.ts`) | 500 ms → 5 s under a 30 s wall-clock budget, then fails closed | n/a (one-shot loop) | +| `fetchJWTKeyWithRetry`, the clone version probe (`cloneNode/`) | 250 ms → 1 s / 1 s → 4 s, attempt count unchanged | n/a | +| `repairBlobs` (`blobRepair.ts`) — per-record | 50 ms → 1 s, only on a record no peer could repair | a repaired record | **The subscription-setup scheduler is the one with dedup.** `onDatabase` used to turn every qualifying node update straight into a retained (not unref'd) 200 ms `setTimeout` plus a `subscribe-to-node` @@ -130,15 +130,25 @@ message, so whatever re-drove `onNodeUpdate` amplified 1:1 into main-thread time WebSocket/TLS setup, and `Setting up subscription with leader` warns — ~1,400 lines/s/node in the field, ending in an OOM kill. The scheduler holds one armed setup per **(peer URL, database)** in its own map (_not_ on the `connectionReplicationMap` entry, which the stale-worker path deletes and recreates), and -the armed setup carries the payload of the call that armed or last refreshed it — reading `entry.nodes` -at fire time is _not_ safe, because `onDatabase`'s early-return path replaces that array without -running the leader/url enrichment (that path calls `refreshPending` instead). A setup is cancelled on +the armed setup carries the newest level-state payload — reading `entry.nodes` at fire time is _not_ +safe, because `onDatabase`'s early-return path replaces that array without running the leader/url +enrichment (that path calls `refreshPending` instead). Self-catchup is separate one-shot state: it is +attached on a fresh array immediately before dispatch and consumed only after the worker message is +accepted, so timer cancellation, stale dispatch, or a synchronous `postMessage` throw cannot lose it. +A setup is cancelled on connect, on unsubscribe, on node deletion, and on a same-name URL migration, all of which became reachable once a pending timer could live 30 s instead of 200 ms. The wedge/stall recovery kicks are owned the same way — one `entry.reDriveTimer` per entry, so a staggered sweep that outruns the reconcile window that started it replaces its predecessor instead of stacking another wave. The warn moved inside the "actually armed" branch: it now describes an attempt, not an event. +The worker boundary has one additional admission point for its asynchronous startup window. Before +components are ready, one insertion-ordered map retains only the latest subscribe/unsubscribe message +per actual connection key and database, with one continuation on the readiness promise. After readiness, +the handlers run inline and allocate no queue state; the existing connection map is then the single-flight +owner. Subscribe, unsubscribe, force-reconnect, and startup admission all derive the connection key through +`getSubscriptionConnectionKey`, including the missing nested-URL fallback. + **What is deliberately NOT on this schedule:** the receive/copy watchdogs and their thresholds (they _detect_ stalls; this discipline paces _retries_), `blobGapReconnectTimer`, the in-place `BLOB_SEND_RETRY_DELAYS_MS` 503 retries, `PING_INTERVAL`/`PING_TIMEOUT`, and `RECONCILE_INTERVAL_MS`. diff --git a/replication/backoff.ts b/replication/backoff.ts index f9896cc41..071c43dfa 100644 --- a/replication/backoff.ts +++ b/replication/backoff.ts @@ -3,10 +3,8 @@ * `DESIGN.md` under "Backoff discipline". * * Full jitter (uniform over the whole window) is the default because decorrelating a fleet's retries - * matters more than a tight worst-case delay on these cold error paths. `'equal'` (the top half of the - * window) is for a site whose invariant is a *rate* bound rather than a latency bound: only a - * ceiling-relative floor keeps the minimum interval proportional as the ceiling escalates. `minMs` is - * the fixed-floor variant, for a site with a lower bound of its own. + * matters more than a tight worst-case delay on these cold error paths. `minMs` preserves a site's + * independent lower bound while jittering the rest of the window. * * `budgetMs` is a deadline read off an injected monotonic clock, not a sum of requested sleeps: a * resolver hang or an event-loop stall must not extend a bounded grace period past what it advertises. @@ -14,33 +12,22 @@ */ export interface BackoffOptions { - /** Ceiling for the first attempt; doubles (or `factor`s) from there. */ initialMs: number; - /** Upper bound on the ceiling. */ maxMs: number; - /** Lower bound on every returned delay. Defaults to 0 (pure full jitter). */ minMs?: number; factor?: number; - /** 'full': uniform over [minMs, ceiling). 'equal': uniform over the top half. 'none': the ceiling. */ - jitter?: 'full' | 'equal' | 'none'; - /** Wall-clock budget, measured from creation/`reset()`. Without it the schedule never exhausts. */ + jitter?: 'full' | 'none'; budgetMs?: number; maxAttempts?: number; random?: () => number; - /** Monotonic clock. Injected for tests; `Date.now` would let a wall-clock jump extend a budget. */ now?: () => number; } export interface Backoff { - /** The delay to wait before the next attempt, and advances the schedule. */ - nextDelay(): number; - /** Back to the first attempt, and restarts the budget clock. Call on real progress, not on setup. */ + nextDelay(): number | undefined; reset(): void; - /** How many delays have been handed out since the last reset. */ readonly attempts: number; - /** The ceiling the next `nextDelay()` will draw under. */ readonly ceiling: number; - /** True once the budget deadline has passed or `maxAttempts` delays have been handed out. */ readonly exhausted: boolean; } @@ -62,6 +49,10 @@ export function createBackoff(options: BackoffOptions): Backoff { function ceilingFor(attempt: number): number { return Math.max(minMs, Math.min(initialMs * factor ** attempt, maxMs)); } + function isExhausted(currentTime: number): boolean { + if (maxAttempts !== undefined && attempts >= maxAttempts) return true; + return deadline !== undefined && currentTime >= deadline; + } return { get attempts() { @@ -71,15 +62,15 @@ export function createBackoff(options: BackoffOptions): Backoff { return ceilingFor(attempts); }, get exhausted() { - if (maxAttempts !== undefined && attempts >= maxAttempts) return true; - return deadline !== undefined && now() >= deadline; + return isExhausted(now()); }, nextDelay() { + const currentTime = now(); + if (isExhausted(currentTime)) return undefined; const ceiling = ceilingFor(attempts); attempts++; - const floor = jitter === 'equal' ? Math.max(minMs, ceiling / 2) : minMs; - let delay = jitter === 'none' ? ceiling : floor + Math.floor(random() * (ceiling - floor)); - if (deadline !== undefined) delay = Math.max(0, Math.min(delay, deadline - now())); + let delay = jitter === 'none' ? ceiling : minMs + Math.floor(random() * (ceiling - minMs)); + if (deadline !== undefined) delay = Math.min(delay, deadline - currentTime); return delay; }, reset() { diff --git a/replication/blobRepair.ts b/replication/blobRepair.ts index 5f183e195..08d6b9595 100644 --- a/replication/blobRepair.ts +++ b/replication/blobRepair.ts @@ -90,7 +90,8 @@ export async function repairBlobs( } else { failed++; logger.warn?.('Could not repair blob for record', recordId, 'in', tableName, '— no peer had a complete copy'); - await pause(backoff.nextDelay()); + const delay = backoff.nextDelay(); + if (delay !== undefined) await pause(delay); } } diff --git a/replication/knownNodes.ts b/replication/knownNodes.ts index 3bd79a2c9..a57f6c684 100644 --- a/replication/knownNodes.ts +++ b/replication/knownNodes.ts @@ -188,7 +188,6 @@ export async function runNodeUpdateWatcher( const backoff = createBackoff({ initialMs: restartDelayMs, maxMs: maxDelayMs, - minMs: Math.min(restartDelayMs, maxDelayMs), random: options.random, }); const isCurrent = () => generation === (watcherGenerations.get(key) ?? 0); @@ -227,7 +226,9 @@ export async function runNodeUpdateWatcher( if (now() - startedAt >= healthyUptimeMs) backoff.reset(); restarts++; if (restarts >= maxRestarts || !isCurrent()) return; - await new Promise((resolve) => setTimeout(resolve, backoff.nextDelay())); + const delay = backoff.nextDelay(); + if (delay === undefined) return; + await new Promise((resolve) => setTimeout(resolve, delay).unref()); } } /** diff --git a/replication/replicationConnection.ts b/replication/replicationConnection.ts index 7f78b99f9..dc21adeb6 100644 --- a/replication/replicationConnection.ts +++ b/replication/replicationConnection.ts @@ -601,7 +601,9 @@ export async function shouldCloseSendAuthWatch( now: deps.now, }); if (backoff.exhausted) break; - await sleep(backoff.nextDelay()); + const delay = backoff.nextDelay(); + if (delay === undefined) break; + await sleep(delay); // Re-check before trusting the next read, not just at the top of the loop: the grace period is // advertised as a deadline, so a row that only becomes decodable after an event-loop stall // pushed us past it must not authorize. Fail closed on the elapsed time, not on the row. @@ -2701,19 +2703,19 @@ export class NodeReplicationConnection extends EventEmitter { // it) would still accumulate unreleased native TLS state faster than V8 can // GC under CPU-saturated bulk-write conditions, leading to OOM (#339). // Doubling reaches 30 s in ~6 retries and resets on success. The delay is drawn - // uniformly over the TOP HALF of that ceiling ('equal', not the discipline's default - // full jitter): decorrelating a fleet that restarts together is worth having, but this - // site's invariant is a dial *rate*, and a ceiling-relative floor is what keeps the - // minimum dial interval proportional as the ceiling escalates. + // with full jitter so a fleet reacting to one outage does not redial in lockstep. Keep + // the original 500 ms lower bound from #339 while jittering the rest of the window. this.retryBackoff ??= createBackoff({ initialMs: INITIAL_RETRY_TIME, maxMs: MAX_RETRY_TIME, - jitter: 'equal', + minMs: INITIAL_RETRY_TIME, random: this.random, }); + const delay = this.retryBackoff.nextDelay(); + if (delay === undefined) return; setTimeout(() => { this.connect(); - }, this.retryBackoff.nextDelay()).unref(); + }, delay).unref(); } /** The ceiling the next reconnect will be drawn under; the initial value means "not backed off". */ get retryTime(): number { diff --git a/replication/replicator.ts b/replication/replicator.ts index 27c1cff7a..5965141d0 100644 --- a/replication/replicator.ts +++ b/replication/replicator.ts @@ -547,7 +547,7 @@ function getSubscriptionConnection( authorization?: string, status?: { reused: boolean } ) { - const connectionKey = connectingUrl + '-' + subscriptionUrl; + const connectionKey = getSubscriptionConnectionKey(connectingUrl, subscriptionUrl); let dbConnections = connections.get(connectionKey); if (!dbConnections) { dbConnections = new Map(); @@ -570,6 +570,10 @@ function getSubscriptionConnection( return connection; } } + +export function getSubscriptionConnectionKey(connectingUrl: string, subscriptionUrl?: string): string { + return connectingUrl + '-' + (subscriptionUrl ?? connectingUrl); +} const nodeNameToRetrievalConnections = new Map>(); /** * Get connection by node name, using caching @@ -693,7 +697,7 @@ export function subscribeToNode(request: any) { logger.error('Error in subscription to node', request.nodes[0]?.url, error); } } -export async function unsubscribeFromNode({ url, nodes, database }) { +export function unsubscribeFromNode({ url, nodes, database }) { logger.trace( 'Unsubscribing from node', url, @@ -701,7 +705,7 @@ export async function unsubscribeFromNode({ url, nodes, database }) { 'nodes', Array.from(getHDBNodeTable().primaryStore.getRange({})) ); - const connectionKey = url + '-' + (nodes[0]?.url ?? url); + const connectionKey = getSubscriptionConnectionKey(url, nodes[0]?.url); const dbConnections = connections.get(connectionKey); if (dbConnections) { const connection = dbConnections.get(database); @@ -721,7 +725,7 @@ export async function unsubscribeFromNode({ url, nodes, database }) { // the worker-local copy-progress watchdog (harper-pro#453) did not recover it. The connection-key lookup // mirrors unsubscribeFromNode so it resolves the same connection the subscribe path created. export function forceReconnectToNode({ url, nodes, database }) { - const connectionKey = url + '-' + (nodes?.[0]?.url ?? url); + const connectionKey = getSubscriptionConnectionKey(url, nodes?.[0]?.url); const connection = connections.get(connectionKey)?.get(database); if (connection) connection.forceReconnect(); } diff --git a/replication/subscriptionManager.ts b/replication/subscriptionManager.ts index aa91ac66b..8d97ccffe 100644 --- a/replication/subscriptionManager.ts +++ b/replication/subscriptionManager.ts @@ -13,6 +13,7 @@ import { forEachReplicatedDatabase, unsubscribeFromNode, forceReconnectToNode, + getSubscriptionConnectionKey, } from './replicator.ts'; import { getThisNodeName, getThisNodeUrl } from '../core/server/nodeName.ts'; import { parentPort } from 'worker_threads'; @@ -207,7 +208,9 @@ export function createSubscribeSetupScheduler(deps: { } schedule.nodes = nodes; if (schedule.timer) return undefined; - const delay = schedule.backoff.nextDelay() + staggerMs; + const backoffDelay = schedule.backoff.nextDelay(); + if (backoffDelay === undefined) return undefined; + const delay = backoffDelay + staggerMs; schedule.timer = setTimeout(() => { schedule.timer = undefined; const pending = schedule.nodes; @@ -247,6 +250,34 @@ export function createSubscribeSetupScheduler(deps: { }; } +export function dispatchSubscriptionNodes( + nodes: any[], + deps: { + startTime?: number; + nodeName?: string; + now?: () => number; + dispatch: (nodes: any[]) => void; + consume: () => void; + } +) { + if (deps.startTime === undefined) { + deps.dispatch(nodes); + return; + } + const dispatchNodes = [ + ...nodes, + { + replicateByDefault: nodes[0]?.replicateByDefault, + name: deps.nodeName, + startTime: deps.startTime, + endTime: (deps.now ?? Date.now)(), + replicates: true, + }, + ]; + deps.dispatch(dispatchNodes); + deps.consume(); +} + /** * Send the subscribe-to-node the scheduler armed. The entry can have been unsubscribed, deleted, or * reassigned to another worker during the (now up to 30s) wait, so ownership is re-checked against @@ -258,10 +289,19 @@ export function createSubscribeSetupScheduler(deps: { function dispatchSubscribeSetup(url: string, database: string, nodes: any[]) { const entry = connectionReplicationMap.get(url)?.get(database); if (!entry || entry.unsubscribed || !nodes[0]) return; - const request = { ...nodes[0], type: 'subscribe-to-node', database, nodes }; - if (entry.worker) { - entry.worker.postMessage(request); - } else subscribeToNode(request); + const startTime = env.get(CONFIG_PARAMS.REPLICATION_FAILOVER) ? selfCatchupOfDatabase.get(database) : undefined; + dispatchSubscriptionNodes(nodes, { + startTime, + nodeName: getThisNodeName(), + dispatch(dispatchNodes) { + const request = { ...dispatchNodes[0], type: 'subscribe-to-node', database, nodes: dispatchNodes }; + if (entry.worker) entry.worker.postMessage(request); + else subscribeToNode(request); + }, + consume() { + selfCatchupOfDatabase.delete(database); + }, + }); } const subscribeSetupScheduler = createSubscribeSetupScheduler({ dispatch: dispatchSubscribeSetup }); @@ -921,20 +961,6 @@ export async function startOnMainThread(options) { // does for table-exclusion. undefined when no config route matches this peer. harper-pro#498. const configRouteReplicates = matchingRoute ? matchingRoute.replicates : undefined; const nodes = [{ replicateByDefault: tablesReplicateByDefault, ...node, routeReplicates, configRouteReplicates }]; - // Self catchup is done in case we have replicated any records that weren't actually written to our storage - // before a crash. - if (selfCatchupOfDatabase.has(databaseName) && env.get(CONFIG_PARAMS.REPLICATION_FAILOVER)) { - // if we have a self catchup (only do if we have failover enabled), we need to add this node to the list of nodes that need to catch up - // and then we will remove it when it is done - nodes.push({ - replicateByDefault: tablesReplicateByDefault, - name: getThisNodeName(), - startTime: selfCatchupOfDatabase.get(databaseName), - endTime: Date.now(), - replicates: true, - }); - selfCatchupOfDatabase.delete(databaseName); - } // Use the enriched payload (nodes[0]) so the receive gate sees configRouteReplicates. const shouldSubscribe = shouldReplicateFromNode(nodes[0] as any, databaseName); // Resolve the URL here rather than at the subscribe-scheduling site below: this array becomes @@ -1346,11 +1372,15 @@ export async function startOnMainThread(options) { // One armed recovery per entry: a sweep staggered across many databases can still be firing when the // next reconcile decides again, and a superseded wave's timers would otherwise be retained until // they no-op. - const armReDrive = (entry: any, delay: number, fire: () => void) => { + const armReDrive = (entry: any, delay: number, url: string, database: string, fire: () => void) => { clearTimeout(entry.reDriveTimer); const timer = setTimeout(() => { entry.reDriveTimer = undefined; - fire(); + try { + fire(); + } catch (error) { + logger.error('Error dispatching replication recovery for', url, database, error); + } }, delay); timer.unref(); return timer; @@ -1442,9 +1472,11 @@ export async function startOnMainThread(options) { // Stagger reconnects (RECONNECT_STAGGER_MS apart) so opening N TLS connections // simultaneously does not spike memory when there are many databases; jitter the base so // every node in a fleet reacting to the same peer outage doesn't fire on the same tick. - const delay = reDriveBackoff.nextDelay() + reconnectCount * RECONNECT_STAGGER_MS; + const backoffDelay = reDriveBackoff.nextDelay(); + if (backoffDelay === undefined) continue; + const delay = backoffDelay + reconnectCount * RECONNECT_STAGGER_MS; reconnectCount++; - entry.reDriveTimer = armReDrive(entry, delay, () => { + entry.reDriveTimer = armReDrive(entry, delay, url, databaseName, () => { // The stamp is our claim on this entry: connectedToNode clears disconnectedAt and a later // reconcile re-stamps it, either of which means this re-drive is stale and would interrupt // a connection that has already recovered or been re-driven. @@ -1489,9 +1521,11 @@ export async function startOnMainThread(options) { database: databaseName, nodes, }; - const delay = reDriveBackoff.nextDelay() + reconnectCount * RECONNECT_STAGGER_MS; + const backoffDelay = reDriveBackoff.nextDelay(); + if (backoffDelay === undefined) continue; + const delay = backoffDelay + reconnectCount * RECONNECT_STAGGER_MS; reconnectCount++; - entry.reDriveTimer = armReDrive(entry, delay, () => { + entry.reDriveTimer = armReDrive(entry, delay, url, databaseName, () => { // Same staleness claim as the wedge path: a newer reconcile re-stamping // receiveStallReconnectAt owns the kick from then on. if (entries?.get(databaseName) !== entry || entry.receiveStallReconnectAt !== now) return; @@ -1586,12 +1620,83 @@ export function requestClusterStatus(message?, port?) { // the dynamic import resolves to the cached module with no side effect. Cached after first use. let componentsLoadedPromise: Promise | undefined; function whenWorkerComponentsLoaded(): Promise { - return (componentsLoadedPromise ??= import('../core/server/threads/threadServer.js').then( - (threadServer) => threadServer.whenComponentsLoaded - )); + return (componentsLoadedPromise ??= import('../core/server/threads/threadServer.js') + .then((threadServer) => threadServer.whenComponentsLoaded) + .catch((error) => { + componentsLoadedPromise = undefined; + throw error; + })); +} + +export function createWorkerSubscriptionAdmission(deps: { + whenReady: () => Promise; + key: (message: any) => string; + dispatch: (message: any) => void; + onError: (message: any | undefined, error: unknown) => void; +}) { + let ready = false; + let flushScheduled = false; + const pending = new Map(); + + function dispatch(message: any) { + try { + deps.dispatch(message); + } catch (error) { + deps.onError(message, error); + } + } + function scheduleFlush() { + if (flushScheduled) return; + flushScheduled = true; + deps + .whenReady() + .then(() => { + ready = true; + for (const [key, message] of pending) { + pending.delete(key); + dispatch(message); + } + }) + .catch((error) => deps.onError(undefined, error)) + .finally(() => { + flushScheduled = false; + }); + } + + return { + submit(message: any) { + if (ready && pending.size === 0) { + dispatch(message); + return; + } + pending.set(deps.key(message), message); + scheduleFlush(); + }, + pendingCount() { + return pending.size; + }, + }; } if (parentPort) { + const subscriptionAdmission = createWorkerSubscriptionAdmission({ + whenReady: whenWorkerComponentsLoaded, + key: (message) => getSubscriptionConnectionKey(message.url, message.nodes?.[0]?.url) + '\0' + message.database, + dispatch(message) { + if (message.type === 'subscribe-to-node') subscribeToNode(message); + else unsubscribeFromNode(message); + }, + onError(message, error) { + if (message) + logger.error( + 'Error applying deferred replication subscription action for', + message.url, + message.database, + error + ); + else logger.error('Error waiting for worker components before replication subscription setup', error); + }, + }); disconnectedFromNode = (connection) => { parentPort.postMessage({ type: 'disconnected-from-node', ...connection }); }; @@ -1605,13 +1710,12 @@ if (parentPort) { // "no subscriptions" close, wedging the (peer, db) until restart (harper-pro#289 / #233). Once // components are loaded the predicate is authoritative. In steady state the promise is already // resolved, so this is effectively synchronous. - whenWorkerComponentsLoaded().then(() => subscribeToNode(message)); + subscriptionAdmission.submit(message); }); onMessageByType('unsubscribe-from-node', (message) => { - // Defer through the same gate as subscribe-to-node so the two stay ordered: a pre-load - // subscribe followed by an unsubscribe must apply in that order (else the deferred subscribe - // would run after the unsubscribe and re-open a connection the main thread already removed). - whenWorkerComponentsLoaded().then(() => unsubscribeFromNode(message)); + // Before readiness no connection can exist, so the latest action for the pair is authoritative; + // after readiness both handlers run inline in parentPort delivery order. + subscriptionAdmission.submit(message); }); onMessageByType('force-reconnect-node', (message) => { // Reconcile-driven recovery for a connected:true / Receiving / no-progress stall. Acts on an diff --git a/unitTests/replication/backoff.test.mjs b/unitTests/replication/backoff.test.mjs index b24fca544..7338a9738 100644 --- a/unitTests/replication/backoff.test.mjs +++ b/unitTests/replication/backoff.test.mjs @@ -1,56 +1,38 @@ -/** - * Coverage for the shared replication backoff schedule (harper-pro#327). Every assertion that - * involves jitter injects the RNG, so the bounds are exact rather than statistical. - */ +/** Coverage for the shared replication backoff schedule (harper-pro#327). */ -import { expect } from 'chai'; +import assert from 'node:assert'; import { createBackoff } from '#src/replication/backoff'; describe('createBackoff', () => { it('doubles the ceiling per attempt and caps it', () => { const backoff = createBackoff({ initialMs: 500, maxMs: 4000, jitter: 'none' }); - expect([ - backoff.nextDelay(), - backoff.nextDelay(), - backoff.nextDelay(), - backoff.nextDelay(), - backoff.nextDelay(), - ]).to.deep.equal([500, 1000, 2000, 4000, 4000]); + assert.deepEqual( + [backoff.nextDelay(), backoff.nextDelay(), backoff.nextDelay(), backoff.nextDelay(), backoff.nextDelay()], + [500, 1000, 2000, 4000, 4000] + ); }); it('honours a non-default factor', () => { const backoff = createBackoff({ initialMs: 100, maxMs: 10_000, factor: 3, jitter: 'none' }); - expect([backoff.nextDelay(), backoff.nextDelay(), backoff.nextDelay()]).to.deep.equal([100, 300, 900]); + assert.deepEqual([backoff.nextDelay(), backoff.nextDelay(), backoff.nextDelay()], [100, 300, 900]); }); it('draws full jitter across the whole window, never reaching the ceiling', () => { const draws = [0, 0.5, 0.999999]; let i = 0; const backoff = createBackoff({ initialMs: 1000, maxMs: 1000, random: () => draws[i++] }); - expect([backoff.nextDelay(), backoff.nextDelay(), backoff.nextDelay()]).to.deep.equal([0, 500, 999]); - }); - - it('equal jitter draws only from the top half of the window, so the floor scales with the ceiling', () => { - const low = createBackoff({ initialMs: 500, maxMs: 30_000, jitter: 'equal', random: () => 0 }); - expect([low.nextDelay(), low.nextDelay(), low.nextDelay()]).to.deep.equal([250, 500, 1000]); - const high = createBackoff({ initialMs: 500, maxMs: 30_000, jitter: 'equal', random: () => 0.999999 }); - expect([high.nextDelay(), high.nextDelay(), high.nextDelay()]).to.deep.equal([499, 999, 1999]); - }); - - it('equal jitter still respects an explicit minMs floor above the half-ceiling', () => { - const backoff = createBackoff({ initialMs: 400, maxMs: 400, minMs: 300, jitter: 'equal', random: () => 0 }); - expect(backoff.nextDelay()).to.equal(300); + assert.deepEqual([backoff.nextDelay(), backoff.nextDelay(), backoff.nextDelay()], [0, 500, 999]); }); it('floors the jitter window at minMs', () => { const backoff = createBackoff({ initialMs: 1000, maxMs: 1000, minMs: 400, random: () => 0 }); - expect(backoff.nextDelay(), 'a zero draw still waits the floor').to.equal(400); - expect(createBackoff({ initialMs: 1000, maxMs: 1000, minMs: 400, random: () => 0.5 }).nextDelay()).to.equal(700); + assert.equal(backoff.nextDelay(), 400, 'a zero draw still waits the floor'); + assert.equal(createBackoff({ initialMs: 1000, maxMs: 1000, minMs: 400, random: () => 0.5 }).nextDelay(), 700); }); it('keeps the ceiling above minMs even when maxMs is lower', () => { const backoff = createBackoff({ initialMs: 10, maxMs: 10, minMs: 250, random: () => 0.9 }); - expect(backoff.nextDelay()).to.equal(250); + assert.equal(backoff.nextDelay(), 250); }); it('decorrelates two schedules with identical failure timing', () => { @@ -58,25 +40,25 @@ describe('createBackoff', () => { const b = createBackoff({ initialMs: 500, maxMs: 30_000, random: () => 0.9 }); const aDelays = [a.nextDelay(), a.nextDelay(), a.nextDelay()]; const bDelays = [b.nextDelay(), b.nextDelay(), b.nextDelay()]; - expect(aDelays).to.not.deep.equal(bDelays); - for (let i = 0; i < aDelays.length; i++) expect(aDelays[i]).to.be.below(bDelays[i]); + assert.notDeepEqual(aDelays, bDelays); + for (let i = 0; i < aDelays.length; i++) assert.ok(aDelays[i] < bDelays[i]); }); it('reset() returns to the first ceiling', () => { const backoff = createBackoff({ initialMs: 500, maxMs: 30_000, jitter: 'none' }); backoff.nextDelay(); backoff.nextDelay(); - expect(backoff.attempts).to.equal(2); - expect(backoff.ceiling).to.equal(2000); + assert.equal(backoff.attempts, 2); + assert.equal(backoff.ceiling, 2000); backoff.reset(); - expect(backoff.attempts).to.equal(0); - expect(backoff.nextDelay()).to.equal(500); + assert.equal(backoff.attempts, 0); + assert.equal(backoff.nextDelay(), 500); }); it('is never exhausted without a budget or attempt cap', () => { const backoff = createBackoff({ initialMs: 1, maxMs: 2 }); for (let i = 0; i < 1000; i++) backoff.nextDelay(); - expect(backoff.exhausted).to.equal(false); + assert.equal(backoff.exhausted, false); }); it('exhausts on the wall-clock deadline, not on the sum of requested sleeps', () => { @@ -85,12 +67,13 @@ describe('createBackoff', () => { // cannot extend the grace period past what it advertises. let clock = 0; const backoff = createBackoff({ initialMs: 500, maxMs: 5000, budgetMs: 30_000, now: () => clock }); - expect(backoff.exhausted).to.equal(false); + assert.equal(backoff.exhausted, false); backoff.nextDelay(); clock = 29_999; - expect(backoff.exhausted).to.equal(false); + assert.equal(backoff.exhausted, false); clock = 30_000; - expect(backoff.exhausted).to.equal(true); + assert.equal(backoff.exhausted, true); + assert.equal(backoff.nextDelay(), undefined); }); it('clamps the last delay so it cannot overshoot the deadline', () => { @@ -103,24 +86,25 @@ describe('createBackoff', () => { now: () => clock, }); clock = 700; - expect(backoff.nextDelay()).to.equal(300); + assert.equal(backoff.nextDelay(), 300); }); it('restarts the budget clock on reset()', () => { let clock = 0; const backoff = createBackoff({ initialMs: 10, maxMs: 10, budgetMs: 100, now: () => clock }); clock = 150; - expect(backoff.exhausted).to.equal(true); + assert.equal(backoff.exhausted, true); backoff.reset(); - expect(backoff.exhausted).to.equal(false); + assert.equal(backoff.exhausted, false); }); it('exhausts on maxAttempts even when the clock never advances', () => { const backoff = createBackoff({ initialMs: 10, maxMs: 10, budgetMs: 30_000, maxAttempts: 3, now: () => 0 }); backoff.nextDelay(); backoff.nextDelay(); - expect(backoff.exhausted).to.equal(false); + assert.equal(backoff.exhausted, false); backoff.nextDelay(); - expect(backoff.exhausted).to.equal(true); + assert.equal(backoff.exhausted, true); + assert.equal(backoff.nextDelay(), undefined); }); }); diff --git a/unitTests/replication/nodeUpdateWatcher.test.mjs b/unitTests/replication/nodeUpdateWatcher.test.mjs index a54ef8d7b..019713b28 100644 --- a/unitTests/replication/nodeUpdateWatcher.test.mjs +++ b/unitTests/replication/nodeUpdateWatcher.test.mjs @@ -22,12 +22,22 @@ import { runNodeUpdateWatcher } from '#src/replication/knownNodes'; function captureTimerDelays() { const realSetTimeout = globalThis.setTimeout; const values = []; + let unrefCalls = 0; globalThis.setTimeout = (fn, ms) => { values.push(ms); - return realSetTimeout(fn, ms); + const timer = realSetTimeout(fn, ms); + const unref = timer.unref.bind(timer); + timer.unref = () => { + unrefCalls++; + return unref(); + }; + return timer; }; return { values, + get unrefCalls() { + return unrefCalls; + }, restore() { globalThis.setTimeout = realSetTimeout; }, @@ -136,7 +146,8 @@ describe('runNodeUpdateWatcher restart loop', () => { delays.restore(); } - expect(delays.values).to.deep.equal([4, 7, 15, 31]); + expect(delays.values).to.deep.equal([3, 7, 15, 31]); + expect(delays.unrefCalls).to.equal(4); }); it('resets the backoff once an iteration survives the healthy-uptime threshold', async () => { @@ -162,7 +173,7 @@ describe('runNodeUpdateWatcher restart loop', () => { } expect(subscribeCalls).to.equal(4); - expect(delays.values, 'a healthy run never escalates').to.deep.equal([4, 4, 4]); + expect(delays.values, 'a healthy run never escalates').to.deep.equal([3, 3, 3]); }); it('forwards events to the listener via the default processEvent path', async () => { diff --git a/unitTests/replication/reconnectJitter.test.mjs b/unitTests/replication/reconnectJitter.test.mjs index cecbceeae..7045a171c 100644 --- a/unitTests/replication/reconnectJitter.test.mjs +++ b/unitTests/replication/reconnectJitter.test.mjs @@ -1,15 +1,14 @@ /** * Coverage for the jittered reconnect schedule (harper-pro#327). `scheduleReconnect` used to wait * exactly `retryTime`, so every node reacting to the same peer outage re-dialed on the same instant. - * The ceiling schedule is unchanged; the draw is equal jitter (the top half of the window) rather than - * the discipline's default full jitter, because this site's invariant is a dial *rate* — every dial - * allocates native TLS state (harper-pro#339) — so its floor has to scale with the ceiling. + * The ceiling schedule is unchanged; full jitter decorrelates the fleet, while the fixed 500 ms floor + * retains the hard minimum interval from the native TLS-state incident (harper-pro#339). * * `null` for the url makes createWebSocket reject before any socket or listener exists, which is the * cheapest way to drive the real scheduleReconnect path without a peer. */ -import { expect } from 'chai'; +import assert from 'node:assert'; import sinon from 'sinon'; import { NodeReplicationConnection } from '#src/replication/replicationConnection'; @@ -74,8 +73,9 @@ describe('NodeReplicationConnection reconnect jitter (harper-pro#327)', () => { 6 ); - expect(early).to.not.deep.equal(late); - for (let i = 0; i < early.length; i++) expect(early[i]).to.be.below(late[i]); + assert.notDeepEqual(early, late); + assert.equal(early[0], INITIAL_RETRY_TIME); + for (let i = 1; i < early.length; i++) assert.ok(early[i] < late[i]); }); it('keeps the unchanged 500ms → 30s ceiling schedule, drawing inside it', () => { @@ -92,39 +92,39 @@ describe('NodeReplicationConnection reconnect jitter (harper-pro#327)', () => { timers.restore(); } - expect(ceilings).to.deep.equal([1000, 2000, 4000, 8000, 16_000, 30_000, 30_000, 30_000]); - // Every draw sits in the top half of the ceiling it was drawn under, so the minimum interval - // between dials never falls below half of what the jitterless schedule guaranteed. + assert.deepEqual(ceilings, [1000, 2000, 4000, 8000, 16_000, 30_000, 30_000, 30_000]); const ceilingFor = (i) => Math.min(INITIAL_RETRY_TIME * 2 ** i, MAX_RETRY_TIME); timers.values.forEach((delay, i) => { - expect(delay).to.be.at.least(ceilingFor(i) / 2); - expect(delay).to.be.below(ceilingFor(i)); + assert.ok(delay >= INITIAL_RETRY_TIME); + if (ceilingFor(i) === INITIAL_RETRY_TIME) assert.equal(delay, INITIAL_RETRY_TIME); + else assert.ok(delay < ceilingFor(i)); }); }); - it('a zero draw still waits half the ceiling, so the dial rate stays bounded as it escalates', () => { - expect( + it('a zero draw still waits the fixed TLS-safety floor', () => { + assert.deepEqual( scheduleDelays( makeConnection(() => 0), 4 - ) - ).to.deep.equal([250, 500, 1000, 2000]); + ), + [500, 500, 500, 500] + ); }); it('retryTime reads as the initial interval before any failure', () => { - expect(makeConnection(Math.random).retryTime).to.equal(INITIAL_RETRY_TIME); + assert.equal(makeConnection(Math.random).retryTime, INITIAL_RETRY_TIME); }); it('onFrameSent resets the ceiling and the retry counter', () => { const connection = makeConnection(() => 0.5); scheduleDelays(connection, 3); connection.retries = 7; - expect(connection.retryTime).to.equal(4000); + assert.equal(connection.retryTime, 4000); connection.onFrameSent(); - expect(connection.retries).to.equal(0); - expect(connection.retryTime).to.equal(INITIAL_RETRY_TIME); - expect(scheduleDelays(connection, 1)[0], 'drawing under the initial ceiling again').to.equal(375); + assert.equal(connection.retries, 0); + assert.equal(connection.retryTime, INITIAL_RETRY_TIME); + assert.equal(scheduleDelays(connection, 1)[0], 500, 'drawing under the initial ceiling again'); }); }); diff --git a/unitTests/replication/subscribeSetupScheduler.test.mjs b/unitTests/replication/subscribeSetupScheduler.test.mjs index 1ba780604..084abf8cf 100644 --- a/unitTests/replication/subscribeSetupScheduler.test.mjs +++ b/unitTests/replication/subscribeSetupScheduler.test.mjs @@ -9,9 +9,9 @@ * produces one dispatch per event and one live timer per event, so both assertions go red. */ -import { expect } from 'chai'; +import assert from 'node:assert'; import sinon from 'sinon'; -import { createSubscribeSetupScheduler } from '#src/replication/subscriptionManager'; +import { createSubscribeSetupScheduler, dispatchSubscriptionNodes } from '#src/replication/subscriptionManager'; const URL_A = 'wss://peer-a:9933'; const URL_B = 'wss://peer-b:9933'; @@ -56,9 +56,12 @@ describe('subscription-setup scheduler (harper-pro#327)', () => { } // Ceilings double 400 → 30,000; each delay is 200 + 0.5 * (ceiling - 200). - expect(dispatches.map((d) => d.at)).to.deep.equal([300, 800, 1700, 3400, 6700, 13_200, 26_100, 41_200, 56_300]); - expect(maxPending, 'never more than one pending setup for the pair').to.equal(1); - expect(scheduler.pendingCount(), 'exactly one still armed at the end').to.equal(1); + assert.deepEqual( + dispatches.map((d) => d.at), + [300, 800, 1700, 3400, 6700, 13_200, 26_100, 41_200, 56_300] + ); + assert.equal(maxPending, 1, 'never more than one pending setup for the pair'); + assert.equal(scheduler.pendingCount(), 1, 'exactly one still armed at the end'); }); it('keeps every delay inside the floor and the cap', () => { @@ -67,33 +70,36 @@ describe('subscription-setup scheduler (harper-pro#327)', () => { const { scheduler } = makeScheduler(() => draws[i++ % draws.length]); for (let attempt = 0; attempt < 40; attempt++) { const delay = scheduler.schedule(URL_A, 'data', NODES); - expect(delay).to.be.at.least(MIN_DELAY); - expect(delay).to.be.below(MAX_DELAY); + assert.ok(delay >= MIN_DELAY); + assert.ok(delay < MAX_DELAY); clock.tick(delay); } }); it('returns undefined instead of arming a second timer for the same pair', () => { const { scheduler, dispatches } = makeScheduler(() => 0.5); - expect(scheduler.schedule(URL_A, 'data', NODES)).to.equal(300); - expect(scheduler.schedule(URL_A, 'data', NODES), 'deduped').to.equal(undefined); - expect(scheduler.schedule(URL_A, 'data', NODES), 'still deduped').to.equal(undefined); + assert.equal(scheduler.schedule(URL_A, 'data', NODES), 300); + assert.equal(scheduler.schedule(URL_A, 'data', NODES), undefined, 'deduped'); + assert.equal(scheduler.schedule(URL_A, 'data', NODES), undefined, 'still deduped'); clock.tick(60_000); - expect(dispatches.length).to.equal(1); + assert.equal(dispatches.length, 1); }); it('tracks (url, database) pairs independently', () => { const { scheduler, dispatches } = makeScheduler(() => 0.5); - expect(scheduler.schedule(URL_A, 'data', NODES)).to.equal(300); - expect(scheduler.schedule(URL_A, 'other', NODES)).to.equal(300); - expect(scheduler.schedule(URL_B, 'data', NODES)).to.equal(300); - expect(scheduler.pendingCount()).to.equal(3); + assert.equal(scheduler.schedule(URL_A, 'data', NODES), 300); + assert.equal(scheduler.schedule(URL_A, 'other', NODES), 300); + assert.equal(scheduler.schedule(URL_B, 'data', NODES), 300); + assert.equal(scheduler.pendingCount(), 3); clock.tick(300); - expect(dispatches.map(({ url, database, at }) => ({ url, database, at }))).to.deep.equal([ - { url: URL_A, database: 'data', at: 300 }, - { url: URL_A, database: 'other', at: 300 }, - { url: URL_B, database: 'data', at: 300 }, - ]); + assert.deepEqual( + dispatches.map(({ url, database, at }) => ({ url, database, at })), + [ + { url: URL_A, database: 'data', at: 300 }, + { url: URL_A, database: 'other', at: 300 }, + { url: URL_B, database: 'data', at: 300 }, + ] + ); }); it('decorrelates two peers failing on identical timing', () => { @@ -106,8 +112,8 @@ describe('subscription-setup scheduler (harper-pro#327)', () => { bDelays.push(b.schedule(URL_A, 'data', NODES)); clock.tick(MAX_DELAY + MIN_DELAY); } - expect(aDelays).to.not.deep.equal(bDelays); - for (let i = 0; i < aDelays.length; i++) expect(aDelays[i]).to.be.below(bDelays[i]); + assert.notDeepEqual(aDelays, bDelays); + for (let i = 0; i < aDelays.length; i++) assert.ok(aDelays[i] < bDelays[i]); }); // The regression that made the deduped path lose the enriched payload: onDatabase replaces @@ -118,10 +124,10 @@ describe('subscription-setup scheduler (harper-pro#327)', () => { const first = [{ name: 'peer-a', url: URL_A }]; const second = [{ name: 'peer-a', url: URL_A, isLeader: true }]; scheduler.schedule(URL_A, 'data', first); - expect(scheduler.schedule(URL_A, 'data', second)).to.equal(undefined); + assert.equal(scheduler.schedule(URL_A, 'data', second), undefined); clock.tick(300); - expect(dispatches.length).to.equal(1); - expect(dispatches[0].nodes).to.equal(second); + assert.equal(dispatches.length, 1); + assert.equal(dispatches[0].nodes, second); }); // onDatabase's early-return path (an already-subscribed, still-desired entry) never reaches @@ -133,23 +139,23 @@ describe('subscription-setup scheduler (harper-pro#327)', () => { const refreshed = [{ name: 'peer-a', url: URL_A, routeReplicates: { receives: true } }]; scheduler.schedule(URL_A, 'data', armed); scheduler.refreshPending(URL_A, 'data', refreshed); - expect(scheduler.pendingCount(), 'no second timer').to.equal(1); + assert.equal(scheduler.pendingCount(), 1, 'no second timer'); clock.tick(300); - expect(dispatches.length).to.equal(1); - expect(dispatches[0].nodes).to.equal(refreshed); + assert.equal(dispatches.length, 1); + assert.equal(dispatches[0].nodes, refreshed); }); it('refreshPending on a pair with nothing armed does not arm one', () => { const { scheduler, dispatches } = makeScheduler(() => 0.5); scheduler.refreshPending(URL_A, 'data', NODES); - expect(scheduler.pendingCount()).to.equal(0); + assert.equal(scheduler.pendingCount(), 0); clock.tick(60_000); - expect(dispatches).to.deep.equal([]); + assert.deepEqual(dispatches, []); }); it('adds the caller-supplied stagger on top of the backoff', () => { const { scheduler } = makeScheduler(() => 0.5); - expect(scheduler.schedule(URL_A, 'data', NODES, 150)).to.equal(450); + assert.equal(scheduler.schedule(URL_A, 'data', NODES, 150), 450); }); it('noteConnected drops the pending setup and the escalated delay', () => { @@ -157,14 +163,14 @@ describe('subscription-setup scheduler (harper-pro#327)', () => { scheduler.schedule(URL_A, 'data', NODES); clock.tick(300); scheduler.schedule(URL_A, 'data', NODES); // second attempt: escalated to 500 - expect(scheduler.pendingCount()).to.equal(1); + assert.equal(scheduler.pendingCount(), 1); scheduler.noteConnected(URL_A, 'data'); - expect(scheduler.pendingCount(), 'the armed setup is cancelled, not just reset').to.equal(0); + assert.equal(scheduler.pendingCount(), 0, 'the armed setup is cancelled, not just reset'); clock.tick(60_000); - expect(dispatches.length, 'the cancelled setup never fired').to.equal(1); + assert.equal(dispatches.length, 1, 'the cancelled setup never fired'); - expect(scheduler.schedule(URL_A, 'data', NODES), 'back to the first ceiling after success').to.equal(300); + assert.equal(scheduler.schedule(URL_A, 'data', NODES), 300, 'back to the first ceiling after success'); }); it('cancel() and cancelUrl() disarm pending setups', () => { @@ -174,14 +180,15 @@ describe('subscription-setup scheduler (harper-pro#327)', () => { scheduler.schedule(URL_B, 'data', NODES); scheduler.cancel(URL_A, 'data'); - expect(scheduler.pendingCount()).to.equal(2); + assert.equal(scheduler.pendingCount(), 2); scheduler.cancelUrl(URL_A); - expect(scheduler.pendingCount()).to.equal(1); + assert.equal(scheduler.pendingCount(), 1); clock.tick(60_000); - expect(dispatches.map(({ url, database, at }) => ({ url, database, at }))).to.deep.equal([ - { url: URL_B, database: 'data', at: 300 }, - ]); + assert.deepEqual( + dispatches.map(({ url, database, at }) => ({ url, database, at })), + [{ url: URL_B, database: 'data', at: 300 }] + ); }); it('a throwing dispatch is contained instead of taking the process down', () => { @@ -192,9 +199,9 @@ describe('subscription-setup scheduler (harper-pro#327)', () => { random: () => 0.5, }); scheduler.schedule(URL_A, 'data', NODES); - expect(() => clock.tick(300)).to.not.throw(); - expect(scheduler.pendingCount(), 'ownership released so the pair can be re-armed').to.equal(0); - expect(scheduler.schedule(URL_A, 'data', NODES)).to.equal(500); + assert.doesNotThrow(() => clock.tick(300)); + assert.equal(scheduler.pendingCount(), 0, 'ownership released so the pair can be re-armed'); + assert.equal(scheduler.schedule(URL_A, 'data', NODES), 500); }); }); @@ -210,7 +217,54 @@ describe('subscription-setup scheduler timer refs', () => { } finally { globalThis.setTimeout = realSetTimeout; } - expect(armed.hasRef()).to.equal(false); + assert.equal(armed.hasRef(), false); clearTimeout(armed); }); }); + +describe('self-catchup dispatch', () => { + it('attaches the rider on a fresh payload and consumes it only after dispatch', () => { + const nodes = [{ name: 'peer-a', url: URL_A, replicateByDefault: true }]; + let consumed = 0; + let dispatched; + dispatchSubscriptionNodes(nodes, { + startTime: 123, + nodeName: 'self', + now: () => 456, + dispatch: (value) => (dispatched = value), + consume: () => consumed++, + }); + + assert.equal(nodes.length, 1); + assert.deepEqual(dispatched, [ + nodes[0], + { + replicateByDefault: true, + name: 'self', + startTime: 123, + endTime: 456, + replicates: true, + }, + ]); + assert.equal(consumed, 1); + }); + + it('retains the rider when dispatch throws', () => { + const nodes = [{ name: 'peer-a', url: URL_A }]; + let consumed = 0; + assert.throws( + () => + dispatchSubscriptionNodes(nodes, { + startTime: 123, + nodeName: 'self', + dispatch: () => { + throw new Error('postMessage failed'); + }, + consume: () => consumed++, + }), + /postMessage failed/ + ); + assert.equal(nodes.length, 1); + assert.equal(consumed, 0); + }); +}); diff --git a/unitTests/replication/workerSubscriptionAdmission.test.mjs b/unitTests/replication/workerSubscriptionAdmission.test.mjs new file mode 100644 index 000000000..aec11716c --- /dev/null +++ b/unitTests/replication/workerSubscriptionAdmission.test.mjs @@ -0,0 +1,108 @@ +import assert from 'node:assert'; +import { setImmediate as waitForTurn } from 'node:timers/promises'; +import { createWorkerSubscriptionAdmission } from '#src/replication/subscriptionManager'; +import { getSubscriptionConnectionKey } from '#src/replication/replicator'; + +function deferred() { + let resolve; + let reject; + const promise = new Promise((resolvePromise, rejectPromise) => { + resolve = resolvePromise; + reject = rejectPromise; + }); + return { promise, resolve, reject }; +} + +describe('worker subscription admission', () => { + it('derives one connection key for setup and teardown when the nested URL is missing', () => { + const connectingUrl = 'wss://peer:9933'; + assert.equal( + getSubscriptionConnectionKey(connectingUrl, undefined), + getSubscriptionConnectionKey(connectingUrl, connectingUrl) + ); + }); + + it('retains one latest pre-readiness action per target', async () => { + const readiness = deferred(); + const actions = []; + const admission = createWorkerSubscriptionAdmission({ + whenReady: () => readiness.promise, + key: (message) => message.key, + dispatch: (message) => actions.push(message), + onError: assert.fail, + }); + const first = { key: 'peer\0data', type: 'subscribe-to-node', generation: 1 }; + const latest = { key: 'peer\0data', type: 'subscribe-to-node', generation: 60_000 }; + admission.submit(first); + for (let generation = 2; generation < latest.generation; generation++) admission.submit({ ...first, generation }); + admission.submit(latest); + + assert.equal(admission.pendingCount(), 1); + assert.deepEqual(actions, []); + readiness.resolve(); + await waitForTurn(); + assert.deepEqual(actions, [latest]); + assert.equal(admission.pendingCount(), 0); + }); + + it('uses the final pre-readiness subscribe or unsubscribe state', async () => { + const readiness = deferred(); + const actions = []; + const admission = createWorkerSubscriptionAdmission({ + whenReady: () => readiness.promise, + key: (message) => message.key, + dispatch: (message) => actions.push(message.type), + onError: assert.fail, + }); + admission.submit({ key: 'peer\0data', type: 'subscribe-to-node' }); + admission.submit({ key: 'peer\0data', type: 'unsubscribe-from-node' }); + readiness.resolve(); + await waitForTurn(); + assert.deepEqual(actions, ['unsubscribe-from-node']); + }); + + it('runs post-readiness actions inline without deriving a key', async () => { + const readiness = deferred(); + const actions = []; + let keyCalls = 0; + const admission = createWorkerSubscriptionAdmission({ + whenReady: () => readiness.promise, + key: (message) => { + keyCalls++; + return message.key; + }, + dispatch: (message) => actions.push(message.generation), + onError: assert.fail, + }); + admission.submit({ key: 'peer\0data', generation: 1 }); + readiness.resolve(); + await waitForTurn(); + admission.submit({ key: 'peer\0data', generation: 2 }); + + assert.deepEqual(actions, [1, 2]); + assert.equal(keyCalls, 1); + }); + + it('retains bounded state after readiness rejection and retries on the next message', async () => { + const firstReadiness = deferred(); + let attempts = 0; + const actions = []; + const errors = []; + const admission = createWorkerSubscriptionAdmission({ + whenReady: () => (++attempts === 1 ? firstReadiness.promise : Promise.resolve()), + key: (message) => message.key, + dispatch: (message) => actions.push(message.generation), + onError: (_message, error) => errors.push(error.message), + }); + admission.submit({ key: 'peer\0data', generation: 1 }); + firstReadiness.reject(new Error('component load failed')); + await waitForTurn(); + assert.equal(admission.pendingCount(), 1); + admission.submit({ key: 'peer\0data', generation: 2 }); + await waitForTurn(); + + assert.deepEqual(errors, ['component load failed']); + assert.deepEqual(actions, [2]); + assert.equal(admission.pendingCount(), 0); + }); +}); From 890c9acc5206ebbb691de9b8ed4e9818fc12fa50 Mon Sep 17 00:00:00 2001 From: Kris Zyp Date: Wed, 2 Sep 2026 07:41:18 -0600 Subject: [PATCH 05/13] Keep the #446 stagger intact and scope connect-side cancellation MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Draw the wedge/stall re-drive jitter once per reconcile sweep instead of once per entry: a per-entry draw varied consecutive delays by up to ±200ms, letting several dials share a 50ms instant and weakening the concurrency bound RECONNECT_STAGGER_MS exists to hold (#446). Only the worker that currently owns an entry may retire its pending setup on connect, so a stale worker's still-open connection cannot cancel the setup armed for the entry's replacement. End a blob-repair sweep once the schedule is exhausted rather than pacing an unrepairable backlog at 1s/record with the cursor open, and record why the subscription connection-key helper keeps its two teardown callers' argument order. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01HEgBi5zh8QKMbFmeGwFv7w --- replication/DESIGN.md | 26 +++++++++++--------- replication/blobRepair.ts | 23 +++++++++++++++--- replication/replicator.ts | 10 ++++++-- replication/subscriptionManager.ts | 39 +++++++++++++++++------------- 4 files changed, 65 insertions(+), 33 deletions(-) diff --git a/replication/DESIGN.md b/replication/DESIGN.md index 039ffb178..39591eefc 100644 --- a/replication/DESIGN.md +++ b/replication/DESIGN.md @@ -114,15 +114,15 @@ jitterless doubling. The invariant the discipline enforces: **at most one pending attempt per target, on a bounded, capped, decorrelated schedule.** Pacing alone is not enough; the storm surface below needed the dedup too. -| Site | Schedule | Reset signal | -| ------------------------------------------------------------------------------- | -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | -------------------------------------------------------------- | -| `createSubscribeSetupScheduler` (`subscriptionManager.ts`) — subscription setup | floor `NODE_SUBSCRIBE_DELAY`, ceiling `2 × NODE_SUBSCRIBE_DELAY` → 30 s, plus the caller's `RECONNECT_STAGGER_MS` stagger | `connectedToNode` (also cancels the pending setup) | -| `NodeReplicationConnection.scheduleReconnect` | fixed 500 ms floor, ceiling `INITIAL_RETRY_TIME` 500 ms → 30 s, full jitter; the floor preserves the hard minimum from the TLS-state incident while the remaining window decorrelates fleet redials (harper-pro#339) | `onFrameSent` — first frame actually sent, **not** socket open | -| `reconcileWorkers` wedge / receive-stall re-drives | fixed window (decorrelation only; the re-drives are already throttled by the `disconnectedAt` / `receiveStallReconnectAt` re-stamps), one owned `entry.reDriveTimer` per entry | n/a — disarmed on connect, unsubscribe, and delete | -| `runNodeUpdateWatcher` (`knownNodes.ts`) — hdb_nodes watcher restart | full-jitter ceiling 1 s → 30 s | an iteration that survived `NODE_WATCHER_HEALTHY_UPTIME_MS` | -| `shouldCloseSendAuthWatch` reprobe (`replicationConnection.ts`) | 500 ms → 5 s under a 30 s wall-clock budget, then fails closed | n/a (one-shot loop) | -| `fetchJWTKeyWithRetry`, the clone version probe (`cloneNode/`) | 250 ms → 1 s / 1 s → 4 s, attempt count unchanged | n/a | -| `repairBlobs` (`blobRepair.ts`) — per-record | 50 ms → 1 s, only on a record no peer could repair | a repaired record | +| Site | Schedule | Reset signal | +| ------------------------------------------------------------------------------- | -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | -------------------------------------------------------------- | +| `createSubscribeSetupScheduler` (`subscriptionManager.ts`) — subscription setup | floor `NODE_SUBSCRIBE_DELAY`, ceiling `2 × NODE_SUBSCRIBE_DELAY` → 30 s, plus the caller's `RECONNECT_STAGGER_MS` stagger | `connectedToNode` (also cancels the pending setup) | +| `NodeReplicationConnection.scheduleReconnect` | fixed 500 ms floor, ceiling `INITIAL_RETRY_TIME` 500 ms → 30 s, full jitter; the floor preserves the hard minimum from the TLS-state incident while the remaining window decorrelates fleet redials (harper-pro#339) | `onFrameSent` — first frame actually sent, **not** socket open | +| `reconcileWorkers` wedge / receive-stall re-drives | one fixed-window draw per sweep, used as a common base under the existing `RECONNECT_STAGGER_MS` spacing (decorrelation only; the re-drives are already throttled by the `disconnectedAt` / `receiveStallReconnectAt` re-stamps), one owned `entry.reDriveTimer` per entry | n/a — disarmed on connect, unsubscribe, and delete | +| `runNodeUpdateWatcher` (`knownNodes.ts`) — hdb_nodes watcher restart | full-jitter ceiling 1 s → 30 s | an iteration that survived `NODE_WATCHER_HEALTHY_UPTIME_MS` | +| `shouldCloseSendAuthWatch` reprobe (`replicationConnection.ts`) | 500 ms → 5 s under a 30 s wall-clock budget, then fails closed | n/a (one-shot loop) | +| `fetchJWTKeyWithRetry`, the clone version probe (`cloneNode/`) | 250 ms → 1 s / 1 s → 4 s, attempt count unchanged | n/a | +| `repairBlobs` (`blobRepair.ts`) — per-record | 50 ms → 1 s, only on a record no peer could repair; the sweep ends once the schedule is exhausted (100 consecutive) | a repaired record | **The subscription-setup scheduler is the one with dedup.** `onDatabase` used to turn every qualifying node update straight into a retained (not unref'd) 200 ms `setTimeout` plus a `subscribe-to-node` @@ -139,8 +139,12 @@ A setup is cancelled on connect, on unsubscribe, on node deletion, and on a same-name URL migration, all of which became reachable once a pending timer could live 30 s instead of 200 ms. The wedge/stall recovery kicks are owned the same way — one `entry.reDriveTimer` per entry, so a staggered sweep that outruns the -reconcile window that started it replaces its predecessor instead of stacking another wave. The warn -moved inside the "actually armed" branch: it now describes an attempt, not an event. +reconcile window that started it replaces its predecessor instead of stacking another wave, and only the +worker that currently owns an entry may retire its pending setup on connect. Their jitter is drawn once +per sweep rather than per entry: a per-entry draw would vary consecutive delays by up to ±200 ms and let +several dials share a 50 ms instant, which is the concurrency the `RECONNECT_STAGGER_MS` spacing exists to +bound (#446). The warn moved inside the "actually armed" branch: it now describes an attempt, not an +event. The worker boundary has one additional admission point for its asynchronous startup window. Before components are ready, one insertion-ordered map retains only the latest subscribe/unsubscribe message diff --git a/replication/blobRepair.ts b/replication/blobRepair.ts index 08d6b9595..eb6986fa1 100644 --- a/replication/blobRepair.ts +++ b/replication/blobRepair.ts @@ -11,9 +11,13 @@ const logger = harperLogger.forComponent('blob-repair').conditional as Logger; // Paces a sweep whose peers cannot serve anything: without it the per-record loop spins as fast as the // incomplete-blob cursor yields. Capped low (not at the 30s replication cap) because the delay is paid -// per unrepairable record while the cursor stays open, so a big backlog must still finish in hours. +// per unrepairable record while the cursor stays open. const REPAIR_RETRY_INITIAL_MS = 50; const REPAIR_RETRY_MAX_MS = 1000; +// Consecutive unrepairable records that end the sweep. A repair resets the count, so this only trips when +// no peer can serve anything — the cluster-wide-loss case, where pacing alone would hold the +// incomplete-blob cursor open for ~1s per record across the whole backlog and report nothing until the end. +const REPAIR_MAX_CONSECUTIVE_FAILURES = 100; // One sweep per database per thread. `repair_blob_data` is fire-and-forget, so repeated calls landing on // the same thread used to stack concurrent sweeps over the same records, wasting peer fetches and // defeating the pacing above. Calls routed to different threads are still independent. @@ -38,7 +42,11 @@ export async function repairBlobs( let repaired = 0; let failed = 0; let noConnection = 0; - const backoff = createBackoff({ initialMs: REPAIR_RETRY_INITIAL_MS, maxMs: REPAIR_RETRY_MAX_MS }); + const backoff = createBackoff({ + initialMs: REPAIR_RETRY_INITIAL_MS, + maxMs: REPAIR_RETRY_MAX_MS, + maxAttempts: REPAIR_MAX_CONSECUTIVE_FAILURES, + }); for await (const { tableName, table, recordId } of findIncompleteBlobRefs(database, dbName)) { checked++; @@ -91,7 +99,16 @@ export async function repairBlobs( failed++; logger.warn?.('Could not repair blob for record', recordId, 'in', tableName, '— no peer had a complete copy'); const delay = backoff.nextDelay(); - if (delay !== undefined) await pause(delay); + if (delay === undefined) { + logger.warn?.( + 'Stopping blob repair for', + dbName, + `after ${REPAIR_MAX_CONSECUTIVE_FAILURES} consecutive records no peer could repair`, + { checked, repaired, failed, noConnection } + ); + break; + } + await pause(delay); } } diff --git a/replication/replicator.ts b/replication/replicator.ts index 5965141d0..d2ad9d23f 100644 --- a/replication/replicator.ts +++ b/replication/replicator.ts @@ -571,8 +571,14 @@ function getSubscriptionConnection( } } -export function getSubscriptionConnectionKey(connectingUrl: string, subscriptionUrl?: string): string { - return connectingUrl + '-' + (subscriptionUrl ?? connectingUrl); +// The `connections` key, so subscribe, unsubscribe, force-reconnect and the worker's pre-readiness +// admission derive byte-identical identity including the missing-nested-URL fallback. The teardown sites +// pass the pair in the opposite order to the subscribe path; those two URLs are the same for every +// ordinary subscription and differ only under failover (connectToNextWorker subscribes node B over peer +// A's URL), where the teardown lookup has always missed. Preserved rather than unified: reordering is a +// failover behavior change, not a retry-pacing one. +export function getSubscriptionConnectionKey(url: string, peerUrl?: string): string { + return url + '-' + (peerUrl ?? url); } const nodeNameToRetrievalConnections = new Map>(); /** diff --git a/replication/subscriptionManager.ts b/replication/subscriptionManager.ts index 8d97ccffe..9b89c8975 100644 --- a/replication/subscriptionManager.ts +++ b/replication/subscriptionManager.ts @@ -1207,7 +1207,7 @@ export async function startOnMainThread(options) { } }; - connectedToNode = function (connection) { + connectedToNode = function (connection, reportingWorker?) { // Basically undo what we did in disconnectedFromNode and also update the latency const dbReplicationWorkers = connectionReplicationMap.get(connection.url); const mainWorkerEntry = dbReplicationWorkers?.get(connection.database); @@ -1221,10 +1221,16 @@ export async function startOnMainThread(options) { } mainWorkerEntry.connected = true; // Real progress for this pair: drop the escalated setup backoff, any setup still pending, and any - // recovery kick armed for a connection that has since come back. - subscribeSetupScheduler.noteConnected(connection.url, connection.database); - clearTimeout(mainWorkerEntry.reDriveTimer); - mainWorkerEntry.reDriveTimer = undefined; + // recovery kick armed for a connection that has since come back. Only the entry's CURRENT owner may + // retire that work: the stale-worker path above deletes and recreates the entry on a new worker while + // the old worker's hung-but-open connection can still report 'open' for the same (url, database), and + // retiring on that report would leave the new worker's setup cancelled and never re-armed. An + // internal caller (the truth-driven up-correction) passes no worker and is always trusted. + if (!reportingWorker || reportingWorker === mainWorkerEntry.worker) { + subscribeSetupScheduler.noteConnected(connection.url, connection.database); + clearTimeout(mainWorkerEntry.reDriveTimer); + mainWorkerEntry.reDriveTimer = undefined; + } mainWorkerEntry.disconnectedAt = undefined; mainWorkerEntry.latency = connection.latency; const restoredNode = mainWorkerEntry.nodes[0]; @@ -1386,12 +1392,15 @@ export async function startOnMainThread(options) { return timer; }; // Decorrelation only, no escalation: these re-drives are already throttled by the disconnectedAt / - // receiveStallReconnectAt re-stamps, so the ceiling is fixed and every draw lands in the same window. - const reDriveBackoff = createBackoff({ - initialMs: NODE_SUBSCRIBE_INITIAL_CEILING_MS, - maxMs: NODE_SUBSCRIBE_INITIAL_CEILING_MS, - minMs: NODE_SUBSCRIBE_DELAY, - }); + // receiveStallReconnectAt re-stamps, so the ceiling is fixed. ONE draw for the whole sweep, used as a + // common base offset: drawing per entry would make consecutive delays differ by up to +/-200ms and let + // ~4 dials share any 50ms instant, which is precisely the concurrency #446's stagger bounds. + const reDriveBaseDelay = + createBackoff({ + initialMs: NODE_SUBSCRIBE_INITIAL_CEILING_MS, + maxMs: NODE_SUBSCRIBE_INITIAL_CEILING_MS, + minMs: NODE_SUBSCRIBE_DELAY, + }).nextDelay() ?? NODE_SUBSCRIBE_DELAY; if (staleNodeUrls.size > 0) logger.warn( 'Reconciling replication subscriptions for nodes pointing at exited workers:', @@ -1472,9 +1481,7 @@ export async function startOnMainThread(options) { // Stagger reconnects (RECONNECT_STAGGER_MS apart) so opening N TLS connections // simultaneously does not spike memory when there are many databases; jitter the base so // every node in a fleet reacting to the same peer outage doesn't fire on the same tick. - const backoffDelay = reDriveBackoff.nextDelay(); - if (backoffDelay === undefined) continue; - const delay = backoffDelay + reconnectCount * RECONNECT_STAGGER_MS; + const delay = reDriveBaseDelay + reconnectCount * RECONNECT_STAGGER_MS; reconnectCount++; entry.reDriveTimer = armReDrive(entry, delay, url, databaseName, () => { // The stamp is our claim on this entry: connectedToNode clears disconnectedAt and a later @@ -1521,9 +1528,7 @@ export async function startOnMainThread(options) { database: databaseName, nodes, }; - const backoffDelay = reDriveBackoff.nextDelay(); - if (backoffDelay === undefined) continue; - const delay = backoffDelay + reconnectCount * RECONNECT_STAGGER_MS; + const delay = reDriveBaseDelay + reconnectCount * RECONNECT_STAGGER_MS; reconnectCount++; entry.reDriveTimer = armReDrive(entry, delay, url, databaseName, () => { // Same staleness claim as the wedge path: a newer reconcile re-stamping From 4c0b1ec1fa56867ffac69e070c7fbf3ac222d8fe Mon Sep 17 00:00:00 2001 From: Kris Zyp Date: Wed, 2 Sep 2026 08:32:45 -0600 Subject: [PATCH 06/13] Self-heal a rejected worker-readiness on the shared schedule MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A component-readiness rejection retained the pre-readiness subscribe/unsubscribe actions but never re-attempted them, so nothing applied until another parentPort message arrived or the wedge reconcile noticed ~30s later — the empty-subscription window this gate exists to close. Re-attempt on the same capped, jittered, unref'd schedule the rest of the discipline uses, resetting once readiness succeeds. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01HEgBi5zh8QKMbFmeGwFv7w --- replication/subscriptionManager.ts | 17 ++++++++ .../workerSubscriptionAdmission.test.mjs | 42 +++++++++++++++++++ 2 files changed, 59 insertions(+) diff --git a/replication/subscriptionManager.ts b/replication/subscriptionManager.ts index 9b89c8975..51d46b095 100644 --- a/replication/subscriptionManager.ts +++ b/replication/subscriptionManager.ts @@ -1638,9 +1638,13 @@ export function createWorkerSubscriptionAdmission(deps: { key: (message: any) => string; dispatch: (message: any) => void; onError: (message: any | undefined, error: unknown) => void; + retry?: (delayMs: number, attempt: () => void) => void; + random?: () => number; }) { + const retry = deps.retry ?? ((delayMs: number, attempt: () => void) => void setTimeout(attempt, delayMs).unref()); let ready = false; let flushScheduled = false; + let retryBackoff: Backoff | undefined; const pending = new Map(); function dispatch(message: any) { @@ -1657,6 +1661,7 @@ export function createWorkerSubscriptionAdmission(deps: { .whenReady() .then(() => { ready = true; + retryBackoff?.reset(); for (const [key, message] of pending) { pending.delete(key); dispatch(message); @@ -1665,6 +1670,18 @@ export function createWorkerSubscriptionAdmission(deps: { .catch((error) => deps.onError(undefined, error)) .finally(() => { flushScheduled = false; + // A readiness failure would otherwise strand the retained actions until another message + // arrives or the wedge reconcile notices ~30s later — the empty-subscription window this + // gate exists to close (harper-pro#289 / #233). Re-attempt on the shared schedule instead. + if (!ready && pending.size > 0) { + retryBackoff ??= createBackoff({ + initialMs: NODE_SUBSCRIBE_DELAY, + maxMs: NODE_SUBSCRIBE_MAX_DELAY_MS, + random: deps.random, + }); + const delay = retryBackoff.nextDelay(); + if (delay !== undefined) retry(delay, scheduleFlush); + } }); } diff --git a/unitTests/replication/workerSubscriptionAdmission.test.mjs b/unitTests/replication/workerSubscriptionAdmission.test.mjs index aec11716c..f4262321e 100644 --- a/unitTests/replication/workerSubscriptionAdmission.test.mjs +++ b/unitTests/replication/workerSubscriptionAdmission.test.mjs @@ -83,6 +83,48 @@ describe('worker subscription admission', () => { assert.equal(keyCalls, 1); }); + // A rejection used to leave the retained action waiting for another inbound message or the ~30s wedge + // reconcile — the empty-subscription window the gate exists to close. It now re-attempts itself. + it('re-attempts a rejected readiness on an escalating schedule without a new message', async () => { + let attempts = 0; + const actions = []; + const errors = []; + const retries = []; + const admission = createWorkerSubscriptionAdmission({ + whenReady: () => (++attempts < 3 ? Promise.reject(new Error(`load failed ${attempts}`)) : Promise.resolve()), + key: (message) => message.key, + dispatch: (message) => actions.push(message.generation), + onError: (_message, error) => errors.push(error.message), + retry: (delayMs, attempt) => { + retries.push(delayMs); + attempt(); + }, + random: () => 0.999999, + }); + admission.submit({ key: 'peer\0data', generation: 1 }); + await waitForTurn(); + await waitForTurn(); + + assert.deepEqual(errors, ['load failed 1', 'load failed 2']); + assert.deepEqual(retries, [199, 399], 'the re-attempt delay escalates under the shared schedule'); + assert.deepEqual(actions, [1], 'the retained action is applied once readiness succeeds'); + assert.equal(admission.pendingCount(), 0); + }); + + it('stops re-attempting once nothing is pending', async () => { + const retries = []; + const admission = createWorkerSubscriptionAdmission({ + whenReady: () => Promise.reject(new Error('load failed')), + key: (message) => message.key, + dispatch: () => assert.fail('nothing should dispatch'), + onError: () => {}, + retry: (delayMs) => retries.push(delayMs), + }); + admission.submit({ key: 'peer\0data' }); + await waitForTurn(); + assert.equal(retries.length, 1); + }); + it('retains bounded state after readiness rejection and retries on the next message', async () => { const firstReadiness = deferred(); let attempts = 0; From 9a50aefa3606c99e3e1fdba364fada4908978759 Mon Sep 17 00:00:00 2001 From: Kris Zyp Date: Wed, 2 Sep 2026 09:11:08 -0600 Subject: [PATCH 07/13] Address the pre-push review: deadline, sweep completeness, and timer ownership MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - shouldCloseSendAuthWatch: the row read is synchronous and can itself carry the clock past the advertised grace period, so re-check the deadline after it and fail closed. - repairBlobs: bound how long a failure run may spend *pausing* instead of ending the sweep on a consecutive-failure count — a cluster-wide-lost prefix must not make the repairable records behind it permanently unreachable through the operation. Drop the per-thread single-flight guard with it: `getRecord()` has no timeout, so one wedged peer would hold the flag for the life of the thread and remove the operator's lever. - runNodeUpdateWatcher: stamp the health clock once the subscription is live, so a subscribe() that blocks past the threshold and then throws no longer reads as uptime. - Worker admission: own the readiness re-attempt so a pre-readiness burst against a rejecting import cannot multiply timers, imports and warn lines 1:1 with messages. - Connect ownership: tag the report with the sending thread id rather than relying on core's undocumented onMessageByType listener arity, behind a tested pure helper. - Disarm an entry's recovery timer when its worker exits or the entry is replaced, and adopt the shared schedule for the copy-cursor flush retry. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01HEgBi5zh8QKMbFmeGwFv7w --- replication/blobRepair.ts | 43 +++++++------- replication/knownNodes.ts | 7 ++- replication/replicationConnection.ts | 30 +++++++--- replication/replicator.ts | 11 ++-- replication/subscriptionManager.ts | 56 +++++++++++++------ .../clearWorkerFromEntries.test.mjs | 27 ++++++++- .../replication/nodeUpdateWatcher.test.mjs | 36 +++++++++++- .../shouldCloseSendAuthWatch.test.mjs | 26 +++++++++ .../workerSubscriptionAdmission.test.mjs | 38 ++++++++++++- 9 files changed, 214 insertions(+), 60 deletions(-) diff --git a/replication/blobRepair.ts b/replication/blobRepair.ts index eb6986fa1..300cba97f 100644 --- a/replication/blobRepair.ts +++ b/replication/blobRepair.ts @@ -14,14 +14,10 @@ const logger = harperLogger.forComponent('blob-repair').conditional as Logger; // per unrepairable record while the cursor stays open. const REPAIR_RETRY_INITIAL_MS = 50; const REPAIR_RETRY_MAX_MS = 1000; -// Consecutive unrepairable records that end the sweep. A repair resets the count, so this only trips when -// no peer can serve anything — the cluster-wide-loss case, where pacing alone would hold the -// incomplete-blob cursor open for ~1s per record across the whole backlog and report nothing until the end. -const REPAIR_MAX_CONSECUTIVE_FAILURES = 100; -// One sweep per database per thread. `repair_blob_data` is fire-and-forget, so repeated calls landing on -// the same thread used to stack concurrent sweeps over the same records, wasting peer fetches and -// defeating the pacing above. Calls routed to different threads are still independent. -const sweepsInFlight = new Set(); +// Wall-clock ceiling on how long one unbroken failure run may spend *pausing*. Once spent the sweep keeps +// scanning at full speed: pacing exists to stop a hot loop, and inferring the rest of the cursor from an +// unrepairable prefix would silently skip records a later peer can still serve. A repair restarts it. +const REPAIR_PACING_BUDGET_MS = 60_000; export async function allBlobsAreComplete( blobs: any[], @@ -32,7 +28,7 @@ export async function allBlobsAreComplete( export async function repairBlobs( dbName: string, - deps: { sleep?: (ms: number) => Promise } = {} + deps: { sleep?: (ms: number) => Promise; now?: () => number } = {} ): Promise<{ checked: number; repaired: number; failed: number; noConnection: number }> { const database = (databases as any)[dbName]; if (!database) throw new Error(`Unknown database '${dbName}'`); @@ -45,8 +41,10 @@ export async function repairBlobs( const backoff = createBackoff({ initialMs: REPAIR_RETRY_INITIAL_MS, maxMs: REPAIR_RETRY_MAX_MS, - maxAttempts: REPAIR_MAX_CONSECUTIVE_FAILURES, + budgetMs: REPAIR_PACING_BUDGET_MS, + now: deps.now, }); + let pacingSpent = false; for await (const { tableName, table, recordId } of findIncompleteBlobRefs(database, dbName)) { checked++; @@ -95,20 +93,21 @@ export async function repairBlobs( if (peerRepaired) { backoff.reset(); + pacingSpent = false; } else { failed++; logger.warn?.('Could not repair blob for record', recordId, 'in', tableName, '— no peer had a complete copy'); const delay = backoff.nextDelay(); if (delay === undefined) { - logger.warn?.( - 'Stopping blob repair for', - dbName, - `after ${REPAIR_MAX_CONSECUTIVE_FAILURES} consecutive records no peer could repair`, - { checked, repaired, failed, noConnection } - ); - break; - } - await pause(delay); + if (!pacingSpent) { + pacingSpent = true; + logger.warn?.( + 'Blob repair pacing budget spent for', + dbName, + `after ${REPAIR_PACING_BUDGET_MS}ms of unrepairable records; continuing the sweep unpaced` + ); + } + } else await pause(delay); } } @@ -122,12 +121,8 @@ server.registerOperation?.({ if (!request.database) throw new Error('Must provide "database" name for blob repair'); const dbName = request.database; if (!(databases as any)[dbName]) throw new Error(`Unknown database '${dbName}'`); - if (sweepsInFlight.has(dbName)) return { message: `Blob repair already running for '${dbName}'` }; - sweepsInFlight.add(dbName); // fire and forget — repair can take hours on large datasets - repairBlobs(dbName) - .catch((err) => logger.error?.('Blob repair failed', dbName, err)) - .finally(() => sweepsInFlight.delete(dbName)); + repairBlobs(dbName).catch((err) => logger.error?.('Blob repair failed', dbName, err)); return { message: 'Blob repair started, check logs for progress' }; }, httpMethod: 'POST', diff --git a/replication/knownNodes.ts b/replication/knownNodes.ts index a57f6c684..7692726d0 100644 --- a/replication/knownNodes.ts +++ b/replication/knownNodes.ts @@ -192,10 +192,13 @@ export async function runNodeUpdateWatcher( }); const isCurrent = () => generation === (watcherGenerations.get(key) ?? 0); while (restarts < maxRestarts && isCurrent()) { - const startedAt = now(); + // Stamped only once the subscription is live: time spent acquiring (or failing) one is not uptime, + // so a subscribe() that blocks past the threshold and then throws must not read as a healthy run. + let liveSince: number | undefined; try { const events = await subscribe(); if (!isCurrent()) break; // superseded while awaiting subscribe + liveSince = now(); const iterator = events[Symbol.asyncIterator](); watcherIterators.set(key, iterator); try { @@ -223,7 +226,7 @@ export async function runNodeUpdateWatcher( } // A watcher that stayed up long enough to have done real work restarts quickly; anything shorter // is a failure cycle and keeps escalating toward the cap. - if (now() - startedAt >= healthyUptimeMs) backoff.reset(); + if (liveSince !== undefined && now() - liveSince >= healthyUptimeMs) backoff.reset(); restarts++; if (restarts >= maxRestarts || !isCurrent()) return; const delay = backoff.nextDelay(); diff --git a/replication/replicationConnection.ts b/replication/replicationConnection.ts index dc21adeb6..e81062564 100644 --- a/replication/replicationConnection.ts +++ b/replication/replicationConnection.ts @@ -540,7 +540,7 @@ const SEND_AUTH_REPROBE_MAX_MS = 5_000; // The grace period is a wall-clock deadline, not a sum of sleeps: a resolver hang or event-loop stall // must not extend how long a revocation carried by an undecodable write can go unenforced. const SEND_AUTH_REPROBE_BUDGET_MS = 30_000; -// Defense in depth for the deadline, and the whole bound when the clock does not advance (tests). +// The bound that still holds when the clock does not advance. const SEND_AUTH_REPROBE_ATTEMPTS = 120; /** @@ -589,8 +589,7 @@ export async function shouldCloseSendAuthWatch( const sleep = deps.sleep ?? ((ms: number) => new Promise((r) => setTimeout(r, ms).unref())); let node = isGenuineNodeDeletion(event.type) ? undefined : resolve(name); - // Built only once a row actually comes back undecodable, so the ordinary decodable event — every - // authorization change on a healthy cluster — allocates nothing and never reads the clock. + // Built only once a row comes back undecodable: the ordinary decodable event never reads the clock. let backoff; while (node === SEND_AUTH_UNCHANGED && !deps.isClosed()) { backoff ??= createBackoff({ @@ -609,6 +608,12 @@ export async function shouldCloseSendAuthWatch( // pushed us past it must not authorize. Fail closed on the elapsed time, not on the row. if (backoff.exhausted) break; node = resolve(name); + // resolveNodeForSendAuth reads the store synchronously, so the read itself can carry the clock + // past the deadline. Same rule applies to what it returned. + if (backoff.exhausted) { + node = SEND_AUTH_UNCHANGED; + break; + } } if (node === SEND_AUTH_UNCHANGED) { if (deps.isClosed()) return false; @@ -2466,6 +2471,8 @@ export async function createWebSocket( const INITIAL_RETRY_TIME = 500; const MAX_RETRY_TIME = 30_000; +const COPY_FLUSH_RETRY_INITIAL_MS = 250; +const COPY_FLUSH_RETRY_MAX_MS = 30_000; /** * This represents a persistent connection to a node for replication, which handles * sockets that may be disconnected and reconnected @@ -2473,8 +2480,8 @@ const MAX_RETRY_TIME = 30_000; export class NodeReplicationConnection extends EventEmitter { socket: WebSocket; startTime: number; - // Created on the first failure so a healthy connection allocates nothing extra. - retryBackoff: Backoff; + retryBackoff: Backoff; // created on the first failure + random = Math.random; // injectable so the jittered reconnect schedule is deterministically testable retries = 0; isConnected = true; // we start out assuming we will be connected @@ -2916,7 +2923,7 @@ export function replicateOverWS(ws: WebSocket, options: any, authorization: any) // at ~100% CPU and flooding logs on a persistent failure. Escalating backoff + a scheduled retry paces it: // transient errors self-heal, a persistent one idles until the operator (or a higher-level watchdog) acts. let copyFlushBackoffUntil = 0; - let copyFlushRetryMs = 0; + let copyFlushBackoff: Backoff | undefined; let copyFlushRetryTimer; const COPY_CURSOR_FLUSH_BYTES = env.get('replication_copyCursorFlushBytes') ?? 64 * 1024 * 1024; const COPY_CURSOR_FLUSH_INTERVAL_MS = Math.max(env.get('replication_copyCursorFlushIntervalMs') ?? 5000, 1); @@ -3104,7 +3111,14 @@ export function replicateOverWS(ws: WebSocket, options: any, authorization: any) if (passAtPersist === copyWatermark.currentPass) pendingCopyCursor ??= cursor; // hold the staged cursor // Escalating backoff (250ms → 30s cap) instead of an immediate re-flush, so a persistent flush // failure idles rather than busy-looping; a scheduled retry drives progress without another event. - copyFlushRetryMs = Math.min(copyFlushRetryMs ? copyFlushRetryMs * 2 : 250, 30000); + // Jittered on the shared schedule so a cluster-wide I/O episode does not re-flush in lockstep, + // keeping 250ms as the hard floor the backoff guard below depends on. + copyFlushBackoff ??= createBackoff({ + initialMs: COPY_FLUSH_RETRY_INITIAL_MS, + maxMs: COPY_FLUSH_RETRY_MAX_MS, + minMs: COPY_FLUSH_RETRY_INITIAL_MS, + }); + const copyFlushRetryMs = copyFlushBackoff.nextDelay() ?? COPY_FLUSH_RETRY_INITIAL_MS; copyFlushBackoffUntil = performance.now() + copyFlushRetryMs; clearTimeout(copyFlushRetryTimer); copyFlushRetryTimer = setTimeout(() => { @@ -3163,7 +3177,7 @@ export function replicateOverWS(ws: WebSocket, options: any, authorization: any) if (copyFromNodeId !== undefined) getDatabaseStores().dbisDB?.put([Symbol.for('copyCursor'), copyFromNodeId], cursorAtFlush); copyFlushBackoffUntil = 0; - copyFlushRetryMs = 0; // flush succeeded; reset backoff + copyFlushBackoff?.reset(); // flush succeeded if (copyCompleteReceived) noteCopyFinalizeProgress(); logger.trace?.(connectionId, 'copy cursor advanced (rows flushed durable)'); // A persist under a drained barrier is the connection's LAST possible progress: every diff --git a/replication/replicator.ts b/replication/replicator.ts index d2ad9d23f..992cdefff 100644 --- a/replication/replicator.ts +++ b/replication/replicator.ts @@ -571,12 +571,11 @@ function getSubscriptionConnection( } } -// The `connections` key, so subscribe, unsubscribe, force-reconnect and the worker's pre-readiness -// admission derive byte-identical identity including the missing-nested-URL fallback. The teardown sites -// pass the pair in the opposite order to the subscribe path; those two URLs are the same for every -// ordinary subscription and differ only under failover (connectToNextWorker subscribes node B over peer -// A's URL), where the teardown lookup has always missed. Preserved rather than unified: reordering is a -// failover behavior change, not a retry-pacing one. +// The `connections` key, shared by subscribe, unsubscribe, force-reconnect and the worker's pre-readiness +// admission so all four derive identical identity including the missing-nested-URL fallback. The teardown +// sites pass the pair in the opposite order to the subscribe path; the two URLs are the same string for +// every ordinary subscription, and differ only under failover (connectToNextWorker subscribes node B over +// peer A's URL), where the teardown lookup has always missed. export function getSubscriptionConnectionKey(url: string, peerUrl?: string): string { return url + '-' + (peerUrl ?? url); } diff --git a/replication/subscriptionManager.ts b/replication/subscriptionManager.ts index 51d46b095..d1901622c 100644 --- a/replication/subscriptionManager.ts +++ b/replication/subscriptionManager.ts @@ -16,7 +16,7 @@ import { getSubscriptionConnectionKey, } from './replicator.ts'; import { getThisNodeName, getThisNodeUrl } from '../core/server/nodeName.ts'; -import { parentPort } from 'worker_threads'; +import { parentPort, threadId } from 'worker_threads'; import { subscribeToNodeUpdates, getHDBNodeTable, @@ -373,12 +373,28 @@ function reportIdentityMismatchOnce(nodes: Array<{ name?: string; url?: string } // Clear a dead worker from every subscription entry it owned, so findStaleNodeUrls re-binds those // entries on a live worker. Pure helper (like findStaleNodeUrls) so its behavior is unit-testable without // real worker threads. Returns whether the worker owned any entries. See harper-pro#357. +/** + * Whether a 'connected-to-node' report may retire the entry's pending setup and recovery. The stale-worker + * path in `onDatabase` recreates an entry on a new worker while the old worker's hung-but-open connection + * can still report 'open' for the same (url, database); retiring on that report would cancel the + * replacement's setup and leave it unsubscribed with `connected: true`, which the wedge net then skips. + * An untagged report (the main thread's own truth-driven up-correction, or an inline subscribe with no + * worker) is trusted. + */ +export function connectReportOwnsEntry(entry: { worker?: any }, reportingThreadId?: number): boolean { + return reportingThreadId === undefined || reportingThreadId === entry?.worker?.threadId; +} + export function clearWorkerFromEntries(connectionMap: Map, worker: any): boolean { let owned = false; for (const dbReplicationWorkers of connectionMap.values()) { for (const entry of dbReplicationWorkers.values()) { if (entry.worker === worker) { entry.worker = undefined; + // The armed recovery posts to this worker and closes over it; disarm rather than leave the + // exited Worker (and its request) retained until the timer's fire-time guard no-ops. + clearTimeout(entry.reDriveTimer); + entry.reDriveTimer = undefined; owned = true; } // Also drop the dead worker from per-node refs (entry.nodes[].worker); connectToNextWorker sets @@ -978,14 +994,16 @@ export async function startOnMainThread(options) { // entry stuck and the subscription never recovers. if (existingEntry && httpWorkers.length > 0 && !httpWorkers.includes(existingEntry.worker as any)) { logger.warn(`Subscription for ${databaseName} on node ${node.name} has no live worker; reassigning`); + // The armed recovery closes over the worker being replaced; its fire-time guard would no-op, + // but until then it retains an exited Worker and its request per entry. + clearTimeout(existingEntry.reDriveTimer); dbReplicationWorkers.delete(databaseName); existingEntry = undefined; } if (existingEntry) { worker = existingEntry.worker; - // isLeader is only decided on the scheduling path below, so a payload built here would drop - // it — and this array becomes `entry.nodes`, which the wedge re-drive posts from. Same - // OR-accumulation the scheduling path uses. + // This array becomes `entry.nodes`, which the wedge re-drive posts from, and isLeader is only + // decided on the scheduling path below — carry it forward or the re-drive loses it. nodes[0].isLeader = nodes[0].isLeader || existingEntry.nodes?.[0]?.isLeader; existingEntry.nodes = nodes; // Normally an existing subscribed entry is left alone. Only the wedge reconcile passes @@ -1057,8 +1075,6 @@ export async function startOnMainThread(options) { // don't dial N catchup connections simultaneously. See #446. const staggerMs = subscribeStagger ? subscribeStagger.count++ * RECONNECT_STAGGER_MS : 0; const subscribeDelay = subscribeSetupScheduler.schedule(getNodeURL(node), databaseName, nodes, staggerMs); - // undefined means a setup for this (url, database) is already pending: it has just taken - // this call's payload, so there is nothing more to do — and nothing to log. // The warn belongs to an armed setup, not to an event, or a re-drive storm reproduces the // 165k-line logs of harper-pro#327 even though the work itself is now bounded. if (subscribeDelay !== undefined) { @@ -1207,7 +1223,7 @@ export async function startOnMainThread(options) { } }; - connectedToNode = function (connection, reportingWorker?) { + connectedToNode = function (connection) { // Basically undo what we did in disconnectedFromNode and also update the latency const dbReplicationWorkers = connectionReplicationMap.get(connection.url); const mainWorkerEntry = dbReplicationWorkers?.get(connection.database); @@ -1221,12 +1237,8 @@ export async function startOnMainThread(options) { } mainWorkerEntry.connected = true; // Real progress for this pair: drop the escalated setup backoff, any setup still pending, and any - // recovery kick armed for a connection that has since come back. Only the entry's CURRENT owner may - // retire that work: the stale-worker path above deletes and recreates the entry on a new worker while - // the old worker's hung-but-open connection can still report 'open' for the same (url, database), and - // retiring on that report would leave the new worker's setup cancelled and never re-armed. An - // internal caller (the truth-driven up-correction) passes no worker and is always trusted. - if (!reportingWorker || reportingWorker === mainWorkerEntry.worker) { + // recovery kick armed for a connection that has since come back. + if (connectReportOwnsEntry(mainWorkerEntry, connection.reportingThreadId)) { subscribeSetupScheduler.noteConnected(connection.url, connection.database); clearTimeout(mainWorkerEntry.reDriveTimer); mainWorkerEntry.reDriveTimer = undefined; @@ -1644,6 +1656,7 @@ export function createWorkerSubscriptionAdmission(deps: { const retry = deps.retry ?? ((delayMs: number, attempt: () => void) => void setTimeout(attempt, delayMs).unref()); let ready = false; let flushScheduled = false; + let retryArmed = false; let retryBackoff: Backoff | undefined; const pending = new Map(); @@ -1655,7 +1668,10 @@ export function createWorkerSubscriptionAdmission(deps: { } } function scheduleFlush() { - if (flushScheduled) return; + // One readiness attempt and one armed re-attempt at a time: without the second guard, every message + // arriving during a boot-time load failure starts its own attempt and arms its own timer, and the + // retained continuations grow with input again — the shape this gate exists to bound. + if (flushScheduled || retryArmed) return; flushScheduled = true; deps .whenReady() @@ -1680,7 +1696,13 @@ export function createWorkerSubscriptionAdmission(deps: { random: deps.random, }); const delay = retryBackoff.nextDelay(); - if (delay !== undefined) retry(delay, scheduleFlush); + if (delay !== undefined) { + retryArmed = true; + retry(delay, () => { + retryArmed = false; + scheduleFlush(); + }); + } } }); } @@ -1723,7 +1745,9 @@ if (parentPort) { parentPort.postMessage({ type: 'disconnected-from-node', ...connection }); }; connectedToNode = (connection) => { - parentPort.postMessage({ type: 'connected-to-node', ...connection }); + // Tagged so the main thread can tell this worker's report from a superseded worker's; see + // connectReportOwnsEntry. + parentPort.postMessage({ type: 'connected-to-node', ...connection, reportingThreadId: threadId }); }; onMessageByType('subscribe-to-node', (message) => { // Defer until this worker has finished loading components (databases/tables + persisted hdb_nodes diff --git a/unitTests/replication/clearWorkerFromEntries.test.mjs b/unitTests/replication/clearWorkerFromEntries.test.mjs index 95b27091a..642c4e362 100644 --- a/unitTests/replication/clearWorkerFromEntries.test.mjs +++ b/unitTests/replication/clearWorkerFromEntries.test.mjs @@ -8,7 +8,7 @@ */ import { expect } from 'chai'; -import { clearWorkerFromEntries } from '#src/replication/subscriptionManager'; +import { clearWorkerFromEntries, connectReportOwnsEntry } from '#src/replication/subscriptionManager'; // Build a connectionReplicationMap: Map>. node.worker mirrors connectToNextWorker, // which assigns it via a configurable, non-writable Object.defineProperty (so it can only be cleared with @@ -68,3 +68,28 @@ describe('clearWorkerFromEntries', () => { expect(clearWorkerFromEntries(new Map(), { id: 1 })).to.equal(false); }); }); + +/** + * The connect edge retires an entry's pending setup and recovery. Only the worker that currently owns the + * entry may do that: the stale-worker path in `onDatabase` recreates an entry on a new worker while the old + * worker's hung-but-open connection can still report 'open' for the same (url, database), and retiring on + * that report would cancel the replacement's setup and leave it unsubscribed with `connected: true`. + */ +describe('connectReportOwnsEntry', () => { + it("lets the entry's current worker retire its pending work", () => { + expect(connectReportOwnsEntry({ worker: { threadId: 7 } }, 7)).to.equal(true); + }); + + it('refuses a report from a superseded worker', () => { + expect(connectReportOwnsEntry({ worker: { threadId: 8 } }, 7)).to.equal(false); + }); + + it('trusts an untagged report (main-thread up-correction, or an inline subscribe with no worker)', () => { + expect(connectReportOwnsEntry({ worker: { threadId: 7 } }, undefined)).to.equal(true); + expect(connectReportOwnsEntry({}, undefined)).to.equal(true); + }); + + it('refuses a tagged report for an entry with no worker', () => { + expect(connectReportOwnsEntry({}, 7)).to.equal(false); + }); +}); diff --git a/unitTests/replication/nodeUpdateWatcher.test.mjs b/unitTests/replication/nodeUpdateWatcher.test.mjs index 019713b28..90b5257d0 100644 --- a/unitTests/replication/nodeUpdateWatcher.test.mjs +++ b/unitTests/replication/nodeUpdateWatcher.test.mjs @@ -158,8 +158,15 @@ describe('runNodeUpdateWatcher restart loop', () => { await runNodeUpdateWatcher(() => {}, { subscribe: async () => { subscribeCalls++; - fakeNow += 60_000; // every run stays up well past healthyUptimeMs - return makeAsyncIterableFromArray([]); + return { + // The clock advances while ITERATING, which is the only thing that counts as uptime. + [Symbol.asyncIterator]: () => ({ + next: async () => { + fakeNow += 60_000; + return { done: true }; + }, + }), + }; }, restartDelayMs: 4, maxDelayMs: 256, @@ -176,6 +183,31 @@ describe('runNodeUpdateWatcher restart loop', () => { expect(delays.values, 'a healthy run never escalates').to.deep.equal([3, 3, 3]); }); + // The health clock must start when the subscription goes live, not when the attempt begins: a + // subscribe() that blocks past the threshold and then throws was never a live watcher. + it('does not count time spent acquiring a subscription as uptime', async () => { + let fakeNow = 0; + const delays = captureTimerDelays(); + try { + await runNodeUpdateWatcher(() => {}, { + subscribe: async () => { + fakeNow += 60_000; // a slow acquire, then a failure + throw new Error('subscribe timed out'); + }, + restartDelayMs: 4, + maxDelayMs: 256, + healthyUptimeMs: 10_000, + now: () => fakeNow, + random: () => 0.999999, + maxRestarts: 5, + }); + } finally { + delays.restore(); + } + + expect(delays.values, 'a slow failed acquire still escalates').to.deep.equal([3, 7, 15, 31]); + }); + it('forwards events to the listener via the default processEvent path', async () => { // Smoke test the default processor at the parameter-passing level using an // injected subscribe that yields a single put event for a foreign node. diff --git a/unitTests/replication/shouldCloseSendAuthWatch.test.mjs b/unitTests/replication/shouldCloseSendAuthWatch.test.mjs index 0fcbe1f96..22aa0e3c9 100644 --- a/unitTests/replication/shouldCloseSendAuthWatch.test.mjs +++ b/unitTests/replication/shouldCloseSendAuthWatch.test.mjs @@ -113,6 +113,32 @@ describe('shouldCloseSendAuthWatch', () => { expect(resolved, 'no probe after the deadline').to.equal(1); }); + // The store read is synchronous, so it can carry the clock past the deadline by itself — the sleep is + // not the only thing that can overrun the advertised grace period. + it('fails closed when the row read itself crosses the deadline', async () => { + let clock = 0; + let timedOut = false; + let resolved = 0; + const shouldClose = await shouldCloseSendAuthWatch({ type: 'put' }, 'node-a', 'data', { + isClosed: neverClosed, + sleep: async () => { + clock += 29_000; + }, + now: () => clock, + reprobeBudgetMs: 30_000, + resolve: () => { + if (resolved++ === 0) return SEND_AUTH_UNCHANGED; + clock += 5000; // the point read blocks past the deadline, then returns an authorizing row + return { name: 'node-a', replicates: true }; + }, + onReprobeTimeout: () => { + timedOut = true; + }, + }); + expect(shouldClose, 'a row that arrived after the deadline does not authorize').to.equal(true); + expect(timedOut).to.equal(true); + }); + it('does not read the clock at all for an immediately decodable row', async () => { const shouldClose = await shouldCloseSendAuthWatch({ type: 'put' }, 'node-a', 'data', { isClosed: neverClosed, diff --git a/unitTests/replication/workerSubscriptionAdmission.test.mjs b/unitTests/replication/workerSubscriptionAdmission.test.mjs index f4262321e..29f5c2f2e 100644 --- a/unitTests/replication/workerSubscriptionAdmission.test.mjs +++ b/unitTests/replication/workerSubscriptionAdmission.test.mjs @@ -111,6 +111,37 @@ describe('worker subscription admission', () => { assert.equal(admission.pendingCount(), 0); }); + it('does not add a second attempt or timer while a retry is armed', async () => { + let readinessCalls = 0; + const retries = []; + let fire; + const admission = createWorkerSubscriptionAdmission({ + whenReady: () => { + readinessCalls++; + return Promise.reject(new Error('load failed')); + }, + key: (message) => message.key, + dispatch: () => assert.fail('nothing should dispatch'), + onError: () => {}, + retry: (delayMs, attempt) => { + retries.push(delayMs); + fire = attempt; + }, + }); + admission.submit({ key: 'peer\0data' }); + await waitForTurn(); + assert.equal(retries.length, 1); + + for (let i = 0; i < 50; i++) admission.submit({ key: `peer\0db-${i}` }); + await waitForTurn(); + assert.equal(readinessCalls, 1, 'no second readiness attempt while one is armed'); + assert.equal(retries.length, 1, 'no second timer'); + + fire(); + await waitForTurn(); + assert.equal(readinessCalls, 2, 'the armed retry is the one that re-attempts'); + }); + it('stops re-attempting once nothing is pending', async () => { const retries = []; const admission = createWorkerSubscriptionAdmission({ @@ -125,22 +156,27 @@ describe('worker subscription admission', () => { assert.equal(retries.length, 1); }); - it('retains bounded state after readiness rejection and retries on the next message', async () => { + it('retains bounded state after a readiness rejection and applies the newest action on the retry', async () => { const firstReadiness = deferred(); let attempts = 0; const actions = []; const errors = []; + let fire; const admission = createWorkerSubscriptionAdmission({ whenReady: () => (++attempts === 1 ? firstReadiness.promise : Promise.resolve()), key: (message) => message.key, dispatch: (message) => actions.push(message.generation), onError: (_message, error) => errors.push(error.message), + retry: (_delayMs, attempt) => (fire = attempt), }); admission.submit({ key: 'peer\0data', generation: 1 }); firstReadiness.reject(new Error('component load failed')); await waitForTurn(); assert.equal(admission.pendingCount(), 1); + // A message arriving before the retry fires replaces the retained one rather than adding work. admission.submit({ key: 'peer\0data', generation: 2 }); + assert.equal(admission.pendingCount(), 1); + fire(); await waitForTurn(); assert.deepEqual(errors, ['component load failed']); From 23ba66995e1eb6941c2ab9baa74258d8a732687b Mon Sep 17 00:00:00 2001 From: Kris Zyp Date: Wed, 2 Sep 2026 09:35:43 -0600 Subject: [PATCH 08/13] Fix the review's documentation, floor, and log-rate nits The backoff table described the blob-repair cutoff the previous commit replaced and listed neither the copy-cursor flush retry nor the worker readiness re-attempt; the exclusions paragraph now also names the copy-finalize timeout bound, which is a wait bound rather than a retry and must stay unjittered. Give the readiness re-attempt the same floor every other adopting site has, so a zero draw cannot re-probe on the next macrotask. Sample the per-record blob-repair warn once the sweep goes unpaced, and put clearWorkerFromEntries' description back over clearWorkerFromEntries. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01HEgBi5zh8QKMbFmeGwFv7w --- replication/DESIGN.md | 22 +++++++++----- replication/blobRepair.ts | 13 ++++++++- replication/subscriptionManager.ts | 29 +++++++++---------- .../workerSubscriptionAdmission.test.mjs | 19 +++++++++++- 4 files changed, 58 insertions(+), 25 deletions(-) diff --git a/replication/DESIGN.md b/replication/DESIGN.md index 39591eefc..4a60db0ca 100644 --- a/replication/DESIGN.md +++ b/replication/DESIGN.md @@ -122,7 +122,9 @@ decorrelated schedule.** Pacing alone is not enough; the storm surface below nee | `runNodeUpdateWatcher` (`knownNodes.ts`) — hdb_nodes watcher restart | full-jitter ceiling 1 s → 30 s | an iteration that survived `NODE_WATCHER_HEALTHY_UPTIME_MS` | | `shouldCloseSendAuthWatch` reprobe (`replicationConnection.ts`) | 500 ms → 5 s under a 30 s wall-clock budget, then fails closed | n/a (one-shot loop) | | `fetchJWTKeyWithRetry`, the clone version probe (`cloneNode/`) | 250 ms → 1 s / 1 s → 4 s, attempt count unchanged | n/a | -| `repairBlobs` (`blobRepair.ts`) — per-record | 50 ms → 1 s, only on a record no peer could repair; the sweep ends once the schedule is exhausted (100 consecutive) | a repaired record | +| `repairBlobs` (`blobRepair.ts`) — per-record | 50 ms → 1 s, only on a record no peer could repair, under a 60 s per-failure-run pacing budget; once that is spent the sweep keeps scanning unpaced (with a sampled warn) rather than stopping, so an unrepairable prefix cannot hide the records behind it | a repaired record | +| copy-cursor flush retry (`replicationConnection.ts`) — `onPersistFailure` | fixed 250 ms floor, ceiling 250 ms → 30 s; the floor is what the `copyFlushBackoffUntil` guard depends on | a flush that persisted the cursor | +| worker readiness re-attempt (`subscriptionManager.ts`) | floor `NODE_SUBSCRIBE_DELAY`, ceiling `2 × NODE_SUBSCRIBE_DELAY` → 30 s, one armed re-attempt at a time | components loaded | **The subscription-setup scheduler is the one with dedup.** `onDatabase` used to turn every qualifying node update straight into a retained (not unref'd) 200 ms `setTimeout` plus a `subscribe-to-node` @@ -139,8 +141,10 @@ A setup is cancelled on connect, on unsubscribe, on node deletion, and on a same-name URL migration, all of which became reachable once a pending timer could live 30 s instead of 200 ms. The wedge/stall recovery kicks are owned the same way — one `entry.reDriveTimer` per entry, so a staggered sweep that outruns the -reconcile window that started it replaces its predecessor instead of stacking another wave, and only the -worker that currently owns an entry may retire its pending setup on connect. Their jitter is drawn once +reconcile window that started it replaces its predecessor instead of stacking another wave, disarmed when +the owning worker exits or the entry is replaced, and only the worker that currently owns an entry may +retire its pending setup on connect (the report carries the sending thread id; see +`connectReportOwnsEntry`). Their jitter is drawn once per sweep rather than per entry: a per-entry draw would vary consecutive delays by up to ±200 ms and let several dials share a 50 ms instant, which is the concurrency the `RECONNECT_STAGGER_MS` spacing exists to bound (#446). The warn moved inside the "actually armed" branch: it now describes an attempt, not an @@ -148,14 +152,18 @@ event. The worker boundary has one additional admission point for its asynchronous startup window. Before components are ready, one insertion-ordered map retains only the latest subscribe/unsubscribe message -per actual connection key and database, with one continuation on the readiness promise. After readiness, +per actual connection key and database, with one continuation on the readiness promise — and, if that +readiness rejects, exactly one armed re-attempt on the same schedule, so the retained actions apply without +waiting for another message or the wedge reconcile. After readiness, the handlers run inline and allocate no queue state; the existing connection map is then the single-flight owner. Subscribe, unsubscribe, force-reconnect, and startup admission all derive the connection key through `getSubscriptionConnectionKey`, including the missing nested-URL fallback. -**What is deliberately NOT on this schedule:** the receive/copy watchdogs and their thresholds (they -_detect_ stalls; this discipline paces _retries_), `blobGapReconnectTimer`, the in-place -`BLOB_SEND_RETRY_DELAYS_MS` 503 retries, `PING_INTERVAL`/`PING_TIMEOUT`, and `RECONCILE_INTERVAL_MS`. +**What is deliberately NOT on this schedule:** the receive/copy watchdogs and their thresholds, and the +doubling copy-finalize _timeout bound_ alongside them (these _detect_ stalls or bound a wait; this +discipline paces _retries_, and jittering a durability deadline would be actively wrong), +`blobGapReconnectTimer`, the in-place `BLOB_SEND_RETRY_DELAYS_MS` 503 retries, +`PING_INTERVAL`/`PING_TIMEOUT`, and `RECONCILE_INTERVAL_MS`. --- diff --git a/replication/blobRepair.ts b/replication/blobRepair.ts index 300cba97f..d2a607c94 100644 --- a/replication/blobRepair.ts +++ b/replication/blobRepair.ts @@ -18,6 +18,9 @@ const REPAIR_RETRY_MAX_MS = 1000; // scanning at full speed: pacing exists to stop a hot loop, and inferring the rest of the cursor from an // unrepairable prefix would silently skip records a later peer can still serve. A repair restarts it. const REPAIR_PACING_BUDGET_MS = 60_000; +// Once unpaced the per-record warn would fire at peer-RTT rate for the rest of the sweep — hundreds of +// thousands of lines during exactly the incident where the log is the diagnostic channel. Sample it. +const REPAIR_UNPACED_WARN_EVERY = 100; export async function allBlobsAreComplete( blobs: any[], @@ -96,7 +99,15 @@ export async function repairBlobs( pacingSpent = false; } else { failed++; - logger.warn?.('Could not repair blob for record', recordId, 'in', tableName, '— no peer had a complete copy'); + if (!pacingSpent || failed % REPAIR_UNPACED_WARN_EVERY === 0) + logger.warn?.( + 'Could not repair blob for record', + recordId, + 'in', + tableName, + '— no peer had a complete copy', + pacingSpent ? `(${failed} failed so far; sampling 1 in ${REPAIR_UNPACED_WARN_EVERY})` : '' + ); const delay = backoff.nextDelay(); if (delay === undefined) { if (!pacingSpent) { diff --git a/replication/subscriptionManager.ts b/replication/subscriptionManager.ts index d1901622c..45ca24fe1 100644 --- a/replication/subscriptionManager.ts +++ b/replication/subscriptionManager.ts @@ -370,21 +370,18 @@ function reportIdentityMismatchOnce(nodes: Array<{ name?: string; url?: string } // `worker: undefined` when httpWorkers is empty, and without this the entry would never // get reassigned once workers came back. Pure helper so the reconcile pass below — and its // unit tests — can verify the broken-chain detection without spinning up real workers. -// Clear a dead worker from every subscription entry it owned, so findStaleNodeUrls re-binds those -// entries on a live worker. Pure helper (like findStaleNodeUrls) so its behavior is unit-testable without -// real worker threads. Returns whether the worker owned any entries. See harper-pro#357. -/** - * Whether a 'connected-to-node' report may retire the entry's pending setup and recovery. The stale-worker - * path in `onDatabase` recreates an entry on a new worker while the old worker's hung-but-open connection - * can still report 'open' for the same (url, database); retiring on that report would cancel the - * replacement's setup and leave it unsubscribed with `connected: true`, which the wedge net then skips. - * An untagged report (the main thread's own truth-driven up-correction, or an inline subscribe with no - * worker) is trusted. - */ +// Whether a 'connected-to-node' report may retire the entry's pending setup and recovery. The stale-worker +// path in onDatabase recreates an entry on a new worker while the old worker's hung-but-open connection can +// still report 'open' for the same (url, database); retiring on that report would cancel the replacement's +// setup and leave it unsubscribed with connected:true, which the wedge net then skips. An untagged report +// (the main thread's own truth-driven up-correction, or an inline subscribe with no worker) is trusted. export function connectReportOwnsEntry(entry: { worker?: any }, reportingThreadId?: number): boolean { return reportingThreadId === undefined || reportingThreadId === entry?.worker?.threadId; } +// Clear a dead worker from every subscription entry it owned, so findStaleNodeUrls re-binds those +// entries on a live worker. Pure helper (like findStaleNodeUrls) so its behavior is unit-testable without +// real worker threads. Returns whether the worker owned any entries. See harper-pro#357. export function clearWorkerFromEntries(connectionMap: Map, worker: any): boolean { let owned = false; for (const dbReplicationWorkers of connectionMap.values()) { @@ -1017,8 +1014,7 @@ export async function startOnMainThread(options) { !existingEntry.unsubscribed && !(forceResubscribe && existingEntry.connected === false) ) { - // Nothing new to send for an already-subscribed entry, but an armed setup would otherwise - // still be holding the payload from before this update. + // An armed setup would otherwise fire with the payload from before this update. subscribeSetupScheduler.refreshPending(getNodeURL(node), databaseName, nodes); return; } @@ -1118,8 +1114,8 @@ export async function startOnMainThread(options) { // Keep the entry for URL/iterator cleanup, but bypass the reuse fast path after an // explicit unsubscribe so restoring membership can schedule subscribe-to-node again. if (existingEntry) existingEntry.unsubscribed = true; - // A setup armed for this pair can now be up to 30s from firing; without this it would - // re-subscribe right after we told the worker to unsubscribe. Same for a recovery kick. + // A setup armed for this pair can be up to 30s from firing, and would re-subscribe right + // after the worker was told to unsubscribe. Same for a recovery kick. subscribeSetupScheduler.cancel(getNodeURL(node), databaseName); if (existingEntry) { clearTimeout(existingEntry.reDriveTimer); @@ -1691,8 +1687,9 @@ export function createWorkerSubscriptionAdmission(deps: { // gate exists to close (harper-pro#289 / #233). Re-attempt on the shared schedule instead. if (!ready && pending.size > 0) { retryBackoff ??= createBackoff({ - initialMs: NODE_SUBSCRIBE_DELAY, + initialMs: NODE_SUBSCRIBE_INITIAL_CEILING_MS, maxMs: NODE_SUBSCRIBE_MAX_DELAY_MS, + minMs: NODE_SUBSCRIBE_DELAY, random: deps.random, }); const delay = retryBackoff.nextDelay(); diff --git a/unitTests/replication/workerSubscriptionAdmission.test.mjs b/unitTests/replication/workerSubscriptionAdmission.test.mjs index 29f5c2f2e..10506c9b6 100644 --- a/unitTests/replication/workerSubscriptionAdmission.test.mjs +++ b/unitTests/replication/workerSubscriptionAdmission.test.mjs @@ -106,7 +106,7 @@ describe('worker subscription admission', () => { await waitForTurn(); assert.deepEqual(errors, ['load failed 1', 'load failed 2']); - assert.deepEqual(retries, [199, 399], 'the re-attempt delay escalates under the shared schedule'); + assert.deepEqual(retries, [399, 799], 'the re-attempt delay escalates under the shared schedule'); assert.deepEqual(actions, [1], 'the retained action is applied once readiness succeeds'); assert.equal(admission.pendingCount(), 0); }); @@ -142,6 +142,23 @@ describe('worker subscription admission', () => { assert.equal(readinessCalls, 2, 'the armed retry is the one that re-attempts'); }); + // Full jitter with no floor would draw near 0 and re-attempt on the next macrotask, turning a boot-time + // component-load failure into a spin of imports and warn lines — the shape this gate exists to bound. + it('never re-attempts below the floor, even on a zero draw', async () => { + const retries = []; + const admission = createWorkerSubscriptionAdmission({ + whenReady: () => Promise.reject(new Error('load failed')), + key: (message) => message.key, + dispatch: () => assert.fail('nothing should dispatch'), + onError: () => {}, + retry: (delayMs) => retries.push(delayMs), + random: () => 0, + }); + admission.submit({ key: 'peer\0data' }); + await waitForTurn(); + assert.deepEqual(retries, [200]); + }); + it('stops re-attempting once nothing is pending', async () => { const retries = []; const admission = createWorkerSubscriptionAdmission({ From fba0d26d02baef9230b790482f3627b0926b43d1 Mon Sep 17 00:00:00 2001 From: Kris Zyp Date: Wed, 2 Sep 2026 09:56:24 -0600 Subject: [PATCH 09/13] Reset the setup backoff on connect instead of attributing the report MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Gating the connect edge on "is this the entry's current worker" is not answerable on the main thread: connectToNextWorker subscribes a failover peer on a worker that is not entry.worker, and a superseded worker's hung-but-open connection reports for the same (url, database) as its replacement. Gating on it meant the escalated setup delay stopped resetting, and connectedBitRestartChurn's chaos cycles converged in 5.3s, 12.0s, then not within 25s — a backoff compounding across reconnects. Reset the delay unconditionally and leave the armed setup and recovery timers to their own fire-time guards, which is what this path did before the schedule existed. That suite is green again. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01HEgBi5zh8QKMbFmeGwFv7w --- replication/DESIGN.md | 14 +++++--- replication/subscriptionManager.ts | 36 ++++++++----------- .../clearWorkerFromEntries.test.mjs | 27 +------------- .../subscribeSetupScheduler.test.mjs | 21 +++++++++-- 4 files changed, 42 insertions(+), 56 deletions(-) diff --git a/replication/DESIGN.md b/replication/DESIGN.md index 4a60db0ca..8bb8d7b83 100644 --- a/replication/DESIGN.md +++ b/replication/DESIGN.md @@ -116,7 +116,7 @@ decorrelated schedule.** Pacing alone is not enough; the storm surface below nee | Site | Schedule | Reset signal | | ------------------------------------------------------------------------------- | -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | -------------------------------------------------------------- | -| `createSubscribeSetupScheduler` (`subscriptionManager.ts`) — subscription setup | floor `NODE_SUBSCRIBE_DELAY`, ceiling `2 × NODE_SUBSCRIBE_DELAY` → 30 s, plus the caller's `RECONNECT_STAGGER_MS` stagger | `connectedToNode` (also cancels the pending setup) | +| `createSubscribeSetupScheduler` (`subscriptionManager.ts`) — subscription setup | floor `NODE_SUBSCRIBE_DELAY`, ceiling `2 × NODE_SUBSCRIBE_DELAY` → 30 s, plus the caller's `RECONNECT_STAGGER_MS` stagger | `connectedToNode` (reset only; the armed setup still fires) | | `NodeReplicationConnection.scheduleReconnect` | fixed 500 ms floor, ceiling `INITIAL_RETRY_TIME` 500 ms → 30 s, full jitter; the floor preserves the hard minimum from the TLS-state incident while the remaining window decorrelates fleet redials (harper-pro#339) | `onFrameSent` — first frame actually sent, **not** socket open | | `reconcileWorkers` wedge / receive-stall re-drives | one fixed-window draw per sweep, used as a common base under the existing `RECONNECT_STAGGER_MS` spacing (decorrelation only; the re-drives are already throttled by the `disconnectedAt` / `receiveStallReconnectAt` re-stamps), one owned `entry.reDriveTimer` per entry | n/a — disarmed on connect, unsubscribe, and delete | | `runNodeUpdateWatcher` (`knownNodes.ts`) — hdb_nodes watcher restart | full-jitter ceiling 1 s → 30 s | an iteration that survived `NODE_WATCHER_HEALTHY_UPTIME_MS` | @@ -141,10 +141,14 @@ A setup is cancelled on connect, on unsubscribe, on node deletion, and on a same-name URL migration, all of which became reachable once a pending timer could live 30 s instead of 200 ms. The wedge/stall recovery kicks are owned the same way — one `entry.reDriveTimer` per entry, so a staggered sweep that outruns the -reconcile window that started it replaces its predecessor instead of stacking another wave, disarmed when -the owning worker exits or the entry is replaced, and only the worker that currently owns an entry may -retire its pending setup on connect (the report carries the sending thread id; see -`connectReportOwnsEntry`). Their jitter is drawn once +reconcile window that started it replaces its predecessor instead of stacking another wave, and disarmed +when the owning worker exits or the entry is replaced. A connect report does **not** cancel either timer — +only the escalated delay is reset. The main thread cannot attribute a report to the entry that armed the +work (`connectToNextWorker` subscribes a failover peer on a worker that is not `entry.worker`, and a +superseded worker's hung-but-open connection reports for the same pair as its replacement), so cancelling +on it would strand a just-recreated entry; both timers re-check live state when they fire instead. Gating +the reset on that attribution instead is what let a chaos-restart peer's setup delay escalate past its +reconvergence budget. Their jitter is drawn once per sweep rather than per entry: a per-entry draw would vary consecutive delays by up to ±200 ms and let several dials share a 50 ms instant, which is the concurrency the `RECONNECT_STAGGER_MS` spacing exists to bound (#446). The warn moved inside the "actually armed" branch: it now describes an attempt, not an diff --git a/replication/subscriptionManager.ts b/replication/subscriptionManager.ts index 45ca24fe1..0659e8ded 100644 --- a/replication/subscriptionManager.ts +++ b/replication/subscriptionManager.ts @@ -16,7 +16,7 @@ import { getSubscriptionConnectionKey, } from './replicator.ts'; import { getThisNodeName, getThisNodeUrl } from '../core/server/nodeName.ts'; -import { parentPort, threadId } from 'worker_threads'; +import { parentPort } from 'worker_threads'; import { subscribeToNodeUpdates, getHDBNodeTable, @@ -152,7 +152,7 @@ export interface SubscribeSetupScheduler { schedule(url: string, database: string, nodes: any[], staggerMs?: number): number | undefined; /** Replace the payload of an already-armed setup without arming one. */ refreshPending(url: string, database: string, nodes: any[]): void; - /** The pair reached 'open': drop the pending setup and the escalated delay. */ + /** The pair reached 'open': real progress, so drop the escalated delay. */ noteConnected(url: string, database: string): void; cancel(url: string, database: string): void; cancelUrl(url: string): void; @@ -231,7 +231,13 @@ export function createSubscribeSetupScheduler(deps: { if (schedule?.timer) schedule.nodes = nodes; }, noteConnected(url, database) { - drop(url, database); + // Reset only — the armed setup is deliberately left to fire. The main thread cannot attribute a + // connect report to the entry that armed the setup: `connectToNextWorker` subscribes a failover + // peer on a worker that is not `entry.worker`, and a superseded worker's hung-but-open connection + // reports for the same (url, database) as its replacement. Cancelling on a report we cannot + // attribute strands a just-recreated entry unsubscribed; letting a redundant subscribe reach a + // live connection is what this path always did. + schedules.get(url)?.get(database)?.backoff.reset(); }, cancel(url, database) { drop(url, database); @@ -370,15 +376,6 @@ function reportIdentityMismatchOnce(nodes: Array<{ name?: string; url?: string } // `worker: undefined` when httpWorkers is empty, and without this the entry would never // get reassigned once workers came back. Pure helper so the reconcile pass below — and its // unit tests — can verify the broken-chain detection without spinning up real workers. -// Whether a 'connected-to-node' report may retire the entry's pending setup and recovery. The stale-worker -// path in onDatabase recreates an entry on a new worker while the old worker's hung-but-open connection can -// still report 'open' for the same (url, database); retiring on that report would cancel the replacement's -// setup and leave it unsubscribed with connected:true, which the wedge net then skips. An untagged report -// (the main thread's own truth-driven up-correction, or an inline subscribe with no worker) is trusted. -export function connectReportOwnsEntry(entry: { worker?: any }, reportingThreadId?: number): boolean { - return reportingThreadId === undefined || reportingThreadId === entry?.worker?.threadId; -} - // Clear a dead worker from every subscription entry it owned, so findStaleNodeUrls re-binds those // entries on a live worker. Pure helper (like findStaleNodeUrls) so its behavior is unit-testable without // real worker threads. Returns whether the worker owned any entries. See harper-pro#357. @@ -1232,13 +1229,10 @@ export async function startOnMainThread(options) { return; } mainWorkerEntry.connected = true; - // Real progress for this pair: drop the escalated setup backoff, any setup still pending, and any - // recovery kick armed for a connection that has since come back. - if (connectReportOwnsEntry(mainWorkerEntry, connection.reportingThreadId)) { - subscribeSetupScheduler.noteConnected(connection.url, connection.database); - clearTimeout(mainWorkerEntry.reDriveTimer); - mainWorkerEntry.reDriveTimer = undefined; - } + // Real progress for this pair, so the escalated setup delay goes back to its first ceiling. The + // pending setup and the armed recovery are left alone: both re-check live state when they fire, and + // a connect report cannot be attributed to the worker that armed them. + subscribeSetupScheduler.noteConnected(connection.url, connection.database); mainWorkerEntry.disconnectedAt = undefined; mainWorkerEntry.latency = connection.latency; const restoredNode = mainWorkerEntry.nodes[0]; @@ -1742,9 +1736,7 @@ if (parentPort) { parentPort.postMessage({ type: 'disconnected-from-node', ...connection }); }; connectedToNode = (connection) => { - // Tagged so the main thread can tell this worker's report from a superseded worker's; see - // connectReportOwnsEntry. - parentPort.postMessage({ type: 'connected-to-node', ...connection, reportingThreadId: threadId }); + parentPort.postMessage({ type: 'connected-to-node', ...connection }); }; onMessageByType('subscribe-to-node', (message) => { // Defer until this worker has finished loading components (databases/tables + persisted hdb_nodes diff --git a/unitTests/replication/clearWorkerFromEntries.test.mjs b/unitTests/replication/clearWorkerFromEntries.test.mjs index 642c4e362..95b27091a 100644 --- a/unitTests/replication/clearWorkerFromEntries.test.mjs +++ b/unitTests/replication/clearWorkerFromEntries.test.mjs @@ -8,7 +8,7 @@ */ import { expect } from 'chai'; -import { clearWorkerFromEntries, connectReportOwnsEntry } from '#src/replication/subscriptionManager'; +import { clearWorkerFromEntries } from '#src/replication/subscriptionManager'; // Build a connectionReplicationMap: Map>. node.worker mirrors connectToNextWorker, // which assigns it via a configurable, non-writable Object.defineProperty (so it can only be cleared with @@ -68,28 +68,3 @@ describe('clearWorkerFromEntries', () => { expect(clearWorkerFromEntries(new Map(), { id: 1 })).to.equal(false); }); }); - -/** - * The connect edge retires an entry's pending setup and recovery. Only the worker that currently owns the - * entry may do that: the stale-worker path in `onDatabase` recreates an entry on a new worker while the old - * worker's hung-but-open connection can still report 'open' for the same (url, database), and retiring on - * that report would cancel the replacement's setup and leave it unsubscribed with `connected: true`. - */ -describe('connectReportOwnsEntry', () => { - it("lets the entry's current worker retire its pending work", () => { - expect(connectReportOwnsEntry({ worker: { threadId: 7 } }, 7)).to.equal(true); - }); - - it('refuses a report from a superseded worker', () => { - expect(connectReportOwnsEntry({ worker: { threadId: 8 } }, 7)).to.equal(false); - }); - - it('trusts an untagged report (main-thread up-correction, or an inline subscribe with no worker)', () => { - expect(connectReportOwnsEntry({ worker: { threadId: 7 } }, undefined)).to.equal(true); - expect(connectReportOwnsEntry({}, undefined)).to.equal(true); - }); - - it('refuses a tagged report for an entry with no worker', () => { - expect(connectReportOwnsEntry({}, 7)).to.equal(false); - }); -}); diff --git a/unitTests/replication/subscribeSetupScheduler.test.mjs b/unitTests/replication/subscribeSetupScheduler.test.mjs index 084abf8cf..10d6b019d 100644 --- a/unitTests/replication/subscribeSetupScheduler.test.mjs +++ b/unitTests/replication/subscribeSetupScheduler.test.mjs @@ -158,7 +158,11 @@ describe('subscription-setup scheduler (harper-pro#327)', () => { assert.equal(scheduler.schedule(URL_A, 'data', NODES, 150), 450); }); - it('noteConnected drops the pending setup and the escalated delay', () => { + // A connect report cannot be attributed to the entry that armed the setup (failover subscribes on a + // worker that is not entry.worker, and a superseded worker still reports for the same pair), so the + // armed setup is left to fire and only the escalated delay is dropped. Escalating across reconnect + // cycles instead is what pushed a chaos-restart peer past its 25s reconvergence budget. + it('noteConnected resets the escalated delay and leaves the armed setup to fire', () => { const { scheduler, dispatches } = makeScheduler(() => 0.5); scheduler.schedule(URL_A, 'data', NODES); clock.tick(300); @@ -166,13 +170,24 @@ describe('subscription-setup scheduler (harper-pro#327)', () => { assert.equal(scheduler.pendingCount(), 1); scheduler.noteConnected(URL_A, 'data'); - assert.equal(scheduler.pendingCount(), 0, 'the armed setup is cancelled, not just reset'); + assert.equal(scheduler.pendingCount(), 1, 'still armed'); clock.tick(60_000); - assert.equal(dispatches.length, 1, 'the cancelled setup never fired'); + assert.equal(dispatches.length, 2, 'the armed setup fired'); assert.equal(scheduler.schedule(URL_A, 'data', NODES), 300, 'back to the first ceiling after success'); }); + it('a pair that reconnects every cycle never escalates', () => { + const { scheduler } = makeScheduler(() => 0.5); + const delays = []; + for (let cycle = 0; cycle < 5; cycle++) { + delays.push(scheduler.schedule(URL_A, 'data', NODES)); + clock.tick(1000); + scheduler.noteConnected(URL_A, 'data'); + } + assert.deepEqual(delays, [300, 300, 300, 300, 300]); + }); + it('cancel() and cancelUrl() disarm pending setups', () => { const { scheduler, dispatches } = makeScheduler(() => 0.5); scheduler.schedule(URL_A, 'data', NODES); From 0ea8e54e651344d70f755cf62048c0d9b1f30e3f Mon Sep 17 00:00:00 2001 From: Kris Zyp Date: Wed, 2 Sep 2026 10:17:41 -0600 Subject: [PATCH 10/13] Give the stall kick its own claim, and make the docs match the code MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Removing the connect-edge cancellation left the receive-stall kick with no guard that observes a reconnect: entry identity holds, receiveStallReconnectAt is untouched by connectedToNode, and the watermark cannot move on a socket that just opened — so a leg that drops and reconnects inside the kick's stagger window was force-reconnected on the strength of the old socket's watermark. Claim it through a connect generation, the way the wedge kick claims its entry through disconnectedAt (which a stalled, connected:true entry does not have). The design table, its prose, and dispatchSubscribeSetup's JSDoc still described the cancel-on-connect behavior that commit removed. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01HEgBi5zh8QKMbFmeGwFv7w --- replication/DESIGN.md | 50 +++++++++++++++++------------- replication/subscriptionManager.ts | 33 +++++++++++++------- 2 files changed, 49 insertions(+), 34 deletions(-) diff --git a/replication/DESIGN.md b/replication/DESIGN.md index 8bb8d7b83..7a154f210 100644 --- a/replication/DESIGN.md +++ b/replication/DESIGN.md @@ -114,17 +114,17 @@ jitterless doubling. The invariant the discipline enforces: **at most one pending attempt per target, on a bounded, capped, decorrelated schedule.** Pacing alone is not enough; the storm surface below needed the dedup too. -| Site | Schedule | Reset signal | -| ------------------------------------------------------------------------------- | -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | -------------------------------------------------------------- | -| `createSubscribeSetupScheduler` (`subscriptionManager.ts`) — subscription setup | floor `NODE_SUBSCRIBE_DELAY`, ceiling `2 × NODE_SUBSCRIBE_DELAY` → 30 s, plus the caller's `RECONNECT_STAGGER_MS` stagger | `connectedToNode` (reset only; the armed setup still fires) | -| `NodeReplicationConnection.scheduleReconnect` | fixed 500 ms floor, ceiling `INITIAL_RETRY_TIME` 500 ms → 30 s, full jitter; the floor preserves the hard minimum from the TLS-state incident while the remaining window decorrelates fleet redials (harper-pro#339) | `onFrameSent` — first frame actually sent, **not** socket open | -| `reconcileWorkers` wedge / receive-stall re-drives | one fixed-window draw per sweep, used as a common base under the existing `RECONNECT_STAGGER_MS` spacing (decorrelation only; the re-drives are already throttled by the `disconnectedAt` / `receiveStallReconnectAt` re-stamps), one owned `entry.reDriveTimer` per entry | n/a — disarmed on connect, unsubscribe, and delete | -| `runNodeUpdateWatcher` (`knownNodes.ts`) — hdb_nodes watcher restart | full-jitter ceiling 1 s → 30 s | an iteration that survived `NODE_WATCHER_HEALTHY_UPTIME_MS` | -| `shouldCloseSendAuthWatch` reprobe (`replicationConnection.ts`) | 500 ms → 5 s under a 30 s wall-clock budget, then fails closed | n/a (one-shot loop) | -| `fetchJWTKeyWithRetry`, the clone version probe (`cloneNode/`) | 250 ms → 1 s / 1 s → 4 s, attempt count unchanged | n/a | -| `repairBlobs` (`blobRepair.ts`) — per-record | 50 ms → 1 s, only on a record no peer could repair, under a 60 s per-failure-run pacing budget; once that is spent the sweep keeps scanning unpaced (with a sampled warn) rather than stopping, so an unrepairable prefix cannot hide the records behind it | a repaired record | -| copy-cursor flush retry (`replicationConnection.ts`) — `onPersistFailure` | fixed 250 ms floor, ceiling 250 ms → 30 s; the floor is what the `copyFlushBackoffUntil` guard depends on | a flush that persisted the cursor | -| worker readiness re-attempt (`subscriptionManager.ts`) | floor `NODE_SUBSCRIBE_DELAY`, ceiling `2 × NODE_SUBSCRIBE_DELAY` → 30 s, one armed re-attempt at a time | components loaded | +| Site | Schedule | Reset signal | +| ------------------------------------------------------------------------------- | -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | ------------------------------------------------------------------------- | +| `createSubscribeSetupScheduler` (`subscriptionManager.ts`) — subscription setup | floor `NODE_SUBSCRIBE_DELAY`, ceiling `2 × NODE_SUBSCRIBE_DELAY` → 30 s, plus the caller's `RECONNECT_STAGGER_MS` stagger | `connectedToNode` (reset only; the armed setup still fires) | +| `NodeReplicationConnection.scheduleReconnect` | fixed 500 ms floor, ceiling `INITIAL_RETRY_TIME` 500 ms → 30 s, full jitter; the floor preserves the hard minimum from the TLS-state incident while the remaining window decorrelates fleet redials (harper-pro#339) | `onFrameSent` — first frame actually sent, **not** socket open | +| `reconcileWorkers` wedge / receive-stall re-drives | one fixed-window draw per sweep, used as a common base under the existing `RECONNECT_STAGGER_MS` spacing (decorrelation only; the re-drives are already throttled by the `disconnectedAt` / `receiveStallReconnectAt` re-stamps), one owned `entry.reDriveTimer` per entry | n/a — disarmed on unsubscribe, delete, worker exit, and entry replacement | +| `runNodeUpdateWatcher` (`knownNodes.ts`) — hdb_nodes watcher restart | full-jitter ceiling 1 s → 30 s | an iteration that survived `NODE_WATCHER_HEALTHY_UPTIME_MS` | +| `shouldCloseSendAuthWatch` reprobe (`replicationConnection.ts`) | 500 ms → 5 s under a 30 s wall-clock budget, then fails closed | n/a (one-shot loop) | +| `fetchJWTKeyWithRetry`, the clone version probe (`cloneNode/`) | 250 ms → 1 s / 1 s → 4 s, attempt count unchanged | n/a | +| `repairBlobs` (`blobRepair.ts`) — per-record | 50 ms → 1 s, only on a record no peer could repair, under a 60 s per-failure-run pacing budget; once that is spent the sweep keeps scanning unpaced (with a sampled warn) rather than stopping, so an unrepairable prefix cannot hide the records behind it | a repaired record | +| copy-cursor flush retry (`replicationConnection.ts`) — `onPersistFailure` | fixed 250 ms floor, ceiling 250 ms → 30 s; the floor is what the `copyFlushBackoffUntil` guard depends on | a flush that persisted the cursor | +| worker readiness re-attempt (`subscriptionManager.ts`) | floor `NODE_SUBSCRIBE_DELAY`, ceiling `2 × NODE_SUBSCRIBE_DELAY` → 30 s, one armed re-attempt at a time | components loaded | **The subscription-setup scheduler is the one with dedup.** `onDatabase` used to turn every qualifying node update straight into a retained (not unref'd) 200 ms `setTimeout` plus a `subscribe-to-node` @@ -138,17 +138,23 @@ enrichment (that path calls `refreshPending` instead). Self-catchup is separate attached on a fresh array immediately before dispatch and consumed only after the worker message is accepted, so timer cancellation, stale dispatch, or a synchronous `postMessage` throw cannot lose it. A setup is cancelled on -connect, on unsubscribe, on node deletion, and on a same-name URL migration, all of which became -reachable once a pending timer could live 30 s instead of 200 ms. The wedge/stall recovery kicks are -owned the same way — one `entry.reDriveTimer` per entry, so a staggered sweep that outruns the -reconcile window that started it replaces its predecessor instead of stacking another wave, and disarmed -when the owning worker exits or the entry is replaced. A connect report does **not** cancel either timer — -only the escalated delay is reset. The main thread cannot attribute a report to the entry that armed the -work (`connectToNextWorker` subscribes a failover peer on a worker that is not `entry.worker`, and a -superseded worker's hung-but-open connection reports for the same pair as its replacement), so cancelling -on it would strand a just-recreated entry; both timers re-check live state when they fire instead. Gating -the reset on that attribution instead is what let a chaos-restart peer's setup delay escalate past its -reconvergence budget. Their jitter is drawn once +unsubscribe, on node deletion, and on a same-name URL migration, all of which became reachable once a +pending timer could live 30 s instead of 200 ms. The wedge/stall recovery kicks are owned the same way — +one `entry.reDriveTimer` per entry, so a staggered sweep that outruns the reconcile window that started it +replaces its predecessor instead of stacking another wave, and disarmed when the owning worker exits or the +entry is replaced. + +**A connect report cancels nothing; it only resets the escalated delay.** The main thread cannot attribute a +report to the entry that armed the work — `connectToNextWorker` subscribes a failover peer on a worker that +is not `entry.worker`, and a superseded worker's hung-but-open connection reports for the same pair as its +replacement — so cancelling on it strands a just-recreated entry, and gating the _reset_ on that attribution +is what let a chaos-restart peer's setup delay escalate past its reconvergence budget. What makes leaving +the timers armed safe is that each re-checks live state when it fires: the setup re-reads the entry and its +`unsubscribed` flag, the wedge kick claims its entry through the `disconnectedAt` stamp a connect clears, +and the stall kick claims it through `connectGeneration` (a stalled connection is `connected: true` with no +`disconnectedAt`, so the stamp cannot discriminate for it) plus the receive watermark. + +Their jitter is drawn once per sweep rather than per entry: a per-entry draw would vary consecutive delays by up to ±200 ms and let several dials share a 50 ms instant, which is the concurrency the `RECONNECT_STAGGER_MS` spacing exists to bound (#446). The warn moved inside the "actually armed" branch: it now describes an attempt, not an diff --git a/replication/subscriptionManager.ts b/replication/subscriptionManager.ts index 0659e8ded..266027b95 100644 --- a/replication/subscriptionManager.ts +++ b/replication/subscriptionManager.ts @@ -72,6 +72,11 @@ type ConnectedWorkerStatus = { // window that started it, so each new decision replaces the entry's pending one instead of stacking // another wave, and connect/unsubscribe/delete can disarm it. reDriveTimer?: ReturnType; + // Bumped on every connect report. The wedge kick claims its entry through `disconnectedAt`, which a + // connect clears; a stalled connection is connected:true with no `disconnectedAt`, so the stall kick + // needs its own claim or a leg that drops and reconnects inside its stagger window gets force-reconnected + // on the strength of the old socket's watermark. + connectGeneration?: number; lastRecovery?: { mechanism: string; at: number }; lastTruthCorrection?: { direction: 'down' | 'up'; at: number }; }; @@ -287,10 +292,9 @@ export function dispatchSubscriptionNodes( /** * Send the subscribe-to-node the scheduler armed. The entry can have been unsubscribed, deleted, or * reassigned to another worker during the (now up to 30s) wait, so ownership is re-checked against - * live state and the message goes to the entry's current worker. A pair that connected in the - * meantime has already had this setup cancelled by `noteConnected`; we deliberately do not re-check - * `connected` here, because a re-subscribe after an unsubscribe is legitimately scheduled while the - * closing connection still reads connected:true. + * live state and the message goes to the entry's current worker. `connected` is deliberately NOT + * re-checked: a re-subscribe after an unsubscribe is legitimately scheduled while the closing connection + * still reads connected:true, and a redundant subscribe on a live connection is a no-op reuse. */ function dispatchSubscribeSetup(url: string, database: string, nodes: any[]) { const entry = connectionReplicationMap.get(url)?.get(database); @@ -996,8 +1000,8 @@ export async function startOnMainThread(options) { } if (existingEntry) { worker = existingEntry.worker; - // This array becomes `entry.nodes`, which the wedge re-drive posts from, and isLeader is only - // decided on the scheduling path below — carry it forward or the re-drive loses it. + // isLeader is decided on the scheduling path below, and this array becomes `entry.nodes`, which + // the wedge re-drive posts from. nodes[0].isLeader = nodes[0].isLeader || existingEntry.nodes?.[0]?.isLeader; existingEntry.nodes = nodes; // Normally an existing subscribed entry is left alone. Only the wedge reconcile passes @@ -1111,8 +1115,8 @@ export async function startOnMainThread(options) { // Keep the entry for URL/iterator cleanup, but bypass the reuse fast path after an // explicit unsubscribe so restoring membership can schedule subscribe-to-node again. if (existingEntry) existingEntry.unsubscribed = true; - // A setup armed for this pair can be up to 30s from firing, and would re-subscribe right - // after the worker was told to unsubscribe. Same for a recovery kick. + // An armed setup can be up to 30s from firing, and would re-subscribe right after the worker was + // told to unsubscribe. Same for a recovery kick. subscribeSetupScheduler.cancel(getNodeURL(node), databaseName); if (existingEntry) { clearTimeout(existingEntry.reDriveTimer); @@ -1229,9 +1233,9 @@ export async function startOnMainThread(options) { return; } mainWorkerEntry.connected = true; - // Real progress for this pair, so the escalated setup delay goes back to its first ceiling. The - // pending setup and the armed recovery are left alone: both re-check live state when they fire, and - // a connect report cannot be attributed to the worker that armed them. + mainWorkerEntry.connectGeneration = (mainWorkerEntry.connectGeneration ?? 0) + 1; + // Real progress for this pair, so the escalated setup delay goes back to its first ceiling. Nothing is + // cancelled here — see noteConnected. subscribeSetupScheduler.noteConnected(connection.url, connection.database); mainWorkerEntry.disconnectedAt = undefined; mainWorkerEntry.latency = connection.latency; @@ -1522,8 +1526,10 @@ export async function startOnMainThread(options) { entry.lastRecovery = { mechanism: 'receive-stall-net', at: now }; // Throttle clock so this entry is not re-kicked until the threshold elapses again. entry.receiveStallReconnectAt = now; - // Watermark this decision was made against, so progress arriving during the delay cancels it. + // Watermark this decision was made against, so progress arriving during the delay cancels it, + // and the connect generation so a reconnect inside the delay does too. const stalledAtWatermark = getReceiveStatus(databaseName, nodes[0]?.name)?.lastReceivedTime; + const stalledAtGeneration = entry.connectGeneration ?? 0; const request = { ...nodes[0], type: 'force-reconnect-node', @@ -1537,6 +1543,9 @@ export async function startOnMainThread(options) { // receiveStallReconnectAt owns the kick from then on. if (entries?.get(databaseName) !== entry || entry.receiveStallReconnectAt !== now) return; if (entry.unsubscribed) return; + // The leg reconnected inside the stagger window: the fresh socket has received nothing yet, + // so the watermark below cannot tell it from the stall this kick was armed for. + if ((entry.connectGeneration ?? 0) !== stalledAtGeneration) return; // A stagger that runs long enough for the copy to resume makes this kick a reconnect of a // healthy connection; the watermark is the only thing that distinguishes the two. const current = getReceiveStatus(databaseName, nodes[0]?.name)?.lastReceivedTime; From 537835b601c171ee5dfd58411053e0bc7d5fea10 Mon Sep 17 00:00:00 2001 From: Kris Zyp Date: Wed, 2 Sep 2026 10:28:11 -0600 Subject: [PATCH 11/13] Hand the stall throttle back when a reconnect cancels the kick MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit entry.receiveStallReconnectAt both claims the armed kick and throttles re-detection, which needs lastReceivedTime past the stamp. Skipping the kick because the leg reconnected inside the stagger window therefore spent an epoch on a kick that never happened: if the fresh socket stalled too it never moved the watermark past the stamp and the receive-stall net never re-armed for that (peer, database) again. The decision moves into shouldFireStallKick — a pure helper with the arm/bump/fire cases under test, which is what the guard shipped without. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01HEgBi5zh8QKMbFmeGwFv7w --- replication/DESIGN.md | 5 +- replication/subscriptionManager.ts | 50 +++++++++----- .../replication/shouldFireStallKick.test.mjs | 69 +++++++++++++++++++ 3 files changed, 105 insertions(+), 19 deletions(-) create mode 100644 unitTests/replication/shouldFireStallKick.test.mjs diff --git a/replication/DESIGN.md b/replication/DESIGN.md index 7a154f210..59bfe4634 100644 --- a/replication/DESIGN.md +++ b/replication/DESIGN.md @@ -152,7 +152,10 @@ is what let a chaos-restart peer's setup delay escalate past its reconvergence b the timers armed safe is that each re-checks live state when it fires: the setup re-reads the entry and its `unsubscribed` flag, the wedge kick claims its entry through the `disconnectedAt` stamp a connect clears, and the stall kick claims it through `connectGeneration` (a stalled connection is `connected: true` with no -`disconnectedAt`, so the stamp cannot discriminate for it) plus the receive watermark. +`disconnectedAt`, so the stamp cannot discriminate for it) plus the receive watermark. `shouldFireStallKick` +holds that decision, because the stamp it checks is also the re-detection throttle: a kick skipped because +the leg reconnected has to hand the stamp back, or a fresh socket that stalls too is never detected — its +`lastReceivedTime` can never move past a stamp it never advanced. Their jitter is drawn once per sweep rather than per entry: a per-entry draw would vary consecutive delays by up to ±200 ms and let diff --git a/replication/subscriptionManager.ts b/replication/subscriptionManager.ts index 266027b95..78fb0ae2e 100644 --- a/replication/subscriptionManager.ts +++ b/replication/subscriptionManager.ts @@ -383,6 +383,28 @@ function reportIdentityMismatchOnce(nodes: Array<{ name?: string; url?: string } // Clear a dead worker from every subscription entry it owned, so findStaleNodeUrls re-binds those // entries on a live worker. Pure helper (like findStaleNodeUrls) so its behavior is unit-testable without // real worker threads. Returns whether the worker owned any entries. See harper-pro#357. +// Whether an armed receive-stall kick should still fire, and whether it owes the entry its throttle stamp +// back. `receiveStallReconnectAt` both claims the kick and throttles re-detection (which needs +// `lastReceivedTime` past the stamp), so a decision to skip has to say whether the epoch was actually +// spent: a reconnect inside the stagger window means no kick happened and a fresh socket that stalls too +// must still be detectable, while progress means the stall resolved and the stamp is correct as it stands. +export function shouldFireStallKick(args: { + current: any; + armed: any; + armedAt: number; + armedGeneration: number; + stalledAtWatermark?: number; + currentWatermark?: number; +}): { fire: boolean; releaseThrottle: boolean } { + const { current, armed, armedAt, armedGeneration, stalledAtWatermark, currentWatermark } = args; + if (current !== armed || armed.receiveStallReconnectAt !== armedAt || armed.unsubscribed) + return { fire: false, releaseThrottle: false }; + if ((armed.connectGeneration ?? 0) !== armedGeneration) return { fire: false, releaseThrottle: true }; + if (stalledAtWatermark != null && currentWatermark != null && currentWatermark > stalledAtWatermark) + return { fire: false, releaseThrottle: false }; + return { fire: true, releaseThrottle: false }; +} + export function clearWorkerFromEntries(connectionMap: Map, worker: any): boolean { let owned = false; for (const dbReplicationWorkers of connectionMap.values()) { @@ -1000,8 +1022,6 @@ export async function startOnMainThread(options) { } if (existingEntry) { worker = existingEntry.worker; - // isLeader is decided on the scheduling path below, and this array becomes `entry.nodes`, which - // the wedge re-drive posts from. nodes[0].isLeader = nodes[0].isLeader || existingEntry.nodes?.[0]?.isLeader; existingEntry.nodes = nodes; // Normally an existing subscribed entry is left alone. Only the wedge reconcile passes @@ -1115,8 +1135,6 @@ export async function startOnMainThread(options) { // Keep the entry for URL/iterator cleanup, but bypass the reuse fast path after an // explicit unsubscribe so restoring membership can schedule subscribe-to-node again. if (existingEntry) existingEntry.unsubscribed = true; - // An armed setup can be up to 30s from firing, and would re-subscribe right after the worker was - // told to unsubscribe. Same for a recovery kick. subscribeSetupScheduler.cancel(getNodeURL(node), databaseName); if (existingEntry) { clearTimeout(existingEntry.reDriveTimer); @@ -1234,8 +1252,6 @@ export async function startOnMainThread(options) { } mainWorkerEntry.connected = true; mainWorkerEntry.connectGeneration = (mainWorkerEntry.connectGeneration ?? 0) + 1; - // Real progress for this pair, so the escalated setup delay goes back to its first ceiling. Nothing is - // cancelled here — see noteConnected. subscribeSetupScheduler.noteConnected(connection.url, connection.database); mainWorkerEntry.disconnectedAt = undefined; mainWorkerEntry.latency = connection.latency; @@ -1539,18 +1555,16 @@ export async function startOnMainThread(options) { const delay = reDriveBaseDelay + reconnectCount * RECONNECT_STAGGER_MS; reconnectCount++; entry.reDriveTimer = armReDrive(entry, delay, url, databaseName, () => { - // Same staleness claim as the wedge path: a newer reconcile re-stamping - // receiveStallReconnectAt owns the kick from then on. - if (entries?.get(databaseName) !== entry || entry.receiveStallReconnectAt !== now) return; - if (entry.unsubscribed) return; - // The leg reconnected inside the stagger window: the fresh socket has received nothing yet, - // so the watermark below cannot tell it from the stall this kick was armed for. - if ((entry.connectGeneration ?? 0) !== stalledAtGeneration) return; - // A stagger that runs long enough for the copy to resume makes this kick a reconnect of a - // healthy connection; the watermark is the only thing that distinguishes the two. - const current = getReceiveStatus(databaseName, nodes[0]?.name)?.lastReceivedTime; - if (stalledAtWatermark != null && current != null && current > stalledAtWatermark) return; - worker.postMessage(request); + const verdict = shouldFireStallKick({ + current: entries?.get(databaseName), + armed: entry, + armedAt: now, + armedGeneration: stalledAtGeneration, + stalledAtWatermark, + currentWatermark: getReceiveStatus(databaseName, nodes[0]?.name)?.lastReceivedTime, + }); + if (verdict.releaseThrottle) entry.receiveStallReconnectAt = undefined; + if (verdict.fire) worker.postMessage(request); }); } if (reconnectCount > 0) diff --git a/unitTests/replication/shouldFireStallKick.test.mjs b/unitTests/replication/shouldFireStallKick.test.mjs new file mode 100644 index 000000000..a9e06d4fa --- /dev/null +++ b/unitTests/replication/shouldFireStallKick.test.mjs @@ -0,0 +1,69 @@ +/** + * The receive-stall kick is armed under `entry.receiveStallReconnectAt`, which is both its claim on the + * entry and the throttle that gates re-detection (`findStalledReceivingNodeUrls` needs `lastReceivedTime` + * past the stamp). A skip therefore has to say whether the epoch was really spent, or a kick that never + * fired can retire the net for that (peer, database) permanently. + */ + +import assert from 'node:assert'; +import { shouldFireStallKick } from '#src/replication/subscriptionManager'; + +const ARMED_AT = 1_000; + +function makeEntry(overrides = {}) { + return { receiveStallReconnectAt: ARMED_AT, connectGeneration: 3, ...overrides }; +} + +function verdict(entry, overrides = {}) { + return shouldFireStallKick({ + current: entry, + armed: entry, + armedAt: ARMED_AT, + armedGeneration: 3, + stalledAtWatermark: 500, + currentWatermark: 500, + ...overrides, + }); +} + +describe('shouldFireStallKick', () => { + it('fires when the entry is unchanged and no data has arrived', () => { + assert.deepEqual(verdict(makeEntry()), { fire: true, releaseThrottle: false }); + }); + + it('does not fire for a superseded entry, and does not release a stamp it does not own', () => { + const entry = makeEntry(); + assert.deepEqual(verdict(entry, { current: makeEntry() }), { fire: false, releaseThrottle: false }); + }); + + it('does not fire once a newer reconcile re-stamped the throttle', () => { + assert.deepEqual(verdict(makeEntry({ receiveStallReconnectAt: 2000 })), { fire: false, releaseThrottle: false }); + }); + + it('does not fire for an entry that has since unsubscribed', () => { + assert.deepEqual(verdict(makeEntry({ unsubscribed: true })), { fire: false, releaseThrottle: false }); + }); + + // The regression: skipping on a reconnect used to keep the stamp, and a fresh socket that also stalls + // never moves lastReceivedTime past it — so the net never re-armed for that pair again. + it('releases the throttle when the leg reconnected inside the stagger window', () => { + assert.deepEqual(verdict(makeEntry({ connectGeneration: 4 })), { fire: false, releaseThrottle: true }); + }); + + it('treats a missing connectGeneration as generation 0', () => { + const entry = { receiveStallReconnectAt: ARMED_AT }; + assert.deepEqual(verdict(entry, { armedGeneration: 0 }), { fire: true, releaseThrottle: false }); + assert.deepEqual(verdict(entry, { armedGeneration: 1 }), { fire: false, releaseThrottle: true }); + }); + + // Progress means the stall resolved on its own: no kick is owed and the stamp correctly records the + // epoch, so it must NOT be released. + it('does not fire, or release, when the watermark advanced', () => { + assert.deepEqual(verdict(makeEntry(), { currentWatermark: 900 }), { fire: false, releaseThrottle: false }); + }); + + it('fires when either watermark is unavailable', () => { + assert.deepEqual(verdict(makeEntry(), { currentWatermark: undefined }), { fire: true, releaseThrottle: false }); + assert.deepEqual(verdict(makeEntry(), { stalledAtWatermark: undefined }), { fire: true, releaseThrottle: false }); + }); +}); From 7f3431df3a96c157d604f06ae1a8e63edc4b4903 Mon Sep 17 00:00:00 2001 From: Kris Zyp Date: Wed, 2 Sep 2026 10:37:00 -0600 Subject: [PATCH 12/13] Put shouldFireStallKick below the function its description sat above Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01HEgBi5zh8QKMbFmeGwFv7w --- replication/subscriptionManager.ts | 44 +++++++++---------- .../replication/shouldFireStallKick.test.mjs | 7 --- 2 files changed, 22 insertions(+), 29 deletions(-) diff --git a/replication/subscriptionManager.ts b/replication/subscriptionManager.ts index 78fb0ae2e..0d1de1e8a 100644 --- a/replication/subscriptionManager.ts +++ b/replication/subscriptionManager.ts @@ -383,28 +383,6 @@ function reportIdentityMismatchOnce(nodes: Array<{ name?: string; url?: string } // Clear a dead worker from every subscription entry it owned, so findStaleNodeUrls re-binds those // entries on a live worker. Pure helper (like findStaleNodeUrls) so its behavior is unit-testable without // real worker threads. Returns whether the worker owned any entries. See harper-pro#357. -// Whether an armed receive-stall kick should still fire, and whether it owes the entry its throttle stamp -// back. `receiveStallReconnectAt` both claims the kick and throttles re-detection (which needs -// `lastReceivedTime` past the stamp), so a decision to skip has to say whether the epoch was actually -// spent: a reconnect inside the stagger window means no kick happened and a fresh socket that stalls too -// must still be detectable, while progress means the stall resolved and the stamp is correct as it stands. -export function shouldFireStallKick(args: { - current: any; - armed: any; - armedAt: number; - armedGeneration: number; - stalledAtWatermark?: number; - currentWatermark?: number; -}): { fire: boolean; releaseThrottle: boolean } { - const { current, armed, armedAt, armedGeneration, stalledAtWatermark, currentWatermark } = args; - if (current !== armed || armed.receiveStallReconnectAt !== armedAt || armed.unsubscribed) - return { fire: false, releaseThrottle: false }; - if ((armed.connectGeneration ?? 0) !== armedGeneration) return { fire: false, releaseThrottle: true }; - if (stalledAtWatermark != null && currentWatermark != null && currentWatermark > stalledAtWatermark) - return { fire: false, releaseThrottle: false }; - return { fire: true, releaseThrottle: false }; -} - export function clearWorkerFromEntries(connectionMap: Map, worker: any): boolean { let owned = false; for (const dbReplicationWorkers of connectionMap.values()) { @@ -432,6 +410,28 @@ export function clearWorkerFromEntries(connectionMap: Map stalledAtWatermark) + return { fire: false, releaseThrottle: false }; + return { fire: true, releaseThrottle: false }; +} export function findStaleNodeUrls(connectionMap: Map, httpWorkers: any[]): Set { const staleNodeUrls = new Set(); // No live workers to reassign to — flagging here would cause endless no-op reassignments. diff --git a/unitTests/replication/shouldFireStallKick.test.mjs b/unitTests/replication/shouldFireStallKick.test.mjs index a9e06d4fa..a86fe7b55 100644 --- a/unitTests/replication/shouldFireStallKick.test.mjs +++ b/unitTests/replication/shouldFireStallKick.test.mjs @@ -1,10 +1,3 @@ -/** - * The receive-stall kick is armed under `entry.receiveStallReconnectAt`, which is both its claim on the - * entry and the throttle that gates re-detection (`findStalledReceivingNodeUrls` needs `lastReceivedTime` - * past the stamp). A skip therefore has to say whether the epoch was really spent, or a kick that never - * fired can retire the net for that (peer, database) permanently. - */ - import assert from 'node:assert'; import { shouldFireStallKick } from '#src/replication/subscriptionManager'; From a5b6aa055105cc338d2a5d15099c324ac1db2bdc Mon Sep 17 00:00:00 2001 From: Kris Zyp Date: Wed, 2 Sep 2026 10:56:13 -0600 Subject: [PATCH 13/13] Resolve the node URL from one map lookup Addresses the Gemini review comment on #800. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01HEgBi5zh8QKMbFmeGwFv7w --- replication/subscriptionManager.ts | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/replication/subscriptionManager.ts b/replication/subscriptionManager.ts index 0d1de1e8a..09c3726cc 100644 --- a/replication/subscriptionManager.ts +++ b/replication/subscriptionManager.ts @@ -933,7 +933,8 @@ export async function startOnMainThread(options) { } // A node that moved to a new URL leaves its old URL's entry behind (pre-existing); at least do // not let a setup armed for the address it left fire against it. - const previousUrl = nodeMap.get(node.name) && getNodeURL(nodeMap.get(node.name)); + const previousNode = nodeMap.get(node.name); + const previousUrl = previousNode && getNodeURL(previousNode); if (previousUrl && previousUrl !== getNodeURL(node)) subscribeSetupScheduler.cancelUrl(previousUrl); nodeMap.set(node.name, node); }