Skip to content

Commit 0d67778

Browse files
johnmzzmazhuojohn
andauthored
feat: engine support EXPLAIN/PROFILE (#708)
## Summary Implement PROFILE and EXPLAIN execution modes for NeuG with ASCII tree formatted output. ## Changes Made ### Core Implementation (C++) - **query_result.h/cc**: Added `profile_result_text()` and `has_profile_result()` methods for formatted output - **response.proto**: Added ProfileResult message containing operator metrics (elapsed_ms, output_rows, operator tree) - **query_processor.cc**: Three-way execution branching for NONE, PROFILE, and EXPLAIN modes ### Python Interface - **py_query_result.h/cc**: pybind11 bindings for Python access - **query_result.py**: High-level Pythonic wrapper with English docstrings - `has_profile_result()` → bool - `get_profile_text()` → formatted ASCII tree string - `get_profile_metrics()` → dict with operator tree structure ### Testing & Examples - **test_explain_profile.cpp**: 9 test cases covering single scan, joins, aggregations, EXPLAIN mode - **explain_profile_example.py**: End-to-end example demonstrating all three modes ## Example Usage ### PROFILE mode (execute + collect metrics) ``` neug > PROFILE MATCH (n:person) RETURN n.name; +-------------+ | _0_n.name | +=============+ | marko | +-------------+ | vadas | +-------------+ | josh | +-------------+ | peter | +-------------+ ╔════════════════════════════════════════╗ ║ PROFILE REPORT ║ ╚════════════════════════════════════════╝ Total output tuples: 4 Total elapsed time: 0.000 s ┌───────────────────────────────────────┐ │ ScanWithGPredOpr │ ├───────────────────────────────────────┤ │ time: 0.000s | rows: 4 tuples │ └───────────────────────────────────────┘ ┌───────────────────────────────────────┐ │ ProjectOpr │ ├───────────────────────────────────────┤ │ time: 0.000s | rows: 4 tuples │ └───────────────────────────────────────┘ ┌───────────────────────────────────────┐ │ SinkOpr │ ├───────────────────────────────────────┤ │ time: 0.000s | rows: 4 tuples │ └───────────────────────────────────────┘ ``` ### EXPLAIN mode (no execution, empty metrics) ``` neug > EXPLAIN MATCH (n:person) RETURN n.name; No results (total records: 0) ╔════════════════════════════════════════╗ ║ PROFILE REPORT ║ ╚════════════════════════════════════════╝ Total output tuples: 0 Total elapsed time: 0.000 s ┌───────────────────────────────────────┐ │ ScanWithGPredOpr │ ├───────────────────────────────────────┤ │ time: 0.000s | rows: 0 tuples │ └───────────────────────────────────────┘ ┌───────────────────────────────────────┐ │ ProjectOpr │ ├───────────────────────────────────────┤ │ time: 0.000s | rows: 0 tuples │ └───────────────────────────────────────┘ ┌───────────────────────────────────────┐ │ SinkOpr │ ├───────────────────────────────────────┤ │ time: 0.000s | rows: 0 tuples │ └───────────────────────────────────────┘ ``` --------- Co-authored-by: mazhuojohn <mazhuojohn@U-T4RYCVM3-2051.local>
1 parent fbcb9d2 commit 0d67778

24 files changed

Lines changed: 2537 additions & 23 deletions

File tree

doc/source/development/performance_debugging.md

Lines changed: 589 additions & 0 deletions
Large diffs are not rendered by default.

include/neug/execution/execute/operator.h

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -37,6 +37,10 @@ class IOperator {
3737
virtual neug::result<Context> Eval(IStorageInterface& graph,
3838
const ParamsMap& params, Context&& ctx,
3939
OprTimer* timer) = 0;
40+
41+
virtual void build_explain_children(OprTimer* parent_timer,
42+
const ParamsMap& params,
43+
IStorageInterface& graph) {}
4044
};
4145

4246
using OpBuildResultT = std::pair<std::unique_ptr<IOperator>, ContextMeta>;

include/neug/execution/execute/pipeline.h

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -34,6 +34,9 @@ class Pipeline {
3434
neug::result<Context> Execute(IStorageInterface& graph, Context&& ctx,
3535
const ParamsMap& params, OprTimer* timer);
3636

37+
neug::result<std::unique_ptr<OprTimer>> explain_tree(IStorageInterface& graph,
38+
const ParamsMap& params);
39+
3740
private:
3841
std::vector<std::unique_ptr<IOperator>> operators_;
3942
};

include/neug/execution/execute/query_cache.h

Lines changed: 10 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -30,14 +30,17 @@ struct CacheValue {
3030
ParamsMetaMap params_type;
3131
neug::MetaDatas result_schema;
3232
physical::ExecutionFlag flags;
33+
physical::ExplainMode explain_mode = physical::ExplainMode::NONE;
3334

3435
CacheValue(Pipeline pipeline, ParamsMetaMap params_type,
3536
const neug::MetaDatas& result_schema,
36-
physical::ExecutionFlag flags)
37+
physical::ExecutionFlag flags,
38+
physical::ExplainMode explain_mode = physical::ExplainMode::NONE)
3739
: pipeline(std::move(pipeline)),
3840
params_type(std::move(params_type)),
3941
result_schema(result_schema),
40-
flags(flags) {}
42+
flags(flags),
43+
explain_mode(explain_mode) {}
4144
};
4245

