Re: Performance problem on 8.2.4, but not 8.2.3 - Mailing list pgsql-performance

Greetings,

We have two servers running pgsql -- an older server running 8.2.3, and a newer (far superior) one running 8.2.4.  One of our reporting queries is running painfully slowly on 8.2.4, but it executes in a reasonable timeframe on 8.2.3.  Below, I've included a contrived, stripped down query which still exhibits the same unintuitively poor performance, as well as its explain analyze output from both servers.  In particular, 8.2.4 opts for filters in a couple places where we would expect index conds.  Also, we've noticed that the 8.2.4 box (in other similar queries) consistently underestimates costs, whereas the 8.2.3 box consistently overestimates.

All columns involved in this query are indexed (btrees), and there is a functional index on mm_date_trunc('day', created_at)...where mm_date_trunc is simply an immutable version of date_trunc (fine for our purposes).  The only configuration differences between the servers are various memory settings... work_mem and temp_buffers are 8mb / 16mb, shared buffers 128mb / 512mb on the 8.2.3 and 8.2.4 servers, respectively.  Stats targets are 10 on both, for consistency... but it is worth mentioning that performance was still abysmal under 8.2.4 with 250 as the target.

Any insight would be most appreciated, as we're a bit stumped.  Thanks!

Cheers,

Dave Pirotte

Director of Technology

Media Matters for America

===============================================================

select h.day, h.c as total,

(select count(*) as c

from hits h2

join uri_qstrings uq on (h2.uri_qstring_id = uq.id)

join referrer_paths rp on (h2.referrer_path_id = rp.id)

join referrer_domains rd on (rp.referrer_domain_id = rd.id)

where mm_date_trunc('day', created_at) = h.day

and site_id = 3

and uq.qstring = '?f=h_top'

and rd.domain = 'mediamatters.org'

) as h_top

from (

select mm_date_trunc('day', h.created_at) as day,

count(*) as c

from hits h

where created_at > date_trunc('day', now() - interval '2 days')

group by mm_date_trunc('day', h.created_at)

) h

order by h.day asc;

                                                                                       QUERY PLAN (8.2.4)                                                                                       

---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- 

Sort  (cost=204012.65..204012.66 rows=3 width=16) (actual time=83012.885..83012.885 rows=3 loops=1)

   Sort Key: "day"   ->  Subquery Scan h  (cost=149811.02..204012.62 rows=3 width=16) (actual time=28875.251..83012.868 rows=3 loops=1)

         ->  HashAggregate  (cost=149811.02..149811.06 rows=3 width=8) (actual time=1602.787..1602.794 rows=3 loops=1)

               ->  Bitmap Heap Scan on hits h  (cost=6485.90..148079.18 rows=346368 width=8) (actual time=48.222..1358.196 rows=391026 loops=1)

                     Recheck Cond: (created_at > date_trunc('day'::text, (now() - '2 days'::interval)))

                     ->  Bitmap Index Scan on hits_created_idx  (cost=0.00..6399.31 rows=346368 width=0) (actual time=47.293..47.293 rows=391027 loops=1)

                           Index Cond: (created_at > date_trunc('day'::text, (now() - '2 days'::interval)))

         SubPlan

           ->  Aggregate  (cost=18067.17..18067.18 rows=1 width=0) (actual time=27136.681..27136.681 rows=1 loops=3)

                 ->  Nested Loop  (cost=40.66..18067.16 rows=1 width=0) (actual time=1105.396..27135.496 rows=3394 loops=3)

                       ->  Nested Loop  (cost=40.66..18063.56 rows=9 width=8) (actual time=32.132..26837.394 rows=50537 loops=3)

                             ->  Nested Loop  (cost=40.66..5869.35 rows=47 width=8) (actual time=20.482..276.889 rows=121399 loops=3)

                                   ->  Index Scan using referrer_domains_domains_idx on referrer_domains rd  (cost=0.00..8.27 rows=1 width=8) (actual time=0.024..0.026 rows=1 loops=3)

                                         Index Cond: (("domain")::text = 'mediamatters.org'::text)

                                   ->  Bitmap Heap Scan on referrer_paths rp  (cost=40.66..5834.77 rows=2105 width=16) (actual time=20.402..210.440 rows=121399 loops=3)

                                         Recheck Cond: (rp.referrer_domain_id = rd.id)

                                         ->  Bitmap Index Scan on referrer_paths_domains_idx  (cost=0.00..40.13 rows=2105 width=0) (actual time=17.077..17.077 rows=121399 loops=3)

                                               Index Cond: (rp.referrer_domain_id = rd.id)

                             ->  Index Scan using hits_refer_idx on hits h2  (cost=0.00..257.59 rows=149 width=16) (actual time=0.167..0.218 rows=0 loops=364197)

                                   Index Cond: (h2.referrer_path_id = rp.id)

                                   Filter: ((mm_date_trunc('day'::text, created_at) = $0) AND (site_id = 3))

                       ->  Index Scan using uri_qstrings_pkey on uri_qstrings uq  (cost=0.00..0.39 rows=1 width=8) (actual time=0.005..0.005 rows=0 loops=151611)

                             Index Cond: (h2.uri_qstring_id = uq.id)

                             Filter: ((qstring)::text = '?f=h_top'::text)

 Total runtime: 83013.098 ms

                                                                                     QUERY PLAN (8.2.3)                                                                                    

