Add pipeline trace logging (enable_pipeline_trace setting)

Adds two debugging capabilities to the pipeline execution system:

1. Static pipeline graph: after query initialization, prints all pipelines
   and their dependency relationships to stderr.

2. Runtime timing trace: records wall-clock start/end times for each
   pipeline and outputs a Chrome Trace JSON report to stderr on query
   completion. The JSON is loadable in https://ui.perfetto.dev/ or
   chrome://tracing for an interactive Gantt visualization.

Usage:
  SET enable_pipeline_trace = true;
  SELECT ...;   -- pipeline graph + Chrome trace JSON go to stderr

New files:
  src/include/duckdb/parallel/pipeline_tracer.hpp
  src/parallel/pipeline_tracer.cpp

Key changes:
  - Pipeline: add pipeline_id, start_time_ns, end_time_ns, MarkStart/MarkEnd
  - PipelineEvent: call MarkStart in Schedule(), MarkEnd in FinishEvent()
  - PipelineFinishEvent: call MarkEnd in FinishEvent() (last-call wins,
    so finalization time is captured for base pipelines)
  - Executor: assign IDs, save traced_pipelines ref, print graph at init
    and Chrome trace JSON before pipelines.clear()
  - Settings: add enable_pipeline_trace (local bool, default false)

https://claude.ai/code/session_01UV8WQWq1RyBsyTAxsbu4yG

Author: claude

src/common/settings.json

@@ -514,6 +514,14 @@
         "default_scope": "global",
         "default_value": "false"
     },
+    {
+        "name": "enable_pipeline_trace",
+        "description": "Enables pipeline trace logging: prints the pipeline graph and outputs a Chrome Trace JSON timing report to stderr on query completion",
+        "type": "BOOLEAN",
+        "scope": "local",
+        "struct": "EnablePipelineTraceSetting",
+        "custom_implementation": true
+    },
     {
         "name": "enable_profiling",
         "description": "Enables profiling, and sets the output format (JSON, QUERY_TREE, QUERY_TREE_OPTIMIZER)",
@@ -1119,4 +1127,4 @@
         "scope": "global",
         "default_value": "4096"
     }
-]
+]

src/include/duckdb/execution/executor.hpp

