On Tue, Apr 14, 2020 at 10:40 AM Amit Langote <amitlangot...@gmail.com> wrote: > > On Tue, Apr 14, 2020 at 5:27 PM Julien Rouhaud <rjuju...@gmail.com> wrote: > > On Tue, Apr 14, 2020 at 10:18 AM Pavel Stehule <pavel.steh...@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=114 loops=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.
