Re: BUG #16109: Postgres planning time is high across version - 10.6 vs 10.10

st 13. 11. 2019 v 11:39 odesílatel Julien Rouhaud <rjuju123@gmail.com>
napsal:

> (moved to -hackers)
>
> On Tue, Nov 12, 2019 at 9:55 PM Andres Freund <andres@anarazel.de> wrote:
> >
> > This last point is more oriented towards other PG developers: I wonder
> > if we ought to display buffer statistics for plan time, for EXPLAIN
> > (BUFFERS). That'd surely make it easier to discern cases where we
> > e.g. access the index and scan a lot of the index from cases where we
> > hit some CPU time issue. We should easily be able to get that data, I
> > think, we already maintain it, we'd just need to compute the diff
> > between pgBufferUsage before / after planning.
>
> That would be quite interesting to have.  I attach as a reference a
> quick POC patch to implement it:
>
> # explain (analyze, buffers) select * from pg_stat_activity;
>                                                              QUERY PLAN
>
> --------------------------------------------------------------------------------------------------------------------------------
>  Hash Left Join  (cost=2.25..3.80 rows=100 width=440) (actual
> time=0.259..0.276 rows=6 loops=1)
>    Hash Cond: (s.usesysid = u.oid)
>    Buffers: shared hit=5
>    ->  Hash Left Join  (cost=1.05..2.32 rows=100 width=376) (actual
> time=0.226..0.236 rows=6 loops=1)
>          Hash Cond: (s.datid = d.oid)
>          Buffers: shared hit=4
>          ->  Function Scan on pg_stat_get_activity s  (cost=0.00..1.00
> rows=100 width=312) (actual time=0.148..0.151 rows=6 loop
>          ->  Hash  (cost=1.02..1.02 rows=2 width=68) (actual
> time=0.034..0.034 rows=5 loops=1)
>                Buckets: 1024  Batches: 1  Memory Usage: 9kB
>                Buffers: shared hit=1
>                ->  Seq Scan on pg_database d  (cost=0.00..1.02 rows=2
> width=68) (actual time=0.016..0.018 rows=5 loops=1)
>                      Buffers: shared hit=1
>    ->  Hash  (cost=1.09..1.09 rows=9 width=68) (actual
> time=0.015..0.015 rows=9 loops=1)
>          Buckets: 1024  Batches: 1  Memory Usage: 9kB
>          Buffers: shared hit=1
>          ->  Seq Scan on pg_authid u  (cost=0.00..1.09 rows=9
> width=68) (actual time=0.004..0.008 rows=9 loops=1)
>                Buffers: shared hit=1
>  Planning Time: 1.902 ms
>    Buffers: shared hit=37 read=29
>    I/O Timings: read=0.506
>  Execution Time: 0.547 ms
> (21 rows)
>
> Note that there's a related discussion in the "Planning counters in
> pg_stat_statements" thread, on whether to also compute buffers from
> planning or not.
>

+1

Pavel