Re: Explain buffers wrong counter with parallel plans

> On Jul 25, 2018, at 10:25 PM, Amit Kapila <amit(dot)kapila16(at)gmail(dot)com> wrote:
>
> On Wed, Jul 25, 2018 at 7:42 PM, Jonathan S. Katz
> <jonathan(dot)katz(at)excoventures(dot)com> wrote:
>>
>> On Jul 7, 2018, at 12:03 AM, Amit Kapila <amit(dot)kapila16(at)gmail(dot)com> wrote:
>>
>> I tried running the below on both 11beta2 and HEAD with the patch
>> applied:
>>
>> CREATE UNLOGGED TABLE t1 (c1 int);
>> INSERT INTO t1 SELECT generate_series(1,100000000);
>> /** restart PostgreSQL */
>> EXPLAIN (analyze,buffers,timing off,costs off)
>> SELECT count(*) FROM t1;
>> /** repeat above two queries */
>>
>> I have identical postgresql.conf files on both instances as well.
>>
>> 11beta2
>> ======
>> buffers=# explain (analyze,buffers,timing off,costs off) select count(*)
>> from t1;
>> QUERY PLAN
>>
>> --------------------------------------------------------------------------
>> Finalize Aggregate (actual rows=1 loops=1)
>> Buffers: shared read=63175
>> -> Gather (actual rows=7 loops=1)
>> Workers Planned: 6
>> Workers Launched: 6
>> Buffers: shared read=63175
>> -> Partial Aggregate (actual rows=1 loops=7)
>> Buffers: shared read=442478
>> -> Parallel Seq Scan on t1 (actual rows=14285714
>> loops=7)
>> Buffers: shared read=442478
>> Planning Time: 1.422 ms
>> Execution Time: 3214.407 ms
>> (12 rows)
>>
>> buffers=# explain (analyze,buffers,timing off,costs off) select count(*)
>> from t1;
>> QUERY PLAN
>>
>> --------------------------------------------------------------------------
>> Finalize Aggregate (actual rows=1 loops=1)
>> Buffers: shared hit=27 read=64960
>> -> Gather (actual rows=7 loops=1)
>> Workers Planned: 6
>> Workers Launched: 6
>> Buffers: shared hit=27 read=64960
>> -> Partial Aggregate (actual rows=1 loops=7)
>> Buffers: shared hit=224 read=442254
>> -> Parallel Seq Scan on t1 (actual rows=14285714
>> loops=7)
>> Buffers: shared hit=224 read=442254
>> Planning Time: 0.080 ms
>> Execution Time: 3774.091 ms
>> (12 rows)
>>
>> HEAD
>> =====
>> buffers=# explain (analyze,buffers,timing off,costs off) select count(*)
>> from t1;
>> QUERY PLAN
>>
>> --------------------------------------------------------------------------
>> Finalize Aggregate (actual rows=1 loops=1)
>> Buffers: shared read=442478
>> -> Gather (actual rows=7 loops=1)
>> Workers Planned: 6
>> Workers Launched: 6
>> Buffers: shared read=442478
>> -> Partial Aggregate (actual rows=1 loops=7)
>> Buffers: shared read=442478
>> -> Parallel Seq Scan on t1 (actual rows=14285714
>> loops=7)
>> Buffers: shared read=442478
>> Planning Time: 1.594 ms
>> Execution Time: 6207.799 ms
>> (12 rows)
>>
>> buffers=# explain (analyze,buffers,timing off,costs off) select count(*)
>> from t1;
>> QUERY PLAN
>>
>> --------------------------------------------------------------------------
>> Finalize Aggregate (actual rows=1 loops=1)
>> Buffers: shared hit=224 read=442254
>> -> Gather (actual rows=7 loops=1)
>> Workers Planned: 6
>> Workers Launched: 6
>> Buffers: shared hit=224 read=442254
>> -> Partial Aggregate (actual rows=1 loops=7)
>> Buffers: shared hit=224 read=442254
>> -> Parallel Seq Scan on t1 (actual rows=14285714
>> loops=7)
>> Buffers: shared hit=224 read=442254
>> Planning Time: 0.074 ms
>> Execution Time: 5006.395 ms
>> (12 rows)
>>
>> Notice the “read” numbers just before the “Finalize Aggregate” is much
>> higher,
>>
>
> You mean to say the number (Buffers: shared read=442478) in HEAD,
> right? If so, yeah, I am also wondering why the results of the patch
> are different in HEAD and 11beta2. So, if I read correctly, the
> numbers in 11beta2 appears correct, but on HEAD it is not correct, it
> should have divided the buffers read by loops. I will figure that
> out, but this is just to clarify that both of us are seeing the
> results in the same way.

I’ll try it again but patch it against 11beta2 and see what results I get.

>
>> and there appears to be a performance hit.
>>
>
> Do you mean to say the performance of the same query in 11beta2 and
> HEAD or something else?

Correct. But per your advice let me try running it against a patched
version of 11beta2 and see what happens.

Jonathan