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    pub fn from_env() -> Self {
112        let min_level = std::env::var("AWS_LAMBDA_LOG_LEVEL")
113            .ok()
114            .and_then(|val| match val.to_uppercase().as_str() {
115                "DEBUG" => Some(LogLevel::Debug),
116                "INFO" => Some(LogLevel::Info),
117                "WARN" => Some(LogLevel::Warn),
118                "ERROR" => Some(LogLevel::Error),
119                _ => None,
120            })
121            .unwrap_or(LogLevel::Debug);
122
123        Self {
124            execution_context: None,
125            min_level,
126        }
127    }
128
129    /// Sets the execution context for all subsequent log entries.
130    pub fn set_context(&mut self, context: JsonLogContext) {
131        self.execution_context = Some(context);
132    }
133
134    /// Returns `true` if a message at the given level should be emitted.
135    fn should_log(&self, level: LogLevel) -> bool {
136        level >= self.min_level
137    }
138
139    /// Builds and prints a JSON log entry to stdout.
140    fn emit(&self, level_str: &str, level: LogLevel, message: &str, info: &LogInfo) {
141        if !self.should_log(level) {
142            return;
143        }
144
145        if let Some(json) = self.build_json(level_str, message, info) {
146            println!("{}", json);
147        }
148    }
149
150    /// Builds a JSON string for a log entry, or `None` if serialization fails.
151    fn build_json(&self, level_str: &str, message: &str, info: &LogInfo) -> Option<String> {
152        let (request_id, execution_arn, tenant_id) = match &self.execution_context {
153            Some(ctx) => (
154                ctx.request_id.clone(),
155                ctx.durable_execution_arn.clone(),
156                ctx.tenant_id.clone(),
157            ),
158            None => (String::new(), String::new(), None),
159        };
160
161        // Extract optional fields from LogInfo extras
162        let mut attempt: Option<u32> = None;
163        let mut error_type: Option<String> = None;
164        let mut error_message: Option<String> = None;
165
166        for (key, value) in &info.extra {
167            match key.as_str() {
168                "attempt" => attempt = value.parse().ok(),
169                "errorType" => error_type = Some(value.clone()),
170                "errorMessage" => error_message = Some(value.clone()),
171                _ => {}
172            }
173        }
174
175        let entry = JsonLogEntry {
176            level: level_str.to_string(),
177            timestamp: iso8601_now(),
178            request_id,
179            execution_arn,
180            message: message.to_string(),
181            tenant_id,
182            operation_id: info.operation_id.clone(),
183            attempt,
184            error_type,
185            error_message,
186        };
187
188        serde_json::to_string(&entry).ok()
189    }
190}
191
192impl Logger for StructuredJsonLogger {
193    fn debug(&self, message: &str, info: &LogInfo) {
194        self.emit("DEBUG", LogLevel::Debug, message, info);
195    }
196
197    fn info(&self, message: &str, info: &LogInfo) {
198        self.emit("INFO", LogLevel::Info, message, info);
199    }
200
201    fn warn(&self, message: &str, info: &LogInfo) {
202        self.emit("WARN", LogLevel::Warn, message, info);
203    }
204
205    fn error(&self, message: &str, info: &LogInfo) {
206        self.emit("ERROR", LogLevel::Error, message, info);
207    }
208}
209
210/// Returns the current UTC time as an ISO 8601 string with millisecond precision.
211fn iso8601_now() -> String {
212    let now = SystemTime::now()
213        .duration_since(SystemTime::UNIX_EPOCH)
214        .unwrap_or_default();
215    let secs = now.as_secs();
216    let millis = now.subsec_millis();
217
218    // Convert seconds to date/time components
219    let days = secs / 86400;
220    let time_secs = secs % 86400;
221    let hours = time_secs / 3600;
222    let minutes = (time_secs % 3600) / 60;
223    let seconds = time_secs % 60;
224
225    // Convert days since epoch to year/month/day
226    let (year, month, day) = days_to_ymd(days);
227
228    format!(
229        "{:04}-{:02}-{:02}T{:02}:{:02}:{:02}.{:03}Z",
230        year, month, day, hours, minutes, seconds, millis
231    )
232}
233
234/// Converts days since Unix epoch to (year, month, day).
235fn days_to_ymd(days: u64) -> (u64, u64, u64) {
236    // Algorithm from http://howardhinnant.github.io/date_algorithms.html
237    let z = days + 719468;
238    let era = z / 146097;
239    let doe = z - era * 146097;
240    let yoe = (doe - doe / 1460 + doe / 36524 - doe / 146096) / 365;
241    let y = yoe + era * 400;
242    let doy = doe - (365 * yoe + yoe / 4 - yoe / 100);
243    let mp = (5 * doy + 2) / 153;
244    let d = doy - (153 * mp + 2) / 5 + 1;
245    let m = if mp < 10 { mp + 3 } else { mp - 9 };
246    let y = if m <= 2 { y + 1 } else { y };
247    (y, m, d)
248}
249
250#[cfg(test)]
251mod tests {
252    use super::*;
253    use serde_json::Value;
254    use std::sync::Mutex;
255
256    /// Mutex to serialize tests that mutate the `AWS_LAMBDA_LOG_LEVEL` env var,
257    /// preventing race conditions when tests run in parallel.
258    static ENV_MUTEX: Mutex<()> = Mutex::new(());
259
260    fn make_logger_with_context() -> StructuredJsonLogger {
261        let mut logger = StructuredJsonLogger::new(LogLevel::Debug);
262        logger.set_context(JsonLogContext {
263            request_id: "req-abc-123".to_string(),
264            durable_execution_arn:
265                "arn:aws:lambda:us-east-1:123456789012:function:my-func:durable:exec-1".to_string(),
266            tenant_id: None,
267        });
268        logger
269    }
270
271    #[test]
272    fn test_output_is_valid_json() {
273        let logger = make_logger_with_context();
274        let info = LogInfo::new("arn:aws:test");
275        let json_str = logger.build_json("INFO", "hello world", &info).unwrap();
276        let parsed: Value = serde_json::from_str(&json_str).expect("output must be valid JSON");
277        assert!(parsed.is_object());
278    }
279
280    #[test]
281    fn test_required_fields_present() {
282        let logger = make_logger_with_context();
283        let info = LogInfo::default();
284        let json_str = logger.build_json("WARN", "test message", &info).unwrap();
285        let v: Value = serde_json::from_str(&json_str).unwrap();
286
287        assert_eq!(v["level"], "WARN");
288        assert!(v["timestamp"].as_str().unwrap().ends_with('Z'));
289        assert_eq!(v["requestId"], "req-abc-123");
290        assert_eq!(
291            v["executionArn"],
292            "arn:aws:lambda:us-east-1:123456789012:function:my-func:durable:exec-1"
293        );
294        assert_eq!(v["message"], "test message");
295    }
296
297    #[test]
298    fn test_timestamp_iso8601_format() {
299        let logger = make_logger_with_context();
300        let info = LogInfo::default();
301        let json_str = logger.build_json("DEBUG", "ts check", &info).unwrap();
302        let v: Value = serde_json::from_str(&json_str).unwrap();
303        let ts = v["timestamp"].as_str().unwrap();
304        // ISO 8601: YYYY-MM-DDTHH:MM:SS.mmmZ
305        assert_eq!(ts.len(), 24, "timestamp should be 24 chars: {}", ts);
306        assert!(ts.contains('T'));
307        assert!(ts.ends_with('Z'));
308    }
309
310    #[test]
311    fn test_optional_fields_absent_when_not_set() {
312        let logger = make_logger_with_context();
313        let info = LogInfo::default();
314        let json_str = logger.build_json("INFO", "minimal", &info).unwrap();
315        let v: Value = serde_json::from_str(&json_str).unwrap();
316
317        assert!(v.get("tenantId").is_none());
318        assert!(v.get("operationId").is_none());
319        assert!(v.get("attempt").is_none());
320        assert!(v.get("errorType").is_none());
321        assert!(v.get("errorMessage").is_none());
322    }
323
324    #[test]
325    fn test_tenant_id_included_when_configured() {
326        let mut logger = StructuredJsonLogger::new(LogLevel::Debug);
327        logger.set_context(JsonLogContext {
328            request_id: "req-1".to_string(),
329            durable_execution_arn: "arn:test".to_string(),
330            tenant_id: Some("tenant-xyz".to_string()),
331        });
332        let info = LogInfo::default();
333        let json_str = logger.build_json("INFO", "with tenant", &info).unwrap();
334        let v: Value = serde_json::from_str(&json_str).unwrap();
335
336        assert_eq!(v["tenantId"], "tenant-xyz");
337    }
338
339    #[test]
340    fn test_operation_id_from_log_info() {
341        let logger = make_logger_with_context();
342        let info = LogInfo::default().with_operation_id("op-456");
343        let json_str = logger.build_json("INFO", "with op", &info).unwrap();
344        let v: Value = serde_json::from_str(&json_str).unwrap();
345
346        assert_eq!(v["operationId"], "op-456");
347    }
348
349    #[test]
350    fn test_attempt_from_extras() {
351        let logger = make_logger_with_context();
352        let info = LogInfo::default().with_extra("attempt", "3");
353        let json_str = logger.build_json("INFO", "retry", &info).unwrap();
354        let v: Value = serde_json::from_str(&json_str).unwrap();
355
356        assert_eq!(v["attempt"], 3);
357    }
358
359    #[test]
360    fn test_error_fields_from_extras() {
361        let logger = make_logger_with_context();
362        let info = LogInfo::default()
363            .with_extra("errorType", "TimeoutError")
364            .with_extra("errorMessage", "connection timed out");
365        let json_str = logger.build_json("ERROR", "failed", &info).unwrap();
366        let v: Value = serde_json::from_str(&json_str).unwrap();
367
368        assert_eq!(v["errorType"], "TimeoutError");
369        assert_eq!(v["errorMessage"], "connection timed out");
370    }
371
372    #[test]
373    fn test_level_filtering_debug_allows_all() {
374        let logger = StructuredJsonLogger::new(LogLevel::Debug);
375        assert!(logger.should_log(LogLevel::Debug));
376        assert!(logger.should_log(LogLevel::Info));
377        assert!(logger.should_log(LogLevel::Warn));
378        assert!(logger.should_log(LogLevel::Error));
379    }
380
381    #[test]
382    fn test_level_filtering_warn_suppresses_debug_and_info() {
383        let logger = StructuredJsonLogger::new(LogLevel::Warn);
384        assert!(!logger.should_log(LogLevel::Debug));
385        assert!(!logger.should_log(LogLevel::Info));
386        assert!(logger.should_log(LogLevel::Warn));
387        assert!(logger.should_log(LogLevel::Error));
388    }
389
390    #[test]
391    fn test_level_filtering_error_only() {
392        let logger = StructuredJsonLogger::new(LogLevel::Error);
393        assert!(!logger.should_log(LogLevel::Debug));
394        assert!(!logger.should_log(LogLevel::Info));
395        assert!(!logger.should_log(LogLevel::Warn));
396        assert!(logger.should_log(LogLevel::Error));
397    }
398
399    #[test]
400    fn test_level_filtering_info_suppresses_debug() {
401        let logger = StructuredJsonLogger::new(LogLevel::Info);
402        assert!(!logger.should_log(LogLevel::Debug));
403        assert!(logger.should_log(LogLevel::Info));
404        assert!(logger.should_log(LogLevel::Warn));
405        assert!(logger.should_log(LogLevel::Error));
406    }
407
408    #[test]
409    fn test_logger_trait_methods_set_correct_level() {
410        let mut logger = StructuredJsonLogger::new(LogLevel::Debug);
411        logger.set_context(JsonLogContext {
412            request_id: "r".to_string(),
413            durable_execution_arn: "a".to_string(),
414            tenant_id: None,
415        });
416        let info = LogInfo::default();
417
418        // Verify each trait method produces the correct level string
419        let debug_json = logger.build_json("DEBUG", "d", &info).unwrap();
420        let info_json = logger.build_json("INFO", "i", &info).unwrap();
421        let warn_json = logger.build_json("WARN", "w", &info).unwrap();
422        let error_json = logger.build_json("ERROR", "e", &info).unwrap();
423
424        let dv: Value = serde_json::from_str(&debug_json).unwrap();
425        let iv: Value = serde_json::from_str(&info_json).unwrap();
426        let wv: Value = serde_json::from_str(&warn_json).unwrap();
427        let ev: Value = serde_json::from_str(&error_json).unwrap();
428
429        assert_eq!(dv["level"], "DEBUG");
430        assert_eq!(iv["level"], "INFO");
431        assert_eq!(wv["level"], "WARN");
432        assert_eq!(ev["level"], "ERROR");
433    }
434
435    // --- AWS_LAMBDA_LOG_LEVEL env var tests (Reqs 10.1, 10.2) ---
436
437    #[test]
438    fn test_from_env_debug() {
439        let _lock = ENV_MUTEX.lock().unwrap();
440        std::env::set_var("AWS_LAMBDA_LOG_LEVEL", "DEBUG");
441        let logger = StructuredJsonLogger::from_env();
442        assert_eq!(logger.min_level, LogLevel::Debug);
443        std::env::remove_var("AWS_LAMBDA_LOG_LEVEL");
444    }
445
446    #[test]
447    fn test_from_env_info() {
448        let _lock = ENV_MUTEX.lock().unwrap();
449        std::env::set_var("AWS_LAMBDA_LOG_LEVEL", "INFO");
450        let logger = StructuredJsonLogger::from_env();
451        assert_eq!(logger.min_level, LogLevel::Info);
452        std::env::remove_var("AWS_LAMBDA_LOG_LEVEL");
453    }
454
455    #[test]
456    fn test_from_env_warn() {
457        let _lock = ENV_MUTEX.lock().unwrap();
458        std::env::set_var("AWS_LAMBDA_LOG_LEVEL", "WARN");
459        let logger = StructuredJsonLogger::from_env();
460        assert_eq!(logger.min_level, LogLevel::Warn);
461        std::env::remove_var("AWS_LAMBDA_LOG_LEVEL");
462    }
463
464    #[test]
465    fn test_from_env_error() {
466        let _lock = ENV_MUTEX.lock().unwrap();
467        std::env::set_var("AWS_LAMBDA_LOG_LEVEL", "ERROR");
468        let logger = StructuredJsonLogger::from_env();
469        assert_eq!(logger.min_level, LogLevel::Error);
470        std::env::remove_var("AWS_LAMBDA_LOG_LEVEL");
471    }
472
473    #[test]
474    fn test_from_env_case_insensitive() {
475        let _lock = ENV_MUTEX.lock().unwrap();
476        std::env::set_var("AWS_LAMBDA_LOG_LEVEL", "warn");
477        let logger = StructuredJsonLogger::from_env();
478        assert_eq!(logger.min_level, LogLevel::Warn);
479
480        std::env::set_var("AWS_LAMBDA_LOG_LEVEL", "Info");
481        let logger = StructuredJsonLogger::from_env();
482        assert_eq!(logger.min_level, LogLevel::Info);
483
484        std::env::set_var("AWS_LAMBDA_LOG_LEVEL", "error");
485        let logger = StructuredJsonLogger::from_env();
486        assert_eq!(logger.min_level, LogLevel::Error);
487        std::env::remove_var("AWS_LAMBDA_LOG_LEVEL");
488    }
489
490    #[test]
491    fn test_from_env_invalid_defaults_to_debug() {
492        let _lock = ENV_MUTEX.lock().unwrap();
493        std::env::set_var("AWS_LAMBDA_LOG_LEVEL", "TRACE");
494        let logger = StructuredJsonLogger::from_env();
495        assert_eq!(logger.min_level, LogLevel::Debug);
496
497        std::env::set_var("AWS_LAMBDA_LOG_LEVEL", "garbage");
498        let logger = StructuredJsonLogger::from_env();
499        assert_eq!(logger.min_level, LogLevel::Debug);
500
501        std::env::set_var("AWS_LAMBDA_LOG_LEVEL", "");
502        let logger = StructuredJsonLogger::from_env();
503        assert_eq!(logger.min_level, LogLevel::Debug);
504        std::env::remove_var("AWS_LAMBDA_LOG_LEVEL");
505    }
506
507    #[test]
508    fn test_from_env_missing_defaults_to_debug() {
509        let _lock = ENV_MUTEX.lock().unwrap();
510        std::env::remove_var("AWS_LAMBDA_LOG_LEVEL");
511        let logger = StructuredJsonLogger::from_env();
512        assert_eq!(logger.min_level, LogLevel::Debug);
513    }
514}
durable_execution_sdk/structured_json_logger.rs

durable_execution_sdk/
structured_json_logger.rs
