durable_lambda_core/operations/
log.rs

1//! Log operation — replay-safe structured logging.
2//!
3//! Implement FR29-FR31: deduplicated log messages, tracing integration,
4//! suppress duplicate output during replay phase.
5//!
6//! Unlike all other operations in this module, logging is NOT a checkpoint-based
7//! durable operation. It does not send checkpoints to AWS, does not generate
8//! operation IDs, and does not interact with the replay engine's operations map.
9//!
10//! Replay suppression is purely client-side: if the context is replaying,
11//! log calls are no-ops. This matches the Python SDK's `context.logger` behavior.
12
13use crate::context::DurableContext;
14
15impl DurableContext {
16    /// Return the parent operation ID for log enrichment, or empty string for root context.
17    fn log_parent_id(&self) -> &str {
18        self.parent_op_id().unwrap_or("")
19    }
20
21    /// Emit a replay-safe info-level log message.
22    ///
23    /// During execution mode, emits the message via `tracing::info!` with
24    /// execution context enrichment (execution ARN, parent ID for child
25    /// contexts). During replay mode, the call is a no-op — no log output
26    /// is produced.
27    ///
28    /// # Arguments
29    ///
30    /// * `message` — The log message to emit
31    ///
32    /// # Examples
33    ///
34    /// ```no_run
35    /// # async fn example(ctx: &durable_lambda_core::context::DurableContext) {
36    /// ctx.log("Order processing started");
37    /// // During replay, this produces no output.
38    /// # }
39    /// ```
40    pub fn log(&self, message: &str) {
41        if !self.is_replaying() {
42            tracing::info!(
43                execution_arn = %self.arn(),
44                parent_id = %self.log_parent_id(),
45                message = message,
46                "durable_log"
47            );
48        }
49    }
50
51    /// Emit a replay-safe info-level log message with structured data.
52    ///
53    /// During execution mode, emits the message and structured data via
54    /// `tracing::info!`. During replay mode, the call is a no-op.
55    ///
56    /// # Arguments
57    ///
58    /// * `message` — The log message to emit
59    /// * `data` — Structured data to include in the log event
60    ///
61    /// # Examples
62    ///
63    /// ```no_run
64    /// # async fn example(ctx: &durable_lambda_core::context::DurableContext) {
65    /// ctx.log_with_data("Order processed", &serde_json::json!({"order_id": 42}));
66    /// # }
67    /// ```
68    pub fn log_with_data(&self, message: &str, data: &serde_json::Value) {
69        if !self.is_replaying() {
70            tracing::info!(
71                execution_arn = %self.arn(),
72                parent_id = %self.log_parent_id(),
73                data = %data,
74                message = message,
75                "durable_log"
76            );
77        }
78    }
79
80    /// Emit a replay-safe debug-level log message.
81    ///
82    /// During execution mode, emits via `tracing::debug!`. During replay
83    /// mode, the call is a no-op.
84    ///
85    /// # Arguments
86    ///
87    /// * `message` — The log message to emit
88    ///
89    /// # Examples
90    ///
91    /// ```no_run
92    /// # async fn example(ctx: &durable_lambda_core::context::DurableContext) {
93    /// ctx.log_debug("Validating order fields");
94    /// # }
95    /// ```
96    pub fn log_debug(&self, message: &str) {
97        if !self.is_replaying() {
98            tracing::debug!(
99                execution_arn = %self.arn(),
100                parent_id = %self.log_parent_id(),
101                message = message,
102                "durable_log"
103            );
104        }
105    }
106
107    /// Emit a replay-safe warn-level log message.
108    ///
109    /// During execution mode, emits via `tracing::warn!`. During replay
110    /// mode, the call is a no-op.
111    ///
112    /// # Arguments
113    ///
114    /// * `message` — The log message to emit
115    ///
116    /// # Examples
117    ///
118    /// ```no_run
119    /// # async fn example(ctx: &durable_lambda_core::context::DurableContext) {
120    /// ctx.log_warn("Inventory below threshold");
121    /// # }
122    /// ```
123    pub fn log_warn(&self, message: &str) {
124        if !self.is_replaying() {
125            tracing::warn!(
126                execution_arn = %self.arn(),
127                parent_id = %self.log_parent_id(),
128                message = message,
129                "durable_log"
130            );
131        }
132    }
133
134    /// Emit a replay-safe error-level log message.
135    ///
136    /// During execution mode, emits via `tracing::error!`. During replay
137    /// mode, the call is a no-op.
138    ///
139    /// # Arguments
140    ///
141    /// * `message` — The log message to emit
142    ///
143    /// # Examples
144    ///
145    /// ```no_run
146    /// # async fn example(ctx: &durable_lambda_core::context::DurableContext) {
147    /// ctx.log_error("Payment gateway timeout");
148    /// # }
149    /// ```
150    pub fn log_error(&self, message: &str) {
151        if !self.is_replaying() {
152            tracing::error!(
153                execution_arn = %self.arn(),
154                parent_id = %self.log_parent_id(),
155                message = message,
156                "durable_log"
157            );
158        }
159    }
160
161    /// Emit a replay-safe debug-level log message with structured data.
162    ///
163    /// During execution mode, emits via `tracing::debug!` with data field.
164    /// During replay mode, the call is a no-op.
165    ///
166    /// # Arguments
167    ///
168    /// * `message` — The log message to emit
169    /// * `data` — Structured data to include in the log event
170    ///
171    /// # Examples
172    ///
173    /// ```no_run
174    /// # async fn example(ctx: &durable_lambda_core::context::DurableContext) {
175    /// ctx.log_debug_with_data("Request details", &serde_json::json!({"method": "POST"}));
176    /// # }
177    /// ```
178    pub fn log_debug_with_data(&self, message: &str, data: &serde_json::Value) {
179        if !self.is_replaying() {
180            tracing::debug!(
181                execution_arn = %self.arn(),
182                parent_id = %self.log_parent_id(),
183                data = %data,
184                message = message,
185                "durable_log"
186            );
187        }
188    }
189
190    /// Emit a replay-safe warn-level log message with structured data.
191    ///
192    /// During execution mode, emits via `tracing::warn!` with data field.
193    /// During replay mode, the call is a no-op.
194    ///
195    /// # Arguments
196    ///
197    /// * `message` — The log message to emit
198    /// * `data` — Structured data to include in the log event
199    ///
200    /// # Examples
201    ///
202    /// ```no_run
203    /// # async fn example(ctx: &durable_lambda_core::context::DurableContext) {
204    /// ctx.log_warn_with_data("Retry attempt", &serde_json::json!({"attempt": 3}));
205    /// # }
206    /// ```
207    pub fn log_warn_with_data(&self, message: &str, data: &serde_json::Value) {
208        if !self.is_replaying() {
209            tracing::warn!(
210                execution_arn = %self.arn(),
211                parent_id = %self.log_parent_id(),
212                data = %data,
213                message = message,
214                "durable_log"
215            );
216        }
217    }
218
219    /// Emit a replay-safe error-level log message with structured data.
220    ///
221    /// During execution mode, emits via `tracing::error!` with data field.
222    /// During replay mode, the call is a no-op.
223    ///
224    /// # Arguments
225    ///
226    /// * `message` — The log message to emit
227    /// * `data` — Structured data to include in the log event
228    ///
229    /// # Examples
230    ///
231    /// ```no_run
232    /// # async fn example(ctx: &durable_lambda_core::context::DurableContext) {
233    /// ctx.log_error_with_data("Payment failed", &serde_json::json!({"error": "timeout"}));
234    /// # }
235    /// ```
236    pub fn log_error_with_data(&self, message: &str, data: &serde_json::Value) {
237        if !self.is_replaying() {
238            tracing::error!(
239                execution_arn = %self.arn(),
240                parent_id = %self.log_parent_id(),
241                data = %data,
242                message = message,
243                "durable_log"
244            );
245        }
246    }
247}
248
249#[cfg(test)]
250mod tests {
251    use std::sync::Arc;
252
253    use aws_sdk_lambda::operation::checkpoint_durable_execution::CheckpointDurableExecutionOutput;
254    use aws_sdk_lambda::operation::get_durable_execution_state::GetDurableExecutionStateOutput;
255    use aws_sdk_lambda::types::{Operation, OperationStatus, OperationType, OperationUpdate};
256    use tracing_test::traced_test;
257
258    use crate::backend::DurableBackend;
259    use crate::context::DurableContext;
260    use crate::error::DurableError;
261
262    /// Minimal mock backend for log tests — logging never calls the backend.
263    struct LogTestBackend;
264
265    #[async_trait::async_trait]
266    impl DurableBackend for LogTestBackend {
267        async fn checkpoint(
268            &self,
269            _arn: &str,
270            _checkpoint_token: &str,
271            _updates: Vec<OperationUpdate>,
272            _client_token: Option<&str>,
273        ) -> Result<CheckpointDurableExecutionOutput, DurableError> {
274            unimplemented!("logging does not checkpoint")
275        }
276
277        async fn get_execution_state(
278            &self,
279            _arn: &str,
280            _checkpoint_token: &str,
281            _next_marker: &str,
282            _max_items: i32,
283        ) -> Result<GetDurableExecutionStateOutput, DurableError> {
284            Ok(GetDurableExecutionStateOutput::builder().build().unwrap())
285        }
286    }
287
288    async fn make_executing_context() -> DurableContext {
289        DurableContext::new(
290            Arc::new(LogTestBackend),
291            "arn:aws:lambda:us-east-1:123456789:durable-execution/test-exec".to_string(),
292            "tok".to_string(),
293            vec![],
294            None,
295        )
296        .await
297        .unwrap()
298    }
299
300    async fn make_replaying_context() -> DurableContext {
301        let op = Operation::builder()
302            .id("op-1")
303            .r#type(OperationType::Step)
304            .status(OperationStatus::Succeeded)
305            .start_timestamp(aws_smithy_types::DateTime::from_secs(0))
306            .build()
307            .unwrap();
308
309        DurableContext::new(
310            Arc::new(LogTestBackend),
311            "arn:aws:lambda:us-east-1:123456789:durable-execution/test-exec".to_string(),
312            "tok".to_string(),
313            vec![op],
314            None,
315        )
316        .await
317        .unwrap()
318    }
319
320    #[traced_test]
321    #[tokio::test]
322    async fn test_log_emits_during_execution() {
323        let ctx = make_executing_context().await;
324        assert!(!ctx.is_replaying());
325
326        ctx.log("order processing started");
327        assert!(logs_contain("order processing started"));
328        assert!(logs_contain("execution_arn"));
329    }
330
331    #[traced_test]
332    #[tokio::test]
333    async fn test_log_suppressed_during_replay() {
334        let ctx = make_replaying_context().await;
335        assert!(ctx.is_replaying());
336
337        ctx.log("should not appear in logs");
338        assert!(!logs_contain("should not appear in logs"));
339    }
340
341    #[traced_test]
342    #[tokio::test]
343    async fn test_log_with_structured_data() {
344        let ctx = make_executing_context().await;
345        let data = serde_json::json!({"order_id": 42, "amount": 99.99});
346
347        ctx.log_with_data("order processed", &data);
348        assert!(logs_contain("order processed"));
349        assert!(logs_contain("order_id"));
350    }
351
352    #[traced_test]
353    #[tokio::test]
354    async fn test_log_all_levels() {
355        let ctx = make_executing_context().await;
356
357        ctx.log_debug("debug message");
358        ctx.log("info message");
359        ctx.log_warn("warn message");
360        ctx.log_error("error message");
361
362        assert!(logs_contain("debug message"));
363        assert!(logs_contain("info message"));
364        assert!(logs_contain("warn message"));
365        assert!(logs_contain("error message"));
366    }
367
368    #[traced_test]
369    #[tokio::test]
370    async fn test_log_all_levels_suppressed_during_replay() {
371        let ctx = make_replaying_context().await;
372
373        ctx.log_debug("replay debug");
374        ctx.log("replay info");
375        ctx.log_warn("replay warn");
376        ctx.log_error("replay error");
377        ctx.log_with_data("replay data", &serde_json::json!({"key": "val"}));
378        ctx.log_debug_with_data("replay debug data", &serde_json::json!({"k": "v"}));
379        ctx.log_warn_with_data("replay warn data", &serde_json::json!({"k": "v"}));
380        ctx.log_error_with_data("replay error data", &serde_json::json!({"k": "v"}));
381
382        assert!(!logs_contain("replay debug"));
383        assert!(!logs_contain("replay info"));
384        assert!(!logs_contain("replay warn"));
385        assert!(!logs_contain("replay error"));
386        assert!(!logs_contain("replay data"));
387        assert!(!logs_contain("replay debug data"));
388        assert!(!logs_contain("replay warn data"));
389        assert!(!logs_contain("replay error data"));
390    }
391
392    #[traced_test]
393    #[tokio::test]
394    async fn test_log_is_not_durable_operation() {
395        let ctx = make_executing_context().await;
396
397        // Logging should NOT generate operation IDs or interact with the replay engine.
398        let ops_before = ctx.replay_engine().operations().len();
399
400        ctx.log("test message");
401        ctx.log_with_data("test data", &serde_json::json!({"k": "v"}));
402        ctx.log_debug("test debug");
403        ctx.log_warn("test warn");
404        ctx.log_error("test error");
405
406        let ops_after = ctx.replay_engine().operations().len();
407        assert_eq!(
408            ops_before, ops_after,
409            "logging must not add operations to replay engine"
410        );
411    }
412
413    #[traced_test]
414    #[tokio::test]
415    async fn test_log_with_data_variants() {
416        let ctx = make_executing_context().await;
417
418        ctx.log_debug_with_data("debug details", &serde_json::json!({"step": "validate"}));
419        ctx.log_warn_with_data("warn details", &serde_json::json!({"retries": 2}));
420        ctx.log_error_with_data("error details", &serde_json::json!({"code": 500}));
421
422        assert!(logs_contain("debug details"));
423        assert!(logs_contain("warn details"));
424        assert!(logs_contain("error details"));
425    }
426
427    #[traced_test]
428    #[tokio::test]
429    async fn test_log_includes_execution_arn() {
430        let ctx = make_executing_context().await;
431
432        ctx.log("arn check");
433        assert!(logs_contain("durable-execution/test-exec"));
434    }
435
436    #[traced_test]
437    #[tokio::test]
438    async fn test_log_root_context_has_empty_parent_id() {
439        let ctx = make_executing_context().await;
440        assert!(ctx.parent_op_id().is_none());
441
442        ctx.log("root log");
443        assert!(logs_contain("root log"));
444        assert!(logs_contain("parent_id"));
445    }
446
447    #[traced_test]
448    #[tokio::test]
449    async fn test_log_child_context_includes_parent_id() {
450        let ctx = make_executing_context().await;
451        let child = ctx.create_child_context("child-op-123");
452
453        assert_eq!(child.parent_op_id(), Some("child-op-123"));
454
455        child.log("child log message");
456        assert!(logs_contain("child log message"));
457        assert!(logs_contain("child-op-123"));
458    }
459}
durable_lambda_core/operations/log.rs

durable_lambda_core/operations/
log.rs
