EXPLAIN ANALYZE в PostgreSQL: как читать план запроса и находить узкие места

Один запрос в панели логистической компании грузился 9 секунд. Разработчики сначала грешили на сеть, потом на бэкенд, и только EXPLAIN ANALYZE показал: дело было в одной забытой детали внутри PostgreSQL. Это встроенная команда, которая вскрывает запрос изнутри и показывает, куда именно уходит время — без гаданий и логов «на глаз».

Прежде чем читать план — исключите два частых виновника

Соблазн сразу открыть SQL и начать его кромсать велик. Но часто проблема прячется не в самом запросе, а рядом с ним.

Первый подозреваемый — отключенная или отстающая автоочистка (autovacuum). Без неё в таблице копятся остатки от старых обновлений и удалений: строки формально удалены, но физически лежат на диске. Таблица на пару сотен тысяч «живых» записей может весить, как таблица на миллиард — и любой запрос к ней будет ползти.

SELECT relname, n_dead_tup, n_live_tup, last_autovacuum
FROM pg_stat_user_tables
ORDER BY n_dead_tup DESC
LIMIT 20;

Огромная цифра в n_dead_tup при пустом last_autovacuum — это уже ответ. Дальше можно не копать.

Второй подозреваемый — устаревшая статистика. Планировщик PostgreSQL строит план запроса на основе данных о таблице: сколько строк, как они распределены. После массовой загрузки эти цифры быстро теряют актуальность, и планировщик начинает строить план вслепую. Лечится в одну строку:

ANALYZE имя_таблицы;

Кто виноват на самом деле: ищем через pg_stat_statements

Хвататься за первый попавшийся медленный запрос — плохая тактика. Время уйдёт, а нагрузка на базу почти не изменится. Нужен конкретный виновник — тот запрос, что реально тянет систему вниз.

Для этого в PostgreSQL есть расширение pg_stat_statements. Подключается через postgresql.conf:

shared_preload_libraries = 'pg_stat_statements'

После рестарта сервера — активация:

CREATE EXTENSION IF NOT EXISTS pg_stat_statements;

А дальше запрос, который сразу покажет главных подозреваемых:

SELECT query, calls,
       round(mean_exec_time::numeric, 2) AS avg_ms,
       round(total_exec_time::numeric, 2) AS total_ms
FROM pg_stat_statements
ORDER BY mean_exec_time DESC
LIMIT 10;

Смотреть только на среднее время — ошибка. Запрос на 5 секунд раз в сутки почти не заметен на фоне общей нагрузки. А вот запрос на 200 мс, который срабатывает 80 тысяч раз за день, суммарно съедает куда больше — с него и стоит начинать.

EXPLAIN и EXPLAIN ANALYZE — это разные вещи

Простой EXPLAIN — это прогноз. Он показывает, что планировщик собирается делать, но запрос при этом не выполняется.

EXPLAIN ANALYZE — это уже факт. Запрос реально проигрывается, и к прогнозу добавляются настоящие цифры: сколько строк обработано, сколько миллисекунд ушло на каждый этап. Разница между прогнозом и фактом — первое, на что стоит смотреть.

EXPLAIN (ANALYZE, BUFFERS, VERBOSE) SELECT ...;

Параметр BUFFERS отдельно рассказывает про память: сколько данных нашлось в кеше, а сколько пришлось поднимать с диска. Диск — самая частая причина задержек.

Важная деталь: раз запрос выполняется по-настоящему, INSERT, UPDATE и DELETE безопаснее оборачивать в транзакцию с откатом:

BEGIN;
EXPLAIN ANALYZE DELETE FROM shipments WHERE status = 'cancelled';
ROLLBACK;

Кейс: почему поиск по трек-коду занимал 9 секунд

Вернёмся к логистической панели. Клиенты искали посылку по трек-коду, и вот что показал план запроса:

EXPLAIN (ANALYZE, BUFFERS)
SELECT id, status, delivery_date FROM shipments 
WHERE tracking_code = 'KZ7784512090';

Seq Scan on shipments  (cost=0.00..52310.00 rows=1 width=32)
                       (actual time=0.081..9214.660 rows=1 loops=1)
  Filter: (tracking_code = 'KZ7784512090')
  Rows Removed by Filter: 2184609
  Buffers: shared hit=8802 read=13417
