Reasons for choosing one execution plan over another? - Mailing list pgsql-performance

Hi all,

I have a number of Postgres 9.2.4 databases with the same schema but with
slightly different contents, running on small servers that are basically
alike (8-16 GB ram).

When I run the same query on these databases it results in one of two
different execution plans where one is much faster (appx. 50 times) than
the other. Each database always gives the same plan, and vacuuming,
updating statistics and reindexing doesn't seem to make any difference.

Clearly the fast plan is preferred, but I haven't been able to identify
any pattern (table sizes, tuning etc.) in why one plan is chosen over the
other, so is there any way I can make Postgres tell me why it chooses to
plan the way it does?

As reference I have included the query and execution plans for two
different databases below. The x and e tables contain about 5 and 10
million records respectively, and the performance difference is perfectly
reasonable as the outer loop has to process 3576 rows in the fast case and
154149 rows in the slow case.

Best regards & thanks,
  Mikkel Lauritsen

---

Query:

SELECT x.r, e.id, a.id
FROM x
  INNER JOIN e ON x.id = e.id
  INNER JOIN a ON x.a_id = a.id
  INNER JOIN i ON a.i_id = i.id
WHERE e.h_id = 'foo' AND i.c = 'bar';

Fast plan:

 Nested Loop  (cost=0.00..24553.77 rows=1 width=86) (actual
time=2.810..102.451 rows=20 loops=1)
   Join Filter: (x.a_id = a.id)
   Rows Removed by Join Filter: 3556
   ->  Nested Loop  (cost=0.00..16.55 rows=1 width=39) (actual
time=0.036..0.046 rows=3 loops=1)
         ->  Index Scan using i_c_idx on i  (cost=0.00..8.27 rows=1
width=39) (actual time=0.019..0.020 rows=1 loops=1)
               Index Cond: (c = 'bar'::text)
         ->  Index Scan using a_i_id_idx on a  (cost=0.00..8.27 rows=1
width=78) (actual time=0.014..0.021 rows=3 loops=1)
               Index Cond: (i_id = i.id)
   ->  Nested Loop  (cost=0.00..24523.00 rows=1138 width=86) (actual
time=2.641..33.818 rows=1192 loops=3)
         ->  Index Scan using e_h_id_idx on e  (cost=0.00..6171.55
rows=1525 width=39) (actual time=0.049..1.108 rows=1857 loops=3)
               Index Cond: (h_id = 'foo'::text)
         ->  Index Scan using x_id_idx on x  (cost=0.00..12.02 rows=1
width=86) (actual time=0.017..0.017 rows=1 loops=5571)
               Index Cond: (id = e.id)
 Total runtime: 102.526 ms

Slow plan:

 Nested Loop  (cost=0.00..858.88 rows=1 width=86) (actual
time=89.430..2589.905 rows=11 loops=1)
   ->  Nested Loop  (cost=0.00..448.38 rows=169 width=86) (actual
time=0.135..142.246 rows=154149 loops=1)
         ->  Nested Loop  (cost=0.00..16.55 rows=1 width=39) (actual
time=0.056..0.064 rows=3 loops=1)
               ->  Index Scan using i_c_idx on i  (cost=0.00..8.27 rows=1
width=39) (actual time=0.030..0.030 rows=1 loops=1)
                     Index Cond: (c = 'bar'::text)
               ->  Index Scan using a_i_id_idx on a  (cost=0.00..8.27
rows=1 width=78) (actual time=0.022..0.028 rows=3 loops=1)
                     Index Cond: (i_id = i.id)
         ->  Index Scan using x_a_id_idx on x  (cost=0.00..372.48
rows=5935 width=86) (actual time=0.065..35.479 rows=51383 loops=3)
               Index Cond: (a_id = a.id)
   ->  Index Scan using e_pkey on e  (cost=0.00..2.42 rows=1 width=39)
(actual time=0.015..0.015 rows=0 loops=154149)
         Index Cond: (id = x.id)
         Filter: (h_id = 'foo'::text)
         Rows Removed by Filter: 1
 Total runtime: 2589.970 ms