From 2ab6e7843ad7bab92201d07d339872563458590b Mon Sep 17 00:00:00 2001 From: prosolis <5590409+prosolis@users.noreply.github.com> Date: Mon, 13 Jul 2026 18:19:16 -0700 Subject: [PATCH] roster: a quietly-succeeding ticker looks exactly like a dead one MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The push logged nothing on success, so during the first deploy an empty board and a silent log were indistinguishable from a ticker that never started — and the debug went looking for a bug that wasn't there. (The snapshot was simply 2 minutes out; the first tick hadn't fired yet.) Logging every push at INFO would be noise forever. Log the transitions instead: the first time it works, the moment it breaks, and when it recovers. --- internal/plugin/pete_roster.go | 27 ++++++++++++++++++++++++--- 1 file changed, 24 insertions(+), 3 deletions(-) diff --git a/internal/plugin/pete_roster.go b/internal/plugin/pete_roster.go index e3761c7..c8900fe 100644 --- a/internal/plugin/pete_roster.go +++ b/internal/plugin/pete_roster.go @@ -51,6 +51,14 @@ func (p *AdventurePlugin) peteRosterTicker() { } } +// rosterPushOK tracks the last push's outcome so we can log the transitions and +// nothing else. A push every 2 minutes forever is far too noisy to log at INFO, +// but total silence is worse: a ticker that is succeeding quietly looks exactly +// like one that never started, and that ambiguity already cost an operator a +// wrong-turn debug during the first deploy. So: say something the first time it +// works, say something when it breaks, say something when it recovers. +var rosterPushOK bool + func (p *AdventurePlugin) pushRoster() { snap, err := buildRosterSnapshot(time.Now().UTC()) if err != nil { @@ -59,11 +67,24 @@ func (p *AdventurePlugin) pushRoster() { } ctx, cancel := context.WithTimeout(context.Background(), rosterPushTimeout) defer cancel() + if err := peteclient.PushRoster(ctx, snap); err != nil { - // Not an error worth shouting about: the next tick retries by simply + // The failure itself is not alarming — the next tick retries by simply // being a fresher snapshot, and if we stay down Pete's board correctly - // stops claiming to be live. - slog.Warn("roster: push failed, dropping snapshot", "err", err) + // stops claiming to be live. Only the *transition* is worth a line. + if rosterPushOK { + slog.Warn("roster: push failed, board will go stale on Pete", "err", err) + } else { + slog.Debug("roster: push failed, dropping snapshot", "err", err) + } + rosterPushOK = false + return + } + + if !rosterPushOK { + slog.Info("roster: board accepted by Pete — live adventurer board is publishing", + "adventurers", len(snap.Adventurers)) + rosterPushOK = true } }