query plan worse after analyze

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(at)frostconsultingllc(dot)com>
Frost Consulting, LLC http://www.frostconsultingllc.com/
Phone: 650-780-7908 FAX: 650-649-1954