Профилирование запросов в Mysql применяется для оценки производительности вашего приложения. При разработке средних и больших приложений приходится иметь дело с сотнями запросов распределенными по вашему коду, которые исполняются каждую секунду. Без техники профилирования запросов бывает очень сложно найти из-за чего страдает быстродействие вашего приложения.
Что такое лог медленных запросов в MySQL?
Лог медленных запросов в MySQL - лог, отмечающий медленные и потенциально проблемные запросы. MySQL по умолчанию поддерживает такой функционал, но он отключен. При помощи настройки определенных переменных сервера мы можем указать какие именно запросы нас интересуют. Чаще всего нам нужны запросы которые требуют определенное количество времени на своё выполнение или запросы, которые некорректно обрабатывают индексы.
Настройка переменных профилирования
Основные переменные для настройки лога запросов:
Slow_query_log G slow_query_log_file G long_query_time G / S log_queries_not_using_indexes G min_examined_row_limit G / S
Замечание : G - глобальные переменные, S - системные переменные
- slow_query_log - булево значение включающее лог
- slow_query_log_file - абсолютный путь к файлу лога. Владельцем каталога должен быть пользователь mysqld , а также директория должна иметь корректные разрешения для чтения и записи. Чаще всего демон mysql работает от имени пользователя mysql .
Для проверки выполните следующую команды:
Ps -ef | grep bin/mysqld | cut -d" " -f1
Вывод команды даст вам имя текущего пользователя и пользователя mysqld. Пример настройки директории /var/log/mysql:
Cd /var/log sudo mkdir mysql sudo chmod 755 mysql sudo chown mysql:mysql mysql
- long_query_time - время в секундах для проверки продолжительности запроса. Например, при значении 5, каждый запрос продолжительностью более 5 секунд будет записан в лог.
- log_queries_not_using_indexes - булево значение, включает сохранение запросов не использующих индексы. Такие запросы очень важны при анализе.
- min_examined_row_limit - указывает минимальное значение количества рядов данных для анализа. Значение 1000 проигнорирует запросы возвращающие меньше 1000 рядов значений.
Установить эти переменные можно в конфигурационном файле MySQL, динамически через MySQL GUI или командную строку MySQL. Если переменные указаны в конфигурационном файле, то сервер установит их при очередном запуске. Обычно этот файл располагается по адресу /etc, /usr, /etc/my.cnf или /etc/mysql/my.cnf. Вот команды поиска файла конфигурации (иногда следует расширить поиск на другие корневые каталоги):
Find /etc -name my.cnf find /usr -name my.cnf
Когда найдете файл, добавьте требуемые переменные в разделе :
; … slow-query-log = 1 slow-query-log-file = /var/log/mysql/localhost-slow.log long_query_time = 1 log-queries-not-using-indexes ; тут не надо значение
Изменения вступят только при очередном запуске MySQL, если вам необходимо динамическое изменение параметров, используйте другие методы установки переменных:
Mysql> SET GLOBAL slow_query_log = "ON"; mysql> SET GLOBAL slow_query_log_file = "/var/log/mysql/localhost-slow.log"; mysql> SET GLOBAL log_queries_not_using_indexes = "ON"; mysql> SET SESSION long_query_time = 1; mysql> SET SESSION min_examined_row_limit = 100;
Проверить значения переменных можно следующим образом:
Mysql> SHOW GLOBAL VARIABLES LIKE "slow_query_log"; mysql> SHOW SESSION VARIABLES LIKE "long_query_time";
Основной недостаток динамической установки - значения будут потеряны при запуске системы. Рекомендуется указывать важные параметры в конфиге MySQL.
Заметка : Синтаксис динамической установки параметров через команду SET и с использованием конфигурационного файла немного различается, например slow_query_log / slow-query-log . В официальной документации СУБД вы найдете полное описание синтаксиса. Формат Option-File используется для файла конфигурации, System Variable Name - имена переменных при динамической установке значений.
Генерация данных для профилирования запроса
Мы рассмотрели основные пункты настройки профилирования, теперь создадим интересующие нас запросы. Этот пример использовался на запущенном MySQL сервере без каких либо предварительных настроек лога. Примеры запросов можно запускать как через MySQL GUI, так и командными средствами СУБД. При мониторинге лога медленных запросов, часто открывают два окна с соединением: одно для запуска запросов, другое - для просмотра лога.
$> mysql -u -p mysql> CREATE DATABASE profile_sampling; mysql> USE profile_sampling; mysql> CREATE TABLE users (id TINYINT PRIMARY KEY AUTO_INCREMENT, name VARCHAR(255)); mysql> INSERT INTO users (name) VALUES ("Walter"),("Skyler"),("Jesse"),("Hank"),("Walter Jr."),("Marie"),("Saul"),("Gustavo"),("Hector"),("Mike"); mysql> SET GLOBAL slow_query_log = 1; mysql> SET GLOBAL slow_query_log_file = "/var/log/mysql/localhost-slow.log"; mysql> SET GLOBAL log_queries_not_using_indexes = 1; mysql> SET long_query_time = 10; mysql> SET min_examined_row_limit = 0;
Теперь у нас есть БД с тестовыми данными. Мы запустили профилирование, но время срабатывания и количество строк мы специально установили малым. Чтобы просмотреть лог воспользуйтесь командой:
Cd /var/log/mysql ls -l
По идеи, файла лога ещё не должно существовать, так как мы не сделали запросов к БД. Если же он существует, то это означает что профилирование было настроено ранее, а это может исказить результаты примера. Выполните в консоли:
Mysql> USE profile_sampling; mysql> SELECT * FROM users WHERE id = 1;
Наш запрос использует Primary Key индекс из таблицы. Запрос отработал очень быстро с использованием индекса, поэтому в логе он не должен отразиться. Обратите внимание, файл лога не должен был создаться.
Теперь выполните следующее:
Mysql> SELECT * FROM users WHERE name = "Jesse";
Здесь мы не использовали индексов. Теперь мы должны увидеть этот запрос в логе:
Sudo cat /var/log/mysql/localhost-slow.log # Time: 140322 13:54:58 # User@Host: root @ localhost # Query_time: 0.000303 Lock_time: 0.000090 Rows_sent: 1 Rows_examined: 10 use profile_sampling; SET timestamp=1395521698; SELECT * FROM users WHERE name = "Jesse";
Рассмотрим ещё один пример. Поднимите планку количества строк в ответе и выполните следующий запрос:
Mysql> SET min_examined_row_limit = 100; mysql> SELECT * FROM users WHERE name = "Walter";
Запрос не отразится в логе, так как мы не превысили 100 строк в ответе на запрос.
Заметка : Если данные не отображаются в логе, то в первую очередь нужно рассмотреть следующие факторы. Первое - права на каталог, где хранится файл лога. Группа и пользователь должны соответствовать пользователю mysqld, права должны быть - chmod 755. Второе - возможно профилирование было настроено ранее. Удалите все существующие значения переменных профилирования из файла конфигурации и перезапустите сервер или установите переменные динамически. Если вы использовали динамический метод, то выйдете и зайдите снова в консоль MySQL.
Анализ данных профилирования запросов
Рассмотрим вышеприведенный пример:
# Time: 140322 13:54:58 # User@Host: root @ localhost # Query_time: 0.000303 Lock_time: 0.000090 Rows_sent: 1 Rows_examined: 10 use profile_sampling; SET timestamp=1395521698; SELECT * FROM users WHERE name = "Jesse";
Здесь мы видим:
- Время, когда был запущен запрос
- Пользователь, который выполнил запрос
- Время работы запросы
- Продолжительность блокировки
- Количество выбранных строк
- Количество проанализированных строк
Эти данные очень полезны, так как при их помощи мы сможем найти и устранить причину замедления системы. Так же разработчик или администратор MySQL всегда сможет увидеть проблемные запросы и хочется отметить, что тут их найти гораздо быстрее, чем изучая программный код приложения. При длительном профилировании можно отследить условия работы при низком быстродействии.
Использование mysqldumpslow
Лог постоянно записывает данные, как правило, пишет он намного больше, чем из него читают. При большом размере лога, читать его становится проблематично. В состав MySQL входит инструмент mysqldumpslow , который помогает сохранить целостность лога. Сама программа совмещена с MySQL (на Linux системах). Для её использования выполните необходимую команду и передайте ей путь до лог файла:
Sudo mysqldumpslow -t 5 -s at /var/log/mysql/localhost-slow.log
Существует ряд параметров помогающих настроить вывод команды. В примере ниже мы увидим пять последних запросов отсортированных по средней продолжительности. В результате читать лог становится намного удобнее. (вывод изменен, чтобы показать реальные значения в логе):
Count: 2 Time=68.34s (136s) Lock=0.00s (0s) Rows=39892974.5 (79785949), root@localhost SELECT PL.pl_title, P.page_title FROM page P INNER JOIN pagelinks PL ON PL.pl_namespace = P.page_namespace WHERE P.page_namespace = N …
Что мы видим:
- Count - количество вхождений запроса в лог
- Time - среднее и общее время запроса
- Lock - время блокировки таблицы
- Rows - Количество выбранных строк
Команда исключает числовые и строковые данные запроса, то есть запросы с одинаковым условием WHERE будут считаться одинаковыми. Благодаря такому инструменту не приходится постоянно просматривать лог. За счет большого количества параметров команды, можно отсортировать вывод как вам удобно. Так же существуют разработки сторонних разработчиков с похожим функционалом, например pt-query-digest .
Разбивка запросов
Следует уделить внимание ещё одному инструменту, который позволяет разбивать сложные запросы. Чаще всего приходится брать запрос из лога, а потом запускать его прямо в консоли MySQL. Сначала надо включить профилирование, а затем выполнить запрос:
Mysql> SET SESSION profiling = 1; mysql> USE profile_sampling; mysql> SELECT * FROM users WHERE name = "Jesse"; mysql> SHOW PROFILES;
После включения профилирования, SHOW PROFILES покажет таблицу связывающую Query_ID и SQL выражение. Найдите соответствующий Query_ID и выполните следующий запрос (замените # на ваш Query_ID):
Mysql> SELECT * FROM INFORMATION_SCHEMA.PROFILING WHERE QUERY_ID=#;
Пример вывода:
SEQ STATE DURATION 1 starting 0.000046 2 checking permissions 0.000005 3 opening tables 0.000036
STATE - шаг в процессе выполнения запроса, DURATION - продолжительность шага в секундах. Этот инструмент не так уж часто используется, но иногда он может быть чрезвычайно полезен в определении причины снижении скорости запроса.
Детальное описание столбцов:
Детальное описание шагов:
Заметка : этот инструмент не следует использовать в рабочем режиме сервера, за исключением анализа специфических запросов.
Быстродействие лога медленных запросов
Последний вопрос - как сказывается работа профилирования на быстродействие сервера в целом. В продуктовом режиме сервера можно вполне спокойно использовать такое логирование, оно не должно сказываться ни на CPU ни на I/O. Тем не менее стоит обратить внимание на размер файла лога, он не должен становится непомерно большим. Так же из опыта хотелось бы отметить, что устанавливать значение переменной long_query_time стоит равным от 1 секунды и выше.
Важно : не стоит использовать инструмент профилирования - SET profiling = 1 - для записи всех запросов, т.е. переменную general_log в продуктовом режиме и при больших нагрузках не рекомендуется использовать.
Заключение
Профилирование запросов может вам очень помочь в выделении проблемного запроса и в оценке общей производительности. Также разработчик может изучить как работают запросы MySQL его приложения. Инструмент mysqldumpslow помогает просматривать и обрабатывать лог запросов. После определения проблемных запросов останется настроить их на максимальную производительность.
Понятие
Логи сервера (лог-файлы, журнал сервера) - фалы, хранящиеся на сервере, которые содержат системную информацию сервера, а так-же протоколирующие все возможные данные о посетителе веб-ресурса.
Логи используются системными администраторами для анализа посетителей , изучения закономерности поведения определенных групп пользователей, а так-же получения различной информации о них, такой как: используемый браузер, IP адрес, данные о географическом положение клиента и многое другое. По мимо анализа, таким образом можно узнать о несанкционированных доступах к сайту, точнее узнать, кем именно он был произведен, и передать данные о данном случае в соответствующие органы.
Данные в лог-файле, в чистом виде, будут не понятным рядовым пользователям, которые увидят во всем этом всего-лишь набор символов в непонятном порядке. Но для системных администраторов и веб-разработчиков, это является вполне читабельным текстом, и довольно полезной информацией.
Последовательность событий
При каждом обращении клиента к веб-ресурсeсе, срабатывают сразу несколько событий, о последовательности которых мы и поговорим.
1. Осуществление запроса страницы.
При вводе адреса в браузерную строку, либо при переходе по активный веб-ссылке, допустим, со страницы поисковой выдачи, браузер осуществляет поиск и соединение с сервером, на котором расположена страницы, и осуществляет ее запрос. При этом, он передает серверу такую информацию:
- IP-адрес компьютера клиента, который запрашивает страницу (в случае использования прокси-сервера, IP адрес вашего прокси);
- адрес запрашиваемой пользователем интернет-страницы (IP-адрес);
- точное время и дата, когда был осуществлен запрос;
- данные о фактическом местонахождении клиента (в случае если используется прокси-сервер, то фактический адрес прокси);
- информация об используемом клиентом браузере (название, версия и т.д.);
- данные о веб-страницы, с которой был осуществлен переход клиента.
2. Передача запрашиваемых данных. Происходит передача запрашиваемых данных (интернет-страница, файлы, cooki, и др.) от сервера на компьютер пользователя.
3. Запись в журнал сервера. После всего, происходит запись в журнал, в котором указываются все данные, которые фигурировали в прошлых двух событиях. Это вся информация отправленная в первом пункте, а так-же информация о переданных данных.
Как посмотреть логи сервера
Лог-файлы, хранятся в файле access.log не зависимо от того, каким типом веб-сервера вы пользуетесь (Apache, Nginx, прокси-сервером squid и т. д.) Данный файл является текстовым документом, на каждой строчке которого, записывается по одному обращению. Форматов записи в access.log довольно много, но наиболее популярным является combined, при котором, запись имеет следующий вид и последовательность:
Код: %h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"
Где:
%h
- хост/IP-адрес, с которого произведён запрос;
%t
- время запроса к серверу и часовой пояс сервера;
%r
- версия, содержимое и тип запроса;
%s
- код состояния HTTP;
%b
- количество отданных сервером байт;
%{Referer}
- URL-источник запроса;
%{User-Agent}
- HTTP-заголовок, с информацией о запросе (клиентское приложение, язык и т.д.);
%{Host}
- имя Virtual Host, к которому идет обращение.
в готовом виде данная строка имеет примерно следующий вид:
127.0.0.1 - - "GET /index.php HTTP/1..0 (compatible; MSIE 7.0; Windows NT 5.1)"
На чтение логов в ручную, уйдет довольно много времени и сил. Поэтому, опытные веб-мастера используют специальное программное обеспечение, которые называют «Анализаторы лог-файлов». Они анализируют все данные, которые довольно сложны к прочтению человеком, и выдают структурированные данные. Это такие программы как: Analog, WebAnalizer, Webalizer, Awstats, Webtrends, и т.д. Видов специального программного обеспечения довольно много, среди них есть как платные программы, так и бесплатные. Поэтому я уверен, что каждый найдет себе что-то по душе.
Где найти логи сайта
Если у вас обычный хостинг, то скорей всего вам придется написать своему хостеру и запросить у него логи. Так-же, довольно часто, вы можете запросить их через панель хостера. У разных хостеров - по разному. Для примера, что бы запросить у моего хостера, достаточно сделать один клик на главной странице панели:
Если у вас есть доступ к системным папкам сервера, то вы можете найти логи по адресу /etc/httpd/logs/access_log в 99 случаях из 100.
Журнал ошибок error.log
Error.log - файл, в котором так-же ведутся логи. Но не посетителей, а возникших на сервере ошибок. Как и в случае с access.log , каждая строка файла - отвечает за одну возникшую ошибку. Запись ведется с учетом такой информации, как: точная дата и время возникновения ошибки, IP-адрес которому была выдана ошибка, тип ошибки, а так-же причина ее возникновения.
Заключение
Логи являются довольно мощным и информативным инструментом, с которыми необходимо работать. Но в наше время, их заменяют такие инструменты, как Яндекс.Метрика, Google Analytics и т.д., тем самым упрощая нам жизнь. Однако, если вы планируете развиваться, расти и познавать что-то новое, несомненно рекомендую вам познакомиться с данной темой поближе.
Журналы событий — первый и самый простой инструмент для определения статуса системы и выявления ошибок. Основных логов в MySQL четыре:
- Error Log — стандартный лог ошибок, которые собираются во время работы сервера (в том числе start и stop);
- Binary Log — лог всех команд изменения БД, нужен для репликации и бэкапов;
- General Query Log — основной лог запросов;
- Slow Query Log — лог медленных запросов.
Лог ошибок
Этот журнал содержит все ошибки, которые произошли во время работы сервера, включая критические ошибки, а также остановки, включения сервера и предупреждения (warnings). С него нужно начать в случае сбоя системы. По умолчанию все ошибки выводятся в консоль (stderr), также можно записывать ошибки в syslog (по умолчанию в Debian) или отдельный лог-файл:
Log_error=/var/log/mysql/mysql_error.log
# Ошибки будут писаться в mysql_error.log
Рекомендуем держать этот журнал включенным для быстрого определения ошибок. А для понимания, что значит та или иная ошибка, в MySQL присутствует утилита perror :
Shell> perror 13 64 OS error code 13: Permission denied OS error code 64: Machine is not on the network
# Объясняет значения кодов ошибок
Бинарный (он же двоичный) лог
В бинарный лог записываются все команды изменения базы данных, пригодится для репликации и восстановления.
Включается так:
Log_bin = /var/log/mysql/mysql-bin.log expire_logs_days = 5 max_binlog_size = 500M
# Указывает расположение, срок жизни и максимальный размер файла
Учтите, что если вы не собираетесь масштабировать систему и реализовывать отказоустойчивость, то бинарный лог лучше не включать. Он требователен к ресурсам и снижает производительность системы.
Лог запросов
В этом журнале содержатся все полученные SQL-запросы, информация о подключениях клиентов. Может пригодиться для анализа индексов и оптимизации, а также выявления ошибочных запросов:
General_log_file = /var/log/mysql/mysql.log general_log = 1
# Включает лог и указывает расположение файла
Также его можно включить/отключить во время работы сервера MySQL:
SET GLOBAL general_log = "ON"; SET GLOBAL general_log = "OFF";
# Для применения не нужно перезагружать сервер
Лог медленных запросов
Журнал пригодится для определения медленных, то есть неэффективных запросов. Подробнее читайте в этой статье .
Просмотр логов
Для просмотра логов на Debian (Ubuntu) нужно выполнить:
# Лог ошибок tail -f /var/log/syslog #Лог запросов tail -f /var/log/mysql/mysql.log # Лог медленных запросов tail -f /var/log/mysql/mysql-slow.log
# Если логи не указаны отдельно, то находятся в /var/lib/mysql
Ротация логов
Не забывайте сжимать (архивировать, ротировать) файлы логов, чтобы они занимали меньше места на сервере. Для этого используйте утилиту logrotate , отредактировав файл конфигурации /etc/logrotate.d/mysql-server :
# - I put everything in one block and added sharedscripts, so that mysql gets # flush-logs"d only once. # Else the binary logs would automatically increase by n times every day. # - The error log is obsolete, messages go to syslog now. /var/log/mysql.log /var/log/mysql/mysql.log /var/log/mysql/mysql-slow.log { daily rotate 7 missingok create 640 mysql adm compress sharedscripts postrotate test -x /usr/bin/mysqladmin || exit 0 # If this fails, check debian.conf! MYADMIN="/usr/bin/mysqladmin --defaults-file=/etc/mysql/debian.cnf" if [ -z "`$MYADMIN ping 2>/dev/null`" ]; then # Really no mysqld or rather a missing debian-sys-maint user? # If this occurs and is not an error please report a bug. #if ps cax | grep -q mysqld; then if killall -q -s0 -umysql mysqld; then exit 1 fi else $MYADMIN flush-logs fi endscript }
# Сжимает и архивирует нужные логи, очищает файлы
DDL Log
MySQL также ведет лог языка описания данных. В него собираются данные операций типа DROP_TABLE and ALTER_TABLE. Лог используется для восстановления после сбоев, которые произошли во время выполнения таких операций. DDL Log — бинарный файл, не предназначенный для чтения пользователем, поэтому не модифицируйте и не удаляйте его.
Самое главное
Всегда включайте лог ошибок, используйте лог запросов для проверки соединения приложения с базой данных, проверки запросов и работы . Лог медленных запросов пригодится для оптимизации работы MySQL.