Вступление

MySQL в сочетании с РНР является одним из наиболее часто используемых движков баз данных. Направить усилия на то, чтобы ваши базы данных MySQL работали наилучшим образом, это то, что вы должны сделать в первую очередь, когда веб-приложение начинает расти.

В этой серии статей мы рассматриваем, как мы можем оптимизировать установки MySQL. Мы расскажем, как можно оптимизировать нашу базу, конфигурацию MySQL, и как мы можем найти потенциальные проблемы, когда MySQL не работает идеально.

Для работы с нашей базой данных мы будем использовать в основном инструменты из Percona Toolkit. Эта статья посвящена обнаружению причин возникновения проблем.

Активация журнала медленных логов для нахождения проблемных мест MySQL

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

Кроме того, он может дать информацию о любом запросе, не использующем индексы.

Активировать журнал медленных логов просто. Все, что вам нужно сделать, это изменить конфигурационный файл MySQL (который в большинстве случаев находится по адресу/etc/mysql/my.cnf) и добавить в него следующие строки:

log_slow_queries = /var/log/mysql/mysql-slow.log
long_query_time = 1
log-queries-not-using-indexes

Любой запрос, который занимает больше одной секунды или не использует индексы, добавляется в этот журнал.

Анализ журнала медленных логов

Вы можете проанализировать ваш журнал медленных логов вручную, перебирая каждый запрос. Однако можно использовать и автоматизированный инструмент, например pt-query-digest.

С его помощью вы можете проанализировать ваш журнал медленных логов, и он автоматически отсортирует все запросы по времени исполнения.

Давайте запустим его pt-query-digest /var/log/mysql/mysql-slow.log:

# 360ms user time, 20ms system time, 24.66M rss, 92.02M vsz
# Current date: Thu Feb 13 22:39:29 2014
# Hostname: *
# Files: mysql-slow.log
# Overall: 8 total, 6 unique, 1.14 QPS, 0.00x concurrency ________________
# Time range: 2014-02-13 22:23:52 to 22:23:59
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 3ms 267us 406us 343us 403us 39us 348us
# Lock time 827us 88us 125us 103us 119us 12us 98us
# Rows sent 36 1 15 4.50 14.52 4.18 3.89
# Rows examine 87 4 30 10.88 28.75 7.37 7.70
# Query size 2.15k 153 296 245.11 284.79 48.90 258.32

Обратите внимание, что у меня было 8 медленных запросов, 6 из них - уникальные. Далее мы видим таблицу с указанием времени, которое заняли определенные действия.

Просмотрите столбец с заголовком 95%, так как в нем приводятся оптимальные средние показатели:

# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ================== ============= ===== ====== ===== ===============
# 1 0x728E539F7617C14D 0.0011 41.0% 3 0.0004 0.00 SELECT blog_article
# 2 0x1290EEE0B201F3FF 0.0003 12.8% 1 0.0003 0.00 SELECT portfolio_item
# 3 0x31DE4535BDBFA465 0.0003 12.6% 1 0.0003 0.00 SELECT portfolio_item
# 4 0xF14E15D0F47A5742 0.0003 12.1% 1 0.0003 0.00 SELECT portfolio_category
# 5 0x8F848005A09C9588 0.0003 11.8% 1 0.0003 0.00 SELECT blog_category
# 6 0x55F49C753CA2ED64 0.0003 9.7% 1 0.0003 0.00 SELECT blog_article

Теперь начинается самое интересное. Видимо это запросы, которые были идентифицированы, как медленные. Обратите внимание, что в моем примере запросы на самом деле не являлись медленными, и были внесены в журнал, потому что не использовали индекс.

Давайте рассмотрим первый вид запросов более подробно:

# Query 1: 0 QPS, 0x concurrency, ID 0x728E539F7617C14D at byte 736 ______
# Scores: V/M = 0.00
# Time range: all events occurred at 2014-02-13 22:23:52
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 37 3
# Exec time 40 1ms 352us 406us 375us 403us 22us 366us
# Lock time 42 351us 103us 125us 117us 119us 9us 119us
# Rows sent 25 9 1 4 3 3.89 1.37 3.89
# Rows examine 24 21 5 8 7 7.70 1.29 7.70
# Query size 47 1.02k 261 262 261.25 258.32 0 258.32
# String:
# Hosts localhost
# Users *
# Query_time distribution
# 1us
# 10us
# 100us ################################################################
# 1ms
# 10ms
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'blog_article'\G
# SHOW CREATE TABLE `blog_article`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT b0_.id AS id0, b0_.slug AS slug1, b0_.title AS title2, b0_.excerpt AS excerpt3, b0_.external_link AS external_link4, b0_.description AS description5, b0_.created AS created6, b0_.updated AS updated7 FROM blog_article b0_ ORDER BY b0_.created DESC LIMIT 10\G

Это, пожалуй, самая важная часть исходящей информации. Здесь мы видим данные по первому запросу в таблице. Еще раз проверяем столбец 95%. Вы можете также видеть, сколько времени потребовалось на обработку запроса, и сколько данных было отправлено.

Вы также можете увидеть, в какую категорию, в зависимости от времени обработки, попал этот запрос. В данном случае он принадлежит диапазону от 100 микросекунд до 1 миллисекунды.

И, наконец, мы видим фактически сам запрос, который был выполнен.

Для каждого запроса, вы получите такую детальную информацию. Вы можете использовать ее, чтобы проанализировать, какие запросы не использовали индексы, а какие были медленными.

Анализ MySQL при возникновении проблем

