Skip to main content

datalogic_rs/
trace.rs

1//! Execution tracing for step-by-step debugging.
2//!
3//! This module provides execution tracing capabilities for debugging JSONLogic
4//! expressions. It generates an expression tree with unique IDs and records
5//! each evaluation step for replay in the Web UI.
6//!
7//! # Feature gating
8//!
9//! Gated on `feature = "trace"`. Trace transitively pulls in
10//! `feature = "serde_json"` (the `Cargo.toml` declares
11//! `trace = ["serde_json"]`) because the per-step expression tree and
12//! recorded values are `serde_json::Value`-shaped — the structured-trace
13//! consumers (the Web UI, JSON exporters) need the JSON↔arena bridge to
14//! render steps. `--features trace` implicitly enables `serde_json`.
15
16use serde::{Deserialize, Serialize};
17use serde_json::Value;
18
19use crate::node_serialize;
20use crate::{CompiledNode, Error};
21
22/// Represents a node in the expression tree for flow diagram rendering.
23#[derive(Debug, Clone, Serialize, Deserialize)]
24pub struct ExpressionNode {
25    /// Unique identifier for this node
26    pub id: u32,
27    /// JSON string of this sub-expression
28    pub expression: String,
29    /// Child nodes (arguments/operands that are operators, not literals)
30    pub children: Vec<ExpressionNode>,
31}
32
33impl ExpressionNode {
34    /// Build an expression tree from a CompiledNode.
35    ///
36    /// Every tree node inherits its compile-time id from the source
37    /// [`CompiledNode::id`]. No side-table is needed: both tracing and error
38    /// reporting look the id up directly on the node.
39    pub(crate) fn build_from_compiled(node: &CompiledNode) -> ExpressionNode {
40        Self::build_node(node)
41    }
42
43    fn build_node(node: &CompiledNode) -> ExpressionNode {
44        let id = node.id();
45        match node {
46            CompiledNode::Value { value, .. } => Self::leaf(id, value.to_json_string()),
47            CompiledNode::Array { nodes, .. } => ExpressionNode {
48                id,
49                expression: node_serialize::node_to_json_string(node),
50                children: Self::op_children(nodes),
51            },
52            CompiledNode::BuiltinOperator { opcode, args, .. } => ExpressionNode {
53                id,
54                expression: node_serialize::builtin_to_json_string(opcode, args),
55                children: Self::op_children(args),
56            },
57            CompiledNode::CustomOperator(data) => ExpressionNode {
58                id,
59                expression: node_serialize::custom_to_json_string(&data.name, &data.args),
60                children: Self::op_children(&data.args),
61            },
62            // Memo wrappers are invisible in the trace tree.
63            CompiledNode::Cse(data) => Self::build_node(&data.inner),
64            #[cfg(feature = "templating")]
65            CompiledNode::StructuredObject(data) => ExpressionNode {
66                id,
67                expression: node_serialize::structured_to_json_string(&data.fields),
68                children: Self::op_children_from_fields(&data.fields),
69            },
70            CompiledNode::Var {
71                scope_level,
72                segments,
73                default_value,
74                ..
75            } => Self::build_compiled_var(id, *scope_level, segments, default_value.as_deref()),
76            #[cfg(feature = "ext-control")]
77            CompiledNode::Exists(data) => Self::leaf(
78                id,
79                node_serialize::compiled_exists_to_json_string(&data.segments),
80            ),
81            #[cfg(feature = "error-handling")]
82            CompiledNode::Throw(_) | CompiledNode::Missing(_) | CompiledNode::MissingSome(_) => {
83                Self::leaf(id, node_serialize::node_to_json_string(node))
84            }
85            #[cfg(not(feature = "error-handling"))]
86            CompiledNode::Missing(_) | CompiledNode::MissingSome(_) => {
87                Self::leaf(id, node_serialize::node_to_json_string(node))
88            }
89            CompiledNode::InvalidArgs { .. } => {
90                Self::leaf(id, "{\"<invalid args>\": null}".to_string())
91            }
92        }
93    }
94
95    /// Build a leaf `ExpressionNode` (no children).
96    #[inline]
97    fn leaf(id: u32, expression: String) -> ExpressionNode {
98        ExpressionNode {
99            id,
100            expression,
101            children: vec![],
102        }
103    }
104
105    /// Recurse into a compiled-node slice, keeping only the operator nodes
106    /// (literals don't appear as flow-diagram children).
107    #[inline]
108    fn op_children(nodes: &[CompiledNode]) -> Vec<ExpressionNode> {
109        nodes
110            .iter()
111            .filter(|n| Self::is_operator_node(n))
112            .map(Self::build_node)
113            .collect()
114    }
115
116    /// `op_children` for the `(name, CompiledNode)` shape used by structured
117    /// object fields.
118    #[cfg(feature = "templating")]
119    #[inline]
120    fn op_children_from_fields(fields: &[(String, CompiledNode)]) -> Vec<ExpressionNode> {
121        fields
122            .iter()
123            .filter(|(_, n)| Self::is_operator_node(n))
124            .map(|(_, n)| Self::build_node(n))
125            .collect()
126    }
127
128    /// `CompiledVar`'s expression node — the only operator-shaped variant
129    /// whose "child" is the optional default value rather than a fixed args
130    /// slice.
131    fn build_compiled_var(
132        id: u32,
133        scope_level: u32,
134        segments: &[crate::node::PathSegment],
135        default_value: Option<&CompiledNode>,
136    ) -> ExpressionNode {
137        let mut children = Vec::new();
138        if let Some(def) = default_value {
139            if Self::is_operator_node(def) {
140                children.push(Self::build_node(def));
141            }
142        }
143        ExpressionNode {
144            id,
145            expression: node_serialize::compiled_var_to_json_string(
146                scope_level,
147                segments,
148                default_value,
149            ),
150            children,
151        }
152    }
153
154    /// Check if a node is an operator (not a literal value)
155    fn is_operator_node(node: &CompiledNode) -> bool {
156        !matches!(node, CompiledNode::Value { .. })
157    }
158}
159
160/// Captures state at each evaluation step.
161#[derive(Debug, Clone, Serialize, Deserialize)]
162pub struct ExecutionStep {
163    /// Sequential step number (assigned by the trace collector in
164    /// recording order). Distinct from `node_id`, which is the
165    /// compiled-node id of the expression being evaluated — `step_id`
166    /// is the *order* this step occurred, `node_id` is *which node* ran.
167    pub step_id: u32,
168    /// ID of the node being evaluated
169    pub node_id: u32,
170    /// Current context/scope data at this step
171    pub context: Value,
172    /// Result after evaluating this node (None if error)
173    pub result: Option<Value>,
174    /// Error message if evaluation failed (None if success)
175    pub error: Option<String>,
176    /// Current iteration index (only for iterator body evaluations)
177    #[serde(skip_serializing_if = "Option::is_none")]
178    pub iteration_index: Option<u32>,
179    /// Total iteration count (only for iterator body evaluations)
180    #[serde(skip_serializing_if = "Option::is_none")]
181    pub iteration_total: Option<u32>,
182}
183
184/// Collector for execution steps during traced evaluation.
185pub(crate) struct TraceCollector {
186    /// Recorded execution steps
187    steps: Vec<ExecutionStep>,
188    /// Counter for generating step IDs
189    step_counter: u32,
190    /// Stack of iteration info (index, total) for nested iterations
191    iteration_stack: Vec<(u32, u32)>,
192}
193
194impl TraceCollector {
195    /// Create a new trace collector
196    pub(crate) fn new() -> Self {
197        Self {
198            steps: Vec::new(),
199            step_counter: 0,
200            iteration_stack: Vec::new(),
201        }
202    }
203
204    /// Record a successful execution step
205    pub(crate) fn record_step(&mut self, node_id: u32, context: Value, result: Value) {
206        self.record(node_id, context, Some(result), None);
207    }
208
209    /// Record an error execution step
210    pub(crate) fn record_error(&mut self, node_id: u32, context: Value, error: String) {
211        self.record(node_id, context, None, Some(error));
212    }
213
214    /// Shared step constructor behind [`Self::record_step`] /
215    /// [`Self::record_error`]: stamp the step with the next sequential id
216    /// and the current iteration context.
217    fn record(
218        &mut self,
219        node_id: u32,
220        context: Value,
221        result: Option<Value>,
222        error: Option<String>,
223    ) {
224        let (iteration_index, iteration_total) = self.current_iteration();
225        self.steps.push(ExecutionStep {
226            step_id: self.step_counter,
227            node_id,
228            context,
229            result,
230            error,
231            iteration_index,
232            iteration_total,
233        });
234        self.step_counter += 1;
235    }
236
237    /// Push iteration context for map/filter/reduce operations
238    pub(crate) fn push_iteration(&mut self, index: u32, total: u32) {
239        self.iteration_stack.push((index, total));
240    }
241
242    /// Pop iteration context
243    pub(crate) fn pop_iteration(&mut self) {
244        self.iteration_stack.pop();
245    }
246
247    /// Get current iteration info if inside an iteration
248    fn current_iteration(&self) -> (Option<u32>, Option<u32>) {
249        self.iteration_stack
250            .last()
251            .map(|(i, t)| (Some(*i), Some(*t)))
252            .unwrap_or((None, None))
253    }
254
255    /// Consume the collector and return the recorded steps
256    pub(crate) fn into_steps(self) -> Vec<ExecutionStep> {
257        self.steps
258    }
259}
260
261impl Default for TraceCollector {
262    fn default() -> Self {
263        Self::new()
264    }
265}
266
267// ============================================================================
268// v5 trace surface — `engine.trace().evaluate*(...)` returning `TracedRun`.
269// ============================================================================
270
271/// Result of a traced evaluation produced by [`TracedSession`]. Always
272/// includes the trace data; the value-or-error split lives on
273/// [`Self::result`].
274#[derive(Debug, Clone)]
275pub struct TracedRun<R> {
276    /// `Ok(value)` on success, `Err(error)` on failure. The error always
277    /// carries the operator + path metadata populated by the engine.
278    pub result: Result<R, Error>,
279    /// Per-node execution log captured during the run.
280    pub steps: Vec<ExecutionStep>,
281    /// Compile-time expression tree for flow-diagram rendering.
282    pub expression_tree: ExpressionNode,
283}
284
285impl<R> TracedRun<R> {
286    /// Rebuild the run around a converted result, preserving the recorded
287    /// steps and expression tree. Internal helper shared by the
288    /// owned-result entry points, which each project the arena-borrowed
289    /// result into an owned shape before the arena drops.
290    fn convert<T>(self, f: impl FnOnce(Result<R, Error>) -> Result<T, Error>) -> TracedRun<T> {
291        TracedRun {
292            result: f(self.result),
293            steps: self.steps,
294            expression_tree: self.expression_tree,
295        }
296    }
297}
298
299/// Trace-enabled view over a [`crate::Engine`] engine. Constructed via
300/// [`crate::Engine::trace`]. Mirrors [`crate::Session`] 1:1 — every
301/// `eval*` returns a [`TracedRun<R>`] carrying the trace alongside the
302/// result, where `R` is the same shape that `Session::eval*` would
303/// return. Owns its own [`bumpalo::Bump`] across calls; reset is
304/// per-call (the trace path always allocates a fresh arena to keep the
305/// borrowed-result lifetime tied to the run).
306pub struct TracedSession<'e> {
307    engine: &'e crate::Engine,
308}
309
310impl<'e> TracedSession<'e> {
311    /// Construct a session over `engine`. Invoked from
312    /// [`crate::Engine::trace`].
313    #[inline]
314    pub(crate) fn new(engine: &'e crate::Engine) -> Self {
315        Self { engine }
316    }
317
318    /// Traced evaluation of a pre-compiled [`crate::Logic`] returning
319    /// [`datavalue::OwnedDataValue`]. The trace surfaces only the
320    /// operators that survived compilation — constant sub-expressions
321    /// folded by [`crate::Engine::compile`] won't appear as steps. For
322    /// full coverage on a one-shot run, prefer [`Self::eval_str`].
323    pub fn eval<D>(&self, compiled: &crate::Logic, data: D) -> TracedRun<datavalue::OwnedDataValue>
324    where
325        D: crate::OwnedInput,
326    {
327        let owned_data = match data.into_owned_input() {
328            Ok(d) => d,
329            Err(e) => return Self::compile_failed(e),
330        };
331        let arena = bumpalo::Bump::new();
332        self.eval_borrowed_in(compiled, &owned_data, &arena)
333            .convert(|result| result.and_then(crate::FromDataValue::from_arena))
334    }
335
336    /// One-shot traced evaluation with JSON-string boundary on both
337    /// sides. Compiles internally with the optimizer + constant-fold
338    /// passes disabled, so the trace surfaces every operator in the
339    /// rule.
340    pub fn eval_str<R, D>(&self, rule: R, data: D) -> TracedRun<String>
341    where
342        R: crate::IntoLogic,
343        D: crate::OwnedInput,
344    {
345        let (compiled, owned_data) = match self.prepare(rule, data) {
346            Ok(prepared) => prepared,
347            Err(e) => return Self::compile_failed(e),
348        };
349        let arena = bumpalo::Bump::new();
350        self.eval_borrowed_in(&compiled, &owned_data, &arena)
351            .convert(|result| result.map(|v| v.to_string()))
352    }
353
354    /// Typed traced evaluation: deserialise the result into
355    /// `T: DeserializeOwned`. Routes through `serde_json`.
356    #[cfg(feature = "serde_json")]
357    #[cfg_attr(docsrs, doc(cfg(feature = "serde_json")))]
358    pub fn eval_into<T, R, D>(&self, rule: R, data: D) -> TracedRun<T>
359    where
360        T: serde::de::DeserializeOwned,
361        R: crate::IntoLogic,
362        D: crate::OwnedInput,
363    {
364        let (compiled, owned_data) = match self.prepare(rule, data) {
365            Ok(prepared) => prepared,
366            Err(e) => return Self::compile_failed(e),
367        };
368        let arena = bumpalo::Bump::new();
369        self.eval_borrowed_in(&compiled, &owned_data, &arena)
370            .convert(|result| {
371                result.and_then(|v| {
372                    let value: serde_json::Value = crate::FromDataValue::from_arena(v)?;
373                    serde_json::from_value(value).map_err(crate::Error::from)
374                })
375            })
376    }
377
378    /// Shared front half of the one-shot traced entry points
379    /// ([`Self::eval_str`] / [`Self::eval_into`]): normalise the rule,
380    /// compile it with the optimizer + constant-fold passes disabled, and
381    /// normalise the data into an owned value the arena run can borrow.
382    fn prepare<R, D>(
383        &self,
384        rule: R,
385        data: D,
386    ) -> crate::Result<(crate::Logic, datavalue::OwnedDataValue)>
387    where
388        R: crate::IntoLogic,
389        D: crate::OwnedInput,
390    {
391        let owned = rule.into_owned_logic()?;
392        let compiled = crate::Logic::compile_for_trace(&owned, self.engine)?;
393        let owned_data = data.into_owned_input()?;
394        Ok((compiled, owned_data))
395    }
396
397    /// Traced borrowed evaluation against a caller-owned arena. Mirrors
398    /// [`crate::Session::eval_borrowed`] / [`crate::Engine::evaluate`]
399    /// — the result references `arena`, while the trace data is owned
400    /// and outlives the arena.
401    pub fn eval_borrowed<'a, D>(
402        &self,
403        compiled: &'a crate::Logic,
404        data: D,
405        arena: &'a bumpalo::Bump,
406    ) -> TracedRun<&'a crate::DataValue<'a>>
407    where
408        D: crate::EvalInput<'a>,
409    {
410        self.eval_borrowed_in(compiled, data, arena)
411    }
412
413    /// Internal: shared body for the borrowed-result trace runs.
414    fn eval_borrowed_in<'a, D>(
415        &self,
416        compiled: &'a crate::Logic,
417        data: D,
418        arena: &'a bumpalo::Bump,
419    ) -> TracedRun<&'a crate::DataValue<'a>>
420    where
421        D: crate::EvalInput<'a>,
422    {
423        let expression_tree = ExpressionNode::build_from_compiled(&compiled.root);
424        let _depth_guard = match self.engine.enter_dispatch_boundary() {
425            Ok(g) => g,
426            Err(e) => return Self::failed(expression_tree, e),
427        };
428        let data_ref = match data.into_arena_value(arena) {
429            Ok(av) => av,
430            Err(e) => return Self::failed(expression_tree, e),
431        };
432        let mut ctx = crate::arena::ContextStack::new(data_ref);
433        ctx.attach_tracer(TraceCollector::new());
434
435        let outcome = self.engine.dispatch_node(&compiled.root, &mut ctx, arena);
436        let result = match outcome {
437            Ok(av) => Ok(av),
438            Err(e) => Err(e.decorated(ctx.take_error_path(), compiled, false)),
439        };
440        let collector = ctx.detach_tracer().expect("attach_tracer was called above");
441        TracedRun {
442            result,
443            steps: collector.into_steps(),
444            expression_tree,
445        }
446    }
447
448    /// A run that failed before any step could be recorded: carries the
449    /// given expression tree and an empty step log.
450    fn failed<R>(expression_tree: ExpressionNode, error: crate::Error) -> TracedRun<R> {
451        TracedRun {
452            result: Err(error),
453            steps: Vec::new(),
454            expression_tree,
455        }
456    }
457
458    /// [`Self::failed`] for errors raised before an expression tree exists
459    /// (rule normalisation / compilation / data conversion): the tree is an
460    /// empty placeholder.
461    fn compile_failed<R>(error: crate::Error) -> TracedRun<R> {
462        Self::failed(
463            ExpressionNode {
464                id: 0,
465                expression: String::new(),
466                children: Vec::new(),
467            },
468            error,
469        )
470    }
471}
472
473#[cfg(test)]
474mod tests {
475    use super::*;
476    use crate::OpCode;
477
478    #[test]
479    fn test_expression_node_from_simple_operator() {
480        // Create a simple {"val": "age"} node (var is normalized to Val).
481        let node = CompiledNode::BuiltinOperator {
482            id: crate::node::SYNTHETIC_ID,
483            opcode: OpCode::Val,
484            args: vec![CompiledNode::synthetic_value(
485                datavalue::OwnedDataValue::from("age"),
486            )]
487            .into_boxed_slice(),
488            predicate_hint: None,
489            iter_arg_kind: crate::operators::array::IterArgKind::General,
490        };
491
492        let tree = ExpressionNode::build_from_compiled(&node);
493
494        // Synthetic test nodes all share SYNTHETIC_ID, which surfaces as 0
495        // through the public `ExpressionNode::id` (u32) shape; the
496        // structural assertions below still hold.
497        assert_eq!(tree.id, 0);
498        assert_eq!(tree.expression, r#"{"val": "age"}"#);
499        assert!(tree.children.is_empty()); // "age" is a literal, not a child
500    }
501
502    #[test]
503    fn test_expression_node_from_nested_operator() {
504        // Create {">=": [{"val": "age"}, 18]}
505        let var_node = CompiledNode::BuiltinOperator {
506            id: crate::node::SYNTHETIC_ID,
507            opcode: OpCode::Val,
508            args: vec![CompiledNode::synthetic_value(
509                datavalue::OwnedDataValue::from("age"),
510            )]
511            .into_boxed_slice(),
512            predicate_hint: None,
513            iter_arg_kind: crate::operators::array::IterArgKind::General,
514        };
515        let node = CompiledNode::BuiltinOperator {
516            id: crate::node::SYNTHETIC_ID,
517            opcode: OpCode::GreaterThanEqual,
518            args: vec![
519                var_node,
520                CompiledNode::synthetic_value(datavalue::OwnedDataValue::Number(
521                    datavalue::NumberValue::Integer(18),
522                )),
523            ]
524            .into_boxed_slice(),
525            predicate_hint: None,
526            iter_arg_kind: crate::operators::array::IterArgKind::General,
527        };
528
529        let tree = ExpressionNode::build_from_compiled(&node);
530
531        assert_eq!(tree.id, 0);
532        assert!(tree.expression.contains(">="));
533        assert_eq!(tree.children.len(), 1); // var node is a child
534        assert!(tree.children[0].expression.contains("val"));
535    }
536
537    #[test]
538    fn test_trace_collector_records_steps() {
539        let mut collector = TraceCollector::new();
540
541        collector.record_step(0, serde_json::json!({"age": 25}), serde_json::json!(25));
542        collector.record_step(1, serde_json::json!({"age": 25}), serde_json::json!(true));
543
544        let steps = collector.into_steps();
545        assert_eq!(steps.len(), 2);
546        assert_eq!(steps[0].step_id, 0);
547        assert_eq!(steps[0].node_id, 0);
548        assert_eq!(steps[1].step_id, 1);
549        assert_eq!(steps[1].node_id, 1);
550    }
551
552    #[test]
553    fn test_trace_collector_iteration_context() {
554        let mut collector = TraceCollector::new();
555
556        collector.push_iteration(0, 3);
557        collector.record_step(2, serde_json::json!(1), serde_json::json!(2));
558
559        let steps = collector.into_steps();
560        assert_eq!(steps[0].iteration_index, Some(0));
561        assert_eq!(steps[0].iteration_total, Some(3));
562    }
563
564    #[test]
565    fn traced_session_evaluate_str_smoke() {
566        let engine = crate::Engine::new();
567        let run = engine.trace().eval_str(r#"{"+": [1, 2, 3]}"#, "null");
568        assert_eq!(run.result.unwrap(), "6");
569        // The one-shot trace path skips static folding internally, so the
570        // `+` operator survives and produces a step.
571        assert!(!run.steps.is_empty(), "expected non-empty steps");
572        assert_ne!(run.expression_tree.id, 0);
573    }
574
575    #[test]
576    fn traced_pre_compiled_inherits_fold() {
577        // Pre-compiled trace inherits the shape from `Engine::compile`, which
578        // folds. A fully-constant rule has no surviving operator → no steps.
579        let engine = crate::Engine::new();
580        let compiled = engine.compile(r#"{"+": [1, 2]}"#).unwrap();
581        let arena = bumpalo::Bump::new();
582        let data = datavalue::DataValue::from_str("null", &arena).unwrap();
583        let run = engine.trace().eval_borrowed(&compiled, data, &arena);
584        assert_eq!(run.result.as_ref().unwrap().as_i64(), Some(3));
585        assert!(
586            run.steps.is_empty(),
587            "folded rule should not produce trace steps"
588        );
589    }
590
591    #[test]
592    fn traced_session_carries_error_metadata() {
593        let engine = crate::Engine::new();
594        let run = engine.trace().eval_str(r#"{"+": ["x", 1]}"#, "null");
595        let err = run.result.expect_err("string-arith should fail");
596        assert_eq!(err.operator(), Some("+"));
597        assert!(!err.node_ids().is_empty(), "expected populated breadcrumb");
598    }
599}