PostgreSQL: Same request is slower with plpgsql language compared to sql

Question

I'm new to PostgreSQL and I'm facing a issue regarding table functions performance. What I need to do is the equivalent of a Stored Procedure in MSSQL. After some research I found that a table function is the way to go so I took an exemple to create my function using plpgsql.

By comparing the execution times, it was 2 times slower using the function than calling the query directly (the query is exactly the same in the function).

After digging a little bit, I've found that using SQL language in my function improves a lot the execution time (becomes exactly the same time as if I call the query). After reading on this, I understand that plpgsql adds a little bit overhead but the difference is too big to explain that.

Since I'm not using any plpgsql functionality, this solution is fine for me and totally makes sense. However, I'd like to understand why such difference. If I compare the execution plans, the plpgsql version does some HashAggregate and sequential search compared to the SQL version that does GroupAggregate with some pre-sorting... I did use auto_explain as suggested by Laurenz Albe and I added at the end both execution plans.

Why such difference in the execution plan of the same query with the only difference the language? And moreover, even the result of the SUM (see my request below) has a significant difference. I know I'm using floating values so the result can be a little different between each call, but in this case the difference between the query and function is around ~3 which is unexpected (~10001 vs ~9998).

Below the code to reproduce the problem using 2 tables and 2 functions.

Note that I'm using PostgreSQL 12.

Any explanation are appreciated :) Thanks.

-- Step 1: Create database

-- Step 2: Create tables
-- table1
CREATE TABLE public.table1(area real, code text COLLATE pg_catalog."default");

-- table 2
CREATE TABLE public.table2(code text COLLATE pg_catalog."default" NOT NULL, surface real, CONSTRAINT table2_pkey PRIMARY KEY (code));

-- Step 3: create functions
-- plpgsql
CREATE OR REPLACE FUNCTION public.test_function()
    RETURNS TABLE(code text, value real) 
    LANGUAGE 'plpgsql'

    COST 100
    VOLATILE 
    ROWS 1000
AS $BODY$
BEGIN
   RETURN QUERY 
   
   SELECT table2.code, (case when (sum(area) * surface) IS NULL then 0 else (sum(area) * surface) end) AS value
   FROM table1 
   INNER JOIN table2 on table1.code = table2.code 
   GROUP BY table2.code, surface
   ;
END;
$BODY$;

-- sql
CREATE OR REPLACE FUNCTION public.test_function2()
  RETURNS TABLE(code text, value real) 
  LANGUAGE SQL
AS $BODY$
   SELECT table2.code, (case when (sum(area) * surface) IS NULL then 0 else (sum(area) * surface) end) AS value
   FROM table1 
   INNER JOIN table2 on table1.code = table2.code 
   GROUP BY table2.code, surface
$BODY$;

-- Step 4: insert some random data
-- table 2
INSERT INTO table2(code, surface) VALUES ('AAAAA', 1);
INSERT INTO table2(code, surface) VALUES ('BBBBB', 1);
INSERT INTO table2(code, surface) VALUES ('CCCCC', 1);
INSERT INTO table2(code, surface) VALUES ('DDDDD', 1);
INSERT INTO table2(code, surface) VALUES ('EEEEE', 1);

-- table1 (will take some time, this simulate my current query with 10 millions rows)
DO
$$
DECLARE random_code text;
DECLARE code_count int := (SELECT COUNT(*) FROM table2);
BEGIN
     FOR i IN 1..10000000 LOOP
        random_code := (SELECT code FROM table2 OFFSET floor(random() * code_count) LIMIT 1);       
        INSERT INTO public.table1(area, code) VALUES (random() / 100, random_code);
    END LOOP;
END
$$  

-- Step 5: compare
SELECT * FROM test_function()
SELECT * FROM test_function2() -- 2 times faster

Execution plan for test_function (plpgsql version)

2021-04-14 11:52:10.335 GMT [5056] LOG:  duration: 3808.919 ms  plan:
    Query Text: SELECT table2.code, (case when (sum(area) * surface) IS NULL then 0 else (sum(area) * surface) end) AS value
       FROM table1 
       INNER JOIN table2 on table1.code = table2.code 
       GROUP BY table2.code, surface
    HashAggregate  (cost=459899.03..459918.08 rows=1270 width=40) (actual time=3808.908..3808.913 rows=5 loops=1)
      Group Key: table2.code
      Buffers: shared hit=34 read=162130
      ->  Hash Join  (cost=38.58..349004.15 rows=14785984 width=40) (actual time=215.340..2595.247 rows=10000000 loops=1)
            Hash Cond: (table1.code = table2.code)
            Buffers: shared hit=34 read=162130
            ->  Seq Scan on table1  (cost=0.00..310022.84 rows=14785984 width=10) (actual time=215.294..1036.615 rows=10000000 loops=1)
                  Buffers: shared hit=33 read=162130
            ->  Hash  (cost=22.70..22.70 rows=1270 width=36) (actual time=0.019..0.020 rows=5 loops=1)
                  Buckets: 2048  Batches: 1  Memory Usage: 17kB
                  Buffers: shared hit=1
                  ->  Seq Scan on table2  (cost=0.00..22.70 rows=1270 width=36) (actual time=0.013..0.014 rows=5 loops=1)
                        Buffers: shared hit=1
2021-04-14 11:52:10.335 GMT [5056] CONTEXT:  PL/pgSQL function test_function() line 3 at RETURN QUERY

Execution plan for test_function2 (sql version)

2021-04-14 11:54:24.122 GMT [5056] LOG:  duration: 1513.001 ms  plan:
    Query Text: 
       SELECT table2.code, (case when (sum(area) * surface) IS NULL then 0 else (sum(area) * surface) end) AS value
       FROM table1 
       INNER JOIN table2 on table1.code = table2.code 
       GROUP BY table2.code, surface
    
    Finalize GroupAggregate  (cost=271918.31..272252.77 rows=1270 width=40) (actual time=1484.846..1512.998 rows=5 loops=1)
      Group Key: table2.code
      Buffers: shared hit=96 read=162098
      ->  Gather Merge  (cost=271918.31..272214.67 rows=2540 width=40) (actual time=1484.840..1512.990 rows=15 loops=1)
            Workers Planned: 2
            Workers Launched: 2
            Buffers: shared hit=96 read=162098
            ->  Sort  (cost=270918.29..270921.46 rows=1270 width=40) (actual time=1435.897..1435.899 rows=5 loops=3)
                  Sort Key: table2.code
                  Sort Method: quicksort  Memory: 25kB
                  Worker 0:  Sort Method: quicksort  Memory: 25kB
                  Worker 1:  Sort Method: quicksort  Memory: 25kB
                  Buffers: shared hit=96 read=162098
                  ->  Partial HashAggregate  (cost=270840.11..270852.81 rows=1270 width=40) (actual time=1435.857..1435.863 rows=5 loops=3)
                        Group Key: table2.code
                        Buffers: shared hit=74 read=162098
                        ->  Hash Join  (cost=38.58..240035.98 rows=6160827 width=40) (actual time=204.916..1022.133 rows=3333333 loops=3)
                              Hash Cond: (table1.code = table2.code)
                              Buffers: shared hit=74 read=162098
                              ->  Parallel Seq Scan on table1  (cost=0.00..223771.27 rows=6160827 width=10) (actual time=204.712..486.850 rows=3333333 loops=3)
                                    Buffers: shared hit=65 read=162098
                              ->  Hash  (cost=22.70..22.70 rows=1270 width=36) (actual time=0.155..0.156 rows=5 loops=3)
                                    Buckets: 2048  Batches: 1  Memory Usage: 17kB
                                    Buffers: shared hit=3
                                    ->  Seq Scan on table2  (cost=0.00..22.70 rows=1270 width=36) (actual time=0.142..0.143 rows=5 loops=3)
                                          Buffers: shared hit=3
2021-04-14 11:54:24.122 GMT [5056] CONTEXT:  SQL function "test_function2" statement 1

Answer 1

First, a general discussion how to get execution plans in such a case

To get to the bottom of that, activate auto_explain and track function execution in postgresql.conf:

shared_preload_libraries = 'auto_explain'
auto_explain.log_min_duration = 0
auto_explain.log_analyze = on
auto_explain.log_buffers = on
auto_explain.log_nested_statements = on
track_functions = 'pl'

Then restart the database. Don't do that on a busy productive database, as it will log a lot and add considerable overhead!

Reset the database statistics with

SELECT pg_stat_reset();

Now the execution plans of all the SQL statements inside your functions will be logged, and PostgreSQL keeps track of function execution times.

Look at the execution plans and execution times of the statements when called from the SQL function and the PL/pgSQL function and see if you can spot a difference. Then compare the execution times in pg_stat_user_functions to compare the function execution time.

Explanation in the current case, after looking at the execution plans

The query run from PL/pgSQL is not parallelized. Due to a limitation in the implementation, queries run with RETURN QUERY never are.