Когда запрос в postgresql тормозит, угадывать причину бесполезно. Нужно увидеть, что планировщик собирается делать и что он сделал на самом деле. Для этого есть две команды: EXPLAIN показывает выбранный план без запуска запроса, а EXPLAIN ANALYZE реально его выполняет и докладывает фактическое время и количество строк. В этом уроке разберём, как читать дерево плана, чем оценка отличается от факта, зачем включать BUFFERS, как ловить узкие места вроде seq scan по огромной таблице или промахов в оценках, и как собирать планы автоматически через auto_explain. Цель - научиться диагностировать медленные запросы осознанно, а не методом тыка.
Как это работает
Любой SQL-запрос проходит через планировщик. Он перебирает способы достать и соединить данные, прикидывает стоимость каждого варианта в условных единицах (cost) и выбирает самый дешёвый. Результат этого выбора и есть план - дерево узлов, где каждый узел что-то делает со строками: читает таблицу, лезет в индекс, соединяет два потока, сортирует, агрегирует.
Читается дерево снизу вверх и изнутри наружу. Листья - это доступ к таблицам (Seq Scan, Index Scan). Узлы выше - соединения и обработка. Верхний узел отдаёт итоговый результат. В EXPLAIN каждый узел показывает cost=0.00..NNN, где первое число - стоимость до выдачи первой строки, второе - до последней. Ещё там rows (ожидаемое число строк) и width (средний размер строки в байтах).
Важно понять разницу. EXPLAIN без ANALYZE - это только прогноз: запрос не выполняется, цифры берутся из статистики. EXPLAIN ANALYZE действительно гоняет запрос и добавляет actual time и actual rows. Сравнивая оценку (rows) с фактом (actual rows), вы видите, где планировщик ошибся в предположениях - а именно из плохих оценок чаще всего и растут медленные планы.
Опция BUFFERS показывает работу с буферным кешем: shared hit - страницы нашлись в памяти, shared read - пришлось читать с диска. Это нагляднее времени, потому что время скачет от нагрузки, а число прочитанных страниц стабильно. В PostgreSQL 16 BUFFERS включается автоматически при ANALYZE, а в 17 буферную статистику стал показывать и обычный EXPLAIN для фазы планирования.
SQL и примеры
Возьмём демобазу Авиаперевозки (схема bookings). Сначала чистый прогноз - план без выполнения:
Код: Выделить всё
EXPLAIN
SELECT * FROM bookings WHERE total_amount > 100000;Теперь реальное выполнение с буферами и удобным форматом. Это основной рабочий вызов для диагностики:
Код: Выделить всё
EXPLAIN (ANALYZE, BUFFERS, FORMAT TEXT)
SELECT t.passenger_name, tf.amount
FROM tickets t
JOIN ticket_flights tf ON tf.ticket_no = t.ticket_no
WHERE tf.amount > 150000;Как читать ключевую строку узла:
Код: Выделить всё
Seq Scan on ticket_flights tf
(cost=0.00..153707.00 rows=295 width=12)
(actual time=0.40..842.11 rows=2700 loops=1)
Filter: (amount > '150000'::numeric)
Rows Removed by Filter: 8388385
Buffers: shared hit=2 read=68585Поле loops тоже критично: если узел внутри Nested Loop, его actual time умножается на loops. Узел с time=0.05 и loops=300000 - это не быстро, это 15 секунд суммарно.
Сравните Index Scan против Seq Scan на большой выборке:
Код: Выделить всё
EXPLAIN (ANALYZE, BUFFERS)
SELECT * FROM ticket_flights WHERE flight_id = 12345;Чтобы увидеть, как меняется план при отключении индексов, можно временно сбить выбор планировщика:
Код: Выделить всё
SET enable_seqscan = off;
EXPLAIN ANALYZE SELECT * FROM flights WHERE flight_no = 'PG0001';
RESET enable_seqscan;Для запросов, которые в EXPLAIN ANALYZE ловить тяжело (короткие, но частые, или внутри функций), подключают auto_explain. Он логирует планы автоматически:
Код: Выделить всё
LOAD 'auto_explain';
SET auto_explain.log_min_duration = '200ms';
SET auto_explain.log_analyze = on;
SET auto_explain.log_buffers = on;Частые грабли
- Путают EXPLAIN и EXPLAIN ANALYZE. Первый ничего не выполняет и показывает только прогноз. Второй реально запускает запрос - и если это INSERT, UPDATE, DELETE или MERGE, данные изменятся. Оборачивайте в BEGIN; ... ROLLBACK;, когда тестируете пишущий запрос.
- Смотрят только на cost и время, игнорируя rows. Главный сигнал проблемы - расхождение оценки и факта. Большой разрыв означает устаревшую или недостаточную статистику.
- Забывают про loops. actual time у узла указано на один проход, а не суммарно. Реальная стоимость - time умножить на loops.
- Видят Seq Scan и сразу паникуют. На маленькой таблице или при выборке большой доли строк последовательное чтение дешевле индекса. Seq Scan - проблема только на большой таблице с маленькой выборкой.
- Не выполнили ANALYZE после массовой загрузки. Без свежей статистики планировщик берёт цифры с потолка, и план получается ужасным, хотя индексы на месте.
- Меряют первый прогон. Первый запуск читает с диска (shared read), повторные - из кеша (shared hit). Без BUFFERS легко принять холодный кеш за плохой план.
- Сравнивают планы на пустой или тестовой базе, где данных мало. Планировщик на тысяче строк и на миллионе ведёт себя по-разному.
- Подключитесь к демобазе: psql -d demo. Убедитесь, что схема видна: SET search_path = bookings, public;
- Выполните EXPLAIN (без ANALYZE) для SELECT по ticket_flights с условием amount > 150000. Запишите оценку rows.
- Повторите то же с EXPLAIN (ANALYZE, BUFFERS). Сравните rows и actual rows - насколько промахнулся планировщик. Посмотрите Rows Removed by Filter и Buffers.
- Выполните EXPLAIN ANALYZE для точечного запроса по PK: SELECT * FROM tickets WHERE ticket_no = '0005432000284'; - сравните число прочитанных страниц с пунктом 3.
- Запустите тот же запрос из пункта 3 повторно и сравните shared read и shared hit между прогонами - увидите эффект кеша.
- Сделайте SET enable_seqscan = off; перед запросом из пункта 3, посмотрите, какой план выберется и быстрее ли он. Затем RESET enable_seqscan;
- Включите auto_explain в сессии (log_min_duration = '0', log_analyze = on), выполните любой JOIN из урока и найдите его план в логе сервера.
- Чем отличается вывод EXPLAIN от EXPLAIN ANALYZE и в каком случае второй опасен для данных?
- Что означает большое значение Rows Removed by Filter и о какой оптимизации оно намекает?
- Почему при анализе вложенного узла нужно учитывать поле loops, а не только actual time?
- Что показывают shared hit и shared read в строке Buffers и почему они стабильнее времени выполнения?
- В каких ситуациях Seq Scan по таблице - это нормально, а не дефект плана?
- Зачем нужен auto_explain, если уже есть EXPLAIN ANALYZE, и какие запросы им удобнее ловить?
