EXPLAIN ANALYZE: читаем план запроса

EXPLAIN ANALYZE: читаем план запроса

Главная идея

Как это выглядит на практике

1. Всегда используй расширенный формат: EXPLAIN (ANALYZE, BUFFERS, FORMAT TEXT) SELECT * FROM orders WHERE user_id = 42 ORDER BY created_at DESC LIMIT 20;. ANALYZE выполняет запрос реально. BUFFERS добавляет статистику I/O. FORMAT TEXT — удобочитаемый формат.
2. Читай план снизу вверх: нижние узлы выполняются первыми. Если в самом низу Seq Scan на таблице с миллионами строк — это первый кандидат на оптимизацию. Если Index Scan — смотри на rows vs actual rows.
3. Анализируй расхождение rows vs actual rows: 'rows=1000 actual rows=150000' означает, что планировщик недооценил число строк в 150 раз. Следствие — он выбрал Hash Join вместо Nested Loop, неправильный порядок соединений. Запусти ANALYZE orders; и повтори EXPLAIN ANALYZE.
4. Диагностика I/O через BUFFERS: найди узел с наибольшим shared read. Если read >> hit — данные этого узла не в кеше. Либо увеличь shared_buffers, либо запрос читает слишком много лишних данных.
5. Hash Join Batches > 1 означает spill на диск: 'Hash Batches: 8 (originally 1)'. Это говорит, что для Hash Join не хватило work_mem. Решение: SET work_mem = '256MB'; перед запросом и проверь снова. Если Batches стал 1 — это был спил.
6. Sort Method: external merge Disk означает что сортировка не поместилась в work_mem и записывалась на диск. Увеличь work_mem для сессии: SET work_mem = '128MB';. После сортировка должна стать Sort Method: quicksort Memory.
7. Для EXPLAIN ANALYZE с DML (DELETE, UPDATE, INSERT) обязательно оборачивай в транзакцию: BEGIN; EXPLAIN ANALYZE DELETE FROM old_events WHERE created_at < '2023-01-01'; ROLLBACK;. Без ROLLBACK данные реально удалятся.
8. Используй EXPLAIN (ANALYZE, BUFFERS, VERBOSE) для дополнительной информации: VERBOSE добавляет список выходных столбцов каждого узла и схему в имена таблиц/функций — полезно при сложных запросах с несколькими таблицами.
9. Проверь loops — сколько раз выполнялся узел: '(actual time=0.1..0.5 rows=10 loops=5000)'. Если loops=5000 и каждый занимает 0.5ms, суммарно узел занял 2500ms. Это типично для Nested Loop Join по неиндексированному столбцу.
10. Используй онлайн-инструмент explain.dalibo.com: вставь вывод EXPLAIN ANALYZE и получи графическую визуализацию с подсветкой медленных узлов. Особенно полезно для сложных планов с 20+ узлами.
11. Проверь JIT компиляцию в плане: 'JIT: Functions: 3 Timing: 8.2 ms'. Если JIT timing > 10% от total time на коротком запросе — отключи JIT для него: SET jit = off; EXPLAIN ANALYZE ...;. JIT помогает для длинных аналитических запросов, вредит для коротких OLTP.
12. Сравни план до и после добавления индекса: сохрани вывод EXPLAIN ANALYZE в файл, добавь индекс, запусти снова и сравни. Ищи: изменение типа scan (Seq Scan → Index Scan), изменение join strategy, изменение actual time.

Примеры кода

Базовый EXPLAIN ANALYZE с интерпретацией

-- Полный синтаксис с всеми полезными опциями
EXPLAIN (ANALYZE, BUFFERS, FORMAT TEXT)
SELECT
  o.id,
  o.total,
  o.status,
  u.email
FROM orders o
JOIN users u ON u.id = o.user_id
WHERE o.user_id = 42
  AND o.status = 'paid'
ORDER BY o.created_at DESC
LIMIT 20;

-- Типичный хороший вывод (Index Scan, данные в кеше):
-- Limit  (cost=0.56..10.18 rows=20 width=52)
--        (actual time=0.089..0.312 rows=20 loops=1)
--   Buffers: shared hit=25
--   ->  Nested Loop  (cost=0.56..48.20 rows=100 width=52)
--         Buffers: shared hit=25
--         ->  Index Scan using idx_orders_user_status on orders o
--               Index Cond: (user_id = 42 AND status = 'paid')
--               Rows Removed by Index Recheck: 0
--         ->  Index Scan using users_pkey on users u
--               Index Cond: (id = o.user_id)
-- Planning Time: 0.3 ms
-- Execution Time: 0.4 ms

