fix(watch): resume from last observed revision on reconnect (fixes nightly beast flake) - #310
Conversation
Watch_ShouldRecover_AfterServerRestart was flaky (nightly beast: 5-20% failure) —
Assert.NotEmpty failed because no events arrived after a server restart.
Root cause: on a broken stream, WatchManager.HandleConnectionFailure re-registered
each watch with the ORIGINAL request, whose StartRevision is 0 ('watch from now'),
and never tracked the last observed revision. So after a reconnect the watch only
saw events created strictly after re-registration completed; anything written during
the reconnect gap was permanently lost. This is a real data-loss bug (same family as
issue #283), not just a test-timing issue — etcd watches are revision-based and the
official clientv3 resumes from the last observed revision (nextRev).
Fix (mirrors clientv3):
- Track NextRevision per watch: after an event batch, lastEvent.ModRevision + 1; for a
created/progress notification, header.Revision + 1; on a compaction cancel, the
CompactRevision. Monotonic.
- On reconnect, set CreateRequest.StartRevision = NextRevision so gap events are replayed.
Tests:
- Unit (deterministic, no docker): reconnect resumes from lastRev+1, from a progress
notification's header+1, and from CompactRevision after a compaction cancel.
- Integration: WatchResilienceTests now polls etcd readiness instead of a fixed 15s sleep.
Verified: the restart test run 30x locally -> 30/30 green (was 5-20% flaky).
|
Summary dotnet-etcd 94.5% |
The nightly beast kept failing Watch_ShouldRecover_AfterServerRestart with 'Collection was empty' even after the revision-resume fix (#310). Root cause was test cross-contamination on the single shared etcd1, not the reconnect logic: 1. xUnit runs different test collections in PARALLEL and there was no assembly-wide guard. AuthClientIntegrationTests enables/disables cluster-wide auth on etcd1; any other test hitting etcd1 unauthenticated during that window fails with 'etcdserver: user name is empty' -> the watch delivers no events -> empty. 2. WatchResilienceTests pause/restart their etcd server, disrupting every other test that shares it (parallel or serial). Fix: - Add xunit.runner.json with parallelizeTestCollections=false so collections run sequentially and auth toggling can't overlap other etcd1 tests. - Give WatchResilienceTests a dedicated single-node etcd (etcd-resilience, port 2409) so pausing/restarting it never affects the shared etcd1 cluster tests. Verified: full integration suite 57/57 green; both resilience tests pass against the dedicated instance.
WatchResilienceTests failed its FIRST assertion ("Collection was empty")
about once every 20 beast iterations. The reconnect logic was not at
fault: the watch was never registered at all.
dotnet-etcd never waited for etcd's Created acknowledgement. CreateWatchAsync
awaited only RequestStream.WriteAsync, which means "the create request was
written to the socket" -- not "etcd registered the watcher". etcd's own proto
says so: "Since creating a watcher in etcd is not a synchronous operation".
Two consequences, both proven by tests that fail before this change:
* Watch() returned before the watch existed server-side, so a write issued
immediately after could be applied first and its event never delivered.
* If the stream died before ANY response arrived -- exactly what happens when
a watch is opened against an etcd that is still restarting -- NextRevision
was still 0, so HandleConnectionFailure re-registered with StartRevision=0,
meaning "watch from now". But "now" was already past the caller's write, so
the event was lost permanently and silently. The revision-resume added in
#310 only engages once NextRevision > 0, so it never covered this window.
WatchAsync now awaits the Created ack before returning. If the stream dies
while waiting, the reconnect re-sends the create and its ack completes the same
wait, so a create lost to a dying stream is retried rather than silently
downgraded to "from now".
Supporting fixes, each with a regression test:
* Register the watch before writing the create: the server can answer while
WriteAsync is still in flight, and TrackResumeRevision dropped responses for
watches not yet in _watches -- losing the created revision.
* Seed NextRevision from the caller's StartRevision (as etcd clientv3 does with
nextRev := initReq.rev). A Created ack carries the CURRENT cluster revision,
so without this a watch resuming from a checkpoint would skip its backlog.
* Ignore the ack header for a replay create, for the same reason.
* Run user callbacks off the receive loop, serialized on one chain. They ran
inline, so a callback that started another watch deadlocked: the loop it
blocked was the only thing that could deliver the new watch's ack.
* Serialize writes to the duplex stream (gRPC allows one pending write).
* Dispose the abandoned Watcher on reconnect; it was leaked, and a still-healthy
stream went on delivering every event a second time.
* Keep the 5s reconnect retry alive when a re-register fails, and surface
failures from the sync overloads as RpcException rather than AggregateException.
Tests: health-gate etcd-resilience (added in #312 but never waited for), poll
instead of sleeping on fixed timers, collect events in a ConcurrentQueue (they
were appended from the receive loop and read from the test thread), capture test
stdout in beast.sh, and fix beast.sh -f All under bash 3.2.
Full suite 417/417; 25x full-suite beast all green.
What & why
The nightly Beast (flakiness) workflow failed 3 runs in a row on
main, always the same test:WatchResilienceTests.Watch_ShouldRecover_AfterServerRestart(flaky ~5–20% per 20-iteration run). The beast-logs artifact pinpointed it:Assert.NotEmpty() Failure: Collection was empty— no events arrive after a server restart.Investigation showed this is a real watch data-loss bug, not just test timing.
Root cause
WatchManager.HandleConnectionFailurere-registered each watch with the original request, whoseStartRevisionis0("watch from now"), and never tracked the last observed revision. After a reconnect the watch only saw events created strictly after re-registration completed — anything written during the reconnect gap was permanently lost. The test's retry-put loop (added in #293) only papered over this; under CI timing variance it still lost the race.etcd watches are revision-based: to resume without missing events you must re-watch from
lastObservedRevision + 1. The official Go client (clientv3/watch.go) does exactly this (nextRev). Ours didn't. This is the same fragility family as #283.Fix (mirrors clientv3)
NextRevisionper watch: event batch →lastEvent.ModRevision + 1; created/progress notification →header.Revision + 1; compaction cancel →CompactRevision. Monotonic.CreateRequest.StartRevision = NextRevisionso gap events are replayed, not lost.WatchResilienceTests: poll etcd readiness instead of a fixed 15s sleep.Tests & verification
lastRev+1, from a progress-notificationheader+1, and fromCompactRevision. The first failed before the fix (Expected 11, Actual 0).Fixes the recurring nightly Beast failures.