Problem
With featureFlagChangeStreamOptimizedUpdateLookup enabled (default: true), a collection-scope
change stream using fullDocument: "updateLookup" batches raw events in
BatchedEnrichmentStage::fillBatch() before enriching them, to amortize the SBE plan
compile + collection acquisition across up to internalChangeStreamUpdateLookupMaxBatchSize
(default 100) events.
Under concurrent write load, this inflates getMore latency by 5-12x, regardless of update
fraction (reproduces even at 0% updates / 100% inserts).
Real throughput is unaffected — events/sec delivered by the change stream is the same as
before batching was introduced. What changes is GetMore's Average Content Size
(events returned per getMore), which grows roughly in proportion to the added latency: since
each getMore now blocks longer before returning, more events accumulate in the oplog during
that wait and get swept into the same reply. The larger batch is a symptom of the latency
increase, not an independent effect -- fewer, latency-inflated getMores end up carrying
proportionally more events each, netting out to the same events/sec.
Root Cause
fillBatch() assumes upstream returns a non-advanced (EOF) result once currently-available
data is exhausted, and flushes the buffered batch on it. That holds for an ordinary collection
scan, but not for a tailable awaitData oplog cursor: at momentary drain the leaf executor blocks
on the insert notifier instead of returning EOF (PlanExecutorImpl::_handleEOFAndExit), gated
by the per-operation flag awaitDataState(opCtx).shouldWaitForInserts.
That flag is supposed to flip false the instant getMore receives its first document
(getmore_cmd.cpp: "As soon as we get a result, this operation no longer waits") -- which is
exactly the contract CursorStage already honors one stage lower, by returning a single
document at a time while the flag is set (cursor_stage.cpp:271-275).
BatchedEnrichmentStage sits above CursorStage and holds the first event instead of
surfacing it, so the flag never flips mid-fill. Every one of the up to 100 fill iterations then
blocks on the insert notifier, and a getMore can only return once 100 events have physically
arrived or the awaitData deadline (~maxTimeMS) fires. On a stream that doesn't sustain 100
events within that window, effectively every getMore pays close to the full deadline.
Impact
- Any collection-scope change stream with updateLookup enabled is affected, not just
high-throughput ones -- low/moderate-throughput CDC consumers (the majority use case) are
hit hardest, since they're the least likely to fill 100 events quickly. - Measured on change_streams_atlas_search_locust (3-node replSet, arm): getMore
Latency50thPercentile regressed from ~1-1.4ms to ~6-15ms across 0%/25%/100% update
fractions, while real events/sec stayed flat.