Skip to main content

dataflow_rs/engine/
trace.rs

1//! # Execution Trace Module
2//!
3//! This module provides step-by-step execution tracing for debugging workflows.
4//! It captures message snapshots after each step, including which workflows/tasks
5//! were executed or skipped.
6//!
7//! [`TraceOptions`] controls what a trace-mode run records. The default
8//! reproduces the historical behaviour — a full [`Message`] snapshot per
9//! executed step — which is unbounded in message size and quadratic in task
10//! count, because each snapshot clones the accumulated audit trail. Hosts that
11//! persist traces should set a snapshot budget, an audit-trail scope, or both.
12
13use crate::engine::message::{AuditTrail, Change, Message};
14use crate::engine::utils::strip_hash_prefix;
15use chrono::{DateTime, Utc};
16use datavalue::OwnedDataValue;
17use serde::{Deserialize, Serialize};
18use serde_json::Value;
19use std::sync::Arc;
20
21/// Approximate in-memory cost charged for a single container or scalar node.
22/// One machine word, per [`TraceOptions::max_snapshot_bytes`]'s contract.
23const NODE_SIZE: usize = std::mem::size_of::<usize>();
24
25/// `skip_serializing_if` predicate — omit `false` so a complete trace keeps the
26/// historical wire shape and only a truncated one carries the flag.
27#[inline]
28fn is_false(b: &bool) -> bool {
29    !*b
30}
31
32/// Result of executing a step (workflow or task)
33///
34/// Deliberately **not** `#[non_exhaustive]`. Downstream code matches on this to
35/// classify a step, and the npm wire type mirrors it as a string union; adding a
36/// variant should break those matches at compile time rather than silently
37/// reclassify them through a `_` arm.
38#[derive(Debug, Clone, Serialize, Deserialize, PartialEq, Eq)]
39#[serde(rename_all = "lowercase")]
40pub enum StepResult {
41    /// The step was executed
42    Executed,
43    /// The step was skipped due to condition being false
44    Skipped,
45}
46
47/// How much of [`Message::audit_trail`] a step's snapshot carries.
48///
49/// This is the knob for the *quadratic* term of trace size: under
50/// [`AuditTrailScope::Full`], step `i` clones `i` audit entries, so an N-task
51/// workflow retains `N*(N+1)/2` of them.
52#[derive(Clone, Copy, Debug, Default, PartialEq, Eq, Serialize, Deserialize)]
53#[serde(rename_all = "snake_case")]
54pub enum AuditTrailScope {
55    /// Every entry accumulated so far — the historical behaviour. Total entries
56    /// across the trace grow as `N*(N+1)/2` in task count.
57    #[default]
58    Full,
59    /// Only the entry this task produced, and none for a `TaskOutcome::Skip`
60    /// step. Linear in task count, and sufficient for the `dataflow-ui` step
61    /// debugger, which reads only the last entry.
62    Own,
63    /// Empty `audit_trail` in every snapshot.
64    None,
65}
66
67/// What a trace-mode run records for each executed step.
68///
69/// [`TraceOptions::default`] reproduces the historical capture behaviour: a full
70/// [`Message`] snapshot and per-mapping contexts on every executed step, no
71/// budget, no redaction, and the whole accumulated audit trail.
72///
73/// Trace mode reads the clock twice per executed task to populate
74/// [`ExecutionStep::duration_us`]. The non-trace path
75/// ([`crate::Engine::process_message`]) is unaffected and still takes a single
76/// `Utc::now()` per message.
77#[derive(Clone, Debug)]
78pub struct TraceOptions {
79    /// Full `Message` snapshot per executed step. `true` (default) is the
80    /// historical behaviour and is what the `dataflow-ui` step debugger
81    /// requires. With `false`, [`ExecutionTrace::final_message`] returns `None`
82    /// and [`ExecutionTrace::is_success`] degenerates to `true` — inspect
83    /// `Message::errors` on the message you passed in instead.
84    pub snapshots: bool,
85
86    /// Per-mapping context snapshots for `map` tasks. `true` (default). These
87    /// are whole-context clones, one per mapping, so a multi-mapping `map` task
88    /// can snapshot more than the step's own `Message` does.
89    pub mapping_contexts: bool,
90
91    /// Per-step diff: the changes produced by this task and nothing else.
92    /// `false` (default) preserves the historical payload byte for byte.
93    ///
94    /// Prefer this over reading `audit_trail.last()`, which mis-attributes on a
95    /// `TaskOutcome::Skip` step — no audit entry is recorded for a skip, so the
96    /// last entry belongs to a different task.
97    ///
98    /// Empty when the message was built with
99    /// `MessageBuilder::capture_changes(false)`: this flag reports the diff, it
100    /// does not turn capture on.
101    pub changes: bool,
102
103    /// Soft budget over the *approximate accumulated in-memory size* of the
104    /// snapshots taken so far — container and scalar nodes counted as one
105    /// machine word, `String` contents by `str::len()`. This is **not**
106    /// serialized JSON length; measuring that would mean serializing every step,
107    /// which defeats the purpose of a pre-capture budget.
108    ///
109    /// Once exceeded, later executed steps are still recorded — ids, result,
110    /// timing, and `changes` if enabled — with `message: None`, and
111    /// [`ExecutionTrace::truncated`] returns `true`. `0` (default) is unbounded.
112    pub max_snapshot_bytes: usize,
113
114    /// Dot-paths under the message context whose subtrees are replaced with
115    /// `OwnedDataValue::Null` as the snapshot is built, via a *pruning clone*:
116    /// the redacted subtree is never cloned, so this bounds the snapshot's
117    /// memory as well as its content. The live message is untouched, so later
118    /// tasks still read the real values.
119    ///
120    /// Also applied to `mapping_contexts`, which are whole-context clones and
121    /// would otherwise carry the redacted subtree through unchanged.
122    ///
123    /// Path syntax is the [`crate::engine::utils::get_nested_value`] vocabulary:
124    /// dot segments, numeric segments index arrays, one leading `#` escapes a
125    /// numerically-named object key. Unlike `set_nested_value`, a path that does
126    /// not resolve creates nothing and is a no-op, and an empty path is ignored.
127    ///
128    /// This is a literal path list and nothing more — no value scanning, no
129    /// pattern matching, no credential heuristics. It is not a masking engine.
130    pub redact_paths: Vec<String>,
131
132    /// How much of the accumulated audit trail each snapshot carries. See
133    /// [`AuditTrailScope`]; this is the lever for trace size in task count.
134    pub snapshot_audit_trail: AuditTrailScope,
135}
136
137impl Default for TraceOptions {
138    fn default() -> Self {
139        Self {
140            snapshots: true,
141            mapping_contexts: true,
142            changes: false,
143            max_snapshot_bytes: 0,
144            redact_paths: Vec::new(),
145            snapshot_audit_trail: AuditTrailScope::Full,
146        }
147    }
148}
149
150impl TraceOptions {
151    /// Ids, result, timing and the per-task diff; no message snapshots and no
152    /// mapping contexts. A step costs a few hundred bytes plus its diff,
153    /// regardless of message size or task count.
154    ///
155    /// Note this is UI-incompatible: the `dataflow-ui` step debugger needs
156    /// snapshots to render the step view.
157    pub fn timings_only() -> Self {
158        Self {
159            snapshots: false,
160            mapping_contexts: false,
161            changes: true,
162            ..Default::default()
163        }
164    }
165
166    /// Pre-split `redact_paths` into raw segments once per trace.
167    ///
168    /// Segments stay raw so object-key matching can apply the `#` escape while
169    /// array matching parses the segment, exactly as `get_nested_value` does.
170    /// Empty paths are dropped here, which is what makes them a no-op.
171    fn redact_segments(&self) -> Vec<Vec<String>> {
172        self.redact_paths
173            .iter()
174            .filter(|p| !p.is_empty())
175            .map(|p| p.split('.').map(str::to_string).collect())
176            .collect()
177    }
178}
179
180/// Task-body timing for an executed step: when the body started and how long
181/// it ran.
182///
183/// Bundled because both executor call sites always have the pair — it is
184/// exactly what [`ExecutionStep::with_timing`] sets — and because it keeps
185/// [`ExecutionTrace::add_executed_step`] inside clippy's argument-count
186/// threshold now that the loop counter rides along too.
187#[derive(Clone, Copy, Debug)]
188pub(crate) struct StepTiming {
189    /// Wall-clock start of the task body.
190    pub started_at: DateTime<Utc>,
191    /// Task body duration in microseconds.
192    pub duration_us: u64,
193}
194
195/// A single step in the execution trace
196///
197/// `#[non_exhaustive]`: construct through [`ExecutionStep::executed`],
198/// [`ExecutionStep::task_skipped`] or [`ExecutionStep::workflow_skipped`] and
199/// chain the `with_*` methods. Field reads and `..` patterns are unaffected.
200#[derive(Debug, Clone, Serialize, Deserialize)]
201#[non_exhaustive]
202pub struct ExecutionStep {
203    /// ID of the workflow this step belongs to
204    pub workflow_id: String,
205    /// ID of the task (None for workflow-level skips)
206    pub task_id: Option<String>,
207    /// Result of the step execution
208    pub result: StepResult,
209    /// Message snapshot after this step. `None` for skipped steps, when
210    /// [`TraceOptions::snapshots`] is off, and for executed steps recorded after
211    /// [`TraceOptions::max_snapshot_bytes`] was exceeded.
212    #[serde(skip_serializing_if = "Option::is_none")]
213    pub message: Option<Message>,
214    /// Context snapshots before each mapping (map tasks only, trace mode only).
215    /// `mapping_contexts[i]` is `message.context` before `mapping[i]` executed.
216    #[serde(skip_serializing_if = "Option::is_none")]
217    pub mapping_contexts: Option<Vec<Value>>,
218    /// Wall-clock start of the task body. `Executed` steps only.
219    ///
220    /// `chrono`, not `std::time::Instant`: `Instant::now()` panics on
221    /// `wasm32-unknown-unknown`, and the wasm bindings run the trace path there.
222    #[serde(skip_serializing_if = "Option::is_none")]
223    pub started_at: Option<DateTime<Utc>>,
224    /// Task body duration in microseconds. `Executed` steps only.
225    ///
226    /// Derived from two `Utc::now()` reads, which are not monotonic: a backward
227    /// clock step clamps to `0` rather than wrapping.
228    #[serde(skip_serializing_if = "Option::is_none")]
229    pub duration_us: Option<u64>,
230    /// This task's own writes, when [`TraceOptions::changes`] is set. `Some(vec![])`
231    /// means the task wrote nothing (or change capture is off), which is
232    /// distinct from `None` meaning "not recorded".
233    #[serde(skip_serializing_if = "Option::is_none")]
234    pub changes: Option<Vec<Change>>,
235    /// Loop counter of the sweep this step belongs to, for workflows carrying
236    /// a [`crate::engine::workflow::LoopConfig`]; `None` otherwise. Group
237    /// steps by it to reconstruct per-iteration execution.
238    ///
239    /// Mirrors [`crate::engine::message::AuditTrail::loop_counter`], including
240    /// being skipped when `None` so a non-looping trace keeps its historical
241    /// wire shape.
242    #[serde(default, skip_serializing_if = "Option::is_none")]
243    pub loop_counter: Option<i64>,
244    /// Index of the element this step ran for, for a task carrying a
245    /// [`crate::engine::for_each::ForEach`]; `None` otherwise. Mirrors
246    /// [`crate::engine::message::AuditTrail::element_index`], including being
247    /// skipped when `None`.
248    #[serde(default, skip_serializing_if = "Option::is_none")]
249    pub element_index: Option<usize>,
250}
251
252impl ExecutionStep {
253    /// Create a new executed step with a message snapshot
254    pub fn executed(workflow_id: &str, task_id: &str, message: &Message) -> Self {
255        Self {
256            workflow_id: workflow_id.to_string(),
257            task_id: Some(task_id.to_string()),
258            result: StepResult::Executed,
259            message: Some(message.clone()),
260            mapping_contexts: None,
261            started_at: None,
262            duration_us: None,
263            changes: None,
264            loop_counter: None,
265            element_index: None,
266        }
267    }
268
269    /// Create a skipped task step
270    pub fn task_skipped(workflow_id: &str, task_id: &str) -> Self {
271        Self {
272            workflow_id: workflow_id.to_string(),
273            task_id: Some(task_id.to_string()),
274            result: StepResult::Skipped,
275            message: None,
276            mapping_contexts: None,
277            started_at: None,
278            duration_us: None,
279            changes: None,
280            loop_counter: None,
281            element_index: None,
282        }
283    }
284
285    /// Create a skipped workflow step
286    pub fn workflow_skipped(workflow_id: &str) -> Self {
287        Self {
288            workflow_id: workflow_id.to_string(),
289            task_id: None,
290            result: StepResult::Skipped,
291            message: None,
292            mapping_contexts: None,
293            started_at: None,
294            duration_us: None,
295            changes: None,
296            loop_counter: None,
297            element_index: None,
298        }
299    }
300
301    /// Set mapping context snapshots (for map tasks in trace mode)
302    pub fn with_mapping_contexts(mut self, contexts: Vec<Value>) -> Self {
303        self.mapping_contexts = Some(contexts);
304        self
305    }
306
307    /// Attach task-body timing. Chains after [`Self::executed`].
308    pub fn with_timing(mut self, started_at: DateTime<Utc>, duration_us: u64) -> Self {
309        self.started_at = Some(started_at);
310        self.duration_us = Some(duration_us);
311        self
312    }
313
314    /// Attach this task's own diff. Chains after [`Self::executed`].
315    pub fn with_changes(mut self, changes: Vec<Change>) -> Self {
316        self.changes = Some(changes);
317        self
318    }
319
320    /// Attach the loop counter of the sweep this step belongs to. `None` is
321    /// the non-looping case and leaves the step's JSON unchanged.
322    pub fn with_loop_counter(mut self, loop_counter: Option<i64>) -> Self {
323        self.loop_counter = loop_counter;
324        self
325    }
326
327    /// Attach the fan-out element this step ran for. `None` is the ordinary
328    /// case and leaves the step's JSON unchanged.
329    pub fn with_element_index(mut self, element_index: Option<usize>) -> Self {
330        self.element_index = element_index;
331        self
332    }
333}
334
335/// Where in a run one executed step sits: the loop sweep and the fan-out
336/// element, either of which may be absent.
337///
338/// Bundled so that stamping a second coordinate did not push
339/// [`ExecutionTrace::add_executed_step`] past clippy's argument-count limit.
340#[derive(Clone, Copy, Debug, Default)]
341pub(crate) struct StepStamp {
342    pub loop_counter: Option<i64>,
343    pub element_index: Option<usize>,
344}
345
346/// Complete execution trace containing all steps
347///
348/// `#[non_exhaustive]`: construct with [`ExecutionTrace::new`] or
349/// [`ExecutionTrace::with_options`]. `steps` stays public for reads.
350#[derive(Debug, Clone, Serialize, Deserialize)]
351#[non_exhaustive]
352pub struct ExecutionTrace {
353    /// All execution steps in order
354    pub steps: Vec<ExecutionStep>,
355
356    /// Set when `max_snapshot_bytes` was exceeded. Serialized only when `true`,
357    /// so a complete trace keeps the historical wire shape.
358    #[serde(default, skip_serializing_if = "is_false")]
359    truncated: bool,
360
361    /// Capture policy. In-memory only — a deserialized trace carries the
362    /// default, which is why `options()` is documented as the policy this trace
363    /// *records* with rather than the one it was recorded with.
364    #[serde(skip)]
365    options: TraceOptions,
366
367    /// Pre-split `options.redact_paths`, so the split cost is paid once.
368    #[serde(skip)]
369    redact_segments: Vec<Vec<String>>,
370
371    /// Approximate accumulated in-memory size of snapshots taken so far.
372    #[serde(skip)]
373    snapshot_bytes: usize,
374}
375
376impl ExecutionTrace {
377    /// Create a new empty execution trace with default capture policy.
378    pub fn new() -> Self {
379        Self::with_options(TraceOptions::default())
380    }
381
382    /// Empty trace that records according to `options`.
383    pub fn with_options(options: TraceOptions) -> Self {
384        Self {
385            steps: Vec::new(),
386            truncated: false,
387            redact_segments: options.redact_segments(),
388            options,
389            snapshot_bytes: 0,
390        }
391    }
392
393    /// The capture policy this trace records with.
394    pub fn options(&self) -> &TraceOptions {
395        &self.options
396    }
397
398    /// Whether [`TraceOptions::max_snapshot_bytes`] was exceeded, and one or
399    /// more executed steps therefore carry `message: None`, missing mapping
400    /// contexts, or both.
401    ///
402    /// The budget is shared across both: with [`TraceOptions::snapshots`] off
403    /// but [`TraceOptions::mapping_contexts`] on, this can still return `true`
404    /// from the mapping-context term alone, even though no step was ever going
405    /// to carry a `message`.
406    pub fn truncated(&self) -> bool {
407        self.truncated
408    }
409
410    /// Add a step to the trace
411    pub fn add_step(&mut self, step: ExecutionStep) {
412        self.steps.push(step);
413    }
414
415    /// Record an executed step under this trace's capture policy.
416    ///
417    /// Owns every policy decision — snapshot scope, pruning clone, audit-trail
418    /// scope, budget check, timing and diff — so the executor's two dispatch
419    /// sites do not duplicate any of it.
420    pub(crate) fn add_executed_step(
421        &mut self,
422        workflow_id: &str,
423        task_id: &str,
424        message: &Message,
425        timing: StepTiming,
426        mapping_contexts: Option<Vec<Value>>,
427        stamp: StepStamp,
428    ) {
429        let mut step = ExecutionStep {
430            workflow_id: workflow_id.to_string(),
431            task_id: Some(task_id.to_string()),
432            result: StepResult::Executed,
433            message: None,
434            mapping_contexts: None,
435            started_at: Some(timing.started_at),
436            duration_us: Some(timing.duration_us),
437            loop_counter: stamp.loop_counter,
438            element_index: stamp.element_index,
439            changes: if self.options.changes {
440                // Derived from this task's own audit entry rather than
441                // `audit_trail.last()` unconditionally — that is the
442                // mis-attribution being fixed. A `TaskOutcome::Skip` records no
443                // entry, so it correctly reports an empty diff instead of
444                // inheriting the previous task's (or another workflow's).
445                Some(
446                    own_audit_entry(message, workflow_id, task_id)
447                        .map(|e| e.changes.clone())
448                        .unwrap_or_default(),
449                )
450            } else {
451                None
452            },
453        };
454
455        if self.options.snapshots {
456            // Size is *probed* without cloning, so a snapshot that would not fit
457            // is never built. Checking after the clone would be pointless: the
458            // peak memory this budget exists to bound has already been paid.
459            let projected = self.projected_snapshot_size(message, workflow_id, task_id);
460            if self.would_exceed(projected) {
461                self.truncated = true;
462            } else {
463                self.snapshot_bytes += projected;
464                step.message = Some(self.build_snapshot(message, workflow_id, task_id));
465            }
466        }
467
468        if self.options.mapping_contexts
469            && let Some(mut contexts) = mapping_contexts
470        {
471            // These arrive already cloned by the map function, so redact
472            // first and then decide whether to retain them.
473            for ctx in &mut contexts {
474                redact_json_in_place(ctx, &self.redact_segments);
475            }
476            let size: usize = contexts.iter().map(approx_json_size).sum();
477            if self.would_exceed(size) {
478                self.truncated = true;
479            } else {
480                self.snapshot_bytes += size;
481                step.mapping_contexts = Some(contexts);
482            }
483        }
484
485        self.steps.push(step);
486    }
487
488    /// Whether retaining `additional` bytes would cross a finite budget.
489    #[inline]
490    fn would_exceed(&self, additional: usize) -> bool {
491        self.options.max_snapshot_bytes != 0
492            && self.snapshot_bytes + additional > self.options.max_snapshot_bytes
493    }
494
495    /// Approximate size the snapshot for this step would occupy, computed
496    /// without cloning anything.
497    ///
498    /// Must agree with what [`Self::build_snapshot`] actually retains; a unit
499    /// test pins the two together.
500    fn projected_snapshot_size(
501        &self,
502        message: &Message,
503        workflow_id: &str,
504        task_id: &str,
505    ) -> usize {
506        let mut size = redacted_size(&message.context, &self.redact_segments);
507        for entry in self.scoped_audit_trail(message, workflow_id, task_id) {
508            size += NODE_SIZE;
509            for change in &entry.changes {
510                size += change.path.len()
511                    + approx_owned_size(&change.old_value)
512                    + approx_owned_size(&change.new_value);
513            }
514        }
515        size
516    }
517
518    /// The audit entries this step's snapshot will carry, per
519    /// [`TraceOptions::snapshot_audit_trail`].
520    fn scoped_audit_trail<'m>(
521        &self,
522        message: &'m Message,
523        workflow_id: &str,
524        task_id: &str,
525    ) -> Vec<&'m AuditTrail> {
526        match self.options.snapshot_audit_trail {
527            AuditTrailScope::Full => message.audit_trail.iter().collect(),
528            AuditTrailScope::Own => own_audit_entry(message, workflow_id, task_id)
529                .map(|e| vec![e])
530                .unwrap_or_default(),
531            AuditTrailScope::None => Vec::new(),
532        }
533    }
534
535    /// Build this step's snapshot: context pruned per `redact_paths`, audit
536    /// trail scoped per `snapshot_audit_trail`. Returns the approximate
537    /// in-memory size charged to the budget.
538    ///
539    /// `payload` is an `Arc`, so it is shared rather than deep-cloned here —
540    /// same as the derived `Message::clone` this replaces.
541    fn build_snapshot(&self, message: &Message, workflow_id: &str, task_id: &str) -> Message {
542        let (context, _) = redacting_clone(&message.context, &self.redact_segments);
543        let audit_trail: Vec<AuditTrail> = self
544            .scoped_audit_trail(message, workflow_id, task_id)
545            .into_iter()
546            .cloned()
547            .collect();
548
549        Message {
550            id: message.id.clone(),
551            payload: Arc::clone(&message.payload),
552            context,
553            audit_trail,
554            errors: message.errors.clone(),
555            capture_changes: message.capture_changes,
556            routing_bucket: message.routing_bucket,
557        }
558    }
559
560    /// Get the final message (from the last executed step)
561    ///
562    /// Returns `None` when [`TraceOptions::snapshots`] is off, or when every
563    /// executed step was recorded after the snapshot budget was exceeded.
564    pub fn final_message(&self) -> Option<&Message> {
565        self.steps
566            .iter()
567            .rev()
568            .find(|s| s.result == StepResult::Executed)
569            .and_then(|s| s.message.as_ref())
570    }
571
572    /// Check if execution was successful (no errors in final message)
573    ///
574    /// Degenerates to `true` when there is no snapshot to inspect — with
575    /// [`TraceOptions::snapshots`] off, read `Message::errors` on the message you
576    /// passed in instead.
577    pub fn is_success(&self) -> bool {
578        self.final_message()
579            .map(|m| m.errors.is_empty())
580            .unwrap_or(true)
581    }
582
583    /// Get number of executed steps
584    pub fn executed_count(&self) -> usize {
585        self.steps
586            .iter()
587            .filter(|s| s.result == StepResult::Executed)
588            .count()
589    }
590
591    /// Get number of skipped steps
592    pub fn skipped_count(&self) -> usize {
593        self.steps
594            .iter()
595            .filter(|s| s.result == StepResult::Skipped)
596            .count()
597    }
598}
599
600impl Default for ExecutionTrace {
601    fn default() -> Self {
602        Self::new()
603    }
604}
605
606/// The audit entry this task produced, if any.
607///
608/// The executor pushes at most one entry per task and pushes it immediately, so
609/// the last entry is this task's exactly when both its workflow and task id
610/// match. A `TaskOutcome::Skip` records none — which is why reading
611/// `audit_trail.last()` unconditionally mis-attributes the previous task's diff
612/// to a skipped step. Comparing `task_id` alone is not enough either: two
613/// workflows can share a task id (or the same task can run again in a later
614/// workflow), so a `Skip` right after a same-named task in a different
615/// workflow would otherwise inherit that other workflow's entry.
616#[inline]
617fn own_audit_entry<'m>(
618    message: &'m Message,
619    workflow_id: &str,
620    task_id: &str,
621) -> Option<&'m AuditTrail> {
622    match message.audit_trail.last() {
623        Some(entry)
624            if entry.task_id.as_ref() == task_id && entry.workflow_id.as_ref() == workflow_id =>
625        {
626            Some(entry)
627        }
628        _ => None,
629    }
630}
631
632/// Microseconds between two non-monotonic clock reads, clamped at `0`.
633///
634/// `Utc::now()` can step backwards, and `num_microseconds()` returns `None` on
635/// overflow; both collapse to `0` rather than panicking or wrapping.
636#[inline]
637pub(crate) fn duration_us_between(start: DateTime<Utc>, end: DateTime<Utc>) -> u64 {
638    (end - start)
639        .num_microseconds()
640        .unwrap_or(0)
641        .max(0)
642        .try_into()
643        .unwrap_or(0)
644}
645
646/// Deep-clone `value`, substituting `OwnedDataValue::Null` for every subtree
647/// named by `paths`, and return the approximate in-memory size of the result.
648///
649/// `paths` holds the path suffixes still in play at this node; an empty suffix
650/// means this node is itself a redaction target, so its subtree is never
651/// cloned. A suffix that matches nothing is dropped, which is what makes an
652/// unresolvable path a no-op rather than a `set_nested_value`-style create.
653fn redacting_clone(value: &OwnedDataValue, paths: &[Vec<String>]) -> (OwnedDataValue, usize) {
654    let refs: Vec<&[String]> = paths.iter().map(|p| p.as_slice()).collect();
655    redacting_clone_inner(value, &refs)
656}
657
658/// Narrow `paths` to the child suffixes that still apply under object key
659/// `key` — the entries whose head segment (after the `#`-prefix escape)
660/// matches `key`, each with that head segment dropped. Shared by every
661/// redact/size walker below so the "does this path element apply here"
662/// filter has one definition instead of one copy per walker per value type.
663fn narrow_for_object_key<'a>(paths: &[&'a [String]], key: &str) -> Vec<&'a [String]> {
664    paths
665        .iter()
666        .filter(|p| strip_hash_prefix(&p[0]) == key)
667        .map(|p| &p[1..])
668        .collect()
669}
670
671/// Same as [`narrow_for_object_key`] but for an array index: the entries
672/// whose head segment parses as `idx`.
673fn narrow_for_array_index<'a>(paths: &[&'a [String]], idx: usize) -> Vec<&'a [String]> {
674    paths
675        .iter()
676        .filter(|p| p[0].parse::<usize>() == Ok(idx))
677        .map(|p| &p[1..])
678        .collect()
679}
680
681fn redacting_clone_inner(value: &OwnedDataValue, paths: &[&[String]]) -> (OwnedDataValue, usize) {
682    // An exhausted suffix names this node: redact without descending.
683    if paths.iter().any(|p| p.is_empty()) {
684        return (OwnedDataValue::Null, NODE_SIZE);
685    }
686
687    match value {
688        OwnedDataValue::Object(pairs) => {
689            let mut out = Vec::with_capacity(pairs.len());
690            let mut size = NODE_SIZE;
691            for (key, child) in pairs {
692                let sub = narrow_for_object_key(paths, key);
693                let (cloned, child_size) = redacting_clone_inner(child, &sub);
694                size += key.len() + child_size;
695                out.push((key.clone(), cloned));
696            }
697            (OwnedDataValue::Object(out), size)
698        }
699        OwnedDataValue::Array(items) => {
700            let mut out = Vec::with_capacity(items.len());
701            let mut size = NODE_SIZE;
702            for (idx, child) in items.iter().enumerate() {
703                let sub = narrow_for_array_index(paths, idx);
704                let (cloned, child_size) = redacting_clone_inner(child, &sub);
705                size += child_size;
706                out.push(cloned);
707            }
708            (OwnedDataValue::Array(out), size)
709        }
710        // Scalars: any leftover suffix cannot resolve, so it is dropped.
711        OwnedDataValue::String(s) => (value.clone(), NODE_SIZE + s.len()),
712        other => (other.clone(), NODE_SIZE),
713    }
714}
715
716/// Size [`redacting_clone`] would produce, computed without cloning.
717///
718/// Exists so the snapshot budget can decline a capture *before* paying for it.
719/// Must stay in step with `redacting_clone`; `redacted_size_agrees_with_redacting_clone`
720/// pins that.
721fn redacted_size(value: &OwnedDataValue, paths: &[Vec<String>]) -> usize {
722    let refs: Vec<&[String]> = paths.iter().map(|p| p.as_slice()).collect();
723    redacted_size_inner(value, &refs)
724}
725
726fn redacted_size_inner(value: &OwnedDataValue, paths: &[&[String]]) -> usize {
727    if paths.iter().any(|p| p.is_empty()) {
728        return NODE_SIZE;
729    }
730    match value {
731        OwnedDataValue::Object(pairs) => {
732            let mut size = NODE_SIZE;
733            for (key, child) in pairs {
734                let sub = narrow_for_object_key(paths, key);
735                size += key.len() + redacted_size_inner(child, &sub);
736            }
737            size
738        }
739        OwnedDataValue::Array(items) => {
740            let mut size = NODE_SIZE;
741            for (idx, child) in items.iter().enumerate() {
742                let sub = narrow_for_array_index(paths, idx);
743                size += redacted_size_inner(child, &sub);
744            }
745            size
746        }
747        OwnedDataValue::String(s) => NODE_SIZE + s.len(),
748        _ => NODE_SIZE,
749    }
750}
751
752/// Approximate in-memory size of an `OwnedDataValue`, on the same scale as
753/// [`redacting_clone`].
754fn approx_owned_size(value: &OwnedDataValue) -> usize {
755    match value {
756        OwnedDataValue::Object(pairs) => {
757            NODE_SIZE
758                + pairs
759                    .iter()
760                    .map(|(k, v)| k.len() + approx_owned_size(v))
761                    .sum::<usize>()
762        }
763        OwnedDataValue::Array(items) => {
764            NODE_SIZE + items.iter().map(approx_owned_size).sum::<usize>()
765        }
766        OwnedDataValue::String(s) => NODE_SIZE + s.len(),
767        _ => NODE_SIZE,
768    }
769}
770
771/// Null out every subtree named by `paths` in a `serde_json::Value`, in place.
772///
773/// Mirrors [`redacting_clone`]'s path semantics so `mapping_contexts` are
774/// redacted the same way message snapshots are. In place because the caller
775/// already owns the value — there is no second clone to save.
776fn redact_json_in_place(value: &mut Value, paths: &[Vec<String>]) {
777    let refs: Vec<&[String]> = paths.iter().map(|p| p.as_slice()).collect();
778    redact_json_inner(value, &refs);
779}
780
781fn redact_json_inner(value: &mut Value, paths: &[&[String]]) {
782    if paths.is_empty() {
783        return;
784    }
785    if paths.iter().any(|p| p.is_empty()) {
786        *value = Value::Null;
787        return;
788    }
789
790    match value {
791        Value::Object(map) => {
792            for (key, child) in map.iter_mut() {
793                let sub = narrow_for_object_key(paths, key);
794                redact_json_inner(child, &sub);
795            }
796        }
797        Value::Array(items) => {
798            for (idx, child) in items.iter_mut().enumerate() {
799                let sub = narrow_for_array_index(paths, idx);
800                redact_json_inner(child, &sub);
801            }
802        }
803        _ => {}
804    }
805}
806
807/// Approximate in-memory size of a `serde_json::Value`, on the same scale as
808/// [`approx_owned_size`].
809fn approx_json_size(value: &Value) -> usize {
810    match value {
811        Value::Object(map) => {
812            NODE_SIZE
813                + map
814                    .iter()
815                    .map(|(k, v)| k.len() + approx_json_size(v))
816                    .sum::<usize>()
817        }
818        Value::Array(items) => NODE_SIZE + items.iter().map(approx_json_size).sum::<usize>(),
819        Value::String(s) => NODE_SIZE + s.len(),
820        _ => NODE_SIZE,
821    }
822}
823
824#[cfg(test)]
825mod tests {
826    use super::*;
827    use serde_json::json;
828
829    fn dv(v: serde_json::Value) -> OwnedDataValue {
830        OwnedDataValue::from(&v)
831    }
832
833    fn segments(paths: &[&str]) -> Vec<Vec<String>> {
834        TraceOptions {
835            redact_paths: paths.iter().map(|s| s.to_string()).collect(),
836            ..Default::default()
837        }
838        .redact_segments()
839    }
840
841    #[test]
842    fn test_step_result_serialization() {
843        assert_eq!(
844            serde_json::to_string(&StepResult::Executed).unwrap(),
845            "\"executed\""
846        );
847        assert_eq!(
848            serde_json::to_string(&StepResult::Skipped).unwrap(),
849            "\"skipped\""
850        );
851    }
852
853    #[test]
854    fn test_execution_step_executed() {
855        let message = Message::from_value(&json!({"test": "data"}));
856        let step = ExecutionStep::executed("workflow1", "task1", &message);
857
858        assert_eq!(step.workflow_id, "workflow1");
859        assert_eq!(step.task_id, Some("task1".to_string()));
860        assert_eq!(step.result, StepResult::Executed);
861        assert!(step.message.is_some());
862    }
863
864    #[test]
865    fn test_execution_step_task_skipped() {
866        let step = ExecutionStep::task_skipped("workflow1", "task1");
867
868        assert_eq!(step.workflow_id, "workflow1");
869        assert_eq!(step.task_id, Some("task1".to_string()));
870        assert_eq!(step.result, StepResult::Skipped);
871        assert!(step.message.is_none());
872    }
873
874    #[test]
875    fn test_execution_step_workflow_skipped() {
876        let step = ExecutionStep::workflow_skipped("workflow1");
877
878        assert_eq!(step.workflow_id, "workflow1");
879        assert_eq!(step.task_id, None);
880        assert_eq!(step.result, StepResult::Skipped);
881        assert!(step.message.is_none());
882    }
883
884    #[test]
885    fn test_execution_step_with_mapping_contexts() {
886        let message = Message::from_value(&json!({"test": "data"}));
887        let contexts = vec![json!({"data": {"a": 1}}), json!({"data": {"a": 1, "b": 2}})];
888
889        let step = ExecutionStep::executed("workflow1", "task1", &message)
890            .with_mapping_contexts(contexts.clone());
891
892        assert_eq!(step.mapping_contexts, Some(contexts));
893
894        // Verify serialization includes mapping_contexts
895        let serialized = serde_json::to_value(&step).unwrap();
896        assert!(serialized.get("mapping_contexts").is_some());
897        assert_eq!(serialized["mapping_contexts"].as_array().unwrap().len(), 2);
898    }
899
900    #[test]
901    fn test_execution_step_without_mapping_contexts_serialization() {
902        let message = Message::from_value(&json!({"test": "data"}));
903        let step = ExecutionStep::executed("workflow1", "task1", &message);
904
905        // Every optional field is None, so all are omitted in serialization.
906        let serialized = serde_json::to_value(&step).unwrap();
907        assert!(serialized.get("mapping_contexts").is_none());
908        assert!(serialized.get("started_at").is_none());
909        assert!(serialized.get("duration_us").is_none());
910        assert!(serialized.get("changes").is_none());
911    }
912
913    #[test]
914    fn test_execution_trace() {
915        let mut trace = ExecutionTrace::new();
916        let message = Message::from_value(&json!({"test": "data"}));
917
918        trace.add_step(ExecutionStep::workflow_skipped("workflow0"));
919        trace.add_step(ExecutionStep::executed("workflow1", "task1", &message));
920        trace.add_step(ExecutionStep::task_skipped("workflow1", "task2"));
921
922        assert_eq!(trace.steps.len(), 3);
923        assert_eq!(trace.executed_count(), 1);
924        assert_eq!(trace.skipped_count(), 2);
925        assert!(trace.final_message().is_some());
926        assert!(trace.is_success());
927    }
928
929    #[test]
930    fn default_options_reproduce_historical_capture() {
931        let o = TraceOptions::default();
932        assert!(o.snapshots);
933        assert!(o.mapping_contexts);
934        assert!(!o.changes);
935        assert_eq!(o.max_snapshot_bytes, 0);
936        assert!(o.redact_paths.is_empty());
937        assert_eq!(o.snapshot_audit_trail, AuditTrailScope::Full);
938    }
939
940    #[test]
941    fn timings_only_drops_snapshots_and_keeps_the_diff() {
942        let o = TraceOptions::timings_only();
943        assert!(!o.snapshots);
944        assert!(!o.mapping_contexts);
945        assert!(o.changes);
946    }
947
948    #[test]
949    fn a_complete_trace_does_not_serialize_the_truncated_flag() {
950        let trace = ExecutionTrace::new();
951        let serialized = serde_json::to_value(&trace).unwrap();
952        assert!(
953            serialized.get("truncated").is_none(),
954            "a complete trace keeps the historical wire shape"
955        );
956        assert!(!trace.truncated());
957    }
958
959    #[test]
960    fn a_trace_deserializes_from_a_payload_without_the_truncated_flag() {
961        let trace: ExecutionTrace = serde_json::from_value(json!({ "steps": [] })).unwrap();
962        assert!(!trace.truncated());
963    }
964
965    #[test]
966    fn duration_clamps_a_backward_clock_step_to_zero() {
967        let start = Utc::now();
968        let earlier = start - chrono::Duration::seconds(5);
969        assert_eq!(duration_us_between(start, earlier), 0);
970        assert_eq!(duration_us_between(start, start), 0);
971        assert_eq!(
972            duration_us_between(start, start + chrono::Duration::microseconds(1500)),
973            1500
974        );
975    }
976
977    #[test]
978    fn redaction_nulls_only_the_named_subtree() {
979        let ctx = dv(json!({"data": {"secret": {"k": "v"}, "keep": 1}}));
980        let (out, _) = redacting_clone(&ctx, &segments(&["data.secret"]));
981        assert_eq!(
982            serde_json::Value::from(&out),
983            json!({"data": {"secret": null, "keep": 1}})
984        );
985    }
986
987    #[test]
988    fn redaction_of_an_unresolvable_path_creates_nothing() {
989        // `set_nested_value` would pad the array to index 99 with nulls; this
990        // must not.
991        let ctx = dv(json!({"data": {"items": [1, 2, 3]}}));
992        let (out, _) = redacting_clone(&ctx, &segments(&["data.items.99"]));
993        assert_eq!(
994            serde_json::Value::from(&out),
995            json!({"data": {"items": [1, 2, 3]}})
996        );
997    }
998
999    #[test]
1000    fn redaction_through_a_non_container_is_a_noop() {
1001        let ctx = dv(json!({"data": {"name": "alice"}}));
1002        let (out, _) = redacting_clone(&ctx, &segments(&["data.name.first"]));
1003        assert_eq!(
1004            serde_json::Value::from(&out),
1005            json!({"data": {"name": "alice"}})
1006        );
1007    }
1008
1009    #[test]
1010    fn an_empty_redact_path_is_ignored() {
1011        let ctx = dv(json!({"data": {"a": 1}}));
1012        let (out, _) = redacting_clone(&ctx, &segments(&[""]));
1013        assert_eq!(serde_json::Value::from(&out), json!({"data": {"a": 1}}));
1014    }
1015
1016    #[test]
1017    fn redaction_honours_the_hash_escape() {
1018        // `data.#20` names the object key "20"; `data.20` indexes an array.
1019        let obj = dv(json!({"data": {"20": "secret", "other": 1}}));
1020        let (out, _) = redacting_clone(&obj, &segments(&["data.#20"]));
1021        assert_eq!(
1022            serde_json::Value::from(&out),
1023            json!({"data": {"20": null, "other": 1}})
1024        );
1025
1026        let arr = dv(json!({"data": [0, 1, 2]}));
1027        let (out, _) = redacting_clone(&arr, &segments(&["data.1"]));
1028        assert_eq!(serde_json::Value::from(&out), json!({"data": [0, null, 2]}));
1029
1030        // The escaped form does not index an array.
1031        let (out, _) = redacting_clone(&arr, &segments(&["data.#1"]));
1032        assert_eq!(serde_json::Value::from(&out), json!({"data": [0, 1, 2]}));
1033    }
1034
1035    #[test]
1036    fn nested_and_duplicated_redact_paths_are_safe() {
1037        let ctx = dv(json!({"data": {"a": {"b": 1, "c": 2}}}));
1038
1039        let (out, _) = redacting_clone(&ctx, &segments(&["data.a", "data.a.b"]));
1040        assert_eq!(serde_json::Value::from(&out), json!({"data": {"a": null}}));
1041
1042        let (out, _) = redacting_clone(&ctx, &segments(&["data.a", "data.a"]));
1043        assert_eq!(serde_json::Value::from(&out), json!({"data": {"a": null}}));
1044    }
1045
1046    #[test]
1047    fn redaction_matches_unicode_keys_and_sizes_strings_by_bytes() {
1048        let ctx = dv(json!({"data": {"café": "secret", "keep": "née"}}));
1049        let (out, size) = redacting_clone(&ctx, &segments(&["data.café"]));
1050        assert_eq!(
1051            serde_json::Value::from(&out),
1052            json!({"data": {"café": null, "keep": "née"}})
1053        );
1054
1055        // "née" is 4 bytes, 3 chars — the budget counts bytes.
1056        let (_, unredacted) = redacting_clone(&ctx, &segments(&[]));
1057        assert!(unredacted > size, "redacting must lower the counted size");
1058        assert!(
1059            approx_owned_size(&dv(json!("née"))) == NODE_SIZE + 4,
1060            "str::len() bytes, not chars().count()"
1061        );
1062    }
1063
1064    #[test]
1065    fn redacted_size_agrees_with_redacting_clone() {
1066        // The budget probes with `redacted_size` and then builds with
1067        // `redacting_clone`; if they drift, the budget stops meaning anything.
1068        let shapes = [
1069            json!({}),
1070            json!({"data": {"a": 1, "b": "hello"}}),
1071            json!({"data": {"items": [1, "two", {"three": 3}], "nested": {"x": {"y": "z"}}}}),
1072            json!({"data": {"secret": {"deep": [1, 2, 3]}, "keep": "café"}}),
1073        ];
1074        let path_sets: [&[&str]; 4] = [&[], &["data.secret"], &["data.items.1"], &["data.nope"]];
1075
1076        for shape in &shapes {
1077            for paths in path_sets {
1078                let v = dv(shape.clone());
1079                let segs = segments(paths);
1080                let (_, cloned_size) = redacting_clone(&v, &segs);
1081                assert_eq!(
1082                    redacted_size(&v, &segs),
1083                    cloned_size,
1084                    "probe and clone disagree for {shape:?} with {paths:?}"
1085                );
1086            }
1087        }
1088    }
1089
1090    #[test]
1091    fn redaction_applies_to_mapping_contexts_too() {
1092        let mut ctx = json!({"data": {"secret": {"k": "v"}, "keep": 1}});
1093        redact_json_in_place(&mut ctx, &segments(&["data.secret"]));
1094        assert_eq!(ctx, json!({"data": {"secret": null, "keep": 1}}));
1095    }
1096
1097    #[test]
1098    fn json_redaction_shares_the_owned_path_semantics() {
1099        let mut arr = json!({"data": {"items": [1, 2, 3]}});
1100        redact_json_in_place(&mut arr, &segments(&["data.items.99"]));
1101        assert_eq!(arr, json!({"data": {"items": [1, 2, 3]}}));
1102
1103        let mut scalar = json!({"data": {"name": "alice"}});
1104        redact_json_in_place(&mut scalar, &segments(&["data.name.first"]));
1105        assert_eq!(scalar, json!({"data": {"name": "alice"}}));
1106
1107        let mut hash = json!({"data": {"20": "secret"}});
1108        redact_json_in_place(&mut hash, &segments(&["data.#20"]));
1109        assert_eq!(hash, json!({"data": {"20": null}}));
1110    }
1111
1112    #[test]
1113    fn execution_step_loop_counter_defaults_to_none_on_every_constructor() {
1114        assert_eq!(
1115            ExecutionStep::executed("w", "t", &Message::from_value(&json!({}))).loop_counter,
1116            None
1117        );
1118        assert_eq!(ExecutionStep::task_skipped("w", "t").loop_counter, None);
1119        assert_eq!(ExecutionStep::workflow_skipped("w").loop_counter, None);
1120    }
1121
1122    #[test]
1123    fn with_loop_counter_sets_and_clears_the_field() {
1124        let step = ExecutionStep::task_skipped("w", "t").with_loop_counter(Some(3));
1125        assert_eq!(step.loop_counter, Some(3));
1126        // Passing None must clear rather than be a no-op, so the non-looping
1127        // caller can chain unconditionally.
1128        assert_eq!(step.with_loop_counter(None).loop_counter, None);
1129    }
1130
1131    #[test]
1132    fn execution_step_loop_counter_is_absent_from_json_when_none() {
1133        // A non-looping trace must keep the historical wire shape byte for
1134        // byte — dataflow-ui parses these.
1135        let step = ExecutionStep::task_skipped("w", "t");
1136        let json = serde_json::to_value(&step).expect("should serialize");
1137        assert!(json.get("loop_counter").is_none());
1138
1139        let looped = ExecutionStep::task_skipped("w", "t").with_loop_counter(Some(0));
1140        assert_eq!(
1141            serde_json::to_value(&looped).expect("should serialize")["loop_counter"],
1142            json!(0),
1143            "counter 0 must serialize, not be elided as a default"
1144        );
1145    }
1146
1147    #[test]
1148    fn execution_step_without_a_loop_counter_key_deserializes() {
1149        // Trace JSON written before loops existed must still round-trip.
1150        let step: ExecutionStep = serde_json::from_value(json!({
1151            "workflow_id": "w",
1152            "task_id": "t",
1153            "result": "skipped"
1154        }))
1155        .expect("legacy trace JSON should deserialize");
1156        assert_eq!(step.loop_counter, None);
1157        assert_eq!(step.workflow_id, "w");
1158    }
1159
1160    #[test]
1161    fn add_executed_step_records_the_timing_bundle_and_the_loop_counter() {
1162        let mut trace = ExecutionTrace::with_options(TraceOptions::timings_only());
1163        let started_at = Utc::now();
1164        trace.add_executed_step(
1165            "w",
1166            "t",
1167            &Message::from_value(&json!({})),
1168            StepTiming {
1169                started_at,
1170                duration_us: 42,
1171            },
1172            None,
1173            StepStamp {
1174                loop_counter: Some(7),
1175                element_index: Some(2),
1176            },
1177        );
1178
1179        let step = &trace.steps[0];
1180        assert_eq!(step.started_at, Some(started_at));
1181        assert_eq!(step.duration_us, Some(42));
1182        assert_eq!(step.loop_counter, Some(7));
1183        assert_eq!(step.element_index, Some(2));
1184        assert_eq!(step.result, StepResult::Executed);
1185    }
1186
1187    #[test]
1188    fn execution_step_element_index_is_absent_from_json_when_none() {
1189        let plain = ExecutionStep::task_skipped("w", "t");
1190        let json = serde_json::to_value(&plain).expect("should serialize");
1191        assert!(
1192            json.get("element_index").is_none(),
1193            "an ordinary step keeps its wire shape"
1194        );
1195
1196        let fanned = ExecutionStep::task_skipped("w", "t").with_element_index(Some(3));
1197        assert_eq!(
1198            serde_json::to_value(&fanned).expect("should serialize")["element_index"],
1199            json!(3)
1200        );
1201
1202        let back: ExecutionStep = serde_json::from_value(json).expect("should deserialize");
1203        assert_eq!(back.element_index, None, "a step without the key loads");
1204    }
1205}