From 5b896f3378bee7d220d98dc790826c50bccd09b4 Mon Sep 17 00:00:00 2001 From: harald Date: Wed, 25 Feb 2026 13:13:19 +0100 Subject: [PATCH] feat(observability): add debug/trace logging to shell tool and command policy Shell tool now logs at debug level: command invocations, policy allow/block decisions with reasons, exit codes, and output sizes. Trace level adds full stdout/stderr content and risk assessment details. Co-Authored-By: Claude Opus 4.6 --- src/security/policy.rs | 6 ++++++ src/tools/shell.rs | 48 ++++++++++++++++++++++++++++++------------ 2 files changed, 41 insertions(+), 13 deletions(-) diff --git a/src/security/policy.rs b/src/security/policy.rs index acc227d..180d9cc 100644 --- a/src/security/policy.rs +++ b/src/security/policy.rs @@ -312,16 +312,20 @@ impl SecurityPolicy { approved: bool, ) -> Result { if !self.is_command_allowed(command) { + tracing::debug!(command, "Shell command blocked by allowlist"); return Err(format!("Command not allowed by security policy: {command}")); } let risk = self.command_risk_level(command); + tracing::trace!(command, ?risk, approved, "Shell command risk assessed"); if risk == CommandRiskLevel::High { if self.block_high_risk_commands { + tracing::debug!(command, "Shell command blocked: high-risk disallowed by policy"); return Err("Command blocked: high-risk command is disallowed by policy".into()); } if self.autonomy == AutonomyLevel::Supervised && !approved { + tracing::debug!(command, "Shell command blocked: high-risk needs approval"); return Err( "Command requires explicit approval (approved=true): high-risk operation" .into(), @@ -334,11 +338,13 @@ impl SecurityPolicy { && self.require_approval_for_medium_risk && !approved { + tracing::debug!(command, "Shell command blocked: medium-risk needs approval"); return Err( "Command requires explicit approval (approved=true): medium-risk operation".into(), ); } + tracing::debug!(command, ?risk, "Shell command allowed by policy"); Ok(risk) } diff --git a/src/tools/shell.rs b/src/tools/shell.rs index 031ed4b..0b5e222 100644 --- a/src/tools/shell.rs +++ b/src/tools/shell.rs @@ -66,7 +66,10 @@ impl Tool for ShellTool { .and_then(|v| v.as_bool()) .unwrap_or(false); + tracing::debug!(command, approved, "Shell tool invoked"); + if self.security.is_rate_limited() { + tracing::warn!(command, "Shell command rejected: rate limit exceeded"); return Ok(ToolResult { success: false, output: String::new(), @@ -122,9 +125,22 @@ impl Tool for ShellTool { match result { Ok(Ok(output)) => { + let exit_code = output.status.code(); + let success = output.status.success(); + tracing::debug!( + command, + ?exit_code, + success, + stdout_bytes = output.stdout.len(), + stderr_bytes = output.stderr.len(), + "Shell command completed" + ); + let mut stdout = String::from_utf8_lossy(&output.stdout).to_string(); let mut stderr = String::from_utf8_lossy(&output.stderr).to_string(); + tracing::trace!(command, stdout = %stdout, stderr = %stderr, "Shell command output"); + // Truncate output to prevent OOM if stdout.len() > MAX_OUTPUT_BYTES { stdout.truncate(stdout.floor_char_boundary(MAX_OUTPUT_BYTES)); @@ -136,7 +152,7 @@ impl Tool for ShellTool { } Ok(ToolResult { - success: output.status.success(), + success, output: stdout, error: if stderr.is_empty() { None @@ -145,18 +161,24 @@ impl Tool for ShellTool { }, }) } - Ok(Err(e)) => Ok(ToolResult { - success: false, - output: String::new(), - error: Some(format!("Failed to execute command: {e}")), - }), - Err(_) => Ok(ToolResult { - success: false, - output: String::new(), - error: Some(format!( - "Command timed out after {SHELL_TIMEOUT_SECS}s and was killed" - )), - }), + Ok(Err(e)) => { + tracing::warn!(command, error = %e, "Shell command failed to execute"); + Ok(ToolResult { + success: false, + output: String::new(), + error: Some(format!("Failed to execute command: {e}")), + }) + } + Err(_) => { + tracing::warn!(command, timeout_secs = SHELL_TIMEOUT_SECS, "Shell command timed out"); + Ok(ToolResult { + success: false, + output: String::new(), + error: Some(format!( + "Command timed out after {SHELL_TIMEOUT_SECS}s and was killed" + )), + }) + } } } }