elif_http/middleware/core/
timing.rs

1//! # Timing Middleware
2//!
3//! HTTP request timing middleware for performance monitoring.
4
5use std::time::Instant;
6use log::{debug, warn};
7use crate::{
8    middleware::v2::{Middleware, Next, NextFuture},
9    request::ElifRequest,
10};
11
12/// Request timing middleware that tracks request duration and adds timing headers
13#[derive(Debug)]
14pub struct TimingMiddleware {
15    /// Whether to add X-Response-Time header to responses
16    add_header: bool,
17    /// Warning threshold in milliseconds for slow requests
18    slow_request_threshold_ms: u64,
19}
20
21impl TimingMiddleware {
22    /// Create new timing middleware with default settings
23    pub fn new() -> Self {
24        Self {
25            add_header: true,
26            slow_request_threshold_ms: 1000, // 1 second
27        }
28    }
29    
30    /// Disable adding timing header to responses
31    pub fn without_header(mut self) -> Self {
32        self.add_header = false;
33        self
34    }
35    
36    /// Set slow request warning threshold in milliseconds
37    pub fn with_slow_threshold(mut self, threshold_ms: u64) -> Self {
38        self.slow_request_threshold_ms = threshold_ms;
39        self
40    }
41}
42
43impl Default for TimingMiddleware {
44    fn default() -> Self {
45        Self::new()
46    }
47}
48
49/// Extension key for storing request start time
50#[derive(Clone, Copy)]
51pub struct RequestStartTime(Instant);
52
53impl RequestStartTime {
54    pub fn new() -> Self {
55        Self(Instant::now())
56    }
57    
58    pub fn elapsed(&self) -> std::time::Duration {
59        self.0.elapsed()
60    }
61    
62    pub fn elapsed_ms(&self) -> u64 {
63        self.elapsed().as_millis() as u64
64    }
65}
66
67impl Middleware for TimingMiddleware {
68    fn handle(&self, request: ElifRequest, next: Next) -> NextFuture<'static> {
69        let add_header = self.add_header;
70        let slow_threshold = self.slow_request_threshold_ms;
71        
72        Box::pin(async move {
73            // Store start time
74            let start_time = Instant::now();
75            
76            debug!("⏱️  Request timing started for {} {}", 
77                request.method, 
78                request.uri.path()
79            );
80            
81            // Continue to next middleware/handler
82            let mut response = next.run(request).await;
83            
84            // Calculate duration
85            let duration = start_time.elapsed();
86            let duration_ms = duration.as_millis() as u64;
87            
88            // Add timing header if enabled
89            if add_header {
90                if let Err(e) = response.add_header("X-Response-Time", &duration_ms.to_string()) {
91                    warn!("Failed to add X-Response-Time header: {}", e);
92                }
93            }
94            
95            // Check for slow requests and log warning
96            if duration_ms > slow_threshold {
97                warn!("🐌 Slow request detected: {}ms (threshold: {}ms)", 
98                    duration_ms, 
99                    slow_threshold
100                );
101            } else {
102                debug!("⏱️  Request completed in {}ms", duration_ms);
103            }
104            
105            response
106        })
107    }
108    
109    fn name(&self) -> &'static str {
110        "TimingMiddleware"
111    }
112}
113
114/// Utility function to format duration for display
115pub fn format_duration(duration: std::time::Duration) -> String {
116    let total_ms = duration.as_millis();
117    
118    if total_ms >= 1000 {
119        format!("{:.2}s", duration.as_secs_f64())
120    } else if total_ms >= 1 {
121        format!("{}ms", total_ms)
122    } else {
123        format!("{}μs", duration.as_micros())
124    }
125}
126
127#[cfg(test)]
128mod tests {
129    use super::*;
130    use crate::middleware::v2::MiddlewarePipelineV2;
131    use crate::request::{ElifRequest, ElifMethod};
132    use crate::response::headers::ElifHeaderMap;
133    use crate::response::{ElifResponse, ElifStatusCode};
134    use tokio::time::Duration;
135    
136    #[test]
137    fn test_format_duration() {
138        assert_eq!(format_duration(Duration::from_micros(500)), "500μs");
139        assert_eq!(format_duration(Duration::from_millis(150)), "150ms");
140        assert_eq!(format_duration(Duration::from_millis(1500)), "1.50s");
141    }
142    
143    #[tokio::test]
144    async fn test_timing_middleware_v2() {
145        let middleware = TimingMiddleware::new();
146        let pipeline = MiddlewarePipelineV2::new().add(middleware);
147        
148        let headers = ElifHeaderMap::new();
149        let request = ElifRequest::new(
150            ElifMethod::GET,
151            "/api/test".parse().unwrap(),
152            headers,
153        );
154        
155        let response = pipeline.execute(request, |_req| {
156            Box::pin(async move {
157                // Add small delay to test timing
158                tokio::time::sleep(tokio::time::Duration::from_millis(10)).await;
159                ElifResponse::ok().text("Success")
160            })
161        }).await;
162        
163        // Should complete successfully and have the timing header
164        assert_eq!(response.status_code(), ElifStatusCode::OK);
165        assert!(response.has_header("x-response-time"));
166    }
167    
168    #[tokio::test]
169    async fn test_timing_middleware_without_header() {
170        let middleware = TimingMiddleware::new().without_header();
171        let pipeline = MiddlewarePipelineV2::new().add(middleware);
172        
173        let request = ElifRequest::new(
174            ElifMethod::GET,
175            "/api/test".parse().unwrap(),
176            ElifHeaderMap::new(),
177        );
178        
179        let response = pipeline.execute(request, |_req| {
180            Box::pin(async move {
181                ElifResponse::ok().text("Success")
182            })
183        }).await;
184        
185        // Should NOT have timing header
186        assert!(!response.has_header("x-response-time"));
187    }
188    
189    #[test]
190    fn test_request_start_time() {
191        let start = RequestStartTime::new();
192        
193        // Add a tiny delay to ensure some time passes
194        std::thread::sleep(std::time::Duration::from_millis(1000));
195        
196        // Should have elapsed time
197        assert!(start.elapsed().as_nanos() > 0);
198        assert!(start.elapsed_ms() > 0);
199    }
200    
201    #[test]
202    fn test_timing_middleware_builder() {
203        let middleware = TimingMiddleware::new()
204            .with_slow_threshold(500)
205            .without_header();
206        
207        assert_eq!(middleware.slow_request_threshold_ms, 500);
208        assert!(!middleware.add_header);
209    }
210}