Существует два подхода к профилированию запросов, соответствующие двум вопросам, упомянутым в этой статье. Можно профилировать весь сервер, основываясь на том, какие запросы в наибольшей степени его загружают. (Если вы начали с верхнего уровня, с профилирования на уровне приложений, то, возможно, уже знаете, какие запросы требуют внимания.) Затем, как только настроите конкретные запросы для оптимизации, можете углубиться в их профилирование по отдельности, определяя, какие подзадачи значительнее увеличивают их время отклика.
Профилирование рабочей нагрузки сервера MySQL
Подход к профилированию на уровне сервера очень полезен, потому что он может помочь вам проверить сервер на предмет неэффективных запросов. Обнаружение и исправление этих запросов позволит улучшить производительность приложения в целом, а также выявить конкретные проблемы. Вы можете снизить общую нагрузку на сервер, тем самым уменьшится конкуренция за совместно используемые ресурсы и увеличится скорость выполнения всех запросов (побочный эффект). Снижение нагрузки на сервер способно помочь вам отложить обновления и другие затратные мероприятия или избежать их, кроме того, вы можете обнаружить и устранить проблемы, связанные с результатами, неприемлемыми для пользователя, такими как выбросы (аномальные результаты измерений).
С каждой следующей версией в MySQL появляется все больше инструментов, и если такая тенденция сохранится, скоро в MySQL будут великолепные инструменты для измерения наиболее важных аспектов ее производительности. Но что касается профилирования запросов и поиска самых затратных из них, нам не нужна вся эта сложность. Необходимый инструмент существует уже довольно давно. Это так называемый журнал медленных запросов.
Фиксация запросов MySQL в журнал
В MySQL журнал медленных запросов изначально предназначался для фиксации только медленных запросов, но для целей профилирования необходима регистрация всех запросов. При этом нам требуется более тонкая детализация времени отклика, чем в MySQL 5.0 и ранних версиях. В этих версиях минимальный временной интервал равнялся 1 секунде. К счастью, прежние ограничения уже неактуальны.
В MySQL 5.1 и более поздних версиях журнал медленных запросов расширен так, что переменную сервера long_query_time можно установить равной нулю, зафиксировав все запросы, а время отклика на запрос детализировано с дискретностью 1 микросекунда. Если вы используете Percona Server, этот функционал доступен уже в версии 5.0, кроме того, Percona Server дает намного больший контроль над содержимым журнала и фиксацией запросов.
В существующих версиях MySQL у журнала медленных запросов наименьшие издержки и наибольшая точность измерения времени выполнения запроса. Если вас беспокоит дополнительный ввод/вывод, вызываемый этим журналом, то не тревожьтесь. Мы провели эталонное тестирование и выяснили, что при нагрузках, связанных с вводом/выводом, издержки незначительны. (На самом деле это лучше видно в ходе работ, нагружающих процессор.) Более актуальной проблемой является заполнение диска. Убедитесь, что вы установили смену журнала для журнала медленных запросов, если он включен постоянно. Либо оставьте его выключенным и включайте только на определенное время для получения образца рабочей нагрузки.
У MySQL есть и другой тип журнала запросов — общий журнал, но он не так полезен для анализа и профилирования сервера. Запросы регистрируются по мере их поступления на сервер, поэтому журнал не содержит информации о времени отклика или о плане выполнения запроса. MySQL 5.1 и более поздние версии поддерживают также ведение журнала запросов к таблицам, однако это не самая удачная идея. Данный журнал сильно влияет на производительность: хотя MySQL 5.1 в журнале медленных запросов отмечает время запросов с точностью до 1 микросекунды, медленные запросы к таблице регистрируются с точностью до 1 секунды. Это не очень полезно.
Percona Server регистрирует в журнале медленных запросов значительно более подробную информацию, чем MySQL. Здесь отмечается полезная информация о плане выполнения запроса, блокировке, операциях ввода/вывода и многом другом. Эти дополнительные биты данных добавлялись медленно, поскольку мы столкнулись с различными сценариями оптимизации, которые требовали более подробных сведений о том, как запросы выполняются и где происходят затраты времени. Мы также упростили администрирование. Например, добавили возможность глобально контролировать порог long_query_time для каждого соединения, поэтому вы можете заставить их запускать или останавливать журналирование своих запросов, когда приложение использует пул соединений или постоянные соединения, но не можете сбросить переменные уровня сеанса.
В целом это легкий и полнофункциональный способ профилирования сервера и оптимизации его запросов.
Допустим, вы не хотите регистрировать запросы на сервере или по какой-то причине не можете делать этого, например не имеете доступа к серверу. Мы сталкивались с такими ограничениями, поэтому разработали две альтернативные методики и добавили их в инструмент pt-query-digest пакета Percona Toolkit. Первая методика подразумевает постоянное отслеживание состояния с помощью команды SHOW FULL PROCESSLIST с параметром -processlist. При этом отмечается, когда запросы появляются и исчезают. В некоторых случаях этот метод довольно точен, но он не может зафиксировать все запросы. Очень короткие запросы могут проскочить и завершиться, прежде чем инструмент их заметит.
Второй метод состоит в фиксировании сетевого трафика TCP и его проверки, а затем декодирования протокола «клиент/сервер MySQL» (MySQL client/server protocol). Вы можете использовать утилиту tcpdump для записи трафика на диск, а затем — pt-query-digest с параметром --type=tpcdump для декодирования и анализа запросов. Это гораздо более точная методика, которая зафиксирует все запросы. Методика работает даже с расширенными протоколами, такими как бинарный протокол, используемый для создания и выполнения подготовленных операторов на стороне сервера, и сжатый протокол. Можно также использовать MySQL Proxy со скриптом журналирования, но в практике это нам редко встречалось.
Анализ журнала запросов
Мы рекомендуем по крайней мере время от времени фиксировать в журнале медленных запросов все запросы, выполняемые на сервере, и анализировать их. Запишите запросы, сделанные в течение репрезентативного периода времени, например за час пикового трафика. Если рабочая нагрузка однородна, достаточно будет минуты или даже меньше для нахождения плохих запросов, которые следует оптимизировать.
Не стоит просто открывать журнал и смотреть в него — это пустая трата времени и денег. Сначала создайте профиль и, если это необходимо, просмотрите конкретные выборки в журнале. Лучше всего начинать с верхнего уровня и двигаться вниз, в противном случае, как упоминалось ранее, вы можете деоптимизировать процесс.
Для создания профиля из журнала медленных запросов требуется хороший инструмент анализа журналов. Мы предлагаем утилиту pt-query-digest, которая, возможно, является самым мощным инструментом анализа журнала запросов MySQL. Она поддерживает множество различных функций, включая возможность сохранять отчеты о запросах в базе данных и отслеживать изменения в рабочей нагрузке.
По умолчанию вы просто выполняете утилиту, передаете ей файл журнала медленных запросов в качестве аргумента, и она сама выполняет нужные действия. Утилита выводит профиль запросов в журнале, а затем выбирает важные классы запросов и выдает подробный отчет по каждому из них. В отчете есть десятки мелочей, облегчающих вашу жизнь. Мы продолжаем активно развивать этот инструмент, поэтому лучше прочитать документацию для последней версии, чтобы узнать о ее функциональности.
Приведем краткий обзор отчета pt-query-digest, начиная с профиля. Ниже представлена полная версия профиля, который мы показали ранее в этой статье:
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ================== ================ ===== ====== ===== =======
# 1 0xBFCF8E3F293F6466 11256.3618 68.1% 78069 0.1442 0.21 SELECT InvitesNew?
# 2 0x620B8CAB2B1C76EC 2029.4730 12.3% 14415 0.1408 0.21 SELECT StatusUpdate?
# 3 0xB90978440CC11CC7 1345.3445 8.1% 3520 0.3822 0.00 SHOW STATUS
# 4 0xCB73D6B5B031B4CF 1341.6432 8.1% 3509 0.3823 0.00 SHOW STATUS
# MISC 0xMISC 560.7556 3.4% 23930 0.0234 0.0 <17 ITEMS>Здесь показано чуть больше деталей, чем раньше. Во-первых, каждый запрос имеет идентификатор, который является хеш-подписью его цифрового отпечатка. Цифровой отпечаток — это нормализованная каноническая версия запроса с удаленными литералами и пробелами, переведенная в нижний регистр (обратите внимание, что запросы 3 и 4 кажутся одинаковыми, но у них разные отпечатки). Инструмент также объединяет таблицы с похожими именами в каноническую форму. Вопросительный знак в конце имени таблицы invitesNew означает, что к имени таблицы был добавлен идентификатор сегмента данных (шарда), а инструмент удалил его, так что запросы к таблицам, сделанные с похожими целями, объединены вместе. Этот отчет взят из сильно шардированного приложения Facebook.
Еще один появившийся здесь столбец — отношение рассеяния к среднему значению V/M. Этот показатель называется индексом рассеяния. У запросов с более высоким индексом рассеяния сильнее колеблется время выполнения, и они, как правило, являются хорошими кандидатами на оптимизацию. Если вы укажете параметр --explain в утилите pt-query-digest, то к таблице будет добавлен столбец с кратким описанием плана запроса EXPLAIN — своего рода неформальный код запроса. Это в сочетании со столбцом V/M позволяет быстро определить, какие запросы являются плохими и потенциально легко оптимизируемыми.
Наконец, в нижней части есть дополнительная строка, показывающая наличие 17 других типов запросов, которые инструмент не счел достаточно важными для отдельной строки, и сводная статистика по ним. При задании параметров --limit и --outliers инструмент не будет сворачивать несущественные запросы в одну финальную строку. По умолчанию он выводит запросы, которые входят в первую десятку по затраченному времени либо время выполнения которых превысило односекундный порог во много раз. Оба этих параметра можно настроить.
После профиля инструмент вывел подробный отчет по каждому типу запроса. Вы можете сравнить отчеты по запросам с профилем, сопоставляя по идентификатору запроса или рангу. Приведем отчет для худшего запроса:
# Query 1: 24.28 QPS, 3.50x concurrency, ID 0xBFCF8E3F293F6466 at byte 5590079
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.21
# Query_time sparkline: | _^_.^_ |
# Time range: 2008-09-13 21:51:55 to 22:45:30
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 63 78069
# Exec time 68 11256s 37us 1s 144ms 501ms 175ms 68ms
# Lock time 85 134s 0 650ms 2ms 176us 20ms 57us
# Rows sent 8 70.18k 0 1 0.92 0.99 0.27 0.99
# Rows examine 8 70.84k 0 3 0.93 0.99 0.28 0.99
# Query size 84 10.43M 135 141 140.13 136.99 0.10 136.99
# String:
# Databases production
# Hosts
# Users fbappuser
# Query_time distribution
# 1us
# 10us #
# 100us ####################################################
# 1ms ###
# 10ms ################
# 100ms ################################################################
# 1s #
# 10s+
# Tables
# SHOW TABLE STATUS FROM `production ` LIKE'InvitesNew82'\G
# SHOW CREATE TABLE `production `.`InvitesNew82'\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT InviteId, InviterIdentifier FROM InvitesNew82 WHERE (InviteSetId = 87041469)
AND (InviteeIdentifier = 1138714082) LIMIT 1\GВверху отчета содержится множество метаданных, в том числе: как часто выполняется запрос, его средняя конкурентность и смещение (в байтах) до того места, где в файле журнала находится запрос с наихудшей производительностью. Существует табличная распечатка числовых метаданных, включая статистику, такую как, например.стандартное отклонение.
Затем представлена гистограмма времени отклика. Любопытно, что, как вы видите под строкой Query_time distribution, у гистограммы этого запроса два пика. Обычно запрос выполняется за сотни миллисекунд, но есть также значительный всплеск числа запросов, которые были выполнены на три порядка быстрее. Если бы этот журнал был создан в пакете Percona Server, в журнале запросов был бы более богатый набор параметров. Как следствие, мы могли бы проанализировать запросы вдоль и поперек, чтобы понять, почему это происходит. Возможно, это были запросы к определенным значениям, которые непропорционально распределены, поэтому использовался другой индекс, или, возможно, это хиты запросов кэша. В реальных системах гистограмма с двумя пиками не редкость, особенно в случае простых запросов, которые часто имеют лишь несколько альтернативных путей выполнения.
Наконец, раздел деталей отчета заканчивается небольшими вспомогательными фрагментами для облегчения копирования и вставки команд в командную строку, а также проверки схемы и статуса упомянутых таблиц и включает образец запроса EXPLAIN. Образец содержит все литералы, а не «отпечатки пальцев», поэтому это реальный запрос. На самом деле это экземпляр запроса, у которого было худшее время выполнения в нашем примере.
После выбора запросов, которые вы хотите оптимизировать, можете использовать этот отчет, чтобы быстро проверить выполнение запроса. Мы постоянно пользуемся этим инструментом, и потратили много времени на то, чтобы сделать его максимально эффективным и полезным. Настоятельно рекомендуем подружиться с ним. Возможно, в скором времени MySQL будет лучше оснащена встроенными инструментами профилирования, но на момент написания этой статьи нет инструментов лучше, чем журналирование запросов с помощью журнала медленных запросов или использование tcpdump и запуск полученного журнала с помощью утилиты pt-query-digest.
Профилирование отдельных запросов
После того как вы определили запрос для оптимизации, можете углубиться в него и определить, почему он требует столько времени и как его оптимизировать. Современные методики оптимизации запросов будут описаны в последующих моих блогах вместе с необходимыми для их использования предварительными сведениями. Сейчас наша цель — просто показать, как измерить то, что делает запрос, и сколько времени требует каждый этап. Эти знания помогут вам определить, какие методики оптимизации использовать.
К сожалению, большинство инструментов в MySQL не очень полезны для профилирования запросов. Ситуация меняется, но на момент написания этого блога большинство производственных серверов не поддерживают новейших функций профилирования. Поэтому при их использовании в практических целях мы сильно ограничены командами SHOW STATUS, SHOW PROFILE и изучением отдельных записей в журнале медленных запросов (если у вас есть Percona Server — в стандартной системе MySQL в журнале нет дополнительной информации). Мы продемонстрируем все три метода на примере одного и того же запроса и покажем, что вы можете узнать о его выполнении в каждом случае.
Команда SHOW PROFILE
Команда SHOW PROFILE появилась благодаря Джереми Коулу (Jeremy Cole). Она включена в MySQL 5.1 и более поздние версии. Это единственный реальный инструмент профилирования запросов, доступный в GA-релизе MySQL на момент написания блога. Профилирование по умолчанию отключено, но его можно включить во время сеанса, установив значение переменной сервера:
mysql> SET profiling = 1;После этого всякий раз, когда вы посылаете выражение на сервер, он будет замерять прошедшее время и еще некоторые данные, когда запрос будет переходить из одного состояния выполнения в другое. Эта команда имеет довольно широкий функционал и была спроектирована так, что может иметь еще больше, но в следующих релизах она, по всей видимости, будет заменена или вытеснена Performance Schema. Несмотря на это, наиболее полезной функцией данной команды является создание профиля работы, выполняемой сервером во время реализации выражения.
Каждый раз, когда вы отправляете запрос на сервер, он записывает информацию профилирования во временную таблицу и присваивает выражению целочисленный идентификатор, начиная с 1. Приведем пример профилирования представления, включенного в базу данных Sakila:
mysql> SELECT * FROM sakila.nicer_but_slower_film_list;
[query results omitted]
997 rows in set (0.17 sec)Запрос возвратил 997 строк примерно через 1/6 секунды. Посмотрим, что выдаст команда SHOW PROFILES (обратите внимание на множественное число):
mysql> SHOW PROFILES;
+----------+------------+-------------------------------------------------+
| Query_ID | Duration | Query |
+----------+------------+-------------------------------------------------+
| 1 | 0.16767900 | SELECT * FROM sakila.nicer_but_slower_film_list |
+----------+------------+-------------------------------------------------+Первое, что мы видим, — то, что время отклика запроса показано с большей точностью, чем принято. Двух десятичных знаков точности, как показано в клиенте
MySQL, часто недостаточно, когда вы работаете с быстрыми запросами. Теперь посмотрим на профиль для этого запроса:
mysql> SHOW PROFILE FOR QUERY 1;
+----------------------+----------+
| Status | Duration |
+----------------------+----------+
| starting | 0.000082 |
| Opening tables | 0.000459 |
| System lock | 0.000010 |
| Table lock | 0.000020 |
| checking permissions | 0.000005 |
| checking permissions | 0.000004 |
| checking permissions | 0.000003 |
| checking permissions | 0.000004 |
| checking permissions | 0.000560 |
| optimizing | 0.000054 |
| statistics | 0.000174 |
| preparing | 0.000059 |
| Creating tmp table | 0.000463 |
| executing | 0.000006 |
| Copying to tmp table | 0.090623 |
| Sorting result | 0.011555 |
| Sending data | 0.045931 |
| removing tmp table | 0.004782 |
| Sending data | 0.000011 |
| init | 0.000022 |
| optimizing | 0.000005 |
| statistics | 0.000013 |
| preparing | 0.000008 |
| executing | 0.000004 |
| Sending data | 0.010832 |
| end | 0.000008 |
| query end | 0.000003 |
| freeing items | 0.000017 |
| removing tmp table | 0.000010 |
| freeing items | 0.000042 |
| removing tmp table | 0.001098 |
| closing tables | 0.000013 |
| logging slow query | 0.000003 |
| logging slow query | 0.000789 |
| cleaning up | 0.000007 |
+----------------------+----------+Профиль позволяет следить за каждым шагом выполнения запроса и видеть, сколько прошло времени. Обратите внимание, что не очень легко просмотреть выведенный результат и найти, где затраты времени были максимальными: он сортируется в хронологическом порядке. Однако нас интересует не порядок, в котором выполнялись операции, — мы просто хотим знать, каковы были затраты времени на них. К сожалению, отсортировать вывод с помощью ORDER BY нельзя. Давайте перейдем к использованию команды SHOW PROFILE для запроса связанной таблицы INFORMATION_SCHEMA и формата, который выглядит как просмотренные нами ранее профили:
Так намного лучше! Теперь мы видим, что причина, по которой этот запрос так долго выполнялся, заключалась в копировании данных во временную таблицу, на что затрачено более половины общего времени. Возможно, придется переписать этот запрос так, чтобы он не использовал временную таблицу или хотя бы делал это более эффективно. Следующий крупный потребитель времени, отправка данных, фактически является своеобразной кладовкой, которая может включать в себя любое количество различных действий сервера, в том числе поиск совпадающих строк в соединении и т. д. Трудно сказать, сможем ли мы здесь что-то сэкономить. Обратите внимание на то, что результат сортировки занимает недостаточно много времени, чтобы его можно было оптимизировать. Это довольно типично, поэтому призываем вас не тратить время на «настройку буферов сортировки» и подобные мероприятия.
Как обычно, хотя профиль помогает нам определить, какие виды деятельности вносят наибольший вклад в затраченное на выполнение запроса время, он не говорит нам, почему это происходит. Чтобы узнать, почему потребовалось столько времени для копирования данных во временную таблицу, нам пришлось бы углубиться в этот процесс и создать профиль выполняемых подзадач.
Команда SHOW STATUS
Команда SHOW STATUS MySQL возвращает множество счетчиков. Существует глобальная область действия сервера для счетчиков, а также область сеанса, которая специфична для конкретного соединения. Например, счетчик Queries в начале вашего сеанса равен нулю и увеличивается каждый раз, когда вы делаете запрос. Выполнив команду SHOW GLOBAL STATUS (обратите внимание на добавление ключевого слова GLOBAL), вы увидите общее количество запросов, полученных с момента его запуска. Области видимости разных счетчиков различаются — счетчики, которые не имеют области видимости на уровне сеанса, отображаются в SHOW STATUS, маскируясь под счетчики сеансов, и это может ввести в заблуждение. Учитывайте это при использовании данной команды. Как говорилось ранее, подбор должным образом откалиброванных инструментов является ключевым фактором успеха. Если вы пытаетесь оптимизировать что-то, что можете наблюдать только в конкретном соединении с сервером, измерения, которые «засоряются» всей активностью сервера, вам не помогут. В руководстве по MySQL есть отличное описание всех переменных, имеющих как глобальную, так и сеансовую область видимости.
SHOW STATUS может быть полезным инструментом, но на самом деле его применение — это не профилирование. Большинство результатов команды SHOW STATUS — всего лишь счетчики. Они сообщают вам, как часто протекали те или иные виды деятельности, например чтение из индекса, но ничего не говорят о том, сколько времени на это было затрачено. В команде SHOW STATUS есть только один счетчик, который показывает время, израсходованное на операцию (Innodb_row_lock_time), но он имеет лишь глобальную область видимости, поэтому вы не можете использовать его для проверки работы, выполненной в ходе сеанса.
Хотя команда SHOW STATUS не предоставляет информацию о затратах времени, тем не менее иногда может быть полезно использовать ее после выполнения запроса для просмотра значений некоторых счетчиков. Вы можете сделать предположение о том, какие типы затратных операций выполнялись и как они могли повлиять на время запроса. Наиболее важными счетчиками являются счетчики обработчиков запросов и счетчики временных файлов и таблиц. А сейчас приведем пример сброса счетчиков состояния сеанса до нуля, выбора из использованного нами ранее представления и просмотра счетчиков:
mysql> SET @query_id = 1;
Query OK, 0 rows affected (0.00 sec)
mysql> SELECT STATE, SUM(DURATION) AS Total_R,
-> ROUND(
-> 100 * SUM(DURATION) /
-> (SELECT SUM(DURATION)
-> FROM INFORMATION_SCHEMA.PROFILING
-> WHERE QUERY_ID = @query_id
-> ), 2) AS Pct_R,
-> COUNT(*) AS Calls,
-> SUM(DURATION) / COUNT(*) AS "R/Call"
-> FROM INFORMATION_SCHEMA.PROFILING
-> WHERE QUERY_ID = @query_id
-> GROUP BY STATE
-> ORDER BY Total_R DESC;
+----------------------+----------+-------+-------+--------------+
| STATE | Total_R | Pct_R | Calls | R/Call |
+----------------------+----------+-------+-------+--------------+
| Copying to tmp table | 0.090623 | 54.05 | 1 | 0.0906230000 |
| Sending data | 0.056774 | 33.86 | 3 | 0.0189246667 |
| Sorting result | 0.011555 | 6.89 | 1 | 0.0115550000 |
| removing tmp table | 0.005890 | 3.51 | 3 | 0.0019633333 |
| logging slow query | 0.000792 | 0.47 | 2 | 0.0003960000 |
| checking permissions | 0.000576 | 0.34 | 5 | 0.0001152000 |
| Creating tmp table | 0.000463 | 0.28 | 1 | 0.0004630000 |
| Opening tables | 0.000459 | 0.27 | 1 | 0.0004590000 |
| statistics | 0.000187 | 0.11 | 2 | 0.0000935000 |
| starting | 0.000082 | 0.05 | 1 | 0.0000820000 |
| preparing | 0.000067 | 0.04 | 2 | 0.0000335000 |
| freeing items | 0.000059 | 0.04 | 2 | 0.0000295000 |
| optimizing | 0.000059 | 0.04 | 2 | 0.0000295000 |
| init | 0.000022 | 0.01 | 1 | 0.0000220000 |
| Table lock | 0.000020 | 0.01 | 1 | 0.0000200000 |
| closing tables | 0.000013 | 0.01 | 1 | 0.0000130000 |
| System lock | 0.000010 | 0.01 | 1 | 0.0000100000 |
| executing | 0.000010 | 0.01 | 2 | 0.0000050000 |
| end | 0.000008 | 0.00 | 1 | 0.0000080000 |
| cleaning up | 0.000007 | 0.00 | 1 | 0.0000070000 |
| query end | 0.000003 | 0.00 | 1 | 0.0000030000 |
+----------------------+----------+-------+-------+--------------+Похоже, что в запросе использовались три временные таблицы — две из них на диске — и было много неиндексированных чтений (Handler_read_rnd_next). Если бы мы ничего не знали о представлении, к которому только что обращались, то могли бы предположить, что запрос сделал объединение без индекса, возможно, из-за подзапроса, который создал временные таблицы, а затем использовал их с правой стороны в соединении. Временные таблицы, созданные для хранения результатов подзапросов, не имеют индексов, поэтому эта версия кажется правдоподобной.
Используя эту методику, имейте в виду, что команда SHOW STATUS создает временную таблицу и обращается к ней с помощью обработчика операций, поэтому на полученные результаты в действительности влияет и SHOW STATUS. Это зависит от версий сервера. Используя информацию о выполнении запроса, полученную от команды SHOW PROFILES, мы можем предположить, что количество временных таблиц завышено на 2.
Стоит отметить, что большую часть той же информации, по-видимому, можно получить, просмотрев план EXPLAIN для этого запроса. Но EXPLAIN — это оценка того, что сервер планирует делать, а просмотр счетчиков статуса — это измерение того, что он на самом деле сделал. EXPLAIN не скажет вам, например, была ли временная таблица создана на диске, что медленнее, чем в памяти.
Использование журнала медленных запросов
Что расширенный в Percona Server журнал медленных запросов расскажет об этом запросе? Вот что было зафиксировано при выполнении запроса, продемонстрированного в разделе о SHOW PROFILE:
mysql> FLUSH STATUS;
mysql> SELECT * FROM sakila.nicer_but_slower_film_list;
[query results omitted]
mysql> SHOW STATUS WHERE Variable_name LIKE 'Handler%'
OR Variable_name LIKE 'Created%';
+----------------------------+-------+
| Variable_name | Value |
+----------------------------+-------+
| Created_tmp_disk_tables | 2 |
| Created_tmp_files | 0 |
| Created_tmp_tables | 3 |
| Handler_commit | 1 |
| Handler_delete | 0 |
| Handler_discover | 0 |
| Handler_prepare | 0 |
| Handler_read_first | 1 |
| Handler_read_key | 7483 |
| Handler_read_next | 6462 |
| Handler_read_prev | 0 |
| Handler_read_rnd | 5462 |
| Handler_read_rnd_next | 6478 |
| Handler_rollback | 0 |
| Handler_savepoint | 0 |
| Handler_savepoint_rollback | 0 |
| Handler_update | 0 |
| Handler_write | 6459 |
+----------------------------+-------+Похоже, что запрос действительно создал три временные таблицы, которые были скрыты от представления в SHOW PROFILE (возможно, из-за особенностей способа выполнения запроса сервером). Две временные таблицы находились на диске. Здесь мы сократили выведенную информацию для улучшения удобочитаемости. В конце концов, данные, полученные при выполнении команды SHOW PROFILE по этому запросу, записываются в журнал, поэтому вы можете журналировать в Percona Server даже такой уровень детализации.
Согласитесь, эта весьма подробная запись в журнале медленных запросов содержит практически все, что вы можете видеть в SHOW PROFILE и SHOW STATUS, и еще кое-что. Это делает журнал очень полезным для поиска более подробной информации при нахождении плохого запроса с помощью утилиты pt-query-digest. Когда вы просмотрите отчет от pt-query-digest, увидите такую строку заголовка:
# Query 1: 0 QPS, 0x concurrency, ID 0xEE758C5E0D7EADEE at byte 3214 _____Вы можете использовать байтовое смещение для фокусировки на нужном разделе журнала следующим образом:
tail -c +3214 /path/to/query.log | head -n100Вуаля! Можно рассмотреть все подробности. Кстати, pt-query-digest понимает все добавленные пары «имя — значение» формата медленного журнала запросов Percona Server и автоматически выводит намного более подробный отчет.
Использование Performance Schema
На момент написания этой статьи таблицы Performance Schema, представленные в MySQL 5.5, не поддерживают профилирование на уровне запросов. Performance Schema появилась не так давно. Однако она быстро развивается, приобретая дополнительную функциональность в каждом следующем релизе. Но даже первоначальная функциональность MySQL 5.5 позволяет получать любопытную информацию. Например, следующий запрос покажет основные причины ожидания в системе:
mysql> SELECT event_name, count_star, sum_timer_wait
-> FROM events_waits_summary_global_by_event_name
-> ORDER BY sum_timer_wait DESC LIMIT 5;
+----------------------------------------+------------+------------------+
| event_name | count_star | sum_timer_wait |
+----------------------------------------+------------+------------------+
| innodb_log_file | 205438 | 2552133070220355 |
| Query_cache::COND_cache_status_changed | 8405302 | 2259497326493034 |
| Query_cache::structure_guard_mutex | 55769435 | 361568224932147 |
| innodb_data_file | 62423 | 347302500600411 |
| dict_table_stats | 15330162 | 53005067680923 |
+----------------------------------------+------------+------------------+Сейчас существует несколько моментов, ограничивающих использование Performance Schema в качестве инструмента профилирования общего назначения. Во-первых, она не обеспечивает достаточный уровень детализации выполнения запросов и затрат времени, который можно получить благодаря существующим инструментам. Во-вторых, она довольно долго не использовалась и в данный момент ее применение приводит к большим издержкам, чем применение привычного для многих инструмента профилирования. (Есть основания полагать, что это будет исправлено в ближайшее время.)
Наконец, иногда она слишком сложна и низкоуровнева для использования большинством пользователей. Функции, реализованные к настоящему моменту, в основном нацелены на то, что нужно измерить при изменении исходного кода MySQL для улучшения производительности сервера. Сюда относятся такие элементы, как ожидания и мьютексы. Некоторые из функций MySQL 5.5 полезны для опытных пользователей, а не для разработчиков серверов. Однако пользователи все еще нуждаются в разработке удобных инструментов интерфейса. В настоящее время для написания сложных запросов к разнообразным таблицам метаданных с большим количеством столбцов требуется настоящее мастерство. Это довольно сложный для использования и понимания набор инструментов.
Будет здорово, когда Performance Schema в более поздних версиях MySQL получит больше функциональности. И очень приятно, что Oracle реализует ее как таблицы, доступные через SQL, тем самым пользователи могут получать данные любым удобным для них способом. Однако пока она еще не способна заменить журнал медленных запросов или другие инструменты, помогающие сразу увидеть варианты улучшения производительности сервера и выполнения запросов.
Использование профиля для оптимизации
Итак, у вас есть профиль сервера или запроса — что с ним делать? Хороший профиль обычно делает проблему очевидной, но решения может и не быть (хотя чаще всего есть). На этом этапе, особенно при оптимизации запросов, вам нужно полагаться на знания о сервере и о том, как он выполняет запросы. Профиль или те данные, которые вы можете собрать, указывают направление движения и дают основания для применения ваших знаний и нахождения результатов с помощью дополнительных инструментов, таких как EXPLAIN.
В общем, хотя нахождение источника проблемы с помощью профиля со всеми метриками не должно представлять труда, наделе невозможно выполнить измерения абсолютно точно, поскольку оцениваемые системы не поддерживают этой возможности. Ранее, рассматривая пример, мы подозревали, что на временные таблицы и неиндексированные чтения затрачивается большая часть времени отклика, однако не можем этого доказать. Иногда проблемы трудно решить, потому что, возможно, не измерено все, что нужно, либо измерения сделаны в неверном направлении. Например, вы можете определять активность всего сервера вместо изучения того фрагмента, который пытаетесь оптимизировать, или анализировать измерения, проведенные с момента времени до начала выполнения запроса, а не тогда, когда он был запущен.
Существует еще одна возможность. Предположим, вы анализируете журнал медленных запросов и находите простой запрос, на несколько запусков которого затрачено неоправданно много времени, хотя он быстро запускался в тысячах других случаев. Вы снова запускаете запрос, и он выполняется молниеносно, как и должно быть. Применяете EXPLAIN и обнаруживаете, что он правильно использует индекс. Вы пытаетесь использовать похожие запросы с разными значениями в разделе WHERE, чтобы убедиться, что запрос не обращается к кэшу, и они тоже выполняются быстро. Кажется, что с этим запросом все нормально. Что дальше?
Если у вас есть только стандартный журнал медленных запросов MySQL без плана выполнения или подробной информации о времени, вы знаете только, что запрос плохо работал, когда был журналирован, и не можете понять, почему это произошло. Возможно, что-то еще потребляло ресурсы в системе, например резервное копирование или какая-то блокировка или параллелизм тормозили ход запроса. Периодически возникающие проблемы — это особый случай, который мы рассмотрим в следующей статье.
