klafs_api/
debug.rs

1//! Debug logging for HTTP traffic
2//!
3//! This module provides utilities for capturing and logging HTTP request/response
4//! traffic for debugging purposes.
5
6use std::path::PathBuf;
7use std::sync::atomic::{AtomicBool, Ordering};
8use std::sync::Arc;
9use std::time::Instant;
10use tokio::sync::RwLock;
11use tracing::{debug, trace};
12
13/// Configuration for debug logging
14#[derive(Debug, Clone)]
15pub struct DebugConfig {
16    /// Whether debug logging is enabled
17    pub enabled: bool,
18    /// Optional file path to write debug logs
19    pub log_file: Option<PathBuf>,
20    /// Whether to log request/response bodies
21    pub log_bodies: bool,
22    /// Whether to redact sensitive information (passwords, tokens)
23    pub redact_sensitive: bool,
24}
25
26impl Default for DebugConfig {
27    fn default() -> Self {
28        Self {
29            enabled: false,
30            log_file: None,
31            log_bodies: true,
32            redact_sensitive: true,
33        }
34    }
35}
36
37impl DebugConfig {
38    /// Create a new debug config with logging enabled
39    pub fn enabled() -> Self {
40        Self {
41            enabled: true,
42            ..Default::default()
43        }
44    }
45
46    /// Enable logging to a file
47    pub fn with_log_file(mut self, path: PathBuf) -> Self {
48        self.log_file = Some(path);
49        self
50    }
51
52    /// Disable body logging
53    pub fn without_bodies(mut self) -> Self {
54        self.log_bodies = false;
55        self
56    }
57
58    /// Disable sensitive data redaction (use with caution!)
59    pub fn without_redaction(mut self) -> Self {
60        self.redact_sensitive = false;
61        self
62    }
63}
64
65/// HTTP traffic logger
66#[derive(Debug)]
67pub struct HttpDebugger {
68    config: DebugConfig,
69    enabled: AtomicBool,
70    log_buffer: Arc<RwLock<Vec<TrafficEntry>>>,
71}
72
73/// A single HTTP traffic entry
74#[derive(Debug, Clone)]
75pub struct TrafficEntry {
76    /// Unique request ID
77    pub request_id: String,
78    /// Timestamp
79    pub timestamp: chrono::DateTime<chrono::Utc>,
80    /// Request method
81    pub method: String,
82    /// Request URL
83    pub url: String,
84    /// Request headers (redacted if configured)
85    pub request_headers: Vec<(String, String)>,
86    /// Request body (redacted if configured)
87    pub request_body: Option<String>,
88    /// Response status code
89    pub response_status: Option<u16>,
90    /// Response headers
91    pub response_headers: Vec<(String, String)>,
92    /// Response body
93    pub response_body: Option<String>,
94    /// Request duration in milliseconds
95    pub duration_ms: Option<u64>,
96    /// Any error that occurred
97    pub error: Option<String>,
98}
99
100impl TrafficEntry {
101    /// Create a new traffic entry for a request
102    pub fn new(method: &str, url: &str) -> Self {
103        Self {
104            request_id: uuid::Uuid::new_v4().to_string(),
105            timestamp: chrono::Utc::now(),
106            method: method.to_string(),
107            url: url.to_string(),
108            request_headers: Vec::new(),
109            request_body: None,
110            response_status: None,
111            response_headers: Vec::new(),
112            response_body: None,
113            duration_ms: None,
114            error: None,
115        }
116    }
117
118    /// Format as a debug string
119    pub fn format(&self) -> String {
120        let mut output = String::new();
121
122        output.push_str(&format!(
123            "\n{}\n[{}] {} {}\nRequest ID: {}\n",
124            "=".repeat(60),
125            self.timestamp.format("%Y-%m-%d %H:%M:%S%.3f UTC"),
126            self.method,
127            self.url,
128            self.request_id
129        ));
130
131        if !self.request_headers.is_empty() {
132            output.push_str("\n--- Request Headers ---\n");
133            for (key, value) in &self.request_headers {
134                output.push_str(&format!("{}: {}\n", key, value));
135            }
136        }
137
138        if let Some(ref body) = self.request_body {
139            output.push_str("\n--- Request Body ---\n");
140            output.push_str(body);
141            output.push('\n');
142        }
143
144        if let Some(status) = self.response_status {
145            output.push_str(&format!("\n--- Response Status: {} ---\n", status));
146        }
147
148        if !self.response_headers.is_empty() {
149            output.push_str("\n--- Response Headers ---\n");
150            for (key, value) in &self.response_headers {
151                output.push_str(&format!("{}: {}\n", key, value));
152            }
153        }
154
155        if let Some(ref body) = self.response_body {
156            output.push_str("\n--- Response Body ---\n");
157            // Try to pretty-print JSON
158            if let Ok(json) = serde_json::from_str::<serde_json::Value>(body) {
159                if let Ok(pretty) = serde_json::to_string_pretty(&json) {
160                    output.push_str(&pretty);
161                } else {
162                    output.push_str(body);
163                }
164            } else {
165                // Only truncate extremely long HTML responses (>500KB)
166                if body.len() > 500000 {
167                    output.push_str(&body[..500000]);
168                    output.push_str(&format!("\n... [truncated, {} bytes total]", body.len()));
169                } else {
170                    output.push_str(body);
171                }
172            }
173            output.push('\n');
174        }
175
176        if let Some(duration) = self.duration_ms {
177            output.push_str(&format!("\nDuration: {}ms\n", duration));
178        }
179
180        if let Some(ref error) = self.error {
181            output.push_str(&format!("\n!!! Error: {} !!!\n", error));
182        }
183
184        output.push_str(&"=".repeat(60));
185        output.push('\n');
186
187        output
188    }
189}
190
191impl Default for HttpDebugger {
192    fn default() -> Self {
193        Self::new(DebugConfig::default())
194    }
195}
196
197impl HttpDebugger {
198    /// Create a new HTTP debugger with the given configuration
199    pub fn new(config: DebugConfig) -> Self {
200        let enabled = config.enabled;
201        Self {
202            config,
203            enabled: AtomicBool::new(enabled),
204            log_buffer: Arc::new(RwLock::new(Vec::new())),
205        }
206    }
207
208    /// Check if debugging is enabled
209    pub fn is_enabled(&self) -> bool {
210        self.enabled.load(Ordering::Relaxed)
211    }
212
213    /// Enable debugging at runtime
214    pub fn enable(&self) {
215        self.enabled.store(true, Ordering::Relaxed);
216    }
217
218    /// Disable debugging at runtime
219    pub fn disable(&self) {
220        self.enabled.store(false, Ordering::Relaxed);
221    }
222
223    /// Log a request (before sending)
224    pub async fn log_request(
225        &self,
226        method: &str,
227        url: &str,
228        headers: &reqwest::header::HeaderMap,
229        body: Option<&str>,
230    ) -> String {
231        let mut entry = TrafficEntry::new(method, url);
232
233        // Capture headers
234        for (key, value) in headers.iter() {
235            let value_str = value.to_str().unwrap_or("<binary>").to_string();
236            let value_str = if self.config.redact_sensitive {
237                self.redact_header(key.as_str(), &value_str)
238            } else {
239                value_str
240            };
241            entry.request_headers.push((key.to_string(), value_str));
242        }
243
244        // Capture body
245        if self.config.log_bodies {
246            if let Some(body) = body {
247                entry.request_body = Some(if self.config.redact_sensitive {
248                    self.redact_body(body)
249                } else {
250                    body.to_string()
251                });
252            }
253        }
254
255        let request_id = entry.request_id.clone();
256
257        if self.is_enabled() {
258            debug!(
259                request_id = %entry.request_id,
260                method = %entry.method,
261                url = %entry.url,
262                "HTTP Request"
263            );
264            trace!("Request details:\n{}", entry.format());
265        }
266
267        // Store in buffer
268        self.log_buffer.write().await.push(entry);
269
270        request_id
271    }
272
273    /// Log a response
274    pub async fn log_response(
275        &self,
276        request_id: &str,
277        status: u16,
278        headers: &reqwest::header::HeaderMap,
279        body: Option<&str>,
280        duration_ms: u64,
281    ) {
282        let mut buffer = self.log_buffer.write().await;
283
284        if let Some(entry) = buffer.iter_mut().find(|e| e.request_id == request_id) {
285            entry.response_status = Some(status);
286            entry.duration_ms = Some(duration_ms);
287
288            // Capture response headers (with redaction if enabled)
289            for (key, value) in headers.iter() {
290                let value_str = value.to_str().unwrap_or("<binary>").to_string();
291                let value_str = if self.config.redact_sensitive {
292                    self.redact_header(key.as_str(), &value_str)
293                } else {
294                    value_str
295                };
296                entry.response_headers.push((key.to_string(), value_str));
297            }
298
299            // Capture response body (with redaction if enabled)
300            if self.config.log_bodies {
301                if let Some(body) = body {
302                    entry.response_body = Some(if self.config.redact_sensitive {
303                        self.redact_body(body)
304                    } else {
305                        body.to_string()
306                    });
307                }
308            }
309
310            if self.is_enabled() {
311                debug!(
312                    request_id = %request_id,
313                    status = status,
314                    duration_ms = duration_ms,
315                    "HTTP Response"
316                );
317                trace!("Response details:\n{}", entry.format());
318            }
319
320            // Write to file if configured
321            if let Some(ref path) = self.config.log_file {
322                if let Err(e) = self.write_to_file(path, &entry.format()).await {
323                    tracing::warn!("Failed to write debug log to file: {}", e);
324                }
325            }
326        }
327    }
328
329    /// Log an error
330    pub async fn log_error(&self, request_id: &str, error: &str) {
331        let mut buffer = self.log_buffer.write().await;
332
333        if let Some(entry) = buffer.iter_mut().find(|e| e.request_id == request_id) {
334            entry.error = Some(error.to_string());
335
336            if self.is_enabled() {
337                debug!(
338                    request_id = %request_id,
339                    error = %error,
340                    "HTTP Error"
341                );
342            }
343        }
344    }
345
346    /// Get all captured traffic entries
347    pub async fn get_traffic(&self) -> Vec<TrafficEntry> {
348        self.log_buffer.read().await.clone()
349    }
350
351    /// Clear the traffic buffer
352    pub async fn clear(&self) {
353        self.log_buffer.write().await.clear();
354    }
355
356    /// Export all traffic to a string
357    pub async fn export(&self) -> String {
358        let buffer = self.log_buffer.read().await;
359        buffer
360            .iter()
361            .map(|e| e.format())
362            .collect::<Vec<_>>()
363            .join("\n")
364    }
365
366    /// Redact sensitive header values
367    fn redact_header(&self, key: &str, value: &str) -> String {
368        let key_lower = key.to_lowercase();
369        if key_lower.contains("authorization")
370            || key_lower.contains("cookie")
371            || key_lower.contains("token")
372            || key_lower.contains("auth")
373        {
374            if value.len() > 10 {
375                format!("{}...REDACTED", &value[..5])
376            } else {
377                "REDACTED".to_string()
378            }
379        } else {
380            value.to_string()
381        }
382    }
383
384    /// Redact sensitive body content
385    fn redact_body(&self, body: &str) -> String {
386        // Try to parse as form data or JSON and redact password fields
387        if body.contains("Password=") {
388            // Form-encoded
389            body.split('&')
390                .map(|pair| {
391                    if pair.to_lowercase().starts_with("password=") {
392                        "Password=REDACTED"
393                    } else {
394                        pair
395                    }
396                })
397                .collect::<Vec<_>>()
398                .join("&")
399        } else if let Ok(mut json) = serde_json::from_str::<serde_json::Value>(body) {
400            // JSON
401            Self::redact_json_passwords(&mut json);
402            serde_json::to_string(&json).unwrap_or_else(|_| body.to_string())
403        } else {
404            body.to_string()
405        }
406    }
407
408    /// Recursively redact password fields in JSON
409    fn redact_json_passwords(value: &mut serde_json::Value) {
410        match value {
411            serde_json::Value::Object(map) => {
412                for (key, val) in map.iter_mut() {
413                    let key_lower = key.to_lowercase();
414                    if key_lower.contains("password")
415                        || key_lower.contains("secret")
416                        || key_lower.contains("token")
417                        || key_lower == "pin"
418                    {
419                        *val = serde_json::Value::String("REDACTED".to_string());
420                    } else {
421                        Self::redact_json_passwords(val);
422                    }
423                }
424            }
425            serde_json::Value::Array(arr) => {
426                for item in arr.iter_mut() {
427                    Self::redact_json_passwords(item);
428                }
429            }
430            _ => {}
431        }
432    }
433
434    /// Write to log file
435    async fn write_to_file(&self, path: &PathBuf, content: &str) -> std::io::Result<()> {
436        use tokio::io::AsyncWriteExt;
437        let mut file = tokio::fs::OpenOptions::new()
438            .create(true)
439            .append(true)
440            .open(path)
441            .await?;
442        file.write_all(content.as_bytes()).await?;
443        file.write_all(b"\n").await?;
444        Ok(())
445    }
446}
447
448/// Helper for timing operations
449pub struct Timer {
450    start: Instant,
451}
452
453impl Timer {
454    /// Start a new timer
455    pub fn start() -> Self {
456        Self {
457            start: Instant::now(),
458        }
459    }
460
461    /// Get elapsed time in milliseconds
462    pub fn elapsed_ms(&self) -> u64 {
463        self.start.elapsed().as_millis() as u64
464    }
465}
466
467#[cfg(test)]
468mod tests {
469    use super::*;
470
471    #[test]
472    fn test_redact_body_form() {
473        let debugger = HttpDebugger::new(DebugConfig::enabled());
474        let body = "UserName=test@example.com&Password=secret123&Remember=true";
475        let redacted = debugger.redact_body(body);
476        assert!(redacted.contains("Password=REDACTED"));
477        assert!(redacted.contains("UserName=test@example.com"));
478    }
479
480    #[test]
481    fn test_redact_body_json() {
482        let debugger = HttpDebugger::new(DebugConfig::enabled());
483        let body = r#"{"username":"test","password":"secret","pin":"1234"}"#;
484        let redacted = debugger.redact_body(body);
485        assert!(redacted.contains("REDACTED"));
486        assert!(!redacted.contains("secret"));
487        assert!(!redacted.contains("1234"));
488    }
489
490    #[test]
491    fn test_redact_header() {
492        let debugger = HttpDebugger::new(DebugConfig::enabled());
493
494        let cookie = debugger.redact_header("Cookie", ".ASPXAUTH=verylongtokenvalue");
495        assert!(cookie.contains("REDACTED"));
496
497        let content_type = debugger.redact_header("Content-Type", "application/json");
498        assert_eq!(content_type, "application/json");
499    }
500}