etcd-io / etcd-io/etcd

mvcc: syncWatchersLoop can panic with "non-positive interval for Ticker.Reset" where the monotonic clock is coarse (windows/amd64)

Open
#22,296 0 comments 0 reactions 0 assignees View on GitHub
Dominant language
Go
Stars
52.3k
Forks
10.5k
Avg merge
3d 1h
Merged PRs (30d)
44

Description

`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:

```go
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.

Contributor guide

Open the contributing guide

Research direction

Start in server/storage/mvcc/watchable_store.go at syncWatchersLoop and inspect the delayTicker.Reset calls around the sync duration measurement. Run go test -count=1 -run "TestWatch" ./storage/mvcc/ on Windows or another coarse-clock environment, then verify the watcher tests complete without a non-positive Ticker.Reset panic.

Written by the indexing model from the issue text.

Assessment

Tech stack
go
Domain
databases, distributed-systems
Issue type
Bug
Difficulty
3/5
Estimated time
1-2 days
Activity status
Quiet
Clarity
Mostly clear
Newbie friendliness
72/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.