X-Original-To: pgsql-performance-postgresql.org@localhost.postgresql.org Received: from localhost (av.hub.org [200.46.204.144]) by svr1.postgresql.org (Postfix) with ESMTP id B9BFCDB411 for ; Sun, 30 Oct 2005 14:32:11 -0400 (AST) Received: from svr1.postgresql.org ([200.46.204.71]) by localhost (av.hub.org [200.46.204.144]) (amavisd-new, port 10024) with ESMTP id 97628-02 for ; Sun, 30 Oct 2005 18:32:09 +0000 (GMT) Received: from cicero2.cybercity.dk (cicero2.cybercity.dk [212.242.40.53]) by svr1.postgresql.org (Postfix) with ESMTP id A1B42DB40F for ; Sun, 30 Oct 2005 14:32:06 -0400 (AST) Received: from [192.168.0.79] (0x3e42eeca.adsl.cybercity.dk [62.66.238.202]) by cicero2.cybercity.dk (Postfix) with ESMTP id 5BFA818FCC3; Sun, 30 Oct 2005 19:32:03 +0100 (CET) Message-ID: <436511DF.5020800@krap.dk> Date: Sun, 30 Oct 2005 19:33:03 +0100 From: Svenne Krap User-Agent: Mozilla Thunderbird 1.0.6 (Windows/20050716) X-Accept-Language: en-us, en MIME-Version: 1.0 To: "Steinar H. Gunderson" Cc: PgSQL Performance Subject: Re: multi-layered view join performance oddities References: <4364FFD4.2020801@krap.dk> <20051030174450.GA22399@uio.no> In-Reply-To: <20051030174450.GA22399@uio.no> Content-Type: multipart/alternative; boundary="------------070008080702050201010600" X-Virus-Scanned: by amavisd-new at hub.org X-Spam-Status: No, score=0.473 required=5 tests=[AWL=-0.473, HTML_10_20=0.945, HTML_MESSAGE=0.001] X-Spam-Score: 0.473 X-Spam-Level: X-Archive-Number: 200510/464 X-Sequence-Number: 15232 This is a multi-part message in MIME format. --------------070008080702050201010600 Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 7bit Hi. Your suggestion with disableing the nested loop really worked well: rkr=# set enable_nestloop=false; SET rkr=# explain analyze select * from ord_result_pct_pretty ; QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------- Hash Join (cost=230.06..337.49 rows=1 width=174) (actual time=21.893..42.356 rows=2250 loops=1) Hash Cond: (("outer".dataset_id = "inner".dataset_id) AND ("outer".nb_property_type_id = "inner".nb_property_type_id)) -> Hash Join (cost=56.94..164.10 rows=26 width=93) (actual time=5.073..17.906 rows=2532 loops=1) Hash Cond: ("outer".dataset_id = "inner".id) -> Hash Join (cost=55.54..161.63 rows=161 width=57) (actual time=4.996..14.775 rows=2532 loops=1) Hash Cond: ("outer".institut = "inner".id) -> Append (cost=54.38..121.72 rows=2476 width=44) (actual time=4.964..11.827 rows=2532 loops=1) -> HashAggregate (cost=54.38..57.20 rows=226 width=16) (actual time=4.964..5.174 rows=282 loops=1) -> Seq Scan on ord_entrydata_current (cost=0.00..37.50 rows=2250 width=16) (actual time=0.002..1.305 rows=2250 loops=1) -> Subquery Scan "*SELECT* 2" (cost=0.00..60.00 rows=2250 width=20) (actual time=0.009..4.948 rows=2250 loops=1) -> Seq Scan on ord_entrydata_current (cost=0.00..37.50 rows=2250 width=20) (actual time=0.003..2.098 rows=2250 loops=1) -> Hash (cost=1.13..1.13 rows=13 width=17) (actual time=0.022..0.022 rows=13 loops=1) -> Seq Scan on groups g (cost=0.00..1.13 rows=13 width=17) (actual time=0.003..0.013 rows=13 loops=1) -> Hash (cost=1.32..1.32 rows=32 width=36) (actual time=0.070..0.070 rows=32 loops=1) -> Seq Scan on ord_dataset od (cost=0.00..1.32 rows=32 width=36) (actual time=0.009..0.043 rows=32 loops=1) Filter: is_visible -> Hash (cost=173.07..173.07 rows=10 width=97) (actual time=15.472..15.472 rows=256 loops=1) -> Hash Join (cost=166.15..173.07 rows=10 width=97) (actual time=14.666..15.203 rows=256 loops=1) Hash Cond: ("outer".nb_property_type_id = "inner".id) -> HashAggregate (cost=165.05..168.15 rows=248 width=40) (actual time=14.619..14.849 rows=288 loops=1) -> Append (cost=54.38..121.72 rows=2476 width=44) (actual time=5.012..11.130 rows=2532 loops=1) -> HashAggregate (cost=54.38..57.20 rows=226 width=16) (actual time=5.011..5.222 rows=282 loops=1) -> Seq Scan on ord_entrydata_current (cost=0.00..37.50 rows=2250 width=16) (actual time=0.001..1.261 rows=2250 loops=1) -> Subquery Scan "*SELECT* 2" (cost=0.00..60.00 rows=2250 width=20) (actual time=0.010..4.308 rows=2250 loops=1) -> Seq Scan on ord_entrydata_current (cost=0.00..37.50 rows=2250 width=20) (actual time=0.002..1.694 rows=2250 loops=1) -> Hash (cost=1.08..1.08 rows=8 width=57) (actual time=0.026..0.026 rows=8 loops=1) -> Seq Scan on nb_property_type npt (cost=0.00..1.08 rows=8 width=57) (actual time=0.004..0.019 rows=8 loops=1) Total runtime: 43.297 ms (28 rows) Now, the whole question becomes, how do I get the planner to make a better estimation of the returned rows. I am not sure, I can follow your moving-the-union-all-further-out advice, as I see no different place for the unioning of the two datasets. Maybe one of the core devs know, where to fiddle :) Svenne Steinar H. Gunderson wrote: >On Sun, Oct 30, 2005 at 06:16:04PM +0100, Svenne Krap wrote: > > >> Nested Loop (cost=223.09..338.61 rows=1 width=174) (actual time=20.213..721.361 rows=2250 loops=1) >> Join Filter: (("outer".dataset_id = "inner".dataset_id) AND ("outer".nb_property_type_id = "inner".nb_property_type_id)) >> -> Hash Join (cost=58.04..164.26 rows=1 width=150) (actual time=5.510..22.088 rows=2250 loops=1) >> >> > >There's horrible misestimation here. It expects one row and thus starts a >nested loop, but gets 2250. No wonder it's slow :-) > >The misestimation can be traced all the way down here: > > > >> Hash Cond: ("outer".institut = "inner".id) >> -> Hash Join (cost=56.88..163.00 rows=16 width=137) (actual time=5.473..19.165 rows=2250 loops=1) >> Hash Cond: ("outer".dataset_id = "inner".id) >> -> Hash Join (cost=55.48..160.95 rows=99 width=101) (actual time=5.412..16.264 rows=2250 loops=1) >> >> > >where the planner misestimates the selectivity of your join (it estimates 99 >rows, and there are 2250). > >I've had problems joining with Append nodes in the past, and solved the >problem by moving the UNION ALL a bit out, but I'm not sure if it's a very >good general solution, or a solution to your problems here. > >If all else fails, you could "set enable_nestloop=false", but that is not a >good idea in the long run, I'd guess -- it's much better to make sure the >planner has good estimates and let it do the correct decisions from there. > >/* Steinar */ > > --------------070008080702050201010600 Content-Type: text/html; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Hi.

