1#include "duckdb/main/query_profiler.hpp"
2
3#include "duckdb/common/fstream.hpp"
4#include "duckdb/common/http_state.hpp"
5#include "duckdb/common/limits.hpp"
6#include "duckdb/common/printer.hpp"
7#include "duckdb/common/string_util.hpp"
8#include "duckdb/common/to_string.hpp"
9#include "duckdb/common/tree_renderer.hpp"
10#include "duckdb/execution/expression_executor.hpp"
11#include "duckdb/execution/operator/helper/physical_execute.hpp"
12#include "duckdb/execution/operator/join/physical_delim_join.hpp"
13#include "duckdb/execution/physical_operator.hpp"
14#include "duckdb/main/client_config.hpp"
15#include "duckdb/main/client_context.hpp"
16#include "duckdb/main/client_data.hpp"
17#include "duckdb/planner/expression/bound_function_expression.hpp"
18
19#include <algorithm>
20#include <utility>
21
22namespace duckdb {
23
24QueryProfiler::QueryProfiler(ClientContext &context_p)
25 : context(context_p), running(false), query_requires_profiling(false), is_explain_analyze(false) {
26}
27
28bool QueryProfiler::IsEnabled() const {
29 return is_explain_analyze ? true : ClientConfig::GetConfig(context).enable_profiler;
30}
31
32bool QueryProfiler::IsDetailedEnabled() const {
33 return is_explain_analyze ? false : ClientConfig::GetConfig(context).enable_detailed_profiling;
34}
35
36ProfilerPrintFormat QueryProfiler::GetPrintFormat() const {
37 return ClientConfig::GetConfig(context).profiler_print_format;
38}
39
40bool QueryProfiler::PrintOptimizerOutput() const {
41 return GetPrintFormat() == ProfilerPrintFormat::QUERY_TREE_OPTIMIZER || IsDetailedEnabled();
42}
43
44string QueryProfiler::GetSaveLocation() const {
45 return is_explain_analyze ? string() : ClientConfig::GetConfig(context).profiler_save_location;
46}
47
48QueryProfiler &QueryProfiler::Get(ClientContext &context) {
49 return *ClientData::Get(context).profiler;
50}
51
52void QueryProfiler::StartQuery(string query, bool is_explain_analyze, bool start_at_optimizer) {
53 if (is_explain_analyze) {
54 StartExplainAnalyze();
55 }
56 if (!IsEnabled()) {
57 return;
58 }
59 if (start_at_optimizer && !PrintOptimizerOutput()) {
60 // This is the StartQuery call before the optimizer, but we don't have to print optimizer output
61 return;
62 }
63 if (running) {
64 // Called while already running: this should only happen when we print optimizer output
65 D_ASSERT(PrintOptimizerOutput());
66 return;
67 }
68 this->running = true;
69 this->query = std::move(query);
70 tree_map.clear();
71 root = nullptr;
72 phase_timings.clear();
73 phase_stack.clear();
74
75 main_query.Start();
76}
77
78bool QueryProfiler::OperatorRequiresProfiling(PhysicalOperatorType op_type) {
79 switch (op_type) {
80 case PhysicalOperatorType::ORDER_BY:
81 case PhysicalOperatorType::RESERVOIR_SAMPLE:
82 case PhysicalOperatorType::STREAMING_SAMPLE:
83 case PhysicalOperatorType::LIMIT:
84 case PhysicalOperatorType::LIMIT_PERCENT:
85 case PhysicalOperatorType::STREAMING_LIMIT:
86 case PhysicalOperatorType::TOP_N:
87 case PhysicalOperatorType::WINDOW:
88 case PhysicalOperatorType::UNNEST:
89 case PhysicalOperatorType::UNGROUPED_AGGREGATE:
90 case PhysicalOperatorType::HASH_GROUP_BY:
91 case PhysicalOperatorType::FILTER:
92 case PhysicalOperatorType::PROJECTION:
93 case PhysicalOperatorType::COPY_TO_FILE:
94 case PhysicalOperatorType::TABLE_SCAN:
95 case PhysicalOperatorType::CHUNK_SCAN:
96 case PhysicalOperatorType::DELIM_SCAN:
97 case PhysicalOperatorType::EXPRESSION_SCAN:
98 case PhysicalOperatorType::BLOCKWISE_NL_JOIN:
99 case PhysicalOperatorType::NESTED_LOOP_JOIN:
100 case PhysicalOperatorType::HASH_JOIN:
101 case PhysicalOperatorType::CROSS_PRODUCT:
102 case PhysicalOperatorType::PIECEWISE_MERGE_JOIN:
103 case PhysicalOperatorType::IE_JOIN:
104 case PhysicalOperatorType::DELIM_JOIN:
105 case PhysicalOperatorType::UNION:
106 case PhysicalOperatorType::RECURSIVE_CTE:
107 case PhysicalOperatorType::EMPTY_RESULT:
108 return true;
109 default:
110 return false;
111 }
112}
113
114void QueryProfiler::Finalize(TreeNode &node) {
115 for (auto &child : node.children) {
116 Finalize(node&: *child);
117 if (node.type == PhysicalOperatorType::UNION) {
118 node.info.elements += child->info.elements;
119 }
120 }
121}
122
123void QueryProfiler::StartExplainAnalyze() {
124 this->is_explain_analyze = true;
125}
126
127void QueryProfiler::EndQuery() {
128 lock_guard<mutex> guard(flush_lock);
129 if (!IsEnabled() || !running) {
130 return;
131 }
132
133 main_query.End();
134 if (root) {
135 Finalize(node&: *root);
136 }
137 this->running = false;
138 // print or output the query profiling after termination
139 // EXPLAIN ANALYSE should not be outputted by the profiler
140 if (IsEnabled() && !is_explain_analyze) {
141 string query_info = ToString();
142 auto save_location = GetSaveLocation();
143 if (!ClientConfig::GetConfig(context).emit_profiler_output) {
144 // disable output
145 } else if (save_location.empty()) {
146 Printer::Print(str: query_info);
147 Printer::Print(str: "\n");
148 } else {
149 WriteToFile(path: save_location.c_str(), info&: query_info);
150 }
151 }
152 this->is_explain_analyze = false;
153}
154string QueryProfiler::ToString() const {
155 const auto format = GetPrintFormat();
156 switch (format) {
157 case ProfilerPrintFormat::QUERY_TREE:
158 case ProfilerPrintFormat::QUERY_TREE_OPTIMIZER:
159 return QueryTreeToString();
160 case ProfilerPrintFormat::JSON:
161 return ToJSON();
162 default:
163 throw InternalException("Unknown ProfilerPrintFormat \"%s\"", format);
164 }
165}
166
167void QueryProfiler::StartPhase(string new_phase) {
168 if (!IsEnabled() || !running) {
169 return;
170 }
171
172 if (!phase_stack.empty()) {
173 // there are active phases
174 phase_profiler.End();
175 // add the timing to all phases prior to this one
176 string prefix = "";
177 for (auto &phase : phase_stack) {
178 phase_timings[phase] += phase_profiler.Elapsed();
179 prefix += phase + " > ";
180 }
181 // when there are previous phases, we prefix the current phase with those phases
182 new_phase = prefix + new_phase;
183 }
184
185 // start a new phase
186 phase_stack.push_back(x: new_phase);
187 // restart the timer
188 phase_profiler.Start();
189}
190
191void QueryProfiler::EndPhase() {
192 if (!IsEnabled() || !running) {
193 return;
194 }
195 D_ASSERT(phase_stack.size() > 0);
196
197 // end the timer
198 phase_profiler.End();
199 // add the timing to all currently active phases
200 for (auto &phase : phase_stack) {
201 phase_timings[phase] += phase_profiler.Elapsed();
202 }
203 // now remove the last added phase
204 phase_stack.pop_back();
205
206 if (!phase_stack.empty()) {
207 phase_profiler.Start();
208 }
209}
210
211void QueryProfiler::Initialize(const PhysicalOperator &root_op) {
212 if (!IsEnabled() || !running) {
213 return;
214 }
215 this->query_requires_profiling = false;
216 this->root = CreateTree(root: root_op);
217 if (!query_requires_profiling) {
218 // query does not require profiling: disable profiling for this query
219 this->running = false;
220 tree_map.clear();
221 root = nullptr;
222 phase_timings.clear();
223 phase_stack.clear();
224 }
225}
226
227OperatorProfiler::OperatorProfiler(bool enabled_p) : enabled(enabled_p), active_operator(nullptr) {
228}
229
230void OperatorProfiler::StartOperator(optional_ptr<const PhysicalOperator> phys_op) {
231 if (!enabled) {
232 return;
233 }
234
235 if (active_operator) {
236 throw InternalException("OperatorProfiler: Attempting to call StartOperator while another operator is active");
237 }
238
239 active_operator = phys_op;
240
241 // start timing for current element
242 op.Start();
243}
244
245void OperatorProfiler::EndOperator(optional_ptr<DataChunk> chunk) {
246 if (!enabled) {
247 return;
248 }
249
250 if (!active_operator) {
251 throw InternalException("OperatorProfiler: Attempting to call EndOperator while another operator is active");
252 }
253
254 // finish timing for the current element
255 op.End();
256
257 AddTiming(op: *active_operator, time: op.Elapsed(), elements: chunk ? chunk->size() : 0);
258 active_operator = nullptr;
259}
260
261void OperatorProfiler::AddTiming(const PhysicalOperator &op, double time, idx_t elements) {
262 if (!enabled) {
263 return;
264 }
265 if (!Value::DoubleIsFinite(value: time)) {
266 return;
267 }
268 auto entry = timings.find(x: op);
269 if (entry == timings.end()) {
270 // add new entry
271 timings[op] = OperatorInformation(time, elements);
272 } else {
273 // add to existing entry
274 entry->second.time += time;
275 entry->second.elements += elements;
276 }
277}
278void OperatorProfiler::Flush(const PhysicalOperator &phys_op, ExpressionExecutor &expression_executor,
279 const string &name, int id) {
280 auto entry = timings.find(x: phys_op);
281 if (entry == timings.end()) {
282 return;
283 }
284 auto &operator_timing = timings.find(x: phys_op)->second;
285 if (int(operator_timing.executors_info.size()) <= id) {
286 operator_timing.executors_info.resize(new_size: id + 1);
287 }
288 operator_timing.executors_info[id] = make_uniq<ExpressionExecutorInfo>(args&: expression_executor, args: name, args&: id);
289 operator_timing.name = phys_op.GetName();
290}
291
292void QueryProfiler::Flush(OperatorProfiler &profiler) {
293 lock_guard<mutex> guard(flush_lock);
294 if (!IsEnabled() || !running) {
295 return;
296 }
297 for (auto &node : profiler.timings) {
298 auto &op = node.first.get();
299 auto entry = tree_map.find(x: op);
300 D_ASSERT(entry != tree_map.end());
301 auto &tree_node = entry->second.get();
302
303 tree_node.info.time += node.second.time;
304 tree_node.info.elements += node.second.elements;
305 if (!IsDetailedEnabled()) {
306 continue;
307 }
308 for (auto &info : node.second.executors_info) {
309 if (!info) {
310 continue;
311 }
312 auto info_id = info->id;
313 if (int32_t(tree_node.info.executors_info.size()) <= info_id) {
314 tree_node.info.executors_info.resize(new_size: info_id + 1);
315 }
316 tree_node.info.executors_info[info_id] = std::move(info);
317 }
318 }
319 profiler.timings.clear();
320}
321
322static string DrawPadded(const string &str, idx_t width) {
323 if (str.size() > width) {
324 return str.substr(pos: 0, n: width);
325 } else {
326 width -= str.size();
327 int half_spaces = width / 2;
328 int extra_left_space = width % 2 != 0 ? 1 : 0;
329 return string(half_spaces + extra_left_space, ' ') + str + string(half_spaces, ' ');
330 }
331}
332
333static string RenderTitleCase(string str) {
334 str = StringUtil::Lower(str);
335 str[0] = toupper(c: str[0]);
336 for (idx_t i = 0; i < str.size(); i++) {
337 if (str[i] == '_') {
338 str[i] = ' ';
339 if (i + 1 < str.size()) {
340 str[i + 1] = toupper(c: str[i + 1]);
341 }
342 }
343 }
344 return str;
345}
346
347static string RenderTiming(double timing) {
348 string timing_s;
349 if (timing >= 1) {
350 timing_s = StringUtil::Format(fmt_str: "%.2f", params: timing);
351 } else if (timing >= 0.1) {
352 timing_s = StringUtil::Format(fmt_str: "%.3f", params: timing);
353 } else {
354 timing_s = StringUtil::Format(fmt_str: "%.4f", params: timing);
355 }
356 return timing_s + "s";
357}
358
359string QueryProfiler::QueryTreeToString() const {
360 std::stringstream str;
361 QueryTreeToStream(str);
362 return str.str();
363}
364
365void QueryProfiler::QueryTreeToStream(std::ostream &ss) const {
366 if (!IsEnabled()) {
367 ss << "Query profiling is disabled. Call "
368 "Connection::EnableProfiling() to enable profiling!";
369 return;
370 }
371 ss << "┌─────────────────────────────────────┐\n";
372 ss << "│┌───────────────────────────────────┐│\n";
373 ss << "││ Query Profiling Information ││\n";
374 ss << "│└───────────────────────────────────┘│\n";
375 ss << "└─────────────────────────────────────┘\n";
376 ss << StringUtil::Replace(source: query, from: "\n", to: " ") + "\n";
377
378 // checking the tree to ensure the query is really empty
379 // the query string is empty when a logical plan is deserialized
380 if (query.empty() && !root) {
381 return;
382 }
383
384 if (context.client_data->http_state && !context.client_data->http_state->IsEmpty()) {
385 string read =
386 "in: " + StringUtil::BytesToHumanReadableString(bytes: context.client_data->http_state->total_bytes_received);
387 string written =
388 "out: " + StringUtil::BytesToHumanReadableString(bytes: context.client_data->http_state->total_bytes_sent);
389 string head = "#HEAD: " + to_string(val: context.client_data->http_state->head_count);
390 string get = "#GET: " + to_string(val: context.client_data->http_state->get_count);
391 string put = "#PUT: " + to_string(val: context.client_data->http_state->put_count);
392 string post = "#POST: " + to_string(val: context.client_data->http_state->post_count);
393
394 constexpr idx_t TOTAL_BOX_WIDTH = 39;
395 ss << "┌─────────────────────────────────────┐\n";
396 ss << "│┌───────────────────────────────────┐│\n";
397 ss << "││ HTTP Stats: ││\n";
398 ss << "││ ││\n";
399 ss << "││" + DrawPadded(str: read, width: TOTAL_BOX_WIDTH - 4) + "││\n";
400 ss << "││" + DrawPadded(str: written, width: TOTAL_BOX_WIDTH - 4) + "││\n";
401 ss << "││" + DrawPadded(str: head, width: TOTAL_BOX_WIDTH - 4) + "││\n";
402 ss << "││" + DrawPadded(str: get, width: TOTAL_BOX_WIDTH - 4) + "││\n";
403 ss << "││" + DrawPadded(str: put, width: TOTAL_BOX_WIDTH - 4) + "││\n";
404 ss << "││" + DrawPadded(str: post, width: TOTAL_BOX_WIDTH - 4) + "││\n";
405 ss << "│└───────────────────────────────────┘│\n";
406 ss << "└─────────────────────────────────────┘\n";
407 }
408
409 constexpr idx_t TOTAL_BOX_WIDTH = 39;
410 ss << "┌─────────────────────────────────────┐\n";
411 ss << "│┌───────────────────────────────────┐│\n";
412 string total_time = "Total Time: " + RenderTiming(timing: main_query.Elapsed());
413 ss << "││" + DrawPadded(str: total_time, width: TOTAL_BOX_WIDTH - 4) + "││\n";
414 ss << "│└───────────────────────────────────┘│\n";
415 ss << "└─────────────────────────────────────┘\n";
416 // print phase timings
417 if (PrintOptimizerOutput()) {
418 bool has_previous_phase = false;
419 for (const auto &entry : GetOrderedPhaseTimings()) {
420 if (!StringUtil::Contains(haystack: entry.first, needle: " > ")) {
421 // primary phase!
422 if (has_previous_phase) {
423 ss << "│└───────────────────────────────────┘│\n";
424 ss << "└─────────────────────────────────────┘\n";
425 }
426 ss << "┌─────────────────────────────────────┐\n";
427 ss << "│" +
428 DrawPadded(str: RenderTitleCase(str: entry.first) + ": " + RenderTiming(timing: entry.second),
429 width: TOTAL_BOX_WIDTH - 2) +
430 "│\n";
431 ss << "│┌───────────────────────────────────┐│\n";
432 has_previous_phase = true;
433 } else {
434 string entry_name = StringUtil::Split(input: entry.first, split: " > ")[1];
435 ss << "││" +
436 DrawPadded(str: RenderTitleCase(str: entry_name) + ": " + RenderTiming(timing: entry.second),
437 width: TOTAL_BOX_WIDTH - 4) +
438 "││\n";
439 }
440 }
441 if (has_previous_phase) {
442 ss << "│└───────────────────────────────────┘│\n";
443 ss << "└─────────────────────────────────────┘\n";
444 }
445 }
446 // render the main operator tree
447 if (root) {
448 Render(node: *root, str&: ss);
449 }
450}
451
452static string JSONSanitize(const string &text) {
453 string result;
454 result.reserve(res_arg: text.size());
455 for (idx_t i = 0; i < text.size(); i++) {
456 switch (text[i]) {
457 case '\b':
458 result += "\\b";
459 break;
460 case '\f':
461 result += "\\f";
462 break;
463 case '\n':
464 result += "\\n";
465 break;
466 case '\r':
467 result += "\\r";
468 break;
469 case '\t':
470 result += "\\t";
471 break;
472 case '"':
473 result += "\\\"";
474 break;
475 case '\\':
476 result += "\\\\";
477 break;
478 default:
479 result += text[i];
480 break;
481 }
482 }
483 return result;
484}
485
486// Print a row
487static void PrintRow(std::ostream &ss, const string &annotation, int id, const string &name, double time,
488 int sample_counter, int tuple_counter, const string &extra_info, int depth) {
489 ss << string(depth * 3, ' ') << " {\n";
490 ss << string(depth * 3, ' ') << " \"annotation\": \"" + JSONSanitize(text: annotation) + "\",\n";
491 ss << string(depth * 3, ' ') << " \"id\": " + to_string(val: id) + ",\n";
492 ss << string(depth * 3, ' ') << " \"name\": \"" + JSONSanitize(text: name) + "\",\n";
493#if defined(RDTSC)
494 ss << string(depth * 3, ' ') << " \"timing\": \"NULL\" ,\n";
495 ss << string(depth * 3, ' ') << " \"cycles_per_tuple\": " + StringUtil::Format("%.4f", time) + ",\n";
496#else
497 ss << string(depth * 3, ' ') << " \"timing\":" + to_string(val: time) + ",\n";
498 ss << string(depth * 3, ' ') << " \"cycles_per_tuple\": \"NULL\" ,\n";
499#endif
500 ss << string(depth * 3, ' ') << " \"sample_size\": " << to_string(val: sample_counter) + ",\n";
501 ss << string(depth * 3, ' ') << " \"input_size\": " << to_string(val: tuple_counter) + ",\n";
502 ss << string(depth * 3, ' ') << " \"extra_info\": \"" << JSONSanitize(text: extra_info) + "\"\n";
503 ss << string(depth * 3, ' ') << " },\n";
504}
505
506static void ExtractFunctions(std::ostream &ss, ExpressionInfo &info, int &fun_id, int depth) {
507 if (info.hasfunction) {
508 double time = info.sample_tuples_count == 0 ? 0 : int(info.function_time) / double(info.sample_tuples_count);
509 PrintRow(ss, annotation: "Function", id: fun_id++, name: info.function_name, time, sample_counter: info.sample_tuples_count, tuple_counter: info.tuples_count, extra_info: "",
510 depth);
511 }
512 if (info.children.empty()) {
513 return;
514 }
515 // extract the children of this node
516 for (auto &child : info.children) {
517 ExtractFunctions(ss, info&: *child, fun_id, depth);
518 }
519}
520
521static void ToJSONRecursive(QueryProfiler::TreeNode &node, std::ostream &ss, int depth = 1) {
522 ss << string(depth * 3, ' ') << " {\n";
523 ss << string(depth * 3, ' ') << " \"name\": \"" + JSONSanitize(text: node.name) + "\",\n";
524 ss << string(depth * 3, ' ') << " \"timing\":" + to_string(val: node.info.time) + ",\n";
525 ss << string(depth * 3, ' ') << " \"cardinality\":" + to_string(val: node.info.elements) + ",\n";
526 ss << string(depth * 3, ' ') << " \"extra_info\": \"" + JSONSanitize(text: node.extra_info) + "\",\n";
527 ss << string(depth * 3, ' ') << " \"timings\": [";
528 int32_t function_counter = 1;
529 int32_t expression_counter = 1;
530 ss << "\n ";
531 for (auto &expr_executor : node.info.executors_info) {
532 // For each Expression tree
533 if (!expr_executor) {
534 continue;
535 }
536 for (auto &expr_timer : expr_executor->roots) {
537 double time = expr_timer->sample_tuples_count == 0
538 ? 0
539 : double(expr_timer->time) / double(expr_timer->sample_tuples_count);
540 PrintRow(ss, annotation: "ExpressionRoot", id: expression_counter++, name: expr_timer->name, time,
541 sample_counter: expr_timer->sample_tuples_count, tuple_counter: expr_timer->tuples_count, extra_info: expr_timer->extra_info, depth: depth + 1);
542 // Extract all functions inside the tree
543 ExtractFunctions(ss, info&: *expr_timer->root, fun_id&: function_counter, depth: depth + 1);
544 }
545 }
546 ss.seekp(-2, ss.cur);
547 ss << "\n";
548 ss << string(depth * 3, ' ') << " ],\n";
549 ss << string(depth * 3, ' ') << " \"children\": [\n";
550 if (node.children.empty()) {
551 ss << string(depth * 3, ' ') << " ]\n";
552 } else {
553 for (idx_t i = 0; i < node.children.size(); i++) {
554 if (i > 0) {
555 ss << ",\n";
556 }
557 ToJSONRecursive(node&: *node.children[i], ss, depth: depth + 1);
558 }
559 ss << string(depth * 3, ' ') << " ]\n";
560 }
561 ss << string(depth * 3, ' ') << " }\n";
562}
563
564string QueryProfiler::ToJSON() const {
565 if (!IsEnabled()) {
566 return "{ \"result\": \"disabled\" }\n";
567 }
568 if (query.empty() && !root) {
569 return "{ \"result\": \"empty\" }\n";
570 }
571 if (!root) {
572 return "{ \"result\": \"error\" }\n";
573 }
574 std::stringstream ss;
575 ss << "{\n";
576 ss << " \"name\": \"Query\", \n";
577 ss << " \"result\": " + to_string(val: main_query.Elapsed()) + ",\n";
578 ss << " \"timing\": " + to_string(val: main_query.Elapsed()) + ",\n";
579 ss << " \"cardinality\": " + to_string(val: root->info.elements) + ",\n";
580 // JSON cannot have literal control characters in string literals
581 string extra_info = JSONSanitize(text: query);
582 ss << " \"extra-info\": \"" + extra_info + "\", \n";
583 // print the phase timings
584 ss << " \"timings\": [\n";
585 const auto &ordered_phase_timings = GetOrderedPhaseTimings();
586 for (idx_t i = 0; i < ordered_phase_timings.size(); i++) {
587 if (i > 0) {
588 ss << ",\n";
589 }
590 ss << " {\n";
591 ss << " \"annotation\": \"" + ordered_phase_timings[i].first + "\", \n";
592 ss << " \"timing\": " + to_string(val: ordered_phase_timings[i].second) + "\n";
593 ss << " }";
594 }
595 ss << "\n";
596 ss << " ],\n";
597 // recursively print the physical operator tree
598 ss << " \"children\": [\n";
599 ToJSONRecursive(node&: *root, ss);
600 ss << " ]\n";
601 ss << "}";
602 return ss.str();
603}
604
605void QueryProfiler::WriteToFile(const char *path, string &info) const {
606 ofstream out(path);
607 out << info;
608 out.close();
609 // throw an IO exception if it fails to write the file
610 if (out.fail()) {
611 throw IOException(strerror(errno));
612 }
613}
614
615unique_ptr<QueryProfiler::TreeNode> QueryProfiler::CreateTree(const PhysicalOperator &root, idx_t depth) {
616 if (OperatorRequiresProfiling(op_type: root.type)) {
617 this->query_requires_profiling = true;
618 }
619 auto node = make_uniq<QueryProfiler::TreeNode>();
620 node->type = root.type;
621 node->name = root.GetName();
622 node->extra_info = root.ParamsToString();
623 node->depth = depth;
624 tree_map.insert(x: make_pair(x: reference<const PhysicalOperator>(root), y: reference<QueryProfiler::TreeNode>(*node)));
625 auto children = root.GetChildren();
626 for (auto &child : children) {
627 auto child_node = CreateTree(root: child.get(), depth: depth + 1);
628 node->children.push_back(x: std::move(child_node));
629 }
630 return node;
631}
632
633void QueryProfiler::Render(const QueryProfiler::TreeNode &node, std::ostream &ss) const {
634 TreeRenderer renderer;
635 if (IsDetailedEnabled()) {
636 renderer.EnableDetailed();
637 } else {
638 renderer.EnableStandard();
639 }
640 renderer.Render(op: node, ss);
641}
642
643void QueryProfiler::Print() {
644 Printer::Print(str: QueryTreeToString());
645}
646
647vector<QueryProfiler::PhaseTimingItem> QueryProfiler::GetOrderedPhaseTimings() const {
648 vector<PhaseTimingItem> result;
649 // first sort the phases alphabetically
650 vector<string> phases;
651 for (auto &entry : phase_timings) {
652 phases.push_back(x: entry.first);
653 }
654 std::sort(first: phases.begin(), last: phases.end());
655 for (const auto &phase : phases) {
656 auto entry = phase_timings.find(x: phase);
657 D_ASSERT(entry != phase_timings.end());
658 result.emplace_back(args: entry->first, args: entry->second);
659 }
660 return result;
661}
662void QueryProfiler::Propagate(QueryProfiler &qp) {
663}
664
665void ExpressionInfo::ExtractExpressionsRecursive(unique_ptr<ExpressionState> &state) {
666 if (state->child_states.empty()) {
667 return;
668 }
669 // extract the children of this node
670 for (auto &child : state->child_states) {
671 auto expr_info = make_uniq<ExpressionInfo>();
672 if (child->expr.expression_class == ExpressionClass::BOUND_FUNCTION) {
673 expr_info->hasfunction = true;
674 expr_info->function_name = child->expr.Cast<BoundFunctionExpression>().function.ToString();
675 expr_info->function_time = child->profiler.time;
676 expr_info->sample_tuples_count = child->profiler.sample_tuples_count;
677 expr_info->tuples_count = child->profiler.tuples_count;
678 }
679 expr_info->ExtractExpressionsRecursive(state&: child);
680 children.push_back(x: std::move(expr_info));
681 }
682 return;
683}
684
685ExpressionExecutorInfo::ExpressionExecutorInfo(ExpressionExecutor &executor, const string &name, int id) : id(id) {
686 // Extract Expression Root Information from ExpressionExecutorStats
687 for (auto &state : executor.GetStates()) {
688 roots.push_back(x: make_uniq<ExpressionRootInfo>(args&: *state, args: name));
689 }
690}
691
692ExpressionRootInfo::ExpressionRootInfo(ExpressionExecutorState &state, string name)
693 : current_count(state.profiler.current_count), sample_count(state.profiler.sample_count),
694 sample_tuples_count(state.profiler.sample_tuples_count), tuples_count(state.profiler.tuples_count),
695 name("expression"), time(state.profiler.time) {
696 // Use the name of expression-tree as extra-info
697 extra_info = std::move(name);
698 auto expression_info_p = make_uniq<ExpressionInfo>();
699 // Maybe root has a function
700 if (state.root_state->expr.expression_class == ExpressionClass::BOUND_FUNCTION) {
701 expression_info_p->hasfunction = true;
702 expression_info_p->function_name = (state.root_state->expr.Cast<BoundFunctionExpression>()).function.name;
703 expression_info_p->function_time = state.root_state->profiler.time;
704 expression_info_p->sample_tuples_count = state.root_state->profiler.sample_tuples_count;
705 expression_info_p->tuples_count = state.root_state->profiler.tuples_count;
706 }
707 expression_info_p->ExtractExpressionsRecursive(state&: state.root_state);
708 root = std::move(expression_info_p);
709}
710} // namespace duckdb
711