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@xxxxxxxxxxxxxx)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general
