P0: routing pod pass-rate instrumentation is broken 3 ways — #35 data gate is unsatisfiable as-coded #73

Closed
opened 2026-06-30 06:30:16 +00:00 by mathias · 1 comment
Owner

Summary

The #35 data gate (/pass-rate?skill=review|debug reaching 50 logged invocations) cannot ever fill as the code stands — not because of low usage, but because the routing pod's session_log instrumentation has three independent defects, each alone sufficient to keep every counter at zero. Discovered 2026-06-30 by an end-to-end smoke test: a real review call routed cleanly to koala/qwen36-35b-a3b (HTTP 200, 4.8s, real output) yet /pass-rate stayed total:0 under every skill key.

The three bugs

Bug A — success logs "skip", never "pass" (fatal to the gate)

internal/routing/log.go:40-43

status := "skip"
if e.Failed { status = "fail" }

A successful routed call has Failed=false → logs final_status:"skip". There is no code path that emits "pass". /pass-rate computes pass/(pass+fail) (ingestion/internal/api/passrate.go:103) and skips count as neither — so pass_rate is null forever and the ≥0.90 gate is mathematically unreachable.
Fix: status := "pass"; if e.Failed { status = "fail" }.

Bug B — all logs written under skill:"_routing", not the real skill

internal/routing/log.go:52 hardcodes "skill": "_routing". So /pass-rate?skill=review and ?skill=debug — exactly what #35 measures — read zero even when traffic flows. (The session_id is already _routing from cmd/routing/main.go:68; the skill field should carry e.Skill.)
Fix: "skill": e.Skill (keep session_id:"_routing" if desired for grouping).

Bug C — the session_log POST is unauthenticated → silent 401

internal/routing/log.go builds the POST to BrainURL+/mcp with only Content-Typeno Authorization header. Ingestion's /mcp is bearer-gated (ingestion/internal/mcp/server.go BearerMiddleware + staticToken; confirmed 401 on an unauthenticated call). This is the exact documented footgun: brain knowledge/mcpclient-empty-token-silent-401-envfrom-missing-key — empty token → silent 401, and LogDecision errors are best-effort (swallowed with slog.Warn). So even after A+B, nothing logs until the POST authenticates.
Fix:

  • internal/config/routing.go: add BrainMCPToken from BRAIN_MCP_TOKEN.
  • internal/routing/log.go: Logger carries the token; set Authorization: Bearer when non-empty (and validate non-empty at construction per the footgun note).
  • cmd/routing/main.go: thread the token into NewLogger.
  • infra k3s/apps/routing/: add BRAIN_MCP_TOKEN env via ExternalSecret (mirror supervisor/brain-mcp-token-externalsecret.yaml); the value must match ingestion's accepted static token.

Why this matters now

The 14-day window (opened 2026-06-26, kill-date 2026-07-10) and the Berget fallback are gated on this counter. As-coded, the window will hit 2026-07-10 at total:0 and trigger the fallback blaming "hyperguild isn't on the critical path" when the true cause is broken plumbing. The kill-date decision is invalid until these are fixed and one real call is observed incrementing pass.

Definition of done

  • A+B fixed with tests (internal/routing/log_test.go): success → final_status:"pass", record carries skill:"review".
  • C: routing Logger authenticates; BRAIN_MCP_TOKEN wired in config + deployment; non-empty validated at construction.
  • Routing image rebuilt + redeployed.
  • Smoke proof: one real review call moves /pass-rate?skill=review from 0 → 1 (pass).
  • #35 kill-date reset to +14d from the day instrumentation is verified working.

Refs: #35, brain mcpclient-empty-token-silent-401-envfrom-missing-key, infra c66a195.

