Hello everyone,
this is very odd, particularly because there's obviously nobody having these
issues when I google for it.
I have a 8.3 database and decided for various reasons to upgrade to 8.4. I also
tried 9.0 - same results.
On the exactly same hardware with the exactly same configuration, some queries
perform a factor of 100000 slower on 8.4 and 9.0 than on 8.3
A factor that large leads me to believe that I'm missing something or the
queries in question were flawed to begin with (which may very well be)
Here's an example:
I have a forum with a table for the threads and a table for the posts. There's
also a table which keeps user specific things (email, user_id) and a table that
lets me assign roles (not database roles) to
a user (i.e. is an admin, is a normal user etc).
The posts table references the threads table (obviously, a post belongs to a
certain thread). I can post table specs, but I think it's rather obvious, so
I'll go to the explain outputs.
There is a view which contains the base query:
create or replace view v_grouptopics_helper_club16 as
select t.id, t.group_id, p.id as postid from groups_threads t left outer join
groups_posts p on p.thread_id=t.id AND t.deleted=false AND p.id = (SELECT p.id
FROM groups_posts p LEFT OUTER JOIN
user_group ugi on ugi.user_id=p.posted_by_uid AND ugi.group_id=16 WHERE
ugi.group_id IS NULL AND p.thread_id=t.id ORDER BY date_posted desc limit 1)
LEFT OUTER JOIN user_group ugt on
ugt.user_id=(select uid from bprofile where id=t.posted_by) AND ugt.group_id=16
WHERE ugt.group_id IS NULL AND t.deleted=false ORDER BY p.date_posted DESC;
So basically what I want is a list of latest forum topics with the latest post
where the user who posted either is not in the role with number 16.
When I do a
explain analyze select * from v_grouptopics_helper_club16 where group_id=199;
on the 8.3 server I get this result:
Subquery Scan v_grouptopics_helper_club16 (cost=4117.52..4118.17 rows=52
width=12) (actual time=5.959..6.173 rows=104 loops=1)
-> Sort (cost=4117.52..4117.65 rows=52 width=20) (actual time=5.957..6.029
rows=104 loops=1)
Sort Key: p.date_posted
Sort Method: quicksort Memory: 21kB
-> Nested Loop Left Join (cost=84.63..4116.04 rows=52 width=20)
(actual time=0.842..5.775 rows=104 loops=1)
Join Filter: ((NOT t.deleted) AND (p.thread_id = t.id))
-> Hash Left Join (cost=71.37..2445.93 rows=52 width=9)
(actual time=0.791..2.017 rows=104 loops=1)
Hash Cond: ((subplan) = ugt.user_id)
Filter: (ugt.group_id IS NULL)
-> Index Scan using groups_threads_group_idx on
groups_threads t (cost=0.00..237.18 rows=104 width=13) (actual
time=0.021..0.257 rows=104 loops=1)
Index Cond: (group_id = 199)
Filter: (NOT deleted)
-> Hash (cost=67.41..67.41 rows=317 width=8) (actual
time=0.741..0.741 rows=318 loops=1)
-> Index Scan using user_group_club16_idx on
user_group ugt (cost=0.00..67.41 rows=317 width=8) (actual time=0.024..0.430
rows=318 loops=1)
Index Cond: (group_id = 16)
SubPlan
-> Index Scan using bprofile_pkey on bprofile
(cost=0.00..5.87 rows=1 width=4) (actual time=0.005..0.006 rows=1 loops=104)
Index Cond: (id = $2)
-> Index Scan using groups_posts_pk on groups_posts p
(cost=13.26..18.84 rows=1 width=16) (actual time=0.005..0.006 rows=1 loops=104)
Index Cond: (p.id = (subplan))
SubPlan
-> Limit (cost=0.00..13.26 rows=1 width=12) (actual
time=0.024..0.024 rows=1 loops=104)
-> Nested Loop Left Join (cost=0.00..238.68
rows=18 width=12) (actual time=0.022..0.022 rows=1 loops=104)
Filter: (ugi.group_id IS NULL)
-> Index Scan Backward using
groups_posts_thread_date_idx on groups_posts p (cost=0.00..85.96 rows=35
width=16) (actual time=0.012..0.012 rows=1 loops=104)
Index Cond: (thread_id = $0)
-> Index Scan using user_group_uid_idx on
user_group ugi (cost=0.00..4.35 rows=1 width=8) (actual time=0.007..0.007
rows=0 loops=104)
Index Cond: (ugi.user_id =
p.posted_by_uid)
Filter: (ugi.group_id = 16)
-> Limit (cost=0.00..13.26 rows=1 width=12) (actual
time=0.024..0.024 rows=1 loops=104)
-> Nested Loop Left Join (cost=0.00..238.68
rows=18 width=12) (actual time=0.022..0.022 rows=1 loops=104)
Filter: (ugi.group_id IS NULL)
-> Index Scan Backward using
groups_posts_thread_date_idx on groups_posts p (cost=0.00..85.96 rows=35
width=16) (actual time=0.012..0.012 rows=1 loops=104)
Index Cond: (thread_id = $0)
-> Index Scan using user_group_uid_idx on
user_group ugi (cost=0.00..4.35 rows=1 width=8) (actual time=0.007..0.007
rows=0 loops=104)
Index Cond: (ugi.user_id =
p.posted_by_uid)
Filter: (ugi.group_id = 16)
Total runtime: 6.365 ms
(38 rows)
So the query executes in around 6ms, which is just dandy.
Here is the same output for the 8.4 server - keep in mind it's identical
machines with identical configuration (except the 8.4 machine has more memory,
but the config is the same):
Subquery Scan v_grouptopics_helper_club16 (cost=7054.97..7054.99 rows=1
width=12) (actual time=1354900.705..1354900.838 rows=105 loops=1)
-> Sort (cost=7054.97..7054.98 rows=1 width=20) (actual
time=1354900.702..1354900.747 rows=105 loops=1)
Sort Key: p.date_posted
Sort Method: quicksort Memory: 21kB
-> Nested Loop Left Join (cost=62.53..7054.96 rows=1 width=20)
(actual time=1.594..1354900.490 rows=105 loops=1)
Join Filter: ((NOT t.deleted) AND (p.id = (SubPlan 1)))
-> Hash Anti Join (cost=62.53..2432.89 rows=1 width=9) (actual
time=0.639..2.976 rows=105 loops=1)
Hash Cond: ((SubPlan 2) = ugt.user_id)
-> Index Scan using groups_threads_group_idx on
groups_threads t (cost=0.00..233.02 rows=104 width=13) (actual
time=0.024..0.528 rows=105 loops=1)
Index Cond: (group_id = 199)
Filter: (NOT deleted)
-> Hash (cost=58.55..58.55 rows=318 width=4) (actual
time=0.592..0.592 rows=318 loops=1)
-> Index Scan using user_group_club16_idx on
user_group ugt (cost=0.00..58.55 rows=318 width=4) (actual time=0.031..0.380
rows=318 loops=1)
Index Cond: (group_id = 16)
SubPlan 2
-> Index Scan using bprofile_pkey on bprofile
(cost=0.00..5.87 rows=1 width=4) (actual time=0.011..0.012 rows=1 loops=105)
Index Cond: (id = $1)
-> Index Scan using groups_posts_threadid_idx on groups_posts p
(cost=0.00..58.24 rows=34 width=16) (actual time=0.033..2.223 rows=919
loops=105)
Index Cond: (p.thread_id = t.id)
SubPlan 1
-> Limit (cost=134.21..134.22 rows=1 width=12) (actual
time=14.034..14.034 rows=1 loops=96470)
-> Sort (cost=134.21..134.22 rows=1 width=12) (actual
time=14.030..14.030 rows=1 loops=96470)
Sort Key: p.date_posted
Sort Method: top-N heapsort Memory: 17kB
-> Hash Anti Join (cost=62.53..134.20 rows=1
width=12) (actual time=0.038..10.850 rows=4540 loops=96470)
Hash Cond: (p.posted_by_uid = ugi.user_id)
-> Index Scan using
groups_posts_threadid_idx on groups_posts p (cost=0.00..71.29 rows=34
width=16) (actual time=0.034..5.287 rows=4540 loops=96470)
Index Cond: (thread_id = $0)
-> Hash (cost=58.55..58.55 rows=318
width=4) (actual time=0.511..0.511 rows=318 loops=1)
-> Index Scan using
user_group_club16_idx on user_group ugi (cost=0.00..58.55 rows=318 width=4)
(actual time=0.024..0.301 rows=318 loops=1)
Index Cond: (group_id = 16)
Total runtime: 1354901.025 ms
Not only does the plan look majorly different, it also loops a gazillion times
and seems to get it all wrong.
... and no, the database was dumped and restored, vacuumed, reindexed and
analyzed. It's just that something in the planner is different.
BTW: a query eliminating the left outer joins in favor of "not in" or "not
exists" subqueries leads to much better results, but is still in the 500ms
area, thus nowhere near the 6ms I used to have.
Does anyone have any smart ideas about this? It grinds my website to a halt.
Thanks
Uwe
--
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general
