diff --git a/crates/app-server/src/chat_completions.rs b/crates/app-server/src/chat_completions.rs index f767714b38..270923da64 100644 --- a/crates/app-server/src/chat_completions.rs +++ b/crates/app-server/src/chat_completions.rs @@ -390,6 +390,13 @@ pub(crate) async fn chat_completions_handler( // Build upstream request. The shared platform builder sets no timeouts, // so the proxy would hang forever on an accept-and-stall upstream; // bound both the connect and the whole non-streaming round trip. + // + // `config` (the read guard) is dropped here on purpose: everything it + // feeds is resolved by now, and holding it across the upstream round + // trip (up to UPSTREAM_TOTAL_TIMEOUT) would block config writes and, + // through the write-preferring lock, every later resolve for that + // whole window. + drop(config); let upstream_req = codewhale_release::platform_http_client_builder() .connect_timeout(UPSTREAM_CONNECT_TIMEOUT) .timeout(UPSTREAM_TOTAL_TIMEOUT) diff --git a/crates/app-server/src/lib.rs b/crates/app-server/src/lib.rs index fed49258e3..38baac0df0 100644 --- a/crates/app-server/src/lib.rs +++ b/crates/app-server/src/lib.rs @@ -1371,6 +1371,12 @@ async fn interrupt_stdio_turn( let Some(turn) = state.in_flight_turns.lock().await.get(thread_id).cloned() else { return Ok(false); }; + interrupt_in_flight_turn(&turn).await +} + +/// POST the interrupt for an in-flight turn. Bounded by its own 10s client +/// timeout so a wedged runtime child cannot park the caller. +async fn interrupt_in_flight_turn(turn: &InFlightTurn) -> std::result::Result { let mut request = codewhale_release::platform_http_client_builder() .timeout(Duration::from_secs(10)) .build() @@ -1423,6 +1429,50 @@ const RUNTIME_BRIDGE_REQUEST_TIMEOUT: std::time::Duration = std::time::Duration: /// avoids). const RUNTIME_BRIDGE_SSE_IDLE_TIMEOUT: std::time::Duration = std::time::Duration::from_secs(60); +/// How many times a dropped event stream may be reconnected after the first +/// connection. A dropped stream is not evidence the turn died — the runtime's +/// lifecycle task keeps it running — so the bridge resumes from the last +/// consumed seq instead of interrupting, and only falls through to the +/// orphan-interrupt once this budget is spent. +const MAX_STREAM_RESUMES: usize = 2; + +/// How one live event-stream connection ended when it did not reach +/// `turn.completed`. Carries what a resume needs: the seq to reconnect +/// from, and whether resuming is pointless because the writer is gone. +struct StreamDrop { + /// Highest event seq this connection consumed. A resume reconnects + /// with `?since_seq=` this value, which the runtime treats as + /// exclusive, so the replay picks up exactly the events that were + /// still in flight. + last_seq: u64, + /// The streaming writer (the client's stdio pipe or HTTP sink) + /// failed. No resume can deliver events to it, so the turn must be + /// interrupted rather than kept running for a peer that left. + writer_gone: bool, + source: anyhow::Error, +} + +impl StreamDrop { + /// The stream stopped under us (idle deadline, transport error, ended + /// before completion). Resumable. + fn transport(last_seq: u64, source: anyhow::Error) -> Self { + Self { + last_seq, + writer_gone: false, + source, + } + } + + /// An event could not be written to the streaming writer. + fn writer(last_seq: u64, source: anyhow::Error) -> Self { + Self { + last_seq, + writer_gone: true, + source, + } + } +} + impl RuntimeBridge { async fn start(config_path: Option<&Path>) -> Result { install_rustls_crypto_provider(); @@ -1486,13 +1536,16 @@ impl RuntimeBridge { )); } - match self - .client - .get(format!("{}/health", self.base_url)) - .send() - .await + match tokio::time::timeout( + deadline.saturating_duration_since(Instant::now()), + self.client.get(format!("{}/health", self.base_url)).send(), + ) + .await { - Ok(response) if response.status().is_success() => return Ok(()), + Ok(Ok(response)) if response.status().is_success() => return Ok(()), + // Covers elapsed timeouts (`Err`) and late non-success + // responses alike: a child that accepts /health but never + // writes headers must not hang this probe forever. _ if Instant::now() >= deadline => { bail!( "timed out waiting for runtime API bridge at {}/health", @@ -1624,37 +1677,102 @@ impl RuntimeBridge { ) .await?; + // Everything the interrupt needs is in scope on every surface, so + // build it unconditionally. The orphan rescue below must not be + // limited to the one surface that also exposes a manual + // `thread/interrupt`: HTTP `/thread` and `/prompt` turns have no + // client-reachable interrupt at all, so for them the rescue is the + // only thing between a dropped stream and a thread that rejects + // every later message with "already has an active turn". + let live_turn = InFlightTurn { + base_url: self.base_url.clone(), + auth_token: self.auth_token.clone(), + runtime_thread_id: thread_id.to_string(), + turn_id: turn_id.clone(), + }; // Publish the turn only for the streaming window, and take it back // before any `?` below: a turn that has already finished must never - // look cancellable. + // look cancellable. Registration stays stdio-only because only that + // surface can ask for a cancel by thread id. if let Some((registry, key)) = registration.as_ref() { - registry.lock().await.insert( - key.clone(), - InFlightTurn { - base_url: self.base_url.clone(), - auth_token: self.auth_token.clone(), - runtime_thread_id: thread_id.to_string(), - turn_id: turn_id.clone(), - }, - ); + registry.lock().await.insert(key.clone(), live_turn.clone()); } let since_seq = self.last_seq_by_thread.get(thread_id).copied().unwrap_or(0); - let stream_result = self - .stream_turn_events( - thread_id, - &turn_id, - &response_id, - writer, - since_seq, - transcript.as_deref_mut(), - ) - .await; + // One live connection plus bounded resumes. A dropped stream is not + // evidence the turn died — the runtime's lifecycle task keeps it + // running — so reconnect from the last consumed seq and keep + // streaming. Only a writer failure (the peer is gone; no resume + // can ever deliver an event to it) or an exhausted resume budget + // falls through to the interrupt below. + let mut resume_from = since_seq; + let mut resumes_left = MAX_STREAM_RESUMES; + let stream_result = loop { + match self + .stream_turn_events( + thread_id, + &turn_id, + &response_id, + writer, + resume_from, + transcript.as_deref_mut(), + ) + .await + { + Ok(result) => break Ok(result), + Err(drop) => { + // Track the last consumed seq on every exit path: a + // resume reconnects from it, and a terminal failure + // writes it back so the thread's next message does not + // replay what this turn consumed. + resume_from = drop.last_seq; + if drop.writer_gone || resumes_left == 0 { + break Err(drop.source); + } + resumes_left -= 1; + // Events the dropped connection consumed are not + // replayed again: `since_seq` is exclusive, so resuming + // from the last seen seq only replays what never + // arrived. A repeated event can only come from a + // runtime that reuses seqs, which the API contract + // disallows. + tracing::warn!( + "runtime event stream dropped mid-turn; resuming \ + from seq {resume_from} ({resumes_left} resume(s) left)" + ); + } + } + }; if let Some((registry, key)) = registration.as_ref() { registry.lock().await.remove(key); } + // The stream died mid-turn past the resume budget (or the writer is + // gone). The runtime's lifecycle task keeps the turn running, so + // leave a best-effort interrupt behind: without it a retried message + // on the same thread is rejected with "already has an active turn" + // until the orphan completes on its own. + let stream_result = match stream_result { + Ok(result) => Ok(result), + Err(stream_err) => { + // Terminal failure, but the live connection and any + // resumes consumed events along the way: persist the last + // consumed seq so the thread's next message streams from + // there instead of replaying this turn's events from the + // store (they would only be turn_id-filtered). Writing back + // a seq whose events a dead writer never received is safe: + // those events belong to this interrupted turn, not to the + // next one. + self.last_seq_by_thread + .insert(thread_id.to_string(), resume_from); + if let Err(interrupt_err) = interrupt_in_flight_turn(&live_turn).await { + tracing::warn!("best-effort interrupt after stream failure: {interrupt_err:?}"); + } + Err(stream_err) + } + }; + let _ = emit_stdio_event( writer, json!({ @@ -1710,7 +1828,8 @@ impl RuntimeBridge { writer: &mut W, since_seq: u64, mut transcript: Option<&mut TurnTranscript>, - ) -> Result<(u64, TurnTerminalStatus, Option)> { + ) -> Result<(u64, TurnTerminalStatus, Option), StreamDrop> { + let mut last_seq = since_seq; // A runtime child that accepts the connection but never writes // response headers would otherwise hold the bridge lock forever — // the same accept-and-stall shape the chunk idle bound below covers @@ -1726,11 +1845,24 @@ impl RuntimeBridge { .send(), ) .await - .context("runtime event stream stalled before the first byte")?? - .error_for_status()?; + .map_err(|elapsed| { + StreamDrop::transport( + last_seq, + anyhow!("runtime event stream stalled before the first byte: {elapsed}"), + ) + })? + .map_err(|err| { + StreamDrop::transport( + last_seq, + anyhow!("runtime event stream request failed: {err}"), + ) + })? + .error_for_status() + .map_err(|err| { + StreamDrop::transport(last_seq, anyhow!("runtime event stream rejected: {err}")) + })?; let mut buffer = Vec::new(); - let mut last_seq = since_seq; // The event stream only ever pauses for the runtime's 15s // keepalives; anything longer means the child wedged mid-stream. @@ -1739,22 +1871,34 @@ impl RuntimeBridge { loop { let chunk = tokio::time::timeout(RUNTIME_BRIDGE_SSE_IDLE_TIMEOUT, response.chunk()) .await - .context("runtime event stream stalled past the idle deadline")??; + .map_err(|elapsed| { + StreamDrop::transport( + last_seq, + anyhow!("runtime event stream stalled past the idle deadline: {elapsed}"), + ) + })? + .map_err(|err| { + StreamDrop::transport(last_seq, anyhow!("event stream read failed: {err}")) + })?; let Some(chunk) = chunk else { break; }; buffer.extend_from_slice(&chunk); if buffer.len() > MAX_SSE_FRAME_BYTES { - bail!( - "runtime SSE frame exceeded {MAX_SSE_FRAME_BYTES} bytes without a frame delimiter" - ); + return Err(StreamDrop::transport( + last_seq, + anyhow!( + "runtime SSE frame exceeded {MAX_SSE_FRAME_BYTES} bytes without a frame delimiter" + ), + )); } while let Some(frame_bytes) = take_sse_frame(&mut buffer) { let Some((event_name, frame_data)) = parse_sse_frame(&frame_bytes) else { continue; }; let envelope: Value = serde_json::from_str(&frame_data) - .with_context(|| format!("invalid SSE json for {event_name}: {frame_data}"))?; + .with_context(|| format!("invalid SSE json for {event_name}: {frame_data}")) + .map_err(|source| StreamDrop::transport(last_seq, source))?; if let Some(seq) = envelope.get("seq").and_then(Value::as_u64) { last_seq = last_seq.max(seq); } @@ -1780,7 +1924,13 @@ impl RuntimeBridge { "delta": delta, }), ) - .await?; + .await + .map_err(|source| { + StreamDrop::writer( + last_seq, + source.context("streaming writer failed"), + ) + })?; if let Some(transcript) = transcript.as_deref_mut() { transcript.text.push_str(delta); transcript.events.push(EventFrame::ResponseDelta { @@ -1804,7 +1954,10 @@ impl RuntimeBridge { } } - bail!("runtime event stream ended before turn.completed") + Err(StreamDrop::transport( + last_seq, + anyhow!("runtime event stream ended before turn.completed"), + )) } #[cfg(test)] @@ -3444,6 +3597,374 @@ mod tests { assert_eq!(response.result["interrupted"], json!(false)); } + /// A mock runtime that serves event-stream connections from a scripted + /// list: connection N gets body N. A body that ends without + /// `turn.completed` is a mid-turn drop. Counts interrupts so tests can + /// assert the resume path never reached for one, and records the + /// `since_seq` cursor of every event-stream connection so the resume + /// arithmetic itself is observable, not just its side effects. + #[derive(Clone)] + struct ScriptedDropState { + interrupts: Arc, + connections: Arc, + served: Arc>>, + since_seq_requests: Arc>>>, + } + + async fn spawn_scripted_drop_runtime( + bodies: Vec, + ) -> ( + String, + Arc, + Arc, + Arc>>>, + tokio::task::JoinHandle<()>, + ) { + let interrupts = Arc::new(std::sync::atomic::AtomicUsize::new(0)); + let connections = Arc::new(std::sync::atomic::AtomicUsize::new(0)); + let served = Arc::new(std::sync::Mutex::new(bodies)); + let since_seq_requests = Arc::new(std::sync::Mutex::new(Vec::new())); + + async fn create_turn(AxumPath(_thread_id): AxumPath) -> Json { + Json(json!({ "turn": { "id": "turn_drop" } })) + } + async fn interrupt( + State(state): State, + AxumPath((_thread_id, _turn_id)): AxumPath<(String, String)>, + ) -> Json { + state + .interrupts + .fetch_add(1, std::sync::atomic::Ordering::SeqCst); + Json(json!({ "ok": true })) + } + async fn thread_events( + State(state): State, + AxumPath(_thread_id): AxumPath, + Query(query): Query>, + ) -> ([(header::HeaderName, &'static str); 1], String) { + state + .connections + .fetch_add(1, std::sync::atomic::Ordering::SeqCst); + state + .since_seq_requests + .lock() + .expect("since_seq log") + .push(query.get("since_seq").and_then(|v| v.parse().ok())); + let body = { + let mut script = state.served.lock().expect("script"); + if script.len() > 1 { + script.remove(0) + } else { + script[0].clone() + } + }; + ([(header::CONTENT_TYPE, "text/event-stream")], body) + } + + let listener = tokio::net::TcpListener::bind("127.0.0.1:0") + .await + .expect("bind test listener"); + let addr = listener.local_addr().expect("listener addr"); + let state = ScriptedDropState { + interrupts: Arc::clone(&interrupts), + connections: Arc::clone(&connections), + served: Arc::clone(&served), + since_seq_requests: Arc::clone(&since_seq_requests), + }; + let app = Router::new() + .route("/v1/threads/{thread_id}/turns", post(create_turn)) + .route( + "/v1/threads/{thread_id}/turns/{turn_id}/interrupt", + post(interrupt), + ) + .route("/v1/threads/{thread_id}/events", get(thread_events)) + .with_state(state); + let server = tokio::spawn(async move { + axum::serve(listener, app) + .await + .expect("serve test runtime"); + }); + ( + format!("http://{addr}"), + interrupts, + connections, + since_seq_requests, + server, + ) + } + + #[tokio::test] + async fn a_mid_stream_drop_resumes_and_no_interrupt_is_issued() { + // Connection 1 delivers the first delta then ends mid-turn; the + // bridge must reconnect from the last consumed seq and finish the + // turn, never reaching for the interrupt. + let bodies = vec![ + [sse_frame( + "item.delta", + json!({ + "seq": 1, + "turn_id": "turn_drop", + "payload": { "kind": "agent_message", "delta": "part-one " } + }), + )] + .concat(), + [ + sse_frame( + "item.delta", + json!({ + "seq": 2, + "turn_id": "turn_drop", + "payload": { "kind": "agent_message", "delta": "part-two" } + }), + ), + sse_frame( + "turn.completed", + json!({ + "seq": 3, + "turn_id": "turn_drop", + "payload": { "turn": { "status": "completed" } } + }), + ), + ] + .concat(), + ]; + let (base_url, interrupts, connections, since_seq_requests, server) = + spawn_scripted_drop_runtime(bodies).await; + let mut bridge = RuntimeBridge::from_base_url_for_test(base_url); + let (mut reader, mut writer) = tokio::io::duplex(4096); + + let result = tokio::time::timeout( + std::time::Duration::from_secs(15), + bridge.message_thread("thr_drop", "go", &mut writer, None, None), + ) + .await + .expect("the resumed turn completes") + .expect("the resumed turn completes"); + drop(writer); + + let mut stdout = Vec::new(); + reader.read_to_end(&mut stdout).await.expect("read output"); + server.abort(); + let _ = server.await; + + assert_eq!( + result.get("status").and_then(Value::as_str), + Some("accepted") + ); + assert_eq!( + connections.load(std::sync::atomic::Ordering::SeqCst), + 2, + "the bridge must have reconnected exactly once" + ); + assert_eq!( + interrupts.load(std::sync::atomic::Ordering::SeqCst), + 0, + "a resumed stream must never reach for the interrupt" + ); + assert_eq!(bridge.last_seq_by_thread.get("thr_drop"), Some(&3)); + // The resume arithmetic itself: the initial connection opens from + // seq 0 (the URL always carries the cursor), and the reconnect must + // ask for exactly the last consumed seq — `since_seq` is exclusive, + // so seq 1 must be requested, never 0 (which would replay the + // dropped delta) or 2 (which would skip the second one). + assert_eq!( + *since_seq_requests.lock().expect("since_seq log"), + vec![Some(0), Some(1)], + "the reconnect cursor must be the last consumed seq (exclusive)" + ); + + let deltas: Vec = String::from_utf8(stdout) + .expect("utf8") + .lines() + .map(|line| serde_json::from_str::(line).expect("json line")) + .filter(|line| line.get("type").and_then(Value::as_str) == Some("response_delta")) + .map(|line| line["delta"].as_str().expect("delta").to_owned()) + .collect::>(); + assert_eq!( + deltas, + ["part-one ", "part-two"], + "no delta may be replayed from the dropped connection" + ); + } + + #[tokio::test] + async fn exhausted_resumes_interrupt_the_orphaned_turn() { + // Every connection drops mid-turn, so the bridge exhausts its resume + // budget and must fall through to the best-effort interrupt instead + // of looping forever — a wedged child must not wedge the app-server. + let drop_once = || { + [sse_frame( + "item.delta", + json!({ + "seq": 1, + "turn_id": "turn_drop", + "payload": { "kind": "agent_message", "delta": "half" } + }), + )] + .concat() + }; + let bodies = vec![drop_once(), drop_once(), drop_once()]; + let (base_url, interrupts, connections, since_seq_requests, server) = + spawn_scripted_drop_runtime(bodies).await; + let mut bridge = RuntimeBridge::from_base_url_for_test(base_url); + let (_reader, mut writer) = tokio::io::duplex(4096); + + // The exhaustion check is the only thing standing between this test + // and an infinite reconnect loop against the scripted server, so + // guard the whole turn with an outer deadline: a regression hangs + // the loop instead of failing the suite silently. + let result = tokio::time::timeout( + std::time::Duration::from_secs(15), + bridge.message_thread("thr_drop", "go", &mut writer, None, None), + ) + .await + .expect("the turn must settle, not loop forever"); + drop(writer); + server.abort(); + let _ = server.await; + + assert!(result.is_err(), "the turn must end as an error, not hang"); + assert_eq!( + connections.load(std::sync::atomic::Ordering::SeqCst), + 1 + 2, + "first connection plus every resume attempt" + ); + assert_eq!( + since_seq_requests.lock().expect("since_seq log").len(), + 1 + 2, + "each connection (live or resume) requests the event stream once" + ); + assert_eq!( + interrupts.load(std::sync::atomic::Ordering::SeqCst), + 1, + "the orphaned turn must be interrupted exactly once" + ); + // The resumes consumed seq 1 before the budget ran out, so the + // cursor must survive the error path: the thread's next message + // must stream from seq 1 instead of replaying them from the store. + assert_eq!( + bridge.last_seq_by_thread.get("thr_drop"), + Some(&1), + "the last consumed seq must be written back on the error path" + ); + } + + /// Succeeds for exactly one `emit_stdio_event` (write, write, flush), + /// then fails every later write and flush like a closed pipe. + #[derive(Default)] + struct WriterThatDiesAfterTheFirstEvent { + flushed: bool, + } + + impl tokio::io::AsyncWrite for WriterThatDiesAfterTheFirstEvent { + fn poll_write( + self: std::pin::Pin<&mut Self>, + _cx: &mut std::task::Context<'_>, + buf: &[u8], + ) -> std::task::Poll> { + if self.flushed { + std::task::Poll::Ready(Err(std::io::Error::new( + std::io::ErrorKind::BrokenPipe, + "peer closed the stream", + ))) + } else { + std::task::Poll::Ready(Ok(buf.len())) + } + } + + fn poll_flush( + mut self: std::pin::Pin<&mut Self>, + _cx: &mut std::task::Context<'_>, + ) -> std::task::Poll> { + if self.flushed { + std::task::Poll::Ready(Err(std::io::Error::new( + std::io::ErrorKind::BrokenPipe, + "peer closed the stream", + ))) + } else { + self.flushed = true; + std::task::Poll::Ready(Ok(())) + } + } + + fn poll_shutdown( + self: std::pin::Pin<&mut Self>, + _cx: &mut std::task::Context<'_>, + ) -> std::task::Poll> { + std::task::Poll::Ready(Ok(())) + } + } + + impl std::marker::Unpin for WriterThatDiesAfterTheFirstEvent {} + + #[tokio::test] + async fn a_dead_writer_interrupts_without_resuming() { + // The peer of the streaming writer is gone: no resume can ever + // deliver an event to it, so the bridge must skip the resume + // attempts entirely and interrupt the orphan immediately. + let drop_delta = || { + [sse_frame( + "item.delta", + json!({ + "seq": 1, + "turn_id": "turn_drop", + "payload": { "kind": "agent_message", "delta": "never-delivered" } + }), + )] + .concat() + }; + // A later, completing body the resume must never pull from: if the + // resume path did run, the turn would complete instead of erroring. + let bodies = vec![ + drop_delta(), + [sse_frame( + "turn.completed", + json!({ + "seq": 2, + "turn_id": "turn_drop", + "payload": { "turn": { "status": "completed" } } + }), + )] + .concat(), + ]; + let (base_url, interrupts, connections, since_seq_requests, server) = + spawn_scripted_drop_runtime(bodies).await; + let mut bridge = RuntimeBridge::from_base_url_for_test(base_url); + + // A writer that is alive for `response_start` and dead before the + // first delta: the stream then ends with the writer gone, which + // must skip the resume and interrupt directly. (A writer dead from + // the very start trips the earlier `response_start` emit instead, + // which never reaches the stream at all.) + let mut dead_writer = WriterThatDiesAfterTheFirstEvent::default(); + + let result = bridge + .message_thread("thr_drop", "go", &mut dead_writer, None, None) + .await; + server.abort(); + let _ = server.await; + + assert!( + result.is_err(), + "a dead writer must end the turn as an error" + ); + assert_eq!( + connections.load(std::sync::atomic::Ordering::SeqCst), + 1, + "no resume may be attempted for a dead writer" + ); + assert_eq!( + since_seq_requests.lock().expect("since_seq log").len(), + 1, + "the live connection is the only event-stream request" + ); + assert_eq!( + interrupts.load(std::sync::atomic::Ordering::SeqCst), + 1, + "the orphan must be interrupted without resuming" + ); + } + #[tokio::test] async fn stdio_runtime_bridge_streams_response_delta_events() { async fn create_turn(AxumPath(thread_id): AxumPath) -> Json { diff --git a/crates/cli/src/update.rs b/crates/cli/src/update.rs index 3e64e6a2c1..d2f7f29309 100644 --- a/crates/cli/src/update.rs +++ b/crates/cli/src/update.rs @@ -32,9 +32,9 @@ const GITHUB_RELEASE_DOWNLOAD_BASE_URL: &str = const UPDATE_HTTP_ATTEMPTS: usize = 3; const UPDATE_HTTP_RETRY_DELAY_MS: u64 = 100; /// Ceiling for one asset download. Release binaries are tens of megabytes -/// and some of the networks this exists for are slow: 600s covers a full -/// 60 MiB at ~100 KiB/s (the same download budget the audit gives skill -/// tarballs; the old 300s needed an implausible >1.6 Mbps to finish). +/// and some of the networks this exists for are slow: 600s covers ~58 MiB +/// at ~100 KiB/s (the same download budget the audit gives skill tarballs; +/// the old 300s needed an implausible >1.6 Mbps to finish). const UPDATE_DOWNLOAD_TIMEOUT: Duration = Duration::from_secs(600); /// Ceiling for one checksum-manifest probe. The manifest is a few hundred /// bytes, so this is only a backstop against a source that accepts the diff --git a/crates/core/src/lib.rs b/crates/core/src/lib.rs index c1b9ce71cb..a70611c685 100644 --- a/crates/core/src/lib.rs +++ b/crates/core/src/lib.rs @@ -43,7 +43,19 @@ use uuid::Uuid; /// Per-tool dispatch budget for the headless runtime. 30 minutes: tools /// legitimately run long (builds, test suites, MCP-backed calls), and this /// wrapper is a runaway backstop, not an expected duration — the previous -/// 300s value cut off healthy in-flight tool work. +/// 300s value cut off healthy in-flight tool work. Part of the 1800s family +/// (TUI client envelope, vision request envelope, model stream cap +/// `STREAM_MAX_DURATION_SECS`, dynamic-tool result wait, sub-agent tool +/// timeout, MCP execute timeout, the mirrors in app-server and the MCP stdio +/// proxy, the background-task wall clock `TaskExecutionLimits::wall_time`, +/// the sub-agent `default_wall_time_secs`, and the fleet `builder` role +/// preset) that comments keep in sync; this comment anchors the family +/// roster — there is no shared constant across the crates yet. +/// +/// Several family members are configurable defaults rather than constants +/// (`STREAM_MAX_DURATION_SECS`, the MCP `execute_timeout`, and the sub-agent +/// `default_wall_time_secs`): a family-wide bump changes their defaults, not +/// their ceilings, and user overrides survive it. fn tool_dispatch_timeout() -> Duration { if cfg!(test) { Duration::from_millis(50) diff --git a/crates/mcp/src/stdio_client.rs b/crates/mcp/src/stdio_client.rs index a948dca558..578faedc91 100644 --- a/crates/mcp/src/stdio_client.rs +++ b/crates/mcp/src/stdio_client.rs @@ -757,6 +757,12 @@ struct Connection { impl Connection { fn send(&mut self, message: &Value) -> Result<()> { + // Known unbounded leg (deliberate, disclosed debt): the write below + // is blocking std I/O while the connection mutex is held, so a + // server that never drains its stdin can park this leg past every + // budget — unlike the read leg, which `request_with_timeout` + // bounds. Fixing it needs an async or threaded writer and is + // tracked as follow-up scale, not silently assumed safe. let stdin = self .stdin .as_ref() @@ -899,6 +905,26 @@ impl Drop for Connection { } } +#[cfg(test)] +mod budget_pins { + // The engine-side stdio proxy has no behavioral timeout tests (the + // budgets are compile-time constants), so pin the wiring values: a + // drift here silently re-bounds every MCP `tools/call` the engine + // proxy carries. CALL_TOOL_TIMEOUT must mirror the TUI pool's default + // execute timeout (1800s), and the generic request budget must stay + // separate and much shorter. + use super::{CALL_TOOL_TIMEOUT, HANDSHAKE_TIMEOUT, REQUEST_TIMEOUT}; + use std::time::Duration; + + #[test] + fn call_tool_budget_mirrors_the_pool_default_and_stays_separate() { + assert_eq!(CALL_TOOL_TIMEOUT, Duration::from_secs(1800)); + assert_eq!(REQUEST_TIMEOUT, Duration::from_secs(120)); + assert!(CALL_TOOL_TIMEOUT > REQUEST_TIMEOUT); + assert_eq!(HANDSHAKE_TIMEOUT, Duration::from_secs(30)); + } +} + #[cfg(test)] mod tests { use std::collections::HashMap; diff --git a/crates/tui/src/client.rs b/crates/tui/src/client.rs index 3578514409..bfa7b67989 100644 --- a/crates/tui/src/client.rs +++ b/crates/tui/src/client.rs @@ -3022,6 +3022,11 @@ impl DeepSeekClient { crate::retry_status::failed(last.to_string()); self.mark_request_failure("non-streaming request envelope exceeded") .await; + // A provider that just wedged past the whole envelope is + // exactly the case where the /models health probe + // matters; without it, connection health stays degraded + // until the next real request succeeds. + self.maybe_probe_recovery().await; return Err(anyhow::Error::new(last)); } } @@ -4557,6 +4562,76 @@ mod tests { ); } + #[tokio::test] + async fn envelope_exceed_probes_recovery_once_degraded() { + // A provider that wedges past the whole envelope must not leave + // connection health stale: once the failure threshold has degraded + // the connection, the envelope exit probes /models so health + // recovers without waiting for the next real request. One exceed + // alone stays under the threshold and must not probe (the + // Healthy-state short-circuit), so this drives exactly two. + let _env_lock = crate::test_support::lock_test_env(); + let _envelope = NonStreamingEnvelopeGuard::millis(2000); + let server = MockServer::start().await; + Mock::given(method("POST")) + .respond_with( + ResponseTemplate::new(200) + .set_body_json(json!({ + "model": "deepseek-v4-pro", + "choices": [ + { "message": { "role": "assistant", "content": "late" } } + ] + })) + .set_delay(Duration::from_secs(5)), + ) + .expect(2) + .mount(&server) + .await; + Mock::given(method("GET")) + .and(path("/v1/models")) + .respond_with(ResponseTemplate::new(200).set_body_json(json!({ "data": [] }))) + .expect(1) + .mount(&server) + .await; + + let client = deepseek_request_boundary_client(&server.uri(), server.uri()); + let make_request = || MessageRequest { + model: "deepseek-v4-pro".to_string(), + messages: vec![Message { + role: Role::User, + content: vec![ContentBlock::Text { + text: "envelope".to_string(), + cache_control: None, + }], + }], + max_tokens: 16, + system: None, + tools: None, + tool_choice: None, + metadata: None, + thinking: None, + reasoning_effort: Some("off".to_string()), + stream: Some(false), + temperature: None, + top_p: None, + }; + + for _ in 0..2 { + let err = client + .create_message(make_request()) + .await + .expect_err("a provider that never answers must hit the envelope"); + assert!( + err.to_string().to_lowercase().contains("timed out"), + "envelope timeout must be reported as such; got {err:#}" + ); + } + + // verify() enforces the expectations above: exactly two stalled + // requests and exactly one /models recovery probe. + server.verify().await; + } + #[tokio::test] async fn stream_open_retry_path_sets_no_total_deadline() { // The injected budget is process-global; serialize against other @@ -4574,7 +4649,7 @@ mod tests { .respond_with( ResponseTemplate::new(200) .set_body_string("data: [DONE]\n\n") - .set_delay(Duration::from_millis(2500)), + .set_delay(Duration::from_millis(4000)), ) .mount(&server) .await; @@ -4606,19 +4681,19 @@ mod tests { // A caller that pins its own, larger total (`list_models` pins 30s) // must keep it: `.timeout()` on the builder is a pure overwrite, so // an unconditional envelope would silently replace the pinned - // budget with the injected 2s and fail this 2.5s-late response. + // budget with the injected 2s and fail this 4s-late response. Mock::given(method("GET")) .respond_with( ResponseTemplate::new(200) .set_body_string("{}") - .set_delay(Duration::from_millis(2500)), + .set_delay(Duration::from_millis(4000)), ) .mount(&server) .await; let client = deepseek_request_boundary_client(&server.uri(), server.uri()); let response = client - .send_with_retry_total(Duration::from_secs(5), || { + .send_with_retry_total(Duration::from_secs(12), || { client.http_client.get(format!("{}/models", server.uri())) }) .await @@ -8325,6 +8400,11 @@ mod tests { #[tokio::test] async fn deepseek_anthropic_translate_uses_messages_endpoint() { + // The Anthropic dialect resolves its budget through the + // process-global `non_streaming_request_envelope()`, so this must + // hold the same lock the injecting tests take; otherwise a parallel + // `NonStreamingEnvelopeGuard` can cut this request off mid-flight. + let _env_lock = crate::test_support::lock_test_env(); let server = MockServer::start().await; Mock::given(method("POST")) .and(path("/v1/messages")) @@ -8452,6 +8532,9 @@ mod tests { #[tokio::test] async fn minimax_anthropic_request_uses_messages_endpoint() { + // Same process-global envelope hazard as the DeepSeek sibling above, + // and its neighbour test injects a 1s budget. + let _env_lock = crate::test_support::lock_test_env(); let server = MockServer::start().await; Mock::given(method("POST")) .and(path("/anthropic/v1/messages")) @@ -8509,6 +8592,240 @@ mod tests { assert!(body.get("output_config").is_none(), "{body}"); } + #[tokio::test] + async fn anthropic_non_streaming_request_carries_the_envelope_and_probes() { + // The Anthropic dialect sends one direct request with no retry + // loop; its total budget must match every other non-streaming + // completion and must actually cut off a stalled provider. The + // transport-level cutoff never reaches the status checks, so this + // arm must mark the failure and probe /models itself — otherwise + // connection health stays stale until the next request. One + // envelope exceed alone stays under the degradation threshold, so + // the health-marking is asserted indirectly: exactly one POST and + // one probe GET reach the server (verified via server.verify()). + let _env_lock = crate::test_support::lock_test_env(); + let _envelope = NonStreamingEnvelopeGuard::millis(1000); + let server = MockServer::start().await; + Mock::given(method("POST")) + .and(path("/anthropic/v1/messages")) + .respond_with( + ResponseTemplate::new(200) + .set_body_json(json!({ + "id": "msg_slow", + "type": "message", + "role": "assistant", + "content": [{"type": "text", "text": "late"}], + "model": "MiniMax-M3", + "stop_reason": "end_turn", + "stop_sequence": null, + "usage": {"input_tokens": 1, "output_tokens": 1} + })) + .set_delay(Duration::from_millis(4000)), + ) + .expect(2) + .mount(&server) + .await; + // The recovery probe: the transport arm runs it immediately after + // marking the failure. Routing the client's base_url at the mock + // (the way the health-check tests do) puts the probe on + // `/anthropic/v1/models`, so the pin stays hermetic. + Mock::given(method("GET")) + .and(path("/anthropic/v1/models")) + .respond_with(ResponseTemplate::new(200).set_body_json(json!({ "data": [] }))) + .expect(1) + .mount(&server) + .await; + + let mut client = + minimax_anthropic_client_with_base_url(format!("{}/anthropic", server.uri())); + client.test_messages_transport_base_url = Some(format!("{}/anthropic", server.uri())); + let make_request = || MessageRequest { + model: "MiniMax-M3".to_string(), + messages: vec![Message { + role: Role::User, + content: vec![ContentBlock::Text { + text: "hello".to_string(), + cache_control: None, + }], + }], + max_tokens: 32, + system: None, + tools: None, + tool_choice: None, + metadata: None, + thinking: None, + reasoning_effort: Some("off".to_string()), + stream: Some(false), + temperature: None, + top_p: None, + }; + for _ in 0..2 { + let err = client + .create_message(make_request()) + .await + .expect_err("a provider that answers past the envelope must be cut off"); + let rendered = format!("{err:#}"); + assert!( + rendered.contains("timed out"), + "the cutoff must surface as a timeout, not a generic failure: {rendered}" + ); + } + // Enforces the expectations above: exactly two stalled POSTs (one + // alone stays under the degradation threshold) and — the point of + // this pin — exactly one /models recovery probe fired by the + // transport arm's own failure handling. + server.verify().await; + } + + #[tokio::test] + async fn anthropic_isolated_requests_keep_shared_health_untouched() { + // The isolated Auto-classifier request runs with + // `isolated_request_state` so a read-only inspection never writes + // the shared connection health. The Anthropic transport marks and + // probes on its own transport errors, so without the gate an + // isolated stall would degrade shared health and fire a /models + // probe from the classifier path. Two stalls are needed for the + // leak to show: one alone stays under the degradation threshold. + let _env_lock = crate::test_support::lock_test_env(); + let _envelope = NonStreamingEnvelopeGuard::millis(1000); + let server = MockServer::start().await; + Mock::given(method("POST")) + .and(path("/anthropic/v1/messages")) + .respond_with( + ResponseTemplate::new(200) + .set_body_json(json!({ + "id": "msg_slow", + "type": "message", + "role": "assistant", + "content": [{"type": "text", "text": "late"}], + "model": "MiniMax-M3", + "stop_reason": "end_turn", + "stop_sequence": null, + "usage": {"input_tokens": 1, "output_tokens": 1} + })) + .set_delay(Duration::from_millis(4000)), + ) + .expect(2) + .mount(&server) + .await; + // No probe may fire from the isolated path: expect(0) fails + // server.verify() if the transport arm leaks a health write. + Mock::given(method("GET")) + .and(path("/anthropic/v1/models")) + .respond_with(ResponseTemplate::new(200).set_body_json(json!({ "data": [] }))) + .expect(0) + .mount(&server) + .await; + + let mut client = + minimax_anthropic_client_with_base_url(format!("{}/anthropic", server.uri())); + client.test_messages_transport_base_url = Some(format!("{}/anthropic", server.uri())); + client.isolated_request_state = true; + let request = MessageRequest { + model: "MiniMax-M3".to_string(), + messages: vec![Message { + role: Role::User, + content: vec![ContentBlock::Text { + text: "hello".to_string(), + cache_control: None, + }], + }], + max_tokens: 32, + system: None, + tools: None, + tool_choice: None, + metadata: None, + thinking: None, + reasoning_effort: Some("off".to_string()), + stream: Some(false), + temperature: None, + top_p: None, + }; + for _ in 0..2 { + client + .create_message(request.clone()) + .await + .expect_err("a provider that answers past the envelope must be cut off"); + } + let health = client.connection_health.lock().await; + assert_eq!( + health.consecutive_failures, 0, + "an isolated request must not write the shared connection health" + ); + assert_eq!(health.state, ConnectionState::Healthy); + drop(health); + server.verify().await; + } + + #[tokio::test] + async fn anthropic_isolated_requests_keep_shared_health_untouched_on_status_errors() { + // The status-level arm of the Anthropic transport (HTTP 4xx/5xx + // error envelopes) marks health as well, so the isolated + // classifier request must skip it too: two failures would cross + // the degradation threshold and fire a /models probe from a + // read-only inspection — the same leak the transport-stall pin + // above covers for the transport arm. + let _env_lock = crate::test_support::lock_test_env(); + let server = MockServer::start().await; + Mock::given(method("POST")) + .and(path("/anthropic/v1/messages")) + .respond_with(ResponseTemplate::new(500).set_body_json(json!({ + "type": "error", + "error": {"type": "api_error", "message": "boom"} + }))) + .expect(2) + .mount(&server) + .await; + // No probe may fire from the isolated path: expect(0) fails + // server.verify() if the status arm leaks a health write. + Mock::given(method("GET")) + .and(path("/anthropic/v1/models")) + .respond_with(ResponseTemplate::new(200).set_body_json(json!({ "data": [] }))) + .expect(0) + .mount(&server) + .await; + + let mut client = + minimax_anthropic_client_with_base_url(format!("{}/anthropic", server.uri())); + client.test_messages_transport_base_url = Some(format!("{}/anthropic", server.uri())); + client.isolated_request_state = true; + let request = MessageRequest { + model: "MiniMax-M3".to_string(), + messages: vec![Message { + role: Role::User, + content: vec![ContentBlock::Text { + text: "hello".to_string(), + cache_control: None, + }], + }], + max_tokens: 32, + system: None, + tools: None, + tool_choice: None, + metadata: None, + thinking: None, + reasoning_effort: Some("off".to_string()), + stream: Some(false), + temperature: None, + top_p: None, + }; + for _ in 0..2 { + client + .create_message(request.clone()) + .await + .expect_err("an HTTP 500 must surface as an API error"); + } + let health = client.connection_health.lock().await; + assert_eq!( + health.consecutive_failures, 0, + "an isolated request must not write the shared connection health on a \ + status error" + ); + assert_eq!(health.state, ConnectionState::Healthy); + drop(health); + server.verify().await; + } + #[test] fn custom_api_key_header_is_allowed_without_primary_provider_key() { let mut extra = HashMap::new(); diff --git a/crates/tui/src/client/anthropic.rs b/crates/tui/src/client/anthropic.rs index 9cb81b6cf3..9380bd749e 100644 --- a/crates/tui/src/client/anthropic.rs +++ b/crates/tui/src/client/anthropic.rs @@ -222,11 +222,35 @@ impl DeepSeekClient { .http_client .post(&url) .header("Accept", "text/event-stream") - .timeout(crate::client::NON_STREAMING_REQUEST_ENVELOPE) + .timeout(crate::client::non_streaming_request_envelope()) .json(body) .send() - .await - .context("Anthropic Messages API request failed")?; + .await; + let response = match response { + Ok(response) => response, + Err(error) => { + let rendered = if error.is_timeout() { + "anthropic request exceeded the envelope".to_string() + } else { + format!("anthropic transport failure: {error}") + }; + // A transport-level failure never reaches the status checks + // below, so it must mark health and probe on its own — + // otherwise a provider that stalls past the envelope leaves + // connection health stale until the next request retries. + // The isolated classifier request is the exception: a + // read-only inspection must not write the shared connection + // health (or fire a /models probe), matching the isolated + // dispatch contract of the generic send paths. + if !self.isolated_request_state { + self.mark_request_failure(&rendered).await; + self.maybe_probe_recovery().await; + } + return Err( + anyhow::Error::new(error).context("Anthropic Messages API request failed") + ); + } + }; self.check_anthropic_response(response).await } @@ -240,11 +264,19 @@ impl DeepSeekClient { if !status.is_success() { let raw = bounded_error_text(response, ERROR_BODY_MAX_BYTES).await; let (error_type, message) = parse_anthropic_error_envelope(&raw); - self.mark_request_failure(&format!("anthropic status={status}")) - .await; + // Same isolation contract as the transport-failure arm above: a + // status-level failure on the isolated classifier request must + // not write the shared connection health (the generic dialect's + // isolated dispatch path writes nothing either). + if !self.isolated_request_state { + self.mark_request_failure(&format!("anthropic status={status}")) + .await; + } anyhow::bail!("Anthropic API error (HTTP {status} {error_type}): {message}"); } - self.mark_request_success().await; + if !self.isolated_request_state { + self.mark_request_success().await; + } Ok(response) } diff --git a/crates/tui/src/config/subagent_limits.rs b/crates/tui/src/config/subagent_limits.rs index 843de48dae..cc452768d7 100644 --- a/crates/tui/src/config/subagent_limits.rs +++ b/crates/tui/src/config/subagent_limits.rs @@ -43,7 +43,11 @@ pub const MAX_SUBAGENT_API_TIMEOUT_SECS: u64 = 3600; /// legitimately outlasts 5 minutes, and the old default killed healthy /// in-flight tools mid-run. The child's own wall-time budget remains the /// spend backstop, and the heartbeat floor (tool_timeout + 30s) follows this -/// constant automatically. +/// constant automatically. Part of the 1800s family that comments keep in +/// sync (roster anchored at the core dispatch backstop's comment); +/// "single source of truth" applies within the sub-agent family. +/// In a background task the task `wall_time` backstop bounds the whole run +/// and preempts this timeout when they coincide — documented trade-off. pub const DEFAULT_SUBAGENT_TOOL_TIMEOUT_SECS: u64 = 1800; /// Default wall-clock interval without manager-visible sub-agent progress /// before a running child can be auto-cancelled to release its slot (#2614). diff --git a/crates/tui/src/core/engine/approval.rs b/crates/tui/src/core/engine/approval.rs index e6eda4c87e..7894c26f5e 100644 --- a/crates/tui/src/core/engine/approval.rs +++ b/crates/tui/src/core/engine/approval.rs @@ -475,4 +475,83 @@ mod tests { "an approval decision without a committed terminal receipt must not grant execution" ); } + + fn user_input_request() -> UserInputRequest { + UserInputRequest { + questions: vec![crate::tools::user_input::UserInputQuestion { + header: "Confirm".to_string(), + id: "confirm".to_string(), + question: "Proceed?".to_string(), + options: vec![ + crate::tools::user_input::UserInputOption { + label: "yes".to_string(), + description: "proceed".to_string(), + }, + crate::tools::user_input::UserInputOption { + label: "no".to_string(), + description: "stop".to_string(), + }, + ], + allow_free_text: false, + multi_select: false, + }], + } + } + + #[tokio::test] + async fn cancel_user_input_resolves_the_headless_wait_deterministically() { + // The headless exec agent's `UserInputRequired` arm resolves the + // otherwise-unbounded engine wait with `handle.cancel_user_input`; + // this pins the engine side of that contract: the cancellation is + // delivered (never dropped behind the approval multiplexer), the + // wait returns promptly with the deterministic cancelled error, and + // a cancellation for a *different* id does not end the wait. + let (mut engine, handle) = Engine::new(EngineConfig::default(), &Config::default()); + let request = user_input_request(); + let task = + tokio::spawn(async move { engine.await_user_input("call_headless", request).await }); + + let emitted = handle + .rx_event + .write() + .await + .recv() + .await + .expect("user input event"); + let Event::UserInputRequired { id, .. } = emitted else { + panic!("expected UserInputRequired, got {emitted:?}"); + }; + assert_eq!(id, "call_headless"); + + // A decision for a different tool id must not resolve the wait: + // the loop re-serves it rather than dropping the waiter. If the + // unrelated cancellation *did* end the wait, the task below would + // already be finished before the matching cancellation arrives. + handle + .cancel_user_input("call_unrelated") + .await + .expect("deliver unrelated cancellation"); + // Give the engine a scheduling opportunity to mis-consume it. + tokio::time::sleep(Duration::from_millis(50)).await; + assert!( + !task.is_finished(), + "a cancellation for a different tool id must not end the wait" + ); + + // The matching cancellation is the one that resolves the wait. + handle + .cancel_user_input("call_headless") + .await + .expect("deliver cancellation"); + + let resolved = tokio::time::timeout(Duration::from_secs(5), task) + .await + .expect("the cancelled wait must resolve promptly") + .expect("engine task"); + let rendered = format!("{resolved:?}"); + assert!( + rendered.to_lowercase().contains("cancel"), + "the wait must end as a cancelled error, got {resolved:?}" + ); + } } diff --git a/crates/tui/src/core/engine/streaming.rs b/crates/tui/src/core/engine/streaming.rs index ccd404e751..17a3b12514 100644 --- a/crates/tui/src/core/engine/streaming.rs +++ b/crates/tui/src/core/engine/streaming.rs @@ -40,6 +40,9 @@ pub(super) const STREAM_MAX_CONTENT_BYTES: usize = 10 * 1024 * 1024; // 10 MB /// 30 min in v0.6.6 after long-reasoning turns hit the old cap. Codex defaults to a /// per-chunk idle of 300s with no wall-clock cap; we keep both layers but /// give the wall-clock a generous window so it never fires in practice. +/// Same value and generation as the 1800s family roster anchored at +/// `core::tool_dispatch_timeout` (crates/core/src/lib.rs); listed there so +/// a family-wide bump cannot silently leave this cap behind. pub(super) const STREAM_MAX_DURATION_SECS: u64 = 1800; // 30 minutes (was 300s; #103/#1) /// Hard cap on consecutive recoverable stream errors before we surface a turn /// failure. Bumped 3 → 5 in v0.6.7 along with the HTTP/2 keepalive defaults diff --git a/crates/tui/src/core/turn.rs b/crates/tui/src/core/turn.rs index 17d5401661..08e1339023 100644 --- a/crates/tui/src/core/turn.rs +++ b/crates/tui/src/core/turn.rs @@ -475,8 +475,11 @@ fn maybe_notify_snapshots_disabled_once(workspace: &Path, error: &std::io::Error // A timed-out git is killed mid-write and leaves a fresh side-repo // index.lock behind, so every snapshot fast-fails for about an hour. // That must reach the user's stderr, not just the tracing log — silent - // undo-history loss is the §2.7 failure mode. - if !size_gated && error.kind() != std::io::ErrorKind::TimedOut { + // undo-history loss is the §2.7 failure mode. A failed `git init` is the + // same class and worse: it repeats on every attempt with no ageing-out, + // and it carries `ErrorKind::Other`, so it needs its own arm here. + let init_failed = message.contains(crate::snapshot::repo::GIT_INIT_FAILED_MARKER); + if !size_gated && !init_failed && error.kind() != std::io::ErrorKind::TimedOut { return; } use std::collections::HashSet; @@ -493,11 +496,7 @@ fn maybe_notify_snapshots_disabled_once(workspace: &Path, error: &std::io::Error // One prominent notice per workspace process lifetime — silent disable is // the §2.7 failure mode. Opt-in remains `[snapshots] max_workspace_gb` // (raise the cap or set 0 to disable the size gate). - let hint = if size_gated { - " raise `[snapshots] max_workspace_gb` in config.toml (or set it to 0 to disable the cap) to opt in." - } else { - " the timed-out git likely left a stale index.lock in the snapshot side repo; snapshots retry once it ages out (about an hour)." - }; + let hint = snapshot_failure_hint(&message, size_gated); eprintln!( "warning: workspace snapshots/undo are failing for {} {message} @@ -506,6 +505,106 @@ fn maybe_notify_snapshots_disabled_once(workspace: &Path, error: &std::io::Error ); } +/// Route the failure to the remedy that actually applies. The needles come +/// from `snapshot::repo` itself rather than from copies of its wording, so +/// rewording a producer moves the router with it instead of silently +/// sending users to the wrong remedy. +fn snapshot_failure_hint(message: &str, size_gated: bool) -> &'static str { + use crate::snapshot::repo::{GIT_INIT_FAILED_MARKER, WEDGED_FS_MARKER, git_timeout_marker}; + if size_gated { + " raise `[snapshots] max_workspace_gb` in config.toml (or set it to 0 to disable the cap) to opt in." + } else if message.contains(WEDGED_FS_MARKER) { + // Bounded pre-git probes (workspace path resolution, first-init + // size walk): no git ran yet, so there is no index.lock to wait out. + " the workspace filesystem did not answer in time (wedged NFS/FUSE mount?); snapshots retry once it responds." + } else if message.contains(&git_timeout_marker("init")) { + // A timed-out init leaves the side repo incomplete; the readiness + // predicate re-inits it, but a lock the killed init left behind is + // fresh and blocks that until the stale-lock sweep may clear it. + " the timed-out init left the snapshot side repo incomplete; snapshots re-init automatically once the filesystem responds (a lock the killed init left behind can delay that by up to an hour)." + } else if message.contains(GIT_INIT_FAILED_MARKER) { + // git never ages a `config.lock` out itself, but the open-path + // sweep clears one that has been stale for an hour, so this state + // does clear itself given time — a fresh lock left by a killed + // init (or by a second host initializing the same workspace + // concurrently) only has to age out. Manual removal is the + // fallback for a persistent failure, not the first move: deleting + // the directory discards the workspace's whole undo history. + " the snapshot side repo under `~/.codewhale/snapshots` is half-initialized; snapshots sweep a leftover lock and re-init automatically once it ages out (about an hour) — remove that workspace's directory (discarding its snapshot history) only if the error persists past that." + } else { + " the timed-out git likely left a stale lock file in the snapshot side repo (`index.lock`, or a ref lock such as `HEAD.lock` from an interrupted ref update); snapshots retry once it ages out (about an hour)." + } +} + +#[cfg(test)] +mod snapshot_failure_hint_tests { + use super::snapshot_failure_hint; + use crate::snapshot::repo::{GIT_INIT_FAILED_MARKER, WEDGED_FS_MARKER, git_timeout_marker}; + + // Every probe string below is assembled from the markers `snapshot::repo` + // exports, not from a copy of its wording, so these really do pin the + // producer/router coupling rather than restating the router. + #[test] + fn size_gated_failures_point_at_the_config_cap() { + let message = "workspace too large for snapshots (over 2 GB ...)"; + assert!(snapshot_failure_hint(message, true).contains("max_workspace_gb")); + } + + #[test] + fn bounded_probe_timeouts_get_the_wedged_filesystem_hint() { + let message = format!( + "first-init workspace size walk did not finish within 120s; {WEDGED_FS_MARKER}" + ); + assert!(snapshot_failure_hint(&message, false).contains("wedged NFS/FUSE mount?")); + } + + #[test] + fn timed_out_git_init_gets_the_reinit_hint_not_the_stale_lock_hint() { + let message = format!( + "failed to run git init: {} after 300s: …", + git_timeout_marker("init") + ); + let hint = snapshot_failure_hint(&message, false); + assert!(hint.contains("re-init automatically"), "{hint}"); + assert!(!hint.contains("index.lock"), "{hint}"); + } + + #[test] + fn other_git_timeouts_keep_the_stale_lock_hint() { + let message = format!("{} after 300s: …", git_timeout_marker("commit")); + let hint = snapshot_failure_hint(&message, false); + assert!(hint.contains("stale lock file"), "{hint}"); + // `update-ref HEAD` leaves a `HEAD.lock`, not an `index.lock`, so + // the generic arm must not promise a single lock name. + assert!(hint.contains("ref lock"), "{hint}"); + } + + // A non-zero-status `git init` repeats forever and carries + // `ErrorKind::Other`, so it needs both its own hint and its own arm in + // the notify gate. The lock behind it is swept once it ages out, so + // the hint leads with waiting — pointing straight at directory removal + // would discard the workspace's undo history for a state that heals + // itself within the hour. + #[test] + fn failed_git_init_gets_the_half_initialized_repo_hint() { + let message = + format!("{GIT_INIT_FAILED_MARKER}: error: could not lock config file .git/config"); + let hint = snapshot_failure_hint(&message, false); + assert!(hint.contains("half-initialized"), "{hint}"); + assert!(hint.contains("about an hour"), "{hint}"); + // Manual removal is the fallback for a persistent failure, not the + // first move, and the hint names what removal costs. + assert!(hint.contains("only if the error persists"), "{hint}"); + assert!(hint.contains("discarding its snapshot history"), "{hint}"); + // The sweep must lead the remedy: a regression that puts removal + // first would point at discarding undo history for a state that + // heals itself within the hour. + let sweep = hint.find("sweep").expect("hint must mention the sweep"); + let remove = hint.find("remove").expect("hint must mention removal"); + assert!(sweep < remove, "the self-healing sweep must lead: {hint}"); + } +} + #[cfg(test)] mod snapshot_label_tests { use super::*; diff --git a/crates/tui/src/exec_agent.rs b/crates/tui/src/exec_agent.rs index 297cc82368..ef82bb388a 100644 --- a/crates/tui/src/exec_agent.rs +++ b/crates/tui/src/exec_agent.rs @@ -471,6 +471,7 @@ pub(crate) async fn run_exec_agent( let mut tool_error_seen = false; let mut last_error_category = None; let mut reported_sandbox_contract = false; + let mut reported_user_input_contract = false; let should_persist_session = resuming_session || output_format == ExecOutputFormat::StreamJson; let mut latest_session_id = loaded_session_id; @@ -700,6 +701,20 @@ pub(crate) async fn run_exec_agent( let _ = engine_handle.deny_tool_call(id).await; } } + Event::UserInputRequired { id, .. } => { + // A headless run has no one to answer a request_user_input + // prompt, and the engine's wait is unbounded (human-paced), + // so without an explicit resolution the run parks forever. + // Cancel the request: the tool returns a cancelled error and + // the turn continues, mirroring how approvals auto-deny here. + let _ = engine_handle.cancel_user_input(id).await; + if !reported_user_input_contract { + eprintln!( + "request_user_input cannot be answered in a headless run; the request was cancelled so the turn can continue" + ); + reported_user_input_contract = true; + } + } Event::ElevationRequired { tool_id, tool_name, diff --git a/crates/tui/src/mcp.rs b/crates/tui/src/mcp.rs index 3833a4e07c..ec2323864b 100644 --- a/crates/tui/src/mcp.rs +++ b/crates/tui/src/mcp.rs @@ -531,7 +531,12 @@ fn default_connect_timeout() -> u64 { // 30 minutes: an MCP tool call legitimately runs minutes (scrapes, remote // jobs, agent-side work). The old 60s default returned "timed out" to the // model for healthy-but-slow tools, which then retried and compounded cost. -// Per-server/global overrides still apply via `execute_timeout`. +// Per-server/global overrides still apply via `execute_timeout`. Part of +// the 1800s family that comments keep in sync (roster anchored at the +// core dispatch backstop's comment). Note the budget is +// per leg: a barely-draining server can consume most of it on the send +// leg and the read leg waits out its own budget, so a single call can +// approach twice this value in the worst case. fn default_execute_timeout() -> u64 { 1800 } @@ -1520,6 +1525,10 @@ fn per_request_read_budget(read_timeout_secs: u64, request_timeout_secs: u64) -> /// longest request the connection carries (`tools/call` at the execute /// budget), so a raised `execute_timeout` governs there too. This is a /// ceiling for the transport, not the read knob — the two stay independent. +/// Because reqwest's client total wraps the response body, it also bounds a +/// long-lived legacy-SSE event stream on the same client at this ceiling; +/// that is strictly better than the base behavior (the client total was the +/// 120s read knob), but do not "fix" the stream by removing this total. fn http_total_timeout(config: &McpServerConfig, global: &McpTimeouts) -> u64 { config .effective_read_timeout(global) @@ -2190,14 +2199,15 @@ impl McpConnection { { Ok(Ok(())) => {} Ok(Err(error)) => return self.finish_guarded_error(error).await, - Err(error) => { + Err(_error) => { // A timed-out write can linger as a partial line; the // connection must not be reused (see the budget comment - // above). + // above). tokio's Elapsed display adds no information, so + // the message carries the budget instead. self.state = ConnectionState::Disconnected; return self .finish_guarded_error(anyhow::anyhow!( - "MCP method '{}' on server '{}' timed out sending after {}s: {error}", + "MCP method '{}' on server '{}' timed out sending after {}s", method, self.name, timeout_secs diff --git a/crates/tui/src/repl/runtime.rs b/crates/tui/src/repl/runtime.rs index 5f96c6b500..a031c4d6ef 100644 --- a/crates/tui/src/repl/runtime.rs +++ b/crates/tui/src/repl/runtime.rs @@ -141,9 +141,11 @@ pub trait RpcDispatcher: Send + Sync { // --------------------------------------------------------------------------- const DEFAULT_STDOUT_LIMIT: usize = 8_192; -// 900s: inline rounds can include `sub_query` RPCs to the live model, which -// legitimately think for minutes (same reasoning as the engine's stream idle -// budget). This cap is a backstop, not the expected round duration. +// 900s: inline rounds can include several `sub_query` RPCs to the live +// model plus local compute, so the round budget is a backstop, not the +// expected round duration. Each individual sub-query is still bounded by +// the bridge's own budget (CHILD_TIMEOUT_SECS on this path), so the two +// bounds compose rather than compete. const ROUND_TIMEOUT: Duration = Duration::from_secs(900); #[cfg(not(windows))] const SPAWN_READY_TIMEOUT: Duration = Duration::from_secs(10); diff --git a/crates/tui/src/rlm/bridge.rs b/crates/tui/src/rlm/bridge.rs index c06bb0a0c5..73b0881c43 100644 --- a/crates/tui/src/rlm/bridge.rs +++ b/crates/tui/src/rlm/bridge.rs @@ -147,8 +147,10 @@ impl RlmBridge { } /// Override the per-child-completion wall-clock budget (seconds). + /// Values below one second are floored at one: `0` would build a tokio + /// timeout that fires immediately and kill every child query. pub(crate) fn with_sub_query_timeout_secs(mut self, secs: u64) -> Self { - self.sub_query_timeout = Duration::from_secs(secs); + self.sub_query_timeout = Duration::from_secs(secs.max(1)); self } @@ -491,14 +493,19 @@ mod tests { // The session's sub_query_timeout_secs was historically stored but // never read (the bridge always used its 120s const); this pins the // configured budget actually governing the deadline, including the - // timeout message naming the configured value. + // timeout message naming the configured value. The outer deadline + // keeps a regression back to the 120s const failing within seconds + // instead of hanging the suite for two minutes. let client: Arc = Arc::new(HangingChildClient); let bridge = RlmBridge::new(Arc::clone(&client), "child-model".to_string(), 1) .with_sub_query_timeout_secs(1); - let response = bridge - .dispatch_llm("hang forever".to_string(), None, None, None) - .await; + let response = tokio::time::timeout( + std::time::Duration::from_secs(5), + bridge.dispatch_llm("hang forever".to_string(), None, None, None), + ) + .await + .expect("the configured budget must fire well within the outer deadline"); let error = response.error.expect("hanging child must time out"); assert!( @@ -507,6 +514,20 @@ mod tests { ); } + #[test] + fn sub_query_timeout_floors_at_one_second() { + // `0` would build a tokio timeout that fires immediately and kill + // every child query, so the setter must floor the budget at 1s. + let client: Arc = Arc::new(HangingChildClient); + let bridge = + RlmBridge::new(client, "child-model".to_string(), 1).with_sub_query_timeout_secs(0); + assert_eq!( + bridge.sub_query_timeout, + Duration::from_secs(1), + "a zero budget must be floored at one second" + ); + } + #[test] fn batch_guard_allows_non_empty_batches_at_the_cap() { assert!(batch_guard(MAX_BATCH, Some("independent")).is_none()); diff --git a/crates/tui/src/rlm/session.rs b/crates/tui/src/rlm/session.rs index 48f4f93c36..91a97779a0 100644 --- a/crates/tui/src/rlm/session.rs +++ b/crates/tui/src/rlm/session.rs @@ -102,7 +102,7 @@ impl Default for RlmSessionConfig { fn default() -> Self { Self { output_feedback: OutputFeedback::Full, - sub_query_timeout_secs: 120, + sub_query_timeout_secs: super::bridge::CHILD_TIMEOUT_SECS, sub_rlm_max_depth: 1, share_session: false, } diff --git a/crates/tui/src/runtime_api.rs b/crates/tui/src/runtime_api.rs index bc4576930b..c6a82afbed 100644 --- a/crates/tui/src/runtime_api.rs +++ b/crates/tui/src/runtime_api.rs @@ -5599,6 +5599,10 @@ fn map_compat_stream_event(event: &crate::runtime_threads::RuntimeEventRecord) - "decision": payload.get("decision"), "remember": payload.get("remember"), "auto": payload.get("auto"), + // Explains an execution-policy denial to compat + // clients; null for plain decisions. The raw + // event stream has always carried it. + "posture": payload.get("posture"), // `timeout` only ever arrives from legacy journal // replays: current producers resolve pending approvals // through deny + `interrupted` instead. diff --git a/crates/tui/src/runtime_api/tests.rs b/crates/tui/src/runtime_api/tests.rs index ef97857500..2dd3549ebc 100644 --- a/crates/tui/src/runtime_api/tests.rs +++ b/crates/tui/src/runtime_api/tests.rs @@ -3927,6 +3927,7 @@ async fn stream_compat_mapping_handles_expected_runtime_events() -> Result<()> { "approval_id": "approval_test", "decision": "allow", "remember": false, + "posture": "auto_review", "internal_secret": "approval-decision-secret", }), }; @@ -3940,6 +3941,9 @@ async fn stream_compat_mapping_handles_expected_runtime_events() -> Result<()> { let text = String::from_utf8_lossy(&body); assert!(text.contains("event: approval.decided")); assert!(text.contains("\"decision\":\"allow\"")); + // The execution-policy explanation must reach compat clients so an + // auto_review denial is distinguishable from a plain auto-deny. + assert!(text.contains("\"posture\":\"auto_review\"")); assert!(!text.contains("approval-decision-secret")); // An interrupted resolution (turn interrupt / engine death / runtime diff --git a/crates/tui/src/runtime_threads.rs b/crates/tui/src/runtime_threads.rs index 8d41377095..44857552dc 100644 --- a/crates/tui/src/runtime_threads.rs +++ b/crates/tui/src/runtime_threads.rs @@ -550,7 +550,9 @@ const EMPTY_TURN_REASON: &str = "Turn completed without engine output"; // ends on turn interrupt or runtime shutdown instead (mirrors the engine-side // approval wait, which excludes approval time from the turn wall clock). // Dynamic (client-executed) tools legitimately run long, so their result wait -// is generous; it still ends on turn interrupt. +// is generous (part of the 1800s family that comments keep in sync; the +// roster is anchored at the core dispatch backstop's comment); it +// still ends on turn interrupt. const DYNAMIC_TOOL_RESULT_TIMEOUT: Duration = Duration::from_secs(1800); #[cfg(test)] @@ -3174,6 +3176,22 @@ pub enum ExternalApprovalDecision { Deny { remember: bool }, } +/// Settle the delivery race on the approval wait's interrupt exit. +/// +/// `deliver_external_approval` removes the entry and then sends, so a +/// decision can land in the oneshot after the wait already chose to stop. +/// That decision was made by the user and must resolve the approval as one. +/// Closing first makes this a linearization point: a send that lands before +/// the close is still readable here, and one that lands after it fails and +/// is reported to the client as not delivered, so a decision is never +/// accepted and then discarded. +fn rescue_decision_after_interrupt( + rx: &mut oneshot::Receiver, +) -> Option { + rx.close(); + rx.try_recv().ok() +} + struct PendingApprovalEntry { thread_id: String, request: PendingApprovalRequest, @@ -3526,8 +3544,34 @@ impl RuntimeThreadManager { rx } - fn cancel_pending_approval(&self, approval_id: &str) { - self.pending_approvals.lock().remove(approval_id); + /// Remove `approval_id` only if the entry still belongs to `thread_id`. + /// The `approval.required`-emit-failure rollback races a same-id + /// registration from another thread (providers reuse tool-call ids + /// across threads), and a blanket remove could evict that other + /// waiter's live entry — so only a same-thread match goes. + fn cancel_thread_pending_approval(&self, approval_id: &str, thread_id: &str) { + let mut map = self.pending_approvals.lock(); + if map + .get(approval_id) + .is_some_and(|entry| entry.thread_id == thread_id) + { + map.remove(approval_id); + } + } + + /// Remove `approval_id` only if its receiver is closed, i.e. the entry + /// belongs to a waiter that has stopped listening. Approval ids come + /// from the model's tool-call ids, which some providers reuse across + /// threads, so a waiter must never remove a live entry registered by + /// another waiter under the same id. + fn cancel_closed_pending_approval(&self, approval_id: &str) { + let mut map = self.pending_approvals.lock(); + if map + .get(approval_id) + .is_some_and(|entry| entry.sender.is_closed()) + { + map.remove(approval_id); + } } fn register_pending_user_input(&self, thread_id: &str, request: PendingUserInputRequest) { @@ -3856,11 +3900,22 @@ impl RuntimeThreadManager { approval_id: &str, decision: ExternalApprovalDecision, ) -> bool { - let entry = self.pending_approvals.lock().remove(approval_id); - match entry { - Some(entry) => entry.sender.send(decision).is_ok(), - None => false, - } + let entry = { + let mut map = self.pending_approvals.lock(); + // A closed receiver means the waiter is gone without removing its + // own entry — its monitor died. Leave the entry for the failure + // settlement, which publishes the resolution; taking it here + // would fail the send and leave the approval with no + // `approval.decided` at all. + if map + .get(approval_id) + .is_none_or(|entry| entry.sender.is_closed()) + { + return false; + } + map.remove(approval_id) + }; + entry.is_some_and(|entry| entry.sender.send(decision).is_ok()) } pub async fn deliver_dynamic_tool_result( @@ -6826,6 +6881,60 @@ impl RuntimeThreadManager { true }; + // The dead monitor owned this turn's pending approval wait, so no + // code path is left to resolve it. Settle this turn's approvals the + // same way the interrupt exit does (deny + interrupted) so external + // clients clear the pending UI and the pending map cannot leak the + // entry; the evicted engine below is cancelled, which resolves the + // engine side of the wait. + let stranded_approvals: Vec<(String, PendingApprovalEntry)> = { + // Collect and remove under one lock hold. By the time this runs + // the monitor has unwound and its receivers are closed, so + // `deliver_external_approval` leaves these entries alone and + // every one of them is published here exactly once. Entries + // whose receiver is still live are settled too (the deny is + // then also pushed through the decision channel): the waiter + // for this turn was the monitor itself, so nothing else can + // ever resolve them. + let mut map = self.pending_approvals.lock(); + map.iter() + .filter(|(_, entry)| { + entry.thread_id == thread_id && entry.request.turn_id == turn_id + }) + .map(|(id, _)| id.clone()) + .collect::>() + .into_iter() + .filter_map(|id| map.remove(&id).map(|entry| (id, entry))) + .collect() + }; + for (approval_id, entry) in stranded_approvals { + // A live receiver resolves through this deny on the decision + // channel; a dead one just drops the send. Either way the + // removal and the event below are the contract. + let _ = entry + .sender + .send(ExternalApprovalDecision::Deny { remember: false }); + if let Err(err) = self + .emit_event( + thread_id, + Some(turn_id), + None, + "approval.decided", + json!({ + "approval_id": approval_id, + "decision": "deny", + "remember": false, + "interrupted": true, + }), + ) + .await + { + tracing::error!( + "Failed to emit approval resolution for {approval_id} after monitor failure: {err}" + ); + } + } + // A terminal record is the externally visible lifecycle boundary. // Keep snapshots outside that boundary until its terminal receipt and // active-claim cleanup are also ordered. The dedupe scan may yield to @@ -9214,20 +9323,29 @@ impl RuntimeThreadManager { // can clear any pending approval UI. Without this // event the GUI would show a frozen approval dialog // that never receives approval.decided. - self.emit_event( - &thread_id, - Some(&turn_id), - None, - "approval.decided", - json!({ - "approval_id": id, - "decision": dec_str, - "remember": false, - "auto": true, - }), - ) - .await - .ok(); + if let Err(err) = self + .emit_event( + &thread_id, + Some(&turn_id), + None, + "approval.decided", + json!({ + "approval_id": id, + "decision": dec_str, + "remember": false, + "auto": true, + }), + ) + .await + { + // A dropped publish here would freeze the + // client's pending approval UI on an approval + // the runtime already resolved itself. + tracing::error!( + "Failed to emit auto approval resolution \ + for {id}: {err}" + ); + } if approved { let _ = engine.approve_tool_call(id).await; } else { @@ -9242,21 +9360,29 @@ impl RuntimeThreadManager { // fail closed (the audit trail stays authoritative) // instead of pausing the turn. if approval_mode == crate::tui::approval::ApprovalMode::Auto { - self.emit_event( - &thread_id, - Some(&turn_id), - None, - "approval.decided", - json!({ - "approval_id": id, - "decision": "deny", - "remember": false, - "auto": true, - "posture": "auto_review", - }), - ) - .await - .ok(); + if let Err(err) = self + .emit_event( + &thread_id, + Some(&turn_id), + None, + "approval.decided", + json!({ + "approval_id": id, + "decision": "deny", + "remember": false, + "auto": true, + "posture": "auto_review", + }), + ) + .await + { + // A dropped publish would strand the pending UI + // on the fail-closed deny below. + tracing::error!( + "Failed to emit auto-review deny \ + for {id}: {err}" + ); + } let _ = engine.deny_tool_call(id).await; continue; } @@ -9283,7 +9409,7 @@ impl RuntimeThreadManager { ) .await { - self.cancel_pending_approval(&id); + self.cancel_thread_pending_approval(&id, &thread_id); drop(projection); let _ = engine.deny_tool_call(&id).await; return Err(err); @@ -9312,14 +9438,6 @@ impl RuntimeThreadManager { tokio::select! { biased; _ = self.cancel_token.cancelled() => { - // The biased order favors the cancel token, - // but a decision already queued in the - // oneshot is a choice the user actually - // made — it must resolve the approval, not - // be discarded as an interrupt. - if let Ok(decision) = rx.try_recv() { - break ApprovalWakeup::Decision(Ok(decision)); - } break ApprovalWakeup::Interrupted; } decision = &mut rx => { @@ -9335,17 +9453,25 @@ impl RuntimeThreadManager { .await .unwrap_or(false) { - // Same race as the cancel arm: honor a - // decision that arrived before the - // interrupt was observed. - if let Ok(decision) = rx.try_recv() { - break ApprovalWakeup::Decision(Ok(decision)); - } break ApprovalWakeup::Interrupted; } } } }; + let wakeup = match wakeup { + ApprovalWakeup::Interrupted => { + match rescue_decision_after_interrupt(&mut rx) { + Some(decision) => ApprovalWakeup::Decision(Ok(decision)), + None => ApprovalWakeup::Interrupted, + } + } + other => other, + }; + // The receiver is closed on every non-decision exit (by + // the rescue above, or by the sender dropping), so this + // removes our entry if a delivery has not already taken + // it, and never a live entry that reuses our id. + self.cancel_closed_pending_approval(&id); match wakeup { ApprovalWakeup::Decision(Ok(ExternalApprovalDecision::Allow { remember, @@ -9353,62 +9479,88 @@ impl RuntimeThreadManager { if remember { self.remember_thread_auto_approve(&thread_id).await; } - self.emit_event( - &thread_id, - Some(&turn_id), - None, - "approval.decided", - json!({ - "approval_id": id, - "decision": "allow", - "remember": remember, - }), - ) - .await - .ok(); + if let Err(err) = self + .emit_event( + &thread_id, + Some(&turn_id), + None, + "approval.decided", + json!({ + "approval_id": id, + "decision": "allow", + "remember": remember, + }), + ) + .await + { + // The user acted on this host, but remote + // clients still need the publish to clear + // their pending UI. + tracing::error!( + "Failed to emit user approval decision \ + for {id}: {err}" + ); + } let _ = engine.approve_tool_call(id).await; } ApprovalWakeup::Decision(Ok(ExternalApprovalDecision::Deny { remember, })) => { - self.emit_event( - &thread_id, - Some(&turn_id), - None, - "approval.decided", - json!({ - "approval_id": id, - "decision": "deny", - "remember": remember, - }), - ) - .await - .ok(); - let _ = engine.deny_tool_call(id).await; - } - ApprovalWakeup::Decision(Err(_recv_err)) => { - self.cancel_pending_approval(&id); + if let Err(err) = self + .emit_event( + &thread_id, + Some(&turn_id), + None, + "approval.decided", + json!({ + "approval_id": id, + "decision": "deny", + "remember": remember, + }), + ) + .await + { + // The user acted on this host, but remote + // clients still need the publish to clear + // their pending UI. + tracing::error!( + "Failed to emit user approval decision \ + for {id}: {err}" + ); + } let _ = engine.deny_tool_call(id).await; } - ApprovalWakeup::Interrupted => { - self.cancel_pending_approval(&id); - // Emit approval.decided so external clients can - // clear the pending approval UI; the denial also - // unblocks the engine if cancellation raced it. - self.emit_event( - &thread_id, - Some(&turn_id), - None, - "approval.decided", - json!({ - "approval_id": id, - "decision": "deny", - "remember": false, - "interrupted": true, - }), - ) - .await - .ok(); + // Interrupt, runtime shutdown, engine exit, or the + // sender dropping unsent (another registration + // reused this approval id and replaced our entry): + // a forced resolution, published as one so clients + // clear the pending UI. The deny also unblocks the + // engine if cancellation raced it. + ApprovalWakeup::Decision(Err(_)) | ApprovalWakeup::Interrupted => { + if let Err(err) = self + .emit_event( + &thread_id, + Some(&turn_id), + None, + "approval.decided", + json!({ + "approval_id": id, + "decision": "deny", + "remember": false, + "interrupted": true, + }), + ) + .await + { + // A dropped publish here would strand the + // client's pending UI on a resolution that + // already happened; the settle path logs the + // same failure loudly. + tracing::error!( + "Failed to emit forced approval resolution \ + for {id}: {err}" + ); + } let _ = engine.deny_tool_call(id).await; } } diff --git a/crates/tui/src/runtime_threads/tests.rs b/crates/tui/src/runtime_threads/tests.rs index 2d77df2200..b321ed2ff5 100644 --- a/crates/tui/src/runtime_threads/tests.rs +++ b/crates/tui/src/runtime_threads/tests.rs @@ -9969,6 +9969,113 @@ async fn approval_wait_ends_when_the_runtime_shuts_down() -> Result<()> { Ok(()) } +#[tokio::test] +async fn settle_claimed_turn_failure_publishes_stranded_approvals() -> Result<()> { + // The dead monitor owned this turn's pending-approval wait, so the + // settlement must resolve it the way the interrupt exit does: publish + // deny+interrupted so clients clear the pending UI, clear the pending + // map so the entry cannot leak, and push the deny through the decision + // channel so no late reader can still observe it as unresolved. + let manager = test_manager(test_runtime_dir())?; + let thread = manager + .create_thread(CreateThreadRequest::default()) + .await?; + let receiver = + manager.register_pending_approval_for_thread_for_test(&thread.id, "tool_stranded"); + assert_eq!(manager.pending_approvals_count(), 1); + + // The register helper pins the entry's turn to "test-turn". + manager + .settle_claimed_turn_failure(&thread.id, "test-turn", "forced monitor failure") + .await; + + assert_eq!( + manager.pending_approvals_count(), + 0, + "stranded approval must not leak in the pending map" + ); + let decision = receiver.await.expect("decision channel must resolve"); + assert!( + matches!(decision, ExternalApprovalDecision::Deny { remember: false }), + "settlement must deny through the decision channel; got {decision:?}" + ); + let events = manager.events_since(&thread.id, None)?; + assert!( + events.iter().any(|event| { + event.event == "approval.decided" + && event.payload.get("approval_id").and_then(Value::as_str) == Some("tool_stranded") + && event.payload.get("decision").and_then(Value::as_str) == Some("deny") + && event.payload.get("interrupted").and_then(Value::as_bool) == Some(true) + }), + "monitor-death settlement should emit approval.decided with interrupted=true" + ); + + Ok(()) +} + +#[tokio::test] +async fn settle_claimed_turn_failure_publishes_when_the_decision_receiver_is_gone() -> Result<()> { + // In production the dead monitor takes the oneshot receiver with it. A + // client decision arriving after that must not take the entry (its send + // could not deliver, and nothing would ever publish a resolution); the + // settlement must then publish exactly one `approval.decided`. + let manager = test_manager(test_runtime_dir())?; + let thread = manager + .create_thread(CreateThreadRequest::default()) + .await?; + let receiver = + manager.register_pending_approval_for_thread_for_test(&thread.id, "tool_dead_rx"); + drop(receiver); + + assert!( + !manager.deliver_external_approval( + "tool_dead_rx", + ExternalApprovalDecision::Allow { remember: false } + ), + "a decision for a dead waiter must report not delivered" + ); + assert_eq!( + manager.pending_approvals_count(), + 1, + "the entry must stay for the failure settlement" + ); + + manager + .settle_claimed_turn_failure(&thread.id, "test-turn", "forced monitor failure") + .await; + + assert_eq!(manager.pending_approvals_count(), 0); + let events = manager.events_since(&thread.id, None)?; + let resolutions: Vec<_> = events + .iter() + .filter(|event| { + event.event == "approval.decided" + && event.payload.get("approval_id").and_then(Value::as_str) == Some("tool_dead_rx") + }) + .collect(); + assert_eq!( + resolutions.len(), + 1, + "exactly one resolution must be published" + ); + assert_eq!( + resolutions[0] + .payload + .get("decision") + .and_then(Value::as_str), + Some("deny") + ); + assert_eq!( + resolutions[0] + .payload + .get("interrupted") + .and_then(Value::as_bool), + Some(true) + ); + + Ok(()) +} + #[tokio::test] async fn approval_decision_queued_before_shutdown_is_honored_not_interrupted() -> Result<()> { // The wait's select favors the cancel token, but a decision already @@ -12385,3 +12492,69 @@ fn restart_rebuild_skips_legacy_tool_items_without_identity() -> Result<()> { let _ = std::fs::remove_dir_all(dir); Ok(()) } + +#[test] +fn interrupt_rescue_honors_a_decision_sent_before_the_close() { + let (tx, mut rx) = oneshot::channel(); + assert!( + tx.send(ExternalApprovalDecision::Allow { remember: false }) + .is_ok() + ); + assert!(matches!( + rescue_decision_after_interrupt(&mut rx), + Some(ExternalApprovalDecision::Allow { remember: false }) + )); +} + +#[test] +fn interrupt_rescue_makes_a_later_send_report_not_delivered() { + let (tx, mut rx) = oneshot::channel(); + assert!(rescue_decision_after_interrupt(&mut rx).is_none()); + assert!( + tx.send(ExternalApprovalDecision::Allow { remember: false }) + .is_err(), + "a decision racing the interrupt must fail rather than be accepted and discarded" + ); +} + +#[tokio::test] +async fn a_waiter_never_removes_a_live_approval_that_reuses_its_id() -> Result<()> { + let manager = test_manager(test_runtime_dir())?; + let thread = manager + .create_thread(CreateThreadRequest::default()) + .await?; + let _live = manager.register_pending_approval_for_thread_for_test(&thread.id, "call_0"); + manager.cancel_closed_pending_approval("call_0"); + assert_eq!( + manager.pending_approvals_count(), + 1, + "an entry whose receiver is still listening belongs to a live waiter" + ); + Ok(()) +} + +#[tokio::test] +async fn the_emit_failure_rollback_never_evicts_a_foreign_same_id_entry() -> Result<()> { + // Providers reuse tool-call ids across threads. The + // `approval.required`-emit-failure rollback removes its own + // registration; under a reused id the map entry may already belong to + // another thread's live waiter, and a blanket remove would strand it — + // the rollback may only take a same-thread match. + let manager = test_manager(test_runtime_dir())?; + let foreign = manager + .create_thread(CreateThreadRequest::default()) + .await?; + let mine = manager + .create_thread(CreateThreadRequest::default()) + .await?; + let _live = manager.register_pending_approval_for_thread_for_test(&foreign.id, "call_0"); + manager.cancel_thread_pending_approval("call_0", &mine.id); + assert_eq!( + manager.pending_approvals_count(), + 1, + "a foreign thread's live entry must survive the rollback" + ); + manager.cancel_thread_pending_approval("call_0", &foreign.id); + assert_eq!(manager.pending_approvals_count(), 0); + Ok(()) +} diff --git a/crates/tui/src/sandbox/backend.rs b/crates/tui/src/sandbox/backend.rs index 8781081d55..1da8ad10c4 100644 --- a/crates/tui/src/sandbox/backend.rs +++ b/crates/tui/src/sandbox/backend.rs @@ -72,9 +72,12 @@ use crate::config::Config; /// client-level deadline. 600s matches the interpreter tools' execution cap /// (js/code/plugin scripts) — a remote sandbox command is the same class of /// work (builds, test runs), and the previous hardcoded 30s cut legitimate -/// long commands off at the HTTP layer with no way to raise it. The Bash -/// tool keeps its own much larger cap; this bound is the client-side backstop -/// for the remote-exec transport, not a per-command policy. +/// long commands off at the HTTP layer with no way to raise it. This bound +/// is the client-side backstop for the remote-exec transport, not a +/// per-command policy: local foreground Bash clamps at the same 600s, the +/// `bash` tool's explicit contract timeout can run far longer, and the +/// external-backend path does not consume the tool timeout at all (the +/// transport is the only bound it sees). const OPEN_SANDBOX_EXEC_TIMEOUT_SECS: u64 = 600; /// Create the configured sandbox backend from config. diff --git a/crates/tui/src/snapshot/paths.rs b/crates/tui/src/snapshot/paths.rs index 60d80e7644..10ee5bddd1 100644 --- a/crates/tui/src/snapshot/paths.rs +++ b/crates/tui/src/snapshot/paths.rs @@ -13,8 +13,9 @@ use std::path::{Path, PathBuf}; /// /// Returns `$STATE_DIR/snapshots///` where /// `$STATE_DIR` is resolved via `codewhale_config::resolve_state_dir`. -/// The caller is responsible for creating it on disk; we purposefully -/// don't touch the filesystem here so this is cheap to call repeatedly. +/// The caller is responsible for creating it on disk. Resolution is not +/// free: it runs the workspace canonicalization under a bounded probe +/// (see below), so callers on hot paths should cache the result. /// /// The `project_hash` is derived from the canonicalized workspace path /// after stripping any `.worktrees/` suffix — multiple worktrees @@ -29,9 +30,19 @@ pub fn snapshot_dir_for(workspace: &Path) -> PathBuf { /// Used by tests so they never touch the user's real state directory. pub fn snapshot_dir_with_home(workspace: &Path, home: Option) -> PathBuf { let home = home.unwrap_or_else(|| PathBuf::from(".")); - let canonical = workspace - .canonicalize() - .unwrap_or_else(|_| workspace.to_path_buf()); + // The canonicalization here is the bounded probe, not an assumption + // that a caller already canonicalized the workspace: any path reaching + // this function gets the same bound. On a wedged mount it fails fast + // to the raw-path fallback, and for an already canonical input the + // raw path hashes identically. + let canonical = super::repo::canonicalize_bounded( + workspace, + super::repo::WORKSPACE_PROBE_TIMEOUT, + ) + .unwrap_or_else(|err| { + tracing::warn!(target: "snapshot", "workspace canonicalization fell back to the raw path: {err}"); + workspace.to_path_buf() + }); let project_root = strip_worktree_suffix(&canonical); let project_hash = stable_hex(&project_root); let worktree_hash = stable_hex(&canonical); diff --git a/crates/tui/src/snapshot/repo.rs b/crates/tui/src/snapshot/repo.rs index 1f215972e0..628ec66a47 100644 --- a/crates/tui/src/snapshot/repo.rs +++ b/crates/tui/src/snapshot/repo.rs @@ -64,9 +64,13 @@ const STALE_TMP_PACK_AGE: Duration = Duration::from_secs(60 * 60); /// [`GIT_COMMAND_TIMEOUT`], and a SIGKILL on timeout cannot run git's lock /// cleanup — without this, one wedged `git add -A` poisons every later /// snapshot with a fast-failing lock. The side repo is private to this -/// module, so a lock older than the command bound cannot belong to a live -/// writer of ours; one hour (matching [`STALE_TMP_PACK_AGE`]) leaves wide -/// margin. +/// module, so outside a wedged mount no lock older than the command bound +/// can belong to a live writer of ours. One known exception: a git stuck in +/// uninterruptible I/O can hold the lock far past any bound — removing that +/// lock is benign (the holder's final rename fails with ENOENT, an error +/// rather than index corruption), and the alternative is every later +/// snapshot fast-failing for as long as the mount stays wedged. One hour +/// (matching [`STALE_TMP_PACK_AGE`]) leaves wide margin. const STALE_INDEX_LOCK_AGE: Duration = Duration::from_secs(60 * 60); /// Maximum total snapshot storage in megabytes before pruning kicks in at @@ -210,11 +214,13 @@ impl SnapshotRepo { /// availability without paying the first-init size walk or surprising the /// user by creating a side repo from a view action. pub fn open_existing(workspace: &Path) -> io::Result> { - let work_tree = workspace - .canonicalize() - .unwrap_or_else(|_| workspace.to_path_buf()); + // Read-only availability surface: a wedged mount must not hang the + // UI, but it must not read as "no snapshots" either — both callers + // have an `Err` arm that reports the reason ("could not be + // opened"), so surface the probe failure instead of swallowing it. + let work_tree = canonicalize_bounded(workspace, WORKSPACE_PROBE_TIMEOUT)?; let git_dir = snapshot_git_dir(&work_tree); - if !git_dir.exists() || !git_dir.join("HEAD").exists() { + if !side_repo_is_ready(&git_dir) { return Ok(None); } Ok(Some(Self { git_dir, work_tree })) @@ -241,13 +247,22 @@ impl SnapshotRepo { /// "workspace too large" reason. Subsequent calls (after the user /// shrinks the workspace or raises the cap via config) succeed. pub fn open_or_init_with_cap(workspace: &Path, cap_bytes: u64) -> io::Result { - let work_tree = workspace - .canonicalize() - .unwrap_or_else(|_| workspace.to_path_buf()); - if let Some(reason) = unsafe_workspace_snapshot_reason( + // A wedged workspace mount must fail the open (degrading snapshots + // with the usual notice) instead of parking the turn pipeline here, + // before the bounded git core ever runs. + let work_tree = canonicalize_bounded(workspace, WORKSPACE_PROBE_TIMEOUT)?; + // The safety classifier resolves the workspace again (and HOME, twice) + // with plain syscalls — an unbounded window between the probe that + // just succeeded and git, on the very mount the probe bounds. Run + // the whole check under the same bound so this leg, like every leg + // of the bounded open path, degrades within its own budget instead + // of parking there. + let reason = snapshot_safety_reason_bounded( &work_tree, crate::config::effective_home_dir().as_deref(), - ) { + WORKSPACE_PROBE_TIMEOUT, + )?; + if let Some(reason) = reason { return Err(io::Error::new( io::ErrorKind::InvalidInput, format!( @@ -260,30 +275,91 @@ impl SnapshotRepo { let _ = ensure_snapshot_dir(&work_tree)?; let git_dir = snapshot_git_dir(&work_tree); - let needs_init = !git_dir.exists(); + // A timed-out `git init` can leave `.git` half-written (git creates + // the directory before HEAD, and HEAD before `objects/`; on a wedged + // mount the kill lands wherever the stall was), which would + // otherwise skip init forever and fail every later snapshot with + // "not a git repository". Use the same readiness predicate as + // `open_existing` and re-init — `git init` is idempotent and fills + // in whatever is missing. + // `first_init` is "this workspace has no side repo at all"; + // `needs_init` additionally covers a `.git` that exists but is not + // ready. The two are deliberately separate: the size guard is a + // *first*-init gate, and charging it to the repair path would re-pay + // a full workspace walk on every snapshot attempt for as long as the + // repair keeps failing. + let first_init = !git_dir.exists(); + let needs_init = first_init || !side_repo_is_ready(&git_dir); if needs_init { - // First-init size guard. Skipping this on subsequent opens - // is intentional: paying a workspace walk on every snapshot - // would defeat the purpose of the cap, and a workspace - // that fit on first init is allowed to grow within the - // existing repo's `MAX_SNAPSHOT_SIZE_MB` budget. Users on - // workspaces that grew past the cap mid-session get the - // existing aggressive-pruning path in `snapshot()`. - if estimate_workspace_size_bounded(&work_tree, cap_bytes).is_none() { - return Err(io::Error::new( - io::ErrorKind::InvalidInput, - format!( - "workspace too large for snapshots (over {} GB of non-excluded content or > {} entries): {}\n raise `[snapshots] max_workspace_gb` in config.toml (or set it to 0 to disable the cap) if you want snapshots on this workspace.", - cap_bytes / (1024 * 1024 * 1024), - SIZE_WALK_MAX_ENTRIES, - work_tree.display() - ), - )); + // First-init size guard, on genuine first inits only. + // `cap_bytes == 0` disables the gate entirely (the documented + // `[snapshots] max_workspace_gb = 0` opt-out), so the walk — and + // its timeout with it — is skipped too: a workspace too large to + // walk within SIZE_WALK_TIMEOUT must still be able to snapshot + // once the user opted out. Skipping the walk on subsequent + // capped opens is intentional: paying a workspace walk on every + // snapshot would defeat the purpose of the cap, and a workspace + // that fit on first init is allowed to grow within the existing + // repo's `MAX_SNAPSHOT_SIZE_MB` budget. Users on workspaces that + // grew past the cap mid-session get the existing + // aggressive-pruning path in `snapshot()`. + if cap_bytes > 0 && first_init { + let sized = { + let work_tree = work_tree.clone(); + run_bounded_fs( + "first-init workspace size walk", + SIZE_WALK_TIMEOUT, + move || estimate_workspace_size_bounded(&work_tree, cap_bytes), + ) + }; + if let Err(err) = sized { + // Preserve the TimedOut kind: the turn pipeline's + // degraded-snapshots notice gates on it, so re-wrapping + // as `io::Error::other` would swallow the user-visible + // wedge warning into the tracing log. + return Err(io::Error::new( + err.kind(), + format!("first-init workspace scan failed: {err}"), + )); + } + if sized.unwrap().is_none() { + return Err(io::Error::new( + io::ErrorKind::InvalidInput, + format!( + "workspace too large for snapshots (over {} GB of non-excluded content or > {} entries): {}\n raise `[snapshots] max_workspace_gb` in config.toml (or set it to 0 to disable the cap) if you want snapshots on this workspace.", + cap_bytes / (1024 * 1024 * 1024), + SIZE_WALK_MAX_ENTRIES, + work_tree.display() + ), + )); + } } let parent = git_dir.parent().ok_or_else(|| { io::Error::new(io::ErrorKind::InvalidInput, "snapshot dir has no parent") })?; std::fs::create_dir_all(parent)?; + // A killed `git init` holds `.git/config.lock` while it writes + // `core.repositoryformatversion` and `.git/HEAD.lock` while it + // writes HEAD, so the interrupted init that leaves us here can + // leave either lock behind — and `git init` then fails on it on + // every later attempt, making the repair above permanently + // ineffective. Nothing else can clear them: git never ages + // lockfiles out. Sweep both on the same staleness rule as + // `index.lock`, before the init rather than after. + for lock in ["config.lock", "HEAD.lock"] { + match clear_stale_lock(&git_dir.join(lock), STALE_INDEX_LOCK_AGE) { + Ok(true) => tracing::warn!( + target: "snapshot", + "removed a stale {lock} from the snapshot side repo; a previous \ + git init was interrupted and left it behind" + ), + Ok(false) => {} + Err(err) => tracing::debug!( + target: "snapshot", + "failed to clear a stale snapshot {lock}: {err}" + ), + } + } // `git init` here uses the parent directory as the work tree // and stores metadata in `.git`. Every later command targets the // side repo through the GIT_DIR / GIT_WORK_TREE environment @@ -291,20 +367,37 @@ impl SnapshotRepo { // must ignore an ambient GIT_DIR/GIT_WORK_TREE exported by the // launching shell — it would redirect the one-time init away // from the hashed side-repo path. - let mut init_cmd = crate::dependencies::Git::command() - .ok_or_else(|| io_other("git not found on PATH"))?; + let mut init_cmd = crate::dependencies::Git::command().ok_or_else(|| { + // Same kind as `run_git`'s arm for the same condition, so + // kind-matching consumers see one shape for "no git". + io::Error::new(io::ErrorKind::NotFound, "git not found on PATH") + })?; init_cmd .arg("init") .arg("--quiet") .arg(parent) .env_remove("GIT_DIR") .env_remove("GIT_WORK_TREE"); - let init = run_bounded_git(&mut init_cmd, "init") - .map_err(|e| io_other(format!("failed to run git init: {e}")))?; + let init = run_bounded_git(&mut init_cmd, "init").map_err(|e| { + // Preserve the TimedOut kind, same contract as the size-walk + // re-wrap above: the turn pipeline's degraded-snapshots + // notice gates on it, so flattening it to `io::Error::other` + // would hide the wedge warning in the tracing log. + io::Error::new(e.kind(), format!("failed to run git init: {e}")) + })?; if !init.status.success() { + // Carries `GIT_INIT_FAILED_MARKER` so the turn pipeline + // surfaces it: this failure repeats on every attempt (a + // lock the sweep above could not clear because it is still + // fresh, a permission problem), which means undo history is + // off until the user acts. Reporting that only to tracing + // is the silent-disable failure mode. return Err(io_other(format!( - "git init failed: {}", - String::from_utf8_lossy(&init.stderr).trim() + "{GIT_INIT_FAILED_MARKER}: {}", + git_stderr_tail( + String::from_utf8_lossy(&init.stderr).trim(), + GIT_STDERR_TAIL_CHARS + ) ))); } @@ -346,6 +439,19 @@ impl SnapshotRepo { "failed to clean a stale snapshot index.lock: {err}" ), } + match clear_stale_ref_locks(&git_dir, STALE_INDEX_LOCK_AGE) { + Ok(0) => {} + Ok(n) => tracing::warn!( + target: "snapshot", + "removed {n} stale ref-update lock(s) from the snapshot side repo; a \ + previous git update-ref was interrupted and snapshots were silently \ + failing since then" + ), + Err(err) => tracing::debug!( + target: "snapshot", + "failed to clean stale snapshot ref locks: {err}" + ), + } Ok(Self { git_dir, work_tree }) } @@ -551,7 +657,9 @@ impl SnapshotRepo { // deliberately not a `/undo` or `revert_turn` candidate label, so the // safety net never changes snapshot selection. Best-effort: a failed // safety snapshot must never block the restore the user asked for. - let target_short = &id.as_str()[..id.as_str().len().min(12)]; + // ids are git-produced hex, so the byte slice is char-safe today; + // `get` keeps it panic-free if that ever changes. + let target_short = id.as_str().get(..12).unwrap_or(id.as_str()); if let Err(e) = self.snapshot_with_session(&format!("pre-restore:{target_short}"), None) { tracing::warn!( target: "snapshot", @@ -605,6 +713,16 @@ impl SnapshotRepo { String::from_utf8_lossy(&ls.stderr).trim() ))); } + if capture_hit_the_cap(&ls.stdout) { + // A truncated listing would make restore compute a wrong + // deletion set (paths missing from the truncated target side + // are treated as "not in the snapshot" and removed), so fail + // before the checkout instead of deleting by a partial truth. + return Err(io_other( + "git ls-tree output exceeded the capture cap; refusing to \ + derive a restore diff from a truncated path listing", + )); + } Ok(parse_nul_paths(&ls.stdout)) } @@ -657,8 +775,34 @@ impl SnapshotRepo { let arg_refs: Vec<&str> = args.iter().map(String::as_str).collect(); let log = run_git(&self.git_dir, &self.work_tree, &arg_refs)?; if !log.status.success() { - // No commits yet → empty list. - return Ok(Vec::new()); + // No commits yet → empty list. Anything else is a broken side + // repo, and reporting it as "no restore points" would hide the + // loss of undo history. `rev-parse --verify -q` exits 1 for an + // unborn HEAD and 128 when git cannot use the repository. + let head = run_git( + &self.git_dir, + &self.work_tree, + &["rev-parse", "--verify", "-q", "HEAD"], + )?; + if head.status.code() == Some(1) { + return Ok(Vec::new()); + } + return Err(io_other(format!( + "git log failed: {}", + git_stderr_tail( + String::from_utf8_lossy(&log.stderr).trim(), + GIT_STDERR_TAIL_CHARS + ) + ))); + } + if capture_hit_the_cap(&log.stdout) { + // A truncated history would end with a half-parsed pseudo + // entry; reporting a partial snapshot list as truth could send + // `/undo` to a fabricated cursor. + return Err(io_other( + "git log output exceeded the capture cap; refusing to \ + report a truncated snapshot history", + )); } let stdout = String::from_utf8_lossy(&log.stdout); let mut out = Vec::new(); @@ -977,18 +1121,31 @@ fn cleanup_stale_pack_temps(git_dir: &Path, stale_age: Duration) -> io::Result bool { + git_dir.join("HEAD").is_file() + && git_dir.join("objects").is_dir() + && git_dir.join("refs").is_dir() +} + /// Remove `/index.lock` when it is older than `stale_age`. Returns /// whether a stale lock was removed. A fresh lock (any age below the bound) /// is left alone: it may belong to a git that is still running. fn clear_stale_index_lock(git_dir: &Path, stale_age: Duration) -> io::Result { - clear_stale_index_lock_in(&git_dir.join("index.lock"), stale_age, SystemTime::now()) + clear_stale_lock(&git_dir.join("index.lock"), stale_age) } -fn clear_stale_index_lock_in( - lock_path: &Path, - stale_age: Duration, - now: SystemTime, -) -> io::Result { +/// Same rule for any git lockfile. `config.lock` and `HEAD.lock` need it +/// too: an interrupted `git init` can leave either behind and git never +/// ages them out, so without a sweep the side repo can never be repaired. +fn clear_stale_lock(lock_path: &Path, stale_age: Duration) -> io::Result { + clear_stale_lock_in(lock_path, stale_age, SystemTime::now()) +} + +fn clear_stale_lock_in(lock_path: &Path, stale_age: Duration, now: SystemTime) -> io::Result { let Ok(metadata) = std::fs::metadata(lock_path) else { return Ok(false); }; @@ -1011,6 +1168,57 @@ fn clear_stale_index_lock_in( } } +/// Sweep stale ref-update locks (`HEAD.lock`, `refs/heads/**.lock`, +/// `packed-refs.lock`). `update-ref HEAD` at commit time takes the HEAD lock +/// and the resolved branch's lock, and `pack-refs` takes `packed-refs.lock`; +/// a git killed mid-update can leave any one of them behind (the locks are +/// taken one after another, so a kill between them leaves a lone file) and, +/// like every git lockfile, nothing but this sweep ages it out — every later +/// snapshot would then fail at the ref update with the loss surfacing +/// nowhere. `HEAD.lock` needs its own entry here because a leftover lock +/// does not make the repo unready, so the init-path sweep never sees it on +/// an already-initialized side repo. Returns how many stale locks were +/// removed. +fn clear_stale_ref_locks(git_dir: &Path, stale_age: Duration) -> io::Result { + let mut swept = 0; + if clear_stale_lock(&git_dir.join("HEAD.lock"), stale_age)? { + swept += 1; + } + if clear_stale_lock(&git_dir.join("packed-refs.lock"), stale_age)? { + swept += 1; + } + swept += clear_stale_ref_locks_in(&git_dir.join("refs").join("heads"), stale_age, 0)?; + Ok(swept) +} + +/// Branch ref locks live one directory level per path segment +/// (`refs/heads/feature/foo.lock`); the walk is depth-capped so a corrupt +/// refs tree cannot turn the snapshot-open sweep into an unbounded +/// traversal. +fn clear_stale_ref_locks_in(dir: &Path, stale_age: Duration, depth: u8) -> io::Result { + const MAX_REF_LOCK_DEPTH: u8 = 16; + let entries = match std::fs::read_dir(dir) { + Ok(entries) => entries, + Err(err) if err.kind() == io::ErrorKind::NotFound => return Ok(0), + Err(err) => return Err(err), + }; + let mut swept = 0; + for entry in entries { + let entry = entry?; + let path = entry.path(); + if entry.file_type()?.is_dir() { + if depth < MAX_REF_LOCK_DEPTH { + swept += clear_stale_ref_locks_in(&path, stale_age, depth + 1)?; + } + } else if path.extension().is_some_and(|ext| ext == "lock") + && clear_stale_lock(&path, stale_age)? + { + swept += 1; + } + } + Ok(swept) +} + fn cleanup_stale_pack_temps_in( pack_dir: &Path, stale_age: Duration, @@ -1073,6 +1281,26 @@ const GIT_PIPE_DRAIN_GRACE: Duration = Duration::from_secs(2); /// the peek-poll cadence for data on an otherwise quiet pipe. const GIT_PIPE_READER_POLL: Duration = Duration::from_millis(50); +/// Cap on the bytes a git pipe reader retains per stream. The readers keep +/// polling to EOF regardless, so cancellation still works and the drain +/// grace still bounds the wait — only the capture stops growing. Legitimate +/// git output here is status lines and a snapshot listing; anything past +/// this is a runaway (e.g. a hook spamming stderr), not a result. +const GIT_CAPTURE_CAP: usize = 16 * 1024 * 1024; + +/// Appended in place when the cap stops a capture mid-stream, so a tail +/// reader sees the truncation instead of a silently cut output. +const GIT_CAPTURE_CAP_NOTE: &[u8] = + b"\n[codewhale] git output capture stopped at the size cap; later output was dropped\n"; + +/// True when a bounded-git capture stopped at the size cap. Parsers that +/// make decisions from a captured stdout (the restore diff's path +/// listings, the snapshot history) must refuse a truncated capture +/// instead of treating its missing tail as ground truth. +fn capture_hit_the_cap(bytes: &[u8]) -> bool { + bytes.ends_with(GIT_CAPTURE_CAP_NOTE) +} + /// Number of bounded-git pipe readers currently running. The thread-leak /// regression uses this to prove a cancelled reader actually exits: a /// reader detached while blocked on a grandchild-held pipe would keep this @@ -1153,7 +1381,12 @@ fn drain_git_pipe( Ok(0) => return, Ok(n) => { if let Ok(mut buf) = buf.lock() { - buf.extend_from_slice(&chunk[..n]); + let remaining = GIT_CAPTURE_CAP.saturating_sub(buf.len()); + let retained = n.min(remaining); + buf.extend_from_slice(&chunk[..retained]); + if retained < n && !buf.ends_with(GIT_CAPTURE_CAP_NOTE) { + buf.extend_from_slice(GIT_CAPTURE_CAP_NOTE); + } } } Err(err) if err.kind() == ErrorKind::WouldBlock => continue, @@ -1219,7 +1452,12 @@ fn drain_git_pipe( Ok(0) => return, Ok(n) => { if let Ok(mut buf) = buf.lock() { - buf.extend_from_slice(&chunk[..n]); + let remaining = GIT_CAPTURE_CAP.saturating_sub(buf.len()); + let retained = n.min(remaining); + buf.extend_from_slice(&chunk[..retained]); + if retained < n && !buf.ends_with(GIT_CAPTURE_CAP_NOTE) { + buf.extend_from_slice(GIT_CAPTURE_CAP_NOTE); + } } } Err(err) if err.kind() == ErrorKind::Interrupted => continue, @@ -1228,11 +1466,36 @@ fn drain_git_pipe( } } +/// Characters of git stderr kept in timeout and failure details — the +/// diagnostics closest to the wedge, not the whole firehose. +const GIT_STDERR_TAIL_CHARS: usize = 500; + +/// Keep the last `limit` characters (the diagnostics closest to the +/// wedge), prefixed with `…`, character-boundary safe by construction. +fn git_stderr_tail(all: &str, limit: usize) -> String { + if all.chars().count() > limit { + let tail: String = all + .chars() + .rev() + .take(limit) + .collect::() + .chars() + .rev() + .collect(); + format!("…{tail}") + } else { + all.to_string() + } +} + /// Run a pre-configured git command under [`GIT_COMMAND_TIMEOUT`] with both /// pipes drained concurrently. Every git invocation in this module goes /// through here (or the thin [`run_git`] wrapper), so a wedged git — /// stalled NFS/FUSE, hung hook, uninterruptible kernel I/O — degrades the -/// snapshot with an error instead of hanging the turn pipeline. +/// snapshot with an error instead of hanging the turn pipeline. The +/// pre-git blocking probes (`canonicalize`, the first-init size walk) are +/// bounded the same way by [`run_bounded_fs`], so the whole snapshot open +/// path degrades instead of hanging on the wedged mount. /// /// The timeout path kills the child and reaps it on a detached thread: on a /// hard-wedged mount git can sit in uninterruptible kernel I/O where even @@ -1248,8 +1511,11 @@ fn run_bounded_git(cmd: &mut std::process::Command, subcommand: &str) -> io::Res // Drain both pipes while waiting: the restore path's `ls-tree -r` emits // output that grows with workspace size, and a child blocked on a full // pipe buffer would never exit, turning every such call into a - // guaranteed timeout. Mirrors the sandbox exec plumbing in - // crate::run_sandbox_command. + // guaranteed timeout. This is the reference implementation of that + // shape; `crate::run_sandbox_command` (the standalone sandbox CLI) and + // the tokio-side `crate::tools::process::run_bounded_child` are the + // siblings, and the sandbox CLI still owes this file's cancellable + // readers and detached reap (tracked follow-up debt). // Readers stream into shared buffers so a grace expiry below can still // return what was captured; the completion channels carry a () once // each reader has seen EOF. The readers are cancellable (see @@ -1287,28 +1553,53 @@ fn run_bounded_git(cmd: &mut std::process::Command, subcommand: &str) -> io::Res }) }; - let Some(status) = child.wait_timeout(GIT_COMMAND_TIMEOUT)? else { - let _ = child.kill(); - // Reap off the pipeline thread (see the doc comment): the kernel may - // not deliver the kill until an uninterruptible syscall returns. - std::thread::spawn(move || { - let _ = child.wait(); - }); - // Cancel and join the readers: killing the child closes only the - // child's write ends, and a grandchild that inherited the pipes - // would hold a plain reader open forever. A cancelled reader ends - // within one poll interval, so the joins are bounded — see - // [`drain_git_pipe`]. - cancel.store(true, std::sync::atomic::Ordering::Relaxed); - let _ = stdout_thread.join(); - let _ = stderr_thread.join(); - return Err(io::Error::new( - io::ErrorKind::TimedOut, - format!( - "git {subcommand} timed out after {}s", - GIT_COMMAND_TIMEOUT.as_secs() - ), - )); + let status = match child.wait_timeout(GIT_COMMAND_TIMEOUT) { + Ok(Some(status)) => status, + Ok(None) => { + let _ = child.kill(); + // Reap off the pipeline thread (see the doc comment): the kernel may + // not deliver the kill until an uninterruptible syscall returns. + std::thread::spawn(move || { + let _ = child.wait(); + }); + // Cancel and join the readers: killing the child closes only the + // child's write ends, and a grandchild that inherited the pipes + // would hold a plain reader open forever. A cancelled reader ends + // within one poll interval, so the joins are bounded — see + // [`drain_git_pipe`]. + cancel.store(true, std::sync::atomic::Ordering::Relaxed); + let _ = stdout_thread.join(); + let _ = stderr_thread.join(); + // The readers captured whatever the child managed to say before + // it wedged — hook and clean-filter diagnostics are exactly what + // explains a timeout, so surface the tail instead of losing it. + let stderr_all = + String::from_utf8_lossy(&stderr_buf.lock().map(|b| b.clone()).unwrap_or_default()) + .trim() + .to_string(); + let stderr_tail = git_stderr_tail(&stderr_all, GIT_STDERR_TAIL_CHARS); + let marker = git_timeout_marker(subcommand); + let detail = if stderr_tail.is_empty() { + format!("{marker} after {}s", GIT_COMMAND_TIMEOUT.as_secs()) + } else { + format!( + "{marker} after {}s: {stderr_tail}", + GIT_COMMAND_TIMEOUT.as_secs() + ) + }; + return Err(io::Error::new(io::ErrorKind::TimedOut, detail)); + } + // The wait itself failed (only `try_wait`/poll hard errors reach + // here). Cancel and join before propagating so this exit leaves no + // reader threads behind either; the std child has no kill_on_drop, + // so also signal it explicitly instead of leaking it on drop. + Err(e) => { + cancel.store(true, std::sync::atomic::Ordering::Relaxed); + let _ = child.kill(); + let _ = stdout_thread.join(); + let _ = stderr_thread.join(); + return Err(e); + } }; // Wait for the readers up to the grace, then cancel and join them. A // clean git already closed its write ends so the readers deliver @@ -1369,6 +1660,44 @@ fn io_other(msg: impl Into) -> io::Error { io::Error::other(msg.into()) } +#[cfg(test)] +mod git_stderr_tail_tests { + use super::git_stderr_tail; + + #[test] + fn short_output_passes_through_trimmed_by_the_caller() { + assert_eq!( + git_stderr_tail("fatal: bad object", 500), + "fatal: bad object" + ); + } + + #[test] + fn empty_output_stays_empty() { + assert_eq!(git_stderr_tail("", 500), ""); + } + + #[test] + fn long_output_keeps_the_last_500_characters_with_an_ellipsis() { + let all = format!("head{}tail", "x".repeat(600)); + let tail = git_stderr_tail(&all, 500); + assert!(tail.starts_with('…')); + assert_eq!(tail.chars().count(), 501); + assert!(tail.ends_with("tail")); + assert!(!tail.contains("head")); + } + + #[test] + fn truncation_never_splits_a_multibyte_character() { + // 300 CJK characters = 900 bytes; keep the last 100 characters. + let all = "漢".repeat(300); + let tail = git_stderr_tail(&all, 100); + assert_eq!(tail.chars().count(), 101); + assert!(tail.starts_with('…')); + assert!(tail.chars().skip(1).all(|c| c == '漢')); + } +} + #[cfg(all(test, unix))] mod bounded_git_tests { use super::*; @@ -1429,6 +1758,25 @@ mod bounded_git_tests { // reader detached instead of joined would only end when the // unrelated grandchild exited, accumulating one thread per pipe per // call. + // Settle before sampling: a baseline captured while unrelated + // readers are still draining is *higher* than the true idle count, + // and the check below would then accept this test's own leaked + // readers as long as the transient ones went away. Wait for the + // counter to hold still, so the baseline is a real floor. + let baseline = { + let settle_by = std::time::Instant::now() + Duration::from_secs(5); + let mut last = LIVE_GIT_PIPE_READERS.load(Ordering::Relaxed); + let mut stable = 0; + loop { + std::thread::sleep(Duration::from_millis(20)); + let now = LIVE_GIT_PIPE_READERS.load(Ordering::Relaxed); + stable = if now == last { stable + 1 } else { 0 }; + last = now; + if stable >= 3 || std::time::Instant::now() >= settle_by { + break last; + } + } + }; for _ in 0..2 { let mut sh = std::process::Command::new("sh"); sh.arg("-c") @@ -1447,13 +1795,14 @@ mod bounded_git_tests { output.stderr ); } - // The live-reader count must drain back to zero. Other tests in - // this binary drive the same core concurrently, so wait briefly for - // their in-flight readers to finish as well; a reverted detach - // would keep this test's own four readers pinned on the - // `sleep 300` pipes for its whole 300s and fail here. - let deadline = std::time::Instant::now() + Duration::from_secs(5); - while LIVE_GIT_PIPE_READERS.load(Ordering::Relaxed) != 0 { + // This call's own readers must be gone. Other tests in this binary + // drive the same core concurrently, so compare against the settled + // baseline instead of demanding a global zero: a reverted detach + // keeps this test's own four readers pinned on the `sleep 300` pipes + // for its whole 300s and fails here, while unrelated concurrent git + // calls only add transient readers that drain within milliseconds. + let deadline = std::time::Instant::now() + Duration::from_secs(30); + while LIVE_GIT_PIPE_READERS.load(Ordering::Relaxed) > baseline { assert!( std::time::Instant::now() < deadline, "cancelled pipe readers must be joined, not detached; {} still running", @@ -1462,6 +1811,28 @@ mod bounded_git_tests { std::thread::sleep(Duration::from_millis(20)); } } + + #[test] + fn run_git_appends_the_cap_note_when_output_exceeds_the_capture_cap() { + let _serial = bounded_git_test_lock(); + // 17 MiB through real pipes: the drain must keep reading to EOF + // (the child still exits promptly) while retaining only the cap, + // and the captured tail must say so — the restore-diff and history + // parsers key on exactly that note. + let mut cmd = std::process::Command::new("sh"); + cmd.arg("-c").arg("head -c 17000000 /dev/zero"); + let output = run_bounded_git(&mut cmd, "head").expect("bounded run"); + assert!(output.status.success()); + assert!( + capture_hit_the_cap(&output.stdout), + "a capped capture must end with the cap note" + ); + assert!( + output.stdout.len() <= GIT_CAPTURE_CAP + GIT_CAPTURE_CAP_NOTE.len(), + "the capture must stop at the cap, got {} bytes", + output.stdout.len() + ); + } } /// Walk `workspace` and accumulate file sizes, returning `Some(total)` @@ -1536,6 +1907,108 @@ fn unsafe_workspace_snapshot_reason(workspace: &Path, home: Option<&Path>) -> Op None } +/// Bounds for the blocking filesystem probes that run before the bounded +/// git core. On a wedged NFS/FUSE workspace these plain calls would +/// otherwise park the turn pipeline exactly where the git bounds cannot +/// reach; on expiry the call errors out and the helper thread is abandoned +/// (it ends when the mount does — the same contract as the detached git +/// reap). +pub(super) const WORKSPACE_PROBE_TIMEOUT: Duration = Duration::from_secs(30); +const SIZE_WALK_TIMEOUT: Duration = Duration::from_secs(120); + +/// Marker phrase every bounded-probe expiry carries. The turn pipeline +/// routes its remedy hint on this exact text, so both sides read it from +/// here: rewording it updates the producer, the router, and their tests +/// together instead of silently sending users to the wrong remedy. +pub(crate) const WEDGED_FS_MARKER: &str = "the filesystem appears wedged"; + +/// Marker phrase a [`run_bounded_git`] expiry carries, per subcommand. Same +/// contract as [`WEDGED_FS_MARKER`]: the hint router builds the needle from +/// this function rather than hardcoding the shape. +pub(crate) fn git_timeout_marker(subcommand: &str) -> String { + format!("git {subcommand} timed out") +} + +/// Marker phrase a non-zero-status `git init` carries. A partially written +/// side repo (a `config.lock` the sweep could not clear, a permission +/// problem) fails here on every attempt, so this one has to reach the user +/// rather than only the tracing log. +pub(crate) const GIT_INIT_FAILED_MARKER: &str = "git init failed"; + +/// Render a probe bound for humans without truncating sub-second values to +/// a meaningless `0s`. +fn render_bound(bound: Duration) -> String { + if bound < Duration::from_secs(1) { + format!("{}ms", bound.as_millis()) + } else { + format!("{}s", bound.as_secs()) + } +} + +/// Run a blocking filesystem probe on a helper thread under a hard bound. +pub(super) fn run_bounded_fs( + what: &'static str, + bound: Duration, + f: impl FnOnce() -> T + Send + 'static, +) -> io::Result { + let (tx, rx) = std::sync::mpsc::channel(); + // `Builder::spawn` rather than `thread::spawn`: this helper deliberately + // abandons a thread per expiry, so thread exhaustion is the one failure + // it is most likely to meet, and `thread::spawn` answers that by + // panicking the caller it exists to protect. + std::thread::Builder::new() + .name("snapshot-fs-probe".to_string()) + .spawn(move || { + let _ = tx.send(f()); + })?; + rx.recv_timeout(bound).map_err(|err| match err { + std::sync::mpsc::RecvTimeoutError::Timeout => io::Error::new( + io::ErrorKind::TimedOut, + format!( + "{what} did not finish within {}; {WEDGED_FS_MARKER}", + render_bound(bound) + ), + ), + // The probe panicked and dropped the sender unsent. Reporting that + // as a wedged mount would be a lie (it returns instantly, and the + // mount is fine) and would route the user to the wrong remedy. + std::sync::mpsc::RecvTimeoutError::Disconnected => { + io::Error::other(format!("{what} panicked before it could report a result")) + } + }) +} + +/// [`std::path::Path::canonicalize`] under [`run_bounded_fs`]. A fast +/// canonicalize failure (missing path, permission) falls back to the +/// unresolved path exactly like the inline calls this replaces; only a +/// probe that exceeds the bound errors out. +pub(super) fn canonicalize_bounded(path: &Path, bound: Duration) -> io::Result { + let owned = path.to_path_buf(); + let resolved = run_bounded_fs("workspace path resolution", bound, move || { + owned.canonicalize() + })?; + Ok(resolved.unwrap_or_else(|_| path.to_path_buf())) +} + +/// [`unsafe_workspace_snapshot_reason`] under [`run_bounded_fs`]. The +/// classifier resolves the workspace a second time and HOME twice with +/// plain syscalls; left inline those are another unbounded pre-git window +/// on the mount the open path just bounded with its own probe. Keep the +/// existing classification semantics untouched and put the whole check +/// under one bound; the open path then degrades with the usual +/// wedged-filesystem notice instead of parking between the probes and git. +fn snapshot_safety_reason_bounded( + workspace: &Path, + home: Option<&Path>, + bound: Duration, +) -> io::Result> { + let owned_workspace = workspace.to_path_buf(); + let owned_home = home.map(Path::to_path_buf); + run_bounded_fs("workspace safety classification", bound, move || { + unsafe_workspace_snapshot_reason(&owned_workspace, owned_home.as_deref()) + }) +} + fn normalize_path_for_safety(path: &Path) -> PathBuf { path.canonicalize().unwrap_or_else(|_| path.to_path_buf()) } @@ -1571,6 +2044,59 @@ fn is_safe_relative_path(path: &Path) -> bool { #[cfg(test)] mod tests { use super::*; + + #[test] + fn bounded_fs_probe_times_out_instead_of_parking_the_caller() { + // A probe that exceeds its bound errors out promptly (the abandoned + // helper thread ends whenever the underlying call returns); a fast + // probe delivers its value untouched. + let started = std::time::Instant::now(); + let err = run_bounded_fs("wedged probe", Duration::from_millis(50), || { + std::thread::sleep(Duration::from_secs(2)); + }) + .expect_err("a probe past its bound must time out"); + assert_eq!(err.kind(), io::ErrorKind::TimedOut, "{err}"); + assert!( + err.to_string().contains("did not finish within 50ms"), + "the timeout must name the probe bound, not truncate it to 0s: {err}" + ); + assert!( + err.to_string().contains(WEDGED_FS_MARKER), + "the wedge marker routes the user-facing remedy hint: {err}" + ); + assert!( + started.elapsed() < Duration::from_secs(1), + "the caller must not wait out the underlying call" + ); + assert_eq!( + run_bounded_fs("fast probe", Duration::from_secs(5), || 42usize).expect("fast probe"), + 42 + ); + } + + #[test] + fn bounded_fs_probe_panic_is_not_reported_as_a_wedged_filesystem() { + // A panicking probe drops the sender unsent, which `recv_timeout` + // reports as `Disconnected`. Folding that into the timeout arm would + // return instantly with a `TimedOut` "filesystem appears wedged" + // error and route the user to the wrong remedy for a mount that is + // perfectly healthy. + let started = std::time::Instant::now(); + let err = run_bounded_fs("panicking probe", Duration::from_secs(30), || { + panic!("probe blew up"); + }) + .expect_err("a panicking probe must surface as an error"); + assert_ne!(err.kind(), io::ErrorKind::TimedOut, "{err}"); + assert!( + !err.to_string().contains(WEDGED_FS_MARKER), + "a panic must not claim the mount is wedged: {err}" + ); + assert!( + started.elapsed() < Duration::from_secs(5), + "the panic must not be reported only after the bound" + ); + } + use crate::test_support::lock_test_env; use std::fs::{File, FileTimes}; use tempfile::tempdir; @@ -1666,6 +2192,241 @@ mod tests { assert!(after.is_some()); } + #[test] + fn bounded_safety_classification_matches_the_inline_classifier() { + // The open path used to run the workspace/home re-canonicalization + // of `unsafe_workspace_snapshot_reason` inline — an unbounded + // pre-git window on a mount whose probes had just been bounded. + // The classifier now runs behind `snapshot_safety_reason_bounded`, + // which is a pass-through into `run_bounded_fs`: the timeout leg is + // pinned there (bounded_fs_probe_times_out…), since a genuinely + // wedged mount — the only shape whose canonicalize would outlast + // any test bound — cannot be induced in a unit test. What this test + // pins instead is the part that could silently regress on its own: + // the wrapper must classify exactly what the inline classifier it + // replaced would have, on every anchored classification, including + // the HOME/Desktop shapes the disabled-workspace tests rely on. + let tmp = tempdir().unwrap(); + // ScopedHome already owns the process-wide env lock for the test's + // duration; taking lock_test_env() again in the same thread would + // deadlock on the non-reentrant mutex. + let _home = scoped_home(tmp.path()); + let desktop = tmp.path().join("Desktop"); + std::fs::create_dir_all(&desktop).unwrap(); + let elsewhere = tmp.path().join("elsewhere"); + std::fs::create_dir_all(&elsewhere).unwrap(); + + for (workspace, expected) in [ + (tmp.path(), Some("home directory")), + (desktop.as_path(), Some("home collection directory")), + (elsewhere.as_path(), None), + ] { + assert_eq!( + unsafe_workspace_snapshot_reason(workspace, Some(tmp.path())), + expected, + "inline classifier baseline must hold for {workspace:?}" + ); + assert_eq!( + snapshot_safety_reason_bounded( + workspace, + Some(tmp.path()), + WORKSPACE_PROBE_TIMEOUT + ) + .expect("the classifier completes well within the probe bound"), + expected, + "bounded classifier must agree with the inline one for {workspace:?}" + ); + } + } + + #[test] + fn open_or_init_recovers_a_side_repo_left_without_a_head() { + // A timed-out `git init` can stop between creating the side repo + // directory and writing HEAD. The directory-existence predicate used + // to skip init forever, failing every later snapshot with "not a git + // repository"; the readiness predicate must see the missing HEAD and + // re-init (git init is idempotent). + let tmp = tempdir().unwrap(); + let workspace = tmp.path().join("workspace"); + std::fs::create_dir_all(&workspace).unwrap(); + let _home = scoped_home(tmp.path()); + + let git_dir = snapshot_git_dir(&workspace); + std::fs::create_dir_all(git_dir.join("refs").join("heads")).unwrap(); + std::fs::create_dir_all(git_dir.join("objects")).unwrap(); + + let repo = SnapshotRepo::open_or_init(&workspace) + .expect("open_or_init must heal a HEAD-less side repo"); + std::fs::write(repo.work_tree().join("a.txt"), b"alpha").unwrap(); + let id = repo + .snapshot("pre-turn:1") + .expect("snapshot must work after the healing re-init"); + assert_eq!(id.as_str().len(), 40); + + // And the healed repo reopens as ready. + let reopened = SnapshotRepo::open_existing(&workspace).expect("open existing"); + assert!(reopened.is_some()); + } + + #[test] + fn open_or_init_recovers_a_side_repo_left_without_objects() { + // git writes HEAD before it creates `objects/`, so a kill between the + // two leaves a side repo that a HEAD-only predicate calls ready while + // every git command rejects it with "not a git repository". + let tmp = tempdir().unwrap(); + let workspace = tmp.path().join("workspace"); + std::fs::create_dir_all(&workspace).unwrap(); + let _home = scoped_home(tmp.path()); + + SnapshotRepo::open_or_init(&workspace).expect("first init"); + let git_dir = snapshot_git_dir(&workspace); + std::fs::remove_dir_all(git_dir.join("objects")).unwrap(); + assert!( + SnapshotRepo::open_existing(&workspace) + .expect("open existing") + .is_none(), + "a side repo without objects/ is not ready" + ); + + let repo = SnapshotRepo::open_or_init(&workspace) + .expect("open_or_init must heal a side repo without objects/"); + std::fs::write(repo.work_tree().join("a.txt"), b"alpha").unwrap(); + assert_eq!( + repo.snapshot("pre-turn:1") + .expect("snapshot must work after the healing re-init") + .as_str() + .len(), + 40 + ); + } + + #[test] + fn list_reports_a_broken_side_repo_instead_of_no_restore_points() { + let tmp = tempdir().unwrap(); + let workspace = tmp.path().join("workspace"); + std::fs::create_dir_all(&workspace).unwrap(); + let _home = scoped_home(tmp.path()); + + let repo = SnapshotRepo::open_or_init(&workspace).expect("init"); + assert!( + repo.list(10) + .expect("an unborn HEAD lists empty") + .is_empty(), + "a fresh side repo has no restore points yet" + ); + std::fs::remove_dir_all(snapshot_git_dir(&workspace).join("objects")).unwrap(); + assert!( + repo.list(10).is_err(), + "a side repo git cannot open must not read as having no restore points" + ); + } + + #[test] + fn open_or_init_clears_the_stale_head_lock_that_blocks_the_reinit() { + // The HEAD write happens under `.git/HEAD.lock`; a kill there leaves + // the lock and no HEAD, and `git init` then fails with "cannot lock + // ref 'HEAD'" on every later attempt unless the stale lock is swept. + let tmp = tempdir().unwrap(); + let workspace = tmp.path().join("workspace"); + std::fs::create_dir_all(&workspace).unwrap(); + let _home = scoped_home(tmp.path()); + + let git_dir = snapshot_git_dir(&workspace); + std::fs::create_dir_all(&git_dir).unwrap(); + let head_lock = git_dir.join("HEAD.lock"); + std::fs::write(&head_lock, b"").unwrap(); + let stale = SystemTime::now() - (STALE_INDEX_LOCK_AGE + Duration::from_secs(60)); + File::options() + .write(true) + .open(&head_lock) + .unwrap() + .set_times(FileTimes::new().set_modified(stale)) + .unwrap(); + + let repo = SnapshotRepo::open_or_init(&workspace) + .expect("a stale HEAD.lock must not make the side repo unrepairable"); + assert!(!head_lock.exists(), "the stale lock must be swept"); + std::fs::write(repo.work_tree().join("a.txt"), b"alpha").unwrap(); + assert_eq!( + repo.snapshot("pre-turn:1") + .expect("snapshot must work after the healing re-init") + .as_str() + .len(), + 40 + ); + } + + #[test] + fn open_or_init_clears_the_stale_config_lock_that_blocks_the_reinit() { + // The interrupted `git init` that leaves a HEAD-less side repo is + // also the one that can leave `.git/config.lock` behind: git writes + // `core.repositoryformatversion` under that lock *before* it creates + // HEAD. `git init` then fails with "could not lock config file" on + // every later attempt, so the HEAD repair above is permanently + // ineffective unless the stale lock is swept first. Git never ages + // lockfiles out, so nothing else would ever clear it. + let tmp = tempdir().unwrap(); + let workspace = tmp.path().join("workspace"); + std::fs::create_dir_all(&workspace).unwrap(); + let _home = scoped_home(tmp.path()); + + let git_dir = snapshot_git_dir(&workspace); + std::fs::create_dir_all(git_dir.join("refs").join("heads")).unwrap(); + std::fs::create_dir_all(git_dir.join("objects")).unwrap(); + let config_lock = git_dir.join("config.lock"); + std::fs::write(&config_lock, b"").unwrap(); + // Age it past the staleness bound; a fresh lock may belong to a git + // that is still running and is deliberately left alone. + let stale = SystemTime::now() - (STALE_INDEX_LOCK_AGE + Duration::from_secs(60)); + File::options() + .write(true) + .open(&config_lock) + .unwrap() + .set_times(FileTimes::new().set_modified(stale)) + .unwrap(); + + let repo = SnapshotRepo::open_or_init(&workspace) + .expect("a stale config.lock must not make the side repo unrepairable"); + assert!(!config_lock.exists(), "the stale lock must be swept"); + std::fs::write(repo.work_tree().join("a.txt"), b"alpha").unwrap(); + assert_eq!( + repo.snapshot("pre-turn:1") + .expect("snapshot must work after the healing re-init") + .as_str() + .len(), + 40 + ); + } + + #[test] + fn a_fresh_config_lock_is_left_for_the_git_that_may_still_own_it() { + // The mirror of the sweep above: a lock younger than the staleness + // bound belongs to a concurrent git, so it stays and the init fails + // loudly rather than being raced. + let tmp = tempdir().unwrap(); + let workspace = tmp.path().join("workspace"); + std::fs::create_dir_all(&workspace).unwrap(); + let _home = scoped_home(tmp.path()); + + let git_dir = snapshot_git_dir(&workspace); + std::fs::create_dir_all(git_dir.join("refs").join("heads")).unwrap(); + std::fs::create_dir_all(git_dir.join("objects")).unwrap(); + let config_lock = git_dir.join("config.lock"); + std::fs::write(&config_lock, b"").unwrap(); + + let err = match SnapshotRepo::open_or_init(&workspace) { + Err(err) => err, + Ok(_) => panic!("a fresh lock must not be stolen from a running git"), + }; + assert!(config_lock.exists(), "a fresh lock must be left alone"); + // And the failure has to be routable to the half-initialized-repo + // remedy, not swallowed: it repeats on every attempt. + assert!( + err.to_string().contains(GIT_INIT_FAILED_MARKER), + "the init failure must carry its routing marker: {err}" + ); + } + #[test] fn restore_reverts_workspace_files() { let tmp = tempdir().unwrap(); @@ -1972,6 +2733,62 @@ mod tests { assert_eq!(after[0].label, "turn:new"); } + #[test] + fn open_or_init_sweeps_a_stale_ref_lock_but_keeps_a_fresh_one() { + let tmp = tempdir().unwrap(); + let (repo, _home) = make_repo(tmp.path()); + let workspace = repo.work_tree().to_path_buf(); + + // `update-ref HEAD` at commit time takes `.git/HEAD.lock` and the + // resolved branch's `refs/heads/.lock`; a git killed mid-update + // leaves one or both behind and every later snapshot then fails at the + // ref update, with nothing but this sweep to age them out. Exactly the + // stale locks go, like index.lock; a fresh one may belong to a live + // git and must survive. + let refs_heads = repo.git_dir().join("refs").join("heads"); + std::fs::create_dir_all(&refs_heads).unwrap(); + let stale = refs_heads.join("main.lock"); + std::fs::write(&stale, b"stale").unwrap(); + let nested = refs_heads.join("feature").join("topic.lock"); + std::fs::create_dir_all(nested.parent().unwrap()).unwrap(); + std::fs::write(&nested, b"stale").unwrap(); + let stale_head = repo.git_dir().join("HEAD.lock"); + std::fs::write(&stale_head, b"stale").unwrap(); + for lock in [&stale, &nested, &stale_head] { + let old_time = SystemTime::now() - STALE_INDEX_LOCK_AGE - Duration::from_secs(60); + let file = File::options().write(true).open(lock).unwrap(); + file.set_times(FileTimes::new().set_modified(old_time)) + .unwrap(); + } + let fresh = repo.git_dir().join("packed-refs.lock"); + std::fs::write(&fresh, b"fresh").unwrap(); + + SnapshotRepo::open_or_init(&workspace).unwrap(); + + assert!(!stale.exists(), "stale ref lock should be removed"); + assert!(!nested.exists(), "stale nested ref lock should be removed"); + assert!( + !stale_head.exists(), + "stale HEAD.lock should be removed: update-ref HEAD takes it, and a \ + leftover one never makes the side repo unready" + ); + assert!( + fresh.exists(), + "a fresh ref lock may belong to a live git and must be kept" + ); + let _ = std::fs::remove_file(&fresh); + + // A fresh HEAD.lock follows the same keep rule as every other lock. + let fresh_head = repo.git_dir().join("HEAD.lock"); + std::fs::write(&fresh_head, b"fresh").unwrap(); + SnapshotRepo::open_or_init(&workspace).unwrap(); + assert!( + fresh_head.exists(), + "a fresh HEAD.lock may belong to a live git and must be kept" + ); + let _ = std::fs::remove_file(&fresh_head); + } + #[test] fn open_or_init_removes_stale_tmp_pack_files_only() { let tmp = tempdir().unwrap(); @@ -2450,4 +3267,18 @@ mod tests { paths.len() ); } + + #[test] + fn capture_hit_the_cap_matches_only_a_truncating_tail() { + assert!(capture_hit_the_cap(GIT_CAPTURE_CAP_NOTE)); + assert!(!capture_hit_the_cap(b"")); + // A note-shaped fragment that is not the tail, or a tail that has + // data after the note, is content — not truncation evidence. + assert!(!capture_hit_the_cap( + b"head\ncodewhale git output capture stopped at the size cap" + )); + assert!(!capture_hit_the_cap( + b"\n[codewhale] git output capture stopped at the size cap; later output was dropped\nmore data" + )); + } } diff --git a/crates/tui/src/task_manager.rs b/crates/tui/src/task_manager.rs index c3356f167b..f6c42e716f 100644 --- a/crates/tui/src/task_manager.rs +++ b/crates/tui/src/task_manager.rs @@ -1996,6 +1996,20 @@ impl TaskManager { _ = self.cancel_token.cancelled(), if !self.cancel_token.is_cancelled() => { cancel.cancel(); } + // Known starvation shape (deliberate, disclosed + // debt): `biased` polls the event arm before this + // flush arm, and the debounce sleep restarts on + // every loop iteration, so an event stream denser + // than the debounce interval defers persistence + // until the stream pauses or the loop exits (the + // trailing flush below still lands it). Heartbeats + // never arm `dirty` themselves, but their ~200ms + // cadence still restarts the debounce, so dirty + // state armed just before a silent-tool phase + // stays unpersisted for that whole phase; a dense + // run of unpersisted deltas starves it the same + // way. Fixing it needs a deadline that survives + // across iterations. _ = sleep(persist_debounce), if dirty => { if let Err(err) = self.flush_task(&task_id).await { tracing::error!("Failed to debounce-persist task {task_id}: {err}"); @@ -2009,6 +2023,12 @@ impl TaskManager { }; while let Ok(event) = event_rx.try_recv() { + // Same invariant as the main loop's heartbeat short-circuit: + // liveness-only ticks are a no-op and must not take the + // manager-wide state lock, even while draining the tail. + if matches!(event, TaskExecutionEvent::ToolHeartbeat { .. }) { + continue; + } append_message_delta(&mut accumulated_result_text, &event); if let Err(err) = self.apply_execution_event(&task_id, event).await { tracing::error!("Failed to apply trailing task event for {task_id}: {err}"); @@ -2040,6 +2060,14 @@ impl TaskManager { if execution_event_is_progress(&event) { guard.note_progress(Instant::now()); } + // Liveness-only heartbeats never mutate the record: short-circuit + // before the state lock so a silent build's ~5 ticks/s do not take + // the manager-wide lock for a no-op, and so they do not mark the + // record dirty (a spurious dirty would only arm a redundant + // debounce flush). + if matches!(event, TaskExecutionEvent::ToolHeartbeat { .. }) { + return; + } append_message_delta(accumulated_result_text, &event); match self.apply_execution_event(task_id, event).await { Ok(outcome) => { diff --git a/crates/tui/src/tools/plugin.rs b/crates/tui/src/tools/plugin.rs index 76f76349c4..11fc6ae594 100644 --- a/crates/tui/src/tools/plugin.rs +++ b/crates/tui/src/tools/plugin.rs @@ -304,14 +304,19 @@ async fn run_plugin_child_raw( if let Ok(parsed) = serde_json::from_str::(&stdout) { Ok(parsed) } else if super::process::drain_truncated(&output) { - // This surface reports stdout only, so the runner's - // truncation note on stderr would otherwise vanish: an + // This surface reports stdout only, so a truncation note in + // the captured tail (a drain that outlived the grace, or the + // size cap stopping the capture) would otherwise vanish: an // unparseable, possibly cut-off output must not pass as a - // silent success. + // silent success. The echo is bounded — the capture can be + // 16 MiB of capture, and none of it needs to reach the + // transcript. Err(ToolError::execution_failed(format!( - "plugin script stdout did not parse as a tool result and the output \ - pipes did not close after the interpreter exited (the captured \ - output may be truncated): {stdout}" + "plugin script stdout did not parse as a tool result and the \ + captured output is truncated (the pipes did not close after \ + the interpreter exited, or the size cap stopped the capture); \ + first characters: {}", + codewhale_hooks::bounded_text(&stdout, 512) ))) } else { Ok(ToolResult::success(stdout)) @@ -749,6 +754,36 @@ echo hello } } + #[cfg(unix)] + #[tokio::test] + async fn capped_plugin_stdout_is_refused_instead_of_passing_as_success() { + let dir = TempDir::new().unwrap(); + let script = dir.path().join("flood.sh"); + std::fs::write( + &script, + "#!/bin/sh\n# name: flood\nhead -c 17000000 /dev/zero\n", + ) + .unwrap(); + + // 17 MiB of NUL bytes trips the drain capture cap and cannot parse + // as a tool result: this surface must refuse the output as truncated + // instead of reporting the cut capture as a silent success. + let (interpreter, args) = script_command_parts(&script, &[]); + let err = run_plugin_child(&interpreter, &args, "flood", serde_json::json!({})) + .await + .expect_err("a capped, unparseable stdout must not pass as a success"); + match err { + ToolError::ExecutionFailed { message } => { + assert!( + message.contains("truncated") && message.contains("size cap"), + "the error must name the truncation evidence: {}", + &message[..message.len().min(400)] + ); + } + other => panic!("expected an execution failure; got {other:?}"), + } + } + #[test] fn plugin_deadlock_child_process() { if std::env::var_os(DEADLOCK_CHILD_ENV).is_none() { diff --git a/crates/tui/src/tools/process.rs b/crates/tui/src/tools/process.rs index bbb5055d60..fe782f5ade 100644 --- a/crates/tui/src/tools/process.rs +++ b/crates/tui/src/tools/process.rs @@ -10,16 +10,37 @@ //! * the budget bounds the child only. Once it exits, the drains get a short //! grace to see EOF; if a grandchild that inherited the write ends keeps //! them open past the grace, the drains are aborted and the output read so -//! far is returned with a note on stderr. Aborting drops our read ends, -//! which hands the grandchild an EPIPE on its next write; -//! * the timeout path kills the child explicitly and reaps it before -//! returning, so there is no window where the tool has failed but the -//! interpreter is still running, and the kill is directly assertable in -//! tests. +//! far is returned with a note on stderr. On Unix, aborting drops our read +//! ends and hands the grandchild an EPIPE on its next write; on Windows +//! the aborted read lingers on a blocking-pool thread until the +//! grandchild closes the pipe, so the grandchild is not signalled — the +//! lingering read ends when the grandchild exits, which bounds the leak +//! by the grandchild's own lifetime; +//! * on Unix each child is spawned in its own process group +//! (`process_group(0)`), and the timeout SIGKILLs the whole group: the +//! shell tools fork their trailing commands instead of exec'ing them, so +//! killing only the direct child would orphan a grandchild (the observed +//! leak was a live 60s sleep left behind by every timed-out gate run). +//! The kill is followed by a synchronous reap, so there is no window +//! where the tool has failed but the interpreter is still running, and +//! the kill is directly assertable in tests. A grandchild that escaped +//! the group (`setsid`, or the Windows kill which covers the child only) +//! is bounded by the drain grace as before; the group is never targeted +//! speculatively on the success paths, so an intentionally-detached +//! background process that closed the pipes is left alone; +//! * the timeout kill can still harvest the pipes: every group writer is +//! dead, EOF is immediate, and whatever the interpreter printed before +//! the kill is returned with the output instead of being discarded. //! //! `kill_on_drop(true)` remains set as the cancel-path backstop: when the //! whole tool future is dropped (turn interrupt), the owned child handle -//! drops with it and the child is killed. +//! drops with it and the child is killed. It kills the direct child only — +//! a process group cannot be signalled by a drop — so on that one path a +//! forked grandchild is still bounded by the drain grace/EPIPE as before. +//! The drain tasks need their own backstop, because dropping a `JoinHandle` +//! detaches rather than aborts — `DrainTasks` owns them and aborts in +//! `Drop`, so the cancel path releases the pipe read ends like every other +//! exit. use std::process::Stdio; use std::sync::{Arc, Mutex}; @@ -45,32 +66,71 @@ pub(crate) const DRAIN_TRUNCATED_NOTE: &[u8] = (inherited by a still-running grandchild?); returning the output \ captured before the drain grace expired\n"; -/// True when `output` carries the drain-truncation note. +/// Cap on the bytes a drain reader retains per stream. The readers keep +/// draining to EOF regardless, so the pipes still close and the grace +/// clock still bounds the wait — only the capture stops growing. Sized to +/// comfortably hold every legitimate interpreter result (the largest is +/// the plugin JSON, and callers truncate for their own limits anyway); a +/// child producing more than this is runaway output, not a result. +const DRAIN_CAPTURE_CAP: usize = 16 * 1024 * 1024; + +/// Appended in place when the cap stops the capture mid-stream. Reads like +/// the drain note so a reader looking for truncation evidence finds it in +/// the tail either way, and [`drain_truncated`] detects it like one too. +const DRAIN_CAP_TRUNCATED_NOTE: &[u8] = + b"\n[codewhale] output capture stopped at the size cap; later output was dropped\n"; + +/// True when `output` carries a truncation note in its tail: the +/// drain-grace note (appended to stderr when the pipes stayed open past +/// the grace) or the size-cap note (appended to whichever stream hit the +/// cap). Both writers append their note as the buffer's last bytes and +/// stop retaining past it, so the match is tail-anchored — the same +/// contract as the snapshot capture's `capture_hit_the_cap` — and output +/// that merely quotes a note mid-body is not truncation evidence. A +/// caller that parses a single stream as its result can thereby detect a +/// cut output instead of reporting it as a success. pub(crate) fn drain_truncated(output: &std::process::Output) -> bool { - output - .stderr - .windows(DRAIN_TRUNCATED_NOTE.len()) - .any(|window| window == DRAIN_TRUNCATED_NOTE) + for buf in [&output.stdout, &output.stderr] { + for note in [DRAIN_TRUNCATED_NOTE, DRAIN_CAP_TRUNCATED_NOTE] { + if buf.ends_with(note) { + return true; + } + } + } + false } -/// Run a pre-configured command under `budget`, capturing stdout/stderr. -/// -/// When `stdin_input` is `Some`, stdin is piped and the bytes are written by -/// a background task (the plugin tools feed the script its JSON input this -/// way); otherwise stdin is left exactly as the caller configured it. The -/// command must already carry its arguments, environment, and working -/// directory. -pub(crate) async fn run_bounded_child( +/// How a bounded run ended. `timed_out` carries the same `output` shape as +/// a completed run — the group was killed and reaped, so `status` is the +/// kill status (no exit code on Unix) and the buffers hold whatever the +/// pipes yielded before the drains were cut. Callers that surface partial +/// output on a timeout (the gate log) want this distinction; callers that +/// report only "it timed out" use [`run_bounded_child`]. +pub(crate) struct BoundedOutcome { + pub output: std::process::Output, + /// The budget elapsed and the run was killed for it. + pub timed_out: bool, +} + +/// Run a pre-configured command under `budget`, reporting whether it was +/// killed for exceeding the budget. Semantics are [`run_bounded_child`]'s; +/// see that function for the argument contract. +pub(crate) async fn run_bounded_child_observed( cmd: &mut tokio::process::Command, stdin_input: Option>, budget: Duration, label: &str, -) -> Result { +) -> Result { // kill_on_drop is the cancel-path backstop: when the tool future is // dropped the owned child handle goes with it, which kills the child. - // The timeout path below kills explicitly regardless, so the kill and - // reap are synchronous and testable rather than best-effort. + // The timeout path below kills the group explicitly and reaps, so the + // kill is synchronous and testable rather than best-effort. cmd.kill_on_drop(true); + // A private group per child, so a timeout kill can take the whole + // tree out (shells fork their trailing commands instead of exec'ing + // them) and stray terminal signals can't reach a tool interpreter. + #[cfg(unix)] + cmd.process_group(0); cmd.stdout(Stdio::piped()); cmd.stderr(Stdio::piped()); if stdin_input.is_some() { @@ -81,7 +141,7 @@ pub(crate) async fn run_bounded_child( .spawn() .map_err(|e| ToolError::execution_failed(format!("failed to spawn {label}: {e}")))?; - let mut stdin_writer = match (child.stdin.take(), stdin_input) { + let stdin_writer = match (child.stdin.take(), stdin_input) { (Some(mut stdin), Some(input_bytes)) => { use tokio::io::AsyncWriteExt as _; Some(tokio::spawn(async move { @@ -101,71 +161,183 @@ pub(crate) async fn run_bounded_child( // still return what was captured instead of losing it with the task. let stdout_buf = Arc::new(Mutex::new(Vec::new())); let stderr_buf = Arc::new(Mutex::new(Vec::new())); - let mut stdout_task = tokio::spawn(drain_pipe(stdout_pipe, Arc::clone(&stdout_buf))); - let mut stderr_task = tokio::spawn(drain_pipe(stderr_pipe, Arc::clone(&stderr_buf))); + let mut drains = DrainTasks { + stdout: tokio::spawn(drain_pipe(stdout_pipe, Arc::clone(&stdout_buf))), + stderr: tokio::spawn(drain_pipe(stderr_pipe, Arc::clone(&stderr_buf))), + stdin: stdin_writer, + }; - let output = match tokio::time::timeout(budget, child.wait()).await { + let (status, timed_out) = match tokio::time::timeout(budget, child.wait()).await { Ok(status) => { - let status = - status.map_err(|e| ToolError::execution_failed(format!("{label}: {e}")))?; - // The child closed its write ends; EOF should already have - // arrived. The grace only bounds the grandchild case, where the - // write ends live on in an inherited copy and read_to_end would - // otherwise wait for that process to exit. - let drained = tokio::time::timeout(CHILD_PIPE_DRAIN_GRACE, async { - let _ = tokio::join!(&mut stdout_task, &mut stderr_task); - if let Some(writer) = stdin_writer.as_mut() { - let _ = writer.await; - } - }) - .await; - if drained.is_err() { - // Abort (don't join) the drain tasks: joining would wait for - // EOF that only the grandchild can deliver. Aborting drops - // our read ends — the grandchild sees EPIPE on its next - // write — and the shared buffers keep what was captured. - stdout_task.abort(); - stderr_task.abort(); - if let Some(writer) = &stdin_writer { - writer.abort(); - } - let mut stderr = snapshot(&stderr_buf); - if stderr.last() != Some(&b'\n') && !stderr.is_empty() { - stderr.push(b'\n'); + let status = match status { + Ok(status) => status, + Err(e) => { + // The one exit that isn't a timeout or a clean exit. + // `drains` aborts on drop, so this needs no explicit + // call; returning is enough. + return Err(ToolError::execution_failed(format!("{label}: {e}"))); } - stderr.extend_from_slice(DRAIN_TRUNCATED_NOTE); - std::process::Output { - status, - stdout: snapshot(&stdout_buf), - stderr, - } - } else { - std::process::Output { - status, - stdout: snapshot(&stdout_buf), - stderr: snapshot(&stderr_buf), - } - } + }; + (status, false) } Err(_elapsed) => { - let _ = child.kill().await; - let _ = child.wait().await; - // Abort (don't join) the drain tasks and the stdin writer: a - // grandchild that inherited the pipes keeps the write ends open - // after the child dies, so read_to_end would never see EOF and - // joining here would hang the caller past the budget. - stdout_task.abort(); - stderr_task.abort(); - if let Some(writer) = &stdin_writer { - writer.abort(); - } - return Err(ToolError::Timeout { - seconds: budget.as_secs(), - }); + // The budget elapsed. Kill the whole process group, not just + // the child: the shell tools fork their trailing commands + // instead of exec'ing them, so a child-only kill orphans every + // grandchild. Then reap, and let the pipes deliver the partial + // output instead of discarding it. + kill_the_run(&mut child).await; + let status = match child.wait().await { + Ok(status) => status, + Err(e) => { + return Err(ToolError::execution_failed(format!("{label}: {e}"))); + } + }; + (status, true) } }; + let output = collect_pipes_after_exit(status, &mut drains, &stdout_buf, &stderr_buf).await; + Ok(BoundedOutcome { output, timed_out }) +} - Ok(output) +/// Run a pre-configured command under `budget`, capturing stdout/stderr. +/// +/// When `stdin_input` is `Some`, stdin is piped and the bytes are written by +/// a background task (the plugin tools feed the script its JSON input this +/// way); otherwise stdin is left exactly as the caller configured it. The +/// command must already carry its arguments, environment, and working +/// directory. +/// +/// A run that exceeds the budget is killed (see the module doc) and +/// reported as [`ToolError::Timeout`]; its partial output is dropped. +/// Callers that want the partial output report via +/// [`run_bounded_child_observed`] instead. +pub(crate) async fn run_bounded_child( + cmd: &mut tokio::process::Command, + stdin_input: Option>, + budget: Duration, + label: &str, +) -> Result { + let observed = run_bounded_child_observed(cmd, stdin_input, budget, label).await?; + if observed.timed_out { + return Err(ToolError::Timeout { + seconds: budget.as_secs(), + }); + } + Ok(observed.output) +} + +/// Kill the run the budget expired on. On Unix this SIGKILLs the child's +/// process group — the child is spawned with `process_group(0)`, so +/// `-pgid` reaches it together with everything it forked that stayed in +/// the group, and never our own group. When there is no group to signal +/// (Windows, or the group is already gone) this kills the direct child, +/// and a pipe-inheriting grandchild is then bounded by the drain grace. +async fn kill_the_run(child: &mut tokio::process::Child) { + #[cfg(unix)] + { + let pgid = libc::pid_t::try_from(child.id().unwrap_or(0)).unwrap_or(0); + if pgid > 0 { + // SAFETY: a negative pid targets the process group led by the + // child; the pgid came from `process_group(0)` at spawn, so this + // group cannot be Codewhale's own or the terminal's. + let killed = unsafe { libc::kill(-pgid, libc::SIGKILL) }; + if killed == 0 { + return; + } + // ESRCH usually means the group is already gone with the child + // dead (the child led its own group and cannot have left it, so + // an escaped live member is not expected here). Fall through to + // the child-only kill on any kill error anyway — a no-op on a + // dead child, the last chance to stop an escaped one. Any other + // failure (e.g. EPERM racing a setuid exec) takes the same + // fallback. + } + } + let _ = child.kill().await; +} + +/// Collect the pipes once the child is gone. The child closed its write +/// ends on a clean exit, so EOF should already have arrived; the grace +/// only bounds a writer that outlived the child (a grandchild that +/// inherited the pipe ends, or on the timeout path one that escaped the +/// process group). If the grace expires, the readers are aborted — +/// dropping our read ends hands an escaped grandchild EPIPE on its next +/// write — the shared buffers keep what was captured, and stderr gains +/// the truncation note. +async fn collect_pipes_after_exit( + status: std::process::ExitStatus, + drains: &mut DrainTasks, + stdout_buf: &Arc>>, + stderr_buf: &Arc>>, +) -> std::process::Output { + let drained = tokio::time::timeout(CHILD_PIPE_DRAIN_GRACE, drains.join()).await; + if drained.is_err() { + // Abort (don't join) the drain tasks: joining would wait for EOF + // that only a still-running writer can deliver. Explicit rather + // than left to the guard so the abort is ordered before the + // buffer snapshots below. + drains.abort(); + let stdout = snapshot(stdout_buf); + let mut stderr = snapshot(stderr_buf); + if stderr.last() != Some(&b'\n') && !stderr.is_empty() { + stderr.push(b'\n'); + } + stderr.extend_from_slice(DRAIN_TRUNCATED_NOTE); + std::process::Output { + status, + stdout, + stderr, + } + } else { + std::process::Output { + status, + stdout: snapshot(stdout_buf), + stderr: snapshot(stderr_buf), + } + } +} + +/// Owns the drain tasks and the stdin writer so that *every* exit aborts +/// them — including the one no function call can cover. Dropping a +/// [`tokio::task::JoinHandle`] detaches its task rather than aborting it, so +/// when the tool future is dropped on a turn interrupt the readers would +/// otherwise keep the pipe read ends open for as long as a pipe-inheriting +/// grandchild holds the write ends, which is exactly the leak +/// [`run_bounded_child`]'s module doc describes. A `Drop` impl is the only +/// construction that covers the cancel path; the explicit [`Self::abort`] +/// exists so the grace-expiry exit can order the abort before it snapshots +/// the buffers. +struct DrainTasks { + stdout: tokio::task::JoinHandle<()>, + stderr: tokio::task::JoinHandle<()>, + stdin: Option>, +} + +impl DrainTasks { + fn abort(&self) { + self.stdout.abort(); + self.stderr.abort(); + if let Some(writer) = self.stdin.as_ref() { + writer.abort(); + } + } + + /// Wait for both readers to see EOF, then for the stdin writer. Only + /// safe under a timeout: EOF may be owed by a grandchild that outlives + /// the child. + async fn join(&mut self) { + let _ = tokio::join!(&mut self.stdout, &mut self.stderr); + if let Some(writer) = self.stdin.as_mut() { + let _ = writer.await; + } + } +} + +impl Drop for DrainTasks { + fn drop(&mut self) { + self.abort(); + } } async fn drain_pipe(pipe: Option, buf: Arc>>) { @@ -179,7 +351,16 @@ async fn drain_pipe(pipe: Option, buf: Arc break, Ok(n) => { if let Ok(mut buf) = buf.lock() { - buf.extend_from_slice(&chunk[..n]); + // Keep draining to EOF — the budget clock and the drain + // grace bound the wait — but stop retaining bytes past + // the cap so a chatty child cannot grow the capture + // without bound across a multi-minute run. + let remaining = DRAIN_CAPTURE_CAP.saturating_sub(buf.len()); + let retained = n.min(remaining); + buf.extend_from_slice(&chunk[..retained]); + if retained < n && !buf.ends_with(DRAIN_CAP_TRUNCATED_NOTE) { + buf.extend_from_slice(DRAIN_CAP_TRUNCATED_NOTE); + } } } } @@ -202,6 +383,53 @@ mod tests { #[cfg(unix)] use super::*; + #[tokio::test] + async fn dropping_the_drain_guard_aborts_the_readers() { + // The cancel path (turn interrupt) drops the whole tool future + // rather than taking any exit inside `run_bounded_child`, and + // dropping a `JoinHandle` only detaches its task. Without the `Drop` + // impl the readers would keep the pipe read ends open for as long as + // a pipe-inheriting grandchild holds the write ends, so pin that a + // dropped guard really does abort them. + use std::sync::Arc; + use std::time::Duration; + + let held = Arc::new(()); + let make = |held: Arc<()>| { + tokio::spawn(async move { + let _held = held; + // Never completes on its own; only an abort ends this. + std::future::pending::<()>().await; + }) + }; + let guard = super::DrainTasks { + stdout: make(Arc::clone(&held)), + stderr: make(Arc::clone(&held)), + stdin: Some(make(Arc::clone(&held))), + }; + tokio::task::yield_now().await; + assert_eq!( + Arc::strong_count(&held), + 4, + "all three readers must be live before the drop" + ); + + drop(guard); + // Aborted tasks release their captured state once the runtime + // reaps them. + for _ in 0..100 { + if Arc::strong_count(&held) == 1 { + break; + } + tokio::time::sleep(Duration::from_millis(10)).await; + } + assert_eq!( + Arc::strong_count(&held), + 1, + "dropping the guard must abort every reader, not detach it" + ); + } + #[cfg(unix)] fn shell_command(script: &str) -> tokio::process::Command { let mut cmd = tokio::process::Command::new("sh"); @@ -209,6 +437,83 @@ mod tests { cmd } + #[tokio::test] + async fn drain_pipe_caps_the_capture_and_notes_the_truncation() { + // A chatty child must not grow the capture without bound across a + // multi-minute budget: the reader keeps draining to EOF (so the + // grace still works) but stops retaining bytes past the cap, and + // the captured tail says so. The cap is 16 MiB; sending the cap + // plus overruns proves both the boundary and the drop. + use tokio::io::AsyncWriteExt; + + let (mut writer, reader) = tokio::io::duplex(64 * 1024); + let buf = Arc::new(Mutex::new(Vec::new())); + let task = tokio::spawn(drain_pipe(Some(reader), Arc::clone(&buf))); + + let cap = DRAIN_CAPTURE_CAP; + let chunk = vec![b'x'; 1024 * 1024]; + let mut sent = 0usize; + while sent < cap + 2 * 1024 * 1024 { + writer.write_all(&chunk).await.expect("write"); + sent += chunk.len(); + } + drop(writer); + task.await.expect("drain task"); + + let captured = buf.lock().expect("captured").clone(); + assert!( + captured.len() <= cap + DRAIN_CAP_TRUNCATED_NOTE.len(), + "the capture must stop at the cap, got {} bytes", + captured.len() + ); + assert!( + captured.ends_with(DRAIN_CAP_TRUNCATED_NOTE), + "a capped capture must end with the truncation note" + ); + assert_eq!( + &captured[..cap], + &vec![b'x'; cap][..], + "the first cap bytes are retained unchanged" + ); + } + + #[cfg(unix)] + #[test] + fn drain_truncated_sees_both_notes_on_both_streams() { + use std::os::unix::process::ExitStatusExt; + + let output = |stdout: &[u8], stderr: &[u8]| std::process::Output { + status: std::process::ExitStatus::from_raw(0), + stdout: stdout.to_vec(), + stderr: stderr.to_vec(), + }; + // The drain-grace note lands on stderr; the size-cap note lands on + // whichever stream hit the cap. A stdout-as-result caller (the + // plugin tools) must see truncation evidence in every combination. + assert!(drain_truncated(&output( + b"partial result", + DRAIN_TRUNCATED_NOTE + ))); + assert!(drain_truncated(&output(DRAIN_CAP_TRUNCATED_NOTE, b""))); + assert!(drain_truncated(&output(b"", DRAIN_CAP_TRUNCATED_NOTE))); + assert!(drain_truncated(&output( + b"partial", + DRAIN_CAP_TRUNCATED_NOTE + ))); + assert!(!drain_truncated(&output(b"clean", b"clean"))); + assert!(!drain_truncated(&output(b"", b""))); + // The writers append their note as the buffer's last bytes, so the + // match is tail-anchored: a stream that quotes a note mid-body and + // keeps writing is not truncation evidence (the same negatives the + // snapshot capture's `capture_hit_the_cap` pins). + let mut quoted = DRAIN_CAP_TRUNCATED_NOTE.to_vec(); + quoted.extend_from_slice(b"trailing data after the quoted note\n"); + assert!(!drain_truncated(&output("ed, b""))); + let mut quoted_grace = DRAIN_TRUNCATED_NOTE.to_vec(); + quoted_grace.extend_from_slice(b"still writing\n"); + assert!(!drain_truncated(&output(b"", "ed_grace))); + } + #[cfg(unix)] #[tokio::test] async fn bounded_child_returns_promptly_when_a_grandchild_holds_the_pipes() { @@ -249,4 +554,121 @@ mod tests { .expect_err("a 60s sleep must hit the budget"); assert!(matches!(err, ToolError::Timeout { seconds: 2 })); } + + #[cfg(unix)] + fn pid_is_gone(pid: libc::pid_t) -> bool { + // kill(pid, 0) stays 0 for a zombie, and a group-killed grandchild + // is reparented to init when its parent dies first; retry briefly + // so reaping races don't flake the assertion. + let deadline = std::time::Instant::now() + std::time::Duration::from_secs(2); + loop { + if unsafe { libc::kill(pid, 0) } != 0 + && std::io::Error::last_os_error().raw_os_error() == Some(libc::ESRCH) + { + return true; + } + if std::time::Instant::now() >= deadline { + return false; + } + std::thread::sleep(Duration::from_millis(25)); + } + } + + #[cfg(unix)] + #[tokio::test] + async fn a_timeout_kill_takes_out_the_whole_process_group_not_just_the_child() { + // The observed leak: a timed-out run killed only the direct child, + // so `sh -c "...; sleep 60 & ..."` orphaned the backgrounded sleep + // for its full minute. Pin that the grandchild itself is dead once + // the call reports the timeout — the whole point of process_group. + let tmp = tempfile::tempdir().expect("tempdir"); + let child_pid_file = tmp.path().join("child.pid"); + let grandchild_pid_file = tmp.path().join("grandchild.pid"); + let script = format!( + "echo $$ > {}; sleep 30 & echo $! > {}; sleep 30", + child_pid_file.display(), + grandchild_pid_file.display(), + ); + let mut cmd = shell_command(&script); + let err = run_bounded_child(&mut cmd, None, Duration::from_secs(2), "sh") + .await + .expect_err("the 30s sleeps must hit the budget"); + assert!(matches!(err, ToolError::Timeout { seconds: 2 })); + + let child: libc::pid_t = std::fs::read_to_string(&child_pid_file) + .expect("child pid") + .trim() + .parse() + .expect("child pid integer"); + let grandchild: libc::pid_t = std::fs::read_to_string(&grandchild_pid_file) + .expect("grandchild pid") + .trim() + .parse() + .expect("grandchild pid integer"); + assert!( + pid_is_gone(child), + "child {child} survived the timeout kill" + ); + assert!( + pid_is_gone(grandchild), + "grandchild {grandchild} outlived the group kill: the original leak" + ); + } + + #[cfg(unix)] + #[tokio::test] + async fn a_completed_run_harvests_partial_output_through_the_group_kill() { + // The child prints, then hangs; the runner kills the group and a + // synchronous reap must leave the pipes readable. The marker proves + // the kill did not discard the interpreter's earlier output. + let mut cmd = shell_command("echo before-hang; sleep 30"); + let outcome = run_bounded_child_observed(&mut cmd, None, Duration::from_secs(2), "sh") + .await + .expect("observed run"); + assert!(outcome.timed_out, "the 30s sleep must trip the budget"); + assert!( + String::from_utf8_lossy(&outcome.output.stdout).contains("before-hang"), + "output printed before the timeout must survive the kill: {:?}", + outcome.output.stdout + ); + assert!( + outcome.output.status.code().is_none(), + "a SIGKILLed child has no exit code on Unix" + ); + } + + #[cfg(unix)] + #[tokio::test] + async fn a_detached_success_run_leaves_a_background_process_alive() { + // The group is only signalled on the timeout path; a run that + // exits cleanly must not take an intentionally-detached `&` + // process with it. Pin that the group is never signalled + // speculatively. + let tmp = tempfile::tempdir().expect("tempdir"); + let detached_pid_file = tmp.path().join("detached.pid"); + // $! is the backgrounded sleep; $$ would be the shell, which + // legitimately exits with the run. + let script = format!("sleep 30 & echo $! > {}", detached_pid_file.display()); + let mut cmd = shell_command(&script); + let outcome = run_bounded_child_observed(&mut cmd, None, Duration::from_secs(20), "sh") + .await + .expect("observed run"); + assert!(!outcome.timed_out); + assert!(outcome.output.status.success()); + + let detached: libc::pid_t = std::fs::read_to_string(&detached_pid_file) + .expect("detached pid") + .trim() + .parse() + .expect("detached pid integer"); + let alive = unsafe { libc::kill(detached, 0) } == 0; + assert!( + alive, + "the backgrounded sleep {detached} died without a group signal" + ); + unsafe { + libc::kill(detached, libc::SIGKILL); + } + assert!(pid_is_gone(detached), "cleanup"); + } } diff --git a/crates/tui/src/tools/tasks.rs b/crates/tui/src/tools/tasks.rs index 0f333222ce..a2ecc97172 100644 --- a/crates/tui/src/tools/tasks.rs +++ b/crates/tui/src/tools/tasks.rs @@ -1,7 +1,6 @@ //! Durable task, gate, and PR-attempt tools. use std::path::{Path, PathBuf}; -use std::process::Stdio; use std::time::Instant; use async_trait::async_trait; @@ -40,14 +39,12 @@ fn build_gate_command_parts(command: &str) -> (String, Vec) { fn build_gate_command(command: &str, cwd: &Path) -> Command { let (program, args) = build_gate_command_parts(command); let mut cmd = Command::new(program); - cmd.args(args) - .current_dir(cwd) - .stdout(Stdio::piped()) - .stderr(Stdio::piped()) - // The gate runs under `timeout(cmd.output())`: on timeout the future - // is dropped, and without this the child would be left running - // orphaned — the same bug the interpreter tools fixed. - .kill_on_drop(true); + // Pipe ends and the Unix process group are configured by + // run_bounded_child_observed; on timeout it kills the child's whole + // process group, which `timeout(cmd.output())` + kill_on_drop could not + // do — the kill targeted the direct child only, orphaning any command + // the shell had forked. + cmd.args(args).current_dir(cwd); cmd } @@ -634,27 +631,45 @@ impl TasksTool { let started = Instant::now(); let mut cmd = build_gate_command(&command, &cwd); - let output = - tokio::time::timeout(std::time::Duration::from_millis(timeout_ms), cmd.output()).await; + // A gate that could not even spawn is still gate evidence, so the + // runner's error is recorded as `spawn_error` instead of surfacing + // a tool error no classifier can describe. + let (exit_code, stdout, stderr, timed_out, spawn_error) = + match crate::tools::process::run_bounded_child_observed( + &mut cmd, + None, + std::time::Duration::from_millis(timeout_ms), + "gate", + ) + .await + { + Ok(outcome) => { + // A timed-out gate is SIGKILLed and never reported a + // code, so keep the exit code absent: hook `exit_code` + // conditions must not match on a fabricated one (the + // conventional 128+SIGKILL doubles as the OOM-kill + // code), and `timed_out` beside it is the timeout + // signal. + let exit_code = outcome.output.status.code(); + let timed_out = outcome.timed_out; + ( + exit_code, + String::from_utf8_lossy(&outcome.output.stdout).to_string(), + String::from_utf8_lossy(&outcome.output.stderr).to_string(), + timed_out, + None, + ) + } + Err(e) => ( + None, + String::new(), + String::new(), + false, + Some(e.to_string()), + ), + }; let duration_ms = u64::try_from(started.elapsed().as_millis()).unwrap_or(u64::MAX); - let (exit_code, stdout, stderr, timed_out, spawn_error) = match output { - Ok(Ok(out)) => ( - out.status.code(), - String::from_utf8_lossy(&out.stdout).to_string(), - String::from_utf8_lossy(&out.stderr).to_string(), - false, - None, - ), - Ok(Err(err)) => ( - None, - String::new(), - String::new(), - false, - Some(err.to_string()), - ), - Err(_) => (None, String::new(), String::new(), true, None), - }; let full_log = format!( "$ {command}\n\n[stdout]\n{stdout}\n\n[stderr]\n{stderr}\n{}", @@ -712,6 +727,9 @@ impl TasksTool { "artifacts": artifact_updates("gate_log", log_path.clone(), &summary) } }); + if let Some(err) = &spawn_error { + metadata["spawn_error"] = json!(err); + } if let Some(path) = log_path { metadata["artifact_path"] = json!(path); } @@ -1315,6 +1333,128 @@ mod tests { use super::*; use crate::tools::spec::ToolSpec; + #[cfg(unix)] + #[tokio::test] + async fn gate_timeout_kills_the_child_instead_of_orphaning_it() { + // The gate used to run under `timeout(cmd.output())` + kill_on_drop: + // the kill targeted the direct child only, so a command the shell + // had forked (`... & sleep 60`) outlived the gate's whole lifecycle + // and kept leaking past every retry. The gate now runs on the shared + // bounded runner, whose timeout SIGKILLs the child's process group. + // Pin that a forked grandchild dies with it, not just the shell. + let tmp = tempfile::tempdir().expect("tempdir"); + let child_pid_file = tmp.path().join("gate.pid"); + let grandchild_pid_file = tmp.path().join("gate-grandchild.pid"); + let command = format!( + "echo $$ > {}; sleep 60 & echo $! > {}; sleep 60", + child_pid_file.display(), + grandchild_pid_file.display(), + ); + let mut cmd = build_gate_command(&command, tmp.path()); + let started = std::time::Instant::now(); + // 5s, not human-scale-tight: `build_gate_command` runs a login + // shell that sources the profile files, and a slow runner must not + // flake the spawn before `echo $$` lands. + let outcome = crate::tools::process::run_bounded_child_observed( + &mut cmd, + None, + std::time::Duration::from_secs(5), + "gate", + ) + .await + .expect("observed run"); + assert!(outcome.timed_out, "sleep 60 must hit the gate deadline"); + assert!( + started.elapsed() < std::time::Duration::from_secs(15), + "the gate call must return at the deadline, not at the child's sleep" + ); + + let child: libc::pid_t = std::fs::read_to_string(&child_pid_file) + .expect("gate child pid") + .trim() + .parse() + .expect("pid integer"); + let grandchild: libc::pid_t = std::fs::read_to_string(&grandchild_pid_file) + .expect("grandchild pid") + .trim() + .parse() + .expect("pid integer"); + let gone = |pid: libc::pid_t, what: &str| { + let deadline = std::time::Instant::now() + std::time::Duration::from_secs(5); + loop { + // kill(pid, 0) stays 0 for a zombie, so this only passes + // once the kill was sent AND the process was reaped — a + // group-killed orphan is reparented to init when its parent + // dies first, so allow a short reaping race. + if unsafe { libc::kill(pid, 0) } != 0 { + return; + } + assert!( + std::time::Instant::now() < deadline, + "{what} {pid} still alive after the timeout kill" + ); + std::thread::sleep(std::time::Duration::from_millis(50)); + } + }; + gone(child, "gate child"); + gone(grandchild, "gate grandchild"); + } + + #[cfg(unix)] + #[tokio::test] + async fn gate_command_not_found_is_not_a_spawn_error() { + // The gate shell is a hardcoded /bin/sh -lc, so on a healthy Unix + // host the runner always spawns and a bogus command surfaces as + // the shell's exit 127. That must stay structured evidence with no + // fabricated `spawn_error` (the classifier reads that field as an + // environment failure): record the 127 instead. + let tmp = tempfile::tempdir().expect("tempdir"); + let gate = TasksTool::alias("task_gate_run", "gate_run"); + let context = ToolContext::new(tmp.path().to_path_buf()); + let result = gate + .execute( + json!({ + "gate": "test", + "command": "exec definitely-not-a-real-shell-binary", + "timeout_ms": 5000, + }), + &context, + ) + .await + .expect("gate evidence, not a raise"); + let meta = result.metadata.expect("gate metadata"); + assert!(!meta["spawn_error"].is_string(), "{meta}"); + assert_eq!(meta["exit_code"].as_i64(), Some(127), "{meta}"); + assert!(meta["timed_out"].as_bool() == Some(false), "{meta}"); + } + + #[cfg(unix)] + #[tokio::test] + async fn gate_timeout_records_no_exit_code() { + // A timed-out gate is SIGKILLed: the child never reported an exit + // code, and hook `exit_code` conditions must not match on a + // fabricated one (`128+SIGKILL` doubles as the OOM-kill code). The + // record carries `timed_out: true` as the timeout signal instead, + // and the hook surface must read the absence as "no exit code". + let tmp = tempfile::tempdir().expect("tempdir"); + let gate = TasksTool::alias("task_gate_run", "gate_run"); + let context = ToolContext::new(tmp.path().to_path_buf()); + let result = gate + .execute( + json!({ + "gate": "test", + "command": "sleep 30", + "timeout_ms": 500, + }), + &context, + ) + .await + .expect("gate evidence, not a raise"); + let meta = result.metadata.as_ref().expect("gate metadata"); + assert!(meta["exit_code"].is_null(), "{meta}"); + assert_eq!(meta["timed_out"].as_bool(), Some(true), "{meta}"); + } + #[test] fn durable_task_schema_requires_prompt() { let schema = TasksTool::alias("task_create", "create").input_schema(); diff --git a/crates/tui/src/tools/web/contract.rs b/crates/tui/src/tools/web/contract.rs index d71ebba0c5..cc85faeb39 100644 --- a/crates/tui/src/tools/web/contract.rs +++ b/crates/tui/src/tools/web/contract.rs @@ -322,6 +322,7 @@ mod tests { #[test] fn retrieval_defaults_are_coherent_across_search_and_fetch() { use super::super::fetch::{DEFAULT_TIMEOUT, HARD_MAX_TIMEOUT}; + use crate::tools::spec::ToolSpec; // Search and fetch share one default timeout so the two halves of // the retrieval path behave identically by default. The fetch hard @@ -331,6 +332,22 @@ mod tests { u128::from(DEFAULT_SEARCH_TIMEOUT_MS), DEFAULT_TIMEOUT.as_millis() ); + // Pin the absolute value too: the fetch_url schema advertises + // "max 300,000" in milliseconds, and only this test binds that + // number to the constant. + assert_eq!(HARD_MAX_TIMEOUT.as_millis(), 300_000); + // Bind the schema text itself to the constant: the description is a + // hand-written string (fetch_url's `json!` schema), and a drift to + // any other number — or dropping the property outright — must fail + // here, not just on the constant above. + let schema = crate::tools::fetch_url::FetchUrlTool.input_schema(); + let description = schema["properties"]["timeout_ms"]["description"] + .as_str() + .expect("fetch_url schema must keep the timeout_ms description"); + assert!( + description.contains("max 300,000"), + "fetch_url schema text must match HARD_MAX_TIMEOUT (300,000 ms); got {description}" + ); assert!(HARD_MAX_TIMEOUT.as_millis() >= u128::from(MAX_SEARCH_TIMEOUT_MS)); assert!(DEFAULT_SEARCH_RESULTS <= usize::from(MAX_SEARCH_RESULTS)); } diff --git a/crates/tui/src/tools/web/fetch.rs b/crates/tui/src/tools/web/fetch.rs index 7563aef477..08211fba48 100644 --- a/crates/tui/src/tools/web/fetch.rs +++ b/crates/tui/src/tools/web/fetch.rs @@ -17,7 +17,10 @@ use crate::tools::spec::{ToolContext, ToolError}; pub(crate) const DEFAULT_TIMEOUT: Duration = Duration::from_secs(15); // 300s hard max: the previous 60s cap made any page needing more than // ~1.3 Mbps of effective throughput unfetchable, and this bound covers the -// whole request including body streaming (10 MB bodies are allowed). +// whole HTTP request including body streaming (10 MB bodies are allowed). +// The initial SSRF pre-flight DNS lookup runs before the envelope starts +// and is bounded separately (10s in the guard), so worst-case wall clock +// is the envelope plus one bounded lookup. pub(crate) const HARD_MAX_TIMEOUT: Duration = Duration::from_secs(300); pub(crate) const DEFAULT_MAX_BYTES: usize = 1_000_000; pub(crate) const HARD_MAX_BYTES: usize = 10 * 1024 * 1024; diff --git a/crates/tui/src/vision/tools.rs b/crates/tui/src/vision/tools.rs index 24cf153988..f3d5ace217 100644 --- a/crates/tui/src/vision/tools.rs +++ b/crates/tui/src/vision/tools.rs @@ -30,7 +30,10 @@ pub struct ImageAnalyzeTool { /// client therefore bounds only the connect handshake, and this envelope /// (the same 30-minute budget as non-streaming model requests) is the sole /// total bound; a stalled connection errors out through it instead of -/// hanging. +/// hanging. The envelope is shared across retry attempts, not per attempt: +/// an attempt that fails slowly consumes its share of the one budget, so +/// only retries of fast failures (connect errors, quick 5xx) fit before +/// the shared envelope expires. const VISION_REQUEST_ENVELOPE: Duration = Duration::from_secs(1800); fn vision_request_envelope() -> Duration { @@ -288,12 +291,15 @@ impl ToolSpec for ImageAnalyzeTool { enabled: true, ..Default::default() }; - let _inference = match self.route_client.as_ref() { - Some(client) => client.acquire_remote_control_inference_permit().await, - None => Some(crate::client::acquire_remote_control_inference_participant().await), - }; - let response_json = tokio::time::timeout(vision_request_envelope(), async { + // Acquire inside the envelope: the ownership window is part of + // the bounded call, so a contested permit cannot park this tool + // (and its share of Runtime Chat availability) outside every + // total bound. The guard is still held for the whole request. + let _inference = match self.route_client.as_ref() { + Some(client) => client.acquire_remote_control_inference_permit().await, + None => Some(crate::client::acquire_remote_control_inference_participant().await), + }; let response = with_retry( &retry_config, || { @@ -338,11 +344,8 @@ impl ToolSpec for ImageAnalyzeTool { Ok(json) }) .await - .map_err(|_| { - ToolError::execution_failed(format!( - "Vision API request timed out after {}s", - vision_request_envelope().as_secs() - )) + .map_err(|_| ToolError::Timeout { + seconds: vision_request_envelope().as_secs(), })??; let content = response_json @@ -774,6 +777,15 @@ mod tests { .execute(json!({"image_path": "sample.png"}), &ctx) .await .expect_err("a provider that never answers must hit the envelope"); + // The variant matters, not just the text: both this Timeout variant + // and the pre-fix execution_failed form render "timed out after", + // so a text-only assertion would not catch a classification + // regression (the variant drives the error taxonomy, telemetry, and + // the wire `ToolCallError::Timeout` shape). + assert!( + matches!(err, ToolError::Timeout { .. }), + "envelope timeout must classify as ToolError::Timeout; got {err:?}" + ); assert!( err.to_string().contains("timed out after"), "envelope timeout must be reported as such; got {err}" diff --git a/docs/MCP.md b/docs/MCP.md index 587d0b20e5..596c4b3a1f 100644 --- a/docs/MCP.md +++ b/docs/MCP.md @@ -438,10 +438,14 @@ Per-server settings: - `env` (object, optional) - `connect_timeout`, `execute_timeout`, `read_timeout` (seconds, optional) - Defaults: `connect_timeout` 10s, `execute_timeout` 1800s (30 min), `read_timeout` 120s. - `execute_timeout` bounds a whole tool call — a server is silent until its tool + `execute_timeout` bounds a tool call — a server is silent until its tool finishes, so slow tools need this raised, not `read_timeout`. `read_timeout` bounds the response wait of quick requests (`resources/read`, discovery, …); a `tools/call` wait is automatically widened to at least its `execute_timeout`. + For stdio servers the budget applies per leg (send, then read): a server that + drains its input barely within the budget can push the total toward twice + `execute_timeout`. An HTTP server is bounded by a single total timeout of + `max(read_timeout, execute_timeout)` for the whole exchange. - `disabled` (bool, optional) - `enabled` (bool, optional, default `true`) - `required` (bool, optional): startup/connect validation fails if this server cannot initialize. @@ -456,6 +460,13 @@ Per-server settings: - `oauth.client_id` (string, optional): pre-registered OAuth client ID. - `oauth_resource` (string, optional): resource parameter appended to the authorization URL. +Headless runs reach stdio servers through the engine-side stdio proxy instead +of these timeout settings (per-server `command`/`args`/`env` still apply); it +uses fixed budgets (30s handshake, 120s request, 1800s tool call). Its send leg is a blocking write under the connection lock and is +deliberately not deadline-bounded (disclosed debt, noted at the write site in +`codewhale-mcp`): a server that stops draining stdin can park that write past +every budget. + ## Safety Notes MCP tools flow through the same approval framework as built-in tools. Read-only diff --git a/docs/RUNTIME_API.md b/docs/RUNTIME_API.md index 8cd938e7e2..07c7e5cef5 100644 --- a/docs/RUNTIME_API.md +++ b/docs/RUNTIME_API.md @@ -774,14 +774,15 @@ the first returned event advances past exactly the omitted history. `/v1/snapshots` lists recent side-git restore points for the runtime workspace. `limit` defaults to `20` and must be between `1` and `100`. `POST /v1/snapshots/{id}/restore` restores workspace files from the snapshot and -returns `{"restored": ""}`. The `id` must match a listed -snapshot exactly (full id, case-sensitive); an unknown or malformed id -returns `404` before any git command runs. +returns `{"restored": ""}`. The `id` must match any snapshot +the side repo actually knows — including entries beyond the default listing +window — exactly (full id, case-sensitive); an unknown or malformed id +returns `404`, and a non-matching id is never passed to any git command. ```json [ { - "id": "snap_...", + "id": "9f2c7a01e5b34d6a89c0f1a2b3c4d5e6f708192a", "label": "post-turn:1", "timestamp": 1780730580 } @@ -1112,7 +1113,8 @@ Common event names: `thread.started`, `thread.forked`, `turn.started`, `turn.lifecycle`, `turn.steered`, `turn.interrupt_requested`, `turn.completed`, `item.started`, `item.delta`, `item.completed`, `item.failed`, `item.interrupted`, `approval.required`, `approval.decided`, -`approval.timeout`, `user_input.required`, `user_input.answered`, +`approval.timeout` (legacy, replay-only — see below), `user_input.required`, +`user_input.answered`, `user_input.canceled`, `tool_call.requested`, `tool_call.resolved`, `tool_call.timeout`, `tool_call.canceled`, `sandbox.denied`. @@ -1133,11 +1135,23 @@ Approval decisions wait for a human and have no wall-clock cap: a pending approval is resolved by a client decision, by interrupting the turn, or when the engine goes away. (Runtime shutdown can also resolve it via `RuntimeThreadManager::shutdown`, but no host invokes that API yet — it is -exercised by tests until a host wires it into its exit path.) Every resolution is published as -`approval.decided` so clients can clear pending UI. A resolution forced by an +exercised by tests until a host wires it into its exit path.) Every +resolution of an approval whose `approval.required` event was published is +itself published as `approval.decided` so clients can clear pending UI. (If +the `approval.required` event itself fails to publish, the pending +registration is rolled back, the tool call never executes, and the turn ends +in error with no `approval.decided` — no client ever saw the request.) A +resolution forced by an interrupt, shutdown, or engine exit carries `decision: "deny"` plus `interrupted: true` (and no user selection was made); a decision the user -actually made never carries `interrupted`. `approval.timeout` and the `timeout` +actually made never carries `interrupted`. `approval.decided` also carries +`posture` when an execution-policy posture **deny** rather than a human +forced the outcome; it is absent for every other decision on the raw event +stream (automatic non-posture resolutions carry `auto: true` instead), and +the compat `/v1/stream` maps the absent field to `null`. A decision posted to +`/v1/approvals/{id}` either resolves the approval (and is published as that +decision) or is rejected with 404 — it is never accepted and then replaced by +an interrupted deny. `approval.timeout` and the `timeout` field on `approval.decided` are legacy shapes produced only by journals written by older builds; current code never emits them. diff --git a/docs/SUBAGENTS.md b/docs/SUBAGENTS.md index 06e1e689b5..e40c7a4ca8 100644 --- a/docs/SUBAGENTS.md +++ b/docs/SUBAGENTS.md @@ -434,8 +434,10 @@ from, in order: (`WorkerRuntimeProfile::default_max_steps` returns zero), plus a **1800 s** wall-clock default. -Omitted or zero `max_steps` remains unbounded even when an operator default is -configured; positive step values clamp to the 2000-turn hard ceiling. +An explicit zero `max_steps` stays unbounded even when an operator default is +configured; an omitted `max_steps` falls back to that operator default (the +fleet role default otherwise), and positive step values clamp to the +2000-turn hard ceiling. Wall-time values clamp to 1..=86400 s. ## Token budget governor @@ -594,6 +596,15 @@ progress at step boundaries, not mid-tool, so a silent build or MCP call must not be cleaned up mid-run), so neither a configured long model request nor a long in-flight tool is cancelled before its own timeout can fire. +These floors only keep the heartbeat from firing early; they do not outrank +the wall clocks above them. Every sub-agent runs under its own wall time +(`default_wall_time_secs`, 1800 seconds by default), and inside a durable task +the task's `wall_time` (default 30 minutes, measured from task start, and +running while a prompt waits on a human) bounds the whole run. A maximal +1800-second tool started late in a child or a task can therefore still be +interrupted by either deadline; raising `execute_timeout` above the remaining +wall time has no effect. + ## Lifecycle Each opened session produces a record that progresses through: diff --git a/docs/zh_hans/MCP.md b/docs/zh_hans/MCP.md index ed828c4bca..47a072a205 100644 --- a/docs/zh_hans/MCP.md +++ b/docs/zh_hans/MCP.md @@ -343,9 +343,12 @@ codewhale-tui mcp tools codewhale - `env`(对象,可选) - `connect_timeout`、`execute_timeout`、`read_timeout`(秒,可选) - 默认值:`connect_timeout` 10 秒、`execute_timeout` 1800 秒(30 分钟)、`read_timeout` 120 秒。 - `execute_timeout` 约束一次完整的工具调用——工具结束前服务器不会回话,慢工具应调大它而不是 + `execute_timeout` 约束一次工具调用——工具结束前服务器不会回话,慢工具应调大它而不是 `read_timeout`。`read_timeout` 约束快速请求(`resources/read`、发现流程等)的响应等待; `tools/call` 的内部读等待会自动放宽到至少其 `execute_timeout`。 + 对 stdio 服务器,该预算按阶段生效(发送、读取各计一次):几乎耗尽预算才读完输入的服务器 + 可能让总耗时接近 `execute_timeout` 的两倍。HTTP 服务器则由单个总超时 + `max(read_timeout, execute_timeout)` 约束整个交换。 - `disabled`(布尔值,可选) - `enabled`(布尔值,可选,默认 `true`) - `required`(布尔值,可选):如果该服务器无法初始化,启动/连接验证会失败。 @@ -360,6 +363,12 @@ codewhale-tui mcp tools codewhale - `oauth.client_id`(字符串,可选):预先注册的 OAuth 客户端 ID。 - `oauth_resource`(字符串,可选):附加到授权 URL 的资源参数。 +无头运行通过引擎侧的 stdio 代理访问 stdio 服务器,不使用这些超时设置(各服务器的 +`command`/`args`/`env` 仍然生效);代理使用固定预算 +(握手 30 秒、请求 120 秒、工具调用 1800 秒)。其发送腿是持有连接锁的阻塞写入,刻意 +不做超时约束(已披露的债务,见 `codewhale-mcp` 写入点处的说明):不再读取 stdin 的 +stdio 服务器可以让该写入阻塞超过任何预算。 + ## 安全说明 MCP 工具与内置工具走相同的审批框架。只读的 MCP 辅助工具(资源/提示的列出与读取)在策略允许时,可以在 Ask 和 Auto-Review 中无提示地运行,而会产生副作用的 MCP 工具则需要审批。Full Access 不会绕过强制性的策略拦截。 diff --git a/docs/zh_hans/SUBAGENTS.md b/docs/zh_hans/SUBAGENTS.md index 2a39bf9863..fd1d73b86b 100644 --- a/docs/zh_hans/SUBAGENTS.md +++ b/docs/zh_hans/SUBAGENTS.md @@ -160,8 +160,9 @@ max_concurrent = 20 launch_concurrency = 20 max_admitted = 200 max_depth = 6 -# 调用不带预算时的每个子代理运行预算(角色默认:60/120 回合)。 -default_max_steps = 120 +# 调用不带预算时的每个子代理运行预算。模型回合预算省略或为零时不设上限; +# 仅当操作者确实需要每个子代理的回合上限时才设正值。 +default_max_steps = 0 default_wall_time_secs = 1800 token_budget = 100000 @@ -217,9 +218,11 @@ max_admitted = 12 1. 调用上一个显式的、解析接受的 `max_steps` / `wall_time_secs`(重放兼容), 2. 操作者默认 `[subagents] default_max_steps` 和 `[subagents] default_wall_time_secs`, -3. Fleet 角色默认:读取为主的角色(scout/planner/reviewer/verifier/consultant)为 **60** 个模型回合,builder/worker/custom 为 **120**(`WorkerRuntimeProfile::default_max_steps`),墙钟默认 **1800 秒**。 +3. Fleet 角色默认:所有角色的模型回合数**不设上限**(`WorkerRuntimeProfile::default_max_steps` 返回零),墙钟默认 **1800 秒**。 -步数值钳制到 2000 回合的硬上限;墙钟值钳制到 1..=86400 秒。 +显式为零的 `max_steps` 即使在操作者默认已配置时仍不设上限;省略 `max_steps` +时落到操作者默认(未配置则为角色默认),正值钳制到 2000 回合的硬上限。 +墙钟值钳制到 1..=86400 秒。 ## Token 预算调节器 @@ -319,6 +322,8 @@ heartbeat_timeout_secs = 300 # 钳制到 30..=3600 有效心跳至少保持在解析后的 `api_timeout_secs` 与内置子代理工具超时之上各 30 秒(子代理只在步骤边界记录进度,不会在工具执行中途记录,因此静默的构建或 MCP 调用不能在运行中被清理),所以配置的长模型请求与长时间在途工具都不会在自己的超时触发之前被取消。 +这些下限只保证心跳不会提前触发,并不凌驾于其上的墙钟:每个子代理都受自身墙钟(`default_wall_time_secs`,默认 1800 秒)约束;在持久任务内部,任务 `wall_time`(默认 30 分钟,自任务启动起算,等待人工回应提示期间照常计时)约束整个运行。因此在子代理或任务后段启动的满额 1800 秒工具仍可能被任一截止时间中断;把 `execute_timeout` 调到超过剩余墙钟不会生效。 + ## 生命周期 每个打开的会话产生一条记录,按以下顺序推进: