Skip to main content

fraiseql_server/
logging.rs

1//! Structured JSON logging for observability.
2//!
3//! Provides structured logging output in JSON format for easier parsing
4//! and integration with log aggregation systems (ELK, Splunk, `DataDog`, etc).
5//!
6//! # Features
7//!
8//! - JSON-formatted log output for every log entry
9//! - Request context tracking (`request_id`, operation, `user_id`)
10//! - Performance metrics in logs (duration, query complexity)
11//! - Severity levels (trace, debug, info, warn, error)
12//! - Automatic timestamp and source location
13
14use std::{fmt, sync::Arc};
15
16use serde::{Deserialize, Serialize};
17use uuid::Uuid;
18
19/// Unique identifier for request context.
20#[derive(Debug, Clone, Copy, Serialize, Deserialize)]
21pub struct RequestId(Uuid);
22
23impl RequestId {
24    /// Generate new random request ID.
25    #[must_use]
26    pub fn new() -> Self {
27        Self(Uuid::new_v4())
28    }
29
30    /// Create from existing UUID.
31    #[must_use]
32    pub fn from_uuid(uuid: Uuid) -> Self {
33        Self(uuid)
34    }
35}
36
37impl Default for RequestId {
38    fn default() -> Self {
39        Self::new()
40    }
41}
42
43impl fmt::Display for RequestId {
44    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
45        write!(f, "{}", self.0)
46    }
47}
48
49/// Request context for structured logging and multi-tenancy.
50#[derive(Debug, Clone, Serialize, Deserialize)]
51pub struct RequestContext {
52    /// Unique request identifier
53    pub request_id: RequestId,
54
55    /// GraphQL operation name (query, mutation, subscription)
56    pub operation: Option<String>,
57
58    /// User identifier (if authenticated)
59    pub user_id: Option<String>,
60
61    /// Organization ID for multi-tenancy enforcement
62    pub org_id: Option<String>,
63
64    /// Client IP address
65    pub client_ip: Option<String>,
66
67    /// API version
68    pub api_version: Option<String>,
69}
70
71impl RequestContext {
72    /// Create new request context.
73    #[must_use]
74    pub fn new() -> Self {
75        Self {
76            request_id:  RequestId::new(),
77            operation:   None,
78            user_id:     None,
79            org_id:      None,
80            client_ip:   None,
81            api_version: None,
82        }
83    }
84
85    /// Set operation name.
86    #[must_use]
87    pub fn with_operation(mut self, operation: String) -> Self {
88        self.operation = Some(operation);
89        self
90    }
91
92    /// Set user ID.
93    #[must_use]
94    pub fn with_user_id(mut self, user_id: String) -> Self {
95        self.user_id = Some(user_id);
96        self
97    }
98
99    /// Set organization ID for multi-tenancy.
100    #[must_use]
101    pub fn with_org_id(mut self, org_id: String) -> Self {
102        self.org_id = Some(org_id);
103        self
104    }
105
106    /// Set client IP.
107    #[must_use]
108    pub fn with_client_ip(mut self, ip: String) -> Self {
109        self.client_ip = Some(ip);
110        self
111    }
112
113    /// Set API version.
114    #[must_use]
115    pub fn with_api_version(mut self, version: String) -> Self {
116        self.api_version = Some(version);
117        self
118    }
119}
120
121impl Default for RequestContext {
122    fn default() -> Self {
123        Self::new()
124    }
125}
126
127/// Log level for severity classification.
128#[derive(Debug, Clone, Copy, Serialize, Deserialize, PartialEq, Eq)]
129#[serde(rename_all = "UPPERCASE")]
130pub enum LogLevel {
131    /// Trace level (most verbose)
132    Trace,
133    /// Debug level
134    Debug,
135    /// Info level
136    Info,
137    /// Warning level
138    Warn,
139    /// Error level
140    Error,
141}
142
143impl fmt::Display for LogLevel {
144    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
145        match self {
146            Self::Trace => write!(f, "TRACE"),
147            Self::Debug => write!(f, "DEBUG"),
148            Self::Info => write!(f, "INFO"),
149            Self::Warn => write!(f, "WARN"),
150            Self::Error => write!(f, "ERROR"),
151        }
152    }
153}
154
155impl From<tracing::Level> for LogLevel {
156    fn from(level: tracing::Level) -> Self {
157        match level {
158            tracing::Level::TRACE => Self::Trace,
159            tracing::Level::DEBUG => Self::Debug,
160            tracing::Level::INFO => Self::Info,
161            tracing::Level::WARN => Self::Warn,
162            tracing::Level::ERROR => Self::Error,
163        }
164    }
165}
166
167/// Structured JSON log entry.
168#[derive(Debug, Clone, Serialize, Deserialize)]
169pub struct StructuredLogEntry {
170    /// Log timestamp (ISO 8601 format)
171    pub timestamp: String,
172
173    /// Log level
174    pub level: LogLevel,
175
176    /// Log message
177    pub message: String,
178
179    /// Request context (if applicable)
180    #[serde(skip_serializing_if = "Option::is_none")]
181    pub request_context: Option<RequestContext>,
182
183    /// Performance metrics
184    #[serde(skip_serializing_if = "Option::is_none")]
185    pub metrics: Option<LogMetrics>,
186
187    /// Error details (if applicable)
188    #[serde(skip_serializing_if = "Option::is_none")]
189    pub error: Option<ErrorDetails>,
190
191    /// Source code location
192    #[serde(skip_serializing_if = "Option::is_none")]
193    pub source: Option<SourceLocation>,
194
195    /// Additional context fields
196    #[serde(skip_serializing_if = "Option::is_none")]
197    pub context: Option<serde_json::Value>,
198}
199
200impl StructuredLogEntry {
201    /// Create new log entry.
202    #[must_use]
203    pub fn new(level: LogLevel, message: String) -> Self {
204        Self {
205            timestamp: chrono::Utc::now().to_rfc3339_opts(chrono::SecondsFormat::Millis, true),
206            level,
207            message,
208            request_context: None,
209            metrics: None,
210            error: None,
211            source: None,
212            context: None,
213        }
214    }
215
216    /// Add request context.
217    #[must_use]
218    pub fn with_request_context(mut self, context: RequestContext) -> Self {
219        self.request_context = Some(context);
220        self
221    }
222
223    /// Add performance metrics.
224    #[must_use]
225    pub fn with_metrics(mut self, metrics: LogMetrics) -> Self {
226        self.metrics = Some(metrics);
227        self
228    }
229
230    /// Add error details.
231    #[must_use]
232    pub fn with_error(mut self, error: ErrorDetails) -> Self {
233        self.error = Some(error);
234        self
235    }
236
237    /// Add source location.
238    #[must_use]
239    pub fn with_source(mut self, source: SourceLocation) -> Self {
240        self.source = Some(source);
241        self
242    }
243
244    /// Add custom context.
245    #[must_use]
246    pub fn with_context(mut self, context: serde_json::Value) -> Self {
247        self.context = Some(context);
248        self
249    }
250
251    /// Serialize to JSON string.
252    #[must_use]
253    pub fn to_json_string(&self) -> String {
254        serde_json::to_string(self).unwrap_or_else(|_| {
255            format!(
256                r#"{{"level":"{}","message":"{}","error":"serialization failed"}}"#,
257                self.level, self.message
258            )
259        })
260    }
261}
262
263/// Performance metrics for a log entry.
264#[derive(Debug, Clone, Serialize, Deserialize)]
265pub struct LogMetrics {
266    /// Duration in milliseconds
267    #[serde(skip_serializing_if = "Option::is_none")]
268    pub duration_ms: Option<f64>,
269
270    /// Query complexity (depth, field count, etc.)
271    #[serde(skip_serializing_if = "Option::is_none")]
272    pub complexity: Option<u32>,
273
274    /// Number of items processed
275    #[serde(skip_serializing_if = "Option::is_none")]
276    pub items_processed: Option<u64>,
277
278    /// Cache hit indicator
279    #[serde(skip_serializing_if = "Option::is_none")]
280    pub cache_hit: Option<bool>,
281
282    /// Database queries executed
283    #[serde(skip_serializing_if = "Option::is_none")]
284    pub db_queries: Option<u32>,
285}
286
287impl LogMetrics {
288    /// Create new metrics container.
289    #[must_use]
290    pub fn new() -> Self {
291        Self {
292            duration_ms:     None,
293            complexity:      None,
294            items_processed: None,
295            cache_hit:       None,
296            db_queries:      None,
297        }
298    }
299
300    /// Set duration in milliseconds.
301    #[must_use]
302    pub fn with_duration_ms(mut self, duration: f64) -> Self {
303        self.duration_ms = Some(duration);
304        self
305    }
306
307    /// Set query complexity.
308    #[must_use]
309    pub fn with_complexity(mut self, complexity: u32) -> Self {
310        self.complexity = Some(complexity);
311        self
312    }
313
314    /// Set items processed count.
315    #[must_use]
316    pub fn with_items_processed(mut self, count: u64) -> Self {
317        self.items_processed = Some(count);
318        self
319    }
320
321    /// Set cache hit status.
322    #[must_use]
323    pub fn with_cache_hit(mut self, hit: bool) -> Self {
324        self.cache_hit = Some(hit);
325        self
326    }
327
328    /// Set database query count.
329    #[must_use]
330    pub fn with_db_queries(mut self, count: u32) -> Self {
331        self.db_queries = Some(count);
332        self
333    }
334}
335
336impl Default for LogMetrics {
337    fn default() -> Self {
338        Self::new()
339    }
340}
341
342/// Error details for error logs.
343#[derive(Debug, Clone, Serialize, Deserialize)]
344pub struct ErrorDetails {
345    /// Error type/category
346    pub error_type: String,
347
348    /// Error message
349    pub message: String,
350
351    /// Error code (if applicable)
352    #[serde(skip_serializing_if = "Option::is_none")]
353    pub code: Option<String>,
354
355    /// Stack trace (in debug builds)
356    #[serde(skip_serializing_if = "Option::is_none")]
357    pub stack_trace: Option<String>,
358}
359
360impl ErrorDetails {
361    /// Create new error details.
362    #[must_use]
363    pub fn new(error_type: String, message: String) -> Self {
364        Self {
365            error_type,
366            message,
367            code: None,
368            stack_trace: None,
369        }
370    }
371
372    /// Set error code.
373    #[must_use]
374    pub fn with_code(mut self, code: String) -> Self {
375        self.code = Some(code);
376        self
377    }
378
379    /// Set stack trace.
380    #[must_use]
381    pub fn with_stack_trace(mut self, trace: String) -> Self {
382        self.stack_trace = Some(trace);
383        self
384    }
385}
386
387/// Source code location information.
388#[derive(Debug, Clone, Serialize, Deserialize)]
389pub struct SourceLocation {
390    /// Source file name
391    pub file: String,
392
393    /// Line number
394    pub line: u32,
395
396    /// Module path
397    pub module: String,
398}
399
400impl SourceLocation {
401    /// Create new source location.
402    #[must_use]
403    pub fn new(file: String, line: u32, module: String) -> Self {
404        Self { file, line, module }
405    }
406}
407
408/// Request logger for contextual logging.
409#[derive(Debug, Clone)]
410pub struct RequestLogger {
411    context: Arc<RequestContext>,
412}
413
414impl RequestLogger {
415    /// Create new request logger.
416    #[must_use]
417    pub fn new(context: RequestContext) -> Self {
418        Self {
419            context: Arc::new(context),
420        }
421    }
422
423    /// Create from request ID.
424    #[must_use]
425    pub fn with_request_id(request_id: RequestId) -> Self {
426        Self::new(RequestContext {
427            request_id,
428            ..Default::default()
429        })
430    }
431
432    /// Get request context.
433    #[must_use]
434    pub fn context(&self) -> &RequestContext {
435        &self.context
436    }
437
438    /// Create info log entry with context.
439    pub fn info(&self, message: impl Into<String>) -> StructuredLogEntry {
440        StructuredLogEntry::new(LogLevel::Info, message.into())
441            .with_request_context((*self.context).clone())
442    }
443
444    /// Create warn log entry with context.
445    pub fn warn(&self, message: impl Into<String>) -> StructuredLogEntry {
446        StructuredLogEntry::new(LogLevel::Warn, message.into())
447            .with_request_context((*self.context).clone())
448    }
449
450    /// Create error log entry with context.
451    pub fn error(&self, message: impl Into<String>) -> StructuredLogEntry {
452        StructuredLogEntry::new(LogLevel::Error, message.into())
453            .with_request_context((*self.context).clone())
454    }
455
456    /// Create debug log entry with context.
457    pub fn debug(&self, message: impl Into<String>) -> StructuredLogEntry {
458        StructuredLogEntry::new(LogLevel::Debug, message.into())
459            .with_request_context((*self.context).clone())
460    }
461}
462
463#[cfg(test)]
464mod tests {
465    use super::*;
466
467    #[test]
468    fn test_request_id_generation() {
469        let id1 = RequestId::new();
470        let id2 = RequestId::new();
471        assert_ne!(id1.0, id2.0);
472    }
473
474    #[test]
475    fn test_request_context_builder() {
476        let context = RequestContext::new()
477            .with_operation("GetUser".to_string())
478            .with_user_id("user123".to_string())
479            .with_client_ip("192.168.1.1".to_string())
480            .with_api_version("v1".to_string());
481
482        assert_eq!(context.operation, Some("GetUser".to_string()));
483        assert_eq!(context.user_id, Some("user123".to_string()));
484        assert_eq!(context.client_ip, Some("192.168.1.1".to_string()));
485        assert_eq!(context.api_version, Some("v1".to_string()));
486    }
487
488    #[test]
489    fn test_log_entry_creation() {
490        let entry = StructuredLogEntry::new(LogLevel::Info, "test message".to_string());
491        assert_eq!(entry.level, LogLevel::Info);
492        assert_eq!(entry.message, "test message");
493        assert!(entry.request_context.is_none());
494    }
495
496    #[test]
497    fn test_log_entry_with_context() {
498        let context = RequestContext::new().with_operation("Query".to_string());
499
500        let entry = StructuredLogEntry::new(LogLevel::Info, "operation executed".to_string())
501            .with_request_context(context.clone());
502
503        assert!(entry.request_context.is_some());
504        assert_eq!(entry.request_context.unwrap().operation, Some("Query".to_string()));
505    }
506
507    #[test]
508    fn test_log_metrics_builder() {
509        let metrics = LogMetrics::new()
510            .with_duration_ms(123.45)
511            .with_complexity(5)
512            .with_items_processed(100)
513            .with_cache_hit(true)
514            .with_db_queries(3);
515
516        assert_eq!(metrics.duration_ms, Some(123.45));
517        assert_eq!(metrics.complexity, Some(5));
518        assert_eq!(metrics.items_processed, Some(100));
519        assert_eq!(metrics.cache_hit, Some(true));
520        assert_eq!(metrics.db_queries, Some(3));
521    }
522
523    #[test]
524    fn test_error_details_builder() {
525        let error =
526            ErrorDetails::new("DatabaseError".to_string(), "Connection timeout".to_string())
527                .with_code("DB_TIMEOUT".to_string());
528
529        assert_eq!(error.error_type, "DatabaseError");
530        assert_eq!(error.message, "Connection timeout");
531        assert_eq!(error.code, Some("DB_TIMEOUT".to_string()));
532    }
533
534    #[test]
535    fn test_log_entry_json_serialization() {
536        let entry = StructuredLogEntry::new(LogLevel::Error, "test error".to_string());
537        let json = entry.to_json_string();
538
539        assert!(json.contains("\"level\":\"ERROR\""));
540        assert!(json.contains("\"message\":\"test error\""));
541        assert!(json.contains("\"timestamp\":"));
542    }
543
544    #[test]
545    fn test_request_logger_creation() {
546        let context = RequestContext::new().with_operation("Query".to_string());
547        let logger = RequestLogger::new(context);
548
549        assert_eq!(logger.context().operation, Some("Query".to_string()));
550    }
551
552    #[test]
553    fn test_request_logger_log_entry() {
554        let logger = RequestLogger::with_request_id(RequestId::new());
555        let entry = logger.info("test message");
556
557        assert_eq!(entry.level, LogLevel::Info);
558        assert!(entry.request_context.is_some());
559    }
560
561    #[test]
562    fn test_log_level_conversion() {
563        assert_eq!(LogLevel::from(tracing::Level::INFO), LogLevel::Info);
564        assert_eq!(LogLevel::from(tracing::Level::WARN), LogLevel::Warn);
565        assert_eq!(LogLevel::from(tracing::Level::ERROR), LogLevel::Error);
566        assert_eq!(LogLevel::from(tracing::Level::DEBUG), LogLevel::Debug);
567        assert_eq!(LogLevel::from(tracing::Level::TRACE), LogLevel::Trace);
568    }
569
570    #[test]
571    fn test_complex_log_entry() {
572        let context = RequestContext::new()
573            .with_operation("GetUsers".to_string())
574            .with_user_id("user123".to_string());
575
576        let metrics = LogMetrics::new()
577            .with_duration_ms(45.67)
578            .with_db_queries(2)
579            .with_cache_hit(true);
580
581        let error =
582            ErrorDetails::new("ValidationError".to_string(), "Invalid query parameter".to_string());
583
584        let source = SourceLocation::new(
585            "routes/graphql.rs".to_string(),
586            42,
587            "fraiseql_server::routes".to_string(),
588        );
589
590        let entry = StructuredLogEntry::new(LogLevel::Warn, "Query validation warning".to_string())
591            .with_request_context(context)
592            .with_metrics(metrics)
593            .with_error(error)
594            .with_source(source);
595
596        let json = entry.to_json_string();
597        assert!(json.contains("\"level\":\"WARN\""));
598        assert!(json.contains("\"duration_ms\":"));
599        assert!(json.contains("\"error_type\":"));
600        assert!(json.contains("\"file\":"));
601    }
602}