Execution Time: 9214.712 ms

Всё видно с первой строки. Seq Scan — PostgreSQL перебрал 2,1 миллиона отправлений, чтобы найти одну посылку. Rows Removed by Filter подтверждает: почти вся таблица прочитана впустую. А 13417 страниц пришлось поднимать с диска — индекса по трек-коду попросту не было.

Решение занимает одну строку:

CREATE INDEX CONCURRENTLY idx_shipments_tracking_code ON shipments(tracking_code);

Тот же запрос после создания индекса:

Index Scan using idx_shipments_tracking_code on shipments
  (cost=0.42..8.44 rows=1 width=32)
  (actual time=0.028..0.031 rows=1 loops=1)
  Buffers: shared hit=4
Execution Time: 0.052 ms

9,2 секунды превратились в 0,05 миллисекунды. Диск из плана исчез — данные нашлись в памяти с первой попытки.

Что означают типы операций в плане

PostgreSQL выбирает между несколькими способами прочитать таблицу, и от выбора напрямую зависит скорость запроса. Вот основные варианты, которые встречаются в плане:

• Seq Scan — сплошное чтение всей таблицы подряд. Нормально для небольших таблиц или когда нужно больше 10–15% строк.
• Index Scan — поиск по индексу с последующим обращением к таблице за остальными полями. Хорош для точечных выборок.
• Index Only Scan — всё нужное уже лежит в индексе, таблицу читать вообще не приходится. Самый быстрый вариант.
• Bitmap Heap Scan — сначала строится карта совпадений по индексу, потом таблица читается блоками. Компромисс для выборок среднего размера.

Выбор между этими вариантами планировщик делает сам — вручную задать тип сканирования нельзя, но индексами можно подтолкнуть его в нужную сторону.

С соединением таблиц похожая история: Hash Join выигрывает при достаточной памяти, Nested Loop хорош для маленьких выборок с индексом, а Merge Join встречается реже и требует заранее отсортированных данных.

Три места, где скорость теряется чаще всего

Большинство проблем с производительностью на практике укладываются в один из трёх сценариев:

1. Пагинация через OFFSET. Запрос ORDER BY delivery_date DESC OFFSET 50000 LIMIT 20 читает и выбрасывает 50 тысяч строк ради 20 нужных. Решение — keyset pagination: фильтр по значению последней строки предыдущей страницы вместо смещения. Скорость перестаёт зависеть от номера страницы.
2. Hash Join уходит на диск. Строка Batches: 6 вместо единицы означает, что хеш-таблица не влезла в память. Часто спасает временное увеличение work_mem для конкретной сессии.
3. Составной индекс работает частично. Индекс по (warehouse_id, status, delivery_date) применяется только с левого столбца. Фильтр по одному status без warehouse_id его проигнорирует полностью.

Все три случая объединяет одно: проблема видна в EXPLAIN ANALYZE сразу, если знать, на какую строку плана смотреть.

Как ловить такие запросы автоматически

Разбирать конкретный случай руками — нормально для отладки. Но в проде нужен автоматический перехват, иначе следующий девятисекундный запрос обнаружат только по жалобам клиентов.

Базовый вариант — параметр, который пишет в лог всё, что выполняется дольше порога:

log_min_duration_statement = 1000

Более удобный инструмент — расширение auto_explain. Оно само ловит медленные запросы и сразу пишет в лог их полный план с реальными цифрами:

shared_preload_libraries = 'pg_stat_statements,auto_explain'
auto_explain.log_min_duration = 1000
auto_explain.log_analyze = on
auto_explain.log_buffers = on

После включения план каждого медленного запроса появляется в логе сразу в момент его выполнения — искать проблему постфактум больше не нужно.

Коротко о главном

Медленный запрос в PostgreSQL почти всегда решается по одной и той же схеме: pg_stat_statements находит виновника, EXPLAIN ANALYZE с флагом BUFFERS показывает причину, а индекс или свежая статистика устраняют её без переписывания архитектуры. История с трек-кодом — не редкость: один недостающий индекс способен превратить девять секунд ожидания в доли миллисекунды.