huge runtime difference between 2 almost identical queries (was: Re: Index Scans become Seq Scans after VACUUM ANALYSE) - Mailing list pgsql-hackers

On Wed, Apr 17, 2002 at 12:44:24AM -0400, Tom Lane wrote:
> Louis-David Mitterrand <vindex@apartia.org> writes:
> > While trying to optimise a query I found that running VACUUM ANALYSE
> > changed all the Index Scans to Seq Scans and that the only way to revert
> > to Index Scans was the add "enable_seqscan = 0" in postgresql.conf.
> >> 
> >> EXPLAIN ANALYZE output would be more interesting than just EXPLAIN.
> >> Also, what does the pg_stats view show for these tables?
> 
> > Thanks, pg_stats output is rather big so I attached it in a separate
> > file. Here are the EXPLAIN ANALYZE ouputs:
> 
> Tell you the truth, I'm having a real hard time getting excited over
> a bug report that says the planner chose a plan taking 10.90 seconds
> in preference to one taking 7.96 seconds.

Now using a reduced test request I have a huge difference in runtime
(2317ms vs 4ms) on two almost identitcal queries. In both cases the
where clause uses the same table and pattern, however the slower query's
where-clause table appears at the end of the join:

gesci5=# explain analyse select p1.titre, p1.nom, p1.prenom,  p2.titre, p2.nom, p2.prenom from personne p1 join
prospectp on (p.id_personne1 = p1.id_personne) join  personne p2 on (p.id_personne2 = p2.id_personne) join contact cn
on(p.dernier_contact = cn.id_contact) where lower(p2.nom) like 'marl%' order by date_contact desc;
 
NOTICE:  QUERY PLAN:

Sort  (cost=5944.88..5944.88 rows=137 width=82) (actual time=2317.45..2317.45 rows=5 loops=1) ->  Nested Loop
(cost=2168.52..5940.00rows=137 width=82) (actual time=1061.58..2317.28 rows=5 loops=1)       ->  Hash Join
(cost=2168.52..5208.38rows=137 width=70) (actual time=1061.23..2316.01 rows=5 loops=1)             ->  Hash Join
(cost=1406.52..4238.55rows=27482 width=41) (actual time=355.60..2267.44 rows=27250 loops=1)                   ->  Seq
Scanon personne p1  (cost=0.00..1102.00 rows=44100 width=29) (actual time=0.12..303.42 rows=44100 loops=1)
    ->  Hash  (cost=1216.82..1216.82 rows=27482 width=12) (actual time=354.64..354.64 rows=0 loops=1)
     ->  Seq Scan on prospect p  (cost=0.00..1216.82 rows=27482 width=12) (actual time=0.11..257.51 rows=27482 loops=1)
           ->  Hash  (cost=761.45..761.45 rows=220 width=29) (actual time=0.33..0.33 rows=0 loops=1)
-> Index Scan using personne_nom on personne p2  (cost=0.00..761.45 rows=220 width=29) (actual time=0.07..0.29 rows=16
loops=1)      ->  Index Scan using contact_pkey on contact cn  (cost=0.00..5.31 rows=1 width=12) (actual
time=0.22..0.23rows=1 loops=5)
 
Total runtime: 2317.77 msec

EXPLAIN

gesci5=# explain analyse select p1.titre, p1.nom, p1.prenom,  p2.titre, p2.nom, p2.prenom from personne p1 join
prospectp on (p.id_personne1 = p1.id_personne) join  personne p2 on (p.id_personne2 = p2.id_personne) join contact cn
on(p.dernier_contact = cn.id_contact) where lower(p1.nom) like 'marl%' order by date_contact desc;
 
NOTICE:  QUERY PLAN:

Sort  (cost=3446.49..3446.49 rows=137 width=82) (actual time=3.85..3.85 rows=5 loops=1) ->  Nested Loop
(cost=0.00..3441.61rows=137 width=82) (actual time=1.86..3.55 rows=5 loops=1)       ->  Nested Loop
(cost=0.00..2709.99rows=137 width=70) (actual time=1.81..3.32 rows=5 loops=1)             ->  Nested Loop
(cost=0.00..2018.40rows=137 width=41) (actual time=0.58..2.41 rows=10 loops=1)                   ->  Index Scan using
personne_nomon personne p1  (cost=0.00..761.45 rows=220 width=29) (actual time=0.30..0.55 rows=16 loops=1)
    ->  Index Scan using prospect_personne1 on prospect p  (cost=0.00..5.69 rows=1 width=12) (actual time=0.10..0.11
rows=1loops=16)             ->  Index Scan using personne_pkey on personne p2  (cost=0.00..5.02 rows=1 width=29)
(actualtime=0.08..0.08 rows=0 loops=10)       ->  Index Scan using contact_pkey on contact cn  (cost=0.00..5.31 rows=1
width=12)(actual time=0.03..0.03 rows=1 loops=5)
 
Total runtime: 4.17 msec


--    PHEDRE: Il n'est plus temps. Il sait mes ardeurs insensées.           De l'austère pudeur les bornes sont
passées.                                        (Phèdre, J-B Racine, acte 3, scène 1)