talos_api_rs/runtime/
logging.rs

1// SPDX-License-Identifier: MIT OR Apache-2.0
2
3//! Logging interceptor for gRPC requests and responses.
4//!
5//! Provides structured logging of all API calls with timing, request/response
6//! metadata, and error details.
7//!
8//! # Example
9//!
10//! ```ignore
11//! use talos_api_rs::runtime::{LoggingInterceptor, LogLevel};
12//!
13//! // Create interceptor with custom log level
14//! let interceptor = LoggingInterceptor::new()
15//!     .with_level(LogLevel::Debug)
16//!     .with_request_body(true)
17//!     .with_response_body(true);
18//!
19//! // Use with TalosClient
20//! let client = TalosClient::with_interceptor(config, interceptor).await?;
21//! ```
22
23use std::fmt;
24use std::sync::atomic::{AtomicU64, Ordering};
25use std::time::Instant;
26use tonic::service::Interceptor;
27use tonic::{Request, Status};
28use tracing::{debug, error, info, trace, warn};
29
30/// Log level for the logging interceptor.
31#[derive(Debug, Clone, Copy, PartialEq, Eq, Default)]
32pub enum LogLevel {
33    /// Trace level - most verbose.
34    Trace,
35    /// Debug level.
36    Debug,
37    /// Info level.
38    #[default]
39    Info,
40    /// Warn level.
41    Warn,
42    /// Error level - only errors.
43    Error,
44    /// Disabled - no logging.
45    Off,
46}
47
48impl fmt::Display for LogLevel {
49    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
50        match self {
51            LogLevel::Trace => write!(f, "TRACE"),
52            LogLevel::Debug => write!(f, "DEBUG"),
53            LogLevel::Info => write!(f, "INFO"),
54            LogLevel::Warn => write!(f, "WARN"),
55            LogLevel::Error => write!(f, "ERROR"),
56            LogLevel::Off => write!(f, "OFF"),
57        }
58    }
59}
60
61/// Configuration for the logging interceptor.
62#[derive(Debug, Clone)]
63pub struct LoggingConfig {
64    /// Log level for successful requests.
65    pub success_level: LogLevel,
66    /// Log level for failed requests.
67    pub error_level: LogLevel,
68    /// Whether to log request metadata.
69    pub log_metadata: bool,
70    /// Whether to log request path.
71    pub log_path: bool,
72    /// Whether to redact sensitive headers.
73    pub redact_sensitive: bool,
74    /// List of sensitive header names to redact.
75    pub sensitive_headers: Vec<String>,
76}
77
78impl Default for LoggingConfig {
79    fn default() -> Self {
80        Self {
81            success_level: LogLevel::Info,
82            error_level: LogLevel::Error,
83            log_metadata: true,
84            log_path: true,
85            redact_sensitive: true,
86            sensitive_headers: vec![
87                "authorization".to_string(),
88                "x-api-key".to_string(),
89                "x-auth-token".to_string(),
90            ],
91        }
92    }
93}
94
95impl LoggingConfig {
96    /// Create a new logging configuration.
97    #[must_use]
98    pub fn new() -> Self {
99        Self::default()
100    }
101
102    /// Set the success log level.
103    #[must_use]
104    pub fn with_success_level(mut self, level: LogLevel) -> Self {
105        self.success_level = level;
106        self
107    }
108
109    /// Set the error log level.
110    #[must_use]
111    pub fn with_error_level(mut self, level: LogLevel) -> Self {
112        self.error_level = level;
113        self
114    }
115
116    /// Enable or disable metadata logging.
117    #[must_use]
118    pub fn with_metadata(mut self, enabled: bool) -> Self {
119        self.log_metadata = enabled;
120        self
121    }
122
123    /// Enable or disable path logging.
124    #[must_use]
125    pub fn with_path(mut self, enabled: bool) -> Self {
126        self.log_path = enabled;
127        self
128    }
129
130    /// Enable or disable sensitive data redaction.
131    #[must_use]
132    pub fn with_redaction(mut self, enabled: bool) -> Self {
133        self.redact_sensitive = enabled;
134        self
135    }
136
137    /// Add a sensitive header to redact.
138    #[must_use]
139    pub fn with_sensitive_header(mut self, header: impl Into<String>) -> Self {
140        self.sensitive_headers.push(header.into());
141        self
142    }
143
144    /// Create a verbose configuration for debugging.
145    #[must_use]
146    pub fn verbose() -> Self {
147        Self {
148            success_level: LogLevel::Debug,
149            error_level: LogLevel::Error,
150            log_metadata: true,
151            log_path: true,
152            redact_sensitive: true,
153            sensitive_headers: vec![
154                "authorization".to_string(),
155                "x-api-key".to_string(),
156                "x-auth-token".to_string(),
157            ],
158        }
159    }
160
161    /// Create a quiet configuration for production.
162    #[must_use]
163    pub fn quiet() -> Self {
164        Self {
165            success_level: LogLevel::Off,
166            error_level: LogLevel::Warn,
167            log_metadata: false,
168            log_path: true,
169            redact_sensitive: true,
170            sensitive_headers: vec![
171                "authorization".to_string(),
172                "x-api-key".to_string(),
173                "x-auth-token".to_string(),
174            ],
175        }
176    }
177}
178
179/// Metrics collected by the logging interceptor.
180#[derive(Debug, Default)]
181pub struct InterceptorMetrics {
182    /// Total number of requests.
183    total_requests: AtomicU64,
184    /// Number of successful requests.
185    successful_requests: AtomicU64,
186    /// Number of failed requests.
187    failed_requests: AtomicU64,
188}
189
190impl InterceptorMetrics {
191    /// Create a new metrics instance.
192    #[must_use]
193    pub fn new() -> Self {
194        Self::default()
195    }
196
197    /// Record a successful request.
198    pub fn record_success(&self) {
199        self.total_requests.fetch_add(1, Ordering::Relaxed);
200        self.successful_requests.fetch_add(1, Ordering::Relaxed);
201    }
202
203    /// Record a failed request.
204    pub fn record_failure(&self) {
205        self.total_requests.fetch_add(1, Ordering::Relaxed);
206        self.failed_requests.fetch_add(1, Ordering::Relaxed);
207    }
208
209    /// Get the total number of requests.
210    #[must_use]
211    pub fn total_requests(&self) -> u64 {
212        self.total_requests.load(Ordering::Relaxed)
213    }
214
215    /// Get the number of successful requests.
216    #[must_use]
217    pub fn successful_requests(&self) -> u64 {
218        self.successful_requests.load(Ordering::Relaxed)
219    }
220
221    /// Get the number of failed requests.
222    #[must_use]
223    pub fn failed_requests(&self) -> u64 {
224        self.failed_requests.load(Ordering::Relaxed)
225    }
226
227    /// Get the success rate (0.0 to 1.0).
228    #[must_use]
229    pub fn success_rate(&self) -> f64 {
230        let total = self.total_requests.load(Ordering::Relaxed);
231        if total == 0 {
232            return 1.0;
233        }
234        let successful = self.successful_requests.load(Ordering::Relaxed);
235        successful as f64 / total as f64
236    }
237
238    /// Reset all metrics.
239    pub fn reset(&self) {
240        self.total_requests.store(0, Ordering::Relaxed);
241        self.successful_requests.store(0, Ordering::Relaxed);
242        self.failed_requests.store(0, Ordering::Relaxed);
243    }
244}
245
246/// A gRPC interceptor that logs requests.
247///
248/// This interceptor logs the start of each request. For complete request/response
249/// logging including timing and response status, you should combine this with
250/// tower middleware or use the `RequestLogger` wrapper.
251#[derive(Clone)]
252pub struct LoggingInterceptor {
253    config: LoggingConfig,
254}
255
256impl LoggingInterceptor {
257    /// Create a new logging interceptor with default configuration.
258    #[must_use]
259    pub fn new() -> Self {
260        Self {
261            config: LoggingConfig::default(),
262        }
263    }
264
265    /// Create a logging interceptor with custom configuration.
266    #[must_use]
267    pub fn with_config(config: LoggingConfig) -> Self {
268        Self { config }
269    }
270
271    /// Get the configuration.
272    #[must_use]
273    pub fn config(&self) -> &LoggingConfig {
274        &self.config
275    }
276
277    fn log_request<T>(&self, request: &Request<T>) {
278        if self.config.success_level == LogLevel::Off {
279            return;
280        }
281
282        let metadata_str = if self.config.log_metadata {
283            let mut parts = Vec::new();
284            for key_and_value in request.metadata().iter() {
285                match key_and_value {
286                    tonic::metadata::KeyAndValueRef::Ascii(key, value) => {
287                        let key_str = key.as_str();
288                        if self.config.redact_sensitive
289                            && self
290                                .config
291                                .sensitive_headers
292                                .iter()
293                                .any(|h| h.eq_ignore_ascii_case(key_str))
294                        {
295                            parts.push(format!("{}=[REDACTED]", key_str));
296                        } else {
297                            parts.push(format!("{}={:?}", key_str, value));
298                        }
299                    }
300                    tonic::metadata::KeyAndValueRef::Binary(key, value) => {
301                        let key_str = key.as_str();
302                        if self.config.redact_sensitive
303                            && self
304                                .config
305                                .sensitive_headers
306                                .iter()
307                                .any(|h| h.eq_ignore_ascii_case(key_str))
308                        {
309                            parts.push(format!("{}=[REDACTED]", key_str));
310                        } else {
311                            parts.push(format!("{}={:?}", key_str, value));
312                        }
313                    }
314                }
315            }
316            if parts.is_empty() {
317                String::new()
318            } else {
319                format!(" metadata=[{}]", parts.join(", "))
320            }
321        } else {
322            String::new()
323        };
324
325        match self.config.success_level {
326            LogLevel::Trace => {
327                trace!(target: "talos_api::grpc", "gRPC request{}", metadata_str);
328            }
329            LogLevel::Debug => {
330                debug!(target: "talos_api::grpc", "gRPC request{}", metadata_str);
331            }
332            LogLevel::Info => {
333                info!(target: "talos_api::grpc", "gRPC request{}", metadata_str);
334            }
335            LogLevel::Warn => {
336                warn!(target: "talos_api::grpc", "gRPC request{}", metadata_str);
337            }
338            LogLevel::Error => {
339                error!(target: "talos_api::grpc", "gRPC request{}", metadata_str);
340            }
341            LogLevel::Off => {}
342        }
343    }
344}
345
346impl Default for LoggingInterceptor {
347    fn default() -> Self {
348        Self::new()
349    }
350}
351
352impl Interceptor for LoggingInterceptor {
353    fn call(&mut self, request: Request<()>) -> std::result::Result<Request<()>, Status> {
354        self.log_request(&request);
355        Ok(request)
356    }
357}
358
359/// A request logger that tracks timing and logs responses.
360///
361/// Use this for complete request/response logging with timing information.
362#[derive(Debug)]
363pub struct RequestLogger {
364    config: LoggingConfig,
365    metrics: InterceptorMetrics,
366}
367
368impl RequestLogger {
369    /// Create a new request logger.
370    #[must_use]
371    pub fn new() -> Self {
372        Self {
373            config: LoggingConfig::default(),
374            metrics: InterceptorMetrics::new(),
375        }
376    }
377
378    /// Create a request logger with custom configuration.
379    #[must_use]
380    pub fn with_config(config: LoggingConfig) -> Self {
381        Self {
382            config,
383            metrics: InterceptorMetrics::new(),
384        }
385    }
386
387    /// Get the metrics.
388    #[must_use]
389    pub fn metrics(&self) -> &InterceptorMetrics {
390        &self.metrics
391    }
392
393    /// Start tracking a request.
394    #[must_use]
395    pub fn start(&self, method: &str) -> RequestSpan {
396        RequestSpan {
397            method: method.to_string(),
398            start: Instant::now(),
399        }
400    }
401
402    /// Finish tracking a request (success).
403    pub fn finish_success(&self, span: RequestSpan) {
404        self.metrics.record_success();
405        let elapsed = span.start.elapsed();
406
407        if self.config.success_level == LogLevel::Off {
408            return;
409        }
410
411        let msg = format!("gRPC response: {} completed in {:?}", span.method, elapsed);
412
413        match self.config.success_level {
414            LogLevel::Trace => trace!(target: "talos_api::grpc", "{}", msg),
415            LogLevel::Debug => debug!(target: "talos_api::grpc", "{}", msg),
416            LogLevel::Info => info!(target: "talos_api::grpc", "{}", msg),
417            LogLevel::Warn => warn!(target: "talos_api::grpc", "{}", msg),
418            LogLevel::Error => error!(target: "talos_api::grpc", "{}", msg),
419            LogLevel::Off => {}
420        }
421    }
422
423    /// Finish tracking a request (failure).
424    pub fn finish_error(&self, span: RequestSpan, error: &str) {
425        self.metrics.record_failure();
426        let elapsed = span.start.elapsed();
427
428        if self.config.error_level == LogLevel::Off {
429            return;
430        }
431
432        let msg = format!(
433            "gRPC error: {} failed in {:?}: {}",
434            span.method, elapsed, error
435        );
436
437        match self.config.error_level {
438            LogLevel::Trace => trace!(target: "talos_api::grpc", "{}", msg),
439            LogLevel::Debug => debug!(target: "talos_api::grpc", "{}", msg),
440            LogLevel::Info => info!(target: "talos_api::grpc", "{}", msg),
441            LogLevel::Warn => warn!(target: "talos_api::grpc", "{}", msg),
442            LogLevel::Error => error!(target: "talos_api::grpc", "{}", msg),
443            LogLevel::Off => {}
444        }
445    }
446}
447
448impl Default for RequestLogger {
449    fn default() -> Self {
450        Self::new()
451    }
452}
453
454/// A span representing an in-flight request.
455#[derive(Debug)]
456pub struct RequestSpan {
457    method: String,
458    start: Instant,
459}
460
461impl RequestSpan {
462    /// Get the method name.
463    #[must_use]
464    pub fn method(&self) -> &str {
465        &self.method
466    }
467
468    /// Get the elapsed time since the request started.
469    #[must_use]
470    pub fn elapsed(&self) -> std::time::Duration {
471        self.start.elapsed()
472    }
473}
474
475#[cfg(test)]
476mod tests {
477    use super::*;
478
479    #[test]
480    fn test_log_level_display() {
481        assert_eq!(LogLevel::Trace.to_string(), "TRACE");
482        assert_eq!(LogLevel::Debug.to_string(), "DEBUG");
483        assert_eq!(LogLevel::Info.to_string(), "INFO");
484        assert_eq!(LogLevel::Warn.to_string(), "WARN");
485        assert_eq!(LogLevel::Error.to_string(), "ERROR");
486        assert_eq!(LogLevel::Off.to_string(), "OFF");
487    }
488
489    #[test]
490    fn test_log_level_default() {
491        assert_eq!(LogLevel::default(), LogLevel::Info);
492    }
493
494    #[test]
495    fn test_logging_config_default() {
496        let config = LoggingConfig::default();
497        assert_eq!(config.success_level, LogLevel::Info);
498        assert_eq!(config.error_level, LogLevel::Error);
499        assert!(config.log_metadata);
500        assert!(config.log_path);
501        assert!(config.redact_sensitive);
502    }
503
504    #[test]
505    fn test_logging_config_builder() {
506        let config = LoggingConfig::new()
507            .with_success_level(LogLevel::Debug)
508            .with_error_level(LogLevel::Warn)
509            .with_metadata(false)
510            .with_path(false)
511            .with_redaction(false)
512            .with_sensitive_header("x-custom-auth");
513
514        assert_eq!(config.success_level, LogLevel::Debug);
515        assert_eq!(config.error_level, LogLevel::Warn);
516        assert!(!config.log_metadata);
517        assert!(!config.log_path);
518        assert!(!config.redact_sensitive);
519        assert!(config
520            .sensitive_headers
521            .contains(&"x-custom-auth".to_string()));
522    }
523
524    #[test]
525    fn test_logging_config_verbose() {
526        let config = LoggingConfig::verbose();
527        assert_eq!(config.success_level, LogLevel::Debug);
528        assert!(config.log_metadata);
529    }
530
531    #[test]
532    fn test_logging_config_quiet() {
533        let config = LoggingConfig::quiet();
534        assert_eq!(config.success_level, LogLevel::Off);
535        assert_eq!(config.error_level, LogLevel::Warn);
536        assert!(!config.log_metadata);
537    }
538
539    #[test]
540    fn test_interceptor_metrics() {
541        let metrics = InterceptorMetrics::new();
542        assert_eq!(metrics.total_requests(), 0);
543        assert_eq!(metrics.successful_requests(), 0);
544        assert_eq!(metrics.failed_requests(), 0);
545        assert_eq!(metrics.success_rate(), 1.0); // No requests = 100% success
546
547        metrics.record_success();
548        metrics.record_success();
549        metrics.record_failure();
550
551        assert_eq!(metrics.total_requests(), 3);
552        assert_eq!(metrics.successful_requests(), 2);
553        assert_eq!(metrics.failed_requests(), 1);
554        assert!((metrics.success_rate() - 0.666_666_666_666_666_6).abs() < 0.001);
555    }
556
557    #[test]
558    fn test_interceptor_metrics_reset() {
559        let metrics = InterceptorMetrics::new();
560        metrics.record_success();
561        metrics.record_failure();
562        metrics.reset();
563
564        assert_eq!(metrics.total_requests(), 0);
565        assert_eq!(metrics.successful_requests(), 0);
566        assert_eq!(metrics.failed_requests(), 0);
567    }
568
569    #[test]
570    fn test_logging_interceptor_default() {
571        let interceptor = LoggingInterceptor::default();
572        assert_eq!(interceptor.config().success_level, LogLevel::Info);
573    }
574
575    #[test]
576    fn test_request_logger() {
577        let logger = RequestLogger::new();
578        let span = logger.start("Version");
579
580        assert_eq!(span.method(), "Version");
581        assert!(span.elapsed() < std::time::Duration::from_secs(1));
582
583        logger.finish_success(span);
584        assert_eq!(logger.metrics().total_requests(), 1);
585        assert_eq!(logger.metrics().successful_requests(), 1);
586    }
587
588    #[test]
589    fn test_request_logger_error() {
590        let logger = RequestLogger::with_config(LoggingConfig::quiet());
591        let span = logger.start("ApplyConfiguration");
592
593        logger.finish_error(span, "Permission denied");
594        assert_eq!(logger.metrics().total_requests(), 1);
595        assert_eq!(logger.metrics().failed_requests(), 1);
596    }
597
598    #[test]
599    fn test_request_span() {
600        let span = RequestSpan {
601            method: "test".to_string(),
602            start: Instant::now(),
603        };
604
605        assert_eq!(span.method(), "test");
606        std::thread::sleep(std::time::Duration::from_millis(1));
607        assert!(span.elapsed() >= std::time::Duration::from_millis(1));
608    }
609}
talos_api_rs/runtime/logging.rs

talos_api_rs/runtime/
logging.rs
