Received: from maia.hub.org (maia-3.hub.org [200.46.204.243]) by mail.postgresql.org (Postfix) with ESMTP id 1F8421337B5C for ; Thu, 20 Jan 2011 03:05:37 -0400 (AST) Received: from mail.postgresql.org ([200.46.204.86]) by maia.hub.org (mx1.hub.org [200.46.204.243]) (amavisd-maia, port 10024) with ESMTP id 07275-02 for ; Thu, 20 Jan 2011 07:05:29 +0000 (UTC) X-Greylist: from auto-whitelisted by SQLgrey-1.7.6 Received: from smadev.internal.net (host3.dynacom.ondsl.gr [62.103.35.211]) by mail.postgresql.org (Postfix) with ESMTP id 72DEB13364DE for ; Thu, 20 Jan 2011 03:05:28 -0400 (AST) Received: from smadev.internal.net (localhost.internal.net [127.0.0.1]) by smadev.internal.net (8.14.2/8.14.2) with ESMTP id p0K75RnG009508 for ; Thu, 20 Jan 2011 09:05:27 +0200 (EET) (envelope-from achill@matrix.gatewaynet.com) Received: from localhost (localhost [[UNIX: localhost]]) by smadev.internal.net (8.14.2/8.14.2/Submit) id p0K75QW5009507 for pgsql-performance@postgresql.org; Thu, 20 Jan 2011 09:05:26 +0200 (EET) (envelope-from achill@matrix.gatewaynet.com) From: Achilleas Mantzios Organization: Dynacom Tankers Mgmt To: pgsql-performance@postgresql.org Subject: Re: "NOT IN" substantially slower in 9.0.2 than 8.3.13 - NOT EXISTS runs fast in both 8.3.13 and 9.0.2 Date: Thu, 20 Jan 2011 09:05:25 +0200 User-Agent: KMail/1.9.7 References: <955263366.48014741295283147090.JavaMail.root@ucimail4.uci.cu> <201101191110.05268.achill@matrix.gatewaynet.com> <21792.1295458016@sss.pgh.pa.us> In-Reply-To: <21792.1295458016@sss.pgh.pa.us> MIME-Version: 1.0 Content-Type: text/plain; charset="utf-8" Content-Transfer-Encoding: quoted-printable Content-Disposition: inline Message-Id: <201101200905.26400.achill@matrix.gatewaynet.com> X-Virus-Scanned: Maia Mailguard 1.0.1 X-Spam-Status: No, hits=-0.451 tagged_above=-10 required=5 tests=BAYES_00=-1.9, RCVD_IN_BRBL_LASTEXT=1.449 X-Spam-Level: X-Archive-Number: 201101/180 X-Sequence-Number: 41967 =CE=A3=CF=84=CE=B9=CF=82 Wednesday 19 January 2011 19:26:56 =CE=BF/=CE=B7 T= om Lane =CE=AD=CE=B3=CF=81=CE=B1=CF=88=CE=B5: > Achilleas Mantzios writes: > > Anyway, i will repost the EXPLAIN plans by copying pasting the query, w= ithout the analyze part. >=20 > Please show EXPLAIN ANALYZE, not just EXPLAIN, results. When > complaining that the planner did the wrong thing, it's not very helpful > to see only its estimates and not reality. I did so two posts before but one more won't do any harm. Here we go: 9.0.2 - SLOW = QUERY PLAN = =20 =2D------------------------------------------------------------------------= =2D------------------------------------------------------------------------= =2D-------------------------------------------------------------------- Unique (cost=3D11525.09..11571.55 rows=3D3717 width=3D23) (actual time=3D= 10439.797..10440.152 rows=3D603 loops=3D1) -> Sort (cost=3D11525.09..11534.38 rows=3D3717 width=3D23) (actual tim= e=3D10439.795..10439.905 rows=3D603 loops=3D1) Sort Key: m.surname, (COALESCE(m.givenname, ''::character varying)= ), (COALESCE(m.midname, ''::character varying)), m.id Sort Method: quicksort Memory: 71kB -> Hash Join (cost=3D8281.98..11304.67 rows=3D3717 width=3D23) (= actual time=3D10402.338..10438.875 rows=3D603 loops=3D1) Hash Cond: (ms.marinerid =3D m.id) -> Hash Join (cost=3D20.12..2963.83 rows=3D3717 width=3D4)= (actual time=3D0.228..35.178 rows=3D2625 loops=3D1) Hash Cond: (ms.vslid =3D vsl.id) -> Seq Scan on marinerstates ms (cost=3D0.00..2889.3= 2 rows=3D4590 width=3D8) (actual time=3D0.015..33.634 rows=3D2625 loops=3D1) Filter: (((state)::text =3D 'Active'::text) AND = ((starttime)::date <=3D '2007-01-11'::date) AND ((COALESCE(endtime, now()))= ::date >=3D '2006-07-15'::date)) -> Hash (cost=3D16.72..16.72 rows=3D272 width=3D4) (= actual time=3D0.203..0.203 rows=3D272 loops=3D1) Buckets: 1024 Batches: 1 Memory Usage: 10kB -> Seq Scan on vessels vsl (cost=3D0.00..16.72= rows=3D272 width=3D4) (actual time=3D0.004..0.117 rows=3D272 loops=3D1) -> Hash (cost=3D8172.57..8172.57 rows=3D7143 width=3D23) (= actual time=3D10402.075..10402.075 rows=3D12832 loops=3D1) Buckets: 1024 Batches: 1 Memory Usage: 702kB -> Seq Scan on mariner m (cost=3D7614.86..8172.57 ro= ws=3D7143 width=3D23) (actual time=3D10386.549..10397.193 rows=3D12832 loop= s=3D1) Filter: ((NOT (hashed SubPlan 1)) AND ((marinert= ype)::text =3D 'Mariner'::text)) SubPlan 1 -> Unique (cost=3D2768.00..7614.86 rows=3D1 = width=3D4) (actual time=3D86.937..10385.379 rows=3D1454 loops=3D1) -> Nested Loop (cost=3D2768.00..7614.8= 6 rows=3D1 width=3D4) (actual time=3D86.936..10384.555 rows=3D1835 loops=3D= 1) Join Filter: (msold.marinerid =3D = mold.id) -> Index Scan using mariner_pkey = on mariner mold (cost=3D0.00..1728.60 rows=3D14286 width=3D4) (actual time= =3D0.007..14.250 rows=3D14286 loops=3D1) Filter: ((marinertype)::text= =3D 'Mariner'::text) -> Materialize (cost=3D2768.00..= 5671.97 rows=3D1 width=3D8) (actual time=3D0.003..0.328 rows=3D1876 loops= =3D14286) -> Nested Loop (cost=3D276= 8.00..5671.96 rows=3D1 width=3D8) (actual time=3D39.259..84.889 rows=3D1876= loops=3D1) -> Hash Semi Join (c= ost=3D2768.00..5671.67 rows=3D1 width=3D12) (actual time=3D39.249..81.025 r= ows=3D1876 loops=3D1) Hash Cond: (msol= d.marinerid =3D msold2.marinerid) Join Filter: ((m= sold2.id <> msold.id) AND (msold2.starttime < msold.starttime) AND ((msold.= starttime - msold2.endtime) <=3D '1 year 6 mons'::interval)) -> Seq Scan on = marinerstates msold (cost=3D0.00..2889.32 rows=3D4590 width=3D20) (actual = time=3D0.003..33.964 rows=3D2625 loops=3D1) Filter: ((= (state)::text =3D 'Active'::text) AND ((starttime)::date <=3D '2007-01-11':= :date) AND ((COALESCE(endtime, now()))::date >=3D '2006-07-15'::date)) -> Hash (cost= =3D2251.66..2251.66 rows=3D41307 width=3D24) (actual time=3D39.156..39.156 = rows=3D41250 loops=3D1) Buckets: 8= 192 Batches: 1 Memory Usage: 2246kB -> Seq Sc= an on marinerstates msold2 (cost=3D0.00..2251.66 rows=3D41307 width=3D24) = (actual time=3D0.002..24.552 rows=3D41250 loops=3D1) Filt= er: ((state)::text =3D 'Active'::text) -> Index Scan using v= essels_pkey on vessels vslold (cost=3D0.00..0.28 rows=3D1 width=3D4) (actu= al time=3D0.001..0.001 rows=3D1 loops=3D1876) Index Cond: (vsl= old.id =3D msold.vslid) Total runtime: 10440.690 ms (37 rows) 8.3.13 - FAST = QUERY PLAN = =20 =2D------------------------------------------------------------------------= =2D------------------------------------------------------------------------= =2D------------------------------------------------------------------------= =2D--- Unique (cost=3D633677.56..633700.48 rows=3D1834 width=3D23) (actual time= =3D551.166..558.487 rows=3D603 loops=3D1) -> Sort (cost=3D633677.56..633682.14 rows=3D1834 width=3D23) (actual t= ime=3D551.156..553.548 rows=3D603 loops=3D1) Sort Key: m.surname, (COALESCE(m.givenname, ''::character varying)= ), (COALESCE(m.midname, ''::character varying)), m.id Sort Method: quicksort Memory: 53kB -> Hash Join (cost=3D630601.65..633578.15 rows=3D1834 width=3D23= ) (actual time=3D447.773..547.934 rows=3D603 loops=3D1) Hash Cond: (ms.vslid =3D vsl.id) -> Hash Join (cost=3D630580.33..633530.01 rows=3D2261 widt= h=3D27) (actual time=3D445.320..540.291 rows=3D603 loops=3D1) Hash Cond: (ms.marinerid =3D m.id) -> Seq Scan on marinerstates ms (cost=3D0.00..2875.3= 2 rows=3D4599 width=3D8) (actual time=3D0.018..79.742 rows=3D2625 loops=3D1) Filter: (((state)::text =3D 'Active'::text) AND = ((starttime)::date <=3D '2007-01-11'::date) AND ((COALESCE(endtime, now()))= ::date >=3D '2006-07-15'::date)) -> Hash (cost=3D630491.54..630491.54 rows=3D7103 wid= th=3D23) (actual time=3D445.216..445.216 rows=3D12832 loops=3D1) -> Index Scan using mariner_pkey on mariner m = (cost=3D628776.89..630491.54 rows=3D7103 width=3D23) (actual time=3D319.675= =2E.388.383 rows=3D12832 loops=3D1) Filter: ((NOT (hashed subplan)) AND ((mari= nertype)::text =3D 'Mariner'::text)) SubPlan -> Unique (cost=3D0.00..628772.30 rows= =3D1834 width=3D4) (actual time=3D0.196..312.728 rows=3D1454 loops=3D1) -> Nested Loop (cost=3D0.00..628= 767.72 rows=3D1834 width=3D4) (actual time=3D0.187..298.780 rows=3D1835 loo= ps=3D1) -> Nested Loop (cost=3D0.0= 0..627027.98 rows=3D1865 width=3D4) (actual time=3D0.165..244.706 rows=3D18= 76 loops=3D1) -> Index Scan using m= arinerstates_marinerid on marinerstates msold (cost=3D0.00..626316.07 rows= =3D2299 width=3D8) (actual time=3D0.138..194.165 rows=3D1876 loops=3D1) Filter: (((state= )::text =3D 'Active'::text) AND ((starttime)::date <=3D '2007-01-11'::date)= AND ((COALESCE(endtime, now()))::date >=3D '2006-07-15'::date) AND (subpla= n)) SubPlan -> Bitmap Hea= p Scan on marinerstates msold2 (cost=3D4.28..12.11 rows=3D1 width=3D0) (ac= tual time=3D0.020..0.020 rows=3D1 loops=3D2625) Recheck = Cond: ((marinerid =3D $0) AND (starttime < $2)) Filter: = ((id <> $1) AND ((state)::text =3D 'Active'::text) AND (($2 - endtime) <=3D= '1 year 6 mons'::interval)) -> Bitm= ap Index Scan on marinerstates_marinerid_starttime (cost=3D0.00..4.28 rows= =3D2 width=3D0) (actual time=3D0.009..0.009 rows=3D6 loops=3D2625) In= dex Cond: ((marinerid =3D $0) AND (starttime < $2)) -> Index Scan using v= essels_pkey on vessels vslold (cost=3D0.00..0.30 rows=3D1 width=3D4) (actu= al time=3D0.006..0.010 rows=3D1 loops=3D1876) Index Cond: (vsl= old.id =3D msold.vslid) -> Index Scan using mariner= _pkey on mariner mold (cost=3D0.00..0.92 rows=3D1 width=3D4) (actual time= =3D0.008..0.012 rows=3D1 loops=3D1876) Index Cond: (mold.id = =3D msold.marinerid) Filter: ((mold.mariner= type)::text =3D 'Mariner'::text) -> Hash (cost=3D17.81..17.81 rows=3D281 width=3D4) (actual= time=3D2.432..2.432 rows=3D273 loops=3D1) -> Seq Scan on vessels vsl (cost=3D0.00..17.81 rows= =3D281 width=3D4) (actual time=3D0.033..1.220 rows=3D273 loops=3D1) Total runtime: 561.208 ms (33 rows) >=20 > regards, tom lane >=20 =2D-=20 Achilleas Mantzios