oficina / home Public

Gate 9: prove no address, team name or queue payload reaches a log line

Section 13 step 1 is "Skeleton, AGENTS.md, gates 1, 2 and 9". Gates 1 and
2 need a database and this app has none. Gate 9 does not — it scans
strings — so it was buildable from the first commit and was simply
missing. This is that gate.

internal/home/logtest is the helper: three canaries, one per sink named
in section 3.4, and a slog.Handler that flattens every record into one
scannable line. It does not reuse slog's own handlers. JSONHandler
marshals an error attribute with json.Marshal, which yields {} for a
plain error and drops its text — so an address wrapped in an error, the
most likely way one reaches a log line here, would be invisible to a
scanner reading JSON while still being printed in production.

The detection primitive is kept separate from the assertion, as
internal/sheets/sealtest does, and for the same reason: a failing
subtest always fails its parent, so a scanner exercised only through a
live *testing.T could never be shown to detect anything while leaving
the suite green. Its tests drive a deliberate leak through the message,
a top-level attr, a group, a wrapped error, an attr bound by With, one
under WithGroup, and a LogValuer.

Each of those was checked by mutation rather than assumed. Three of the
first four mutations failed the suite as they should. The fourth did
not: the LogValuer test passed with Resolve removed, because
fmt.Sprint of the test's own struct rendered the canary anyway and the
test found it by accident. The type now has a String method returning
"REDACTED", so the unresolved form does not contain the canary and only
a scanner that resolves — which is what slog's real handlers do — sees
it. That test now fails without Resolve.

internal/home/logs_test.go is the gate against the app's own surface: it
drives every route with canaries in the query, the path, Referer,
User-Agent, X-Forwarded-For and a cookie, and asserts none reach a log
line. Verified by planting a request logger in handleIndex, which failed
the gate and named the line.

It passes trivially today, and the doc comment says so. This skeleton
logs nothing per request, so the value is entirely as a tripwire for
step 2: the day sign-in logs an address, this fails. A guard written
after the code it guards is a guard written to pass.

internal/guardstest is new, ported from Sheets' package of the same name
rather than reinvented — two apps disagreeing about how to find their
own repo root is a bug waiting to differ. It carries one rule so far:
logtest imports testing, so importing it from production code would link
testing into the deployed binary and change what that binary accepts on
its command line, with nothing announcing it at build time.

Not covered, and named in the doc comment rather than left silent: gate
9 lists metric labels as a third sink and this app emits no metrics, so
there is nothing to scan. That needs a second assertion the day one is
exported. cmd/home/main.go's own two logger.Error calls run outside any
handler with no seam to drive from a test; they log a rastrillo error
and no app value today.

All four .amadan/ci.d gates green.

🤖 Generated with Claude Opus 5, at the direction of Paul Campbell.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01SfmrCe9McDH9dnqkuEMrjF
Paul Campbell pushed by paul@keymail.dev 0c00cd9bb72ab9d0deca7719bb5f9f9c2a6a4da4 parent ad6dd30
5 files changed, +543 −0
  • internal/guardstest/logtest_containment_test.go +34 −0
  • internal/guardstest/repo_test.go +132 −0
  • internal/home/logs_test.go +66 −0
  • internal/home/logtest/logtest.go +176 −0
  • internal/home/logtest/logtest_test.go +135 −0

CI passed — run details