@@ -155,6 +155,10 @@ class Executor {
 	vector<shared_ptr<Pipeline>> pipelines;
 	//! The root pipelines of the query
 	vector<shared_ptr<Pipeline>> root_pipelines;
+	//! Pipelines saved for trace output (persists after pipelines.clear())
+	vector<shared_ptr<Pipeline>> traced_pipelines;
+	//! Steady-clock nanoseconds at query initialization (base for Chrome trace timestamps)
+	int64_t pipeline_trace_start_ns = 0;
 	//! The recursive CTE's in this query plan
 	vector<reference<PhysicalOperator>> recursive_ctes;
 	//! The pipeline executor for the root pipeline

src/include/duckdb/main/client_config.hpp

@@ -101,6 +101,10 @@ struct ClientConfig {
 	//! If HTTP logging is enabled or not.
 	bool enable_http_logging = true;
 
+	//! If pipeline trace logging is enabled (SET enable_pipeline_trace = true).
+	//! Prints the pipeline dependency graph and Chrome Trace JSON timing to stderr.
+	bool enable_pipeline_trace = false;
+
 	//! **DEPRECATED** The file to save query HTTP logging information to, instead of printing it to the console
 	//! (empty = output to the DuckDB logger)
 	string http_logging_output;

src/include/duckdb/main/settings.hpp

@@ -780,6 +780,18 @@ struct EnableObjectCacheSetting {
 	static constexpr idx_t SettingIndex = 42;
 };
 
+struct EnablePipelineTraceSetting {
+	using RETURN_TYPE = bool;
+	static constexpr const char *Name = "enable_pipeline_trace";
+	static constexpr const char *Description =
+	    "Enables pipeline trace logging: prints the pipeline graph and outputs a Chrome Trace JSON "
+	    "timing report to stderr on query completion";
+	static constexpr const char *InputType = "BOOLEAN";
+	static void SetLocal(ClientContext &context, const Value &parameter);
+	static void ResetLocal(ClientContext &context);
+	static Value GetSetting(const ClientContext &context);
+};
+
 struct EnableProfilingSetting {
 	using RETURN_TYPE = string;
 	static constexpr const char *Name = "enable_profiling";

src/include/duckdb/parallel/pipeline.hpp

@@ -76,6 +76,7 @@ class Pipeline : public enable_shared_from_this<Pipeline> {
 	friend class PipelineFinishEvent;
 	friend class PipelineBuildState;
 	friend class MetaPipeline;
+	friend class PipelineTracer;
 
 public:
 	explicit Pipeline(Executor &execution_context);
@@ -100,6 +101,21 @@ class Pipeline : public enable_shared_from_this<Pipeline> {
 	void Print() const;
 	void PrintDependencies() const;
 
+	//! Record the wall-clock start time of this pipeline's execution.
+	void MarkStart();
+	//! Record the wall-clock end time (last-call wins, so PipelineFinishEvent overwrites PipelineEvent).
+	void MarkEnd();
+
+	idx_t GetPipelineId() const {
+		return pipeline_id;
+	}
+	int64_t GetStartTimeNs() const {
+		return start_time_ns;
+	}
+	int64_t GetEndTimeNs() const {
+		return end_time_ns;
+	}
+
 	//! Returns query progress
 	bool GetProgress(ProgressData &progress_data);
 
@@ -132,6 +148,12 @@ class Pipeline : public enable_shared_from_this<Pipeline> {
 	atomic<bool> initialized;
 	//! The source of this pipeline
 	optional_ptr<PhysicalOperator> source;
+
+	//! Pipeline ID assigned by PipelineTracer::AssignIds (0-based)
+	idx_t pipeline_id = 0;
+	//! Wall-clock start/end times in steady_clock nanoseconds since epoch (-1 = unset)
+	int64_t start_time_ns = -1;
+	int64_t end_time_ns = -1;
 	//! The chain of intermediate operators
 	vector<reference<PhysicalOperator>> operators;
 	//! The sink (i.e. destination) for data; this is e.g. a hash table to-be-built

src/include/duckdb/parallel/pipeline_tracer.hpp

@@ -0,0 +1,41 @@
+//===----------------------------------------------------------------------===//
+//                         DuckDB
+//
+// duckdb/parallel/pipeline_tracer.hpp
+//
+//
+//===----------------------------------------------------------------------===//
+
+#pragma once
+
+#include "duckdb/common/common.hpp"
+
+namespace duckdb {
+
+class Pipeline;
+
+//! PipelineTracer collects and outputs pipeline structure and execution timing.
+//! Enabled by SET enable_pipeline_trace = true.
+//! Outputs:
+//!   1. A pipeline dependency graph to stderr after initialization.
+//!   2. A Chrome Trace JSON timing report to stderr after query completion
+//!      (loadable in https://ui.perfetto.dev/ or chrome://tracing).
+class PipelineTracer {
+public:
+	//! Assign sequential IDs (0, 1, 2, ...) to all pipelines.
+	//! Must be called before PrintGraph or PrintChromeTrace.
+	static void AssignIds(vector<shared_ptr<Pipeline>> &pipelines);
+
+	//! Print the static pipeline structure and dependency graph to stderr.
+	static void PrintGraph(const vector<shared_ptr<Pipeline>> &pipelines);
+
+	//! Print Chrome Trace JSON to stderr.
+	//! query_start_ns: steady_clock nanoseconds since epoch at query start.
+	static void PrintChromeTrace(const vector<shared_ptr<Pipeline>> &pipelines, int64_t query_start_ns);
+
+private:
+	//! Build a short human-readable description: "TableScan→HashJoinBuild→..."
+	static string Describe(const Pipeline &pipeline);
+};
+
+} // namespace duckdb

src/main/settings/custom_settings.cpp

@@ -1205,6 +1205,22 @@ Value EnableHTTPLoggingSetting::GetSetting(const ClientContext &context) {
 	return Value::BOOLEAN(config.enable_http_logging);
 }
 
+//===----------------------------------------------------------------------===//
+// Enable Pipeline Trace
+//===----------------------------------------------------------------------===//
+
+void EnablePipelineTraceSetting::SetLocal(ClientContext &context, const Value &input) {
+	ClientConfig::GetConfig(context).enable_pipeline_trace = input.GetValue<bool>();
+}
+
+void EnablePipelineTraceSetting::ResetLocal(ClientContext &context) {
+	ClientConfig::GetConfig(context).enable_pipeline_trace = ClientConfig().enable_pipeline_trace;
+}
+
+Value EnablePipelineTraceSetting::GetSetting(const ClientContext &context) {
+	return Value::BOOLEAN(ClientConfig::GetConfig(context).enable_pipeline_trace);
+}
+
 //===----------------------------------------------------------------------===//
 // Enable Mbedtls
 //===----------------------------------------------------------------------===//

src/parallel/CMakeLists.txt

@@ -10,6 +10,7 @@ add_library_unity(
   interrupt.cpp
   pipeline.cpp
   pipeline_complete_event.cpp
+  pipeline_tracer.cpp
   pipeline_event.cpp
   pipeline_executor.cpp
   pipeline_finish_event.cpp

src/parallel/executor.cpp

@@ -1,5 +1,6 @@
 #include "duckdb/execution/executor.hpp"
 
+#include "duckdb/common/chrono.hpp"
 #include "duckdb/execution/execution_context.hpp"
 #include "duckdb/execution/operator/helper/physical_result_collector.hpp"
 #include "duckdb/execution/operator/scan/physical_table_scan.hpp"
@@ -16,8 +17,10 @@
 #include "duckdb/parallel/pipeline_finish_event.hpp"
 #include "duckdb/parallel/pipeline_initialize_event.hpp"
 #include "duckdb/parallel/pipeline_prepare_finish_event.hpp"
+#include "duckdb/parallel/pipeline_tracer.hpp"
 #include "duckdb/parallel/task_scheduler.hpp"
 #include "duckdb/parallel/thread_context.hpp"
+#include "duckdb/main/client_config.hpp"
 
 #include <algorithm>
 #include <chrono>
@@ -424,6 +427,16 @@ void Executor::InitializeInternal(PhysicalOperator &plan) {
 		// finally, verify and schedule
 		VerifyPipelines();
 		ScheduleEvents(to_schedule);
+
+		// pipeline trace: assign IDs, record query start time, and print the static graph
+		auto &trace_config = ClientConfig::GetConfig(context);
+		if (trace_config.enable_pipeline_trace) {
+			PipelineTracer::AssignIds(pipelines);
+			pipeline_trace_start_ns = static_cast<int64_t>(
+			    duration_cast<nanoseconds>(steady_clock::now().time_since_epoch()).count());
+			PipelineTracer::PrintGraph(pipelines);
+			traced_pipelines = pipelines;
+		}
 	}
 }
 
@@ -622,6 +635,11 @@ PendingExecutionResult Executor::ExecuteTask(bool dry_run) {
 	D_ASSERT(!task);
 
 	lock_guard<mutex> elock(executor_lock);
+	// emit Chrome Trace JSON before clearing pipelines (timing data lives in Pipeline objects)
+	if (!traced_pipelines.empty()) {
+		PipelineTracer::PrintChromeTrace(traced_pipelines, pipeline_trace_start_ns);
+		traced_pipelines.clear();
+	}
 	pipelines.clear();
 	NextExecutor();
 	if (HasError()) { // LCOV_EXCL_START
@@ -647,6 +665,8 @@ void Executor::Reset() {
 	events.clear();
 	to_be_rescheduled_tasks.clear();
 	execution_result = PendingExecutionResult::RESULT_NOT_READY;
+	traced_pipelines.clear();
+	pipeline_trace_start_ns = 0;
 }
 
 shared_ptr<Pipeline> Executor::CreateChildPipeline(Pipeline &current, PhysicalOperator &op) {

src/parallel/pipeline.cpp

@@ -1,6 +1,7 @@
 #include "duckdb/parallel/pipeline.hpp"
 
 #include "duckdb/common/algorithm.hpp"
+#include "duckdb/common/chrono.hpp"
 #include "duckdb/common/printer.hpp"
 #include "duckdb/common/tree_renderer/text_tree_renderer.hpp"
 #include "duckdb/execution/executor.hpp"
@@ -73,6 +74,16 @@ ClientContext &Pipeline::GetClientContext() {
 	return executor.context;
 }
 
+void Pipeline::MarkStart() {
+	start_time_ns = static_cast<int64_t>(
+	    duration_cast<nanoseconds>(steady_clock::now().time_since_epoch()).count());
+}
+
+void Pipeline::MarkEnd() {
+	end_time_ns = static_cast<int64_t>(
+	    duration_cast<nanoseconds>(steady_clock::now().time_since_epoch()).count());
+}
+
 bool Pipeline::GetProgress(ProgressData &progress) {
 	D_ASSERT(source);
 	idx_t source_cardinality = MinValue<idx_t>(source->estimated_cardinality, 1ULL << 48ULL);