From 3e3230b2cd6843bd29509d92e5c8164722cc97b5 Mon Sep 17 00:00:00 2001 From: Anthonin Bonnefoy Date: Tue, 10 Sep 2024 11:24:47 +0200 Subject: [PATCH] Only use planstate as parent if it's still running With before trigger, the planstate will be finished by the time the next top span is created. We need to check whether the planstate is still running to be a parent candidate. --- expected/trigger.out | 42 +++++++++++++++++++++++++++++------ sql/trigger.sql | 15 +++++++++++++ src/pg_tracing.c | 4 ++-- src/pg_tracing_active_spans.c | 14 ++++++++---- 4 files changed, 62 insertions(+), 13 deletions(-) diff --git a/expected/trigger.out b/expected/trigger.out index ccce0da..bb37a25 100644 --- a/expected/trigger.out +++ b/expected/trigger.out @@ -189,13 +189,13 @@ SELECT trace_id, span_type, span_operation, lvl from peek_ordered_spans where tr 00000000000000000000000000000001 | Insert | Insert on before_trigger_table | 3 00000000000000000000000000000001 | ProjectSet | ProjectSet | 4 00000000000000000000000000000001 | Result | Result | 5 - 00000000000000000000000000000001 | Select query | SELECT $1 | 5 - 00000000000000000000000000000001 | Planner | Planner | 6 - 00000000000000000000000000000001 | ExecutorRun | ExecutorRun | 6 - 00000000000000000000000000000001 | Result | Result | 7 - 00000000000000000000000000000001 | Select query | SELECT $1 | 5 - 00000000000000000000000000000001 | ExecutorRun | ExecutorRun | 6 - 00000000000000000000000000000001 | Result | Result | 7 + 00000000000000000000000000000001 | Select query | SELECT $1 | 3 + 00000000000000000000000000000001 | Planner | Planner | 4 + 00000000000000000000000000000001 | ExecutorRun | ExecutorRun | 4 + 00000000000000000000000000000001 | Result | Result | 5 + 00000000000000000000000000000001 | Select query | SELECT $1 | 3 + 00000000000000000000000000000001 | ExecutorRun | ExecutorRun | 4 + 00000000000000000000000000000001 | Result | Result | 5 00000000000000000000000000000001 | TransactionCommit | TransactionCommit | 1 (14 rows) @@ -270,6 +270,34 @@ SELECT trace_id, span_type, span_operation, lvl from peek_ordered_spans where tr 00000000000000000000000000000004 | IndexScan | IndexScan using enumtest_parent_pkey on enumtest_parent x | 6 (11 rows) +-- Test before trigger with copy dml +create table copydml_test (id serial, t text); +create function qqq_trig() returns trigger as $$ +begin +if tg_op in ('INSERT', 'UPDATE') then + return new; +end if; +end +$$ language plpgsql; +create trigger qqqbef before insert or update or delete on copydml_test + for each row execute procedure qqq_trig(); +/*traceparent='00-00000000000000000000000000000005-0000000000000005-01'*/ copy (insert into copydml_test (t) values ('f') returning id) to stdout; +1 +SELECT trace_id, span_type, span_operation, lvl from peek_ordered_spans where trace_id='00000000000000000000000000000005'; + trace_id | span_type | span_operation | lvl +----------------------------------+-------------------+--------------------------------------------------------------------------+----- + 00000000000000000000000000000005 | Utility query | copy (insert into copydml_test (t) values ('f') returning id) to stdout; | 1 + 00000000000000000000000000000005 | ProcessUtility | ProcessUtility | 2 + 00000000000000000000000000000005 | Insert query | copy (insert into copydml_test (t) values ($1) returning id) to stdout; | 3 + 00000000000000000000000000000005 | Planner | Planner | 4 + 00000000000000000000000000000005 | ExecutorRun | ExecutorRun | 4 + 00000000000000000000000000000005 | Insert | Insert on copydml_test | 5 + 00000000000000000000000000000005 | Result | Result | 6 + 00000000000000000000000000000005 | Select query | tg_op in ($7, $8) | 5 + 00000000000000000000000000000005 | Planner | Planner | 6 + 00000000000000000000000000000005 | TransactionCommit | TransactionCommit | 1 +(10 rows) + -- Cleanup CALL reset_settings(); CALL clean_spans(); diff --git a/sql/trigger.sql b/sql/trigger.sql index 2a51653..43a02c9 100644 --- a/sql/trigger.sql +++ b/sql/trigger.sql @@ -169,6 +169,21 @@ INSERT INTO enumtest_parent VALUES ('red'); /*traceparent='00-00000000000000000000000000000004-0000000000000004-01'*/ INSERT INTO enumtest_child VALUES ('blue'); SELECT trace_id, span_type, span_operation, lvl from peek_ordered_spans where trace_id='00000000000000000000000000000004'; +-- Test before trigger with copy dml +create table copydml_test (id serial, t text); +create function qqq_trig() returns trigger as $$ +begin +if tg_op in ('INSERT', 'UPDATE') then + return new; +end if; +end +$$ language plpgsql; +create trigger qqqbef before insert or update or delete on copydml_test + for each row execute procedure qqq_trig(); +/*traceparent='00-00000000000000000000000000000005-0000000000000005-01'*/ copy (insert into copydml_test (t) values ('f') returning id) to stdout; + +SELECT trace_id, span_type, span_operation, lvl from peek_ordered_spans where trace_id='00000000000000000000000000000005'; + -- Cleanup CALL reset_settings(); CALL clean_spans(); diff --git a/src/pg_tracing.c b/src/pg_tracing.c index acadc64..c500994 100644 --- a/src/pg_tracing.c +++ b/src/pg_tracing.c @@ -1045,8 +1045,8 @@ process_query_desc(const Traceparent * traceparent, const QueryDesc *queryDesc, { NodeCounters *node_counters = &peek_active_span()->node_counters; - if (!queryDesc->totaltime->running) - return; + if (!queryDesc->totaltime->running) + return; /* Process total counters */ if (queryDesc->totaltime) diff --git a/src/pg_tracing_active_spans.c b/src/pg_tracing_active_spans.c index bbdb4e8..78ed743 100644 --- a/src/pg_tracing_active_spans.c +++ b/src/pg_tracing_active_spans.c @@ -153,18 +153,24 @@ begin_active_span(const SpanContext * span_context, Span * span, /* * Both planstate and previous top span can be the parent for the new - * top span, we use the most recent as a parent + * top span, we use the most recent as a parent. planstate must be + * currently active to be a parent candidate. */ - if (parent_traced_planstate != NULL && parent_traced_planstate->node_start >= parent_span->start) + if (parent_traced_planstate != NULL + && parent_traced_planstate->node_start >= parent_span->start + && !INSTR_TIME_IS_ZERO(parent_traced_planstate->planstate->instrument->starttime)) parent_id = parent_traced_planstate->span_id; else + { parent_id = parent_span->span_id; + parent_planstate_index = -1; + } } - begin_span(span_context->traceparent->trace_id, span, span_type, - NULL, parent_id, span_context->query_id, span_context->start_time); /* Keep track of the parent planstate index */ span->parent_planstate_index = parent_planstate_index; + begin_span(span_context->traceparent->trace_id, span, span_type, + NULL, parent_id, span_context->query_id, span_context->start_time); if (IsParallelWorker()) {