From b66c895ff3d298a542b00b6abd22055c4a7bacd3 Mon Sep 17 00:00:00 2001 From: gen16k Date: Sun, 2 Aug 2026 06:30:42 +0000 Subject: [PATCH] test(agent): give the peer reconciler a clock seam and delete the timing sleeps (#357, #384) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit TestReconciler_SafetyNetSilencedByRecentDirectEvidence was a coin flip on Windows. It injected direct evidence, slept 35ms, then required that less than FallbackAfter (50ms) had passed -- 15ms of slack against a platform whose default timer granularity is ~15.6ms and whose time.Sleep rounds up to the next tick. One tick of overshoot inverted the assertion. Linux's ~1ms timers hid it, so it only ever failed on the Windows leg, on PRs that had not touched cmd/waired-agent at all (#355, #367, and again here). Both issues asked for the seam rather than a wider window, and CLAUDE.md §Test discipline says the same: put the seam below the behaviour under test. Widening only moves the coin toss. The reconciler turns out to need a very small one. It reaches for the wall clock in exactly two places -- Apply and Tick -- because every disco-driven decision is already stamped from the event's own At (evaluateSwitchLocked takes e.At). So a single `now func() time.Time`, defaulted to time.Now in newReconciler, covers the entire surface. With it, all seven time.Sleep calls in reconcile_test.go are gone: * the five Apply/Tick-timed tests install the fakeClock that setup_desired_test.go already defines for the setup executor, and say the elapsed time exactly rather than approximating it; * TestReconciler_NoFlapWithinDwellTime needed no seam at all -- dwell is measured from lastSwitchAt, which its own event stamped, so it just passes a later At. Of those seven, only the two in the safety-net silencing test were ever at risk: the rest sleep PAST a threshold and want it crossed, so overshoot was harmless. They are converted for determinism, not because they were failing. #357 asked for exactly that sweep. Package tests drop from ~0.5s of real sleeping to 0.27s. Verified the tests did not go green for the wrong reason -- each one still fails with its subject behaviour removed: * silencing rule (reconcile.go:841) neutralised -> SafetyNetSilenced fails * handshake gate (:847) neutralised -> StaysDirectIfHandshake fails * dwell gate (:512) neutralised -> NoFlapWithinDwellTime fails * safety net forced to never fire (:835) -> both firing tests fail TestNewReconcilerHasAClock pins the production wiring: a constructor path that forgets the clock would not fail any timing test (those install their own) -- it would nil-panic in Apply on a real agent. Verified: go build ./..., go vet, gofmt, golangci-lint (0 issues), TestReconciler_* at -count=30. Fixes #357 Fixes #384 Signed-off-by: gen16k --- cmd/waired-agent/reconcile.go | 15 +++++- cmd/waired-agent/reconcile_test.go | 85 ++++++++++++++++++++++++------ 2 files changed, 82 insertions(+), 18 deletions(-) diff --git a/cmd/waired-agent/reconcile.go b/cmd/waired-agent/reconcile.go index 6c25c1e4f..bc2696eb3 100644 --- a/cmd/waired-agent/reconcile.go +++ b/cmd/waired-agent/reconcile.go @@ -178,6 +178,16 @@ type reconciler struct { // unit tests that exercise reconciler logic only. disco discoSubsystem + // now is the reconciler's clock, read by Apply and Tick — the only + // two places that reach for the wall clock (every disco-driven + // decision is stamped from the event's own At instead). Production + // leaves it at time.Now; tests replace it so an assertion about a + // duration cannot be decided by how long a sleep actually took. See + // #357/#384: the safety-net silencing test allowed 15 ms of slack + // against Windows' ~15.6 ms timer tick, so one tick of sleep + // overshoot flipped it — on Windows it was a coin toss, not a test. + now func() time.Time + mu sync.Mutex nm *signer.NetworkMap state map[string]*peerPathState // keyed by peer NodePublicKey (std-base64) @@ -282,6 +292,7 @@ func newReconciler(engine peerEngine, provider *agentProvider, logger *slog.Logg logger: logger, cfg: cfg.withDefaults(), id: id, + now: time.Now, state: map[string]*peerPathState{}, } } @@ -644,7 +655,7 @@ func pongRingFull(st *peerPathState, capN int) bool { func (r *reconciler) Apply(nm *signer.NetworkMap) error { r.mu.Lock() r.nm = nm - now := time.Now() + now := r.now() live := make(map[string]struct{}, len(nm.Peers)) r.logNames = make(map[string]string, len(nm.Peers)) added := 0 @@ -805,7 +816,7 @@ func (r *reconciler) Tick(ctx context.Context) { r.mu.Unlock() return } - now := time.Now() + now := r.now() changed := false for _, p := range r.nm.Peers { st := r.state[p.NodePublicKey] diff --git a/cmd/waired-agent/reconcile_test.go b/cmd/waired-agent/reconcile_test.go index 7f8f410be..a96f410a5 100644 --- a/cmd/waired-agent/reconcile_test.go +++ b/cmd/waired-agent/reconcile_test.go @@ -149,6 +149,44 @@ func fastTestConfig() reconcilerConfig { } } +// useFakeClock installs c (the same fakeClock the setup-executor tests +// use, setup_desired_test.go) as the peer reconciler's clock. Call it +// before the first Apply so every timestamp the reconciler stamps comes +// from c. +// +// The reconciler reaches for the wall clock in exactly two places — +// Apply and Tick — and every disco-driven decision is already stamped +// from the event's own At, so this covers the whole surface and lets the +// timing tests below state elapsed time exactly instead of approximating +// it with sleeps. +// +// This is a fix, not extra margin (#357/#384). The safety-net silencing +// test used to inject evidence 35 ms before a Tick and require less than +// FallbackAfter (50 ms) to have passed — 15 ms of slack, under Windows' +// ~15.6 ms timer granularity, where time.Sleep rounds up to the next +// tick. It failed there about as often as it passed while staying green +// on Linux's ~1 ms timers. Widening the window would only have moved the +// coin toss; taking the clock away removes it. +func useFakeClock(rec *reconciler, c *fakeClock) { + rec.mu.Lock() + defer rec.mu.Unlock() + rec.now = c.now +} + +// TestNewReconcilerHasAClock pins the production wiring: newReconciler +// must leave a usable clock behind. A future constructor path that +// forgets it would not fail a timing test — the tests that care install +// their own — it would nil-panic in Apply on a real agent. +func TestNewReconcilerHasAClock(t *testing.T) { + rec := newReconciler(&fakeEngine{}, &agentProvider{}, quietLogger(), nil, fastTestConfig()) + if rec.now == nil { + t.Fatal("newReconciler left now nil; Apply/Tick would panic in production") + } + if got := rec.now(); got.IsZero() { + t.Errorf("default clock returned the zero time (%v), want the wall clock", got) + } +} + // --- LEGACY behaviour, repurposed for the new model --- // TestReconciler_SafetyNetFiresWhenProbesSilent: when no disco events @@ -164,6 +202,8 @@ func TestReconciler_SafetyNetFiresWhenProbesSilent(t *testing.T) { eng := &fakeEngine{} prov := &agentProvider{} rec := newReconciler(eng, prov, quietLogger(), nil, fastTestConfig()) + clk := newFakeClock() + useFakeClock(rec, clk) if err := rec.Apply(nm); err != nil { t.Fatalf("Apply: %v", err) @@ -178,10 +218,10 @@ func TestReconciler_SafetyNetFiresWhenProbesSilent(t *testing.T) { t.Fatalf("expected direct still after early Tick, got %q", got) } - // Wait past fallback-after AND past last-direct-evidence (= Apply + // Move past fallback-after AND past last-direct-evidence (= Apply // time). No disco events ever arrived (probes silent), no WG // handshake completed → safety net fires. - time.Sleep(rec.cfg.FallbackAfter + 25*time.Millisecond) + clk.advance(rec.cfg.FallbackAfter + 25*time.Millisecond) rec.Tick(context.Background()) if got := eng.lastEndpointFor(pubA); !strings.HasPrefix(got, "relay:") { t.Fatalf("expected relay endpoint after safety-net fallback, got %q", got) @@ -200,17 +240,20 @@ func TestReconciler_StaysDirectIfHandshakeSucceeds(t *testing.T) { eng := &fakeEngine{} prov := &agentProvider{} rec := newReconciler(eng, prov, quietLogger(), nil, fastTestConfig()) + clk := newFakeClock() + useFakeClock(rec, clk) if err := rec.Apply(nm); err != nil { t.Fatalf("Apply: %v", err) } - // Simulate a successful handshake observed mid-window. - time.Sleep(rec.cfg.FallbackAfter / 2) - eng.setHandshake(pubA, time.Now()) + // Simulate a successful handshake observed mid-window. It must land + // after Apply's lastEvalAt — that ordering is the gate under test. + clk.advance(rec.cfg.FallbackAfter / 2) + eng.setHandshake(pubA, clk.now()) - // Wait past fallback-after and Tick; should stay direct. - time.Sleep(rec.cfg.FallbackAfter) + // Move past fallback-after and Tick; should stay direct. + clk.advance(rec.cfg.FallbackAfter) rec.Tick(context.Background()) if got := eng.lastEndpointFor(pubA); !strings.HasPrefix(got, "udp4:") { t.Fatalf("expected direct UDP after successful handshake, got %q", got) @@ -721,11 +764,14 @@ func TestReconciler_NoFlapWithinDwellTime(t *testing.T) { t.Fatalf("dwell suppression broken: expected relay still, got %q", got) } - // Wait past dwell, then a fresh sample should let the upgrade fire. - time.Sleep(cfg.MinDwellTime + 25*time.Millisecond) + // Past dwell, a fresh sample should let the upgrade fire. The dwell + // window is measured against lastSwitchAt, which the downgrade above + // stamped from its event's At — so saying "later than that" with a + // timestamp is exact, where a sleep only approximated it. rec.OnDiscoEvent(disco.EventProbeRTTSampled{ PeerNodePub: pubA, PeerDeviceID: "dev_peer_a", - Path: pathDirect, RTT: 5 * time.Millisecond, At: time.Now(), + Path: pathDirect, RTT: 5 * time.Millisecond, + At: now.Add(cfg.MinDwellTime + time.Millisecond), }) if got := eng.lastEndpointFor(pubA); !strings.HasPrefix(got, "udp4:") { t.Fatalf("expected upgrade after dwell elapsed, got %q", got) @@ -816,18 +862,23 @@ func TestReconciler_SafetyNetSilencedByRecentDirectEvidence(t *testing.T) { eng := &fakeEngine{} prov := &agentProvider{} rec := newReconciler(eng, prov, quietLogger(), nil, fastTestConfig()) + clk := newFakeClock() + useFakeClock(rec, clk) if err := rec.Apply(nm); err != nil { t.Fatalf("Apply: %v", err) } - // Wait past FallbackAfter, but inject an RTT sample mid-way so - // lastDirectEvidenceAt is recent. Safety net must NOT fire. - time.Sleep(rec.cfg.FallbackAfter / 2) + // Move past FallbackAfter so the lastEvalAt gate opens, but inject an + // RTT sample mid-way so lastDirectEvidenceAt stays recent. At the Tick + // below, exactly FallbackAfter+10ms has passed since Apply (gate open) + // and exactly FallbackAfter/2+10ms since the evidence (still inside + // the silencing window). Safety net must NOT fire. + clk.advance(rec.cfg.FallbackAfter / 2) rec.OnDiscoEvent(disco.EventProbeRTTSampled{ PeerNodePub: pubA, PeerDeviceID: "dev_peer_a", - Path: pathDirect, RTT: 80 * time.Millisecond, At: time.Now(), + Path: pathDirect, RTT: 80 * time.Millisecond, At: clk.now(), }) - time.Sleep(rec.cfg.FallbackAfter/2 + 10*time.Millisecond) + clk.advance(rec.cfg.FallbackAfter/2 + 10*time.Millisecond) rec.Tick(context.Background()) if got := eng.lastEndpointFor(pubA); !strings.HasPrefix(got, "udp4:") { @@ -845,11 +896,13 @@ func TestReconciler_ColdStartUsesSafetyNet(t *testing.T) { eng := &fakeEngine{} prov := &agentProvider{} rec := newReconciler(eng, prov, quietLogger(), nil, fastTestConfig()) + clk := newFakeClock() + useFakeClock(rec, clk) if err := rec.Apply(nm); err != nil { t.Fatalf("Apply: %v", err) } - time.Sleep(rec.cfg.FallbackAfter + 25*time.Millisecond) + clk.advance(rec.cfg.FallbackAfter + 25*time.Millisecond) rec.Tick(context.Background()) if got := eng.lastEndpointFor(pubA); !strings.HasPrefix(got, "relay:") { t.Fatalf("expected relay after cold-start safety net, got %q", got)