RE:NODE

Базы данных12 мин чтения

Журнал медленных запросов MySQL: включить, прочитать, исправить

Как включить журнал медленных запросов MySQL, выбрать long_query_time, свести его через mysqldumpslow или performance_schema и исправить пойманные запросы.

0 прочтений

Журнал медленных запросов записывает каждый оператор, выполнявшийся дольше long_query_time секунд, с указанием, сколько он длился, сколько строк просмотрел и сколько вернул. По умолчанию он выключен, а для включения не нужен перезапуск:

sql
SET GLOBAL slow_query_log = ON;SET GLOBAL long_query_time = 0.5;SET GLOBAL log_output = 'FILE';SHOW VARIABLES LIKE 'slow_query_log_file';

Оставьте его работать на протяжении обычного дня, сведите через mysqldumpslow -s t -t 10, чтобы найти десять видов операторов, которые обходятся дороже всего по суммарному времени, и исправляйте их по одному - почти всегда индексом, иногда переписыванием запроса. Две ловушки: новое значение long_query_time действует только на соединения, открытые после его изменения, а порог по умолчанию в десять секунд настолько высок, что не ловит почти ничего, что волнует веб-приложение.

Это руководство описывает MySQL 8.0 и 8.4 LTS: настройки, формат журнала, инструменты для его сводки, что делать, если до файла журнала не добраться, и решения проблем, которые он обычно выявляет.

Настройки#

ПеременнаяПо умолчаниюЧто делает
slow_query_logOFFВключает журнал
long_query_time10Порог в секундах; допускаются дроби вплоть до микросекунд
slow_query_log_filehost_name-slow.logИмя файла, в каталоге данных, если не указан путь
log_outputFILEFILE, TABLE (в mysql.slow_log) или оба через запятую
log_queries_not_using_indexesOFFЗаписывает также быстрые запросы, выполнившие полное сканирование
log_throttle_queries_not_using_indexes0Ограничивает их число в минуту; 0 - без ограничения
min_examined_row_limit0Пропускает операторы, просмотревшие меньше строк
log_slow_admin_statementsOFFВключает ALTER TABLE, OPTIMIZE, ANALYZE и подобные
log_slow_extraOFFДобавляет к каждой записи дополнительные поля (8.0.14 и новее)

Все они динамические, так что SET GLOBAL работает без перезапуска, а SET PERSIST сохраняет значение между перезапусками. Для изменения глобальных переменных нужна SYSTEM_VARIABLES_ADMIN, которая есть у учётной записи root и нет у пользователя приложения.

Как выбрать long_query_time

Десять секунд имели смысл для пакетных отчётов в 2005 году. Для веб-приложения, где страница должна готовиться за несколько сотен миллисекунд, это значит, что журнал остаётся пустым, пока пользователи ждут. Разумные отправные точки:

  • Веб-приложение или API: от 0.5 до 1. О всём, что дольше полсекунды на пути запроса, стоит знать.
  • Фоновые задания и отчёты: от 2 до 5, или выделите им отдельную учётную запись и смотрите на них отдельно.
  • Короткий осознанный сбор: 0 записывает каждый оператор. Полезно минут на десять, чтобы увидеть полную картину загрузки страницы; опасно, если оставить включённым, потому что каждый запрос пишется на диск.

Подвох, который сбивает с толку всех: у long_query_time есть сессионное значение, которое копируется из глобального при открытии соединения. Приложение с пулом соединений может держать свои соединения часами, и они сохраняют старый порог. Либо перезапустите приложение после изменения, либо дождитесь, пока пул пересоздаст соединения. log_queries_not_using_indexes и сам slow_query_log действуют на всех сразу.

log_queries_not_using_indexes звучит полезно, но в основном даёт шум: он записывает каждый запрос к справочной таблице из десяти строк и каждый SELECT COUNT(*) по маленькой таблице. Если включаете его, добавьте min_examined_row_limit = 1000, чтобы записывались только сканирования реального размера, и log_throttle_queries_not_using_indexes, чтобы один горячий запрос не затопил файл.

Как читать запись#

code
# Time: 2026-10-08T14:02:11.482913Z# User@Host: app[app] @  [198.51.100.7]  Id:    42# Query_time: 2.481920  Lock_time: 0.000004 Rows_sent: 20  Rows_examined: 1840022use appdb;SET timestamp=1791468131;SELECT id, title, created_at FROM postsWHERE status = 'published' ORDER BY created_at DESC LIMIT 20 OFFSET 36000;

