jlens_core/audit/
mod.rs

1//! Evaluation logging and auditing (see ADR 0004).
2//!
3//! The evaluator reports what it does to a [`Tracer`]: it enters and leaves nodes, compares
4//! operands, short-circuits `and`/`or`, takes conditional branches, binds variables and filters
5//! sequences. Tracers turn these events into something useful:
6//!
7//! * [`AuditCollector`] builds an [`AuditTree`], which records how the result was reached with
8//!   business labels from [annotations](crate::annotation). [`explain`] summarizes it.
9//! * [`JsonlTracer`] writes one JSON object per event, for offline analysis.
10//! * `TracingTracer` (feature `tracing`) forwards events to the `tracing` crate.
11//!
12//! ```
13//! use jlens_core::{Bindings, Expression, Options};
14//! use jlens_core::audit::{AuditOptions, explain};
15//! use serde_json::json;
16//!
17//! let expr = Expression::compile(
18//!     r#"/** @label "Big order" */ total > 100 and /** @label "Known customer" */ customer != null"#,
19//! ).unwrap();
20//! let input = json!({"total": 250, "customer": null});
21//! let (result, audit) =
22//!     expr.evaluate_audited(Some(&input), &Bindings::new(), &Options::default(), &AuditOptions::decisions());
23//! assert_eq!(result.unwrap(), Some(json!(false)));
24//! let text = explain(&audit).to_string();
25//! assert!(text.contains("✘ Known customer"));
26//! ```
27
28mod collector;
29mod explain;
30mod jsonl;
31#[cfg(feature = "tracing")]
32mod tracing_tracer;
33
34pub use collector::AuditCollector;
35pub use explain::{Explanation, ExplanationLine, explain};
36pub use jsonl::JsonlTracer;
37#[cfg(feature = "tracing")]
38pub use tracing_tracer::TracingTracer;
39
40use serde::{Deserialize, Serialize};
41use serde_json::Value as JsonValue;
42
43use crate::ast::{Node, NodeId, Span};
44use crate::error::Error;
45use crate::value::{Inspect, MAX_NESTING, Value, nest};
46
47/// Receives evaluation events. Every method has an empty default implementation.
48///
49/// Events nest: between `enter(node)` and the matching `exit(node)`, all events concern the
50/// evaluation of `node` and of its descendants. The same node is entered many times when it is
51/// evaluated for several items or inside a function called repeatedly.
52pub trait Tracer {
53    /// The evaluation starts.
54    fn begin(&mut self, info: &EvalInfo) {
55        let _ = info;
56    }
57    /// Evaluation of `node` against `input` starts.
58    fn enter(&mut self, node: &Node, input: ValueRef<'_>) {
59        let _ = (node, input);
60    }
61    /// Evaluation of `node` ends with a value or an error.
62    fn exit(&mut self, node: &Node, outcome: Outcome<'_>) {
63        let _ = (node, outcome);
64    }
65    /// A comparison (`=`, `!=`, `<`, `<=`, `>`, `>=`, `in`) is about to compare these operands.
66    fn operands(&mut self, node: &Node, lhs: ValueRef<'_>, rhs: ValueRef<'_>) {
67        let _ = (node, lhs, rhs);
68    }
69    /// The right side of `and`/`or` was not evaluated because the left side decided.
70    fn short_circuit(&mut self, node: &Node) {
71        let _ = node;
72    }
73    /// A conditional took a branch.
74    fn branch(&mut self, node: &Node, taken: Branch) {
75        let _ = (node, taken);
76    }
77    /// `$name := value` bound a variable.
78    fn bind(&mut self, node: &Node, name: &str, value: ValueRef<'_>) {
79        let _ = (node, name, value);
80    }
81    /// A predicate filter starts testing the items of a sequence.
82    fn filter_begin(&mut self, predicate: &Node) {
83        let _ = predicate;
84    }
85    /// A predicate filter tested one item.
86    fn filter_item(&mut self, predicate: &Node, index: usize, item: ValueRef<'_>, passed: bool) {
87        let _ = (predicate, index, item, passed);
88    }
89    /// A predicate filter finished.
90    fn filter_end(&mut self, predicate: &Node) {
91        let _ = predicate;
92    }
93    /// The evaluation ended.
94    fn end(&mut self, outcome: Outcome<'_>) {
95        let _ = outcome;
96    }
97}
98
99/// Facts about an evaluation, given to [`Tracer::begin`].
100#[derive(Debug, Clone)]
101pub struct EvalInfo<'a> {
102    /// Source text of the expression.
103    pub source: &'a str,
104    /// The evaluation's timestamp (`$millis()`), in milliseconds since the epoch.
105    pub timestamp: f64,
106}
107
108/// A read-only view of a run-time value.
109#[derive(Clone, Copy)]
110pub struct ValueRef<'a>(pub(crate) &'a dyn Inspect);
111
112impl ValueRef<'_> {
113    /// The value as JSON (`None` for undefined and functions, and for a value nested more than
114    /// 1,000 levels deep).
115    pub fn to_json(&self) -> Option<JsonValue> {
116        self.0.to_json()
117    }
118
119    /// The value as JSON, truncated according to `limits`.
120    pub fn capture(&self, limits: &CaptureLimits) -> Option<JsonValue> {
121        self.0.capture(limits)
122    }
123
124    /// Whether the value is undefined.
125    pub fn is_undefined(&self) -> bool {
126        self.0.signature_symbol() == 'm'
127    }
128
129    /// The value if it is a boolean.
130    pub fn as_bool(&self) -> Option<bool> {
131        self.0.as_bool()
132    }
133
134    /// The JSONata type name (`string`, `number`, `boolean`, `null`, `array`, `object`,
135    /// `function`, or `undefined`).
136    pub fn type_name(&self) -> &'static str {
137        match self.0.signature_symbol() {
138            'm' => "undefined",
139            'l' => "null",
140            'b' => "boolean",
141            'n' => "number",
142            's' => "string",
143            'a' => "array",
144            'o' => "object",
145            _ => "function",
146        }
147    }
148}
149
150impl std::fmt::Debug for ValueRef<'_> {
151    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
152        self.0.fmt(f)
153    }
154}
155
156/// How the evaluation of a node ended.
157#[derive(Debug, Clone, Copy)]
158pub enum Outcome<'a> {
159    /// It produced a value (possibly undefined).
160    Value(ValueRef<'a>),
161    /// It raised an error.
162    Error(&'a Error),
163}
164
165/// The branch taken by a conditional.
166#[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize, Deserialize)]
167#[serde(rename_all = "lowercase")]
168pub enum Branch {
169    /// The condition held.
170    Then,
171    /// The condition did not hold and there is an `else` part.
172    Else,
173    /// The condition did not hold and there is no `else` part.
174    None,
175}
176
177/// How much an [`AuditCollector`] records.
178#[derive(Debug, Clone, Copy, PartialEq, Eq, Default, Serialize, Deserialize)]
179#[serde(rename_all = "lowercase")]
180pub enum AuditLevel {
181    /// Nothing; the tree only has a header.
182    Off,
183    /// Only nodes that decide something: comparisons, `and`/`or`, conditionals, variable
184    /// bindings, nodes producing booleans, filters, and annotated nodes.
185    #[default]
186    Decisions,
187    /// Every evaluated node, with its input.
188    Full,
189}
190
191/// Bounds on what an audit captures, so that large inputs produce bounded audits.
192#[derive(Debug, Clone, Copy, Serialize, Deserialize)]
193#[serde(rename_all = "camelCase")]
194pub struct CaptureLimits {
195    /// Items kept from an array (and fields from an object) in captured values.
196    pub max_items: usize,
197    /// Characters kept from a string in captured values.
198    pub max_string: usize,
199    /// Nesting depth kept in captured values.
200    pub max_depth: usize,
201    /// Rejected items kept as samples per filter.
202    pub max_rejected: usize,
203    /// Nodes recorded in the tree; further nodes are dropped and `truncated` is set.
204    pub max_nodes: usize,
205    /// Characters of source text kept per node.
206    pub max_source: usize,
207}
208
209impl Default for CaptureLimits {
210    fn default() -> Self {
211        CaptureLimits {
212            max_items: 10,
213            max_string: 200,
214            max_depth: 4,
215            max_rejected: 5,
216            max_nodes: 10_000,
217            max_source: 200,
218        }
219    }
220}
221
222/// Settings for [`crate::Expression::evaluate_audited`].
223#[derive(Debug, Clone, Copy, Default, Serialize, Deserialize)]
224pub struct AuditOptions {
225    /// What to record.
226    pub level: AuditLevel,
227    /// Bounds on captured values and tree size.
228    pub limits: CaptureLimits,
229}
230
231impl AuditOptions {
232    /// Records decisions only (the default).
233    pub fn decisions() -> Self {
234        AuditOptions::default()
235    }
236
237    /// Records every evaluated node.
238    pub fn full() -> Self {
239        AuditOptions {
240            level: AuditLevel::Full,
241            ..AuditOptions::default()
242        }
243    }
244}
245
246/// The audit of one evaluation.
247#[derive(Debug, Clone, Serialize, Deserialize)]
248#[serde(rename_all = "camelCase")]
249pub struct AuditTree {
250    /// What was evaluated, when, and how it ended.
251    pub header: AuditHeader,
252    /// The root of the recorded tree (absent with [`AuditLevel::Off`]).
253    #[serde(skip_serializing_if = "Option::is_none")]
254    pub root: Option<AuditNode>,
255    /// Number of recorded nodes.
256    pub node_count: usize,
257    /// Whether nodes were dropped because of [`CaptureLimits::max_nodes`].
258    pub truncated: bool,
259}
260
261/// The header of an [`AuditTree`].
262#[derive(Debug, Clone, Serialize, Deserialize)]
263#[serde(rename_all = "camelCase")]
264pub struct AuditHeader {
265    /// `jlens-core` and its version.
266    pub engine: String,
267    /// FNV-1a 64-bit hash of the expression source, in hexadecimal.
268    pub expression_hash: String,
269    /// FNV-1a 64-bit hash of the input document's JSON text, in hexadecimal.
270    pub input_hash: String,
271    /// The evaluation timestamp (`$now()`), in ISO 8601.
272    pub timestamp: String,
273    /// Wall-clock duration of the evaluation, in milliseconds.
274    pub duration_ms: f64,
275    /// The level the audit was recorded at.
276    pub level: AuditLevel,
277    /// The result of the evaluation (absent when undefined or on error).
278    #[serde(skip_serializing_if = "Option::is_none")]
279    pub result: Option<JsonValue>,
280    /// The error, if the evaluation failed.
281    #[serde(skip_serializing_if = "Option::is_none")]
282    pub error: Option<AuditError>,
283}
284
285/// An error recorded in an audit.
286#[derive(Debug, Clone, PartialEq, Serialize, Deserialize)]
287pub struct AuditError {
288    /// The JSONata error code.
289    pub code: String,
290    /// The message.
291    pub message: String,
292}
293
294impl From<&Error> for AuditError {
295    fn from(e: &Error) -> Self {
296        AuditError {
297            code: e.code().to_owned(),
298            message: e.message(),
299        }
300    }
301}
302
303/// The result kind of an audited node.
304#[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize, Deserialize)]
305#[serde(rename_all = "lowercase")]
306pub enum OutcomeKind {
307    /// It produced `true`.
308    True,
309    /// It produced `false`.
310    False,
311    /// It produced another value.
312    Value,
313    /// It produced undefined.
314    Undefined,
315    /// It raised an error.
316    Error,
317}
318
319/// One evaluation of one node.
320#[derive(Debug, Clone, Serialize, Deserialize)]
321#[serde(rename_all = "camelCase")]
322pub struct AuditNode {
323    /// The syntax-tree node (`Node::id`).
324    pub node: NodeId,
325    /// The node type (`binary`, `path`, `function`, ...).
326    pub kind: String,
327    /// The operator, function or variable name, when there is one.
328    #[serde(skip_serializing_if = "Option::is_none")]
329    pub op: Option<String>,
330    /// Byte range of the node in the expression source.
331    pub span: Span,
332    /// The node's source text (possibly shortened).
333    pub source: String,
334    /// `@label` of the node's annotation.
335    #[serde(skip_serializing_if = "Option::is_none")]
336    pub label: Option<String>,
337    /// `@message` of the node's annotation.
338    #[serde(skip_serializing_if = "Option::is_none")]
339    pub message: Option<String>,
340    /// `@id` of the node's annotation.
341    #[serde(skip_serializing_if = "Option::is_none")]
342    pub check_id: Option<String>,
343    /// The context value (recorded with [`AuditLevel::Full`] only).
344    #[serde(skip_serializing_if = "Option::is_none")]
345    pub input: Option<JsonValue>,
346    /// The value produced.
347    #[serde(skip_serializing_if = "Option::is_none")]
348    pub output: Option<JsonValue>,
349    /// How the evaluation ended.
350    pub outcome: OutcomeKind,
351    /// The error, when `outcome` is `error`.
352    #[serde(skip_serializing_if = "Option::is_none")]
353    pub error: Option<AuditError>,
354    /// The compared values, for comparisons.
355    #[serde(skip_serializing_if = "Option::is_none")]
356    pub operands: Option<[Option<JsonValue>; 2]>,
357    /// For `and`/`or`: the right side was not evaluated.
358    #[serde(skip_serializing_if = "std::ops::Not::not", default)]
359    pub short_circuited: bool,
360    /// For conditionals: the branch taken.
361    #[serde(skip_serializing_if = "Option::is_none")]
362    pub branch: Option<Branch>,
363    /// For `$name := value`: the variable bound.
364    #[serde(skip_serializing_if = "Option::is_none")]
365    pub binding: Option<String>,
366    /// Predicate filters applied while evaluating this node.
367    #[serde(skip_serializing_if = "Vec::is_empty", default)]
368    pub filters: Vec<FilterAudit>,
369    /// Recorded evaluations nested inside this one.
370    #[serde(skip_serializing_if = "Vec::is_empty", default)]
371    pub children: Vec<AuditNode>,
372}
373
374impl AuditNode {
375    /// Whether the node evaluated to `true` (`Some(true)`), `false` (`Some(false)`), or
376    /// something else (`None`).
377    pub fn passed(&self) -> Option<bool> {
378        match self.outcome {
379            OutcomeKind::True => Some(true),
380            OutcomeKind::False => Some(false),
381            _ => None,
382        }
383    }
384}
385
386/// Statistics of a predicate filter (`items[price > 10]`).
387#[derive(Debug, Clone, Serialize, Deserialize)]
388#[serde(rename_all = "camelCase")]
389pub struct FilterAudit {
390    /// The predicate node.
391    pub node: NodeId,
392    /// The predicate's source text.
393    pub source: String,
394    /// `@label` of the predicate's annotation.
395    #[serde(skip_serializing_if = "Option::is_none")]
396    pub label: Option<String>,
397    /// Items tested.
398    pub tested: usize,
399    /// Items that passed.
400    pub passed: usize,
401    /// A sample of the items that did not pass.
402    #[serde(skip_serializing_if = "Vec::is_empty", default)]
403    pub rejected: Vec<JsonValue>,
404}
405
406/// Captures a value as JSON within `limits`. Truncated arrays end with a `"… N more"` string,
407/// truncated objects with a `"…": "N more"` field, and strings with `…`.
408pub(crate) fn capture(v: &Value<'_>, limits: &CaptureLimits, depth: usize) -> Option<JsonValue> {
409    Some(match v {
410        Value::Undefined => return None,
411        Value::Function(_) => JsonValue::String("<function>".into()),
412        Value::String(s) => {
413            let count = s.chars().count();
414            if count > limits.max_string {
415                let mut t: String = s.chars().take(limits.max_string).collect();
416                t.push('…');
417                JsonValue::String(t)
418            } else {
419                JsonValue::String(s.to_string())
420            }
421        }
422        Value::Array(_) | Value::Object(_) if depth >= limits.max_depth.min(MAX_NESTING) => {
423            JsonValue::String("…".into())
424        }
425        Value::Array(a) => {
426            let mut items: Vec<JsonValue> = a
427                .items()
428                .iter()
429                .take(limits.max_items)
430                .map(|i| {
431                    nest(depth + 1, || capture(i, limits, depth + 1)).unwrap_or(JsonValue::Null)
432                })
433                .collect();
434            if a.items().len() > limits.max_items {
435                items.push(JsonValue::String(format!(
436                    "… {} more",
437                    a.items().len() - limits.max_items
438                )));
439            }
440            JsonValue::Array(items)
441        }
442        Value::Object(o) => {
443            let o = o.borrow();
444            let mut map = serde_json::Map::new();
445            for (k, v) in o.iter().take(limits.max_items) {
446                if let Some(j) = nest(depth + 1, || capture(v, limits, depth + 1)) {
447                    map.insert(k.to_string(), j);
448                }
449            }
450            if o.len() > limits.max_items {
451                map.insert(
452                    "…".into(),
453                    JsonValue::String(format!("{} more", o.len() - limits.max_items)),
454                );
455            }
456            JsonValue::Object(map)
457        }
458        other => other.to_json()?,
459    })
460}
461
462/// FNV-1a, 64 bits, as 16 hexadecimal digits.
463pub(crate) fn fnv1a(text: &str) -> String {
464    let mut hash: u64 = 0xcbf2_9ce4_8422_2325;
465    for b in text.bytes() {
466        hash ^= u64::from(b);
467        hash = hash.wrapping_mul(0x0000_0100_0000_01b3);
468    }
469    format!("{hash:016x}")
470}
471
472/// A short description of a node for audits: its kind and operator/name.
473pub(crate) fn describe(node: &Node) -> (&'static str, Option<String>) {
474    use crate::ast::NodeKind;
475    let op = match &node.kind {
476        NodeKind::Binary { op, .. } => Some(op.symbol().to_owned()),
477        NodeKind::Function { procedure, .. } | NodeKind::Partial { procedure, .. } => {
478            match &procedure.kind {
479                NodeKind::Variable { name } => Some(format!("${name}")),
480                NodeKind::Path { steps, .. } => match &steps[0].kind {
481                    NodeKind::Variable { name } => Some(format!("${name}")),
482                    NodeKind::Name { name } => Some(name.clone()),
483                    _ => None,
484                },
485                _ => None,
486            }
487        }
488        NodeKind::Variable { name } => Some(format!("${name}")),
489        NodeKind::Name { name } => Some(name.clone()),
490        NodeKind::Bind { lhs, .. } => match &lhs.kind {
491            NodeKind::Variable { name } => Some(format!("${name}")),
492            _ => None,
493        },
494        _ => None,
495    };
496    (node.type_name(), op)
497}
498
499/// The source text of `span`, whitespace-normalized and shortened to `max` characters.
500pub(crate) fn snippet(source: &str, span: Span, max: usize) -> String {
501    let text = source.get(span.start..span.end).unwrap_or_default();
502    // Drop comments (annotations show up as labels instead).
503    let mut without_comments = String::with_capacity(text.len());
504    let mut rest = text;
505    while let Some(start) = rest.find("/*") {
506        without_comments.push_str(&rest[..start]);
507        match rest[start + 2..].find("*/") {
508            Some(end) => rest = &rest[start + 2 + end + 2..],
509            None => rest = "",
510        }
511    }
512    without_comments.push_str(rest);
513    let collapsed = without_comments
514        .split_whitespace()
515        .collect::<Vec<_>>()
516        .join(" ");
517    if collapsed.chars().count() > max {
518        let mut s: String = collapsed.chars().take(max).collect();
519        s.push('…');
520        s
521    } else {
522        collapsed
523    }
524}
jlens_core/audit/mod.rs

jlens_core/audit/
mod.rs
