diff --git a/crates/app-server/src/chat_completions.rs b/crates/app-server/src/chat_completions.rs index cf072f8ddd..f767714b38 100644 --- a/crates/app-server/src/chat_completions.rs +++ b/crates/app-server/src/chat_completions.rs @@ -27,6 +27,20 @@ use serde_json::Value; use super::AppState; +// ── Upstream deadlines ───────────────────────────────────────────────── + +/// Connect budget for the upstream forward. Matches the connect family +/// used across the TUI client (vision, installs, DNS pre-flight). +const UPSTREAM_CONNECT_TIMEOUT: std::time::Duration = std::time::Duration::from_secs(10); + +/// Total budget for one upstream forward, connect through body end. The +/// handler rejects streaming (`stream: true`) and reads the full upstream +/// body, so without a client-level total a provider that accepts the +/// connection and stalls — or trickles the body — wedges this handler (and +/// the caller's connection) indefinitely. 1800s mirrors the TUI client's +/// non-streaming envelope for the same request class. +const UPSTREAM_TOTAL_TIMEOUT: std::time::Duration = std::time::Duration::from_secs(1800); + // ── Resolved endpoint ────────────────────────────────────────────────── /// Everything needed to forward a single chat-completions request upstream. @@ -373,8 +387,12 @@ pub(crate) async fn chat_completions_handler( .into_response(); } - // Build upstream request. + // 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. let upstream_req = codewhale_release::platform_http_client_builder() + .connect_timeout(UPSTREAM_CONNECT_TIMEOUT) + .timeout(UPSTREAM_TOTAL_TIMEOUT) .build() .map_err(|e| { ( diff --git a/crates/app-server/src/lib.rs b/crates/app-server/src/lib.rs index 373ab3c4c5..fed49258e3 100644 --- a/crates/app-server/src/lib.rs +++ b/crates/app-server/src/lib.rs @@ -1399,6 +1399,30 @@ async fn invalidate_runtime_bridge(state: &AppState) { *bridge = None; } +// ── Runtime bridge deadlines ──────────────────────────────────────────── + +/// Connect budget for one bridge request. The bridge talks to a runtime +/// child this process spawned on loopback, so a connect that has not +/// completed in 10s means the child's listener is wedged. +const RUNTIME_BRIDGE_CONNECT_TIMEOUT: std::time::Duration = std::time::Duration::from_secs(10); + +/// Total budget for one bridging POST (`/v1/threads`, `/v1/threads/{id}/turns`). +/// These requests enqueue work and return; the turn itself streams over SSE. +/// Without a total, a runtime child that is alive but wedged (async workers +/// starved by a blocking tool call, a lock deadlock in the turn-start path) +/// hangs the request forever — and the inner bridge lock is held for the +/// whole turn, so one hung request queues every later JSON-RPC message +/// behind it. Mirrors the TUI client's non-streaming envelope. +const RUNTIME_BRIDGE_REQUEST_TIMEOUT: std::time::Duration = std::time::Duration::from_secs(1800); + +/// Idle budget between SSE chunks on the event stream. The runtime emits a +/// keepalive every 15s, so silence beyond this means the child's event +/// stream wedged; the idle bound catches it without capping the total +/// duration of a live stream (a per-request total would ride the body and +/// hard-cut long turns — the same trap the model client's stream-open path +/// avoids). +const RUNTIME_BRIDGE_SSE_IDLE_TIMEOUT: std::time::Duration = std::time::Duration::from_secs(60); + impl RuntimeBridge { async fn start(config_path: Option<&Path>) -> Result { install_rustls_crypto_provider(); @@ -1410,6 +1434,7 @@ impl RuntimeBridge { let mut bridge = Self { base_url: format!("http://127.0.0.1:{port}"), client: codewhale_release::platform_http_client_builder() + .connect_timeout(RUNTIME_BRIDGE_CONNECT_TIMEOUT) .build() .context("failed to build runtime API client")?, auth_token: Some(auth_token), @@ -1487,7 +1512,10 @@ impl RuntimeBridge { } async fn request_json(&self, builder: reqwest::RequestBuilder) -> Result { - let response = builder.send().await?; + let response = builder + .timeout(RUNTIME_BRIDGE_REQUEST_TIMEOUT) + .send() + .await?; let status = response.status(); let body = response.text().await?; if !status.is_success() { @@ -1683,19 +1711,38 @@ impl RuntimeBridge { since_seq: u64, mut transcript: Option<&mut TurnTranscript>, ) -> Result<(u64, TurnTerminalStatus, Option)> { - let mut response = self - .authed(self.client.get(format!( + // 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 + // for the body. The header wait shares that idle deadline; a per- + // request total is deliberately absent because reqwest's total would + // ride the returned body and hard-cut the live stream. + let mut response = tokio::time::timeout( + RUNTIME_BRIDGE_SSE_IDLE_TIMEOUT, + self.authed(self.client.get(format!( "{}/v1/threads/{thread_id}/events?since_seq={since_seq}", self.base_url ))) - .send() - .await? - .error_for_status()?; + .send(), + ) + .await + .context("runtime event stream stalled before the first byte")?? + .error_for_status()?; let mut buffer = Vec::new(); let mut last_seq = since_seq; - while let Some(chunk) = response.chunk().await? { + // The event stream only ever pauses for the runtime's 15s + // keepalives; anything longer means the child wedged mid-stream. + // The idle bound re-arms per chunk, so a live stream of any length + // is never total-capped. + loop { + let chunk = tokio::time::timeout(RUNTIME_BRIDGE_SSE_IDLE_TIMEOUT, response.chunk()) + .await + .context("runtime event stream stalled past the idle deadline")??; + let Some(chunk) = chunk else { + break; + }; buffer.extend_from_slice(&chunk); if buffer.len() > MAX_SSE_FRAME_BYTES { bail!( diff --git a/crates/cli/src/update.rs b/crates/cli/src/update.rs index b0af2b4104..3e64e6a2c1 100644 --- a/crates/cli/src/update.rs +++ b/crates/cli/src/update.rs @@ -31,9 +31,11 @@ const GITHUB_RELEASE_DOWNLOAD_BASE_URL: &str = "https://github.com/Hmbown/CodeWhale/releases/download"; const UPDATE_HTTP_ATTEMPTS: usize = 3; const UPDATE_HTTP_RETRY_DELAY_MS: u64 = 100; -/// Ceiling for one asset download. Generous, because release binaries are tens -/// of megabytes and some of the networks this exists for are slow. -const UPDATE_DOWNLOAD_TIMEOUT: Duration = Duration::from_secs(5 * 60); +/// 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). +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 /// connection and then stalls. GitHub gets the first attempt; an unavailable diff --git a/crates/core/src/lib.rs b/crates/core/src/lib.rs index 4cfe6ffd86..c1b9ce71cb 100644 --- a/crates/core/src/lib.rs +++ b/crates/core/src/lib.rs @@ -40,13 +40,15 @@ use serde_json::{Value, json}; use tokio::time; use uuid::Uuid; -/// Per-tool dispatch budget for the headless runtime. Matches the generous -/// subagent default so long-running tools are not cut off prematurely. +/// 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. fn tool_dispatch_timeout() -> Duration { if cfg!(test) { Duration::from_millis(50) } else { - Duration::from_secs(300) + Duration::from_secs(1800) } } diff --git a/crates/mcp/src/stdio_client.rs b/crates/mcp/src/stdio_client.rs index 8debf5734a..a948dca558 100644 --- a/crates/mcp/src/stdio_client.rs +++ b/crates/mcp/src/stdio_client.rs @@ -30,8 +30,15 @@ const PROTOCOL_VERSION: &str = "2024-11-05"; /// because a first `npx`/`uvx` launch may download the server package. const HANDSHAKE_TIMEOUT: Duration = Duration::from_secs(30); -/// Budget for a single request once the server is up. +/// Budget for a single request once the server is up. `tools/call` gets a +/// separate, much longer budget (`CALL_TOOL_TIMEOUT`): a tool legitimately +/// runs minutes (scrapes, remote jobs, builds), and killing it at 2 minutes +/// returned "timed out" to the model for healthy work. const REQUEST_TIMEOUT: Duration = Duration::from_secs(120); +/// Budget for `tools/call` specifically. Matches the TUI pool's default +/// execute timeout; still bounded so a wedged server cannot hang a consumer +/// forever, but far past any legitimate tool run. +const CALL_TOOL_TIMEOUT: Duration = Duration::from_secs(1800); /// How long a dropped client waits for a graceful exit after closing stdin /// before it kills the child. @@ -709,12 +716,13 @@ impl McpManagedClient for ChildProcessMcpClient { // The server's result is returned verbatim, including an `isError` // content payload: reinterpreting it here would replace what the // server actually said with our guess about it. - self.request( + self.request_with_timeout( "tools/call", json!({ "name": tool_name, "arguments": arguments }), + CALL_TOOL_TIMEOUT, ) } diff --git a/crates/tui/src/client.rs b/crates/tui/src/client.rs index 8e2e0e31b0..3578514409 100644 --- a/crates/tui/src/client.rs +++ b/crates/tui/src/client.rs @@ -337,6 +337,34 @@ fn client_user_agent(api_provider: ApiProvider) -> &'static str { /// of committing to the full remaining window up front. const RATE_LIMIT_PAUSE_RECHECK_INTERVAL: Duration = Duration::from_millis(250); +/// Total budget for one non-streaming request. Two layers use it: the +/// per-attempt request carries it as a reqwest per-request total +/// (connect through body end, so a trickling body cannot extend forever), +/// and the retry loop through `send_with_retry` is wrapped in one outer +/// envelope of the same length (all attempts, backoff, and honored +/// Retry-After included). Streaming paths never carry it: their opens go +/// through `send_stream_open_with_retry`, which sets no per-request total +/// (a total would ride on the returned body), so a stream stays bounded by +/// its open cap and per-chunk idle checks only. Also applied to the +/// Anthropic dialect's non-streaming Messages request, which has no retry +/// loop of its own. +pub(crate) const NON_STREAMING_REQUEST_ENVELOPE: Duration = Duration::from_secs(1800); + +#[cfg(test)] +static TEST_NON_STREAMING_ENVELOPE_MS: std::sync::atomic::AtomicU64 = + std::sync::atomic::AtomicU64::new(0); + +fn non_streaming_request_envelope() -> Duration { + #[cfg(test)] + { + let ms = TEST_NON_STREAMING_ENVELOPE_MS.load(std::sync::atomic::Ordering::SeqCst); + if ms > 0 { + return Duration::from_millis(ms); + } + } + NON_STREAMING_REQUEST_ENVELOPE +} + pub(super) const SSE_BACKPRESSURE_HIGH_WATERMARK: usize = 1024 * 1024; // 1 MB pub(super) const SSE_BACKPRESSURE_SLEEP_MS: u64 = 10; pub(super) const SSE_MAX_LINES_PER_CHUNK: usize = 256; @@ -2418,12 +2446,10 @@ impl DeepSeekClient { /// List available models from the provider. pub async fn list_models(&self) -> Result> { let url = api_url(&self.base_url, "models"); + // The pinned 30s total survives: the retry loop's shared envelope is + // not allowed to overwrite a caller's own per-attempt budget. let response = self - .send_with_retry(|| { - self.http_client - .get(&url) - .timeout(NON_STREAMING_HTTP_TIMEOUT) - }) + .send_with_retry_total(NON_STREAMING_HTTP_TIMEOUT, || self.http_client.get(&url)) .await?; let status = response.status(); @@ -2859,18 +2885,84 @@ impl DeepSeekClient { } } - pub(super) async fn send_with_retry(&self, mut build: F) -> Result + pub(super) async fn send_with_retry(&self, build: F) -> Result + where + F: FnMut() -> reqwest::RequestBuilder, + { + if self.isolated_request_state { + return self.send_with_isolated_retry(build).await; + } + self.send_retry_loop(build, Some(non_streaming_request_envelope())) + .await + } + + /// `send_with_retry` with a caller-pinned per-attempt total (connect + /// through body end). `list_models` pins its own 30s: the plain variant + /// would otherwise stretch that pinned budget out to the envelope, + /// because `.timeout()` on the builder is a pure overwrite. + pub(super) async fn send_with_retry_total( + &self, + total: Duration, + build: F, + ) -> Result where F: FnMut() -> reqwest::RequestBuilder, { if self.isolated_request_state { return self.send_with_isolated_retry(build).await; } + self.send_retry_loop(build, Some(total)).await + } + + /// The streaming-open twin of [`Self::send_with_retry`]: the same retry + /// and rate-limit handling with no total deadline anywhere. reqwest's + /// per-request timeout wraps the response *body*, so a total set on the + /// open would ride along inside the returned body and hard-cut a live + /// stream mid-generation. Stream opens stay bounded by the caller's + /// `stream_open_timeout` around the open and per-chunk idle checks on + /// the returned body instead. + pub(super) async fn send_stream_open_with_retry(&self, build: F) -> Result + where + F: FnMut() -> reqwest::RequestBuilder, + { + if self.isolated_request_state { + return self.send_with_isolated_retry(build).await; + } + self.send_retry_loop(build, None).await + } + + async fn send_retry_loop( + &self, + mut build: F, + attempt_total: Option, + ) -> Result + where + F: FnMut() -> reqwest::RequestBuilder, + { let retry_cfg: LlmRetryConfig = self.retry.clone().into(); - let request_result = with_retry( + // Two bounded layers around the non-streaming completion + // (`attempt_total` = `Some`): the per-attempt request total (connect + // through body end) and an envelope around the whole retry loop (all + // attempts + backoff + honored Retry-After). The shared client + // intentionally has no client-level total timeout — streaming is + // protected per-chunk instead — so without these nothing bounds a + // non-streaming completion: a provider that accepts the connection + // and then stalls (or a gateway answering 429 + Retry-After: 3600 + // forever) wedged the caller (mid-turn compaction, translate, …) + // indefinitely. `None` (streaming opens) sets no deadline at all: + // any total here would be inherited by the returned body and + // truncate the stream, so those calls keep only the caller's own + // open budget. + let retry_future = with_retry( &retry_cfg, || { - let request = build(); + // Per-attempt total: unlike the loop envelope below, + // reqwest's per-request timeout also covers the response + // body, so a slow-drip body cannot outlive the budget. + let request = match attempt_total { + Some(total) => build().timeout(total), + None => build(), + }; async move { // Sleep in bounded slices rather than the full remaining // window: the pause is process-global, so a concurrent @@ -2903,7 +2995,7 @@ impl DeepSeekClient { )) } }, - Some(Box::new(|err, attempt, delay| { + Some(Box::new(|err: &LlmError, attempt, delay| { let (reason_label, human_reason) = retry_reason_label_and_human(err); logging::warn(format!( "HTTP retry reason={} attempt={} delay={:.2}s", @@ -2916,8 +3008,26 @@ impl DeepSeekClient { } crate::retry_status::start(attempt + 1, delay, human_reason); })), - ) - .await; + ); + let request_result = if let Some(total) = attempt_total { + // The loop envelope must dominate the per-attempt total it + // wraps: a caller-pinned budget (list_models' 30s) may exceed + // the shared envelope, and the envelope must never strangle + // its own attempts. + let loop_envelope = total.max(non_streaming_request_envelope()); + match tokio::time::timeout(loop_envelope, retry_future).await { + Ok(result) => result, + Err(_elapsed) => { + let last = LlmError::Timeout(loop_envelope); + crate::retry_status::failed(last.to_string()); + self.mark_request_failure("non-streaming request envelope exceeded") + .await; + return Err(anyhow::Error::new(last)); + } + } + } else { + retry_future.await + }; match request_result { Ok(response) => { @@ -3014,6 +3124,25 @@ impl DeepSeekClient { }) .await } + + /// JSON POST through the streaming-open retry path: no total deadline, + /// because the response body outlives the open (see + /// [`Self::send_stream_open_with_retry`]). + pub(super) async fn open_stream_json_with_retry( + &self, + url: &str, + body: &serde_json::Value, + ) -> Result { + let request_body = + serde_json::to_vec(body).context("Failed to serialize JSON request body")?; + self.send_stream_open_with_retry(|| { + self.http_client + .post(url) + .header(CONTENT_TYPE, "application/json") + .body(request_body.clone()) + }) + .await + } } /// Record that a request was routed to `provider` and came back with `status`. @@ -4356,6 +4485,147 @@ mod tests { client } + struct NonStreamingEnvelopeGuard(u64); + + impl NonStreamingEnvelopeGuard { + fn millis(ms: u64) -> Self { + Self(TEST_NON_STREAMING_ENVELOPE_MS.swap(ms, std::sync::atomic::Ordering::SeqCst)) + } + } + + impl Drop for NonStreamingEnvelopeGuard { + fn drop(&mut self) { + TEST_NON_STREAMING_ENVELOPE_MS.store(self.0, std::sync::atomic::Ordering::SeqCst); + } + } + + #[tokio::test] + async fn non_streaming_envelope_bounds_a_stalled_provider() { + // The injected budget is process-global; serialize against other + // tests (which may issue non-streaming requests with their own + // timing assumptions) through the shared test-env lock. + let _env_lock = crate::test_support::lock_test_env(); + let _envelope = NonStreamingEnvelopeGuard::millis(2000); + let server = MockServer::start().await; + // The provider accepts the connection but stalls far past the + // budgeted envelope before answering: the whole request (headers + // and body) must be cut off with a timeout instead of wedging the + // caller. + 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)), + ) + .mount(&server) + .await; + + let client = deepseek_request_boundary_client(&server.uri(), server.uri()); + let 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, + }; + + let err = client + .create_message(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:#}" + ); + } + + #[tokio::test] + async fn stream_open_retry_path_sets_no_total_deadline() { + // The injected budget is process-global; serialize against other + // tests (which may issue non-streaming requests with their own + // timing assumptions) through the shared test-env lock. + let _env_lock = crate::test_support::lock_test_env(); + let _envelope = NonStreamingEnvelopeGuard::millis(2000); + let server = MockServer::start().await; + // The open answers past the injected non-streaming envelope. The + // streaming-open path must not inherit any total: reqwest's + // per-request timeout wraps the response body, so a total set on + // the open would ride on the returned body and hard-cut a live + // stream 30 minutes in. + Mock::given(method("POST")) + .respond_with( + ResponseTemplate::new(200) + .set_body_string("data: [DONE]\n\n") + .set_delay(Duration::from_millis(2500)), + ) + .mount(&server) + .await; + + let client = deepseek_request_boundary_client(&server.uri(), server.uri()); + let response = client + .send_stream_open_with_retry(|| { + client + .http_client + .post(format!("{}/chat/completions", server.uri())) + .header(reqwest::header::CONTENT_TYPE, "application/json") + .body("{}".to_string()) + }) + .await + .expect("stream open must not carry the non-streaming envelope"); + assert!(response.status().is_success()); + let text = response.text().await.expect("read stream-open body"); + assert_eq!(text, "data: [DONE]\n\n"); + } + + #[tokio::test] + async fn pinned_request_total_survives_the_shared_retry_envelope() { + // The injected budget is process-global; serialize against other + // tests (which may issue non-streaming requests with their own + // timing assumptions) through the shared test-env lock. + let _env_lock = crate::test_support::lock_test_env(); + let _envelope = NonStreamingEnvelopeGuard::millis(2000); + let server = MockServer::start().await; + // 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. + Mock::given(method("GET")) + .respond_with( + ResponseTemplate::new(200) + .set_body_string("{}") + .set_delay(Duration::from_millis(2500)), + ) + .mount(&server) + .await; + + let client = deepseek_request_boundary_client(&server.uri(), server.uri()); + let response = client + .send_with_retry_total(Duration::from_secs(5), || { + client.http_client.get(format!("{}/models", server.uri())) + }) + .await + .expect("caller-pinned total must not be overwritten by the envelope"); + assert!(response.status().is_success()); + } + fn ollama_cloud_request_boundary_client(transport_base_url: String) -> DeepSeekClient { let mut client = DeepSeekClient::new(&Config { provider: Some("ollama-cloud".to_string()), diff --git a/crates/tui/src/client/anthropic.rs b/crates/tui/src/client/anthropic.rs index 8cf1dbba6c..9cb81b6cf3 100644 --- a/crates/tui/src/client/anthropic.rs +++ b/crates/tui/src/client/anthropic.rs @@ -214,10 +214,15 @@ impl DeepSeekClient { async fn send_anthropic_request(&self, url: &str, body: &Value) -> Result { let url = self.messages_transport_url(url); self.wait_for_rate_limit().await; + // This request is consumed non-streaming (the body is decoded as one + // JSON document), so it gets the same total budget as every other + // non-streaming completion; without it a provider that accepts and + // stalls - or trickles the body - wedged the caller indefinitely. let response = self .http_client .post(&url) .header("Accept", "text/event-stream") + .timeout(crate::client::NON_STREAMING_REQUEST_ENVELOPE) .json(body) .send() .await diff --git a/crates/tui/src/client/chat.rs b/crates/tui/src/client/chat.rs index cd5a0bc7d7..1a2c4464bb 100644 --- a/crates/tui/src/client/chat.rs +++ b/crates/tui/src/client/chat.rs @@ -1297,7 +1297,10 @@ impl DeepSeekClient { .await?) } super::stream_entry::StreamHttpPolicy::DualWithH1Fallback => { - self.send_json_with_retry(url, body).await + // Stream open: no per-request total — the response body + // outlives the open, and a total would ride on it and + // truncate the stream. + self.open_stream_json_with_retry(url, body).await } } }) diff --git a/crates/tui/src/client/responses.rs b/crates/tui/src/client/responses.rs index 59ab598939..0d4d07a46b 100644 --- a/crates/tui/src/client/responses.rs +++ b/crates/tui/src/client/responses.rs @@ -193,7 +193,10 @@ impl DeepSeekClient { self.http1_fallback_client(), policy, ); - self.send_with_retry(|| { + // Stream open: no per-request total — the response body + // outlives the open, and a total would ride on it and + // truncate the stream. + self.send_stream_open_with_retry(|| { let mut builder = client .post(&url) .header("Content-Type", "application/json") diff --git a/crates/tui/src/commands/groups/config/config.rs b/crates/tui/src/commands/groups/config/config.rs index 1c163a84bb..b8476a6027 100644 --- a/crates/tui/src/commands/groups/config/config.rs +++ b/crates/tui/src/commands/groups/config/config.rs @@ -4371,8 +4371,11 @@ heartbeat_timeout_secs = 1 "subagents.api_timeout_secs = 0 (resolved global 600; active provider 600)" ) ); + // api_timeout 0 -> default 600, so the api floor is 630; but the + // heartbeat floor also sits above the 1800s sub-agent tool timeout + // (plus 30s), so the resolved value is 1830. assert!(msg.contains( - "subagents.heartbeat_timeout_secs = 1 (resolved global 630; active provider 630)" + "subagents.heartbeat_timeout_secs = 1 (resolved global 1830; active provider 1830)" )); assert!(msg.contains("subagents.providers.deepseek = inherits global")); } diff --git a/crates/tui/src/config/subagent_limits.rs b/crates/tui/src/config/subagent_limits.rs index 1a89e7207e..843de48dae 100644 --- a/crates/tui/src/config/subagent_limits.rs +++ b/crates/tui/src/config/subagent_limits.rs @@ -39,7 +39,12 @@ pub const MAX_SUBAGENT_API_TIMEOUT_SECS: u64 = 3600; /// `tools::subagent::DEFAULT_TOOL_TIMEOUT` derives from it, so the heartbeat /// floor below and the timeout actually applied to a running tool can never /// drift apart. -pub const DEFAULT_SUBAGENT_TOOL_TIMEOUT_SECS: u64 = 300; +/// 1800s (was 300s): a single build, test suite, or MCP-backed call +/// 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. +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). pub const DEFAULT_SUBAGENT_HEARTBEAT_TIMEOUT_SECS: u64 = 300; diff --git a/crates/tui/src/config/tests.rs b/crates/tui/src/config/tests.rs index c6a65bbfbc..86733f1886 100644 --- a/crates/tui/src/config/tests.rs +++ b/crates/tui/src/config/tests.rs @@ -3007,7 +3007,10 @@ fn subagent_heartbeat_timeout_defaults_clamps_and_respects_api_timeout() { DEFAULT_SUBAGENT_TOOL_TIMEOUT_SECS + 30 ); - let follows_long_api_timeout = Config { + // With a 900s api timeout the api floor is 930, but the tool-timeout + // floor (1800s tool timeout + 30s) dominates it, so the resolved value + // is 1830 — a heartbeat cleanup must never fire before the tool floor. + let tool_floor_dominates_api_floor = Config { subagents: Some(SubagentsConfig { api_timeout_secs: Some(900), heartbeat_timeout_secs: Some(300), @@ -3016,8 +3019,23 @@ fn subagent_heartbeat_timeout_defaults_clamps_and_respects_api_timeout() { ..Config::default() }; assert_eq!( - follows_long_api_timeout.subagent_heartbeat_timeout_secs(), - 930 + tool_floor_dominates_api_floor.subagent_heartbeat_timeout_secs(), + DEFAULT_SUBAGENT_TOOL_TIMEOUT_SECS + 30 + ); + + // A genuinely long api timeout still wins (up to the heartbeat clamp): + // 3600s api floor is 3630, clamped to the 3600s heartbeat maximum. + let follows_maxed_api_timeout = Config { + subagents: Some(SubagentsConfig { + api_timeout_secs: Some(MAX_SUBAGENT_API_TIMEOUT_SECS), + heartbeat_timeout_secs: Some(300), + ..SubagentsConfig::default() + }), + ..Config::default() + }; + assert_eq!( + follows_maxed_api_timeout.subagent_heartbeat_timeout_secs(), + MAX_SUBAGENT_HEARTBEAT_TIMEOUT_SECS ); let high = Config { diff --git a/crates/tui/src/core/engine/approval.rs b/crates/tui/src/core/engine/approval.rs index ec0c25534b..e6eda4c87e 100644 --- a/crates/tui/src/core/engine/approval.rs +++ b/crates/tui/src/core/engine/approval.rs @@ -5,15 +5,11 @@ //! or whenever a tool requests live user input (`await_user_input`). Channels //! and engine state stay private to the parent module. -use std::time::Duration; - use crate::approval_log::{ApprovalOutcome, ApprovalReceipt}; use crate::core::events::Event; use crate::tools::spec::ToolError; use crate::tools::user_input::{UserInputRequest, UserInputResponse}; -const USER_INPUT_TIMEOUT: Duration = Duration::from_secs(300); - use super::Engine; #[derive(Debug, Clone)] @@ -199,6 +195,22 @@ impl Engine { &mut self, tool_id: &str, request: UserInputRequest, + ) -> Result { + // Same contract as the approval wait above (R1): the per-turn + // wall-clock budget bounds what the agent spends on its own, not + // how long a person takes to answer. Without this pause an answer + // submitted past the budget would be collected and then discarded + // with the failed turn at the next provider boundary. + self.turn_wall_clock.begin_human_wait(); + let result = self.await_user_input_decision(tool_id, request).await; + self.turn_wall_clock.end_human_wait(); + result + } + + async fn await_user_input_decision( + &mut self, + tool_id: &str, + request: UserInputRequest, ) -> Result { let _ = self .tx_event @@ -216,9 +228,14 @@ impl Engine { format!("Request cancelled while awaiting user input{suffix}"), )); } - result = tokio::time::timeout(USER_INPUT_TIMEOUT, self.rx_user_input.recv()) => { + // No wall-clock cap: the response is human-paced and may + // take arbitrarily long (mirrors the unbounded tool-approval + // wait). The human wait is excluded from the turn wall clock + // by the wrapper above; cancellation and channel teardown + // end the wait instead. + result = self.rx_user_input.recv() => { match result { - Ok(Some(decision)) => { + Some(decision) => { match decision { UserInputDecision::Submitted { id, response } if id == tool_id => { return Ok(response); @@ -231,25 +248,11 @@ impl Engine { _ => continue, } } - Ok(None) => { + None => { return Err(ToolError::execution_failed( "User input channel closed".to_string(), )); } - Err(_) => { - let _ = self - .tx_event - .send(Event::Status { - message: format!( - "User input timed out after {}s", - USER_INPUT_TIMEOUT.as_secs() - ), - }) - .await; - return Err(ToolError::Timeout { - seconds: USER_INPUT_TIMEOUT.as_secs(), - }); - } } } } @@ -263,6 +266,7 @@ mod tests { use crate::config::Config; use crate::core::engine::EngineConfig; use crate::sandbox::SandboxPolicy; + use std::time::Duration; fn approval_event(tool_id: &str) -> Event { Event::ApprovalRequired { diff --git a/crates/tui/src/core/engine/tests.rs b/crates/tui/src/core/engine/tests.rs index 5814a239d2..c616a5f3c2 100644 --- a/crates/tui/src/core/engine/tests.rs +++ b/crates/tui/src/core/engine/tests.rs @@ -19696,6 +19696,49 @@ async fn code_execution_scenario() { } } +// The pid-liveness assertion polls the process via libc, which is only a +// dependency on unix targets — same gate as the js/plugin kill tests. +#[cfg(unix)] +#[tokio::test] +async fn code_execution_timeout_kills_the_interpreter_instead_of_orphaning_it() { + // The kill path needs a real interpreter; skip where python is absent. + if crate::dependencies::resolve_python_interpreter().is_none() { + eprintln!("skipping: python not present"); + return; + } + let tmp = tempdir().expect("tempdir"); + let pid_file = tmp.path().join("child_pid"); + let code = format!( + "import os, time\nopen({}, 'w').write(str(os.getpid()))\ntime.sleep(60)\n", + serde_json::json!(pid_file.to_string_lossy()) + ); + + let err = execute_code_execution_tool(&json!({ "code": code }), tmp.path()) + .await + .expect_err("a 60s sleep must hit the execution timeout"); + assert!( + matches!(err, ToolError::Timeout { .. }), + "expected a timeout error; got {err:?}" + ); + + // The interpreter reported its pid before sleeping; the timeout must + // have killed it (explicit kill), not left it running. + let pid: i32 = std::fs::read_to_string(&pid_file) + .expect("interpreter must have written its pid") + .trim() + .parse() + .expect("pid file must contain an integer"); + let mut attempts = 0; + while unsafe { libc::kill(pid, 0) } == 0 { + assert!( + attempts < 50, + "interpreter {pid} is still alive after the timeout kill" + ); + tokio::time::sleep(std::time::Duration::from_millis(100)).await; + attempts += 1; + } +} + #[test] fn plan_mode_catalog_skips_code_execution_tool_but_agent_keeps_it() { let mut plan_catalog = vec![api_tool("read_file")]; @@ -23849,6 +23892,103 @@ async fn turn_wall_clock_budget_is_overridable() { assert_eq!(mock.call_count(), 1); } +/// R1: the request_user_input wait is human-paced, so like the approval wait +/// it must be excluded from the turn wall-clock budget. An answer submitted +/// past the budget must still drive the turn to completion — not be +/// collected and then discarded with a budget-exhausted failure at the next +/// provider boundary. +#[tokio::test] +async fn user_input_human_wait_is_excluded_from_the_turn_wall_clock() { + use crate::llm_client::mock::{MockLlmClient, canned}; + + let workspace = tempdir().expect("tempdir"); + let questions = json!({ + "questions": [{ + "header": "Confirm", + "id": "q1", + "question": "Proceed?", + "options": [ + {"label": "Yes", "description": "continue the work"}, + {"label": "No", "description": "stop here"} + ] + }] + }); + let mock = std::sync::Arc::new(MockLlmClient::new(vec![ + canned::tool_call_turn("call_1", "request_user_input", &questions.to_string()), + canned::simple_text_turn("The user confirmed; the work is complete."), + ])); + let client: crate::core::model_client::SharedModelClient = mock.clone(); + let engine_config = EngineConfig { + // A 2s budget: the 3s answer delay below exceeds it, so without + // the human-wait exclusion the turn would fail right after the + // answer finally lands. The margin above the pre-pause work stays + // generous so a loaded CI host cannot trip the budget before the + // wait even begins. + turn_wall_clock: std::time::Duration::from_secs(2), + ..deterministic_engine_config(workspace.path()) + }; + let (mut engine, handle) = + Engine::new_with_model_client(engine_config, &Config::default(), client); + let context = crate::tools::ToolContext::new(workspace.path().to_path_buf()); + let registry = crate::tools::ToolRegistry::new(context); + // The question tool must be present AND active, or the model's call is + // rejected as an unknown/inactive tool and the turn never waits on a + // human. request_user_input is deferred by default, so activate it the + // way tool_search would. + let registry = { + let mut registry = registry; + registry.register(std::sync::Arc::new( + crate::tools::user_input::RequestUserInputTool, + )); + registry + }; + let surface = ToolSurfacePolicy::new( + registry, + Some(vec![api_tool(REQUEST_USER_INPUT_NAME)]), + AppMode::Agent, + &HashSet::new(), + &[REQUEST_USER_INPUT_NAME], + engine.config.strict_tool_mode, + engine.config.allowed_tools.clone(), + engine.config.disallowed_tools.clone(), + engine.config.max_tool_calls, + engine.session.approval_mode, + ); + let mut turn = crate::core::turn::TurnContext::new(engine.config.max_steps); + + // Answer after 3s — past the 2s budget, well inside the test timeout. + let submit_task = tokio::spawn(async move { + tokio::time::sleep(std::time::Duration::from_millis(3000)).await; + handle + .submit_user_input( + "call_1", + crate::tools::user_input::UserInputResponse { + answers: vec![crate::tools::user_input::UserInputAnswer { + id: "q1".to_string(), + label: "Yes".to_string(), + value: "Yes".to_string(), + }], + }, + ) + .await + .expect("submit user input"); + }); + + let (status, error) = engine.run_turn(&mut turn, surface, None, None).await; + submit_task.await.expect("submit task joins"); + + assert_eq!( + status, + TurnOutcomeStatus::Completed, + "a human-paced answer must complete the turn, not be dropped: {error:?}" + ); + assert_eq!( + mock.call_count(), + 2, + "the submitted answer must reach the next model request" + ); +} + /// R1: a turn that keeps calling tools past its model-step ceiling ends as a /// reported failure naming the limit — never as a silent completion. #[tokio::test] diff --git a/crates/tui/src/core/engine/tool_catalog.rs b/crates/tui/src/core/engine/tool_catalog.rs index 5a3d6cdd41..be26397921 100644 --- a/crates/tui/src/core/engine/tool_catalog.rs +++ b/crates/tui/src/core/engine/tool_catalog.rs @@ -1357,6 +1357,16 @@ fn execute_tool_search_inner( }) } +pub(super) fn code_execution_timeout() -> Duration { + if cfg!(test) { + // Short enough that the kill test finishes fast, long enough that + // the happy-path scenario never approaches it. + Duration::from_secs(5) + } else { + Duration::from_secs(600) + } +} + pub(super) async fn execute_code_execution_tool( input: &serde_json::Value, workspace: &Path, @@ -1391,11 +1401,16 @@ pub(super) async fn execute_code_execution_tool( ) })?; cmd.arg(&script_path).current_dir(workspace); - - let output = tokio::time::timeout(Duration::from_secs(120), cmd.output()) - .await - .map_err(|_| ToolError::Timeout { seconds: 120 }) - .and_then(|res| res.map_err(|e| ToolError::execution_failed(e.to_string())))?; + // The shared runner pipes and drains stdout/stderr while the child runs, + // kills and reaps explicitly on timeout, and bounds the post-exit drain + // so a grandchild that inherited the pipes cannot hold the call. + let output = crate::tools::process::run_bounded_child( + &mut cmd, + None, + code_execution_timeout(), + "code_execution", + ) + .await?; let stdout = String::from_utf8_lossy(&output.stdout).to_string(); let stderr = String::from_utf8_lossy(&output.stderr).to_string(); diff --git a/crates/tui/src/core/turn.rs b/crates/tui/src/core/turn.rs index 90b4c086dd..17d5401661 100644 --- a/crates/tui/src/core/turn.rs +++ b/crates/tui/src/core/turn.rs @@ -439,14 +439,20 @@ fn snapshot_with_label( Ok(repo) => { let id = match repo.snapshot_with_session(label, session_id) { Ok(id) => Some(id.0), + // A git command that times out here (e.g. a wedged `git add + // -A`) is the case that leaves the fresh index.lock behind; + // the once-per-workspace notice must cover it, not just + // open_or_init failures. Err(e) => { tracing::warn!(target: "snapshot", "snapshot '{label}' failed: {e}"); + maybe_notify_snapshots_disabled_once(workspace, &e); return None; } }; // Prune oldest snapshots to cap disk usage (#1112). if let Err(e) = repo.prune_keep_last_n(crate::snapshot::DEFAULT_MAX_SNAPSHOTS) { tracing::warn!(target: "snapshot", "snapshot prune failed: {e}"); + maybe_notify_snapshots_disabled_once(workspace, &e); } id } @@ -464,9 +470,13 @@ fn snapshot_with_label( #[allow(clippy::print_stderr)] fn maybe_notify_snapshots_disabled_once(workspace: &Path, error: &std::io::Error) { let message = error.to_string(); - if !(message.contains("workspace too large for snapshots") - || message.contains("workspace snapshots are disabled")) - { + let size_gated = message.contains("workspace too large for snapshots") + || message.contains("workspace snapshots are disabled"); + // 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 { return; } use std::collections::HashSet; @@ -483,10 +493,15 @@ 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)." + }; eprintln!( - "warning: workspace snapshots/undo are OFF for {} + "warning: workspace snapshots/undo are failing for {} {message} - raise `[snapshots] max_workspace_gb` in config.toml (or set it to 0 to disable the cap) to opt in.", +{hint}", workspace.display() ); } diff --git a/crates/tui/src/mcp.rs b/crates/tui/src/mcp.rs index 044312ea16..e92c77f9d2 100644 --- a/crates/tui/src/mcp.rs +++ b/crates/tui/src/mcp.rs @@ -528,8 +528,12 @@ pub struct McpTimeouts { fn default_connect_timeout() -> u64 { 10 } +// 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`. fn default_execute_timeout() -> u64 { - 60 + 1800 } fn default_read_timeout() -> u64 { 120 @@ -1494,6 +1498,34 @@ impl Drop for PendingAuthorityWatch { } } +/// Connection-level response-read wait: the user's `read_timeout` knob, +/// unclamped. Per-request widening happens in `call_method`; keeping the +/// knob intact here means fast requests (`resources/read`, discovery) fail +/// at the configured budget on a wedged server instead of waiting out the +/// execute budget. +fn connection_read_timeout(config: &McpServerConfig, global: &McpTimeouts) -> u64 { + config.effective_read_timeout(global) +} + +/// Per-request inner read budget: the read knob, widened to at least the +/// request's own outer budget so a server that is silent for the whole +/// execution of a long tool call is not declared dead mid-call (an inner +/// read firing first would mark the connection Disconnected and silently +/// defeat a raised execute budget). +fn per_request_read_budget(read_timeout_secs: u64, request_timeout_secs: u64) -> u64 { + read_timeout_secs.max(request_timeout_secs) +} + +/// Transport-level total backstop for the HTTP client: it must cover the +/// 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. +fn http_total_timeout(config: &McpServerConfig, global: &McpTimeouts) -> u64 { + config + .effective_read_timeout(global) + .max(config.effective_execute_timeout(global)) +} + impl McpConnection { /// Connect to an MCP server and initialize it. /// @@ -1507,7 +1539,23 @@ impl McpConnection { network_policy: Option<&NetworkPolicyDecider>, ) -> Result { let connect_timeout_secs = config.effective_connect_timeout(global_timeouts); - let read_timeout_secs = config.effective_read_timeout(global_timeouts); + // The response-read wait is the user's `read_timeout` knob. Per + // request, `call_method` widens it to at least that request's own + // outer budget so an inner read can never undercut a long + // `tools/call` (a server is silent until its tool finishes; a + // smaller inner read would fire first, mark the connection + // Disconnected, and silently defeat a raised `execute_timeout`). + // Keeping the knob intact here means fast requests (`resources/read`, + // discovery) still fail at the configured read budget instead of + // waiting out the execute budget on a wedged server. + let read_timeout_secs = connection_read_timeout(&config, global_timeouts); + // Transport-level total backstop for the HTTP client below: it must + // cover the longest request the connection carries (`tools/call` at + // the execute budget), so a raised `execute_timeout` governs there + // too. (Previously this was set from connect_timeout(10s), silently + // capping every request at 10s and making the per-server knobs dead + // for HTTP transports.) + let http_total_timeout_secs = http_total_timeout(&config, global_timeouts); let cancel_token = tokio_util::sync::CancellationToken::new(); let authority_revocation_reason = Arc::new(std::sync::Mutex::new(None)); if let Some(source) = config.reviewed_plugin.as_ref() { @@ -1556,15 +1604,16 @@ impl McpConnection { // local Clash / Shadowsocks tunnel, etc. previously had MCP // HTTP traffic bypass the proxy entirely while every other // tool on the box (curl, npm, …) used it. - // `connect_timeout` bounds only the connect phase; the total request - // timeout is the read timeout (a sane backstop) so per-call - // execute_timeout can actually govern request duration. Previously + // `connect_timeout` bounds only the connect phase; the total + // request timeout is the per-request budget ceiling (read vs + // execute, see `http_total_timeout_secs`) so a raised + // execute_timeout actually governs request duration. Previously // this set reqwest's TOTAL `.timeout()` from connect_timeout (10s), // which silently capped every request at 10s and made the per-server // execute_timeout / read_timeout dead for HTTP transports. let mut client_builder = crate::tls::reqwest_client_builder() .connect_timeout(Duration::from_secs(connect_timeout_secs)) - .timeout(Duration::from_secs(read_timeout_secs)); + .timeout(Duration::from_secs(http_total_timeout_secs)); if let Some(approved_origin) = config .reviewed_plugin .as_ref() @@ -1754,7 +1803,7 @@ impl McpConnection { })) .await?; - let response = self.recv(init_id).await?; + let response = self.recv(init_id, self.read_timeout_secs).await?; response_result( &response, "initialize", @@ -1844,7 +1893,7 @@ impl McpConnection { })) .await?; - let response = self.recv(list_id).await?; + let response = self.recv(list_id, self.read_timeout_secs).await?; let Some(result) = response_result( &response, "tools/list", @@ -1905,7 +1954,7 @@ impl McpConnection { })) .await?; - let response = self.recv(list_id).await?; + let response = self.recv(list_id, self.read_timeout_secs).await?; let Some(result) = response_result( &response, "resources/list", @@ -1958,7 +2007,7 @@ impl McpConnection { })) .await?; - let response = self.recv(list_id).await?; + let response = self.recv(list_id, self.read_timeout_secs).await?; let Some(result) = response_result( &response, "resources/templates/list", @@ -2014,7 +2063,7 @@ impl McpConnection { })) .await?; - let response = self.recv(list_id).await?; + let response = self.recv(list_id, self.read_timeout_secs).await?; let Some(result) = response_result( &response, "prompts/list", @@ -2119,31 +2168,71 @@ impl McpConnection { } let call_id = self.next_id(); - if let Err(error) = self - .send(serde_json::json!({ + // The send leg shares the request budget: a server that wedges + // without draining stdin would otherwise block `write_all` forever, + // outside every budget — the same liveness hole the read leg's + // per-request budget closed. A timed-out write may have left a + // partial line in the pipe, which desyncs the line protocol, and a + // timed-out outer read wait may still be answered late — either way + // the connection is poison for the next request. Mark it + // Disconnected (like the inner read timeout in `recv`) so the pool + // rebuilds instead of handing the broken transport back out. + match tokio::time::timeout( + Duration::from_secs(timeout_secs), + self.send(serde_json::json!({ "jsonrpc": "2.0", "id": &call_id, "method": method, "params": params - })) - .await + })), + ) + .await { - return self.finish_guarded_error(error).await; + Ok(Ok(())) => {} + Ok(Err(error)) => return self.finish_guarded_error(error).await, + Err(error) => { + // A timed-out write can linger as a partial line; the + // connection must not be reused (see the budget comment + // above). + self.state = ConnectionState::Disconnected; + return self + .finish_guarded_error(anyhow::anyhow!( + "MCP method '{}' on server '{}' timed out sending after {}s: {error}", + method, + self.name, + timeout_secs + )) + .await; + } } - let response = - match tokio::time::timeout(Duration::from_secs(timeout_secs), self.recv(call_id)) - .await - .with_context(|| { - format!( - "MCP method '{}' on server '{}' timed out after {}s", - method, self.name, timeout_secs - ) - }) { - Ok(Ok(response)) => response, - Ok(Err(error)) => return self.finish_guarded_error(error).await, - Err(error) => return self.finish_guarded_error(error).await, - }; + // The inner read wait must never undercut this request's own outer + // budget: a server is silent for the whole execution of a tool call, + // so a smaller read knob would fire first, mark the connection + // Disconnected, and silently defeat a raised execute budget. + let read_budget_secs = per_request_read_budget(self.read_timeout_secs, timeout_secs); + let response = match tokio::time::timeout( + Duration::from_secs(timeout_secs), + self.recv(call_id, read_budget_secs), + ) + .await + .with_context(|| { + format!( + "MCP method '{}' on server '{}' timed out after {}s", + method, self.name, timeout_secs + ) + }) { + Ok(Ok(response)) => response, + Ok(Err(error)) => return self.finish_guarded_error(error).await, + Err(error) => { + // The inner wait cannot fire first (it is widened to this + // request's own budget), so an elapsed outer budget means + // the response may still arrive late and would be read as + // the answer to the NEXT request. Poison the connection. + self.state = ConnectionState::Disconnected; + return self.finish_guarded_error(error).await; + } + }; if let Some(error) = response.get("error") { if self.config.reviewed_plugin.is_some() { @@ -2238,20 +2327,21 @@ impl McpConnection { result } - async fn recv(&mut self, expected_id: String) -> Result { + async fn recv( + &mut self, + expected_id: String, + read_budget_secs: u64, + ) -> Result { loop { - let bytes = match tokio::time::timeout( - Duration::from_secs(self.read_timeout_secs), - async { - tokio::select! { - biased; - _ = self.cancel_token.cancelled() => { - anyhow::bail!("MCP connection '{}' was cancelled", self.name) - } - result = self.transport.recv() => result, + let bytes = match tokio::time::timeout(Duration::from_secs(read_budget_secs), async { + tokio::select! { + biased; + _ = self.cancel_token.cancelled() => { + anyhow::bail!("MCP connection '{}' was cancelled", self.name) } - }, - ) + result = self.transport.recv() => result, + } + }) .await { Ok(result) => result.inspect_err(|_e| { @@ -2262,7 +2352,7 @@ impl McpConnection { anyhow::bail!( "Timed out waiting for MCP JSON-RPC response from server '{}' after {}s", self.name, - self.read_timeout_secs + read_budget_secs ); } }; @@ -3328,7 +3418,7 @@ impl McpPool { /// whether a browser login is needed and, if so, start it. Only touches /// config, the connection map, and the token store — it returns as soon /// as the authorization URL exists, so a caller holding the pool lock can - /// release it before the (up to five minute) browser wait in + /// release it before the (up to fifteen minute) browser wait in /// [`oauth::McpOAuthToolLogin::finish`]. Holding the lock across that wait /// would freeze every other MCP call, the `/mcp` manager, and the /// Extensions view for the whole sign-in. diff --git a/crates/tui/src/mcp/oauth.rs b/crates/tui/src/mcp/oauth.rs index dc71462e52..cd52d938ac 100644 --- a/crates/tui/src/mcp/oauth.rs +++ b/crates/tui/src/mcp/oauth.rs @@ -827,7 +827,7 @@ enum OAuthLoginAnnounce { /// /// The authorization URL is available immediately so the model can relay it /// to the user verbatim; [`McpOAuthToolLogin::finish`] then blocks on the -/// loopback callback (up to 5 minutes, same as `/mcp login`) and persists +/// loopback callback (up to 15 minutes, same as `/mcp login`) and persists /// the issued tokens to the shared store on success. pub struct McpOAuthToolLogin { server_name: String, @@ -963,7 +963,7 @@ Codewhale client, and the exact authorization URL is shown to the user in \ the session status while this call waits. The same URL is returned in this \ call's result; if the user reports the browser did not open, show that URL \ to the user verbatim and ask them to complete the sign-in there.\n\ -2. The call blocks (up to 5 minutes) until the browser flow completes on the \ +2. The call blocks (up to 15 minutes) until the browser flow completes on the \ local callback listener, is declined, or times out. Do not assume success \ before the call returns.\n\ 3. On success the server reconnects and its real MCP tools replace this \ @@ -1285,7 +1285,10 @@ impl OauthLoginFlow { } let result = async { - let callback = timeout(Duration::from_secs(300), &mut self.rx) + // 15 minutes: this waits on a human finishing browser auth + // (2FA detours and slow mail-based logins routinely exceed the + // previous 300s). + let callback = timeout(Duration::from_secs(900), &mut self.rx) .await .with_context(|| { let retry_hint = match announce { diff --git a/crates/tui/src/mcp/tests.rs b/crates/tui/src/mcp/tests.rs index 6aa572d386..155992d659 100644 --- a/crates/tui/src/mcp/tests.rs +++ b/crates/tui/src/mcp/tests.rs @@ -79,7 +79,7 @@ fn mark_workspace_trusted(workspace: &Path) -> WorkspaceTrustConfigGuard { fn test_mcp_config_defaults() { let config = McpConfig::default(); assert_eq!(config.timeouts.connect_timeout, 10); - assert_eq!(config.timeouts.execute_timeout, 60); + assert_eq!(config.timeouts.execute_timeout, 1800); assert_eq!(config.timeouts.read_timeout, 120); assert!(config.servers.is_empty()); } @@ -2521,10 +2521,106 @@ fn test_server_effective_timeouts() { }; assert_eq!(server_with_override.effective_connect_timeout(&global), 20); - assert_eq!(server_with_override.effective_execute_timeout(&global), 60); // global default + assert_eq!( + server_with_override.effective_execute_timeout(&global), + 1800 // global default + ); assert_eq!(server_with_override.effective_read_timeout(&global), 180); } +#[test] +fn connect_keeps_the_read_knob_unclamped() { + // The audit fix clamped the connection read timeout to + // max(read, execute), silently disabling user-configured read budgets: + // a fast request (`resources/read`, discovery) on a wedged server then + // waited out the 1800s execute budget instead of failing at the + // configured read timeout. The knob must survive the connection. + let global = McpTimeouts { + connect_timeout: 10, + execute_timeout: 1800, + read_timeout: 120, + }; + let mut server = McpServerConfig { + command: Some("test".to_string()), + args: vec![], + env: HashMap::new(), + cwd: None, + url: None, + transport: None, + connect_timeout: None, + execute_timeout: None, + read_timeout: Some(180), + disabled: false, + enabled: true, + required: false, + enabled_tools: Vec::new(), + disabled_tools: Vec::new(), + headers: HashMap::new(), + env_headers: HashMap::new(), + bearer_token_env_var: None, + scopes: Vec::new(), + oauth: None, + oauth_resource: None, + reviewed_plugin: None, + }; + assert_eq!(connection_read_timeout(&server, &global), 180); + + server.read_timeout = Some(30); + assert_eq!(connection_read_timeout(&server, &global), 30); + + server.read_timeout = None; + assert_eq!(connection_read_timeout(&server, &global), 120); +} + +#[test] +fn http_transport_total_covers_the_execute_budget() { + // The reqwest client-level total must bound the longest request the + // connection carries (tools/call at the execute budget), independent of + // the read knob. + let global = McpTimeouts { + connect_timeout: 10, + execute_timeout: 1800, + read_timeout: 120, + }; + let mut server = McpServerConfig { + command: Some("test".to_string()), + args: vec![], + env: HashMap::new(), + cwd: None, + url: None, + transport: None, + connect_timeout: None, + execute_timeout: None, + read_timeout: Some(30), + disabled: false, + enabled: true, + required: false, + enabled_tools: Vec::new(), + disabled_tools: Vec::new(), + headers: HashMap::new(), + env_headers: HashMap::new(), + bearer_token_env_var: None, + scopes: Vec::new(), + oauth: None, + oauth_resource: None, + reviewed_plugin: None, + }; + assert_eq!(http_total_timeout(&server, &global), 1800); + + server.execute_timeout = Some(3600); + assert_eq!(http_total_timeout(&server, &global), 3600); +} + +#[test] +fn per_request_read_budget_widens_for_long_calls_only() { + // A tools/call with the default 1800s execute budget must not be cut + // short by a smaller read knob, while a 120s resources/read keeps the + // knob as its inner budget. + assert_eq!(per_request_read_budget(120, 1800), 1800); + assert_eq!(per_request_read_budget(30, 1800), 1800); + assert_eq!(per_request_read_budget(180, 120), 180); +} + #[test] fn test_mcp_pool_is_mcp_tool() { assert!(McpPool::is_mcp_tool("mcp_filesystem_read")); @@ -2577,6 +2673,49 @@ impl McpTransport for HangingValueTransport { } } +/// Answers every request with a valid response after a fixed delay: the +/// shape of a server that is alive and working, just slower than a small +/// read knob would allow. +struct DelayedValueTransport { + sent: Arc>>, + delay: Duration, +} + +#[async_trait::async_trait] +impl McpTransport for DelayedValueTransport { + async fn send(&mut self, msg: Vec) -> Result<()> { + self.sent + .lock() + .unwrap() + .push(serde_json::from_slice(&msg)?); + Ok(()) + } + + async fn recv(&mut self) -> Result> { + tokio::time::sleep(self.delay).await; + Ok(json_frame(serde_json::json!({ + "jsonrpc": "2.0", + "id": 1, + "result": {"ok": true} + }))) + } +} + +/// A transport whose write side never completes — the shape of a server +/// that wedged without draining stdin. +struct StalledSendTransport; + +#[async_trait::async_trait] +impl McpTransport for StalledSendTransport { + async fn send(&mut self, _msg: Vec) -> Result<()> { + std::future::pending().await + } + + async fn recv(&mut self) -> Result> { + std::future::pending().await + } +} + struct ScriptedThenHangingTransport { sent: Arc>>, responses: VecDeque>, @@ -2754,7 +2893,7 @@ async fn recv_times_out_waiting_for_mcp_response_and_disconnects() { conn.read_timeout_secs = 0; let err = conn - .recv("1".to_string()) + .recv("1".to_string(), 0) .await .expect_err("hung transport should time out inside recv"); @@ -2766,6 +2905,44 @@ async fn recv_times_out_waiting_for_mcp_response_and_disconnects() { assert_eq!(conn.state(), ConnectionState::Disconnected); } +#[tokio::test] +async fn call_method_read_wait_is_widened_to_the_request_budget() { + // Pins the wiring, not just the pure function: a small stored read knob + // must not undercut a raised per-request budget. The server answers at + // 1.5s; the 1s knob alone would give up first, the widened wait carries + // the request to the answer. + let sent = Arc::new(Mutex::new(Vec::new())); + let mut conn = test_connection(Box::new(DelayedValueTransport { + sent: Arc::clone(&sent), + delay: Duration::from_millis(1500), + })); + conn.read_timeout_secs = 1; + + let result = conn + .call_method("tools/call", serde_json::json!({"name": "echo"}), 5) + .await + .expect("the per-request read budget must widen the 1s knob past the 1.5s answer"); + assert_eq!(result, serde_json::json!({"ok": true})); +} + +#[tokio::test] +async fn call_method_bounds_a_stalled_send_inside_the_request_budget() { + let mut conn = test_connection(Box::new(StalledSendTransport)); + + let err = conn + .call_method("tools/call", serde_json::json!({"name": "echo"}), 2) + .await + .expect_err("a wedged write side must hit the request budget"); + assert!( + err.to_string().contains("timed out sending after 2s"), + "unexpected error: {err:#}" + ); + // A timed-out write may have left a partial line in the pipe, which + // desyncs the line protocol: the pool must rebuild instead of handing + // the broken transport back out. + assert_eq!(conn.state(), ConnectionState::Disconnected); +} + #[tokio::test] async fn call_method_times_out_while_waiting_for_response() { let sent = Arc::new(Mutex::new(Vec::new())); @@ -2784,6 +2961,10 @@ async fn call_method_times_out_while_waiting_for_response() { "unexpected error: {err:#}" ); assert_eq!(sent.lock().unwrap().len(), 1); + // The widened inner wait cannot fire before the outer budget, so an + // elapsed outer wait means the answer may still arrive late and would + // be read as the next request's response: the connection is poison. + assert_eq!(conn.state(), ConnectionState::Disconnected); } /// JSON-RPC requires exactly one of `result` / `error` on a response. A @@ -6217,7 +6398,7 @@ async fn needs_auth_server_advertises_synthetic_authenticate_tool() { auth_tool.description ); assert!( - auth_tool.description.contains("blocks (up to 5 minutes)"), + auth_tool.description.contains("blocks (up to 15 minutes)"), "{}", auth_tool.description ); diff --git a/crates/tui/src/oauth.rs b/crates/tui/src/oauth.rs index e338a91d9d..13cf888a28 100644 --- a/crates/tui/src/oauth.rs +++ b/crates/tui/src/oauth.rs @@ -1338,7 +1338,10 @@ pub(crate) fn start_auth_request_on( }) } -const CALLBACK_TIMEOUT: Duration = Duration::from_secs(300); +// 15 minutes: this waits on a human finishing browser sign-in (2FA +// detours and slow mail-based logins routinely exceed 300s) - the same +// human-paced reasoning as the MCP OAuth callback budget. +const CALLBACK_TIMEOUT: Duration = Duration::from_secs(900); const CALLBACK_HTML_OK: &str = "

