SQL: что смотреть в логе медленных запросов, прежде чем резать сервис

Рядом с разрезом обычно предлагают кеш спереди и очередь сбоку: текущая граница «выглядит стыдно». Если разрезать раньше, чем прочитан запрос, тот же SQL переедет туда, где логи хуже, а строк база перебирает столько же.

Порядок такой. Возьмите ожидание, которое человек уже чувствует. Найдите запросы в этом окне. Сгруппируйте по тексту. Сравните Rows_examined с Rows_sent и посчитайте повторы. И только потом решайте: индекс, один агрегирующий запрос вместо цикла, ответ поменьше, или работа, которой правда не место в запросе страницы. Цифры ниже относятся к отдельным операциям на одной учебной платформе. Это не множитель для вашего сервиса, и платформу ради них не пилили на части.

1. Что говорит одна запись, если не пугаться шапки

В slow log MySQL шапка и сам запрос. В шапке время, пользователь, хост, Query_time, Lock_time, Rows_sent, Rows_examined. Потом SQL. Query_time — сколько занял этот запрос, не сколько ждал человек у экрана. Lock_time — кусок, который прошёл в ожидании блокировки. Rows_sent — сколько ушло клиенту. Rows_examined — сколько сервер перебрал, чтобы это отдать.

Первый разрез — отношение двух последних. Запрос перебрал сотни тысяч строк, чтобы отдать двадцать: проблема в пути к данным. Нет индекса, маска с процентом в начале, функция вокруг колонки, джойн, который размножает строки до фильтра. Это не доказательство, что граница сервиса кривая. Разрез оставит запрос как был. То же отношение вы прочитаете в двух репозиториях.

Если Lock_time почти равен Query_time, строку держит кто-то другой. Новый сервис с теми же блокировками добавит сетевой прыжок. Сначала найдите второго писателя, потом перерисовывайте схему.

• Query_time, Lock_time, Rows_sent, Rows_examined записаны рядом с SQL, не «я примерно помню».
• Rows_examined на порядки больше Rows_sent. Пока EXPLAIN не скажет иначе, база плохо добирается до строк.
• Lock_time — шум округления или заметная доля Query_time.
• Таблица и условие, на которые можно показать пальцем. «Запрос заказов» — не запись. Запись — это SQL.

2. Лог молчит про цикл, и это его свойство, не ваша удача

long_query_time — порог. Запрос короче порога в файл не попадает. Экран, который гоняет запрос на 200 миллисекунд по разу на строку, может держать человека много секунд, а лог останется тихим, если каждый запуск ниже порога. Человек ждал двенадцать секунд, в логе одна короткая строка: сначала посчитайте повторы, потом верьте, что запрос страницы объяснён. Лог запросов фреймворка или выборка с опущенным порогом на копии покажет цикл, который slow log пропустил.

На учебной платформе фраза «платформа тормозит» ничего не давала. Цикл запросов собрали в один агрегирующий: операция ушла с 12,41 секунды на 2,451, памяти стало меньше на 1,5 ГБ. Повтор и был поломкой. Агрегат, который по-прежнему перебирает не те строки, время бы сохранил. Рефакторинг, который это пропустит, — перенос цикла в воркер с подписью «ручка стала быстрой».

Окно группируют по тексту, выкидывая литералы, которые меняются от строки к строке. Пятьдесят строк, которые отличаются только id, — один запрос. Рядом с Query_time пишут счётчик. Если беда в счётчике, меняют на один агрегирующий запрос. Если один запуск перебирает неприлично много строк, меняют индекс или условие. Разрез сервиса — третья заплатка, и ни одна из первых двух её не требует.

• Секунды, которые ждал человек, записаны рядом с окном лога. Лог эту заметку не заменяет.
• Запросы сгруппированы по тексту. Цикл — это счётчик, не пятьдесят аварий.
• Порог, с которым писался лог. Не знаете порог — не знаете, чего в файле нет.
• Копия, где порог можно опустить или прочитать запросы фреймворка, чтобы быстрый, но частый запрос стал виден.

3. EXPLAIN на копии с объёмом, и только потом правка

План смотрят на базе той же формы и с серьёзным объёмом, и эта база не должна обслуживать клиентов. На пустой схеме план будет другой. «Просто глянуть» на проде — способ изучать план на копии, которая принимает заказы. Если читать можно только боевой MySQL, сначала реплика или восстановление. Индекс — это запись. На большой таблице запись долгая.

План читают против уже сгруппированного запроса. Тип доступа, каким ключом воспользовались, сколько строк план собирается перебрать. Нет ключа на избирательном условии — кандидат в индекс. Ключ есть, а строк всё равно огромно: условие не совпадает с ключом, либо запрос просит сортировку или маску, которую ключ не обслуживает. Это предложение записывают. Индекс, который с ним не сходится, — ключ, которым никто не пользуется.

