Re: Performance problems with 9.2.15 - Mailing list pgsql-performance

> > The rowcount estimates from 9.2 seem greatly different from the 8.4 plan.
> > Did you remember to ANALYZE all the tables after migrating?  Maybe there
> > were some table-specific statistics targets that you forgot to transfer
> > over?  In any case, the 9.2 plan looks like garbage-in-garbage-out to
> > me :-( ... without estimates at least a little closer to reality, the
> > planner is unlikely to do anything very sane.
> >
> > (BTW, I wonder why you are moving only to 9.2 and not something more
> > recent.)
>
> You put me on the right track with your conclusion that the estimates
> were off the chart. The quick-and-dirty fix "DELETE FROM pg_statistic;"
> solved this problem. This database now have to build up sane estimates
> from scratch.

Actually it took a VACUUM FULL; and DELETE FROM pg_statistic; followed
by ANALYZE on all tables to get it right.

Can someone please explain to me the difference between these two query
plans:

The bad one:
 Unique  (cost=6037.10..6037.18 rows=1 width=434) (actual
time=255608.588..255646.828 rows=572 loops=1)
   ->  Sort  (cost=6037.10..6037.11 rows=1 width=434) (actual
time=255608.583..255611.632 rows=33209 loops=1)
         Sort Method: quicksort  Memory: 13143kB
         ->  Nested Loop  (cost=42.51..6037.09 rows=1 width=434) (actual
time=152.818..254886.674 rows=33209 loops=1)
               Join Filter: (cachedgroupmembers_4.groupid =
acl_3.principalid)
               Rows Removed by Join Filter: 495425041
               ->  Bitmap Heap Scan on public.acl acl_3
(cost=30.07..144.35 rows=497 width=4) (actual time=0.284..8.184 rows=525
loops=1)
                     Recheck Cond: ((((acl_3.rightname)::text =
'OwnTicket'::text) AND ((acl_3.principaltype)::text = 'Group'::text)) OR
(((acl_3.rightname)::text = 'SuperUser'::text) AND
((acl_3.principaltype):
:text = 'Group'::text)))
                     Filter: (((acl_3.objecttype)::text =
'RT::Queue'::text) OR (((acl_3.objecttype)::text = 'RT::System'::text)
AND (acl_3.objectid = 1)))
                     ->  BitmapOr  (cost=30.07..30.07 rows=531 width=0)
(actual time=0.249..0.249 rows=0 loops=1)
                           ->  Bitmap Index Scan on acl1
(cost=0.00..25.46 rows=521 width=0) (actual time=0.233..0.233 rows=521
loops=1)
                                 Index Cond: (((acl_3.rightname)::text =
'OwnTicket'::text) AND ((acl_3.principaltype)::text = 'Group'::text))
                           ->  Bitmap Index Scan on acl1
(cost=0.00..4.36 rows=11 width=0) (actual time=0.016..0.016 rows=4
loops=1)
                                 Index Cond: (((acl_3.rightname)::text =
'SuperUser'::text) AND ((acl_3.principaltype)::text = 'Group'::text))
               ->  Materialize  (cost=12.44..5870.39 rows=3 width=438)
(actual time=0.004..176.296 rows=943730 loops=525)
                     ->  Nested Loop  (cost=12.44..5870.37 rows=3
width=438) (actual time=0.351..1028.683 rows=943730 loops=1)
                           ->  Nested Loop  (cost=12.44..5601.49 rows=2
width=442) (actual time=0.326..15.591 rows=675 loops=1)
                                 ->  Nested Loop  (cost=12.44..5502.26
rows=27 width=8) (actual time=0.303..9.744 rows=675 loops=1)
                                       Output: principals_1.id,
cachedgroupmembers_2.memberid
                                       ->  Bitmap Heap Scan on
public.cachedgroupmembers cachedgroupmembers_2  (cost=12.44..1659.12
rows=446 width=4) (actual time=0.267..1.266 rows=676 loops=1)

Recheck Cond: (cachedgroupmembers_2.groupid = 4)
                                             Filter:
(cachedgroupmembers_2.disabled = 0)
                                             ->  Bitmap Index Scan on
cachedgroupmembers2  (cost=0.00..12.33 rows=446 width=0) (actual
time=0.171..0.171 rows=676 loops=1)
                                                   Index Cond:
(cachedgroupmembers_2.groupid = 4)
                                       ->  Index Scan using
principals_pkey on public.principals principals_1  (cost=0.00..8.61
rows=1 width=4) (actual time=0.011..0.011 rows=1 loops=676)
                                             Output: principals_1.id
                                             Index Cond:
(principals_1.id = cachedgroupmembers_2.memberid)
                                             Filter: ((principals_1.id
<> 1) AND (principals_1.disabled = 0) AND
((principals_1.principaltype)::text = 'User'::text))
                                             Rows Removed by Filter: 0
                                 ->  Index Scan using users_pkey on
public.users main  (cost=0.00..3.67 rows=1 width=434) (actual
time=0.007..0.008 rows=1
loops=675)
                                       Index Cond: (main.id =
principals_1.id)
                           ->  Index Scan using cachedgroupmembers1 on
public.cachedgroupmembers cachedgroupmembers_4  (cost=0.00..133.79
rows=65 width=8) (actual time=0.012..1.199 rows=1398 loops=675)

                                 Index Cond:
(cachedgroupmembers_4.memberid = principals_1.id)
                                 Filter: (cachedgroupmembers_4.disabled
= 0)
                                 Rows Removed by Filter: 0
 Total runtime: 255694.440 ms
(47 rows)


The good one:
 Unique  (cost=528.88..528.96 rows=1 width=522) (actual
time=5029.906..5068.395 rows=572 loops=1)
   ->  Sort  (cost=528.88..528.89 rows=1 width=522) (actual
time=5029.889..5032.743 rows=33209 loops=1)
         Sort Method: quicksort  Memory: 13143kB
         ->  Nested Loop  (cost=36.08..528.87 rows=1 width=522) (actual
time=0.410..4178.931 rows=33209 loops=1)
               ->  Nested Loop  (cost=3.54..449.25 rows=2 width=526)
(actual time=0.139..1459.785 rows=943730 loops=1)
                     Join Filter: (principals_1.id =
cachedgroupmembers_4.memberid)
                     ->  Nested Loop  (cost=0.00..314.65 rows=1
width=530) (actual time=0.115..12.537 rows=675 loops=1)
                           ->  Nested Loop  (cost=0.00..310.98 rows=1
width=8) (actual time=0.106..7.203 rows=675 loops=1)
                                 Output: principals_1.id,
cachedgroupmembers_2.memberid
                                 ->  Index Only Scan using disgroumem on
public.cachedgroupmembers cachedgroupmembers_2  (cost=0.00..101.59
rows=24 width=4) (actual time=0.071..1.046 rows=676 loops=1)
                                       Output:
cachedgroupmembers_2.groupid, cachedgroupmembers_2.memberid,
cachedgroupmembers_2.disabled
                                       Index Cond:
((cachedgroupmembers_2.groupid = 4) AND (cachedgroupmembers_2.disabled =
0))
                                       Heap Fetches: 676
                                 ->  Index Scan using principals_pkey on
public.principals principals_1  (cost=0.00..8.71 rows=1 width=4) (actual
time=0.008..0.008 rows=1 loops=676)
                                       Output: principals_1.id
                                       Index Cond: (principals_1.id =
cachedgroupmembers_2.memberid)
                                       Filter: ((principals_1.id <> 1)
AND (principals_1.disabled = 0) AND ((principals_1.principaltype)::text
= 'User'::text))
                                       Rows Removed by Filter: 0
                           ->  Index Scan using users_pkey on
public.users main  (cost=0.00..3.67 rows=1 width=522) (actual
time=0.006..0.007 rows=1 loops=675)
                                 Index Cond: (main.id = principals_1.id)
                     ->  Bitmap Heap Scan on public.cachedgroupmembers
cachedgroupmembers_4  (cost=3.54..133.77 rows=66 width=8) (actual
time=0.309..1.752 rows=1398 loops=675)
                           Recheck Cond: (cachedgroupmembers_4.memberid
= main.id)
                           Filter: (cachedgroupmembers_4.disabled = 0)
                           Rows Removed by Filter: 0
                           ->  Bitmap Index Scan on cachedgroupmembers1
(cost=0.00..3.52 rows=66 width=0) (actual time=0.185..0.185 rows=1398
loops=675)
                                 Index Cond:
(cachedgroupmembers_4.memberid = main.id)
               ->  Bitmap Heap Scan on public.acl acl_3
(cost=32.54..39.78 rows=3 width=4) (actual time=0.002..0.002 rows=0
loops=943730)
                     Recheck Cond: ((acl_3.principalid =
cachedgroupmembers_4.groupid) AND ((((acl_3.rightname)::text =
'OwnTicket'::text) AND ((acl_3.principaltype)::text = 'Group'::text)) OR
(((acl_3.rightname
)::text = 'SuperUser'::text) AND ((acl_3.principaltype)::text =
'Group'::text))))
                     Filter: (((acl_3.objecttype)::text =
'RT::Queue'::text) OR (((acl_3.objecttype)::text = 'RT::System'::text)
AND (acl_3.objectid = 1)))
                     ->  BitmapAnd  (cost=32.54..32.54 rows=3 width=0)
(actual time=0.002..0.002 rows=0 loops=943730)
                           ->  Bitmap Index Scan on acl3
(cost=0.00..2.22 rows=49 width=0) (actual time=0.001..0.001 rows=1
loops=943730)
                                 Index Cond: (acl_3.principalid =
cachedgroupmembers_4.groupid)
                           ->  BitmapOr  (cost=30.07..30.07 rows=531
width=0) (actual time=0.110..0.110 rows=0 loops=4412)
                                 ->  Bitmap Index Scan on acl1
(cost=0.00..25.46 rows=521 width=0) (actual time=0.102..0.102 rows=521
loops=4412)
                                       Index Cond:
(((acl_3.rightname)::text = 'OwnTicket'::text) AND
((acl_3.principaltype)::text = 'Group'::text))
                                 ->  Bitmap Index Scan on acl1
(cost=0.00..4.36 rows=11 width=0) (actual time=0.007..0.007 rows=4
loops=4412)
                                       Index Cond:
(((acl_3.rightname)::text = 'SuperUser'::text) AND
((acl_3.principaltype)::text = 'Group'::text))
 Total runtime: 5069.842 ms
(47 rows)


Why does PostgreSQL pick one before the other and how can I make sure
that it will keep using the "good" one instead of the "bad" one?

        / Eskil