Диагностика: плохая оценка строк и устаревшая статистика

-- Запрос с плохой оценкой
EXPLAIN (ANALYZE, BUFFERS)
SELECT * FROM events
WHERE event_type = 'purchase'
  AND created_at >= now() - interval '7 days';

-- Плохой вывод (rows сильно занижены):
-- Seq Scan on events
--   Filter: (event_type = 'purchase' AND created_at >= ...)
--   Rows Removed by Filter: 4500000
--   rows=100  actual rows=450000  <-- расхождение в 4500x!
--   actual time=2100..8400

-- Причина: статистика устарела после большого импорта данных
-- Решение: обновить статистику
ANALYZE events;

-- Или для более детальной статистики:
ALTER TABLE events ALTER COLUMN event_type
  SET STATISTICS 500;  -- дефолт 100
ANALYZE events;

-- Теперь повторить EXPLAIN ANALYZE — планировщик выберет индекс

Hash Join с spill на диск

-- Медленный запрос с большим join
EXPLAIN (ANALYZE, BUFFERS)
SELECT
  p.name,
  sum(oi.quantity * oi.price) AS revenue
FROM order_items oi
JOIN products p ON p.id = oi.product_id
WHERE oi.created_at >= '2024-01-01'
GROUP BY p.id, p.name
ORDER BY revenue DESC;

-- Плохой вывод:
-- Hash  (cost=...)  actual time=1200..1200
--   Buckets: 1024  Batches: 16  Memory Usage: 4096kB
--                              ^^^^^^^^^^ spill на диск!
--   Buffers: shared hit=450, shared read=12000, temp written=8000

-- Решение: увеличить work_mem для этого запроса
SET work_mem = '256MB';

EXPLAIN (ANALYZE, BUFFERS)
SELECT ... (тот же запрос);
-- Ожидаем: Batches: 1  (всё в памяти)

Сравнение планов: до и после индекса

-- ДО: нет индекса на payment_method
EXPLAIN (ANALYZE, BUFFERS)
SELECT order_id, amount, payment_method
FROM payments
WHERE payment_method = 'card'
  AND status = 'failed'
  AND created_at >= now() - interval '30 days';

-- Plan: Seq Scan on payments
--   Filter: (payment_method = 'card' AND status = 'failed' AND ...)
--   Rows Removed by Filter: 2847392
--   actual time=0.5..3200  rows=1847  loops=1
--   Buffers: shared hit=15, read=18920  <-- почти всё с диска

-- Добавляем индекс
CREATE INDEX CONCURRENTLY idx_payments_method_status_created
  ON payments(payment_method, status, created_at DESC);

-- ПОСЛЕ:
EXPLAIN (ANALYZE, BUFFERS)
SELECT ... (тот же запрос);
-- Plan: Index Scan using idx_payments_method_status_created
--   Index Cond: (payment_method = 'card' AND status = 'failed' AND ...)
--   actual time=0.1..2.3  rows=1847  loops=1
--   Buffers: shared hit=890, read=0  <-- всё из кеша

Анализ Nested Loop с большим numbers of loops

EXPLAIN (ANALYZE, BUFFERS)
SELECT
  u.name,
  count(o.id) AS order_count,
  sum(o.total) AS total_spent
FROM users u
LEFT JOIN orders o ON o.user_id = u.id
WHERE u.created_at >= '2024-01-01'
GROUP BY u.id, u.name;

-- Плохой вывод (нет индекса на orders.user_id):
-- Nested Loop Left Join
--   ->  Index Scan on users (50000 rows)
--   ->  Seq Scan on orders
--         Filter: (user_id = u.id)
--         actual time=0.1..15.0 rows=3 loops=50000  <-- 50000 seq scan!
--         Buffers: shared hit=250000, read=500000

-- total time: 50000 * 15ms = 750 секунд

-- Решение: CREATE INDEX на orders.user_id
CREATE INDEX idx_orders_user_id ON orders(user_id);

-- После: Nested Loop с Index Scan, loops=50000 но каждый 0.05ms
-- total time: 50000 * 0.05ms = 2.5 секунды

Что происходит под капотом

