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 const 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")]
130#[non_exhaustive]
131pub enum LogLevel {
132    /// Trace level (most verbose)
133    Trace,
134    /// Debug level
135    Debug,
136    /// Info level
137    Info,
138    /// Warning level
139    Warn,
140    /// Error level
141    Error,
142}
143
144impl fmt::Display for LogLevel {
145    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
146        match self {
147            Self::Trace => write!(f, "TRACE"),
148            Self::Debug => write!(f, "DEBUG"),
149            Self::Info => write!(f, "INFO"),
150            Self::Warn => write!(f, "WARN"),
151            Self::Error => write!(f, "ERROR"),
152        }
153    }
154}
155
156impl From<tracing::Level> for LogLevel {
157    fn from(level: tracing::Level) -> Self {
158        match level {
159            tracing::Level::TRACE => Self::Trace,
160            tracing::Level::DEBUG => Self::Debug,
161            tracing::Level::INFO => Self::Info,
162            tracing::Level::WARN => Self::Warn,
163            tracing::Level::ERROR => Self::Error,
164        }
165    }
166}
167
168/// Structured JSON log entry.
169#[derive(Debug, Clone, Serialize, Deserialize)]
170pub struct StructuredLogEntry {
171    /// Log timestamp (ISO 8601 format)
172    pub timestamp: String,
173
174    /// Log level
175    pub level: LogLevel,
176
177    /// Log message
178    pub message: String,
179
180    /// Request context (if applicable)
181    #[serde(skip_serializing_if = "Option::is_none")]
182    pub request_context: Option<RequestContext>,
183
184    /// Performance metrics
185    #[serde(skip_serializing_if = "Option::is_none")]
186    pub metrics: Option<LogMetrics>,
187
188    /// Error details (if applicable)
189    #[serde(skip_serializing_if = "Option::is_none")]
190    pub error: Option<ErrorDetails>,
191
192    /// Source code location
193    #[serde(skip_serializing_if = "Option::is_none")]
194    pub source: Option<SourceLocation>,
195
196    /// Additional context fields
197    #[serde(skip_serializing_if = "Option::is_none")]
198    pub context: Option<serde_json::Value>,
199}
200
201impl StructuredLogEntry {
202    /// Create new log entry.
203    #[must_use]
204    pub fn new(level: LogLevel, message: String) -> Self {
205        Self {
206            timestamp: chrono::Utc::now().to_rfc3339_opts(chrono::SecondsFormat::Millis, true),
207            level,
208            message,
209            request_context: None,
210            metrics: None,
211            error: None,
212            source: None,
213            context: None,
214        }
215    }
216
217    /// Add request context.
218    #[must_use]
219    pub fn with_request_context(mut self, context: RequestContext) -> Self {
220        self.request_context = Some(context);
221        self
222    }
223
224    /// Add performance metrics.
225    #[must_use]
226    pub const fn with_metrics(mut self, metrics: LogMetrics) -> Self {
227        self.metrics = Some(metrics);
228        self
229    }
230
231    /// Add error details.
232    #[must_use]
233    pub fn with_error(mut self, error: ErrorDetails) -> Self {
234        self.error = Some(error);
235        self
236    }
237
238    /// Add source location.
239    #[must_use]
240    pub fn with_source(mut self, source: SourceLocation) -> Self {
241        self.source = Some(source);
242        self
243    }
244
245    /// Add custom context.
246    #[must_use]
247    pub fn with_context(mut self, context: serde_json::Value) -> Self {
248        self.context = Some(context);
249        self
250    }
251
252    /// Serialize to JSON string.
253    #[must_use]
254    pub fn to_json_string(&self) -> String {
255        serde_json::to_string(self).unwrap_or_else(|_| {
256            format!(
257                r#"{{"level":"{}","message":"{}","error":"serialization failed"}}"#,
258                self.level, self.message
259            )
260        })
261    }
262}
263
264/// Performance metrics for a log entry.
265#[derive(Debug, Clone, Serialize, Deserialize)]
266pub struct LogMetrics {
267    /// Duration in milliseconds
268    #[serde(skip_serializing_if = "Option::is_none")]
269    pub duration_ms: Option<f64>,
270
271    /// Query complexity (depth, field count, etc.)
272    #[serde(skip_serializing_if = "Option::is_none")]
273    pub complexity: Option<u32>,
274
275    /// Number of items processed
276    #[serde(skip_serializing_if = "Option::is_none")]
277    pub items_processed: Option<u64>,
278
279    /// Cache hit indicator
280    #[serde(skip_serializing_if = "Option::is_none")]
281    pub cache_hit: Option<bool>,
282
283    /// Database queries executed
284    #[serde(skip_serializing_if = "Option::is_none")]
285    pub db_queries: Option<u32>,
286}
287
288impl LogMetrics {
289    /// Create new metrics container.
290    #[must_use]
291    pub const fn new() -> Self {
292        Self {
293            duration_ms:     None,
294            complexity:      None,
295            items_processed: None,
296            cache_hit:       None,
297            db_queries:      None,
298        }
299    }
300
301    /// Set duration in milliseconds.
302    #[must_use]
303    pub const fn with_duration_ms(mut self, duration: f64) -> Self {
304        self.duration_ms = Some(duration);
305        self
306    }
307
308    /// Set query complexity.
309    #[must_use]
310    pub const fn with_complexity(mut self, complexity: u32) -> Self {
311        self.complexity = Some(complexity);
312        self
313    }
314
315    /// Set items processed count.
316    #[must_use]
317    pub const fn with_items_processed(mut self, count: u64) -> Self {
318        self.items_processed = Some(count);
319        self
320    }
321
322    /// Set cache hit status.
323    #[must_use]
324    pub const fn with_cache_hit(mut self, hit: bool) -> Self {
325        self.cache_hit = Some(hit);
326        self
327    }
328
329    /// Set database query count.
330    #[must_use]
331    pub const fn with_db_queries(mut self, count: u32) -> Self {
332        self.db_queries = Some(count);
333        self
334    }
335}
336
337impl Default for LogMetrics {
338    fn default() -> Self {
339        Self::new()
340    }
341}
342
343/// Error details for error logs.
344#[derive(Debug, Clone, Serialize, Deserialize)]
345pub struct ErrorDetails {
346    /// Error type/category
347    pub error_type: String,
348
349    /// Error message
350    pub message: String,
351
352    /// Error code (if applicable)
353    #[serde(skip_serializing_if = "Option::is_none")]
354    pub code: Option<String>,
355
356    /// Stack trace (in debug builds)
357    #[serde(skip_serializing_if = "Option::is_none")]
358    pub stack_trace: Option<String>,
359}
360
361impl ErrorDetails {
362    /// Create new error details.
363    #[must_use]
364    pub const fn new(error_type: String, message: String) -> Self {
365        Self {
366            error_type,
367            message,
368            code: None,
369            stack_trace: None,
370        }
371    }
372
373    /// Set error code.
374    #[must_use]
375    pub fn with_code(mut self, code: String) -> Self {
376        self.code = Some(code);
377        self
378    }
379
380    /// Set stack trace.
381    #[must_use]
382    pub fn with_stack_trace(mut self, trace: String) -> Self {
383        self.stack_trace = Some(trace);
384        self
385    }
386}
387
388/// Source code location information.
389#[derive(Debug, Clone, Serialize, Deserialize)]
390pub struct SourceLocation {
391    /// Source file name
392    pub file: String,
393
394    /// Line number
395    pub line: u32,
396
397    /// Module path
398    pub module: String,
399}
400
401impl SourceLocation {
402    /// Create new source location.
403    #[must_use]
404    pub const fn new(file: String, line: u32, module: String) -> Self {
405        Self { file, line, module }
406    }
407}
408
409/// Request logger for contextual logging.
410#[derive(Debug, Clone)]
411pub struct RequestLogger {
412    context: Arc<RequestContext>,
413}
414
415impl RequestLogger {
416    /// Create new request logger.
417    #[must_use]
418    pub fn new(context: RequestContext) -> Self {
419        Self {
420            context: Arc::new(context),
421        }
422    }
423
424    /// Create from request ID.
425    #[must_use]
426    pub fn with_request_id(request_id: RequestId) -> Self {
427        Self::new(RequestContext {
428            request_id,
429            ..Default::default()
430        })
431    }
432
433    /// Get request context.
434    #[must_use]
435    pub fn context(&self) -> &RequestContext {
436        &self.context
437    }
438
439    /// Create info log entry with context.
440    pub fn info(&self, message: impl Into<String>) -> StructuredLogEntry {
441        StructuredLogEntry::new(LogLevel::Info, message.into())
442            .with_request_context((*self.context).clone())
443    }
444
445    /// Create warn log entry with context.
446    pub fn warn(&self, message: impl Into<String>) -> StructuredLogEntry {
447        StructuredLogEntry::new(LogLevel::Warn, message.into())
448            .with_request_context((*self.context).clone())
449    }
450
451    /// Create error log entry with context.
452    pub fn error(&self, message: impl Into<String>) -> StructuredLogEntry {
453        StructuredLogEntry::new(LogLevel::Error, message.into())
454            .with_request_context((*self.context).clone())
455    }
456
457    /// Create debug log entry with context.
458    pub fn debug(&self, message: impl Into<String>) -> StructuredLogEntry {
459        StructuredLogEntry::new(LogLevel::Debug, message.into())
460            .with_request_context((*self.context).clone())
461    }
462}
463
464#[cfg(test)]
465mod tests {
466    #![allow(clippy::unwrap_used)] // Reason: test code, panics acceptable
467    #![allow(clippy::cast_precision_loss)] // Reason: test metrics reporting
468    #![allow(clippy::cast_sign_loss)] // Reason: test data uses small positive integers
469    #![allow(clippy::cast_possible_truncation)] // Reason: test data values are bounded
470    #![allow(clippy::cast_possible_wrap)] // Reason: test data values are bounded
471    #![allow(clippy::missing_panics_doc)] // Reason: test helpers
472    #![allow(clippy::missing_errors_doc)] // Reason: test helpers
473    #![allow(missing_docs)] // Reason: test code
474    #![allow(clippy::items_after_statements)] // Reason: test helpers defined near use site
475
476    use super::*;
477
478    #[test]
479    fn test_request_id_generation() {
480        let id1 = RequestId::new();
481        let id2 = RequestId::new();
482        assert_ne!(id1.0, id2.0);
483    }
484
485    #[test]
486    fn test_request_context_builder() {
487        let context = RequestContext::new()
488            .with_operation("GetUser".to_string())
489            .with_user_id("user123".to_string())
490            .with_client_ip("192.168.1.1".to_string())
491            .with_api_version("v1".to_string());
492
493        assert_eq!(context.operation, Some("GetUser".to_string()));
494        assert_eq!(context.user_id, Some("user123".to_string()));
495        assert_eq!(context.client_ip, Some("192.168.1.1".to_string()));
496        assert_eq!(context.api_version, Some("v1".to_string()));
497    }
498
499    #[test]
500    fn test_log_entry_creation() {
501        let entry = StructuredLogEntry::new(LogLevel::Info, "test message".to_string());
502        assert_eq!(entry.level, LogLevel::Info);
503        assert_eq!(entry.message, "test message");
504        assert!(entry.request_context.is_none());
505    }
506
507    #[test]
508    fn test_log_entry_with_context() {
509        let context = RequestContext::new().with_operation("Query".to_string());
510
511        let entry = StructuredLogEntry::new(LogLevel::Info, "operation executed".to_string())
512            .with_request_context(context);
513
514        assert_eq!(entry.request_context.unwrap().operation, Some("Query".to_string()));
515    }
516
517    #[test]
518    fn test_log_metrics_builder() {
519        let metrics = LogMetrics::new()
520            .with_duration_ms(123.45)
521            .with_complexity(5)
522            .with_items_processed(100)
523            .with_cache_hit(true)
524            .with_db_queries(3);
525
526        assert_eq!(metrics.duration_ms, Some(123.45));
527        assert_eq!(metrics.complexity, Some(5));
528        assert_eq!(metrics.items_processed, Some(100));
529        assert_eq!(metrics.cache_hit, Some(true));
530        assert_eq!(metrics.db_queries, Some(3));
531    }
532
533    #[test]
534    fn test_error_details_builder() {
535        let error =
536            ErrorDetails::new("DatabaseError".to_string(), "Connection timeout".to_string())
537                .with_code("DB_TIMEOUT".to_string());
538
539        assert_eq!(error.error_type, "DatabaseError");
540        assert_eq!(error.message, "Connection timeout");
541        assert_eq!(error.code, Some("DB_TIMEOUT".to_string()));
542    }
543
544    #[test]
545    fn test_log_entry_json_serialization() {
546        let entry = StructuredLogEntry::new(LogLevel::Error, "test error".to_string());
547        let json = entry.to_json_string();
548
549        assert!(json.contains("\"level\":\"ERROR\""));
550        assert!(json.contains("\"message\":\"test error\""));
551        assert!(json.contains("\"timestamp\":"));
552    }
553
554    #[test]
555    fn test_request_logger_creation() {
556        let context = RequestContext::new().with_operation("Query".to_string());
557        let logger = RequestLogger::new(context);
558
559        assert_eq!(logger.context().operation, Some("Query".to_string()));
560    }
561
562    #[test]
563    fn test_request_logger_log_entry() {
564        let logger = RequestLogger::with_request_id(RequestId::new());
565        let entry = logger.info("test message");
566
567        assert_eq!(entry.level, LogLevel::Info);
568        assert!(
569            entry.request_context.is_some(),
570            "RequestLogger should attach request_context to every log entry"
571        );
572    }
573
574    #[test]
575    fn test_log_level_conversion() {
576        assert_eq!(LogLevel::from(tracing::Level::INFO), LogLevel::Info);
577        assert_eq!(LogLevel::from(tracing::Level::WARN), LogLevel::Warn);
578        assert_eq!(LogLevel::from(tracing::Level::ERROR), LogLevel::Error);
579        assert_eq!(LogLevel::from(tracing::Level::DEBUG), LogLevel::Debug);
580        assert_eq!(LogLevel::from(tracing::Level::TRACE), LogLevel::Trace);
581    }
582
583    #[test]
584    fn test_complex_log_entry() {
585        let context = RequestContext::new()
586            .with_operation("GetUsers".to_string())
587            .with_user_id("user123".to_string());
588
589        let metrics = LogMetrics::new()
590            .with_duration_ms(45.67)
591            .with_db_queries(2)
592            .with_cache_hit(true);
593
594        let error =
595            ErrorDetails::new("ValidationError".to_string(), "Invalid query parameter".to_string());
596
597        let source = SourceLocation::new(
598            "routes/graphql.rs".to_string(),
599            42,
600            "fraiseql_server::routes".to_string(),
601        );
602
603        let entry = StructuredLogEntry::new(LogLevel::Warn, "Query validation warning".to_string())
604            .with_request_context(context)
605            .with_metrics(metrics)
606            .with_error(error)
607            .with_source(source);
608
609        let json = entry.to_json_string();
610        assert!(json.contains("\"level\":\"WARN\""));
611        assert!(json.contains("\"duration_ms\":"));
612        assert!(json.contains("\"error_type\":"));
613        assert!(json.contains("\"file\":"));
614    }
615}
fraiseql_server/logging.rs

fraiseql_server/
logging.rs
