diff --git a/src/agent/agent_loop.rs b/src/agent/agent_loop.rs index 9afd7bc2..18a7d6fc 100644 --- a/src/agent/agent_loop.rs +++ b/src/agent/agent_loop.rs @@ -28,7 +28,7 @@ use crate::tools::ToolRegistry; use crate::workspace::Workspace; /// Collapse a tool output string into a single-line preview for display. -fn truncate_for_preview(output: &str, max_chars: usize) -> String { +pub(crate) fn truncate_for_preview(output: &str, max_chars: usize) -> String { let collapsed: String = output .chars() .take(max_chars + 50) @@ -37,8 +37,14 @@ fn truncate_for_preview(output: &str, max_chars: usize) -> String { .split_whitespace() .collect::>() .join(" "); - if collapsed.len() > max_chars { - format!("{}...", &collapsed[..max_chars]) + // char_indices gives us byte offsets at char boundaries, so the slice is always valid UTF-8. + if collapsed.chars().count() > max_chars { + let byte_offset = collapsed + .char_indices() + .nth(max_chars) + .map(|(i, _)| i) + .unwrap_or(collapsed.len()); + format!("{}...", &collapsed[..byte_offset]) } else { collapsed } @@ -2627,4 +2633,70 @@ mod tests { assert!(detect_auth_awaiting("tool_activate", &result).is_none()); } + + // --- truncate_for_preview tests --- + + use super::truncate_for_preview; + + #[test] + fn test_truncate_short_input() { + assert_eq!(truncate_for_preview("hello", 10), "hello"); + } + + #[test] + fn test_truncate_empty_input() { + assert_eq!(truncate_for_preview("", 10), ""); + } + + #[test] + fn test_truncate_exact_length() { + assert_eq!(truncate_for_preview("hello", 5), "hello"); + } + + #[test] + fn test_truncate_over_limit() { + let result = truncate_for_preview("hello world, this is long", 10); + assert!(result.ends_with("...")); + // "hello worl" = 10 chars + "..." + assert_eq!(result, "hello worl..."); + } + + #[test] + fn test_truncate_collapses_newlines() { + let result = truncate_for_preview("line1\nline2\nline3", 100); + assert!(!result.contains('\n')); + assert_eq!(result, "line1 line2 line3"); + } + + #[test] + fn test_truncate_collapses_whitespace() { + let result = truncate_for_preview("hello world", 100); + assert_eq!(result, "hello world"); + } + + #[test] + fn test_truncate_multibyte_utf8() { + // Each emoji is 4 bytes. Truncating at char boundary must not panic. + let input = "๐Ÿ˜€๐Ÿ˜๐Ÿ˜‚๐Ÿคฃ๐Ÿ˜ƒ๐Ÿ˜„๐Ÿ˜…๐Ÿ˜†๐Ÿ˜‰๐Ÿ˜Š"; + let result = truncate_for_preview(input, 5); + assert!(result.ends_with("...")); + // First 5 chars = 5 emoji + assert_eq!(result, "๐Ÿ˜€๐Ÿ˜๐Ÿ˜‚๐Ÿคฃ๐Ÿ˜ƒ..."); + } + + #[test] + fn test_truncate_cjk_characters() { + // CJK chars are 3 bytes each in UTF-8. + let input = "ไฝ ๅฅฝไธ–็•Œๆต‹่ฏ•ๆ•ฐๆฎๅพˆ้•ฟ็š„ๅญ—็ฌฆไธฒ"; + let result = truncate_for_preview(input, 4); + assert_eq!(result, "ไฝ ๅฅฝไธ–็•Œ..."); + } + + #[test] + fn test_truncate_mixed_multibyte_and_ascii() { + let input = "hello ไธ–็•Œ foo"; + let result = truncate_for_preview(input, 8); + // 'h','e','l','l','o',' ','ไธ–','็•Œ' = 8 chars + assert_eq!(result, "hello ไธ–็•Œ..."); + } } diff --git a/src/agent/mod.rs b/src/agent/mod.rs index 1455c92c..a667b17d 100644 --- a/src/agent/mod.rs +++ b/src/agent/mod.rs @@ -26,6 +26,7 @@ pub mod task; pub mod undo; pub mod worker; +pub(crate) use agent_loop::truncate_for_preview; pub use agent_loop::{Agent, AgentDeps}; pub use compaction::{CompactionResult, ContextCompactor}; pub use context_monitor::{CompactionStrategy, ContextBreakdown, ContextMonitor}; diff --git a/src/channels/repl.rs b/src/channels/repl.rs index cbfd1c4a..ea91082b 100644 --- a/src/channels/repl.rs +++ b/src/channels/repl.rs @@ -33,9 +33,13 @@ use termimad::MadSkin; use tokio::sync::mpsc; use tokio_stream::wrappers::ReceiverStream; +use crate::agent::truncate_for_preview; use crate::channels::{Channel, IncomingMessage, MessageStream, OutgoingResponse, StatusUpdate}; use crate::error::ChannelError; +/// Max characters for thinking/status messages in the terminal. +const CLI_STATUS_MAX: usize = 200; + /// Slash commands available in the REPL. const SLASH_COMMANDS: &[&str] = &[ "/help", @@ -400,7 +404,8 @@ impl Channel for ReplChannel { match status { StatusUpdate::Thinking(msg) => { - eprintln!(" \x1b[90m\u{25CB} {msg}\x1b[0m"); + let display = truncate_for_preview(&msg, CLI_STATUS_MAX); + eprintln!(" \x1b[90m\u{25CB} {display}\x1b[0m"); } StatusUpdate::ToolStarted { name } => { eprintln!(" \x1b[33m\u{25CB} {name}\x1b[0m"); @@ -438,7 +443,8 @@ impl Channel for ReplChannel { } StatusUpdate::Status(msg) => { if debug || msg.contains("approval") || msg.contains("Approval") { - eprintln!(" \x1b[90m{msg}\x1b[0m"); + let display = truncate_for_preview(&msg, CLI_STATUS_MAX); + eprintln!(" \x1b[90m{display}\x1b[0m"); } } StatusUpdate::ApprovalNeeded { diff --git a/src/lib.rs b/src/lib.rs index 54313777..7185d3f3 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -58,6 +58,7 @@ pub mod secrets; pub mod settings; pub mod setup; pub mod tools; +pub mod tracing_fmt; pub mod util; pub mod worker; pub mod workspace; diff --git a/src/llm/nearai_chat.rs b/src/llm/nearai_chat.rs index 5ca5e95e..13a36a91 100644 --- a/src/llm/nearai_chat.rs +++ b/src/llm/nearai_chat.rs @@ -71,8 +71,9 @@ impl NearAiChatProvider { tracing::debug!("Sending request to NEAR AI Chat: {}", url); - // Log the request body for debugging tool call issues - if let Ok(json) = serde_json::to_string(body) { + if tracing::enabled!(tracing::Level::DEBUG) + && let Ok(json) = serde_json::to_string(body) + { tracing::debug!("NEAR AI Chat request body: {}", json); } diff --git a/src/main.rs b/src/main.rs index 1a933ee6..cc619eb8 100644 --- a/src/main.rs +++ b/src/main.rs @@ -305,7 +305,11 @@ async fn main() -> anyhow::Result<()> { tracing_subscriber::registry() .with(env_filter) - .with(tracing_subscriber::fmt::layer().with_target(false)) + .with( + tracing_subscriber::fmt::layer() + .with_target(false) + .with_writer(ironclaw::tracing_fmt::TruncatingStderr::default()), + ) .with(WebLogLayer::new(Arc::clone(&log_broadcaster))) .init(); diff --git a/src/tracing_fmt.rs b/src/tracing_fmt.rs new file mode 100644 index 00000000..f0d7073a --- /dev/null +++ b/src/tracing_fmt.rs @@ -0,0 +1,319 @@ +//! Truncating terminal writer for tracing. +//! +//! Tracing events from LLM providers can dump 10KB+ JSON bodies to stderr. +//! Rather than truncating at every call site (fragile, easy to miss), we +//! handle it at the writer level: the fmt layer gets a `TruncatingStderr` +//! that caps each event before flushing, while the web gateway `WebLogLayer` +//! still sees the full, untruncated content. +//! +//! ```text +//! tracing::debug!("body: {huge_json}") +//! | +//! v +//! tracing_subscriber::registry() +//! | +//! +-- fmt::layer().with_writer(TruncatingStderr) <-- caps at 500B +//! | \-- stderr (truncated) +//! | +//! \-- WebLogLayer (unchanged) +//! \-- SSE broadcast (full) +//! ``` + +use std::io::{self, Write}; + +use tracing_subscriber::fmt::MakeWriter; + +/// Maximum bytes per tracing event written to the terminal. +const TERMINAL_MAX_EVENT_BYTES: usize = 500; + +/// A `MakeWriter` that creates per-event buffers which truncate on flush. +/// +/// Each call to `make_writer()` returns an `EventBuffer`. All `write()` +/// calls accumulate into the buffer. When the buffer drops (after the fmt +/// layer finishes writing one event), it flushes to stderr, truncating if +/// the total exceeds `TERMINAL_MAX_EVENT_BYTES`. +#[derive(Clone)] +pub struct TruncatingStderr { + max_bytes: usize, +} + +impl Default for TruncatingStderr { + fn default() -> Self { + Self { + max_bytes: TERMINAL_MAX_EVENT_BYTES, + } + } +} + +impl TruncatingStderr { + #[cfg(test)] + fn with_max_bytes(max_bytes: usize) -> Self { + Self { max_bytes } + } +} + +impl<'a> MakeWriter<'a> for TruncatingStderr { + type Writer = EventBuffer; + + fn make_writer(&'a self) -> Self::Writer { + EventBuffer { + buf: Vec::with_capacity(256), + max_bytes: self.max_bytes, + #[cfg(test)] + sink: None, + } + } +} + +/// Per-event buffer that truncates on drop. +pub struct EventBuffer { + buf: Vec, + max_bytes: usize, + /// Test-only: capture output instead of writing to stderr. + #[cfg(test)] + sink: Option>>>, +} + +impl Write for EventBuffer { + fn write(&mut self, data: &[u8]) -> io::Result { + self.buf.extend_from_slice(data); + Ok(data.len()) + } + + fn flush(&mut self) -> io::Result<()> { + Ok(()) + } +} + +/// Find the last valid UTF-8 char boundary at or before `pos` in `bytes`. +/// +/// Walks backwards from `pos` until we find a byte that isn't a UTF-8 +/// continuation byte (0x80..0xBF). Returns 0 if the entire prefix is +/// somehow invalid (shouldn't happen with valid UTF-8 input from tracing). +fn utf8_floor(bytes: &[u8], pos: usize) -> usize { + let mut i = pos; + // UTF-8 continuation bytes have the form 10xxxxxx (0x80..0xBF). + // Walk backwards past them to find the start of the last character. + while i > 0 && bytes[i] & 0xC0 == 0x80 { + i -= 1; + } + i +} + +impl Drop for EventBuffer { + fn drop(&mut self) { + if self.buf.is_empty() { + return; + } + + let output = if self.buf.len() <= self.max_bytes { + &self.buf[..] + } else { + // Truncate at a UTF-8 safe boundary + let cut = utf8_floor(&self.buf, self.max_bytes); + let suffix = format!("...[{}B total]\n", self.buf.len()); + let mut truncated = Vec::with_capacity(cut + suffix.len()); + // Strip trailing newline from the cut portion (we add our own via suffix) + let cut_slice = &self.buf[..cut]; + let trimmed = if cut_slice.last() == Some(&b'\n') { + &cut_slice[..cut_slice.len() - 1] + } else { + cut_slice + }; + truncated.extend_from_slice(trimmed); + truncated.extend_from_slice(suffix.as_bytes()); + + #[cfg(test)] + if let Some(ref sink) = self.sink { + let mut s = sink.lock().expect("test sink lock poisoned"); + s.extend_from_slice(&truncated); + return; + } + + let _ = io::stderr().write_all(&truncated); + return; + }; + + #[cfg(test)] + if let Some(ref sink) = self.sink { + let mut s = sink.lock().expect("test sink lock poisoned"); + s.extend_from_slice(output); + return; + } + + let _ = io::stderr().write_all(output); + } +} + +#[cfg(test)] +mod tests { + use std::sync::{Arc, Mutex}; + + use crate::tracing_fmt::{EventBuffer, TruncatingStderr, utf8_floor}; + + use std::io::Write; + + /// Helper: create an EventBuffer that captures output to a shared Vec + /// instead of writing to stderr. + fn test_buffer(max_bytes: usize) -> (EventBuffer, Arc>>) { + let sink = Arc::new(Mutex::new(Vec::new())); + let buf = EventBuffer { + buf: Vec::new(), + max_bytes, + sink: Some(Arc::clone(&sink)), + }; + (buf, sink) + } + + #[test] + fn test_short_event_not_truncated() { + let (mut buf, sink) = test_buffer(500); + buf.write_all(b"hello world\n").unwrap(); + drop(buf); + + let output = sink.lock().unwrap(); + assert_eq!(&*output, b"hello world\n"); + } + + #[test] + fn test_long_event_truncated() { + let (mut buf, sink) = test_buffer(20); + let data = "abcdefghijklmnopqrstuvwxyz0123456789\n"; + buf.write_all(data.as_bytes()).unwrap(); + let total = data.len(); + drop(buf); + + let output = sink.lock().unwrap(); + let output_str = String::from_utf8_lossy(&output); + // Should contain the suffix with total byte count + assert!( + output_str.contains(&format!("...[{}B total]", total)), + "expected truncation suffix, got: {}", + output_str + ); + // Should be shorter than the original + assert!(output.len() < total); + } + + #[test] + fn test_utf8_boundary_safe() { + // "Helloรฉ" = [72, 101, 108, 108, 111, 195, 169] + // ^-- 2-byte UTF-8 char + // If we truncate at 6 bytes, we'd land in the middle of 'รฉ'. + // utf8_floor should back up to byte 5 (start of 'รฉ' = 195). + let (mut buf, sink) = test_buffer(6); + let data = "Helloรฉ world"; + buf.write_all(data.as_bytes()).unwrap(); + drop(buf); + + let output = sink.lock().unwrap(); + let output_str = String::from_utf8(output.clone()); + assert!( + output_str.is_ok(), + "output should be valid UTF-8, got bytes: {:?}", + &*output + ); + let s = output_str.unwrap(); + assert!( + s.contains("...["), + "should be truncated with suffix, got: {}", + s + ); + // The truncated prefix must be valid UTF-8 up to the cut point. + // "Hello" (5 bytes) is the last valid cut before the 2-byte รฉ. + assert!( + s.starts_with("Hello"), + "should start with 'Hello', got: {}", + s + ); + } + + #[test] + fn test_utf8_floor_basic() { + // ASCII: every byte is a valid boundary + assert_eq!(utf8_floor(b"hello", 3), 3); + + // 2-byte UTF-8 char รฉ = [0xC3, 0xA9] + // Landing on the continuation byte (0xA9) should back up to 0xC3 + let bytes = "Hรฉ".as_bytes(); // [72, 0xC3, 0xA9] + assert_eq!(utf8_floor(bytes, 2), 1); // backs up to start of รฉ + + // 3-byte UTF-8 char (e.g. ใ‚ = [0xE3, 0x81, 0x82]) + let bytes = "aใ‚".as_bytes(); // [97, 0xE3, 0x81, 0x82] + assert_eq!(utf8_floor(bytes, 2), 1); // backs up past continuation to 0xE3 + assert_eq!(utf8_floor(bytes, 3), 1); // same: 0x82 is continuation, 0x81 is too + } + + #[test] + fn test_multiple_writes_accumulated() { + let (mut buf, sink) = test_buffer(500); + buf.write_all(b"hello ").unwrap(); + buf.write_all(b"world\n").unwrap(); + drop(buf); + + let output = sink.lock().unwrap(); + assert_eq!(&*output, b"hello world\n"); + } + + #[test] + fn test_empty_buffer_no_output() { + let (_buf, sink) = test_buffer(500); + // drop without writing + drop(_buf); + + let output = sink.lock().unwrap(); + assert!(output.is_empty()); + } + + #[test] + fn test_default_max_bytes() { + let writer = TruncatingStderr::default(); + assert_eq!(writer.max_bytes, 500); + } + + #[test] + fn test_custom_max_bytes() { + let writer = TruncatingStderr::with_max_bytes(100); + assert_eq!(writer.max_bytes, 100); + } + + #[test] + fn test_exactly_at_limit_not_truncated() { + let (mut buf, sink) = test_buffer(5); + buf.write_all(b"hello").unwrap(); + drop(buf); + + let output = sink.lock().unwrap(); + assert_eq!(&*output, b"hello"); + } + + #[test] + fn test_one_over_limit_truncated() { + let (mut buf, sink) = test_buffer(5); + buf.write_all(b"hello!").unwrap(); + drop(buf); + + let output = sink.lock().unwrap(); + let s = String::from_utf8_lossy(&output); + assert!(s.contains("...[6B total]"), "got: {}", s); + } + + #[test] + fn test_4byte_utf8_boundary() { + // 4-byte UTF-8 char: ๐„ž (musical symbol) = [0xF0, 0x9D, 0x84, 0x9E] + let data = "AB๐„žCD"; + // bytes: [65, 66, 0xF0, 0x9D, 0x84, 0x9E, 67, 68] + // Truncating at byte 4 lands in the middle of the 4-byte char + let (mut buf, sink) = test_buffer(4); + buf.write_all(data.as_bytes()).unwrap(); + drop(buf); + + let output = sink.lock().unwrap(); + let s = String::from_utf8(output.clone()); + assert!(s.is_ok(), "output must be valid UTF-8, got: {:?}", &*output); + let s = s.unwrap(); + // Should back up to byte 2 (just "AB"), since bytes 2..5 are all part of ๐„ž + assert!(s.starts_with("AB"), "expected 'AB', got: {}", s); + assert!(s.contains("...["), "should be truncated, got: {}", s); + } +}