4346
/**
@@ -83,16 +86,17 @@ class GlobalQueryCache {
8386

8487
auto params_type =
8588
execution::PlanParser::parse_params_type(plan_result.first);
89+
auto explain_mode = plan_result.first.explain_mode();
8690
{
8791
std::unique_lock<std::shared_mutex> write_lock(mutex_);
8892
auto iter = cache_.find(query);
8993
if (iter != cache_.end()) {
9094
return iter->second;
9195
}
92-
cache_.emplace(query,
93-
std::make_shared<CacheValue>(std::move(pipeline_result),
94-
std::move(params_type), sch,
95-
plan_result.first.flag()));
96+
cache_.emplace(
97+
query, std::make_shared<CacheValue>(
98+
std::move(pipeline_result), std::move(params_type), sch,
99+
plan_result.first.flag(), explain_mode));
96100
return cache_.at(query);
97101
}
98102
}

include/neug/execution/utils/opr_timer.h

Lines changed: 17 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -15,12 +15,15 @@
1515
#pragma once
1616

1717
#include <chrono>
18+
#include <functional>
1819
#include <iostream>
1920
#include <memory>
2021
#include <string>
2122
#include <utility>
2223
#include <vector>
2324

25+
#include "neug/generated/proto/response/response.pb.h"
26+
2427
namespace neug {
2528

2629
namespace execution {
@@ -84,6 +87,9 @@ class OprTimer {
8487

8588
OprTimer& operator+=(const OprTimer& other);
8689

90+
// Convert OprTimer tree to ProfileResult protobuf message
91+
static ProfileResult ToProfileResult(OprTimer* root);
92+
8793
double elapsed() const {
8894
double time = time_;
8995
auto next = next_.get();
@@ -95,6 +101,17 @@ class OprTimer {
95101
}
96102

97103
private:
104+
size_t get_children_count() const { return children_.size(); }
105+
106+
OprTimer* get_child(size_t index) const {
107+
if (index < children_.size()) {
108+
return children_[index].get();
109+
}
110+
return nullptr;
111+
}
112+
113+
uint64_t get_num_tuples() const { return numTuples_; }
114+
98115
std::vector<std::unique_ptr<OprTimer>> children_;
99116
std::unique_ptr<OprTimer> next_;
100117
std::string name_;

include/neug/main/query_processor.h

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -81,6 +81,13 @@ class QueryProcessor {
8181
AccessMode access_mode, const execution::ParamsMap& parameters = {},
8282
int32_t num_threads = 0);
8383

84+
result<QueryResult> execute_explain_mode(
85+
const std::string& query_string,
86+
std::shared_ptr<execution::CacheValue> cache_value,
87+
const execution::ParamsMap& parameters, IStorageInterface& graph,
88+
AccessMode access_mode, const PropertyGraph& pg,
89+
google::protobuf::Arena& arena);
90+
8491
bool need_exclusive_lock(AccessMode access_mode);
8592

8693
void update_compiler_meta_if_needed(const PropertyGraph& pg,

include/neug/main/query_result.h

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -178,6 +178,19 @@ class QueryResult {
178178
*/
179179
std::string Serialize() const;
180180

