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.
58pub fn build_profile_tree(
59    logical: &LogicalOperator,
60    entries: &mut impl Iterator<Item = ProfileEntry>,
61) -> ProfileNode {
62    // Recurse into children first (post-order)
63    let children: Vec<ProfileNode> = logical
64        .children()
65        .into_iter()
66        .map(|child| build_profile_tree(child, entries))
67        .collect();
68
69    // Consume the entry for this node
70    let entry = entries
71        .next()
72        .expect("profile entry count must match logical operator count");
73
74    ProfileNode {
75        name: entry.name,
76        label: entry.label,
77        stats: entry.stats,
78        children,
79    }
80}
81
82/// Formats a `ProfileNode` tree into a human-readable text representation
83/// and wraps it in a `QueryResult` with a single "profile" column.
84pub fn profile_result(root: &ProfileNode, total_time_ms: f64) -> QueryResult {
85    let mut output = String::new();
86    format_node(&mut output, root, 0);
87    let _ = writeln!(output);
88    let _ = write!(output, "Total time: {total_time_ms:.2}ms");
89
90    QueryResult {
91        columns: vec!["profile".to_string()],
92        column_types: vec![LogicalType::String],
93        rows: vec![vec![Value::String(output.into())]],
94        execution_time_ms: Some(total_time_ms),
95        rows_scanned: None,
96        status_message: None,
97        gql_status: grafeo_common::utils::GqlStatus::SUCCESS,
98    }
99}
100
101/// Recursively formats a profile node with indentation.
102fn format_node(out: &mut String, node: &ProfileNode, depth: usize) {
103    let indent = "  ".repeat(depth);
104
105    // Compute self-time before locking stats (self_time_ns also locks).
106    let self_time_ns = self_time_ns(node);
107    let self_time_ms = self_time_ns as f64 / 1_000_000.0;
108
109    let rows_out = node.stats.lock().rows_out;
110
111    let _ = writeln!(
112        out,
113        "{indent}{name} ({label})  rows={rows}  time={time:.2}ms",
114        name = node.name,
115        label = node.label,
116        rows = rows_out,
117        time = self_time_ms,
118    );
119
120    for child in &node.children {
121        format_node(out, child, depth + 1);
122    }
123}
124
125/// Computes self-time: wall time minus children's wall time.
126fn self_time_ns(node: &ProfileNode) -> u64 {
127    let own_time = node.stats.lock().time_ns;
128    let child_time: u64 = node.children.iter().map(|c| c.stats.lock().time_ns).sum();
129    own_time.saturating_sub(child_time)
130}
grafeo_engine/query/profile.rs

grafeo_engine/query/
profile.rs