Your suggestion with disableing the nested loop really worked well:

rkr=3D# set enable_nestloop=3Dfalse;
SET
rkr=3D# explain analyze select * from ord_result_pct_pretty ;
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 QUERY PLAN
-------------------------------------------------------------------------= -------------------------------------------------------------------------= ---------
=C2=A0Hash Join=C2=A0 (cost=3D230.06..337.49 rows=3D1 width=3D174) (actua= l time=3D21.893..42.356 rows=3D2250 loops=3D1)
=C2=A0=C2=A0 Hash Cond: (("outer".dataset_id =3D "inner".dataset_id) AND ("outer".nb_property_type_id =3D "inner".nb_property_type_id))
=C2=A0=C2=A0 ->=C2=A0 Hash Join=C2=A0 (cost=3D56.94..164.10 rows=3D26 = width=3D93) (actual time=3D5.073..17.906 rows=3D2532 loops=3D1)
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 Hash Cond: ("outer".data= set_id =3D "inner".id)
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 ->=C2=A0 Hash Join=C2= =A0 (cost=3D55.54..161.63 rows=3D161 width=3D57) (actual time=3D4.996..14.775 rows=3D2532 loops=3D1)
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0 Hash Cond: ("outer".institut =3D "inner".id)
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0 ->=C2=A0 Append=C2=A0 (cost=3D54.38..121.72 rows=3D2476 widt= h=3D44) (actual time=3D4.964..11.827 rows=3D2532 loops=3D1)
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 ->=C2=A0 HashAggregate=C2= =A0 (cost=3D54.38..57.20 rows=3D226 width=3D16) (actual time=3D4.964..5.174 rows=3D282 loops=3D1)
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0 ->=C2=A0 Seq Scan on ord_entrydata_current=C2=A0 (cost=3D0.00..37.50 rows=3D2250 width=3D16) (actual time=3D0.002..1.305 rows=3D2250 loops=3D1)
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 ->=C2=A0 Subquery Scan "= *SELECT* 2"=C2=A0 (cost=3D0.00..60.00 rows=3D2250 width=3D20) (actual time=3D0.009..4.948 rows=3D2250 loops=3D1)
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0 ->=C2=A0 Seq Scan on ord_entrydata_current=C2=A0 (cost=3D0.00..37.50 rows=3D2250 width=3D20) (actual time=3D0.003..2.098 rows=3D2250 loops=3D1)
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0 ->=C2=A0 Hash=C2=A0 (cost=3D1.13..1.13 rows=3D13 width=3D17)= (actual time=3D0.022..0.022 rows=3D13 loops=3D1)
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 ->=C2=A0 Seq Scan on gro= ups g=C2=A0 (cost=3D0.00..1.13 rows=3D13 width=3D17) (actual time=3D0.003..0.013 rows=3D13 loops=3D1) =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 ->=C2=A0 Hash=C2=A0 (= cost=3D1.32..1.32 rows=3D32 width=3D36) (actual time=3D0.070..0.070 rows=3D32 loops=3D1)
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0 ->=C2=A0 Seq Scan on ord_dataset od=C2=A0 (cost=3D0.00..1.32= rows=3D32 width=3D36) (actual time=3D0.009..0.043 rows=3D32 loops=3D1) =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 Filter: is_visible
=C2=A0=C2=A0 ->=C2=A0 Hash=C2=A0 (cost=3D173.07..173.07 rows=3D10 widt= h=3D97) (actual time=3D15.472..15.472 rows=3D256 loops=3D1)
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 ->=C2=A0 Hash Join=C2= =A0 (cost=3D166.15..173.07 rows=3D10 width=3D97) (actual time=3D14.666..15.203 rows=3D256 loops=3D1)
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0 Hash Cond: ("outer".nb_property_type_id =3D "inner".id)
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0 ->=C2=A0 HashAggregate=C2=A0 (cost=3D165.05..168.15 rows=3D2= 48 width=3D40) (actual time=3D14.619..14.849 rows=3D288 loops=3D1)
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 ->=C2=A0 Append=C2=A0 (c= ost=3D54.38..121.72 rows=3D2476 width=3D44) (actual time=3D5.012..11.130 rows=3D2532 loops=3D1)
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0 ->=C2=A0 HashAggregate=C2=A0 (cost=3D54.38..57.20 rows=3D226 width=3D16) (actual time=3D5.011..5.222 rows=3D282 loops=3D1)<= br> =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 ->=C2=A0 Seq Scan on ord_entrydata_current=C2=A0 (cost=3D0.00..37.50 rows=3D2250 width=3D16) (= actual time=3D0.001..1.261 rows=3D2250 loops=3D1)
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0 ->=C2=A0 Subquery Scan "*SELECT* 2"=C2=A0 (cost=3D0.00..60.00 rows=3D2250 width=3D20) (actual time=3D0.010..4.308 rows=3D2250 loops=3D1)
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 ->=C2=A0 Seq Scan on ord_entrydata_current=C2=A0 (cost=3D0.00..37.50 rows=3D2250 width=3D20) (= actual time=3D0.002..1.694 rows=3D2250 loops=3D1)
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0 ->=C2=A0 Hash=C2=A0 (cost=3D1.08..1.08 rows=3D8 width=3D57) = (actual time=3D0.026..0.026 rows=3D8 loops=3D1)
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 ->=C2=A0 Seq Scan on nb_= property_type npt=C2=A0 (cost=3D0.00..1.08 rows=3D8 width=3D57) (actual time=3D0.004..0.019 rows=3D= 8 loops=3D1)
=C2=A0Total runtime: 43.297 ms
(28 rows)

