From 366e26b35d03032a3981ac6825613e3ea4702546 Mon Sep 17 00:00:00 2001 From: Yahor Yuzefovich Date: Tue, 18 Mar 2025 13:23:36 -0700 Subject: [PATCH] sql: fix recent regression in EXPLAIN ANALYZE This commit fixes a regression in EXPLAIN ANALYZE output recently added in 44da781bbe493dedcdb2674d6433a6d862c8b3ae. Before that change we always performed the association of the current planNode with the last stage of the physical plan, and after that change we started doing the association only when a new stage is added. However, this resulted in missing associations when a particular planNode didn't result in a new stage of the physical plan (for example, renderNode is handled as a projection by adjusting PostProcessSpec of already existing stage). As a result, we could lose the ability to associate execution statistics to some nodes in EXPLAIN ANALYZE output. This is now fixed by bringing back the unconditional call to associate the current planNode with the last stage of the physical plan, even if a new stage isn't added. This required teaching `associateNodeWithComponents` to "swallow" duplicate associations and make them no-ops (otherwise, we would double-count statistics in some cases). Release note: None --- pkg/sql/distsql_physical_planner.go | 18 +++- pkg/sql/instrumentation.go | 25 ++++- .../exec/execbuilder/testdata/explain_analyze | 99 +++++++++++++++++++ 3 files changed, 139 insertions(+), 3 deletions(-) diff --git a/pkg/sql/distsql_physical_planner.go b/pkg/sql/distsql_physical_planner.go index 6f31bc3eb2dd..9faf65df28cd 100644 --- a/pkg/sql/distsql_physical_planner.go +++ b/pkg/sql/distsql_physical_planner.go @@ -1066,8 +1066,9 @@ func (p *PlanningCtx) setUpForMainQuery( } // associateWithPlanNode returns a callback function (possibly nil) that should -// be invoked when a new stage of processors is added that corresponds to the -// given planNode. +// be invoked to associate the last stage of processors with the given planNode. +// The returned function can be safely invoked multiple times for the given +// planNode and the same last stage of processors. func (p *PlanningCtx) associateWithPlanNode(node planNode) func(*physicalplan.PhysicalPlan) { if p.associateNodeWithComponents == nil { return nil @@ -4227,6 +4228,19 @@ func (dsp *DistSQLPlanner) createPhysPlanForPlanNode( return nil, err } + if associateWithPlanNode := planCtx.associateWithPlanNode(node); associateWithPlanNode != nil { + // Even though we might not have created a new stage in the physical + // plan for the current planNode, we still need to associate it with the + // last stage. This is needed to handle cases where a single physical + // plan stage handles multiple planNodes (e.g. renderNode that is done + // by adjusting PostProcessSpec). + // + // Note that it is ok if we already did the association with the current + // planNode when created the last stage of the physical plan - the + // callback handles this case safely (i.e. without double-counting). + associateWithPlanNode(&plan.PhysicalPlan) + } + return plan, err } diff --git a/pkg/sql/instrumentation.go b/pkg/sql/instrumentation.go index 5c739fbb5636..757de05de6b1 100644 --- a/pkg/sql/instrumentation.go +++ b/pkg/sql/instrumentation.go @@ -959,11 +959,34 @@ type execNodeTraceMetadata map[exec.Node][]execComponents type execComponents []execinfrapb.ComponentID // associateNodeWithComponents is called during planning, as processors are -// planned for an execution operator. +// planned for an execution operator. This function can be called multiple times +// for the same exec.Node and execComponents. func (m execNodeTraceMetadata) associateNodeWithComponents( node exec.Node, components execComponents, ) { if prevComponents, ok := m[node]; ok { + // We already have some components associated with this node. Check + // whether this is a duplicate association (that should be a no-op). + for _, oldComponents := range prevComponents { + if len(oldComponents) != len(components) { + continue + } + dup := true + for i := range oldComponents { + // Duplicate association can only happen when component IDs are + // in exactly the same order. + if oldComponents[i] != components[i] { + dup = false + break + } + } + if dup { + // This association has already been performed. + return + } + } + // This must be a new stage in the physical plan, so we want to extend + // the mapping for the exec.Node. m[node] = append(prevComponents, components) } else { m[node] = []execComponents{components} diff --git a/pkg/sql/opt/exec/execbuilder/testdata/explain_analyze b/pkg/sql/opt/exec/execbuilder/testdata/explain_analyze index 1586d25d7a28..b9abc3c8b495 100644 --- a/pkg/sql/opt/exec/execbuilder/testdata/explain_analyze +++ b/pkg/sql/opt/exec/execbuilder/testdata/explain_analyze @@ -82,3 +82,102 @@ vectorized: true estimated row count: 10 (missing stats) table: privileges@privileges_path_user_id_key spans: /"vtable/crdb_internal/tables"-/"vtable/crdb_internal/tables"/PrefixEnd + +query T +EXPLAIN ANALYZE SHOW TABLES; +---- +planning time: 10µs +execution time: 100µs +distribution: +vectorized: +plan type: custom +maximum memory usage: +network usage: +regions: +isolation level: serializable +priority: normal +quality of service: regular +· +• sort +│ sql nodes: +│ regions: +│ actual row count: 1 +│ estimated max memory allocated: 0 B +│ order: +nspname,+relname +│ +└── • render + │ + └── • hash join (left outer) + │ sql nodes: + │ regions: + │ actual row count: 1 + │ estimated max memory allocated: 0 B + │ equality: (column80) = (table_id) + │ + ├── • render + │ │ + │ └── • hash join (left outer) + │ │ sql nodes: + │ │ regions: + │ │ actual row count: 1 + │ │ estimated max memory allocated: 0 B + │ │ equality: (column62) = (table_id) + │ │ + │ ├── • render + │ │ │ + │ │ └── • hash join (right outer) + │ │ │ sql nodes: + │ │ │ regions: + │ │ │ actual row count: 1 + │ │ │ estimated max memory allocated: 0 B + │ │ │ equality: (oid) = (relowner) + │ │ │ + │ │ ├── • virtual table + │ │ │ sql nodes: + │ │ │ regions: + │ │ │ actual row count: 4 + │ │ │ table: pg_roles@primary + │ │ │ + │ │ └── • hash join + │ │ │ sql nodes: + │ │ │ regions: + │ │ │ actual row count: 1 + │ │ │ estimated max memory allocated: 0 B + │ │ │ equality: (oid) = (relnamespace) + │ │ │ + │ │ ├── • filter + │ │ │ │ sql nodes: + │ │ │ │ regions: + │ │ │ │ actual row count: 1 + │ │ │ │ filter: nspname NOT IN ('crdb_internal', 'information_schema', __more1_10__, 'pg_extension') + │ │ │ │ + │ │ │ └── • virtual table + │ │ │ sql nodes: + │ │ │ regions: + │ │ │ actual row count: 5 + │ │ │ table: pg_namespace@primary + │ │ │ + │ │ └── • filter + │ │ │ sql nodes: + │ │ │ regions: + │ │ │ actual row count: 330 + │ │ │ filter: relkind IN ('S', 'm', __more1_10__, 'v') + │ │ │ + │ │ └── • virtual table + │ │ sql nodes: + │ │ regions: + │ │ actual row count: 362 + │ │ table: pg_class@primary + │ │ + │ └── • virtual table + │ sql nodes: + │ regions: + │ actual row count: 330 + │ table: table_row_statistics@primary + │ + └── • virtual table + sql nodes: + regions: + actual row count: 1 + table: tables@tables_database_name_idx (partial index) + spans: [/'test' - /'test']