MySQL 8.0.18 был только что выпущен, и он содержит совершенно новую функцию для анализа и понимания того, как выполняются запросы: EXPLAIN ANALYZE.
Что это такое?
EXPLAIN ANALYZE – это инструмент профилирования для ваших запросов, который покажет вам, где MySQL тратит время на ваш запрос и почему. Он будет планировать запрос, обрабатывать его и выполнять при подсчете строк и измерении времени, проведенного в различных точках плана выполнения. Когда выполнение завершится, EXPLAIN ANALYZE напечатает план и измерения вместо результата запроса.
Эта новая функция построена поверх обычного инструмента проверки плана запросов EXPLAIN и может рассматриваться как расширение EXPLAIN FORMAT = TREE, которое было добавлено ранее в MySQL 8.0. В дополнение к плану запроса и сметным затратам, которые печатает обычный EXPLAIN, EXPLAIN ANALYZE также печатает фактические затраты отдельных итераторов в плане выполнения.
Как мне это использовать?
В качестве примера мы будем использовать данные из базы данных и запрос, в котором указана общая сумма, которую каждый сотрудник набрал в Ноябре 2019 года. Запрос прост:
SELECT first_name, last_name, SUM(amount) AS total FROM staff INNER JOIN payment ON staff.staff_id = payment.staff_id AND payment_date LIKE '2019-11%' GROUP BY first_name, last_name; +------------+-----------+----------+ | first_name | last_name | total | +------------+-----------+----------+ | AndreyEx | Master | 78452.12 | | Destroyer | Graduate | 54678.14 | +------------+-----------+----------+ 2 rows in set (0,02 sec)
Есть только два человека, AndreyEx и Destroyer, и мы получаем общую сумму в Ноябре 2019 года для каждого из них.
EXPLAIN FORMAT = TREE покажет нам план запроса и оценки стоимости:
EXPLAIN FORMAT=TREE SELECT first_name, last_name, SUM(amount) AS total FROM staff INNER JOIN payment ON staff.staff_id = payment.staff_id AND payment_date LIKE '2019-11%' GROUP BY first_name, last_name; -> Table scan on <temporary> -> Aggregate using temporary table -> Nested loop inner join (cost=1211.21 rows=1121) -> Table scan on staff (cost=2.11 rows=2) -> Filter: (payment.payment_date like '2019-11%') (cost=100.23 rows=768) -> Index lookup on payment using idx_fk_staff_id (staff_id=staff.staff_id) (cost=100.23 rows=7668)
Но это не говорит нам, правильны ли эти оценки, или на какие операции в плане запроса действительно затрачивается время. EXPLAIN ANALYZE сделает это:
EXPLAIN ANALYZE SELECT first_name, last_name, SUM(amount) AS total FROM staff INNER JOIN payment ON staff.staff_id = payment.staff_id AND payment_date LIKE '2005-08%' GROUP BY first_name, last_name; -> Table scan on <temporary> (actual time=0.001..0.001 rows=2 loops=1) -> Aggregate using temporary table (actual time=44.231..45.445 rows=2 loops=1) -> Nested loop inner join (cost=1211.21 rows=1121) (actual time=0.564..34.111 rows=5687 loops=1) -> Table scan on staff (cost=3.20 rows=2) (actual time=0.047..0.051 rows=2 loops=1) -> Filter: (payment.payment_date like '2019-11%') (cost=100.23 rows=768) (actual time=0.337..18.436 rows=2844 loops=2) -> Index lookup on payment using idx_fk_staff_id (staff_id=staff.staff_id) (cost=100.23 rows=7668) (actual time=0.342..14.342 rows=7610 loops=2)
Здесь есть несколько новых измерений:
- Фактическое время получения первой строки (в миллисекундах)
- Фактическое время получения всех строк (в миллисекундах)
- Фактическое количество прочитанных строк
- Фактическое количество петель
Давайте рассмотрим конкретный пример, оценки затрат и фактические измерения итератора фильтрации, который выбирает продажи в ноябре 2019 года (строка 13 в выходных данных EXPLAIN ANALYZE выше).
Filter: (payment.payment_date like '2019-11%') (cost=100.23 rows=768) (actual time=0.337..18.436 rows=2844 loops=2)
Наш фильтр оценивается в 100,23, и, по оценкам, возвращает 768 строк. Эти оценки производятся оптимизатором запросов до его выполнения на основе доступной статистики. Эта информация также присутствует в выходных данных EXPLAIN FORMAT = TREE.
Мы начнем в конце с количества циклов. Число циклов для этого итератора фильтрации равно 2. Что это значит? Чтобы понять это число, мы должны посмотреть, что находится над итератором фильтрации в плане запроса. В строке 11 есть соединение с вложенным циклом, а в строке 12 – сканирование таблицы на рабочем столе. Это означает, что мы выполняем соединение с вложенным циклом, где сканируем таблицу персонала, и для каждой строки в этой таблице мы ищем соответствующие записи в таблице платежей, используя поиск по индексу и фильтрацию по дате оплаты. Поскольку в таблице персонала есть две строки (AndreyEx и Destroyer), мы получаем две итерации цикла при фильтрации и поиске индекса в строке 14.
Для многих людей самой интересной новой информацией, предоставляемой EXPLAIN ANALYZE, является фактическое время «0,337..18.436», что означает, что в среднем на чтение первой строки приходилось 0,337 мс, а на чтение всех строк – 18,436 мс. В среднем? Да, из-за зацикливания нам приходится дважды рассчитывать время этого итератора, и сообщаемые числа являются средними значениями всех итераций цикла. Это означает, что фактическое время выполнения фильтрации в два раза больше этих чисел. Таким образом, если мы посмотрим на время получения всех строк на один уровень выше, в итераторе вложенного цикла (строка 11), это составит 34,111 мс, чуть более чем в два раза больше времени для одного запуска итератора фильтрации.
Время отражает время целого поддерева, укорененного в операторе фильтрации, т. е. Время чтения строк с использованием итератора поиска по индексу, а затем оценки условия, что дата платежа была в августе 2005 года. Если мы посмотрим на итератор цикла индекса (строка 14), мы видим, что соответствующие числа равны 0,450 и 19,988 мс соответственно. Это означает, что большая часть времени была потрачена на чтение строк с использованием поиска по индексу, и что фактическая фильтрация была относительно дешевой по сравнению с чтением данных.
Фактическое число прочитанных строк составило 2844, а оценка – 768 строк. Таким образом, оптимизатор пропустил в 3 раза. Опять же, из-за зацикливания как расчетные, так и фактические числа являются средними по всем итерациям цикла. Если мы посмотрим на схему, то в столбце payment_date нет индекса или гистограммы, поэтому статистика, предоставляемая оптимизатору для вычисления селективности фильтра, ограничена. В качестве примера, где лучшая статистика приводит к более точным оценкам, мы можем снова взглянуть на итератор поиска индекса. Мы видим, что индекс предоставил намного более точную статистику: оценка 7668 строк против 7610 фактических прочитанных строк. Это очень хорошо. Это происходит потому, что индексы поставляются с дополнительной статистикой, которой просто нет в неиндексированных столбцах.
Так что вы можете сделать с этой информацией? Анализ запросов и понимание того, почему они плохо работают, требует некоторой практики. Но некоторые простые советы, которые помогут вам начать:
- Если вам интересно, что это занимает так много времени, посмотрите на сроки. Где исполнитель проводит свое время?
- Если вам интересно, почему оптимизатор выбрал этот план, посмотрите на счетчики строк. Большая разница (т. е. несколько порядков или более) между предполагаемым количеством строк и фактическим числом строк является признаком того, что вам стоит присмотреться к нему. Оптимизатор выбирает свой план на основе оценки, но, глядя на фактическое выполнение, вы можете сказать, что другой план был бы лучше.
Вот оно! Еще один инструмент в наборе инструментов анализа запросов MySQL:
- Чтобы изучить план запроса: EXPLAIN FORMAT = TREE
- Чтобы профилировать выполнение запроса: EXPLAIN ANALYZE
- Чтобы понять выбор плана: трассировка оптимизатора
Надеюсь, вам понравился этот краткий обзор новой функции, и этот EXPLAIN ANALYZE поможет вам профилировать и понимать ваши медленные запросы.