Проект «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

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