| 1 | //! Low-level tool execution helpers for the engine turn loop. |
| 2 | //! |
| 3 | //! This module keeps the mechanics of MCP dispatch, execution locking, and |
| 4 | //! parallel-tool fanout out of `engine.rs`; the turn loop still owns planning, |
| 5 | //! approval, and how tool results are written back into session state. |
| 6 | |
| 7 | use std::{ |
| 8 | fs::OpenOptions, |
| 9 | io::Write, |
| 10 | path::{Path, PathBuf}, |
| 11 | sync::Arc, |
| 12 | time::Duration, |
| 13 | }; |
| 14 | |
| 15 | use super::*; |
| 16 | |
| 17 | const TOOL_HEARTBEAT_INTERVAL: Duration = Duration::from_secs(10); |
| 18 | |
| 19 | /// Emits delayed, best-effort liveness pulses for one running tool. |
| 20 | /// |
| 21 | /// Keep the ticker in its own task instead of embedding `tokio::time::Interval` |
| 22 | /// in the already-large engine turn future. Besides keeping the turn future |
| 23 | /// compact, this leaves pre-execution MCP discovery and approval scheduling |
| 24 | /// untouched. Dropping the guard cancels and aborts the ticker synchronously. |
| 25 | struct ToolHeartbeatGuard { |
| 26 | cancel: tokio_util::sync::CancellationToken, |
| 27 | task: tokio::task::JoinHandle<()>, |
| 28 | } |
| 29 | |
| 30 | impl ToolHeartbeatGuard { |
| 31 | fn start(tx_event: mpsc::Sender<Event>, interval: Duration) -> Self { |
| 32 | let cancel = tokio_util::sync::CancellationToken::new(); |
| 33 | let task_cancel = cancel.clone(); |
| 34 | let task = tokio::spawn(async move { |
| 35 | let mut ticker = tokio::time::interval(interval); |
| 36 | ticker.set_missed_tick_behavior(tokio::time::MissedTickBehavior::Skip); |
| 37 | // Tokio intervals tick immediately once. Consume that tick so fast |
| 38 | // tools do not produce a pulse and the first heartbeat is delayed. |
| 39 | ticker.tick().await; |
| 40 | |
| 41 | loop { |
| 42 | tokio::select! { |
| 43 | biased; |
| 44 | |
| 45 | () = task_cancel.cancelled() => break, |
| 46 | _ = ticker.tick() => { |
| 47 | match tx_event.try_send(Event::ToolCallHeartbeat) { |
| 48 | Ok(()) | Err(tokio::sync::mpsc::error::TrySendError::Full(_)) => {} |
| 49 | Err(tokio::sync::mpsc::error::TrySendError::Closed(_)) => break, |
| 50 | } |
| 51 | } |
| 52 | } |
| 53 | } |
| 54 | }); |
| 55 | Self { cancel, task } |
| 56 | } |
| 57 | } |
| 58 | |
| 59 | impl Drop for ToolHeartbeatGuard { |
| 60 | fn drop(&mut self) { |
| 61 | self.cancel.cancel(); |
| 62 | self.task.abort(); |
| 63 | } |
| 64 | } |
| 65 | |
| 66 | /// RAII guard that pauses the TUI's terminal-state ownership for the duration |
| 67 | /// of an interactive tool, then restores it on drop. |
| 68 | /// |
| 69 | /// Background: interactive tools (anything that needs the raw TTY — external |
| 70 | /// editor, `exec_shell` with stdin, etc.) need the TUI to leave alt-screen, |
| 71 | /// disable raw mode, and release mouse capture so the child sees a normal |
| 72 | /// terminal. The TUI listens for `Event::PauseEvents` / `Event::ResumeEvents` |
| 73 | /// and runs `pause_terminal` / `resume_terminal` in response. |
| 74 | /// |
| 75 | /// Earlier code sent `PauseEvents` before tool execution and `ResumeEvents` |
| 76 | /// after. That worked on the happy path, but if the tool's future was dropped |
| 77 | /// — Ctrl+C cancellation, sub-agent abort, parent task cancelled while the |
| 78 | /// tool was awaiting — the second `await` never reached and `ResumeEvents` |
| 79 | /// was never sent. It also let interactive children start before the UI had |
| 80 | /// actually left alt-screen/raw mode. Both failures strand the TUI in a |
| 81 | /// regular shell scrollback: the parent shell scrollbar takes over, mouse |
| 82 | /// wheel scrolls the host terminal instead of the transcript, and the TUI |
| 83 | /// renders at the bottom of cooked-mode output. |
| 84 | /// |
| 85 | /// `Drop` runs synchronously and can't await, so we first use `try_send` on a |
| 86 | /// **clone of the event channel** to push `ResumeEvents` non-blockingly. If the |
| 87 | /// channel is full we enqueue the resume on the active Tokio runtime instead of |
| 88 | /// dropping it; otherwise a burst of engine events can strand the UI in the |
| 89 | /// paused terminal state. |
| 90 | pub(super) struct InteractiveTerminalGuard { |
| 91 | tx: Option<mpsc::Sender<Event>>, |
| 92 | } |
| 93 | |
| 94 | impl InteractiveTerminalGuard { |
| 95 | /// Send `PauseEvents` and arm the guard. If `interactive` is false the |
| 96 | /// guard is a no-op — `Drop` will skip the resume. |
| 97 | pub(super) async fn engage(tx: mpsc::Sender<Event>, interactive: bool) -> Self { |
| 98 | if !interactive { |
| 99 | return Self { tx: None }; |
| 100 | } |
| 101 | // Best-effort: if the receiver is gone the TUI has already shut down |
| 102 | // and there's nothing to restore. If the event is delivered, wait for |
| 103 | // the UI to actually release the terminal before starting the child. |
| 104 | let ack = Arc::new(tokio::sync::Notify::new()); |
| 105 | match tx |
| 106 | .send(Event::PauseEvents { |
| 107 | ack: Some(ack.clone()), |
| 108 | }) |
| 109 | .await |
| 110 | { |
| 111 | Ok(()) => { |
| 112 | if tokio::time::timeout(Duration::from_millis(750), ack.notified()) |
| 113 | .await |
| 114 | .is_err() |
| 115 | { |
| 116 | tracing::warn!( |
| 117 | target: "engine.tool_execution", |
| 118 | "InteractiveTerminalGuard: timed out waiting for terminal pause ack; \ |
| 119 | continuing with interactive tool" |
| 120 | ); |
| 121 | } |
| 122 | } |
| 123 | Err(err) => { |
| 124 | tracing::debug!( |
| 125 | target: "engine.tool_execution", |
| 126 | ?err, |
| 127 | "InteractiveTerminalGuard: event channel closed before PauseEvents" |
| 128 | ); |
| 129 | } |
| 130 | } |
| 131 | Self { tx: Some(tx) } |
| 132 | } |
| 133 | } |
| 134 | |
| 135 | impl Drop for InteractiveTerminalGuard { |
| 136 | fn drop(&mut self) { |
| 137 | if let Some(tx) = self.tx.take() { |
| 138 | match tx.try_send(Event::ResumeEvents) { |
| 139 | Ok(()) => {} |
| 140 | Err(tokio::sync::mpsc::error::TrySendError::Full(event)) => { |
| 141 | match tokio::runtime::Handle::try_current() { |
| 142 | Ok(handle) => { |
| 143 | handle.spawn(async move { |
| 144 | if let Err(err) = tx.send(event).await { |
| 145 | tracing::warn!( |
| 146 | target: "engine.tool_execution", |
| 147 | ?err, |
| 148 | "InteractiveTerminalGuard: async send(ResumeEvents) failed; \ |
| 149 | terminal may stay in paused state until the next \ |
| 150 | pause/resume cycle" |
| 151 | ); |
| 152 | } |
| 153 | }); |
| 154 | } |
| 155 | Err(err) => { |
| 156 | tracing::warn!( |
| 157 | target: "engine.tool_execution", |
| 158 | ?err, |
| 159 | "InteractiveTerminalGuard: event channel full and no Tokio runtime \ |
| 160 | available to queue ResumeEvents; terminal may stay paused until \ |
| 161 | the next pause/resume cycle" |
| 162 | ); |
| 163 | } |
| 164 | } |
| 165 | } |
| 166 | Err(tokio::sync::mpsc::error::TrySendError::Closed(_)) => { |
| 167 | tracing::debug!( |
| 168 | target: "engine.tool_execution", |
| 169 | "InteractiveTerminalGuard: event channel closed before ResumeEvents" |
| 170 | ); |
| 171 | } |
| 172 | } |
| 173 | } |
| 174 | } |
| 175 | } |
| 176 | |
| 177 | pub(super) fn emit_tool_audit(event: serde_json::Value) { |
| 178 | let Some(path) = std::env::var_os("CODEWHALE_TOOL_AUDIT_LOG") |
| 179 | .or_else(|| std::env::var_os("DEEPSEEK_TOOL_AUDIT_LOG")) |
| 180 | else { |
| 181 | return; |
| 182 | }; |
| 183 | emit_tool_audit_to_path(&PathBuf::from(path), event); |
| 184 | } |
| 185 | |
| 186 | fn emit_tool_audit_to_path(path: &Path, event: serde_json::Value) { |
| 187 | let line = match serde_json::to_string(&event) { |
| 188 | Ok(line) => line, |
| 189 | Err(e) => { |
| 190 | tracing::error!("Failed to serialize tool audit event: {e}"); |
| 191 | return; |
| 192 | } |
| 193 | }; |
| 194 | if let Some(parent) = path.parent() |
| 195 | && let Err(e) = std::fs::create_dir_all(parent) |
| 196 | { |
| 197 | tracing::error!( |
| 198 | "Failed to create audit log directory {}: {e}", |
| 199 | parent.display() |
| 200 | ); |
| 201 | return; |
| 202 | } |
| 203 | match OpenOptions::new().create(true).append(true).open(path) { |
| 204 | Ok(mut file) => { |
| 205 | if let Err(e) = writeln!(file, "{line}") { |
| 206 | tracing::error!("Failed to write to audit log {}: {e}", path.display()); |
| 207 | } |
| 208 | } |
| 209 | Err(e) => { |
| 210 | tracing::error!("Failed to open audit log {}: {e}", path.display()); |
| 211 | } |
| 212 | } |
| 213 | } |
| 214 | |
| 215 | impl Engine { |
| 216 | pub(super) async fn execute_mcp_tool_with_pool( |
| 217 | pool: Arc<AsyncMutex<McpPool>>, |
| 218 | name: &str, |
| 219 | input: serde_json::Value, |
| 220 | ) -> Result<ToolResult, ToolError> { |
| 221 | let mut pool = pool.lock().await; |
| 222 | let result = pool |
| 223 | .call_tool(name, input) |
| 224 | .await |
| 225 | .map_err(|e| ToolError::execution_failed(format!("MCP tool failed: {e}")))?; |
| 226 | let content = serde_json::to_string(&result).unwrap_or_else(|_| result.to_string()); |
| 227 | Ok(ToolResult::success(content)) |
| 228 | } |
| 229 | |
| 230 | pub(super) async fn execute_parallel_tool( |
| 231 | &mut self, |
| 232 | input: serde_json::Value, |
| 233 | tool_registry: Option<&crate::tools::ToolRegistry>, |
| 234 | tool_exec_lock: Arc<RwLock<()>>, |
| 235 | context_override: Option<crate::tools::ToolContext>, |
| 236 | ) -> Result<ToolResult, ToolError> { |
| 237 | let calls = parse_parallel_tool_calls(&input)?; |
| 238 | let mcp_pool = if calls.iter().any(|(tool, _)| McpPool::is_mcp_tool(tool)) { |
| 239 | Some(self.ensure_mcp_pool().await?) |
| 240 | } else { |
| 241 | None |
| 242 | }; |
| 243 | let Some(registry) = tool_registry else { |
| 244 | return Err(ToolError::not_available( |
| 245 | "tool registry unavailable for multi_tool_use.parallel", |
| 246 | )); |
| 247 | }; |
| 248 | |
| 249 | let result_count = calls.len(); |
| 250 | let mut tasks = FuturesUnordered::new(); |
| 251 | let shell_permits = Arc::new(tokio::sync::Semaphore::new(MAX_PARALLEL_SHELL_EXEC)); |
| 252 | for (index, (tool_name, tool_input)) in calls.into_iter().enumerate() { |
| 253 | if tool_name == MULTI_TOOL_PARALLEL_NAME { |
| 254 | return Err(ToolError::invalid_input( |
| 255 | "multi_tool_use.parallel cannot call itself", |
| 256 | )); |
| 257 | } |
| 258 | if McpPool::is_mcp_tool(&tool_name) { |
| 259 | if !mcp_tool_is_parallel_safe(&tool_name) { |
| 260 | return Err(ToolError::invalid_input(format!( |
| 261 | "Tool '{tool_name}' is an MCP tool and cannot run in parallel. \ |
| 262 | Allowed MCP tools: list_mcp_resources, list_mcp_resource_templates, \ |
| 263 | mcp_read_resource, read_mcp_resource, mcp_get_prompt." |
| 264 | ))); |
| 265 | } |
| 266 | } else { |
| 267 | let Some(spec) = registry.get(&tool_name) else { |
| 268 | return Err(ToolError::not_available(format!( |
| 269 | "tool '{tool_name}' is not registered" |
| 270 | ))); |
| 271 | }; |
| 272 | if !spec.is_read_only_for(&tool_input) { |
| 273 | return Err(ToolError::invalid_input(format!( |
| 274 | "Tool '{tool_name}' is not read-only and cannot run in parallel" |
| 275 | ))); |
| 276 | } |
| 277 | if spec.approval_requirement_for(&tool_input) != ApprovalRequirement::Auto { |
| 278 | return Err(ToolError::invalid_input(format!( |
| 279 | "Tool '{tool_name}' requires approval and cannot run in parallel" |
| 280 | ))); |
| 281 | } |
| 282 | if !spec.supports_parallel_for(&tool_input) { |
| 283 | return Err(ToolError::invalid_input(format!( |
| 284 | "Tool '{tool_name}' does not support parallel execution" |
| 285 | ))); |
| 286 | } |
| 287 | } |
| 288 | |
| 289 | let registry_ref = registry; |
| 290 | let lock = tool_exec_lock.clone(); |
| 291 | let tx_event = self.tx_event.clone(); |
| 292 | let mcp_pool = mcp_pool.clone(); |
| 293 | let shell_permits = shell_permits.clone(); |
| 294 | let workspace = self.session.workspace.clone(); |
| 295 | let context_override = context_override.clone(); |
| 296 | let cancel_token = self.cancel_token.clone(); |
| 297 | tasks.push(async move { |
| 298 | let _shell_permit = if tool_name == "exec_shell" { |
| 299 | shell_permits.acquire_owned().await.ok() |
| 300 | } else { |
| 301 | None |
| 302 | }; |
| 303 | let result = Engine::execute_tool_with_lock( |
| 304 | lock, |
| 305 | true, |
| 306 | false, |
| 307 | tx_event, |
| 308 | Some(cancel_token), |
| 309 | tool_name.clone(), |
| 310 | tool_input.clone(), |
| 311 | workspace, |
| 312 | Some(registry_ref), |
| 313 | mcp_pool, |
| 314 | context_override, |
| 315 | ) |
| 316 | .await; |
| 317 | (index, tool_name, result) |
| 318 | }); |
| 319 | } |
| 320 | |
| 321 | let mut results: Vec<Option<ParallelToolResultEntry>> = Vec::with_capacity(result_count); |
| 322 | results.resize_with(result_count, || None); |
| 323 | while let Some((index, tool_name, result)) = tasks.next().await { |
| 324 | let entry = match result { |
| 325 | Ok(output) => { |
| 326 | let mut error = None; |
| 327 | if !output.success { |
| 328 | error = Some(output.content.clone()); |
| 329 | } |
| 330 | ParallelToolResultEntry { |
| 331 | tool_name, |
| 332 | success: output.success, |
| 333 | content: output.content, |
| 334 | error, |
| 335 | } |
| 336 | } |
| 337 | Err(err) => { |
| 338 | let message = format!("{err}"); |
| 339 | ParallelToolResultEntry { |
| 340 | tool_name, |
| 341 | success: false, |
| 342 | content: format!("Error: {message}"), |
| 343 | error: Some(message), |
| 344 | } |
| 345 | } |
| 346 | }; |
| 347 | results[index] = Some(entry); |
| 348 | } |
| 349 | let results = results.into_iter().flatten().collect(); |
| 350 | |
| 351 | ToolResult::json(&ParallelToolResult { results }) |
| 352 | .map_err(|e| ToolError::execution_failed(e.to_string())) |
| 353 | } |
| 354 | |
| 355 | #[allow(clippy::too_many_arguments)] |
| 356 | pub(super) async fn execute_tool_with_lock( |
| 357 | lock: Arc<RwLock<()>>, |
| 358 | supports_parallel: bool, |
| 359 | interactive: bool, |
| 360 | tx_event: mpsc::Sender<Event>, |
| 361 | cancel_token: Option<CancellationToken>, |
| 362 | tool_name: String, |
| 363 | tool_input: serde_json::Value, |
| 364 | workspace: PathBuf, |
| 365 | registry: Option<&crate::tools::ToolRegistry>, |
| 366 | mcp_pool: Option<Arc<AsyncMutex<McpPool>>>, |
| 367 | context_override: Option<crate::tools::ToolContext>, |
| 368 | ) -> Result<ToolResult, ToolError> { |
| 369 | if cancel_token |
| 370 | .as_ref() |
| 371 | .is_some_and(CancellationToken::is_cancelled) |
| 372 | { |
| 373 | return Err(ToolError::permission_denied( |
| 374 | "Turn stopped by user. Tool call blocked.", |
| 375 | )); |
| 376 | } |
| 377 | // This guard starts before lock acquisition, so contention as well as |
| 378 | // registry/MCP/interpreter execution remains visibly live. |
| 379 | let _heartbeat = ToolHeartbeatGuard::start(tx_event.clone(), TOOL_HEARTBEAT_INTERVAL); |
| 380 | let started_at = std::time::Instant::now(); |
| 381 | let dispatch = if McpPool::is_mcp_tool(&tool_name) { |
| 382 | "mcp" |
| 383 | } else if matches!( |
| 384 | tool_name.as_str(), |
| 385 | CODE_EXECUTION_TOOL_NAME | JS_EXECUTION_TOOL_NAME |
| 386 | ) { |
| 387 | "interpreter" |
| 388 | } else if registry.is_some() { |
| 389 | "registry" |
| 390 | } else { |
| 391 | "missing" |
| 392 | }; |
| 393 | let input_bytes = serde_json::to_string(&tool_input) |
| 394 | .map(|s| s.len()) |
| 395 | .unwrap_or(0); |
| 396 | tracing::debug!( |
| 397 | target: "engine.tool_execution", |
| 398 | tool = %tool_name, |
| 399 | dispatch, |
| 400 | interactive, |
| 401 | supports_parallel, |
| 402 | input_bytes, |
| 403 | "tool.exec.start", |
| 404 | ); |
| 405 | |
| 406 | let _guard = if supports_parallel { |
| 407 | ToolExecGuard::Read(lock.read().await) |
| 408 | } else { |
| 409 | ToolExecGuard::Write(lock.write().await) |
| 410 | }; |
| 411 | |
| 412 | // RAII pause/resume: ensures `Event::ResumeEvents` always fires on |
| 413 | // drop, even if the tool future is cancelled mid-await. See |
| 414 | // `InteractiveTerminalGuard` doc-comment for the regression this |
| 415 | // closes (parent terminal scrollback hijacking the TUI after a |
| 416 | // cancelled interactive tool). |
| 417 | let _terminal = InteractiveTerminalGuard::engage(tx_event, interactive).await; |
| 418 | |
| 419 | if cancel_token |
| 420 | .as_ref() |
| 421 | .is_some_and(CancellationToken::is_cancelled) |
| 422 | { |
| 423 | return Err(ToolError::permission_denied( |
| 424 | "Turn stopped by user. Tool call blocked.", |
| 425 | )); |
| 426 | } |
| 427 | |
| 428 | let tool_authority = context_override |
| 429 | .as_ref() |
| 430 | .and_then(|context| context.tool_authority.as_ref()) |
| 431 | .or_else(|| registry.and_then(|registry| registry.context().tool_authority.as_ref())); |
| 432 | if let Some(authority) = tool_authority { |
| 433 | if McpPool::is_mcp_tool(&tool_name) |
| 434 | && !super::dispatch::mcp_tool_is_read_only(&tool_name) |
| 435 | { |
| 436 | return Err(ToolError::permission_denied(format!( |
| 437 | "worker '{}' cannot run mutating MCP tool {tool_name}: it has no authorized file target", |
| 438 | authority.owner |
| 439 | ))); |
| 440 | } |
| 441 | if matches!( |
| 442 | tool_name.as_str(), |
| 443 | CODE_EXECUTION_TOOL_NAME | JS_EXECUTION_TOOL_NAME |
| 444 | ) { |
| 445 | return Err(ToolError::permission_denied(format!( |
| 446 | "worker '{}' cannot run {tool_name}: arbitrary code execution is outside its machine-readable authority envelope", |
| 447 | authority.owner |
| 448 | ))); |
| 449 | } |
| 450 | } |
| 451 | |
| 452 | let outcome = if McpPool::is_mcp_tool(&tool_name) { |
| 453 | if let Some(pool) = mcp_pool { |
| 454 | Engine::execute_mcp_tool_with_pool(pool, &tool_name, tool_input).await |
| 455 | } else { |
| 456 | Err(ToolError::not_available(format!( |
| 457 | "tool '{tool_name}' is not registered" |
| 458 | ))) |
| 459 | } |
| 460 | } else if tool_name == CODE_EXECUTION_TOOL_NAME { |
| 461 | execute_code_execution_tool(&tool_input, &workspace).await |
| 462 | } else if tool_name == JS_EXECUTION_TOOL_NAME { |
| 463 | execute_js_execution_tool(&tool_input, &workspace).await |
| 464 | } else if let Some(registry) = registry { |
| 465 | registry |
| 466 | .execute_full_with_context(&tool_name, tool_input, context_override.as_ref()) |
| 467 | .await |
| 468 | } else { |
| 469 | Err(ToolError::not_available(format!( |
| 470 | "tool '{tool_name}' is not registered" |
| 471 | ))) |
| 472 | }; |
| 473 | |
| 474 | let duration_ms = started_at.elapsed().as_millis() as u64; |
| 475 | // The surface-agnostic choke point for every tool call, so this one |
| 476 | // bump covers exec and the CLI as well as the TUI. `memory_search` is |
| 477 | // counted here for the same reason — one site, not one per tool. |
| 478 | let telemetry = codewhale_telemetry::session_counters(); |
| 479 | telemetry.bump(codewhale_telemetry::Counter::ToolCalls); |
| 480 | if tool_name == "memory_search" { |
| 481 | telemetry.bump(codewhale_telemetry::Counter::MemorySearch); |
| 482 | } |
| 483 | match &outcome { |
| 484 | Ok(result) => { |
| 485 | tracing::debug!( |
| 486 | target: "engine.tool_execution", |
| 487 | tool = %tool_name, |
| 488 | dispatch, |
| 489 | duration_ms, |
| 490 | success = result.success, |
| 491 | output_bytes = result.content.len(), |
| 492 | "tool.exec.end", |
| 493 | ); |
| 494 | } |
| 495 | Err(err) => { |
| 496 | let kind = match err { |
| 497 | ToolError::InvalidInput { .. } => "invalid_input", |
| 498 | ToolError::MissingField { .. } => "missing_field", |
| 499 | ToolError::PathEscape { .. } => "path_escape", |
| 500 | ToolError::ExecutionFailed { .. } => "execution_failed", |
| 501 | ToolError::Timeout { .. } => "timeout", |
| 502 | ToolError::Cancelled { .. } => "cancelled", |
| 503 | ToolError::NotAvailable { .. } => "not_available", |
| 504 | ToolError::PermissionDenied { .. } => "permission_denied", |
| 505 | }; |
| 506 | // The discriminant and nothing else. `ToolError::PathEscape`'s |
| 507 | // `Display` *is* an absolute path, and several sibling |
| 508 | // variants render a literal source fragment the model emitted. |
| 509 | match err { |
| 510 | ToolError::PermissionDenied { .. } => { |
| 511 | telemetry.bump_error(codewhale_telemetry::ErrorCounter::ToolDeniedByPolicy) |
| 512 | } |
| 513 | ToolError::Timeout { .. } => { |
| 514 | telemetry.bump_error(codewhale_telemetry::ErrorCounter::ToolTimeout); |
| 515 | } |
| 516 | _ => {} |
| 517 | } |
| 518 | tracing::warn!( |
| 519 | target: "engine.tool_execution", |
| 520 | tool = %tool_name, |
| 521 | dispatch, |
| 522 | duration_ms, |
| 523 | error_kind = kind, |
| 524 | error = %err, |
| 525 | "tool.exec.end", |
| 526 | ); |
| 527 | } |
| 528 | } |
| 529 | outcome |
| 530 | } |
| 531 | } |
| 532 | |
| 533 | #[cfg(test)] |
| 534 | mod tests { |
| 535 | use super::*; |
| 536 | use serde_json::json; |
| 537 | use std::time::Duration; |
| 538 | |
| 539 | const TEST_HEARTBEAT_INTERVAL: Duration = Duration::from_millis(10); |
| 540 | |
| 541 | #[tokio::test] |
| 542 | async fn tool_heartbeat_emits_for_slow_tool() { |
| 543 | let (tx, mut rx) = mpsc::channel(4); |
| 544 | let guard = ToolHeartbeatGuard::start(tx, TEST_HEARTBEAT_INTERVAL); |
| 545 | |
| 546 | let event = tokio::time::timeout(Duration::from_secs(1), rx.recv()) |
| 547 | .await |
| 548 | .expect("heartbeat before slow tool completes") |
| 549 | .expect("event channel stays open"); |
| 550 | |
| 551 | assert!(matches!(event, Event::ToolCallHeartbeat)); |
| 552 | drop(guard); |
| 553 | } |
| 554 | |
| 555 | #[tokio::test] |
| 556 | async fn tool_heartbeat_is_delayed_for_fast_tool() { |
| 557 | let (tx, mut rx) = mpsc::channel(4); |
| 558 | |
| 559 | let guard = ToolHeartbeatGuard::start(tx, TEST_HEARTBEAT_INTERVAL); |
| 560 | drop(guard); |
| 561 | tokio::time::sleep(TEST_HEARTBEAT_INTERVAL * 2).await; |
| 562 | |
| 563 | assert!(rx.try_recv().is_err(), "fast tool emitted a heartbeat"); |
| 564 | } |
| 565 | |
| 566 | #[tokio::test] |
| 567 | async fn tool_heartbeat_stops_after_tool_completes() { |
| 568 | let (tx, mut rx) = mpsc::channel(8); |
| 569 | let guard = ToolHeartbeatGuard::start(tx, TEST_HEARTBEAT_INTERVAL); |
| 570 | |
| 571 | let event = tokio::time::timeout(Duration::from_secs(1), rx.recv()) |
| 572 | .await |
| 573 | .expect("heartbeat before slow tool completes") |
| 574 | .expect("event channel stays open"); |
| 575 | assert!(matches!(event, Event::ToolCallHeartbeat)); |
| 576 | |
| 577 | drop(guard); |
| 578 | tokio::task::yield_now().await; |
| 579 | while rx.try_recv().is_ok() {} |
| 580 | tokio::time::sleep(TEST_HEARTBEAT_INTERVAL * 2).await; |
| 581 | assert!( |
| 582 | rx.try_recv().is_err(), |
| 583 | "heartbeat continued after tool completion" |
| 584 | ); |
| 585 | } |
| 586 | |
| 587 | #[tokio::test] |
| 588 | async fn full_event_channel_never_blocks_tool_heartbeat() { |
| 589 | let (tx, mut rx) = mpsc::channel(1); |
| 590 | tx.try_send(Event::status("filler")).expect("fill channel"); |
| 591 | |
| 592 | let result = tokio::time::timeout(Duration::from_secs(1), async { |
| 593 | let guard = ToolHeartbeatGuard::start(tx, TEST_HEARTBEAT_INTERVAL); |
| 594 | tokio::time::sleep(TEST_HEARTBEAT_INTERVAL * 3).await; |
| 595 | drop(guard); |
| 596 | "done" |
| 597 | }) |
| 598 | .await |
| 599 | .expect("full event channel must not block tool completion"); |
| 600 | |
| 601 | assert_eq!(result, "done"); |
| 602 | assert!(matches!(rx.recv().await, Some(Event::Status { .. }))); |
| 603 | assert!(rx.try_recv().is_err(), "heartbeat displaced queued event"); |
| 604 | } |
| 605 | |
| 606 | #[tokio::test] |
| 607 | async fn terminal_guard_queues_resume_when_event_channel_is_full() { |
| 608 | let (tx, mut rx) = mpsc::channel(1); |
| 609 | tx.try_send(Event::status("filler")).expect("fill channel"); |
| 610 | |
| 611 | drop(InteractiveTerminalGuard { tx: Some(tx) }); |
| 612 | |
| 613 | assert!(matches!(rx.recv().await, Some(Event::Status { .. }))); |
| 614 | let resumed = tokio::time::timeout(Duration::from_secs(1), rx.recv()) |
| 615 | .await |
| 616 | .expect("queued resume event") |
| 617 | .expect("event channel still open"); |
| 618 | assert!(matches!(resumed, Event::ResumeEvents)); |
| 619 | } |
| 620 | |
| 621 | #[tokio::test] |
| 622 | async fn terminal_guard_waits_for_pause_ack_before_returning() { |
| 623 | let (tx, mut rx) = mpsc::channel(4); |
| 624 | let task = tokio::spawn(InteractiveTerminalGuard::engage(tx, true)); |
| 625 | |
| 626 | let event = tokio::time::timeout(Duration::from_secs(1), rx.recv()) |
| 627 | .await |
| 628 | .expect("pause event") |
| 629 | .expect("event channel still open"); |
| 630 | let ack = match event { |
| 631 | Event::PauseEvents { ack: Some(ack) } => ack, |
| 632 | other => panic!("expected PauseEvents with ack, got {other:?}"), |
| 633 | }; |
| 634 | |
| 635 | tokio::task::yield_now().await; |
| 636 | assert!(!task.is_finished(), "guard returned before pause ack"); |
| 637 | |
| 638 | ack.notify_one(); |
| 639 | let guard = tokio::time::timeout(Duration::from_secs(1), task) |
| 640 | .await |
| 641 | .expect("guard returned after ack") |
| 642 | .expect("guard task joined"); |
| 643 | |
| 644 | drop(guard); |
| 645 | let resumed = tokio::time::timeout(Duration::from_secs(1), rx.recv()) |
| 646 | .await |
| 647 | .expect("resume event") |
| 648 | .expect("event channel still open"); |
| 649 | assert!(matches!(resumed, Event::ResumeEvents)); |
| 650 | } |
| 651 | |
| 652 | #[test] |
| 653 | fn emit_tool_audit_to_path_writes_jsonl_lines() { |
| 654 | let tmp = tempfile::tempdir().expect("tempdir"); |
| 655 | let path = tmp.path().join("audit.log"); |
| 656 | let marker = path.display().to_string(); |
| 657 | |
| 658 | emit_tool_audit_to_path( |
| 659 | &path, |
| 660 | json!({ |
| 661 | "event": "tool.spillover", |
| 662 | "test_marker": marker, |
| 663 | "tool_id": "call-abc", |
| 664 | "tool_name": "exec_shell", |
| 665 | "path": "/tmp/foo.txt", |
| 666 | }), |
| 667 | ); |
| 668 | emit_tool_audit_to_path( |
| 669 | &path, |
| 670 | json!({ |
| 671 | "event": "tool.result", |
| 672 | "test_marker": marker, |
| 673 | "tool_id": "call-xyz", |
| 674 | "success": true, |
| 675 | }), |
| 676 | ); |
| 677 | |
| 678 | let body = std::fs::read_to_string(&path).expect("audit log written"); |
| 679 | let entries: Vec<serde_json::Value> = body |
| 680 | .lines() |
| 681 | .map(|line| serde_json::from_str(line).expect("audit line is JSON")) |
| 682 | .filter(|entry: &serde_json::Value| { |
| 683 | entry.get("test_marker").and_then(|v| v.as_str()) == Some(marker.as_str()) |
| 684 | }) |
| 685 | .collect(); |
| 686 | assert_eq!(entries.len(), 2, "two marked emits -> two lines"); |
| 687 | |
| 688 | // Each line round-trips as JSON, has the expected event key. |
| 689 | let first = &entries[0]; |
| 690 | assert_eq!( |
| 691 | first.get("event").and_then(|v| v.as_str()), |
| 692 | Some("tool.spillover") |
| 693 | ); |
| 694 | assert_eq!( |
| 695 | first.get("tool_id").and_then(|v| v.as_str()), |
| 696 | Some("call-abc") |
| 697 | ); |
| 698 | |
| 699 | let second = &entries[1]; |
| 700 | assert_eq!( |
| 701 | second.get("event").and_then(|v| v.as_str()), |
| 702 | Some("tool.result") |
| 703 | ); |
| 704 | } |
| 705 | |
| 706 | #[test] |
| 707 | fn emit_tool_audit_creates_parent_directory() { |
| 708 | let tmp = tempfile::tempdir().expect("tempdir"); |
| 709 | // Path with a parent that doesn't exist yet — the writer |
| 710 | // should create it. |
| 711 | let nested = tmp.path().join("nested").join("dir").join("audit.log"); |
| 712 | emit_tool_audit_to_path(&nested, json!({"event": "test"})); |
| 713 | assert!(nested.exists(), "writer should mkdir -p the parent chain"); |
| 714 | } |
| 715 | } |
| 716 |