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

Reply via email to