comprehensive_nested_statements_test_v4.sql
application/octet-stream
Filename: comprehensive_nested_statements_test_v4.sql
Type: application/octet-stream
Part: 2
-- ============================================================================
-- NESTED_STATEMENTS Feature - Comprehensive Test Suite
-- ============================================================================
-- This script tests the NESTED_STATEMENTS feature and demonstrates
-- how nesting levels reflect the actual PostgreSQL executor call stack.
--
-- KEY INSIGHT: Nesting levels depend on HOW a function is called:
-- PERFORM func() / SELECT func() INTO var → creates new executor level
-- result := func() → same executor level as caller
-- ============================================================================
\echo '============================================================================'
\echo 'NESTED_STATEMENTS Feature - Comprehensive Test Suite'
\echo '============================================================================'
\echo ''
\echo 'This test suite demonstrates:'
\echo ' 1. Validation (NESTED_STATEMENTS requires ANALYZE)'
\echo ' 2. Simple PL/pgSQL function (all level 1)'
\echo ' 3. PERFORM pattern (creates deeper nesting levels)'
\echo ' 4. Expression assignment pattern (stays at same level)'
\echo ' 5. Comparison: PERFORM vs expression assignment'
\echo ' 6. SQL function nesting (true SQL nesting)'
\echo ' 7. Three-level chain with PERFORM'
\echo ' 8. Recursive function (increasing levels)'
\echo ' 9. Exception handling blocks'
\echo ' 10. No nested statements (plain query)'
\echo ' 11. Trigger-fired nested statements'
\echo ' 12. Combined with VERBOSE and BUFFERS options'
\echo ' 13. Statement numbering = completion order (triggers demo)'
\echo ' 14. BEGIN/ROLLBACK safety pattern'
\echo ' 15. Error during EXPLAIN does not crash (Bug 1 fix)'
\echo ' 16. Nested EXPLAIN does not crash (Bug 2 fix)'
\echo ' 17. Memory context cleanup (Bug 3 fix)'
\echo ' 18. Memory context does not grow across repeated calls'
\echo ' 19. Stress test - 50 nested statements'
\echo ' 20. Execution Time per nested statement (SUMMARY default)'
\echo ' 21. SUMMARY OFF hides timing, percentages, and summary section'
\echo ' 22. Structured output - JSON format'
\echo ' 23. Structured output - XML format'
\echo ' 24. Structured output - YAML format'
\echo ' 25. SHOW_NESTED - limit displayed plans'
\echo ' 26. SHOW_NESTED 0 - summary only'
\echo ' 27. SHOW_NESTED validation (requires NESTED_STATEMENTS)'
\echo ' 28. Nested Statements Summary with percentages'
\echo ' 29. Statement timeout — hooks cleaned up'
\echo ' 30. Dynamic SQL — query text captured correctly'
\echo ' 31. Infinite recursion — graceful error'
\echo ' 32. auto_explain compatibility'
\echo ' 33. Deep nesting (20 levels)'
\echo ' 34. All EXPLAIN options combined with SHOW_NESTED'
\echo ' 35. Performance — zero overhead when disabled'
\echo ' 36. Interpreting Total Nested Time percentage'
\echo ' 37. Multiple triggers on separate tables'
\echo ' 38. Direct DML with triggers (BEFORE + AFTER, cascading)'
\echo ' 39. BEFORE and AFTER triggers in function context'
\echo ' 40. Query Identifier integration (pg_stat_statements)'
\echo ' 41. Level-1 only counting (no double-counting with deep nesting)'
\echo ''-- ============================================================================
-- Setup: Create shared test table
-- ============================================================================
DROP TABLE IF EXISTS products CASCADE;
CREATE TABLE products (id INT, name TEXT, price NUMERIC, category TEXT);
INSERT INTO products VALUES
(1, 'Laptop', 999, 'Electronics'),
(2, 'Mouse', 29, 'Electronics'),
(3, 'Book', 19, 'Books');
-- ============================================================================
-- TEST 1: Validation
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 1: Validation - NESTED_STATEMENTS requires ANALYZE'
\echo '============================================================================'
\echo ''
\echo 'Expected: ERROR message'
\echo ''
EXPLAIN (NESTED_STATEMENTS) SELECT 1;
\echo ''
-- ============================================================================
-- TEST 2: Simple PL/pgSQL Function (All Level 1)
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 2: Simple PL/pgSQL Function - All Statements at Level 1'
\echo '============================================================================'
\echo ''
\echo 'Purpose: SQL statements in a single function all execute at level 1'
\echo ' because they run sequentially in the same executor context.'
\echo ''
CREATE OR REPLACE FUNCTION simple_function() RETURNS INTEGER AS $$
DECLARE cnt INTEGER;
BEGIN
SELECT COUNT(*) INTO cnt FROM products;
INSERT INTO products VALUES (10, 'Temp', 1, 'Temp');
UPDATE products SET price = price + 1 WHERE id = 1;
DELETE FROM products WHERE id = 10;
RETURN cnt;
END;
$$ LANGUAGE plpgsql;
\echo 'Expected: All 4 statements at level 1'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF)
SELECT simple_function();
\echo ''
-- ============================================================================
-- TEST 3: PERFORM Pattern - Creates Deeper Nesting
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 3: PERFORM Pattern - Creates Deeper Nesting Levels'
\echo '============================================================================'
\echo ''
\echo 'Purpose: PERFORM func() creates a new executor call (SELECT func()),'
\echo ' so statements inside the called function run at a deeper level.'
\echo ''
\echo 'How it works internally:'
\echo ' PERFORM func() → executes "SELECT func()" → ExecutorRun increments level'
\echo ' → func() body runs its SQL at the elevated level'
\echo ''
CREATE OR REPLACE FUNCTION inner_perform() RETURNS void AS $$
BEGIN
UPDATE products SET price = price + 1 WHERE id = 2;
INSERT INTO products VALUES (20, 'Inner', 50, 'Test');
DELETE FROM products WHERE id = 20;
END;
$$ LANGUAGE plpgsql;
CREATE OR REPLACE FUNCTION outer_perform() RETURNS void AS $$
DECLARE cnt INTEGER;
BEGIN
SELECT COUNT(*) INTO cnt FROM products; -- level 1
PERFORM inner_perform(); -- creates new executor → inner runs at level 2
UPDATE products SET price = price - 1 WHERE id = 2; -- level 1
END;
$$ LANGUAGE plpgsql;
\echo 'Expected:'
\echo ' Statement #1 (level 1): SELECT COUNT in outer_perform'
\echo ' Statement #2 (level 2): UPDATE in inner_perform'
\echo ' Statement #3 (level 2): INSERT in inner_perform'
\echo ' Statement #4 (level 2): DELETE in inner_perform'
\echo ' Statement #5 (level 1): SELECT inner_perform() [the PERFORM call]'
\echo ' Statement #6 (level 1): UPDATE in outer_perform'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF)
SELECT outer_perform();
\echo ''
-- ============================================================================
-- TEST 4: Expression Assignment - Same Level
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 4: Expression Assignment (result := func()) - Same Level'
\echo '============================================================================'
\echo ''
\echo 'Purpose: result := func() evaluates the function as an expression via'
\echo ' ExecEvalFunc WITHOUT creating a new executor call. Statements'
\echo ' inside the called function run at the SAME level as the caller.'
\echo ''
\echo 'How it works internally:'
\echo ' result := func() → ExecEvalFunc(func) → NO new ExecutorRun'
\echo ' → func() body runs its SQL at the SAME level as caller'
\echo ''
CREATE OR REPLACE FUNCTION inner_expr() RETURNS NUMERIC AS $$
DECLARE total NUMERIC;
BEGIN
SELECT SUM(price) INTO total FROM products;
UPDATE products SET price = price + 1 WHERE id = 3;
RETURN total;
END;
$$ LANGUAGE plpgsql;
CREATE OR REPLACE FUNCTION outer_expr() RETURNS TEXT AS $$
DECLARE
result NUMERIC;
cnt INTEGER;
BEGIN
SELECT COUNT(*) INTO cnt FROM products; -- level 1
result := inner_expr(); -- expression eval, inner runs at level 1 too!
DELETE FROM products WHERE price > 9999; -- level 1
RETURN 'Total: ' || result;
END;
$$ LANGUAGE plpgsql;
\echo 'Expected: ALL statements at level 1 (no deeper nesting)'
\echo ' Statement #1 (level 1): SELECT COUNT in outer_expr'
\echo ' Statement #2 (level 1): SELECT SUM in inner_expr ← same level!'
\echo ' Statement #3 (level 1): UPDATE in inner_expr ← same level!'
\echo ' Statement #4 (level 1): DELETE in outer_expr'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF)
SELECT outer_expr();
\echo ''
-- ============================================================================
-- TEST 5: Side-by-Side Comparison
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 5: PERFORM vs Expression Assignment - Side by Side'
\echo '============================================================================'
\echo ''
\echo 'Purpose: Same inner function called two different ways to show the'
\echo ' nesting level difference.'
\echo ''
CREATE OR REPLACE FUNCTION shared_inner() RETURNS INTEGER AS $$
DECLARE cnt INTEGER;
BEGIN
SELECT COUNT(*) INTO cnt FROM products WHERE category = 'Electronics';
RETURN cnt;
END;
$$ LANGUAGE plpgsql;
-- Calls via PERFORM (creates new executor level)
CREATE OR REPLACE FUNCTION caller_perform() RETURNS void AS $$
BEGIN
PERFORM shared_inner(); -- new executor → inner at level 2
END;
$$ LANGUAGE plpgsql;
-- Calls via expression assignment (same executor level)
CREATE OR REPLACE FUNCTION caller_assign() RETURNS INTEGER AS $$
DECLARE result INTEGER;
BEGIN
result := shared_inner(); -- expression eval → inner at level 1
RETURN result;
END;
$$ LANGUAGE plpgsql;
\echo '--- Via PERFORM (expect level 2 for inner SELECT): ---'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF)
SELECT caller_perform();
\echo ''
\echo '--- Via expression assignment (expect level 1 for inner SELECT): ---'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF)
SELECT caller_assign();
\echo ''
\echo 'Notice: Same function, different nesting levels depending on call pattern.'
\echo ''
-- ============================================================================
-- TEST 6: SQL Function Nesting (True SQL Nesting)
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 6: SQL Functions - True SQL Execution Nesting'
\echo '============================================================================'
\echo ''
\echo 'Purpose: SQL functions execute DURING the parent query, creating true'
\echo ' SQL nesting where inner functions complete before outer.'
\echo ''
DROP TABLE IF EXISTS t1, t2, t3 CASCADE;
CREATE TABLE t1 (id INT, data TEXT);
CREATE TABLE t2 (id INT, data TEXT);
CREATE TABLE t3 (id INT, data TEXT);
INSERT INTO t1 VALUES (1, 'A');
INSERT INTO t2 VALUES (1, 'B');
INSERT INTO t3 VALUES (1, 'C');
CREATE OR REPLACE FUNCTION sql_level3() RETURNS TEXT AS $$
SELECT data FROM t3 WHERE id = 1;
$$ LANGUAGE sql;
CREATE OR REPLACE FUNCTION sql_level2() RETURNS TEXT AS $$
SELECT data || '+' || sql_level3() FROM t2 WHERE id = 1;
$$ LANGUAGE sql;
CREATE OR REPLACE FUNCTION plpgsql_sql_caller() RETURNS TEXT AS $$
DECLARE result TEXT;
BEGIN
SELECT data || '+' || sql_level2() INTO result FROM t1 WHERE id = 1;
RETURN result;
END;
$$ LANGUAGE plpgsql;
\echo 'Expected: Deepest-first execution order (3→2→1)'
\echo ' Statement #1 (level 3): SELECT from t3 (sql_level3)'
\echo ' Statement #2 (level 2): SELECT from t2 (sql_level2)'
\echo ' Statement #3 (level 1): SELECT from t1 (plpgsql_sql_caller)'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF)
SELECT plpgsql_sql_caller();
\echo ''
-- ============================================================================
-- TEST 7: Three-Level Chain with PERFORM
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 7: Three-Level PL/pgSQL Chain (via PERFORM)'
\echo '============================================================================'
\echo ''
\echo 'Purpose: Each PERFORM adds one executor level'
\echo ''
CREATE OR REPLACE FUNCTION chain_level3() RETURNS void AS $$
BEGIN
PERFORM COUNT(*) FROM products WHERE category = 'Books';
END;
$$ LANGUAGE plpgsql;
CREATE OR REPLACE FUNCTION chain_level2() RETURNS void AS $$
BEGIN
PERFORM COUNT(*) FROM products WHERE id = 1;
PERFORM chain_level3();
END;
$$ LANGUAGE plpgsql;
CREATE OR REPLACE FUNCTION chain_level1() RETURNS void AS $$
BEGIN
PERFORM COUNT(*) FROM products;
PERFORM chain_level2();
END;
$$ LANGUAGE plpgsql;
\echo 'Expected:'
\echo ' Statement #1 (level 1): SELECT COUNT(*) FROM products'
\echo ' Statement #2 (level 2): SELECT COUNT(*) WHERE id = 1'
\echo ' Statement #3 (level 3): SELECT COUNT(*) WHERE category = Books'
\echo ' Statement #4 (level 2): SELECT chain_level3()'
\echo ' Statement #5 (level 1): SELECT chain_level2()'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF)
SELECT chain_level1();
\echo ''
-- ============================================================================
-- TEST 8: Recursive Function
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 8: Recursive Function - Increasing Nesting Levels'
\echo '============================================================================'
\echo ''
\echo 'Purpose: Recursive PERFORM calls increase the nesting level each time'
\echo ''
DROP TABLE IF EXISTS counter_log;
CREATE TABLE counter_log (depth INT, val INT);
CREATE OR REPLACE FUNCTION recursive_func(n INT) RETURNS VOID AS $$
BEGIN
INSERT INTO counter_log VALUES (n, n * 10);
IF n > 1 THEN
PERFORM recursive_func(n - 1);
END IF;
END;
$$ LANGUAGE plpgsql;
\echo 'Expected:'
\echo ' Statement #1 (level 1): INSERT with n=3'
\echo ' Statement #2 (level 2): INSERT with n=2'
\echo ' Statement #3 (level 3): INSERT with n=1'
\echo ' + PERFORM calls at levels 2 and 1'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF)
SELECT recursive_func(3);
\echo ''
-- ============================================================================
-- TEST 9: Exception Handling
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 9: Exception Handling - Statements in BEGIN/EXCEPTION Blocks'
\echo '============================================================================'
\echo ''
\echo 'Purpose: Verify statements in exception handlers are captured'
\echo ''
DROP TABLE IF EXISTS safe_table;
CREATE TABLE safe_table (id INT PRIMARY KEY, data TEXT);
INSERT INTO safe_table VALUES (1, 'existing');
CREATE OR REPLACE FUNCTION exception_func() RETURNS TEXT AS $$
BEGIN
UPDATE safe_table SET data = 'updated' WHERE id = 1;
BEGIN
INSERT INTO safe_table VALUES (1, 'duplicate'); -- will fail
EXCEPTION WHEN unique_violation THEN
UPDATE safe_table SET data = 'recovered' WHERE id = 1;
END;
RETURN 'done';
END;
$$ LANGUAGE plpgsql;
\echo 'Expected:'
\echo ' - UPDATE (level 1): initial update'
\echo ' - UPDATE (level 1): recovery in exception handler'
\echo ' - The failed INSERT is rolled back and may not appear'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF)
SELECT exception_func();
\echo ''
-- ============================================================================
-- TEST 10: No Nested Statements
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 10: No Nested Statements - Plain Query'
\echo '============================================================================'
\echo ''
\echo 'Purpose: When no nested statements execute, no "Nested Plans:" section'
\echo ''
\echo 'Expected: Normal EXPLAIN output, no Nested Plans section'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF)
SELECT * FROM products WHERE id = 1;
\echo ''
-- ============================================================================
-- TEST 11: Trigger-Fired Nested Statements
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 11: Trigger-Fired Nested Statements'
\echo '============================================================================'
\echo ''
\echo 'Purpose: Triggers fire DURING the triggering statement, creating'
\echo ' deeper nesting. Trigger-fired statements are automatically'
\echo ' detected and annotated with "(trigger)" in the header.'
\echo ' Their time is tracked separately in the summary.'
\echo ''
\echo 'What this tests:'
\echo ' - Trigger detection via nested_in_finish flag'
\echo ' - "(trigger)" annotation on trigger-fired statements'
\echo ' - Trigger statements show no percentage (time included in parent)'
\echo ' - Deeper-level direct statements show no percentage (time included in level-1 parent)'
\echo ' - Summary shows "N direct, M trigger-fired" breakdown'
\echo ' - Total Trigger Time shown separately with % of nested time'
\echo ' - Completion order: trigger finishes before parent'
\echo ''
DROP TABLE IF EXISTS orders CASCADE;
DROP TABLE IF EXISTS audit_log CASCADE;
CREATE TABLE orders (id INT PRIMARY KEY, amount NUMERIC, status TEXT);
CREATE TABLE audit_log (order_id INT, action TEXT, logged_at TIMESTAMP DEFAULT now());
CREATE OR REPLACE FUNCTION log_order_change() RETURNS TRIGGER AS $$
BEGIN
INSERT INTO audit_log (order_id, action)
VALUES (NEW.id, TG_OP || ': ' || NEW.status);
RETURN NEW;
END;
$$ LANGUAGE plpgsql;
CREATE TRIGGER order_audit_trigger
AFTER INSERT OR UPDATE ON orders
FOR EACH ROW EXECUTE FUNCTION log_order_change();
CREATE OR REPLACE FUNCTION process_order(p_id INT) RETURNS VOID AS $$
BEGIN
INSERT INTO orders VALUES (p_id, 99.99, 'new');
UPDATE orders SET status = 'processed' WHERE id = p_id;
END;
$$ LANGUAGE plpgsql;
\echo 'Expected:'
\echo ' #1 (level 2, trigger): INSERT INTO audit_log — trigger from INSERT'
\echo ' #2 (level 1): INSERT INTO orders — the triggering statement'
\echo ' #3 (level 2, trigger): INSERT INTO audit_log — trigger from UPDATE'
\echo ' #4 (level 1): UPDATE orders — the triggering statement'
\echo ''
\echo 'Summary should show: (2 direct, 2 trigger-fired)'
\echo 'Total Trigger Time shows % of nested time'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF)
SELECT process_order(1);
\echo ''
-- ============================================================================
-- TEST 12: Combined with VERBOSE and BUFFERS
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 12: NESTED_STATEMENTS with VERBOSE and BUFFERS'
\echo '============================================================================'
\echo ''
\echo 'Purpose: VERBOSE and BUFFERS options are inherited by nested plans'
\echo ''
CREATE OR REPLACE FUNCTION verbose_func() RETURNS INT AS $$
DECLARE cnt INT;
BEGIN
SELECT COUNT(*) INTO cnt FROM products;
RETURN cnt;
END;
$$ LANGUAGE plpgsql;
\echo 'Expected: Schema-qualified names (public.products) and Output columns'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, VERBOSE, BUFFERS, TIMING OFF, SUMMARY OFF)
SELECT verbose_func();
\echo ''
-- ============================================================================
-- TEST 13: Statement Numbering = Completion Order
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 13: Statement Numbering Shows Completion Order'
\echo '============================================================================'
\echo ''
\echo 'Purpose: Statement #N reflects when a statement FINISHES (ExecutorEnd),'
\echo ' not when it starts. This is most visible with triggers:'
\echo ''
\echo ' Timeline for INSERT with an AFTER trigger:'
\echo ' 1. Parent INSERT starts executing'
\echo ' 2. Trigger fires → trigger INSERT starts → trigger INSERT FINISHES → gets #1'
\echo ' 3. Parent INSERT FINISHES → gets #2'
\echo ''
\echo ' The trigger statement finishes INSIDE the parent, so it gets a lower number.'
\echo ''
DROP TABLE IF EXISTS demo_orders CASCADE;
DROP TABLE IF EXISTS demo_log CASCADE;
CREATE TABLE demo_orders (id INT, item TEXT);
CREATE TABLE demo_log (msg TEXT);
CREATE OR REPLACE FUNCTION demo_log_trigger() RETURNS TRIGGER AS $$
BEGIN
INSERT INTO demo_log VALUES ('order placed: ' || NEW.item);
RETURN NEW;
END;
$$ LANGUAGE plpgsql;
CREATE TRIGGER demo_after_insert
AFTER INSERT ON demo_orders
FOR EACH ROW EXECUTE FUNCTION demo_log_trigger();
CREATE OR REPLACE FUNCTION place_order() RETURNS void AS $$
BEGIN
INSERT INTO demo_orders VALUES (1, 'Widget'); -- has trigger
INSERT INTO demo_orders VALUES (2, 'Gadget'); -- has trigger
END;
$$ LANGUAGE plpgsql;
\echo 'Expected numbering (completion order):'
\echo ' #1 (level 2, trigger): INSERT INTO demo_log ← trigger finishes first'
\echo ' #2 (level 1): INSERT INTO demo_orders (Widget) ← parent finishes second'
\echo ' #3 (level 2, trigger): INSERT INTO demo_log ← second trigger finishes'
\echo ' #4 (level 1): INSERT INTO demo_orders (Gadget) ← second parent finishes'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF)
SELECT place_order();
\echo ''
\echo 'Key takeaway: Lower statement number = finished earlier.'
\echo 'Triggers finish inside their parent, so they always get lower numbers.'
\echo ''
-- ============================================================================
-- TEST 14: BEGIN/ROLLBACK Safety Pattern
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 14: BEGIN/ROLLBACK - Safe Analysis of Data-Modifying Functions'
\echo '============================================================================'
\echo ''
\echo 'Purpose: Demonstrate the recommended pattern for safely analyzing'
\echo ' functions that modify data without persisting changes.'
\echo ''
\echo 'Pattern:'
\echo ' BEGIN;'
\echo ' EXPLAIN (ANALYZE, NESTED_STATEMENTS) SELECT my_function();'
\echo ' ROLLBACK;'
\echo ''
\echo 'The function executes (so we get real plans with actual rows),'
\echo 'but ROLLBACK undoes all changes.'
\echo ''
DROP TABLE IF EXISTS safe_orders CASCADE;
CREATE TABLE safe_orders (id INT, item TEXT, status TEXT);
INSERT INTO safe_orders VALUES (1, 'Widget', 'pending'), (2, 'Gadget', 'pending');
CREATE OR REPLACE FUNCTION process_all_orders() RETURNS INT AS $$
DECLARE processed INT := 0;
BEGIN
UPDATE safe_orders SET status = 'processing' WHERE status = 'pending';
INSERT INTO safe_orders VALUES (3, 'Bonus', 'new');
DELETE FROM safe_orders WHERE item = 'Gadget';
GET DIAGNOSTICS processed = ROW_COUNT;
RETURN processed;
END;
$$ LANGUAGE plpgsql;
\echo '--- Before: ---'
SELECT * FROM safe_orders;
\echo ''
\echo '--- EXPLAIN inside BEGIN/ROLLBACK: ---'
BEGIN;
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF)
SELECT process_all_orders();
ROLLBACK;
\echo ''
\echo '--- After ROLLBACK (data unchanged): ---'
SELECT * FROM safe_orders;
\echo ''
\echo 'Result: We got full execution plans with actual row counts,'
\echo ' but the data is unchanged after ROLLBACK.'
\echo ''
-- ============================================================================
-- TEST 15: Error During EXPLAIN Does Not Crash (Bug 1 Fix)
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 15: Error During EXPLAIN Does Not Crash Server'
\echo '============================================================================'
\echo ''
\echo 'Purpose: If EXPLAIN errors (e.g., division by zero), hooks must be'
\echo ' cleaned up so subsequent queries do not crash the backend.'
\echo ''
CREATE OR REPLACE FUNCTION divz_plpgsql(x int) RETURNS int LANGUAGE plpgsql AS $$
DECLARE r int;
BEGIN
SELECT 1/x INTO r;
RETURN r;
END;
$$;
-- This errors - hooks must be cleaned up via PG_FINALLY
EXPLAIN (ANALYZE, NESTED_STATEMENTS) SELECT divz_plpgsql(0);
\echo 'After error - next query (should not crash):'
SELECT 1 AS post_error_test;
\echo 'After error - EXPLAIN NESTED_STATEMENTS again:'
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF) SELECT 1;
\echo 'TEST 15: Server survived the error — hooks cleaned up correctly'
\echo ''
-- ============================================================================
-- TEST 16: Nested EXPLAIN Does Not Crash (Bug 2 Fix)
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 16: Nested EXPLAIN Does Not Crash Server'
\echo '============================================================================'
\echo ''
\echo 'Purpose: A function that internally runs EXPLAIN (NESTED_STATEMENTS)'
\echo ' should not corrupt the outer EXPLAIN state (reentrancy guard).'
\echo ''
CREATE OR REPLACE FUNCTION f_nested_explain() RETURNS void LANGUAGE plpgsql AS $$
DECLARE r record;
BEGIN
FOR r IN EXECUTE 'EXPLAIN (ANALYZE, NESTED_STATEMENTS) SELECT 1'
LOOP NULL; END LOOP;
END;
$$;
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT f_nested_explain();
\echo 'TEST 16: Server survived nested EXPLAIN — reentrancy guard works'
\echo ''
-- ============================================================================
-- TEST 17: Memory Context Cleanup (Bug 3 Fix)
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 17: Memory Context Properly Freed After EXPLAIN'
\echo '============================================================================'
\echo ''
\echo 'Purpose: The dedicated memory context for nested plans should not'
\echo ' persist after EXPLAIN completes (no memory leak).'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT 1;
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT 1;
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT 1;
\echo 'Memory contexts named "Nested EXPLAIN plans" (should be 0 rows):'
SELECT name FROM pg_backend_memory_contexts WHERE name = 'Nested EXPLAIN plans';
\echo 'TEST 17: 0 rows above = memory context freed after EXPLAIN'
\echo ''
-- ============================================================================
-- TEST 18: Memory Context Does Not Grow Across Repeated Calls
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 18: Memory Context Does Not Grow Across Repeated Calls'
\echo '============================================================================'
\echo ''
\echo 'Purpose: Run EXPLAIN NESTED_STATEMENTS 20 times and verify no memory'
\echo ' context persists or accumulates between calls.'
\echo ''
CREATE TABLE IF NOT EXISTS mem_test (id INT, val TEXT);
INSERT INTO mem_test VALUES (1, 'a'), (2, 'b');
CREATE OR REPLACE FUNCTION mem_func() RETURNS INT AS $$
DECLARE cnt INT;
BEGIN
SELECT COUNT(*) INTO cnt FROM mem_test;
UPDATE mem_test SET val = val || 'x' WHERE id = 1;
RETURN cnt;
END;
$$ LANGUAGE plpgsql;
-- Run 20 times
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT mem_func();
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT mem_func();
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT mem_func();
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT mem_func();
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT mem_func();
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT mem_func();
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT mem_func();
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT mem_func();
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT mem_func();
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT mem_func();
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT mem_func();
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT mem_func();
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT mem_func();
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT mem_func();
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT mem_func();
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT mem_func();
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT mem_func();
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT mem_func();
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT mem_func();
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT mem_func();
\echo 'After 20 runs - "Nested EXPLAIN plans" contexts (should be 0 rows):'
SELECT name FROM pg_backend_memory_contexts WHERE name = 'Nested EXPLAIN plans';
\echo 'TEST 18: 0 rows above = no memory accumulation after 20 runs'
\echo ''
-- ============================================================================
-- TEST 19: Stress Test - 50 Nested Statements
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 19: Stress Test - Function With 50 Nested Statements'
\echo '============================================================================'
\echo ''
\echo 'Purpose: Verify the feature handles many nested statements without'
\echo ' crashing or corrupting memory.'
\echo ''
DROP TABLE IF EXISTS stress_table;
CREATE TABLE stress_table (id INT, val TEXT);
INSERT INTO stress_table SELECT g, 'row_' || g FROM generate_series(1, 100) g;
CREATE OR REPLACE FUNCTION stress_func() RETURNS INT AS $$
DECLARE cnt INT;
BEGIN
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 1;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 2;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 3;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 4;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 5;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 6;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 7;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 8;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 9;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 10;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 11;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 12;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 13;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 14;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 15;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 16;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 17;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 18;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 19;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 20;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 21;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 22;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 23;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 24;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 25;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 26;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 27;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 28;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 29;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 30;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 31;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 32;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 33;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 34;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 35;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 36;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 37;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 38;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 39;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 40;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 41;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 42;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 43;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 44;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 45;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 46;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 47;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 48;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 49;
SELECT COUNT(*) INTO cnt FROM stress_table WHERE id = 50;
RETURN cnt;
END;
$$ LANGUAGE plpgsql;
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF) SELECT stress_func();
\echo ''
\echo 'Server healthy after stress:'
SELECT 1 AS server_healthy;
\echo 'No memory leak after stress:'
SELECT name FROM pg_backend_memory_contexts WHERE name = 'Nested EXPLAIN plans';
\echo 'TEST 19: 50 nested statements captured, server healthy, no leak'
\echo ''
-- ============================================================================
-- TEST 20: Execution Time Per Nested Statement (SUMMARY default)
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 20: Execution Time Per Nested Statement'
\echo '============================================================================'
\echo ''
\echo 'Purpose: Each nested statement shows its Execution Time when SUMMARY'
\echo ' is enabled (default with ANALYZE). Uses query_instr->total.'
\echo ''
DROP TABLE IF EXISTS et_test;
CREATE TABLE et_test (id INT, val TEXT);
INSERT INTO et_test VALUES (1, 'hello'), (2, 'world');
CREATE OR REPLACE FUNCTION et_func() RETURNS INT AS $$
DECLARE cnt INT;
BEGIN
SELECT COUNT(*) INTO cnt FROM et_test;
UPDATE et_test SET val = 'updated' WHERE id = 1;
RETURN cnt;
END;
$$ LANGUAGE plpgsql;
\echo 'Expected: Each nested statement shows "Execution Time: X.XXX ms"'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF) SELECT et_func();
\echo ''
-- ============================================================================
-- TEST 21: Summary and Percentages Hidden with SUMMARY OFF
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 21: Summary and Percentages Hidden with SUMMARY OFF'
\echo '============================================================================'
\echo ''
\echo 'Purpose: When SUMMARY OFF is specified, the following are all hidden:'
\echo ' - Per-statement Execution Time and percentage'
\echo ' - Nested Statements Summary section (total, max depth, slowest)'
\echo ' - Main query Planning Time and Execution Time'
\echo ' This is consistent with how the main query hides its timing info.'
\echo ''
\echo 'Expected: No Execution Time, no percentages, no Summary section'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT et_func();
DROP FUNCTION et_func();
DROP TABLE et_test;
\echo ''
-- ============================================================================
-- TEST 22: Structured Output - JSON Format
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 22: Structured Output - JSON Format'
\echo '============================================================================'
\echo ''
\echo 'Purpose: Nested plans are output as proper structured JSON with'
\echo ' Node Type, Plans array, costs, timing, and execution time.'
\echo ''
DROP TABLE IF EXISTS json_t;
CREATE TABLE json_t (id INT, val TEXT);
INSERT INTO json_t VALUES (1, 'test'), (2, 'data');
CREATE OR REPLACE FUNCTION json_func() RETURNS INT AS $$
DECLARE cnt INT;
BEGIN
SELECT COUNT(*) INTO cnt FROM json_t;
UPDATE json_t SET val = 'updated' WHERE id = 1;
RETURN cnt;
END;
$$ LANGUAGE plpgsql;
EXPLAIN (ANALYZE, NESTED_STATEMENTS, FORMAT JSON) SELECT json_func();
DROP FUNCTION json_func();
DROP TABLE json_t;
\echo ''
-- ============================================================================
-- TEST 23: Structured Output - XML Format
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 23: Structured Output - XML Format'
\echo '============================================================================'
\echo ''
\echo 'Purpose: Nested plans are output as proper XML with Node-Type,'
\echo ' Plans elements, costs, timing, and execution time.'
\echo ''
DROP TABLE IF EXISTS xml_t;
CREATE TABLE xml_t (id INT, val TEXT);
INSERT INTO xml_t VALUES (1, 'test'), (2, 'data');
CREATE OR REPLACE FUNCTION xml_func() RETURNS INT AS $$
DECLARE cnt INT;
BEGIN
SELECT COUNT(*) INTO cnt FROM xml_t;
UPDATE xml_t SET val = 'updated' WHERE id = 1;
RETURN cnt;
END;
$$ LANGUAGE plpgsql;
EXPLAIN (ANALYZE, NESTED_STATEMENTS, FORMAT XML) SELECT xml_func();
DROP FUNCTION xml_func();
DROP TABLE xml_t;
\echo ''
-- ============================================================================
-- TEST 24: Structured Output - YAML Format
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 24: Structured Output - YAML Format'
\echo '============================================================================'
\echo ''
\echo 'Purpose: Nested plans are output as proper YAML with Node Type,'
\echo ' Plans list, costs, timing, and execution time.'
\echo ''
DROP TABLE IF EXISTS yaml_t;
CREATE TABLE yaml_t (id INT, val TEXT);
INSERT INTO yaml_t VALUES (1, 'test'), (2, 'data');
CREATE OR REPLACE FUNCTION yaml_func() RETURNS INT AS $$
DECLARE cnt INT;
BEGIN
SELECT COUNT(*) INTO cnt FROM yaml_t;
UPDATE yaml_t SET val = 'updated' WHERE id = 1;
RETURN cnt;
END;
$$ LANGUAGE plpgsql;
EXPLAIN (ANALYZE, NESTED_STATEMENTS, FORMAT YAML) SELECT yaml_func();
DROP FUNCTION yaml_func();
DROP TABLE yaml_t;
\echo ''
-- ============================================================================
-- TEST 25: SHOW_NESTED - Limit Displayed Plans
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 25: SHOW_NESTED - Limit Displayed Plans'
\echo '============================================================================'
\echo ''
\echo 'Purpose: SHOW_NESTED N controls how many nested plans are displayed.'
\echo ' All statements are still captured internally for the summary,'
\echo ' but only the first N plans are shown in the output.'
\echo ''
\echo 'What this tests:'
\echo ' - A function with 5 nested statements'
\echo ' - SHOW_NESTED 2 shows only first 2 plans'
\echo ' - Header shows "(showing 2 of 5)"'
\echo ' - Summary still reflects all 5 statements'
\echo ''
DROP TABLE IF EXISTS sn_test;
CREATE TABLE sn_test (id INT, val TEXT);
INSERT INTO sn_test SELECT g, 'row_' || g FROM generate_series(1, 10) g;
CREATE OR REPLACE FUNCTION sn_func() RETURNS INT AS $$
DECLARE cnt INT;
BEGIN
SELECT COUNT(*) INTO cnt FROM sn_test WHERE id = 1;
SELECT COUNT(*) INTO cnt FROM sn_test WHERE id = 2;
SELECT COUNT(*) INTO cnt FROM sn_test WHERE id = 3;
SELECT COUNT(*) INTO cnt FROM sn_test WHERE id = 4;
SELECT COUNT(*) INTO cnt FROM sn_test WHERE id = 5;
RETURN cnt;
END;
$$ LANGUAGE plpgsql;
EXPLAIN (ANALYZE, NESTED_STATEMENTS, SHOW_NESTED 2, COSTS OFF, TIMING OFF) SELECT sn_func();
\echo ''
-- ============================================================================
-- TEST 26: SHOW_NESTED 0 - Summary Only
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 26: SHOW_NESTED 0 - Summary Only (No Plans Displayed)'
\echo '============================================================================'
\echo ''
\echo 'Purpose: SHOW_NESTED 0 means "capture all but display none".'
\echo ' Only the summary is shown — useful for getting a quick'
\echo ' overview of a complex function without pages of plan output.'
\echo ''
\echo 'What this tests:'
\echo ' - No individual plans are displayed'
\echo ' - Header shows "(showing 0 of 5)"'
\echo ' - Summary shows total count, max depth, timing, and slowest'
\echo ' - User can then re-run with a higher SHOW_NESTED to see details'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, SHOW_NESTED 0, COSTS OFF, TIMING OFF) SELECT sn_func();
\echo ''
-- ============================================================================
-- TEST 27: SHOW_NESTED Validation
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 27: SHOW_NESTED Validation'
\echo '============================================================================'
\echo ''
\echo 'Purpose: SHOW_NESTED requires NESTED_STATEMENTS to be enabled.'
\echo ' Using it alone should produce a clear error message.'
\echo ''
EXPLAIN (ANALYZE, SHOW_NESTED 5) SELECT 1;
\echo ''
-- ============================================================================
-- TEST 28: Nested Statements Summary with Percentages
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 28: Nested Statements Summary with Percentages'
\echo '============================================================================'
\echo ''
\echo 'Purpose: The summary shows statistics about all nested statements:'
\echo ' - Total count and max nesting depth'
\echo ' - Total Nested Time with % of main Execution Time'
\echo ' - Slowest statement with % of nested total'
\echo ''
\echo 'Per-statement Execution Time shows % of nested total for level-1'
\echo 'statements only. Deeper levels show absolute time (their time is'
\echo 'already included in their level-1 parent).'
\echo ''
\echo 'Percentage bases:'
\echo ' - Per-statement %: statement_time / total_nested_time (level 1 only)'
\echo ' - Summary Total %: total_nested_time / main_execution_time'
\echo ' - Slowest %: slowest_time / total_nested_time (level 1 only)'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF) SELECT sn_func();
DROP FUNCTION sn_func();
DROP TABLE sn_test;
\echo ''
-- ============================================================================
-- TEST 29: Statement Timeout Cleanup
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 29: Statement Timeout — Hooks Cleaned Up After Timeout'
\echo '============================================================================'
\echo ''
\echo 'Purpose: A function with multiple statements times out mid-execution.'
\echo ' The first statement was captured internally but the timeout'
\echo ' aborts the entire EXPLAIN before output is produced.'
\echo ' PG_FINALLY cleanup frees the partial data correctly.'
\echo ' After the error, the server continues working normally.'
\echo ''
CREATE OR REPLACE FUNCTION timeout_inner() RETURNS void AS $$
BEGIN
PERFORM pg_sleep(5);
END;
$$ LANGUAGE plpgsql;
CREATE OR REPLACE FUNCTION timeout_outer() RETURNS void AS $$
DECLARE cnt INT;
BEGIN
SELECT COUNT(*) INTO cnt FROM pg_class WHERE relname = 'pg_type';
PERFORM timeout_inner();
END;
$$ LANGUAGE plpgsql;
SET statement_timeout = '200ms';
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT timeout_outer();
RESET statement_timeout;
\echo 'After timeout - server still works:'
SELECT 1 AS post_timeout_ok;
\echo ''
DROP FUNCTION timeout_outer();
DROP FUNCTION timeout_inner();
-- ============================================================================
-- TEST 30: Dynamic SQL — Query Text Captured Correctly
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 30: Dynamic SQL — Query Text Captured Correctly'
\echo '============================================================================'
\echo ''
\echo 'Purpose: When a function uses EXECUTE (dynamic SQL), the Query Text'
\echo ' field shows the actual executed SQL string, not the PL/pgSQL'
\echo ' expression that built it.'
\echo ''
DROP TABLE IF EXISTS dyn_t;
CREATE TABLE dyn_t (id INT, val TEXT);
INSERT INTO dyn_t VALUES (1, 'hello'), (2, 'world');
CREATE OR REPLACE FUNCTION dyn_func() RETURNS INT AS $$
DECLARE cnt INT; tbl TEXT := 'dyn_t';
BEGIN
EXECUTE 'SELECT COUNT(*) FROM ' || tbl INTO cnt;
EXECUTE format('UPDATE %I SET val = %L WHERE id = %L', tbl, 'dynamic', 1);
RETURN cnt;
END;
$$ LANGUAGE plpgsql;
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF) SELECT dyn_func();
DROP FUNCTION dyn_func();
DROP TABLE dyn_t;
\echo ''
-- ============================================================================
-- TEST 31: Infinite Recursion — Graceful Error
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 31: Infinite Recursion — Graceful Error and Cleanup'
\echo '============================================================================'
\echo ''
\echo 'Purpose: A function that calls itself infinitely triggers'
\echo ' "stack depth limit exceeded". After this error, the server'
\echo ' must not crash and hooks must be cleaned up.'
\echo ''
\echo 'How PostgreSQL prevents infinite recursion:'
\echo ' - Every function call adds a "frame" to the OS call stack'
\echo ' - PostgreSQL has a GUC: max_stack_depth (default 2MB)'
\echo ' - The function check_stack_depth() is called before each PL/pgSQL'
\echo ' function entry to check if the stack is getting too large'
\echo ' - When the stack exceeds max_stack_depth, PostgreSQL throws:'
\echo ' ERROR: stack depth limit exceeded'
\echo ' - This happens after roughly 100-200 nested calls'
\echo ''
\echo 'What this tests for NESTED_STATEMENTS:'
\echo ' - The error fires while our hooks are installed'
\echo ' - Some nested plans may have been partially captured in memory'
\echo ' - PG_TRY/PG_FINALLY must clean up: remove hooks, free memory'
\echo ' - After the error, the next query must work normally'
\echo ''
CREATE OR REPLACE FUNCTION inf_func() RETURNS void AS $$
BEGIN
PERFORM inf_func();
END;
$$ LANGUAGE plpgsql;
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT inf_func();
\echo 'After recursion error - server still works:'
SELECT 1 AS post_recursion_ok;
\echo ''
DROP FUNCTION inf_func();
-- ============================================================================
-- TEST 32: auto_explain Compatibility
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 32: auto_explain Compatibility — Hooks Coexist'
\echo '============================================================================'
\echo ''
\echo 'Purpose: auto_explain uses the same executor hooks we use.'
\echo ' Both must coexist without crashes or duplicate output.'
\echo ' Hook chaining (prev_hook saved/restored) must work.'
\echo ''
DROP TABLE IF EXISTS ae_t;
CREATE TABLE ae_t (id INT);
INSERT INTO ae_t VALUES (1);
CREATE OR REPLACE FUNCTION ae_f() RETURNS INT AS $$
DECLARE cnt INT;
BEGIN
SELECT COUNT(*) INTO cnt FROM ae_t;
RETURN cnt;
END;
$$ LANGUAGE plpgsql;
LOAD 'auto_explain';
SET auto_explain.log_min_duration = 0;
SET auto_explain.log_nested_statements = on;
SET auto_explain.log_analyze = on;
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF) SELECT ae_f();
RESET auto_explain.log_min_duration;
RESET auto_explain.log_nested_statements;
RESET auto_explain.log_analyze;
DROP FUNCTION ae_f();
DROP TABLE ae_t;
\echo ''
-- ============================================================================
-- TEST 33: Deep Nesting (20 Levels)
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 33: Deep Nesting — 20 Levels Without Crash'
\echo '============================================================================'
\echo ''
\echo 'Purpose: Verify deep function call chains do not crash or corrupt'
\echo ' memory. Uses 20 levels (100 would hit stack limit).'
\echo ''
CREATE OR REPLACE FUNCTION d_leaf() RETURNS INT AS $$
BEGIN RETURN 1; END;
$$ LANGUAGE plpgsql;
CREATE OR REPLACE FUNCTION d10() RETURNS INT AS $$ BEGIN RETURN d_leaf(); END; $$ LANGUAGE plpgsql;
CREATE OR REPLACE FUNCTION d9() RETURNS INT AS $$ BEGIN RETURN d10(); END; $$ LANGUAGE plpgsql;
CREATE OR REPLACE FUNCTION d8() RETURNS INT AS $$ BEGIN RETURN d9(); END; $$ LANGUAGE plpgsql;
CREATE OR REPLACE FUNCTION d7() RETURNS INT AS $$ BEGIN RETURN d8(); END; $$ LANGUAGE plpgsql;
CREATE OR REPLACE FUNCTION d6() RETURNS INT AS $$ BEGIN RETURN d7(); END; $$ LANGUAGE plpgsql;
CREATE OR REPLACE FUNCTION d5() RETURNS INT AS $$ BEGIN RETURN d6(); END; $$ LANGUAGE plpgsql;
CREATE OR REPLACE FUNCTION d4() RETURNS INT AS $$ BEGIN RETURN d5(); END; $$ LANGUAGE plpgsql;
CREATE OR REPLACE FUNCTION d3() RETURNS INT AS $$ BEGIN RETURN d4(); END; $$ LANGUAGE plpgsql;
CREATE OR REPLACE FUNCTION d2() RETURNS INT AS $$ BEGIN RETURN d3(); END; $$ LANGUAGE plpgsql;
CREATE OR REPLACE FUNCTION d1() RETURNS INT AS $$ BEGIN RETURN d2(); END; $$ LANGUAGE plpgsql;
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF) SELECT d1();
DROP FUNCTION d1(); DROP FUNCTION d2(); DROP FUNCTION d3();
DROP FUNCTION d4(); DROP FUNCTION d5(); DROP FUNCTION d6();
DROP FUNCTION d7(); DROP FUNCTION d8(); DROP FUNCTION d9();
DROP FUNCTION d10(); DROP FUNCTION d_leaf();
\echo ''
-- ============================================================================
-- TEST 34: All EXPLAIN Options Combined with SHOW_NESTED
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 34: All EXPLAIN Options Combined with SHOW_NESTED'
\echo '============================================================================'
\echo ''
\echo 'Purpose: Every option together — NESTED_STATEMENTS, VERBOSE, BUFFERS,'
\echo ' WAL, SETTINGS, SHOW_NESTED 3. Verifies no conflicts.'
\echo ''
DROP TABLE IF EXISTS combo_t;
CREATE TABLE combo_t (id INT, val TEXT);
INSERT INTO combo_t VALUES (1, 'a'), (2, 'b'), (3, 'c');
CREATE OR REPLACE FUNCTION combo_f() RETURNS INT AS $$
DECLARE cnt INT;
BEGIN
SELECT COUNT(*) INTO cnt FROM combo_t;
UPDATE combo_t SET val = 'x' WHERE id = 1;
DELETE FROM combo_t WHERE id = 99;
INSERT INTO combo_t VALUES (4, 'new');
SELECT COUNT(*) INTO cnt FROM combo_t;
RETURN cnt;
END;
$$ LANGUAGE plpgsql;
EXPLAIN (ANALYZE, NESTED_STATEMENTS, VERBOSE, BUFFERS, WAL, SETTINGS, SHOW_NESTED 3) SELECT combo_f();
DROP FUNCTION combo_f();
DROP TABLE combo_t;
\echo ''
-- ============================================================================
-- TEST 35: Performance — Zero Overhead When Disabled
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 35: Performance — Zero Overhead When Feature Disabled'
\echo '============================================================================'
\echo ''
\echo 'Purpose: When NESTED_STATEMENTS is not used, there should be zero'
\echo ' overhead. Hooks are only installed during EXPLAIN with'
\echo ' NESTED_STATEMENTS — regular queries are unaffected.'
\echo ''
DROP TABLE IF EXISTS perf_t;
CREATE TABLE perf_t (id INT, val TEXT);
INSERT INTO perf_t SELECT g, 'row_' || g FROM generate_series(1, 1000) g;
CREATE OR REPLACE FUNCTION perf_f() RETURNS INT AS $$
DECLARE cnt INT;
BEGIN
SELECT COUNT(*) INTO cnt FROM perf_t;
RETURN cnt;
END;
$$ LANGUAGE plpgsql;
\timing on
\echo 'Without NESTED_STATEMENTS (baseline):'
EXPLAIN (ANALYZE, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT perf_f();
\echo ''
\echo 'With NESTED_STATEMENTS:'
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT perf_f();
\timing off
DROP FUNCTION perf_f();
DROP TABLE perf_t;
\echo ''
-- ============================================================================
-- TEST 36: Interpreting Total Nested Time Percentage
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 36: Interpreting Total Nested Time Percentage'
\echo '============================================================================'
\echo ''
\echo 'Purpose: Demonstrate how the "Total Nested Time (X% of total time)"'
\echo ' helps users decide WHERE to optimize.'
\echo ''
\echo 'The percentage answers: "How much of my function execution time'
\echo ' is spent in SQL vs PL/pgSQL overhead?"'
\echo ''
\echo 'Interpretation guide:'
\echo ' High % (80-100%): Most time is in SQL queries.'
\echo ' → Action: Optimize the SQL (add indexes, rewrite queries)'
\echo ' Low % (0-20%): SQL is fast, PL/pgSQL overhead dominates.'
\echo ' → Action: Reduce function complexity (fewer loops, less logic)'
\echo ' Medium % (20-80%): Mixed — both SQL and overhead contribute.'
\echo ' → Action: Look at per-statement % to find the slow query'
\echo ''
\echo '--- Function A: SQL-heavy (big scan, minimal PL/pgSQL logic) ---'
\echo ''
DROP TABLE IF EXISTS big_table;
CREATE TABLE big_table (id INT, category TEXT, val NUMERIC);
INSERT INTO big_table SELECT g, 'cat_' || (g % 10), random() * 1000
FROM generate_series(1, 10000) g;
CREATE OR REPLACE FUNCTION sql_heavy_func() RETURNS NUMERIC AS $$
DECLARE result NUMERIC;
BEGIN
-- This query does real work (full table scan + aggregation)
SELECT SUM(val) INTO result FROM big_table WHERE category = 'cat_5';
RETURN result;
END;
$$ LANGUAGE plpgsql;
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF) SELECT sql_heavy_func();
\echo ''
\echo '--- Function B: Overhead-heavy (trivial SQL, lots of PL/pgSQL work) ---'
\echo ''
CREATE OR REPLACE FUNCTION overhead_heavy_func() RETURNS INT AS $$
DECLARE
i INT;
total INT := 0;
BEGIN
-- Trivial SQL but called in a loop with PL/pgSQL overhead
FOR i IN 1..100 LOOP
total := total + i;
END LOOP;
-- One trivial SQL at the end
PERFORM 1;
RETURN total;
END;
$$ LANGUAGE plpgsql;
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF) SELECT overhead_heavy_func();
\echo ''
\echo 'Compare the "Total Nested Time (X% of total time)" between the two:'
\echo ' - sql_heavy_func: high % → SQL is the bottleneck'
\echo ' - overhead_heavy_func: low % → PL/pgSQL overhead is the bottleneck'
\echo ''
DROP FUNCTION sql_heavy_func();
DROP FUNCTION overhead_heavy_func();
DROP TABLE big_table;
\echo ''
-- ============================================================================
-- TEST 37: Multiple Triggers on Separate Tables
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 37: Multiple Triggers on Separate Tables'
\echo '============================================================================'
\echo ''
\echo 'Purpose: Verify trigger detection works correctly when a function'
\echo ' touches multiple tables, each with its own trigger.'
\echo ''
\echo 'What this tests:'
\echo ' - Triggers on different tables are all detected'
\echo ' - Total Trigger Time accumulates across all trigger-fired statements'
\echo ' - Summary correctly counts all trigger-fired vs direct statements'
\echo ' - Per-statement percentages only apply to level-1 direct statements'
\echo ''
DROP TABLE IF EXISTS mt_orders CASCADE;
DROP TABLE IF EXISTS mt_inventory CASCADE;
DROP TABLE IF EXISTS mt_audit CASCADE;
CREATE TABLE mt_orders (id INT, item TEXT, qty INT);
CREATE TABLE mt_inventory (item TEXT, stock INT);
CREATE TABLE mt_audit (msg TEXT);
INSERT INTO mt_inventory VALUES ('widget', 100), ('gadget', 50);
-- Trigger on mt_orders: log the order
CREATE OR REPLACE FUNCTION mt_log_order() RETURNS TRIGGER AS $$
BEGIN
INSERT INTO mt_audit VALUES ('order: ' || NEW.item || ' x' || NEW.qty);
RETURN NEW;
END;
$$ LANGUAGE plpgsql;
CREATE TRIGGER mt_orders_audit AFTER INSERT ON mt_orders
FOR EACH ROW EXECUTE FUNCTION mt_log_order();
-- Trigger on mt_inventory: log stock change
CREATE OR REPLACE FUNCTION mt_log_stock() RETURNS TRIGGER AS $$
BEGIN
INSERT INTO mt_audit VALUES ('stock: ' || NEW.item || ' now ' || NEW.stock);
RETURN NEW;
END;
$$ LANGUAGE plpgsql;
CREATE TRIGGER mt_inventory_audit AFTER UPDATE ON mt_inventory
FOR EACH ROW EXECUTE FUNCTION mt_log_stock();
-- Function that touches both tables (fires both triggers)
CREATE OR REPLACE FUNCTION mt_place_order(p_item TEXT, p_qty INT) RETURNS VOID AS $$
BEGIN
INSERT INTO mt_orders VALUES (1, p_item, p_qty);
UPDATE mt_inventory SET stock = stock - p_qty WHERE item = p_item;
PERFORM COUNT(*) FROM mt_audit;
END;
$$ LANGUAGE plpgsql;
\echo 'Expected:'
\echo ' #1 (level 2, trigger): INSERT INTO mt_audit — from orders trigger'
\echo ' #2 (level 1): INSERT INTO mt_orders — direct'
\echo ' #3 (level 2, trigger): INSERT INTO mt_audit — from inventory trigger'
\echo ' #4 (level 1): UPDATE mt_inventory — direct'
\echo ' #5 (level 1): SELECT COUNT(*) — direct'
\echo ''
\echo 'Summary: 5 statements (3 direct, 2 trigger-fired)'
\echo 'Total Trigger Time accumulates both trigger statements'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF)
SELECT mt_place_order('widget', 5);
DROP FUNCTION mt_place_order(TEXT, INT);
DROP TRIGGER mt_inventory_audit ON mt_inventory;
DROP FUNCTION mt_log_stock();
DROP TRIGGER mt_orders_audit ON mt_orders;
DROP FUNCTION mt_log_order();
DROP TABLE mt_orders, mt_inventory, mt_audit;
\echo ''
-- ============================================================================
-- TEST 38: Direct DML with Triggers (No Function Wrapper)
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 38: Direct DML with Triggers (No Function Wrapper)'
\echo '============================================================================'
\echo ''
\echo 'Purpose: NESTED_STATEMENTS is not just for functions — it reveals'
\echo ' trigger activity on any DML statement. This helps DBAs'
\echo ' understand why an INSERT/UPDATE/DELETE is slow when triggers'
\echo ' are involved, without needing to wrap anything in a function.'
\echo ''
\echo 'What this tests:'
\echo ' - Direct UPDATE with BEFORE trigger (validation + logging)'
\echo ' - Direct UPDATE with AFTER trigger (audit logging)'
\echo ' - Cascading triggers (trigger inserts into table with its own trigger)'
\echo ' - Both BEFORE and AFTER triggers detected via GetMyTriggerDepth()'
\echo ''
-- Setup
DROP TABLE IF EXISTS emp CASCADE;
DROP TABLE IF EXISTS emp_audit CASCADE;
DROP TABLE IF EXISTS notifications CASCADE;
CREATE TABLE emp (id INT PRIMARY KEY, name TEXT, salary NUMERIC);
CREATE TABLE emp_audit (emp_id INT, action TEXT, old_salary NUMERIC, new_salary NUMERIC);
CREATE TABLE notifications (msg TEXT);
INSERT INTO emp VALUES (1, 'Alice', 50000), (2, 'Bob', 60000), (3, 'Charlie', 70000);
-- BEFORE trigger: validate and log rejected changes
CREATE OR REPLACE FUNCTION validate_salary() RETURNS TRIGGER AS $$
BEGIN
IF NEW.salary > 200000 THEN
INSERT INTO emp_audit VALUES (NEW.id, 'REJECTED', OLD.salary, NEW.salary);
RETURN NULL; -- reject the update
END IF;
RETURN NEW;
END;
$$ LANGUAGE plpgsql;
CREATE TRIGGER emp_validate BEFORE UPDATE OF salary ON emp
FOR EACH ROW EXECUTE FUNCTION validate_salary();
-- AFTER trigger: audit accepted changes
CREATE OR REPLACE FUNCTION audit_salary() RETURNS TRIGGER AS $$
BEGIN
INSERT INTO emp_audit VALUES (NEW.id, 'ACCEPTED', OLD.salary, NEW.salary);
RETURN NEW;
END;
$$ LANGUAGE plpgsql;
CREATE TRIGGER emp_audit_trigger AFTER UPDATE OF salary ON emp
FOR EACH ROW EXECUTE FUNCTION audit_salary();
-- Cascading trigger: notify on audit inserts
CREATE OR REPLACE FUNCTION notify_audit() RETURNS TRIGGER AS $$
BEGIN
INSERT INTO notifications VALUES ('audit: ' || NEW.action || ' emp ' || NEW.emp_id);
RETURN NEW;
END;
$$ LANGUAGE plpgsql;
CREATE TRIGGER audit_notify_trigger AFTER INSERT ON emp_audit
FOR EACH ROW EXECUTE FUNCTION notify_audit();
\echo '--- Part A: Accepted UPDATE (BEFORE passes, AFTER fires) ---'
\echo 'Expected: All statements annotated as (trigger)'
\echo ' - AFTER trigger on emp_audit fires cascading trigger on notifications'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF)
UPDATE emp SET salary = salary + 10000 WHERE id = 1;
\echo ''
\echo '--- Part B: Rejected UPDATE (BEFORE trigger rejects, logs, no AFTER) ---'
\echo 'Expected: BEFORE trigger INSERT into emp_audit detected as (trigger)'
\echo ' - Cascading notification trigger also fires'
\echo ' - No AFTER trigger (update was rejected by BEFORE returning NULL)'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF)
UPDATE emp SET salary = 999999 WHERE id = 2;
-- Cleanup Test 38
DROP TABLE emp CASCADE;
DROP TABLE emp_audit CASCADE;
DROP TABLE notifications;
DROP FUNCTION validate_salary();
DROP FUNCTION audit_salary();
DROP FUNCTION notify_audit();
\echo ''
-- ============================================================================
-- TEST 39: BEFORE and AFTER Triggers in Function Context
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 39: BEFORE and AFTER Triggers in Function Context'
\echo '============================================================================'
\echo ''
\echo 'Purpose: Verify trigger detection works correctly when DML with'
\echo ' BEFORE and AFTER triggers is executed inside a function.'
\echo ' Both trigger types should be annotated, and direct function'
\echo ' statements should NOT be annotated.'
\echo ''
\echo 'What this tests:'
\echo ' - Function executes INSERT (fires BEFORE + AFTER triggers)'
\echo ' - Function also executes a plain SELECT (not a trigger)'
\echo ' - Trigger statements: annotated with (trigger), no percentage'
\echo ' - Direct level-1 statements: show percentage, no (trigger) annotation'
\echo ' - Summary correctly separates direct vs trigger-fired counts'
\echo ''
DROP TABLE IF EXISTS t39_data CASCADE;
DROP TABLE IF EXISTS t39_log CASCADE;
CREATE TABLE t39_data (id INT PRIMARY KEY, val TEXT, created_at TIMESTAMP);
CREATE TABLE t39_log (msg TEXT);
-- BEFORE trigger: set timestamp
CREATE OR REPLACE FUNCTION t39_before_func() RETURNS TRIGGER AS $$
BEGIN
NEW.created_at := now();
INSERT INTO t39_log VALUES ('before: setting timestamp for id=' || NEW.id);
RETURN NEW;
END;
$$ LANGUAGE plpgsql;
CREATE TRIGGER t39_before BEFORE INSERT ON t39_data
FOR EACH ROW EXECUTE FUNCTION t39_before_func();
-- AFTER trigger: log insertion
CREATE OR REPLACE FUNCTION t39_after_func() RETURNS TRIGGER AS $$
BEGIN
INSERT INTO t39_log VALUES ('after: row inserted id=' || NEW.id);
RETURN NEW;
END;
$$ LANGUAGE plpgsql;
CREATE TRIGGER t39_after AFTER INSERT ON t39_data
FOR EACH ROW EXECUTE FUNCTION t39_after_func();
-- Function that does INSERT (fires both triggers) + plain SELECT
CREATE OR REPLACE FUNCTION t39_test_func() RETURNS INT AS $$
DECLARE cnt INT;
BEGIN
INSERT INTO t39_data VALUES (1, 'hello', NULL);
INSERT INTO t39_data VALUES (2, 'world', NULL);
SELECT COUNT(*) INTO cnt FROM t39_log;
RETURN cnt;
END;
$$ LANGUAGE plpgsql;
\echo 'Expected:'
\echo ' - BEFORE trigger INSERTs: (trigger) annotation'
\echo ' - AFTER trigger INSERTs: (trigger) annotation'
\echo ' - INSERT INTO t39_data: direct (level 1)'
\echo ' - SELECT COUNT(*): direct (level 1) with percentage'
\echo ' - Summary: mix of direct and trigger-fired'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF)
SELECT t39_test_func();
-- Cleanup Test 39
DROP TABLE t39_data CASCADE;
DROP TABLE t39_log;
DROP FUNCTION t39_test_func();
DROP FUNCTION t39_before_func();
DROP FUNCTION t39_after_func();
\echo ''
-- ============================================================================
-- TEST 40: Query Identifier Integration (pg_stat_statements)
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 40: Query Identifier Integration (pg_stat_statements)'
\echo '============================================================================'
\echo ''
\echo 'Purpose: When VERBOSE and compute_query_id are enabled, each nested'
\echo ' statement shows its Query Identifier. This allows users to'
\echo ' correlate nested plans with pg_stat_statements entries.'
\echo ''
\echo 'What this tests:'
\echo ' - Each nested statement shows Query Identifier with VERBOSE'
\echo ' - Repeated queries share the same Query Identifier'
\echo ' - Trigger-fired statements have their own Query Identifier'
\echo ' - Users can look up any nested query in pg_stat_statements'
\echo ''
SET compute_query_id = on;
DROP TABLE IF EXISTS qid_orders CASCADE;
DROP TABLE IF EXISTS qid_audit CASCADE;
CREATE TABLE qid_orders (id INT PRIMARY KEY, item TEXT, total NUMERIC);
CREATE TABLE qid_audit (order_id INT, action TEXT);
INSERT INTO qid_orders VALUES (1, 'Widget', 99.99), (2, 'Gadget', 49.99);
-- Trigger function
CREATE OR REPLACE FUNCTION qid_audit_func() RETURNS TRIGGER AS $$
BEGIN
INSERT INTO qid_audit VALUES (NEW.id, TG_OP);
RETURN NEW;
END;
$$ LANGUAGE plpgsql;
CREATE TRIGGER qid_audit_trig AFTER UPDATE ON qid_orders
FOR EACH ROW EXECUTE FUNCTION qid_audit_func();
-- Helper function called multiple times
CREATE OR REPLACE FUNCTION qid_apply_discount(p_id INT, p_pct NUMERIC) RETURNS VOID AS $$
BEGIN
UPDATE qid_orders SET total = total * (1 - p_pct/100) WHERE id = p_id;
END;
$$ LANGUAGE plpgsql;
-- Main function
CREATE OR REPLACE FUNCTION qid_process_orders() RETURNS INT AS $$
DECLARE cnt INT;
BEGIN
SELECT COUNT(*) INTO cnt FROM qid_orders;
PERFORM qid_apply_discount(1, 10);
PERFORM qid_apply_discount(2, 20);
RETURN cnt;
END;
$$ LANGUAGE plpgsql;
\echo 'Expected: Each nested statement shows Query Identifier.'
\echo 'Repeated queries (UPDATE, trigger INSERT, PERFORM) share the same ID.'
\echo ''
EXPLAIN (ANALYZE, NESTED_STATEMENTS, VERBOSE, COSTS OFF)
SELECT qid_process_orders();
RESET compute_query_id;
-- Cleanup Test 40
DROP TABLE qid_orders CASCADE;
DROP TABLE qid_audit;
DROP FUNCTION qid_process_orders();
DROP FUNCTION qid_apply_discount(INT, NUMERIC);
DROP FUNCTION qid_audit_func();
\echo ''
-- ============================================================================
-- TEST 41: Level-1 Only Counting (no double-counting with deep nesting)
-- ============================================================================
\echo '============================================================================'
\echo 'TEST 41: Level-1 Only Counting — No Double-Counting'
\echo '============================================================================'
\echo ''
\echo 'Purpose: Demonstrate that Total Nested Time sums only level-1 statements.'
\echo ' Deeper levels show absolute time but are NOT added to the total,'
\echo ' because their time is already included in their level-1 parent.'
\echo ''
\echo 'Setup: 3-level PERFORM chain, each level does pg_sleep(0.01) = ~10ms.'
\echo ' - Level 1: own sleep (10ms) + PERFORM level2 (~20ms) = ~30ms'
\echo ' - Level 2: own sleep (10ms) + PERFORM level3 (~10ms) = ~20ms'
\echo ' - Level 3: own sleep (10ms) = ~10ms'
\echo ''
\echo 'Key indicators:'
\echo ' - Level-1 statements show percentage'
\echo ' - Level-2 and level-3 statements show time only (no %)'
\echo ' - Total Nested Time ≤ Total Execution Time (always)'
\echo ''
CREATE OR REPLACE FUNCTION dc_level3() RETURNS void AS $$
BEGIN
PERFORM pg_sleep(0.01);
END;
$$ LANGUAGE plpgsql;
CREATE OR REPLACE FUNCTION dc_level2() RETURNS void AS $$
BEGIN
PERFORM pg_sleep(0.01);
PERFORM dc_level3();
END;
$$ LANGUAGE plpgsql;
CREATE OR REPLACE FUNCTION dc_level1() RETURNS void AS $$
BEGIN
PERFORM pg_sleep(0.01);
PERFORM dc_level2();
END;
$$ LANGUAGE plpgsql;
EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF)
SELECT dc_level1();
-- Cleanup Test 41
DROP FUNCTION dc_level3();
DROP FUNCTION dc_level2();
DROP FUNCTION dc_level1();
\echo ''
-- ============================================================================
-- Cleanup
-- ============================================================================
DROP FUNCTION IF EXISTS simple_function();
DROP FUNCTION IF EXISTS inner_perform();
DROP FUNCTION IF EXISTS outer_perform();
DROP FUNCTION IF EXISTS inner_expr();
DROP FUNCTION IF EXISTS outer_expr();
DROP FUNCTION IF EXISTS shared_inner();
DROP FUNCTION IF EXISTS caller_perform();
DROP FUNCTION IF EXISTS caller_assign();
DROP FUNCTION IF EXISTS sql_level3();
DROP FUNCTION IF EXISTS sql_level2();
DROP FUNCTION IF EXISTS plpgsql_sql_caller();
DROP FUNCTION IF EXISTS chain_level1();
DROP FUNCTION IF EXISTS chain_level2();
DROP FUNCTION IF EXISTS chain_level3();
DROP FUNCTION IF EXISTS recursive_func(INT);
DROP FUNCTION IF EXISTS exception_func();
DROP FUNCTION IF EXISTS process_order(INT);
DROP TRIGGER IF EXISTS order_audit_trigger ON orders;
DROP FUNCTION IF EXISTS log_order_change();
DROP FUNCTION IF EXISTS verbose_func();
DROP FUNCTION IF EXISTS place_order();
DROP TRIGGER IF EXISTS demo_after_insert ON demo_orders;
DROP FUNCTION IF EXISTS demo_log_trigger();
DROP TABLE IF EXISTS products CASCADE;
DROP TABLE IF EXISTS t1, t2, t3 CASCADE;
DROP TABLE IF EXISTS counter_log;
DROP TABLE IF EXISTS safe_table;
DROP TABLE IF EXISTS orders CASCADE;
DROP TABLE IF EXISTS audit_log;
DROP TABLE IF EXISTS demo_orders CASCADE;
DROP TABLE IF EXISTS demo_log;
DROP TABLE IF EXISTS safe_orders CASCADE;
DROP FUNCTION IF EXISTS process_all_orders();
DROP FUNCTION IF EXISTS divz_plpgsql(int);
DROP FUNCTION IF EXISTS f_nested_explain();
DROP FUNCTION IF EXISTS mem_func();
DROP FUNCTION IF EXISTS stress_func();
DROP TABLE IF EXISTS mem_test;
DROP TABLE IF EXISTS stress_table;
\echo '============================================================================'
\echo 'Test Suite Complete — 41 tests'
\echo '============================================================================'