From ac5d34f613120754d53425965b8e0e1f52ce9f10 Mon Sep 17 00:00:00 2001 From: jochen Date: Mon, 12 Oct 2026 11:41:41 +0200 Subject: [PATCH] Give the unheld log test its own writer and memory, so it passes on a repeat (novox/hq issue 486) logUnheld kept what it had logged in package state and the test swapped os.Stderr, so a second run in one process logged nothing and failed. --- cmd/mesh-controller/plan.go | 35 ++++++++++++++++------- cmd/mesh-controller/unheld_report_test.go | 21 +++++++------- 2 files changed, 36 insertions(+), 20 deletions(-) diff --git a/cmd/mesh-controller/plan.go b/cmd/mesh-controller/plan.go index 2ec829b1..b4811f4e 100644 --- a/cmd/mesh-controller/plan.go +++ b/cmd/mesh-controller/plan.go @@ -7,6 +7,7 @@ import ( "errors" "flag" "fmt" + "io" "os" "slices" "sort" @@ -1691,17 +1692,27 @@ func providerModuleOf(resolved catalogue.Resolution, open *stores, ctx context.C return "" } -// unheldLogged is what was last logged about each node's unmet seat dependencies, so the log says -// each change once (novox/hq ADR 0207), on stderr so `status --json` stays a document. +// unheldLogger remembers what was last logged about each node's unmet seat dependencies, so the +// log says each change once (novox/hq ADR 0207), on stderr so `status --json` stays a document. +// A test gives its own writer and memory, and no longer shares the process's (novox/hq issue 486). // // **The serving controller's log only.** planFor runs for every node on every push, assignment and // status — `blockedElsewhere` alone resolves the whole mesh — and a one-shot command starts with an // empty memory, so every node's report was "a change" and a push printed the whole mesh's list, // burying the line about the node it acted on. A command says what concerns its own act instead // (unheldChange, reportUnheldPushed); the full list is `status`'s. +type unheldLogger struct { + mu sync.Mutex + logged map[string]string + out io.Writer +} + +func newUnheldLogger(out io.Writer) *unheldLogger { + return &unheldLogger{logged: map[string]string{}, out: out} +} + var ( - unheldLogged = map[string]string{} - unheldLoggedMu sync.Mutex + unheldLog = newUnheldLogger(os.Stderr) logUnheldChanges bool ) @@ -1711,23 +1722,27 @@ func logUnheld(node string, unheld []catalogue.Unheld) { if !logUnheldChanges { return } + unheldLog.log(node, unheld) +} + +func (l *unheldLogger) log(node string, unheld []catalogue.Unheld) { lines := make([]string, 0, len(unheld)) for _, u := range unheld { lines = append(lines, u.String()) } now := strings.Join(lines, "\n") - unheldLoggedMu.Lock() - before, seen := unheldLogged[node] - unheldLogged[node] = now - unheldLoggedMu.Unlock() + l.mu.Lock() + defer l.mu.Unlock() + before, seen := l.logged[node] + l.logged[node] = now if (seen && before == now) || (!seen && now == "") { return } if now == "" { - fmt.Fprintf(os.Stderr, "%s: every seat its modules depend on is held (novox/hq ADR 0207)\n", node) + fmt.Fprintf(l.out, "%s: every seat its modules depend on is held (novox/hq ADR 0207)\n", node) return } - fmt.Fprintf(os.Stderr, "%s: %d unmet seat dependenc(ies), reported and not refused (novox/hq ADR 0207):\n %s\n", + fmt.Fprintf(l.out, "%s: %d unmet seat dependenc(ies), reported and not refused (novox/hq ADR 0207):\n %s\n", node, len(lines), strings.Join(lines, "\n ")) } diff --git a/cmd/mesh-controller/unheld_report_test.go b/cmd/mesh-controller/unheld_report_test.go index 1339eda3..9430d671 100644 --- a/cmd/mesh-controller/unheld_report_test.go +++ b/cmd/mesh-controller/unheld_report_test.go @@ -2,7 +2,6 @@ package main import ( "bytes" - "os" "strings" "testing" @@ -81,28 +80,30 @@ func TestAPushSaysANamedNodesDependenciesAndCountsTheRest(t *testing.T) { } } +// The test gives logUnheld its own writer and memory, so a repeat in one process and the +// package's other tests see neither the last run's memory nor a swapped os.Stderr (novox/hq issue 486). func TestOnlyTheServingControllerLogsEachChange(t *testing.T) { + var out bytes.Buffer + saved, savedOn := unheldLog, logUnheldChanges + unheldLog, logUnheldChanges = newUnheldLogger(&out), false + t.Cleanup(func() { unheldLog, logUnheldChanges = saved, savedOn }) read := func(f func()) string { - old := os.Stderr - r, w, _ := os.Pipe() - os.Stderr = w + out.Reset() f() - _ = w.Close() - os.Stderr = old - var b bytes.Buffer - _, _ = b.ReadFrom(r) - return b.String() + return out.String() } u := []catalogue.Unheld{{Node: "n1", Module: "web", Seat: catalogue.ContainerRuntimeSeat}} if got := read(func() { logUnheld("n1", u) }); got != "" { t.Errorf("a command logged:\n%s", got) } logUnheldChanges = true - defer func() { logUnheldChanges = false }() if got := read(func() { logUnheld("n1", u) }); !strings.Contains(got, "web on n1") { t.Errorf("the serving controller did not log a change:\n%s", got) } if got := read(func() { logUnheld("n1", u) }); got != "" { t.Errorf("an unchanged report was logged again:\n%s", got) } + if got := read(func() { logUnheld("n1", nil) }); !strings.Contains(got, "every seat its modules depend on is held") { + t.Errorf("a report that became none was not logged:\n%s", got) + } }