From 49ef60f0f7bb797ff10fb6831e156d7fa4280831 Mon Sep 17 00:00:00 2001 From: Matthew Boston Date: Thu, 23 Jul 2026 09:56:17 -0600 Subject: [PATCH 1/2] test: ACP request timeout must name the hung RPC method A non-prompt RPC that hangs (e.g. session/new stalled on agent-side extension startup) times out with a bare "agent did not respond within 60s", leaving no clue which method the agent was stuck on. Adds a timeout-injection seam to send_request and a failing test asserting the error message names the method. Co-Authored-By: Claude Fable 5 --- crates/buzz-acp/src/acp.rs | 38 +++++++++++++++++++++++++++++++++++++- 1 file changed, 37 insertions(+), 1 deletion(-) diff --git a/crates/buzz-acp/src/acp.rs b/crates/buzz-acp/src/acp.rs index b7bca5477b..fccb00a7fe 100644 --- a/crates/buzz-acp/src/acp.rs +++ b/crates/buzz-acp/src/acp.rs @@ -966,6 +966,19 @@ impl AcpClient { &mut self, method: &str, params: serde_json::Value, + ) -> Result { + self.send_request_with_timeout(method, params, Self::REQUEST_TIMEOUT) + .await + } + + /// [`send_request`](Self::send_request) with an explicit timeout instead + /// of `REQUEST_TIMEOUT` — the seam that lets tests exercise the timeout + /// path without a 60s wait. + async fn send_request_with_timeout( + &mut self, + method: &str, + params: serde_json::Value, + timeout: std::time::Duration, ) -> Result { let id = self.next_id; self.next_id += 1; @@ -982,7 +995,6 @@ impl AcpClient { // Wrap write + read in a single timeout so a hung agent can't block forever. // We cannot use an async block that borrows `self` mutably across two awaits // inside timeout(), so we sequence them with early-return on timeout. - let timeout = Self::REQUEST_TIMEOUT; match tokio::time::timeout(timeout, self.write_ndjson(&msg)).await { Ok(result) => result?, Err(_) => return Err(AcpError::Timeout(timeout)), @@ -2810,6 +2822,30 @@ mod tests { assert_eq!(result.unwrap()["worked"], serde_json::json!(true)); } + /// A hung non-prompt RPC must surface WHICH method timed out. When an + /// agent stalls during `session/new` (e.g. goose blocking on MCP + /// extension startup while the package index is unreachable), a bare + /// "agent did not respond within 60s" gives the operator nothing to + /// act on — the error must name the hung method. + #[tokio::test] + async fn request_timeout_error_names_the_hung_rpc_method() { + // Agent that reads the request but never responds. + let mut client = spawn_script("read -t 5 _req; sleep 5").await; + let err = client + .send_request_with_timeout( + "session/new", + serde_json::json!({}), + std::time::Duration::from_millis(100), + ) + .await + .expect_err("request against a silent agent must time out"); + let msg = err.to_string(); + assert!( + msg.contains("session/new"), + "timeout error must name the hung RPC method; got: {msg}" + ); + } + #[tokio::test] async fn keepalive_resets_idle_past_deadline() { // Keepalive session/update lines every 50ms against a 100ms idle deadline. From 8c0602b921cb57fba1f55c8de1217593bed6b9c7 Mon Sep 17 00:00:00 2001 From: Matthew Boston Date: Thu, 23 Jul 2026 09:56:47 -0600 Subject: [PATCH 2/2] fix(acp): name the hung RPC method in request timeout errors MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit When a non-prompt RPC times out, the error now reads "Request timeout — agent did not respond to session/new within 60s" instead of dropping the method. Operators diagnosing a stalled agent from the harness log or the desktop Activity panel can see what the agent was doing (session/new stalls usually mean extension startup; initialize stalls mean the binary never came up) instead of a generic timeout that requires correlating multiple log sources. Co-Authored-By: Claude Fable 5 --- crates/buzz-acp/src/acp.rs | 19 +++++++++++++++---- crates/buzz-acp/src/lib.rs | 2 +- crates/buzz-acp/src/pool.rs | 14 ++++++++++---- 3 files changed, 26 insertions(+), 9 deletions(-) diff --git a/crates/buzz-acp/src/acp.rs b/crates/buzz-acp/src/acp.rs index fccb00a7fe..df34d66056 100644 --- a/crates/buzz-acp/src/acp.rs +++ b/crates/buzz-acp/src/acp.rs @@ -95,8 +95,11 @@ pub enum AcpError { #[error("Agent did not stop within {0:?} after cancellation")] CancelDrainTimeout(std::time::Duration), - #[error("Request timeout — agent did not respond within {0:?}")] - Timeout(std::time::Duration), + #[error("Request timeout — agent did not respond to {method} within {timeout:?}")] + Timeout { + method: String, + timeout: std::time::Duration, + }, #[error("Write timeout — agent stopped reading stdin (blocked for {0:?})")] WriteTimeout(std::time::Duration), @@ -997,12 +1000,20 @@ impl AcpClient { // inside timeout(), so we sequence them with early-return on timeout. match tokio::time::timeout(timeout, self.write_ndjson(&msg)).await { Ok(result) => result?, - Err(_) => return Err(AcpError::Timeout(timeout)), + Err(_) => { + return Err(AcpError::Timeout { + method: method.to_string(), + timeout, + }) + } } match tokio::time::timeout(timeout, self.read_until_response(id)).await { Ok(result) => result, - Err(_) => Err(AcpError::Timeout(timeout)), + Err(_) => Err(AcpError::Timeout { + method: method.to_string(), + timeout, + }), } } diff --git a/crates/buzz-acp/src/lib.rs b/crates/buzz-acp/src/lib.rs index 808a34a793..68fa1be7a3 100644 --- a/crates/buzz-acp/src/lib.rs +++ b/crates/buzz-acp/src/lib.rs @@ -3029,7 +3029,7 @@ fn handle_prompt_result( e, acp::AcpError::Io(_) | acp::AcpError::WriteTimeout(_) - | acp::AcpError::Timeout(_) + | acp::AcpError::Timeout { .. } | acp::AcpError::Protocol(_) ); let error_code = match &e { diff --git a/crates/buzz-acp/src/pool.rs b/crates/buzz-acp/src/pool.rs index 3637869968..4312caadf3 100644 --- a/crates/buzz-acp/src/pool.rs +++ b/crates/buzz-acp/src/pool.rs @@ -911,7 +911,7 @@ async fn apply_model_switch( // so the caller can respawn the agent instead of reusing a poisoned one. Ok(Err(e @ AcpError::Io(_))) | Ok(Err(e @ AcpError::WriteTimeout(_))) - | Ok(Err(e @ AcpError::Timeout(_))) + | Ok(Err(e @ AcpError::Timeout { .. })) | Ok(Err(e @ AcpError::Protocol(_))) | Ok(Err(e @ AcpError::AgentExited)) => { tracing::error!( @@ -934,7 +934,10 @@ async fn apply_model_switch( target: "pool::model", "model set via {method_label} timed out ({MODEL_SWITCH_TIMEOUT:?}) — treating as fatal" ); - return Err(AcpError::Timeout(MODEL_SWITCH_TIMEOUT)); + return Err(AcpError::Timeout { + method: method_label, + timeout: MODEL_SWITCH_TIMEOUT, + }); } } Ok(()) @@ -987,7 +990,7 @@ async fn apply_permission_mode( // so the caller can respawn the agent. Ok(Err(e @ AcpError::Io(_))) | Ok(Err(e @ AcpError::WriteTimeout(_))) - | Ok(Err(e @ AcpError::Timeout(_))) + | Ok(Err(e @ AcpError::Timeout { .. })) | Ok(Err(e @ AcpError::Protocol(_))) | Ok(Err(e @ AcpError::AgentExited)) => { tracing::error!( @@ -1009,7 +1012,10 @@ async fn apply_permission_mode( target: "pool::permission", "permission mode set timed out ({PERMISSION_MODE_TIMEOUT:?}) — treating as fatal" ); - return Err(AcpError::Timeout(PERMISSION_MODE_TIMEOUT)); + return Err(AcpError::Timeout { + method: "session/set_config_option".to_string(), + timeout: PERMISSION_MODE_TIMEOUT, + }); } } Ok(())