Now, the whole question becomes, how do I get the planner to make a better estimation of the returned rows.

I am not sure, I can follow your moving-the-union-all-further-out advice, as I see no different place for the unioning of the two datasets.

Maybe one of the core devs know, where to fiddle :)

Svenne

Steinar H. Gunderson wrote: 
On Sun, Oct 30, 2005 at 06:16:04PM +0100, Svenne Krap wr=
ote:
  
 Nested Loop  (cost=3D223.09..338.61 rows=3D1 width=3D=
174) (actual time=3D20.213..721.361 rows=3D2250 loops=3D1)
   Join Filter: (("outer".dataset_id =3D "inner".dataset_id) AND ("outer"=
=2Enb_property_type_id =3D "inner".nb_property_type_id))
   ->  Hash Join  (cost=3D58.04..164.26 rows=3D1 width=3D150) (actual =
time=3D5.510..22.088 rows=3D2250 loops=3D1)
    

There's horrible misestimation here. It expects one row and thus starts a=

nested loop, but gets 2250. No wonder it's slow :-)

The misestimation can be traced all the way down here:

  
         Hash Cond: ("outer".institut =3D "inner".id)
         ->  Hash Join  (cost=3D56.88..163.00 rows=3D16 width=3D137) (=
actual time=3D5.473..19.165 rows=3D2250 loops=3D1)
               Hash Cond: ("outer".dataset_id =3D "inner".id)
               ->  Hash Join  (cost=3D55.48..160.95 rows=3D99 width=3D=
101) (actual time=3D5.412..16.264 rows=3D2250 loops=3D1)
    

where the planner misestimates the selectivity of your join (it estimates=
 99
rows, and there are 2250).

I've had problems joining with Append nodes in the past, and solved the
problem by moving the UNION ALL a bit out, but I'm not sure if it's a ver=
y
good general solution, or a solution to your problems here.

If all else fails, you could "set enable_nestloop=3Dfalse", but that is n=
ot a
good idea in the long run, I'd guess -- it's much better to make sure the=

planner has good estimates and let it do the correct decisions from there=
=2E

/* Steinar */

--------------070008080702050201010600--