Каждая строка несёт подсказку:

  • Query_time - реальное время выполнения. В него входит ожидание, так что оператор, заблокированный другой транзакцией, выглядит медленным, даже если его собственная работа тривиальна.
  • Lock_time - время, потраченное на получение блокировок. Когда оно составляет большую часть Query_time, запрос - жертва конкуренции, а не её причина; смотрите, что держало блокировку, - об этом статья транзакции, блокировки и взаимоблокировки.
  • Соотношение Rows_sent и Rows_examined - самая полезная отдельная метрика. Двадцать отправленных строк на 1,8 миллиона просмотренных значат, что сервер прочитал и выбросил почти всё. Хороший запрос просматривает небольшое кратное того, что возвращает.
  • User@Host говорит, какое приложение или задание его отправило, что важно, когда сервер делят несколько.

С log_slow_extra = ON у каждой записи появляются поля вроде Thread_id, Errno, Bytes_received, Bytes_sent, Read_first, Read_key, Read_next, Sort_merge_passes, Sort_rows, Created_tmp_tables и Created_tmp_disk_tables, которые позволяют отличить запрос, нагруженный сортировкой, от нагруженного сканированием, не запуская его снова. Включите его: журнал станет шире, но цена ничтожна.

Пример выше - классика: глубокая пагинация через OFFSET. MySQL приходится прочитать и выбросить 36 000 строк, чтобы вернуть 20, и страница 2000 архива медленнее первой ровно на эту величину. Решение - в последнем разделе.

Сводка через mysqldumpslow#

Журнал за день может содержать тысячи записей, большинство из которых - одни и те же несколько операторов с разными значениями. mysqldumpslow, Perl-скрипт, поставляемый с сервером MySQL, группирует их по форме - заменяя числа на N, а строки на 'S' - и подводит итоги:

bash
# Top 10 by total time: the queries that cost you the most overall$ mysqldumpslow -s t -t 10 /var/lib/mysql/db-slow.log# Top 10 by count: the ones that run constantly$ mysqldumpslow -s c -t 10 /var/lib/mysql/db-slow.log# Only statements touching the orders table$ mysqldumpslow -s t -g 'orders' /var/lib/mysql/db-slow.log
code
Count: 1412  Time=1.84s (2598s)  Lock=0.00s (0s)  Rows=20.0 (28240), app[app]@[198.51.100.7]  SELECT id, title, created_at FROM posts  WHERE status = 'S' ORDER BY created_at DESC LIMIT N OFFSET N

Сначала сортируйте по суммарному времени (-s t). Запрос, который раз в день идёт 30 секунд, важен меньше, чем запрос на 0,6 секунды, выполняемый 4000 раз в день, и именно суммарное время расставляет их в правильном порядке. Числа в скобках - итоги; вне скобок - средние.

pt-query-digest из Percona Toolkit делает то же самое подробнее - перцентили, ID отпечатка запроса, предложения по EXPLAIN - и его стоит установить, если вы часто анализируете журналы. Обоим инструментам нужен файл на машине, где их можно запустить; скачайте его через SFTP или scp, а не запускайте анализ на маленьком сервере баз данных.

Когда файл журнала недоступен#

На хостинговой базе данных у вас может не быть шелла на машине с базой. Два способа без него обходятся.

Журнал в таблицу. С log_output = 'TABLE' записи попадают в mysql.slow_log, который читается через SQL:

sql
SET GLOBAL log_output = 'TABLE';SET GLOBAL slow_query_log = ON;SELECT start_time, query_time, rows_sent, rows_examined, LEFT(sql_text, 200) AS queryFROM mysql.slow_logORDER BY query_time DESCLIMIT 20;

Таблица использует движок CSV, не имеет индексов и растёт, пока вы не очистите её через TRUNCATE TABLE mysql.slow_log. Годится для сбора за день, но не для того, чтобы оставить включённым на месяцы.

Дайджесты performance_schema. MySQL и так агрегирует каждый оператор по форме в performance_schema, независимо от того, включён ли журнал медленных запросов, и вообще без порога. Часто это лучше журнала, потому что ловит быстрый запрос, выполняемый миллион раз:

sql
SELECT schema_name,       count_star                          AS calls,       ROUND(sum_timer_wait / 1e12, 1)     AS total_s,       ROUND(avg_timer_wait / 1e9, 1)      AS avg_ms,       sum_rows_examined, sum_rows_sent,       LEFT(digest_text, 120)              AS queryFROM performance_schema.events_statements_summary_by_digestWHERE schema_name = 'appdb'ORDER BY sum_timer_wait DESCLIMIT 10;

