read explain (analyse, buffers) output in Postgres 10.4 with parallel on - Mailing list pgsql-sql

From Huan Ruan
Subject read explain (analyse, buffers) output in Postgres 10.4 with parallel on
Date
Msg-id CAGgcTZs0o02L2uoZOAzcFRD62RgtJfwu+FAPLVzw--M3jSHrhw@mail.gmail.com
Whole thread Raw
Responses Re: read explain (analyse, buffers) output in Postgres 10.4 withparallel on
List pgsql-sql
Hi

PostgreSQL 10.4 on CentOS 7.2 64 bit

As per doc states in https://www.postgresql.org/docs/current/static/sql-explain.html, under the BUFFERS section:

The number of blocks shown for an upper-level node includes those used by all its child nodes.  

However, with parallel execution, the output of 'explain (analyse, buffers)' does not seem to match the above doc..

To illustrate,
psql -qE <<EOF
drop database IF EXISTS test_db;
create database test_db;
\c test_db
create table t1 as select f from generate_series(1, 1000000) as t(f);
-- warm up cache
select count(*) from t1;

set max_parallel_workers_per_gather to 0;
explain (analyse, buffers) select count(*) from t1;

set max_parallel_workers_per_gather to 4;
explain (analyse, buffers) select count(*) from t1;
EOF

Output
                                                    QUERY PLAN
-------------------------------------------------------------------------------------------------------------------
 Aggregate  (cost=63664.69..63664.74 rows=1 width=8) (actual time=176.344..176.344 rows=1 loops=1)
   Buffers: shared hit=4425
   ->  Seq Scan on t1  (cost=0.00..60843.75 rows=1128375 width=0) (actual time=0.010..91.800 rows=1000000 loops=1)
         Buffers: shared hit=4425
 Planning time: 0.101 ms
 Execution time: 176.418 ms
(6 rows)

                                                              QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------------
 Finalize Aggregate  (cost=30108.46..30108.51 rows=1 width=8) (actual time=88.572..88.572 rows=1 loops=1)
   Buffers: shared hit=2075
   ->  Gather  (cost=30108.20..30108.45 rows=2 width=8) (actual time=88.549..88.567 rows=3 loops=1)
         Workers Planned: 2
         Workers Launched: 2
         Buffers: shared hit=2075
         ->  Partial Aggregate  (cost=29108.20..29108.25 rows=1 width=8) (actual time=83.902..83.902 rows=1 loops=3)
               Buffers: shared hit=4425
               ->  Parallel Seq Scan on t1  (cost=0.00..27932.81 rows=470156 width=0) (actual time=0.026..48.045 rows=333333 loops=3)
                     Buffers: shared hit=4425
 Planning time: 0.201 ms
 Execution time: 91.212 ms
(12 rows)

I would've thought the highlighted nodes are at top-level. 
  • Output 1 with parallel off seems to match the doc.
  • Output 2 with parallel on does not seem to match the doc.
Am I missing something in interpreting output 2? What is the expected way to work out a query's total buffer usage?

Thanks
Huan


pgsql-sql by date:

Previous
From: Andreas Kretschmer
Date:
Subject: Re: Regarding vacuumdb
Next
From: "Jonathan S. Katz"
Date:
Subject: Re: read explain (analyse, buffers) output in Postgres 10.4 withparallel on