grafeo_engine/query/
profile.rs

1//! PROFILE statement: per-operator execution metrics.
2//!
3//! After a profiled query executes, the results are collected into a
4//! [`ProfileNode`] tree that mirrors the physical operator tree, annotated
5//! with actual row counts, timing, and call counts.
6
7use std::fmt::Write;
8use std::sync::Arc;
9
10use grafeo_common::types::{LogicalType, Value};
11use grafeo_core::execution::profile::{ProfileStats, SharedProfileStats};
12use parking_lot::Mutex;
13
14use super::plan::LogicalOperator;
15use crate::database::QueryResult;
16
17/// A node in the profile output tree, corresponding to one physical operator.
18#[derive(Debug)]
19pub struct ProfileNode {
20    /// Operator name (e.g., "NodeScan", "Filter", "Expand").
21    pub name: String,
22    /// Display label (e.g., "(n:Person)", "(n.age > 25) [label-first]").
23    pub label: String,
24    /// Shared stats handle, populated during execution.
25    pub stats: SharedProfileStats,
26    /// Child nodes.
27    pub children: Vec<ProfileNode>,
28}
29
30/// An entry collected during physical planning, used to build the profile tree.
31pub struct ProfileEntry {
32    /// Operator name from `Operator::name()`.
33    pub name: String,
34    /// Human-readable label from the logical operator.
35    pub label: String,
36    /// Shared stats handle passed to the `ProfiledOperator` wrapper.
37    pub stats: SharedProfileStats,
38}
39
40impl ProfileEntry {
41    /// Creates a new profile entry with fresh (empty) stats.
42    pub fn new(name: &str, label: String) -> (Self, SharedProfileStats) {
43        let stats = Arc::new(Mutex::new(ProfileStats::default()));
44        let entry = Self {
45            name: name.to_string(),
46            label,
47            stats: Arc::clone(&stats),
48        };
49        (entry, stats)
50    }
51}
52
53/// Builds a `ProfileNode` tree from the logical plan and a list of
54/// [`ProfileEntry`] items collected during physical planning.
55///
56/// The entries must be in **post-order** (children before parents),
57/// matching the order in which `plan_operator()` processes operators.
58///
59/// # Panics
60///
61/// Panics if the iterator yields fewer entries than there are logical operators.
62pub fn build_profile_tree(
63    logical: &LogicalOperator,
64    entries: &mut impl Iterator<Item = ProfileEntry>,
65) -> ProfileNode {
66    // Recurse into children first (post-order)
67    let children: Vec<ProfileNode> = logical
68        .children()
69        .into_iter()
70        .map(|child| build_profile_tree(child, entries))
71        .collect();
72
73    // Consume the entry for this node
74    let entry = entries
75        .next()
76        .expect("profile entry count must match logical operator count");
77
78    ProfileNode {
79        name: entry.name,
80        label: entry.label,
81        stats: entry.stats,
82        children,
83    }
84}
85
86/// Formats a `ProfileNode` tree into a human-readable text representation
87/// and wraps it in a `QueryResult` with a single "profile" column.
88pub fn profile_result(root: &ProfileNode, total_time_ms: f64) -> QueryResult {
89    let mut output = String::new();
90    format_node(&mut output, root, 0);
91    let _ = writeln!(output);
92    let _ = write!(output, "Total time: {total_time_ms:.2}ms");
93
94    QueryResult {
95        columns: vec!["profile".to_string()],
96        column_types: vec![LogicalType::String],
97        rows: vec![vec![Value::String(output.into())]],
98        execution_time_ms: Some(total_time_ms),
99        rows_scanned: None,
100        status_message: None,
101        gql_status: grafeo_common::utils::GqlStatus::SUCCESS,
102    }
103}
104
105/// Recursively formats a profile node with indentation.
106fn format_node(out: &mut String, node: &ProfileNode, depth: usize) {
107    let indent = "  ".repeat(depth);
108
109    // Compute self-time before locking stats (self_time_ns also locks).
110    let self_time_ns = self_time_ns(node);
111    let self_time_ms = self_time_ns as f64 / 1_000_000.0;
112
113    let rows_out = node.stats.lock().rows_out;
114
115    let _ = writeln!(
116        out,
117        "{indent}{name} ({label})  rows={rows}  time={time:.2}ms",
118        name = node.name,
119        label = node.label,
120        rows = rows_out,
121        time = self_time_ms,
122    );
123
124    for child in &node.children {
125        format_node(out, child, depth + 1);
126    }
127}
128
129/// Computes self-time: wall time minus children's wall time.
130fn self_time_ns(node: &ProfileNode) -> u64 {
131    let own_time = node.stats.lock().time_ns;
132    let child_time: u64 = node.children.iter().map(|c| c.stats.lock().time_ns).sum();
133    own_time.saturating_sub(child_time)
134}
grafeo_engine/query/profile.rs

grafeo_engine/query/
profile.rs
