Проект «SnakeProject» Михаила Козлова

⇒ FreeBSD and Nix ⇐

CISCO

Voice(Asterisk\Cisco)

Microsoft

Powershell

Python

SQL\T-SQL

1С

Общая

WEB Разработка

ORACLE SQL \ JAVA

Мото

Стрельба, пневматика, оружие

PostgreSQL медленное выполнение при первом запросе

PostgreSQL медленное выполнение при первом запросе

После старта Postgres первые запросы будут долго выполняться
Последующие будут выполняться порядком быстрее
Причина - в файловом кеше ОС и общих буферах нет данных

Вы можете проверить это с помощью расширенных EXPLAIN параметров:
EXPLAIN (ANALYZE, BUFFERS) SELECT ...
Вы увидите, сколько буферов было выбрано с диска (read) или из кеша (hit)
Пример: Buffers: shared hit=13935 read=5353

PostgreSQL и два уровня кеша

1 - кеш файлов ОС (effective_cache_size)
2 - общие буферы (shared_buffers)

Postgres напрямую контролирует только второй уровень

Какие настройки для postgresql.conf указать:

effective_cache_size - около 3/4 от всей доступной оперативной памяти

Внимание! 
Параметр - всего лишь рекомендация планировщику Postgres
Сообщает некоторую оценку размера кеша файлов ОС

shared_buffers - около 1/4 объема ОЗУ

Внимание! 
Изучите настройки, связанные с памятью (work_mem, maintenance_work_mem)

Конструкция для анализа:
EXPLAIN(ANALYZE, BUFFERS) SELECT ...

Пример на двух идентичных запросах

# EXPLAIN(ANALYZE, BUFFERS)
# SELECT "doc_table"."id", "doc_table"."doc_id", "doc_table"."column_id"
# FROM "doc_table"
# INNER JOIN "doc" ON ( "doc_table"."doc_id" = "doc"."id" )
# WHERE "doc_table"."column_id" IN (11111, 22222, 33333)
# ORDER BY "doc"."create_date2" DESC LIMIT 30;
                                                                         QUERY PLAN

-----------------------------------------------------------------------------------------------------------------------------------------------------------
--
 Limit  (cost=59361.90..59365.40 rows=30 width=32) (actual time=10165.397..10169.987 rows=30 loops=1)
   Buffers: shared hit=13935 read=5353
   ->  Gather Merge  (cost=59361.90..60145.02 rows=6712 width=32) (actual time=10165.389..10169.972 rows=30 loops=1)
         Workers Planned: 2
         Workers Launched: 2
         Buffers: shared hit=13935 read=5353
         ->  Sort  (cost=58361.88..58370.27 rows=3356 width=32) (actual time=10119.729..10119.735 rows=23 loops=3)
               Sort Key: doc.create_date2 DESC
               Sort Method: top-N heapsort  Memory: 27kB
               Worker 0:  Sort Method: top-N heapsort  Memory: 28kB
               Worker 1:  Sort Method: top-N heapsort  Memory: 28kB
               Buffers: shared hit=13935 read=5353
               ->  Nested Loop  (cost=160.70..58262.76 rows=3356 width=32) (actual time=88.262..10117.709 rows=1168 loops=3)
                     Buffers: shared hit=13921 read=5353
                     ->  Parallel Bitmap Heap Scan on doc_table  (cost=160.13..29624.84 rows=3356 width=24) (actual time=68.407..2103.363 rows=1168 loops=3
)
                           Recheck Cond: (column_id = ANY ('{11111,22222,33333}'::bigint[]))
                           Heap Blocks: exact=567
                           Buffers: shared hit=8 read=1744
                           ->  Bitmap Index Scan on doc_table_i1  (cost=0.00..158.11 rows=8054 width=0) (actual time=82.402..82.403 rows=3504 loops=1)
                                 Index Cond: (column_id = ANY ('{11111,22222,33333}'::bigint[]))
                                 Buffers: shared hit=6 read=16
                     ->  Index Scan using doc_pkey1 on doc  (cost=0.57..8.53 rows=1 width=16) (actual time=6.858..6.858 rows=1 loops=3504)
                           Index Cond: (id = doc_table.doc_id)
                           Buffers: shared hit=13913 read=3609
 Planning Time: 39.942 ms
 Execution Time: 10170.235 ms
(26 rows)

# EXPLAIN(ANALYZE, BUFFERS)
SELECT "doc_table"."id", "doc_table"."doc_id", "doc_table"."column_id"
FROM "doc_table"
INNER JOIN "doc" ON ( "doc_table"."doc_id" = "doc"."id" )
WHERE "doc_table"."column_id" IN (11111, 22222, 33333)
ORDER BY "doc"."create_date2" DESC LIMIT 30;
                                                                       QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=59361.90..59365.40 rows=30 width=32) (actual time=29.919..34.125 rows=30 loops=1)
   Buffers: shared hit=19288
   ->  Gather Merge  (cost=59361.90..60145.02 rows=6712 width=32) (actual time=29.917..34.117 rows=30 loops=1)
         Workers Planned: 2
         Workers Launched: 2
         Buffers: shared hit=19288
         ->  Sort  (cost=58361.88..58370.27 rows=3356 width=32) (actual time=23.624..23.629 rows=30 loops=3)
               Sort Key: doc.create_date2 DESC
               Sort Method: top-N heapsort  Memory: 28kB
               Worker 0:  Sort Method: top-N heapsort  Memory: 29kB
               Worker 1:  Sort Method: top-N heapsort  Memory: 29kB
               Buffers: shared hit=19288
               ->  Nested Loop  (cost=160.70..58262.76 rows=3356 width=32) (actual time=0.817..23.056 rows=1168 loops=3)
                     Buffers: shared hit=19274
                     ->  Parallel Bitmap Heap Scan on doc_table  (cost=160.13..29624.84 rows=3356 width=24) (actual time=0.733..5.835 rows=1168 loops=3)
                           Recheck Cond: (column_id = ANY ('{11111,22222,33333}'::bigint[]))
                           Heap Blocks: exact=938
                           Buffers: shared hit=1752
                           ->  Bitmap Index Scan on doc_table_i1  (cost=0.00..158.11 rows=8054 width=0) (actual time=1.397..1.397 rows=3504 loops=1)
                                 Index Cond: (column_id = ANY ('{11111,22222,33333}'::bigint[]))
                                 Buffers: shared hit=22
                     ->  Index Scan using doc_pkey1 on doc  (cost=0.57..8.53 rows=1 width=16) (actual time=0.014..0.014 rows=1 loops=3504)
                           Index Cond: (id = doc_table.doc_id)
                           Buffers: shared hit=17522
 Planning Time: 0.606 ms
 Execution Time: 34.209 ms
(26 rows)

Обратите внимание:
1й - Buffers: shared hit=13935 read=5353
2й - Buffers: shared hit=19288

Комментарии пользователей