Differents execution times with gin index, prepared statement and literals. - Mailing list pgsql-hackers
From | Pierrick Chovelon |
---|---|
Subject | Differents execution times with gin index, prepared statement and literals. |
Date | |
Msg-id | 25c2ce5f-08ed-4e80-a852-9fc2151d0252@dalibo.com Whole thread Raw |
Responses |
Re: Differents execution times with gin index, prepared statement and literals.
|
List | pgsql-hackers |
Hello,
One of our customer is facing an issue regarding a prepared statement and a gin index.
An important gap between execution times can be shown when using execute or plain literals.
Here is the test that shown this issue :
Init table :
create table tmp_tk_test_index ( sync_id bigint, line_id varchar(50), chk_upgrade_index smallint default 0 ); create index idx_tmp_tk_test_index_1 on tmp_tk_test_index using gin (sync_id, line_id); insert into tmp_tk_test_index SELECT tb_seq as sync_id, case when tb_seq = 950000 then 'the-test-value-fa529a621a15' else gen_random_uuid()::text end as line_id FROM generate_series(1,1000000) as tb_seq;
Prepare query :
prepare stmt(bigint, text, int) as delete from tmp_tk_test_index where sync_id <= $1 and line_id = $2 and chk_upgrade_index = $3;
And then execute it :
postgres=# begin; BEGIN postgres=*# explain (analyse) execute stmt(950000, 'the-test-value-fa529a621a15', 0); QUERY PLAN ----------------------------------------------------------------------------------------------------------------------- Delete on tmp_tk_test_index (cost=212.52..2662.59 rows=0 width=0) (actual time=60.766..60.767 rows=0 loops=1) -> Bitmap Heap Scan on tmp_tk_test_index (cost=212.52..2662.59 rows=4 width=6) (actual time=60.756..60.758 rows=1 loops=1) Recheck Cond: ((sync_id <= '950000'::bigint) AND ((line_id)::text = 'the-test-value-fa529a621a15'::text)) Filter: (chk_upgrade_index = 0) Heap Blocks: exact=1 -> Bitmap Index Scan on idx_tmp_tk_test_index_1 (cost=0.00..212.52 rows=810 width=0) (actual time=60.745..60 .745 rows=1 loops=1) Index Cond: ((sync_id <= '950000'::bigint) AND ((line_id)::text = 'the-test-value-fa529a621a15'::text)) Planning Time: 6.765 ms Execution Time: 61.160 ms (9 rows) postgres=*# rollback ; ROLLBACK
It takes 61.160ms to be executed. However, the "same" query without a prepared statement is far faster :
postgres=# begin; BEGIN postgres=*# explain analyze delete from tmp_tk_test_index where sync_id <= 950000 and line_id = 'the-test-value-fa529a621a15' and chk_upgrade_index = 0;
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------
----------------
Delete on tmp_tk_test_index (cost=21.36..25.38 rows=0 width=0) (actual time=0.084..0.085 rows=0 loops=1)
-> Bitmap Heap Scan on tmp_tk_test_index (cost=21.36..25.38 rows=1 width=6) (actual time=0.042..0.043 rows=1 loops
=1)
Recheck Cond: ((line_id)::text = 'the-test-value-fa529a621a15'::text)
Filter: ((sync_id <= 950000) AND (chk_upgrade_index = 0))
Heap Blocks: exact=1
-> Bitmap Index Scan on idx_tmp_tk_test_index_1 (cost=0.00..21.36 rows=1 width=0) (actual time=0.027..0.028
rows=1 loops=1)
Index Cond: ((line_id)::text = 'the-test-value-fa529a621a15'::text)
Planning Time: 0.325 ms
Execution Time: 0.148 ms
(9 rows)
postgres=*# rollback ;
ROLLBACK
Only 0.148ms to be executed...
What can cause this quite important gap ? (0.148ms vs 61.160ms).
In the explain plan, I can see that the Index Cond is different : in the slowest case (sync_id <= '950000'::bigint) is present.
Why isn't it present in the second case ?
Two more tests :
The prepared statement is tweaked with sync_id+0. The query is fast :
prepare stmt3(bigint, text, int) as delete from tmp_tk_test_index where sync_id+0 <= $1 and line_id = $2 and chk_upgrade_index = $3; explain (analyse) execute stmt3(950000, 'the-test-value-fa529a621a15', 0);
Delete on tmp_tk_test_index (cost=21.36..25.38 rows=0 width=0) (actual time=0.057..0.058 rows=0 loops=1)
-> Bitmap Heap Scan on tmp_tk_test_index (cost=21.36..25.38 rows=1 width=6) (actual time=0.040..0.042 rows=1 loops
=1)
Recheck Cond: ((line_id)::text = 'the-test-value-fa529a621a15'::text)
Filter: ((chk_upgrade_index = 0) AND ((sync_id + 0) <= '950000'::bigint))
Heap Blocks: exact=1
-> Bitmap Index Scan on idx_tmp_tk_test_index_1 (cost=0.00..21.36 rows=1 width=0) (actual time=0.020..0.020
rows=1 loops=1)
Index Cond: ((line_id)::text = 'the-test-value-fa529a621a15'::text)
Planning Time: 0.355 ms
Execution Time: 0.101 ms
(9 rows)
And one with an index but without sync_id inside it. Prepared statement isn't changed.
create index idx_tmp_tk_test_index_2 on tmp_tk_test_index using gin (line_id);
Delete on tmp_tk_test_index (cost=21.36..25.38 rows=0 width=0) (actual time=0.052..0.053 rows=0 loops=1) -> Bitmap Heap Scan on tmp_tk_test_index (cost=21.36..25.38 rows=1 width=6) (actual time=0.036..0.038 rows=1 loops =1) Recheck Cond: ((line_id)::text = 'the-test-value-fa529a621a15'::text) Filter: ((sync_id <= '950000'::bigint) AND (chk_upgrade_index = 0)) Heap Blocks: exact=1 -> Bitmap Index Scan on idx_tmp_tk_test_index_2 (cost=0.00..21.36 rows=1 width=0) (actual time=0.020..0.021 rows=1 loops=1) Index Cond: ((line_id)::text = 'the-test-value-fa529a621a15'::text) Planning Time: 0.439 ms Execution Time: 0.098 ms (9 rows
Quite fast as well...
Have you got an idea on the initial issue ? Why when using a prepared statement and a gin index the execution time "explode" ?
Something to do with the planner ? optimizer ?
(We executed the same test with a btree index and execution times are the same in both cases).
Regards
pgsql-hackers by date: