fix(watch): wait for etcd to acknowledge a watch before returning - #313
Conversation
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.
|
Summary dotnet-etcd 93.1% |
1 participant
The flake was not the reconnect — the watch was never registered
WatchResilienceTestsfailed its first assertion (Assert.NotEmpty() Failure: Collection was empty) roughly 1 iteration in 20 of the nightly Beast. That assertion runs before any pause or restart, so the reconnect/resume logic was never even reached.The client never waited for etcd's
Createdacknowledgement.Watcher.CreateWatchAsyncawaited onlyRequestStream.WriteAsync, which guarantees "the create request was written to the socket" — not "etcd registered the watcher". etcd's own proto says so:Two consequences, each proven by a test that fails before this change:
Watch()/WatchAsync()returned before the watch existed server-side, so a write issued immediately after could be applied first and its event never delivered.NextRevisionwas still0, soHandleConnectionFailurere-registered withStartRevision = 0, i.e. "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 fix(watch): resume from last observed revision on reconnect (fixes nightly beast flake) #310 only engages onceNextRevision > 0, so it never covered this window.The fix
WatchAsyncnow awaits theCreatedack 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 its own regression test:
WriteAsyncis still in flight, andTrackResumeRevisiondropped responses for watches not yet in_watches— losing the created revision.NextRevisionfrom the caller'sStartRevision(as etcd clientv3 does:nextRev := w.initReq.rev). ACreatedack carries the current cluster revision, so without this a watch resuming from a checkpoint would skip its backlog.Watcheron reconnect. It was leaked, and a still-healthy stream went on delivering every event a second time.RpcExceptionrather thanAggregateException.Watch()/WatchAsync()now block until etcd acknowledges the watch (30s cap, or the caller'sdeadline) and can throw (RpcExceptionwithDeadlineExceeded/FailedPrecondition) where they previously returned instantly. This is the point of the change — it is what makes "the event I write afterWatch()returns will be delivered" actually true — but it is a change in shape.Anyone unit-testing against their own mock watch stream that never sends a
Createdresponse will now see a 30s timeout instead of an immediate return.Test / CI fixes
start-etcd.shnow health-gatesetcd-resilience(added in test: fix integration flakiness from shared-etcd cross-contamination #312 but never waited for).WatchResilienceTests: bounded polling instead of fixed sleeps; events collected in aConcurrentQueue(they were appended from the gRPC receive loop and read from the test thread with no synchronisation); the trace is dumped on failure so the next flake is diagnosable.beast.shnow captures test stdout (--logger console;verbosity=detailed) — previously all 140 archived CI logs contained zero test diagnostics — and-f Allno longer breaks under bash 3.2 (macOS).Verification
Every behavioural fix was confirmed RED before / GREEN after by reverting each implementation individually (e.g. the backlog skip:
Expected: 11, Actual: 100; the re-entrancy deadlock hangs the full 15s timeout).WatchResilienceTestsfailures