PostgreSQL: використання EXPLAIN та налаштування “auto_explain” в AWS RDS

Автор |  12/02/2025
0 коментарів
 

Вже згадував про можливості EXPLAIN в пості PostgreSQL: AWS RDS Performance and monitoring, але це настільки цікава і корисна штука, що варто про неї поговорити окремо.

До того ж, в AWS RDS для PostgreSQL є можливість включити логування Execution Plans з EXPLAIN, що теж корисно для моніторингу і дебагу, тому подивимось як це включити і які параметри для цього є.

PostgreSQL EXPLAIN

Отже, що таке EXPLAIN? див. також Using EXPLAIN.

Explain відобразить нам Execution Plan. А аби краще розуміти що таке Execution Plan – глянемо на те, як взагалі виглядає процес виконання запитів.

Що таке Execution Plan в PostgreSQL

Коли ми відправляємо запит до PostgreSQL, то:

  • запит проходить через лексичний (Lexing) та синтаксичний (Parsing) аналіз
    • Lexing: розділення на токени (оператори) – SELECT, FROM, WHERE тощо
    • Parsing: перевірка синтаксису та створення дерева синтаксичного аналізу (Parse Tree)
  • далі відбувається аналіз (Analysis/Binding)
    • перевірка існування таблиць, колонок та функцій, прав доступу
    • створюється схематична інформація (schema information) – мета-дані про структуру таблиць, індекси, привілегії тощо
  • створюється логічний план (Logical Plan Generation)
    • на основі дерева синтаксичного аналізу (Parse Tree) формується логічний план запиту, в якому визначаються операції, які треба виконати – JOIN, AGREGATE etc
  • виконується оптимізація запиту (Query Optimization)
    • визначаються найкращі алгоритми JOIN (Nested Loop, Hash Join, Merge Join)
    • вирішується, чи використовувати індекси (Index Scan, Bitmap Index Scan) або повний перегляд таблиці (Seq Scan)
  • генерується фізичний план (Execution Plan Generation)
    • логічний план перетворюється у конкретний набір операцій для виконання (Seq Scan, Index Scan, Hash Join тощо)
    • визначається, як буде використовуватися оперативна пам’ять, кеш і тимчасові файли на диску (саме тому фізичний план – бо вже враховуються фізичні ресурси системи)
  • і нарешті відбувається виконання запиту (Execution)
    • отримуємо дані з диску, змінюємо дані в пам’яті тощо
    • якщо це SELECT – дані відправляються клієнту
    • якщо виконується INSERT/UPDATE/DELETE – дані фізично змінюються на диску
  • завершення операції (Commit або Rollback)
    • COMMIT (підтвердження транзакції) – зміни фіксуються в базі даних, і стають доступні іншим клієнтам
    • ROLLBACK (скасування транзакції) – зміни повертаються до стану, який був до BEGIN

Використання EXPLAIN

Отже, з EXPLAIN ми можемо отримати Execution Plan – тобто, побачити те, які операції будуть виконуватись, і скільки даних і ресурсів вони торкнуться.

Найпростіший приклад може виглядати так:

EXPLAIN SELECT * FROM table_name;

Execution Plan являє собою дерево фізичних операцій, де Nodes – це окрема операція, така як Seq Scan, Index Scan, Sort, Join, Aggregate тощо, а стрілочки – зв’язки між вузлами і передача даних між операціями.

Візуалізація EXPLAIN

Є можливість візуалізувати результати Explain, наприклад онлайн з https://www.pgexplain.dev:

Або https://explain.depesz.com:

Опції EXPLAIN

Загальний синтаксис:

EXPLAIN (options) statement

Основні Options такі:

  • ANALYZE: коли ми просто викликаємо EXPLAIN, то реальні дії не виконуються; додавання ANALYZE запускає виконання запиту, і потім відображає статистику
    • default: FALSE
  • VERBOSE: включає в результат додаткову інформацію (імена колонок, функцій тощо)
    • default: FALSE
  • COSTS: відображення “вартості” виконання операції – умовна одиниця вимірювання витрат на виконання запиту з врахування затрат CPU та IO
    • default: TRUE
  • BUFFERS: відображення використання буферів пам’яті (тільки якщо ANALYZE=TRUE) – скільки даних знайдено в кеші, скільки буде зчитано з диску, записано на диск тощо
    • default: FALSE
  • FORMAT: в якому форматі вивести результат – TEXT, XML, JSON, YAML
    • default: TEXT

Результати EXPLAIN

Давайте глянемо, що у нас було в результаті виконання такого запиту:

EXPLAIN (ANALYZE, VERBOSE, BUFFERS, FORMAT YAML)  SELECT * FROM foster_home;

Що цікавого ми тут маємо:

  • основний план і загальна інформація:
    • Node Type: "Seq Scan": операція послідовного сканування (Sequential Scan), без використання індексів
    • Parallel Aware: false: запит буде виконано без паралелізації
    • Async Capable: false: запит не може бути виконано асинхронно
    • Relation Name: "foster_home": ім’я таблиці, над якою виконуються дії
    • Schema: "public": ім’я схеми, в якій знаходиться таблиця
  • оцінка вартості (COSTS):
    • Startup Cost: 0.00: операція починається миттєво, оскільки це послідовне читання
    • Total Cost: 16242.01: оцінка вартості всієї операції (не час, а умовні одиниці)
    • Plan Rows: 35801: планується повернути в результаті запита 35801 рядків
    • Plan Width: 1330: середній очікуваний розмір рядка в байтах
  • фактичне виконання запиту (ANALYZE):
    • Actual Startup Time: 0.018: час на початок виконання запиту
    • Actual Total Time: 638.911: скільки всього часу зайняло виконання
    • Actual Rows: 35801: скільки рядків було повернуто в результаті виконання
  • вихідні дані (Output):
    • список колонок, які були повернуті в результаті запиту (всі, бо виконуємо SELECT *)
  • буфери пам’яті (BUFFERS):
    • Shared Hit Blocks: 455: в shared_buffers було знайдено 455 блоків з існуючими даними
    • Shared Read Blocks: 15429: 15429 блоків довелось читати з диску
    • Shared Dirtied Blocks: 0 та Shared Written Blocks: 0: в результаті виконання запиту ніякі дані не змінювались
    • Temp Read Blocks: 0 та Temp Written Blocks: 0 – тимчасові файли не використовувались (temp_blks_read в pg_stat_statements)
  • операції введення/виведення (I/O)
    • I/O Read Time: 599.188: скільки часу витратили на читання з диску
    • I/O Write Time: 0.000: нічого не писали
    • Temp I/O Read Time: 0.000 та Temp I/O Write Time: 0.000: знов-таки, тимчасові файли не використовувались

EXPLAIN та використання пам’яті

Що найбільш цікаве для мене, бо до цього всього ми прийшли саме тому, що розбирались з питанням “що з’їло всю пам’ять на сервері” – це скільки пам’яті буде використано при виконання різних запитів.

Використання shared_buffers

Отже, в результатах EXPLAIN ми бачили, що оцінка була:

  • Plan Rows: 35801: планується повернути в результаті запита 35801 строк
  • Plan Width: 1330: і кожен рядок займе 1330 байт у пам’яті

Тобто, в результаті виконання запиту SELECT * FROM foster_home очікується отримати 35801 рядків, в середньому кожен розміром в 1330 байт.

Відповідно, в shared_buffers на час виконання запиту планується мати:

35801*1330/1024/1024
45

45 мегабайт.

Але реальний розмір після виконання вказано в Shared Hit Blocks + Shared Read Blocks: 455 блоків даних по 8 КБ вже було в пам’яті, і 15429 блоків було зчитано з диску.

Враховуючи, що кожен блок це 8КБ, то маємо:

(455+15429)*8/1024
124

Порівняємо з розміром самої таблиці:

dev_kraken_db=> SELECT pg_size_pretty(pg_relation_size('foster_home'));
 pg_size_pretty 
----------------
 124 MB

Отже, в результаті виконання SELECT * FROM foster_home ми в shared_buffers будемо мати 124 мегабайти (3640 байти там вже були, і 123432 буде додатково зчитано з диску).

При тому, що під shared_buffers на Dev-сервері всього виділено:

dev_kraken_db=> SHOW shared_buffers;
 shared_buffers 
----------------
 190496kB

~186 мегабайт.

Різниця в Plan Width і Shared Read Blocks

Чому в плані ми бачили ~45 мегабайт, а після виконання – 124 MB?

Бо Plan Width відображає дані по середньому розміру рядка, а Shared Read Blocks – скільки фізичних блоків даних було прочитано з диску.

Для значень в Plan Width PostgreSQL використовує дані з view pg_stats.avg_width.

Колонки в нашій таблиці:

dev_kraken_db=> \d foster_home
                  Table "public.foster_home"
       Column        | Type  | Collation | Nullable | Default 
