Skip to content

Per-iteration Time stamp in the managed Developer message (index 1) defeats prompt caching — ~40× input-token amplification measured #10

Description

@JoshuaBearup

Summary

The agent loop re-renders the managed Developer message (index 1, ahead of all conversation history) on every iteration, and its # Environment section embeds a second-resolution timestamp:

// crates/norn/src/system_prompt/environment.rs (format_environment_section)
let _ = writeln!(
    out,
    "Time: {}",
    chrono::Utc::now().format("%Y-%m-%dT%H:%M:%SZ"),
);

Agent turns are seconds apart, so this line differs on every request. Because the managed Developer message sits at MANAGED_DEV_INDEX = 1 — "immediately after the System message at index 0, ahead of all persisted history" (crates/norn/src/loop/dev_context.rs) — the request prompt diverges from the provider's prefix cache at message[1] on every turn. The entire conversation history behind it (which grows to 150k+ tokens in long sessions) is re-tokenised and billed as uncached input on every single request.

This defeats norn's own caching design: the loop deliberately keeps the System message expansion-stable "so the instructions field stays stable for caching" (R5 comment in crates/norn/src/loop/runner.rs), and open_session wires the session id as prompt_cache_key (crates/norn/src/agent/builder.rs:445). The Time line one message later undoes both.

Refs are against f37f992.

Measured impact

From norn's own session logs (~/.norn/sessions/*.jsonl; every AssistantMessage records usage), across 147 sessions / 7,342 turns on two worker hosts over ~1 week (model gpt-5.5, OpenAI Responses API):

input tokens cache-hit rate uncached
host A (108 sessions) 370,476,498 13% 322,855,634
host B (39 sessions) 184,069,846 14% 158,076,630
combined 554,546,344 ~13% 480,932,264

Output tokens are 0.5% of input (2.8M combined) — the spend is almost entirely history re-send.

Signature trace (one 150-turn dev session, 40 min): input_tokens grows 19k → 163k per turn while cache_read_tokens sits frozen at exactly 15,488 the entire session — the static System+tools prefix is the only thing that ever cache-hits.

Counterfactual: with a stable prefix (only each turn's new delta uncached), the same work would have cost ~12.1M uncached tokens instead of ~481M — a ~40× input-token amplification.

Suggested fix

Any of (in increasing order of thoroughness):

  1. Coarsen the timestamp to date-only (%Y-%m-%d) so the Developer message is stable within a session.
  2. Render the environment/time once at session start and only re-sync the managed Developer message when its content (beyond time) actually changes.
  3. Structural: keep per-iteration dynamic context out of the cacheable prefix — append it at the conversation tail (as the latest user-turn context) instead of mutating message[1], which is what the major agent CLIs do to keep prefix caching effective.

Note read_git_branch in the same section can also mutate mid-session (branch switches), but the per-second Time line is the one that changes every turn.

Verification

After the fix, a session's cache_read_tokens should grow with input_tokens (>80% of input by mid-session) instead of freezing at the static-prefix size.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions