Важные логи сайта
Access.log — логи посещений пользователей и ботов. Позволяет составить более точную и подробную статистику, нежели сторонние ресурсы, выполняющие внешнее сканирование сайта и отправляющие ряд ненужных запросов серверу. Благодаря данному логу можно получить информацию об используемом браузере и IP-адрес посетителя, данные о местонахождении клиента (страна и город) и многое другое
Стоит обратить внимание, если сайт имеет высокую посещаемость, то анализ логов сервера потребует больше времени. Поэтому для составления статистики стоит использовать специализированные программы (анализаторы).
Error.log — программные ошибки сервера
Стоит внимательно отнестись к анализу данного лога, ведь боты поисковиков, сканируя, получают все данные о работе сайта. При обнаружении большого количества ошибок, сайт может попасть под санкции поисковых систем. В свою очередь из записей данного журнала можно узнать точную дату и время ошибки, IP-адрес получателя, тип и описание ошибки.
Slow.log (название зависит от используемой оболочки сервера) — в данный журнал записываются медленные запросы сервера. Так принято обозначать запросы с повышенным порогом задержки, выданные пользователю. Этот журнал позволяет выявить слабые места сервера и исправить проблему. Ниже будет рассмотрен способ включить ведение данного лога на разных типах серверов, а также настройка задержки, с которой записи будут заноситься в файл.
Просмотр логов с помощью ISPManager
Если на сервере установлен ISPManager, логи можно легко читать, используя приведенный ниже алгоритм.
- На главной странице, в панели инструментов «WWW» нужно нажать на вкладку «Журналы».
- ISPManager выдаст журналы посещений и серверных ошибок в виде:
- ru.access.log;
- ru.error.log.*
* Вместо «newdomen.ru» из примера в выдаче будет название актуального домена.
Открыть файл лога можно, нажав на «Посмотреть» в верхнем меню.
- Для просмотра всех записей журнала, необходимо нажать на «Скачать» и сохранить файл на локальный носитель.
- Более старые версии логов можно найти во вкладке «Архив».
Working with slow query log
You can use or other pager of your preferences to read the slow query log, i.e. .
On a production system, slow query log can grow big and contain tons of queries. It might be a burden to investigate it and understand which ones are most frequent.
The YUM repository of Percona contains useful packages for generating digest of slow queries. Let’s install that first:
Percona Toolkit can help you to generate digest of the slow queries found. Let’s do that:
Example output:
Example output: # Profile # Rank Query ID Response time Calls R/Call V/M Item # ==== ================== =============== ===== ====== ===== ============= # 1 0x13C86AF70C18C60A 1622.5487 83.0% 211 7.6898 2.91 UPDATE bai_wp_eStore_download_links_tbl # 2 0xD5613DAE943A30BE 287.7647 14.7% 213 1.3510 2.99 SELECT bai_wp_eStore_download_links_tbl # MISC 0xMISC 44.8708 2.3% 2570 0.0175 0.0 # Query 1: 0.18 QPS, 1.37x concurrency, ID 0x13C86AF70C18C60A at byte 143788 # This item is included in the report because it matches --limit. # Scores: V/M = 2.91 # Time range: 2017-02-07 20:02:09 to 20:21:56 # Attribute pct total min max avg 95% stddev median # ============ === ======= ======= ======= ======= ======= ======= ======= # Count 7 211 # Exec time 82 1623s 4s 24s 8s 19s 5s 5s # Lock time 91 820s 44us 20s 4s 15s 5s 901ms # Rows sent 0 0 0 0 0 0 0 0 # Rows examine 45 415.15M 1.97M 1.97M 1.97M 1.95M 0 1.95M # Rows affecte 80 221 1 3 1.05 0.99 0.23 0.99 # Bytes sent 0 10.71k 52 52 52 52 0 52 # Query size 7 22.43k 105 109 108.85 107.34 0.98 107.34 # String: # Databases mrprint1_wor3 # Hosts localhost # Last errno 0 # Users mrprint1_wor3 # Query_time distribution # 1us # 10us # 100us # 1ms # 10ms # 100ms # 1s ################################################################ # 10s+ ####################### # Tables # SHOW TABLE STATUS FROM `mrprint1_wor3` LIKE 'bai_wp_eStore_download_links_tbl'\G # SHOW CREATE TABLE `mrprint1_wor3`.`bai_wp_eStore_download_links_tbl`\G UPDATE bai_wp_eStore_download_links_tbl SET access_count = '1' WHERE download_key = 's8jM9+LO0CcVzVkpPEY='\G # Converted for EXPLAIN # EXPLAIN /*!50100 PARTITIONS*/ select access_count = '1' from bai_wp_eStore_download_links_tbl where download_key = 's8jM9+LO0CcVzVkpPEY='\G
This example digest basically tells us that there is one highly inefficient query that we need to take care of. Example:
To understand what can be done in order to optimize the query, the digest suggests our to run an EXPLAIN statement for this query. So we do that:
When you take note on your particular query, you need to make sure that EXPLAIN reports use of indexes. In case they are missing, you will need to add them.
When you troubleshoot your slow queries in WordPress, you might find one particular index that is missing and killing your performance.
In some WordPress installations (due to failed upgrade, or what not, old version), it is the index for autoload field in wp_options table. Here is how to add it and fix performance quickly:
Программы для анализа логов
Анализировать журналы с большим количеством данных вручную не только сложно, но и чревато ошибками. Для упрощения работы с лог файлами было создано большое количество сервисов и утилит.
Инструменты для анализа логов делятся на два основных типа — статические и работающие в режиме реального времени.
Статические программы
Данный тип выполняет работу только с извлеченными логами, но обеспечивает быструю сортировку данных.
WebLog Expert![](/wp-content/uploads/f/1/a/f1ad46e008204c431904c9ef25ebc1a9.png)
Возможности
- Предоставление информации об активность сайта, количестве посетителей, доступ к файлам, URL страницы, ссылающиеся страницы, информацию о пользователе (браузер и операционная система).
- Создание отчётов в формате HTML (.html), PDF (.pdf), CSV (.csv).
- Поддерживает анализ логов Nginx, Apache, ISS.
- Чтение файлов даже в архивах ZIP (.zip), GZ (.gz).
Web Log Explorer
Возможности
- Создание многоуровневых отчётов, включающих количество посетителей, маршруты пользователей по сайту, местоположение хостов (страна и город), указанные в поисковике ключевые слова.
- Поддержка более 43 форматов логов.
- Возможность прямой загрузки логов с FTP, HTTP сервера.
- Чтение архивированных журналов.
Программы для анализа в режиме реального времени
Эти инструменты встраиваются в программную среду сервера, анализируют данные в реальном времени и записывают непрерывный отчёт.
GoAccess
Возможности
- Автоматическая генерация отчёта в формате HTML (.html), JSON (.json), CSV (.csv).
- При подключении к серверу через SSH, возможен анализ в браузере и в терминале
- Поддержка почти всех форматов (Apache, Nginx, Amazon S3, Elastic Load Balancing, CloudFront и др.).
Возможности
- Постоянная генерация отчёта в файл JSON (.json).
- Получение и анализ информации из нескольких источников.
- Возможность пересылать журналы с помощью Filebeat.
- Поддержка анализа системных журналов.
- Поддерживается большое количество форматов: от Apache до Log4j (Java).
Ведение логов в Logrotate
На больших ресурсах журналы могут достигать огромных размеров, поэтому нужно своевременно архивировать или очищать логи. С помощью утилиты Logrotate можно управлять ведением журналов: настроить период ротации (архивирование старого журнала и создание нового), период и количество хранения журналов и многое другое.
Изначально программа отсутствует в системе. Ниже приведены команды для инсталляции Logrotate из официальных репозиториев.
Ubuntu, Debian:
sudo apt install logrotate
CentOS:
sudo yum install logrotate
После установки необходимо проверить путь для будущих конфигурационных файлов. Для правильной работы они должны находится в папке «logrotate.d». Проверить данный параметр можно открыв конфигурационный файл командой:
nano /etc/logrotate.conf
В директории «RPM packages drop log rotation information into this directory» должна присутствовать строка:
include /etc/logrotate.d
Теперь создаётся конфигурационный файл «rsyslog.conf». В нём будет находиться конфигурацию по работе с логами. Для создания файла в терминале вводится команда:
sudo nano /etc/logrotate.d/rsyslog.conf
В окне терминала откроется текстовой редактор. Теперь нужно внести конфигурацию, как указано в образце. В качестве примера будет использоваться журнал посещений «Access.log» (Nginx).
/var/log/nginx/access.log { daily rotate 3 size 500M compress delaycompress }
Теперь остаётся только запустить Logrotate. Для этого вводится команда:
sudo logrotate -d /etc/logrotate.d/rsyslog.conf
Для проверки правильности работы программы в терминале можно ввести команду:
ls /var/cron.daily/
Просмотр логов сервера с помощью команды tail
Выполнить просмотр логов в Linux можно с помощью команды tail. Данный инструмент позволяет смотреть записи в логах, выводя последние строки из файла. По умолчанию tail выводит 10 строк.
Первый вариант использования Tail
tail -f /var/log/syslog
Аргумент «-f» позволяет команде делать просмотр событий в режиме реального времени, в ожидании новых записей в лог файлах. Для прерывания процесса следует нажать сочетание клавиш «Ctrl+C.
На место переменной «/var/log/syslog» в примере следует подставить актуальный адрес до нужных системных журналов.
Второй вариант использования Tail
tail -F /var/log/syslog
В Linux логи веб-сервера не ведутся до бесконечности, поскольку это усложняет их дальнейший анализ. При преодолении лимита записей, система переименует переполненный строками файл журнала и отправит в «архив». Вместо старого файла создастся новый, но с прежним названием.
Если будет использоваться аргумент «-f», команда продолжит отслеживание старого, переименованного журнала. Данный метод делает невозможным просмотр логов в реальном времени, поскольку файл более не актуален.
При использовании аргумента «-F», команда, после окончания записи старого журнала, перейдёт к чтению нового файла с логами. В таком случае просмотр логов в режиме реального времени продолжится.
Аналог команды Tail
tailf /var/log/syslog
Отличие команды tailf от предыдущей заключается в том, что она не обращается к файлу и файловой системе в период, когда запись логов не происходит. Это экономит ресурсы системы и заряд, если используется нестационарное устройство — ноутбук, смартфон или планшет.
Недостаток данного способа — проблема с чтением больших файлов. Если системный журнал достаточно большой, возникает вероятность отказа в работе программы.
Изменение стандартного количества строк для вывода
Как и отмечалось выше, по умолчанию выводится 10 строк. Если требуется увеличить или уменьшить их количество, в команду добавляется аргумент «-n» и необходимое число строк.
Пример:
tail -f -n 100 /var/log/syslog
При использовании данной команды будут показаны последние 100 строк журнала.
How to configure and enable slow queries log
Step by step guide
If you want to take it slow and understand the above commands, following is step by step to enable slow query log
Before enabling the slow query log, we should configure it. Percona MySQL comes with parameters allowing you to unconditionally log slow queries which exceed specific time, with microseconds resolution
Open MySQL shell with command in SSH terminal and run the following:
This tells MySQL to log all queries which take slower than 150 milliseconds to run. However, this will consume I/O bandwidth and cause the log file to grow large on busy websites. So we are going to adjust this so that 1 in 10 slow queries will be logged instead:
When a query is too slow, we may want to unconditionally log it, independent of the log rate limit. Let’s always log every query that is slower than 1 second:
We also setup resolution to microseconds, make sure that the slow log is rotated when it reaches 100 Mb in size and tell MySQL to keep up to 3 rotated logs to save space:
Finally, let’s enable slow query log :sql
If you also want to log queries without indexes, you can run:
You can verify variables related to slow query log like this:
The slow query log is now being populated. Typical location is .
Генерирование запроса для профилирования
Теперь вы знакомы с настройками логов медленных запросов. Попробуйте сгенерировать данные запроса для профилирования.
Примечание
: Приведенный здесь пример был выполнен на запущенном экземпляре MySQL без настроенных логов медленных запросов. Эти тестовые запросы можно выполнять через графический интерфейс или командную строку MySQL.
При мониторинге лога медленных запросов полезно открыть два окна терминала: одно соединение для отправки операторов MySQL, а второе – для просмотра лога запросов.
Зайдите на сервер MySQL с помощью консоли как пользователь с привилегиями SUPER ADMIN. Для начала создайте тестовую базу данных и таблицу, добавьте в нее фиктивные данные и включите лог медленных запросов.
Примечание
: В идеале этот пример лучше выполнять в среде без каких-либо других приложений, использующих MySQL, чтобы избежать загромождения лога запросов.
$> mysql -u -pmysql> 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 и запустите:
mysql> USE profile_sampling;
mysql> SELECT * FROM users WHERE id = 1;
Выполненный запрос просто извлекает данные и использует индекс первого ключа из таблицы. Этот запрос был быстрым и использовал индекс, поэтому в логе медленных запросов он не регистрируется. Вернитесь в каталог и убедитесь, что лог запросов не был создан. Теперь вернитесь в окно MySQL и запустите:
mysql>
В этом запросе не используется индекс. Теперь в логе /var/log/mysql/localhost-slow.log должна появиться примерно такая запись:
# Time: 140322 13:54:58
use profile_sampling;
SET timestamp=1395521698;
Еще один пример. Увеличьте минимальное количество строк для анализа и отправьте такой запрос:
mysql> SET min_examined_row_limit = 100;
mysql> SELECT * FROM users WHERE name = «Walter»;
Данные не будут добавлены в лог, поскольку при запросе было проанализировано меньше 100 строк.
Примечание
: Если данные не были добавлены в лог, нужно проверить несколько факторов. Сначала проверьте права каталога, в котором создается лог. Он должен принадлежать пользователю/группе mysqld и иметь привилегии chmod 755. Затем следует проверить, нет ли на сервере других настроек медленных запросов, которые переопределяют ваши параметры. Сбросьте значения по умолчанию, чтобы удалить все переменные медленных запросов из конфигурационного файла, и перезагрузите сервер. Также можно динамически установить глобальным переменным их стандартные значения. Если вы вносите изменения динамически, выйдите из системы и войдите в MySQL, чтобы обновить параметры.
Querying Process List and InnoDB Status Monitor
In a normal DBA routine, this step is the most common way to determine the long running queries or active running queries that causes performance degradation. It might even cause your server to be stuck followed by piled up queues that are slowly increasing due to a lock covered by a running query. You can just simply run,
or
If you are using ClusterControl, you can find it by using <select your MySQL cluster> → Performance → InnoDB Status just like below,
or using <select your MySQL cluster> → Query Monitor → Running Queries (which will discuss later) to view the active processes, just like how a SHOW PROCESSLIST works but with better control of the queries.
Checking Your Slow Query Logs
MySQL has the capability to filter and log slow queries. There are various ways you can investigate these, but the most common and efficient way is to use the slow query logs.
You need to determine first if your slow query logs are enabled. To deal with this, you can go to your server and query the following variable:
You must ensure that the variable is set to ON, while the slow_query_log_file determines the path where you need to place your slow query logs. If this variable is not set, it will use the DATA_DIR of your MySQL data directory.
Accompanied by the slow_query_log variable are the and which impacts how the slow query logging works. Basically, the slow query logs work as SQL statements that take more than long_query_time seconds to execute and also require at least min_examined_row_limit rows to be examined. It can be used to find queries that take a long time to execute and are therefore candidates for optimization and then you can use external tools to bring the report for you, which will talk later.
By default, administrative statements (ALTER TABLE, ANALYZE TABLE, CHECK TABLE, CREATE INDEX, DROP INDEX, OPTIMIZE TABLE, and REPAIR TABLE) do not fall into slow query logs. In order to do this, you need to enable variable .
Скорость работы MySQL
Оптимизация без аналитики бессмысленна. Перед тем как переходить к оптимизации давайте посмотрим как работает база данных сейчас, есть ли запросы, которые выполняются очень медленно. Все настройки вашего сервиса mysql находятся в файле /etc/my.cnf. Чтобы включить отображение медленных запросов добавьте такие строки в my.cnf, в секцию :
Здесь первая строка включает запись лога медленных запросов, вторая указывает, что минимальное время запроса для внесения его в этот лог — две секунды. Еще можно включить в лог запросы, которые не используют индексы:
Но это уже необязательно для проверки скорости и используется больше для отладки кода и правильности создания таблиц. Дальше перезапустите сервер баз данных и посмотрите лог:
Мы можем видеть, что есть запросы, которые выполняются больше, чем 10 секунд. Это, например, запрос
Можно его выполнить отдельно, в консоли mysql:
Здесь тоже измеряется время, и мы видим результат — три секунды. Это очень много. И еще ничего, если такие запросы приходят редко, если ваш сайт постоянно под нагрузкой, то тремя секундами вы не отделаетесь, количество необработанных запросов будет расти, а скорость ответа увеличиваться до нескольких минут. Можно пойти двумя путями — оптимизировать код, убрать сложные запросы, или же нужна оптимизация mysql на сервере.
Analyzing Slow Queries Using ClusterControl
If you are using ClusterControl, there are different ways to deal with this. For example, in a MariaDB Cluster I have below, it shows you the following tab (Query Monitor) and it’s drop-down items (Top Queries, Running Queries, Query Outliers):
- — aggregated list of all your top queries running on all the nodes of your database cluster
- — View current running queries on your database cluster similar to SHOW FULL PROCESSLIST command in MySQL
- — Shows queries that are outliers. An outlier is a query taking longer time than the normal query of that type.
On top of that, ClusterControl also captures query performance using graphs which provides you a quick overlook of how your database system performs in relation to query performance. See below,
Wait, it’s not over yet. ClusterControl also offers a high resolution metric using Prometheus and showcases very detailed metrics and captures real-time statistics from the server. We have discussed this in our previous blogs which are divided into two part series of blog. Check out part 1 and then the part 2 blogs. It offers you on how to efficiently monitor not only the slow queries but the overall performance of your MySQL, MariaDB, or Percona database servers.
There are also other tools in ClusterControl which provide pointers and hints that can cause slow query performance even if it’s not yet occurred or captured by the slow query log. Check out the Performance Tab as seen below,
these items provides you the following:
- Overview — You can view graphs of different database counters on this page
- Advisors — Lists of scheduled advisors’ results created in ClusterControl > Manage > Developer Studio using .
- DB Status — DB Status provides a quick overview of MySQL status across all your database nodes, similar to SHOW STATUS statement
- DB Variables — DB Variables provide a quick overview of MySQL variables that are set across all your database nodes, similar to SHOW GLOBAL VARIABLES statement
- DB Growth — Provides a summary of your database and table growth on daily basis for the last 30 days.
- InnoDB Status — Fetches the current InnoDB monitor output for selected host, similar to SHOW ENGINE INNODB STATUS command.
- Schema Analyzer — Analyzes your database schemas for missing primary keys, redundant indexes and tables using the MyISAM storage engine.
- Transaction Log — Lists out long-running transactions and deadlocks across database cluster where you can easily view what transactions are causing the deadlocks. The default query time threshold is 30 seconds.
Чтение записей в логах
Записи в логах имеют структуру: одно событие – одна строка.
Записи в разных логах имеют общие черты, но количество подробностей отличается. Далее будут приведены примеры строк из разных системных журналов.
Примеры записей
Error.log
PHP Notice: Undefined variable: moduleclass_sfx in /var/data/www/site.ru/modules/contacts/default.php on line 14
В приведенном примере:
- — дата и время события.
- — ошибка и её тип.
- — IP-адрес подключившегося клиента.
- PHP Notice: Undefined variable: moduleclass_sfx in — событие PHP Notice. В данной ситуации — обнаружена неизвестная переменная.
- /var/data/www/site.ru/modules/contacts/default.php on line 14 — путь и номер строки в проблемном файле.
Access.log
194.61.0.6 – alex [10/Oct/2019:15:32:22 -0700] "GET /apache_pb.gif HTTP/1.0" 200 5396 "http://www.mysite/myserver.html" "Mozilla/4.08 (Win98; I ;Nav)"
В приведенном примере:
- 194.61.0.6 — IP-адрес пользователя.
- alex — если пользователь зарегистрирован в системе, то в логах будет указан идентификатор.
- [10/Oct/2019:15:32:22 -0700]— дата и время записи.
- «GET /apache_pb.gif HTTP/1.0» — «GET» означает, что определённый документ со страницы сайта был отправлен пользователю. Существует команда «POST», наоборот отправляет конкретные данные (комментарий или любое другое сообщение) на сервер . Далее указан извлечённый документ «Apache_pb.gif», а также использованный протокол «HTTP/1.0».
- 200 5396 — код и количество байтов документа, которые были возвращены сервером.
- «http://www. www.mysite/myserver.html»— страница, с которой был произведён запрос на извлечение документа «Apache_pb.gif».
- «Mozilla/4.08 (Win98; I ;Nav)» — данные о пользователе, которой произвёл запрос (используемый браузер и операционная система).