package host import ( "context" "errors" "fmt" "strings" "sync" "testing" "time" "github.com/carlosframework/platform/internal/alerting" "github.com/carlosframework/platform/internal/park" ) // Quiet refusals (Plan 5 Task 9a): the Task 5 provider's expected refusals // are rate-limited in the regional worker's log, and an anomaly pages once // through the box pager. type refusalLog struct { mu sync.Mutex lines []string now time.Time } func (l *refusalLog) logf(format string, args ...any) { l.mu.Lock() defer l.mu.Unlock() l.lines = append(l.lines, fmt.Sprintf(format, args...)) } func (l *refusalLog) clock() time.Time { l.mu.Lock() defer l.mu.Unlock() return l.now } func (l *refusalLog) take() []string { l.mu.Lock() defer l.mu.Unlock() out := l.lines l.lines = nil return out } // TestExpectedMovesRefusalsAreRateLimited: a live move, residue the close // does not vouch for and a named dependency (the wake-source gate's) are // each logged once, then not again within the hour; an unexpected error is // logged every time. func TestExpectedMovesRefusalsAreRateLimited(t *testing.T) { l := &refusalLog{now: evNow} var pages pagesSeen r := newMovesRefusals("ie-box", pages.hook(), l.logf, l.clock) boom := errors.New("listing failed") pass := errors.Join( &MovesSweepRefusal{Host: "a.example", Reason: "the record carries the live move mv_x"}, &NotMovesEvidence{Host: "b.example", Generation: "g", Reason: "written after the close"}, &ClaimDependencyError{Contracts: []string{movesWakeSourceContract}}, boom, ) r.report(pass) if got := l.take(); len(got) != 4 { t.Fatalf("the first pass logged %q", got) } l.now = evNow.Add(30 * time.Minute) r.report(pass) if got := l.take(); len(got) != 1 || !strings.Contains(got[0], boom.Error()) { t.Fatalf("within the hour the pass logged %q; want only the unexpected error", got) } l.now = evNow.Add(61 * time.Minute) r.report(pass) if got := l.take(); len(got) != 4 { t.Fatalf("after the hour the pass logged %q", got) } if len(pages) != 0 { t.Fatalf("an expected refusal paged: %+v", pages) } } // TestMovesAnomalyPagesOnce: an anomaly from either method pages once per // host and reason, as a warning naming the host and the box and carrying no // path; an expected refusal pages nothing, and the error reaches the worker // unchanged. func TestMovesAnomalyPagesOnce(t *testing.T) { l := &refusalLog{now: evNow} var pages pagesSeen r := newMovesRefusals("ie-box", pages.hook(), l.logf, l.clock) f := newEvFixture(t) f.rec.CreatedAt = evCreated.Add(time.Hour) // a record of another incarnation: an anomaly e := r.evidence(f.provider()) obs, census := f.observe(t), f.census(t) for i := 0; i < 3; i++ { _, _, err := e.VerifyRetirement(t.Context(), obs, census) var refusal *MovesSweepRefusal if !errors.As(err, &refusal) || !refusal.Anomaly { t.Fatalf("the wrapper changed the refusal: %v", err) } if _, err := e.VerifyMovesSweep(t.Context(), obs, census); !errors.As(err, &refusal) { t.Fatalf("the wrapper changed the sweep refusal: %v", err) } } if len(pages) != 1 { t.Fatalf("pages %+v, want one", pages) } subject, body := movesAnomalyPage(evHost, "ie-box") if p := pages[0]; p.level != alerting.LevelWarning || p.subject != subject || p.body != body || strings.Contains(p.subject+p.body, "/") { t.Fatalf("page %+v", p) } // An expected refusal of another host pages nothing. g := newEvFixture(t) g.rec.LastMove = nil if _, _, err := r.evidence(g.provider()).VerifyRetirement(t.Context(), g.observe(t), g.census(t)); err == nil { t.Fatal("no refusal") } if len(pages) != 1 { t.Fatalf("an expected refusal paged: %+v", pages) } } // TestRegionalWorkerRefusalsAreQuiet: through the claim's real regional // worker, an anomalous host refuses the sweep every pass, pages once and is // logged once within the hour. func TestRegionalWorkerRefusalsAreQuiet(t *testing.T) { l := &refusalLog{now: evNow} var pages pagesSeen r := newMovesRefusals("ie-box", pages.hook(), l.logf, l.clock) f := newEvFixture(t) f.rec.CreatedAt = evCreated.Add(time.Hour) f.lane(evMoveID, "move.json") // the census finds the host by its objects w := f.worker(t, evNow) e := r.evidence(f.provider()) w.Evidence = e var verifier park.MoveSweepVerifier = e w.Regional.Engine.VerifyMovesSweep = verifier.VerifyMovesSweep for i := 0; i < 3; i++ { err := w.Run(t.Context()) if err == nil { t.Fatal("the sweep ran on an anomaly") } r.report(err) } if lines := l.take(); len(pages) != 1 || len(lines) != 1 { t.Fatalf("pages %+v, log lines %q over three passes", pages, lines) } } // anomalyErr is one anomalous refusal of evHost. var anomalyErr = &MovesSweepRefusal{Host: evHost, Reason: "the record is not the holder's incarnation", Anomaly: true} // TestMovesAnomalyPageRetriesUntilDelivered (fix round 1, I4): a page that // fails is not marked delivered; a later observation, past the backoff, // pages again; once one succeeds nothing more is sent. A pager that always // fails is tried a bounded number of times. func TestMovesAnomalyPageRetriesUntilDelivered(t *testing.T) { l := &refusalLog{now: evNow} calls, fail := 0, true r := newMovesRefusals("ie-box", func(context.Context, string, string, string) error { calls++ if fail { return errors.New("the webhook answered 503") } return nil }, l.logf, l.clock) r.observe(t.Context(), anomalyErr) if calls != 1 { t.Fatalf("first observation: %d calls", calls) } l.now = evNow.Add(30 * time.Second) r.observe(t.Context(), anomalyErr) if calls != 1 { t.Fatalf("inside the backoff: %d calls", calls) } fail = false l.now = evNow.Add(2 * time.Minute) r.observe(t.Context(), anomalyErr) if calls != 2 { t.Fatalf("after the backoff: %d calls", calls) } for i := 0; i < 5; i++ { l.now = l.now.Add(time.Hour) r.observe(t.Context(), anomalyErr) } if calls != 2 { t.Fatalf("after a delivered page: %d calls", calls) } l2 := &refusalLog{now: evNow} always := 0 r2 := newMovesRefusals("ie-box", func(context.Context, string, string, string) error { always++; return errors.New("down") }, l2.logf, l2.clock) for i := 0; i < 50; i++ { r2.observe(t.Context(), anomalyErr) l2.now = l2.now.Add(2 * time.Hour) } if always != movesPageAttempts { t.Fatalf("a pager that always fails was called %d times, want %d", always, movesPageAttempts) } } // TestMovesAnomalyPageIsNotDoubled (fix round 1, I4): while one page is in // flight, a concurrent observation of the same anomaly does not page again. func TestMovesAnomalyPageIsNotDoubled(t *testing.T) { l := &refusalLog{now: evNow} var mu sync.Mutex calls := 0 entered, release := make(chan struct{}), make(chan struct{}) r := newMovesRefusals("ie-box", func(context.Context, string, string, string) error { mu.Lock() calls++ mu.Unlock() close(entered) <-release return nil }, l.logf, l.clock) done := make(chan struct{}) go func() { r.observe(context.Background(), anomalyErr); close(done) }() <-entered r.observe(t.Context(), anomalyErr) // in flight: skipped, does not block close(release) <-done r.observe(t.Context(), anomalyErr) mu.Lock() defer mu.Unlock() if calls != 1 { t.Fatalf("%d pages, want one", calls) } }