Files
codex/codex-rs/core/src/tasks/mod.rs
T
Owen Lin 6ea041032b fix(core): prevent hanging turn/start due to websocket warming issues (#14838)
## Description

This PR fixes a bad first-turn failure mode in app-server when the
startup websocket prewarm hangs. Before this change, `initialize ->
thread/start -> turn/start` could sit behind the prewarm for up to five
minutes, so the client would not see `turn/started`, and even
`turn/interrupt` would block because the turn had not actually started
yet.

Now, we:
- set a (configurable) timeout of 15s for websocket startup time,
exposed as `websocket_startup_timeout_ms` in config.toml
- `turn/started` is sent immediately on `turn/start` even if the
websocket is still connecting
- `turn/interrupt` can be used to cancel a turn that is still waiting on
the websocket warmup
- the turn task will wait for the full 15s websocket warming timeout
before falling back

## Why

The old behavior made app-server feel stuck at exactly the moment the
client expects turn lifecycle events to start flowing. That was
especially painful for external clients, because from their point of
view the server had accepted the request but then went silent for
minutes.

## Configuring the websocket startup timeout
Can set it in config.toml like this:
```
[model_providers.openai]
supports_websockets = true
websocket_connect_timeout_ms = 15000
```
2026-03-17 10:07:46 -07:00

469 lines
18 KiB
Rust

mod compact;
mod ghost_snapshot;
mod regular;
mod review;
mod undo;
mod user_shell;
use std::sync::Arc;
use std::time::Duration;
use std::time::Instant;
use async_trait::async_trait;
use tokio::select;
use tokio::sync::Notify;
use tokio_util::sync::CancellationToken;
use tokio_util::task::AbortOnDropHandle;
use tracing::Instrument;
use tracing::info_span;
use tracing::trace;
use tracing::warn;
use crate::AuthManager;
use crate::codex::Session;
use crate::codex::TurnContext;
use crate::contextual_user_message::TURN_ABORTED_OPEN_TAG;
use crate::event_mapping::parse_turn_item;
use crate::models_manager::manager::ModelsManager;
use crate::protocol::EventMsg;
use crate::protocol::TokenUsage;
use crate::protocol::TurnAbortReason;
use crate::protocol::TurnAbortedEvent;
use crate::protocol::TurnCompleteEvent;
use crate::state::ActiveTurn;
use crate::state::RunningTask;
use crate::state::TaskKind;
use codex_otel::SessionTelemetry;
use codex_otel::metrics::names::TURN_E2E_DURATION_METRIC;
use codex_otel::metrics::names::TURN_NETWORK_PROXY_METRIC;
use codex_otel::metrics::names::TURN_TOKEN_USAGE_METRIC;
use codex_otel::metrics::names::TURN_TOOL_CALL_METRIC;
use codex_protocol::items::TurnItem;
use codex_protocol::models::ContentItem;
use codex_protocol::models::ResponseInputItem;
use codex_protocol::models::ResponseItem;
use codex_protocol::protocol::RolloutItem;
use codex_protocol::user_input::UserInput;
use crate::features::Feature;
pub(crate) use compact::CompactTask;
pub(crate) use ghost_snapshot::GhostSnapshotTask;
pub(crate) use regular::RegularTask;
pub(crate) use review::ReviewTask;
pub(crate) use undo::UndoTask;
pub(crate) use user_shell::UserShellCommandMode;
pub(crate) use user_shell::UserShellCommandTask;
pub(crate) use user_shell::execute_user_shell_command;
const GRACEFULL_INTERRUPTION_TIMEOUT_MS: u64 = 100;
const TURN_ABORTED_INTERRUPTED_GUIDANCE: &str = "The user interrupted the previous turn on purpose. Any running unified exec processes may still be running in the background. If any tools/commands were aborted, they may have partially executed; verify current state before retrying.";
fn emit_turn_network_proxy_metric(
session_telemetry: &SessionTelemetry,
network_proxy_active: bool,
tmp_mem: (&str, &str),
) {
let active = if network_proxy_active {
"true"
} else {
"false"
};
session_telemetry.counter(
TURN_NETWORK_PROXY_METRIC,
/*inc*/ 1,
&[("active", active), tmp_mem],
);
}
/// Thin wrapper that exposes the parts of [`Session`] task runners need.
#[derive(Clone)]
pub(crate) struct SessionTaskContext {
session: Arc<Session>,
}
impl SessionTaskContext {
pub(crate) fn new(session: Arc<Session>) -> Self {
Self { session }
}
pub(crate) fn clone_session(&self) -> Arc<Session> {
Arc::clone(&self.session)
}
pub(crate) fn auth_manager(&self) -> Arc<AuthManager> {
Arc::clone(&self.session.services.auth_manager)
}
pub(crate) fn models_manager(&self) -> Arc<ModelsManager> {
Arc::clone(&self.session.services.models_manager)
}
}
/// Async task that drives a [`Session`] turn.
///
/// Implementations encapsulate a specific Codex workflow (regular chat,
/// reviews, ghost snapshots, etc.). Each task instance is owned by a
/// [`Session`] and executed on a background Tokio task. The trait is
/// intentionally small: implementers identify themselves via
/// [`SessionTask::kind`], perform their work in [`SessionTask::run`], and may
/// release resources in [`SessionTask::abort`].
#[async_trait]
pub(crate) trait SessionTask: Send + Sync + 'static {
/// Describes the type of work the task performs so the session can
/// surface it in telemetry and UI.
fn kind(&self) -> TaskKind;
/// Returns the tracing name for a spawned task span.
fn span_name(&self) -> &'static str;
/// Executes the task until completion or cancellation.
///
/// Implementations typically stream protocol events using `session` and
/// `ctx`, returning an optional final agent message when finished. The
/// provided `cancellation_token` is cancelled when the session requests an
/// abort; implementers should watch for it and terminate quickly once it
/// fires. Returning [`Some`] yields a final message that
/// [`Session::on_task_finished`] will emit to the client.
async fn run(
self: Arc<Self>,
session: Arc<SessionTaskContext>,
ctx: Arc<TurnContext>,
input: Vec<UserInput>,
cancellation_token: CancellationToken,
) -> Option<String>;
/// Gives the task a chance to perform cleanup after an abort.
///
/// The default implementation is a no-op; override this if additional
/// teardown or notifications are required once
/// [`Session::abort_all_tasks`] cancels the task.
async fn abort(&self, session: Arc<SessionTaskContext>, ctx: Arc<TurnContext>) {
let _ = (session, ctx);
}
}
impl Session {
pub async fn spawn_task<T: SessionTask>(
self: &Arc<Self>,
turn_context: Arc<TurnContext>,
input: Vec<UserInput>,
task: T,
) {
self.abort_all_tasks(TurnAbortReason::Replaced).await;
self.clear_connector_selection().await;
let task: Arc<dyn SessionTask> = Arc::new(task);
let task_kind = task.kind();
let span_name = task.span_name();
let started_at = Instant::now();
turn_context
.turn_timing_state
.mark_turn_started(started_at)
.await;
let token_usage_at_turn_start = self.total_token_usage().await.unwrap_or_default();
let cancellation_token = CancellationToken::new();
let done = Arc::new(Notify::new());
let timer = turn_context
.session_telemetry
.start_timer(TURN_E2E_DURATION_METRIC, &[])
.ok();
let done_clone = Arc::clone(&done);
let handle = {
let session_ctx = Arc::new(SessionTaskContext::new(Arc::clone(self)));
let ctx = Arc::clone(&turn_context);
let task_for_run = Arc::clone(&task);
let task_cancellation_token = cancellation_token.child_token();
// Task-owned turn spans keep a core-owned span open for the
// full task lifecycle after the submission dispatch span ends.
let task_span = info_span!(
"turn",
otel.name = span_name,
thread.id = %self.conversation_id,
turn.id = %turn_context.sub_id,
model = %turn_context.model_info.slug,
);
tokio::spawn(
async move {
let ctx_for_finish = Arc::clone(&ctx);
let last_agent_message = task_for_run
.run(
Arc::clone(&session_ctx),
ctx,
input,
task_cancellation_token.child_token(),
)
.await;
let sess = session_ctx.clone_session();
sess.flush_rollout().await;
if !task_cancellation_token.is_cancelled() {
// Emit completion uniformly from spawn site so all tasks share the same lifecycle.
sess.on_task_finished(Arc::clone(&ctx_for_finish), last_agent_message)
.await;
}
done_clone.notify_waiters();
}
.instrument(task_span),
)
};
let running_task = RunningTask {
done,
handle: Arc::new(AbortOnDropHandle::new(handle)),
kind: task_kind,
task,
cancellation_token,
turn_context: Arc::clone(&turn_context),
_timer: timer,
};
self.register_new_active_task(running_task, token_usage_at_turn_start)
.await;
}
pub async fn abort_all_tasks(self: &Arc<Self>, reason: TurnAbortReason) {
if let Some(mut active_turn) = self.take_active_turn().await {
for task in active_turn.drain_tasks() {
self.handle_task_abort(task, reason.clone()).await;
}
// Let interrupted tasks observe cancellation before dropping pending approvals, or an
// in-flight approval wait can surface as a model-visible rejection before TurnAborted.
active_turn.clear_pending().await;
}
}
pub async fn on_task_finished(
self: &Arc<Self>,
turn_context: Arc<TurnContext>,
last_agent_message: Option<String>,
) {
turn_context
.turn_metadata_state
.cancel_git_enrichment_task();
let mut active = self.active_turn.lock().await;
let mut pending_input = Vec::<ResponseInputItem>::new();
let mut should_clear_active_turn = false;
let mut token_usage_at_turn_start = None;
let mut turn_tool_calls = 0_u64;
if let Some(at) = active.as_mut()
&& at.remove_task(&turn_context.sub_id)
{
let mut ts = at.turn_state.lock().await;
pending_input = ts.take_pending_input();
turn_tool_calls = ts.tool_calls;
token_usage_at_turn_start = Some(ts.token_usage_at_turn_start.clone());
should_clear_active_turn = true;
}
if should_clear_active_turn {
*active = None;
}
drop(active);
if !pending_input.is_empty() {
let pending_response_items = pending_input
.into_iter()
.map(ResponseItem::from)
.collect::<Vec<_>>();
for response_item in pending_response_items {
if let Some(TurnItem::UserMessage(user_message)) = parse_turn_item(&response_item) {
// Keep leftover user input on the same persistence + lifecycle path as the
// normal pre-sampling drain. This helper records the response item once, then
// emits ItemStarted/UserMessage and ItemCompleted/UserMessage for clients.
self.record_user_prompt_and_emit_turn_item(
turn_context.as_ref(),
&user_message.content,
response_item,
)
.await;
} else {
self.record_conversation_items(
turn_context.as_ref(),
std::slice::from_ref(&response_item),
)
.await;
}
}
}
// Emit token usage metrics.
if let Some(token_usage_at_turn_start) = token_usage_at_turn_start {
// TODO(jif): drop this
let tmp_mem = (
"tmp_mem_enabled",
if self.enabled(Feature::MemoryTool) {
"true"
} else {
"false"
},
);
let network_proxy_active = match self.services.network_proxy.as_ref() {
Some(started_network_proxy) => {
match started_network_proxy.proxy().current_cfg().await {
Ok(config) => config.network.enabled,
Err(err) => {
warn!(
"failed to read managed network proxy state for turn metrics: {err:#}"
);
false
}
}
}
None => false,
};
emit_turn_network_proxy_metric(
&self.services.session_telemetry,
network_proxy_active,
tmp_mem,
);
self.services.session_telemetry.histogram(
TURN_TOOL_CALL_METRIC,
i64::try_from(turn_tool_calls).unwrap_or(i64::MAX),
&[tmp_mem],
);
let total_token_usage = self.total_token_usage().await.unwrap_or_default();
let turn_token_usage = crate::protocol::TokenUsage {
input_tokens: (total_token_usage.input_tokens
- token_usage_at_turn_start.input_tokens)
.max(0),
cached_input_tokens: (total_token_usage.cached_input_tokens
- token_usage_at_turn_start.cached_input_tokens)
.max(0),
output_tokens: (total_token_usage.output_tokens
- token_usage_at_turn_start.output_tokens)
.max(0),
reasoning_output_tokens: (total_token_usage.reasoning_output_tokens
- token_usage_at_turn_start.reasoning_output_tokens)
.max(0),
total_tokens: (total_token_usage.total_tokens
- token_usage_at_turn_start.total_tokens)
.max(0),
};
self.services.session_telemetry.histogram(
TURN_TOKEN_USAGE_METRIC,
turn_token_usage.total_tokens,
&[("token_type", "total"), tmp_mem],
);
self.services.session_telemetry.histogram(
TURN_TOKEN_USAGE_METRIC,
turn_token_usage.input_tokens,
&[("token_type", "input"), tmp_mem],
);
self.services.session_telemetry.histogram(
TURN_TOKEN_USAGE_METRIC,
turn_token_usage.cached_input(),
&[("token_type", "cached_input"), tmp_mem],
);
self.services.session_telemetry.histogram(
TURN_TOKEN_USAGE_METRIC,
turn_token_usage.output_tokens,
&[("token_type", "output"), tmp_mem],
);
self.services.session_telemetry.histogram(
TURN_TOKEN_USAGE_METRIC,
turn_token_usage.reasoning_output_tokens,
&[("token_type", "reasoning_output"), tmp_mem],
);
}
let event = EventMsg::TurnComplete(TurnCompleteEvent {
turn_id: turn_context.sub_id.clone(),
last_agent_message,
});
self.send_event(turn_context.as_ref(), event).await;
}
async fn register_new_active_task(
&self,
task: RunningTask,
token_usage_at_turn_start: TokenUsage,
) {
let mut active = self.active_turn.lock().await;
let mut turn = ActiveTurn::default();
let mut turn_state = turn.turn_state.lock().await;
turn_state.token_usage_at_turn_start = token_usage_at_turn_start;
drop(turn_state);
turn.add_task(task);
*active = Some(turn);
}
async fn take_active_turn(&self) -> Option<ActiveTurn> {
let mut active = self.active_turn.lock().await;
active.take()
}
pub(crate) async fn close_unified_exec_processes(&self) {
self.services
.unified_exec_manager
.terminate_all_processes()
.await;
}
pub(crate) async fn cleanup_after_interrupt(&self, turn_context: &Arc<TurnContext>) {
if let Some(manager) = turn_context.js_repl.manager_if_initialized()
&& let Err(err) = manager.interrupt_turn_exec(&turn_context.sub_id).await
{
warn!("failed to interrupt js_repl kernel: {err}");
}
}
async fn handle_task_abort(self: &Arc<Self>, task: RunningTask, reason: TurnAbortReason) {
let sub_id = task.turn_context.sub_id.clone();
if task.cancellation_token.is_cancelled() {
return;
}
trace!(task_kind = ?task.kind, sub_id, "aborting running task");
task.cancellation_token.cancel();
task.turn_context
.turn_metadata_state
.cancel_git_enrichment_task();
let session_task = task.task;
select! {
_ = task.done.notified() => {
},
_ = tokio::time::sleep(Duration::from_millis(GRACEFULL_INTERRUPTION_TIMEOUT_MS)) => {
warn!("task {sub_id} didn't complete gracefully after {}ms", GRACEFULL_INTERRUPTION_TIMEOUT_MS);
}
}
task.handle.abort();
let session_ctx = Arc::new(SessionTaskContext::new(Arc::clone(self)));
session_task
.abort(session_ctx, Arc::clone(&task.turn_context))
.await;
if reason == TurnAbortReason::Interrupted {
self.cleanup_after_interrupt(&task.turn_context).await;
let marker = ResponseItem::Message {
id: None,
role: "user".to_string(),
content: vec![ContentItem::InputText {
text: format!(
"{TURN_ABORTED_OPEN_TAG}\n{TURN_ABORTED_INTERRUPTED_GUIDANCE}\n</turn_aborted>"
),
}],
end_turn: None,
phase: None,
};
self.record_into_history(std::slice::from_ref(&marker), task.turn_context.as_ref())
.await;
self.persist_rollout_items(&[RolloutItem::ResponseItem(marker)])
.await;
// Ensure the marker is durably visible before emitting TurnAborted: some clients
// synchronously re-read the rollout on receipt of the abort event.
self.flush_rollout().await;
}
let event = EventMsg::TurnAborted(TurnAbortedEvent {
turn_id: Some(task.turn_context.sub_id.clone()),
reason,
});
self.send_event(task.turn_context.as_ref(), event).await;
}
}
#[cfg(test)]
#[path = "mod_tests.rs"]
mod tests;