Оптимизация в MySQL, часть 3: проблемные моменты

Данная статья является 3 из 3 частей цикла «Оптимизация MySQL»:

  1. Оптимизация индексов MySQL;
  2. Оптимизация конфигурации MySQL;
  3. Оптимизация проблемных моментов MySQL.

mysql

Эта статья посвящена обнаружению причин возникновения проблем. Прежде всего, нам нужно активировать журнал медленных логов. В журнале медленных логов 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, которые еще не были рассмотрены, зайдите, пожалуйста, на эту страницу, и вы найдете там информацию о том, что еще можно сделать с помощью этого инструмента.

Перевод статьи «Optimizing MySQL Bottlenecks» был подготовлен дружной командой проекта Сайтостроение от А до Я.

Автор: Unknow, Источник
 

Добавить комментарий


Защитный код
Обновить