Skip to content

Commit 8e2733c

Browse files
committed
fix(realtime): keep the file-doc store reconnecting instead of dying quietly
A relay that lost Redis for longer than its retry budget did not degrade — it went silently split-brain and stayed that way. The reconnect strategy returned an `Error` after ten attempts, which tells node-redis to give up and CLOSE the client, and a closed client rejects every command with "The client is closed" for the rest of the process's life. From that point the task kept serving clients while its rooms stopped receiving other tasks' updates, its own edits stopped reaching the shared stream (also the crash buffer between persists), and seeds, locks and the persist If-Match token all failed. The tail loop then treated that as a transient read error — `running` is only false during shutdown, so it retried every 500ms forever, one warning per attempt. A tab left open overnight produced thousands of identical lines, which is how the actual failure stayed invisible. - Never stop reconnecting. This process holds live documents whose only convergence path is that connection, so a connection it can rebuild is always worth rebuilding. Same capped backoff, now via the shared `backoffWithJitter`, and no error return. - Back the reader off after a failed read (500ms → 10s) instead of retrying at the read cadence, re-open a client that was CLOSED — node-redis reconnects a dropped client, never a closed one — and log the first failure of a streak then one in twenty, carrying the streak length, so an outage stays visible without burying itself. Pinned by a test that models a closed connection: six read attempts in three seconds before, about three after, and proof the reader is re-opened rather than abandoned.
1 parent 0c4e674 commit 8e2733c

2 files changed

Lines changed: 99 additions & 8 deletions

File tree

apps/realtime/src/handlers/file-doc-store.test.ts

Lines changed: 50 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -15,6 +15,12 @@ interface Backing {
1515
seq: number
1616
/** Number of upcoming xAdd calls to fail with a transient error (to exercise publish retry). */
1717
failXAdd: number
18+
/** Set to fail every xRead the way node-redis does once a client has been closed. */
19+
readerClosed: boolean
20+
/** Failed reads served, so a test can prove the loop is not spinning at the read cadence. */
21+
reads: number
22+
/** `connect()` calls, so a test can prove a closed reader is re-opened rather than abandoned. */
23+
connects: number
1824
}
1925

