test(firestore): wait out the emulator's Listen-stream backoff

[tyler-reitz]

Why

test/firestore.test.tsx flakes at roughly 18% per run (11 of 60 iterations, measured 2026-08-11). The Firestore emulator intermittently corrupts a Listen frame, grpc-js reads four body bytes as a length prefix, and the SDK answers the resulting RESOURCE_EXHAUSTED by parking the stream on a 60 second maximum backoff.

This is an unresolved upstream emulator bug, firebase-tools#8654. Nothing to pin, so this survives it rather than preventing it.

What actually rescues the tests

Not a reconnect. The same failure sends the client to OnlineState.Offline after ONLINE_STATE_TIMEOUT_MS (10s), and an offline client raises the pending snapshot from the local cache, empty cache included. Two tests assert that a document is absent, which is exactly what the empty cache reports, so they reach success about ten seconds after the failure with no server involved. They are the only two in the file whose first snapshot cannot be served from local data.

Those two currently abandon the wait after one second, before the fallback can fire, and vitest would kill them at five seconds regardless. Both ceilings have to move or neither does anything.

What changed

Three waitFor calls get a 120s budget, and the two tests holding them get vitest timeouts of 150s and 270s, each clearing the sum of the budgets beneath it. 120s is far above the ~10s the fallback needs, deliberately, because a ceiling is not a delay.

waitFor polls at 50ms, so the larger ceiling costs nothing on a healthy run. Per-test durations, healthy samples only:

Test	With	Without
returns undefined if document does not exist	80-95ms (n=9)	82-136ms (n=3)
works when the document does not exist...	90-140ms (n=11)	101-120ms (n=3)

The bands overlap; the wider upper tail on the larger sample is sampling, not cost.

The third wait in useFirestoreDocOnce keeps the 1000ms default deliberately. It waits on the client's own write, which is raised from the local cache before the acknowledgement returns, so the offline fallback has no bearing on it. Measured with the client offline via disableNetwork: the write reaches an attached listener in 8ms, fromCache=true, against a control that fails at 1000ms when no write is issued.

Verification

The desync reproduced locally twice during this work, having never been seen off CI before, and was rescued both times. One has a full log, carrying RESOURCE_EXHAUSTED: Received message larger than max (4110323459 vs 4194304) and Using maximum backoff delay, with returns undefined if document does not exist taking 9878ms and passing where it normally runs 80-95ms. The other is a 9872ms sample from a batch that discarded output. CI showed the same rescue on this branch at 9795ms (details).

All three observations are with the fix in place. That the old ceilings would have killed a 9878ms wait follows from testing-library's 1000ms default and vitest's 5000ms, not from an observed failure.

Also verified: a simulated 65s stall survives the new budget and fails under the default; the per-test ceilings apply, confirmed by shortening one until it failed; both typechecks clean; firestore suite green against the emulator.

Signal for closing #776: desyncs keep appearing in logs while flakes stop. A rescued run reaches its assertion from an empty cache rather than from the server, so a zero flake count alone is not comparable to the 18.3% baseline. The probe records saw_grpc per iteration, and a rescued desync shows up as outcome=pass with saw_grpc=1.

Cost

A genuine regression in those two tests now takes up to 120s to surface instead of 1s, confined to the two tests this bug can kill.

Refs #776

[tyler-reitz]

Got a real occurrence in CI while this sat waiting, so the "not verified" caveat in the description is now partly answerable.

The test workflow has run nine times on this PR (18 job samples). Three attempts hit the desync; one of those landed on a vulnerable test and was rescued rather than failing:

GrpcConnection RPC 'Listen' stream error. Code: 8 RESOURCE_EXHAUSTED:
  Received message larger than max (1650553701 vs 4194304)
Using maximum backoff delay to prevent overloading the backend.
 ✓ test/firestore.test.tsx (15 tests) 12818ms
       ✓ returns undefined if document does not exist  9795ms

That test normally runs in ~90ms. Under the current ceilings it would have failed at 1000ms, or been killed by vitest at 5000ms. Recovery took about 10 seconds rather than the full 60, which matches the ~35s another project reported on the upstream issue and suggests the 120s budget has headroom.

18 of 18 jobs passed. On its own that is only p ≈ 0.03 against the 18.3% baseline flake rate, so the rescued stall is the persuasive part rather than the pass count.

[armando-navarro]

I am suggesting one change, and nothing about it touches the code.

What actually rescues these tests (the one change)

The tests never wait out the backoff:

• After resetToMax() the stream's next attempt is the 60s base plus or minus 50% jitter, minus the time since the stream was created or last retried (backoffAndRun in @firebase/firestore). The subtracted clock starts at the stream's creation, and this file's Listen stream is created by its first listener (the web SDK creates it lazily), in useFirestoreDoc > can get a Firestore document, the very test your desync is logged under, about two seconds into the file. So the earliest possible reconnect was roughly 28s after the failure.

• The failure also starts a 10s timer (ONLINE_STATE_TIMEOUT_MS). When it fires, the client broadcasts Offline, and shouldRaiseInitialEvent then raises the pending snapshot straight from the local cache, empty cache included.

• For these two tests the cached answer (document absent) is exactly what they assert, so they go green at about 10s with no server involved.

