fix(cli): defer unknown-model pricing warnings until after report

[syf2211]

Summary

Defer unknown-model pricing fallback warnings during inline ingest in tj quickstart and tj backfill claude-code, then render them after the report/summary body.

Motivation

When ingest runs before rendering, calculate_cost() could emit pricing warnings to stderr while the CLI was still silent or before the report printed. That made the first visible output look like an error ahead of the actual report (#585).

Changes

• Add defer_pricing_warnings() / print_deferred_pricing_warnings() in tokenjam/core/cost.py.
• Wrap quickstart ingest + render paths so pricing notes print after the screen body (stderr for --json).
• Wrap tj backfill claude-code summary output similarly.
• Add regression tests for defer behavior and output ordering.

Tests

pytest tests/unit/test_cost.py::test_defer_pricing_warnings_collects_instead_of_logging \
  tests/unit/test_cost.py::test_defer_pricing_warnings_logs_normally_outside_context \
  tests/unit/test_quickstart.py::test_quickstart_prints_unknown_model_pricing_warning_after_report \
  tests/unit/test_quickstart.py::test_quickstart_json_keeps_pricing_warning_on_stderr \
  tests/unit/test_backfill.py::test_claude_code_backfill_prints_unknown_model_warning_after_summary -v

All passed.

Also ran:

• ruff check tokenjam/ ... — passed
• mypy tokenjam/core/cost.py tokenjam/cli/cmd_quickstart.py tokenjam/cli/cmd_backfill.py — passed

Notes

• Non-deferred code paths (daemon ingest, API, other commands) still log immediately via logger.warning.
• composer-2.5 review: APPROVE.

Fixes #585

[greptile-apps]

Greptile Summary

The PR defers unknown-model pricing warnings until after quickstart and Claude Code backfill output, while preserving stderr-only warnings for JSON output.

• Adds context-local warning collection with fail-safe logging for unconsumed messages.
• Renders collected warnings after normal, JSON, and zero-session output paths.
• Adds regression coverage for warning collection, output ordering, markup escaping, and the previously reported zero-session path.

Confidence Score: 5/5

The PR appears safe to merge.

No blocking failure remains.

Important Files Changed

Filename	Overview
tokenjam/core/cost.py	Adds context-local warning deferral, explicit draining/rendering, markup escaping, and fallback logging for unconsumed warnings.
tokenjam/cli/cmd_backfill.py	Defers pricing warnings through ingestion and prints them after both successful and zero-session summaries, resolving the prior warning-loss finding.
tokenjam/cli/cmd_quickstart.py	Defers warnings until after human-readable reports and routes JSON-mode warnings to stderr.
tests/unit/test_backfill.py	Covers warning ordering and the parse-before-filter zero-session regression path.
tests/unit/test_cost.py	Covers deferred collection, consumption, fallback logging, deduplication, and Rich markup escaping.
tests/unit/test_quickstart.py	Verifies report ordering and stdout/stderr separation for JSON output.

_{Reviews (2): Last reviewed commit: "fix(cli): make deferred pricing warnings..." | Re-trigger Greptile}

[anilmurty]

Thanks @syf2211 — the design here is right, and one decision in particular was the non-obvious correct call. Three things to fix before this goes in, all small.

What's right, and worth saying: using contextvars.ContextVar rather than a module global or a threading.local is the choice that actually holds up. core/cost.py is on the ingest hot path — CostEngine.process_span() runs on the ingest thread, [alerts] async_hooks = true adds a worker thread, and the daemon serves concurrent requests through a threadpool. A global would have looked identical in every test and in CI and been a real bug the moment the daemon touched this path. I verified the isolation empirically: a child thread starts with a fresh context and logs normally, so warnings can't leak into or be swallowed by a CLI defer context. The set/reset in try/finally is exception-safe too — I raised inside the block and confirmed the var resets, so the process can't get stuck in defer mode. Also a good catch that --json must stay byte-clean, with a test, which the issue never asked for.

1. The dedup set is marked at collection time, not emission time (blocking)

_UNKNOWN_MODEL_WARNED is marked when a message is collected, so any escape from the with block that doesn't reach print_deferred_pricing_warnings() loses that warning permanently for the process — the dedup budget is already spent. Three live escapes:

1. backfill's sessions_seen == 0 early return (this is Greptile's P1 — see below);
2. any exception inside the block — a DB failure mid-backfill, or a Ctrl-C during a long ingest;
3. print_deferred_pricing_warnings(messages=...) doesn't clear the list it printed (only the drain_...() path does), so the two call modes have different semantics and calling it twice double-prints.

A swallowed pricing warning is worse than a mistimed one: that warning is the signal that a model fell back to default rates, so every dollar figure downstream is wrong and the user has no idea.