• Планировщик PostgreSQL использует статистику из pg_statistic (обновляется через ANALYZE) для оценки числа строк. Для каждого столбца хранит: количество уникальных значений (n_distinct), наиболее частые значения (most_common_vals) с частотами, гистограмму распределения (histogram_bounds). Неточная статистика = неверные оценки rows = плохой план.
• cost единицы: seq_page_cost = 1.0, random_page_cost = 4.0 (или 1.1 для SSD), cpu_tuple_cost = 0.01, cpu_operator_cost = 0.0025. Планировщик вычисляет взвешенную сумму операций для каждого возможного плана и выбирает наименьший. Это объясняет почему при random_page_cost = 4.0 (дефолт для HDD) планировщик избегает Index Scan даже когда он был бы быстрее — он 'думает' что random I/O дорогой.
• Join strategies: Nested Loop — хорош для небольших наборов данных с индексом на inner table. Hash Join — хорош для больших наборов без индекса, строит hash table из меньшей таблицы. Merge Join — хорош когда обе таблицы уже отсортированы. Планировщик выбирает стратегию на основе оценки строк — неверная оценка = неверная стратегия.
• startup cost vs total cost: startup = время до первой строки, total = время до последней строки. LIMIT сильно влияет: планировщик может выбрать Nested Loop с low startup cost вместо Hash Join с high startup cost, зная что нужно только 10 строк. Без LIMIT предпочтёт Hash Join с лучшим total cost.
• BUFFERS детализация: shared hit — страница была в shared buffers. shared read — страница читалась с диска (или OS page cache). local hit/read — для temporary tables. temp read/written — временные файлы на диске (Sort spill, Hash spill). dirtied — страница была модифицирована. Соотношение hit/(hit+read) = cache hit ratio для этого конкретного запроса.
• actual time в узле — это время только этого узла без дочерних. Чтобы найти суммарное время включая дочерние, смотри на самый верхний узел, который включает всё. actual time=start..end — start это время до первой строки, end это время до последней. В VERBOSE режиме виден вклад каждого узла в общее время.
• never executed в узле (видно как actual rows=0 loops=0) — этот узел не выполнялся. Типично для правой ветки Anti Join или для плана с несколькими путями где выбрался только один. Не ошибка — просто планировщик избежал этой ветки.
• JIT (Just-In-Time compilation): PostgreSQL 11+ может компилировать части плана в нативный код через LLVM. Полезен для сложных аналитических запросов (много arithmetic, expression evaluation). Вреден для коротких OLTP-запросов — overhead компиляции 10-50ms выше самого запроса. Управление: SET jit = off/on. В плане видно: 'JIT: Functions: N Timing: Xms'.
• Parallel query: планировщик может разбить Seq Scan на несколько параллельных воркеров. В плане: 'Gather (workers: 4)', 'Parallel Seq Scan'. Эффективно для аналитики (100M строк full scan). Параметры: max_parallel_workers_per_gather, min_parallel_table_scan_size. Для OLTP с индексами — параллелизм обычно не нужен и не включается.
• Проверка через explain.dalibo.com или pgMustard: онлайн-инструменты парсят вывод EXPLAIN ANALYZE и строят графическое дерево с подсветкой медленных узлов, автоматически указывают на проблемы (bad estimates, seq scans, disk spills). Используй при анализе сложных планов с 15+ узлами — читать текстовый вывод сложно.

Термины урока

Мини-разбор реальной ситуации

Медленный отчёт в SaaS-приложении: SELECT user_id, count(*), sum(amount) FROM payments WHERE created_at >= '2024-01-01' AND status = 'completed' GROUP BY user_id ORDER BY sum DESC LIMIT 100. Время: 28 секунд. pg_stat_statements показал этот запрос в топ-1 по total_exec_time. EXPLAIN (ANALYZE, BUFFERS) выявил: Seq Scan на таблице 80M строк (8 секунд), Hash Aggregate (Batches: 4 — spill на диск, temp written: 12000 blocks), Sort (Sort Method: external merge Disk). Три проблемы одновременно. Решения: (1) CREATE INDEX CONCURRENTLY idx_payments_status_created ON payments(status, created_at) INCLUDE (user_id, amount). (2) SET work_mem = '128MB' для аналитических запросов через connection parameter в Rails. После оптимизации: Index Scan (0.8 сек), Hash Batches: 1, Sort in memory. Итоговое время: 1.2 секунды вместо 28. В pg_stat_statements total_exec_time для этого запроса упала на 96%.