• Your captured rescue fits only that path: 9795ms is where the 10s timer puts it, not where a reconnect could be.

• I confirmed the fallback on its own: a listener on a nonexistent doc, against an emulator I froze with SIGSTOP for the whole run, reached success at 10.0s while it was still frozen. That run exercises the timer on a first connection attempt. That the timer also starts after a mid-run failure comes from the source, not from that run.

So "Recovery took about 10 seconds rather than the full 60" in your comment is not headroom, it is what this failure class costs: the wait ends about ten seconds after the stream fails, whatever the backoff is doing. 120s stays comfortably clear of that, so I am not asking you to change the number.

The ask: reword the code comment and the commit message to name the offline fallback as the rescue mechanism. Nothing in this file depends on the Listen stream reconnecting.

Also:

• "Only the tests that read a document which does not exist need a live server round trip" is broader than the mechanism supports: every test in the file awaits setDoc/addDoc, and those resolve only on backend acknowledgement. The narrow true claim is that these two are the only tests whose first snapshot cannot be served from local data.

• The 120s-over-60s figure leans on a third party that measures something else. I tracked it down (yarivluts/smart-marketing#73 and #75, via the upstream issue's cross-references): their ~35s is the total runtime of a test doing 17 to 44 sequential round trips in another repo, not a measured recovery. A fine reason to be generous, but not evidence about what these two waits need.

• If you take the rewording, the constant name WAIT_OUT_BACKOFF carries the same model. Renaming it is the one part of this that would touch code, so entirely optional.

The useFirestoreDocOnce test's ceilings do not compose

Three 120s waits plus an awaited setDoc sit under one 150s test timeout, so only one of them can ever spend its stated budget. The cost is measurement rather than correctness, in your own probe's buckets:

• Either of the first two waits expiring at 120s still prints the status assertion and counts as a flake.

• A setDoc stalled long enough to overrun the 150s ceiling prints Test timed out in 150000ms, which the probe files as a hang and drops from both sides of the rate.

• The third wait cannot be stranded by this bug at all, its update is raised locally before the ack even returns, so its budget buys nothing. A genuine regression there prints expected false to deeply equal true, which matches neither signature and lands in your unmatched list either way, just two minutes later instead of in a second.

I would suggest dropping the third wait's budget, or raising that one test's timeout above the sum.

Also noted

• After this lands, a desync-run pass means the client inferred absence from an empty cache rather than the server confirming it. For these two assertions the inference always matches the truth, so there is no correctness hole, but a clean probe alone cannot distinguish healed from guessed. The probe can, though: it already records saw_grpc per iteration, so a rescued desync shows up as an outcome=pass row with saw_grpc=1, and a zero flake count alone is not comparable to the 18.3% baseline.

• The #776 thread currently ends with "no timeout increase can help" and a fileParallelism: false PR that never came. A short comment there pointing at this PR would keep the record coherent. Possibly useful for it: smart-marketing#73 reports they still hit the desync fully serialized, which supports dropping it. The thread also still carries its own objection that a raised waitFor budget would not have saved the recorded 120s local hang, which is fair: that hang is plausibly a different failure this PR does not target, and worth saying so there.

• Minor: the reworked it calls drift from prettier (the file already had a few deviations on main, and this adds many more). vitest 4 accepts the options object as the second argument, it('...', { timeout: BACKOFF_TEST_TIMEOUT }, async () => {...}), which I ran against 4.1.9 and which prettier keeps on one line.

Let me know if you'd like another review after any changes you make addressing the suggestions above.

[tyler-reitz]

Took all of it except the vitest 4 form, which does not typecheck here.

it(name, { timeout }, fn) fails tsc -p tsconfig.test.json with TS2353, 'timeout' does not exist in type 'ProvidesCallback': @types/jest@29.5.2 arrives through jest-dom v5 and types the globals, so vitest-only signatures run fine and go red in the type-check job. Your prettier point still holds, and it is fixed the other way: prettier only breaks these calls when the timeout is a named constant, not a numeric literal. The file's only remaining deviations are the two already on main.

Correcting myself: my comment above said the ~10s recovery "suggests the 120s budget has headroom", against the ~35s figure. Both were wrong, for the reason you give. 10s is what this failure costs. The PR body carried the same wrong mechanism and has been rewritten.

I dropped the third wait's budget as you suggested, and measured the assumption under it first: offline via disableNetwork, a local write reaches an attached listener in 8ms, fromCache=true, against a control that fails at the 1000ms default when no write is issued. Ceilings are 150s and 270s now, each clearing the sum beneath it.

One new thing while re-measuring: the desync reproduced locally twice, having never been seen off CI before, and was rescued both times (9878ms with a full log, 9872ms without). Details in the body.

saw_grpc noted, I will read the next probe run that way rather than treating a zero flake count as comparable. Comment going on #776 as well.

[armando-navarro]

Everything you took landed, and the one thing you pushed back on, you were right about.

What I checked on b0c5051:

• The reworded comment, commit message, and PR body all state the mechanism accurately against what I traced.
• The two ceilings each clear the sum of the budgets beneath them.
• The file's only prettier deviations are the two already on main.
• Your two local rescues at 9878ms and 9872ms sit exactly where the 10s fallback puts them.

Approving. Nothing is left from my previous review, and the #776 comment you mentioned covers the last of it.