diff --git a/internal/guardstest/logtest_containment_test.go b/internal/guardstest/logtest_containment_test.go
new file mode 100644
index 0000000..b3f8bbb
--- /dev/null
+++ b/internal/guardstest/logtest_containment_test.go
@@ -0,0 +1,34 @@
+package guards
+
+import (
+ "strings"
+ "testing"
+)
+
+// logtestImport is gate 9's test helper package. Its own doc comment
+// already says this — "this package must never be imported from
+// non-test code: doing so would drag the testing package into the
+// production binary" — but a comment is not a guard.
+const logtestImport = "amadan.net/oficina/home/internal/home/logtest"
+
+// TestLogtestOnlyImportedByTests fails on any non-_test.go file that
+// imports logtest.
+//
+// The failure this prevents is quiet: importing logtest from production
+// code links testing into the binary, which registers test flags on the
+// default flag set and changes what the deployed binary accepts on its
+// command line. Nothing about that announces itself at build time.
+func TestLogtestOnlyImportedByTests(t *testing.T) {
+ root := repoRoot(t)
+ for _, path := range goFiles(t, root) {
+ if strings.HasSuffix(path, "_test.go") {
+ continue
+ }
+ rel := relPath(t, root, path)
+ for _, imp := range fileImports(t, path) {
+ if imp == logtestImport {
+ t.Errorf("%s: imports %q from non-test code (logtest imports testing, so it must stay test-only)", rel, logtestImport)
+ }
+ }
+ }
+}
diff --git a/internal/guardstest/repo_test.go b/internal/guardstest/repo_test.go
new file mode 100644
index 0000000..7e400c6
--- /dev/null
+++ b/internal/guardstest/repo_test.go
@@ -0,0 +1,132 @@
+// Package guards turns rules that live as prose in AGENTS.md into
+// tests. CARLOS's own rule for this: "A guard a shell step can satisfy
+// is a guard a shell step can be wrong about — put guards inside the
+// test binary." So these run as part of `go test ./...`, not as
+// separate shell greps that a CI step could get subtly wrong (or that a
+// shell rewrite could quietly stop running).
+//
+// This file holds the shared plumbing (repo-root discovery, file
+// walking, import parsing) that every rule's test file uses. It carries
+// no Test functions of its own. The shape is ported from Sheets'
+// internal/guardstest/repo_test.go deliberately: two apps disagreeing
+// about how to find their own repo root is a bug waiting to differ.
+package guards
+
+import (
+ "go/parser"
+ "go/token"
+ "os"
+ "path/filepath"
+ "runtime"
+ "strconv"
+ "strings"
+ "testing"
+)
+
+// module is the module path declared in this repo's go.mod. Used to
+// confirm repoRoot found the right go.mod, not some unrelated one on a
+// parent path (e.g. if the worktree lives under another Go module).
+const module = "amadan.net/oficina/home"
+
+// repoRoot locates the module root by walking up from this source
+// file's own location (via runtime.Caller), not from the working
+// directory. `go test ./...` runs every package's tests with that
+// package's own directory as cwd, so cwd is not a reliable anchor —
+// runtime.Caller(0) always points back to this file, wherever it was
+// invoked from.
+func repoRoot(t *testing.T) string {
+ t.Helper()
+ _, thisFile, _, ok := runtime.Caller(0)
+ if !ok {
+ t.Fatal("guards: runtime.Caller(0) failed")
+ }
+ dir := filepath.Dir(thisFile)
+ for {
+ if b, err := os.ReadFile(filepath.Join(dir, "go.mod")); err == nil {
+ if strings.Contains(string(b), "module "+module+"\n") {
+ return dir
+ }
+ }
+ parent := filepath.Dir(dir)
+ if parent == dir {
+ t.Fatalf("guards: no go.mod for module %q found above %s", module, filepath.Dir(thisFile))
+ }
+ dir = parent
+ }
+}
+
+// skipDir names directories goFiles never descends into: version
+// control, dependency/vendor trees, and dotfiles-style tooling
+// directories that hold no Go source of ours. Skipping dot-directories
+// also keeps .claude/worktrees — which holds full checkouts of this
+// same repo — out of the walk, so a guard never reports another
+// branch's files as this one's.
+func skipDir(name string) bool {
+ if strings.HasPrefix(name, ".") {
+ return true
+ }
+ switch name {
+ case "vendor", "node_modules", "testdata":
+ return true
+ }
+ return false
+}
+
+// goFiles returns the path of every *.go file under root.
+func goFiles(t *testing.T, root string) []string {
+ t.Helper()
+ var files []string
+ err := filepath.WalkDir(root, func(path string, d os.DirEntry, err error) error {
+ if err != nil {
+ return err
+ }
+ if d.IsDir() {
+ if path != root && skipDir(d.Name()) {
+ return filepath.SkipDir
+ }
+ return nil
+ }
+ if strings.HasSuffix(path, ".go") {
+ files = append(files, path)
+ }
+ return nil
+ })
+ if err != nil {
+ t.Fatalf("guards: walk %s: %v", root, err)
+ }
+ return files
+}
+
+// relPath is filepath.Rel with the guards-package error-handling
+// boilerplate folded in, since every rule needs a repo-relative path
+// for its failure messages.
+func relPath(t *testing.T, root, path string) string {
+ t.Helper()
+ rel, err := filepath.Rel(root, path)
+ if err != nil {
+ t.Fatalf("guards: rel %s: %v", path, err)
+ }
+ return filepath.ToSlash(rel)
+}
+
+// fileImports returns the import paths a Go source file declares. It
+// parses in ImportsOnly mode — the cheapest mode that still sees the
+// import block — so walking every file in the tree on every test run
+// stays fast.
+func fileImports(t *testing.T, path string) []string {
+ t.Helper()
+ fset := token.NewFileSet()
+ f, err := parser.ParseFile(fset, path, nil, parser.ImportsOnly)
+ if err != nil {
+ t.Fatalf("guards: parse %s: %v", path, err)
+ }
+ imports := make([]string, 0, len(f.Imports))
+ for _, imp := range f.Imports {
+ p, err := strconv.Unquote(imp.Path.Value)
+ if err != nil {
+ t.Fatalf("guards: unquote import in %s: %v", path, err)
+ }
+ imports = append(imports, p)
+ }
+ return imports
+}
diff --git a/internal/home/logs_test.go b/internal/home/logs_test.go
new file mode 100644
index 0000000..5cdd45f
--- /dev/null
+++ b/internal/home/logs_test.go
@@ -0,0 +1,66 @@
+package home
+
+import (
+ "log/slog"
+ "net/http"
+ "net/http/httptest"
+ "net/url"
+ "testing"
+
+ "amadan.net/oficina/home/internal/home/logtest"
+)
+
+// TestNoContentInLogs is §12 gate 9 against the app's own surface: it
+// drives every route with canary-laden input and asserts none of it
+// reaches a log line. AGENTS.md: "No address, team name, or queue
+// payload in any log line, error string, job status message or metric
+// label. Platform-held logs are storage we cannot grep."
+//
+// It passes trivially today — this skeleton logs nothing per request —
+// and that is the point. §13 step 1 lists gate 9 beside the skeleton so
+// the guard exists before the code it guards: the day a request logger,
+// a sign-in handler or an error path prints a URL, a header or an
+// address, this fails. A guard written afterwards is a guard written to
+// pass.
+//
+// Scope: this covers internal/home's router. It does NOT cover
+// cmd/home/main.go's own logger.Error("resolve", …) and
+// logger.Error("serve", …) calls, which run outside any handler and
+// have no seam to drive from a test. They log a rastrillo error and no
+// app value today; if main ever logs something derived from config or a
+// request, that needs its own guard.
+func TestNoContentInLogs(t *testing.T) {
+ rec := logtest.NewRecorder()
+
+ // The app and rastrillo both log through slog.Default(), so swapping
+ // the default is what actually captures them. Restored on cleanup;
+ // this test must not run in parallel with anything that logs.
+ prev := slog.Default()
+ slog.SetDefault(slog.New(rec.Handler()))
+ t.Cleanup(func() { slog.SetDefault(prev) })
+
+ app := New()
+
+ targets := []string{
+ "/",
+ "/healthz",
+ "/?q=" + url.QueryEscape(logtest.Canaries[0]),
+ "/" + url.PathEscape(logtest.Canaries[1]),
+ "/no-such-route",
+ }
+
+ for _, target := range targets {
+ req := httptest.NewRequest(http.MethodGet, target, nil)
+ // The headers most likely to be logged wholesale by a future
+ // request logger, each carrying content that must never appear.
+ req.Header.Set("Referer", "https://"+logtest.Canaries[1]+".example.invalid")
+ req.Header.Set("User-Agent", logtest.Canaries[0])
+ req.Header.Set("X-Forwarded-For", logtest.Canaries[0])
+ req.AddCookie(&http.Cookie{Name: "team", Value: logtest.Canaries[2]})
+
+ w := httptest.NewRecorder()
+ app.Router().ServeHTTP(w, req)
+ }
+
+ rec.AssertNoContent(t)
+}
diff --git a/internal/home/logtest/logtest.go b/internal/home/logtest/logtest.go
new file mode 100644
index 0000000..3858360
--- /dev/null
+++ b/internal/home/logtest/logtest.go
@@ -0,0 +1,176 @@
+// Package logtest is §12 gate 9, "no-content-in-logs": it proves, by
+// capturing what the app actually logs, that no address, team name or
+// queue payload reaches a log line.
+//
+// AGENTS.md states the rule this enforces — "No address, team name, or
+// queue payload in any log line, error string, job status message or
+// metric label. Platform-held logs are storage we cannot grep." The
+// design spec's §3.4 is the reasoning: logs are storage, and storage we
+// do not control is storage we cannot redact.
+//
+// # What it does not cover yet
+//
+// Gate 9 names three sinks. This package covers log lines, and error
+// strings transitively wherever an error is logged. It does NOT cover
+// metric labels: this app emits no metrics, so there is nothing to
+// scan. The day rastrillo or this app exports a metric with a label
+// built from a value, this package needs a second assertion and this
+// paragraph is wrong. Named here rather than left as a silent gap,
+// because "gate 9 is done" would otherwise be believed.
+//
+// # Why it passes trivially today
+//
+// The skeleton holds no content and takes no user input, so there is
+// nothing yet to leak. Its value is as a tripwire for §13 step 2: the
+// day sign-in logs an address, this fails. §13 step 1 lists gate 9
+// alongside the skeleton for exactly that reason — a guard written
+// after the code it guards is a guard written to pass.
+//
+// AssertNoContent takes a *testing.T, so this package must never be
+// imported from non-test code: doing so would drag the testing package
+// into the production binary. internal/sheets/sealtest carries the same
+// warning for the same reason.
+package logtest
+
+import (
+ "context"
+ "log/slog"
+ "strings"
+ "sync"
+ "testing"
+)
+
+// Canaries are the strings a test seeds into the app before asserting.
+// Any of them reaching a log record — as the message, as an attribute
+// value, or nested inside a group — is a content leak.
+//
+// One per sink named in §3.4. They are deliberately unlike anything the
+// app would otherwise log, so a match is a leak and never a coincidence.
+var Canaries = []string{
+ "CANARY-ADDRESS-a41f@example.invalid",
+ "CANARY-TEAM-NAME-7c2e",
+ "CANARY-QUEUE-PAYLOAD-93bd",
+}
+
+// Recorder collects everything logged through the handler it hands out.
+// The zero value is not usable; call NewRecorder.
+type Recorder struct {
+ mu sync.Mutex
+ buf strings.Builder
+}
+
+// NewRecorder returns a Recorder ready to hand out handlers.
+func NewRecorder() *Recorder { return &Recorder{} }
+
+// Handler returns a slog.Handler that records into r. Install it with
+// slog.New(r.Handler()).
+func (r *Recorder) Handler() slog.Handler { return &handler{rec: r} }
+
+// Text returns every record captured so far, one per line.
+func (r *Recorder) Text() string {
+ r.mu.Lock()
+ defer r.mu.Unlock()
+ return r.buf.String()
+}
+
+func (r *Recorder) write(line string) {
+ r.mu.Lock()
+ defer r.mu.Unlock()
+ r.buf.WriteString(line)
+ r.buf.WriteByte('\n')
+}
+
+// found returns the first canary present in what was captured, or "".
+//
+// It is the detection primitive, kept separate from AssertNoContent so
+// this package's own tests can drive a deliberate leak: a failing
+// subtest always fails its parent, so a scanner exercised only through
+// a live *testing.T could never be proven to detect anything while
+// leaving the suite green.
+func (r *Recorder) found() string {
+ text := r.Text()
+ for _, c := range Canaries {
+ if strings.Contains(text, c) {
+ return c
+ }
+ }
+ return ""
+}
+
+// AssertNoContent fails t if any canary reached a log record, naming
+// the canary and dumping everything captured so the offending line is
+// visible without a second run.
+func (r *Recorder) AssertNoContent(t *testing.T) {
+ t.Helper()
+ if c := r.found(); c != "" {
+ t.Fatalf("gate 9: %q reached a log line.\ncaptured:\n%s", c, r.Text())
+ }
+}
+
+// handler flattens each record into one scannable line.
+//
+// It does not reuse slog's own handlers on purpose. JSONHandler marshals
+// an attribute of type error with json.Marshal, which yields {} for a
+// plain error and drops its text — so an address wrapped in an error,
+// the most likely way one reaches a log line here, would be invisible to
+// a scanner reading JSON while still being printed in production.
+// Formatting each value with slog.Value.String (fmt.Sprint semantics)
+// keeps what production would show.
+type handler struct {
+ rec *Recorder
+ attrs []slog.Attr
+}
+
+// Enabled answers true at every level. A handler that filtered by level
+// would let a canary logged at Debug pass the gate by never reaching
+// Handle — the gate would succeed by not looking.
+func (h *handler) Enabled(context.Context, slog.Level) bool { return true }
+
+func (h *handler) Handle(_ context.Context, r slog.Record) error {
+ var b strings.Builder
+ b.WriteString(r.Message)
+ for _, a := range h.attrs {
+ appendAttr(&b, a)
+ }
+ r.Attrs(func(a slog.Attr) bool {
+ appendAttr(&b, a)
+ return true
+ })
+ h.rec.write(b.String())
+ return nil
+}
+
+// WithAttrs copies rather than appending in place: slog may call it on
+// one handler from several loggers, and append can share a backing array.
+func (h *handler) WithAttrs(as []slog.Attr) slog.Handler {
+ n := &handler{rec: h.rec}
+ n.attrs = append(append([]slog.Attr{}, h.attrs...), as...)
+ return n
+}
+
+// WithGroup keeps the handler unchanged. Grouping only nests keys, and
+// this handler scans values: a canary under a group still arrives in the
+// Record (or in attrs) and is still found. Returning h itself would be
+// wrong if the group name ever mattered — it does not here, and the day
+// it does this method needs writing properly.
+func (h *handler) WithGroup(string) slog.Handler { return h }
+
+// appendAttr writes one attribute's value, recursing into groups.
+//
+// Resolve first: a slog.LogValuer can carry content its static type does
+// not show, and an unresolved value would be scanned as its wrapper.
+// Group attrs arrive as a single attr whose value holds the members, so
+// a scanner that does not recurse misses everything inside one.
+func appendAttr(b *strings.Builder, a slog.Attr) {
+ v := a.Value.Resolve()
+ if v.Kind() == slog.KindGroup {
+ for _, g := range v.Group() {
+ appendAttr(b, g)
+ }
+ return
+ }
+ b.WriteByte(' ')
+ b.WriteString(a.Key)
+ b.WriteByte('=')
+ b.WriteString(v.String())
+}
diff --git a/internal/home/logtest/logtest_test.go b/internal/home/logtest/logtest_test.go
new file mode 100644
index 0000000..d20fd4e
--- /dev/null
+++ b/internal/home/logtest/logtest_test.go
@@ -0,0 +1,135 @@
+package logtest
+
+import (
+ "errors"
+ "fmt"
+ "log/slog"
+ "testing"
+)
+
+// found is the detection primitive every test here drives. It is
+// exercised directly rather than through AssertNoContent because a
+// failing subtest always fails its parent: routing a deliberate leak
+// through a live *testing.T would leave this package unable to go
+// green. internal/sheets/sealtest splits leaked/findLeak from its
+// assertion for the same reason.
+
+func TestFoundCatchesACanaryInTheMessage(t *testing.T) {
+ r := NewRecorder()
+ slog.New(r.Handler()).Info("sending to " + Canaries[0])
+ if got := r.found(); got != Canaries[0] {
+ t.Fatalf("found() = %q, want %q", got, Canaries[0])
+ }
+}
+
+func TestFoundCatchesACanaryInATopLevelAttr(t *testing.T) {
+ r := NewRecorder()
+ slog.New(r.Handler()).Info("upsert", "team", Canaries[1])
+ if got := r.found(); got != Canaries[1] {
+ t.Fatalf("found() = %q, want %q", got, Canaries[1])
+ }
+}
+
+// A leak inside a group is the one a naive scanner misses: slog.Record's
+// Attrs walk yields the group as a single attr, and its members are only
+// reachable by recursing into Value.Group().
+func TestFoundCatchesACanaryNestedInAGroup(t *testing.T) {
+ r := NewRecorder()
+ slog.New(r.Handler()).Info("enqueue",
+ slog.Group("job", slog.String("payload", Canaries[2])))
+ if got := r.found(); got != Canaries[2] {
+ t.Fatalf("found() = %q, want %q", got, Canaries[2])
+ }
+}
+
+// The skeleton's only real logging is logger.Error("resolve", "err", err),
+// so an address reaching a log line will most likely arrive wrapped in an
+// error. A JSON handler would hide this: json.Marshal of a plain error
+// yields {} and drops the text entirely.
+func TestFoundCatchesACanaryInsideAWrappedError(t *testing.T) {
+ r := NewRecorder()
+ err := fmt.Errorf("resolve: %w", errors.New("no mailbox for "+Canaries[0]))
+ slog.New(r.Handler()).Error("resolve", "err", err)
+ if got := r.found(); got != Canaries[0] {
+ t.Fatalf("found() = %q, want %q", got, Canaries[0])
+ }
+}
+
+// Attrs bound by With() are preformatted by the handler and never appear
+// in the Record, so a scanner that only walks the Record misses them.
+func TestFoundCatchesACanaryBoundByWith(t *testing.T) {
+ r := NewRecorder()
+ slog.New(r.Handler()).With("addr", Canaries[0]).Info("start")
+ if got := r.found(); got != Canaries[0] {
+ t.Fatalf("found() = %q, want %q", got, Canaries[0])
+ }
+}
+
+func TestFoundCatchesACanaryUnderWithGroup(t *testing.T) {
+ r := NewRecorder()
+ slog.New(r.Handler()).WithGroup("mail").Info("queued", "to", Canaries[0])
+ if got := r.found(); got != Canaries[0] {
+ t.Fatalf("found() = %q, want %q", got, Canaries[0])
+ }
+}
+
+// A LogValuer can carry content that formatting the value plainly does
+// not show, so values must be resolved before they are scanned.
+//
+// The String method is what makes this test bite. Without it, fmt.Sprint
+// of the struct renders its field and an unresolved scan finds the
+// canary by accident — the test would pass even with Resolve removed,
+// proving nothing. With it, the unresolved form is "REDACTED" and only a
+// scanner that resolves sees the canary, which is exactly what slog's
+// real handlers do before printing.
+type valuer struct{ s string }
+
+func (v valuer) String() string { return "REDACTED" }
+
+func (v valuer) LogValue() slog.Value { return slog.StringValue(v.s) }
+
+func TestFoundResolvesLogValuers(t *testing.T) {
+ r := NewRecorder()
+ slog.New(r.Handler()).Info("person", "who", valuer{Canaries[1]})
+ if got := r.found(); got != Canaries[1] {
+ t.Fatalf("found() = %q, want %q", got, Canaries[1])
+ }
+}
+
+func TestFoundReportsNothingForCleanLogs(t *testing.T) {
+ r := NewRecorder()
+ l := slog.New(r.Handler())
+ l.Info("serve", "port", 8080)
+ l.Error("resolve", "err", errors.New("socket path missing"))
+ l.With("app", "home").WithGroup("db").Info("open", "path", "/var/lib/home.db")
+ if got := r.found(); got != "" {
+ t.Fatalf("found() = %q, want no leak", got)
+ }
+}
+
+// Enabled must answer true at every level, or a canary logged at Debug
+// would never reach Handle and the gate would pass by not looking.
+func TestRecorderIsEnabledAtEveryLevel(t *testing.T) {
+ r := NewRecorder()
+ l := slog.New(r.Handler())
+ l.Debug("debug " + Canaries[0])
+ if got := r.found(); got != Canaries[0] {
+ t.Fatalf("found() = %q at Debug, want %q", got, Canaries[0])
+ }
+}
+
+func TestCanariesAreDistinctAndNonEmpty(t *testing.T) {
+ seen := map[string]bool{}
+ for _, c := range Canaries {
+ if c == "" {
+ t.Fatal("a canary is empty: it would match every log line")
+ }
+ if seen[c] {
+ t.Fatalf("duplicate canary %q", c)
+ }
+ seen[c] = true
+ }
+ if len(Canaries) < 3 {
+ t.Fatalf("got %d canaries, want one each for address, team name and queue payload", len(Canaries))
+ }
+}