git_iris/agents/
debug.rs

1//! Debug observability module for Iris agent operations
2//!
3//! All debug output goes through tracing. Use `-l <file>` to log to file,
4//! `--debug` to enable debug-level output.
5
6use std::fs::{self, OpenOptions};
7use std::io::{self, Write};
8use std::path::PathBuf;
9use std::sync::atomic::{AtomicBool, Ordering};
10use std::time::{Duration, Instant};
11
12#[cfg(unix)]
13use std::os::unix::fs::{OpenOptionsExt, PermissionsExt};
14
15const DEBUG_DIR_ENV: &str = "GIT_IRIS_DEBUG_DIR";
16
17/// Global debug mode flag
18static DEBUG_MODE: AtomicBool = AtomicBool::new(false);
19
20/// Enable debug mode
21pub fn enable_debug_mode() {
22    DEBUG_MODE.store(true, Ordering::SeqCst);
23}
24
25/// Disable debug mode
26pub fn disable_debug_mode() {
27    DEBUG_MODE.store(false, Ordering::SeqCst);
28}
29
30/// Check if debug mode is enabled
31pub fn is_debug_enabled() -> bool {
32    DEBUG_MODE.load(Ordering::SeqCst)
33}
34
35/// Resolve the directory used for storing debug artifacts (LLM dumps, extracted JSON)
36fn debug_artifacts_dir() -> io::Result<PathBuf> {
37    let base = std::env::var_os(DEBUG_DIR_ENV)
38        .map(PathBuf::from)
39        .or_else(|| {
40            dirs::cache_dir().map(|mut dir| {
41                dir.push("git-iris");
42                dir.push("debug-artifacts");
43                dir
44            })
45        })
46        .unwrap_or_else(|| {
47            std::env::temp_dir()
48                .join("git-iris")
49                .join("debug-artifacts")
50        });
51
52    if !base.exists() {
53        fs::create_dir_all(&base)?;
54    }
55
56    #[cfg(unix)]
57    {
58        let _ = fs::set_permissions(&base, fs::Permissions::from_mode(0o700));
59    }
60
61    Ok(base)
62}
63
64/// Write debug artifact with restrictive permissions and return the file path.
65///
66/// # Errors
67///
68/// Returns an error when the artifact directory or file cannot be created.
69pub fn write_debug_artifact(filename: &str, contents: &str) -> io::Result<PathBuf> {
70    let mut path = debug_artifacts_dir()?;
71    path.push(filename);
72
73    write_secure_file(&path, contents)?;
74    Ok(path)
75}
76
77fn write_secure_file(path: &PathBuf, contents: &str) -> io::Result<()> {
78    #[cfg(unix)]
79    {
80        let mut options = OpenOptions::new();
81        options.write(true).create(true).truncate(true).mode(0o600);
82        let mut file = options.open(path)?;
83        file.write_all(contents.as_bytes())?;
84        Ok(())
85    }
86
87    #[cfg(not(unix))]
88    {
89        let mut file = OpenOptions::new()
90            .write(true)
91            .create(true)
92            .truncate(true)
93            .open(path)?;
94        file.write_all(contents.as_bytes())
95    }
96}
97
98/// Format duration in a human-readable way
99fn format_duration(duration: Duration) -> String {
100    if duration.as_secs() > 0 {
101        format!("{:.2}s", duration.as_secs_f64())
102    } else if duration.as_millis() > 0 {
103        format!("{}ms", duration.as_millis())
104    } else {
105        format!("{}μs", duration.as_micros())
106    }
107}
108
109/// Safely truncate a string at a character boundary
110fn truncate_at_char_boundary(s: &str, max_bytes: usize) -> &str {
111    if s.len() <= max_bytes {
112        return s;
113    }
114    let mut end = max_bytes;
115    while end > 0 && !s.is_char_boundary(end) {
116        end -= 1;
117    }
118    &s[..end]
119}
120
121/// Print a debug header
122pub fn debug_header(title: &str) {
123    if !is_debug_enabled() {
124        return;
125    }
126    tracing::debug!(target: "iris", "══════════════════════════════════════════════════════════════════════════════");
127    tracing::debug!(target: "iris", "◆ {} ◆", title);
128    tracing::debug!(target: "iris", "══════════════════════════════════════════════════════════════════════════════");
129}
130
131/// Print a debug section
132pub fn debug_section(title: &str) {
133    if !is_debug_enabled() {
134        return;
135    }
136    tracing::debug!(target: "iris", "▸ {}", title);
137    tracing::debug!(target: "iris", "──────────────────────────────────────────────────────────────────────────────");
138}
139
140/// Print tool call information
141pub fn debug_tool_call(tool_name: &str, args: &str) {
142    if !is_debug_enabled() {
143        return;
144    }
145
146    tracing::debug!(target: "iris", "🔧 Tool Call: {}", tool_name);
147
148    if !args.is_empty() {
149        let truncated = if args.len() > 200 {
150            format!("{}...", truncate_at_char_boundary(args, 200))
151        } else {
152            args.to_string()
153        };
154        tracing::debug!(target: "iris", "   Args: {}", truncated);
155    }
156}
157
158/// Print tool response information
159pub fn debug_tool_response(tool_name: &str, response: &str, duration: Duration) {
160    if !is_debug_enabled() {
161        return;
162    }
163
164    let truncated = if response.len() > 500 {
165        format!("{}...", truncate_at_char_boundary(response, 500))
166    } else {
167        response.to_string()
168    };
169
170    tracing::debug!(target: "iris", "✓ Tool Response: {} ({})", tool_name, format_duration(duration));
171    tracing::debug!(target: "iris", "   {}", truncated);
172}
173
174/// Print LLM request information
175pub fn debug_llm_request(prompt: &str, max_tokens: Option<usize>) {
176    if !is_debug_enabled() {
177        return;
178    }
179
180    tracing::debug!(target: "iris", "🧠 LLM Request: {} chars, {} words {}",
181        prompt.chars().count(),
182        prompt.split_whitespace().count(),
183        max_tokens.map(|t| format!("(max {} tokens)", t)).unwrap_or_default()
184    );
185
186    trace_prompt_preview(prompt);
187
188    if let Ok(path) = write_debug_artifact("iris_last_prompt.txt", prompt) {
189        tracing::debug!(target: "iris", "   Full prompt saved to: {}", path.display());
190    }
191}
192
193/// Print streaming chunk
194pub fn debug_stream_chunk(_chunk: &str, chunk_number: usize) {
195    if !is_debug_enabled() {
196        return;
197    }
198
199    // Only print every 10th chunk to avoid overwhelming output
200    if chunk_number.is_multiple_of(10) {
201        tracing::debug!(target: "iris", "▹ chunk #{}", chunk_number);
202    }
203}
204
205/// Print complete LLM response
206pub fn debug_llm_response(response: &str, duration: Duration, tokens_used: Option<usize>) {
207    if !is_debug_enabled() {
208        return;
209    }
210
211    trace_response_summary(response, duration);
212    trace_response_tokens(tokens_used);
213    trace_response_artifact(response);
214    trace_response_lines(response);
215}
216
217fn trace_response_summary(response: &str, duration: Duration) {
218    tracing::debug!(target: "iris", "✨ LLM Response: {} chars, {} words ({})",
219        response.chars().count(),
220        response.split_whitespace().count(),
221        format_duration(duration)
222    );
223}
224
225fn trace_response_tokens(tokens_used: Option<usize>) {
226    if let Some(tokens) = tokens_used {
227        tracing::debug!(target: "iris", "   Tokens: {}", tokens);
228    }
229}
230
231fn trace_response_artifact(response: &str) {
232    if let Ok(path) = write_debug_artifact("iris_last_response.txt", response) {
233        tracing::debug!(target: "iris", "   Full response saved to: {}", path.display());
234    }
235}
236
237fn trace_response_lines(response: &str) {
238    for line in truncated_response(response).lines() {
239        tracing::debug!(target: "iris", "{}", line);
240    }
241}
242
243/// Print JSON parsing attempt
244pub fn debug_json_parse_attempt(json_str: &str) {
245    if !is_debug_enabled() {
246        return;
247    }
248
249    tracing::debug!(target: "iris", "📝 JSON Parse Attempt: {} chars", json_str.len());
250    tracing::debug!(target: "iris", "{}", truncated_line(json_str, 500));
251
252    if json_str.len() > 700 {
253        trace_json_tail(json_str);
254    }
255}
256
257fn trace_prompt_preview(prompt: &str) {
258    for line in prompt.lines().take(5) {
259        tracing::debug!(target: "iris", "   {}", truncated_line(line, 120));
260    }
261
262    let line_count = prompt.lines().count();
263    if line_count > 5 {
264        tracing::debug!(target: "iris", "   ... ({} more lines)", line_count - 5);
265    }
266}
267
268fn truncated_line(line: &str, max_len: usize) -> String {
269    if line.len() > max_len {
270        format!("{}...", truncate_at_char_boundary(line, max_len))
271    } else {
272        line.to_string()
273    }
274}
275
276fn truncated_response(response: &str) -> String {
277    if response.len() > 1000 {
278        format!(
279            "{}...\n\n... ({} more characters)",
280            truncate_at_char_boundary(response, 1000),
281            response.len() - 1000
282        )
283    } else {
284        response.to_string()
285    }
286}
287
288fn trace_json_tail(json_str: &str) {
289    tracing::debug!(target: "iris", "... truncated ...");
290    let mut tail_start = json_str.len().saturating_sub(200);
291    while tail_start < json_str.len() && !json_str.is_char_boundary(tail_start) {
292        tail_start += 1;
293    }
294    tracing::debug!(target: "iris", "{}", &json_str[tail_start..]);
295}
296
297/// Print JSON parse success
298pub fn debug_json_parse_success(type_name: &str) {
299    if !is_debug_enabled() {
300        return;
301    }
302    tracing::debug!(target: "iris", "✓ JSON Parsed: {}", type_name);
303}
304
305/// Print JSON parse error
306pub fn debug_json_parse_error(error: &str) {
307    if !is_debug_enabled() {
308        return;
309    }
310    tracing::warn!(target: "iris", "✗ JSON Parse Error: {}", error);
311}
312
313/// Print context management decision
314pub fn debug_context_management(action: &str, details: &str) {
315    if !is_debug_enabled() {
316        return;
317    }
318    tracing::debug!(target: "iris", "🔍 {} {}", action, details);
319}
320
321/// Print an error
322pub fn debug_error(error: &str) {
323    if !is_debug_enabled() {
324        return;
325    }
326    tracing::error!(target: "iris", "✗ Error: {}", error);
327}
328
329/// Print a warning
330pub fn debug_warning(warning: &str) {
331    if !is_debug_enabled() {
332        return;
333    }
334    tracing::warn!(target: "iris", "⚠ {}", warning);
335}
336
337/// Print agent phase change
338pub fn debug_phase_change(phase: &str) {
339    if !is_debug_enabled() {
340        return;
341    }
342    tracing::debug!(target: "iris", "◆ {}", phase);
343    tracing::debug!(target: "iris", "──────────────────────────────────────────────────────────────────────────────");
344}
345
346/// Timer for measuring operation duration
347pub struct DebugTimer {
348    start: Instant,
349    operation: String,
350}
351
352impl DebugTimer {
353    pub fn start(operation: &str) -> Self {
354        if is_debug_enabled() {
355            tracing::debug!(target: "iris", "⏱ Started: {}", operation);
356        }
357
358        Self {
359            start: Instant::now(),
360            operation: operation.to_string(),
361        }
362    }
363
364    pub fn finish(self) {
365        if is_debug_enabled() {
366            let duration = self.start.elapsed();
367            tracing::debug!(target: "iris", "✓ Completed: {} ({})", self.operation, format_duration(duration));
368        }
369    }
370}
git_iris/agents/debug.rs

git_iris/agents/
debug.rs
