Message-ID: <4E548A7D.6090003@catalyst.net.nz>
Date: Wed, 24 Aug 2011 17:22:05 +1200
From: Mark Kirkwood <mark.kirkwood@catalyst.net.nz>
User-Agent: Mozilla/5.0 (X11; U; Linux x86_64; en-US;
	rv:1.9.2.18) Gecko/20110617 Lightning/1.0b2 Thunderbird/3.1.11
MIME-Version: 1.0
To: Tom Lane <tgl@sss.pgh.pa.us>
CC: PGSQL Performance <pgsql-performance@postgresql.org>
Subject: Re: 8.4 optimization regression?
References: <4E5331FF.3000900@catalyst.net.nz>
 <15708.1314155740@sss.pgh.pa.us>
In-Reply-To: <15708.1314155740@sss.pgh.pa.us>
Content-Type: text/plain; charset=ISO-8859-1; format=flowed
Content-Transfer-Encoding: 7bit

On 24/08/11 15:15, Tom Lane wrote:
>
> Hmmm ... this is structurally a pretty simple query, so I'm surprised
> that 8.3 and 8.4 see it very much differently.  The relation-level
> estimates and plan choices are very nearly the same; the only thing
> that's changed much is the estimates of the join sizes, and there were
> not that many changes in the join selectivity estimation for simple
> inner joins.  I wonder whether you are seeing a bad side-effect of this
> patch:
>
> http://git.postgresql.org/gitweb/?p=postgresql.git&a=commitdiff&h=7f3eba30
>

Here is what the plan looks like with that patch reversed (it is back to 
8.3 speed too).

QUERY PLAN  8.4 - 7f3eba30
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
  Hash Join  (cost=948567.18..1882454.51 rows=349702 width=0) (actual 
time=12320.037..38146.697 rows=217427 loops=1)
    Hash Cond: (cm.person_id = p.person_id)
    ->  Hash Join  (cost=791689.32..1702481.12 rows=581887 width=4) 
(actual time=7492.004..32727.783 rows=248441 loops=1)
          Hash Cond: (cm.corresp_master_id = c.corresp_master_id)
          ->  Seq Scan on correspondence_master cm  
(cost=0.00..777460.25 rows=34003380 width=12) (actual 
time=0.016..8977.181 rows=33960209 loops=1)
                Filter: (person_id IS NOT NULL)
          ->  Hash  (cost=783297.43..783297.43 rows=671351 width=8) 
(actual time=7375.019..7375.019 rows=354456 loops=1)
                ->  Hash Join  (cost=231577.28..783297.43 rows=671351 
width=8) (actual time=6374.538..7257.067 rows=354456 loops=1)
                      Hash Cond: (c.generated_audit_id = gen_al.audit_id)
                      ->  Bitmap Heap Scan on correspondence c  
(cost=77121.49..532445.85 rows=4247118 width=16) (actual 
time=742.738..2790.225 rows=5293603 loops=1)
                            Recheck Cond: (corresp_type_id = ANY 
('{CL11,CL11A,CL12,CL15,CL15A,CL16,DM_1,DM_2}'::text[]))
                            ->  Bitmap Index Scan on corresp_type_fk  
(cost=0.00..76059.71 rows=4247118 width=0) (actual time=708.164..708.164 
rows=5293603 loops=1)
                                  Index Cond: (corresp_type_id = ANY 
('{CL11,CL11A,CL12,CL15,CL15A,CL16,DM_1,DM_2}'::text[]))
                      ->  Hash  (cost=108073.47..108073.47 rows=2827066 
width=8) (actual time=2759.145..2759.145 rows=2819891 loops=1)
                            ->  Index Scan using 
audit_log_audit_timestamp on audit_log gen_al  (cost=0.00..108073.47 
rows=2827066 width=8) (actual time=0.085..1800.175 rows=2819891 loops=1)
                                  Index Cond: (audit_timestamp > 
'2011-02-19 13:05:00'::timestamp without time zone)
    ->  Hash  (cost=115044.00..115044.00 rows=2549829 width=4) (actual 
time=4827.310..4827.310 rows=3101177 loops=1)
          ->  Seq Scan on person p  (cost=0.00..115044.00 rows=2549829 
width=4) (actual time=0.061..3600.767 rows=3101177 loops=1)
                Filter: (active AND (NOT exclude_walklist_alt) AND 
(postal_address_id IS NULL) AND (NOT unpublished) AND 
(enrolment_status_id = ANY ('{E,T}'::text[])) AND (person_type = ANY 
('{M,D,O}'::text[])))
  Total runtime: 38171.865 ms


Cheers

Mark