oficina / memoria Public

Review 6: the clock, not the timer; counts, not wall-clock; four more pages

Reviewed by Codex GPT-6-Astra (dispatched: codex/gpt-6-astra; self-
reported "GPT-6 (Codex)"), of 5b1ac4e and 867612c. REQUEST CHANGES,
three must-fix.

**ctx.Err() is not the deadline.** It reports expiry only once the
runtime's timer has fired, and that lags: with one CPU and a busy wait
just past the deadline, the review got a late row five times out of five.
Measured here, Err() was still nil past the deadline in three or four
runs of five — and in the rest the timer HAD fired, so racing for it in
a test is a coin toss. expired() now reads the clock as well, and the
test models the lagging timer exactly instead of racing for it: a
context whose deadline has passed and whose Err() is nil, through the
real Search. expired() is also tested directly.

**Three wall-clock guards failed on correct code with ten CPUs busy**,
each blaming a mechanism that was present. Replaced by a probe — nil in
production — that COUNTS what modelFacts did: one recogniser pass per
passage, one examination per distinct proposal, and none after the
deadline, which the test ends at a known point (the tenth examination)
instead of waiting for. Stable three times idle and three times with ten
CPUs busy; each mechanism's removal fails its own subtest.

**My own mutation harness reported a false green**, and it is worth
recording because it is the failure this repo's AGENTS.md opens with.
Reverting expired() to ctx.Err()-only broke the build — `time` became
unused — and the harness grepped for "--- FAIL" lines, found none, and
said green. With the build kept valid, that mutation fails both tests
with the review's own symptom. Harness output now shows the tail.

