query plan worse after analyze - Mailing list pgsql-performance

Postgresql: 8.2.4 and 8.2.5

I've run into a really strange problem.  I have a query that runs much
slower after analyze.  I load the DB, then run the query and it runs in
about 200ms.  I then analyze the DB, run the query again and it takes about
1500ms.  Before analyze it seems to choose Bitmap Heap Scan on episodes
current_episode, but after it chooses Index Scan Backward using
index_episodes_on_publish_on on episodes current_episode.  I've tried it on
two different pg servers and the results are same with default
random_page_cost and with random_page_cost = 2.  The entire DB is only 8MB
so easily fits in memory on all the test systems.  Any ideas what's going
on?  Setting enable_indexscan = 0 also yields a fast (200ms) plan, so that's
a workaround.

Here are the plans:


jeff=# explain ANALYZE   SELECT DISTINCT ON (shows.id) shows.id,
seasons.position AS alias_0 FROM shows
  LEFT OUTER JOIN images ON images.id = shows.landing_page_image_id
  LEFT OUTER JOIN seasons ON seasons.show_id = shows.id
  LEFT OUTER JOIN episodes ON episodes.season_id = seasons.id AND
episodes.publish_on = (
    SELECT MAX(current_episode.publish_on) AS publish_on FROM episodes AS
current_episode
     WHERE current_episode.publish_on IS NOT NULL AND
current_episode.publish_on <= NOW()
       AND current_episode.season_id = episodes.season_id
  )
  LEFT OUTER JOIN seasons current_seasons_shows ON
current_seasons_shows.show_id = shows.id AND seasons.position = (
    SELECT MAX(latest_unvaulted_season.position) FROM seasons AS
latest_unvaulted_season, episodes
    WHERE latest_unvaulted_season.show_id = seasons.show_id AND (
      latest_unvaulted_season.vaults_on IS NULL OR
latest_unvaulted_season.vaults_on > NOW()
    )
    AND episodes.season_id = latest_unvaulted_season.id AND
episodes.publish_on IS NOT NULL
    AND episodes.publish_on <= NOW()
  )
  LEFT OUTER JOIN episodes current_episodes_seasons ON
current_episodes_seasons.season_id = current_seasons_shows.id
  AND episodes.publish_on = (
    SELECT MAX(current_episode.publish_on) AS publish_on FROM episodes AS
current_episode
    WHERE current_episode.publish_on IS NOT NULL AND
current_episode.publish_on <= NOW()
    AND current_episode.season_id = episodes.season_id
  )
  WHERE (
    ( shows.deleted_at IS NULL OR shows.deleted_at > '2007-10-05
21:14:02.438466' )
    AND ( shows.archived_at IS NULL OR shows.archived_at > '2007-10-05
21:14:02.438559' )
  )
  AND (episodes.id IS NOT NULL AND current_seasons_shows.id IS NOT NULL)
;


QUERY PLAN

----------------------------------------------------------------------------
--------------------------------------------------
----------------------------------------------------------------------------
--------------------------------------------------
-------
 Unique  (cost=106.63..106.64 rows=1 width=8) (actual time=178.931..181.528
rows=29 loops=1)
   ->  Sort  (cost=106.63..106.64 rows=1 width=8) (actual
time=178.931..180.120 rows=6229 loops=1)
         Sort Key: shows.id
         ->  Nested Loop Left Join  (cost=2.27..106.62 rows=1 width=8)
(actual time=0.302..175.506 rows=6229 loops=1)
               Join Filter: (episodes.publish_on = (subplan))
               ->  Nested Loop Left Join  (cost=2.27..80.66 rows=1 width=24)
(actual time=0.262..21.725 rows=500 loops=1)
                     ->  Nested Loop  (cost=2.27..76.88 rows=1 width=28)
(actual time=0.221..19.641 rows=500 loops=1)
                           Join Filter: (current_seasons_shows.show_id =
shows.id)
                           ->  Nested Loop  (cost=2.27..74.55 rows=1
width=28) (actual time=0.215..10.716 rows=267 loops=1)
                                 ->  Nested Loop  (cost=0.00..45.72 rows=1
width=20) (actual time=0.164..2.593 rows=29 loops=1
)
                                       ->  Seq Scan on shows
(cost=0.00..1.51 rows=4 width=8) (actual time=0.010..0.033 rows=
33 loops=1)
                                             Filter: (((deleted_at IS NULL)
OR (deleted_at > '2007-10-05 21:14:02.438466'::tim
estamp without time zone)) AND ((archived_at IS NULL) OR (archived_at >
'2007-10-05 21:14:02.438559'::timestamp without time z
one)))
                                       ->  Index Scan using
index_seasons_on_show_id_and_position on seasons  (cost=0.00..11.0
4 rows=1 width=12) (actual time=0.076..0.076 rows=1 loops=33)
                                             Index Cond: (seasons.show_id =
shows.id)
                                             Filter: ("position" =
(subplan))
                                             SubPlan
                                               ->  Aggregate
(cost=9.26..9.27 rows=1 width=4) (actual time=0.040..0.040 rows=
1 loops=58)
                                                     ->  Nested Loop
(cost=2.27..9.25 rows=1 width=4) (actual time=0.015..0.0
36 rows=12 loops=58)
                                                           ->  Seq Scan on
seasons latest_unvaulted_season  (cost=0.00..2.03 r
ows=1 width=8) (actual time=0.004..0.009 rows=1 loops=58)
                                                                 Filter:
((show_id = $1) AND ((vaults_on IS NULL) OR (vaults_o
n > now())))
                                                           ->  Bitmap Heap
Scan on episodes  (cost=2.27..7.18 rows=3 width=4)
(actual time=0.009..0.019 rows=11 loops=62)
                                                                 Recheck
Cond: (episodes.season_id = latest_unvaulted_season.i
d)
                                                                 Filter:
((publish_on IS NOT NULL) AND (publish_on <= now()))
                                                                 ->  Bitmap
Index Scan on index_episodes_on_season_id  (cost=0
.00..2.27 rows=3 width=0) (actual time=0.005..0.005 rows=12 loops=62)
                                                                       Index
Cond: (episodes.season_id = latest_unvaulted_seas
on.id)
                                 ->  Bitmap Heap Scan on episodes
(cost=2.27..28.80 rows=3 width=12) (actual time=0.041..0.27
4 rows=9 loops=29)
                                       Recheck Cond: (episodes.season_id =
seasons.id)
                                       Filter: ((id IS NOT NULL) AND
(publish_on = (subplan)))
                                       ->  Bitmap Index Scan on
index_episodes_on_season_id  (cost=0.00..2.27 rows=3 width=0)
(actual time=0.005..0.005 rows=11 loops=29)
                                             Index Cond: (episodes.season_id
= seasons.id)
                                       SubPlan
                                         ->  Aggregate  (cost=7.20..7.21
rows=1 width=8) (actual time=0.022..0.022 rows=1 loop
s=324)
                                               ->  Bitmap Heap Scan on
episodes current_episode  (cost=2.27..7.19 rows=1 width
=8) (actual time=0.007..0.016 rows=12 loops=324)
                                                     Recheck Cond:
(season_id = $0)
                                                     Filter: ((publish_on IS
NOT NULL) AND (publish_on <= now()))
                                                     ->  Bitmap Index Scan
on index_episodes_on_season_id  (cost=0.00..2.27 ro
ws=3 width=0) (actual time=0.004..0.004 rows=12 loops=324)
                                                           Index Cond:
(season_id = $0)
                           ->  Seq Scan on seasons current_seasons_shows
(cost=0.00..1.59 rows=59 width=8) (actual time=0.002
..0.018 rows=59 loops=267)
                                 Filter: (id IS NOT NULL)
                     ->  Index Scan using images_pkey on images
(cost=0.00..3.77 rows=1 width=4) (actual time=0.003..0.003 ro
ws=1 loops=500)
                           Index Cond: (images.id =
shows.landing_page_image_id)
               ->  Index Scan using index_episodes_on_season_id on episodes
current_episodes_seasons  (cost=0.00..4.30 rows=3
width=4) (actual time=0.002..0.009 rows=12 loops=500)
                     Index Cond: (current_episodes_seasons.season_id =
current_seasons_shows.id)
               SubPlan
                 ->  Aggregate  (cost=7.20..7.21 rows=1 width=8) (actual
time=0.022..0.022 rows=1 loops=6229)
                       ->  Bitmap Heap Scan on episodes current_episode
(cost=2.27..7.19 rows=1 width=8) (actual time=0.007..
0.016 rows=13 loops=6229)
                             Recheck Cond: (season_id = $0)
                             Filter: ((publish_on IS NOT NULL) AND
(publish_on <= now()))
                             ->  Bitmap Index Scan on
index_episodes_on_season_id  (cost=0.00..2.27 rows=3 width=0) (actual ti
me=0.004..0.004 rows=13 loops=6229)
                                   Index Cond: (season_id = $0)
 Total runtime: 181.829 ms
(51 rows)


Now, analyze comes along and updates the statistics for me:

jeff=# ANALYZE ;
ANALYZE


QUERY
 PLAN

----------------------------------------------------------------------------
--------------------------------------------------
----------------------------------------------------------------------------
--------------------------------------------------
-
 Unique  (cost=0.00..1226.04 rows=1 width=8) (actual time=1.121..1472.459
rows=29 loops=1)
   ->  Nested Loop Left Join  (cost=0.00..1226.03 rows=1 width=8) (actual
time=1.120..1470.904 rows=6229 loops=1)
         Join Filter: (episodes.publish_on = (subplan))
         ->  Nested Loop Left Join  (cost=0.00..1156.52 rows=1 width=24)
(actual time=0.662..99.337 rows=500 loops=1)
               ->  Nested Loop  (cost=0.00..1155.40 rows=1 width=28) (actual
time=0.655..97.353 rows=500 loops=1)
                     Join Filter: (current_seasons_shows.show_id = shows.id)
                     ->  Nested Loop  (cost=0.00..1153.07 rows=1 width=28)
(actual time=0.652..88.459 rows=267 loops=1)
                           ->  Nested Loop  (cost=0.00..1062.02 rows=1
width=20) (actual time=0.089..3.140 rows=29 loops=1)
                                 Join Filter: (seasons.show_id = shows.id)
                                 ->  Index Scan using
index_seasons_on_show_id_and_position on seasons  (cost=0.00..1060.12 ro
ws=1 width=12) (actual time=0.065..2.466 rows=30 loops=1)
                                       Filter: ("position" = (subplan))
                                       SubPlan
                                         ->  Aggregate  (cost=17.83..17.84
rows=1 width=4) (actual time=0.039..0.040 rows=1 lo
ops=59)
                                               ->  Nested Loop
(cost=2.34..17.80 rows=11 width=4) (actual time=0.016..0.035 r
ows=12 loops=59)
                                                     ->  Seq Scan on seasons
latest_unvaulted_season  (cost=0.00..2.03 rows=1
width=8) (actual time=0.004..0.009 rows=1 loops=59)
                                                           Filter: ((show_id
= $2) AND ((vaults_on IS NULL) OR (vaults_on > no
w())))
                                                     ->  Bitmap Heap Scan on
episodes  (cost=2.34..15.62 rows=12 width=4) (act
ual time=0.009..0.017 rows=11 loops=63)
                                                           Recheck Cond:
(episodes.season_id = latest_unvaulted_season.id)
                                                           Filter:
((publish_on IS NOT NULL) AND (publish_on <= now()))
                                                           ->  Bitmap Index
Scan on index_episodes_on_season_id  (cost=0.00..2
.34 rows=12 width=0) (actual time=0.006..0.006 rows=11 loops=63)
                                                                 Index Cond:
(episodes.season_id = latest_unvaulted_season.id)
                                 ->  Seq Scan on shows  (cost=0.00..1.51
rows=31 width=8) (actual time=0.002..0.013 rows=33 lo
ops=30)
                                       Filter: (((deleted_at IS NULL) OR
(deleted_at > '2007-10-05 21:14:02.438466'::timestamp
 without time zone)) AND ((archived_at IS NULL) OR (archived_at >
'2007-10-05 21:14:02.438559'::timestamp without time zone)))
                           ->  Index Scan using index_episodes_on_season_id
on episodes  (cost=0.00..91.04 rows=1 width=12) (a
ctual time=0.466..2.936 rows=9 loops=29)
                                                           ->  Bitmap Index
Scan on index_episodes_on_season_id  (cost=0.00..2
.34 rows=12 width=0) (actual time=0.006..0.006 rows=11 loops=63)
                                                                 Index Cond:
(episodes.season_id = latest_unvaulted_season.id)
                                 ->  Seq Scan on shows  (cost=0.00..1.51
rows=31 width=8) (actual time=0.002..0.013 rows=33 lo
ops=30)
                                       Filter: (((deleted_at IS NULL) OR
(deleted_at > '2007-10-05 21:14:02.438466'::timestamp
 without time zone)) AND ((archived_at IS NULL) OR (archived_at >
'2007-10-05 21:14:02.438559'::timestamp without time zone)))
                           ->  Index Scan using index_episodes_on_season_id
on episodes  (cost=0.00..91.04 rows=1 width=12) (a
ctual time=0.466..2.936 rows=9 loops=29)
                                 Index Cond: (episodes.season_id =
seasons.id)
                                 Filter: ((id IS NOT NULL) AND (publish_on =
(subplan)))
                                 SubPlan
                                   ->  Result  (cost=5.70..5.71 rows=1
width=0) (actual time=0.261..0.261 rows=1 loops=324)
                                         InitPlan
                                           ->  Limit  (cost=0.00..5.70
rows=1 width=8) (actual time=0.259..0.260 rows=1 loops=
324)
                                                 ->  Index Scan Backward
using index_episodes_on_publish_on on episodes curren
t_episode  (cost=0.00..62.72 rows=11 width=8) (actual time=0.258..0.258
rows=1 loops=324)
                                                       Index Cond:
(publish_on <= now())
                                                       Filter: ((publish_on
IS NOT NULL) AND (season_id = $0))
                     ->  Seq Scan on seasons current_seasons_shows
(cost=0.00..1.59 rows=59 width=8) (actual time=0.002..0.01
7 rows=59 loops=267)
                           Filter: (id IS NOT NULL)
               ->  Index Scan using images_pkey on images  (cost=0.00..1.11
rows=1 width=4) (actual time=0.002..0.003 rows=1 l
oops=500)
                     Index Cond: (images.id = shows.landing_page_image_id)
         ->  Index Scan using index_episodes_on_season_id on episodes
current_episodes_seasons  (cost=0.00..0.77 rows=12 width
=4) (actual time=0.002..0.008 rows=12 loops=500)
               Index Cond: (current_episodes_seasons.season_id =
current_seasons_shows.id)
         SubPlan
           ->  Result  (cost=5.70..5.71 rows=1 width=0) (actual
time=0.218..0.218 rows=1 loops=6229)
                 InitPlan
                   ->  Limit  (cost=0.00..5.70 rows=1 width=8) (actual
time=0.217..0.217 rows=1 loops=6229)
                         ->  Index Scan Backward using
index_episodes_on_publish_on on episodes current_episode  (cost=0.00..6
2.72 rows=11 width=8) (actual time=0.216..0.216 rows=1 loops=6229)
                               Index Cond: (publish_on <= now())
                               Filter: ((publish_on IS NOT NULL) AND
(season_id = $0))
 Total runtime: 1472.613 ms
(47 rows)

set enable_indexscan = 0;


QU
ERY PLAN

----------------------------------------------------------------------------
--------------------------------------------------
----------------------------------------------------------------------------
--------------------------------------------------
-------
 Unique  (cost=1456.34..1456.35 rows=1 width=8) (actual
time=180.423..183.024 rows=29 loops=1)
   ->  Sort  (cost=1456.34..1456.35 rows=1 width=8) (actual
time=180.422..181.624 rows=6229 loops=1)
         Sort Key: shows.id
         ->  Nested Loop Left Join  (cost=3.31..1456.33 rows=1 width=8)
(actual time=0.165..177.225 rows=6229 loops=1)
               Join Filter: (episodes.publish_on = (subplan))
               ->  Nested Loop Left Join  (cost=2.92..1265.33 rows=1
width=24) (actual time=0.133..22.742 rows=500 loops=1)
                     ->  Nested Loop  (cost=2.34..1262.73 rows=1 width=28)
(actual time=0.125..20.141 rows=500 loops=1)
                           Join Filter: (current_seasons_shows.show_id =
shows.id)
                           ->  Nested Loop  (cost=2.34..1260.40 rows=1
width=28) (actual time=0.122..11.087 rows=267 loops=1)
                                 ->  Nested Loop  (cost=0.00..1056.47 rows=1
width=20) (actual time=0.087..2.966 rows=29 loops
=1)
                                       Join Filter: (seasons.show_id =
shows.id)
                                       ->  Seq Scan on seasons
(cost=0.00..1054.57 rows=1 width=12) (actual time=0.063..2.309
 rows=30 loops=1)
                                             Filter: ("position" =
(subplan))
                                             SubPlan
                                               ->  Aggregate
(cost=17.83..17.84 rows=1 width=4) (actual time=0.037..0.038 row
s=1 loops=59)
                                                     ->  Nested Loop
(cost=2.34..17.80 rows=11 width=4) (actual time=0.014..0
.033 rows=12 loops=59)
                                                           ->  Seq Scan on
seasons latest_unvaulted_season  (cost=0.00..2.03 r
ows=1 width=8) (actual time=0.004..0.009 rows=1 loops=59)
                                                                 Filter:
((show_id = $1) AND ((vaults_on IS NULL) OR (vaults_o
n > now())))
                                                           ->  Bitmap Heap
Scan on episodes  (cost=2.34..15.62 rows=12 width=4
) (actual time=0.008..0.016 rows=11 loops=63)
                                                                 Recheck
Cond: (episodes.season_id = latest_unvaulted_season.i
d)
                                                                 Filter:
((publish_on IS NOT NULL) AND (publish_on <= now()))
                                                                 ->  Bitmap
Index Scan on index_episodes_on_season_id  (cost=0
.00..2.34 rows=12 width=0) (actual time=0.005..0.005 rows=11 loops=63)
                                                                       Index
Cond: (episodes.season_id = latest_unvaulted_seas
on.id)
                                       ->  Seq Scan on shows
(cost=0.00..1.51 rows=31 width=8) (actual time=0.002..0.012 rows
=33 loops=30)
                                             Filter: (((deleted_at IS NULL)
OR (deleted_at > '2007-10-05 21:14:02.438466'::tim
estamp without time zone)) AND ((archived_at IS NULL) OR (archived_at >
'2007-10-05 21:14:02.438559'::timestamp without time z
one)))
                                 ->  Bitmap Heap Scan on episodes
(cost=2.34..203.90 rows=3 width=12) (actual time=0.041..0.2
74 rows=9 loops=29)
                                       Recheck Cond: (episodes.season_id =
seasons.id)
                                       Filter: ((id IS NOT NULL) AND
(publish_on = (subplan)))
                                       ->  Bitmap Index Scan on
index_episodes_on_season_id  (cost=0.00..2.34 rows=12 width=0)
 (actual time=0.005..0.005 rows=11 loops=29)
                                             Index Cond: (episodes.season_id
= seasons.id)
                                       SubPlan
                                         ->  Aggregate  (cost=15.68..15.69
rows=1 width=8) (actual time=0.022..0.022 rows=1 lo
ops=324)
                                               ->  Bitmap Heap Scan on
episodes current_episode  (cost=2.34..15.65 rows=11 wid
th=8) (actual time=0.007..0.016 rows=12 loops=324)
                                                     Recheck Cond:
(season_id = $0)
                                                     Filter: ((publish_on IS
NOT NULL) AND (publish_on <= now()))
                                                     ->  Bitmap Index Scan
on index_episodes_on_season_id  (cost=0.00..2.34 ro
ws=12 width=0) (actual time=0.004..0.004 rows=12 loops=324)
                                                           Index Cond:
(season_id = $0)
                           ->  Seq Scan on seasons current_seasons_shows
(cost=0.00..1.59 rows=59 width=8) (actual time=0.002
..0.018 rows=59 loops=267)
                                 Filter: (id IS NOT NULL)
                     ->  Bitmap Heap Scan on images  (cost=0.58..2.59 rows=1
width=4) (actual time=0.003..0.003 rows=1 loops=5
00)
                           Recheck Cond: (images.id =
shows.landing_page_image_id)
                           ->  Bitmap Index Scan on images_pkey
(cost=0.00..0.58 rows=1 width=0) (actual time=0.002..0.002 ro
ws=1 loops=500)
                                 Index Cond: (images.id =
shows.landing_page_image_id)
               ->  Bitmap Heap Scan on episodes current_episodes_seasons
(cost=0.39..2.51 rows=12 width=4) (actual time=0.006
..0.010 rows=12 loops=500)
                     Recheck Cond: (current_episodes_seasons.season_id =
current_seasons_shows.id)
                     ->  Bitmap Index Scan on index_episodes_on_season_id
(cost=0.00..0.39 rows=12 width=0) (actual time=0.00
4..0.004 rows=12 loops=500)
                           Index Cond: (current_episodes_seasons.season_id =
current_seasons_shows.id)
               SubPlan
                 ->  Aggregate  (cost=15.68..15.69 rows=1 width=8) (actual
time=0.022..0.022 rows=1 loops=6229)
                       ->  Bitmap Heap Scan on episodes current_episode
(cost=2.34..15.65 rows=11 width=8) (actual time=0.007
..0.016 rows=13 loops=6229)
                             Recheck Cond: (season_id = $0)
                             Filter: ((publish_on IS NOT NULL) AND
(publish_on <= now()))
                             ->  Bitmap Index Scan on
index_episodes_on_season_id  (cost=0.00..2.34 rows=12 width=0) (actual t
ime=0.004..0.004 rows=13 loops=6229)
                                   Index Cond: (season_id = $0)
 Total runtime: 183.160 ms
(55 rows)


----
Jeff Frost, Owner       <jeff@frostconsultingllc.com>
Frost Consulting, LLC   http://www.frostconsultingllc.com/
Phone: 650-780-7908     FAX: 650-649-1954