elif_http/middleware/core/
enhanced_logging.rs

1//! # Enhanced Logging Middleware
2//!
3//! Production-ready logging middleware with structured logging, correlation IDs, 
4//! and request tracing using V2 middleware system.
5
6use std::time::{Instant, Duration};
7use std::collections::HashMap;
8use uuid::Uuid;
9
10use tracing::{info, warn, error};
11use serde_json::{json, Value};
12
13use crate::{
14    middleware::v2::{Middleware, Next, NextFuture},
15    request::ElifRequest,
16};
17
18/// Enhanced logging middleware with structured logging and request tracing
19#[derive(Debug, Clone)]
20pub struct EnhancedLoggingMiddleware {
21    config: LoggingConfig,
22}
23
24/// Configuration for enhanced logging middleware  
25#[derive(Debug, Clone)]
26pub struct LoggingConfig {
27    /// Enable structured JSON logging
28    pub structured: bool,
29    /// Log request body (be careful with sensitive data)
30    pub log_request_body: bool,
31    /// Log response body (be careful with sensitive data) 
32    pub log_response_body: bool,
33    /// Log request headers (sensitive headers are always filtered)
34    pub log_request_headers: bool,
35    /// Log response headers
36    pub log_response_headers: bool,
37    /// Enable request correlation ID tracking
38    pub correlation_ids: bool,
39    /// Enable request tracing spans
40    pub tracing_spans: bool,
41    /// Slow request threshold (requests slower than this will be logged as warnings)
42    pub slow_request_threshold: Duration,
43    /// Custom header name for correlation ID (defaults to "X-Correlation-ID")
44    pub correlation_header: String,
45    /// Additional custom fields to include in structured logs
46    pub custom_fields: HashMap<String, String>,
47}
48
49impl Default for LoggingConfig {
50    fn default() -> Self {
51        Self {
52            structured: true,
53            log_request_body: false,
54            log_response_body: false,
55            log_request_headers: true,
56            log_response_headers: false,
57            correlation_ids: true,
58            tracing_spans: true,
59            slow_request_threshold: Duration::from_millis(1000),
60            correlation_header: "X-Correlation-ID".to_string(),
61            custom_fields: HashMap::new(),
62        }
63    }
64}
65
66/// Request context for enhanced logging
67#[derive(Debug, Clone)]
68pub struct RequestContext {
69    pub correlation_id: String,
70    pub start_time: Instant,
71    pub method: String,
72    pub path: String,
73    pub user_agent: Option<String>,
74    pub remote_addr: Option<String>,
75}
76
77impl EnhancedLoggingMiddleware {
78    /// Create new enhanced logging middleware with default configuration
79    pub fn new() -> Self {
80        Self {
81            config: LoggingConfig::default(),
82        }
83    }
84    
85    /// Create with custom configuration
86    pub fn with_config(config: LoggingConfig) -> Self {
87        Self { config }
88    }
89    
90    /// Builder pattern: Enable structured JSON logging
91    pub fn structured(mut self, enabled: bool) -> Self {
92        self.config.structured = enabled;
93        self
94    }
95    
96    /// Builder pattern: Enable request body logging
97    pub fn log_request_body(mut self, enabled: bool) -> Self {
98        self.config.log_request_body = enabled;
99        self
100    }
101    
102    /// Builder pattern: Enable response body logging
103    pub fn log_response_body(mut self, enabled: bool) -> Self {
104        self.config.log_response_body = enabled;
105        self
106    }
107    
108    /// Builder pattern: Enable correlation ID tracking
109    pub fn correlation_ids(mut self, enabled: bool) -> Self {
110        self.config.correlation_ids = enabled;
111        self
112    }
113    
114    /// Builder pattern: Set slow request threshold
115    pub fn slow_request_threshold(mut self, threshold: Duration) -> Self {
116        self.config.slow_request_threshold = threshold;
117        self
118    }
119    
120    /// Builder pattern: Enable request header logging
121    pub fn log_request_headers(mut self, enabled: bool) -> Self {
122        self.config.log_request_headers = enabled;
123        self
124    }
125    
126    /// Builder pattern: Add custom field for structured logging
127    pub fn with_custom_field<K, V>(mut self, key: K, value: V) -> Self 
128    where
129        K: Into<String>,
130        V: Into<String>,
131    {
132        self.config.custom_fields.insert(key.into(), value.into());
133        self
134    }
135}
136
137impl Default for EnhancedLoggingMiddleware {
138    fn default() -> Self {
139        Self::new()
140    }
141}
142
143impl Middleware for EnhancedLoggingMiddleware {
144    fn handle(&self, mut request: ElifRequest, next: Next) -> NextFuture<'static> {
145        let config = self.config.clone();
146        Box::pin(async move {
147            let context = {
148                let correlation_id = if !config.correlation_ids {
149                    "disabled".to_string()
150                } else {
151                    // Try to get existing correlation ID from headers
152                    if let Some(header_value) = request.headers.get_str(&config.correlation_header) {
153                        if let Ok(correlation_id) = header_value.to_str() {
154                            if !correlation_id.is_empty() && correlation_id.len() <= 64 {
155                                correlation_id.to_string()
156                            } else {
157                                Uuid::new_v4().to_string()
158                            }
159                        } else {
160                            Uuid::new_v4().to_string()
161                        }
162                    } else {
163                        Uuid::new_v4().to_string()
164                    }
165                };
166                
167                let method = request.method.to_string();
168                let path = request.uri.path().to_string();
169                
170                let user_agent = request.headers
171                    .get_str("user-agent")
172                    .and_then(|h| h.to_str().ok())
173                    .map(String::from);
174                
175                let remote_addr = request.headers
176                    .get_str("x-forwarded-for")
177                    .or_else(|| request.headers.get_str("x-real-ip"))
178                    .and_then(|h| h.to_str().ok())
179                    .map(String::from);
180                
181                RequestContext {
182                    correlation_id,
183                    start_time: Instant::now(),
184                    method,
185                    path,
186                    user_agent,
187                    remote_addr,
188                }
189            };
190            
191            // Log the incoming request
192            if config.structured {
193                let mut log_data = json!({
194                    "event": "request_start",
195                    "correlation_id": context.correlation_id,
196                    "method": context.method,
197                    "path": context.path,
198                    "user_agent": context.user_agent,
199                    "remote_addr": context.remote_addr,
200                    "timestamp": chrono::Utc::now().to_rfc3339(),
201                });
202                
203                // Add custom fields
204                for (key, value) in &config.custom_fields {
205                    log_data[key] = Value::String(value.clone());
206                }
207                
208                // Add headers if enabled
209                if config.log_request_headers {
210                    let mut headers = HashMap::new();
211                    for name in request.headers.keys() {
212                        if let Some(value) = request.headers.get_str(name.as_str()) {
213                            if let Ok(value_str) = value.to_str() {
214                                if !is_sensitive_header(name.as_str()) {
215                                    headers.insert(name.as_str().to_string(), value_str.to_string());
216                                } else {
217                                    headers.insert(name.as_str().to_string(), "[REDACTED]".to_string());
218                                }
219                            }
220                        }
221                    }
222                    log_data["headers"] = json!(headers);
223                }
224                
225                info!(target: "elif::http::request", "{}", log_data);
226            } else {
227                info!(
228                    "→ {} {} [{}] from {}",
229                    context.method,
230                    context.path,
231                    context.correlation_id,
232                    context.remote_addr.as_deref().unwrap_or("unknown")
233                );
234            }
235            
236            // Add correlation ID header for response processing
237            if config.correlation_ids && context.correlation_id != "disabled" {
238                if let Err(e) = request.headers.add_header("x-elif-correlation-id", &context.correlation_id) {
239                    warn!("Failed to add correlation ID header: {}", e);
240                }
241            }
242            
243            // Continue to next middleware/handler
244            let mut response = next.run(request).await;
245            
246            // Calculate duration and log response
247            let duration = context.start_time.elapsed();
248            let status = response.status_code();
249            let duration_ms = duration.as_millis();
250            
251            let is_slow = duration > config.slow_request_threshold;
252            let is_error = status.is_client_error() || status.is_server_error();
253            
254            if config.structured {
255                let mut log_data = json!({
256                    "event": "request_complete",
257                    "correlation_id": context.correlation_id,
258                    "method": context.method,
259                    "path": context.path,
260                    "status_code": status.as_u16(),
261                    "duration_ms": duration_ms,
262                    "is_slow": is_slow,
263                    "is_error": is_error,
264                    "user_agent": context.user_agent,
265                    "remote_addr": context.remote_addr,
266                    "timestamp": chrono::Utc::now().to_rfc3339(),
267                });
268                
269                // Add custom fields
270                for (key, value) in &config.custom_fields {
271                    log_data[key] = Value::String(value.clone());
272                }
273                
274                // Add response headers if enabled
275                if config.log_response_headers {
276                    let mut headers = HashMap::new();
277                    for (name, value) in response.headers().iter() {
278                        if let Ok(value_str) = value.to_str() {
279                            headers.insert(name.as_str().to_string(), value_str.to_string());
280                        }
281                    }
282                    log_data["response_headers"] = json!(headers);
283                }
284                
285                // Log at appropriate level
286                if is_error {
287                    error!(target: "elif::http::response", "{}", log_data);
288                } else if is_slow {
289                    warn!(target: "elif::http::response", "Slow request: {}", log_data);
290                } else {
291                    info!(target: "elif::http::response", "{}", log_data);
292                }
293            } else {
294                let log_msg = format!(
295                    "← {:?} {} [{}] {}ms",
296                    status,
297                    context.path,
298                    context.correlation_id,
299                    duration_ms
300                );
301                
302                if is_error {
303                    error!("{}", log_msg);
304                } else if is_slow {
305                    warn!("SLOW: {}", log_msg);
306                } else {
307                    info!("{}", log_msg);
308                }
309            }
310            
311            // Add correlation ID to response headers if enabled
312            if config.correlation_ids && context.correlation_id != "disabled" {
313                if let Err(e) = response.add_header(&config.correlation_header, &context.correlation_id) {
314                    warn!("Failed to add correlation ID to response: {}", e);
315                }
316            }
317            
318            response
319        })
320    }
321    
322    fn name(&self) -> &'static str {
323        "EnhancedLoggingMiddleware"
324    }
325}
326
327/// Check if a header name contains sensitive information
328fn is_sensitive_header(name: &str) -> bool {
329    let sensitive_headers = [
330        "authorization",
331        "cookie",
332        "set-cookie",
333        "x-api-key",
334        "x-auth-token",
335        "x-csrf-token", 
336        "x-access-token",
337        "bearer",
338        "basic",
339        "digest",
340        "negotiate",
341        "oauth",
342        "jwt",
343        "session",
344        "password",
345        "secret",
346        "key",
347        "token",
348    ];
349    
350    let name_lower = name.to_lowercase();
351    sensitive_headers.iter().any(|&sensitive| {
352        name_lower.contains(sensitive)
353    })
354}
355
356/// Convenience builder for common logging configurations
357impl EnhancedLoggingMiddleware {
358    /// Development configuration: verbose logging, correlation IDs, no body logging
359    pub fn development() -> Self {
360        Self::new()
361            .structured(false)
362            .correlation_ids(true)
363            .slow_request_threshold(Duration::from_millis(500))
364            .with_custom_field("env", "development")
365    }
366    
367    /// Production configuration: structured logging, correlation IDs, minimal verbosity
368    pub fn production() -> Self {
369        Self::new()
370            .structured(true)
371            .log_request_body(false)
372            .log_response_body(false)
373            .correlation_ids(true)
374            .slow_request_threshold(Duration::from_millis(2000))
375            .with_custom_field("env", "production")
376    }
377    
378    /// Debug configuration: maximum verbosity for troubleshooting
379    pub fn debug() -> Self {
380        Self::new()
381            .structured(true)
382            .log_request_body(true)
383            .log_response_body(true)
384            .log_request_headers(true)
385            .correlation_ids(true)
386            .slow_request_threshold(Duration::from_millis(100))
387            .with_custom_field("env", "debug")
388    }
389}
390
391#[cfg(test)]
392mod tests {
393    use super::*;
394    use crate::middleware::v2::MiddlewarePipelineV2;
395    use crate::request::{ElifRequest, ElifMethod};
396    use crate::response::{ElifResponse, ElifStatusCode, ElifHeaderMap};
397    
398    #[test]
399    fn test_sensitive_header_detection() {
400        assert!(is_sensitive_header("Authorization"));
401        assert!(is_sensitive_header("AUTHORIZATION"));
402        assert!(is_sensitive_header("x-api-key"));
403        assert!(is_sensitive_header("Cookie"));
404        assert!(is_sensitive_header("Bearer-Token"));
405        assert!(is_sensitive_header("JWT-Token"));
406        
407        assert!(!is_sensitive_header("Content-Type"));
408        assert!(!is_sensitive_header("User-Agent"));
409        assert!(!is_sensitive_header("Accept"));
410        assert!(!is_sensitive_header("X-Forwarded-For"));
411    }
412    
413    #[test]
414    fn test_logging_config_builder() {
415        let config = LoggingConfig::default();
416        assert!(config.structured);
417        assert!(config.correlation_ids);
418        assert!(!config.log_request_body);
419        assert_eq!(config.correlation_header, "X-Correlation-ID");
420    }
421    
422    #[tokio::test]
423    async fn test_enhanced_logging_middleware_v2() {
424        let middleware = EnhancedLoggingMiddleware::development();
425        let pipeline = MiddlewarePipelineV2::new().add(middleware);
426        
427        let mut headers = ElifHeaderMap::new();
428        headers.insert("content-type".parse().unwrap(), "application/json".parse().unwrap());
429        headers.insert("user-agent".parse().unwrap(), "test-client/1.0".parse().unwrap());
430        headers.insert("authorization".parse().unwrap(), "Bearer secret-token".parse().unwrap());
431        headers.insert("x-correlation-id".parse().unwrap(), "existing-correlation-123".parse().unwrap());
432        
433        let request = ElifRequest::new(
434            ElifMethod::POST,
435            "/api/users".parse().unwrap(),
436            headers,
437        );
438        
439        let response = pipeline.execute(request, |_req| {
440            Box::pin(async move {
441                ElifResponse::ok().text("Created user")
442            })
443        }).await;
444        
445        // Should complete successfully
446        assert_eq!(response.status_code(), ElifStatusCode::OK);
447        
448        // Should have correlation ID in response headers
449        assert!(response.has_header("X-Correlation-ID"));
450    }
451    
452    #[test]
453    fn test_preset_configurations() {
454        let dev = EnhancedLoggingMiddleware::development();
455        assert!(!dev.config.structured);
456        assert_eq!(dev.config.custom_fields.get("env").unwrap(), "development");
457        
458        let prod = EnhancedLoggingMiddleware::production();
459        assert!(prod.config.structured);
460        assert!(!prod.config.log_request_body);
461        assert_eq!(prod.config.custom_fields.get("env").unwrap(), "production");
462        
463        let debug = EnhancedLoggingMiddleware::debug();
464        assert!(debug.config.structured);
465        assert!(debug.config.log_request_body);
466        assert!(debug.config.log_response_body);
467        assert_eq!(debug.config.custom_fields.get("env").unwrap(), "debug");
468    }
469}
elif_http/middleware/core/enhanced_logging.rs

elif_http/middleware/core/
enhanced_logging.rs
