Count every Codex model request, not just the last

App-server sends `thread/tokenUsage/updated` once per *model request*, and a
Codex turn makes as many as it made tool calls. The translator held the last
one until `turn/completed`, so a turn's cost was reported as its final
request alone -- measured against the real rollout, 28,878 tokens for a turn
that spent 51,399 -- and the gap grows with how much work the turn did. The
context figure also stood still for the whole turn, which is exactly when it
is moving most.

Reported as each arrives instead: `tokens` now adds up to what the turn
spent, and the context figure climbs during the turn (28,921 -> 33,190 ->
35,978 on a two-file read here, matching Codex's own `last_token_usage`
exactly at every step).
This commit is contained in:
iris committed 2026-09-13 03:58:47 -04:00
1 parent 898e6b92d0
commit fe25108c51
1 file changed
+41 -37
+41 -37
View File
@@ -17,7 +17,6 @@ pub(super) struct Translator {
pub(super) thread_id: Option<String>, pub(super) thread_id: Option<String>,
completed: bool, completed: bool,
limited: bool, limited: bool,
pending_usage: Option<Usage>,
subagents: Option<Arc<Subagents>>, subagents: Option<Arc<Subagents>>,
children: HashMap<String, Translator>, children: HashMap<String, Translator>,
prompts: HashMap<String, String>, prompts: HashMap<String, String>,
@@ -25,11 +24,6 @@ pub(super) struct Translator {
in_turn: bool, in_turn: bool,
} }
struct Usage {
tokens: u64,
context: Option<u64>,
}
impl Translator { impl Translator {
pub(super) fn new(subagents: Arc<Subagents>, thread_id: Option<String>, in_turn: bool) -> Self { pub(super) fn new(subagents: Arc<Subagents>, thread_id: Option<String>, in_turn: bool) -> Self {
Self { Self {
@@ -130,7 +124,6 @@ impl Translator {
Some("turn.started") | Some("turn/started") => { Some("turn.started") | Some("turn/started") => {
self.completed = false; self.completed = false;
self.limited = false; self.limited = false;
self.pending_usage = None;
vec![Event::Status { vec![Event::Status {
state: SessionStatus::Running, state: SessionStatus::Running,
}] }]
@@ -191,27 +184,31 @@ impl Translator {
output: output.to_string(), output: output.to_string(),
}] }]
} }
// One of these per *model request*, not per turn: app-server's `last` is the
// request that just finished, and a turn is as many requests as it made tool
// calls. Reported as each arrives, so `tokens` adds up to what the turn cost --
// held to the end of the turn it was the last request's cost alone, which on a
// two-request turn measured 28,878 against the 51,399 actually spent -- and so
// the context figure moves while a long turn is still running rather than
// standing at what it was before the turn began.
Some("thread/tokenUsage/updated") => { Some("thread/tokenUsage/updated") => {
let last = &body["tokenUsage"]["last"]; let last = &body["tokenUsage"]["last"];
self.pending_usage = last.get("totalTokens")
last.get("totalTokens") .and_then(Value::as_u64)
.and_then(Value::as_u64) .map(|tokens| Event::UsageDelta {
.map(|tokens| Usage { tokens,
tokens, // Cached input is a subset of this figure, not an additional count.
// Cached input is a subset of this figure, not an additional count. context: last.get("inputTokens").and_then(Value::as_u64),
context: last.get("inputTokens").and_then(Value::as_u64), })
}); .into_iter()
Vec::new() .collect()
} }
Some("turn.completed") | Some("turn/completed") => { Some("turn.completed") | Some("turn/completed") => {
self.completed = true; self.completed = true;
let mut events = Vec::new(); let mut events = Vec::new();
if let Some(usage) = self.pending_usage.take() { // The old `codex exec --json` dialect reports the turn's usage here and
events.push(Event::UsageDelta { // sends no `thread/tokenUsage/updated` at all.
tokens: usage.tokens, if let Some(usage) = line.get("usage") {
context: usage.context,
});
} else if let Some(usage) = line.get("usage") {
let input = number(usage, "input_tokens"); let input = number(usage, "input_tokens");
let output = number(usage, "output_tokens"); let output = number(usage, "output_tokens");
if input.is_some() || output.is_some() { if input.is_some() || output.is_some() {
@@ -1069,26 +1066,33 @@ mod tests {
text: "hello, revised".to_string() text: "hello, revised".to_string()
}] }]
); );
assert!( // One per model request, as it arrives. A turn that made two of them costs both,
translator // and the context figure moves while the turn is still running.
.translate(&line( assert_eq!(
r#"{"method":"thread/tokenUsage/updated","params":{"tokenUsage":{"last":{"inputTokens":39,"cachedInputTokens":30,"outputTokens":3,"reasoningOutputTokens":1,"totalTokens":42},"total":{"inputTokens":100,"cachedInputTokens":80,"outputTokens":9,"reasoningOutputTokens":2,"totalTokens":109},"modelContextWindow":258400}}}"# translator.translate(&line(
)) r#"{"method":"thread/tokenUsage/updated","params":{"tokenUsage":{"last":{"inputTokens":39,"cachedInputTokens":30,"outputTokens":3,"reasoningOutputTokens":1,"totalTokens":42},"total":{"inputTokens":100,"cachedInputTokens":80,"outputTokens":9,"reasoningOutputTokens":2,"totalTokens":109},"modelContextWindow":258400}}}"#
.is_empty() )),
vec![Event::UsageDelta {
tokens: 42,
context: Some(39)
}]
);
assert_eq!(
translator.translate(&line(
r#"{"method":"thread/tokenUsage/updated","params":{"tokenUsage":{"last":{"inputTokens":61,"cachedInputTokens":39,"outputTokens":4,"reasoningOutputTokens":1,"totalTokens":65},"total":{"inputTokens":161,"cachedInputTokens":119,"outputTokens":13,"reasoningOutputTokens":3,"totalTokens":174},"modelContextWindow":258400}}}"#
)),
vec![Event::UsageDelta {
tokens: 65,
context: Some(61)
}]
); );
assert_eq!( assert_eq!(
translator.translate(&line( translator.translate(&line(
r#"{"method":"turn/completed","params":{"turn":{"id":"turn-1","status":"completed","error":null}}}"# r#"{"method":"turn/completed","params":{"turn":{"id":"turn-1","status":"completed","error":null}}}"#
)), )),
vec![ vec![Event::Status {
Event::UsageDelta { state: SessionStatus::Idle
tokens: 42, }]
context: Some(39)
},
Event::Status {
state: SessionStatus::Idle
}
]
); );
} }