package calls import ( "bytes" "context" "io" "log/slog" "path/filepath" "strings" "sync" "testing" "amadan.net/rastrillo/rastrillo/db" ) // openRelayTestDB is a fresh temp database for the app-level relay // wiring tests below: build() and NewForTest need a real *db.DB, not // the bare Config resolve() takes. func openRelayTestDB(t *testing.T, logger *slog.Logger) *db.DB { t.Helper() d, err := db.Open(filepath.Join(t.TempDir(), "relay.db"), logger) if err != nil { t.Fatal(err) } t.Cleanup(func() { d.Close() }) return d } // TestSetRelayFlipsRelayConfigured is the with-relay path through // build: nothing before this exercised SetRelay at all — the config // package tests only ever checked resolved.relayConfigured, which // build() never reads back through the app's own atomic. func TestSetRelayFlipsRelayConfigured(t *testing.T) { cfg := minimalConfig(t) cfg.Env = EnvDevelopment d := openRelayTestDB(t, slog.New(slog.NewTextHandler(io.Discard, nil))) _, ctl, err := NewForTest(d, cfg) if err != nil { t.Fatal(err) } t.Cleanup(ctl.ShutdownForTest) // stops the sign-in mail worker if ctl.a.relayConfigured() { t.Fatal("expected no relay at boot") } if err := ctl.SetRelay(relayVector(t)); err != nil { t.Fatal(err) } if !ctl.a.relayConfigured() || len(ctl.a.relayRegions()) != 1 { t.Fatalf("SetRelay did not flip relayConfigured: configured=%v regions=%d", ctl.a.relayConfigured(), len(ctl.a.relayRegions())) } } // TestBuildLogsOneINFOLineWithTheRegionCountAndNotTheKey: build()'s own // INFO line was untested — make ci passed with a hardcoded Floor and no // assertion on the log at all, so a mutation that dropped the line, or // one that logged the raw contract instead of its length, would have // survived. func TestBuildLogsOneINFOLineWithTheRegionCountAndNotTheKey(t *testing.T) { var buf bytes.Buffer rec := newRecordingHandler(slog.NewTextHandler(&buf, nil)) logger := slog.New(rec) cfg := minimalConfig(t) cfg.Logger = logger cfg.Relay = relayVector(t) d := openRelayTestDB(t, logger) _, a, err := buildForTest(t, d, cfg) if err != nil { t.Fatal(err) } // The INFO line alone does not prove build() ever stored the parsed // contract into the app's own atomic — a log call that ran and a // Store call that didn't would still print this line. Assert both. if !a.relayConfigured() || len(a.relayRegions()) != 1 { t.Fatalf("build did not store the parsed relay: configured=%v regions=%d", a.relayConfigured(), len(a.relayRegions())) } // Records, not substrings. A substring search says nothing about how // many lines there were, what level they were at, or what else they // carried: two identical lines, a WARN, or a line that also logged a // decoded region would all have passed (Codex S3-6). var configured []slog.Record for _, r := range rec.records() { if r.Message == "calls: relay configured" { configured = append(configured, r) } } if len(configured) != 1 { t.Fatalf("want exactly one \"calls: relay configured\" record, got %d:\n%s", len(configured), buf.String()) } got := configured[0] if got.Level != slog.LevelInfo { t.Fatalf("the relay line is %s, not INFO", got.Level) } // A slice, not a map: a map collapses two attributes that share a // key, so `regions=1, regions=` would have read // as one attribute and passed (Codex S3-11). And the value is // checked as an int64, not as its rendering, so a string "1" is not // mistaken for the count. attrs := recordAttrs(got) if len(attrs) != 1 { t.Fatalf("want exactly one attribute on the relay line, got %d: %v", len(attrs), attrs) } if attrs[0].Key != "regions" { t.Fatalf("the one attribute is %q, not regions", attrs[0].Key) } if attrs[0].Value.Kind() != slog.KindInt64 || attrs[0].Value.Int64() != 1 { t.Fatalf("regions is %v (%s), want the int64 1", attrs[0].Value, attrs[0].Value.Kind()) } if log := buf.String(); strings.Contains(log, "uMhwW4P") { t.Fatal("the relay key reached the log") } } // recordingHandler keeps every record whole so a test can ask how many // there were, at what level, and with which attributes — the three // questions a rendered line cannot answer. It forwards to a real // handler as well, so a failure can still print what was written. // // The store is shared with every handler derived from this one, and the // attributes and groups bound along the way are kept and replayed onto // each record. Without both, a logger reached through WithAttrs wrote // into a store nobody read, and the attributes it was carrying were // invisible to the assertions — so a line that logged the decoded // contract through a bound attribute would have passed a test whose // name says it cannot (Codex S3-11). type recordingHandler struct { inner slog.Handler store *recordStore bound []slog.Attr groups []string } type recordStore struct { mu sync.Mutex kept []slog.Record } func newRecordingHandler(inner slog.Handler) *recordingHandler { return &recordingHandler{inner: inner, store: &recordStore{}} } func (h *recordingHandler) Enabled(ctx context.Context, l slog.Level) bool { return h.inner.Enabled(ctx, l) } func (h *recordingHandler) Handle(ctx context.Context, r slog.Record) error { kept := r.Clone() if len(h.bound) > 0 { // Bound attributes belong to the record as much as the ones the // call site passed: they are what a reader of the line sees. front := slog.NewRecord(r.Time, r.Level, r.Message, r.PC) front.AddAttrs(h.bound...) r.Attrs(func(a slog.Attr) bool { front.AddAttrs(a) return true }) kept = front } if len(h.groups) > 0 { // A grouped record is not the shape this test is about, and // pretending otherwise would hide it: keep it whole and let the // count assertion speak. kept.AddAttrs(slog.String("__groups", strings.Join(h.groups, "."))) } h.store.mu.Lock() h.store.kept = append(h.store.kept, kept) h.store.mu.Unlock() return h.inner.Handle(ctx, r) } func (h *recordingHandler) WithAttrs(as []slog.Attr) slog.Handler { return &recordingHandler{ inner: h.inner.WithAttrs(as), store: h.store, bound: append(append([]slog.Attr(nil), h.bound...), as...), groups: h.groups, } } func (h *recordingHandler) WithGroup(name string) slog.Handler { return &recordingHandler{ inner: h.inner.WithGroup(name), store: h.store, bound: h.bound, groups: append(append([]string(nil), h.groups...), name), } } func (h *recordingHandler) records() []slog.Record { h.store.mu.Lock() defer h.store.mu.Unlock() return append([]slog.Record(nil), h.store.kept...) } // recordAttrs is a record's attributes in order, duplicates and all. func recordAttrs(r slog.Record) []slog.Attr { var out []slog.Attr r.Attrs(func(a slog.Attr) bool { out = append(out, a) return true }) return out } // TestTheRecordingHandlerSeesWhatALoggerCarries is a test of the test: // the assertions above are only worth their names if the handler under // them keeps duplicate keys apart and carries bound attributes through. func TestTheRecordingHandlerSeesWhatALoggerCarries(t *testing.T) { rec := newRecordingHandler(slog.NewTextHandler(io.Discard, nil)) base := slog.New(rec) base.Info("plain", "regions", 1, "regions", 2) slog.New(rec).With("bound", "yes").Info("derived", "regions", 1) got := rec.records() if len(got) != 2 { t.Fatalf("want both records in one store, got %d", len(got)) } if attrs := recordAttrs(got[0]); len(attrs) != 2 { t.Fatalf("duplicate keys were collapsed: %v", attrs) } attrs := recordAttrs(got[1]) if len(attrs) != 2 || attrs[0].Key != "bound" { t.Fatalf("a bound attribute did not reach the record: %v", attrs) } } // TestSetRelayIsTypeConsistentWithBuildsInitialStore: build() stores a // nil []relay.Region into a.relay when no relay is configured, and // SetRelay later stores a real []relay.Region into the same // atomic.Value. atomic.Value panics on a Store whose concrete type // disagrees with an earlier one, so swapping to a real slice and back // to empty here without a panic is the proof the two call sites agree. func TestSetRelayIsTypeConsistentWithBuildsInitialStore(t *testing.T) { cfg := minimalConfig(t) cfg.Env = EnvDevelopment d := openRelayTestDB(t, slog.New(slog.NewTextHandler(io.Discard, nil))) _, ctl, err := NewForTest(d, cfg) if err != nil { t.Fatal(err) } t.Cleanup(ctl.ShutdownForTest) // stops the sign-in mail worker if err := ctl.SetRelay(relayVector(t)); err != nil { t.Fatal(err) } if !ctl.a.relayConfigured() { t.Fatal("SetRelay did not take effect") } if err := ctl.SetRelay(""); err != nil { t.Fatal(err) } if ctl.a.relayConfigured() { t.Fatal(`SetRelay("") did not clear the relay`) } } // TestSetRelayOfAMalformedValueLeavesRegionsUnchanged: SetRelay parses // before it stores, so a malformed value must return the error and // leave whatever was there before untouched — never a half-applied // swap. func TestSetRelayOfAMalformedValueLeavesRegionsUnchanged(t *testing.T) { cfg := minimalConfig(t) cfg.Env = EnvDevelopment d := openRelayTestDB(t, slog.New(slog.NewTextHandler(io.Discard, nil))) _, ctl, err := NewForTest(d, cfg) if err != nil { t.Fatal(err) } t.Cleanup(ctl.ShutdownForTest) // stops the sign-in mail worker if err := ctl.SetRelay(relayVector(t)); err != nil { t.Fatal(err) } before := ctl.a.relayRegions() if err := ctl.SetRelay("%%%not-base64"); err == nil { t.Fatal("want an error") } after := ctl.a.relayRegions() if len(after) != len(before) || len(after) == 0 || after[0].Region != before[0].Region { t.Fatalf("a malformed SetRelay mutated the regions: before len=%d after len=%d", len(before), len(after)) } }