Re: Actuall row count of Parallel Seq Scan in EXPLAIN ANALYZE .

On Mon, Jun 20, 2016 at 2:54 AM, Masahiko Sawada <sawada(dot)mshk(at)gmail(dot)com>
wrote:

> >> QUERY PLAN
> >>
> >>
> -----------------------------------------------------------------------------------------------------------------------------------------------------
> >> Finalize Aggregate (cost=217018.55..217018.56 rows=1 width=8)
> >> (actual time=2640.015..2640.015 rows=1 loops=1)
> >> Output: count(*)
> >> -> Gather (cost=217018.33..217018.54 rows=2 width=8) (actual
> >> time=2639.064..2640.002 rows=3 loops=1)
> >> Output: (PARTIAL count(*))
> >> Workers Planned: 2
> >> Workers Launched: 2
> >> -> Partial Aggregate (cost=216018.33..216018.34 rows=1
> >> width=8) (actual time=2632.714..2632.715 rows=1 loops=3)
> >> Output: PARTIAL count(*)
> >> Worker 0: actual time=2632.583..2632.584 rows=1 loops=1
> >> Worker 1: actual time=2627.517..2627.517 rows=1 loops=1
> >> -> Parallel Seq Scan on public.pgbench_accounts
> >> (cost=0.00..205601.67 rows=4166667 width=0) (actual
> >> time=0.042..1685.542 rows=3333333 loops=3)
> >> Worker 0: actual time=0.033..1657.486 rows=3457968
> >> loops=1
> >> Worker 1: actual time=0.039..1702.979 rows=3741069
> >> loops=1
>

> postgres(1)=# explain analyze verbose select * from pgbench_accounts
> where aid = 10;
> QUERY PLAN
>
> --------------------------------------------------------------------------------------------------------------------------------------------
> Gather (cost=1000.00..217018.43 rows=1 width=97) (actual
> time=0.541..2094.773 rows=1 loops=1)
> Output: aid, bid, abalance, filler
> Workers Planned: 2
> Workers Launched: 2
> -> Parallel Seq Scan on public.pgbench_accounts
> (cost=0.00..216018.34 rows=0 width=97) (actual time=1390.109..2088.103
> rows=0 loops=3)
> Output: aid, bid, abalance, filler
> Filter: (pgbench_accounts.aid = 10)
> Rows Removed by Filter: 3333333
> Worker 0: actual time=2082.681..2082.681 rows=0 loops=1
> Worker 1: actual time=2087.532..2087.532 rows=0 loops=1
> Planning time: 0.126 ms
> Execution time: 2095.564 ms
> (12 rows)
>
>
The below discrepancy bothered me but it finally dawned on me that this is
exactly what Robert's complaint is about. The 1 row returned by the leader
is averaged across three parallel workers and shows as zero in the "actual"
count for the PSS in the second plan.

​Actual rows in parens:

First Plan:

Finalize Agg. (1) <- Gather (3) <- ​Partial Agg (1x3 = 3) { "Leader" (1) +
Worker0 (1) + Worker1 (1) } <- ParallelSS (3.33Mx3) { "Leader" (~2M) +
Worker0 (~4M) + Worker1 (~4M) }

Second Plan:

Gather (1) <- ParallelSS (0.33, rounded down :( x 3) { "Leader" (0) +
Worker0 (0) + Worker1 (0) }

(rhetorical question, see my first paragraph)
Why, in the first plan, does the PSS node have a total count of 10M which
are fed to and aggregated by the Partial Agg node parent, while in the
second plan the PSS node shows zero actual rows yet its parent has a row
count of 1?

I'm inclined to go with Robert on this - reporting averages seems
counter-productive. Similar information can be had by reporting totals and
loop and letting the do the division if needed.

As a middle position if the resultant integer average rows value is 0 can
we output <rows=actual loops=0>? Or omit "loops" altogether? Maybe this
doesn't help on other cases where the round-off error doesn't force the
result to zero - I haven't gone that deep into the pool. Or just start
reporting "totalrows=x" in addition to the other information.

While this issue isn't new to Parallel Queries its scope and visibility is
greatly expanded now that we have them. At that same time the history
suggests that we don't have to fix this in 9.6 but instead can get a feel
for how this plays out in the new reality and then react either via better
documentation or implementation changes.

The two obvious issues with changes in this area are:

Backward compatibility (which can be mitigated)
Regression testing expected output changes (which can be funded)

In any case I do think it would be nice to output leader-as-worker data
alongside dedicated workers. The fewer the hidden numbers the better. In
this case seeing a 1 from the leader actual, even if the PSS node has an
actual count of 0, would have been enough of a hint that indeed the single
row is being passed through. As it stands the reader doesn't see any
rows=1 until the final gather.

David J.