From 6efac5d3ee50c52e59f48f83ec5669834e7cf40b Mon Sep 17 00:00:00 2001 From: Anthonin Bonnefoy Date: Tue, 19 Mar 2024 11:47:57 +0100 Subject: [PATCH] Remove old PG17 tests --- tests/17/expected/cleanup.out | 8 - tests/17/expected/extended.out | 133 ---------------- tests/17/expected/insert.out | 49 ------ tests/17/expected/nested.out | 183 ---------------------- tests/17/expected/reset.out | 13 -- tests/17/expected/sample.out | 154 ------------------- tests/17/expected/select.out | 251 ------------------------------ tests/17/expected/subxact.out | 43 ------ tests/17/expected/trigger.out | 246 ------------------------------ tests/17/expected/utility.out | 270 --------------------------------- tests/17/expected/wal.out | 25 --- 11 files changed, 1375 deletions(-) delete mode 100644 tests/17/expected/cleanup.out delete mode 100644 tests/17/expected/extended.out delete mode 100644 tests/17/expected/insert.out delete mode 100644 tests/17/expected/nested.out delete mode 100644 tests/17/expected/reset.out delete mode 100644 tests/17/expected/sample.out delete mode 100644 tests/17/expected/select.out delete mode 100644 tests/17/expected/subxact.out delete mode 100644 tests/17/expected/trigger.out delete mode 100644 tests/17/expected/utility.out delete mode 100644 tests/17/expected/wal.out diff --git a/tests/17/expected/cleanup.out b/tests/17/expected/cleanup.out deleted file mode 100644 index 7ab6696..0000000 --- a/tests/17/expected/cleanup.out +++ /dev/null @@ -1,8 +0,0 @@ --- Drop test table and test functions -DROP TABLE pg_tracing_test; -DROP function test_function_project_set; -DROP function test_function_result; -DROP EXTENSION pg_tracing CASCADE; -NOTICE: drop cascades to 2 other objects -DETAIL: drop cascades to view peek_spans_with_level -drop cascades to view peek_ordered_spans diff --git a/tests/17/expected/extended.out b/tests/17/expected/extended.out deleted file mode 100644 index 90400d7..0000000 --- a/tests/17/expected/extended.out +++ /dev/null @@ -1,133 +0,0 @@ --- Trace everything -SET pg_tracing.sample_rate = 1.0; --- Simple query with extended protocol -SELECT $1, $2 \bind 1 2 \g - ?column? | ?column? -----------+---------- - 1 | 2 -(1 row) - -SELECT span_type, span_operation, parameters, lvl FROM peek_ordered_spans; - span_type | span_operation | parameters | lvl ---------------+----------------+--------------------+----- - Select query | SELECT $1, $2 | $1 = '1', $2 = '2' | 1 - Planner | Planner | | 2 - Executor | ExecutorRun | | 2 -(3 rows) - -CALL clean_spans(); --- Trigger an error due to mismatching number of parameters -BEGIN; select $1 \bind \g -ERROR: bind message supplies 0 parameters, but prepared statement "" requires 1 -ROLLBACK; -SELECT span_type, span_operation, parameters, lvl FROM peek_ordered_spans; - span_type | span_operation | parameters | lvl -----------------+----------------+------------+----- - Utility query | BEGIN; | | 1 - ProcessUtility | ProcessUtility | | 2 - Utility query | ROLLBACK; | | 1 - ProcessUtility | ProcessUtility | | 2 -(4 rows) - -CALL clean_spans(); --- Execute queries with extended protocol within an explicit transaction -BEGIN; -SELECT $1 \bind 1 \g - ?column? ----------- - 1 -(1 row) - -SELECT $1, $2 \bind 2 3 \g - ?column? | ?column? -----------+---------- - 2 | 3 -(1 row) - -COMMIT; --- Spans within the same transaction should have been generated with the same trace_id -SELECT count(distinct(trace_id)) = 1 FROM pg_tracing_peek_spans; - ?column? ----------- - t -(1 row) - -SELECT span_type, span_operation, parameters, lvl FROM peek_ordered_spans; - span_type | span_operation | parameters | lvl -----------------+----------------+--------------------+----- - Utility query | BEGIN; | | 1 - ProcessUtility | ProcessUtility | | 2 - Select query | SELECT $1 | $1 = '1' | 1 - Planner | Planner | | 2 - Executor | ExecutorRun | | 2 - Select query | SELECT $1, $2 | $1 = '2', $2 = '3' | 1 - Planner | Planner | | 2 - Executor | ExecutorRun | | 2 - Utility query | COMMIT; | | 1 - ProcessUtility | ProcessUtility | | 2 -(10 rows) - -CALL clean_spans(); --- Mix extended protocol and simple protocol -BEGIN; -SELECT $1 \bind 1 \g - ?column? ----------- - 1 -(1 row) - -SELECT 5, 6, 7; - ?column? | ?column? | ?column? -----------+----------+---------- - 5 | 6 | 7 -(1 row) - -SELECT $1, $2 \bind 2 3 \g - ?column? | ?column? -----------+---------- - 2 | 3 -(1 row) - -COMMIT; --- Spans within the same transaction should have been generated with the same trace_id -SELECT count(distinct(trace_id)) = 1 FROM pg_tracing_peek_spans; - ?column? ----------- - t -(1 row) - -SELECT span_type, span_operation, parameters, lvl FROM peek_ordered_spans; - span_type | span_operation | parameters | lvl -----------------+--------------------+------------------------+----- - Utility query | BEGIN; | | 1 - ProcessUtility | ProcessUtility | | 2 - Select query | SELECT $1 | $1 = '1' | 1 - Planner | Planner | | 2 - Executor | ExecutorRun | | 2 - Select query | SELECT $1, $2, $3; | $1 = 5, $2 = 6, $3 = 7 | 1 - Planner | Planner | | 2 - Executor | ExecutorRun | | 2 - Select query | SELECT $1, $2 | $1 = '2', $2 = '3' | 1 - Planner | Planner | | 2 - Executor | ExecutorRun | | 2 - Utility query | COMMIT; | | 1 - ProcessUtility | ProcessUtility | | 2 -(13 rows) - -CALL clean_spans(); --- gdesc calls a single parse command then execute a query. Make sure we handle this case -SELECT 1 \gdesc - Column | Type -----------+--------- - ?column? | integer -(1 row) - -SELECT span_type, span_operation, parameters, lvl FROM peek_ordered_spans; - span_type | span_operation | parameters | lvl ---------------+------------------------------------------------------------------------------------------------------------------------------+-------------------------------------+----- - Select query | SELECT name AS "Column", pg_catalog.format_type(tp, tpm) AS "Type"FROM (VALUES ($1, $2::pg_catalog.oid,$3)) s(name, tp, tpm) | $1 = '?column?', $2 = '23', $3 = -1 | 1 - Planner | Planner | | 2 - Executor | ExecutorRun | | 2 -(3 rows) - -CALL clean_spans(); diff --git a/tests/17/expected/insert.out b/tests/17/expected/insert.out deleted file mode 100644 index bcffbc3..0000000 --- a/tests/17/expected/insert.out +++ /dev/null @@ -1,49 +0,0 @@ --- Only trace queries with sample flag -SET pg_tracing.sample_rate = 0.0; -SET pg_tracing.caller_sample_rate = 1.0; -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000001-0000000000000001-01'*/ CREATE TABLE IF NOT EXISTS pg_tracing_test_table_with_constraint (a int, b char(20), CONSTRAINT PK_tracing_test PRIMARY KEY (a)); -SELECT span_type, span_operation, lvl from peek_ordered_spans where trace_id='00000000000000000000000000000001'; - span_type | span_operation | lvl -----------------+-----------------------------------------------------------------------------------------------------------------------------------+----- - Utility query | CREATE TABLE IF NOT EXISTS pg_tracing_test_table_with_constraint (a int, b char(20), CONSTRAINT PK_tracing_test PRIMARY KEY (a)); | 1 - ProcessUtility | ProcessUtility | 2 - Utility query | CREATE TABLE IF NOT EXISTS pg_tracing_test_table_with_constraint (a int, b char(20), CONSTRAINT PK_tracing_test PRIMARY KEY (a)); | 3 - ProcessUtility | ProcessUtility | 4 - Utility query | CREATE TABLE IF NOT EXISTS pg_tracing_test_table_with_constraint (a int, b char(20), CONSTRAINT PK_tracing_test PRIMARY KEY (a)); | 3 - ProcessUtility | ProcessUtility | 4 -(6 rows) - --- Simple insertion -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000002-0000000000000002-01'*/ INSERT INTO pg_tracing_test_table_with_constraint VALUES(1, 'aaa'); -SELECT span_type, span_operation from peek_ordered_spans where trace_id='00000000000000000000000000000002'; - span_type | span_operation ---------------+------------------------------------------------------------------- - Insert query | INSERT INTO pg_tracing_test_table_with_constraint VALUES($1, $2); - Planner | Planner - Executor | ExecutorRun -(3 rows) - --- Trigger constraint violation -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000003-0000000000000003-01'*/ INSERT INTO pg_tracing_test_table_with_constraint VALUES(1, 'aaa'); -ERROR: duplicate key value violates unique constraint "pk_tracing_test" -DETAIL: Key (a)=(1) already exists. -SELECT span_type, span_operation, sql_error_code, lvl from peek_ordered_spans where trace_id='00000000000000000000000000000003'; - span_type | span_operation | sql_error_code | lvl ---------------+-------------------------------------------------------------------+----------------+----- - Insert query | INSERT INTO pg_tracing_test_table_with_constraint VALUES($1, $2); | 23505 | 1 - Planner | Planner | 00000 | 2 - Executor | ExecutorRun | 23505 | 2 -(3 rows) - --- Trigger an error while calling pg_tracing_peek_spans which resets tracing, nothing should be generated -CALL clean_spans(); -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000004-0000000000000004-01'*/ INSERT INTO pg_tracing_test_table_with_constraint VALUES(length((select sql_error_code from public.pg_tracing_peek_spans)), 'aaa'); -ERROR: null value in column "a" of relation "pg_tracing_test_table_with_constraint" violates not-null constraint -DETAIL: Failing row contains (null, aaa ). -SELECT span_type, span_operation, sql_error_code from peek_ordered_spans where trace_id='00000000000000000000000000000004'; - span_type | span_operation | sql_error_code ------------+----------------+---------------- -(0 rows) - --- Cleanup -CALL clean_spans(); diff --git a/tests/17/expected/nested.out b/tests/17/expected/nested.out deleted file mode 100644 index 3ae7f62..0000000 --- a/tests/17/expected/nested.out +++ /dev/null @@ -1,183 +0,0 @@ --- Create test function to sample -CREATE OR REPLACE FUNCTION test_function_project_set(a int) RETURNS SETOF oid AS -$BODY$ -BEGIN - RETURN QUERY SELECT oid from pg_class where oid = a; -END; -$BODY$ -LANGUAGE plpgsql; -CREATE OR REPLACE FUNCTION test_function_result(a int, b text) RETURNS void AS -$BODY$ -BEGIN - INSERT INTO pg_tracing_test(a, b) VALUES (a, b); -END; -$BODY$ -LANGUAGE plpgsql; --- Trace a statement with a function call -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000051-0000000000000051-01'*/ select test_function_project_set(1); - test_function_project_set ---------------------------- -(0 rows) - --- The test function call will generate the following spans (non exhaustive list): --- +------------------------------------------------------------+ --- | A: Select test_function_project_set(1); | --- +-+----------+-+------------------------------------------+--+ --- |C: Planner| |E: ExecutorRun | --- +----------+ +-----------+------------------------------+ --- | I: Select a from b where... | --- +---+--------------+-----------+ --- |J: ExecutorRun| --- +--------------+ --- Gather span_id, span start and span end of function call statement -SELECT span_id AS span_a_id, - get_span_start(span_start) as span_a_start, - get_span_end(span_start) as span_a_end - from pg_tracing_peek_spans where parent_id='0000000000000051' \gset -SELECT span_id AS span_e_id, - get_span_start(span_start) as span_e_start, - get_span_end(span_start) as span_e_end - from pg_tracing_peek_spans where parent_id=:'span_a_id' and span_type='Executor' and span_operation='ExecutorRun' \gset -SELECT span_id AS span_i_id, - get_span_start(span_start) as span_i_start, - get_span_end(span_start) as span_i_end - from pg_tracing_peek_spans where parent_id=:'span_e_id' and span_type='Select query' \gset -SELECT span_id AS span_j_id, - get_span_start(span_start) as span_j_start, - get_span_end(span_start) as span_j_end - from pg_tracing_peek_spans where parent_id=:'span_i_id' and span_operation='ExecutorRun' \gset --- Check that spans' start and end are within expection -SELECT :span_a_start <= :span_e_start AS top_query_before_run, - :span_a_end >= :span_e_end AS top_ends_after_run_end; - top_query_before_run | top_ends_after_run_end -----------------------+------------------------ - t | t -(1 row) - --- Check that the root span is the longest one -WITH max_end AS (select max(span_end) from pg_tracing_peek_spans) -SELECT span_end = max_end.max from pg_tracing_peek_spans, max_end - where span_id = :'span_a_id'; - ?column? ----------- - t -(1 row) - --- Check tracking with top tracking -SET pg_tracing.track = 'top'; -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000052-0000000000000052-01'*/ select test_function_project_set(1); - test_function_project_set ---------------------------- -(0 rows) - -SELECT count(*) from pg_tracing_consume_spans where trace_id='00000000000000000000000000000052'; - count -------- - 3 -(1 row) - --- Check tracking with no tracking -SET pg_tracing.track = 'none'; -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000053-0000000000000053-01'*/ select test_function_project_set(1); - test_function_project_set ---------------------------- -(0 rows) - -SELECT count(*) from pg_tracing_consume_spans where trace_id='00000000000000000000000000000053'; - count -------- - 0 -(1 row) - --- Reset tracking setting -SET pg_tracing.track TO DEFAULT; --- Create test procedure -CREATE OR REPLACE PROCEDURE sum_one(i int) AS $$ -DECLARE - r int; -BEGIN - SELECT (i + i)::int INTO r; -END; $$ LANGUAGE plpgsql; --- Test tracking of procedure with utility tracking enabled -SET pg_tracing.track_utility=on; -/*traceparent='00-00000000000000000000000000000054-0000000000000054-01'*/ CALL sum_one(3); -select span_operation, lvl FROM peek_ordered_spans where trace_id='00000000000000000000000000000054'; - span_operation | lvl ----------------------+----- - CALL sum_one($1); | 1 - ProcessUtility | 2 - SELECT (i + i)::int | 3 - Planner | 4 - Planner | 4 - ExecutorRun | 4 -(6 rows) - --- Test again with utility tracking disabled -SET pg_tracing.track_utility=off; -/*traceparent='00-00000000000000000000000000000055-0000000000000055-01'*/ CALL sum_one(10); -select span_operation, lvl FROM peek_ordered_spans where trace_id='00000000000000000000000000000055'; - span_operation | lvl -----------------+----- -(0 rows) - --- Create immutable function -CREATE OR REPLACE FUNCTION test_immutable_function(a int) RETURNS oid -AS 'SELECT oid from pg_class where oid = a;' -LANGUAGE sql IMMUTABLE; -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000056-0000000000000056-01'*/ select test_immutable_function(1); - test_immutable_function -------------------------- - -(1 row) - -select span_operation, lvl FROM peek_ordered_spans where trace_id='00000000000000000000000000000056'; - span_operation | lvl --------------------------------------+----- - select test_immutable_function($1); | 1 - Planner | 2 - Planner | 3 - ExecutorRun | 2 -(4 rows) - --- +-------------------------------------------------------------------+ --- | A: Select test_function(1); | --- +-+----------++----------------++-------------------------------+---+ --- |C: Planner||D: ExecutorStart||E: ExecutorRun | --- +----------++----------------+++------------------------------+ --- |H: Insert INTO... | --- +--+--------------+---+ --- |I: ExecutorRun| --- +--------------+ --- Check function with result node -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000058-0000000000000058-01'*/ select test_function_result(1, 'test'); - test_function_result ----------------------- - -(1 row) - --- Gather span_id, span start and span end of function call statement -SELECT span_id AS span_a_id, - get_span_start(span_start) as span_a_start, - get_span_end(span_start) as span_a_end - from pg_tracing_peek_spans where parent_id='0000000000000058' \gset -SELECT span_id AS span_e_id, - get_span_start(span_start) as span_e_start, - get_span_end(span_start) as span_e_end - from pg_tracing_peek_spans where parent_id=:'span_a_id' and span_type='Executor' and span_operation='ExecutorRun' \gset -SELECT span_id AS span_h_id, - get_span_start(span_start) as span_h_start, - get_span_end(span_start) as span_h_end - from pg_tracing_peek_spans where parent_id=:'span_e_id' and span_type='Insert query' \gset -select span_operation, lvl FROM peek_ordered_spans where trace_id='00000000000000000000000000000058'; - span_operation | lvl --------------------------------------------------+----- - select test_function_result($1, $2); | 1 - Planner | 2 - ExecutorRun | 2 - INSERT INTO pg_tracing_test(a, b) VALUES (a, b) | 3 - Planner | 4 - ExecutorRun | 4 -(6 rows) - --- Cleanup -CALL clean_spans(); diff --git a/tests/17/expected/reset.out b/tests/17/expected/reset.out deleted file mode 100644 index 2e0c903..0000000 --- a/tests/17/expected/reset.out +++ /dev/null @@ -1,13 +0,0 @@ --- Check reset is working -SELECT pg_tracing_reset(); - pg_tracing_reset ------------------- - -(1 row) - -SELECT traces from pg_tracing_info; - traces --------- - 0 -(1 row) - diff --git a/tests/17/expected/sample.out b/tests/17/expected/sample.out deleted file mode 100644 index 3648340..0000000 --- a/tests/17/expected/sample.out +++ /dev/null @@ -1,154 +0,0 @@ --- Trace nothing -SET pg_tracing.sample_rate = 0.0; -SET pg_tracing.caller_sample_rate = 0.0; --- Query with sampling flag -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000001-0000000000000001-01'*/ SELECT 1; - ?column? ----------- - 1 -(1 row) - -select count(distinct(trace_id))=0 from pg_tracing_consume_spans; - ?column? ----------- - t -(1 row) - --- Query without trace context -SELECT 1; - ?column? ----------- - 1 -(1 row) - -select count(distinct(trace_id))=0 from pg_tracing_consume_spans; - ?column? ----------- - t -(1 row) - --- Enable full sampling -SET pg_tracing.sample_rate = 1.0; --- Generate queries with sampling flag on, off and no trace context -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000002-0000000000000002-01'*/ SELECT 1; - ?column? ----------- - 1 -(1 row) - -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000003-0000000000000003-00'*/ SELECT 2; - ?column? ----------- - 2 -(1 row) - -SELECT 3; - ?column? ----------- - 3 -(1 row) - -SELECT 4; - ?column? ----------- - 4 -(1 row) - --- Check number of generated spans -select count(distinct(trace_id)) from pg_tracing_peek_spans; - count -------- - 4 -(1 row) - --- Check span order for full sampling -select span_operation, parameters, lvl from peek_ordered_spans; - span_operation | parameters | lvl -----------------+------------+----- - SELECT $1; | $1 = 1 | 1 - Planner | | 2 - ExecutorRun | | 2 - SELECT $1; | $1 = 2 | 1 - Planner | | 2 - ExecutorRun | | 2 - SELECT $1; | $1 = 3 | 1 - Planner | | 2 - ExecutorRun | | 2 - SELECT $1; | $1 = 4 | 1 - Planner | | 2 - ExecutorRun | | 2 -(12 rows) - --- Top spans should reuse generated ids and have trace_id = parent_id -select span_operation, parameters from peek_ordered_spans where right(trace_id, 16) = parent_id; - span_operation | parameters -----------------+------------ - SELECT $1; | $1 = 1 - SELECT $1; | $1 = 2 - SELECT $1; | $1 = 3 - SELECT $1; | $1 = 4 -(4 rows) - -CALL clean_spans(); --- Only trace query with sampled flag -SET pg_tracing.sample_rate = 0.0; -SET pg_tracing.caller_sample_rate = 1.0; --- Clean set call spans -CALL clean_spans(); --- Generate queries with sampling flag on, off, no trace context and SQLComment at the end -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000004-0000000000000004-01'*/ SELECT 1; - ?column? ----------- - 1 -(1 row) - -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000005-0000000000000005-00'*/ SELECT 2; - ?column? ----------- - 2 -(1 row) - -SELECT 3 /*dddbs='postgres.db',traceparent='00-00000000000000000000000000000006-0000000000000006-01'*/; - ?column? ----------- - 3 -(1 row) - -/*dddbs='postgres.db',traceparent='00-fffffffffffffffff000000000000007-0000000000000007-01'*/ SELECT 4; - ?column? ----------- - 4 -(1 row) - -SELECT 1; - ?column? ----------- - 1 -(1 row) - --- Check number of generated spans -select distinct(trace_id) from pg_tracing_peek_spans order by trace_id; - trace_id ----------------------------------- - 00000000000000000000000000000004 - 00000000000000000000000000000006 - fffffffffffffffff000000000000007 -(3 rows) - --- Check span order for sampled flag only -select span_operation, parameters, lvl from peek_ordered_spans; - span_operation | parameters | lvl -----------------+------------+----- - SELECT $1; | $1 = 1 | 1 - Planner | | 2 - ExecutorRun | | 2 - SELECT $1; | $1 = 3 | 1 - Planner | | 2 - ExecutorRun | | 2 - SELECT $1; | $1 = 4 | 1 - Planner | | 2 - ExecutorRun | | 2 -(9 rows) - --- Cleaning -CALL clean_spans(); diff --git a/tests/17/expected/select.out b/tests/17/expected/select.out deleted file mode 100644 index ee0b5d6..0000000 --- a/tests/17/expected/select.out +++ /dev/null @@ -1,251 +0,0 @@ --- Only trace queries with sample flag -SET pg_tracing.sample_rate = 0.0; -SET pg_tracing.caller_sample_rate = 1.0; --- Run a simple query -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000001-0000000000000001-01'*/ SELECT 1; - ?column? ----------- - 1 -(1 row) - --- Get top span id -SELECT span_id AS top_span_id from pg_tracing_peek_spans where parent_id='0000000000000001' and span_type!='Parse' \gset --- Check parameters -SELECT parameters from pg_tracing_peek_spans where span_id=:'top_span_id'; - parameters ------------- - $1 = 1 -(1 row) - --- Check the number of children -SELECT count(*) from pg_tracing_peek_spans where parent_id=:'top_span_id'; - count -------- - 2 -(1 row) - --- Check span_operation -SELECT span_type, span_operation from pg_tracing_peek_spans where trace_id='00000000000000000000000000000001' order by span_start, span_end desc; - span_type | span_operation ---------------+---------------- - Select query | SELECT $1; - Planner | Planner - Executor | ExecutorRun -(3 rows) - --- Check count of query_id -SELECT count(distinct query_id) from pg_tracing_consume_spans where trace_id='00000000000000000000000000000001'; - count -------- - 1 -(1 row) - --- Check reported number of trace -SELECT traces from pg_tracing_info; - traces --------- - 26 -(1 row) - --- Trace a statement with function call -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000003-0000000000000003-01'*/ SELECT count(*) from current_database(); - count -------- - 1 -(1 row) - --- Check the generated span span_type, span_operation and order of function call -SELECT span_type, span_operation, lvl FROM peek_ordered_spans where trace_id='00000000000000000000000000000003'; - span_type | span_operation | lvl ---------------+------------------------------------------+----- - Select query | SELECT count(*) from current_database(); | 1 - Planner | Planner | 2 - Executor | ExecutorRun | 2 -(3 rows) - --- Trace a more complex query with multiple function calls -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000004-0000000000000004-01'*/ SELECT s.relation_size + s.index_size -FROM (SELECT - pg_relation_size(C.oid) as relation_size, - pg_indexes_size(C.oid) as index_size - FROM pg_class C) as s limit 1; - ?column? ----------- - 0 -(1 row) - --- Check the nested level of spans for a query with multiple function calls -SELECT span_type, span_operation, lvl FROM peek_ordered_spans where trace_id='00000000000000000000000000000004'; - span_type | span_operation | lvl ---------------+------------------------------------------------------------------------------------------------------------------------------------------------------------------+----- - Select query | SELECT s.relation_size + s.index_sizeFROM (SELECT pg_relation_size(C.oid) as relation_size, pg_indexes_size(C.oid) as index_size FROM pg_class C) as s limit $1; | 1 - Planner | Planner | 2 - Executor | ExecutorRun | 2 -(3 rows) - --- Check that we're in a correct state after a timeout -set statement_timeout=200; --- Trace query triggering a statement timeout -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000007-0000000000000007-01'*/ select * from pg_sleep(10); -ERROR: canceling statement due to statement timeout -SELECT span_type, span_operation, sql_error_code, lvl FROM peek_ordered_spans where trace_id='00000000000000000000000000000007'; - span_type | span_operation | sql_error_code | lvl ---------------+-----------------------------+----------------+----- - Select query | select * from pg_sleep($1); | 57014 | 1 - Planner | Planner | 00000 | 2 - Executor | ExecutorRun | 57014 | 2 -(3 rows) - --- Cleanup statement setting -set statement_timeout=0; --- Trace a working query after the timeout to check we're in a consistent state -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000008-0000000000000008-01'*/ select 1; - ?column? ----------- - 1 -(1 row) - --- Check the spans order and error code -SELECT span_type, span_operation, sql_error_code, lvl FROM peek_ordered_spans where trace_id='00000000000000000000000000000008'; - span_type | span_operation | sql_error_code | lvl ---------------+----------------+----------------+----- - Select query | select $1; | 00000 | 1 - Planner | Planner | 00000 | 2 - Executor | ExecutorRun | 00000 | 2 -(3 rows) - --- Cleanup -SET plan_cache_mode='auto'; --- Run a statement with node not executed -/*dddbs='postgres.db',traceparent='00-0000000000000000000000000000000b-000000000000000b-01'*/ select 1 limit 0; - ?column? ----------- -(0 rows) - -SELECT span_operation, parameters, lvl from peek_ordered_spans where trace_id='0000000000000000000000000000000b'; - span_operation | parameters | lvl ----------------------+----------------+----- - select $1 limit $2; | $1 = 1, $2 = 0 | 1 - Planner | | 2 - ExecutorRun | | 2 -(3 rows) - --- Test multiple statements in a single query -/*dddbs='postgres.db',traceparent='00-0000000000000000000000000000000c-000000000000000c-01'*/ select 1; select 2; - ?column? ----------- - 1 -(1 row) - - ?column? ----------- - 2 -(1 row) - -SELECT span_operation, parameters, lvl from peek_ordered_spans where trace_id='0000000000000000000000000000000c'; - span_operation | parameters | lvl -----------------+------------+----- - select $1; | $1 = 1 | 1 - Planner | | 2 - ExecutorRun | | 2 -(3 rows) - --- Check that parameters are not exported when disabled -SET pg_tracing.export_parameters=false; -/*dddbs='postgres.db',traceparent='00-0000000000000000000000000000000d-000000000000000d-01'*/ select 1, 2, 3; - ?column? | ?column? | ?column? -----------+----------+---------- - 1 | 2 | 3 -(1 row) - -SELECT span_operation, parameters, lvl from peek_ordered_spans where trace_id='0000000000000000000000000000000d'; - span_operation | parameters | lvl ---------------------+------------+----- - select $1, $2, $3; | | 1 - Planner | | 2 - ExecutorRun | | 2 -(3 rows) - -SET pg_tracing.export_parameters=true; --- Check multi statement query -CALL clean_spans(); -SET pg_tracing.sample_rate = 1.0; --- Force a multi-query statement with \; -SELECT 1\; SELECT 1, 2; - ?column? ----------- - 1 -(1 row) - - ?column? | ?column? -----------+---------- - 1 | 2 -(1 row) - -SELECT span_type, span_operation, parameters, lvl from peek_ordered_spans; - span_type | span_operation | parameters | lvl ---------------+----------------+------------+----- - Select query | SELECT $1; | $1 = 1 | 1 - Planner | Planner | | 2 - Executor | ExecutorRun | | 2 -(3 rows) - -CALL clean_spans(); --- Check standalone trace -SELECT 1; - ?column? ----------- - 1 -(1 row) - --- Make sure we have unique span ids -SELECT count(span_id) from pg_tracing_consume_spans group by span_id; - count -------- - 1 - 1 - 1 -(3 rows) - --- Trigger a planner error -SELECT '\xDEADBEEF'::bytea::text::int; -ERROR: invalid input syntax for type integer: "\xdeadbeef" --- Check planner error -SELECT span_type, span_operation, parameters, sql_error_code, lvl from peek_ordered_spans; - span_type | span_operation | parameters | sql_error_code | lvl ---------------+------------------------------+-------------------+----------------+----- - Select query | SELECT $1::bytea::text::int; | $1 = '\xDEADBEEF' | 22P02 | 1 - Planner | Planner | | 22P02 | 2 -(2 rows) - -CALL clean_spans(); --- Check spans generated by lazy functions -CREATE OR REPLACE FUNCTION lazy_function(IN anyarray, OUT x anyelement) - RETURNS SETOF anyelement - LANGUAGE sql - AS 'select * from pg_catalog.generate_series(array_lower($1, 1), array_upper($1, 1), 1)'; -SELECT lazy_function('{1,2,3,4}'::int[]) FROM (VALUES (1,2)); - lazy_function ---------------- - 1 - 2 - 3 - 4 -(4 rows) - --- Check lazy function spans -SELECT span_type, span_operation, parameters, lvl from peek_ordered_spans; - span_type | span_operation | parameters | lvl -----------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------------------------------+----- - Utility query | CREATE OR REPLACE FUNCTION lazy_function(IN anyarray, OUT x anyelement) RETURNS SETOF anyelement LANGUAGE sql AS 'select * from pg_catalog.generate_series(array_lower($1, 1), array_upper($1, 1), 1)'; | | 1 - ProcessUtility | ProcessUtility | | 2 - Select query | SELECT lazy_function($1::int[]) FROM (VALUES ($2,$3)); | $1 = '{1,2,3,4}', $2 = 1, $3 = 2 | 1 - Planner | Planner | | 2 - Executor | ExecutorRun | | 2 - Select query | select * from pg_catalog.generate_series(array_lower($1, $2), array_upper($1, $3), $4) | $1 = 1, $2 = 1, $3 = 1 | 3 - Planner | Planner | | 4 -(7 rows) - --- Cleanup -SET pg_tracing.sample_rate = 0.0; -CALL clean_spans(); diff --git a/tests/17/expected/subxact.out b/tests/17/expected/subxact.out deleted file mode 100644 index a434a97..0000000 --- a/tests/17/expected/subxact.out +++ /dev/null @@ -1,43 +0,0 @@ --- Enable full sampling -SET pg_tracing.sample_rate = 1.0; --- Start a transaction with subxaction -BEGIN; -SAVEPOINT s1; -INSERT INTO pg_tracing_test VALUES(generate_series(1, 2), 'aaa'); -SAVEPOINT s2; -INSERT INTO pg_tracing_test VALUES(generate_series(1, 2), 'aaa'); -SAVEPOINT s3; -SELECT 1; - ?column? ----------- - 1 -(1 row) - -COMMIT; --- Check that subxact_count is correctly reported -select span_operation, parameters, subxact_count, lvl FROM peek_ordered_spans; - span_operation | parameters | subxact_count | lvl -------------------------------------------------------------------+----------------------------+---------------+----- - BEGIN; | | 0 | 1 - ProcessUtility | | 0 | 2 - SAVEPOINT $1; | $1 = s1 | 0 | 1 - ProcessUtility | | 0 | 2 - INSERT INTO pg_tracing_test VALUES(generate_series($1, $2), $3); | $1 = 1, $2 = 2, $3 = 'aaa' | 0 | 1 - Planner | | 0 | 2 - ExecutorRun | | 0 | 2 - SAVEPOINT $1; | $1 = s2 | 1 | 1 - ProcessUtility | | 1 | 2 - INSERT INTO pg_tracing_test VALUES(generate_series($1, $2), $3); | $1 = 1, $2 = 2, $3 = 'aaa' | 1 | 1 - Planner | | 1 | 2 - ExecutorRun | | 1 | 2 - SAVEPOINT $1; | $1 = s3 | 2 | 1 - ProcessUtility | | 2 | 2 - SELECT $1; | $1 = 1 | 2 | 1 - Planner | | 2 | 2 - ExecutorRun | | 2 | 2 - COMMIT; | | 2 | 1 - ProcessUtility | | 2 | 2 -(19 rows) - --- Cleaning -CALL clean_spans(); diff --git a/tests/17/expected/trigger.out b/tests/17/expected/trigger.out deleted file mode 100644 index 9c0b11a..0000000 --- a/tests/17/expected/trigger.out +++ /dev/null @@ -1,246 +0,0 @@ --- Only trace queries with sample flag -SET pg_tracing.sample_rate = 0.0; -SET pg_tracing.caller_sample_rate = 1.0; --- Create test tables -CREATE TABLE Employee ( - EmployeeId INT NOT NULL, - LastName VARCHAR(20) NOT NULL, - CONSTRAINT PK_Employee PRIMARY KEY (EmployeeId)); -CREATE TABLE Employee_Audit ( - EmployeeId INT NOT NULL, - LastName VARCHAR(20) NOT NULL, - EmpAdditionTime VARCHAR(20) NOT NULL); --- Create trigger functions -CREATE OR REPLACE FUNCTION employee_insert_trigger_fnc() - RETURNS trigger AS -$$ -BEGIN - INSERT INTO Employee_Audit (EmployeeId, LastName, EmpAdditionTime) - VALUES(NEW.EmployeeId,NEW.LastName,current_date); -RETURN NEW; -END; -$$ -LANGUAGE plpgsql; -CREATE OR REPLACE FUNCTION before_trigger_fnc() - RETURNS trigger AS -$$ -BEGIN - PERFORM 'SELECT 1'; -RETURN NEW; -END; -$$ -LANGUAGE plpgsql; --- Hook the insert trigger twice after each row -CREATE TRIGGER employee_insert_trigger - AFTER INSERT - ON Employee - FOR EACH ROW - EXECUTE PROCEDURE employee_insert_trigger_fnc(); -CREATE TRIGGER employee_insert_trigger_2 - AFTER INSERT - ON Employee - FOR EACH ROW - EXECUTE PROCEDURE employee_insert_trigger_fnc(); --- Call insert -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000001-0000000000000001-01'*/ INSERT INTO Employee VALUES(10,'Adams'); --- --- +--------------------------------------------------------------------------------------------------------+ --- | B: INSERT INTO Employee | --- ++----------+-+--------------+---------------------------------------------------------------------------+ --- |C: Planner| |D: ExecutorRun| G: ExecutorFinish | --- +----------+ +--------------+--+-----------------------------------+-+--------------------------------+ --- |I: INSERT INTO Employee_Audit... | |N: INSERT INTO Employee_Audit...| --- +-+----------++--------------------++ +--------------------------------+ --- |J: Planner||K: ExecutorRun | |O: ExecutorRun | --- +----------++--------------------+ +---------------+ --- Gather span_id, span start and span end of call with triggers -SELECT span_id AS span_b_id, - get_span_start(span_start) as span_b_start, - get_span_end(span_start) as span_b_end - from pg_tracing_peek_spans where parent_id='0000000000000001' \gset -SELECT span_id AS span_c_id, - get_span_start(span_start) as span_c_start, - get_span_end(span_start) as span_c_end - from pg_tracing_peek_spans where parent_id=:'span_b_id' and span_type='Planner' \gset -SELECT span_id AS span_d_id, - get_span_start(span_start) as span_d_start, - get_span_end(span_start) as span_d_end - from pg_tracing_peek_spans where parent_id=:'span_b_id' and span_type='Executor' and span_operation='ExecutorRun' \gset --- Executor Finish, first trigger -SELECT span_id AS span_g_id, - get_span_start(span_start) as span_g_start, - get_span_end(span_start) as span_g_end - from pg_tracing_peek_spans where parent_id=:'span_b_id' and span_type='Executor' and span_operation='ExecutorFinish' \gset -SELECT span_id AS span_i_id, - get_span_start(span_start) as span_i_start, - get_span_end(span_start) as span_i_end - from pg_tracing_peek_spans where parent_id=:'span_g_id' and span_type='Insert query' limit 1 \gset -SELECT span_id AS span_j_id, - get_span_start(span_start) as span_j_start, - get_span_end(span_start) as span_j_end - from pg_tracing_peek_spans where parent_id=:'span_i_id' and span_type='Planner' \gset -SELECT span_id AS span_k_id, - get_span_start(span_start) as span_k_start, - get_span_end(span_start) as span_k_end - from pg_tracing_peek_spans where parent_id=:'span_i_id' and span_type='Executor' and span_operation='ExecutorRun' \gset --- Executor Finish, second trigger -SELECT span_id AS span_n_id, - get_span_start(span_start) as span_n_start, - get_span_end(span_start) as span_n_end - from pg_tracing_peek_spans where parent_id=:'span_g_id' and span_type='Insert query' limit 1 offset 1 \gset -SELECT span_id AS span_o_id, - get_span_start(span_start) as span_o_start, - get_span_end(span_start) as span_o_end - from pg_tracing_peek_spans where parent_id=:'span_n_id' and span_type='Executor' and span_operation='ExecutorRun' \gset --- Check that spans' start and end are within expection --- Planner -SELECT :span_c_start >= :span_b_start as planner_starts_after_root_span; - planner_starts_after_root_span --------------------------------- - t -(1 row) - --- ExecutorRun -SELECT :span_d_start >= :span_c_end as executor_run_starts_after_planner, - :span_d_end <= :span_g_start as executor_run_ends_before_finish; - executor_run_starts_after_planner | executor_run_ends_before_finish ------------------------------------+--------------------------------- - t | t -(1 row) - --- ExecutorFinish -SELECT :span_g_start <= :span_i_start as executor_finish_starts_before_child, - :span_g_end >= :span_o_end as executor_finish_ends_after_child; - executor_finish_starts_before_child | executor_finish_ends_after_child --------------------------------------+---------------------------------- - t | t -(1 row) - --- First trigger -SELECT :span_i_end >= :span_n_end as first_trigger_ends_after_child; - first_trigger_ends_after_child --------------------------------- - t -(1 row) - --- Second trigger -SELECT :span_o_start >= :span_i_end as second_trigger_starts_after_first, - :span_o_end >= :span_o_end as second_trigger_ends_after_child, - :span_o_end <= :span_g_end as second_trigger_ends_before_executorfinish_end, - :span_n_end <= :span_g_end as second_trigger_ends_before_root_executorfinish_end; - second_trigger_starts_after_first | second_trigger_ends_after_child | second_trigger_ends_before_executorfinish_end | second_trigger_ends_before_root_executorfinish_end ------------------------------------+---------------------------------+-----------------------------------------------+---------------------------------------------------- - t | t | t | t -(1 row) - --- Check span_operation -SELECT span_type, span_operation, lvl from peek_ordered_spans where trace_id='00000000000000000000000000000001'; - span_type | span_operation | lvl ---------------+---------------------------------------------------------------------------------------------------------------------+----- - Insert query | INSERT INTO Employee VALUES($1,$2); | 1 - Planner | Planner | 2 - Executor | ExecutorRun | 2 - Executor | ExecutorFinish | 2 - Insert query | INSERT INTO Employee_Audit (EmployeeId, LastName, EmpAdditionTime) VALUES(NEW.EmployeeId,NEW.LastName,current_date) | 3 - Planner | Planner | 4 - Executor | ExecutorRun | 4 - Insert query | INSERT INTO Employee_Audit (EmployeeId, LastName, EmpAdditionTime) VALUES(NEW.EmployeeId,NEW.LastName,current_date) | 3 - Planner | Planner | 4 - Executor | ExecutorRun | 4 -(10 rows) - --- Check count of query_id -SELECT count(distinct query_id) from pg_tracing_consume_spans where trace_id='00000000000000000000000000000001'; - count -------- - 2 -(1 row) - --- Test table to test before trigger -CREATE TABLE before_trigger_table (a int); --- Hook the before trigger -CREATE TRIGGER employee_insert_trigger - BEFORE INSERT - ON before_trigger_table - FOR EACH ROW - EXECUTE PROCEDURE before_trigger_fnc(); -CREATE TRIGGER employee_update_trigger - BEFORE UPDATE - ON before_trigger_table - FOR EACH ROW - EXECUTE PROCEDURE before_trigger_fnc(); -CREATE TRIGGER employee_delete_trigger - BEFORE DELETE - ON before_trigger_table - FOR EACH ROW - EXECUTE PROCEDURE before_trigger_fnc(); --- Test explain on a before trigger --- This will go through ExecutorEnd without any parent executor run -/*dddbs='postgres.db',traceparent='00-fed00000000000000000000000000001-0000000000000003-01'*/ explain INSERT INTO before_trigger_table VALUES(10); - QUERY PLAN ------------------------------------------------------------------- - Insert on before_trigger_table (cost=0.00..0.01 rows=0 width=0) - -> Result (cost=0.00..0.01 rows=1 width=4) -(2 rows) - -SELECT span_type, span_operation, lvl from peek_ordered_spans where trace_id='fed00000000000000000000000000001'; - span_type | span_operation | lvl -----------------+------------------------------------------------------+----- - Utility query | explain INSERT INTO before_trigger_table VALUES($1); | 1 - ProcessUtility | ProcessUtility | 2 - Insert query | explain INSERT INTO before_trigger_table VALUES($1); | 3 - Planner | Planner | 4 -(4 rows) - --- Call before trigger insert -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000002-0000000000000002-01'*/ INSERT INTO before_trigger_table SELECT generate_series(1,2); -SELECT span_type, span_operation, lvl from peek_ordered_spans where trace_id='00000000000000000000000000000002'; - span_type | span_operation | lvl ---------------+-----------------------------------------------------------------+----- - Insert query | INSERT INTO before_trigger_table SELECT generate_series($1,$2); | 1 - Planner | Planner | 2 - Executor | ExecutorRun | 2 - Select query | SELECT $1 | 3 - Planner | Planner | 4 - Executor | ExecutorRun | 4 - Select query | SELECT 'SELECT 1' | 3 - Executor | ExecutorRun | 4 -(8 rows) - --- Call before trigger update -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000003-0000000000000003-01'*/ UPDATE before_trigger_table set a=1; -SELECT span_type, span_operation, lvl from peek_ordered_spans where trace_id='00000000000000000000000000000003'; - span_type | span_operation | lvl ---------------+---------------------------------------+----- - Update query | UPDATE before_trigger_table set a=$1; | 1 - Planner | Planner | 2 - Executor | ExecutorRun | 2 - Select query | SELECT $1 | 3 - Planner | Planner | 4 - Executor | ExecutorRun | 4 - Select query | SELECT 'SELECT 1' | 3 - Executor | ExecutorRun | 4 -(8 rows) - --- Call before trigger delete -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000004-0000000000000004-01'*/ DELETE FROM before_trigger_table where a=1; -SELECT span_type, span_operation, lvl from peek_ordered_spans where trace_id='00000000000000000000000000000004'; - span_type | span_operation | lvl ---------------+----------------------------------------------+----- - Delete query | DELETE FROM before_trigger_table where a=$1; | 1 - Planner | Planner | 2 - Executor | ExecutorRun | 2 - Select query | SELECT $1 | 3 - Planner | Planner | 4 - Executor | ExecutorRun | 4 - Select query | SELECT 'SELECT 1' | 3 - Executor | ExecutorRun | 4 -(8 rows) - --- Check count of query_id -SELECT count(distinct query_id) from pg_tracing_consume_spans; - count -------- - 6 -(1 row) - diff --git a/tests/17/expected/utility.out b/tests/17/expected/utility.out deleted file mode 100644 index bf4d787..0000000 --- a/tests/17/expected/utility.out +++ /dev/null @@ -1,270 +0,0 @@ --- Some helper functions -CREATE OR REPLACE FUNCTION get_span_start(time_start timestamptz) RETURNS bigint AS -$BODY$ - SELECT extract(epoch from time_start); -$BODY$ -LANGUAGE sql; -CREATE OR REPLACE FUNCTION get_span_end(time_end timestamptz) RETURNS bigint AS -$BODY$ -BEGIN - RETURN extract(epoch from time_end); -END; -$BODY$ -LANGUAGE plpgsql; -CREATE OR REPLACE FUNCTION get_span_end(time_end timestamptz) RETURNS bigint AS -$BODY$ -BEGIN - RETURN extract(epoch from time_end); -END; -$BODY$ -LANGUAGE plpgsql; -CREATE OR REPLACE PROCEDURE clean_spans() AS $$ -BEGIN - PERFORM count(*) from pg_tracing_consume_spans; -END; -$$ LANGUAGE plpgsql; --- Create pg_tracing extension with sampling on -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000001-0000000000000001-01'*/ CREATE EXTENSION pg_tracing; --- This will create the following spans (non exhaustive list): --- --- +-------------------------------------------------------------------------------------+ --- | A: Utility: Create Extension | --- +-+-----------------------------------------------------------------------------------+ --- +----------------------------------------------------------------------------------+ --- |B: ProcessUtility: Create Extension | --- +---+-----------------------------------+---+--------------------------------------+ --- +-----------------------------------+ +-------------------------------------+ --- |C: Utility: Create Function1 | |E: Utility: Create Function2 | --- ++----------------------------------+ ++-----------------------------------++ --- +----------------------------------+ +-----------------------------------+ --- |D: ProcessUtility: Create Function| |F: ProcessUtility: Create Function2| --- +----------------------------------+ +-----------------------------------+ --- Extract span_ids, start and end of those spans -SELECT span_id AS span_a_id, - get_span_start(span_start) as span_a_start, - get_span_end(span_start) as span_a_end - from pg_tracing_peek_spans where parent_id='0000000000000001' and span_type='Utility query' \gset -SELECT span_id AS span_b_id, - get_span_start(span_start) as span_b_start, - get_span_end(span_start) as span_b_end - from pg_tracing_peek_spans where parent_id=:'span_a_id' and span_type='ProcessUtility' \gset -SELECT span_id AS span_c_id, - get_span_start(span_start) as span_c_start, - get_span_end(span_start) as span_c_end - from pg_tracing_peek_spans where parent_id=:'span_b_id' and span_type='Utility query' limit 1 \gset -SELECT span_id AS span_d_id, - get_span_start(span_start) as span_d_start, - get_span_end(span_start) as span_d_end - from pg_tracing_peek_spans where parent_id=:'span_c_id' and span_type='ProcessUtility' \gset -SELECT span_id AS span_e_id, - get_span_start(span_start) as span_e_start, - get_span_end(span_start) as span_e_end - from pg_tracing_peek_spans where parent_id=:'span_b_id' and span_type='Utility query' limit 1 offset 1 \gset --- Check that the start and end of those spans are within expectation -SELECT :span_a_start <= :span_b_start AS span_a_starts_first, - :span_a_end >= :span_b_end AS span_a_ends_last, - :span_d_end <= :span_c_end AS nested_span_ends_before_parent, - :span_c_end <= :span_e_start AS next_utility_starts_after; - span_a_starts_first | span_a_ends_last | nested_span_ends_before_parent | next_utility_starts_after ----------------------+------------------+--------------------------------+--------------------------- - t | t | t | t -(1 row) - --- Clean current spans -CALL clean_spans(); --- --- Test that no utility is captured with track_utility off --- --- Set utility off -SET pg_tracing.track_utility = off; --- Test utility tracking disabled + full sampling -SET pg_tracing.sample_rate = 1.0; -DROP EXTENSION pg_tracing; -CREATE EXTENSION pg_tracing; -SET pg_tracing.sample_rate = 0.0; --- View displaying spans with their nested level -CREATE VIEW peek_spans_with_level AS - WITH RECURSIVE list_trace_spans(trace_id, parent_id, span_id, query_id, span_type, span_operation, span_start, span_end, sql_error_code, userid, dbid, pid, subxact_count, plan_startup_cost, plan_total_cost, plan_rows, plan_width, rows, nloops, shared_blks_hit, shared_blks_read, shared_blks_dirtied, shared_blks_written, local_blks_hit, local_blks_read, local_blks_dirtied, local_blks_written, blk_read_time, blk_write_time, temp_blks_read, temp_blks_written, temp_blk_read_time, temp_blk_write_time, wal_records, wal_fpi, wal_bytes, jit_functions, jit_generation_time, jit_inlining_time, jit_optimization_time, jit_emission_time, startup, parameters, lvl) AS ( - SELECT p.*, 1 - FROM pg_tracing_peek_spans p where not parent_id=ANY(SELECT span_id from pg_tracing_peek_spans) - UNION ALL - SELECT s.*, lvl + 1 - FROM pg_tracing_peek_spans s, list_trace_spans st - WHERE s.parent_id = st.span_id - ) SELECT * FROM list_trace_spans; --- Create utility view to keep order stable -CREATE VIEW peek_ordered_spans AS - SELECT * FROM peek_spans_with_level order by span_start, lvl, span_end; --- Nothing should have been generated -select count(*) = 0 from pg_tracing_consume_spans; - ?column? ----------- - t -(1 row) - --- Prepare and execute a prepared statement -PREPARE test_prepared_one_param (integer) AS SELECT $1; -EXECUTE test_prepared_one_param(100); - ?column? ----------- - 100 -(1 row) - --- Nothing should be generated -select count(*) = 0 from pg_tracing_consume_spans; - ?column? ----------- - t -(1 row) - --- Force a query to start from ExecutorRun -SET plan_cache_mode='force_generic_plan'; -EXECUTE test_prepared_one_param(200); - ?column? ----------- - 200 -(1 row) - -SET plan_cache_mode TO DEFAULT; --- Again, nothing should be generated -select count(*) = 0 from pg_tracing_consume_spans; - ?column? ----------- - t -(1 row) - --- --- Test that no utility is captured with track_utility off --- --- Enable utility tracking and track everything -SET pg_tracing.track_utility = on; -SET pg_tracing.sample_rate = 1.0; --- Prepare and execute a prepared statement -PREPARE test_prepared_one_param_2 (integer) AS SELECT $1; -EXECUTE test_prepared_one_param_2(100); - ?column? ----------- - 100 -(1 row) - --- Check the number of generated spans -select count(distinct(trace_id)) from pg_tracing_peek_spans; - count -------- - 2 -(1 row) - --- Check spans of test_prepared_one_param_2 execution -select span_operation, parameters, lvl from peek_ordered_spans; - span_operation | parameters | lvl ------------------------------------------------------------+------------+----- - PREPARE test_prepared_one_param_2 (integer) AS SELECT $1; | | 1 - ProcessUtility | | 2 - PREPARE test_prepared_one_param_2 (integer) AS SELECT $1; | | 3 - EXECUTE test_prepared_one_param_2(100); | | 1 - ProcessUtility | | 2 - PREPARE test_prepared_one_param_2 (integer) AS SELECT $1; | $1 = '100' | 3 - Planner | | 4 - ExecutorRun | | 4 -(8 rows) - --- Check the top span (standalone top span has trace_id=parent_id) -select span_operation, parameters, lvl from peek_ordered_spans where right(trace_id, 16) = parent_id; - span_operation | parameters | lvl ------------------------------------------------------------+------------+----- - PREPARE test_prepared_one_param_2 (integer) AS SELECT $1; | | 1 - EXECUTE test_prepared_one_param_2(100); | | 1 -(2 rows) - -CALL clean_spans(); --- Test prepared statement with generic plan -SET plan_cache_mode='force_generic_plan'; -EXECUTE test_prepared_one_param(200); - ?column? ----------- - 200 -(1 row) - -SET plan_cache_mode TO DEFAULT; --- Check the number of generated spans -select count(distinct(trace_id)) from pg_tracing_peek_spans; - count -------- - 3 -(1 row) - --- Check spans of test_prepared_one_param execution -select span_operation, parameters, lvl from peek_ordered_spans; - span_operation | parameters | lvl ----------------------------------------------------------+------------+----- - SET plan_cache_mode='force_generic_plan'; | | 1 - ProcessUtility | | 2 - EXECUTE test_prepared_one_param(200); | | 1 - ProcessUtility | | 2 - PREPARE test_prepared_one_param (integer) AS SELECT $1; | | 3 - ExecutorRun | | 4 - SET plan_cache_mode TO DEFAULT; | | 1 - ProcessUtility | | 2 -(8 rows) - --- Check the top span (standalone top span has trace_id=parent_id) -select span_operation, parameters, lvl from peek_ordered_spans where right(trace_id, 16) = parent_id; - span_operation | parameters | lvl --------------------------------------------+------------+----- - SET plan_cache_mode='force_generic_plan'; | | 1 - EXECUTE test_prepared_one_param(200); | | 1 - SET plan_cache_mode TO DEFAULT; | | 1 -(3 rows) - -CALL clean_spans(); --- Second create extension should generate an error that is captured by span -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000001-0000000000000001-01'*/ CREATE EXTENSION pg_tracing; -ERROR: extension "pg_tracing" already exists -select span_operation, parameters, sql_error_code, lvl from peek_ordered_spans where trace_id='00000000000000000000000000000001'; - span_operation | parameters | sql_error_code | lvl -------------------------------+------------+----------------+----- - CREATE EXTENSION pg_tracing; | | 42710 | 1 - ProcessUtility | | 42710 | 2 -(2 rows) - --- Create test table -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000002-0000000000000002-01'*/ CREATE TABLE pg_tracing_test (a int, b char(20)); --- Check create table spans -select trace_id, span_type, span_operation, lvl from peek_ordered_spans where trace_id='00000000000000000000000000000002'; - trace_id | span_type | span_operation | lvl -----------------------------------+----------------+---------------------------------------------------+----- - 00000000000000000000000000000002 | Utility query | CREATE TABLE pg_tracing_test (a int, b char(20)); | 1 - 00000000000000000000000000000002 | ProcessUtility | ProcessUtility | 2 -(2 rows) - -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000003-0000000000000003-01'*/ CREATE INDEX pg_tracing_index ON pg_tracing_test (a); --- Check create index spans -select trace_id, span_type, span_operation, lvl from peek_ordered_spans where trace_id='00000000000000000000000000000003'; - trace_id | span_type | span_operation | lvl -----------------------------------+----------------+-------------------------------------------------------+----- - 00000000000000000000000000000003 | Utility query | CREATE INDEX pg_tracing_index ON pg_tracing_test (a); | 1 - 00000000000000000000000000000003 | ProcessUtility | ProcessUtility | 2 -(2 rows) - -CREATE OR REPLACE FUNCTION function_with_error(IN anyarray, OUT x anyelement, OUT n int) - RETURNS SETOF RECORD - LANGUAGE sql STRICT IMMUTABLE PARALLEL SAFE - AS 'select s from pg_catalog.generate_series(1, 1, 1) as g(s)'; --- Check that tracing a function call with the wrong number of arguments is managed correctly -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000004-0000000000000004-01'*/ select function_with_error('{1,2,3}'::int[]); -ERROR: return type mismatch in function declared to return record -DETAIL: Final statement returns too few columns. -CONTEXT: SQL function "function_with_error" during startup --- Check lazy function call with error -select trace_id, span_type, span_operation, sql_error_code, lvl from peek_ordered_spans where trace_id='00000000000000000000000000000004'; - trace_id | span_type | span_operation | sql_error_code | lvl -----------------------------------+--------------+--------------------------------------------------------------+----------------+----- - 00000000000000000000000000000004 | Select query | select function_with_error($1::int[]); | 42P13 | 1 - 00000000000000000000000000000004 | Planner | Planner | 00000 | 2 - 00000000000000000000000000000004 | Executor | ExecutorRun | 42P13 | 2 - 00000000000000000000000000000004 | Select query | select s from pg_catalog.generate_series($1, $2, $3) as g(s) | 00000 | 3 -(4 rows) - --- Cleanup -CALL clean_spans(); -SET pg_tracing.track_utility TO DEFAULT; diff --git a/tests/17/expected/wal.out b/tests/17/expected/wal.out deleted file mode 100644 index 9e8fa02..0000000 --- a/tests/17/expected/wal.out +++ /dev/null @@ -1,25 +0,0 @@ --- Generate queries with wal write -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000001-0000000000000001-01'*/ INSERT INTO pg_tracing_test VALUES(generate_series(1, 10), 'aaa'); -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000002-0000000000000002-01'*/ UPDATE pg_tracing_test SET b = 'bbb' WHERE a = 7; -/*dddbs='postgres.db',traceparent='00-00000000000000000000000000000003-0000000000000003-01'*/ DELETE FROM pg_tracing_test WHERE a = 9; --- Check WAL is generated for the above statements -SELECT trace_id, span_type, span_operation, - wal_records > 0 as wal_records, - wal_bytes > 0 as wal_bytes -FROM peek_ordered_spans; - trace_id | span_type | span_operation | wal_records | wal_bytes -----------------------------------+--------------+------------------------------------------------------------------+-------------+----------- - 00000000000000000000000000000001 | Insert query | INSERT INTO pg_tracing_test VALUES(generate_series($1, $2), $3); | t | t - 00000000000000000000000000000001 | Planner | Planner | f | f - 00000000000000000000000000000001 | Executor | ExecutorRun | | - 00000000000000000000000000000002 | Update query | UPDATE pg_tracing_test SET b = $1 WHERE a = $2; | t | t - 00000000000000000000000000000002 | Planner | Planner | f | f - 00000000000000000000000000000002 | Executor | ExecutorRun | | - 00000000000000000000000000000003 | Delete query | DELETE FROM pg_tracing_test WHERE a = $1; | t | t - 00000000000000000000000000000003 | Planner | Planner | f | f - 00000000000000000000000000000003 | Executor | ExecutorRun | | -(9 rows) - -CALL clean_spans(); --- Cleanup -CALL clean_spans();