Skip to content

Replication full-copy OOM: per-record audit-chain walk in Table.commit scales with audit-log depth #1114

Description

@kriszyp

Summary

During replication full-copy catch-up, a receiving node can OOM because Table.commit's out-of-order-write reconciliation walks the entire backward audit-history chain for every record synchronously, buffering intermediate records in the JS heap. The cost scales with audit-history depth, and the walk runs concurrently on all HTTP workers, so a database whose replication transaction log has accumulated a large history becomes effectively un-ingestable under a fixed container memory limit.

Observed on harper-pro 5.0.21; the same code path is present on main (v5.1.0-beta.1).

Symptom

  • A follower requesting a full copy of a database crash-loops with the container memory cgroup OOM-killer firing (Killed process … (MainThread) anon-rss ~5.4GB at a 6 GiB limit).
  • Workers log JavaScript execution has taken too long and is not allowing proper event queue cycling during ingestion.
  • The OOM can be masked at the orchestration layer: the in-container supervisor respawns the killed process, so docker ps shows "Up" and RestartCount stays frozen — the kills are only visible via dmesg.

Root cause

Table.commit reconciles out-of-order / incremental writes by walking the record's audit chain (resources/Table.ts:1769-1837):

do {
  while (localTime > txnTime || (auditedVersion >= txnTime && localTime > 0)) {
    const auditRecord = auditStore.get(localTime, tableId, id, nodeId);
    if (!auditRecord) break;
    // …collect succeedingUpdates / additionalAuditRefs…
    localTime = auditRecord.previousVersion;   // walk backward through the version chain
    nodeId = auditRecord.previousNodeId;
  }
  nextRef = auditRefsToVisit.shift();          // then branch into additional audit refs
  if (nextRef) { localTime = auditedVersion = nextRef.localTime; nodeId = nextRef.nodeId; }
} while (nextRef);

Each auditStore.get(localTime, …) lands in RocksTransactionLogStore.getSync, which does a fresh range scan of the transaction log per step (resources/RocksTransactionLogStore.ts:100-112):

getSync(key, tableId, recordId, nodeId) {
  if (typeof key === 'number') {
    for (const entry of this.getRange({ start: key, exactStart: true, log: nodeId })) {
      if (entry.recordId === recordId && entry.tableId === tableId) return entry;
      if (entry.version !== key) return;
    }
  } …
}

Why this OOMs during full-copy:

  1. Cost scales with audit-history depth. A record with a long version history walks the whole chain (plus branches via auditRefsToVisit), with a msgpackr-decode + txnlog scan at each step. During a full-copy of a database with a large accumulated history, this repeats for many records.
  2. Intermediate records are buffered in heap. succeedingUpdates accumulates audit records, and getValue(primaryStore) is later materialized for each.
  3. It is synchronous with no yielding. The loop blocks the event loop ("JS execution too long"), so GC cannot reclaim between commits and the heap grows monotonically.
  4. It runs on all workers at once. A full-copy is ingested across every HTTP worker concurrently, multiplying peak heap by the worker count.

Evidence (live instance)

  • Heap composition (per-worker process.memoryUsage()): memory is JS heap (heapUsed 0.6–1.2 GB on each of 8 workers), not native buffers (external/arrayBuffers ≤ 330 MB). This rules out a single bad-allocation (e.g. txnlog framing) cause.
  • CPU profile of the busiest worker: 79% garbage collector (heap-ceiling death spiral) + msgpackr record decode + rocksdb-js iteration + readAuditEntry/onWSMessage.
  • Live async stacks (consistent across captures): Table.commit → RocksTransactionLogStore.get/getSync → transaction-log-reader iteration, under DatabaseTransaction.commit.

Contributing factor: unbounded system-DB replication log growth

The trigger in the observed case was the system database's per-peer replication transaction log growing to ~2 GB on the follower (and ~1 GB on the leader) while the actual system data was only ~250 MB. The leader's own-origin (local) system log was only ~25 MB, so the growth is in the per-peer replication logs, not genuine local writes — suggesting a retention/pruning gap and/or a write-amplification feedback loop (a persistent invalid user role found error storm accompanied it). Even if the audit-walk is made memory-safe, the unbounded replication-log growth is worth investigating separately.

Suggested fix directions

  • Make the audit-chain walk in Table.commit memory-safe: yield to the event loop and/or cap/stream succeedingUpdates so a deep history doesn't pin the heap, and let GC run between commits.
  • Avoid ingesting a full-copy concurrently on all workers (or bound concurrency) to cap peak heap.
  • Investigate why the system-DB per-peer replication transaction log grows unbounded (retention/compaction and the role-reconciliation feedback loop).

