Hello,
We have a strange issue related to a prepared statement.
We have two equals queries where the sole difference is in the limit.
- The first is hard coded with limit 500.
- The second is prepared with limit $1 ($1 is bound to 500).
PostgreSQL give us two different plans with a huge execution time for the prepared query:
-----------------------------------------------------------------------------------------------------------------------
2- Static Query
-----------------------------------------------------------------------------------------------------------------------
explain analyze
select *
from dm2_lignecommandevente lignecomma0_
inner join dm2_lignedocumentcommercialvente lignecomma0_1_ on lignecomma0_.id=lignecomma0_1_.id
inner join dm1_lignedocumentcommercial lignecomma0_2_ on lignecomma0_.id=lignecomma0_2_.id
where (lignecomma0_.id not like 'DefaultRecord_%') and (lignecomma0_2_.dateFinValidite is null)
order by coalescedate(lignecomma0_2_.dateCreationSysteme) desc
limit 500
-------------------
Static query plan
-------------------
Limit (cost=0.00..12165.11 rows=500 width=909) (actual time=73.477..90.256 rows=500 loops=1)
-> Nested Loop (cost=0.00..11241165.90 rows=462025 width=909) (actual time=73.475..90.164 rows=500 loops=1)
-> Nested Loop (cost=0.00..9086881.29 rows=462025 width=852) (actual time=4.105..11.749 rows=500 loops=1)
-> Index Scan Backward using x_dm1_lignedocumentcommercial_14 on dm1_lignedocumentcommercial lignecomma0_2_ (cost=0.00..2744783.31 rows=1652194 width=541) (actual time=0.017..1.374 rows=1944 loops=1)
Filter: (datefinvalidite IS NULL)
-> Index Scan using dm2_lignecommandevente_pkey on dm2_lignecommandevente lignecomma0_ (cost=0.00..3.83 rows=1 width=311) (actual time=0.004..0.004 rows=0 loops=1944)
Index Cond: ((lignecomma0_.id)::text = (lignecomma0_2_.id)::text)
Filter: ((lignecomma0_.id)::text !~~ 'DefaultRecord_%'::text)
-> Index Scan using dm2_lignedocumentcommercialvente_pkey on dm2_lignedocumentcommercialvente lignecomma0_1_ (cost=0.00..4.40 rows=1 width=57) (actual time=0.005..0.005 rows=1 loops=500)
Index Cond: ((lignecomma0_1_.id)::text = (lignecomma0_.id)::text)
Total runtime: 90.572 ms
-----------------------------------------------------------------------------------------------------------------------
2- Prepared Query
-----------------------------------------------------------------------------------------------------------------------
PREPARE query(int) AS
select *
from dm2_lignecommandevente lignecomma0_
inner join dm2_lignedocumentcommercialvente lignecomma0_1_ on lignecomma0_.id=lignecomma0_1_.id
inner join dm1_lignedocumentcommercial lignecomma0_2_ on lignecomma0_.id=lignecomma0_2_.id
where (lignecomma0_.id not like 'DefaultRecord_%')
and (lignecomma0_2_.dateFinValidite is null)
order by coalescedate(lignecomma0_2_.dateCreationSysteme) desc
limit $1;
explain analyze
execute query(500);
-------------------
Prepared query plan
-------------------
Limit (cost=879927.25..880042.76 rows=46202 width=909) (actual time=69609.593..69609.642 rows=500 loops=1)
-> Sort (cost=879927.25..881082.32 rows=462025 width=909) (actual time=69609.588..69609.610 rows=500 loops=1)
Sort Key: (coalescedate(lignecomma0_2_.datecreationsysteme))
Sort Method: top-N heapsort Memory: 498kB
-> Hash Join (cost=164702.90..651691.22 rows=462025 width=909) (actual time=7786.467..68148.530 rows=470294 loops=1)
Hash Cond: ((lignecomma0_2_.id)::text = (lignecomma0_.id)::text)
-> Seq Scan on dm1_lignedocumentcommercial lignecomma0_2_ (cost=0.00..102742.36 rows=1652194 width=541) (actual time=0.009..50840.692 rows=1650554 loops=1)
Filter: (datefinvalidite IS NULL)
-> Hash (cost=136181.67..136181.67 rows=472579 width=368) (actual time=7681.787..7681.787 rows=472625 loops=1)
-> Hash Join (cost=40690.06..136181.67 rows=472579 width=368) (actual time=986.580..7090.877 rows=472625 loops=1)
Hash Cond: ((lignecomma0_1_.id)::text = (lignecomma0_.id)::text)
-> Seq Scan on dm2_lignedocumentcommercialvente lignecomma0_1_ (cost=0.00..29881.18 rows=1431818 width=57) (actual time=14.401..2288.869 rows=1431818 loops=1)
-> Hash (cost=15398.83..15398.83 rows=472579 width=311) (actual time=967.209..967.209 rows=472625 loops=1)
-> Seq Scan on dm2_lignecommandevente lignecomma0_ (cost=0.00..15398.83 rows=472579 width=311) (actual time=18.154..662.185 rows=472625 loops=1)
Filter: ((id)::text !~~ 'DefaultRecord_%'::text)
Total runtime: 69612.191 ms
-----------------------------------------------------------------------------------------------------------------------
We saw that both folowing queries give the same plan :
- Static query with limit 500 removed
explain analyzeselect *from dm2_lignecommandevente lignecomma0_inner join dm2_lignedocumentcommercialvente lignecomma0_1_ on lignecomma0_.id=lignecomma0_1_.idinner join dm1_lignedocumentcommercial lignecomma0_2_ on lignecomma0_.id=lignecomma0_2_.idwhere (lignecomma0_.id not like 'DefaultRecord_%') and (lignecomma0_2_.dateFinValidite is null)order by coalescedate(lignecomma0_2_.dateCreationSysteme) desc
- The bad prepared query
PREPARE query(int) ASselect *from dm2_lignecommandevente lignecomma0_inner join dm2_lignedocumentcommercialvente lignecomma0_1_ on lignecomma0_.id=lignecomma0_1_.idinner join dm1_lignedocumentcommercial lignecomma0_2_ on lignecomma0_.id=lignecomma0_2_.idwhere (lignecomma0_.id not like 'DefaultRecord_%')and (lignecomma0_2_.dateFinValidite is null)order by coalescedate(lignecomma0_2_.dateCreationSysteme) desclimit $1;
explain analyzeexecute query(500);
We met the same behaviour with both :
- PostgreSQL 8.4.8 on Windows 2008 (Prod)
- PostgreSQL 8.4.8 and 8.4.17 on Windows 7 (Dev)
I hope someone has any idea.
Ghislain ROUVIGNAC
