mirror of
https://github.com/openai/codex.git
synced 2026-04-28 00:25:56 +00:00
fix(app-server): replay token usage after resume and fork (#18023)
## Problem When a user resumed or forked a session, the TUI could render the restored thread history immediately, but it did not receive token usage until a later model turn emitted a fresh usage event. That left the context/status UI blank or stale during the exact window where the user expects resumed state to look complete. Core already reconstructed token usage from the rollout; the missing behavior was app-server lifecycle replay to the client that just attached. ## Mental model Token usage has two representations. The rollout is the durable source of historical `TokenCount` events, and the core session cache is the in-memory snapshot reconstructed from that rollout on resume or fork. App-server v2 clients do not read core state directly; they learn about usage through `thread/tokenUsage/updated`. The fix keeps those roles separate: core exposes the restored `TokenUsageInfo`, and app-server sends one targeted notification after a successful `thread/resume` or `thread/fork` response when that restored snapshot exists. This notification is not a new model event. It is a replay of already-persisted state for the client that just attached. That distinction matters because using the normal core event path here would risk duplicating `TokenCount` entries in the rollout and making future resumes count historical usage twice. ## Non-goals This change does not add a new protocol method or payload shape. It reuses the existing v2 `thread/tokenUsage/updated` notification and the TUI’s existing handler for that notification. This change does not alter how token usage is computed, accumulated, compacted, or written during turns. It only exposes the token usage that resume and fork reconstruction already restored. This change does not broadcast historical usage replay to every subscribed client. The replay is intentionally scoped to the connection that requested resume or fork so already-attached clients are not surprised by an old usage update while they may be rendering live activity. ## Tradeoffs Sending the usage notification after the JSON-RPC response preserves a clear lifecycle order: the client first receives the thread object, then receives restored usage for that thread. The tradeoff is that usage is still a notification rather than part of the `thread/resume` or `thread/fork` response. That keeps the protocol shape stable and avoids duplicating usage fields across response types, but clients must continue listening for notifications after receiving the response. The helper selects the latest non-in-progress turn id for the replayed usage notification. This is conservative because restored usage belongs to completed persisted accounting, not to newly attached in-flight work. The fallback to the last turn preserves a stable wire payload for unusual histories, but histories with no meaningful completed turn still have a weak attribution story. ## Architecture Core already seeds `Session` token state from the last persisted rollout `TokenCount` during `InitialHistory::Resumed` and `InitialHistory::Forked`. The new core accessor exposes the complete `TokenUsageInfo` through `CodexThread` without giving app-server direct session mutation authority. App-server calls that accessor from three lifecycle paths: cold `thread/resume`, running-thread resume/rejoin, and `thread/fork`. In each path, the server sends the normal response first, then calls a shared helper that converts core usage into `ThreadTokenUsageUpdatedNotification` and sends it only to the requesting connection. The tests build fake rollouts with a user turn plus a persisted token usage event. They then exercise `thread/resume` and `thread/fork` without starting another model turn, proving that restored usage arrives before any next-turn token event could be produced. ## Observability The primary debug path is the app-server JSON-RPC stream. After `thread/resume` or `thread/fork`, a client should see the response followed by `thread/tokenUsage/updated` when the source rollout includes token usage. If the notification is absent, check whether the rollout contains an `event_msg` payload of type `token_count`, whether core reconstruction seeded `Session::token_usage_info`, and whether the connection stayed attached long enough to receive the targeted notification. The notification is sent through the existing `OutgoingMessageSender::send_server_notification_to_connections` path, so existing app-server tracing around server notifications still applies. Because this is a replay, not a model turn event, debugging should start at the resume/fork handlers rather than the turn event translation in `bespoke_event_handling`. ## Tests The focused regression coverage is `cargo test -p codex-app-server emits_restored_token_usage`, which covers both resume and fork. The core reconstruction guard is `cargo test -p codex-core record_initial_history_seeds_token_info_from_rollout`. Formatting and lint/fix passes were run with `just fmt`, `just fix -p codex-core`, and `just fix -p codex-app-server`. Full crate test runs surfaced pre-existing unrelated failures in command execution and plugin marketplace tests; the new token usage tests passed in focused runs and within the app-server suite before the unrelated command execution failure.
This commit is contained in:
@@ -2,6 +2,7 @@ use anyhow::Result;
|
||||
use app_test_support::ChatGptAuthFixture;
|
||||
use app_test_support::McpProcess;
|
||||
use app_test_support::create_fake_rollout;
|
||||
use app_test_support::create_fake_rollout_with_token_usage;
|
||||
use app_test_support::create_mock_responses_server_repeating_assistant;
|
||||
use app_test_support::to_response;
|
||||
use app_test_support::write_chatgpt_auth;
|
||||
@@ -9,6 +10,7 @@ use codex_app_server_protocol::JSONRPCError;
|
||||
use codex_app_server_protocol::JSONRPCMessage;
|
||||
use codex_app_server_protocol::JSONRPCResponse;
|
||||
use codex_app_server_protocol::RequestId;
|
||||
use codex_app_server_protocol::ServerNotification;
|
||||
use codex_app_server_protocol::SessionSource;
|
||||
use codex_app_server_protocol::ThreadForkParams;
|
||||
use codex_app_server_protocol::ThreadForkResponse;
|
||||
@@ -186,6 +188,59 @@ async fn thread_fork_creates_new_thread_and_emits_started() -> Result<()> {
|
||||
Ok(())
|
||||
}
|
||||
|
||||
#[tokio::test]
|
||||
async fn thread_fork_emits_restored_token_usage_before_next_turn() -> Result<()> {
|
||||
let server = create_mock_responses_server_repeating_assistant("Done").await;
|
||||
let codex_home = TempDir::new()?;
|
||||
create_config_toml(codex_home.path(), &server.uri())?;
|
||||
|
||||
let conversation_id = create_fake_rollout_with_token_usage(
|
||||
codex_home.path(),
|
||||
"2025-01-05T12-00-00",
|
||||
"2025-01-05T12:00:00Z",
|
||||
"Saved user message",
|
||||
Some("mock_provider"),
|
||||
)?;
|
||||
|
||||
let mut mcp = McpProcess::new(codex_home.path()).await?;
|
||||
timeout(DEFAULT_READ_TIMEOUT, mcp.initialize()).await??;
|
||||
|
||||
let fork_id = mcp
|
||||
.send_thread_fork_request(ThreadForkParams {
|
||||
thread_id: conversation_id,
|
||||
..Default::default()
|
||||
})
|
||||
.await?;
|
||||
let fork_resp: JSONRPCResponse = timeout(
|
||||
DEFAULT_READ_TIMEOUT,
|
||||
mcp.read_stream_until_response_message(RequestId::Integer(fork_id)),
|
||||
)
|
||||
.await??;
|
||||
let ThreadForkResponse { thread, .. } = to_response::<ThreadForkResponse>(fork_resp)?;
|
||||
|
||||
let note = timeout(
|
||||
DEFAULT_READ_TIMEOUT,
|
||||
mcp.read_stream_until_notification_message("thread/tokenUsage/updated"),
|
||||
)
|
||||
.await??;
|
||||
let parsed: ServerNotification = note.try_into()?;
|
||||
let ServerNotification::ThreadTokenUsageUpdated(notification) = parsed else {
|
||||
panic!("expected thread/tokenUsage/updated notification");
|
||||
};
|
||||
|
||||
assert_eq!(notification.thread_id, thread.id);
|
||||
assert_eq!(notification.turn_id, thread.turns[0].id);
|
||||
assert_eq!(notification.token_usage.total.total_tokens, 150);
|
||||
assert_eq!(notification.token_usage.total.input_tokens, 120);
|
||||
assert_eq!(notification.token_usage.total.cached_input_tokens, 20);
|
||||
assert_eq!(notification.token_usage.total.output_tokens, 30);
|
||||
assert_eq!(notification.token_usage.total.reasoning_output_tokens, 10);
|
||||
assert_eq!(notification.token_usage.last.total_tokens, 90);
|
||||
assert_eq!(notification.token_usage.model_context_window, Some(200_000));
|
||||
|
||||
Ok(())
|
||||
}
|
||||
|
||||
#[tokio::test]
|
||||
async fn thread_fork_tracks_thread_initialized_analytics() -> Result<()> {
|
||||
let server = create_mock_responses_server_repeating_assistant("Done").await;
|
||||
|
||||
@@ -3,6 +3,7 @@ use app_test_support::ChatGptAuthFixture;
|
||||
use app_test_support::McpProcess;
|
||||
use app_test_support::create_apply_patch_sse_response;
|
||||
use app_test_support::create_fake_rollout_with_text_elements;
|
||||
use app_test_support::create_fake_rollout_with_token_usage;
|
||||
use app_test_support::create_final_assistant_message_sse_response;
|
||||
use app_test_support::create_mock_responses_server_repeating_assistant;
|
||||
use app_test_support::create_mock_responses_server_sequence_unchecked;
|
||||
@@ -23,6 +24,7 @@ use codex_app_server_protocol::JSONRPCResponse;
|
||||
use codex_app_server_protocol::PatchApplyStatus;
|
||||
use codex_app_server_protocol::PatchChangeKind;
|
||||
use codex_app_server_protocol::RequestId;
|
||||
use codex_app_server_protocol::ServerNotification;
|
||||
use codex_app_server_protocol::ServerRequest;
|
||||
use codex_app_server_protocol::SessionSource;
|
||||
use codex_app_server_protocol::ThreadItem;
|
||||
@@ -50,6 +52,11 @@ use codex_protocol::protocol::EventMsg;
|
||||
use codex_protocol::protocol::SessionMeta;
|
||||
use codex_protocol::protocol::SessionMetaLine;
|
||||
use codex_protocol::protocol::SessionSource as RolloutSessionSource;
|
||||
use codex_protocol::protocol::TokenCountEvent;
|
||||
use codex_protocol::protocol::TokenUsage;
|
||||
use codex_protocol::protocol::TokenUsageInfo;
|
||||
use codex_protocol::protocol::TurnAbortReason;
|
||||
use codex_protocol::protocol::TurnAbortedEvent;
|
||||
use codex_protocol::protocol::TurnStartedEvent;
|
||||
use codex_protocol::user_input::ByteRange;
|
||||
use codex_protocol::user_input::TextElement;
|
||||
@@ -278,6 +285,268 @@ async fn thread_resume_returns_rollout_history() -> Result<()> {
|
||||
Ok(())
|
||||
}
|
||||
|
||||
#[tokio::test]
|
||||
async fn thread_resume_emits_restored_token_usage_before_next_turn() -> Result<()> {
|
||||
let server = create_mock_responses_server_repeating_assistant("Done").await;
|
||||
let codex_home = TempDir::new()?;
|
||||
create_config_toml(codex_home.path(), &server.uri())?;
|
||||
|
||||
let conversation_id = create_fake_rollout_with_token_usage(
|
||||
codex_home.path(),
|
||||
"2025-01-05T12-00-00",
|
||||
"2025-01-05T12:00:00Z",
|
||||
"Saved user message",
|
||||
Some("mock_provider"),
|
||||
)?;
|
||||
|
||||
let mut mcp = McpProcess::new(codex_home.path()).await?;
|
||||
timeout(DEFAULT_READ_TIMEOUT, mcp.initialize()).await??;
|
||||
|
||||
let resume_id = mcp
|
||||
.send_thread_resume_request(ThreadResumeParams {
|
||||
thread_id: conversation_id,
|
||||
..Default::default()
|
||||
})
|
||||
.await?;
|
||||
let resume_resp: JSONRPCResponse = timeout(
|
||||
DEFAULT_READ_TIMEOUT,
|
||||
mcp.read_stream_until_response_message(RequestId::Integer(resume_id)),
|
||||
)
|
||||
.await??;
|
||||
let ThreadResumeResponse { thread, .. } = to_response::<ThreadResumeResponse>(resume_resp)?;
|
||||
|
||||
let note = timeout(
|
||||
DEFAULT_READ_TIMEOUT,
|
||||
mcp.read_stream_until_notification_message("thread/tokenUsage/updated"),
|
||||
)
|
||||
.await??;
|
||||
let parsed: ServerNotification = note.try_into()?;
|
||||
let ServerNotification::ThreadTokenUsageUpdated(notification) = parsed else {
|
||||
panic!("expected thread/tokenUsage/updated notification");
|
||||
};
|
||||
|
||||
assert_eq!(notification.thread_id, thread.id);
|
||||
assert_eq!(notification.turn_id, thread.turns[0].id);
|
||||
assert_eq!(notification.token_usage.total.total_tokens, 150);
|
||||
assert_eq!(notification.token_usage.total.input_tokens, 120);
|
||||
assert_eq!(notification.token_usage.total.cached_input_tokens, 20);
|
||||
assert_eq!(notification.token_usage.total.output_tokens, 30);
|
||||
assert_eq!(notification.token_usage.total.reasoning_output_tokens, 10);
|
||||
assert_eq!(notification.token_usage.last.total_tokens, 90);
|
||||
assert_eq!(notification.token_usage.model_context_window, Some(200_000));
|
||||
|
||||
Ok(())
|
||||
}
|
||||
|
||||
#[tokio::test]
|
||||
async fn thread_resume_token_usage_replay_ignores_stale_interrupted_tail_turn() -> Result<()> {
|
||||
let server = create_mock_responses_server_repeating_assistant("Done").await;
|
||||
let codex_home = TempDir::new()?;
|
||||
create_config_toml(codex_home.path(), &server.uri())?;
|
||||
|
||||
let filename_ts = "2025-01-05T12-00-00";
|
||||
let meta_rfc3339 = "2025-01-05T12:00:00Z";
|
||||
let conversation_id = create_fake_rollout_with_token_usage(
|
||||
codex_home.path(),
|
||||
filename_ts,
|
||||
meta_rfc3339,
|
||||
"Saved user message",
|
||||
Some("mock_provider"),
|
||||
)?;
|
||||
let rollout_file_path = rollout_path(codex_home.path(), filename_ts, &conversation_id);
|
||||
let persisted_rollout = std::fs::read_to_string(&rollout_file_path)?;
|
||||
let stale_turn_id = "incomplete-turn-after-token-usage";
|
||||
let appended_rollout = [
|
||||
json!({
|
||||
"timestamp": meta_rfc3339,
|
||||
"type": "event_msg",
|
||||
"payload": serde_json::to_value(EventMsg::TurnStarted(TurnStartedEvent {
|
||||
turn_id: stale_turn_id.to_string(),
|
||||
started_at: None,
|
||||
model_context_window: None,
|
||||
collaboration_mode_kind: Default::default(),
|
||||
}))?,
|
||||
})
|
||||
.to_string(),
|
||||
json!({
|
||||
"timestamp": meta_rfc3339,
|
||||
"type": "event_msg",
|
||||
"payload": serde_json::to_value(EventMsg::AgentMessage(AgentMessageEvent {
|
||||
message: "Still running".to_string(),
|
||||
phase: None,
|
||||
memory_citation: None,
|
||||
}))?,
|
||||
})
|
||||
.to_string(),
|
||||
]
|
||||
.join("\n");
|
||||
std::fs::write(
|
||||
&rollout_file_path,
|
||||
format!("{persisted_rollout}{appended_rollout}\n"),
|
||||
)?;
|
||||
|
||||
let mut mcp = McpProcess::new(codex_home.path()).await?;
|
||||
timeout(DEFAULT_READ_TIMEOUT, mcp.initialize()).await??;
|
||||
|
||||
let resume_id = mcp
|
||||
.send_thread_resume_request(ThreadResumeParams {
|
||||
thread_id: conversation_id,
|
||||
..Default::default()
|
||||
})
|
||||
.await?;
|
||||
let resume_resp: JSONRPCResponse = timeout(
|
||||
DEFAULT_READ_TIMEOUT,
|
||||
mcp.read_stream_until_response_message(RequestId::Integer(resume_id)),
|
||||
)
|
||||
.await??;
|
||||
let ThreadResumeResponse { thread, .. } = to_response::<ThreadResumeResponse>(resume_resp)?;
|
||||
|
||||
assert_eq!(thread.turns.len(), 2);
|
||||
assert_eq!(thread.turns[0].status, TurnStatus::Completed);
|
||||
assert_eq!(thread.turns[1].id, stale_turn_id);
|
||||
assert_eq!(thread.turns[1].status, TurnStatus::Interrupted);
|
||||
|
||||
let note = timeout(
|
||||
DEFAULT_READ_TIMEOUT,
|
||||
mcp.read_stream_until_notification_message("thread/tokenUsage/updated"),
|
||||
)
|
||||
.await??;
|
||||
let parsed: ServerNotification = note.try_into()?;
|
||||
let ServerNotification::ThreadTokenUsageUpdated(notification) = parsed else {
|
||||
panic!("expected thread/tokenUsage/updated notification");
|
||||
};
|
||||
|
||||
assert_eq!(notification.thread_id, thread.id);
|
||||
assert_eq!(notification.turn_id, thread.turns[0].id);
|
||||
assert_ne!(notification.turn_id, stale_turn_id);
|
||||
assert_eq!(notification.token_usage.total.total_tokens, 150);
|
||||
assert_eq!(notification.token_usage.last.total_tokens, 90);
|
||||
|
||||
Ok(())
|
||||
}
|
||||
|
||||
#[tokio::test]
|
||||
async fn thread_resume_token_usage_replay_can_belong_to_interrupted_turn() -> Result<()> {
|
||||
let server = create_mock_responses_server_repeating_assistant("Done").await;
|
||||
let codex_home = TempDir::new()?;
|
||||
create_config_toml(codex_home.path(), &server.uri())?;
|
||||
|
||||
let filename_ts = "2025-01-05T12-00-00";
|
||||
let meta_rfc3339 = "2025-01-05T12:00:00Z";
|
||||
let conversation_id = create_fake_rollout_with_token_usage(
|
||||
codex_home.path(),
|
||||
filename_ts,
|
||||
meta_rfc3339,
|
||||
"Saved user message",
|
||||
Some("mock_provider"),
|
||||
)?;
|
||||
let rollout_file_path = rollout_path(codex_home.path(), filename_ts, &conversation_id);
|
||||
let persisted_rollout = std::fs::read_to_string(&rollout_file_path)?;
|
||||
let interrupted_turn_id = "interrupted-turn-with-token-usage";
|
||||
let appended_rollout = [
|
||||
json!({
|
||||
"timestamp": meta_rfc3339,
|
||||
"type": "event_msg",
|
||||
"payload": serde_json::to_value(EventMsg::TurnStarted(TurnStartedEvent {
|
||||
turn_id: interrupted_turn_id.to_string(),
|
||||
started_at: None,
|
||||
model_context_window: None,
|
||||
collaboration_mode_kind: Default::default(),
|
||||
}))?,
|
||||
})
|
||||
.to_string(),
|
||||
json!({
|
||||
"timestamp": meta_rfc3339,
|
||||
"type": "event_msg",
|
||||
"payload": serde_json::to_value(EventMsg::AgentMessage(AgentMessageEvent {
|
||||
message: "Interrupted after usage".to_string(),
|
||||
phase: None,
|
||||
memory_citation: None,
|
||||
}))?,
|
||||
})
|
||||
.to_string(),
|
||||
json!({
|
||||
"timestamp": meta_rfc3339,
|
||||
"type": "event_msg",
|
||||
"payload": serde_json::to_value(EventMsg::TokenCount(TokenCountEvent {
|
||||
info: Some(TokenUsageInfo {
|
||||
total_token_usage: TokenUsage {
|
||||
input_tokens: 180,
|
||||
cached_input_tokens: 40,
|
||||
output_tokens: 50,
|
||||
reasoning_output_tokens: 15,
|
||||
total_tokens: 230,
|
||||
},
|
||||
last_token_usage: TokenUsage {
|
||||
input_tokens: 90,
|
||||
cached_input_tokens: 30,
|
||||
output_tokens: 40,
|
||||
reasoning_output_tokens: 12,
|
||||
total_tokens: 130,
|
||||
},
|
||||
model_context_window: Some(200_000),
|
||||
}),
|
||||
rate_limits: None,
|
||||
}))?,
|
||||
})
|
||||
.to_string(),
|
||||
json!({
|
||||
"timestamp": meta_rfc3339,
|
||||
"type": "event_msg",
|
||||
"payload": serde_json::to_value(EventMsg::TurnAborted(TurnAbortedEvent {
|
||||
turn_id: Some(interrupted_turn_id.to_string()),
|
||||
reason: TurnAbortReason::Interrupted,
|
||||
completed_at: None,
|
||||
duration_ms: None,
|
||||
}))?,
|
||||
})
|
||||
.to_string(),
|
||||
]
|
||||
.join("\n");
|
||||
std::fs::write(
|
||||
&rollout_file_path,
|
||||
format!("{persisted_rollout}{appended_rollout}\n"),
|
||||
)?;
|
||||
|
||||
let mut mcp = McpProcess::new(codex_home.path()).await?;
|
||||
timeout(DEFAULT_READ_TIMEOUT, mcp.initialize()).await??;
|
||||
|
||||
let resume_id = mcp
|
||||
.send_thread_resume_request(ThreadResumeParams {
|
||||
thread_id: conversation_id,
|
||||
..Default::default()
|
||||
})
|
||||
.await?;
|
||||
let resume_resp: JSONRPCResponse = timeout(
|
||||
DEFAULT_READ_TIMEOUT,
|
||||
mcp.read_stream_until_response_message(RequestId::Integer(resume_id)),
|
||||
)
|
||||
.await??;
|
||||
let ThreadResumeResponse { thread, .. } = to_response::<ThreadResumeResponse>(resume_resp)?;
|
||||
|
||||
assert_eq!(thread.turns.len(), 2);
|
||||
assert_eq!(thread.turns[0].status, TurnStatus::Completed);
|
||||
assert_eq!(thread.turns[1].id, interrupted_turn_id);
|
||||
assert_eq!(thread.turns[1].status, TurnStatus::Interrupted);
|
||||
|
||||
let note = timeout(
|
||||
DEFAULT_READ_TIMEOUT,
|
||||
mcp.read_stream_until_notification_message("thread/tokenUsage/updated"),
|
||||
)
|
||||
.await??;
|
||||
let parsed: ServerNotification = note.try_into()?;
|
||||
let ServerNotification::ThreadTokenUsageUpdated(notification) = parsed else {
|
||||
panic!("expected thread/tokenUsage/updated notification");
|
||||
};
|
||||
|
||||
assert_eq!(notification.thread_id, thread.id);
|
||||
assert_eq!(notification.turn_id, interrupted_turn_id);
|
||||
assert_eq!(notification.token_usage.total.total_tokens, 230);
|
||||
assert_eq!(notification.token_usage.last.total_tokens, 130);
|
||||
|
||||
Ok(())
|
||||
}
|
||||
|
||||
#[tokio::test]
|
||||
async fn thread_resume_prefers_persisted_git_metadata_for_local_threads() -> Result<()> {
|
||||
let server = create_mock_responses_server_repeating_assistant("Done").await;
|
||||
|
||||
Reference in New Issue
Block a user