In PostgreSQL, an execution plan is a graphical representation of the steps involved in query execution. The query plan is generated by the query optimizer, which prepares multiple execution plans and then selects the most efficient one.
As we know it is impossible to generate an execution plan for stored procedures directly from psql terminal as we normally do for the “SELECT” operation. There are a few steps that we have to perform to generate an execution plan for the stored procedure.
Generate explain plan during the execution of the stored procedure.
Change the below parameter in postgresql.conf:
session_preload_libraries = 'auto_explain'
log_statement=all
Reload the configuration with either pg_ctl reload or SELECT pg_reload_conf() after making the above changes.
Set session level parameter settings as below:
edb=# LOAD 'auto_explain';
edb=# set auto_explain.log_min_duration=0;
edb=# set auto_explain.log_nested_statements=true;
edb=# set auto_explain.log_analyze=true;
Without logging out of the current psql session, create and execute the below procedure:
edb=# CREATE OR REPLACE PROCEDURE transaction_test()
edb-# AS $$
edb$# DECLARE
edb$# BEGIN
edb$# CREATE TABLE committed_table (id int);
edb$# INSERT INTO committed_table VALUES (1);
edb$# COMMIT;
edb$# CREATE TABLE rollback_table (id int);
edb$# INSERT INTO rollback_table VALUES (1);
edb$# ROLLBACK;
edb$# END $$;
CREATE PROCEDURE
edb=# CALL transaction_test();
EDB-SPL Procedure successfully completed
Now looking at the log we could see below:
2023-01-24 20:45:18 IST LOG: statement: CALL transaction_test();
2023-01-24 20:45:18 IST LOG: duration: 0.104 ms plan:
Query Text: INSERT INTO committed_table VALUES (1)
Insert on committed_table (cost=0.00..0.01 rows=1 width=4) (actual time=0.102..0.102 rows=0 loops=1)
-> Result (cost=0.00..0.01 rows=1 width=4) (actual time=0.009..0.009 rows=1 loops=1)
2023-01-24 20:45:18 IST CONTEXT: SQL statement "INSERT INTO committed_table VALUES (1)"
edb-spl function transaction_test() line 5 at SQL statement
2023-01-24 20:45:18 IST LOG: duration: 0.059 ms plan:
Query Text: INSERT INTO rollback_table VALUES (1)
Insert on rollback_table (cost=0.00..0.01 rows=1 width=4) (actual time=0.058..0.058 rows=0 loops=1)
-> Result (cost=0.00..0.01 rows=1 width=4) (actual time=0.000..0.001 rows=1 loops=1)
2023-01-24 20:45:18 IST CONTEXT: SQL statement "INSERT INTO rollback_table VALUES (1)"
edb-spl function transaction_test() line 8 at SQL statement
2023-01-24 20:45:18 IST LOG: duration: 41.189 ms plan:
Query Text: CALL transaction_test();
Result (cost=0.00..0.26 rows=1 width=4) (actual time=41.187..41.187 rows=1 loops=1)