Еще один интересный инструмент Percona это pt-stalk. С помощью этого инструмента вы можете получить обзор того, что происходит в MySQL в определенные моменты времени.

Давайте предположим, что сегодня, мы хотим проверить состояние MySQL 4 раза. Мы можем сделать это, запустив следующую команду:

pt-stalk --sleep=21600 --threshold=0 --iterations=4

После каждой итерации, pt-stalk записывает все виды данных в папку `/var/lib/pt-stalk/’.

В ней Вы найдете такой список файлов:

-rw-r--r-- 1 root root 11220 Feb 22 14:52 2014_02_22_14_51_35-df
-rw-r--r-- 1 root root 121 Feb 22 14:52 2014_02_22_14_51_35-disk-space
-rw-r--r-- 1 root root 42870 Feb 22 14:52 2014_02_22_14_51_35-diskstats
-rw-r--r-- 1 root root 9 Feb 22 14:52 2014_02_22_14_51_35-hostname
-rw-r--r-- 1 root root 3968 Feb 22 14:51 2014_02_22_14_51_35-innodbstatus1
-rw-r--r-- 1 root root 3969 Feb 22 14:52 2014_02_22_14_51_35-innodbstatus2
-rw-r--r-- 1 root root 49980 Feb 22 14:52 2014_02_22_14_51_35-interrupts
-rw-r--r-- 1 root root 4146 Feb 22 14:51 2014_02_22_14_51_35-log_error
-rw-r--r-- 1 root root 69763 Feb 22 14:51 2014_02_22_14_51_35-lsof
-rw-r--r-- 1 root root 36420 Feb 22 14:52 2014_02_22_14_51_35-meminfo
-rw-r--r-- 1 root root 82 Feb 22 14:51 2014_02_22_14_51_35-mutex-status1
-rw-r--r-- 1 root root 82 Feb 22 14:52 2014_02_22_14_51_35-mutex-status2
-rw-r--r-- 1 root root 559349 Feb 22 14:52 2014_02_22_14_51_35-mysqladmin
-rw-r--r-- 1 root root 139723 Feb 22 14:52 2014_02_22_14_51_35-netstat
-rw-r--r-- 1 root root 104400 Feb 22 14:52 2014_02_22_14_51_35-netstat_s
-rw-r--r-- 1 root root 12542 Feb 22 14:51 2014_02_22_14_51_35-opentables1
-rw-r--r-- 1 root root 12542 Feb 22 14:52 2014_02_22_14_51_35-opentables2
-rw-r--r-- 1 root root 810 Feb 22 14:52 2014_02_22_14_51_35-output
-rw-r--r-- 1 root root 9380 Feb 22 14:51 2014_02_22_14_51_35-pmap
-rw-r--r-- 1 root root 34134 Feb 22 14:52 2014_02_22_14_51_35-processlist
-rw-r--r-- 1 root root 43504 Feb 22 14:52 2014_02_22_14_51_35-procstat
-rw-r--r-- 1 root root 61620 Feb 22 14:52 2014_02_22_14_51_35-procvmstat
-rw-r--r-- 1 root root 11379 Feb 22 14:51 2014_02_22_14_51_35-ps
-rw-r--r-- 1 root root 335970 Feb 22 14:52 2014_02_22_14_51_35-slabinfo
-rw-r--r-- 1 root root 26524 Feb 22 14:51 2014_02_22_14_51_35-sysctl
-rw-r--r-- 1 root root 11468 Feb 22 14:51 2014_02_22_14_51_35-top
-rw-r--r-- 1 root root 379 Feb 22 14:51 2014_02_22_14_51_35-trigger
-rw-r--r-- 1 root root 8181 Feb 22 14:51 2014_02_22_14_51_35-variables
-rw-r--r-- 1 root root 2652 Feb 22 14:52 2014_02_22_14_51_35-vmstat
-rw-r--r-- 1 root root 312 Feb 22 14:52 2014_02_22_14_51_35-vmstat-overall

По названию файла вы уже можете догадаться, что в нем содержится. Данные по использованию дискового пространства, список процессов - кое-что, из того, что вы можете найти в этом файле. Такой файл создается для каждой итерации выполнения команды.

Ну, все это, конечно, интересно, но было бы еще более интересно, получить такие данные на моменты времени, когда что-то идет не так. К счастью, мы можем настроить pt-stalk так, чтобы проверка запускалась при достижении определенных пороговых значений.

Скажем, мы хотим посмотреть, что происходит в тот момент, когда у нас есть 100 подключений:

pt-stalk --function processlist --variable Host --match=localhost --threshold 100 --daemonize

Добавив --dameonize, мы указываем инструменту работать в фоновом режиме, пока он не будет остановлен. Остальные параметры будут настроены так, чтобы начинать заносить логи в журнал, как только на сайте зарегистрировано 100 соединений одновременно.

Журнал логов, который вы получите, будет точно таким же, как мы описали выше.

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

При том, вы также можете проанализировать лог-файлы и посмотреть, происходит ли что-нибудь странное.

Заключение

Это заключение нашего обзора Percona Toolkit. Мы показали вам много инструментов от Toolkit Percona, которые вы можете использовать, чтобы оптимизировать или проинспектировать конфигурацию MySQL и базы данных.

Если вам интересно узнать о других инструментах Percona, которые еще не были рассмотрены, зайдите, пожалуйста, на эту страницу, и вы найдете там информацию о том, что еще можно сделать с помощью этого инструмента.

Оставьте свой отзыв ниже!