plan with result cache is very slow when work_mem is not enough
| От | Pavel Stehule |
|---|---|
| Тема | plan with result cache is very slow when work_mem is not enough |
| Дата | |
| Msg-id | CAFj8pRAzgoSkdEiqrKbT=7yG9FA5fjUAP3jmJywuDqYq6Ki5ug@mail.gmail.com обсуждение исходный текст |
| Ответы |
Re: plan with result cache is very slow when work_mem is not enough
(Pavel Stehule <pavel.stehule@gmail.com>)
|
| Список | pgsql-hackers |
Hi
I am testing new features of Postgres 14, and now I am trying to check the result cache. Unfortunately on my test data, the result is not too good.
the behaviour is very non linear. Is it expected?
create table t1(a int, t2_id int);
insert into t1 select random() * 100000, random() * 100000 from generate_series(1,1000000);
create table t2(b int, id int);
insert into t2 select random() * 100000, random() * 100000 from generate_series(1,1000000);
create index on t2(id);
vacuum analyze t1, t2;
when work_mem is 40MB
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------
Nested Loop (cost=4.65..472639.79 rows=1000000 width=16) (actual time=0.041..1078.882 rows=1000000 loops=1)
-> Seq Scan on t1 (cost=0.00..14425.00 rows=1000000 width=8) (actual time=0.010..60.212 rows=1000000 loops=1)
-> Result Cache (cost=4.65..4.67 rows=1 width=8) (actual time=0.001..0.001 rows=1 loops=1000000)
Cache Key: t1.t2_id
Hits: 900006 Misses: 99994 Evictions: 0 Overflows: 0 Memory Usage: 10547kB
-> Aggregate (cost=4.64..4.65 rows=1 width=8) (actual time=0.003..0.003 rows=1 loops=99994)
-> Index Only Scan using t2_id_idx on t2 (cost=0.42..4.62 rows=11 width=0) (actual time=0.002..0.003 rows=10 loops=99994)
Index Cond: (id = t1.t2_id)
Heap Fetches: 0
Planning Time: 0.091 ms
Execution Time: 1120.177 ms
-------------------------------------------------------------------------------------------------------------------------------------------
Nested Loop (cost=4.65..472639.79 rows=1000000 width=16) (actual time=0.041..1078.882 rows=1000000 loops=1)
-> Seq Scan on t1 (cost=0.00..14425.00 rows=1000000 width=8) (actual time=0.010..60.212 rows=1000000 loops=1)
-> Result Cache (cost=4.65..4.67 rows=1 width=8) (actual time=0.001..0.001 rows=1 loops=1000000)
Cache Key: t1.t2_id
Hits: 900006 Misses: 99994 Evictions: 0 Overflows: 0 Memory Usage: 10547kB
-> Aggregate (cost=4.64..4.65 rows=1 width=8) (actual time=0.003..0.003 rows=1 loops=99994)
-> Index Only Scan using t2_id_idx on t2 (cost=0.42..4.62 rows=11 width=0) (actual time=0.002..0.003 rows=10 loops=99994)
Index Cond: (id = t1.t2_id)
Heap Fetches: 0
Planning Time: 0.091 ms
Execution Time: 1120.177 ms
when work_mem is 10MB
postgres=# set work_mem to '10MB'; -- 11MB is ok
SET
postgres=# explain analyze select * from t1, lateral(select count(*) from t2 where t1.t2_id = t2.id) s ;
QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------------------
Nested Loop (cost=4.65..472639.79 rows=1000000 width=16) (actual time=0.040..56576.187 rows=1000000 loops=1)
-> Seq Scan on t1 (cost=0.00..14425.00 rows=1000000 width=8) (actual time=0.010..76.753 rows=1000000 loops=1)
-> Result Cache (cost=4.65..4.67 rows=1 width=8) (actual time=0.056..0.056 rows=1 loops=1000000)
Cache Key: t1.t2_id
Hits: 884158 Misses: 115842 Evictions: 18752 Overflows: 0 Memory Usage: 10241kB
-> Aggregate (cost=4.64..4.65 rows=1 width=8) (actual time=0.005..0.005 rows=1 loops=115842)
-> Index Only Scan using t2_id_idx on t2 (cost=0.42..4.62 rows=11 width=0) (actual time=0.003..0.004 rows=10 loops=115842)
Index Cond: (id = t1.t2_id)
Heap Fetches: 0
Planning Time: 0.087 ms
Execution Time: 56621.421 ms
(11 rows)
SET
postgres=# explain analyze select * from t1, lateral(select count(*) from t2 where t1.t2_id = t2.id) s ;
QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------------------
Nested Loop (cost=4.65..472639.79 rows=1000000 width=16) (actual time=0.040..56576.187 rows=1000000 loops=1)
-> Seq Scan on t1 (cost=0.00..14425.00 rows=1000000 width=8) (actual time=0.010..76.753 rows=1000000 loops=1)
-> Result Cache (cost=4.65..4.67 rows=1 width=8) (actual time=0.056..0.056 rows=1 loops=1000000)
Cache Key: t1.t2_id
Hits: 884158 Misses: 115842 Evictions: 18752 Overflows: 0 Memory Usage: 10241kB
-> Aggregate (cost=4.64..4.65 rows=1 width=8) (actual time=0.005..0.005 rows=1 loops=115842)
-> Index Only Scan using t2_id_idx on t2 (cost=0.42..4.62 rows=11 width=0) (actual time=0.003..0.004 rows=10 loops=115842)
Index Cond: (id = t1.t2_id)
Heap Fetches: 0
Planning Time: 0.087 ms
Execution Time: 56621.421 ms
(11 rows)
The query without result cache
postgres=# explain analyze select * from t1, lateral(select count(*) from t2 where t1.t2_id = t2.id) s ;
QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------
Nested Loop (cost=4.64..4689425.00 rows=1000000 width=16) (actual time=0.031..3260.858 rows=1000000 loops=1)
-> Seq Scan on t1 (cost=0.00..14425.00 rows=1000000 width=8) (actual time=0.008..71.792 rows=1000000 loops=1)
-> Aggregate (cost=4.64..4.65 rows=1 width=8) (actual time=0.003..0.003 rows=1 loops=1000000)
-> Index Only Scan using t2_id_idx on t2 (cost=0.42..4.62 rows=11 width=0) (actual time=0.002..0.002 rows=10 loops=1000000)
Index Cond: (id = t1.t2_id)
Heap Fetches: 0
Planning Time: 0.081 ms
Execution Time: 3293.543 ms
(8 rows)
QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------
Nested Loop (cost=4.64..4689425.00 rows=1000000 width=16) (actual time=0.031..3260.858 rows=1000000 loops=1)
-> Seq Scan on t1 (cost=0.00..14425.00 rows=1000000 width=8) (actual time=0.008..71.792 rows=1000000 loops=1)
-> Aggregate (cost=4.64..4.65 rows=1 width=8) (actual time=0.003..0.003 rows=1 loops=1000000)
-> Index Only Scan using t2_id_idx on t2 (cost=0.42..4.62 rows=11 width=0) (actual time=0.002..0.002 rows=10 loops=1000000)
Index Cond: (id = t1.t2_id)
Heap Fetches: 0
Planning Time: 0.081 ms
Execution Time: 3293.543 ms
(8 rows)
Samples: 119K of event 'cycles', 4000 Hz, Event count (approx.):
Overhead Shared Object Symbol
79.20% postgres [.] cache_reduce_memory
1.94% [kernel] [k] native_write_msr_safe
1.63% [kernel] [k] update_cfs_shares
1.00% [kernel] [k] trigger_load_balance
0.97% [kernel] [k] timerqueue_add
0.51% [kernel] [k] task_tick_fair
0.51% [kernel] [k] task_cputime
0.50% [kernel] [k] perf_event_task_tick
0.50% [kernel] [k] update_curr
0.49% [kernel] [k] hrtimer_active
Overhead Shared Object Symbol
79.20% postgres [.] cache_reduce_memory
1.94% [kernel] [k] native_write_msr_safe
1.63% [kernel] [k] update_cfs_shares
1.00% [kernel] [k] trigger_load_balance
0.97% [kernel] [k] timerqueue_add
0.51% [kernel] [k] task_tick_fair
0.51% [kernel] [k] task_cputime
0.50% [kernel] [k] perf_event_task_tick
0.50% [kernel] [k] update_curr
0.49% [kernel] [k] hrtimer_active
Regards
Pavel
В списке pgsql-hackers по дате отправления:
Предыдущее
От: James ColemanДата:
Сообщение: Re: Processing btree walks as a batch to parallelize IO
Следующее
От: Andrew DunstanДата:
Сообщение: Re: Why do we have perl and sed versions of Gen_dummy_probes?