## Summary The #35 data gate (`/pass-rate?skill=review|debug` reaching 50 logged invocations) **cannot ever fill as the code stands** — not because of low usage, but because the routing pod's `session_log` instrumentation has three independent defects, each alone sufficient to keep every counter at zero. Discovered 2026-06-30 by an end-to-end smoke test: a real `review` call routed cleanly to `koala/qwen36-35b-a3b` (HTTP 200, 4.8s, real output) yet `/pass-rate` stayed `total:0` under every skill key. ## The three bugs ### Bug A — success logs `"skip"`, never `"pass"` (fatal to the gate) `internal/routing/log.go:40-43` ```go status := "skip" if e.Failed { status = "fail" } ``` A successful routed call has `Failed=false` → logs `final_status:"skip"`. There is **no code path that emits `"pass"`**. `/pass-rate` computes `pass/(pass+fail)` (`ingestion/internal/api/passrate.go:103`) and skips count as neither — so `pass_rate` is `null` forever and the ≥0.90 gate is mathematically unreachable. **Fix:** `status := "pass"; if e.Failed { status = "fail" }`. ### Bug B — all logs written under `skill:"_routing"`, not the real skill `internal/routing/log.go:52` hardcodes `"skill": "_routing"`. So `/pass-rate?skill=review` and `?skill=debug` — exactly what #35 measures — read zero even when traffic flows. (The `session_id` is already `_routing` from `cmd/routing/main.go:68`; the `skill` field should carry `e.Skill`.) **Fix:** `"skill": e.Skill` (keep `session_id:"_routing"` if desired for grouping). ### Bug C — the session_log POST is unauthenticated → silent 401 `internal/routing/log.go` builds the POST to `BrainURL+/mcp` with only `Content-Type` — **no `Authorization` header**. Ingestion's `/mcp` is bearer-gated (`ingestion/internal/mcp/server.go` BearerMiddleware + staticToken; confirmed 401 on an unauthenticated call). This is the exact documented footgun: brain `knowledge/mcpclient-empty-token-silent-401-envfrom-missing-key` — empty token → silent 401, and `LogDecision` errors are best-effort (swallowed with `slog.Warn`). So even after A+B, nothing logs until the POST authenticates. **Fix:** - `internal/config/routing.go`: add `BrainMCPToken` from `BRAIN_MCP_TOKEN`. - `internal/routing/log.go`: `Logger` carries the token; set `Authorization: Bearer` when non-empty (and validate non-empty at construction per the footgun note). - `cmd/routing/main.go`: thread the token into `NewLogger`. - infra `k3s/apps/routing/`: add `BRAIN_MCP_TOKEN` env via ExternalSecret (mirror `supervisor/brain-mcp-token-externalsecret.yaml`); the value must match ingestion's accepted static token. ## Why this matters now The 14-day window (opened 2026-06-26, kill-date **2026-07-10**) and the Berget fallback are gated on this counter. As-coded, the window will hit 2026-07-10 at `total:0` and trigger the fallback **blaming "hyperguild isn't on the critical path"** when the true cause is broken plumbing. The kill-date decision is invalid until these are fixed and one real call is observed incrementing `pass`. ## Definition of done - [ ] A+B fixed with tests (`internal/routing/log_test.go`): success → `final_status:"pass"`, record carries `skill:"review"`. - [ ] C: routing Logger authenticates; `BRAIN_MCP_TOKEN` wired in config + deployment; non-empty validated at construction. - [ ] Routing image rebuilt + redeployed. - [ ] Smoke proof: one real `review` call moves `/pass-rate?skill=review` from 0 → 1 (pass). - [ ] #35 kill-date reset to +14d from the day instrumentation is verified working. Refs: #35, brain `mcpclient-empty-token-silent-401-envfrom-missing-key`, infra `c66a195`.
Author
Owner

RESOLVED + verified in production (2026-06-30)

All three bugs fixed (da9bdc4), shipped through the now-restored CD (b9d0331, run 294 green), deployed via flux. Routing pod running routing:b9d0331 with BRAIN_MCP_TOKEN synced by ESO (SecretSynced).

End-to-end proof — a real review call through the routing pod (routed to koala/qwen36-35b-a3b):

BEFORE: {"skill":"review","pass":0,"fail":0,"total":0,"pass_rate":null}
AFTER:  {"skill":"review","pass":1,"fail":0,"total":1,"pass_rate":1}
  • Bug C session_log POST now authenticates → no silent 401 → it logs.
  • Bug B record carries skill:"review"/pass-rate?skill=review sees it.
  • Bug A success logs "pass"pass=1, pass_rate=1.

The gate is now genuinely measurable. Closing.

## RESOLVED + verified in production (2026-06-30) All three bugs fixed (`da9bdc4`), shipped through the now-restored CD (`b9d0331`, run 294 green), deployed via flux. Routing pod running `routing:b9d0331` with `BRAIN_MCP_TOKEN` synced by ESO (`SecretSynced`). **End-to-end proof** — a real `review` call through the routing pod (routed to `koala/qwen36-35b-a3b`): ``` BEFORE: {"skill":"review","pass":0,"fail":0,"total":0,"pass_rate":null} AFTER: {"skill":"review","pass":1,"fail":0,"total":1,"pass_rate":1} ``` - Bug C ✅ session_log POST now authenticates → no silent 401 → it logs. - Bug B ✅ record carries `skill:"review"` → `/pass-rate?skill=review` sees it. - Bug A ✅ success logs `"pass"` → `pass=1, pass_rate=1`. The gate is now genuinely measurable. Closing.
Sign in to join this conversation.
No labels
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: mathias/hyperguild#73