Re: Display of buffers for planning time show nothing for second run - Mailing list pgsql-hackers

From Amit Langote
Subject Re: Display of buffers for planning time show nothing for second run
Date
Msg-id CA+HiwqGX-HyZ+pKhj2GyqzpU+4bhrrwX4+zOKSPEtsNnpctEpw@mail.gmail.com
Whole thread Raw
In response to Re: Display of buffers for planning time show nothing for second run  (Julien Rouhaud <rjuju123@gmail.com>)
Responses Re: Display of buffers for planning time show nothing for second run  (Julien Rouhaud <rjuju123@gmail.com>)
Re: Display of buffers for planning time show nothing for second run  (Pavel Stehule <pavel.stehule@gmail.com>)
List pgsql-hackers
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.

-- 

Amit Langote
EnterpriseDB: http://www.enterprisedb.com

pgsql-hackers by date:

Previous
From: Pavel Stehule
Date:
Subject: Re: Display of buffers for planning time show nothing for second run
Next
From: Julien Rouhaud
Date:
Subject: Re: Display of buffers for planning time show nothing for second run