Waiting for 9.6 – Allow EXPLAIN (ANALYZE, VERBOSE) to display per-worker statistics.

On 9th of December, Robert Haas committed patch:

Allow EXPLAIN (ANALYZE, VERBOSE) to display per-worker statistics.
 
The original parallel sequential scan commit included only very limited
changes to the EXPLAIN output.  Aggregated totals from all workers were
displayed, but there was no way to see what each individual worker did
or to distinguish the effort made by the workers from the effort made by
the leader.
 
Per a gripe by Thom Brown (and maybe others).  Patch by me, reviewed
by Amit Kapila.

I wrote earlier about parallel seq scans in PostgreSQL.

Their explains weren't all that great, looked like:

$ EXPLAIN analyze SELECT * FROM test WHERE some_text LIKE '%xy%';
                                                      QUERY PLAN                                                       
-----------------------------------------------------------------------------------------------------------------------
 Gather  (cost=1000.00..7759.14 ROWS=100 width=59) (actual TIME=0.160..46.413 ROWS=6663 loops=1)
   NUMBER OF Workers: 3
   ->  Parallel Seq Scan ON test  (cost=0.00..6749.14 ROWS=100 width=59) (actual TIME=0.034..44.427 ROWS=1666 loops=4)
         FILTER: (some_text ~~ '%xy%'::text)
         ROWS Removed BY FILTER: 248334
 Planning TIME: 0.046 ms
 Execution TIME: 47.489 ms
(7 ROWS)

but now, with this new patch, it contains more information:

$ EXPLAIN (analyze, buffers, verbose) SELECT * FROM test WHERE some_text LIKE '%xy%';
                                                          QUERY PLAN                                                          
------------------------------------------------------------------------------------------------------------------------------
 Gather  (cost=1000.00..7759.14 ROWS=100 width=59) (actual TIME=0.159..49.196 ROWS=6663 loops=1)
   Output: id, some_text
   NUMBER OF Workers: 3
   Buffers: shared hit=2713 READ=8658
   ->  Parallel Seq Scan ON public.test  (cost=0.00..6749.14 ROWS=100 width=59) (actual TIME=0.040..47.277 ROWS=1666 loops=4)
         Output: id, some_text
         FILTER: (test.some_text ~~ '%xy%'::text)
         ROWS Removed BY FILTER: 248334
         Buffers: shared hit=2464 READ=8658
         Worker 0: actual TIME=0.021..47.322 ROWS=1662 loops=1
           Buffers: shared hit=616 READ=2143
         Worker 1: actual TIME=0.062..47.464 ROWS=1590 loops=1
           Buffers: shared hit=616 READ=1984
         Worker 2: actual TIME=0.021..47.458 ROWS=1611 loops=1
           Buffers: shared hit=591 READ=2085
 Planning TIME: 0.047 ms
 Execution TIME: 50.258 ms
(17 ROWS)

I do miss “Rows Removed by Filter" for workers, but even as is, it gives you a lot of additional information that can used for further optimizations or debugging.

Now, if only Pg parallel executor could handle more things than plain seq scans … Anyway – it's really nice addition. Thanks a lot.