181+
/**
182+
* @brief Check if profile result is available.
183+
*/
184+
bool has_profile_result() const;
185+
186+
/**
187+
* @brief Get human-readable PROFILE/EXPLAIN text output.
188+
*
189+
* Returns empty string if no profile_result available.
190+
* Suitable for CLI output and debugging.
191+
*/
192+
std::string profile_result_text() const;
193+
181194
private:
182195
void ValidateCursorAccess(size_t column_index) const;
183196
size_t GetColumnIndex(const std::string& column_name) const;

proto/response.proto

Lines changed: 16 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -135,9 +135,25 @@ message Array {
135135
}
136136
}
137137

138+
message ProfileResult {
139+
message OperatorMetrics {
140+
int64 operator_id = 1;
141+
int64 parent_id = 2;
142+
string operator_name = 3;
143+
double elapsed_ms = 4;
144+
uint64 output_rows = 5;
145+
repeated int64 child_ids = 6;
146+
}
147+
148+
double total_elapsed_ms = 1;
149+
uint64 total_output_rows = 2;
150+
repeated OperatorMetrics operators = 3;
151+
}
152+
138153
message QueryResponse {
139154
int32 row_count = 1;
140155
MetaDatas schema = 2;
141156
repeated Array arrays = 3;
157+
ProfileResult profile_result = 4;
142158
};
143159

src/execution/execute/ops/retrieve/join.cc

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -85,6 +85,21 @@ class JoinOpr : public IOperator {
8585
return out;
8686
}
8787

88+
void build_explain_children(OprTimer* parent_timer, const ParamsMap& params,
89+
IStorageInterface& graph) override {
90+
// Build explain tree for left and right pipelines
91+
// and add them as children to the parent timer
92+
auto left_tree_result = left_pipeline_.explain_tree(graph, params);
93+
auto right_tree_result = right_pipeline_.explain_tree(graph, params);
94+
95+
if (left_tree_result && left_tree_result.value()) {
96+
parent_timer->add_child(std::move(left_tree_result.value()));
97+
}
98+
if (right_tree_result && right_tree_result.value()) {
99+
parent_timer->add_child(std::move(right_tree_result.value()));
100+
}
101+
}
102+
88103
private:
89104
neug::execution::Pipeline left_pipeline_;
90105
neug::execution::Pipeline right_pipeline_;

src/execution/execute/ops/retrieve/union.cc

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -65,6 +65,18 @@ class UnionOpr : public IOperator {
6565
return out;
6666
}
6767

68+
void build_explain_children(OprTimer* parent_timer, const ParamsMap& params,
69+
IStorageInterface& graph) override {
70+
// Build explain tree for each sub plan
71+
// and add them as children to the parent timer
72+
for (auto& plan : sub_plans_) {
73+
auto tree_result = plan.explain_tree(graph, params);
74+
if (tree_result && tree_result.value()) {
75+
parent_timer->add_child(std::move(tree_result.value()));
76+
}
77+
}
78+
}
79+
6880
private:
6981
std::vector<Pipeline> sub_plans_;
7082
};

0 commit comments

Comments
 (0)