Значения таймеров в пикосекундах, отсюда деления. Схема sys оборачивает те же данные в более дружелюбные представления: sys.statement_analysis (всё, по убыванию суммарной задержки), sys.statements_with_full_table_scans, sys.statements_with_sorting, sys.statements_with_temp_tables и sys.statements_with_runtimes_in_95th_percentile. Счётчики сбрасываются при перезапуске сервера или по требованию через TRUNCATE TABLE performance_schema.events_statements_summary_by_digest, и так можно чисто измерить «до» и «после».

На RE:NODE пароль root для каждого сервера MySQL генерируется за вас, так что оба способа доступны без чьей-либо помощи: SET GLOBAL для настроек журнала медленных запросов и полный доступ на чтение к performance_schema и sys.

Как исправить то, что он находит#

Большинство записей объясняется одной и той же горсткой причин.

Нет подходящего индекса. Rows_examined в сотнях тысяч, EXPLAIN показывает type: ALL или слабый ref. Добавьте индекс, соответствующий WHERE и ORDER BY, со столбцами равенства в начале. Как его спроектировать и проверить, что он сработал, описано в статье индексы MySQL и EXPLAIN.

Глубокая пагинация через OFFSET. LIMIT 20 OFFSET 36000 читает 36 020 строк. Замените её пагинацией по ключу: запоминайте значение сортировки последней строки и продолжайте с него.

sql
-- Instead of OFFSET, continue after the last row the user sawSELECT id, title, created_at FROM postsWHERE status = 'published'  AND (created_at < '2026-03-14 09:12:00'       OR (created_at = '2026-03-14 09:12:00' AND id < 88213))ORDER BY created_at DESC, id DESCLIMIT 20;

С индексом по (status, created_at, id) каждая страница стоит одних и тех же двадцати строк.

Функции на индексированных столбцах. WHERE DATE(created_at) = '2026-10-08' не может использовать индекс по created_at. Перепишите как диапазон: created_at >= '2026-10-08' AND created_at < '2026-10-09'.

**SELECT * на широких таблицах.** Чтение каждого столбца, включая большие TEXT и JSON, когда страница показывает три. Перечисляйте столбцы явно; с правильным индексом запрос может стать покрывающим и вообще не обращаться к таблице.

`ORDER BY RAND()`. Генерирует случайное значение для каждой строки и сортирует их все. Для «случайного избранного товара» выбирайте случайный ID в приложении или заранее перемешивайте данные в небольшую таблицу.

Подсчёт больших таблиц. SELECT COUNT(*) FROM events по таблице InnoDB с миллионами строк каждый раз сканирует индекс, потому что InnoDB не хранит точного числа строк. Кэшируйте число, ведите счётчик или показывайте оценку из information_schema.tables.

Ожидание блокировок. Высокий Lock_time или Query_time намного больше того, что показывает EXPLAIN ANALYZE при отдельном запуске. Запрос ждёт другую транзакцию. Найдите долгую транзакцию в sys.innodb_lock_waits или information_schema.innodb_trx и держите транзакции короткими.

Шаблон N+1. В журнале медленных запросов никогда не появляется, потому что каждый запрос быстрый. В таблице дайджестов виден как один оператор с огромным count_star - один и тот же SELECT ... WHERE post_id = ?, выполняемый по разу на каждую строку списка. Исправляется в приложении через соединение или пакетный IN (...).

Расследование за один день, шаг за шагом#

Когда кто-то говорит «сайт тормозит», а никто не знает почему, этот порядок за день доводит от жалобы до причины без гаданий.

  1. Снимите исходную точку. Сбросьте счётчики дайджестов через TRUNCATE TABLE performance_schema.events_statements_summary_by_digest, чтобы цифры, которые вы прочтёте завтра, охватывали только сегодняшний день.
  2. Включите журнал медленных запросов с порогом, который заметили бы ваши пользователи, - 0.5 для сайта - с log_slow_extra = ON, и перезапустите приложение или дайте его пулу пересоздать соединения, чтобы они подхватили новое значение.
  3. Оставьте его на самую загруженную часть дня. Сбор в 3 часа ночи найдёт задание бэкапа и больше ничего.
  4. Ранжируйте по суммарному времени через mysqldumpslow -s t или запрос к дайджестам. Выпишите пять самых затратных видов операторов с числом вызовов и средним временем.
  5. Для каждого возьмите один реальный пример из журнала - с настоящими значениями параметров, потому что план может различаться для клиента с пятью заказами и клиента с пятьюдесятью тысячами, - и выполните для него EXPLAIN ANALYZE.
  6. Классифицируйте: нет индекса, не тот индекс, форма запроса (offset, функция на столбце, SELECT *), ожидание блокировки или законно тяжёлая работа, которой нужен кэш или сводная таблица.
  7. Исправьте первый, выкатите и на следующий день проверьте его цифры в дайджестах, прежде чем браться за второй.

