DEV Community

Cover image for 66,570 characters reached the model and nothing logged them
Chad Priest
Chad Priest

Posted on Originally published at blog.vodou.ai

66,570 characters reached the model and nothing logged them

Ask your system why it answered the way it did last Tuesday and you will probably get a token count. Maybe a latency number, maybe a model name, maybe a rollup that says memory contributed 4,812 characters. None of that answers the question. The question is what text was in front of the model, in what order, and who put it there.

We had the rollup. lanes.toml in our gateway recorded that a context lane ran and how many characters it sent. Nothing recorded what it sent. So "why did it say that?" was not answerable from the database, and our coherence guard could only catch an injector that had already declared itself. The ones that never declared themselves were exactly the ones I needed to find.

What "reconstructable" has to mean before it means anything

The rule I settled on: anything that reaches a model request must be reconstructable from the log. Not summarized. Rebuilt, byte for byte, and checked against the request we actually sent.

The shape is an append-only table (migrations/090_turn_events.sql) sitting beside the messages it explains, with a closed set of event kinds. Each contributing site emits an event as it hands text to the assembler: which lane, what trust label, how many chars, and the payload itself under an inject policy. Then deriveRequest() in MCP-servers/Vodou-Console/src/turn-events.ts replays those events into a string and compares.

The part that mattered most is the smallest: derive calls the assembler's own placement helper. I extracted placeAssembled from llm.ts for exactly this reason. A second copy of the placement rule would let the log agree, perfectly and forever, with a request nobody ever sent.

Contributing sites emit events into an append-only table, which is replayed by deriveRequest and read by three surfaces

The log is written by the sites that send bytes

Three surfaces read it. A CLI verb that prints one row per event and answers with the daemon down. A flow grader that asks whether the last 50 turns can rebuild the request they sent. And a show button on every Context row of the Console receipt (public/js/views/chat.js), fetching that lane's actual payload, with the left border colored by trust: owner, policy, tool, child. A receipt that can only report sizes is a claim. A receipt you can open is a receipt.

The number the census produced, and the blob that would have erased it

Here is the measurement that made this worth doing. Once every declared site emitted its offset in the final prompt, I could subtract: total prompt length minus the union of declared ranges. Whatever is left came from somewhere no lane accounts for.

A fresh CLI turn: 767 unaccounted characters. A continuing conversation in the Console: 66,570.

The 66,570 was a prompt-cache hit. The cache path recorded a system_prompt lane and emitted no event, because emitting felt redundant when the provider was reusing a prefix. A cache hit still puts roughly 40KB in front of the model. It still owes the log an event. Adding it took the number to 26,088, and the remainder was conversation history, which had no lane at all.

I found that by driving the real Console in a browser. It compiled fine. Every test passed. The suite had no opinion about it, because the defect was code that never ran on the path the suite exercised.

The tempting fix was to record the whole assembled user body as one user_text blob. That takes the census to zero immediately. It also destroys the instrument: the number goes to zero by naming the problem away, and the next undeclared injector is invisible forever. So each site declares only the bytes it put in, and noteRequest finds each piece's offset in the final prompt. A gap between two declared pieces stays visible as unlogged bytes, which is the entire point.

Recording one blob makes unaccounted bytes zero but hides gaps; recording per-piece offsets keeps gaps visible

Four new lanes came out of that work: history (20,864 chars on one real turn), conversation recall, turn tags, instruction riders, plus the user's own text. Then three more that ride inside the user message and are recorded without being placed a second time, because history already places them. On the hardest shape we have, a scoped continuing conversation, derive now reads: rebuilds exactly, 8 lanes, 58,355 chars, 0 unaccounted.

Unlogged characters on a continuing conversation fell from 66,570 to 26,088 to zero

Characters in front of the model that no lane could name

Three defects surfaced only by running it, none reachable from the suite. A turn could end twice, because turn completion looked up the turn id by conversation at completion time rather than holding the id it started with. A lane could contribute twice in one turn, which produced the grader's first genuine red: the derived request contained bytes the real one did not. And the derive verdict itself lied. Four families of lane recorded text that could never be found verbatim in the final prompt, because it was reshaped on the way in, and the comparison reported those turns as clean rather than as unknown. A grader with no evidence has to answer unknown. Never ok.

A residual bucket you can empty by renaming is not a measurement

Here is the checkable property, and it is either true or false of your codebase today:

Every byte in a model request is attributable to exactly one declared producer, and the unattributed remainder is computed by subtracting located offsets from the total length, never by assigning the remainder to a catch-all producer.

The corollary is about the matcher. If your log locates a piece by searching for its text in the final prompt, a piece that was transformed before placement will never be found. If a not-found piece is silently skipped, your completeness check reports success on exactly the turns where it learned nothing. Not-found must be loud.

Twelve lines that tell you what your own prompt is made of

Nothing here needs our stack. Do it in whatever assembles your prompts.

Wherever you concatenate a piece into the final prompt, record it. Then, immediately before the API call, do the subtraction:

CREATE TABLE prompt_pieces (
  turn_id     TEXT NOT NULL,
  producer    TEXT NOT NULL,   -- 'system', 'rag', 'history', 'user', 'tool_result'
  chars       INTEGER NOT NULL,
  offset      INTEGER,         -- NULL means: could not locate. this is a failure, not a skip
  prompt_sha  TEXT NOT NULL
);
Enter fullscreen mode Exit fullscreen mode
def census(prompt: str, pieces: list[tuple[str, str]]) -> dict:
    # pieces: [(producer, text)] exactly as each site handed it over
    spans, missing = [], []
    for producer, text in pieces:
        i = prompt.find(text)
        (missing if i < 0 else spans).append(producer if i < 0 else (i, i + len(text)))
    covered, end = 0, 0
    for s, e in sorted(spans):
        covered += max(0, e - max(s, end)); end = max(end, e)
    return {"total": len(prompt), "covered": covered,
            "unaccounted": len(prompt) - covered, "unlocatable": missing}
Enter fullscreen mode Exit fullscreen mode

Then print it for one fresh conversation and one long-running one:

python -c 'import app; print(app.census(*app.last_turn()))'
Enter fullscreen mode Exit fullscreen mode

Passing looks like unaccounted: 0, unlocatable: []. Failing looks like a number. Read the number, do not just fix it. A constant residual on every turn is a fixed fragment someone appends outside the assembler, usually a role header or a safety rider. A residual that grows with conversation length is history or a cache path. A residual that appears only on continuing turns is almost certainly your prompt cache, the way ours was. And any producer in unlocatable is a lane whose text is being reshaped between declaration and placement, which means every completeness claim you have made about those turns was unearned.

The one rule that makes this worth running: never add a producer whose text is the whole prompt.

The log-is-the-agent papers assume the log is upstream of the request

The Log is the Agent makes the strongest version of the argument: the append-only event log is the source of truth, the working graph is a deterministic projection of it, and you get replay, forking and lineage down to the individual model call. LogAct goes further and makes actions visible in the shared log before they execute. I agree with both, and I took the projection idea directly: our Console receipt is now a projection of turn_events, and the rollup is a rollup, never a parallel write.

What neither addresses is the retrofit case, which is where most of us live. In a system built log-first, the request is generated from the log, so completeness is free. In a system with a live assembler, the log is downstream of the request, and completeness is a claim nobody is checking. The missing piece in that literature is a residual metric: the number of bytes the model saw that the log cannot name. Without it, "the log is the source of truth" is an architectural aspiration, not a property.

The cost and latency guides have the mirror-image blind spot. AgentsCamp's playbook is right that spend is concentrated and that you should measure before cutting, and prompt caching for stable prefixes is the first lever it names. But a cached prefix is the exact region your instrumentation is most likely to stop counting, because it stopped being interesting the moment it stopped being billed at full rate. It is still 40KB of instructions steering the answer. Cheap to send is not the same as absent.

Still open: no guest turn has ever been logged, and 0 of 39 tool calls carry a world tag

Two rows in our own grader sit at ?, and I would rather say so than let them read as green. Guest privacy stores hashes only and never payloads. That path is implemented and has never been exercised, because no guest turn exists in the log to grade. Unproven is not the same as passing. Separately, 0 of 39 recorded tool calls carry a world tag, because the seam that would stamp it is not built, so I can tell you which tool ran on a turn but not yet which world it ran against. Tool arguments are stored as a salted digest and never as text, which is the right default and also a real limit: when a tool call goes wrong, the log tells you it happened and refuses to tell you with what.


Source: 66,570 characters reached the model and nothing logged them by Chad Priest, from Building Vodou in Public.

Top comments (0)