**Four more pages carried the footer unchecked.** With Home configured,
/auth/start, /auth/finish, /auth/callback and /auth/verify render failure
pages at 400 with the shared footer; the exclusion list called them
"redirects", which was a guess stated as fact. Making renderHome drop
ModelOn for /auth/ paths alone left the suite green. They are now driven
through the real routes with the cookie conditions the Home library
refuses — a duplicate init cookie, a duplicate pending-auth cookie,
missing finish state — and that mutation fails all four at 400. Every
remaining exclusion reason was verified, not assumed; /auth/local/complete
was read and does only redirect. Two native reasons were wrong ("not
wired by AppForTest" — it is) and are corrected. The spec now states the
coverage that exists rather than "every page".
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Paul Campbell pushed by paul@keymail.dev 075e3d6f93e02b47c057233e952576b1e8ac920e parent 867612c
5 files changed, +226 −52
  • docs/superpowers/specs/2026-09-03-memoria-design.md +8 −4
  • internal/memoria/home_router_test.go +36 −3
  • internal/memoria/modelfacts_test.go +113 −26
  • internal/memoria/store.go +49 −6
  • internal/memoriatest/footer_model_test.go +20 −13

CI failed — run details

CI log
=== vet ===
go vet ./...
=== fmt ===
=== test ===
go test ./...
?   	amadan.net/oficina/memoria/cmd/memoria	[no test files]
--- FAIL: TestCreditsMatchProductionDependencies (0.03s)
    credits_inventory_test.go:36: production dependency graph unavailable exit status 1
FAIL
FAIL	amadan.net/oficina/memoria/internal/memoria	2.772s
ok  	amadan.net/oficina/memoria/internal/memoria/chunk	(cached)
ok  	amadan.net/oficina/memoria/internal/memoria/fact	(cached)
?   	amadan.net/oficina/memoria/internal/memoria/icons	[no test files]
ok  	amadan.net/oficina/memoria/internal/memoria/index	(cached)
ok  	amadan.net/oficina/memoria/internal/memoria/notion	(cached)
ok  	amadan.net/oficina/memoria/internal/memoria/provider	(cached)
ok  	amadan.net/oficina/memoria/internal/memoria/query	(cached)
ok  	amadan.net/oficina/memoria/internal/memoria/seal	(cached)
ok  	amadan.net/oficina/memoria/internal/memoria/sibling	(cached)
ok  	amadan.net/oficina/memoria/internal/memoriatest	1.536s
?   	amadan.net/oficina/memoria/tools/bench	[no test files]
?   	amadan.net/oficina/memoria/tools/drive	[no test files]
?   	amadan.net/oficina/memoria/tools/seed	[no test files]
?   	amadan.net/oficina/memoria/tools/vendorassets	[no test files]
FAIL
make: *** [Makefile:62: test] Error 1

amadan: step test failed: exit status 2

amadan: job failed at step test — its output is above, not at the tail of this log
diff --git a/docs/superpowers/specs/2026-09-03-memoria-design.md b/docs/superpowers/specs/2026-09-03-memoria-design.md
index 03c68ec..fb9a7fc 100644
--- a/docs/superpowers/specs/2026-09-03-memoria-design.md
+++ b/docs/superpowers/specs/2026-09-03-memoria-design.md
@@ -3661,10 +3661,14 @@ claim could be false **outside** the path the section above describes:
makes the strong claim, which is then true. A gate walks every declared
GET route and checks each footer at whatever status it renders; a route
that renders no footer must be on a list with its reason, or the walk
- fails. The pages that exist only when Home is configured are checked by
- name, through the Home fixture. (The first version of that gate skipped
- non-200 routes silently and so missed all four Home pages — found by
- review, then fixed.)
+ fails, and each listed reason was verified rather than assumed. The
+ pages that exist only when Home is configured are checked by name
+ through the Home fixture — eight of them, including four `/auth/`
+ failure pages that render the footer at 400. That is the coverage; it
+ is not "every page in every configuration", and a new Home page has to
+ be added there by hand. (The first two versions of this gate missed,
+ in turn, every non-200 page and then the four `/auth/` failure pages —
+ each found by review.)
- **Processing time.** The deadline covered the call and not the work on
its response; a legal-sized response of repeated proposals took 6.8 s to
validate. One deadline now covers both, identical proposals are
diff --git a/internal/memoria/home_router_test.go b/internal/memoria/home_router_test.go
index 59fc973..1ab5119 100644
--- a/internal/memoria/home_router_test.go
+++ b/internal/memoria/home_router_test.go
@@ -313,15 +313,48 @@ func TestHomeSigninClearsOnlyDefinitivelyStaleSession(t *testing.T) {
// was never looked at, and removing ModelOn from renderHome left the
// suite green until the next commit added this. A review found both.
func TestHomePagesStateTheModelSwitch(t *testing.T) {
- routes := []string{"/signed-out", "/account/home", "/account/home/confirm", "/signin/local"}
+ // Each route with the extra cookies that make it render. The four
+ // /auth/ routes are FAILURE pages — a duplicate or malformed cookie, or
+ // missing state — and a review found all four render the shared footer
+ // at 400 while this test did not look at them: making renderHome drop
+ // ModelOn only for /auth/ paths left the whole suite green. The
+ // cookie conditions are the Home library's own refusals
+ // (connect.homeCookie, Routes.LocalGuard, Bridge.Finish).
+ type visit struct {
+ path string
+ extra []*http.Cookie
+ }
+ dup := func(name string) []*http.Cookie {
+ v := strings.Repeat("A", 43)
+ return []*http.Cookie{{Name: name, Value: v}, {Name: name, Value: v}}
+ }
+ visits := []visit{
+ {path: "/signed-out"},
+ {path: "/account/home"},
+ {path: "/account/home/confirm"},
+ {path: "/signin/local"},
+ {path: "/auth/start", extra: dup("__Host-oficina-home-init")},
+ {path: "/auth/finish"},
+ {path: "/auth/callback", extra: dup("__Host-rastrillo_pending")},
+ {path: "/auth/verify", extra: dup("__Host-rastrillo_pending")},
+ }
for _, on := range []bool{true, false} {
f := newHomeRouterFixture(t)
if on {
f.app.store.extractor = &recorder{}
}
f.local(t)
- for _, path := range routes {
- w := f.do("GET", path, "")
+ for _, v := range visits {
+ path := v.path
+ r := httptest.NewRequest("GET", homeTestOrigin+path, nil)
+ for _, c := range f.cookies {
+ r.AddCookie(c)
+ }
+ for _, c := range v.extra {
+ r.AddCookie(c)
+ }
+ w := httptest.NewRecorder()
+ f.handler.ServeHTTP(w, r)
b := w.Body.String()
i := strings.Index(b, "<footer")
if i < 0 {
diff --git a/internal/memoria/modelfacts_test.go b/internal/memoria/modelfacts_test.go
index f3bb9f3..749d0ac 100644
--- a/internal/memoria/modelfacts_test.go
+++ b/internal/memoria/modelfacts_test.go
@@ -901,9 +901,13 @@ func TestAModelResponseIsCheapToProcess(t *testing.T) {
}
})
- // Mutation: recompute the recognisers per proposal. A thousand DISTINCT
- // proposals that are all present, against a dense passage: cached, one
- // ~70 ms pass; uncached, a thousand, cut off at the deadline.
+ // **Counted, not timed.** The three guards below were wall-clock
+ // thresholds, and a review ran them with ten CPUs busy and watched all
+ // three fail on correct code — each blaming a missing mechanism that
+ // was present. The probe counts what modelFacts actually did, so each
+ // assertion is about the mechanism and nothing else can move it.
+
+ // Mutation: recompute the recognisers per proposal.
t.Run("the recognisers run once per passage", func(t *testing.T) {
var prefix strings.Builder
var props []provider.Pointer
@@ -912,59 +916,108 @@ func TestAModelResponseIsCheapToProcess(t *testing.T) {
prefix.WriteString(a + ",")
props = append(props, provider.Pointer{Passage: 0, Text: a})
}
- s := build(t, prefix.String(), 20000)
+ s := build(t, prefix.String(), 200)
+ s.probe = &modelProbe{}
rec := &recorder{reply: func([]string) ([]provider.Pointer, error) { return props, nil }}
s.extractor = rec
- took, _ := timed(t, s, "office address")
+ searchFacts(t, s, "office address")
onePassage(t, rec.calls)
- if took > 400*time.Millisecond {
- t.Errorf("took %v: the recognisers are running per proposal", took)
+ if s.probe.examinations != 1000 {
+ t.Fatalf("examined %d proposals, want 1000: the fixture is not exercising the cache", s.probe.examinations)
+ }
+ if s.probe.recognitions != 1 {
+ t.Errorf("the recognisers ran %d times over one passage; want 1", s.probe.recognitions)
}
})
- // Mutation: drop the dedupe. A thousand IDENTICAL near-miss proposals:
- // each would be a full ~1 ms scan of 1.23 MB; deduped, one.
+ // Mutation: drop the dedupe.
t.Run("identical proposals are examined once", func(t *testing.T) {
- s := build(t, "", 60000)
+ s := build(t, "", 200)
+ s.probe = &modelProbe{}
props := make([]provider.Pointer, 1000)
for i := range props {
props[i] = provider.Pointer{Passage: 0, Text: "D02X285,info@tito.iq"}
}
rec := &recorder{reply: func([]string) ([]provider.Pointer, error) { return props, nil }}
s.extractor = rec
- took, _ := timed(t, s, "office address")
+ searchFacts(t, s, "office address")
onePassage(t, rec.calls)
- // 600 ms: the search alone — opening and snippeting a 1.23 MB chunk —
- // is ~220 ms before the model path starts; without dedupe it is
- // ~1.02 s, deadline-bound (measured 2026-09-27). 300 ms, the first
- // threshold, left 80 ms of margin.
- if took > 600*time.Millisecond {
- t.Errorf("took %v: identical proposals are each being examined", took)
+ if s.probe.examinations != 1 {
+ t.Errorf("examined %d identical proposals; want 1", s.probe.examinations)
}
})
- // Mutation: drop the per-proposal deadline check. 2,500 DISTINCT
- // near-miss proposals — dedupe cannot help — at ~1 ms each is ~2.5 s of
- // scanning; the check stops it at the 800 ms deadline. The threshold
- // sits between, and only the deadline can get under it.
+ // Mutation: drop the per-proposal deadline check. The request is
+ // cancelled after the tenth examination — a known point, not a
+ // measured one — and nothing after it may be examined.
t.Run("the deadline stops the scan, not the end of the list", func(t *testing.T) {
- s := build(t, "", 60000)
+ s := build(t, "", 200)
+ ctx, cancel := context.WithCancel(context.Background())
+ defer cancel()
+ s.probe = &modelProbe{}
+ s.probe.afterExamine = func() {
+ if s.probe.examinations == 10 {
+ cancel()
+ }
+ }
props := make([]provider.Pointer, 2500)
for i := range props {
props[i] = provider.Pointer{Passage: 0, Text: fmt.Sprintf("D02X285,info@tito.%dq", i)}
}
rec := &recorder{reply: func([]string) ([]provider.Pointer, error) { return props, nil }}
s.extractor = rec
- took, rows := timed(t, s, "office address")
+ p, err := s.Search(ctx, suite.Subject{Kind: suite.SubjectAddress, Value: "paul@tito.io"}, "office address", 25)
+ if err != nil {
+ t.Fatal(err)
+ }
onePassage(t, rec.calls)
- if took > 1400*time.Millisecond {
- t.Errorf("took %v: the scan ran past the deadline to the end of the list", took)
+ if s.probe.examinations != 10 {
+ t.Errorf("examined %d proposals after the deadline passed at 10", s.probe.examinations)
}
- if len(rows) != 0 {
+ if rows := modelRows(p); len(rows) != 0 {
t.Errorf("rows = %+v", rows)
}
})
+ // **The deadline is a time, not a callback.** ctx.Err() reports it only
+ // once the runtime's timer has fired, and that lags: measured with one
+ // CPU and a busy wait just past the deadline, Err() was still nil in
+ // three or four runs of five — and in the others the timer had fired,
+ // so a single late run is a coin toss. A review got a late row five
+ // times out of five this way.
+ //
+ // So the lagging timer is modelled EXACTLY rather than raced for: a
+ // context whose deadline has passed and whose Err() is still nil —
+ // the state the race reaches by accident, reached on purpose. The
+ // presence half is the same search with the deadline ahead.
+ t.Run("a row is dropped by the clock, whether or not the timer has fired", func(t *testing.T) {
+ for _, late := range []bool{false, true} {
+ s := storeForTest(t)
+ upload(t, s, "Tito office", "## Contact\n\nOffice address: 12 Main Street, Dublin 2")
+ rec := &recorder{reply: point(0, "12 Main Street, Dublin 2")}
+ s.extractor = rec
+ dl := time.Now().Add(time.Hour)
+ if late {
+ dl = time.Now().Add(-time.Millisecond)
+ }
+ ctx := timerNotFired{Context: context.Background(), deadline: dl}
+ p, err := s.Search(ctx, suite.Subject{Kind: suite.SubjectAddress, Value: "paul@tito.io"}, "office address", 25)
+ if err != nil {
+ t.Fatal(err)
+ }
+ if len(rec.calls) != 1 {
+ t.Fatalf("calls = %d; the model path did not run", len(rec.calls))
+ }
+ rows := modelRows(p)
+ if !late && len(rows) != 1 {
+ t.Fatalf("no row with the deadline ahead (%d); the late case proves nothing", len(rows))
+ }
+ if late && len(rows) != 0 {
+ t.Errorf("a row came back after the deadline, because the timer had not fired: %+v", rows)
+ }
+ }
+ })
+
// The whole model path runs under one deadline: the extractor is
// handed a context that expires within the provider's budget even
// when the request's own context never does.
@@ -1002,3 +1055,37 @@ func (c ctxThen) ExtractAddresses(ctx context.Context, passages []string) ([]pro
c.wait(ctx)
return c.reply(passages)
}
+
+// timerNotFired is a context whose deadline may have passed while its
+// Err() is still nil — exactly what a context looks like between its
+// deadline and the runtime firing its timer. context.WithTimeout over it
+// keeps the earlier deadline and never cancels, so it reaches modelFacts
+// intact.
+type timerNotFired struct {
+ context.Context
+ deadline time.Time
+}
+
+func (c timerNotFired) Deadline() (time.Time, bool) { return c.deadline, true }
+
+// expired's own contract, directly: the clock decides, not the callback.
+func TestExpiredReadsTheClock(t *testing.T) {
+ past := timerNotFired{Context: context.Background(), deadline: time.Now().Add(-time.Millisecond)}
+ if past.Err() != nil {
+ t.Fatal("the fixture's Err() is not nil; it does not model a timer that has not fired")
+ }
+ if !expired(past) {
+ t.Error("expired() missed a passed deadline whose timer had not fired")
+ }
+ if expired(timerNotFired{Context: context.Background(), deadline: time.Now().Add(time.Hour)}) {
+ t.Error("expired() reported a deadline an hour away")
+ }
+ cancelled, cancel := context.WithCancel(context.Background())
+ cancel()
+ if !expired(cancelled) {
+ t.Error("expired() missed a cancellation")
+ }
+ if expired(context.Background()) {
+ t.Error("expired() reported a context with no deadline")
+ }
+}
diff --git a/internal/memoria/store.go b/internal/memoria/store.go
index 7a85f3d..40b1e92 100644
--- a/internal/memoria/store.go
+++ b/internal/memoria/store.go
@@ -7,6 +7,7 @@ import (
"log/slog"
"sort"
"strings"
+ "time"
"github.com/carlosframework/rastrillo/db"
@@ -32,6 +33,11 @@ type Store struct {
// breaker that quietly stops counting reads as "no anomaly" forever,
// which is the failure §8.1 spends a paragraph on.
logger *slog.Logger
+ // probe observes §8.9's processing for tests, and is nil in
+ // production. It exists so caching, dedupe and the deadline can be
+ // asserted by COUNTING what was done rather than by timing it: three
+ // wall-clock guards failed on correct code with ten CPUs busy.
+ probe *modelProbe
// extractor is §8.9's model. **nil means the model layer is off**, which
// is decision 5's floor and the default: nothing is sent anywhere. Set
// only by WireModel, only when the owner said MEMORIA_AI=on.
@@ -1239,18 +1245,27 @@ func (s *Store) modelFacts(ctx context.Context, results []Result, texts map[int6
if !ok {
sp = fact.RecognisedSpans(passages[i])
recognised[i] = sp
+ if s.probe != nil {
+ s.probe.recognitions++
+ }
}
return sp
}
var accepted []coord
for _, ptr := range ptrs {
- if ctx.Err() != nil {
+ if expired(ctx) {
return nil
}
if tried[proposal{ptr.Passage, ptr.Text}] {
continue
}
tried[proposal{ptr.Passage, ptr.Text}] = true
+ if s.probe != nil {
+ s.probe.examinations++
+ if s.probe.afterExamine != nil {
+ s.probe.afterExamine()
+ }
+ }
// 1. It must name a passage that was SENT. An authorised result
// ranked ninth was never in the request, and a proposal pointing
// at it is pointing at something the model was not shown.
@@ -1291,9 +1306,10 @@ func (s *Store) modelFacts(ctx context.Context, results []Result, texts map[int6
// here, again in the labelling loop, and once more before returning.
//
// What this does NOT bound: a single recogniser pass is not
- // interruptible, so the path can overrun by one passage's scan. The
- // rows are never late; the latency can be, by that much.
- if ctx.Err() != nil {
+ // interruptible, so the path can overrun by one passage's scan. What
+ // it does bound: no row is returned once the deadline has passed by
+ // the CLOCK — see expired, and why ctx.Err() alone was not enough.
+ if expired(ctx) {
return nil
}
@@ -1311,7 +1327,7 @@ func (s *Store) modelFacts(ctx context.Context, results []Result, texts map[int6
var out []Fact
seen := map[string]bool{}
for _, c := range accepted {
- if ctx.Err() != nil {
+ if expired(ctx) {
return nil
}
text := passages[c.passage]
@@ -1346,7 +1362,7 @@ func (s *Store) modelFacts(ctx context.Context, results []Result, texts map[int6
// is all this layer can apply them to. §8.9 says what that costs: an
// address the model did not return cannot trip the cap, and nothing
// here can know it was there.
- if len(out) > MaxFacts || collides(out) || ctx.Err() != nil {
+ if len(out) > MaxFacts || collides(out) || expired(ctx) {
return nil
}
return out
@@ -1381,6 +1397,33 @@ func modelFailure(err error) string {
}
}
+// expired reports whether ctx is done, reading the CLOCK as well as the
+// cancellation.
+//
+// ctx.Err() reports a deadline only once the runtime's timer has fired,
+// and that can lag the deadline itself. A review pinned GOMAXPROCS to 1,
+// had the model busy-wait half a millisecond past the deadline, and got
+// every row back — 5 of 5, twice — because the timer had not yet run when
+// the checks did. The deadline is a time; this compares against it.
+func expired(ctx context.Context) bool {
+ if ctx.Err() != nil {
+ return true
+ }
+ dl, ok := ctx.Deadline()
+ return ok && !time.Now().Before(dl)
+}
+
+// modelProbe counts what modelFacts did, for tests. nil in production.
+type modelProbe struct {
+ // recognitions is recogniser passes — one per passage if caching works.
+ recognitions int
+ // examinations is proposals examined after dedupe.
+ examinations int
+ // afterExamine runs after each examination, so a test can end the
+ // deadline at a known point rather than by timing.
+ afterExamine func()
+}
+
// admissibleSpan is §8.9's structural bound on a model's proposal.
func admissibleSpan(t string) bool {
return len(t) >= 12 && strings.ContainsAny(t, "0123456789,\n")
diff --git a/internal/memoriatest/footer_model_test.go b/internal/memoriatest/footer_model_test.go
index a096263..6d96d41 100644
--- a/internal/memoriatest/footer_model_test.go
+++ b/internal/memoriatest/footer_model_test.go
@@ -20,19 +20,26 @@ import (
// under this harness, and why. A route missing from here that renders no
// footer fails the walk.
var noLayoutHere = map[string]string{
- "GET /search": "the results fragment, swapped into a page by search.js — no layout",
- "GET /api/native/session": "JSON for the native client",
- "GET /native/start": "native sign-in redirect; not wired by AppForTest",
- "GET /native/authorize": "native sign-in redirect; not wired by AppForTest",
- "GET /auth/callback": "sign-in redirect; auth is not wired by AppForTest",
- "GET /auth/verify": "sign-in redirect; auth is not wired by AppForTest",
- "GET /auth/start": "Home sign-in redirect; Home is not configured here",
- "GET /auth/finish": "Home sign-in redirect; Home is not configured here",
- "GET /auth/local/complete": "Home sign-in redirect; Home is not configured here",
- "GET /signin/local": "Home-only page — covered by memoria.TestHomePagesStateTheModelSwitch",
- "GET /signed-out": "Home-only page — covered by memoria.TestHomePagesStateTheModelSwitch",
- "GET /account/home": "Home-only page — covered by memoria.TestHomePagesStateTheModelSwitch",
- "GET /account/home/confirm": "Home library's own confirm page, rendered through renderHome — covered there",
+ // Each reason is VERIFIED, not assumed — a review found two of the
+ // first set were guesses stated as facts: "/native/*: not wired by
+ // AppForTest" (it is wired) and "/auth/*: sign-in redirect" (with Home
+ // configured, four of them render the footer on failure).
+ "GET /search": "the results fragment search.js swaps into a page; renders the results define alone, no layout",
+ "GET /api/native/session": "JSON for the native client",
+ "GET /native/start": "wired by AppForTest, but 404 without a pending native request id; with one it redirects (303)",
+ "GET /native/authorize": "wired by AppForTest, but 404 without a pending id; with one it serves the native library's standalone consent template, which has no layout footer",
+ "GET /auth/local/complete": "a redirect on every GET path — the Home navigation guard either passes and redirects, or redirects; it renders nothing (read in home/connect navigation.go)",
+ // These render the footer when Home is configured, which this harness
+ // does not do. They are checked there, by name, including their
+ // failure pages at 400.
+ "GET /signed-out": "Home-only — memoria.TestHomePagesStateTheModelSwitch",
+ "GET /signin/local": "Home-only — memoria.TestHomePagesStateTheModelSwitch",
+ "GET /account/home": "Home-only — memoria.TestHomePagesStateTheModelSwitch",
+ "GET /account/home/confirm": "Home-only — memoria.TestHomePagesStateTheModelSwitch",
+ "GET /auth/start": "Home-only; its failure page renders the footer — memoria.TestHomePagesStateTheModelSwitch",
+ "GET /auth/finish": "Home-only; its failure page renders the footer — memoria.TestHomePagesStateTheModelSwitch",
+ "GET /auth/callback": "no sign-in wired here; with Home its LocalGuard failure renders the footer — memoria.TestHomePagesStateTheModelSwitch",
+ "GET /auth/verify": "no sign-in wired here; with Home its LocalGuard failure renders the footer — memoria.TestHomePagesStateTheModelSwitch",
}
// countingModel is a stand-in model that counts calls and points at any