From 35eeb531ebea10aab3ad4000bd69f749cd2a0c6d Mon Sep 17 00:00:00 2001 From: Ben Brandt Date: Wed, 21 Oct 2026 13:47:39 +0200 Subject: [PATCH] fix(acp): redact payload-bearing errors in warning logs --- Cargo.lock | 1 + md/SUMMARY.md | 1 + md/logging-privacy.md | 27 +++ src/agent-client-protocol/CHANGELOG.md | 7 + src/agent-client-protocol/Cargo.toml | 1 + .../src/jsonrpc/close.rs | 2 +- .../src/jsonrpc/incoming_actor.rs | 14 +- .../src/jsonrpc/outgoing_actor.rs | 10 +- src/agent-client-protocol/src/util.rs | 38 +++ src/agent-client-protocol/src/util/typed.rs | 4 +- .../tests/log_privacy.rs | 221 ++++++++++++++++++ 11 files changed, 311 insertions(+), 15 deletions(-) create mode 100644 md/logging-privacy.md create mode 100644 src/agent-client-protocol/tests/log_privacy.rs diff --git a/Cargo.lock b/Cargo.lock index a7b96047..7fc6da6f 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -25,6 +25,7 @@ dependencies = [ "tokio", "tokio-util", "tracing", + "tracing-subscriber", "uuid", "windows-sys 0.61.2", ] diff --git a/md/SUMMARY.md b/md/SUMMARY.md index d81893ed..d480ef30 100644 --- a/md/SUMMARY.md +++ b/md/SUMMARY.md @@ -10,6 +10,7 @@ - [Native MCP-over-ACP](./mcp-over-acp.md) - [Sending Requests](./sending-requests.md) - [Request Cancellation](./request-cancellation.md) +- [Logging and Diagnostic Privacy](./logging-privacy.md) - [Ordered Application Dispatch](./ordered-application-dispatch.md) - [Configurable LLM Providers](./llm-providers.md) - [Protocol V2 and Version Routing](./protocol-v2.md) diff --git a/md/logging-privacy.md b/md/logging-privacy.md new file mode 100644 index 00000000..23679cda --- /dev/null +++ b/md/logging-privacy.md @@ -0,0 +1,27 @@ +# Logging and diagnostic privacy + +Ordinary SDK warning logs describe protocol errors using the numeric error code +and a fixed, code-derived reason. Dispatch warnings also identify the method +and, where applicable, request ID and handler. They do not format the error's +application-controlled message or data. + +This applies to malformed typed notifications, request and notification handler +failures (including dynamic handlers), and outgoing error responses. Serde parse +reasons can quote invalid strings or enum variants, so merely omitting +`Error.data.json` would not make those reasons safe to log. The SDK does not +extract field paths from free-form error text; there is currently no separately +trusted structured field path to include in these warnings. + +## Detailed diagnostics are sensitive + +The errors returned to callers and sent to peers are unchanged. In particular, +`util::json_cast` and `util::json_cast_params` can include the complete failing +JSON input and a payload-bearing parse reason. Applications should not log these +errors using their ordinary `Debug` or `Display` representations unless they +intend to record that content. + +Explicitly enabled protocol TRACE logging can record complete messages, +including terminal output, prompts, tool arguments, and error responses. Treat +these traces as private data and enable, store, and share them accordingly. +This warning-log policy does not redact opt-in DEBUG/TRACE diagnostics or +application-provided logging callbacks. diff --git a/src/agent-client-protocol/CHANGELOG.md b/src/agent-client-protocol/CHANGELOG.md index b5c01df1..5ac4fca9 100644 --- a/src/agent-client-protocol/CHANGELOG.md +++ b/src/agent-client-protocol/CHANGELOG.md @@ -2,6 +2,13 @@ ## [Unreleased] +### Fixed + +- Redact error messages and data in ordinary protocol warning logs, including + malformed notification parameters, handler failures, and outgoing error + responses. Preserve detailed returned errors and opt-in protocol tracing. + See [Logging and Diagnostic Privacy](../../md/logging-privacy.md). + ## [3.4.0](https://github.com/agentclientprotocol/rust-sdk/compare/v3.3.0...v3.4.0) - 2026-10-16 ### Added diff --git a/src/agent-client-protocol/Cargo.toml b/src/agent-client-protocol/Cargo.toml index 6fe2cecb..e3209dc8 100644 --- a/src/agent-client-protocol/Cargo.toml +++ b/src/agent-client-protocol/Cargo.toml @@ -103,6 +103,7 @@ expect-test.workspace = true futures = { workspace = true, features = ["executor"] } tokio = { workspace = true, features = ["io-std", "io-util", "macros", "rt", "rt-multi-thread", "sync", "time"] } tokio-util.workspace = true +tracing-subscriber.workspace = true [lints] workspace = true diff --git a/src/agent-client-protocol/src/jsonrpc/close.rs b/src/agent-client-protocol/src/jsonrpc/close.rs index 8c56220b..1111d718 100644 --- a/src/agent-client-protocol/src/jsonrpc/close.rs +++ b/src/agent-client-protocol/src/jsonrpc/close.rs @@ -72,7 +72,7 @@ where ) -> Result<(), crate::Error> { let result = (self.callback)(connection_context::from_raw::(connection)).await; if let Err(error) = &result { - tracing::warn!(?error, "Connection close callback failed"); + tracing::warn!(error = ?crate::util::redacted_error(error.code), "Connection close callback failed"); } result } diff --git a/src/agent-client-protocol/src/jsonrpc/incoming_actor.rs b/src/agent-client-protocol/src/jsonrpc/incoming_actor.rs index aa41e02e..5c0192a7 100644 --- a/src/agent-client-protocol/src/jsonrpc/incoming_actor.rs +++ b/src/agent-client-protocol/src/jsonrpc/incoming_actor.rs @@ -294,7 +294,7 @@ pub(super) async fn incoming_protocol_actor( } Err(error) => { tracing::warn!( - ?error, + error = ?crate::util::redacted_error(error.code), "Invalid transport input, sending error response" ); let destination = destination.expect( @@ -352,7 +352,7 @@ async fn handle_dynamic_handler_message( new_pending_messages.push(m); } Err(err) => { - tracing::warn!(?err, handler = ?handler.dyn_describe_chain(), "Dynamic handler errored on pending message"); + tracing::warn!(%method, err = ?crate::util::redacted_error(err.code), handler = ?handler.dyn_describe_chain(), "Dynamic handler errored on pending message"); handle_handler_error(connection, reply_target, method, err)?; } } @@ -534,7 +534,7 @@ async fn dispatch_dispatch( tracing::warn!( ?method, ?id, - ?err, + err = ?crate::util::redacted_error(err.code), "Request cancellation notification errored" ); return handle_handler_error(connection, error_target, method, err); @@ -559,7 +559,7 @@ async fn dispatch_dispatch( } Err(err) => { - tracing::warn!(?method, ?id, ?err, handler = ?handler.describe_chain(), "Handler errored"); + tracing::warn!(?method, ?id, err = ?crate::util::redacted_error(err.code), handler = ?handler.describe_chain(), "Handler errored"); return handle_handler_error(connection, error_target, method, err); } } @@ -583,7 +583,7 @@ async fn dispatch_dispatch( } Err(err) => { - tracing::warn!(?method, ?id, ?err, handler = ?dynamic_handler.dyn_describe_chain(), "Dynamic handler errored"); + tracing::warn!(?method, ?id, err = ?crate::util::redacted_error(err.code), handler = ?dynamic_handler.dyn_describe_chain(), "Dynamic handler errored"); return handle_handler_error(connection, error_target, method, err); } } @@ -608,7 +608,7 @@ async fn dispatch_dispatch( tracing::warn!( ?method, ?id, - ?err, + err = ?crate::util::redacted_error(err.code), handler = "default", "Default handler errored" ); @@ -682,7 +682,7 @@ fn handle_handler_error( None => { tracing::warn!( %method, - ?error, + error = ?crate::util::redacted_error(error.code), "Ignoring message-processing error because there is no request to answer" ); Ok(()) diff --git a/src/agent-client-protocol/src/jsonrpc/outgoing_actor.rs b/src/agent-client-protocol/src/jsonrpc/outgoing_actor.rs index 970e31d4..35edb6e4 100644 --- a/src/agent-client-protocol/src/jsonrpc/outgoing_actor.rs +++ b/src/agent-client-protocol/src/jsonrpc/outgoing_actor.rs @@ -121,7 +121,7 @@ pub(super) async fn outgoing_protocol_actor( tracing::warn!( ?id, %method, - ?error, + error = ?crate::util::redacted_error(error.code), "Outgoing request readiness failed" ); if let Some(pending_reply) = pending_replies.remove(&id) { @@ -142,7 +142,7 @@ pub(super) async fn outgoing_protocol_actor( { Ok(request) => request, Err(error) => { - tracing::warn!(?id, %method, ?error, "Failed to prepare outgoing request"); + tracing::warn!(?id, %method, error = ?crate::util::redacted_error(error.code), "Failed to prepare outgoing request"); if let Some(pending_reply) = pending_replies.remove(&id) { pending_reply.fail(error); } @@ -168,7 +168,7 @@ pub(super) async fn outgoing_protocol_actor( Ok(messages) => messages, Err(error) => { tracing::warn!( - ?error, + error = ?crate::util::redacted_error(error.code), "Dropping outgoing notification after preparation failed" ); continue; @@ -180,7 +180,7 @@ pub(super) async fn outgoing_protocol_actor( Ok(message) => message, Err(error) => { tracing::warn!( - ?error, + error = ?crate::util::redacted_error(error.code), "Dropping outgoing notification after serialization failed" ); continue; @@ -203,7 +203,7 @@ pub(super) async fn outgoing_protocol_actor( (RawJsonRpcMessage::response(id, Ok(value)), destination) } Err(error) => { - tracing::warn!(?id, %method, ?error, "Sending error response"); + tracing::warn!(?id, %method, error = ?crate::util::redacted_error(error.code), "Sending error response"); (RawJsonRpcMessage::response(id, Err(error)), destination) } }, diff --git a/src/agent-client-protocol/src/util.rs b/src/agent-client-protocol/src/util.rs index fb495347..01366525 100644 --- a/src/agent-client-protocol/src/util.rs +++ b/src/agent-client-protocol/src/util.rs @@ -8,7 +8,42 @@ use futures::{ mod typed; pub use typed::{MatchDispatch, MatchDispatchFrom, TypeNotification}; +/// Format only code-derived metadata at ordinary log levels. +/// +/// Error messages, data, and even Serde parse reasons can contain private input. +/// Do not add fields from the original error here, including purported paths +/// extracted from its text. Full diagnostics belong in opt-in protocol tracing. +pub(crate) fn redacted_error(code: impl Into) -> impl std::fmt::Debug { + struct RedactedError { + code: i32, + reason: &'static str, + } + + impl std::fmt::Debug for RedactedError { + fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + f.debug_struct("Error") + .field("code", &self.code) + .field("reason", &self.reason) + .finish() + } + } + + let code = code.into(); + let reason = match code { + -32700 => "Parse error", + -32600 => "Invalid request", + -32601 => "Method not found", + -32602 => "Invalid params", + -32603 => "Internal error", + _ => "Protocol or application error", + }; + RedactedError { code, reason } +} + /// Cast from `N` to `M` by serializing/deserialization to/from JSON. +/// +/// Returned diagnostics can contain the input JSON and payload-bearing parse +/// reasons. Treat them as sensitive, as with [`json_cast_params`]. pub fn json_cast(params: N) -> Result where N: serde::Serialize, @@ -36,6 +71,9 @@ where /// [`Error::invalid_params`](`crate::Error::invalid_params`) (`-32602`) /// instead of a parse error, which is the correct JSON-RPC error code for /// malformed method parameters. +/// +/// Returned diagnostics include the input JSON and may include input values in +/// the parse reason. Treat them as sensitive; the SDK redacts errors at WARN. pub fn json_cast_params(params: N) -> Result where N: serde::Serialize, diff --git a/src/agent-client-protocol/src/util/typed.rs b/src/agent-client-protocol/src/util/typed.rs index eba105cd..86ab013c 100644 --- a/src/agent-client-protocol/src/util/typed.rs +++ b/src/agent-client-protocol/src/util/typed.rs @@ -891,7 +891,7 @@ impl TypeNotification { Ok(request) => TypeNotificationState::Handled(op(request).await), Err(error) => { tracing::warn!( - ?error, + error = ?crate::util::redacted_error(error.code), method, "Invalid notification params; ignoring notification without replying" ); @@ -923,7 +923,7 @@ impl TypeNotification { Ok(m) => op(m).await, Err(error) => { tracing::warn!( - ?error, + error = ?crate::util::redacted_error(error.code), method, "Invalid untyped notification; ignoring notification without replying" ); diff --git a/src/agent-client-protocol/tests/log_privacy.rs b/src/agent-client-protocol/tests/log_privacy.rs new file mode 100644 index 00000000..98a3a260 --- /dev/null +++ b/src/agent-client-protocol/tests/log_privacy.rs @@ -0,0 +1,221 @@ +//! Capture ordinary warning output, not just the returned protocol error. + +use std::{ + io::{self, Write}, + sync::{Arc, Mutex}, +}; + +use agent_client_protocol::{ + ConnectionTo, Error, JsonRpcMessage, JsonRpcNotification, JsonRpcRequest, JsonRpcResponse, + Responder, UntypedMessage, role::UntypedRole, util::TypeNotification, +}; +use serde::{Deserialize, Serialize}; +use serde_json::{Value, json}; +use tokio::io::{AsyncBufReadExt, AsyncWriteExt, BufReader}; +use tokio_util::compat::{TokioAsyncReadCompatExt, TokioAsyncWriteCompatExt}; + +const PRIVATE_MARKER: &str = "SDK_2_SYNTHETIC_PRIVATE_TERMINAL_OUTPUT"; + +#[derive(Clone)] +struct LogCapture(Arc>>); + +impl Write for LogCapture { + fn write(&mut self, bytes: &[u8]) -> io::Result { + self.0.lock().unwrap().extend_from_slice(bytes); + Ok(bytes.len()) + } + + fn flush(&mut self) -> io::Result<()> { + Ok(()) + } +} + +impl LogCapture { + fn new() -> Self { + Self(Arc::default()) + } + + fn subscriber(&self) -> impl tracing::Subscriber + Send + Sync + 'static { + let writer = self.clone(); + tracing_subscriber::fmt() + .with_max_level(tracing::Level::WARN) + .without_time() + .with_ansi(false) + .with_writer(move || writer.clone()) + .finish() + } + + fn text(&self) -> String { + String::from_utf8(self.0.lock().unwrap().clone()).unwrap() + } +} + +#[derive(Clone, Debug, Serialize, Deserialize)] +enum Kind { + Known, +} + +#[derive(Clone, Debug, Serialize, Deserialize, JsonRpcNotification)] +#[notification(method = "_test/private_notification")] +struct Notice { + required: u64, + kind: Kind, +} + +#[derive(Clone, Debug, Serialize, Deserialize, JsonRpcRequest)] +#[request(method = "_test/private_request", response = Response)] +struct Request { + required: u64, +} + +#[derive(Clone, Debug, Serialize, Deserialize, JsonRpcResponse)] +struct Response {} + +#[test] +fn type_notification_warnings_do_not_echo_private_params_or_parse_reasons() { + let capture = LogCapture::new(); + tracing::subscriber::with_default(capture.subscriber(), || { + futures::executor::block_on(async { + for params in [ + json!({ "extra": PRIVATE_MARKER }), + json!({ "required": PRIVATE_MARKER, "kind": "Known" }), + json!({ "required": 1, "kind": PRIVATE_MARKER }), + ] { + // The full error remains available to callers; neither its JSON + // nor a Serde reason quoting an invalid value is safe for WARN. + let error = + Notice::parse_message("_test/private_notification", ¶ms).unwrap_err(); + assert!(format!("{error:?}").contains(PRIVATE_MARKER)); + + TypeNotification::new( + UntypedMessage::new("_test/private_notification", params).unwrap(), + ) + .handle_if(async |_: Notice| { + panic!("malformed notification must not reach its handler"); + }) + .await + .otherwise(async |_| { + panic!("malformed matching notification must not reach fallback"); + }) + .await + .unwrap(); + } + }); + }); + + let logs = capture.text(); + assert_eq!(logs.matches("Invalid notification params;").count(), 3); + assert!(logs.contains("_test/private_notification")); + assert!(logs.contains("-32602")); + assert!(logs.contains("Invalid params")); + assert!(!logs.contains(PRIVATE_MARKER), "{logs}"); +} + +fn private_handler_error() -> Error { + // Both fields are application-controlled, even for a standard error code. + Error::new(-32602, PRIVATE_MARKER).data(json!({ "private": PRIVATE_MARKER })) +} + +#[tokio::test(flavor = "current_thread")] +async fn dispatch_and_error_response_warnings_do_not_echo_private_errors() { + let capture = LogCapture::new(); + let _subscriber = tracing::subscriber::set_default(capture.subscriber()); + tokio::task::LocalSet::new() + .run_until(async { + let (mut client_writer, server_reader) = tokio::io::duplex(4096); + let (server_writer, client_reader) = tokio::io::duplex(4096); + let server = UntypedRole + .builder() + .on_receive_notification( + async |_: Notice, _: ConnectionTo| { + Err::<(), _>(private_handler_error()) + }, + agent_client_protocol::on_receive_notification!(), + ) + .on_receive_request( + async |request: Request, + responder: Responder, + _: ConnectionTo| { + if request.required == 0 { + responder.respond(Response {}) + } else { + Err(private_handler_error()) + } + }, + agent_client_protocol::on_receive_request!(), + ); + let task = tokio::task::spawn_local(async move { + server + .connect_to(agent_client_protocol::ByteStreams::new( + server_writer.compat_write(), + server_reader.compat(), + )) + .await + .unwrap(); + }); + let mut client_reader = BufReader::new(client_reader); + + for params in [ + json!({ "required": PRIVATE_MARKER, "kind": "Known" }), + json!({ "required": 1, "kind": "Known" }), + ] { + let line = json!({ + "jsonrpc": "2.0", + "method": "_test/private_notification", + "params": params, + }); + client_writer + .write_all(format!("{line}\n").as_bytes()) + .await + .unwrap(); + } + for (id, params) in [ + (1, json!({ "required": PRIVATE_MARKER })), + (2, json!({ "required": 1 })), + (3, json!({ "required": 0 })), + ] { + let line = json!({ + "jsonrpc": "2.0", + "id": id, + "method": "_test/private_request", + "params": params, + }); + client_writer + .write_all(format!("{line}\n").as_bytes()) + .await + .unwrap(); + client_writer.flush().await.unwrap(); + + let mut response = String::new(); + tokio::time::timeout( + std::time::Duration::from_secs(5), + client_reader.read_line(&mut response), + ) + .await + .expect("server must respond and remain alive") + .unwrap(); + let response: Value = serde_json::from_str(&response).unwrap(); + // No notification replies may precede the request response. + assert_eq!(response["id"], id); + if id < 3 { + assert_eq!(response["error"]["code"], -32602); + assert!(response.to_string().contains(PRIVATE_MARKER)); + } else { + assert_eq!(response["result"], json!({})); + } + } + task.abort(); + assert!(task.await.unwrap_err().is_cancelled()); + }) + .await; + + let logs = capture.text(); + // Assert that real warnings were captured from both actors, not an empty log. + assert!(logs.contains("Handler errored"), "{logs}"); + assert!(logs.contains("Ignoring message-processing error"), "{logs}"); + assert_eq!(logs.matches("Sending error response").count(), 2, "{logs}"); + assert!(logs.contains("_test/private_notification")); + assert!(logs.contains("_test/private_request")); + assert!(logs.contains("-32602")); + assert!(!logs.contains(PRIVATE_MARKER), "{logs}"); +}