durable_execution_sdk/
structured_json_logger.rs

1//! Structured JSON logger for durable execution.
2//!
3//! This module provides a [`StructuredJsonLogger`] that emits structured JSON log entries
4//! to stdout, matching the Node.js DefaultLogger output format. Each log entry includes
5//! execution context (requestId, executionArn, tenantId) and optional operation metadata
6//! (operationId, attempt, error details).
7//!
8//! # Requirements
9//!
10//! - 9.1: Output is valid JSON to stdout
11//! - 9.2: Contains level, timestamp, requestId, executionArn, message
12//! - 9.3: Includes tenantId when configured
13//! - 9.4: Includes operationId from LogInfo
14//! - 9.5: Level filtering via min_level
15
16use crate::context::{LogInfo, Logger};
17use crate::sealed::Sealed;
18use serde::Serialize;
19use std::time::SystemTime;
20
21/// Log level for filtering structured JSON output.
22///
23/// Priority order: Debug(2) < Info(3) < Warn(4) < Error(5).
24/// Log calls below the configured `min_level` are suppressed.
25#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord)]
26pub enum LogLevel {
27    /// Debug level (priority 2) — verbose diagnostic information.
28    Debug = 2,
29    /// Info level (priority 3) — general operational messages.
30    Info = 3,
31    /// Warn level (priority 4) — potential issues that deserve attention.
32    Warn = 4,
33    /// Error level (priority 5) — failures requiring investigation.
34    Error = 5,
35}
36
37/// Context fields included in every JSON log entry.
38///
39/// Set this on a [`StructuredJsonLogger`] to enrich all log output with
40/// execution-level metadata such as `requestId` and `executionArn`.
41pub struct JsonLogContext {
42    /// The Lambda request ID for this invocation.
43    pub request_id: String,
44    /// The durable execution ARN.
45    pub durable_execution_arn: String,
46    /// Optional tenant identifier for multi-tenant workloads.
47    pub tenant_id: Option<String>,
48}
49
50/// A single structured log entry serialized to JSON.
51#[derive(Serialize)]
52struct JsonLogEntry {
53    level: String,
54    timestamp: String,
55    #[serde(rename = "requestId")]
56    request_id: String,
57    #[serde(rename = "executionArn")]
58    execution_arn: String,
59    message: String,
60    #[serde(skip_serializing_if = "Option::is_none")]
61    #[serde(rename = "tenantId")]
62    tenant_id: Option<String>,
63    #[serde(skip_serializing_if = "Option::is_none")]
64    #[serde(rename = "operationId")]
65    operation_id: Option<String>,
66    #[serde(skip_serializing_if = "Option::is_none")]
67    attempt: Option<u32>,
68    #[serde(skip_serializing_if = "Option::is_none")]
69    #[serde(rename = "errorType")]
70    error_type: Option<String>,
71    #[serde(skip_serializing_if = "Option::is_none")]
72    #[serde(rename = "errorMessage")]
73    error_message: Option<String>,
74}
75
76/// Structured JSON logger for durable execution.
77///
78/// Emits one JSON object per line to stdout. Each entry includes execution
79/// context from [`JsonLogContext`] and optional operation metadata extracted
80/// from [`LogInfo`].
81///
82/// # Level Filtering
83///
84/// The `min_level` field controls which messages are emitted. Messages with
85/// a level below `min_level` are silently dropped.
86pub struct StructuredJsonLogger {
87    execution_context: Option<JsonLogContext>,
88    min_level: LogLevel,
89}
90
91impl Sealed for StructuredJsonLogger {}
92
93impl StructuredJsonLogger {
94    /// Creates a new `StructuredJsonLogger` with the given minimum log level.
95    ///
96    /// No execution context is set initially — call [`set_context`](Self::set_context)
97    /// to attach request and execution metadata.
98    pub fn new(min_level: LogLevel) -> Self {
99        Self {
100            execution_context: None,
101            min_level,
102        }
103    }
104
105    /// Creates a new `StructuredJsonLogger` with `min_level` derived from the
106    /// `AWS_LAMBDA_LOG_LEVEL` environment variable.
107    ///
108    /// Valid values (case-insensitive): `"DEBUG"`, `"INFO"`, `"WARN"`, `"ERROR"`.
109    /// If the variable is not set or contains an invalid value, defaults to
110    /// [`LogLevel::Debug`] (all messages emitted).
111    ///
112    /// # Requirements
113    ///
114    /// - 10.1: Valid env var → corresponding log level
115    /// - 10.2: Missing/invalid env var → defaults to DEBUG
116    pub fn from_env() -> Self {
117        let min_level = std::env::var("AWS_LAMBDA_LOG_LEVEL")
118            .ok()
119            .and_then(|val| match val.to_uppercase().as_str() {
120                "DEBUG" => Some(LogLevel::Debug),
121                "INFO" => Some(LogLevel::Info),
122                "WARN" => Some(LogLevel::Warn),
123                "ERROR" => Some(LogLevel::Error),
124                _ => None,
125            })
126            .unwrap_or(LogLevel::Debug);
127
128        Self {
129            execution_context: None,
130            min_level,
131        }
132    }
133
134    /// Sets the execution context for all subsequent log entries.
135    pub fn set_context(&mut self, context: JsonLogContext) {
136        self.execution_context = Some(context);
137    }
138
139    /// Returns `true` if a message at the given level should be emitted.
140    fn should_log(&self, level: LogLevel) -> bool {
141        level >= self.min_level
142    }
143
144    /// Builds and prints a JSON log entry to stdout.
145    fn emit(&self, level_str: &str, level: LogLevel, message: &str, info: &LogInfo) {
146        if !self.should_log(level) {
147            return;
148        }
149
150        if let Some(json) = self.build_json(level_str, message, info) {
151            println!("{}", json);
152        }
153    }
154
155    /// Builds a JSON string for a log entry, or `None` if serialization fails.
156    fn build_json(&self, level_str: &str, message: &str, info: &LogInfo) -> Option<String> {
157        let (request_id, execution_arn, tenant_id) = match &self.execution_context {
158            Some(ctx) => (
159                ctx.request_id.clone(),
160                ctx.durable_execution_arn.clone(),
161                ctx.tenant_id.clone(),
162            ),
163            None => (String::new(), String::new(), None),
164        };
165
166        // Extract optional fields from LogInfo extras
167        let mut attempt: Option<u32> = None;
168        let mut error_type: Option<String> = None;
169        let mut error_message: Option<String> = None;
170
171        for (key, value) in &info.extra {
172            match key.as_str() {
173                "attempt" => attempt = value.parse().ok(),
174                "errorType" => error_type = Some(value.clone()),
175                "errorMessage" => error_message = Some(value.clone()),
176                _ => {}
177            }
178        }
179
180        let entry = JsonLogEntry {
181            level: level_str.to_string(),
182            timestamp: iso8601_now(),
183            request_id,
184            execution_arn,
185            message: message.to_string(),
186            tenant_id,
187            operation_id: info.operation_id.clone(),
188            attempt,
189            error_type,
190            error_message,
191        };
192
193        serde_json::to_string(&entry).ok()
194    }
195}
196
197impl Logger for StructuredJsonLogger {
198    fn debug(&self, message: &str, info: &LogInfo) {
199        self.emit("DEBUG", LogLevel::Debug, message, info);
200    }
201
202    fn info(&self, message: &str, info: &LogInfo) {
203        self.emit("INFO", LogLevel::Info, message, info);
204    }
205
206    fn warn(&self, message: &str, info: &LogInfo) {
207        self.emit("WARN", LogLevel::Warn, message, info);
208    }
209
210    fn error(&self, message: &str, info: &LogInfo) {
211        self.emit("ERROR", LogLevel::Error, message, info);
212    }
213}
214
215/// Returns the current UTC time as an ISO 8601 string with millisecond precision.
216fn iso8601_now() -> String {
217    let now = SystemTime::now()
218        .duration_since(SystemTime::UNIX_EPOCH)
219        .unwrap_or_default();
220    let secs = now.as_secs();
221    let millis = now.subsec_millis();
222
223    // Convert seconds to date/time components
224    let days = secs / 86400;
225    let time_secs = secs % 86400;
226    let hours = time_secs / 3600;
227    let minutes = (time_secs % 3600) / 60;
228    let seconds = time_secs % 60;
229
230    // Convert days since epoch to year/month/day
231    let (year, month, day) = days_to_ymd(days);
232
233    format!(
234        "{:04}-{:02}-{:02}T{:02}:{:02}:{:02}.{:03}Z",
235        year, month, day, hours, minutes, seconds, millis
236    )
237}
238
239/// Converts days since Unix epoch to (year, month, day).
240fn days_to_ymd(days: u64) -> (u64, u64, u64) {
241    // Algorithm from http://howardhinnant.github.io/date_algorithms.html
242    let z = days + 719468;
243    let era = z / 146097;
244    let doe = z - era * 146097;
245    let yoe = (doe - doe / 1460 + doe / 36524 - doe / 146096) / 365;
246    let y = yoe + era * 400;
247    let doy = doe - (365 * yoe + yoe / 4 - yoe / 100);
248    let mp = (5 * doy + 2) / 153;
249    let d = doy - (153 * mp + 2) / 5 + 1;
250    let m = if mp < 10 { mp + 3 } else { mp - 9 };
251    let y = if m <= 2 { y + 1 } else { y };
252    (y, m, d)
253}
254
255#[cfg(test)]
256mod tests {
257    use super::*;
258    use serde_json::Value;
259    use std::sync::Mutex;
260
261    /// Mutex to serialize tests that mutate the `AWS_LAMBDA_LOG_LEVEL` env var,
262    /// preventing race conditions when tests run in parallel.
263    static ENV_MUTEX: Mutex<()> = Mutex::new(());
264
265    fn make_logger_with_context() -> StructuredJsonLogger {
266        let mut logger = StructuredJsonLogger::new(LogLevel::Debug);
267        logger.set_context(JsonLogContext {
268            request_id: "req-abc-123".to_string(),
269            durable_execution_arn:
270                "arn:aws:lambda:us-east-1:123456789012:function:my-func:durable:exec-1".to_string(),
271            tenant_id: None,
272        });
273        logger
274    }
275
276    #[test]
277    fn test_output_is_valid_json() {
278        let logger = make_logger_with_context();
279        let info = LogInfo::new("arn:aws:test");
280        let json_str = logger.build_json("INFO", "hello world", &info).unwrap();
281        let parsed: Value = serde_json::from_str(&json_str).expect("output must be valid JSON");
282        assert!(parsed.is_object());
283    }
284
285    #[test]
286    fn test_required_fields_present() {
287        let logger = make_logger_with_context();
288        let info = LogInfo::default();
289        let json_str = logger.build_json("WARN", "test message", &info).unwrap();
290        let v: Value = serde_json::from_str(&json_str).unwrap();
291
292        assert_eq!(v["level"], "WARN");
293        assert!(v["timestamp"].as_str().unwrap().ends_with('Z'));
294        assert_eq!(v["requestId"], "req-abc-123");
295        assert_eq!(
296            v["executionArn"],
297            "arn:aws:lambda:us-east-1:123456789012:function:my-func:durable:exec-1"
298        );
299        assert_eq!(v["message"], "test message");
300    }
301
302    #[test]
303    fn test_timestamp_iso8601_format() {
304        let logger = make_logger_with_context();
305        let info = LogInfo::default();
306        let json_str = logger.build_json("DEBUG", "ts check", &info).unwrap();
307        let v: Value = serde_json::from_str(&json_str).unwrap();
308        let ts = v["timestamp"].as_str().unwrap();
309        // ISO 8601: YYYY-MM-DDTHH:MM:SS.mmmZ
310        assert_eq!(ts.len(), 24, "timestamp should be 24 chars: {}", ts);
311        assert!(ts.contains('T'));
312        assert!(ts.ends_with('Z'));
313    }
314
315    #[test]
316    fn test_optional_fields_absent_when_not_set() {
317        let logger = make_logger_with_context();
318        let info = LogInfo::default();
319        let json_str = logger.build_json("INFO", "minimal", &info).unwrap();
320        let v: Value = serde_json::from_str(&json_str).unwrap();
321
322        assert!(v.get("tenantId").is_none());
323        assert!(v.get("operationId").is_none());
324        assert!(v.get("attempt").is_none());
325        assert!(v.get("errorType").is_none());
326        assert!(v.get("errorMessage").is_none());
327    }
328
329    #[test]
330    fn test_tenant_id_included_when_configured() {
331        let mut logger = StructuredJsonLogger::new(LogLevel::Debug);
332        logger.set_context(JsonLogContext {
333            request_id: "req-1".to_string(),
334            durable_execution_arn: "arn:test".to_string(),
335            tenant_id: Some("tenant-xyz".to_string()),
336        });
337        let info = LogInfo::default();
338        let json_str = logger.build_json("INFO", "with tenant", &info).unwrap();
339        let v: Value = serde_json::from_str(&json_str).unwrap();
340
341        assert_eq!(v["tenantId"], "tenant-xyz");
342    }
343
344    #[test]
345    fn test_operation_id_from_log_info() {
346        let logger = make_logger_with_context();
347        let info = LogInfo::default().with_operation_id("op-456");
348        let json_str = logger.build_json("INFO", "with op", &info).unwrap();
349        let v: Value = serde_json::from_str(&json_str).unwrap();
350
351        assert_eq!(v["operationId"], "op-456");
352    }
353
354    #[test]
355    fn test_attempt_from_extras() {
356        let logger = make_logger_with_context();
357        let info = LogInfo::default().with_extra("attempt", "3");
358        let json_str = logger.build_json("INFO", "retry", &info).unwrap();
359        let v: Value = serde_json::from_str(&json_str).unwrap();
360
361        assert_eq!(v["attempt"], 3);
362    }
363
364    #[test]
365    fn test_error_fields_from_extras() {
366        let logger = make_logger_with_context();
367        let info = LogInfo::default()
368            .with_extra("errorType", "TimeoutError")
369            .with_extra("errorMessage", "connection timed out");
370        let json_str = logger.build_json("ERROR", "failed", &info).unwrap();
371        let v: Value = serde_json::from_str(&json_str).unwrap();
372
373        assert_eq!(v["errorType"], "TimeoutError");
374        assert_eq!(v["errorMessage"], "connection timed out");
375    }
376
377    #[test]
378    fn test_level_filtering_debug_allows_all() {
379        let logger = StructuredJsonLogger::new(LogLevel::Debug);
380        assert!(logger.should_log(LogLevel::Debug));
381        assert!(logger.should_log(LogLevel::Info));
382        assert!(logger.should_log(LogLevel::Warn));
383        assert!(logger.should_log(LogLevel::Error));
384    }
385
386    #[test]
387    fn test_level_filtering_warn_suppresses_debug_and_info() {
388        let logger = StructuredJsonLogger::new(LogLevel::Warn);
389        assert!(!logger.should_log(LogLevel::Debug));
390        assert!(!logger.should_log(LogLevel::Info));
391        assert!(logger.should_log(LogLevel::Warn));
392        assert!(logger.should_log(LogLevel::Error));
393    }
394
395    #[test]
396    fn test_level_filtering_error_only() {
397        let logger = StructuredJsonLogger::new(LogLevel::Error);
398        assert!(!logger.should_log(LogLevel::Debug));
399        assert!(!logger.should_log(LogLevel::Info));
400        assert!(!logger.should_log(LogLevel::Warn));
401        assert!(logger.should_log(LogLevel::Error));
402    }
403
404    #[test]
405    fn test_level_filtering_info_suppresses_debug() {
406        let logger = StructuredJsonLogger::new(LogLevel::Info);
407        assert!(!logger.should_log(LogLevel::Debug));
408        assert!(logger.should_log(LogLevel::Info));
409        assert!(logger.should_log(LogLevel::Warn));
410        assert!(logger.should_log(LogLevel::Error));
411    }
412
413    #[test]
414    fn test_logger_trait_methods_set_correct_level() {
415        let mut logger = StructuredJsonLogger::new(LogLevel::Debug);
416        logger.set_context(JsonLogContext {
417            request_id: "r".to_string(),
418            durable_execution_arn: "a".to_string(),
419            tenant_id: None,
420        });
421        let info = LogInfo::default();
422
423        // Verify each trait method produces the correct level string
424        let debug_json = logger.build_json("DEBUG", "d", &info).unwrap();
425        let info_json = logger.build_json("INFO", "i", &info).unwrap();
426        let warn_json = logger.build_json("WARN", "w", &info).unwrap();
427        let error_json = logger.build_json("ERROR", "e", &info).unwrap();
428
429        let dv: Value = serde_json::from_str(&debug_json).unwrap();
430        let iv: Value = serde_json::from_str(&info_json).unwrap();
431        let wv: Value = serde_json::from_str(&warn_json).unwrap();
432        let ev: Value = serde_json::from_str(&error_json).unwrap();
433
434        assert_eq!(dv["level"], "DEBUG");
435        assert_eq!(iv["level"], "INFO");
436        assert_eq!(wv["level"], "WARN");
437        assert_eq!(ev["level"], "ERROR");
438    }
439
440    // --- AWS_LAMBDA_LOG_LEVEL env var tests (Reqs 10.1, 10.2) ---
441
442    #[test]
443    fn test_from_env_debug() {
444        let _lock = ENV_MUTEX.lock().unwrap();
445        std::env::set_var("AWS_LAMBDA_LOG_LEVEL", "DEBUG");
446        let logger = StructuredJsonLogger::from_env();
447        assert_eq!(logger.min_level, LogLevel::Debug);
448        std::env::remove_var("AWS_LAMBDA_LOG_LEVEL");
449    }
450
451    #[test]
452    fn test_from_env_info() {
453        let _lock = ENV_MUTEX.lock().unwrap();
454        std::env::set_var("AWS_LAMBDA_LOG_LEVEL", "INFO");
455        let logger = StructuredJsonLogger::from_env();
456        assert_eq!(logger.min_level, LogLevel::Info);
457        std::env::remove_var("AWS_LAMBDA_LOG_LEVEL");
458    }
459
460    #[test]
461    fn test_from_env_warn() {
462        let _lock = ENV_MUTEX.lock().unwrap();
463        std::env::set_var("AWS_LAMBDA_LOG_LEVEL", "WARN");
464        let logger = StructuredJsonLogger::from_env();
465        assert_eq!(logger.min_level, LogLevel::Warn);
466        std::env::remove_var("AWS_LAMBDA_LOG_LEVEL");
467    }
468
469    #[test]
470    fn test_from_env_error() {
471        let _lock = ENV_MUTEX.lock().unwrap();
472        std::env::set_var("AWS_LAMBDA_LOG_LEVEL", "ERROR");
473        let logger = StructuredJsonLogger::from_env();
474        assert_eq!(logger.min_level, LogLevel::Error);
475        std::env::remove_var("AWS_LAMBDA_LOG_LEVEL");
476    }
477
478    #[test]
479    fn test_from_env_case_insensitive() {
480        let _lock = ENV_MUTEX.lock().unwrap();
481        std::env::set_var("AWS_LAMBDA_LOG_LEVEL", "warn");
482        let logger = StructuredJsonLogger::from_env();
483        assert_eq!(logger.min_level, LogLevel::Warn);
484
485        std::env::set_var("AWS_LAMBDA_LOG_LEVEL", "Info");
486        let logger = StructuredJsonLogger::from_env();
487        assert_eq!(logger.min_level, LogLevel::Info);
488
489        std::env::set_var("AWS_LAMBDA_LOG_LEVEL", "error");
490        let logger = StructuredJsonLogger::from_env();
491        assert_eq!(logger.min_level, LogLevel::Error);
492        std::env::remove_var("AWS_LAMBDA_LOG_LEVEL");
493    }
494
495    #[test]
496    fn test_from_env_invalid_defaults_to_debug() {
497        let _lock = ENV_MUTEX.lock().unwrap();
498        std::env::set_var("AWS_LAMBDA_LOG_LEVEL", "TRACE");
499        let logger = StructuredJsonLogger::from_env();
500        assert_eq!(logger.min_level, LogLevel::Debug);
501
502        std::env::set_var("AWS_LAMBDA_LOG_LEVEL", "garbage");
503        let logger = StructuredJsonLogger::from_env();
504        assert_eq!(logger.min_level, LogLevel::Debug);
505
506        std::env::set_var("AWS_LAMBDA_LOG_LEVEL", "");
507        let logger = StructuredJsonLogger::from_env();
508        assert_eq!(logger.min_level, LogLevel::Debug);
509        std::env::remove_var("AWS_LAMBDA_LOG_LEVEL");
510    }
511
512    #[test]
513    fn test_from_env_missing_defaults_to_debug() {
514        let _lock = ENV_MUTEX.lock().unwrap();
515        std::env::remove_var("AWS_LAMBDA_LOG_LEVEL");
516        let logger = StructuredJsonLogger::from_env();
517        assert_eq!(logger.min_level, LogLevel::Debug);
518    }
519}
durable_execution_sdk/structured_json_logger.rs

durable_execution_sdk/
structured_json_logger.rs
