Skip to content

Commit 2da8855

Browse files
test(realtime): wait for the idle read the streak test depends on (#6673)
The guard failed intermittently in CI — `expected 1870 to be less than 1000`, which is the carried-streak backoff, meaning the streak was never reset before the phase that measures it. The middle phase cleared the fault and then waited a FIXED 1000ms for an idle read to land. It usually did. But the pending backoff from the two failures before it runs 400–600ms then 800–1200ms, so the next read is due anywhere up to ~1805ms — and the phase ends at 1800ms. When both jitters drew high the read arrived after the fault had already been re-armed, so it failed instead of succeeding, the streak survived at two, and the measurement caught the third backoff (1600–2400ms) rather than the first. Waiting for a duration where the thing being waited for is an event is the bug. Each phase now waits for its own event: two failed reads to build the streak, then a read that actually RETURNS to clear it. Also measure failure-to-failure rather than read-to-read. A successful read can land in the instant after the fault is re-armed, and as the first sample it would make the gap ~5ms — passing for the wrong reason, the same false-pass shape review caught in this test last round. 20 consecutive runs green; still fails on the un-fixed reader every time (1753ms, 1688ms, 1881ms, 1701ms, 1837ms against the 1200ms bound).
1 parent 85c8451 commit 2da8855

1 file changed

Lines changed: 44 additions & 20 deletions

File tree

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

Lines changed: 44 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -20,8 +20,10 @@ interface Backing {
2020
readerClosed: boolean
2121
/** Failed reads served, so a test can prove the loop is not spinning at the read cadence. */
2222
reads: number
23-
/** When each read was attempted, so a test can assert the BACKOFF rather than a count in a window. */
24-
readTimes: number[]
23+
/** When each FAILED read was attempted, so a test can measure one backoff interval exactly. */
24+
failedReadTimes: number[]
25+
/** Reads that returned (the idle steady state) — the event that ends a failure streak. */
26+
idleReads: number
2527
/** `connect()` calls, so a test can prove a closed reader is re-opened rather than abandoned. */
2628
connects: number
2729
}
@@ -66,8 +68,8 @@ function makeClient(): any {
6668
},
6769
xRead: async (streams: { key: string; id: string }[]) => {
6870
b().reads++
69-
b().readTimes.push(Date.now())
7071
if (b().readerClosed) {
72+
b().failedReadTimes.push(Date.now())
7173
client.isOpen = false
7274
throw new Error('The client is closed')
7375
}
@@ -77,8 +79,12 @@ function makeClient(): any {
7779
const after = (b().streams.get(key) ?? []).filter((e) => seqOf(e.id) > seqOf(id))
7880
if (after.length) res.push({ name: key, messages: after.map((e) => ({ ...e })) })
7981
}
80-
if (res.length) return res
82+
if (res.length) {
83+
b().idleReads++
84+
return res
85+
}
8186
await sleep(5)
87+
b().idleReads++
8288
return null
8389
},
8490
set: async (key: string, val: string, opts?: { NX?: boolean }) => {
@@ -155,7 +161,8 @@ describe('FileDocStore', () => {
155161
failXAdd: 0,
156162
readerClosed: false,
157163
reads: 0,
158-
readTimes: [],
164+
failedReadTimes: [],
165+
idleReads: 0,
159166
connects: 0,
160167
}
161168
stores = []
@@ -201,29 +208,46 @@ describe('FileDocStore', () => {
201208
const doc = new Y.Doc()
202209
await store.attachRoom(NAME, doc)
203210

204-
// Build a streak of two failures (retries back off ~0.5s, then ~1s).
211+
// Build a streak of two failures (the retries back off ~0.5s, then ~1s).
205212
state.backing!.readerClosed = true
206-
await sleep(800)
207-
// Redis comes back. Wait past the pending backoff so a read actually lands — and it returns
208-
// nothing new, which is the idle case this test is about.
213+
await vi.waitFor(
214+
() => expect(state.backing!.failedReadTimes.length).toBeGreaterThanOrEqual(2),
215+
{
216+
timeout: 5000,
217+
interval: 25,
218+
}
219+
)
220+
221+
// Redis comes back. Wait for a read to actually RETURN — waiting a fixed span instead is a race:
222+
// the pending backoff can outlast it, no idle read lands, and the streak survives into the phase
223+
// below, which then measures the wrong backoff and fails. That is an event, so wait on the event.
209224
state.backing!.readerClosed = false
210-
await sleep(1000)
225+
const idleBefore = state.backing!.idleReads
226+
await vi.waitFor(() => expect(state.backing!.idleReads).toBeGreaterThan(idleBefore), {
227+
timeout: 5000,
228+
interval: 25,
229+
})
211230

212231
// A fresh blip must retry at the START of the backoff curve, not partway up it. Assert the DELAY
213232
// itself: counting attempts inside a fixed window cannot tell the two apart, because the jittered
214233
// delay for a carried streak (1.6–2.4s) overlaps any window wide enough to catch a reset one.
234+
// Measure FAILURE to FAILURE so the sample is exactly one backoff — a straggler successful read
235+
// landing just after the flag flips would otherwise become the first sample and pass trivially.
215236
state.backing!.readerClosed = true
216-
state.backing!.readTimes.length = 0
217-
await vi.waitFor(() => expect(state.backing!.readTimes.length).toBeGreaterThanOrEqual(2), {
218-
timeout: 5000,
219-
interval: 50,
220-
})
221-
const [first, second] = state.backing!.readTimes
237+
state.backing!.failedReadTimes.length = 0
238+
await vi.waitFor(
239+
() => expect(state.backing!.failedReadTimes.length).toBeGreaterThanOrEqual(2),
240+
{
241+
timeout: 6000,
242+
interval: 25,
243+
}
244+
)
245+
const [first, second] = state.backing!.failedReadTimes
222246

223-
// Streak reset ⇒ the first delay is 500ms ±20% ⇒ 400–600ms. Streak carried over ⇒ it is the third
224-
// delay, 2000ms ±20% ⇒ 1600–2400ms. Disjoint ranges, so this cannot pass on the wrong one without
225-
// the machine stalling the shorter sleep by 65%.
226-
expect(second - first).toBeLessThan(1000)
247+
// Streak reset ⇒ the first delay is 500ms ±20% ⇒ at most 600ms. Streak carried over ⇒ it is the
248+
// third delay, 2000ms ±20% ⇒ at least 1600ms. The bound sits between them with room on both
249+
// sides, so a loaded machine stretching the short sleep does not flip the verdict.
250+
expect(second - first).toBeLessThan(1200)
227251
doc.destroy()
228252
})
229253

0 commit comments

Comments
 (0)