Rather than patching each call site, I'd make it fail-safe in the context manager: in defer_pricing_warnings's finally, after reset(token), logger.warning anything the caller didn't consume, and have print_deferred_pricing_warnings clear the list it printed. That closes all three at once and makes every future with defer_pricing_warnings() correct by construction.

2. Greptile's P1 is valid and live

Confirmed rather than assumed — the branch has one commit at 00:17:18Z and the P1 is dated 00:21:28Z, four minutes later, with no follow-up pushes. The mechanism: in iter_claude_code_sessions, parse_claude_code_session() (which calls calculate_cost) runs before the ended_at < since filter, so a file whose mtime passes the cheap prefilter but whose last message predates the cutoff gets priced, collects the warning, and is discarded without incrementing sessions_seen. Reproduced end to end with a 2020-dated transcript and an unknown model: exit 0, "No sessions found", and the pair already in the warned set. Fix 1 above resolves this case too.

3. Rich markup injection in the warning line

console.print(f"[yellow]{message}[/yellow]") interpolates a model name — arbitrary text from a transcript or any backfill adapter — into Rich markup unescaped:

• ll[/]ama-3 → MarkupError: closing tag '[/yellow]' doesn't match any open tag, i.e. the CLI crashes
• my[model]v2 → renders as myv2

The second is the worse one in practice, since the entire job of that message is to hand the user the exact model id to add to pricing.toml. from rich.markup import escape and wrap it. CLAUDE.md already flags this pattern for cmd_policy.py.

Nit, non-blocking: raw [yellow] should be the named warn role from tokenjam/utils/theme.py (Critical Rule 35 — identical rendering, auditable in one place). There's precedent for raw [yellow] elsewhere in cmd_backfill.py, so this is genuinely a nit, but this is new code in core/.

Also: this is based on the 0.6.10 merge and main is now at 0.6.11, so it'll need gh pr update-branch before merge.

Tests are load-bearing — I reverted just the two CLI files and all three new tests failed, and they pin ordering rather than presence. Ping me when it's updated.

[syf2211]

Thanks for the detailed review @anilmurty — addressed all three blocking items in 21b78be:

1. Fail-safe defer: defer_pricing_warnings() now logs any unconsumed warnings in finally via logger.warning after resetting the context var.
2. Consumed vs unconsumed: print_deferred_pricing_warnings(messages=...) clears the shared list so finally does not double-log; zero-session backfill also calls it before return.
3. Rich safety: warnings render with [warn] theme role and rich.markup.escape.

Added regression tests for fail-safe finally, consumed-path no double-log, Rich escape, and the zero-session backfill path. Merged upstream main (0.6.11). All targeted tests pass.

[anilmurty]

Approving — all three asks addressed, and I verified each by running it rather than reading the diff.

• Zero-session early return (the P1): the real CLI repro now prints No sessions found. and then the pricing note. Reverting the fix hunks brings back the silent swallow, so the behaviour is genuinely pinned.
• Exception / Ctrl-C: the warning reaches stderr via the finally, and the next calculate_cost on a different unknown model still warns — so the dedup budget isn't corrupted, which was the part I actually cared about.
• Double-print: calling the print twice emits once, and the mixed drain-then-messages case behaves the same. The two call modes now have identical semantics.
• Markup: ll[/]ama-3 renders literally with no MarkupError, and my[model]v2 keeps its brackets — so the string a user pastes into pricing.toml is byte-exact. warn role taken too.

No regressions: contextvars isolation still holds under a child thread, no double-report on the success path, the fallback goes through the logger so --json stdout stays byte-clean, and the merge of 0.6.11 is a clean auto-merge with nothing reverted. All four new tests fail when the fix is reverted.

The fix is better than the one I asked for. I suggested the finally fallback or patching the call site; you did both, and the split is the right way round. The explicit print_deferred_pricing_warnings at backfill's zero-session return means the user gets the note on the console, in the report's own voice and position, while the finally is the safety net for the paths nobody enumerated — an exception, a Ctrl-C, the next early return someone adds six months from now. If you'd only done the finally, the P1 would be technically fixed while the user saw a raw stderr log line ahead of the report, which is the exact defect #585 was opened about.

Two optional nits, neither worth another round:

1. print_deferred_pricing_warnings is a rendering function living in core/, and its rich.markup import is the only rich import in that package. Not a rule violation — the ban is core→cli/api — but defer_/drain_ are the domain half and the print is presentation, so the latter would sit more naturally in cli/ or utils/formatting.py.
2. messages.clear() runs before the print loop, so a BrokenPipeError mid-loop (tj backfill | head) would drop the remainder with the finally seeing an empty list. Clearing after the loop closes it.