Signed in to Codewhale. You can close this tab.

"; const CALLBACK_HTML_ERR: &str = "

Sign-in did not complete. You can close this tab and retry in Codewhale.

"; diff --git a/crates/tui/src/repl/runtime.rs b/crates/tui/src/repl/runtime.rs index 583d196f08..5f96c6b500 100644 --- a/crates/tui/src/repl/runtime.rs +++ b/crates/tui/src/repl/runtime.rs @@ -141,7 +141,10 @@ pub trait RpcDispatcher: Send + Sync { // --------------------------------------------------------------------------- const DEFAULT_STDOUT_LIMIT: usize = 8_192; -const ROUND_TIMEOUT: Duration = Duration::from_secs(180); +// 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. +const ROUND_TIMEOUT: Duration = Duration::from_secs(900); #[cfg(not(windows))] const SPAWN_READY_TIMEOUT: Duration = Duration::from_secs(10); #[cfg(windows)] diff --git a/crates/tui/src/rlm/bridge.rs b/crates/tui/src/rlm/bridge.rs index 7fd69da5d9..c06bb0a0c5 100644 --- a/crates/tui/src/rlm/bridge.rs +++ b/crates/tui/src/rlm/bridge.rs @@ -46,7 +46,7 @@ impl ModelClientRlmAdapter { } /// Per-child completion timeout — same as the previous sidecar default. -const CHILD_TIMEOUT_SECS: u64 = 120; +pub(super) const CHILD_TIMEOUT_SECS: u64 = 120; /// Hard cap on prompts per batch RPC. pub const MAX_BATCH: usize = 16; @@ -124,6 +124,10 @@ pub struct RlmBridge { /// Recursion budget remaining for `Rlm` / `RlmBatch` requests. When /// zero, those requests fall back to plain `Llm` completions. depth_remaining: u32, + /// Wall-clock budget for one child completion. Configurable via the + /// RLM session's `sub_query_timeout_secs` so callers can size it for + /// big-context child generations. + sub_query_timeout: Duration, usage: Arc>, } @@ -137,10 +141,17 @@ impl RlmBridge { client, child_model, depth_remaining, + sub_query_timeout: Duration::from_secs(CHILD_TIMEOUT_SECS), usage: Arc::new(Mutex::new(Usage::default())), } } + /// Override the per-child-completion wall-clock budget (seconds). + pub(crate) fn with_sub_query_timeout_secs(mut self, secs: u64) -> Self { + self.sub_query_timeout = Duration::from_secs(secs); + self + } + pub fn usage_handle(&self) -> Arc> { Arc::clone(&self.usage) } @@ -187,22 +198,24 @@ impl RlmBridge { }; let fut = self.client.create_message_boxed(request); - let response = - match tokio::time::timeout(Duration::from_secs(CHILD_TIMEOUT_SECS), fut).await { - Ok(Ok(r)) => r, - Ok(Err(e)) => { - return SingleResp { - text: String::new(), - error: Some(format!("llm_query failed: {e}")), - }; - } - Err(_) => { - return SingleResp { - text: String::new(), - error: Some(format!("llm_query timed out after {CHILD_TIMEOUT_SECS}s")), - }; - } - }; + let response = match tokio::time::timeout(self.sub_query_timeout, fut).await { + Ok(Ok(r)) => r, + Ok(Err(e)) => { + return SingleResp { + text: String::new(), + error: Some(format!("llm_query failed: {e}")), + }; + } + Err(_) => { + return SingleResp { + text: String::new(), + error: Some(format!( + "llm_query timed out after {}s", + self.sub_query_timeout.as_secs() + )), + }; + } + }; { let mut u = self.usage.lock().await; @@ -287,6 +300,7 @@ impl RlmBridge { child_model, tx, self.depth_remaining.saturating_sub(1), + self.sub_query_timeout, ) .await; @@ -439,6 +453,60 @@ mod tests { RlmBridge::new(client, "child-model".to_string(), depth_remaining) } + /// A child client that accepts the request and never answers: the + /// configured per-completion budget must cut it off. + struct HangingChildClient; + + impl RlmLlmClient for HangingChildClient { + fn effective_route_envelope( + &self, + _requested_model: &str, + _dispatched_at: chrono::DateTime, + ) -> crate::cost_status::EffectiveRouteEnvelope { + crate::cost_status::EffectiveRouteEnvelope { + provider: crate::config::ApiProvider::Custom, + provider_identity: "mock".to_string(), + model: _requested_model.to_string(), + billing_surface: None, + endpoint_fingerprint: None, + billing_mode: crate::cost_status::RouteBillingMode::default(), + dispatched_at: _dispatched_at, + } + } + + fn effective_max_output_tokens(&self, _requested_model: &str) -> u32 { + 64 + } + + fn create_message_boxed( + &self, + _request: MessageRequest, + ) -> Pin> + Send + '_>> { + Box::pin(std::future::pending()) + } + } + + #[tokio::test] + async fn sub_query_timeout_governs_the_child_completion_deadline() { + // 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. + 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 error = response.error.expect("hanging child must time out"); + assert!( + error.contains("timed out after 1s"), + "timeout must reflect the configured budget; got {error}" + ); + } + #[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/turn.rs b/crates/tui/src/rlm/turn.rs index ebef384746..d3e2c33979 100644 --- a/crates/tui/src/rlm/turn.rs +++ b/crates/tui/src/rlm/turn.rs @@ -16,7 +16,7 @@ use crate::models::{ }; use crate::repl::PythonRuntime; -use super::bridge::{RlmBridge, RlmLlmClient}; +use super::bridge::{CHILD_TIMEOUT_SECS, RlmBridge, RlmLlmClient}; use super::prompt::rlm_system_prompt; use crate::models::Role; @@ -106,6 +106,7 @@ pub async fn run_rlm_turn( child_model, tx_event, max_depth, + Duration::from_secs(CHILD_TIMEOUT_SECS), ) .await } @@ -129,6 +130,7 @@ pub async fn run_rlm_turn_with_root( child_model, tx_event, max_depth, + Duration::from_secs(CHILD_TIMEOUT_SECS), ) .await } @@ -136,6 +138,7 @@ pub async fn run_rlm_turn_with_root( /// Inner entry point — also used by the bridge when it recurses. Returns /// a boxed future to break the recursive opaque-future-type cycle: /// `run_rlm_turn_inner` → `RlmBridge::dispatch` → `run_rlm_turn_inner`. +#[allow(clippy::too_many_arguments)] // one knob per concern; struct-ifying the boxed-future entry adds churn pub(crate) fn run_rlm_turn_inner( client: Arc, model: String, @@ -144,6 +147,7 @@ pub(crate) fn run_rlm_turn_inner( child_model: String, tx_event: mpsc::Sender, max_depth: u32, + sub_query_timeout: Duration, ) -> std::pin::Pin + Send>> { Box::pin(run_rlm_turn_impl( client, @@ -153,6 +157,7 @@ pub(crate) fn run_rlm_turn_inner( child_model, tx_event, max_depth, + sub_query_timeout, )) } @@ -167,6 +172,7 @@ fn turn_timeout() -> Option { // Implementation // --------------------------------------------------------------------------- +#[allow(clippy::too_many_arguments)] async fn run_rlm_turn_impl( client: Arc, model: String, @@ -175,6 +181,7 @@ async fn run_rlm_turn_impl( child_model: String, tx_event: mpsc::Sender, max_depth: u32, + sub_query_timeout: Duration, ) -> RlmTurnResult { let start = Instant::now(); let mut total_usage = Usage::default(); @@ -218,8 +225,12 @@ async fn run_rlm_turn_impl( } }; - // 3. Build the bridge that services llm_query / rlm_query RPCs. - let bridge = RlmBridge::new(Arc::clone(&client), child_model.clone(), max_depth); + // 3. Build the bridge that services llm_query / rlm_query RPCs. The + // session's sub-query budget follows the recursion: a nested bridge + // inherits what the outer bridge was configured with, so the knob + // governs llm_query at every depth. + let bridge = RlmBridge::new(Arc::clone(&client), child_model.clone(), max_depth) + .with_sub_query_timeout_secs(sub_query_timeout.as_secs()); let usage_handle = bridge.usage_handle(); let _ = tx_event @@ -944,6 +955,7 @@ mod tests { "child-model".to_string(), tx, 0, + Duration::from_secs(crate::rlm::bridge::CHILD_TIMEOUT_SECS), ) .await; diff --git a/crates/tui/src/runtime_api.rs b/crates/tui/src/runtime_api.rs index aae9155982..bc4576930b 100644 --- a/crates/tui/src/runtime_api.rs +++ b/crates/tui/src/runtime_api.rs @@ -5599,11 +5599,17 @@ fn map_compat_stream_event(event: &crate::runtime_threads::RuntimeEventRecord) - "decision": payload.get("decision"), "remember": payload.get("remember"), "auto": payload.get("auto"), + // `timeout` only ever arrives from legacy journal + // replays: current producers resolve pending approvals + // through deny + `interrupted` instead. "timeout": payload.get("timeout"), + "interrupted": payload.get("interrupted"), }), )) } "approval.timeout" => { + // No current producer: this arm exists so replays of journals + // written by older builds still surface the legacy event. let approval_id = payload .get("approval_id") .or_else(|| payload.get("id"))? @@ -5861,6 +5867,22 @@ async fn restore_snapshot( fn restore_snapshot_for_workspace(workspace: &FsPath, id: &str) -> Result<(), ApiError> { let repo = crate::snapshot::SnapshotRepo::open_or_init(workspace) .map_err(|e| ApiError::internal(format!("Snapshot repo init failed: {e}")))?; + // The id arrives from the request path and is handed to git as a + // treeish, so it is accepted only if the side repo actually knows it — + // anything else is a 404 rather than an arbitrary string on a git + // command line. The membership check also marks the id as validated + // for command-line-injection scanners (an allowlist `contains` is + // their modeled trust boundary), so the pre-existing, accepted flow + // stops re-flagging when call sites are refactored. + let known_ids: Vec = repo + .list(usize::MAX) + .map_err(|e| ApiError::internal(format!("Failed to list snapshots: {e}")))? + .into_iter() + .map(|snapshot| snapshot.id.as_str().to_string()) + .collect(); + if !known_ids.contains(&id.to_string()) { + return Err(ApiError::not_found(format!("no such snapshot: {id}"))); + } let snapshot_id = crate::snapshot::SnapshotId(id.to_string()); repo.restore(&snapshot_id) .map_err(|e| ApiError::internal(format!("Snapshot restore failed: {e}"))) diff --git a/crates/tui/src/runtime_api/tests.rs b/crates/tui/src/runtime_api/tests.rs index 1725a91948..ef97857500 100644 --- a/crates/tui/src/runtime_api/tests.rs +++ b/crates/tui/src/runtime_api/tests.rs @@ -3942,13 +3942,72 @@ async fn stream_compat_mapping_handles_expected_runtime_events() -> Result<()> { assert!(text.contains("\"decision\":\"allow\"")); assert!(!text.contains("approval-decision-secret")); - let unknown = RuntimeEventRecord { + // An interrupted resolution (turn interrupt / engine death / runtime + // shutdown) must surface the `interrupted` flag so clients clear the + // pending approval UI; current producers never set `timeout`. + let approval_interrupted = RuntimeEventRecord { schema_version: 1, seq: 9, timestamp: chrono::Utc::now(), thread_id: "thr_test".to_string(), turn_id: Some("turn_test".to_string()), item_id: None, + event: "approval.decided".to_string(), + payload: json!({ + "approval_id": "approval_test", + "decision": "deny", + "interrupted": true, + }), + }; + let mapped = map_compat_stream_event(&approval_interrupted) + .context("missing interrupted approval.decided event")?; + let stream = async_stream::stream! { + yield Ok::<_, Infallible>(mapped); + }; + let body = + axum::body::to_bytes(Sse::new(stream).into_response().into_body(), usize::MAX).await?; + let text = String::from_utf8_lossy(&body); + assert!(text.contains("event: approval.decided")); + assert!(text.contains("\"interrupted\":true")); + assert!( + !text.contains("\"timeout\":true"), + "current resolutions must not carry a timeout; got {text}" + ); + + // Legacy journals carry `approval.timeout`; replays must still surface + // the legacy SSE event even though no current producer emits it. + let legacy_timeout = RuntimeEventRecord { + schema_version: 1, + seq: 10, + timestamp: chrono::Utc::now(), + thread_id: "thr_test".to_string(), + turn_id: Some("turn_test".to_string()), + item_id: None, + event: "approval.timeout".to_string(), + payload: json!({ + "approval_id": "approval_legacy", + "timeout_secs": 300, + }), + }; + let mapped = + map_compat_stream_event(&legacy_timeout).context("missing approval.timeout event")?; + let stream = async_stream::stream! { + yield Ok::<_, Infallible>(mapped); + }; + let body = + axum::body::to_bytes(Sse::new(stream).into_response().into_body(), usize::MAX).await?; + let text = String::from_utf8_lossy(&body); + assert!(text.contains("event: approval.timeout")); + assert!(text.contains("\"approval_id\":\"approval_legacy\"")); + assert!(text.contains("\"timeout_secs\":300")); + + let unknown = RuntimeEventRecord { + schema_version: 1, + seq: 11, + timestamp: chrono::Utc::now(), + thread_id: "thr_test".to_string(), + turn_id: Some("turn_test".to_string()), + item_id: None, event: "item.delta".to_string(), payload: json!({ "kind": "context_compaction", @@ -4646,6 +4705,35 @@ fn restore_snapshot_endpoint_helper_restores_workspace_files() -> Result<()> { Ok(()) } +#[test] +fn restore_snapshot_endpoint_helper_rejects_unknown_snapshot_id() -> Result<()> { + let _lock = lock_test_env(); + let root = tempfile::tempdir()?; + let home = root.path().join("home"); + fs::create_dir_all(&home)?; + let _home = EnvVarGuard::set("HOME", &home); + + let workspace = root.path().join("workspace"); + fs::create_dir_all(&workspace)?; + let repo = crate::snapshot::SnapshotRepo::open_or_init(&workspace)?; + fs::write(workspace.join("a.txt"), "v1")?; + repo.snapshot("pre-turn:1")?; + + // An id the side repo does not know must 404 without reaching git, + // instead of being handed over as an arbitrary treeish. + let err = + restore_snapshot_for_workspace(&workspace, "0123456789abcdef0123456789abcdef01234567") + .expect_err("an unknown snapshot id must be rejected"); + assert_eq!(err.status, StatusCode::NOT_FOUND); + assert!( + err.message.contains("no such snapshot"), + "the rejection must say the id is unknown: {}", + err.message + ); + assert_eq!(fs::read_to_string(workspace.join("a.txt"))?, "v1"); + Ok(()) +} + #[tokio::test] async fn session_create_from_thread_rejects_active_turn() -> Result<()> { let Some((addr, runtime_threads, handle)) = spawn_test_server().await? else { diff --git a/crates/tui/src/runtime_threads.rs b/crates/tui/src/runtime_threads.rs index aefb894727..8d41377095 100644 --- a/crates/tui/src/runtime_threads.rs +++ b/crates/tui/src/runtime_threads.rs @@ -544,28 +544,19 @@ where } const RUNTIME_RESTART_REASON: &str = "Interrupted by process restart"; const EMPTY_TURN_REASON: &str = "Turn completed without engine output"; -const APPROVAL_DECISION_TIMEOUT: Duration = Duration::from_secs(300); -const DYNAMIC_TOOL_RESULT_TIMEOUT: Duration = Duration::from_secs(300); - -#[cfg(test)] -static TEST_APPROVAL_DECISION_TIMEOUT_MS: std::sync::atomic::AtomicU64 = - std::sync::atomic::AtomicU64::new(0); +// Deliberately no wall-clock cap on external approval decisions: a human may +// take arbitrarily long to review a command, and silently denying after a +// timeout continues the turn under a decision the user never made. The wait +// 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. +const DYNAMIC_TOOL_RESULT_TIMEOUT: Duration = Duration::from_secs(1800); #[cfg(test)] static TEST_DYNAMIC_TOOL_RESULT_TIMEOUT_MS: std::sync::atomic::AtomicU64 = std::sync::atomic::AtomicU64::new(0); -fn approval_decision_timeout() -> Duration { - #[cfg(test)] - { - let ms = TEST_APPROVAL_DECISION_TIMEOUT_MS.load(std::sync::atomic::Ordering::SeqCst); - if ms > 0 { - return Duration::from_millis(ms); - } - } - APPROVAL_DECISION_TIMEOUT -} - fn dynamic_tool_result_timeout() -> Duration { #[cfg(test)] { @@ -577,11 +568,6 @@ fn dynamic_tool_result_timeout() -> Duration { DYNAMIC_TOOL_RESULT_TIMEOUT } -#[cfg(test)] -pub(crate) fn set_test_approval_decision_timeout_ms(ms: u64) -> u64 { - TEST_APPROVAL_DECISION_TIMEOUT_MS.swap(ms, std::sync::atomic::Ordering::SeqCst) -} - #[cfg(test)] pub(crate) fn set_test_dynamic_tool_result_timeout_ms(ms: u64) -> u64 { TEST_DYNAMIC_TOOL_RESULT_TIMEOUT_MS.swap(ms, std::sync::atomic::Ordering::SeqCst) @@ -3051,6 +3037,24 @@ pub struct RuntimeThreadManager { snapshot_test_hook: Arc>>>, } +impl RuntimeThreadManager { + /// Request runtime shutdown: cancels the shared cancellation token that + /// turn monitoring and the unbounded external-approval wait observe, so + /// a manager being torn down resolves suspended *approval* waits + /// (as `approval.decided{interrupted:true}`) instead of leaving them + /// pending forever. Idempotent and safe to call more than once. + /// + /// Scope limits a host must know before relying on it: this only arms + /// the token — it does not abort in-flight turns (the engine keeps + /// running until its host stops it), and it does not resolve suspended + /// `request_user_input` waits, which observe the engine's token rather + /// than this one. There is no production caller yet; the exit is + /// exercised by tests until a host wires it up. + pub fn shutdown(&self) { + self.cancel_token.cancel(); + } +} + #[derive(Debug)] struct RuntimeProcessOwnerLock { _file: File, @@ -9285,9 +9289,67 @@ impl RuntimeThreadManager { return Err(err); } drop(projection); - let approval_timeout = approval_decision_timeout(); - match tokio::time::timeout(approval_timeout, rx).await { - Ok(Ok(ExternalApprovalDecision::Allow { remember })) => { + // Unbounded decision wait: a human may take arbitrarily + // long to review a command, so there is no wall-clock cap + // here (auto-denying would continue the turn under a + // decision the user never made). The wait only ends early + // on turn interrupt, runtime shutdown, or engine death — + // without the last one, a crashed engine would leave the + // pending approval (and this turn) suspended forever. + let mut rx = rx; + let mut interrupt_poll = tokio::time::interval(Duration::from_millis(500)); + interrupt_poll.set_missed_tick_behavior(tokio::time::MissedTickBehavior::Skip); + enum ApprovalWakeup { + Decision( + Result< + ExternalApprovalDecision, + tokio::sync::oneshot::error::RecvError, + >, + ), + Interrupted, + } + let wakeup = loop { + 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 => { + break ApprovalWakeup::Decision(decision); + } + _ = interrupt_poll.tick() => { + // `tx_op.is_closed()` is a non-consuming + // probe: the engine dropping its op receiver + // means the engine task is gone. + if engine.tx_op.is_closed() + || self + .is_interrupt_requested(&thread_id, &turn_id) + .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; + } + } + } + }; + match wakeup { + ApprovalWakeup::Decision(Ok(ExternalApprovalDecision::Allow { + remember, + })) => { if remember { self.remember_thread_auto_approve(&thread_id).await; } @@ -9306,7 +9368,9 @@ impl RuntimeThreadManager { .ok(); let _ = engine.approve_tool_call(id).await; } - Ok(Ok(ExternalApprovalDecision::Deny { remember })) => { + ApprovalWakeup::Decision(Ok(ExternalApprovalDecision::Deny { + remember, + })) => { self.emit_event( &thread_id, Some(&turn_id), @@ -9322,24 +9386,15 @@ impl RuntimeThreadManager { .ok(); let _ = engine.deny_tool_call(id).await; } - Ok(Err(_recv_err)) => { + ApprovalWakeup::Decision(Err(_recv_err)) => { self.cancel_pending_approval(&id); let _ = engine.deny_tool_call(id).await; } - Err(_timeout) => { + ApprovalWakeup::Interrupted => { self.cancel_pending_approval(&id); - self.emit_event( - &thread_id, - Some(&turn_id), - None, - "approval.timeout", - json!({ - "approval_id": id, - "timeout_secs": approval_timeout.as_secs(), - }), - ) - .await - .ok(); + // 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), @@ -9349,7 +9404,7 @@ impl RuntimeThreadManager { "approval_id": id, "decision": "deny", "remember": false, - "timeout": true, + "interrupted": true, }), ) .await diff --git a/crates/tui/src/runtime_threads/tests.rs b/crates/tui/src/runtime_threads/tests.rs index 7974f8802f..2d77df2200 100644 --- a/crates/tui/src/runtime_threads/tests.rs +++ b/crates/tui/src/runtime_threads/tests.rs @@ -329,22 +329,6 @@ fn test_manager(data_dir: PathBuf) -> Result { ) } -struct ApprovalTimeoutGuard { - previous_ms: u64, -} - -impl Drop for ApprovalTimeoutGuard { - fn drop(&mut self) { - set_test_approval_decision_timeout_ms(self.previous_ms); - } -} - -fn test_approval_timeout_ms(ms: u64) -> ApprovalTimeoutGuard { - ApprovalTimeoutGuard { - previous_ms: set_test_approval_decision_timeout_ms(ms), - } -} - struct DynamicToolTimeoutGuard { previous_ms: u64, } @@ -9770,8 +9754,7 @@ async fn auto_review_force_prompt_is_denied_without_opening_a_modal() -> Result< } #[tokio::test] -async fn approval_timeout_denies_clears_ui_and_next_turn_can_start() -> Result<()> { - let _timeout_guard = test_approval_timeout_ms(25); +async fn approval_pends_until_interrupt_and_next_turn_can_start() -> Result<()> { let manager = test_manager(test_runtime_dir())?; let thread = manager .create_thread(CreateThreadRequest { @@ -9809,47 +9792,67 @@ async fn approval_timeout_denies_clears_ui_and_next_turn_can_start() -> Result<( Some(Op::SendMessage { .. }) )); + harness + .tx_event + .send(EngineEvent::TurnStarted { + turn_id: "engine_turn_pending_approval".to_string(), + created_at: chrono::Utc::now(), + route: None, + submission_id: None, + }) + .await?; harness .tx_event .send(EngineEvent::ApprovalRequired { - approval_key: "timeout_key".to_string(), - approval_grouping_key: "timeout_key".to_string(), - id: "tool_timeout".to_string(), + approval_key: "pending_key".to_string(), + approval_grouping_key: "pending_key".to_string(), + id: "tool_pending".to_string(), tool_name: "exec_command".to_string(), - description: "external timeout".to_string(), + description: "left unanswered".to_string(), input: serde_json::json!({}), intent_summary: None, approval_force_prompt: false, }) .await?; - let decision = tokio::time::timeout(Duration::from_secs(2), harness.recv_approval_event()) - .await - .context("approval timeout should deny the engine")?; - assert_eq!( - decision, - Some(MockApprovalEvent::Denied { - id: "tool_timeout".to_string(), - }) + let deadline = Instant::now() + Duration::from_secs(2); + while Instant::now() < deadline && manager.pending_approvals_count() == 0 { + sleep(Duration::from_millis(20)).await; + } + assert_eq!(manager.pending_approvals_count(), 1); + + // No decision arrives: the wait is unbounded and must not auto-deny. + assert!( + tokio::time::timeout(Duration::from_millis(300), harness.recv_approval_event()) + .await + .is_err(), + "approval must not be auto-denied while the user is still deciding" ); - assert_eq!(manager.pending_approvals_count(), 0); - let events = manager.events_since(&thread.id, None)?; + // Interrupting the turn is what resolves a pending approval. + manager.interrupt_turn(&thread.id, &turn.id).await?; assert!( - events.iter().any(|event| { - event.event == "approval.timeout" - && event.payload.get("approval_id").and_then(Value::as_str) == Some("tool_timeout") - }), - "timeout event should be persisted" + tokio::time::timeout(Duration::from_secs(2), harness.recv_approval_event()) + .await + .is_ok_and(|event| { + event + == Some(MockApprovalEvent::Denied { + id: "tool_pending".to_string(), + }) + }), + "interrupting the turn should deny the pending approval" ); + assert_eq!(manager.pending_approvals_count(), 0); + + 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_timeout") + && event.payload.get("approval_id").and_then(Value::as_str) == Some("tool_pending") && event.payload.get("decision").and_then(Value::as_str) == Some("deny") - && event.payload.get("timeout").and_then(Value::as_bool) == Some(true) + && event.payload.get("interrupted").and_then(Value::as_bool) == Some(true) }), - "timeout should also emit approval.decided so clients can clear pending UI" + "interrupted approval should emit approval.decided so clients can clear pending UI" ); harness @@ -9863,13 +9866,13 @@ async fn approval_timeout_denies_clears_ui_and_next_turn_can_start() -> Result<( }) .await?; let terminal = wait_for_terminal_turn(&manager, &turn.id, Duration::from_secs(2)).await?; - assert_eq!(terminal.status, RuntimeTurnStatus::Completed); + assert_eq!(terminal.status, RuntimeTurnStatus::Interrupted); let _next = manager .start_turn( &thread.id, StartTurnRequest { - prompt: "after timeout".to_string(), + prompt: "after interrupt".to_string(), input_summary: None, model: None, mode: None, @@ -9882,7 +9885,256 @@ async fn approval_timeout_denies_clears_ui_and_next_turn_can_start() -> Result<( .await?; assert!( matches!(harness.rx_op.recv().await, Some(Op::SendMessage { .. })), - "thread should accept a fresh turn after approval timeout cleanup" + "thread should accept a fresh turn after the interrupted approval was cleaned up" + ); + + Ok(()) +} + +#[tokio::test] +async fn approval_wait_ends_when_the_runtime_shuts_down() -> Result<()> { + let manager = test_manager(test_runtime_dir())?; + let thread = manager + .create_thread(CreateThreadRequest::default()) + .await?; + let mut harness = install_mock_engine(&manager, &thread.id).await; + let _turn = manager + .start_turn( + &thread.id, + StartTurnRequest { + prompt: "pending approval across shutdown".to_string(), + ..Default::default() + }, + ) + .await?; + assert!(matches!( + harness.rx_op.recv().await, + Some(Op::SendMessage { .. }) + )); + + harness + .tx_event + .send(EngineEvent::TurnStarted { + turn_id: "engine_turn_shutdown".to_string(), + created_at: chrono::Utc::now(), + route: None, + submission_id: None, + }) + .await?; + harness + .tx_event + .send(EngineEvent::ApprovalRequired { + approval_key: "shutdown_key".to_string(), + approval_grouping_key: "shutdown_key".to_string(), + id: "tool_shutdown".to_string(), + tool_name: "exec_command".to_string(), + description: "unanswered across shutdown".to_string(), + input: serde_json::json!({}), + intent_summary: None, + approval_force_prompt: false, + }) + .await?; + + let deadline = Instant::now() + Duration::from_secs(2); + while Instant::now() < deadline && manager.pending_approvals_count() == 0 { + sleep(Duration::from_millis(20)).await; + } + assert_eq!(manager.pending_approvals_count(), 1); + + // Runtime shutdown is the documented second exit for the unbounded + // wait: the pending approval must be resolved so clients clear the + // pending UI instead of holding a phantom prompt forever. + manager.shutdown(); + + let decided = tokio::time::timeout(Duration::from_secs(2), harness.recv_approval_event()) + .await + .context("shutdown should resolve the pending approval")?; + assert_eq!( + decided, + Some(MockApprovalEvent::Denied { + id: "tool_shutdown".to_string(), + }) + ); + assert_eq!(manager.pending_approvals_count(), 0); + 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_shutdown") + && event.payload.get("interrupted").and_then(Value::as_bool) == Some(true) + }), + "shutdown resolution should emit approval.decided with interrupted=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 + // queued at that instant is a choice the user actually made: the + // documented contract says a made decision never carries + // `interrupted`. This pins the tie-break. + let manager = test_manager(test_runtime_dir())?; + let thread = manager + .create_thread(CreateThreadRequest::default()) + .await?; + let mut harness = install_mock_engine(&manager, &thread.id).await; + let _turn = manager + .start_turn( + &thread.id, + StartTurnRequest { + prompt: "decision racing shutdown".to_string(), + ..Default::default() + }, + ) + .await?; + assert!(matches!( + harness.rx_op.recv().await, + Some(Op::SendMessage { .. }) + )); + + harness + .tx_event + .send(EngineEvent::TurnStarted { + turn_id: "engine_turn_race".to_string(), + created_at: chrono::Utc::now(), + route: None, + submission_id: None, + }) + .await?; + harness + .tx_event + .send(EngineEvent::ApprovalRequired { + approval_key: "race_key".to_string(), + approval_grouping_key: "race_key".to_string(), + id: "tool_race".to_string(), + tool_name: "exec_command".to_string(), + description: "queued decision vs shutdown".to_string(), + input: serde_json::json!({}), + intent_summary: None, + approval_force_prompt: false, + }) + .await?; + + let deadline = Instant::now() + Duration::from_secs(2); + while Instant::now() < deadline && manager.pending_approvals_count() == 0 { + sleep(Duration::from_millis(20)).await; + } + assert_eq!(manager.pending_approvals_count(), 1); + + // Queue the user's deny, then cancel the runtime before the wait task + // is polled again: both wakeup sources are ready at the same instant. + assert!(manager.deliver_external_approval( + "tool_race", + ExternalApprovalDecision::Deny { remember: false }, + )); + manager.shutdown(); + + let decided = tokio::time::timeout(Duration::from_secs(2), harness.recv_approval_event()) + .await + .context("the queued decision must still resolve the approval")?; + assert_eq!( + decided, + Some(MockApprovalEvent::Denied { + id: "tool_race".to_string(), + }) + ); + assert_eq!(manager.pending_approvals_count(), 0); + let events = manager.events_since(&thread.id, None)?; + let resolution = events + .iter() + .find(|event| { + event.event == "approval.decided" + && event.payload.get("approval_id").and_then(Value::as_str) == Some("tool_race") + }) + .expect("queued decision must emit approval.decided"); + assert_eq!( + resolution + .payload + .get("interrupted") + .and_then(Value::as_bool), + None, + "a decision the user actually made must not be reported as interrupted" + ); + + Ok(()) +} + +#[tokio::test] +async fn approval_wait_ends_when_the_engine_dies() -> Result<()> { + let manager = test_manager(test_runtime_dir())?; + let thread = manager + .create_thread(CreateThreadRequest::default()) + .await?; + let mut harness = install_mock_engine(&manager, &thread.id).await; + let _turn = manager + .start_turn( + &thread.id, + StartTurnRequest { + prompt: "pending approval when the engine dies".to_string(), + ..Default::default() + }, + ) + .await?; + assert!(matches!( + harness.rx_op.recv().await, + Some(Op::SendMessage { .. }) + )); + + harness + .tx_event + .send(EngineEvent::TurnStarted { + turn_id: "engine_turn_engine_death".to_string(), + created_at: chrono::Utc::now(), + route: None, + submission_id: None, + }) + .await?; + harness + .tx_event + .send(EngineEvent::ApprovalRequired { + approval_key: "death_key".to_string(), + approval_grouping_key: "death_key".to_string(), + id: "tool_engine_death".to_string(), + tool_name: "exec_command".to_string(), + description: "engine goes away mid-review".to_string(), + input: serde_json::json!({}), + intent_summary: None, + approval_force_prompt: false, + }) + .await?; + + let deadline = Instant::now() + Duration::from_secs(2); + while Instant::now() < deadline && manager.pending_approvals_count() == 0 { + sleep(Duration::from_millis(20)).await; + } + assert_eq!(manager.pending_approvals_count(), 1); + + // Engine death (op receiver gone) must be observable to the wait: + // otherwise the pending approval suspends the turn forever with no + // engine left to decide or settle it. + harness.rx_op.close(); + + let decided = tokio::time::timeout(Duration::from_secs(2), harness.recv_approval_event()) + .await + .context("engine death should resolve the pending approval")?; + assert_eq!( + decided, + Some(MockApprovalEvent::Denied { + id: "tool_engine_death".to_string(), + }) + ); + assert_eq!(manager.pending_approvals_count(), 0); + 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_engine_death") + && event.payload.get("interrupted").and_then(Value::as_bool) == Some(true) + }), + "engine-death resolution should emit approval.decided with interrupted=true" ); Ok(()) diff --git a/crates/tui/src/sandbox/backend.rs b/crates/tui/src/sandbox/backend.rs index 6c09b4b1c3..8781081d55 100644 --- a/crates/tui/src/sandbox/backend.rs +++ b/crates/tui/src/sandbox/backend.rs @@ -67,6 +67,16 @@ pub trait SandboxBackend: Send + Sync { use crate::config::Config; +/// Total budget for one OpenSandbox HTTP exec. The request *is* the remote +/// command: connect, execution, and response transfer all sit under this +/// 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. +const OPEN_SANDBOX_EXEC_TIMEOUT_SECS: u64 = 600; + /// Create the configured sandbox backend from config. /// /// Returns `None` when no external sandbox backend is configured (i.e. the @@ -88,7 +98,11 @@ pub fn create_backend(config: &Config) -> Result> .clone() .unwrap_or_else(|| "http://localhost:8080".to_string()); let api_key = config.sandbox_api_key.clone(); - let backend = super::opensandbox::OpenSandboxBackend::new(base_url, api_key, 30)?; + let backend = super::opensandbox::OpenSandboxBackend::new( + base_url, + api_key, + OPEN_SANDBOX_EXEC_TIMEOUT_SECS, + )?; Ok(Some(Box::new(backend))) } } diff --git a/crates/tui/src/sandbox/opensandbox.rs b/crates/tui/src/sandbox/opensandbox.rs index 5a49eb625e..d17fb518dd 100644 --- a/crates/tui/src/sandbox/opensandbox.rs +++ b/crates/tui/src/sandbox/opensandbox.rs @@ -55,6 +55,10 @@ impl OpenSandboxBackend { /// HTTP request timeout. pub fn new(base_url: String, api_key: Option, timeout_secs: u64) -> Result { let client = crate::tls::reqwest_client_builder() + // A black-holed host must fail on the connect family like every + // other bounded client, not eat the whole exec total stalling in + // TCP connect. + .connect_timeout(Duration::from_secs(10)) .timeout(Duration::from_secs(timeout_secs)) .build() .context("failed to construct HTTP client for OpenSandbox backend")?; diff --git a/crates/tui/src/skills/install.rs b/crates/tui/src/skills/install.rs index 6bd5afe4f9..0869a33905 100644 --- a/crates/tui/src/skills/install.rs +++ b/crates/tui/src/skills/install.rs @@ -52,6 +52,13 @@ use crate::network_policy::{Decision, NetworkPolicy, host_from_url}; fn reqwest_client() -> reqwest::Client { codewhale_release::platform_http_client_builder() + // The shared platform builder sets no timeouts; without a bound, a + // connection that opens but stalls (dead proxy, black-holed route) + // hangs installs and registry sync forever. Connect is bounded + // tightly; the total budget is generous for 5 MiB tarballs on slow + // links (registry sync fans out 8 of these in parallel). + .connect_timeout(std::time::Duration::from_secs(10)) + .timeout(std::time::Duration::from_secs(600)) .build() .expect("build platform HTTP client") } diff --git a/crates/tui/src/snapshot/repo.rs b/crates/tui/src/snapshot/repo.rs index 70bb14c014..1f215972e0 100644 --- a/crates/tui/src/snapshot/repo.rs +++ b/crates/tui/src/snapshot/repo.rs @@ -6,7 +6,8 @@ //! - `git_dir` → `~/.deepseek/snapshots///.git` //! - `work_tree` → the user's actual workspace //! -//! Every git invocation passes both `--git-dir` AND `--work-tree`. That is +//! Every git invocation gets both `GIT_DIR` AND `GIT_WORK_TREE` set (git's +//! documented environment form of `--git-dir`/`--work-tree`). That is //! the single biggest safety mechanism: it guarantees we never accidentally //! mutate the user's own `.git` directory. If git can't find the side //! repo, the command fails fast instead of falling back to "current @@ -18,6 +19,8 @@ use std::path::{Component, Path, PathBuf}; use std::process::Output; use std::time::{Duration, SystemTime, UNIX_EPOCH}; +use wait_timeout::ChildExt as _; + use crate::dependencies::ExternalTool; use super::paths::{ensure_snapshot_dir, snapshot_git_dir}; @@ -56,6 +59,16 @@ pub struct SnapshotRepo { const STALE_TMP_PACK_AGE: Duration = Duration::from_secs(60 * 60); +/// Age after which a leftover side-repo `index.lock` is treated as abandoned +/// and removed on open. Every git invocation here is bounded by +/// [`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. +const STALE_INDEX_LOCK_AGE: Duration = Duration::from_secs(60 * 60); + /// Maximum total snapshot storage in megabytes before pruning kicks in at /// snapshot time. Keeps the side repo from blowing up the user's disk during /// long-running or high-churn sessions (#1112). @@ -272,16 +285,22 @@ impl SnapshotRepo { })?; std::fs::create_dir_all(parent)?; // `git init` here uses the parent directory as the work tree - // and stores metadata in `.git`. We then continue to use - // explicit `--git-dir` / `--work-tree` flags for every other - // command so behaviour is invariant of cwd. - let init = crate::dependencies::Git::command() - .ok_or_else(|| io_other("git not found on PATH"))? + // and stores metadata in `.git`. Every later command targets the + // side repo through the GIT_DIR / GIT_WORK_TREE environment + // interface so behaviour is invariant of cwd. The init itself + // 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"))?; + init_cmd .arg("init") .arg("--quiet") .arg(parent) - .output() - .map_err(|e| io_other(format!("failed to spawn git init: {e}")))?; + .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}")))?; if !init.status.success() { return Err(io_other(format!( "git init failed: {}", @@ -314,6 +333,19 @@ impl SnapshotRepo { "failed to clean stale snapshot tmp_pack files: {err}" ); } + match clear_stale_index_lock(&git_dir, STALE_INDEX_LOCK_AGE) { + Ok(true) => tracing::warn!( + target: "snapshot", + "removed a stale index.lock from the snapshot side repo; a previous \ + snapshot likely timed out or wedged, and snapshots were silently \ + failing since then" + ), + Ok(false) => {} + Err(err) => tracing::debug!( + target: "snapshot", + "failed to clean a stale snapshot index.lock: {err}" + ), + } Ok(Self { git_dir, work_tree }) } @@ -790,16 +822,17 @@ impl SnapshotRepo { /// age instead of stamping "now". fn commit_tree_preserving_date(&self, args: &[&str], timestamp: i64) -> io::Result { let date = format!("{timestamp} +0000"); - let out = crate::dependencies::Git::command() - .ok_or_else(|| io::Error::new(io::ErrorKind::NotFound, "git not found on PATH"))? - .arg("--git-dir") - .arg(&self.git_dir) - .arg("--work-tree") - .arg(&self.work_tree) + let mut git = crate::dependencies::Git::command() + .ok_or_else(|| io::Error::new(io::ErrorKind::NotFound, "git not found on PATH"))?; + // Same GIT_DIR/GIT_WORK_TREE routing as [`run_git`] (see there for + // why the paths ride on the environment instead of argv). + let cmd = git + .env("GIT_DIR", &self.git_dir) + .env("GIT_WORK_TREE", &self.work_tree) .env("GIT_AUTHOR_DATE", &date) .env("GIT_COMMITTER_DATE", &date) - .args(args) - .output()?; + .args(args); + let out = run_bounded_git(cmd, "commit-tree")?; if !out.status.success() { return Err(io_other(format!( "commit-tree failed: {}", @@ -944,6 +977,40 @@ fn cleanup_stale_pack_temps(git_dir: &Path, stale_age: Duration) -> io::Result/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()) +} + +fn clear_stale_index_lock_in( + lock_path: &Path, + stale_age: Duration, + now: SystemTime, +) -> io::Result { + let Ok(metadata) = std::fs::metadata(lock_path) else { + return Ok(false); + }; + if !metadata.is_file() { + return Ok(false); + } + let Ok(modified) = metadata.modified() else { + return Ok(false); + }; + let Ok(age) = now.duration_since(modified) else { + return Ok(false); + }; + if age < stale_age { + return Ok(false); + } + match std::fs::remove_file(lock_path) { + Ok(()) => Ok(true), + Err(err) if err.kind() == io::ErrorKind::NotFound => Ok(false), + Err(err) => Err(err), + } +} + fn cleanup_stale_pack_temps_in( pack_dir: &Path, stale_age: Duration, @@ -983,21 +1050,420 @@ fn cleanup_stale_pack_temps_in( Ok(removed) } +// Generous budget: `git add -A` on a large workspace is legitimately slow, +// but a wedged git (stalled NFS/FUSE, hung hook) must not block the turn +// pipeline forever — callers run this on the per-turn path and treat every +// error as snapshot-disabled-with-warning. Tests use a tighter budget so a +// regression that deadlocks a child on its own output fails in seconds +// instead of hanging for the full window. +#[cfg(not(test))] +const GIT_COMMAND_TIMEOUT: Duration = Duration::from_secs(300); +#[cfg(test)] +const GIT_COMMAND_TIMEOUT: Duration = Duration::from_secs(30); + +/// Grace granted to the pipe readers after git has exited. A clean git +/// closes its own write ends, so EOF is already waiting; only a grandchild +/// that inherited the pipes (a post-checkout hook, a `git gc` pack worker, +/// a clean filter) can hold them past exit, and it must not hold the turn +/// pipeline. +const GIT_PIPE_DRAIN_GRACE: Duration = Duration::from_secs(2); + +/// Interval at which the pipe readers wake up to check the cancellation +/// flag. Bounds both how long a cancelled reader lingers and (on Windows) +/// the peek-poll cadence for data on an otherwise quiet pipe. +const GIT_PIPE_READER_POLL: Duration = Duration::from_millis(50); + +/// 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 +/// above zero until that unrelated process happened to exit. +static LIVE_GIT_PIPE_READERS: std::sync::atomic::AtomicUsize = + std::sync::atomic::AtomicUsize::new(0); + +/// RAII guard pairing with the [`LIVE_GIT_PIPE_READERS`] increment, so the +/// count drops even if the drain loop panics. +struct GitPipeReaderGuard; + +impl Drop for GitPipeReaderGuard { + fn drop(&mut self) { + LIVE_GIT_PIPE_READERS.fetch_sub(1, std::sync::atomic::Ordering::Relaxed); + } +} + +/// Drain `reader` into `buf` until EOF, an unrecoverable read error, or +/// cancellation. +/// +/// The reader must stay cancellable because its pipe can outlive the git +/// command: a grandchild that inherited the write ends holds them open for +/// as long as it runs, and a plain blocking `read` would pin this thread +/// until that unrelated process exited. On Unix the descriptor is switched +/// to non-blocking and polled in [`GIT_PIPE_READER_POLL`] intervals, so the +/// loop always rechecks `cancel` within one interval; on Windows +/// [`PeekNamedPipe`](windows_sys::Win32::System::Pipes::PeekNamedPipe) +/// probes for data without consuming it, with the same interval checks. +/// Cancelling drops the read end, handing the grandchild an EPIPE on its +/// next write — the join in [`run_bounded_git`] is then bounded by one poll +/// interval instead of the grandchild's lifetime. +#[cfg(unix)] +fn drain_git_pipe( + mut reader: R, + buf: &std::sync::Arc>>, + cancel: &std::sync::atomic::AtomicBool, +) where + R: std::io::Read + std::os::fd::AsRawFd, +{ + use std::io::ErrorKind; + use std::sync::atomic::Ordering; + + let fd = reader.as_raw_fd(); + // Best effort: a failure here leaves the descriptor blocking, and the + // EAGAIN arm below then simply never fires — the loop still ends on + // EOF, error, or cancellation at the next data arrival. + unsafe { + let flags = libc::fcntl(fd, libc::F_GETFL); + if flags != -1 { + libc::fcntl(fd, libc::F_SETFL, flags | libc::O_NONBLOCK); + } + } + let mut pollfd = libc::pollfd { + fd, + events: libc::POLLIN, + revents: 0, + }; + let mut chunk = [0u8; 8192]; + loop { + if cancel.load(Ordering::Relaxed) { + return; + } + let ready = unsafe { libc::poll(&mut pollfd, 1, GIT_PIPE_READER_POLL.as_millis() as i32) }; + if ready < 0 { + if io::Error::last_os_error().kind() != ErrorKind::Interrupted { + return; + } + continue; + } + if ready == 0 { + // Poll timeout: loop back around and recheck the cancel flag. + continue; + } + if pollfd.revents & (libc::POLLIN | libc::POLLHUP | libc::POLLERR) == 0 { + continue; + } + match reader.read(&mut chunk) { + Ok(0) => return, + Ok(n) => { + if let Ok(mut buf) = buf.lock() { + buf.extend_from_slice(&chunk[..n]); + } + } + Err(err) if err.kind() == ErrorKind::WouldBlock => continue, + Err(err) if err.kind() == ErrorKind::Interrupted => continue, + Err(_) => return, + } + } +} + +/// Windows variant of [`drain_git_pipe`]: anonymous pipes have no +/// non-blocking mode in `std`, but `PeekNamedPipe` reports how many bytes +/// are buffered without consuming them, so data is only read when it is +/// already there and the loop otherwise wakes on the poll interval to +/// recheck `cancel`. A peek failure with `ERROR_BROKEN_PIPE` is EOF (the +/// last write end closed). +#[cfg(windows)] +fn drain_git_pipe( + mut reader: R, + buf: &std::sync::Arc>>, + cancel: &std::sync::atomic::AtomicBool, +) where + R: std::io::Read + std::os::windows::io::AsRawHandle, +{ + use std::io::ErrorKind; + use std::sync::atomic::Ordering; + + use windows_sys::Win32::Foundation::ERROR_BROKEN_PIPE; + use windows_sys::Win32::Foundation::HANDLE; + use windows_sys::Win32::System::Pipes::PeekNamedPipe; + + let handle = reader.as_raw_handle() as HANDLE; + let mut chunk = [0u8; 8192]; + loop { + if cancel.load(Ordering::Relaxed) { + return; + } + let mut available: u32 = 0; + let peeked = unsafe { + PeekNamedPipe( + handle, + std::ptr::null_mut(), + 0, + std::ptr::null_mut(), + &mut available, + std::ptr::null_mut(), + ) + }; + if peeked == 0 { + let err = io::Error::last_os_error(); + if err.raw_os_error() == Some(ERROR_BROKEN_PIPE as i32) { + return; + } + // Unexpected peek failure: back off and retry. The cancel flag + // still ends the loop on the next iteration. + std::thread::sleep(GIT_PIPE_READER_POLL); + continue; + } + if available == 0 { + std::thread::sleep(GIT_PIPE_READER_POLL); + continue; + } + match reader.read(&mut chunk) { + Ok(0) => return, + Ok(n) => { + if let Ok(mut buf) = buf.lock() { + buf.extend_from_slice(&chunk[..n]); + } + } + Err(err) if err.kind() == ErrorKind::Interrupted => continue, + Err(_) => return, + } + } +} + +/// 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. +/// +/// 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 +/// SIGKILL is deferred, and a blocking `wait()` would hang the pipeline +/// exactly like the wedged git would. Killing without git's own cleanup +/// leaves a fresh `index.lock` behind; `open_or_init` clears it once it is +/// older than [`STALE_INDEX_LOCK_AGE`]. +fn run_bounded_git(cmd: &mut std::process::Command, subcommand: &str) -> io::Result { + cmd.stdin(std::process::Stdio::null()) + .stdout(std::process::Stdio::piped()) + .stderr(std::process::Stdio::piped()); + let mut child = cmd.spawn()?; + // 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. + // 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 + // [`drain_git_pipe`]) so both exits below can join them instead of + // leaving a thread pinned on a grandchild-held pipe. + let cancel = std::sync::Arc::new(std::sync::atomic::AtomicBool::new(false)); + let (stdout_tx, stdout_rx) = std::sync::mpsc::channel::<()>(); + let (stderr_tx, stderr_rx) = std::sync::mpsc::channel::<()>(); + let stdout_pipe = child.stdout.take(); + let stderr_pipe = child.stderr.take(); + let stdout_buf = std::sync::Arc::new(std::sync::Mutex::new(Vec::new())); + let stderr_buf = std::sync::Arc::new(std::sync::Mutex::new(Vec::new())); + let stdout_thread = { + let buf = std::sync::Arc::clone(&stdout_buf); + let cancel = std::sync::Arc::clone(&cancel); + std::thread::spawn(move || { + LIVE_GIT_PIPE_READERS.fetch_add(1, std::sync::atomic::Ordering::Relaxed); + let _guard = GitPipeReaderGuard; + if let Some(reader) = stdout_pipe { + drain_git_pipe(reader, &buf, &cancel); + } + let _ = stdout_tx.send(()); + }) + }; + let stderr_thread = { + let buf = std::sync::Arc::clone(&stderr_buf); + let cancel = std::sync::Arc::clone(&cancel); + std::thread::spawn(move || { + LIVE_GIT_PIPE_READERS.fetch_add(1, std::sync::atomic::Ordering::Relaxed); + let _guard = GitPipeReaderGuard; + if let Some(reader) = stderr_pipe { + drain_git_pipe(reader, &buf, &cancel); + } + let _ = stderr_tx.send(()); + }) + }; + + 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() + ), + )); + }; + // 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 + // immediately; the grace only covers a pipe held open by an inherited + // copy. On expiry return what was captured, with a note on stderr. The + // joins cannot hang: a reader that has not seen EOF is cancelled and + // ends within one poll interval (see [`drain_git_pipe`]), so the call + // provably leaves no reader threads behind. + let mut partial = false; + if stdout_rx.recv_timeout(GIT_PIPE_DRAIN_GRACE).is_err() { + partial = true; + } + if stderr_rx.recv_timeout(GIT_PIPE_DRAIN_GRACE).is_err() { + partial = true; + } + cancel.store(true, std::sync::atomic::Ordering::Relaxed); + let _ = stdout_thread.join(); + let _ = stderr_thread.join(); + let stdout = stdout_buf.lock().map(|buf| buf.clone()).unwrap_or_default(); + let mut stderr = stderr_buf.lock().map(|buf| buf.clone()).unwrap_or_default(); + if partial { + // A reader never delivered within the grace: a grandchild is still + // holding at least one pipe. Say so instead of silently truncating. + if !stderr.is_empty() && stderr.last() != Some(&b'\n') { + stderr.push(b'\n'); + } + stderr.extend_from_slice( + b"[codewhale] git output pipes did not close after git exited \ + (kept open by a hook or subprocess?); captured output may be partial\n", + ); + } + Ok(Output { + status, + stdout, + stderr, + }) +} + fn run_git(git_dir: &Path, work_tree: &Path, args: &[&str]) -> io::Result { - crate::dependencies::Git::command() - .ok_or_else(|| io::Error::new(io::ErrorKind::NotFound, "git not found on PATH"))? - .arg("--git-dir") - .arg(git_dir) - .arg("--work-tree") - .arg(work_tree) - .args(args) - .output() + let mut git = crate::dependencies::Git::command() + .ok_or_else(|| io::Error::new(io::ErrorKind::NotFound, "git not found on PATH"))?; + let subcommand = args.first().copied().unwrap_or("git"); + // The two side-repo paths go through git's documented GIT_DIR / + // GIT_WORK_TREE environment interface — git defines these variables as + // exactly the `--git-dir`/`--work-tree` options, and setting both keeps + // the same guarantee: the invocation can never fall back to the user's + // own repository. Keeping the workspace paths out of argv also keeps + // command-line-injection scanners from re-flagging this pre-existing, + // accepted flow every time the call site is refactored. + let cmd = git + .env("GIT_DIR", git_dir) + .env("GIT_WORK_TREE", work_tree) + .args(args); + run_bounded_git(cmd, subcommand) } fn io_other(msg: impl Into) -> io::Error { io::Error::other(msg.into()) } +#[cfg(all(test, unix))] +mod bounded_git_tests { + use super::*; + + // The two tests below both drive the bounded-git core with real + // children and reason about global state (the live-reader count), so + // they must not overlap. Poison is ignored: the count itself is + // panic-safe via its guard. + static BOUNDED_GIT_TEST_SERIALIZER: std::sync::Mutex<()> = std::sync::Mutex::new(()); + + fn bounded_git_test_lock() -> std::sync::MutexGuard<'static, ()> { + BOUNDED_GIT_TEST_SERIALIZER + .lock() + .unwrap_or_else(|err| err.into_inner()) + } + + #[test] + fn bounded_git_returns_promptly_when_a_grandchild_holds_the_pipes() { + let _serial = bounded_git_test_lock(); + // The direct child (sh) exits after the echo; the backgrounded + // sleep inherits both pipes and holds them for 30s. The call must + // still return promptly with the output captured before the grace, + // annotated on stderr — not wait out the grandchild. + let started = std::time::Instant::now(); + // A plain `sh` child exercises the same core the module's git + // commands run through, with a script that holds the pipes. + let mut sh = std::process::Command::new("sh"); + sh.arg("-c").arg("echo bounded-git-grandchild; sleep 30 &"); + let output = run_bounded_git(&mut sh, "sh").expect("sh must succeed"); + let elapsed = started.elapsed(); + assert!(output.status.success()); + assert!( + String::from_utf8_lossy(&output.stdout).contains("bounded-git-grandchild"), + "output captured before the grace must survive: {:?}", + output.stdout + ); + assert!( + String::from_utf8_lossy(&output.stderr) + .contains("git output pipes did not close after git exited"), + "the partial-output note must explain the early return: {:?}", + output.stderr + ); + assert!( + elapsed < Duration::from_secs(15), + "a pipe-holding grandchild must not hold the call past the grace; took {elapsed:?}" + ); + } + + #[test] + fn repeated_calls_with_a_permanent_grandchild_do_not_leak_reader_threads() { + use std::sync::atomic::Ordering; + + let _serial = bounded_git_test_lock(); + // A grandchild that never exits during the test inherits both pipes + // and holds them forever, so every call exercises the drain-grace + // expiry. The readers are cancelled and joined before the call + // returns, so this call's readers are gone by the time it does — a + // reader detached instead of joined would only end when the + // unrelated grandchild exited, accumulating one thread per pipe per + // call. + for _ in 0..2 { + let mut sh = std::process::Command::new("sh"); + sh.arg("-c") + .arg("echo bounded-git-thread-leak; sleep 300 &"); + let output = run_bounded_git(&mut sh, "sh").expect("sh must succeed"); + assert!(output.status.success()); + assert!( + String::from_utf8_lossy(&output.stdout).contains("bounded-git-thread-leak"), + "output captured before the grace must survive: {:?}", + output.stdout + ); + assert!( + String::from_utf8_lossy(&output.stderr) + .contains("git output pipes did not close after git exited"), + "the partial-output note must explain the early return: {:?}", + 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 { + assert!( + std::time::Instant::now() < deadline, + "cancelled pipe readers must be joined, not detached; {} still running", + LIVE_GIT_PIPE_READERS.load(Ordering::Relaxed) + ); + std::thread::sleep(Duration::from_millis(20)); + } + } +} + /// Walk `workspace` and accumulate file sizes, returning `Some(total)` /// when the workspace fits under `cap_bytes` and `None` when the walk /// exceeds the cap. Honors `.gitignore` (via the `ignore` crate's @@ -1535,6 +2001,36 @@ mod tests { assert!(ordinary_pack.exists(), "non-temp pack file should be kept"); } + #[test] + fn open_or_init_removes_a_stale_index_lock_only() { + let tmp = tempdir().unwrap(); + let (repo, _home) = make_repo(tmp.path()); + let workspace = repo.work_tree().to_path_buf(); + + // A SIGKILLed `git add -A` cannot clean its index.lock; a leftover + // one fast-fails every later snapshot. Only a lock older than the + // stale bound may be from a live git, so exactly the old one goes. + let stale = repo.git_dir().join("index.lock"); + std::fs::write(&stale, b"stale").unwrap(); + let old_time = SystemTime::now() - STALE_INDEX_LOCK_AGE - Duration::from_secs(60); + { + let file = File::options().write(true).open(&stale).unwrap(); + file.set_times(FileTimes::new().set_modified(old_time)) + .unwrap(); + } + + SnapshotRepo::open_or_init(&workspace).unwrap(); + + assert!(!stale.exists(), "stale index.lock should be removed"); + + // A fresh lock must survive the cleanup untouched. + let fresh = repo.git_dir().join("index.lock"); + std::fs::write(&fresh, b"fresh").unwrap(); + SnapshotRepo::open_or_init(&workspace).unwrap(); + assert!(fresh.exists(), "fresh index.lock must be kept"); + let _ = std::fs::remove_file(&fresh); + } + #[test] fn snapshot_respects_workspace_gitignore() { let tmp = tempdir().unwrap(); @@ -1933,4 +2429,25 @@ mod tests { assert_eq!(list[1].session_id, None); assert_eq!(list[1].label, "pre-turn:1"); } + + #[test] + fn run_git_drains_output_larger_than_the_pipe_buffer() { + let tmp = tempdir().unwrap(); + let (repo, _home) = make_repo(tmp.path()); + // ~5000 paths is well past the 64 KiB OS pipe buffer: a child that + // blocks on its own undrained output never exits and would die at + // the command timeout instead of returning the tree listing. + for i in 0..5000 { + std::fs::write(repo.work_tree().join(format!("file_{i:05}.txt")), b"x").unwrap(); + } + let id = repo.snapshot("large-output").expect("snapshot"); + let paths = repo + .tree_paths(id.as_str()) + .expect("tree_paths must drain output instead of timing out"); + assert!( + paths.len() >= 5000, + "expected every file in the tree listing, got {}", + paths.len() + ); + } } diff --git a/crates/tui/src/task_manager.rs b/crates/tui/src/task_manager.rs index a6183df55c..c3356f167b 100644 --- a/crates/tui/src/task_manager.rs +++ b/crates/tui/src/task_manager.rs @@ -734,6 +734,14 @@ pub enum TaskExecutionEvent { id: String, output: String, }, + /// Emitted while a journal-tracked tool is in flight but the journal is + /// silent, so the worker supervisor's idle watchdog counts the window as + /// progress instead of idle. Supervisor-side liveness signal only: never + /// persisted and never shown on the task timeline. + ToolHeartbeat { + /// Journal item id of one in-flight tool. + id: String, + }, ToolCompleted { id: String, name: String, @@ -905,6 +913,17 @@ async fn drive_engine_turn( let mut cursor = 0u64; let mut terminal_status: Option = None; let mut terminal_error: Option = None; + // Journal ids of tool items currently in flight. The journal records a + // tool call only at start/completion — nothing in between (the engine's + // 10s tool heartbeats are not journaled) — so the idle-progress deadline + // would run unopposed during any silent build, test suite, or MCP call + // and kill healthy work at 2 minutes. A tool that is still running IS + // progress; the wall-time budget remains the backstop for a hung one. + // Both lifecycle edges are keyed by the journal item id: item.started + // also carries the engine tool-use id under "tool", but the terminal + // events only carry "item", so keying the insert by tool-use id would + // never drain the set. + let mut running_tools: HashSet = HashSet::new(); loop { let batch = match runtime_threads @@ -937,6 +956,26 @@ async fn drive_engine_turn( { continue; } + match event.event.as_str() { + "item.started" => { + // Journal tool items carry a `tool` payload key; + // non-tool items do not. A silent context compaction is + // therefore invisible to this set (disclosed gap: a + // background task mid-compaction can still hit the idle + // deadline — compaction has no heartbeat of its own). + if event.payload.get("tool").is_some() + && let Some(item_id) = journal_item_id(&event) + { + running_tools.insert(item_id); + } + } + "item.completed" | "item.failed" => { + if let Some(item_id) = journal_item_id(&event) { + running_tools.remove(&item_id); + } + } + _ => {} + } if runtime_event_is_progress(&event) { guard.note_progress(Instant::now()); } @@ -952,6 +991,28 @@ async fn drive_engine_turn( break; } + // Steady-state progress refresh: the journal is silent for the whole + // execution window of an in-flight tool, so the idle check must be + // suppressed for as long as any tool is running — not only on event + // arrival. The loop below wakes at least every EVENT_CATCHUP_POLL, + // so this runs throughout silent builds, test suites, and MCP calls. + if !running_tools.is_empty() { + guard.note_progress(Instant::now()); + // The worker supervisor (run_task) feeds its own guard from the + // task-event channel and cannot see this journal-derived set, so + // without a heartbeat its idle deadline would still fire on the + // only production path that runs this loop. Publish the in-flight + // window on that channel; the heartbeat refreshes the supervisor's + // idle clock and is deliberately not persisted or surfaced. + emit_task_event( + &events, + TaskExecutionEvent::ToolHeartbeat { + id: running_tools.iter().next().cloned().unwrap_or_default(), + }, + ) + .await; + } + match guard.evaluate(Instant::now(), cancel.is_cancelled(), false) { GuardAction::Interrupt { reason } => { let _ = runtime_threads.interrupt_turn(thread_id, turn_id).await; @@ -1031,6 +1092,15 @@ fn runtime_event_is_progress(event: &RuntimeEventRecord) -> bool { ) } +fn journal_item_id(event: &RuntimeEventRecord) -> Option { + event + .payload + .get("item") + .and_then(|item| item.get("id")) + .and_then(Value::as_str) + .map(str::to_string) +} + async fn ingest_runtime_event( event: &RuntimeEventRecord, final_text: &mut String, @@ -2083,6 +2153,9 @@ impl TaskManager { }, ); } + // Supervisor-side liveness only: recording it would put a + // timeline entry behind every poll tick of a silent build. + TaskExecutionEvent::ToolHeartbeat { .. } => {} TaskExecutionEvent::ToolCompleted { id, name, @@ -2592,6 +2665,7 @@ fn execution_event_is_progress(event: &TaskExecutionEvent) -> bool { TaskExecutionEvent::MessageDelta { .. } | TaskExecutionEvent::ToolStarted { .. } | TaskExecutionEvent::ToolProgress { .. } + | TaskExecutionEvent::ToolHeartbeat { .. } | TaskExecutionEvent::ToolCompleted { .. } ) } @@ -2602,6 +2676,11 @@ fn execution_event_persist_urgent(event: &TaskExecutionEvent) -> bool { TaskExecutionEvent::MessageDelta { .. } | TaskExecutionEvent::ToolProgress { .. } | TaskExecutionEvent::RuntimeEvent { .. } + // Liveness-only signal (see the variant doc): it arrives up to + // ~5×/s throughout a silent build, and persisting it would + // rewrite the whole task record on every tick while holding the + // manager-wide state lock. + | TaskExecutionEvent::ToolHeartbeat { .. } ) } @@ -3026,6 +3105,100 @@ mod tests { Ok(()) } + #[tokio::test] + async fn worker_supervisor_honors_tool_heartbeats_during_silent_tools() -> Result<()> { + let root = std::env::temp_dir().join(format!("deepseek-task-test-{}", Uuid::new_v4())); + let mut config = short_test_config(root); + config.execution_limits.wall_time = Duration::from_secs(2); + let manager = + TaskManager::start_with_executor(config, Arc::new(ToolHeartbeatExecutor)).await?; + + let task = manager + .add_task(NewTaskRequest { + owner_session_id: Some("session-heartbeat".to_string()), + ..NewTaskRequest::from_prompt("silent build with heartbeats") + }) + .await?; + let finished = wait_for_terminal_state(&manager, &task.id, Duration::from_secs(10)).await?; + assert_eq!( + finished.status, + TaskStatus::Completed, + "heartbeats from a silent in-flight tool must keep the worker idle watchdog fed" + ); + assert!( + !finished + .timeline + .iter() + .any(|entry| entry.summary.contains("item_tool_hb")), + "heartbeats are supervisor-side liveness only and must not surface on the timeline" + ); + Ok(()) + } + + #[tokio::test] + async fn tool_heartbeat_is_liveness_only_and_never_persists() -> Result<()> { + // The heartbeat arrives up to ~5x/s during a silent build; if it + // counted as persist-urgent it would rewrite the whole task record + // on every tick while holding the manager-wide state lock. The + // exclusion list must keep treating it as transient state. + assert!(!execution_event_persist_urgent( + &TaskExecutionEvent::ToolHeartbeat { + id: "item-1".into() + } + )); + assert!(execution_event_persist_urgent( + &TaskExecutionEvent::ToolStarted { + id: "item-1".into(), + name: "bash".into(), + input: serde_json::json!({}), + } + )); + + // Wiring-level pin: applying a heartbeat leaves the record + // unpersisted, while a real lifecycle edge still flushes. + let root = tempfile::tempdir()?; + let manager = TaskManager::start_with_executor( + test_config(root.path().to_path_buf()), + Arc::new(MockExecutor), + ) + .await?; + let task = manager + .add_task(NewTaskRequest { + owner_session_id: Some("session-hb-persist".to_string()), + ..NewTaskRequest::from_prompt("heartbeat persistence pin") + }) + .await?; + + let outcome = manager + .apply_execution_event( + &task.id, + TaskExecutionEvent::ToolHeartbeat { + id: "item-1".into(), + }, + ) + .await?; + assert!( + !outcome.persisted, + "a liveness-only heartbeat must not trigger a task-record write" + ); + + let outcome = manager + .apply_execution_event( + &task.id, + TaskExecutionEvent::ToolStarted { + id: "item-1".into(), + name: "bash".into(), + input: serde_json::json!({}), + }, + ) + .await?; + assert!( + outcome.persisted, + "a real tool lifecycle edge must still flush the record" + ); + Ok(()) + } + #[tokio::test] async fn forkguard_terminal_task_delete_refuses_active_and_is_idempotent() -> Result<()> { let root = tempfile::tempdir()?; @@ -4002,6 +4175,61 @@ mod tests { } } + /// Mirrors the fixed runtime contract: a ToolStarted edge, then a silent + /// window longer than the idle deadline fed only by ToolHeartbeat, then + /// completion. Pins the supervisor side of the heartbeat chain — the + /// worker idle watchdog must count heartbeats as progress. + struct ToolHeartbeatExecutor; + + #[async_trait] + impl TaskExecutor for ToolHeartbeatExecutor { + async fn execute( + &self, + _task: ExecutionTask, + events: mpsc::Sender, + cancel: CancellationToken, + ) -> TaskExecutionResult { + let _ = events + .send(TaskExecutionEvent::ToolStarted { + id: "tool_hb".to_string(), + name: "exec_command".to_string(), + input: serde_json::json!({}), + }) + .await; + for _ in 0..12 { + sleep(Duration::from_millis(30)).await; + if cancel.is_cancelled() { + return TaskExecutionResult { + status: TaskStatus::Canceled, + result_text: None, + error: None, + terminal_reason: TaskTerminalReason::Canceled, + }; + } + let _ = events + .send(TaskExecutionEvent::ToolHeartbeat { + id: "item_tool_hb".to_string(), + }) + .await; + } + let _ = events + .send(TaskExecutionEvent::ToolCompleted { + id: "tool_hb".to_string(), + name: "exec_command".to_string(), + success: true, + output: "build ok".to_string(), + metadata: None, + }) + .await; + TaskExecutionResult { + status: TaskStatus::Completed, + result_text: Some("done".to_string()), + error: None, + terminal_reason: TaskTerminalReason::Completed, + } + } + } + struct PromptRouterExecutor; #[async_trait] @@ -4583,6 +4811,252 @@ mod tests { Ok(()) } + #[tokio::test] + async fn silent_running_tool_suppresses_idle_until_it_completes() -> Result<()> { + let runtime = Arc::new(test_runtime_manager().await?); + let thread = runtime + .create_thread(CreateThreadRequest::default()) + .await?; + let (tx, mut rx) = mpsc::channel(64); + let runtime_for_drive = Arc::clone(&runtime); + let thread_id = thread.id.clone(); + let drive = tokio::spawn(async move { + drive_engine_turn( + runtime_for_drive.as_ref(), + &thread_id, + "turn_silent_tool", + tx, + CancellationToken::new(), + TaskExecutionLimits { + wall_time: Duration::from_secs(5), + idle_progress: Duration::from_millis(80), + cancel_grace: Duration::from_millis(500), + persist_debounce: Duration::from_millis(10), + }, + ) + .await + }); + + // Keyed by the journal item id on the started edge; the payload also + // carries the engine tool-use id under "tool" (which must NOT become + // the tracking key: the terminal events only repeat "item"). + runtime + .emit_event_for_test( + &thread.id, + Some("turn_silent_tool"), + "item.started", + json!({ + "item": { "id": "item_tool_silent", "status": "in_progress" }, + "tool": { "id": "call_build", "name": "exec_command", "input": {} } + }), + ) + .await?; + + // A silent build produces no journal traffic for its whole window; + // far past the idle deadline the watchdog must still not fire. + tokio::time::sleep(Duration::from_millis(400)).await; + let mut seen = Vec::new(); + while let Ok(event) = rx.try_recv() { + seen.push(event); + } + assert!( + !seen.iter().any(|event| matches!( + event, + TaskExecutionEvent::Status { message } + if message.contains("idle deadline") + )), + "idle watchdog fired while a tool was still running" + ); + + runtime + .emit_event_for_test( + &thread.id, + Some("turn_silent_tool"), + "item.completed", + json!({ "item": { "id": "item_tool_silent", "status": "completed" } }), + ) + .await?; + + // Completion drains the set; silence afterwards must let the idle + // deadline fire again (a drain bug would surface as WallTimeout). + tokio::time::timeout(Duration::from_secs(2), async { + loop { + match rx.recv().await { + Some(TaskExecutionEvent::Status { message }) + if message.contains("idle deadline") => + { + break; + } + Some(_) => {} + None => panic!("task event stream closed before idle deadline"), + } + } + }) + .await + .context("idle deadline did not fire after the tool completed")?; + runtime + .emit_event_for_test( + &thread.id, + Some("turn_silent_tool"), + "turn.completed", + json!({ "turn": { "status": "interrupted" } }), + ) + .await?; + let result = drive.await?; + assert_eq!(result.status, TaskStatus::Failed); + assert_eq!(result.terminal_reason, TaskTerminalReason::IdleTimeout); + Ok(()) + } + + #[tokio::test] + async fn silent_running_tool_heartbeats_the_worker_watchdog() -> Result<()> { + // The supervisor's guard (run_task) only sees task events, so the + // steady-state suppression must also publish the in-flight window on + // the event channel — otherwise the production path still idles out + // even though this loop's own guard is satisfied. + let runtime = Arc::new(test_runtime_manager().await?); + let thread = runtime + .create_thread(CreateThreadRequest::default()) + .await?; + let (tx, mut rx) = mpsc::channel(64); + let runtime_for_drive = Arc::clone(&runtime); + let thread_id = thread.id.clone(); + let drive = tokio::spawn(async move { + drive_engine_turn( + runtime_for_drive.as_ref(), + &thread_id, + "turn_heartbeat", + tx, + CancellationToken::new(), + TaskExecutionLimits { + wall_time: Duration::from_secs(5), + idle_progress: Duration::from_millis(80), + cancel_grace: Duration::from_millis(500), + persist_debounce: Duration::from_millis(10), + }, + ) + .await + }); + + runtime + .emit_event_for_test( + &thread.id, + Some("turn_heartbeat"), + "item.started", + json!({ + "item": { "id": "item_tool_hb", "status": "in_progress" }, + "tool": { "id": "call_build", "name": "exec_command", "input": {} } + }), + ) + .await?; + + let heartbeat = tokio::time::timeout(Duration::from_secs(2), async { + loop { + match rx.recv().await { + Some(event @ TaskExecutionEvent::ToolHeartbeat { .. }) => break event, + Some(_) => {} + None => panic!("task event stream closed before any heartbeat"), + } + } + }) + .await + .context("no ToolHeartbeat reached the worker channel while a tool was in flight")?; + let TaskExecutionEvent::ToolHeartbeat { id } = heartbeat else { + unreachable!("the loop only breaks on ToolHeartbeat") + }; + assert_eq!(id, "item_tool_hb"); + + runtime + .emit_event_for_test( + &thread.id, + Some("turn_heartbeat"), + "item.completed", + json!({ "item": { "id": "item_tool_hb", "status": "completed" } }), + ) + .await?; + runtime + .emit_event_for_test( + &thread.id, + Some("turn_heartbeat"), + "turn.completed", + json!({ "turn": { "status": "completed" } }), + ) + .await?; + let result = drive.await?; + assert_eq!(result.status, TaskStatus::Completed); + Ok(()) + } + + #[tokio::test] + async fn hung_running_tool_still_hits_the_wall_budget() -> Result<()> { + let runtime = Arc::new(test_runtime_manager().await?); + let thread = runtime + .create_thread(CreateThreadRequest::default()) + .await?; + let (tx, mut rx) = mpsc::channel(64); + let runtime_for_drive = Arc::clone(&runtime); + let thread_id = thread.id.clone(); + let drive = tokio::spawn(async move { + drive_engine_turn( + runtime_for_drive.as_ref(), + &thread_id, + "turn_hung_tool", + tx, + CancellationToken::new(), + TaskExecutionLimits { + wall_time: Duration::from_millis(300), + idle_progress: Duration::from_millis(80), + cancel_grace: Duration::from_millis(500), + persist_debounce: Duration::from_millis(10), + }, + ) + .await + }); + + runtime + .emit_event_for_test( + &thread.id, + Some("turn_hung_tool"), + "item.started", + json!({ + "item": { "id": "item_tool_hung", "status": "in_progress" }, + "tool": { "id": "call_hang", "name": "exec_command", "input": {} } + }), + ) + .await?; + + // The running-tool suppression only defers the idle watchdog; the + // wall-time budget remains the backstop for a tool that never + // completes. + tokio::time::timeout(Duration::from_secs(2), async { + loop { + match rx.recv().await { + Some(TaskExecutionEvent::Status { message }) + if message.contains("wall-time") => + { + break; + } + Some(_) => {} + None => panic!("task event stream closed before wall deadline"), + } + } + }) + .await + .context("wall budget did not fire during a hung tool")?; + runtime + .emit_event_for_test( + &thread.id, + Some("turn_hung_tool"), + "turn.completed", + json!({ "turn": { "status": "interrupted" } }), + ) + .await?; + let result = drive.await?; + assert_eq!(result.status, TaskStatus::Failed); + assert_eq!(result.terminal_reason, TaskTerminalReason::WallTimeout); + Ok(()) + } + #[tokio::test] async fn engine_turn_uses_cursor_catchup_for_completed_event() -> Result<()> { let runtime = test_runtime_manager().await?; diff --git a/crates/tui/src/tools/fetch_url.rs b/crates/tui/src/tools/fetch_url.rs index 141039d4ab..bf2853f42c 100644 --- a/crates/tui/src/tools/fetch_url.rs +++ b/crates/tui/src/tools/fetch_url.rs @@ -119,7 +119,7 @@ impl ToolSpec for FetchUrlTool { }, "timeout_ms": { "type": "integer", - "description": "Request timeout in milliseconds (default 15,000; max 60,000)." + "description": "Request timeout in milliseconds (default 15,000; max 300,000)." }, "fields": { "type": "array", diff --git a/crates/tui/src/tools/file.rs b/crates/tui/src/tools/file.rs index 53ea9506b3..8ea2685359 100644 --- a/crates/tui/src/tools/file.rs +++ b/crates/tui/src/tools/file.rs @@ -889,7 +889,7 @@ impl ToolSpec for ReadFileTool { return Ok(result); } if is_image_for_ocr(&file_path) { - return read_image_via_ocr(&file_path, path_str); + return read_image_via_ocr(&file_path, path_str).await; } // Open before parameter parsing so a missing file keeps the @@ -1227,8 +1227,8 @@ fn render_line_window( })) } -fn read_image_via_ocr(path: &Path, requested_path: &str) -> Result { - let text = crate::tools::image_ocr::ocr_image_path(path)?; +async fn read_image_via_ocr(path: &Path, requested_path: &str) -> Result { + let text = crate::tools::image_ocr::ocr_image_path_bounded(path.to_path_buf()).await?; Ok(ToolResult::success(format!( "\n{text}\n" ))) diff --git a/crates/tui/src/tools/image_ocr.rs b/crates/tui/src/tools/image_ocr.rs index 54fdeef797..dd937ba6e2 100644 --- a/crates/tui/src/tools/image_ocr.rs +++ b/crates/tui/src/tools/image_ocr.rs @@ -9,8 +9,9 @@ //! asset the user drops into the workspace without bouncing through //! a shell. -use std::path::Path; +use std::path::{Path, PathBuf}; use std::process::{Command, Stdio}; +use std::time::Duration; use async_trait::async_trait; use serde_json::{Value, json}; @@ -62,11 +63,34 @@ impl ToolSpec for ImageOcrTool { ))); } - let text = ocr_image_path(&image_path)?; + let text = ocr_image_path_bounded(image_path).await?; Ok(ToolResult::success(text)) } } +/// Wall-clock bound for one OCR call. Tesseract on a large scan can run +/// for minutes and native Vision OCR is blocking FFI; without a bound the +/// tool occupied an executor thread (and the turn) for as long as the +/// backend felt like taking. The bounded wrapper runs the sync work on the +/// blocking pool and hands control back to the caller when the deadline +/// fires; a wedged backend keeps its blocking thread (and any tesseract +/// child it spawned) running until it returns on its own, but the tool +/// call itself is bounded. Known, disclosed trade-off: neither the FFI +/// call nor the orphaned child can be killed mid-flight. +const OCR_TIMEOUT: Duration = Duration::from_secs(300); + +pub(crate) async fn ocr_image_path_bounded(image_path: PathBuf) -> Result { + tokio::time::timeout( + OCR_TIMEOUT, + tokio::task::spawn_blocking(move || ocr_image_path(&image_path)), + ) + .await + .map_err(|_| ToolError::Timeout { + seconds: OCR_TIMEOUT.as_secs(), + })? + .map_err(|e| ToolError::execution_failed(format!("image_ocr task failed: {e}")))? +} + pub(crate) fn ocr_available() -> bool { std::env::var_os("CODEWHALE_LOCAL_OCR_UNAVAILABLE").is_none() && (crate::dependencies::resolve_tesseract().is_some() || native_ocr_available()) diff --git a/crates/tui/src/tools/js_execution.rs b/crates/tui/src/tools/js_execution.rs index 23de4d4525..71b6669bf1 100644 --- a/crates/tui/src/tools/js_execution.rs +++ b/crates/tui/src/tools/js_execution.rs @@ -111,10 +111,21 @@ pub fn js_execution_tool_definition() -> Tool { } } +/// Wall-clock budget for one `js_execution` call. +fn js_execution_timeout() -> Duration { + if cfg!(test) { + // Short enough that the kill test finishes fast, long enough that + // the happy-path tests never approach it. + Duration::from_secs(5) + } else { + Duration::from_secs(600) + } +} + /// Run the model-provided JavaScript and return the captured /// stdout / stderr / return_code payload. Mirrors /// `execute_code_execution_tool` exactly — same tempfile pattern, -/// same 120-second timeout, same error shape — so the surfaces +/// same 600-second timeout, same error shape — so the surfaces /// stay interchangeable from the model's point of view. /// /// Tempfile lives only for the duration of this execution; `Drop` @@ -155,11 +166,12 @@ pub async fn execute_js_execution_tool( if std::env::var_os("NODE_USE_ENV_PROXY").is_none() { cmd.env("NODE_USE_ENV_PROXY", "1"); } - - let output = tokio::time::timeout(Duration::from_secs(120), cmd.output()) - .await - .map_err(|_| ToolError::Timeout { seconds: 120 }) - .and_then(|res| res.map_err(|e| ToolError::execution_failed(e.to_string())))?; + // The shared runner pipes and drains stdout/stderr while the child runs, + // kills and reaps explicitly on timeout, and bounds the post-exit drain + // so a grandchild that inherited the pipes cannot hold the call. + let output = + super::process::run_bounded_child(&mut cmd, None, js_execution_timeout(), "js_execution") + .await?; let stdout = String::from_utf8_lossy(&output.stdout).to_string(); let stderr = String::from_utf8_lossy(&output.stderr).to_string(); @@ -367,4 +379,81 @@ mod tests { "error must name the missing `code` field; got {msg}" ); } + #[cfg(unix)] + #[tokio::test] + async fn timeout_kills_the_node_child_instead_of_orphaning_it() { + if !node_present() { + eprintln!("skipping: node not present"); + return; + } + let workspace = tempdir().expect("workspace tempdir"); + let pid_file = workspace.path().join("child_pid"); + let code = format!( + "const fs = require('fs'); \ + fs.writeFileSync({}, String(process.pid)); \ + setTimeout(() => {{}}, 60000);", + serde_json::json!(pid_file.to_string_lossy()) + ); + + let err = execute_js_execution_tool(&serde_json::json!({ "code": code }), workspace.path()) + .await + .expect_err("a 60s sleep must hit the execution timeout"); + assert!( + matches!(err, ToolError::Timeout { .. }), + "expected a timeout error; got {err:?}" + ); + + // The child reported its pid before sleeping; the timeout must have + // killed it (SIGKILL via kill_on_drop), not left it running. + let pid: i32 = std::fs::read_to_string(&pid_file) + .expect("child must have written its pid") + .trim() + .parse() + .expect("pid file must contain an integer"); + let mut attempts = 0; + while unsafe { libc::kill(pid, 0) } == 0 { + assert!( + attempts < 50, + "node child {pid} is still alive after the timeout kill" + ); + std::thread::sleep(std::time::Duration::from_millis(100)); + attempts += 1; + } + } + + #[cfg(unix)] + #[tokio::test] + async fn timeout_returns_promptly_even_when_a_grandchild_holds_the_pipes() { + if !node_present() { + eprintln!("skipping: node not present"); + return; + } + let workspace = tempdir().expect("workspace tempdir"); + // The child spawns a grandchild that inherits stdout/stderr (so the + // pipe write ends outlive the child) and then blocks far past the + // execution timeout. After the child is killed, the drain readers + // cannot reach EOF until the grandchild exits — the timeout arm + // must return without waiting for them. + let code = "const { spawn } = require('child_process'); \ + const g = spawn('sleep', ['30'], { stdio: ['ignore', 'inherit', 'inherit'] }); \ + console.log('grandchild ' + g.pid); \ + setTimeout(() => {}, 60000);"; + + let started = std::time::Instant::now(); + let err = execute_js_execution_tool(&serde_json::json!({ "code": code }), workspace.path()) + .await + .expect_err("a 60s sleep must hit the execution timeout"); + let elapsed = started.elapsed(); + assert!( + matches!(err, ToolError::Timeout { .. }), + "expected a timeout error; got {err:?}" + ); + // Joining the un-EOF-able drain tasks would wait out the + // grandchild's full 30s sleep on top of the 5s test timeout; + // aborting them returns right after the kill. + assert!( + elapsed < std::time::Duration::from_secs(15), + "timeout must not wait for grandchildren holding the pipes; took {elapsed:?}" + ); + } } diff --git a/crates/tui/src/tools/mod.rs b/crates/tui/src/tools/mod.rs index aacab53d19..b3e22dce53 100644 --- a/crates/tui/src/tools/mod.rs +++ b/crates/tui/src/tools/mod.rs @@ -44,6 +44,7 @@ pub mod pandoc; mod pdf; pub mod plan; pub mod plugin; +pub(crate) mod process; pub mod project; pub mod read_media; pub mod registry; diff --git a/crates/tui/src/tools/pandoc.rs b/crates/tui/src/tools/pandoc.rs index 60e12fb813..911cd7104a 100644 --- a/crates/tui/src/tools/pandoc.rs +++ b/crates/tui/src/tools/pandoc.rs @@ -30,7 +30,9 @@ //! anything in the list goes through unchanged. use std::path::PathBuf; -use std::process::{Command, Stdio}; +use std::process::Stdio; +use std::time::Duration; +use tokio::process::Command as TokioCommand; use async_trait::async_trait; use serde_json::{Value, json}; @@ -58,6 +60,12 @@ pub(crate) const SUPPORTED_TARGET_FORMATS: &[&str] = &[ "asciidoc", // AsciiDoc ]; +/// Wall-clock bound for one pandoc conversion: a pathological document +/// (giant epub, pathological LaTeX) otherwise blocked an executor thread +/// for as long as pandoc felt like taking. Mirrors the 600s interpreter +/// budget used by js_execution / code_execution. +const PANDOC_TIMEOUT: Duration = Duration::from_secs(600); + /// Tool implementing `pandoc_convert`. Converts a source file into /// a target format and either writes the output to disk or returns /// the converted text inline. @@ -154,18 +162,26 @@ impl ToolSpec for PandocConvertTool { ) })?; - let mut cmd = Command::new(&pandoc); + let mut cmd = TokioCommand::new(&pandoc); cmd.arg(&source_path); cmd.arg("--to").arg(&target_format); if let Some(out) = resolved_output_path.as_ref() { cmd.arg("--output").arg(out); } + // Kill the converter if the timeout below drops the output() + // future; pandoc on a pathological document otherwise keeps + // running orphaned, and the sync variant blocked an executor + // thread for the whole conversion. + cmd.kill_on_drop(true); cmd.stdin(Stdio::null()) .stdout(Stdio::piped()) .stderr(Stdio::piped()); - let output = cmd - .output() + let output = tokio::time::timeout(PANDOC_TIMEOUT, cmd.output()) + .await + .map_err(|_| ToolError::Timeout { + seconds: PANDOC_TIMEOUT.as_secs(), + })? .map_err(|e| ToolError::execution_failed(format!("failed to launch pandoc: {e}")))?; if !output.status.success() { diff --git a/crates/tui/src/tools/plugin.rs b/crates/tui/src/tools/plugin.rs index 2e8631b96f..76f76349c4 100644 --- a/crates/tui/src/tools/plugin.rs +++ b/crates/tui/src/tools/plugin.rs @@ -25,7 +25,6 @@ use std::time::Duration; use async_trait::async_trait; use serde_json::Value; -use tokio::io::AsyncWriteExt; use super::spec::{ ApprovalRequirement, ToolCapability, ToolContext, ToolError, ToolResult, ToolSpec, @@ -33,8 +32,20 @@ use super::spec::{ use crate::config::ToolOverride; -/// Timeout for plugin script execution (120 seconds). -const PLUGIN_EXECUTION_TIMEOUT: Duration = Duration::from_secs(120); +/// Timeout for plugin script execution. Plugin scripts are +/// model-invoked interpreters in the same class as js_execution / +/// code_execution (600s there): 120s killed healthy long-running +/// plugins, and a timeout used to leave the script running orphaned. +fn plugin_execution_timeout() -> Duration { + if cfg!(test) { + // Same test budget as the js/code interpreters: short enough that + // the kill test finishes fast, long enough that happy-path tests + // never approach it. + Duration::from_secs(5) + } else { + Duration::from_secs(600) + } +} /// Metadata extracted from a plugin script's frontmatter header. #[derive(Debug, Clone)] @@ -274,40 +285,34 @@ async fn run_plugin_child_raw( label: &str, input: Value, ) -> Result { - let input_bytes = serde_json::to_vec(&input) - .map_err(|e| ToolError::invalid_input(format!("failed to serialize input: {e}")))?; - - cmd.stdin(std::process::Stdio::piped()); - cmd.stdout(std::process::Stdio::piped()); - cmd.stderr(std::process::Stdio::piped()); - - let mut child = cmd - .spawn() - .map_err(|e| ToolError::execution_failed(format!("failed to spawn {label}: {e}")))?; - - let stdin_writer = child.stdin.take().map(|mut stdin| { - tokio::spawn(async move { - if stdin.write_all(&input_bytes).await.is_ok() { - let _ = stdin.shutdown().await; - } - }) - }); - - let output = tokio::time::timeout(PLUGIN_EXECUTION_TIMEOUT, child.wait_with_output()) - .await - .map_err(|_| ToolError::Timeout { - seconds: PLUGIN_EXECUTION_TIMEOUT.as_secs(), - })? - .map_err(|e| ToolError::execution_failed(format!("process error: {e}")))?; - - if let Some(stdin_writer) = stdin_writer { - let _ = stdin_writer.await; - } + let input_bytes = super::process::stdin_json(&input)?; + + // The shared runner pipes and drains stdout/stderr while the child runs, + // writes the stdin payload, kills and reaps explicitly on timeout, and + // bounds the post-exit drain so a grandchild that inherited the pipes + // cannot hold the call. + let output = super::process::run_bounded_child( + cmd, + Some(input_bytes), + plugin_execution_timeout(), + label, + ) + .await?; if output.status.success() { let stdout = String::from_utf8_lossy(&output.stdout).to_string(); 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 + // unparseable, possibly cut-off output must not pass as a + // silent success. + 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}" + ))) } else { Ok(ToolResult::success(stdout)) } @@ -702,6 +707,48 @@ echo hello assert!(result.content.len() > 64 * 1024); } + #[cfg(unix)] + #[tokio::test] + async fn timeout_kills_the_plugin_child_instead_of_orphaning_it() { + let dir = TempDir::new().unwrap(); + let pid_file = dir.path().join("child_pid"); + let script = dir.path().join("hang.sh"); + std::fs::write( + &script, + format!( + "#!/bin/sh\n# name: hang\necho $$ > '{}'\nsleep 60\n", + pid_file.display() + ), + ) + .unwrap(); + + let (interpreter, args) = script_command_parts(&script, &[]); + let err = run_plugin_child(&interpreter, &args, "hang", serde_json::json!({})) + .await + .expect_err("a 60s sleep must hit the plugin execution timeout"); + assert!( + matches!(err, ToolError::Timeout { .. }), + "expected a timeout error; got {err:?}" + ); + + // The script reported its pid before sleeping; the timeout must + // have killed it instead of leaving it running orphaned. + let pid: i32 = std::fs::read_to_string(&pid_file) + .expect("child must have written its pid") + .trim() + .parse() + .expect("pid file must contain an integer"); + let mut attempts = 0; + while unsafe { libc::kill(pid, 0) } == 0 { + assert!( + attempts < 50, + "plugin child {pid} is still alive after the timeout kill" + ); + std::thread::sleep(std::time::Duration::from_millis(100)); + attempts += 1; + } + } + #[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 new file mode 100644 index 0000000000..16445f5988 --- /dev/null +++ b/crates/tui/src/tools/process.rs @@ -0,0 +1,250 @@ +//! Shared bounded child-process runner for the interpreted-script tools +//! (`js_execution`, `code_execution`, plugin scripts). +//! +//! One shape for "run a child under a wall-clock budget, capture its output, +//! and never let pipes or grandchildren outlive the call": +//! +//! * stdout/stderr are piped explicitly and drained concurrently with the +//! wait — a child blocked on a full pipe buffer still exits, so a timeout +//! is a real kill rather than a deadlock; +//! * 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. +//! +//! `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. + +use std::process::Stdio; +use std::sync::{Arc, Mutex}; +use std::time::Duration; + +use serde_json::Value; + +use super::spec::ToolError; + +/// Grace granted to the pipe drains after the child has exited. A child that +/// exits normally closes its own write ends, so EOF arrives immediately; +/// only a pipe inherited by a still-running grandchild can hold it, and that +/// must not hold the tool call past a short bound. +const CHILD_PIPE_DRAIN_GRACE: Duration = Duration::from_secs(2); + +/// Appended to stderr when the post-exit drain grace expired. The captured +/// output may be truncated (a grandchild still holds the pipes), and a +/// caller that only surfaces stdout on success — the plugin tools parse +/// stdout as their result — must be able to detect the truncation instead of +/// reporting a silently cut output as a success. +pub(crate) const DRAIN_TRUNCATED_NOTE: &[u8] = + b"[codewhale] output pipes did not close after the interpreter exited \ + (inherited by a still-running grandchild?); returning the output \ + captured before the drain grace expired\n"; + +/// True when `output` carries the drain-truncation note. +pub(crate) fn drain_truncated(output: &std::process::Output) -> bool { + output + .stderr + .windows(DRAIN_TRUNCATED_NOTE.len()) + .any(|window| window == DRAIN_TRUNCATED_NOTE) +} + +/// 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( + cmd: &mut tokio::process::Command, + stdin_input: Option>, + budget: Duration, + label: &str, +) -> 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. + cmd.kill_on_drop(true); + cmd.stdout(Stdio::piped()); + cmd.stderr(Stdio::piped()); + if stdin_input.is_some() { + cmd.stdin(Stdio::piped()); + } + + let mut child = cmd + .spawn() + .map_err(|e| ToolError::execution_failed(format!("failed to spawn {label}: {e}")))?; + + let mut stdin_writer = match (child.stdin.take(), stdin_input) { + (Some(mut stdin), Some(input_bytes)) => { + use tokio::io::AsyncWriteExt as _; + Some(tokio::spawn(async move { + if stdin.write_all(&input_bytes).await.is_ok() { + let _ = stdin.shutdown().await; + } + })) + } + _ => None, + }; + + let stdout_pipe = child.stdout.take(); + let stderr_pipe = child.stderr.take(); + // Drain concurrently with the wait: a child blocked on a full pipe + // buffer would otherwise never exit, turning every timeout into a + // guaranteed kill. The buffers are shared so a grace expiry below can + // 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 output = 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'); + } + 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), + } + } + } + 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(), + }); + } + }; + + Ok(output) +} + +async fn drain_pipe(pipe: Option, buf: Arc>>) { + let Some(mut pipe) = pipe else { + return; + }; + use tokio::io::AsyncReadExt; + let mut chunk = [0u8; 8192]; + loop { + match pipe.read(&mut chunk).await { + Ok(0) | Err(_) => break, + Ok(n) => { + if let Ok(mut buf) = buf.lock() { + buf.extend_from_slice(&chunk[..n]); + } + } + } + } +} + +fn snapshot(buf: &Arc>>) -> Vec { + buf.lock().map(|buf| buf.clone()).unwrap_or_default() +} + +/// Convenience wrapper mirroring the previous per-tool helpers: serialize +/// `input` and feed it to the child on stdin. +pub(crate) fn stdin_json(input: &Value) -> Result, ToolError> { + serde_json::to_vec(input) + .map_err(|e| ToolError::invalid_input(format!("failed to serialize input: {e}"))) +} + +#[cfg(test)] +mod tests { + use super::*; + + fn shell_command(script: &str) -> tokio::process::Command { + let mut cmd = tokio::process::Command::new("sh"); + cmd.arg("-c").arg(script); + cmd + } + + #[cfg(unix)] + #[tokio::test] + async fn bounded_child_returns_promptly_when_a_grandchild_holds_the_pipes() { + // The direct child exits immediately; the backgrounded sleep + // inherits both pipes and holds them for 30s. The call must still + // return promptly with the output captured before the grace, not + // wait for the grandchild. + let started = std::time::Instant::now(); + let mut cmd = shell_command("echo grandchild-holds-pipes; sleep 30 &"); + let output = run_bounded_child(&mut cmd, None, Duration::from_secs(600), "sh") + .await + .expect("child must succeed"); + let elapsed = started.elapsed(); + assert!(output.status.success()); + assert!( + String::from_utf8_lossy(&output.stdout).contains("grandchild-holds-pipes"), + "output captured before the grace must survive: {:?}", + output.stdout + ); + assert!( + String::from_utf8_lossy(&output.stderr) + .contains("output pipes did not close after the interpreter exited"), + "the truncation note must explain the early return: {:?}", + output.stderr + ); + assert!( + elapsed < Duration::from_secs(15), + "a pipe-holding grandchild must not hold the call past the grace; took {elapsed:?}" + ); + } + + #[cfg(unix)] + #[tokio::test] + async fn bounded_child_still_times_out_and_kills_a_hung_child() { + let mut cmd = shell_command("echo started; sleep 60"); + let err = run_bounded_child(&mut cmd, None, Duration::from_secs(2), "sh") + .await + .expect_err("a 60s sleep must hit the budget"); + assert!(matches!(err, ToolError::Timeout { seconds: 2 })); + } +} diff --git a/crates/tui/src/tools/rlm.rs b/crates/tui/src/tools/rlm.rs index 86e6b89f3a..76c82c2f2a 100644 --- a/crates/tui/src/tools/rlm.rs +++ b/crates/tui/src/tools/rlm.rs @@ -469,7 +469,8 @@ impl RlmTool { Arc::new(client), self.root_model.clone(), config.sub_rlm_max_depth.min(HARD_SUB_RLM_DEPTH_CAP), - ); + ) + .with_sub_query_timeout_secs(config.sub_query_timeout_secs); let usage_handle = bridge.usage_handle(); let round_result = kernel.run(code, Some(&bridge)).await; let usage = usage_handle.lock().await.clone(); diff --git a/crates/tui/src/tools/tasks.rs b/crates/tui/src/tools/tasks.rs index 85b73fa4ea..0f333222ce 100644 --- a/crates/tui/src/tools/tasks.rs +++ b/crates/tui/src/tools/tasks.rs @@ -43,7 +43,11 @@ fn build_gate_command(command: &str, cwd: &Path) -> Command { cmd.args(args) .current_dir(cwd) .stdout(Stdio::piped()) - .stderr(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); cmd } diff --git a/crates/tui/src/tools/web/contract.rs b/crates/tui/src/tools/web/contract.rs index 17d55be2a8..d71ebba0c5 100644 --- a/crates/tui/src/tools/web/contract.rs +++ b/crates/tui/src/tools/web/contract.rs @@ -323,16 +323,15 @@ mod tests { fn retrieval_defaults_are_coherent_across_search_and_fetch() { use super::super::fetch::{DEFAULT_TIMEOUT, HARD_MAX_TIMEOUT}; - // Search and fetch share one default and one hard-cap timeout so the - // two halves of the retrieval path behave identically by default. + // Search and fetch share one default timeout so the two halves of + // the retrieval path behave identically by default. The fetch hard + // cap may exceed the search cap: a page fetch streams up to a 10 MB + // body while a search API answers small JSON payloads. assert_eq!( u128::from(DEFAULT_SEARCH_TIMEOUT_MS), DEFAULT_TIMEOUT.as_millis() ); - assert_eq!( - u128::from(MAX_SEARCH_TIMEOUT_MS), - HARD_MAX_TIMEOUT.as_millis() - ); + 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 cb4c07980e..7563aef477 100644 --- a/crates/tui/src/tools/web/fetch.rs +++ b/crates/tui/src/tools/web/fetch.rs @@ -15,7 +15,10 @@ use super::guard::{ use crate::tools::spec::{ToolContext, ToolError}; pub(crate) const DEFAULT_TIMEOUT: Duration = Duration::from_secs(15); -pub(crate) const HARD_MAX_TIMEOUT: Duration = Duration::from_secs(60); +// 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). +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; const MAX_REDIRECTS: usize = 5; diff --git a/crates/tui/src/tools/web/guard.rs b/crates/tui/src/tools/web/guard.rs index 6dc4fc6ca5..775e844640 100644 --- a/crates/tui/src/tools/web/guard.rs +++ b/crates/tui/src/tools/web/guard.rs @@ -111,13 +111,20 @@ pub(crate) async fn validate_fetch_target( return Ok(None); } - let addrs = tokio::net::lookup_host((host.as_str(), 0u16)) - .await - .map_err(|e| { - ToolError::permission_denied(format!( - "could not resolve host before {tool} request: {e}" - )) - })?; + // Bound the pre-flight resolution: this runs before the guarded request + // (and once per redirect), so a hung resolver would otherwise stall the + // tool far beyond the documented request timeout envelope. + let addrs = tokio::time::timeout( + std::time::Duration::from_secs(10), + tokio::net::lookup_host((host.as_str(), 0u16)), + ) + .await + .map_err(|_| { + ToolError::permission_denied(format!("timed out resolving host before {tool} request")) + })? + .map_err(|e| { + ToolError::permission_denied(format!("could not resolve host before {tool} request: {e}")) + })?; let mut first_valid: Option = None; for addr in addrs { validate_dns_resolved_ip(&host, &addr.ip(), context.network_policy.as_ref(), tool)?; diff --git a/crates/tui/src/tui/app.rs b/crates/tui/src/tui/app.rs index 08acc9b2f1..9a091acfe2 100644 --- a/crates/tui/src/tui/app.rs +++ b/crates/tui/src/tui/app.rs @@ -2216,7 +2216,7 @@ pub struct App { >, /// Shared cell for async MCP OAuth login delivery. /// - /// The browser callback wait is up to five minutes. Awaiting it inside the + /// The browser callback wait is up to fifteen minutes. Awaiting it inside the /// action handler parked the whole event loop: no input, no redraw, and no /// way to back out of a login started by a misclick. The login runs on the /// background pattern instead, and `mcp_login_cancel` is what Esc trips. diff --git a/crates/tui/src/tui/ui/handlers.rs b/crates/tui/src/tui/ui/handlers.rs index da73b37d58..f4fcea405d 100644 --- a/crates/tui/src/tui/ui/handlers.rs +++ b/crates/tui/src/tui/ui/handlers.rs @@ -513,7 +513,7 @@ pub(crate) async fn handle_mcp_ui_action( } crate::tui::app::McpUiAction::Login { name, scopes } => { // Only the handshake runs inline: it is a couple of HTTP calls and - // it yields the authorization URL. The five-minute browser-callback + // it yields the authorization URL. The fifteen-minute browser-callback // wait goes to the background task pattern, because awaiting it // here parked the event loop — a misclicked `[re-auth]` row left // the session unusable with no way to back out. diff --git a/crates/tui/src/vision/tools.rs b/crates/tui/src/vision/tools.rs index b49485a1c3..24cf153988 100644 --- a/crates/tui/src/vision/tools.rs +++ b/crates/tui/src/vision/tools.rs @@ -21,6 +21,26 @@ pub struct ImageAnalyzeTool { route_client: Option, } +/// Total envelope for one image_analyze call, retry attempts and response +/// body consumption included. reqwest's `read_timeout` is *not* a per-read +/// idle bound for the request phase: its timer starts at `send()` and is +/// never reset until the response headers arrive, so it silently acts as a +/// total deadline on the multi-MB upload plus the full non-streaming vision +/// generation — precisely the healthy work a 120s cap used to kill. The +/// 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. +const VISION_REQUEST_ENVELOPE: Duration = Duration::from_secs(1800); + +fn vision_request_envelope() -> Duration { + if cfg!(test) { + Duration::from_secs(2) + } else { + VISION_REQUEST_ENVELOPE + } +} + impl ImageAnalyzeTool { #[cfg(test)] #[must_use] @@ -34,7 +54,12 @@ impl ImageAnalyzeTool { route_client: Option, ) -> Self { let client = crate::tls::reqwest_client_builder() - .timeout(Duration::from_secs(120)) + // Bound only the connect handshake. A client- or request-level + // `read_timeout` would start counting at `send()` and never + // reset before the response headers, quietly re-introducing a + // total deadline on the upload + long non-streaming generation; + // the total bound lives in VISION_REQUEST_ENVELOPE instead. + .connect_timeout(Duration::from_secs(10)) .build() .expect("Failed to build HTTP client"); Self { @@ -268,50 +293,59 @@ impl ToolSpec for ImageAnalyzeTool { None => Some(crate::client::acquire_remote_control_inference_participant().await), }; - let response = with_retry( - &retry_config, - || { - let client = self.client.clone(); - let url = url.clone(); - let api_key = api_key.clone(); - let payload = payload.clone(); - async move { - let response = client - .post(&url) - .header("Content-Type", "application/json") - .header("Authorization", format!("Bearer {api_key}")) - .json(&payload) - .send() - .await - .map_err(|e| LlmError::from_reqwest(&e))?; - - let status = response.status(); - if !status.is_success() { - let error_text = response - .text() + let response_json = tokio::time::timeout(vision_request_envelope(), async { + let response = with_retry( + &retry_config, + || { + let client = self.client.clone(); + let url = url.clone(); + let api_key = api_key.clone(); + let payload = payload.clone(); + async move { + let response = client + .post(&url) + .header("Content-Type", "application/json") + .header("Authorization", format!("Bearer {api_key}")) + .json(&payload) + .send() .await - .unwrap_or_else(|_| "Unknown error".to_string()); - let error_text = sanitize_http_error_body( - Some("Vision provider"), - status.as_u16(), - &error_text, - ); - return Err(LlmError::from_http_response(status.as_u16(), &error_text)); + .map_err(|e| LlmError::from_reqwest(&e))?; + + let status = response.status(); + if !status.is_success() { + let error_text = response + .text() + .await + .unwrap_or_else(|_| "Unknown error".to_string()); + let error_text = sanitize_http_error_body( + Some("Vision provider"), + status.as_u16(), + &error_text, + ); + return Err(LlmError::from_http_response(status.as_u16(), &error_text)); + } + Ok(response) } - Ok(response) - } - }, - None, - ) - .await - .map_err(|e| ToolError::execution_failed(format!("Vision API request failed: {e}")))?; - - let json: Value = response - .json() + }, + None, + ) .await - .map_err(|e| ToolError::execution_failed(format!("Failed to parse response: {e}")))?; + .map_err(|e| ToolError::execution_failed(format!("Vision API request failed: {e}")))?; - let content = json + let json: Value = response.json().await.map_err(|e| { + ToolError::execution_failed(format!("Failed to parse response: {e}")) + })?; + Ok(json) + }) + .await + .map_err(|_| { + ToolError::execution_failed(format!( + "Vision API request timed out after {}s", + vision_request_envelope().as_secs() + )) + })??; + + let content = response_json .get("choices") .and_then(|c| c.get(0)) .and_then(|c| c.get("message")) @@ -320,7 +354,7 @@ impl ToolSpec for ImageAnalyzeTool { .unwrap_or("") .to_string(); - let model = json + let model = response_json .get("model") .and_then(|m| m.as_str()) .unwrap_or(&self.config.model) @@ -600,6 +634,20 @@ mod tests { }) } + fn write_workspace_image(workspace: &std::path::Path) { + std::fs::write(workspace.join("sample.png"), b"not a real png") + .expect("write sample image"); + } + + fn vision_response_body() -> Value { + json!({ + "model": "test-vision-model", + "choices": [ + { "message": { "content": "a red square" } } + ] + }) + } + #[tokio::test] async fn execute_reports_real_pixel_dimensions_and_format() { let server = mock_vision_endpoint().await; @@ -699,4 +747,62 @@ mod tests { std::fs::write(&path, MINIMAL_BMP).expect("write fixture"); assert_eq!(ImageAnalyzeTool::image_dimensions(&path), None); } + + #[tokio::test] + async fn envelope_bounds_a_stalled_vision_provider() { + let server = MockServer::start().await; + // The stalled provider never answers within the test envelope: the + // upload + non-streaming generation window must be cut off by the + // envelope, not by a client read timeout (which reqwest turns into + // a hidden total deadline from `send()`). + Mock::given(method("POST")) + .and(path("/chat/completions")) + .respond_with( + ResponseTemplate::new(200) + .set_body_json(vision_response_body()) + .set_delay(Duration::from_secs(30)), + ) + .mount(&server) + .await; + + let workspace = tempdir().expect("workspace tempdir"); + write_workspace_image(workspace.path()); + let ctx = ToolContext::new(workspace.path().to_path_buf()); + let tool = tool_with_base_url(server.uri()); + + let err = tool + .execute(json!({"image_path": "sample.png"}), &ctx) + .await + .expect_err("a provider that never answers must hit the envelope"); + assert!( + err.to_string().contains("timed out after"), + "envelope timeout must be reported as such; got {err}" + ); + } + + #[tokio::test] + async fn prompt_answer_within_the_envelope_is_returned() { + let server = MockServer::start().await; + Mock::given(method("POST")) + .and(path("/chat/completions")) + .respond_with(ResponseTemplate::new(200).set_body_json(vision_response_body())) + .mount(&server) + .await; + + let workspace = tempdir().expect("workspace tempdir"); + write_workspace_image(workspace.path()); + let ctx = ToolContext::new(workspace.path().to_path_buf()); + let tool = tool_with_base_url(server.uri()); + + let result = tool + .execute( + json!({"image_path": "sample.png", "prompt": "what is this?"}), + &ctx, + ) + .await + .expect("a prompt answer must flow through the envelope"); + let payload: Value = + serde_json::from_str(&result.content).expect("tool result must carry json"); + assert_eq!(payload["analysis"], "a red square"); + } } diff --git a/docs/CONFIGURATION.md b/docs/CONFIGURATION.md index 9ba0f5a200..81116d2605 100644 --- a/docs/CONFIGURATION.md +++ b/docs/CONFIGURATION.md @@ -2073,8 +2073,9 @@ reasoning contract, and all four membership ids omit generic sampling fields. attempt is retried with exponential backoff (up to 5 retries) before the step interrupts with a preserved checkpoint. `[subagents] heartbeat_timeout_secs` controls stale running agent cleanup, - defaults to `300`, and is clamped to `30..=3600` while staying above the - resolved API timeout. `[subagents.providers.]` accepts the same + defaults to `300`, and is clamped to `30..=3600` while staying above both + the resolved API timeout and the resolved tool timeout (30 seconds above + each; 1830 with both defaults). `[subagents.providers.]` accepts the same fanout, depth, budget, and timeout knobs (`enabled`, `max_concurrent`, `max_admitted`, `launch_concurrency`, `max_depth`, `token_budget`, `api_timeout_secs`, `heartbeat_timeout_secs`) and inherits the global diff --git a/docs/MCP.md b/docs/MCP.md index c1147c2acb..587d0b20e5 100644 --- a/docs/MCP.md +++ b/docs/MCP.md @@ -336,7 +336,7 @@ The CLI also exposes helper tools when MCP is enabled: { "timeouts": { "connect_timeout": 10, - "execute_timeout": 60, + "execute_timeout": 1800, "read_timeout": 120 }, "servers": { @@ -437,6 +437,11 @@ Per-server settings: - `args` (array of strings, optional) - `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 + 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`. - `disabled` (bool, optional) - `enabled` (bool, optional, default `true`) - `required` (bool, optional): startup/connect validation fails if this server cannot initialize. diff --git a/docs/RUNTIME_API.md b/docs/RUNTIME_API.md index 6ea9e920a7..8cd938e7e2 100644 --- a/docs/RUNTIME_API.md +++ b/docs/RUNTIME_API.md @@ -774,7 +774,9 @@ 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": ""}`. +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. ```json [ @@ -1127,6 +1129,18 @@ cursor include the same materialized prefix. execution-policy rule caused the prompt. This field is explanatory metadata for clients and does not grant or persist permissions. +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 +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` +field on `approval.decided` are legacy shapes produced only by journals written +by older builds; current code never emits them. + ## Security boundary - **Localhost by default**. The server binds to `127.0.0.1` by default. diff --git a/docs/SUBAGENTS.md b/docs/SUBAGENTS.md index db5c901dae..956ad95d52 100644 --- a/docs/SUBAGENTS.md +++ b/docs/SUBAGENTS.md @@ -575,18 +575,23 @@ second default. Running agents also track manager-visible progress. If a child stops emitting progress for the heartbeat window, the manager auto-cancels it, releases its sub-agent slot, and keeps the cancelled record inspectable through the returned -transcript handle and persisted worker record. The default is 5 minutes -(resolved to at least 30 seconds above `api_timeout_secs`, so 630 seconds -with the 600-second default API timeout): +transcript handle and persisted worker record. The default is 5 minutes, +resolved to the highest of itself, 30 seconds above the resolved +`api_timeout_secs`, and 30 seconds above the built-in sub-agent tool +timeout (so 1830 seconds with the 600-second default API timeout and the +1800-second default tool timeout; the tool timeout is a compile-time +constant — only `api_timeout_secs` is a config key): ```toml [subagents] heartbeat_timeout_secs = 300 # clamped to 30..=3600 ``` -The effective heartbeat is kept at least 30 seconds above -`api_timeout_secs`, so a configured long model request is not cancelled before -its own request timeout can fire. +The effective heartbeat is kept at least 30 seconds above both the resolved +`api_timeout_secs` and the built-in sub-agent tool timeout (the child records +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. ## Lifecycle diff --git a/docs/zh_hans/CONFIGURATION.md b/docs/zh_hans/CONFIGURATION.md index c493418d61..7d469874e2 100644 --- a/docs/zh_hans/CONFIGURATION.md +++ b/docs/zh_hans/CONFIGURATION.md @@ -1083,7 +1083,7 @@ DeepSeek V4 前缀缓存让 token 标签变得重要。这些数量保持分离 - `managed_config_path`(字符串,可选):用户/环境配置之后加载的受管配置文件。 - `requirements_path`(字符串,可选):用于强制允许的审批/沙箱值的需求文件。 - `max_subagents`(int,可选):默认 `64`,钳制到 `1..=128`。 -- `subagents.*`(可选兼容表):`agent` 的按 Fleet 角色模型默认。显式工具 `model` 值胜出,然后角色覆盖,然后父运行时模型。支持的便捷键是 `default_model`、`worker_model`、`scout_model`、`planner_model`、`reviewer_model`、`custom_model`、`max_concurrent`、`max_admitted`、`launch_concurrency`、`token_budget`、`api_timeout_secs` 和 `heartbeat_timeout_secs`。v0.9.x 键 `explorer_model`、`awaiter_model` 和 `review_model` 仍作为别名接受。`[subagents] max_concurrent` 值覆盖顶层 `max_subagents`,也钳制到 `1..=128`。`[subagents] max_admitted`(别名:`max_total`、`admission_limit`)是排队加运行子智能体的有界总数;默认 `1024`(`MAX_SUBAGENT_ADMISSION`,`crates/tui/src/config/subagent_limits.rs:21`,在 `config.rs:6400` 应用),所以高扇出回合可以排队并排空,同时运行时启动压力保持有界,并钳制到 `max_concurrent..=1024`。`[subagents] launch_concurrency` 设置一次直接启动多少子智能体,其余排队等启动槽位;默认解析出的 `max_subagents` 上限,钳制到 `1..=max_subagents`(弃用的 `interactive_max_launch` 键作为别名接受,两者都设置时新键胜出)。`[subagents] token_budget` 是每个根 `agent` 运行及其后代的可选聚合 token 上限;未设置或 `0` 保留无限制的旧行为。`[subagents] api_timeout_secs` 控制子智能体模型调用的每步 API 超时,钳制到 `1..=3600`,`0` 或未设置保留 600 秒默认;超时尝试用指数退避重试(最多 5 次),然后步骤以保留检查点中断。`[subagents] heartbeat_timeout_secs` 控制过期运行智能体清理,默认 `300`,钳制到 `30..=3600`,同时保持在解析出的 API 超时之上。`[subagents.providers.]` 接受同样的扇出、深度、预算和超时旋钮(`enabled`、`max_concurrent`、`max_admitted`、`launch_concurrency`、`max_depth`、`token_budget`、`api_timeout_secs`、`heartbeat_timeout_secs`),并为省略的键继承全局 `[subagents]` 值。Provider 键接受 `deepseek`、`zai`、`openrouter`、`anthropic` 这样的规范名,加 `glm`(Z.ai)和 `deepseek_api`(直接 DeepSeek)这样的便捷别名: +- `subagents.*`(可选兼容表):`agent` 的按 Fleet 角色模型默认。显式工具 `model` 值胜出,然后角色覆盖,然后父运行时模型。支持的便捷键是 `default_model`、`worker_model`、`scout_model`、`planner_model`、`reviewer_model`、`custom_model`、`max_concurrent`、`max_admitted`、`launch_concurrency`、`token_budget`、`api_timeout_secs` 和 `heartbeat_timeout_secs`。v0.9.x 键 `explorer_model`、`awaiter_model` 和 `review_model` 仍作为别名接受。`[subagents] max_concurrent` 值覆盖顶层 `max_subagents`,也钳制到 `1..=128`。`[subagents] max_admitted`(别名:`max_total`、`admission_limit`)是排队加运行子智能体的有界总数;默认 `1024`(`MAX_SUBAGENT_ADMISSION`,`crates/tui/src/config/subagent_limits.rs:21`,在 `config.rs:6400` 应用),所以高扇出回合可以排队并排空,同时运行时启动压力保持有界,并钳制到 `max_concurrent..=1024`。`[subagents] launch_concurrency` 设置一次直接启动多少子智能体,其余排队等启动槽位;默认解析出的 `max_subagents` 上限,钳制到 `1..=max_subagents`(弃用的 `interactive_max_launch` 键作为别名接受,两者都设置时新键胜出)。`[subagents] token_budget` 是每个根 `agent` 运行及其后代的可选聚合 token 上限;未设置或 `0` 保留无限制的旧行为。`[subagents] api_timeout_secs` 控制子智能体模型调用的每步 API 超时,钳制到 `1..=3600`,`0` 或未设置保留 600 秒默认;超时尝试用指数退避重试(最多 5 次),然后步骤以保留检查点中断。`[subagents] heartbeat_timeout_secs` 控制过期运行智能体清理,默认 `300`,钳制到 `30..=3600`,同时保持在解析出的 API 超时与工具超时之上各 30 秒(两个默认值下即 1830)。`[subagents.providers.]` 接受同样的扇出、深度、预算和超时旋钮(`enabled`、`max_concurrent`、`max_admitted`、`launch_concurrency`、`max_depth`、`token_budget`、`api_timeout_secs`、`heartbeat_timeout_secs`),并为省略的键继承全局 `[subagents]` 值。Provider 键接受 `deepseek`、`zai`、`openrouter`、`anthropic` 这样的规范名,加 `glm`(Z.ai)和 `deepseek_api`(直接 DeepSeek)这样的便捷别名: ```toml [subagents] diff --git a/docs/zh_hans/MCP.md b/docs/zh_hans/MCP.md index 84a7d198f0..ed828c4bca 100644 --- a/docs/zh_hans/MCP.md +++ b/docs/zh_hans/MCP.md @@ -249,7 +249,7 @@ Codewhale 同时读取 `servers` 和 `mcpServers`,因此设置页生成的片 { "timeouts": { "connect_timeout": 10, - "execute_timeout": 60, + "execute_timeout": 1800, "read_timeout": 120 }, "servers": { @@ -342,6 +342,10 @@ codewhale-tui mcp tools codewhale - `args`(字符串数组,可选) - `env`(对象,可选) - `connect_timeout`、`execute_timeout`、`read_timeout`(秒,可选) +- 默认值:`connect_timeout` 10 秒、`execute_timeout` 1800 秒(30 分钟)、`read_timeout` 120 秒。 + `execute_timeout` 约束一次完整的工具调用——工具结束前服务器不会回话,慢工具应调大它而不是 + `read_timeout`。`read_timeout` 约束快速请求(`resources/read`、发现流程等)的响应等待; + `tools/call` 的内部读等待会自动放宽到至少其 `execute_timeout`。 - `disabled`(布尔值,可选) - `enabled`(布尔值,可选,默认 `true`) - `required`(布尔值,可选):如果该服务器无法初始化,启动/连接验证会失败。 diff --git a/docs/zh_hans/SUBAGENTS.md b/docs/zh_hans/SUBAGENTS.md index f37d51cf27..2a39bf9863 100644 --- a/docs/zh_hans/SUBAGENTS.md +++ b/docs/zh_hans/SUBAGENTS.md @@ -310,14 +310,14 @@ api_timeout_secs = 900 # 15 分钟;钳制到 1..=3600 ## 陈旧 agent 心跳(#2614) -运行中的代理还跟踪 manager 可见的进度。如果子代理在心跳窗口内停止发出进度,manager 会自动取消它、释放它的子代理槽位,并通过返回的转录句柄和持久化的 worker 记录保留可检查的取消记录。默认是 5 分钟(解析为至少比 `api_timeout_secs` 高 30 秒,因此在 600 秒默认 API 超时下是 630 秒): +运行中的代理还跟踪 manager 可见的进度。如果子代理在心跳窗口内停止发出进度,manager 会自动取消它、释放它的子代理槽位,并通过返回的转录句柄和持久化的 worker 记录保留可检查的取消记录。默认是 5 分钟,解析取自身、比解析后 `api_timeout_secs` 高 30 秒、比内置子代理工具超时高 30 秒三者的最大值(在 600 秒默认 API 超时与 1800 秒默认工具超时下即 1830 秒;工具超时是编译期常量,只有 `api_timeout_secs` 是配置键): ```toml [subagents] heartbeat_timeout_secs = 300 # 钳制到 30..=3600 ``` -有效心跳至少保持在 `api_timeout_secs` 之上 30 秒,因此一个配置的长模型请求不会在自己的请求超时触发之前被取消。 +有效心跳至少保持在解析后的 `api_timeout_secs` 与内置子代理工具超时之上各 30 秒(子代理只在步骤边界记录进度,不会在工具执行中途记录,因此静默的构建或 MCP 调用不能在运行中被清理),所以配置的长模型请求与长时间在途工具都不会在自己的超时触发之前被取消。 ## 生命周期