Create top span in ExecutorRun hook if needed

When fetching an existing cursors, the portal already exists and the
query directly starts from ExecutorRun without going through planner,
post_parse or ExecutorStart. Since top spans were only initialised
within those 3 hooks, cursor fetch wouldn't have a matching top span.

This commit fixes the issue by creating the top span in ExecutorRun if
it doesn't exist.

Fixes #10

Makefile

@@ -19,7 +19,7 @@ OBJS = \
 	src/pg_tracing_span.o \
 	src/version_compat.o
 
-REGRESSCHECKS = setup utility select insert trigger
+REGRESSCHECKS = setup utility select insert trigger cursor
 ifeq ($(PG_VERSION),15)
 REGRESSCHECKS += trigger_15
 else

expected/cursor.out

@@ -0,0 +1,148 @@
+BEGIN;
+/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000001-0000000000000001-01'*/ DECLARE c CURSOR FOR SELECT * from pg_tracing_test;
+/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000001-0000000000000002-01'*/ FETCH FORWARD 20 from c \gset
+more than one row returned for \gset
+/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000001-0000000000000003-01'*/ FETCH BACKWARD 10 from c \gset
+more than one row returned for \gset
+COMMIT;
+-- First declare
+-- +----------------------------------------+
+-- | A: Declare (Utility)                   |
+-- ++------------------------------------+--+
+--  | B: ProcessUtility                  |
+--  +-+-------------------------------+--+
+--    | C: Declare cursor... (Select) |
+--    +-------------------------------+
+--    | D: Planner   |
+--    +--------------+
+SELECT span_id AS span_a_id,
+        get_epoch(span_start) as span_a_start,
+        get_epoch(span_end) as span_a_end
+		from pg_tracing_peek_spans
+        where trace_id='00000000000000000000000000000001' AND parent_id='0000000000000001' \gset
+SELECT span_id AS span_b_id,
+        get_epoch(span_start) as span_b_start,
+        get_epoch(span_end) as span_b_end
+		from pg_tracing_peek_spans
+        where parent_id =:'span_a_id' and span_operation='ProcessUtility' \gset
+SELECT span_id AS span_c_id,
+        get_epoch(span_start) as span_c_start,
+        get_epoch(span_end) as span_c_end
+		from pg_tracing_peek_spans
+        where parent_id =:'span_b_id' and span_type='Select query' \gset
+SELECT span_id AS span_d_id,
+        get_epoch(span_start) as span_d_start,
+        get_epoch(span_end) as span_d_end
+		from pg_tracing_peek_spans
+        where parent_id =:'span_c_id' and span_operation='Planner' \gset
+SELECT :span_a_end >= MAX(v) as root_ends_last FROM UNNEST(ARRAY[:span_b_end, :span_c_end, :span_d_end]) as v;
+ root_ends_last 
+----------------
+ t
+(1 row)
+
+SELECT :span_c_start >= :span_b_start as nested_declare_starts_after_parent,
+       :span_d_end <= :span_c_end as nested_planner_ends_before_parent;
+ nested_declare_starts_after_parent | nested_planner_ends_before_parent 
+------------------------------------+-----------------------------------
+ t                                  | t
+(1 row)
+
+-- Fetch forward
+-- +----------------------------------------+
+-- | A: Fetch forward (Utility)             |
+-- ++------------------------------------+--+
+--  | B: ProcessUtility                  |
+--  +-+-------------------------------+--+
+--    | C: Declare cursor... (Select) |
+--    +------------------+------------+
+--    | D: ExecutorRun   |
+--    +------------------+
+SELECT span_id AS span_a_id,
+        get_epoch(span_start) as span_a_start,
+        get_epoch(span_end) as span_a_end
+		from pg_tracing_peek_spans
+        where trace_id='00000000000000000000000000000001' AND parent_id='0000000000000002' \gset
+SELECT span_id AS span_b_id,
+        get_epoch(span_start) as span_b_start,
+        get_epoch(span_end) as span_b_end
+		from pg_tracing_peek_spans
+        where parent_id =:'span_a_id' and span_operation='ProcessUtility' \gset
+SELECT span_id AS span_c_id,
+        get_epoch(span_start) as span_c_start,
+        get_epoch(span_end) as span_c_end
+		from pg_tracing_peek_spans
+        where parent_id =:'span_b_id' and span_type='Select query' \gset
+SELECT span_id AS span_d_id,
+        get_epoch(span_start) as span_d_start,
+        get_epoch(span_end) as span_d_end
+		from pg_tracing_peek_spans
+        where parent_id =:'span_c_id' and span_operation='ExecutorRun' \gset
+SELECT :span_a_end >= MAX(v) as root_ends_last FROM UNNEST(ARRAY[:span_b_end, :span_c_end, :span_d_end]) as v;
+ root_ends_last 
+----------------
+ t
+(1 row)
+
+SELECT :span_c_start >= :span_b_start as nested_declare_starts_after_parent,
+       :span_d_end <= :span_c_end as nested_planner_ends_before_parent;
+ nested_declare_starts_after_parent | nested_planner_ends_before_parent 
+------------------------------------+-----------------------------------
+ t                                  | t
+(1 row)
+
+-- Fetch Backward
+-- Same structure as fetch forward
+SELECT span_id AS span_a_id,
+        get_epoch(span_start) as span_a_start,
+        get_epoch(span_end) as span_a_end
+		from pg_tracing_peek_spans
+        where trace_id='00000000000000000000000000000001' AND parent_id='0000000000000003' \gset
+SELECT span_id AS span_b_id,
+        get_epoch(span_start) as span_b_start,
+        get_epoch(span_end) as span_b_end
+		from pg_tracing_peek_spans
+        where parent_id =:'span_a_id' and span_operation='ProcessUtility' \gset
+SELECT span_id AS span_c_id,
+        get_epoch(span_start) as span_c_start,
+        get_epoch(span_end) as span_c_end
+		from pg_tracing_peek_spans
+        where parent_id =:'span_b_id' and span_type='Select query' \gset
+SELECT span_id AS span_d_id,
+        get_epoch(span_start) as span_d_start,
+        get_epoch(span_end) as span_d_end
+		from pg_tracing_peek_spans
+        where parent_id =:'span_c_id' and span_operation='ExecutorRun' \gset
+SELECT :span_a_end >= MAX(v) as root_ends_last FROM UNNEST(ARRAY[:span_b_end, :span_c_end, :span_d_end]) as v;
+ root_ends_last 
+----------------
+ t
+(1 row)
+
+SELECT :span_c_start >= :span_b_start as nested_declare_starts_after_parent,
+       :span_d_end <= :span_c_end as nested_planner_ends_before_parent;
+ nested_declare_starts_after_parent | nested_planner_ends_before_parent 
+------------------------------------+-----------------------------------
+ t                                  | t
+(1 row)
+
+-- Check
+SELECT span_type, span_operation, lvl from peek_ordered_spans where trace_id='00000000000000000000000000000001';
+   span_type    |                   span_operation                    | lvl 
+----------------+-----------------------------------------------------+-----
+ Utility query  | DECLARE c CURSOR FOR SELECT * from pg_tracing_test; |   1
+ ProcessUtility | ProcessUtility                                      |   2
+ Select query   | DECLARE c CURSOR FOR SELECT * from pg_tracing_test; |   3
+ Planner        | Planner                                             |   4
+ Utility query  | FETCH FORWARD 20 from c                             |   1
+ ProcessUtility | ProcessUtility                                      |   2
+ Select query   | DECLARE c CURSOR FOR SELECT * from pg_tracing_test; |   3
+ Executor       | ExecutorRun                                         |   4
+ Utility query  | FETCH BACKWARD 10 from c                            |   1
+ ProcessUtility | ProcessUtility                                      |   2
+ Select query   | DECLARE c CURSOR FOR SELECT * from pg_tracing_test; |   3
+ Executor       | ExecutorRun                                         |   4
+(12 rows)
+
+-- Clean created spans
+CALL clean_spans();

sql/cursor.sql

@@ -0,0 +1,112 @@
+BEGIN;
+/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000001-0000000000000001-01'*/ DECLARE c CURSOR FOR SELECT * from pg_tracing_test;
+/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000001-0000000000000002-01'*/ FETCH FORWARD 20 from c \gset
+/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000001-0000000000000003-01'*/ FETCH BACKWARD 10 from c \gset
+COMMIT;
+
+-- First declare
+-- +----------------------------------------+
+-- | A: Declare (Utility)                   |
+-- ++------------------------------------+--+
+--  | B: ProcessUtility                  |
+--  +-+-------------------------------+--+
+--    | C: Declare cursor... (Select) |
+--    +-------------------------------+
+--    | D: Planner   |
+--    +--------------+
+
+SELECT span_id AS span_a_id,
+        get_epoch(span_start) as span_a_start,
+        get_epoch(span_end) as span_a_end
+		from pg_tracing_peek_spans
+        where trace_id='00000000000000000000000000000001' AND parent_id='0000000000000001' \gset
+SELECT span_id AS span_b_id,
+        get_epoch(span_start) as span_b_start,
+        get_epoch(span_end) as span_b_end
+		from pg_tracing_peek_spans
+        where parent_id =:'span_a_id' and span_operation='ProcessUtility' \gset
+SELECT span_id AS span_c_id,
+        get_epoch(span_start) as span_c_start,
+        get_epoch(span_end) as span_c_end
+		from pg_tracing_peek_spans
+        where parent_id =:'span_b_id' and span_type='Select query' \gset
+SELECT span_id AS span_d_id,
+        get_epoch(span_start) as span_d_start,
+        get_epoch(span_end) as span_d_end
+		from pg_tracing_peek_spans
+        where parent_id =:'span_c_id' and span_operation='Planner' \gset
+
+SELECT :span_a_end >= MAX(v) as root_ends_last FROM UNNEST(ARRAY[:span_b_end, :span_c_end, :span_d_end]) as v;
+SELECT :span_c_start >= :span_b_start as nested_declare_starts_after_parent,
+       :span_d_end <= :span_c_end as nested_planner_ends_before_parent;
+
+
+-- Fetch forward
+-- +----------------------------------------+
+-- | A: Fetch forward (Utility)             |
+-- ++------------------------------------+--+
+--  | B: ProcessUtility                  |
+--  +-+-------------------------------+--+
+--    | C: Declare cursor... (Select) |
+--    +------------------+------------+
+--    | D: ExecutorRun   |
+--    +------------------+
+
+SELECT span_id AS span_a_id,
+        get_epoch(span_start) as span_a_start,
+        get_epoch(span_end) as span_a_end
+		from pg_tracing_peek_spans
+        where trace_id='00000000000000000000000000000001' AND parent_id='0000000000000002' \gset
+SELECT span_id AS span_b_id,
+        get_epoch(span_start) as span_b_start,
+        get_epoch(span_end) as span_b_end
+		from pg_tracing_peek_spans
+        where parent_id =:'span_a_id' and span_operation='ProcessUtility' \gset
+SELECT span_id AS span_c_id,
+        get_epoch(span_start) as span_c_start,
+        get_epoch(span_end) as span_c_end
+		from pg_tracing_peek_spans
+        where parent_id =:'span_b_id' and span_type='Select query' \gset
+SELECT span_id AS span_d_id,
+        get_epoch(span_start) as span_d_start,
+        get_epoch(span_end) as span_d_end
+		from pg_tracing_peek_spans
+        where parent_id =:'span_c_id' and span_operation='ExecutorRun' \gset
+
+SELECT :span_a_end >= MAX(v) as root_ends_last FROM UNNEST(ARRAY[:span_b_end, :span_c_end, :span_d_end]) as v;
+SELECT :span_c_start >= :span_b_start as nested_declare_starts_after_parent,
+       :span_d_end <= :span_c_end as nested_planner_ends_before_parent;
+
+-- Fetch Backward
+-- Same structure as fetch forward
+
+SELECT span_id AS span_a_id,
+        get_epoch(span_start) as span_a_start,
+        get_epoch(span_end) as span_a_end
+		from pg_tracing_peek_spans
+        where trace_id='00000000000000000000000000000001' AND parent_id='0000000000000003' \gset
+SELECT span_id AS span_b_id,
+        get_epoch(span_start) as span_b_start,
+        get_epoch(span_end) as span_b_end
+		from pg_tracing_peek_spans
+        where parent_id =:'span_a_id' and span_operation='ProcessUtility' \gset
+SELECT span_id AS span_c_id,
+        get_epoch(span_start) as span_c_start,
+        get_epoch(span_end) as span_c_end
+		from pg_tracing_peek_spans
+        where parent_id =:'span_b_id' and span_type='Select query' \gset
+SELECT span_id AS span_d_id,
+        get_epoch(span_start) as span_d_start,
+        get_epoch(span_end) as span_d_end
+		from pg_tracing_peek_spans
+        where parent_id =:'span_c_id' and span_operation='ExecutorRun' \gset
+
+SELECT :span_a_end >= MAX(v) as root_ends_last FROM UNNEST(ARRAY[:span_b_end, :span_c_end, :span_d_end]) as v;
+SELECT :span_c_start >= :span_b_start as nested_declare_starts_after_parent,
+       :span_d_end <= :span_c_end as nested_planner_ends_before_parent;
+
+-- Check
+SELECT span_type, span_operation, lvl from peek_ordered_spans where trace_id='00000000000000000000000000000001';
+
+-- Clean created spans
+CALL clean_spans();

