watchableStore.syncWatchersLoop measures how long a syncWatchers pass took and, when the
pass made progress but watchers are still unsynced, resets its delay ticker to that duration so
the loop yields time to other store operations:
syncDuration := time.Since(st)
delayTicker.Reset(watchResyncPeriod)
// more work pending?
if unsyncedWatchers != 0 && lastUnsyncedWatchers > unsyncedWatchers {
// be fair to other store operations by yielding time taken
delayTicker.Reset(syncDuration)
}
time.Ticker.Reset panics on a non-positive interval, and time.Since can return exactly zero
when the pass finishes faster than the platform's monotonic clock can resolve. The panic happens
in a goroutine started by mvcc.New, so it is not recoverable and takes the process down.
On windows/amd64 the Go runtime's monotonic clock has a resolution of roughly 500 microseconds,
so this is not a rare race, it is the common case for a fast sync pass. Measured with a small
program on this machine, 200000 iterations of st := time.Now(); d := time.Since(st):
== WINDOWS ==
samples=200000 zero-duration=199998 (100.0%) smallest-nonzero=504.3µs
== LINUX (docker) ==
samples=200000 zero-duration=0 (0.0%) smallest-nonzero=15ns
Reproduction, on Windows 11, Go 1.26.6, against main at f744d457:
go test -count=1 -run "TestWatch" ./storage/mvcc/
panic: non-positive interval for Ticker.Reset
goroutine 330 [running]:
time.(*Ticker).Reset(0x7eec7680070?, 0x5f5e100?)
.../src/time/tick.go:67 +0x69
go.etcd.io/etcd/server/v3/storage/mvcc.(*watchableStore).syncWatchersLoop(0x7eec7350140)
.../server/storage/mvcc/watchable_store.go:246 +0x19f
created by go.etcd.io/etcd/server/v3/storage/mvcc.New in goroutine 376
.../server/storage/mvcc/watchable_store.go:87 +0x85
FAIL go.etcd.io/etcd/server/v3/storage/mvcc 6.366s
Reproduced 5 times out of 5. On Linux the same command passes, and the full server module unit
suite passes, which is consistent with the clock resolution measurement above.
Why this has not been noticed: there is no Windows runner in .github/workflows, and the Prow
presubmits are Linux. scripts/build-binary.sh does build and ship windows release binaries
(for os in darwin windows linux), so the affected code does get distributed.
watchableStore.syncWatchersLoopmeasures how long asyncWatcherspass took and, when thepass made progress but watchers are still unsynced, resets its delay ticker to that duration so
the loop yields time to other store operations:
time.Ticker.Resetpanics on a non-positive interval, andtime.Sincecan return exactly zerowhen the pass finishes faster than the platform's monotonic clock can resolve. The panic happens
in a goroutine started by
mvcc.New, so it is not recoverable and takes the process down.On windows/amd64 the Go runtime's monotonic clock has a resolution of roughly 500 microseconds,
so this is not a rare race, it is the common case for a fast sync pass. Measured with a small
program on this machine, 200000 iterations of
st := time.Now(); d := time.Since(st):Reproduction, on Windows 11, Go 1.26.6, against
mainatf744d457:Reproduced 5 times out of 5. On Linux the same command passes, and the full
servermodule unitsuite passes, which is consistent with the clock resolution measurement above.
Why this has not been noticed: there is no Windows runner in
.github/workflows, and the Prowpresubmits are Linux.
scripts/build-binary.shdoes build and shipwindowsrelease binaries(
for os in darwin windows linux), so the affected code does get distributed.