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

On Tue, Apr 14, 2020 at 11:25 AM Pavel Stehule <pavel.stehule@gmail.com> wrote:
>
> út 14. 4. 2020 v 10:40 odesílatel Amit Langote <amitlangote09@gmail.com> napsal:
>>
>> 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
sessionmemory?
 
>> >
>> > 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.
>
>
> unfortunatelly, I cannot to repeat it.
>
> create table foo(a int);
> create index on foo(a);
> insert into foo values(1);
> analyze foo;
>
> for this case any second EXPLAIN is without buffer on my comp

_bt_getrootheight() won't cache any value if the index is totally
empty.  Removing the INSERT in your example should lead to Amit's
behavior.