Skip to content

Commit

Permalink
Use outerplan start as hash node start
Browse files Browse the repository at this point in the history
  • Loading branch information
bonnefoa committed Apr 3, 2024
1 parent 983ab83 commit 5974409
Show file tree
Hide file tree
Showing 4 changed files with 111 additions and 5 deletions.
2 changes: 1 addition & 1 deletion Makefile
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,7 @@ OBJS = \
src/pg_tracing_span.o

REGRESSCHECKS = setup utility select extended insert trigger sample \
planstate planstate_bitmap \
planstate planstate_bitmap planstate_hash \
parallel subxact full_buffer \
nested wal cleanup
REGRESSCHECKS_OPTS = --no-locale --encoding=UTF8 --temp-config pg_tracing.conf
Expand Down
60 changes: 60 additions & 0 deletions expected/planstate_hash.out
Original file line number Diff line number Diff line change
@@ -0,0 +1,60 @@
/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000001-0000000000000001-01'*/ select count(*) from pg_tracing_test r join pg_tracing_test s using (a);
count
-------
10000
(1 row)

SELECT span_operation, deparse_info, parameters, lvl from peek_ordered_spans where trace_id='00000000000000000000000000000001';
span_operation | deparse_info | parameters | lvl
--------------------------------------------------------------------------+--------------------+------------+-----
select count(*) from pg_tracing_test r join pg_tracing_test s using (a); | | | 1
Planner | | | 2
ExecutorRun | | | 2
Aggregate | | | 3
Hash Join | Hash Cond: (a = a) | | 4
SeqScan on pg_tracing_test r | | | 5
Hash | | | 5
SeqScan on pg_tracing_test s | | | 6
(8 rows)

-- +-----------------------------------------+
-- | A: HashJoin |
-- ++-----------------+----------------------+
-- | B: SeqScan |
-- +-----------------+
-- +--------------------+
-- | C: Hash |
-- +--------------------+
-- | D: SeqScan |
-- +--------------+
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 span_operation='Hash Join' \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='SeqScan on pg_tracing_test r' \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_a_id' and span_operation='Hash' \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='SeqScan on pg_tracing_test s' \gset
SELECT :span_a_end >= :span_c_end as root_ends_last,
:span_c_start >= :span_b_start as hash_start_after_seqscan,
:span_c_start = :span_d_start as hash_start_same_as_child_seqscan,
:span_d_end <= :span_c_end as nested_seq_scan_end_before_parent;
root_ends_last | hash_start_after_seqscan | hash_start_same_as_child_seqscan | nested_seq_scan_end_before_parent
----------------+--------------------------+----------------------------------+-----------------------------------
t | t | t | t
(1 row)

-- Clean created spans
CALL clean_spans();
42 changes: 42 additions & 0 deletions sql/planstate_hash.sql
Original file line number Diff line number Diff line change
@@ -0,0 +1,42 @@
/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000001-0000000000000001-01'*/ select count(*) from pg_tracing_test r join pg_tracing_test s using (a);
SELECT span_operation, deparse_info, parameters, lvl from peek_ordered_spans where trace_id='00000000000000000000000000000001';

-- +-----------------------------------------+
-- | A: HashJoin |
-- ++-----------------+----------------------+
-- | B: SeqScan |
-- +-----------------+
-- +--------------------+
-- | C: Hash |
-- +--------------------+
-- | D: SeqScan |
-- +--------------+

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 span_operation='Hash Join' \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='SeqScan on pg_tracing_test r' \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_a_id' and span_operation='Hash' \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='SeqScan on pg_tracing_test s' \gset

SELECT :span_a_end >= :span_c_end as root_ends_last,
:span_c_start >= :span_b_start as hash_start_after_seqscan,
:span_c_start = :span_d_start as hash_start_same_as_child_seqscan,
:span_d_end <= :span_c_end as nested_seq_scan_end_before_parent;

-- Clean created spans
CALL clean_spans();
12 changes: 8 additions & 4 deletions src/pg_tracing_planstate.c
Original file line number Diff line number Diff line change
Expand Up @@ -68,7 +68,8 @@ drop_traced_planstate(int exec_nested_level)
}

/*
* If spans from planstate is requested, we override planstate's ExecProcNode's pointer with this function. It will track the time of the first node call needed to place the planstate span.
* If spans from planstate is requested, we override planstate's ExecProcNode's pointer with this function.
* It will track the time of the first node call needed to place the planstate span.
*/
static TupleTableSlot *
ExecProcNodeFirstPgTracing(PlanState *node)
Expand Down Expand Up @@ -388,17 +389,20 @@ generate_span_from_planstate(PlanState *planstate, planstateTraceContext * plans
switch (nodeTag(planstate->plan))
{
case T_BitmapIndexScan:
case T_Hash:
case T_BitmapAnd:
case T_BitmapOr:

/*
* Those nodes won't go through ExecProcNode so we won't have
* their start. Fallback to the parent start. TODO: Use the child
* start as a fallback instead
* their start. Fallback to the parent start.
*/
span_start = fallback_start;
break;
case T_Hash:
/* For hash node, use the child's start */
traced_planstate = get_traced_planstate(outerPlanState(planstate));
span_start = traced_planstate->node_start;
break;
default:
traced_planstate = get_traced_planstate(planstate);
/* TODO: better fallback if planstate is not found */
Expand Down

0 comments on commit 5974409

Please sign in to comment.