fix(agent): restore token-usage telemetry after the OpenClaw JSONL→SQLite transcript move - #1631
Merged
Merged
Conversation
… removed JSONL
OpenClaw 2026.7.2-beta.5 migrated per-session transcripts out of
<workspace>/agents/<agentId>/sessions/<sessionId>.jsonl into the per-agent
SQLite database <workspace>/agents/<agentId>/agent/openclaw-agent.sqlite
(table transcript_events) and DELETED the JSONL files. OpenClawAdapter's usage
read still opened the JSONL path, so every turn reported input=0 output=0
cache_read=0 cache_write=0 model_calls=0 with capture_complete=False.
Nothing failed loudly: the wrapper treats a zero read as an honest zero, so the
admin/agents dashboard has shown all-zero token usage since 2026-07-31 (dev)
and 2026-08-01 (prod) with no error surfaced anywhere. Caching itself was never
broken -- a checkpointed workspace database shows cacheRead 56k-71k per turn
against ~2 billable input tokens. Only the telemetry read regressed.
Verified against a real checkpointed 2026.7.2-beta.5 database rather than
assumed:
- transcript_events(session_id TEXT, seq INTEGER, event_json TEXT,
created_at INTEGER), STRICT, PRIMARY KEY (session_id, seq).
- event_json holds the SAME record objects the JSONL did, verbatim:
{id, message, parentId, timestamp, type} with
message.usage.{input,output,cacheRead,cacheWrite} and message.stopReason
in {toolUse, stop, error}.
- created_at is the row's INSERT time and is always at or after the record's
own message.timestamp (488 records, 0 inversions, skew 0..19941ms).
- created_at is only WEAKLY ordered against seq: 28 of 32 sessions contain a
row whose created_at precedes that of a lower seq.
Implementation:
- _fold_usage_records() now holds the whole accounting fold and is shared by
both stores, which take an iterable of record JSON in APPEND order. The
SQLite and JSONL paths therefore cannot drift in window filtering,
completeness, or token extraction.
- _sum_sqlite_transcript_usage() opens a read-only file: URI (mode=ro, which
also refuses to create a missing file), binds session_id as a parameter,
prefilters on created_at >= since_ms, and orders by seq.
* created_at >= since_ms is a safe SUPERSET prefilter given
created_at >= message.timestamp, so it narrows the scan without ever
hiding an in-window record; the authoritative in-window test stays on
the record timestamp exactly as before.
* ORDER BY seq, not created_at: completeness is decided by the LAST
record, so ordering by the weakly-ordered column would mis-read it.
- Session isolation moved from the filename to a WHERE clause, so a regression
there would bill concurrent sessions to one turn; covered by a test.
- _settle_usage() extracts the bounded retry. sqlite3.OperationalError
(locked/busy DB, or a pre-transcript_events schema) retries through it;
DatabaseError (corrupt file) breaks out immediately rather than paying the
full wait on every turn. Telemetry still never breaks a chat turn.
- _contained_transcript_path() extracts the realpath containment shared by
both stores, still paired with the dot-only component rejection that the
containment check cannot substitute for.
- JSONL remains a fallback for hosts older than 2026.7.2-beta.5; the database
wins when both exist, so an archived JSONL cannot double-bill.
- Booleans no longer count as tokens (bool is an int subclass in Python, so a
JSON `true` previously added 1).
The sessionId is no longer a path component at all on the SQLite path -- it is a
bound SQL parameter, and the filename is a constant. Only the agentId directory
component remains untrusted path input.
Tests: transcript usage suite rebuilt on a sqlite fixture whose DDL is copied
from the real database, covering the window, cross-session isolation, seq-vs-
created_at ordering, the created_at lag, malformed/non-object event_json, a
genuinely locked database (verified to raise OperationalError, not pass
incidentally), a corrupt file, and read-only-ness (the read neither creates nor
mutates the DB). Traversal, dot-name, and symlink security tests are retained
for both stores, and the JSONL fallback keeps its own suite.
766 passed, 1 skipped in the infra/agent-image suite.
agent_messages.model has carried `us.anthropic.claude-sonnet-5` since 2026-07-31, not the bare `claude-sonnet-5` this module named. #1227 moved the provider off Bedrock Mantle onto bedrock-runtime's native anthropic-messages endpoint, and that endpoint echoes the request's inference-profile id verbatim instead of rewriting it to the bare form -- so the RECORDED id and the REQUEST id became equal again without anything being updated to say so. Verified against the dev database rather than inferred: every agent_messages row on/after 2026-07-31 carries `us.anthropic.claude-sonnet-5` (58 rows), and the bare `claude-sonnet-5` appears only through 2026-07-29 (630 rows). This class of drift does not fail loudly -- the rows simply stop joining ai_models and the cost UI reads $0, which is bug #1083 all over again. All three id forms are already priced by migration 092 and all three are inactive, so no cost was actually lost; the constants were just describing the wrong world, and the next reader would have trusted them. Changes: - AGENT_MODEL_ID -> `us.anthropic.claude-sonnet-5`, with the verification recorded in the doc comment and the reason the two constants are now equal (they stay separate: they are distinct concepts and the next provider swap can split them apart again). - New AGENT_MODEL_ID_ALIASES listing every id form the harness model has ever been recorded under. - getPricableModels() excludes the whole alias list instead of only the current id, so a re-activated historical alias cannot reappear as a projection candidate against the harness itself. Replaces ne() with notInArray(). - agentcore_wrapper.py DEFAULT_AGENT_MODEL_ID follows, keeping the existing cross-deployable drift guard meaningful; its comment now names the silent failure mode. Two new drift-guard tests: every alias must be priced by migration 092 (the cost UI aggregates across the whole date range, so an unpriced historical alias silently zeroes those rows), and the alias list must contain both the recorded and request ids.
…en turns
The 2026-07-31 telemetry outage was invisible for ten days for one structural
reason: once a broken usage read reaches agent_messages, a zero is
indistinguishable from an honest zero. There was no persisted signal and no
alarm for "capture returned nothing", so the Cost tab read $0 and nothing
anywhere disagreed.
The wrapper already COMPUTED the answer. agentcore_wrapper.usage_capture_is_complete
produced a per-turn `usage_capture_complete` boolean, and metadata carried it --
but only infra/agent-image/eval consumed it. The router never read it and the
schema had nowhere to put it, so every production turn threw it away. This wires
that existing signal through to storage and adds the alarm.
Migration 176 -- agent_messages.usage_capture_complete BOOLEAN, nullable:
TRUE = usage was positively measured this turn.
FALSE = the read did not complete; the token columns are a FLOOR, not a
total. This is the outage signature.
NULL = unknown: the row predates the column, or the reporting image does.
Nullable is deliberate. A DEFAULT TRUE would assert that ten days of all-zero
rows were fully measured; a DEFAULT FALSE would brand all history suspect.
Neither is true. Added to migrationFiles; files 001-005 untouched; re-runnable
(ADD COLUMN IF NOT EXISTS). Partial index on the FALSE case only, since that is
the only value anything queries for and a full index would be dead weight on
the insert path.
Router (infra/lambdas/agent-router/index.ts):
- AgentCoreResult.usageCaptureComplete: boolean | null, threaded through
agentResultTelemetry -> TelemetryParams -> normalizeTelemetryParams -> the
agent_messages INSERT.
- Parsed as `typeof metadata.usage_capture_complete === 'boolean' ? ... : null`
rather than `=== true`. An image that omits the field is UNKNOWN, not
incomplete; collapsing absent to false would brand every turn from an older
image a capture failure and bury the real signal.
- normalizeTelemetryParams uses `?? null`, not `|| null`, so a legitimate
false survives.
- A router-side failure records null, not false: no usage read was attempted,
so it must not look like the transcript regression this column exists to
surface.
Alarm (UsageCaptureZero, PSD/AgentPlatform/<env>):
- New agentcore_wrapper.usage_capture_looks_broken() fires only on the
arithmetically impossible case -- a SUCCESSFUL turn that made at least one
model call yet reports zero across all four token counters. Failed turns and
zero-model-call turns are excluded so the signal stays actionable. An
unparseable counter counts as broken rather than as zero.
- Emitted via emit_agent_metric (put_metric_data), because the AgentCore log
group name carries a runtime-generated suffix that a CDK MetricFilter cannot
attach to -- the same escape hatch BootOk/BootTruncationWarn use. Also logs
a USAGE_CAPTURE_ZERO warning line.
- UsageCaptureZeroAlarm in agent-platform-stack, threshold 5-in-5-min: a rare
edge turn can trip the heuristic once, but a BROKEN capture path trips it on
every turn, so a real regression clears the threshold in a single period.
Joins the existing iterationAlarms SNS wiring.
VERIFIED, not assumed: `cdk synth AIStudio-AgentPlatformStack-Prod
--context alertEmail=...` emits the alarm with AlarmActions pointing at
AgentAlarmTopic. NOTE FOR DEPLOY: without --context alertEmail=<address> the
topic is not created and this alarm -- like all 15 existing agent-platform
alarms -- evaluates correctly and notifies nobody. The stack already emits a
synth warning for that case.
Tests: 7 new cases for usage_capture_looks_broken, including the verbatim outage
shape (model_call_count=10 with all-zero counters) and the healthy cache-only
turn (2 input tokens against a 65,301-token cache read) that must never be
mistaken for it. CDK assertion that the alarm ships with the right
metric/threshold/comparison and an SNS action.
…ge telemetry
The ten days of all-zero agent_messages rows are recoverable: the turns were
fine and the transcripts survive in the S3-checkpointed workspaces. This adds
the backfill, plus docs for the whole outage.
NO WRITE HAS BEEN EXECUTED. Dry-run is the default and writing requires explicit
per-run approval, per the standing "never write to Aurora directly" rule.
TURN ATTRIBUTION IS THE HARD PART, and the reason the logic is a separate pure
module. agent_messages.session_id is a PSD sessionKey (agent-chat-<sha256>), NOT
the OpenClaw transcript UUID. The mapping was verified against a real
checkpointed database:
session_windows.session_key = "agent:main:" + agent_messages.session_id
Up to 8 rows (turns) share one sessionKey and the transcript is append-only
across all of them, so summing a session into one row would inflate it by the
entire session history -- the same mistake the live adapter's since_ms window
exists to prevent. Each turn's window is reconstructed from the row timestamps:
turn k = ( created_at[k-1], created_at[k] ]
turn 1 = ( session start, created_at[1] ]
Sound because turns in a session are strictly serial: the router inserts a row
only after the wrapper finishes the turn, and turn k cannot start until k-1 ends.
Windows are half-open at the start so a boundary record bills to exactly one
turn. A sessionKey with several windows (rollover/compaction/fork) has them all
merged first, so a mid-session rollover cannot drop the pre-rollover calls.
Safety properties:
- Dry-run default; writing needs BOTH --execute and
--confirmation=BACKFILL_AGENT_USAGE, so no single typo mutates telemetry.
- Idempotent: every UPDATE re-asserts "all four token counters are still zero"
in its WHERE clause. The guard is enforced by the DATABASE at write time, not
by the plan computed earlier, so the run is safe to interrupt and safe to
repeat; a second run updates 0 rows and a row the fixed live capture has
since populated is never clobbered.
- Only fills zero rows -- it cannot overwrite a real measurement.
- Prints reconciliation (transcript totals vs planned totals vs unattributed
model calls) BEFORE any write. Records outside every window are reported,
never forced into the nearest turn, because inventing attribution would
corrupt per-turn cost.
- Fails fast when migration 176 is absent, instead of emitting one opaque SQL
error per workspace that never names the prerequisite.
- One unreadable workspace is logged and skipped, not fatal.
A turn whose covering records carry no usage themselves is reported
UNRECOVERABLE rather than written as zeros-over-zeros -- that is what the
pre-2026-07-29 rows look like, and claiming to have fixed them would be a lie.
FUNCTIONALLY VERIFIED against real dev data, not just unit-tested. A dry run
over psd-agents-dev-390844780692 (--since=2026-07-25) plans 57 recoverable rows
carrying input=651,790 output=51,724 cacheRead=10,207,165 cacheWrite=2,600,380,
with 2 rows correctly classified unrecoverable and 6 unattributed calls
(records past the newest row, plus background sessions that have no telemetry
row by design). Recovered rows show the caching pattern the outage hid, e.g.
input=2 output=473 cacheRead=54,256.
Two bugs that only a real run could find, both fixed:
- `immutable=1` is REQUIRED to open a checkpointed transcript. The file is in
WAL mode but arrives without its -wal/-shm sidecars, and a plain read-only
open must build the -shm, which read-only forbids ("unable to open database
file"). Safe here -- a static snapshot in a private temp dir with no
concurrent writer -- and explicitly NOT used by the live adapter, which reads
a database the runtime is actively writing.
- The -wal sidecar is deliberately not fetched at all: pairing a current
.sqlite with a stale uploaded -wal can surface a torn state. Reading the main
file alone may miss the newest uncheckpointed turns, which under-counts
rather than corrupting -- the right direction to fail.
Also:
- scripts/db/bun-sqlite.d.ts: a narrow ambient declaration for bun:sqlite.
Adding bun-types to tsconfig would override the global fetch/DOM types for
the whole tsc program and break unrelated DOM-typed tests (see
docs/learnings/build-errors/2026-06-29-bun-types-triple-slash-tsc-dom-pollution.md);
this is the contained alternative that learning points to.
- createIterationMonitoring split: the new alarm pushed it past
max-lines-per-function, so the log-derived metric filters moved into
createIterationMetricFilters. Behaviour-preserving -- verified by diffing
`cdk synth` before and after: identical logical IDs, no resource
replacement, only synth nonces differ.
- docs/operations/agent-usage-telemetry-backfill.md documents the outage, the
fix, why ORDER BY seq (not created_at), the attribution model, how to read
the report, and the alertEmail deploy caveat.
Tests: 22 cases over the pure module, covering boundary records billing to
exactly one turn, session history never collapsing into one row, seq-vs-window
completeness, unrecoverable classification, unattributed counting, the real
transcript record shape, and the confirmation-token gate.
The created_at >= since_ms prefilter rests on created_at never preceding the record's own message.timestamp. The obvious way that could break is the 2026.7.2-beta.5 import stamping migrated records with the migration time. Checked rather than assumed: the same database holds events from 2026-07-27, before its 2026-07-30 import, and no row has a skew above 60s -- the import preserved the original timestamps. Also notes why this is not load-bearing anyway: a too-large created_at only widens the prefilter, so the record-timestamp filter still decides. That is the reason the authoritative window test was deliberately NOT pushed into SQL.
…events Found in self-review: the fallback was keyed on the transcript database FILE existing, not on the transcript_events TABLE existing. Those differ on every OpenClaw host older than 2026.7.2-beta.5 -- openclaw-agent.sqlite already existed there for other state, while transcripts were still per-session JSONL. On such a host the reader would open the database, fail with 'no such table', retry six times, and report zeros -- reintroducing the exact silent-zero regression this change set exists to fix, just for older hosts instead of newer ones. The repo explicitly supports harness candidates pinned to another host, so this is a live path, not a hypothetical. Adds TranscriptTableMissing and a sqlite_master probe to raise it. The probe is needed because a missing table and a locked table BOTH surface as sqlite3.OperationalError from a plain SELECT, yet the remedies are opposite: a lock clears on retry, a missing table never will. _settle_usage keeps absorbing read failures (telemetry must never break a turn) but lets this one through, because it is a routing signal rather than a failure. Also drops a dead local left over from extracting the containment helper. Tests: an older-host database plus a JSONL transcript now reads the JSONL (31 input tokens, not 0); the same database with no JSONL returns zeros immediately instead of paying the bounded retry on every turn; and the missing table is asserted to raise TranscriptTableMissing rather than be mistaken for a lock. 776 passed in the agent-image suite.
dev took 176 for the OpenClaw OAuth client redirect repair (#1629) while this branch was open. Renumbers the migration file and every reference to it so the numbering stays collision-free and migrationFiles can hold both.
…-token-cache-b2aef3 # Conflicts: # infra/database/migrations.json
![chatgpt-codex-connector[bot]](https://avatars.githubusercontent.com/in/1144995?s=60&v=4){kind=small}
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: dfa89a4794
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
ReviewThorough, well-documented fix for the telemetry outage — the investigation depth (verifying Nit: misnamed function in the backfill script
async function requireMigration176(): Promise<void> {
...
log.fail(
"agent_messages.usage_capture_complete is missing — migration 177 has " +
"not been applied to this database. ..."
);The function is named Things I verified and did not find issues with
Turn-attribution edge case (not a blocker, worth being aware of)
Test coverageCoverage looks comprehensive for the risk surface (path traversal, WAL locking/corruption degradation, completeness/ordering, turn-window attribution, idempotent writes, migration guard). No gaps stood out. No security concerns — all SQL is parameterized (both the RDS Data API calls and the SQLite queries), the read-only |
…mestamps
The backfill reconstructed each turn's window from agent_messages timestamps:
turn k covered (created_at[k-1], created_at[k]]. That model is wrong. The router
releases the session lock in the finally of its invocation wrapper but does not
insert the telemetry row until after the Google Chat response is sent, so the
next turn can begin and append transcript records BEFORE the previous turn's row
is stamped. The windows overlap and model calls get billed to the wrong row.
Writing confidently wrong per-turn cost is worse than writing none.
Replace windows with segmentation over the transcript's own turn structure, and
use the rows only for order and count:
1. Walk a session's records in append order, cutting a segment after each
record whose stopReason is terminal (stop / end_turn). OpenClaw writes
toolUse on every call that hands off to a tool, so a terminal reason is
precisely the end-of-turn marker.
2. Drop a trailing segment with no terminal reason -- an in-flight or aborted
turn, which has no row yet. Keeping it would shift the pairing.
3. Pair segment k with row k, rows ordered by created_at.
4. If the counts disagree, attribute NOTHING for that session and report it.
A mismatch means the model of the session is wrong, and guessing would
silently misprice turns.
Step 4 is also what contains the two remaining ways attribution could be
corrupted, both surfacing as a reported count mismatch rather than a bad number:
a duplicate agent_messages row (the router's INSERT carries no idempotency key,
unlike its agent_sessions upsert), and a terminal record with no usage object
(dropped at parse time, so its segment never gets cut).
Two consequences that required call-site changes:
- Pairing needs EVERY row of a session, including already-populated ones. A
populated row still consumes a segment, so the SELECT no longer filters to
zero rows -- filtering there would slide every later segment onto the wrong
row. planSessionBackfill alone decides which rows are writable, and a
populated row is left strictly alone.
- --since is applied to the resulting UPDATES, never to the query. Removing a
session's earlier rows would delete the anchors that establish its turn
order. New restrictPlanToRowsSince does this after pairing and recomputes
plannedTotals.
Also make argument parsing fail closed. A malformed --since previously degraded
to "no filter", which would widen a production run from the outage window to ALL
history -- the opposite of what a mistyped date asked for. Any unparsed argument
(bad date, empty --prefix, unrecognized flag) is now collected into
BackfillArguments.errors and aborts before the environment and migration probes
run, so a malformed command never even connects. The --execute-without-token
check moved into the same gate.
New reporting: turnCountMismatches counts skipped sessions, and
unattributedModelCalls now means "records no paired segment claimed" rather than
"records outside every window".
Tests rewritten against the segmentation model, pinning the behaviours that a
regression would silently break: a populated row consumes its segment without
being touched, a count mismatch attributes nothing, a trailing in-flight turn is
reported as unattributed, and a novel or absent stopReason is never terminal.
…e last usage Two defects in the transcript usage read, both found by review of the SQLite migration work. 1. Completeness was decided by the wrong record. _fold_usage_records documented that "complete" is set by the newest in-window assistant record carrying a terminal stopReason. The code actually set it from the newest record carrying a usage dict: records without usage were skipped by a continue placed BEFORE the stopReason was read. So a turn whose terminal record has no usage object had its verdict decided by the preceding toolUse call, and reported incomplete despite having finished. That is not cosmetic. It pays the full settle-retry budget on a turn that was already done, and it writes FALSE into agent_messages.usage_capture_complete, which per migration 177 means "these token columns are a floor, not a total" -- manufacturing the exact broken-capture signature the UsageCaptureZero alarm exists to catch, on turns that captured everything correctly. Completeness is now decided independently of usage: any in-window assistant record carrying a stopReason updates the verdict, and records with no stopReason at all leave it untouched rather than clearing it, so a trailing non-model-call record cannot un-finish a finished turn either. The in-window test moved ahead of the usage test so an out-of-window record can never reach the verdict and report a previous turn's ending as this turn's. Token accumulation is unchanged and still requires a usage dict, so a usage-less record adds no tokens and is not counted as a model call. 2. The success-path read sat outside every exception boundary. _read_turn_usage promises "returns zeros with capture_complete=False on any failure; telemetry must never break a chat turn", but it only handled sqlite3.OperationalError and sqlite3.DatabaseError internally. The success-path call site runs after the WebSocket try/except has already closed, and neither process() nor the wrapper's executor await wraps it, so any other exception -- an OverflowError out of an absurd ISO timestamp, or any future non-defensive edit to the fold -- would propagate and discard a reply the model had already produced. Worse, that turn's tool calls have run, so a retry at any higher layer would re-run their side effects, the precise outcome _should_retry_upstream is written to avoid. Fixed on the callee rather than at each call site, so the guarantee is intrinsic and cannot be reintroduced by moving a call: the implementation is now _read_turn_usage_unguarded, and _read_turn_usage is a thin wrapper that catches Exception, logs it, and returns the zeroed result. Both call sites (success path and the chat-error path) inherit it. Tests added for all four behaviours: a terminal record without usage completes the turn, a record with no stopReason does not un-finish it, a previous turn's terminal record cannot complete this one, and a non-sqlite exception forced out of the fold degrades to zeros instead of escaping. Also close a filesystem-facade gap this work introduced: mkdtemp and mkdtempSync were in neither READ_METHODS nor WRITE_METHODS, so validatedFs passed them straight through with no path validation. The backfill script's temp-dir call is safe only because its prefix is hardcoded; adding both to WRITE_METHODS confines the target like any other write, so a future caller with a dynamic prefix stays inside the allowed roots.
Review: restore token-usage telemetry after OpenClaw JSONL→SQLite moveReviewed the full diff (20 files, ~3020 additions). This is a well-tested, carefully documented fix for a real 10-day silent-telemetry outage — the shared Bugs/Correctness1. totals: Dict[str, int] = {"input": 0, "output": 0, "cache_read": 0,
"cache_write": 0, "model_calls": 0}
for attempt in range(self.USAGE_SETTLE_ATTEMPTS):
try:
totals, complete = read()
except sqlite3.OperationalError as exc:
...
complete = False
except sqlite3.DatabaseError as exc:
...
break
if complete:
return {**totals, "capture_complete": True}
...
2. Stale comment on the SecurityNo issues found. PerformanceNo concerns. Re-opening the SQLite connection per settle attempt mirrors the prior JSONL design's per-attempt reopen, operates on a local per-container file, and is bounded by Test CoverageCoverage is thorough on both sides — bool-vs-int, corrupt DB, locked DB, missing table vs. missing file, path containment/ Code Quality/Style
Nice work tracking down a genuinely subtle silent-failure bug (zero telemetry reads being indistinguishable from real zeros) and building both the fix and a verified backfill path for the affected window. |
Two review notes on _settle_usage, both addressed. The comment on the OperationalError branch claimed it also covers "a host whose schema predates transcript_events". That is no longer true and was a leftover from an earlier iteration of the error split: a missing table is raised as TranscriptTableMissing by the sqlite_master probe specifically so the retryable case (locked or busy) and the fall-back-to-JSONL case stay distinguishable. Corrected, and the reason the distinction exists is now stated where the next reader will need it. The reviewer also flagged that "complete" was not seeded before the retry loop, and could not confirm from their environment whether that was live. It is not: the corrupt-database branch breaks out before "complete" is read, and the post-loop return uses a literal False rather than the variable, so no UnboundLocalError is reachable today. Seeded it anyway, alongside totals. The cost is one line, and it makes the fast-break path self-contained rather than correct-by-coincidence -- a future edit returning "complete" instead of the literal would otherwise fail on the single hardest path to reach in testing. No behaviour change; 171 agent-image tests still pass.
Member
Author
|
🤖 pr-fix routine round 1 complete.
What I did: re-verified every open finding against the current head (
Marking Two items in the PR description remain deliberately open and are not routine-actionable — the pre-existing router INSERT idempotency gap and the symlinked-directory containment limitation, both explicitly scoped out by the author. The post-deploy steps (rebuild the agent image so Generated by Claude Code |
krishagel
added
the
pr-fix-done
Claude
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
Agent token-usage telemetry has read zero on every turn since 2026-07-31 (dev) / 2026-08-01 (prod). OpenClaw
2026.7.2-beta.5moved per-session transcripts out ofinto a per-agent SQLite database
and deleted the JSONL files.
harness_adapter._read_turn_usage()— the only usage source on the post-#1384 SigV4 path — kept opening the JSONL path, found nothing, and returned honest zeros.Nothing failed. A zero read is indistinguishable from a genuine zero once it lands in
agent_messages, soadmin/agents→ Cost showed$0for ten days with no error, no alarm, and no failed turn.Caching was never broken. A checkpointed workspace database shows the healthy steady state throughout: ~2 billable input tokens against a 54k–71k cache read per turn. Only the telemetry regressed.
Changes
1. Read the SQLite transcript (
harness_adapter.py)_fold_usage_records()now holds the whole accounting fold, shared by both stores (each supplies record JSON in append order), so the SQLite and JSONL paths cannot drift in windowing, completeness, or token extraction._sum_sqlite_transcript_usage(): read-onlyfile:URI (mode=ro, which also refuses to create a missing file),session_idbound,created_at >= since_msprefilter,ORDER BY seq._settle_usage()/_contained_transcript_path()extracted;OperationalErrorretries,DatabaseError(corrupt) breaks out immediately.boolis anintsubclass, so a JSONtruepreviously added 1).2. Correct the recorded model id (
platform-model.ts)AGENT_MODEL_ID→us.anthropic.claude-sonnet-5. #1227 moved the provider onto bedrock-runtime's native endpoint, which echoes the request's inference-profile id verbatim instead of rewriting it to the bare form. NewAGENT_MODEL_ID_ALIASES;getPricableModels()excludes all three forms. This class of drift doesn't fail loudly — rows just stop joiningai_modelsand cost reads $0 (bug #1083).3. Make the next one loud (migration 177 +
UsageCaptureZero)The wrapper already computed
usage_capture_complete— but only the eval harness consumed it, so production turns threw the answer away. Now persisted onagent_messages, nullable on purpose:true= measured,false= the token columns are a floor not a total,null= unknown (row or image predates the column). ADEFAULT TRUEwould assert ten days of zeros were measured;DEFAULT FALSEwould brand all history suspect.New
UsageCaptureZerometric +psd-agent-usage-capture-zero-<env>alarm fires on the arithmetically impossible case: a successful turn that made ≥1 model call yet reports zero across all four counters.4. Backfill the history (
scripts/db/backfill-agent-message-usage.ts)Dry-run-first, idempotent. No write has been executed.
Verification
Re-run in full after the review fixes below:
python3 -m unittest(agent-image)bun run lint(--max-warnings 0)bun run typecheck(full codebase)bun run test:ci(full suite)atrium-bulk-run,gemini-live-provider) died on a jest worker SIGSEGV under parallel load; both pass in isolation (32/32), so this is a runner crash, not a failuretests/e2e/admin-agents.spec.tscdk synth --allDev + Prodpsd-agent-usage-capture-zero-devpresent in the Dev templateinfratsc --noEmit177-agent-usage-capture-complete.sqlinmigrationFiles--since, unknown flag, and--executewithout the token each abort before any connectionNote on infra jest: CI does not run it (the CDK job runs
tsc+cdk synth), and it does not resolve ts-jest from this worktree.tscandsynthboth pass, which is the gate CI actually applies.Verified against reality, not assumed
I pulled a real checkpointed
openclaw-agent.sqlitefrompsd-agents-dev-390844780692and the dev database, rather than trusting the handoff:event_jsonholds the same record objects the JSONL did, verbatim (message.usage.{input,output,cacheRead,cacheWrite},stopReason ∈ {toolUse, stop, error}).created_at >= message.timestampalways — 488 records, 0 inversions, skew 0–19,941 ms. That makescreated_at >= since_msa safe superset prefilter; the authoritative window test stays on the record timestamp.created_atis NOT monotonic withseq— 28 of 32 sessions contain a row whosecreated_atprecedes that of a lowerseq. Completeness is decided by the last record, soORDER BY created_atwould misread it. This is why the scan orders byseq.created_at— the same database holds events from 2026-07-27 (before its 2026-07-30 import) and no row has a skew above 60 s. So migrated rows don't mis-window a turn.agent_messagesrow on/after 2026-07-31 carriesus.anthropic.claude-sonnet-5(58 rows); the bare form appears only through 2026-07-29 (630 rows). All three aliases are priced and inactive.Backfill dry run — earlier numbers WITHDRAWN
An earlier revision of this PR quoted a dev dry run (57 rows to update, ~10.2M recovered
cacheRead). Those numbers are withdrawn. They were produced under the row-timestamp attribution model that review then disproved (see below), so the per-row split cannot be trusted even where the aggregate looked plausible.It cannot be re-run yet:
usage_capture_completedoes not exist on dev (confirmed by queryinginformation_schema), and the script correctly refuses to read anything without it. A fresh dry run is a post-deploy step, and its report must be read before anyone passes--execute.Turn attribution — the row-timestamp model was WRONG
agent_messages.session_idis a PSD sessionKey (agent-chat-<sha256>), not the transcript UUID; the mapping (session_windows.session_key = "agent:main:" + session_id) was verified against the real database, and up to 8 turns share one sessionKey with an append-only transcript across all of them.The original fix reconstructed each turn as
( created_at[k-1], created_at[k] ]. That is unsound. The router releases the session lock in thefinallyof its invocation wrapper but does not insert the telemetry row until after the Google Chat response is sent, so the next turn can begin and append transcript records before the previous turn's row is stamped. The windows overlap and model calls get billed to the wrong row — confidently wrong cost, which is worse than none.Replaced with segmentation over the transcript's own turn structure, rows supplying only order and count:
stopReason(stop/end_turn). OpenClaw writestoolUseon every hand-off to a tool, so a terminal reason is exactly the end-of-turn marker.created_at.turnCountMismatches). A mismatch means the session model is wrong, and guessing would silently misprice turns.Step 4 is also what contains the two remaining corruption routes, converting both into a reported gap rather than a bad number: a duplicate
agent_messagesrow (the router's INSERT has no idempotency key, unlike itsagent_sessionsupsert), and a terminal record carrying nousageobject (dropped at parse time, so its segment never gets cut).Two consequences that changed call sites:
planSessionBackfillalone decides what is writable, and a populated row is left strictly alone.--sincenow filters the resulting updates, never the query. Removing a session's earlier rows would delete the anchors that establish its turn order.Two bugs only a real run could find, both fixed:
immutable=1is required to open a checkpointed transcript — it's WAL-mode but arrives without its-wal/-shm, and a plain read-only open must build the-shm, which read-only forbids. Safe there (static snapshot, no writer) and deliberately not used by the live adapter.-walsidecar is intentionally never fetched: pairing a current.sqlitewith a stale uploaded-walcan surface a torn state. Reading the main file alone under-counts rather than corrupting.One bug found in self-review: the JSONL fallback was keyed on the database file existing rather than the
transcript_eventstable existing. Those differ on every host older than 2026.7.2-beta.5 — which would have reintroduced the identical silent-zero bug for older/candidate images. Fixed withTranscriptTableMissing+ asqlite_masterprobe, because a missing table and a locked table both surface asOperationalErroryet need opposite remedies.Review response — two more real defects in the adapter
Beyond the attribution rewrite above, review found two defects in the live read. Both are fixed with regression tests.
1. Completeness was decided by the wrong record.
_fold_usage_recordsdocumented that completeness comes from the newest in-window assistant record with a terminalstopReason, but the code took it from the newest record carrying a usage dict — records without usage hit acontinueplaced beforestopReasonwas read. So a turn whose terminal record has no usage object had its verdict set by the precedingtoolUsecall and reported incomplete despite having finished.That is not cosmetic: it burns the full settle-retry budget on an already-finished turn, and writes
FALSEintousage_capture_complete, which per migration 177 means "these token columns are a floor, not a total" — manufacturing the exact broken-capture signature the new alarm exists to catch, on turns that captured correctly.Completeness is now decided independently of usage. Any in-window assistant record carrying a
stopReasonupdates the verdict; a record with nostopReasonleaves it untouched rather than clearing it, so a trailing non-model-call record cannot un-finish a finished turn either. The in-window test moved ahead of the usage test so an out-of-window record can never reach the verdict and report a previous turn's ending as this turn's. Token accumulation still requires a usage dict, so a usage-less record adds no tokens and is not counted as a model call.2. The success-path read sat outside every exception boundary.
_read_turn_usagepromises zeros on any failure ("telemetry must never break a chat turn") but only handledsqlite3.OperationalErrorandsqlite3.DatabaseError. Its success-path call site runs after the WebSockettry/excepthas closed, and neitherprocess()nor the wrapper's executor await wraps it — so any other exception would propagate and discard a reply the model had already produced. That turn's tool calls have run, so a retry at a higher layer would re-run their side effects, exactly what_should_retry_upstreamis written to avoid.Fixed on the callee, not the call site, so the guarantee is intrinsic and cannot be reintroduced by moving a call: the body is now
_read_turn_usage_unguardedand_read_turn_usageis a thin wrapper catchingException. Both call sites inherit it.Also closed a facade gap this PR introduced:
mkdtemp/mkdtempSyncwere in neither method set invalidated-fs.ts, sovalidatedFspassed them through unvalidated. The backfill's temp-dir call is safe only because its prefix is hardcoded; both are now inWRITE_METHODS.Bot-review findings, both addressed
OperationalErrorcomment (CONFIRMED). It claimed the branch also covers a host whose schema predatestranscript_events; that case is raised asTranscriptTableMissingby thesqlite_masterprobe. Comment corrected, and it now states why the split exists.completenot seeded before the settle loop (PLAUSIBLE). Verified not live: the corrupt-database branchbreaks beforecompleteis read, and the post-loop return uses a literalFalse. Seeded it anyway — one line to make the fast-break path self-contained rather than correct-by-coincidence, since a future edit returning the variable would fail on the hardest path to reach in testing.applyUpdate()'s zero-guard has no automated regression test. Fair. It is an unexported function in an ops script gated behind--executeplus a confirmation token, and the guard is enforced by the database in theWHEREclause rather than by the plan; making it testable would mean restructuring the script, which I left out of this PR.Two findings deliberately not acted on
insertTelemetrySummaryis a plain INSERT with no idempotency key, so a Lambda retry can double-write a turn. Real, but pre-existing and outside this PR; adding a uniqueness guard is new blocking behaviour I won't add unasked. The backfill's count-mismatch refusal (step 4) already converts a duplicate row from "silently mispriced turn" into "reported gap". Say the word and I'll do it as a follow-up.-shmexists, tripping the alarm on every scale-out. Ordering refutes it: this read happens strictly after the runtime appended this turn's transcript records, which requires the writer to have opened the database, so-shmnecessarily exists by then. If it somehow failed, the settle loop retries and degrades. No change made.Known pre-existing limitation (verified, not fixed here — your call)
The realpath containment catches a symlinked transcript file, but not a symlinked containing directory. I confirmed empirically: if
agents/main/agent/is itself a symlink pointing outside the workspace, the read follows it (a planted database returned its 31,337 tokens).This is unchanged behaviour — the old JSONL path had the identical property for
agents/<id>/sessions/, and the existing comment scopes the check to symlinked transcripts, with the dot-name component check being what stops traversal. Impact is telemetry integrity, not confidentiality: the sandboxednodeagent already owns that tree, and the only thing it could achieve is having another database's token counts billed to its own turns. Nothing is exfiltrated — only aggregate numbers reachagent_messages.I did not add a guard for it, since that would be new blocking behaviour outside this PR's scope. Happy to do it as a follow-up if you want it closed.
Evidence
Agent Platform Dashboard → Cost tab, captured by the authenticated E2E run. Note the local fixture has no agent messages, so the figures are
$0.00— this shows the tab renders correctly and the "Compare to" list no longer offers the harness model against itself. The numeric evidence is the dry run above.Deploy notes
agentImageDigestOVERRIDESagentImageTag. A stale digest silently deploys the wrong image — this caused a prod outage on 2026-08-10. The fix here lives in the agent image, so it does nothing until a rebuilt image is actually deployed. Rebuild viainfra/agent-image/build-and-push.shand confirm the digest is updated.usage_capture_complete(migration 177), anddevAgentPlatformStack.addDependency(devDbStack)puts the migration before the router. A deliberately partial router-only deploy would break inserts — don't partial-deploy.--context alertEmail=<address>. Without it the topic isn't created and this alarm — like all 15 existing agent-platform alarms — evaluates correctly and notifies nobody. The stack emits a synth warning for that case.Prod confirmed broken the same way (queried this session)
Read via the RDS Data API against
aistudio-prod-cluster, daily totals onagent_messages:us.anthropic.claude-sonnet-5us.anthropic.claude-sonnet-5us.anthropic.claude-sonnet-5claude-sonnet-5claude-sonnet-5claude-sonnet-5claude-sonnet-5This pins the whole story: prod went dark 2026-08-01, exactly when the recorded model id flipped to the inference-profile form, and healthy cache telemetry (29.3M
cache_readagainst 810 billable input on 7/30) is what the dashboard should be showing. Schema note for anyone re-running this: the columns aremodel,cache_read_input_tokens,cache_write_input_tokens— notmodel_id/cache_read_tokens.Still to confirm post-deploy
input/output/cache_readtoagent_messages, and the Cost tab renders it.turnCountMismatches— before anyone passes--execute. The withdrawn numbers above must not be used as the expectation.'unknown'.