-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

Sort  (cost=270110.73..270110.74 rows=1 width=16) (actual time=2116.106..2116.107 rows=3 loops=1)

   Sort Key: "day"   ->  Subquery Scan h  (cost=118726.46..270110.72 rows=1 width=16) (actual time=1763.504..2116.090 rows=3 loops=1)

         ->  HashAggregate  (cost=118726.46..118726.47 rows=1 width=8) (actual time=1678.462..1678.467 rows=3 loops=1)

               ->  Bitmap Heap Scan on hits h  (cost=1827.68..118382.45 rows=68802 width=8) (actual time=56.346..1496.264 rows=334231 loops=1)

                     Recheck Cond: (created_at > date_trunc('day'::text, (now() - '2 days'::interval)))

                     ->  Bitmap Index Scan on hits_created_idx  (cost=0.00..1810.48 rows=68802 width=0) (actual time=55.225..55.225 rows=334231 loops=1)

                           Index Cond: (created_at > date_trunc('day'::text, (now() - '2 days'::interval)))

         SubPlan

           ->  Aggregate  (cost=151384.23..151384.24 rows=1 width=0) (actual time=145.865..145.865 rows=1 loops=3)

                 ->  Hash Join  (cost=4026.42..151384.23 rows=1 width=0) (actual time=30.663..145.271 rows=2777 loops=3)

                       Hash Cond: (rp.referrer_domain_id = rd.id)

                       ->  Nested Loop  (cost=4018.13..151375.82 rows=30 width=8) (actual time=30.585..143.498 rows=3174 loops=3)

                             ->  Hash Join  (cost=4018.13..151149.21 rows=30 width=8) (actual time=30.550..93.357 rows=3174 loops=3)

                                   Hash Cond: (h2.uri_qstring_id = uq.id)

                                   ->  Bitmap Heap Scan on hits h2  (cost=3857.37..150325.60 rows=176677 width=16) (actual time=19.710..60.881 rows=108568 loops=3)

                                         Recheck Cond: (mm_date_trunc('day'::text, created_at) = $0)

                                         Filter: (site_id = 3)

                                         ->  Bitmap Index Scan on hits_date_trunc_day_idx  (cost=0.00..3813.20 rows=178042 width=0) (actual time=19.398..19.398 rows=111410 loops=3)

                                               Index Cond: (mm_date_trunc('day'::text, created_at) = $0)

                                   ->  Hash  (cost=160.24..160.24 rows=42 width=8) (actual time=32.417..32.417 rows=141 loops=1)

                                         ->  Bitmap Heap Scan on uri_qstrings uq  (cost=4.69..160.24 rows=42 width=8) (actual time=31.502..32.352 rows=141 loops=1)

                                               Recheck Cond: ((qstring)::text = '?f=h_top'::text)

                                               ->  Bitmap Index Scan on uri_qstrings_qstring_idx  (cost=0.00..4.68 rows=42 width=0) (actual time=31.482..31.482 rows=141 loops=1)

                                                     Index Cond: ((qstring)::text = '?f=h_top'::text)

                             ->  Index Scan using referrer_paths_pkey on referrer_paths rp  (cost=0.00..7.54 rows=1 width=16) (actual time=0.014..0.015 rows=1 loops=9521)

                                   Index Cond: (h2.referrer_path_id = rp.id)

                       ->  Hash  (cost=8.27..8.27 rows=1 width=8) (actual time=0.062..0.062 rows=1 loops=1)

                             ->  Index Scan using referrer_domains_domains_idx on referrer_domains rd  (cost=0.00..8.27 rows=1 width=8) (actual time=0.058..0.059 rows=1 loops=1)

                                   Index Cond: (("domain")::text = 'mediamatters.org'::text)

 Total runtime: 2116.266 ms