Re: plan_rows confusion with parallel queries

On 11/02/2016 11:56 PM, Tomas Vondra wrote:
> On 11/02/2016 09:00 PM, Tom Lane wrote:
>> Tomas Vondra <tomas(dot)vondra(at)2ndquadrant(dot)com> writes:
>>> while eye-balling some explain plans for parallel queries, I got a bit
>>> confused by the row count estimates. I wonder whether I'm alone.
>>
>> I got confused by that a minute ago, so no you're not alone. The problem
>> is even worse in join cases. For example:
>>
>> Gather (cost=34332.00..53265.35 rows=100 width=8)
>> Workers Planned: 2
>> -> Hash Join (cost=33332.00..52255.35 rows=100 width=8)
>> Hash Cond: ((pp.f1 = cc.f1) AND (pp.f2 = cc.f2))
>> -> Append (cost=0.00..8614.96 rows=417996 width=8)
>> -> Parallel Seq Scan on pp (cost=0.00..8591.67
>> rows=416667 widt
>> h=8)
>> -> Parallel Seq Scan on pp1 (cost=0.00..23.29
>> rows=1329 width=8
>> )
>> -> Hash (cost=14425.00..14425.00 rows=1000000 width=8)
>> -> Seq Scan on cc (cost=0.00..14425.00 rows=1000000
>> width=8)
>>
>> There are actually 1000000 rows in pp, and none in pp1. I'm not bothered
>> particularly by the nonzero estimate for pp1, because I know where that
>> came from, but I'm not very happy that nowhere here does it look like
>> it's estimating a million-plus rows going into the join.
>>

Although - it is estimating 1M rows, but only "per worker" estimates are
shown, and because there are 2 workers planned it says 1M/2.4 which is
the 416k. I agree it's a bit unclear, but at least it's consistent with
how we treat loops (i.e. that the numbers are per loop).

But there's more fun with joins - consider for example this simple join:

QUERY PLAN
------------------------------------------------------------------------------
Gather (cost=19515.96..43404.82 rows=96957 width=12)
(actual time=295.167..746.312 rows=99999 loops=1)
Workers Planned: 2
Workers Launched: 2
-> Hash Join (cost=18515.96..32709.12 rows=96957 width=12)
(actual time=249.281..670.309 rows=33333 loops=3)
Hash Cond: (t2.a = t1.a)
-> Parallel Seq Scan on t2
(cost=0.00..8591.67 rows=416667 width=8)
(actual time=0.100..184.315 rows=333333 loops=3)
-> Hash (cost=16925.00..16925.00 rows=96957 width=8)
(actual time=246.760..246.760 rows=99999 loops=3)
Buckets: 131072 Batches: 2 Memory Usage: 2976kB
-> Seq Scan on t1
(cost=0.00..16925.00 rows=96957 width=8)
(actual time=0.065..178.385 rows=99999 loops=3)
Filter: (b < 100000)
Rows Removed by Filter: 900001
Planning time: 0.763 ms
Execution time: 793.653 ms
(13 rows)

Suddenly we don't show per-worker estimates for the hash join - both the
Hash Join and the Gather have exactly the same cardinality estimate.

Now, let's try forcing Nested Loops and see what happens:

QUERY PLAN
-----------------------------------------------------------------------------
Gather (cost=1000.42..50559.65 rows=96957 width=12)
(actual time=0.610..203.694 rows=99999 loops=1)
Workers Planned: 2
Workers Launched: 2
-> Nested Loop (cost=0.42..39863.95 rows=96957 width=12)
(actual time=0.222..182.755 rows=33333 loops=3)
-> Parallel Seq Scan on t1
(cost=0.00..9633.33 rows=40399 width=8)
(actual time=0.030..40.358 rows=33333 loops=3)
Filter: (b < 100000)
Rows Removed by Filter: 300000
-> Index Scan using t2_a_idx on t2
(cost=0.42..0.74 rows=1 width=8)
(actual time=0.002..0.002 rows=1 loops=99999)
Index Cond: (a = t1.a)
Planning time: 0.732 ms
Execution time: 250.707 ms
(11 rows)

So, different join method but same result - 2 workers, loops=3. But
let's try with small tables (100k rows instead of 1M rows):

QUERY PLAN
----------------------------------------------------------------------------
Gather (cost=0.29..36357.94 rows=100118 width=12) (actual
time=13.219..589.723 rows=100000 loops=1)
Workers Planned: 1
Workers Launched: 1
Single Copy: true
-> Nested Loop (cost=0.29..36357.94 rows=100118 width=12)
(actual time=0.288..442.821 rows=100000 loops=1)
-> Seq Scan on t1 (cost=0.00..1444.18 rows=100118 width=8)
(actual time=0.148..49.308 rows=100000 loops=1)
-> Index Scan using t2_a_idx on t2
(cost=0.29..0.34 rows=1 width=8)
(actual time=0.002..0.002 rows=1 loops=100000)
Index Cond: (a = t1.a)
Planning time: 0.483 ms
Execution time: 648.941 ms
(10 rows)

Suddenly, we get nworkers=1 with loops=1 (and not nworkers+1 as before).
FWIW I've only seen this with force_parallel_mode=on, and the row counts
are correct, so perhaps that's OK. single_copy seems a bit
underdocumented, though.

regards

--
Tomas Vondra http://www.2ndQuadrant.com
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services