Workaround

Temporarily raising the container memory limit (e.g. 6 → 12 GiB) lets the full-copy complete once; steady-state then fits. This is mitigation, not a fix.

Activity

  1. kriszyp commented on Jun 3, 2026

    @kriszyp
    MemberAuthor

    The unbounded system-DB log growth referenced under "Contributing factor" now has its own issue: #1115 (hdb_analytics is audit: true, replicating per-node telemetry cluster-wide). That growth is the volume that makes this audit-walk OOM fatal during full-copy re-sync.

  2. self-assigned this
    on Jun 3, 2026
  3. kriszyp commented on Jun 8, 2026

    @kriszyp
    MemberAuthor

    Proposal: move write de-duplication to the replication ingest layer; simplify full-copy to LWW-merge

    Context: investigation with @kriszyp into whether the duplicate-detection burden in Table.commit (the capped out-of-order walk from #1116/#1122, plus the #1137/#1147 follow-ups) can move to the replication layer, leaving Table.ts to focus on CRDT reconciliation. Trace of harper-pro/replication/* + harper/resources/Table.ts below, then a concrete design.

    What the trace established

    1. Full-copy sends only synthetic puts, never patches — it iterates primaryStore.getRange({ versions: true }) and emits type:'put', previousVersion:null, with origin rewritten to the sender (replicationConnection.ts:1461-1516). Puts don't accumulate, so full-copy itself can't double-apply a commutative op. The re-delivered commutative patch in Unit test red on main: 're-delivered duplicate must not double-apply the commutative op' (v22 + v26) #1137 arrives via the steady-state audit stream that follows (overlap/resume window) or via transitive relay — both carry (originNodeId, version) at the receiver before dispatch (replicationConnection.ts:1646-1696).

    2. Replication full-copy OOM: per-record audit-chain walk in Table.commit scales with audit-log depth #1114's OOM is the out-of-order fold walking the receiver's deep local audit chain when a full-copy put lands older than local head (Table.ts:1738-1898; the walk seeds from existingEntry.localTime and scans backward).

    3. A durability asymmetry constrains where dedup state may live. dbisDb is RocksDB-WAL-durable (immediate); the primary store's durability is Harper's txn log (separate mechanism). So a dedup mark placed in dbisDb can outlive the data it guards — on crash the mark says "seen" while the write is gone and is never re-requested → silent loss. Dedup state must be no more durable than the data: derived from the primary/txn-log domain and co-committed (the atomic-CF-write flag gives the atomicity), or read-your-writes against the record. This is also why fix(table): reliably skip a re-delivered out-of-order commutative op (#1137) #1147's record-based additionalAuditRefs check works where the auditStore.get(txnTime) lookup lags (Transaction-log point reads (RocksTransactionLogStore) intermittently miss visible entries, breaking out-of-order duplicate detection #1148).

    4. Exclusion is node-granular, not a windowed partition (replicationConnection.ts:2110-2137, filter at :1151-1158). The transitive case (A⊂B,C; B,C⊂D) yields duplicates, not gaps — A receives D's full stream from both B and C, each gap-free and in D's order. Genuine gaps only on (a) time-window boundaries (not currently constructed) and (b) topology-change handoffs, where gap-freeness rests on the proxy seq-tracking (nodes[] in the seq entry — Table.ts:425-438, replicationConnection.ts:2069-2089).

    Proposal

    A. Ingest-layer de-duplication, keyed on (originNodeId, version).
    At the receiver, before dispatch (replicationConnection.ts:1646-1696), drop already-applied writes. State lives in the primary/txn-log durability domain, co-committed with the record (not dbisDb). Because mark and value revert together on crash, this is safe even for non-idempotent commutative ops.

    B. Full-copy: lose-on-tie + merge-when-older (keep the merge).

    C. Drop the per-record receiver-side audit entry for full-copy; leave a single boundary marker.
    Full-copy records become durable via flush + re-fetch-from-leader (lose-on-tie makes re-sync idempotent), so the per-record txn-log entry is unnecessary — a large write-amplification cut on catch-up (#1114). But incremental relay reads the audit log (replicationConnection.ts:1547-1557), so dropping the entries outright would silently gap a downstream resuming from before the full-copy. Mitigate with one full-copy boundary marker in the audit log: a downstream whose resume point is below it must re-bootstrap (full-copy) rather than incremental; above it streams normally. Keeps the savings; keeps relay correct.

    Net

    Open questions / follow-ups

    1. Handoff gap-freeness — confirm the proxy nodes[] seq-tracking guarantees a new direct path resumes at-or-before where the relayed path stopped. This is the one place a gap (→ data loss) could hide, and it's the same invariant the existing resume watermark already trusts.
    2. Boundary-marker semantics for relay re-bootstrap (per-table vs per-db; interaction with residency).
    3. Co-commit mechanics for the dedup contiguity state in the primary domain.

    Relationship to existing work: builds on #1116/#1122 (the cap), supersedes the #1147 approach for #1137, implements #1115's primary fix, and makes #1148 non-blocking for correctness.

    — Claude (investigation with Kris)

  4. kriszyp commented on Jun 16, 2026

    @kriszyp
    MemberAuthor

    Live-production confirmation on eh-prod.gend + root cause of the event-loop stalls

    Investigated this on the eh-prod.gend cluster (node 7rg-us-west-1, harper-pro 5.1.1), where the symptom presented as replication ping-timeouts / wedged subscriptions rather than OOM. The depth cap added for this issue stops the OOM, but the synchronous walk itself stalls the event loop (steady JavaScript execution has taken too long warnings + Timeout waiting for ping → terminated replication connections). Captured the live mechanism with a non-pausing logpoint at the depth-cap site (Table.js:1902).

    What the walk is actually doing (logpoint evidence)

    Every capped event looked like:

    id=<...norton.com/blog/...>  depth=1001  type=patch  fullUpdate=false
    addRefs=0  toVisit=0  succ=858–1000   srcNode=4|8|9  viaNodeId=<set>
    dupFound=true  dupVerMatch=true  dupNode===srcNode
    

    Reading that off:

    • It's a genuine deep linear chain, not ref fan-out. additionalAuditRefs/auditRefsToVisit are empty (addRefs=0, toVisit=0); the depth is almost entirely succeedingUpdates = 858–1000. The records are high-churn pages updated exclusively via patch (scheduled lastRefresh/nextRefresh bumps), so there's no put in history to short-circuit the walk on.
    • The triggering writes are out-of-order re-deliveries via transitive replication. type=patch, older than the current record head (they reach the precedesExisting <= 0 block and walk ~1000 steps without finding a head-tie), and every one carries viaNodeId — relayed through a proxy node.
    • They are pure duplicates. The post-cap keyed lookup auditStore.get(txnTime, tableId, id, nodeId) returns a matching (version, nodeId) entry (dupVerMatch=true, dupNode===srcNode). So the write was already applied; the walk burns ~1000 synchronous steps only to discard it.

    Why PR #370 (leading-duplicate fast-skip) doesn't cover it

    Two reasons:

    1. It deliberately doesn't arm for proxied/indirect subscriptions. hasPersistedResumeCursor checks the direct sequence cursor only, and the arming code explicitly leaves a proxy-derived resume un-armed. All the re-deliveries here arrive via viaNodeId (proxy), so the fast-skip never engages.
    2. Even if armed, its tie check is against the record head (existing.version === incomingVersion). These re-deliveries are older than the head (the head advanced via other paths before the proxied copy arrived), so they're buried-history matches, not head-ties — the head-tie check can't catch them regardless of arming.

    Proposed fix (primary)

    Hoist the keyed duplicate lookup to before the resequencing walk. The cap block already does auditStore.get(txnTime, tableId, id, options?.nodeId) and we've confirmed it identifies these as exact (version, nodeId) duplicates — it's just invoked after the ~1000-step walk. Doing that O(1) keyed lookup up front (for the precedesExisting <= 0 replicated path, with the same precedesExistingVersion(...) === 0 identity-tie guard) short-circuits the re-delivery before the walk. It is keyed by nodeId, so it is inherently multi-source — no single node can "break" it. A miss simply falls through to today's walk, so there is no correctness change; the existing keyed-lookup-can-miss-under-load caveat only costs us the optimization, never correctness.

    Follow-ups (separate tickets)

    • Reduce the volume of transitive re-deliveries. The proxy-resume start-time derivation re-streams an already-applied tail when the proxied seq cursor isn't relayed/persisted tightly. Worth a separate investigation to cut re-deliveries at the source (the dedup fix above cheaply absorbs them; this would stop generating them).
    • Extend Add loadComponent config option for conditional package loading #370 arming to proxied subscriptions — a cheaper still earlier skip for the in-order proxied subset (complementary; does not replace the core hoist, which is what covers the out-of-order case observed here).
    • Record-level LWW for full-copy base frames — separate ticket (ref harper-pro feat: expose urlPath in deploy_component operation and CLI #1113); orthogonal to this, since the cap walks here are relayed patches, not copy base puts.

    Implementing the primary fix now.

    Investigation + writeup by Claude (Opus 4.8) via the fabric-investigation workflow.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

No labels
No labels

Type

No type

Fields

Priority

None yet

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions