Why is 8.4 and 9.0 so much slower on some queries? - Mailing list pgsql-general

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
and9.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
(whichmay 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,
butI 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=falseAND 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
BYdate_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=falseORDER 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
inthe 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.006rows=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.006rows=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=1loops=104) 
                                   Filter: (ugi.group_id IS NULL)
                                   ->  Index Scan Backward using groups_posts_thread_date_idx on groups_posts p
(cost=0.00..85.96rows=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=1loops=104) 
                                   Filter: (ugi.group_id IS NULL)
                                   ->  Index Scan Backward using groups_posts_thread_date_idx on groups_posts p
(cost=0.00..85.96rows=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
the8.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.838rows=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.012rows=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)
(actualtime=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=4540loops=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=34width=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.55rows=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
planneris 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