src/pg_tracing.c

@@ -1536,8 +1536,9 @@ pg_tracing_post_parse_analyze(ParseState *pstate, Query *query, JumbleState *jst
 		return;
 
 	/*
-	 * We want to avoid calling GetCurrentTimestamp at the start of post parse as it will
-	 * impact all queries and we will only use it when the query is sampled.
+	 * We want to avoid calling GetCurrentTimestamp at the start of post parse
+	 * as it will impact all queries and we will only use it when the query is
+	 * sampled.
 	 */
 	start_top_span = GetCurrentTimestamp();
 
@@ -1751,7 +1752,17 @@ pg_tracing_ExecutorRun(QueryDesc *queryDesc, ScanDirection direction, uint64 cou
 	{
 		Span	   *executor_run_span;
 		TimestampTz span_start_time = GetCurrentTimestamp();
-		uint64		parent_id = get_latest_top_span(exec_nested_level)->span_id;
+		uint64		parent_id;
+
+		/*
+		 * When fetching an existing cursor, the portal already exists and
+		 * ExecutorRun is the first hook called. Create the top span if it
+		 * doesn't already exist.
+		 */
+		initialize_top_span(trace_context, queryDesc->operation, NULL, NULL, NULL,
+							queryDesc->sourceText, span_start_time, false);
+
+		parent_id = get_latest_top_span(exec_nested_level)->span_id;
 
 		/* Start ExecutorRun span as a new top span */
 		executor_run_span = allocate_new_top_span();