From babde88de0e5577b3489c00c08172b1f381efdd0 Mon Sep 17 00:00:00 2001 From: Julian Sommer <115516918+juliansommer@users.noreply.github.com> Date: Wed, 2 Sep 2026 11:27:29 +1000 Subject: [PATCH] test: cover waitForClusterReady via a sleep and deadline seam The readiness loop terminates on wall clock, so a stubbed sleep alone still costs two minutes; clusterReadyMaxWait becomes a var alongside clusterReadySleep so the timeout branch is reachable. Adds the in-package marker to the EIP association tests, which drive setupTestEIP and read svc.natsConn. --- spinifex/daemon/cluster_ready_test.go | 130 ++++++++++++++++++++ spinifex/daemon/daemon.go | 11 +- spinifex/handlers/ec2/eip/associate_test.go | 3 + 3 files changed, 142 insertions(+), 2 deletions(-) create mode 100644 spinifex/daemon/cluster_ready_test.go diff --git a/spinifex/daemon/cluster_ready_test.go b/spinifex/daemon/cluster_ready_test.go new file mode 100644 index 000000000..eb9ea479a --- /dev/null +++ b/spinifex/daemon/cluster_ready_test.go @@ -0,0 +1,130 @@ +//test:in-package — waitForClusterReady and its sleep/deadline seams +//(clusterReadySleep, clusterReadyMaxWait) are unexported, and the tests build a +//Daemon with an unexported natsConn field. + +package daemon + +import ( + "bytes" + "log/slog" + "net" + "net/http" + "net/http/httptest" + "net/url" + "testing" + "time" + + "github.com/mulgadc/spinifex/spinifex/config" + "github.com/mulgadc/spinifex/spinifex/testutil" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +// stubClusterReadySleep swaps the waitForClusterReady poll delay for fn so tests +// drive the loop instead of waiting out 2s per iteration. Restored via t.Cleanup. +func stubClusterReadySleep(t *testing.T, fn func(time.Duration)) { + t.Helper() + prev := clusterReadySleep + clusterReadySleep = fn + t.Cleanup(func() { clusterReadySleep = prev }) +} + +// stubClusterReadyMaxWait shortens the readiness deadline so the timeout branch +// is reachable inside the package test timeout. +func stubClusterReadyMaxWait(t *testing.T, d time.Duration) { + t.Helper() + prev := clusterReadyMaxWait + clusterReadyMaxWait = d + t.Cleanup(func() { clusterReadyMaxWait = prev }) +} + +// captureWarnLogs redirects the default logger so the readiness outcome, which +// the function reports only by logging, can be asserted. +func captureWarnLogs(t *testing.T) *bytes.Buffer { + t.Helper() + buf := &bytes.Buffer{} + prev := slog.Default() + slog.SetDefault(slog.New(slog.NewTextHandler(buf, &slog.HandlerOptions{Level: slog.LevelWarn}))) + t.Cleanup(func() { slog.SetDefault(prev) }) + return buf +} + +// closedPort returns an address nothing is listening on. +func closedPort(t *testing.T) string { + t.Helper() + l, err := net.Listen("tcp", "127.0.0.1:0") + require.NoError(t, err) + addr := l.Addr().String() + require.NoError(t, l.Close()) + return addr +} + +// TestWaitForClusterReady_ReadyImmediately asserts the loop returns on the first +// pass without sleeping when both dependencies are already reachable. +func TestWaitForClusterReady_ReadyImmediately(t *testing.T) { + _, nc := testutil.StartTestNATS(t) + + sleeps := 0 + stubClusterReadySleep(t, func(time.Duration) { sleeps++ }) + logs := captureWarnLogs(t) + + d := &Daemon{config: &config.Config{}, natsConn: nc} + d.waitForClusterReady() + + assert.Equal(t, 0, sleeps, "ready on first check must not sleep") + assert.NotContains(t, logs.String(), "Cluster readiness timeout") +} + +// TestWaitForClusterReady_PredastoreBecomesReady asserts the loop keeps polling +// while predastore is unreachable and returns once it starts serving, rather +// than latching the first not-ready result. +func TestWaitForClusterReady_PredastoreBecomesReady(t *testing.T) { + _, nc := testutil.StartTestNATS(t) + + srv := httptest.NewTLSServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { + w.WriteHeader(http.StatusForbidden) + })) + t.Cleanup(srv.Close) + u, err := url.Parse(srv.URL) + require.NoError(t, err) + + d := &Daemon{ + config: &config.Config{Predastore: config.PredastoreConfig{Host: closedPort(t)}}, + natsConn: nc, + } + + // Point predastore at the live server from inside the poll delay, so the + // second iteration observes it without waiting on wall-clock time. + sleeps := 0 + stubClusterReadySleep(t, func(time.Duration) { + sleeps++ + d.config.Predastore.Host = u.Host + }) + logs := captureWarnLogs(t) + + d.waitForClusterReady() + + assert.Equal(t, 1, sleeps, "must poll again after predastore reports not ready") + assert.NotContains(t, logs.String(), "Cluster readiness timeout") +} + +// TestWaitForClusterReady_TimesOut asserts the deadline branch: with viperblock +// permanently unreachable the loop gives up at maxWait, logs the warning and +// returns so recovery proceeds anyway, instead of blocking startup forever. +func TestWaitForClusterReady_TimesOut(t *testing.T) { + stubClusterReadyMaxWait(t, 20*time.Millisecond) + + sleeps := 0 + stubClusterReadySleep(t, func(time.Duration) { + sleeps++ + time.Sleep(5 * time.Millisecond) + }) + logs := captureWarnLogs(t) + + // natsConn nil means viperblock never reports ready. + d := &Daemon{config: &config.Config{}} + d.waitForClusterReady() + + assert.Positive(t, sleeps, "must poll before timing out") + assert.Contains(t, logs.String(), "Cluster readiness timeout, proceeding with recovery anyway") +} diff --git a/spinifex/daemon/daemon.go b/spinifex/daemon/daemon.go index 49596d02a..e71de43a7 100644 --- a/spinifex/daemon/daemon.go +++ b/spinifex/daemon/daemon.go @@ -2300,11 +2300,18 @@ func initServiceWithRetry[T any](name string, initFn func() (T, error)) (T, erro } } +// clusterReadySleep is the poll delay seam used by waitForClusterReady, and +// clusterReadyMaxWait bounds the loop; tests override both. +var ( + clusterReadySleep = time.Sleep + clusterReadyMaxWait = 2 * time.Minute +) + // waitForClusterReady blocks until viperblock and predastore are reachable, // preventing races during VM recovery. func (d *Daemon) waitForClusterReady() { slog.Info("Waiting for cluster readiness...") - maxWait := 2 * time.Minute + maxWait := clusterReadyMaxWait start := time.Now() interval := 2 * time.Second @@ -2330,7 +2337,7 @@ func (d *Daemon) waitForClusterReady() { } slog.Debug("Cluster not ready, waiting...", "reason", reason, "elapsed_ms", otelsetup.Millis(time.Since(start))) - time.Sleep(interval) + clusterReadySleep(interval) } slog.Warn("Cluster readiness timeout, proceeding with recovery anyway", "max_wait_ms", otelsetup.Millis(maxWait)) diff --git a/spinifex/handlers/ec2/eip/associate_test.go b/spinifex/handlers/ec2/eip/associate_test.go index 9014eba05..404d2bc44 100644 --- a/spinifex/handlers/ec2/eip/associate_test.go +++ b/spinifex/handlers/ec2/eip/associate_test.go @@ -1,3 +1,6 @@ +//test:in-package — these tests drive the package's own setupTestEIP fixture and +//read svc.natsConn to assert the NAT messages AssociateAddress publishes. + package handlers_ec2_eip import (