diff --git a/crates/buzz-acp/src/acp.rs b/crates/buzz-acp/src/acp.rs index 700d5e8dcf..ca0b8242bd 100644 --- a/crates/buzz-acp/src/acp.rs +++ b/crates/buzz-acp/src/acp.rs @@ -95,8 +95,15 @@ 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 {elapsed:?}")] + Timeout { + /// The JSON-RPC method that went unanswered. Without it a caller + /// cannot tell a slow `session/new` from a slow `session/prompt`, + /// and sessions are created lazily inside the prompt task — so the + /// two are indistinguishable from the outside (see #4098). + method: &'static str, + elapsed: std::time::Duration, + }, #[error("Write timeout — agent stopped reading stdin (blocked for {0:?})")] WriteTimeout(std::time::Duration), @@ -1075,7 +1082,7 @@ impl AcpClient { /// if they don't, the agent is likely stuck and we must not block forever. async fn send_request( &mut self, - method: &str, + method: &'static str, params: serde_json::Value, ) -> Result { let id = self.next_id; @@ -1096,12 +1103,20 @@ impl AcpClient { let timeout = Self::REQUEST_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, + elapsed: 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, + elapsed: timeout, + }), } } diff --git a/crates/buzz-acp/src/lib.rs b/crates/buzz-acp/src/lib.rs index 811253e4ac..02879c867a 100644 --- a/crates/buzz-acp/src/lib.rs +++ b/crates/buzz-acp/src/lib.rs @@ -3470,7 +3470,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 64edf68ee2..6bd184facf 100644 --- a/crates/buzz-acp/src/pool.rs +++ b/crates/buzz-acp/src/pool.rs @@ -1025,6 +1025,18 @@ async fn create_session_and_apply_model( /// with the agent's default model. This is intentionally non-fatal: a stale /// response from a timed-out request is safely ignored by `read_until_response` /// (non-matching JSON-RPC IDs are skipped). +/// The JSON-RPC method a given switch actually sends. +/// +/// Kept next to the dispatch it mirrors, and separate from `method_label`: +/// that one is prose for humans, this one names a wire method in an error a +/// caller may act on. Naming the wrong method is worse than naming none. +fn rpc_method_for(method: &ModelSwitchMethod) -> &'static str { + match method { + ModelSwitchMethod::ConfigOption { .. } => "session/set_config_option", + ModelSwitchMethod::SetModel { .. } => "session/set_model", + } +} + async fn apply_model_switch( acp: &mut AcpClient, session_id: &str, @@ -1037,6 +1049,7 @@ async fn apply_model_switch( } ModelSwitchMethod::SetModel { .. } => "set_model".to_string(), }; + let rpc_method = rpc_method_for(method); let result = tokio::time::timeout(MODEL_SWITCH_TIMEOUT, async { match method { @@ -1065,7 +1078,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!( @@ -1088,7 +1101,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: rpc_method, + elapsed: MODEL_SWITCH_TIMEOUT, + }); } } Ok(()) @@ -1141,7 +1157,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!( @@ -1163,7 +1179,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", + elapsed: PERMISSION_MODE_TIMEOUT, + }); } } Ok(()) @@ -3989,6 +4008,28 @@ mod tests { use nostr::{EventBuilder, Keys, Kind, Tag, Timestamp}; use serde_json::json; + /// `apply_model_switch` serves BOTH variants but hardcoded + /// `session/set_model` in its outer-timeout error, so a ConfigOption + /// switch that blew the budget reported an RPC it never sent. The + /// dispatch and the error text have to agree for every variant, and only + /// a test keeps them agreeing as variants are added. + #[test] + fn rpc_method_matches_the_request_each_variant_sends() { + assert_eq!( + rpc_method_for(&ModelSwitchMethod::ConfigOption { + config_id: "model".to_string(), + option_value: "sonnet".to_string(), + }), + "session/set_config_option" + ); + assert_eq!( + rpc_method_for(&ModelSwitchMethod::SetModel { + model_id: "sonnet".to_string(), + }), + "session/set_model" + ); + } + // These pin the initial_message dispatch path (run_prompt_task, ~line 855): // a legacy agent WITH a base_prompt must get [Base] prepended to the user // message. This is the exact regression that shipped in the round-2 bug.