Repository navigation
fix(replication): fail loud on oversized replication frame instead of silent data loss #713
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,96 @@ | ||
| /** | ||
| * Integration test: an oversized replication transaction must not be silently skipped. | ||
| * | ||
| * The production failure (harper-pro#711) was permanent data loss: a queued transaction larger than | ||
| * replication_maxPayload was dropped with a bare `return`, and later transactions kept advancing the | ||
| * peer's resume cursor past it. The fix throws instead, which closes the leg so it resumes from the | ||
| * un-advanced cursor. This pins the cursor-safety invariant: once a transaction is too large to send, | ||
| * NO later transaction is delivered ahead of it. | ||
| * | ||
| * Setup: a small maxPayload on the source. Write a normal record (delivered), then an oversized record | ||
| * (wedges the send leg), then another normal record. The follower must have the first record but NOT | ||
| * the third. On base (silent drop) the third arrives while the oversized one is lost, so this fails. | ||
| * | ||
| * Keys are ordered k1 < k2 (oversized) < k3 so that neither delivery path can hand out the later record | ||
| * early: a wedged leg reconnects into a key-ordered full copy, so k3 sorting AFTER the oversized k2 | ||
| * (rather than alphabetically before it) is what makes its absence a real cursor-safety signal. | ||
| */ | ||
| import { suite, test, before, after } from 'node:test'; | ||
| import { equal, ok } from 'node:assert/strict'; | ||
| import { setTimeout as delay } from 'node:timers/promises'; | ||
| import { startHarper, teardownHarper, getNextAvailableLoopbackAddress } from '@harperfast/integration-testing'; | ||
| import { join } from 'node:path'; | ||
| import { sendOperation } from './clusterShared.mjs'; | ||
|
|
||
| process.env.HARPER_INTEGRATION_TEST_INSTALL_SCRIPT = join(import.meta.dirname ?? module.path, '..', '..', 'dist', 'bin', 'harper.js'); | ||
|
|
||
| const MAX_PAYLOAD = 512 * 1024; // 512 KiB send cap | ||
| const OVERSIZED_BYTES = 1024 * 1024; // 1 MiB value -> transaction frame exceeds the cap | ||
|
|
||
| suite('oversized replication transaction does not skip later transactions', { timeout: 180000 }, (ctx) => { | ||
| before(async () => { | ||
| const hostnameA = await getNextAvailableLoopbackAddress(); | ||
| const hostnameB = await getNextAvailableLoopbackAddress(); | ||
| const makeNodeCtx = (hostname) => ({ name: ctx.name, harper: { hostname } }); | ||
| const commonConfig = (hostname) => ({ | ||
| config: { | ||
| analytics: { aggregatePeriod: -1 }, | ||
| logging: { colors: false, stdStreams: false, console: true }, | ||
| replication: { port: hostname + ':9933', securePort: null, databases: ['data'], maxPayload: MAX_PAYLOAD }, | ||
| }, | ||
| env: { HARPER_NO_FLUSH_ON_EXIT: true }, | ||
| }); | ||
| const ctxA = makeNodeCtx(hostnameA); | ||
| const ctxB = makeNodeCtx(hostnameB); | ||
| await Promise.all([startHarper(ctxA, commonConfig(hostnameA)), startHarper(ctxB, commonConfig(hostnameB))]); | ||
| ctx.nodeA = ctxA.harper; | ||
| ctx.nodeB = ctxB.harper; | ||
|
|
||
| await sendOperation(ctx.nodeA, { operation: 'create_table', database: 'data', table: 'oversized_test', primary_key: 'id' }); | ||
| // Establish replication before any oversized write, so the base copy (small) is unaffected. | ||
| await sendOperation(ctx.nodeB, { | ||
| operation: 'add_node', | ||
| hostname: ctx.nodeA.hostname, | ||
| rejectUnauthorized: false, | ||
| isLeader: true, | ||
| authorization: ctx.nodeA.admin, | ||
| }); | ||
| }); | ||
|
|
||
| after(async () => { | ||
| await Promise.all([ctx.nodeA && teardownHarper({ harper: ctx.nodeA }), ctx.nodeB && teardownHarper({ harper: ctx.nodeB })]); | ||
| }); | ||
|
|
||
| test('the follower receives the pre-oversized record but not the one queued behind it', async () => { | ||
| const { nodeA, nodeB } = ctx; | ||
| const hasId = async (id) => | ||
| ((await sendOperation(nodeB, { | ||
| operation: 'search_by_value', | ||
| database: 'data', | ||
| table: 'oversized_test', | ||
| search_attribute: 'id', | ||
| search_value: id, | ||
| get_attributes: ['id'], | ||
| }).catch(() => [])) ?? []).length > 0; | ||
|
|
||
| // A normal record, delivered normally before the wedge. | ||
| await sendOperation(nodeA, { operation: 'upsert', database: 'data', table: 'oversized_test', records: [{ id: 'k1_before', v: 'x' }] }); | ||
| for (let i = 0; i < 60 && !(await hasId('k1_before')); i++) await delay(500); | ||
| ok(await hasId('k1_before'), 'the pre-oversized record must replicate normally'); | ||
|
|
||
| // An oversized transaction: too large to send, so the leg wedges on it. | ||
| await sendOperation(nodeA, { | ||
| operation: 'upsert', | ||
| database: 'data', | ||
| table: 'oversized_test', | ||
| records: [{ id: 'k2_oversized', v: 'x'.repeat(OVERSIZED_BYTES) }], | ||
| }); | ||
| // A later normal transaction: must NOT be delivered ahead of the wedged one. | ||
| await sendOperation(nodeA, { operation: 'upsert', database: 'data', table: 'oversized_test', records: [{ id: 'k3_after', v: 'x' }] }); | ||
|
|
||
| // Give the leg ample time to (wrongly, on base) skip and deliver 'after'. | ||
| await delay(10000); | ||
| equal(await hasId('k3_after'), false, 'a transaction queued behind an oversized one must not be delivered'); | ||
| equal(await hasId('k2_oversized'), false, 'the oversized transaction itself cannot be sent under this cap'); | ||
| }); | ||
| }); |
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -236,6 +236,20 @@ | |
| } | ||
|
|
||
| const MAX_PAYLOAD = env.get('replication_maxPayload') ?? 100_000_000; | ||
| // Flush a bulk-copy batch once it approaches the payload cap, so a run of large rows can't assemble a | ||
| // single oversized frame (harper-pro#711) that would throw and wedge the copy with no operator escape | ||
| // (existing rows can't be split). Leaves headroom for the in-progress record; a single row above this | ||
| // still relies on raising replication_maxPayload. | ||
| const COPY_FLUSH_BYTES = Math.floor(MAX_PAYLOAD * 0.9); | ||
|
|
||
| // Pure oversized-frame predicate, extracted so it is unit-testable (the frameWriter/copyFlushPacer | ||
| // pattern, harper-pro#440). A frame at exactly the cap is allowed; only a strictly larger one is rejected. | ||
| export function exceedsMaxPayload(messageSize: number, maxPayload: number = MAX_PAYLOAD): boolean { | ||
| return messageSize > maxPayload; | ||
| } | ||
| // Throttle the oversized-send error: it closes and reconnects the leg, so it would otherwise re-log on | ||
| // every reconnect cycle. Module-level so the throttle survives across the per-cycle connection instances. | ||
| const oversizedSendWarnThrottle = createThrottleState(); | ||
| // When receiving a replication message, we apply per-record backpressure to keep a single | ||
| // large batch from synchronously decoding thousands of records and ballooning the worker | ||
| // heap past its limit. If the local replicator queue grows beyond this threshold we pause | ||
|
|
@@ -831,7 +845,7 @@ | |
| logger.warn?.(`[test] forcing open-but-idle replication wedge for db "${databaseName}" (harper-pro#420)`); | ||
| ws.terminate = () => {}; | ||
| ws.close = () => {}; | ||
| ws._socket?.pause(); | ||
|
Check failure on line 848 in replication/replicationConnection.ts
|
||
| return true; // tell the watchdog to treat this connection's byte count as frozen | ||
| } | ||
|
|
||
|
|
@@ -2056,6 +2070,10 @@ | |
| noDelay: true, // we want to send the data immediately | ||
| // we set this very high (2x times the v22 default) because it performs better | ||
| highWaterMark: 128 * 1024, | ||
| // Match the server's accept cap (replicator.ts) so the configurable send guard (replication_maxPayload) | ||
| // is the binding limit on client-initiated legs too. Otherwise ws defaults to 100 MiB here, just under | ||
| // the 100 MB send default, and raising replication_maxPayload to clear a wedge would hit a silent 1009. | ||
| maxPayload: 10 * 1024 * 1024 * 1024, | ||
| rejectUnauthorized: rejectUnauthorized !== false, | ||
| secureContext: undefined, | ||
| }; | ||
|
|
@@ -2189,8 +2207,9 @@ | |
| this.socket._socket.unref(); | ||
| // in normal startup, just use info, but adjust log level to warn if we were previously disconnected, because there was a warn message on the disconnect and we want to keep symmetry | ||
| logger[this.isConnected ? 'info' : 'warn']?.(`Connected to ${this.url}, db: ${this.databaseName}`); | ||
| this.retries = 0; | ||
| this.retryTime = INITIAL_RETRY_TIME; | ||
| // Reset backoff on first successful SEND (onFrameSent), not here on open: a leg that reopens and | ||
| // immediately fails to send (an oversized frame throws and closes it) must keep escalating toward | ||
| // the 30 s cap instead of hot-looping at 500 ms and accumulating native TLS state (harper-pro#339). | ||
| // if we have already connected, we need to send a reconnected event | ||
| if (this.nodeSubscriptions) { | ||
| connectedToNode({ | ||
|
|
@@ -2331,6 +2350,14 @@ | |
| // Doubling reaches 30 s in ~6 retries (~62 s total) and resets on success. | ||
| this.retryTime = Math.min(this.retryTime << 1, 30_000); | ||
| } | ||
| // 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) { | ||
| this.retries = 0; | ||
| this.retryTime = INITIAL_RETRY_TIME; | ||
| } | ||
| } | ||
| // Retire the live replicateOverWS instance: the single enforcement point for "at most one live session | ||
| // per connection". Every path that supersedes a session (socket replaced in connect(), forceReconnect) | ||
| // calls this; the socket's own 'close' does the same teardown through retireInstance, which is | ||
|
|
@@ -4623,8 +4650,15 @@ | |
| const sendQueuedData = () => { | ||
| if (frame.position - frame.encodingStart > 8) { | ||
| // if we have more than just a txn time, send it | ||
| if (checkExcessMessageSize(frame.position - frame.encodingStart)) return; | ||
| // Throw, don't return: a silent return skips this transaction while later ones | ||
|
cb1kenobi marked this conversation as resolved.
|
||
| // keep advancing the peer's resume cursor past it, losing it permanently. Throwing | ||
| // closes the leg so it resumes from the un-advanced cursor (as the blob path does). | ||
| if (checkExcessMessageSize(frame.position - frame.encodingStart)) | ||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Could we add a regression test for this cursor-safety path? Configure a small replication payload cap, send an oversized transaction followed by another transaction, then verify that reconnect/replay delivers both rather than advancing past the rejected one. The production failure here was permanent data loss, and the current change has no coverage of the throw → close → resume chain. — KrAIs (Codex)
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Added in 367988f: Fails on base (the silent Lavinia, via Claude
cb1kenobi marked this conversation as resolved.
|
||
| throw new Error('Replication message too large to send'); | ||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. High: this close reconnects every ~500 ms forever — the backoff never engages The throw reaches the The PR body's "the leg cycles with a logged error" understates this; the trade-off being accepted is a hot loop, not a quiet hold. Suggested fix: gate the backoff reset on progress rather than on —
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Fixed in 367988f. Moved the backoff reset off socket Rig-verified: the wedged leg's reconnects widened (~500 ms → ~8 s → ~16 s) instead of hot-looping at 500 ms. Also throttled Lavinia, via Claude
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Medium: the invariant has a bypass — The throw here correctly keeps the cursor pinned on this path, because the
ws.send(encode([SEQUENCE_ID_UPDATE, currentSequenceId]));That is a direct
Worth being clear about scope: this path is pre-existing (blame Confidence: I traced every line involved, but did not reproduce the race — it needs a skip to arm the timer plus >300 ms of accumulation. Your new integration test cannot catch it as written: with Suggested fix: suppress the skip update while a frame is pending — — |
||
| ws.send(frame.encodingBuffer.subarray(frame.encodingStart, frame.position)); | ||
| // A frame actually went out: tell the outbound connection so it can reset its reconnect | ||
| // backoff on genuine progress rather than on bare socket-open (harper-pro#339). | ||
| options.connection?.onFrameSent?.(); | ||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. High: I verified this on a live two-node rig rather than by reading: I instrumented this exact call site in the built The reason is structural. The consequence is larger than the oversized-frame case, because this PR also removed the
The hot-loop from my earlier comment is genuinely gone, but by deletion rather than by this mechanism — so the fix reads as targeted while actually being unconditional. Suggested fix: drive the reset from a signal the leg holding the backoff can observe. The subscriber side is the one with the — |
||
| logger.debug?.(connectionId, 'Sent message, size:', frame.position - frame.encodingStart); | ||
| if (databaseName !== 'system') { | ||
| recordAction( | ||
|
|
@@ -4948,7 +4982,8 @@ | |
| // naturally above; this also bounds same-version bulk data into committable batches.) The | ||
| // watermark is only advanced to copyStartTime by the single end_txn after the whole copy. | ||
| if ( | ||
| ++recordsSinceCheckpoint >= COPY_CHECKPOINT_RECORDS && | ||
| (++recordsSinceCheckpoint >= COPY_CHECKPOINT_RECORDS || | ||
| frame.position - frame.encodingStart >= COPY_FLUSH_BYTES) && | ||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Medium: the byte checkpoint is evaluated after the record is appended, so a run of large rows still assembles an oversized frame This is the right idea and it does fix the harper-pro#711 repro (1200 x 100 KB), but the threshold is checked once the record is already in the frame. Concretely at the 100 MB default: rows of ~60 MB each accumulate to 60 MB (below the 90 MB threshold, no flush), then the next append takes the frame to 120 MB — which exceeds That makes the PR body's caveat narrower than the actual behavior: it says a single row above the cap still needs Suggested fix: flush before appending when the incoming record would not fit — i.e. check — |
||
| frame.position - frame.encodingStart > 8 | ||
| ) { | ||
| recordsSinceCheckpoint = 0; | ||
|
|
@@ -6654,16 +6689,19 @@ | |
| }; | ||
|
|
||
| function checkExcessMessageSize(messageSize) { | ||
| if (messageSize > MAX_PAYLOAD) { | ||
| logger.error?.( | ||
| connectionId, | ||
| 'Message too large to send, size:', | ||
| messageSize, | ||
| 'remote node:', | ||
| remoteNodeName, | ||
| 'database:', | ||
| databaseName | ||
| ); | ||
| if (exceedsMaxPayload(messageSize)) { | ||
| const { emit, suppressedCount } = decideThrottledWarn(oversizedSendWarnThrottle, Date.now()); | ||
| if (emit) | ||
| logger.error?.( | ||
| connectionId, | ||
| 'Message too large to send, size:', | ||
| messageSize, | ||
| 'remote node:', | ||
| remoteNodeName, | ||
| 'database:', | ||
| databaseName, | ||
| suppressedCount ? `(${suppressedCount} suppressed)` : '' | ||
| ); | ||
| return true; | ||
| } | ||
| } | ||
|
|
||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,30 @@ | ||
| /** | ||
| * Coverage for `exceedsMaxPayload` — the pure oversized-frame predicate extracted from the connection | ||
| * closure (harper-pro#711 review) so the send-or-throw decision can be pinned without a live socket. The | ||
| * boundary is inclusive: a frame at exactly the cap is allowed; only a strictly larger one is rejected, | ||
| * matching the ws server's own accept semantics. | ||
| */ | ||
| import { expect } from 'chai'; | ||
| import { exceedsMaxPayload } from '#src/replication/replicationConnection'; | ||
|
|
||
| describe('exceedsMaxPayload', () => { | ||
| const cap = 100_000_000; | ||
|
|
||
| it('allows a frame below the cap', () => { | ||
| expect(exceedsMaxPayload(0, cap)).to.equal(false); | ||
| expect(exceedsMaxPayload(cap - 1, cap)).to.equal(false); | ||
| }); | ||
|
|
||
| it('allows a frame exactly at the cap (boundary is inclusive)', () => { | ||
| expect(exceedsMaxPayload(cap, cap)).to.equal(false); | ||
| }); | ||
|
|
||
| it('rejects a frame strictly above the cap', () => { | ||
| expect(exceedsMaxPayload(cap + 1, cap)).to.equal(true); | ||
| }); | ||
|
|
||
| it('honors an explicit smaller cap', () => { | ||
| expect(exceedsMaxPayload(2_000_000, 1_000_000)).to.equal(true); | ||
| expect(exceedsMaxPayload(500_000, 1_000_000)).to.equal(false); | ||
| }); | ||
| }); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Medium: on the base-copy path there is no "split the transaction" escape, and a clone can never reach Available
sendQueuedDatais also called from the full-copy loop at lines 4550 and 4626, where the frame is assembled from up toCOPY_CHECKPOINT_RECORDS(default 1000, line 249) existing rows rather than from a client transaction. A table averaging >100 KB per record therefore produces an oversized copy batch at the default 100 MB cap — issue #711's own repro is 1200 × 100 KB. After this change that throw closes the leg, the copy resumes from the sameafterKey, re-assembles the same batch, and throws again: the clone never emitsCOPY_COMPLETEand never reaches Available. The PR's stated remedies don't apply — an operator can't "split" rows that already exist, leaving only raisingreplication_maxPayload(see the note on line 4296).Unlike the audit-log path, this one is fixable now without the deferred chunking protocol change: both copy flushes are documented in-code as plain flushes with no sequence update, so splitting them is safe.
Suggested fix: add a byte-based condition to the copy checkpoint at 4621 alongside the record count — flush when
frame.position - frame.encodingStartapproachesMAX_PAYLOAD— so the copy path never builds an oversized frame in the first place. That leaves only the genuinely atomic single-transaction case for the chunking follow-up.—
Generated by Barber AI
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Fixed for the batch case in 367988f: added a byte threshold (
COPY_FLUSH_BYTES = floor(MAX_PAYLOAD * 0.9)) alongside the record count at the copy checkpoint, so a run of large rows flushes before assembling an oversized frame. As you noted, both copy flushes are plain (no sequence update), so splitting is safe.Caveat kept honest: a SINGLE row larger than the cap still cannot be split and relies on raising
replication_maxPayload— the #711 repro (1200 x 100 KB) is the batch case and is now fixed; one >100 MB row is not. Rig-confirmed a single oversized row still wedges the copy (expected), while normal large-row batches flush under the cap.Lavinia, via Claude