HarperFast / HarperFast/harper
Subscription replay: startTime collection branch silently drops events committed after the audit cursor terminates
- Dominant language
- JavaScript
- Stars
- 89
- Forks
- 10
- Avg merge
- 2d 6h
- Merged PRs (30d)
- 200
Description
`Table.subscribe({ startTime, isCollection: true })` can silently drop an event for a write that commits while the replay cursor is running. The event is neither replayed (the audit cursor has already terminated) nor delivered live (the listener is gated off for the duration of replay), and nothing logs or errors — the subscriber simply never sees that record again until it is written to a second time.
This is the product-side defect behind the `FIRST-subscription-on-fresh-DB while writes are in flight delivers each exactly once` flake in `unitTests/resources/subscriptionReplay.test.js` (see #2276). Filed separately from the flake because the test is byte-identical at that PR's merge base and the fix is in `resources/Table.ts`, not in the test.
## Mechanism
`resources/Table.ts:4149-4188`, the `startTime` collection branch:
```ts
pendingRealTimeQueue = null;
dropDuringReplay = true; // 4151 — the live listener now returns immediately (4071)
try {
for (const auditRecord of auditStore.getRange({ start: startTime, exclusiveStart: true, snapshot: false })) {
...
subscription.startTime = auditRecord.localTime ?? auditRecord.version; // 4184
}
} finally {
dropDuringReplay = false; // 4188
}
```
Unlike the `count` / `!omitCurrent` / non-collection branches — which buffer live events in `pendingRealTimeQueue` and drain them after replay — this branch **discards** them (`pendingRealTimeQueue = null`), on the stated assumption that "the `snapshot:false` cursor picks up the live tail directly" (comment at `Table.ts:4024`).
That assumption holds only while the cursor is still iterating. `getRange()` returns a *terminating* iterator: once it reaches the end of the range it is finished, and `snapshot: false` renewal cannot resurrect it. So the window `[cursor terminates, dropDuringReplay = false]` is covered by neither path — every commit landing in it is dropped and never delivered.
A second, narrower hole in the same handoff, code-traced but not reproduced here: `subscription.startTime` is advanced to the last audit record the cursor saw (`Table.ts:4184`), and the broadcast path skips any live event with `subscription.startTime >= timestamp` (`resources/transactionBroadcast.ts:202`). An in-flight commit whose audit timestamp is not strictly greater than the last replayed record is therefore dropped by the live path as "already sent", while the cursor has already passed its key.
## Evidence
Reproduced by widening the uncovered window rather than by inference. With a 100 ms delay inserted between the end of the replay `for` loop and the `finally` that clears `dropDuringReplay` (`dist/resources/Table.js`, no other change), against the existing test on `HARPER_STORAGE_ENGINE=lmdb`:
- **200 of 200** in-flight events hit the `dropDuringReplay` early return
- the cursor recovered **none** of them (`subscription.startTime` never advanced past the initial value — the audit range was empty when the iterator was created)
- the test failed with `AssertionError: missing in-flight id 20000`, the same signature as the CI/reviewer-observed failure
The mid-replay portion of the window is genuinely covered, which is worth recording so a fix does not over-correct: with an artificial delay at the `await rest()` yield point instead (`REPLAY_YIELD_INTERVAL` forced to 3-10, 10-50 ms delay), **200 events were dropped by the listener and all 200 were subsequently delivered by the cursor** — the test passed. Only the terminal window loses events.
Unmodified, the failure is machine-dependent:
| box | isolated lmdb runs | failures |
|---|---|---|
| this one (20 cores, Node 26.2.0), incl. 6-way contended and single-core-pinned | 41 | 0 |
| reviewer's, `--grep FIRST-subscription-on-fresh-DB` and the suite-glob form | 6 | 6 (`missing in-flight id 20015 / 20006 / 20018`) |
On the box where it passes, the replay cursor sees an *empty* audit range — every one of the 200 in-flight writes commits after `dropDuringReplay` is already false, so the uncovered window is never entered. Instrumented directly: `0` listener drops, and `subscription.startTime` unchanged at the end of replay. That is why the same head is 41/41 green here and deterministic red elsewhere; it is a timing coincidence, not an engine-selection artifact (the probe confirms the lmdb store is in use — `test2.mdb` — on both the passing and failing paths).
## Repro
```bash
npm run build
HARPER_STORAGE_ENGINE=lmdb npx mocha unitTests/resources/subscriptionReplay.test.js \
--grep FIRST-subscription-on-fresh-DB
```
Fails as `missing in-flight id ` on boxes where the in-flight writes straddle the end of replay. To force it anywhere, add `await new Promise((r) => setTimeout(r, 100));` immediately after the replay `for` loop in `dist/resources/Table.js` (before the `finally`) and re-run.
## Suggested direction
Make the drop window and the cursor's coverage the same window instead of assuming they coincide. The other three replay branches already have the machinery: buffer into `pendingRealTimeQueue` for the whole of replay and drain it afterwards, deduplicating against what the cursor sent (the `count` branch's `cursorMaxTime` filter at `Table.ts:4248` is the existing pattern for exactly that de-dup). That removes the reliance on "the cursor is still live", at the cost of holding the replay tail in memory — which the other branches already accept.
Whatever the shape, the `subscription.startTime >= timestamp` interaction above needs to be resolved with it, or the buffered events will be filtered out at `transactionBroadcast.ts:202` instead of at the listener.
## Impact
Any subscriber replaying from a timestamp on a table taking concurrent writes — the MQTT/SSE reconnect path is exactly this shape. The loss is silent (no log, no error, no gap marker) and does not self-heal: the record is delivered again only when it is next written. Not a regression; the branch has behaved this way for as long as `dropDuringReplay` has existed.
Related: #1655 (the flake this surfaced through), #2276 (the deflake PR that documents it).
---
_Filed by Claude Opus 5._
Contributor guide
Research direction
Run the named mocha command after reading the startTime collection branch in resources/Table.ts:4149-4188 and the broadcast check in resources/transactionBroadcast.ts:202. Trace the existing pendingRealTimeQueue and cursorMaxTime handling in the other replay branches. Done means the FIRST-subscription test passes without silently losing concurrent events, including the terminal replay window and timestamp handoff.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- node.js, typescript
- Domain
- backend, database
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Active
- Clarity
- Clearly specified
- Newbie friendliness
- 55/100