Поисковые индексы, которых не хватало, были частью той же работы на учебной платформе. Средняя за неделю загрузка CPU ушла с 82,2% до 2,75%, когда разобрали узкие места, включая эти индексы. Цифра — среднее за неделю на той платформе. EXPLAIN её не печатает, и это не прогноз вашего CPU. Лог и план сказали, куда смотреть. CPU сдвинулся, потому что запросы перестали делать лишнее, не потому что сервис переименовали.

• EXPLAIN сгруппированного запроса на копии с живым объёмом, лежит рядом с SQL.
• Ключ, которым воспользовались, или его отсутствие, одним предложением, которое можно перечитать через неделю.
• Новый индекс — отдельная правка с замером того же запроса до и после. Не пачка индексов из чужой статьи.
• План вы не изучаете, меняя боевой сервер.

Если отдельного окружения ещё нет, копию собирают до индекса. Для людей, которые почувствуют выкладку, решение рядом: не выясняйте это на проде.

4. Чего slow log вам не разрешит

Он не разрешит поставить очередь перед запросом, который вы не читали. Фоновая задача с тем же циклом перебирает те же строки. Крутилка становится бейджем «обрабатываем». Ожидание переехало. Очередь уместна, когда цена — работа, которая не должна держать страницу, и повтор не должен повторить побочный эффект. Это другое решение, не способ спрятать медленный запрос. Сначала текст. Граница описана в заметке когда очередь на Node стоит рядом с Laravel.

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

Лог также не покажет ответ, который обработчик собирает уже после запроса. На той учебной платформе отдельная критичная операция ушла с 23 937 мс до 48 мс, а один ответ API — с 912 КБ до 2,1 КБ. Обрезка ответа — не строка slow log. Экрану не нужна была остальная запись. Рефакторинг, который по-прежнему выбирает все колонки, увезёт тот же объём через новый край. Прочитали лог — прочитайте, что действие отдаёт. Обе цифры остаются при своих операциях. Ни одна не значит, что платформа стала быстрее в фиксированное число раз.

И он не разрешит переписать фреймворк. Унаследованные боевые системы ставили на ноги формой запроса, индексами и размером ответа. Если предложение звучит как «сервис грязный, давайте перепишем», спросите текст, счётчики строк и секунды. Грязный код, который гоняет один запрос по индексу, — сопровождение. Не сегодняшний инцидент.

• Очередь, кеш или разрез сервиса не предлагают, пока у сгруппированного запроса нет Rows_examined, Rows_sent и счётчика.
• Размер ответа обработчика — отдельная строка. В slow log его нет.
• Переписывание сервиса, если оно ещё стоит работы, — поздний проект со своей причиной, не способ починить этот запрос.

5. Порядок, который можно повторить на следующем инциденте

Экран или задача, на которых человек уже ждёт. Секунды записываете сами. Slow log за это окно. Если секунды не сходятся, достаёте запросы, которые порог спрятал. Группировка по тексту SQL. У верхнего запроса — Query_time, Lock_time, Rows_sent, Rows_examined и число повторов. EXPLAIN на копии. Меняете одно: цикл в агрегирующий запрос, недостающий индекс или колонки, которые были не нужны. Ту же операцию меряете снова. Строка лога остаётся рядом с цифрой.

Нет полей лога — первый шаг всё ещё назвать экран до любого редизайна. Если ждут отчёт в CRM, спросите, принадлежат ли строки этому клиенту: отчёты без переписывания платформы. Более быстрый запрос, который отдаёт чужие строки, улучшением не является.

• Одна операция, до и после, и SQL всё ещё можно узнать.
• Названа копия, на которой смотрели план. Назван и порог лога.
• Перекройка сервиса, если она ещё нужна, начинается после того, как эта заметка есть.

Когда имеет смысл второй взгляд

Сгруппировать лог и выписать счётчики строк можно вдвоём не собираться. Зовите, когда лог лежит на сервере, который команда не читает, когда для EXPLAIN нужна копия объёма прода, а её нет, или когда запрос сидит в сервисе, который вот-вот заменят, и в плане замены нет Rows_examined. Пришлите экран, секунды и SQL с этими счётчиками. Сырой лог с клиентскими значениями не нужен. Литералы вычистите.

Такое чтение и правка после него — работа, которую я делаю на системах, уже стоящих на проде. Услуги — скорость и backend. Проекты держат цифру рядом с операцией: агрегирующий запрос, индексы, размер ответа. Если текст и счётчики уже есть, напишите в LinkedIn и пришлите их. Строки клиентов оставьте у себя.