<!-- canonical: https://klappy.dev/page/odd/ledger/2026-04-26-telemetry-and-canon-integration-session -->
<!-- content: klappy/klappy.dev@b750d7d3aa85a3e5ed6d1e2b24d63471f3df4bac -->

# Ledger — Telemetry Semantic Names, cache_tier Streaming-Race, And Canon-Integration-Audit (Four PRs Shipped)

> Four PRs shipped this session: the Penny Wise and Pound Foolish essay with four supporting canon docs (PR #134), the canon-integration-audit constraint codifying three integration-layer audits (PR #135), the telemetry consumer interface refactor exposing semantic names only (PR #137), and the cache_tier streaming-race fix that took every-tool-records-"none" to first-time-real-values-in-production (PR #138). The semantic-names PR took three Bugbot iterations to land cleanly (count() collision, string literal corruption in rewrite, detection inconsistency vs rewrite — all fixed by Cursor Agent, all verified by added regression tests). The cache_tier defect was discovered by the user's "have we validated that token usage is tracked?" challenge — an audit triggered by mistrust of prior-session memory — which surfaced that cache_tier had been silently recording "none" for 9,745 calls / 7 days / 100% of tool calls. The streaming-race diagnosis came from a contradiction between two read sites of the same tracer instance: response.debug.trace.index_source returned "cache" while telemetry blob9 returned "none". Production verification within 5 minutes of PR #138 deploy confirmed real values populating: 5 calls "cache", 5 calls "memory", non-"none" cache_tier appearing for the first time in the field's history.

---

## Summary — The Arc, The Defects, The Verification

The session opened with a question: *how do we ensure P11 — mechanical enforcement of canon-integration-audit — is enforceable?* The first response named a layered architecture, listed forcing-function preconditions, and proposed a spec doc. The user named the antipattern: *performed prudence about how to prevent performed prudence.* I had been proposing more documentation when the work was code. The Dream House Principle (canonized hours earlier in PR #134) named the same move I was making — cutting from prediction instead of drawing from contact with reality.

The pivot was the user's question — *have we validated that token usage is tracked?* — which inverted the rhythm from "ship more spec" to "audit existing instrumentation." The audit revealed: the `telemetry_public` tool's docstring listed only blob1-8 and double1-2, but the worker actually wrote blob9 (cache_tier) and doubles 3-6 (bytes_in, bytes_out, tokens_in, tokens_out). The schema and the docs had drifted. Of those undocumented fields, four were populating correctly in aggregate over 7 days — `bytes_in` sum 41,545; `bytes_out` 1,316,480; `tokens_in` 12,602; `tokens_out` 325,627 — and one was always `"none"`: cache_tier. Across 9,745 tool calls in 7 days, zero exceptions, every single `cache_tier` value was the fallback.

PR #137 fixed the consumer-facing interface: the public tool now accepts only semantic names, raw `blob*`/`double*` are rejected with a helpful error, the schema mapping is fetched from canon at runtime via the same `KnowledgeBaseFetcher` mechanism all canon-loading paths use, and the docstring shows only semantic names. No deprecation path — the user was clear: *no deprication, nobody uses them yet.* Cursor Bugbot found three real bugs across three iterations: `count()` SQL aggregate collision (`\bcount\b` would have rewritten `SELECT count(*)` to `SELECT double1(*)`, invalid SQL), string literal corruption in `rewriteSqlToRaw` (semantic names inside `'...'` getting word-boundary-rewritten), and detection inconsistency between `detectRawSlotNames` and `rewriteSqlToRaw` (the rewrite path correctly skipped literals; the detect path didn't, falsely rejecting valid queries). Each fix shipped as a separate Cursor Agent commit. Two of the three fixes initially landed without regression tests; a follow-up commit added them.

PR #138 fixed the cache_tier defect. The diagnosis came from a contradiction. An `oddkit_search` call's response envelope showed `debug.trace.index_source: "cache"` — read inside `handleUnifiedAction` at `orchestrate.ts:2806`, after the action handler had run. The same call's telemetry blob9 showed `"none"` — read at `index.ts:981`, immediately after `await handler(request, env, ctx)` resolved. Same tracer instance, two read sites, two different values. The MCP handler from `agents/mcp` returns a streaming Response — `await handler(...)` resolves with the Response object before the tool handler closure has finished running. The fix moved the `cacheTier = tracer.indexSource` read inside the `ctx.waitUntil` callback, after `await responseClone.text()` resolves. Reading the response body to completion forces the streaming tool handler to finish, which means the tracer is fully populated.

Production verification within 5 minutes of PR #138 deploy: `oddkit_encode` → `cache`, `oddkit_catalog` → `cache`, `oddkit` (router) → `memory`. Within 20 minutes: 5 calls `cache`, 5 calls `memory`, 52 calls `none` (mostly mcp_request events that don't trigger a tool, plus action handlers like `oddkit_version` that legitimately don't fetch the index). For the first time in the lifetime of blob9, real values are flowing.

PR #135 (the canon-integration-audit constraint) was authored on the prior day but waited for Bugbot completion and a clean state before merging. It codifies three integration-layer audits — concept audit, adjacent-canon audit, validator-completeness audit — as a single tier-2 constraint with trigger points specified at `oddkit_preflight`, `oddkit_gate`, and `oddkit_validate`. Tool-side enforcement (the wiring that fires the audits proactively) is deferred to P11 at klappy/oddkit, currently O-open.

---

## Decisions

**[D1] Telemetry consumer interface uses semantic names only, no deprecation.** The public `telemetry_public` tool now accepts SQL written against semantic field names (event_type, method, tool_name, consumer_label, consumer_source, knowledge_base_url, document_uri, worker_version, cache_tier, count, duration_ms, bytes_in, bytes_out, tokens_in, tokens_out). Raw slot names (`blob1`–`blob9`, `double1`–`double6`) are rejected at query construction with a helpful error naming the semantic equivalent. Result columns are translated back from raw to semantic before return. The schema mapping is sourced from canon at runtime via `KnowledgeBaseFetcher.getFile(canon/constraints/telemetry-governance.md)` — same mechanism all other canon-loading paths use — with hardcoded baseline arrays as safety net per vodka architecture. No deprecation path: per maintainer directive, *"no deprication, nobody uses them yet."* Decided this session, shipped as PR #137 (squash-merged 2026-04-26 as `33cceee`).

**[D2] cache_tier read happens AFTER body consumption, not after handler return.** The `cacheTier = tracer.indexSource` read in `workers/src/index.ts` is performed inside the `ctx.waitUntil` callback, after `await responseClone.text()` resolves. NOT immediately after `await handler(request, env, ctx)` returns. Rationale: the MCP handler from `agents/mcp` returns a streaming Response. The outer `await` resolves with the Response object before the tool handler closure completes — the tool handler is what calls `fetcher.getIndex()`, which is what records the `index` span on the tracer. Reading the response body to completion forces the streaming tool handler to finish, which means the tracer is fully populated. Decided and shipped this session as PR #138 (squash-merged 2026-04-26 as `838d97c`). Verified in production within 5 minutes of deploy.

**[D3] canon-integration-audit shipped as ONE tier-2 constraint, not three.** The three integration-layer audits (concept audit, adjacent-canon audit, validator-completeness audit) are codified as a single tier-2 constraint at `https://klappy.dev/page/canon/constraints/canon-integration-audit`, not three separate constraints. Rationale: shared root cause (extrinsic-integration missing from existing gauntlets), lower drift surface, easier extension when a fourth integration check emerges, tight cross-references (one URI citable from preflight/gate/validate). Trigger points specified per audit. Tool-side enforcement deferred to P11 at klappy/oddkit, currently O-open. Decided 2026-04-24, merged this session as PR #135 (squash-merged 2026-04-26 as `365b553`).

---

## Observations Closed

**[O1] Production telemetry verification post-PR-138 deploy is sticky.** In the 20-minute window after PR #138's production deploy, 5 calls recorded `cache_tier="cache"`, 5 calls recorded `cache_tier="memory"`, and 52 calls recorded `cache_tier="none"`. The "none" calls are predominantly mcp_request events (no tool dispatched) plus action handlers that legitimately don't fetch the index (oddkit_version, oddkit_time, error paths). Compare to the baseline measured at the start of the session: 9,745 tool calls over 7 days, all with `cache_tier="none"`, zero exceptions. The fix is sticky in production. Confirmed via SQL query against the `oddkit_telemetry` dataset on Cloudflare Analytics Engine. Multiple distinct tools (oddkit, oddkit_search, oddkit_orient, oddkit_catalog, oddkit_encode, oddkit_challenge) recorded values across multiple distinct tiers (memory, cache).

**[O2] bytes_in/out and tokens_in/out are populated correctly in aggregate, despite a sampled zero-row.** The PR #137 implementer's Phase 1 audit ran against 7 days of production data: `bytes_in` sum 41,545; `bytes_out` sum 1,316,480; `tokens_in` sum 12,602; `tokens_out` sum 325,627. The token-tracking claim from prior-session memory was correct in aggregate, even though a single sampled row earlier in this session showed zeros across the doubles slots — that row turned out to be a legitimate edge case, either an SSE-streaming response path or a tokenization-skipped event per the canon's "0 when tokenization was skipped or failed" note. The aggregate query proved real data is being captured. The validation that opened the session ("have we validated that token usage is tracked?") closes here: yes, in aggregate.

---

## Learnings

**[L1] Streaming responses break naive tracer reads.** `await handler()` for a streaming MCP request returns the Response object before the body streams. Any state populated DURING body production must be read AFTER body consumption — i.e., after `await responseClone.text()` resolves. The contradiction was the diagnostic: the trace embedded in the response's debug envelope had the correct value because that snapshot was captured INSIDE the action handler at `orchestrate.ts:2806`, after the action ran. The OUTER read at `index.ts:981` happened before the streaming tool handler completed. Same tracer instance, two read sites, two different values. When a tracer's value is required for a side-effect (telemetry write), and the tracer is populated by code that runs while the response body is streaming, the side-effect must be deferred until the body has been consumed — not just until the response object has been returned.

**[L2] Validate before assuming.** The user's "have we validated that token usage is tracked?" challenge surfaced a real defect (cache_tier always "none") that would have shipped silently otherwise. The telemetry-governance PR title implied payload tracking; the published `telemetry_public` docstring listed only blob1-8/double1-2; the worker actually wrote blob9 + double3-6. Schema and docs had drifted. The audit caught this only because the user demanded measurement instead of accepting the prior-session claim from memory. Prior-session memory is a starting hypothesis, not a closed observation. When a feature's correctness is being relied on, the question is never "did the prior session say this works" — it is always "does the current data show it works."

**[L3] Independent context catches what same-session validation rationalizes.** Two parallel proofs this session. (1) On PR #134 rev 21: the local Python validator passed all four files as compliant; the Managed Agent validator dispatched per release-validation-gate caught a `derives_from` list-vs-string violation that the local validator hadn't been written to check. (2) On PR #137: same-session unit tests covered the schema mapping and result rewriting but not the literal-skip cases — the author hadn't thought to test them. Cursor Bugbot caught all three findings (count() collision, string literal corruption in rewrite, detection inconsistency vs rewrite) on a fresh-context pass. In both cases, the author's mental model of what to test had a gap, and only an independent reviewer with no investment in the existing tests could see it. Same-session validators are necessary; they are not sufficient. The release-validation-gate's requirement of independent re-validation is the structural answer to this, and it was vindicated twice in one session.

---

## Constraints Honored

**[C1] release-validation-gate.** All four PRs this session went through Cursor Bugbot to `completed` status (not `in_progress`) before merge — the canon's stated gate. PR #135 (canon constraint) additionally received an MA validator dispatch per the gate's broader prescription for canon changes. PR #137 (telemetry semantic names) and PR #138 (cache_tier streaming-race) both had Bugbot complete before merge; both received clean (zero new findings) Bugbot verdicts on the final HEAD. The gate's recursive enforcement on its own canon was honored — the canon-integration-audit constraint, which itself prescribes validator-completeness checks, was validated by an independent MA before being merged.

**[C2] vodka-architecture.** PR #137's schema mapping is fetched from canon at runtime via `KnowledgeBaseFetcher.getFile(canon/constraints/telemetry-governance.md)` — the same content-addressed R2/ZIP/memory cache mechanism all other canon-loading paths in oddkit use. Hardcoded `BASELINE_BLOB_SEMANTIC_NAMES` and `BASELINE_DOUBLE_SEMANTIC_NAMES` arrays are present in the source code, but only as the safety-net tier per vodka architecture: invoked exclusively when canon is unreachable, never as the default. The protocol stays thin and stateless; the canon stays the moat. Verified by reading the implementation: `getSchemaMap()` is async, fetches canon, parses the doubles table, falls back only on failure, caches in module memory.

---

## Opens

**[O-open: getFile-tier vs index-tier wiring]** `getFile` emits `` file:${path} `` spans with sources `memory`/`r2`/`build`/`miss`, NOT `index` or `index-build` spans. The `RequestTracer._indexSource` setter only recognizes the latter two labels. So `oddkit_get`'s `cache_tier` reflects the index tier (resolved when `runGet` calls `getIndex` first to validate the URI) rather than the file tier (where the document was actually fetched from). Three options surveyed during the session: (a) extend the setter to recognize "file" labels — semantics get murky for actions that fetch many files (oddkit_search fetches evidence files; the LAST file would win, which isn't necessarily meaningful), (b) each action explicitly sets a primary tier via a new `setPrimaryTier()` method on the tracer — cleanest, requires changes in multiple action handlers, (c) add a separate `file_tier` blob10 to telemetry — most info, requires schema extension and telemetry-governance canon update. Filing for follow-up; not blocking. Current behavior post-PR-138 is an improvement over "always none" — it just means oddkit_get's blob9 reflects the index tier, not the file tier.

**[O-open: P11 mechanical enforcement of canon-integration-audit]** The canon-integration-audit constraint defines what the audits check (concept audit at gate, adjacent-canon audit at preflight, validator-completeness audit at validate). The tool-side wiring that fires the audits proactively at those transition points is deferred. Until P11 ships at klappy/oddkit, the canon is passively discoverable via `oddkit_search` and citable from existing workflows, but the audits do not fire without invocation. Both pieces (canon + tool) are required for the proactive property; this session shipped the canon, P11 ships the tool wiring. Will likely extend the existing P11 scope (mechanical enforcement of release-validation-gate) rather than open a new epoch.

---

## Handoff

**[H] Session 2026-04-25/26 telemetry-and-canon ship.** Four PRs merged this session:

- **PR #134** at klappy/klappy.dev — *Penny Wise and Pound Foolish* essay (rev 23) plus four supporting canon docs (`measure-before-you-object`, `performed-prudence-anti-pattern`, `dream-house-principle`, `discernment-layer`) and `telemetry-governance` payload-shape additions. Squash-merged 2026-04-24 as `33209e7`.
- **PR #135** at klappy/klappy.dev — `canon/constraints/canon-integration-audit.md` (tier 2, three named audits) plus reciprocal See-Also updates to `revision-lens-sequence`, `frontmatter-validation-before-merge`, `dream-house-principle`, `discernment-layer`. Squash-merged 2026-04-26 as `365b553`.
- **PR #137** at klappy/oddkit — telemetry semantic-names interface, three Cursor Bugbot fixes (count() collision, literal-skip in rewrite, literal-skip in detection), regression tests for all three. Squash-merged 2026-04-26 as `33cceee`. Production deployed.
- **PR #138** at klappy/oddkit — cache_tier streaming-race fix (move read inside waitUntil callback after body consumption), regression test using `setImmediate` to model the streaming race. Squash-merged 2026-04-26 as `838d97c`. Production deployed and verified — first non-"none" `cache_tier` values flowing.

All four shipped through full release-validation-gate. Production verified for both telemetry PRs. Two open follow-ups recorded above. Working copies at `/home/claude/work/klappy.dev` and `/home/claude/work/oddkit`, both synced to main post-merges. Next session can resume on either open follow-up; the file-tier-vs-index-tier wiring is the smaller of the two and would be a natural next ship if the rhythm continues.
