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

Στις Wednesday 19 January 2011 19:26:56 ο/η Tom Lane έγραψε:
> Achilleas Mantzios <achill(at)matrix(dot)gatewaynet(dot)com> writes:
> > Anyway, i will repost the EXPLAIN plans by copying pasting the query, without the analyze part.
>
> 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
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Unique (cost=11525.09..11571.55 rows=3717 width=23) (actual time=10439.797..10440.152 rows=603 loops=1)
-> Sort (cost=11525.09..11534.38 rows=3717 width=23) (actual time=10439.795..10439.905 rows=603 loops=1)
Sort Key: m.surname, (COALESCE(m.givenname, ''::character varying)), (COALESCE(m.midname, ''::character varying)), m.id
Sort Method: quicksort Memory: 71kB
-> Hash Join (cost=8281.98..11304.67 rows=3717 width=23) (actual time=10402.338..10438.875 rows=603 loops=1)
Hash Cond: (ms.marinerid = m.id)
-> Hash Join (cost=20.12..2963.83 rows=3717 width=4) (actual time=0.228..35.178 rows=2625 loops=1)
Hash Cond: (ms.vslid = vsl.id)
-> Seq Scan on marinerstates ms (cost=0.00..2889.32 rows=4590 width=8) (actual time=0.015..33.634 rows=2625 loops=1)
Filter: (((state)::text = 'Active'::text) AND ((starttime)::date <= '2007-01-11'::date) AND ((COALESCE(endtime, now()))::date >= '2006-07-15'::date))
-> Hash (cost=16.72..16.72 rows=272 width=4) (actual time=0.203..0.203 rows=272 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 10kB
-> Seq Scan on vessels vsl (cost=0.00..16.72 rows=272 width=4) (actual time=0.004..0.117 rows=272 loops=1)
-> Hash (cost=8172.57..8172.57 rows=7143 width=23) (actual time=10402.075..10402.075 rows=12832 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 702kB
-> Seq Scan on mariner m (cost=7614.86..8172.57 rows=7143 width=23) (actual time=10386.549..10397.193 rows=12832 loops=1)
Filter: ((NOT (hashed SubPlan 1)) AND ((marinertype)::text = 'Mariner'::text))
SubPlan 1
-> Unique (cost=2768.00..7614.86 rows=1 width=4) (actual time=86.937..10385.379 rows=1454 loops=1)
-> Nested Loop (cost=2768.00..7614.86 rows=1 width=4) (actual time=86.936..10384.555 rows=1835 loops=1)
Join Filter: (msold.marinerid = mold.id)
-> Index Scan using mariner_pkey on mariner mold (cost=0.00..1728.60 rows=14286 width=4) (actual time=0.007..14.250 rows=14286 loops=1)
Filter: ((marinertype)::text = 'Mariner'::text)
-> Materialize (cost=2768.00..5671.97 rows=1 width=8) (actual time=0.003..0.328 rows=1876 loops=14286)
-> Nested Loop (cost=2768.00..5671.96 rows=1 width=8) (actual time=39.259..84.889 rows=1876 loops=1)
-> Hash Semi Join (cost=2768.00..5671.67 rows=1 width=12) (actual time=39.249..81.025 rows=1876 loops=1)
Hash Cond: (msold.marinerid = msold2.marinerid)
Join Filter: ((msold2.id <> msold.id) AND (msold2.starttime < msold.starttime) AND ((msold.starttime - msold2.endtime) <= '1 year 6 mons'::interval))
-> Seq Scan on marinerstates msold (cost=0.00..2889.32 rows=4590 width=20) (actual time=0.003..33.964 rows=2625 loops=1)
Filter: (((state)::text = 'Active'::text) AND ((starttime)::date <= '2007-01-11'::date) AND ((COALESCE(endtime, now()))::date >= '2006-07-15'::date))
-> Hash (cost=2251.66..2251.66 rows=41307 width=24) (actual time=39.156..39.156 rows=41250 loops=1)
Buckets: 8192 Batches: 1 Memory Usage: 2246kB
-> Seq Scan on marinerstates msold2 (cost=0.00..2251.66 rows=41307 width=24) (actual time=0.002..24.552 rows=41250 loops=1)
Filter: ((state)::text = 'Active'::text)
-> Index Scan using vessels_pkey on vessels vslold (cost=0.00..0.28 rows=1 width=4) (actual time=0.001..0.001 rows=1 loops=1876)
Index Cond: (vslold.id = msold.vslid)
Total runtime: 10440.690 ms
(37 rows)

8.3.13 - FAST

QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Unique (cost=633677.56..633700.48 rows=1834 width=23) (actual time=551.166..558.487 rows=603 loops=1)
-> Sort (cost=633677.56..633682.14 rows=1834 width=23) (actual time=551.156..553.548 rows=603 loops=1)
Sort Key: m.surname, (COALESCE(m.givenname, ''::character varying)), (COALESCE(m.midname, ''::character varying)), m.id
Sort Method: quicksort Memory: 53kB
-> Hash Join (cost=630601.65..633578.15 rows=1834 width=23) (actual time=447.773..547.934 rows=603 loops=1)
Hash Cond: (ms.vslid = vsl.id)
-> Hash Join (cost=630580.33..633530.01 rows=2261 width=27) (actual time=445.320..540.291 rows=603 loops=1)
Hash Cond: (ms.marinerid = m.id)
-> Seq Scan on marinerstates ms (cost=0.00..2875.32 rows=4599 width=8) (actual time=0.018..79.742 rows=2625 loops=1)
Filter: (((state)::text = 'Active'::text) AND ((starttime)::date <= '2007-01-11'::date) AND ((COALESCE(endtime, now()))::date >= '2006-07-15'::date))
-> Hash (cost=630491.54..630491.54 rows=7103 width=23) (actual time=445.216..445.216 rows=12832 loops=1)
-> Index Scan using mariner_pkey on mariner m (cost=628776.89..630491.54 rows=7103 width=23) (actual time=319.675..388.383 rows=12832 loops=1)
Filter: ((NOT (hashed subplan)) AND ((marinertype)::text = 'Mariner'::text))
SubPlan
-> Unique (cost=0.00..628772.30 rows=1834 width=4) (actual time=0.196..312.728 rows=1454 loops=1)
-> Nested Loop (cost=0.00..628767.72 rows=1834 width=4) (actual time=0.187..298.780 rows=1835 loops=1)
-> Nested Loop (cost=0.00..627027.98 rows=1865 width=4) (actual time=0.165..244.706 rows=1876 loops=1)
-> Index Scan using marinerstates_marinerid on marinerstates msold (cost=0.00..626316.07 rows=2299 width=8) (actual time=0.138..194.165 rows=1876 loops=1)
Filter: (((state)::text = 'Active'::text) AND ((starttime)::date <= '2007-01-11'::date) AND ((COALESCE(endtime, now()))::date >= '2006-07-15'::date) AND (subplan))
SubPlan
-> Bitmap Heap Scan on marinerstates msold2 (cost=4.28..12.11 rows=1 width=0) (actual time=0.020..0.020 rows=1 loops=2625)
Recheck Cond: ((marinerid = $0) AND (starttime < $2))
Filter: ((id <> $1) AND ((state)::text = 'Active'::text) AND (($2 - endtime) <= '1 year 6 mons'::interval))
-> Bitmap Index Scan on marinerstates_marinerid_starttime (cost=0.00..4.28 rows=2 width=0) (actual time=0.009..0.009 rows=6 loops=2625)
Index Cond: ((marinerid = $0) AND (starttime < $2))
-> Index Scan using vessels_pkey on vessels vslold (cost=0.00..0.30 rows=1 width=4) (actual time=0.006..0.010 rows=1 loops=1876)
Index Cond: (vslold.id = msold.vslid)
-> Index Scan using mariner_pkey on mariner mold (cost=0.00..0.92 rows=1 width=4) (actual time=0.008..0.012 rows=1 loops=1876)
Index Cond: (mold.id = msold.marinerid)
Filter: ((mold.marinertype)::text = 'Mariner'::text)
-> Hash (cost=17.81..17.81 rows=281 width=4) (actual time=2.432..2.432 rows=273 loops=1)
-> Seq Scan on vessels vsl (cost=0.00..17.81 rows=281 width=4) (actual time=0.033..1.220 rows=273 loops=1)
Total runtime: 561.208 ms
(33 rows)

>
> regards, tom lane
>

--
Achilleas Mantzios