Порядок важнее, чем кажется. Исправление одного оператора часто меняет картину для остальных: отсутствующий индекс, из-за которого один запрос сканировал таблицу, заодно заставлял его держать buffer pool в заложниках, вытесняя из памяти страницы других запросов. Те другие запросы ускоряются, даже если их не трогать, и вы зря потратили бы силы, оптимизируя их первыми.

Ещё до всего этого стоит проверить, что время действительно уходит в базу данных. Если самый медленный оператор за день журналирования с порогом в полсекунды - это отчёт на 0,6 секунды, то не база данных виновата в том, что страницы грузятся четыре секунды; смотрите на приложение, вызовы внешних API или CPU сервера. Журнал медленных запросов так же полезен, чтобы исключить базу данных, как и чтобы найти в ней проблему.

Как не дать журналу стать проблемой#

Журнал медленных запросов с низким порогом на загруженном сервере растёт быстро, и на томе в 10 или 20 ГБ забытый журнал - вполне реальный способ заполнить диск. Ротируйте его:

bash
$ mv /var/lib/mysql/db-slow.log /var/lib/mysql/db-slow.log.1$ mysql -u root -p -e "FLUSH SLOW LOGS;"

FLUSH SLOW LOGS закрывает и снова открывает файл, так что MySQL начинает новый под исходным именем. В системе с logrotate это каждую ночь делает секция с postrotate и этой командой. Без доступа к файлам выключите журнал, когда расследование закончено (SET GLOBAL slow_query_log = OFF), и очистите mysql.slow_log, если пользовались таблицей.

Разумная постоянная настройка на небольшом сервере: журнал медленных запросов включён, порог в одну секунду, log_slow_extra включён, log_queries_not_using_indexes выключен, и раз в неделю - взгляд на mysqldumpslow или представление дайджестов. Это почти ничего не стоит и превращает «сайт какой-то медленный» в список. Статьи журналы, которые стоит хранить и мониторинг, который что-то сообщает ставят его в один ряд со всем остальным, что стоит собирать, а сторона памяти медленного сервера описана в статье настройка InnoDB для небольших серверов.

FAQ#

Замедляет ли журнал медленных запросов MySQL?

При разумном пороге - почти нет: запись нескольких сотен записей в час ничего не стоит. При long_query_time = 0 на загруженном сервере он пишет каждый оператор, а это дисковый I/O и место, так что оставляйте такое для коротких сборов. log_output = 'TABLE' несколько медленнее файла.

Я задал long_query_time, но ничего не записывается. Почему?

Обычно потому, что соединения приложения были открыты до изменения и всё ещё несут старое сессионное значение. Перезапустите приложение или дождитесь, пока его пул пересоздаст соединения. Также проверьте, что slow_query_log равен ON, что min_examined_row_limit не отфильтровывает всё подряд и что вы смотрите в файл, указанный в slow_query_log_file.

Можно ли записывать медленные запросы только одного пользователя?

Настройкой на пользователя - нет, но можно менять её на уровне сессии: приложение может выполнить SET SESSION long_query_time = 0.2 на своих соединениях (для сессионного значения особые привилегии не нужны), а отчётное задание - задать порог выше. Отфильтровать по пользователю потом легко через mysqldumpslow или по столбцу user_host в mysql.slow_log.

Какое соотношение Rows_examined к Rows_sent считается хорошим?

Для поиска и страниц со списками - единицы, максимум несколько десятков. Исключение - агрегаты: SUM по заказам за месяц вполне законно просматривает много строк, чтобы вернуть одну. Для них вопрос в том, не справился бы покрывающий индекс или сводная таблица с меньшими затратами.

Журнал медленных запросов - это то же самое, что общий журнал?

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


Комментарии

Полностью анонимно: без аккаунта, без почты, без cookie. Мы храним имя, которое вы ввели, текст и время - больше ничего. Количество ссылок ограничено, разметка не отображается.

0/2000