Чтение EXPLAIN-планов и диагностика медленных запросов

Все предыдущие уроки модуля давали теорию: MVCC, проходы оптимизатора, DPccp, pushdown. Этот урок — практический. Когда конкретный запрос работает медленно, нужно не догадываться, а посмотреть, что движок делает на самом деле. Инструмент для этого — EXPLAIN и EXPLAIN ANALYZE. Умение читать их вывод отделяет «запрос тормозит, не знаю почему» от «вот этот join — узкое место, вот причина».

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

EXPLAIN против EXPLAIN ANALYZE

Два разных инструмента для двух разных задач.

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

Как читать дерево плана

План — это дерево операторов. Читается снизу вверх: листья дерева — источники данных (сканы таблиц), корень — финальный результат. Данные текут от листьев к корню, проходя через операторы.

EXPLAIN
SELECT c.country, sum(o.amount) AS total
FROM orders o
JOIN customers c ON o.customer_id = c.id
WHERE o.amount > 0
GROUP BY c.country;

┌───────────────────────────┐
│       HASH_GROUP_BY       │   <- 4. группировка по country
│      country, sum(amount) │
└─────────────┬─────────────┘
┌─────────────┴─────────────┐
│         HASH_JOIN         │   <- 3. соединение по ключу
│      customer_id = id     │
└──────┬─────────────┬──────┘
┌──────┴──────┐ ┌────┴──────┐
│   SEQ_SCAN  │ │  SEQ_SCAN │   <- 1, 2. чтение таблиц (листья)
│   orders    │ │ customers │
│ amount > 0  │ │           │
└─────────────┘ └───────────┘

Порядок исполнения: сначала сканируются таблицы (листья) -> результаты подаются в HASH_JOIN -> результат join подаётся в HASH_GROUP_BY -> финальный результат. Каждый прямоугольник — оператор; читая снизу вверх, вы видите, во что превращаются данные на каждом шаге.

Основные физические операторы, которые встречаются чаще всего:

EXPLAIN ANALYZE: что показывают счётчики

EXPLAIN ANALYZE добавляет к каждому оператору фактические данные. Главные числа, на которые смотреть:

• Фактическое число строк на выходе оператора.
• Время, проведённое в операторе.

EXPLAIN ANALYZE
SELECT c.country, sum(o.amount)
FROM orders o JOIN customers c ON o.customer_id = c.id
GROUP BY c.country;

┌─────────────────────────────────────┐
│           Total Time: 0.84s         │
└─────────────────────────────────────┘
┌───────────────────────────┐
│       HASH_GROUP_BY       │
│         result: 195       │   <- 195 стран на выходе
│           0.02s           │
└─────────────┬─────────────┘
┌─────────────┴─────────────┐
│         HASH_JOIN         │
│       result: 9874210     │   <- столько строк после join
│           0.71s           │   <- здесь почти всё время
└──────┬─────────────┬──────┘
┌──────┴──────┐ ┌────┴──────┐
│   SEQ_SCAN  │ │  SEQ_SCAN │
│  result:    │ │ result:   │
│  10000000   │ │  100000   │
│  0.06s      │ │  0.01s    │
└─────────────┘ └───────────┘

Что читается из этого вывода:

• Total Time — общее время. Дальше ищем, какой оператор его съел.
• HASH_JOIN потратил 0.71s из 0.84s — это узкое место. Он обрабатывает ~9.9 млн строк.
• Сканы быстрые: orders прочитан за 0.06s, customers за 0.01s.
• HASH_GROUP_BY дёшев — он схлопывает 9.9 млн строк в 195 групп за 0.02s.

Вывод диагностики: время уходит в join, потому что он соединяет миллионы строк. Если запрос нужно ускорить — смотреть надо на фильтры (можно ли уменьшить вход join) и на порядок join.

Расхождение оценок и факта

Самый ценный диагностический сигнал — сравнение оценочной кардинальности (EC в EXPLAIN) с фактической (result в EXPLAIN ANALYZE). Оптимизатор строил план, опираясь на EC; если EC сильно расходится с фактом, план мог получиться неудачным.

Пример проблемы: EXPLAIN показывает у join EC: 5000, EXPLAIN ANALYZE — result: 4200000. Расхождение в 800 раз. Оптимизатор спланировал так, будто из join выйдет 5 тысяч строк, а вышло 4 миллиона — и под эти 5 тысяч он, например, поставил join в неудачную позицию. Причина расхождения — почти всегда плохая статистика: запрос к внешнему CSV без хороших метаданных, или коррелированные фильтры, селективность которых оценщик предполагает независимой.

Типичные паттерны проблем

Несколько узнаваемых сигнатур в плане и что они означают.

Огромный промежуточный результат у раннего join. Если первый по порядку join выдаёт сотни миллионов строк, а финальный результат — тысячи, значит порядок join неудачен: большой объём тащится через весь план. Смотрите, нельзя ли применить фильтр раньше или почему оптимизатор выбрал такой порядок (вероятно, расхождение EC).

FILTER отдельным оператором над сканом. Если фильтр стоит как отдельный FILTER, а не опущен в SEQ_SCAN, значит pushdown его не взял. Иногда это нормально (фильтр по результату выражения), иногда — повод переписать условие так, чтобы оно опускалось.

rows scanned равно размеру всей таблицы при селективном фильтре. Если фильтр селективный (отбирает малую долю), но rows scanned равно полному размеру таблицы, значит zonemap не помог — данные физически разбросаны. Помогает сортировка/партиционирование таблицы по колонке фильтра.

Спилл на диск в операторе. Если HASH_JOIN, HASH_GROUP_BY или ORDER_BY показывает признаки спилла (out-of-core исполнение), запросу не хватило памяти, и он сбрасывал данные на диск. Это медленнее работы в RAM. Out-of-core исполнение разбирается в следующем модуле; в плане это сигнал «памяти было мало».

Профилирование без EXPLAIN ANALYZE

Иногда нужен профиль запроса, который вы не хотите оборачивать в EXPLAIN ANALYZE вручную, или нужен машиночитаемый формат. DuckDB умеет профилировать сессию:

PRAGMA enable_profiling = 'query_tree';
-- теперь после каждого запроса печатается дерево с таймингами
SELECT ... ;

-- или в JSON-файл для программного разбора:
PRAGMA enable_profiling = 'json';
PRAGMA profiling_output = 'profile.json';
SELECT ... ;

PRAGMA disable_profiling;  -- выключить

query_tree печатает то же дерево, что EXPLAIN ANALYZE, после каждого запроса автоматически. Формат json пишет структурированный профиль в файл — удобно, когда нужно собрать тайминги многих запросов и анализировать их программно.

Попробуй сам

1. Создай customers(id, country) на 100 тыс строк и orders(id, customer_id, amount) на 5 млн строк со ссылками на существующих клиентов.
2. Выполни EXPLAIN ANALYZE для запроса с join и GROUP BY country. Найди оператор с максимальным временем — это узкое место. Запиши его время и долю от Total Time.
3. Для того же запроса сравни EC из обычного EXPLAIN с фактическим result из EXPLAIN ANALYZE на каждом операторе. Есть ли где-то расхождение больше чем в 10 раз?
4. Добавь к запросу селективный фильтр WHERE amount > <большое число>, оставляющий малую долю строк. Сравни EXPLAIN ANALYZE до и после: уменьшился ли вход join, сократилось ли общее время, изменился ли узкий оператор?
5. Включи PRAGMA enable_profiling = 'query_tree';, выполни пару запросов и посмотри автоматически печатаемые деревья. Затем выключи профилирование.