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

Unrelated to your problem, but: declare starts a block where multiple (all) variables can be declared. It is unnecessary to start a new declare block for each variable. — user330315
– user330315, Commented Apr 14, 2021 at 6:02

Laurenz Albe · Accepted Answer · 2021-04-14 14:30:56Z

7

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.

edited Apr 14, 2021 at 14:30

answered Apr 14, 2021 at 2:54

Laurenz Albe

257k22 gold badges313 silver badges389 bronze badges

Sign up to request clarification or add additional context in comments.

5 Comments

Pascal Veilleux Over a year ago

Thanks for your great answer, I edited my original post and added both execution plans. Any idea why there is a difference? SQL version is still a lot faster.

Laurenz Albe Over a year ago

The explanation is simple, but I don't think this can be avoided. See my updated answer.

Pascal Veilleux Over a year ago

Ahhh great this is exactly the explanation I was looking for, thanks!!

Erwin Brandstetter Over a year ago

Are you sure that track_functions = 'pl' is needed? I think that only affects whether function calls are counted for run-time statistics. SELECT pg_stat_reset(); has its use in that context, but is also unrelated to auto_explain. Aside: superusers can load auto_explain in the current session dynamically, no changes to postgresql.conf required. Related: dba.stackexchange.com/a/23357/3684 (But I wasn't aware that RETURN QUERY stands in the way of parallelization, thank you!)

Laurenz Albe Over a year ago

@ErwinBrandstetter It was perhaps confusing to mix these two things up. track_functions has nothing to do with auto_explain. I just thought it might provide additional, useful information. The question evolved over time - it started without execution plans, and I provided help how to get additional information.

Collectives™ on Stack Overflow

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

1 Answer 1

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

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

5 Comments

Your Answer

Hot Network Questions

Collectives™ on Stack Overflow

1 Answer 1

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

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

5 Comments

Your Answer

Sign up or log in

Post as a guest

Related