Re: Performance problem on 8.2.4, but not 8.2.3

From: Kristo Kaiv <kristo(dot)kaiv(at)skype(dot)net>
To: Dave Pirotte <dpirotte(at)mediamatters(dot)org>
Cc: pgsql-performance(at)postgresql(dot)org
Subject: Re: Performance problem on 8.2.4, but not 8.2.3
Date: 2007-05-25 19:17:50
Message-ID: CDE3AFDB-3A07-40F9-B245-225E1C43175A@skype.net
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

Lo!

referrer_paths seems to have totally wrong stats. try full analyze on
it.
how many records in total do you have in referrer_paths on 8.2.4 server?
might be just a problem of usage pattern change from old system to
new (1 row vs. 121399 rows) ?
does not seem to be just a plan problem as the data itself seems to
be quite different.

Kristo

On 25.05.2007, at 21:08, Dave Pirotte wrote:

> 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
>
>
>
>
>

In response to

Browse pgsql-performance by date

  From Date Subject
Next Message Tom Lane 2007-05-25 19:56:35 Re: Performance problem on 8.2.4, but not 8.2.3
Previous Message Peter T. Breuer 2007-05-25 18:57:34 Re: general PG network slowness (possible cure) (repost)