---------------------+-------+-----------+----------+---------
 challenge_id        | text  |           |          | 
 type                | text  |           |          | 
 parent_challenge_id | text  |           |          | 
 source_challenge_id | text  |           |          | 
 base_challenge_id   | text  |           |          | 
 bio_parent_id       | text  |           |          | 
 matched_by          | text  |           |          | 
 title               | text  |           |          | 
 challenge           | jsonb |           |          | 
 user_id             | text  |           |          | 
Indexes:
    "foster_home_challenge_id" btree (challenge_id)

І їх розмір в pg_stats:

dev_kraken_db=> SELECT attname, avg_width 
FROM pg_stats 
WHERE tablename = 'foster_home';
       attname       | avg_width 
---------------------+-----------
 type                |         7
 bio_parent_id       |        37
 matched_by          |        18
 challenge_id        |        37
 parent_challenge_id |        37
 title               |        27
 user_id             |        37
 source_challenge_id |        37
 base_challenge_id   |        37
 challenge           |      1056

Що дає нам ті самі 1330 байт:

1056+37+37+37+27+37+37+18+37+7
1330

Отже, планується отримати 35801 строк, і кожна приблизно ~1330 байт.

Але реальний їх розмір ми можемо дізнатись з pg_column_size():

dev_kraken_db=> SELECT pg_size_pretty(avg(pg_column_size(t))) 
FROM foster_home t;
       pg_size_pretty        
-----------------------------
 1424.0065081980950253 bytes

Або:

1424*35801/1024/1024
48

48 мегабайт.

Але ж все одно не 124 мегабайти, які були прочитані з диска? Чому так?

Бо:

  • дані з диску читаються блоками по 8 КБ, а не окремими рядками:
    • тобто, навіть якщо треба отримати кілька рядків в пару кілобайт, то для їх отримання доведеться зчитати 8 КБ блоку, в якому вони знаходяться
  • таблиця може бути фрагментованою:
    • тобто рядки можуть знаходиться в різних блоках даних на диску, і читати доведеться кожен блок
  • виконується Seq Scan (повне сканування таблиці), а не використовується індекс:
    • через це з диску читається вся таблиця
  • частина даних може зберігатись поза основною таблицею в TOAST-таблиці:
    • але в SELECT pg_size_pretty(pg_relation_size('foster_home')); ми вже маємо розмір без TOAST та індексів – 124 мегабайти
    • отримати весь розмір можна з SELECT pg_size_pretty(pg_total_relation_size('foster_home'));

Відносно індексу – як виглядає різниця в читані даних, коли індекс є, і коли нема.

Наприклад, подивимось EXPLAIN SELECT по полю user_id, для якого нема індексу:

dev_kraken_db=> EXPLAIN (ANALYZE, VERBOSE, BUFFERS, FORMAT YAML)  SELECT user_id FROM foster_home;
...
     Node Type: "Seq Scan"               +
     ...
     Total Cost: 16242.01                +
     Plan Rows: 35801                    +
     Plan Width: 37                      +
     ...
     Actual Rows: 35801                  +
     ...
     Output:                             +
       - "user_id"                       +
     Shared Hit Blocks: 715              +
     Shared Read Blocks: 15169           +
...

Знов маємо Node Type: "Seq Scan", тобто вичитування всієї таблиці з диску і, відповідно, багато Shared Read Blocks.

Тоді як для challenge_id, для кого індекс є, це було б:

dev_kraken_db=> EXPLAIN (ANALYZE, VERBOSE, BUFFERS, FORMAT YAML) SELECT challenge_id FROM foster_home;
                 QUERY PLAN                 
--------------------------------------------
 - Plan:                                   +
     Node Type: "Index Only Scan"          +
     ...
     Total Cost: 1629.43                   +
     Plan Rows: 35801                      +
     Plan Width: 37                        +
     ...
     Actual Rows: 35801                    +
     ...
     Output:                               +
       - "challenge_id"                    +
     Heap Fetches: 0                       +
     Shared Hit Blocks: 271                +
     Shared Read Blocks: 0                 +
...

Тут всі дані з нашого індексу вже є в shared_buffers, тому з диску взагалі нічого не читалось.

Перевірити shared_bufers для індексу foster_home_challenge_id можемо так:

dev_kraken_db=> SELECT count(*) AS cached_pages,
       pg_size_pretty(count(*) * 8192) AS cached_size
FROM pg_buffercache
WHERE relfilenode = (SELECT relfilenode FROM pg_class WHERE relname = 'foster_home_challenge_id');
 cached_pages | cached_size 
--------------+-------------
          271 | 2168 kB

Окей – тут наче розібрались?

Але окрім shared_buffers під час виконання запиту може ще використовуватись і work_mem.

Використання work_mem

work_mem використовується, якщо в запиті є ORDER BY, HASH JOIN.

Див. Resource Consumption.

При цьому якщо в одному запиті є кілька таких операцій – то під кожну буде виділено свою область work_mem:

Query Plan:
   Sort (work_mem = 4MB)
     -> Nested Loop
         -> Sort (work_mem = 4MB)
         -> Hash Join (work_mem = 4MB)

Крім того, окремий work_mem виділяється кожному Worker, тобто додатковому процесу при виконанні запиту – див. How Parallel Query Works:

...
   ->  Sort  (cost=25736.77..25774.06 rows=14917 width=1330) (actual time=1286.099..1352.484 rows=11934 loops=3)
         ...
         Worker 0:  actual time=1279.232..1338.547 rows=10752 loops=1
           ...
         Worker 1:  actual time=1281.125..1358.600 rows=12929 loops=1
           ...
...

Перевірити, скільки work_mem споживає запит, і чи достатньо дефолтних 4 мегабайт можемо так:

dev_kraken_db=> EXPLAIN (ANALYZE, VERBOSE, BUFFERS, FORMAT YAML)
dev_kraken_db-> SELECT * FROM foster_home ORDER BY title;
                 QUERY PLAN                 
--------------------------------------------
 - Plan:                                   +
     Node Type: "Gather Merge"             +
     ...
     Temp Read Blocks: 5497                +
     Temp Written Blocks: 5507             +
     ...
     Temp I/O Read Time: 192.337           +
     Temp I/O Write Time: 117.445          +
     ...
     Plans:                                +
       - Node Type: "Sort" 
         ...
         Sort Key:                         +
           - "foster_home.title"           +
         Sort Method: "external merge"     +
         Sort Space Used: 17048            +
         Sort Space Type: "Disk"           +
...

Тут ми бачимо, що:

  • Temp Read та Written Blocks: використовувались тимчасові блоки
  • Temp I/O Read та Write Time: був витрачений час на роботу з диском
  • Sort Method: "external merge" та Sort Space Type: "Disk": для сортування використовувався диск, а не "Memory", бо в work_mem весь результат не вмістився
  • Sort Space Used: 17048: для сортування знадобилось 17048 кілобайт (16 мегабайт)

Перевірити поточне значення для work_mem можемо так:

dev_kraken_db=> SHOW work_mem;
 work_mem 
----------
 4MB

Саме тому для сортування знадобилось створювати temp files.

Якщо ж ми збільшимо work_mem (через SET для поточної сесії, або через Parameters Group для RDS аби зміни були постійними):

dev_kraken_db=> SET work_mem = '20MB';
SET

То тепер будемо бачити іншу картину:

...
     Temp Written Blocks: 0                 +
     ...
     Temp I/O Write Time: 0.000             +
...
         Sort Key:                          +
           - "foster_home.title"            +
         Sort Method: "quicksort"           +
         Sort Space Used: 17454             +
         Sort Space Type: "Memory"          +

...

Отже, як резюме: з EXPLAIN ANALYZE ми можемо отримати інформацію про те, скільки даних при виконанні запиту буде зчитано з диску в shared_buffers, і скільки даних буде використано в work_mem або temp files

Як нам це може допомогти моніторити “важкі” запити в AWS RDS?

AWS RDS PostgreSQL та auto_explain

В RDS ми можемо включити auto_explain, який буде записувати в лог результат EXPLAIN для подальшого аналізу.

Документація – auto_explain — log execution plans of slow queries. Код самого модуля – auto_explain.c.

Аби включити auto_explain в RDS, його треба додати в shared_preload_libraries:

Після чого ребутаємо інстанс RDS.

Далі налаштовуємо такі параметри:

  • auto_explain.log_min_duration: скільки часу має виконуватись запит, аби бути записаним в лог з EXPLAIN (в мілісекундах)
  • auto_explain.log_analyze: виконувати ANALIZE, а не просто EXPLAIN (може впливати на навантаження RDS)
  • auto_explain.log_buffers: додавати інформацію по BUFFERS
  • auto_explain.log_verbose: VERBOSE для EXPLAIN
  • auto_explain.log_format: в якому форматі пишемо лог

Зберігаємо параметри, і перевіряємо лог:

Готово.

Корисні посилання