2026
const state = vi.hoisted(() => ({ backing: null as Backing | null }))
@@ -27,7 +33,11 @@ function makeClient(): any {
2733
return state.backing
2834
}
2935
const client: any = {
30-
connect: async () => {},
36+
isOpen: true,
37+
connect: async () => {
38+
client.isOpen = true
39+
b().connects++
40+
},
3141
quit: async () => {},
3242
on: () => client,
3343
duplicate: () => makeClient(),
@@ -52,6 +62,11 @@ function makeClient(): any {
5262
)
5363
},
5464
xRead: async (streams: { key: string; id: string }[]) => {
65+
b().reads++
66+
if (b().readerClosed) {
67+
client.isOpen = false
68+
throw new Error('The client is closed')
69+
}
5570
const res: { name: string; messages: { id: string; message: Record<string, string> }[] }[] =
5671
[]
5772
for (const { key, id } of streams) {
@@ -129,14 +144,47 @@ async function newStore(): Promise<FileDocStore> {
129144

130145
describe('FileDocStore', () => {
131146
beforeEach(() => {
132-
state.backing = { streams: new Map(), kv: new Map(), seq: 0, failXAdd: 0 }
147+
state.backing = {
148+
streams: new Map(),
149+
kv: new Map(),
150+
seq: 0,
151+
failXAdd: 0,
152+
readerClosed: false,
153+
reads: 0,
154+
connects: 0,
155+
}
133156
stores = []
134157
})
135158

136159
afterEach(async () => {
137160
await Promise.all(stores.map((s) => s.shutdown()))
138161
})
139162

163+
/**
164+
* A connection that stops serving reads used to spin the tailer at the read cadence — two attempts a
165+
* second, one warning each, forever — while the task quietly stopped converging with every other one.
166+
* The loop must back off instead, and re-open a client that was closed rather than reading a dead one.
167+
*/
168+
it('backs off and re-opens the reader when its connection is closed, instead of spinning', async () => {
169+
const store = await newStore()
170+
const doc = new Y.Doc()
171+
await store.attachRoom(NAME, doc)
172+
state.backing!.readerClosed = true
173+
174+
state.backing!.connects = 0 // ignore the two `init` connects; count only recovery attempts
175+
const before = state.backing!.reads
176+
await new Promise((r) => setTimeout(r, 3000))
177+
const attempts = state.backing!.reads - before
178+
179+
// A fixed 500ms retry manages 6–7 attempts in this window; backing off (500 → 1s → 2s → …) manages
180+
// about 3. Exact counts are timing-dependent, so assert the property — it slowed down — not a number.
181+
expect(attempts).toBeGreaterThan(0)
182+
expect(attempts).toBeLessThanOrEqual(4)
183+
// …and it tried to bring the connection back rather than leaving the tailer dead forever.
184+
expect(state.backing!.connects).toBeGreaterThan(0)
185+
doc.destroy()
186+
})
187+
140188
it('elects exactly one seeder across tasks (no split-brain seed)', async () => {
141189
const a = await newStore()
142190
const b = await newStore()

apps/realtime/src/handlers/file-doc-store.ts

Lines changed: 49 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -160,6 +160,12 @@ const SEED_LOCK_TTL_MS = FILE_DOC_TIMEOUTS.seedRequestMs + 4_000
160160
const STREAM_TTL_SEC = 600
161161
/** Refresh every occupied stream's TTL on this cadence, so a live doc's stream never expires. */
162162
const HEARTBEAT_MS = 60_000
163+
/** Cap on the delay between reconnection attempts — the strategy retries indefinitely (see `init`). */
164+
const RECONNECT_MAX_DELAY_MS = 3_000
165+
/** Cap on the reader's own retry backoff after a failed read. */
166+
const READER_RETRY_MAX_MS = 10_000
167+
/** After the first failure of a streak, log one reader failure in this many. */
168+
const READER_ERROR_LOG_EVERY = 20
163169

164170
const streamKey = (name: string) => `${STREAM_PREFIX}${name}`
165171

@@ -246,10 +252,17 @@ export class FileDocStore {
246252
const options = {
247253
url: this.redisUrl,
248254
socket: {
249-
reconnectStrategy: (retries: number) => {
250-
if (retries > 10) return new Error('FileDocStore Redis reconnection failed')
251-
return Math.min(retries * 100, 3000)
252-
},
255+
/**
256+
* Never stop reconnecting. Returning an `Error` here tells node-redis to give up and CLOSE the
257+
* client — and a closed client rejects every command with "The client is closed" for the rest of
258+
* the process's life. So an outage longer than the retry budget does not degrade this task, it
259+
* takes it out silently: its rooms stop receiving other tasks' updates, its own edits stop
260+
* reaching the shared stream, seeds and locks fail, and the only symptom is a warning per retry.
261+
* This process holds live documents whose sole convergence path is this connection, so a
262+
* connection it can rebuild is always worth rebuilding.
263+
*/
264+
reconnectStrategy: (retries: number) =>
265+
backoffWithJitter(retries + 1, null, { baseMs: 100, maxMs: RECONNECT_MAX_DELAY_MS }),
253266
},
254267
}
255268
this.write = createClient(options)
@@ -651,6 +664,7 @@ export class FileDocStore {
651664
* apply new entries. One blocking connection for the whole process regardless of open-file count.
652665
*/
653666
private async runReader(): Promise<void> {
667+
let failures = 0
654668
while (this.running && this.read) {
655669
const snapshot = new Map(this.rooms)
656670
if (snapshot.size === 0) {
@@ -672,14 +686,43 @@ export class FileDocStore {
672686
if (!room || room !== snapshot.get(name)) continue
673687
for (const entry of stream.messages) this.applyEntry(room, entry.id, entry.message)
674688
}
689+
failures = 0
675690
} catch (error) {
676691
if (!this.running) break
677-
logger.warn('FileDocStore reader error; retrying', { error: getErrorMessage(error) })
678-
await sleep(500)
692+
await this.recoverReader(++failures, error)
679693
}
680694
}
681695
}
682696

697+
/**
698+
* A failed read is either a transient blip or a connection that is gone, and this loop cannot tell
699+
* them apart — so it backs off instead of retrying at the read cadence. Without that, a connection
700+
* that cannot serve reads spins this loop forever at two attempts a second, one warning each, which
701+
* is how an outage turns into thousands of identical log lines that bury the reason for it.
702+
*
703+
* It also re-opens a CLOSED client. node-redis reconnects a client that merely dropped, but never one
704+
* it has closed; the strategy above no longer closes one, so this covers a client closed some other
705+
* way (an explicit disconnect, a shutdown that raced a read) rather than leaving the tailer dead.
706+
*
707+
* Logs the first failure of a streak and then one in every {@link READER_ERROR_LOG_EVERY}, carrying
708+
* the streak length, so a real outage stays visible without filling the log.
709+
*/
710+
private async recoverReader(failures: number, error: unknown): Promise<void> {
711+
if (failures === 1 || failures % READER_ERROR_LOG_EVERY === 0) {
712+
logger.warn(`FileDocStore reader failed ${failures}x in a row; retrying`, {
713+
error: getErrorMessage(error),
714+
})
715+
}
716+
await sleep(backoffWithJitter(failures, null, { baseMs: 500, maxMs: READER_RETRY_MAX_MS }))
717+
if (this.running && this.read && !this.read.isOpen) {
718+
await this.read.connect().catch((reconnectError) => {
719+
logger.warn('FileDocStore could not re-open the reader connection', {
720+
error: getErrorMessage(reconnectError),
721+
})
722+
})
723+
}
724+
}
725+
683726
/**
684727
* Snapshot-then-trim compaction: append a full-state snapshot and drop the older deltas it subsumes,
685728
* so the stream stays bounded while a fresh task can still catch up from the head. Lock-guarded so

0 commit comments

Comments
 (0)