Re: Display of buffers for planning time show nothing for second run - Mailing list pgsql-hackers
| From | Julien Rouhaud |
|---|---|
| Subject | Re: Display of buffers for planning time show nothing for second run |
| Date | |
| Msg-id | CAOBaU_a5QrG2hKs8eUrnWarj5QZF97zWDktHdmHF_-B3GPqgZQ@mail.gmail.com Whole thread |
| In response to | Re: Display of buffers for planning time show nothing for second run (Amit Langote <amitlangote09@gmail.com>) |
| List | pgsql-hackers |
On Tue, Apr 14, 2020 at 10:40 AM Amit Langote <amitlangote09@gmail.com> wrote:
>
> On Tue, Apr 14, 2020 at 5:27 PM Julien Rouhaud <rjuju123@gmail.com> wrote:
> > On Tue, Apr 14, 2020 at 10:18 AM Pavel Stehule <pavel.stehule@gmail.com> wrote:
> > > For second run I get
> > >
> > > postgres=# EXPLAIN (BUFFERS, ANALYZE) SELECT * FROM obce WHERE okres_id = 'CZ0201';
> > >
┌──────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┐
> > > │ QUERY PLAN
│
> > >
╞══════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════╡
> > > │ Index Scan using obce_okres_id_idx on obce (cost=0.28..14.49 rows=114 width=41) (actual time=0.044..0.101
rows=114loops=1) │
> > > │ Index Cond: ((okres_id)::text = 'CZ0201'::text)
│
> > > │ Buffers: shared hit=4
│
> > > │ Planning Time: 0.159 ms
│
> > > │ Execution Time: 0.155 ms
│
> > >
└──────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┘
> > > (5 rows)
> > >
> > > Now, there is not any touch in planning time. Does it mean so this all these data are cached somewhere in session
memory?
> >
> > The planning time is definitely shorter the 2nd time. And yes, what
> > you see are all the catcache accesses that are initially performed on
> > a fresh new backend.
>
> By the way, even with all catcaches served from local memory, one may
> still see shared buffers being hit during planning. For example:
>
> explain (buffers, analyze) select * from foo where a = 1;
> QUERY PLAN
> -------------------------------------------------------------------------------------------------------------------
> Index Only Scan using foo_pkey on foo (cost=0.15..8.17 rows=1
> width=4) (actual time=0.010..0.011 rows=0 loops=1)
> Index Cond: (a = 1)
> Heap Fetches: 0
> Buffers: shared hit=2
> Planning Time: 0.775 ms
> Buffers: shared hit=72
> Execution Time: 0.086 ms
> (7 rows)
>
> Time: 2.477 ms
> postgres=# explain (buffers, analyze) select * from foo where a = 1;
> QUERY PLAN
> -------------------------------------------------------------------------------------------------------------------
> Index Only Scan using foo_pkey on foo (cost=0.15..8.17 rows=1
> width=4) (actual time=0.012..0.012 rows=0 loops=1)
> Index Cond: (a = 1)
> Heap Fetches: 0
> Buffers: shared hit=2
> Planning Time: 0.102 ms
> Buffers: shared hit=1
> Execution Time: 0.047 ms
> (7 rows)
>
> It seems that 1 Buffer hit comes from get_relation_info() doing
> _bt_getrootheight() for that index on foo.
Indeed. Having received some relcache invalidation should also lead
to similar effect. Having those counters can help to quantify all of
those interactions.
pgsql-hackers by date: