Problemas de desempenho são problemas comuns ao administrar bancos de dados MySQL. Às vezes, esses problemas são, de fato, devido a consultas lentas. Neste blog, vamos lidar com consultas lentas e como identificá-las.
Verificando seus registros de consultas lentas O MySQL tem a capacidade de filtrar e registrar consultas lentas. Existem várias maneiras de investigá-las, mas a maneira mais comum e eficiente é usar os logs de consulta lenta.
Você precisa determinar primeiro se seus logs de consulta lenta estão ativados. Para lidar com isso, você pode ir ao seu servidor e consultar a seguinte variável:
MariaDB [(none)]> show global variables like 'slow%log%';
+---------------------+-------------------------------+
| Variable_name | Value |
+---------------------+-------------------------------+
| slow_query_log | ON |
| slow_query_log_file | /var/log/mysql/mysql-slow.log |
+---------------------+-------------------------------+
2 rows in set (0.001 sec)Você deve garantir que a variável slow_query_log esteja definida como ON, enquanto o slow_query_log_file determina o caminho onde você precisa colocar seus logs de consulta lenta. Se esta variável não estiver definida, ela usará o DATA_DIR do seu diretório de dados MySQL.
Acompanhados pela variável slow_query_log estão o long_query_time e o min_examined_row_limit, que afetam o funcionamento do log de consultas lentas. Basicamente, os logs de consulta lenta funcionam como instruções SQL que levam mais de long_query_time segundos para serem executadas e também exigem que pelo menos linhas min_examined_row_limit sejam examinadas. Ele pode ser usado para encontrar consultas que levam muito tempo para serem executadas e, portanto, são candidatas a otimização e, em seguida, você pode usar ferramentas externas para trazer o relatório para você, que falaremos mais adiante.
Por padrão, as instruções administrativas (ALTER TABLE, ANALYZE TABLE, CHECK TABLE, CREATE INDEX, DROP INDEX, OPTIMIZE TABLE e REPAIR TABLE) não caem em logs de consulta lenta. Para fazer isso, você precisa habilitar a variável log_slow_admin_statements.
Lista de processos de consulta e Monitor de status do InnoDB Em uma rotina normal de DBA, essa etapa é a maneira mais comum de determinar as consultas de execução longa ou consultas em execução ativas que causam degradação do desempenho. Pode até fazer com que seu servidor fique travado seguido por filas empilhadas que estão aumentando lentamente devido a um bloqueio coberto por uma consulta em execução. Você pode simplesmente correr,
SHOW [FULL] PROCESSLIST;ou
SHOW ENGINE INNODB STATUS \GSe você estiver usando o ClusterControl, você pode encontrá-lo usando → Performance → InnoDB Status como abaixo, ou usando → Query Monitor → Running Queries ( que discutiremos mais adiante) para visualizar os processos ativos, assim como funciona um SHOW PROCESSLIST, mas com melhor controle das consultas. Analisando consultas MySQL Os registros de consultas lentas mostrarão uma lista de consultas que foram identificadas como lentas, com base nos valores fornecidos nas variáveis do sistema, conforme mencionado anteriormente. A definição de consultas lentas pode diferir em casos diferentes, pois há certas ocasiões em que mesmo uma consulta de 10 segundos é aceitável e ainda não lenta. No entanto, se seu aplicativo for um OLTP, é muito comum que uma consulta de 10 segundos ou até 5 segundos seja um problema ou cause degradação de desempenho em seu banco de dados. O log de consultas do MySQL ajuda você nisso, mas não é suficiente abrir o arquivo de log, pois ele não fornece uma visão geral do que são essas consultas, como elas são executadas e qual é a frequência de sua ocorrência. Portanto, ferramentas de terceiros podem ajudá-lo com isso.
pt-query-digest Usar o Percona Toolkit, que posso dizer que é a ferramenta de DBA mais comum, é usar pt-query-digest. pt-query-digest fornece uma visão geral clara de um relatório específico proveniente de seu log de consulta lenta. Por exemplo, este relatório específico mostra uma perspectiva clara de entender os relatórios de consulta lenta em um nó específico:
# A software update is available:
# 100ms user time, 100ms system time, 29.12M rss, 242.41M vsz
# Current date: Mon Feb 3 20:26:11 2020
# Hostname: testnode7
# Files: /var/log/mysql/mysql-slow.log
# Overall: 24 total, 14 unique, 0.00 QPS, 0.02x concurrency ______________
# Time range: 2019-12-12T10:01:16 to 2019-12-12T15:31:46
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 345s 1s 98s 14s 30s 19s 7s
# Lock time 1s 0 1s 58ms 24ms 252ms 786us
# Rows sent 5.72M 0 1.91M 244.14k 1.86M 629.44k 0
# Rows examine 15.26M 0 1.91M 651.23k 1.86M 710.58k 961.27k
# Rows affecte 9.54M 0 1.91M 406.90k 961.27k 546.96k 0
# Bytes sent 305.81M 11 124.83M 12.74M 87.73M 33.48M 56.92
# Query size 1.20k 25 244 51.17 59.77 40.60 38.53
# Profile
# Rank Query ID Response time Calls R/Call V/M
# ==== ================================ ============= ===== ======= =====
# 1 0x00C8412332B2795DADF0E55C163... 98.0337 28.4% 1 98.0337 0.00 UPDATE sbtest?
# 2 0xDEF289292EA9B2602DC12F70C7A... 74.1314 21.5% 3 24.7105 6.34 ALTER TABLE sbtest? sbtest3
# 3 0x148D575F62575A20AB9E67E41C3... 37.3039 10.8% 6 6.2173 0.23 INSERT SELECT sbtest? sbtest
# 4 0xD76A930681F1B4CC9F748B4398B... 32.8019 9.5% 3 10.9340 4.24 SELECT sbtest?
# 5 0x7B9A47FF6967FD905289042DD3B... 20.6685 6.0% 1 20.6685 0.00 ALTER TABLE sbtest? sbtest3
# 6 0xD1834E96EEFF8AC871D51192D8F... 19.0787 5.5% 1 19.0787 0.00 CREATE
# 7 0x2112E77F825903ED18028C7EA76... 18.7133 5.4% 1 18.7133 0.00 ALTER TABLE sbtest? sbtest3
# 8 0xC37F2569578627487D948026820... 15.0177 4.3% 2 7.5088 0.00 INSERT SELECT sbtest? sbtest
# 9 0xDE43B2066A66AFA881D6D45C188... 13.7180 4.0% 1 13.7180 0.00 ALTER TABLE sbtest? sbtest3
# MISC 0xMISC 15.8605 4.6% 5 3.1721 0.0 <5 ITEMS>
# Query 1: 0 QPS, 0x concurrency, ID 0x00C8412332B2795DADF0E55C1631626D at byte 5319
# Scores: V/M = 0.00
# Time range: all events occurred at 2019-12-12T13:23:15
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 4 1
# Exec time 28 98s 98s 98s 98s 98s 0 98s
# Lock time 1 25ms 25ms 25ms 25ms 25ms 0 25ms
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 12 1.91M 1.91M 1.91M 1.91M 1.91M 0 1.91M
# Rows affecte 20 1.91M 1.91M 1.91M 1.91M 1.91M 0 1.91M
# Bytes sent 0 67 67 67 67 67 0 67
# Query size 7 89 89 89 89 89 0 89
# String:
# Databases test
# Hosts localhost
# Last errno 0
# Users root
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms
# 1s
# 10s+ ################################################################
# Tables
# SHOW TABLE STATUS FROM `test` LIKE 'sbtest3'\G
# SHOW CREATE TABLE `test`.`sbtest3`\G
update sbtest3 set c=substring(MD5(RAND()), -16), pad=substring(MD5(RAND()), -16) where 1\G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/
select c=substring(MD5(RAND()), -16), pad=substring(MD5(RAND()), -16) from sbtest3 where 1\G
# Query 2: 0.00 QPS, 0.01x concurrency, ID 0xDEF289292EA9B2602DC12F70C7A041A9 at byte 3775
# Scores: V/M = 6.34
# Time range: 2019-12-12T12:41:47 to 2019-12-12T15:25:14
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 12 3
# Exec time 21 74s 6s 36s 25s 35s 13s 30s
# Lock time 0 13ms 1ms 8ms 4ms 8ms 3ms 3ms
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 0 0 0 0 0 0 0 0
# Rows affecte 0 0 0 0 0 0 0 0
# Bytes sent 0 144 44 50 48 49.17 3 49.17
# Query size 8 99 33 33 33 33 0 33
# String:
# Databases test
# Hosts localhost
# Last errno 0 (2/66%), 1317 (1/33%)
# Users root
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms
# 1s ################################
# 10s+ ################################################################
# Tables
# SHOW TABLE STATUS FROM `test` LIKE 'sbtest3'\G
# SHOW CREATE TABLE `test`.`sbtest3`\G
ALTER TABLE sbtest3 ENGINE=INNODB\GUsando performance_schema Registros de consulta lentos podem ser um problema se você não tiver acesso direto ao arquivo, como usar RDS ou usar serviços de banco de dados totalmente gerenciados, como Google Cloud SQL ou Azure SQL. Embora possa precisar de algumas variáveis para ativar esses recursos, é útil ao consultar consultas registradas em seu sistema. Você pode encomendá-lo usando uma instrução SQL padrão para recuperar um resultado parcial. Por exemplo,
mysql> SELECT SCHEMA_NAME, DIGEST, DIGEST_TEXT, COUNT_STAR, SUM_TIMER_WAIT/1000000000000 SUM_TIMER_WAIT_SEC, MIN_TIMER_WAIT/1000000000000 MIN_TIMER_WAIT_SEC, AVG_TIMER_WAIT/1000000000000 AVG_TIMER_WAIT_SEC, MAX_TIMER_WAIT/1000000000000 MAX_TIMER_WAIT_SEC, SUM_LOCK_TIME/1000000000000 SUM_LOCK_TIME_SEC, FIRST_SEEN, LAST_SEEN FROM events_statements_summary_by_digest;
+--------------------+----------------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+------------+--------------------+--------------------+--------------------+--------------------+-------------------+---------------------+---------------------+
| SCHEMA_NAME | DIGEST | DIGEST_TEXT | COUNT_STAR | SUM_TIMER_WAIT_SEC | MIN_TIMER_WAIT_SEC | AVG_TIMER_WAIT_SEC | MAX_TIMER_WAIT_SEC | SUM_LOCK_TIME_SEC | FIRST_SEEN | LAST_SEEN |
+--------------------+----------------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+------------+--------------------+--------------------+--------------------+--------------------+-------------------+---------------------+---------------------+
| NULL | 390669f3d1f72317dab6deb40322d119 | SELECT @@`skip_networking` , @@`skip_name_resolve` , @@`have_ssl` = ? , @@`ssl_key` , @@`ssl_ca` , @@`ssl_capath` , @@`ssl_cert` , @@`ssl_cipher` , @@`ssl_crl` , @@`ssl_crlpath` , @@`tls_version` | 1 | 0.0373 | 0.0373 | 0.0373 | 0.0373 | 0.0000 | 2020-02-03 20:22:54 | 2020-02-03 20:22:54 |
| NULL | fba95d44e3d0a9802dd534c782314352 | SELECT `UNIX_TIMESTAMP` ( ) | 2 | 0.0002 | 0.0001 | 0.0001 | 0.0001 | 0.0000 | 2020-02-03 20:22:57 | 2020-02-03 20:23:00 |
| NULL | 18c649da485456d6cdf12e4e6b0350e9 | SELECT @@GLOBAL . `SERVER_ID` | 2 | 0.0001 | 0.0001 | 0.0001 | 0.0001 | 0.0000 | 2020-02-03 20:22:57 | 2020-02-03 20:23:00 |
| NULL | dd356b8a5a6ed0d7aee2abd939cdb6c9 | SET @? = ? | 6 | 0.0003 | 0.0000 | 0.0001 | 0.0001 | 0.0000 | 2020-02-03 20:22:57 | 2020-02-03 20:23:00 |
| NULL | 1c5ae643e930af6d069845d74729760d | SET @? = @@GLOBAL . `binlog_checksum` | 2 | 0.0001 | 0.0001 | 0.0001 | 0.0001 | 0.0000 | 2020-02-03 20:22:57 | 2020-02-03 20:23:00 |
| NULL | ad5208ffa004a6ad7e26011b73cbfb4c | SELECT @? | 2 | 0.0001 | 0.0000 | 0.0000 | 0.0001 | 0.0000 | 2020-02-03 20:22:57 | 2020-02-03 20:23:00 |
| NULL | ed0d1eb982c106d4231b816539652907 | SELECT @@GLOBAL . `GTID_MODE` | 2 | 0.0001 | 0.0000 | 0.0000 | 0.0001 | 0.0000 | 2020-02-03 20:22:57 | 2020-02-03 20:23:00 |
| NULL | cb47e22372fdd4441486b02c133fb94f | SELECT @@GLOBAL . `SERVER_UUID` | 2 | 0.0001 | 0.0000 | 0.0000 | 0.0001 | 0.0000 | 2020-02-03 20:22:57 | 2020-02-03 20:23:00 |
| NULL | 73301368c301db5d2e3db5626a21b647 | SELECT @@GLOBAL . `rpl_semi_sync_master_enabled` | 2 | 0.0001 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 2020-02-03 20:22:57 | 2020-02-03 20:23:00 |
| NULL | 0ff7375c5f076ba5c040e78a9250a659 | SELECT @@`version_comment` LIMIT ? | 1 | 0.0001 | 0.0001 | 0.0001 | 0.0001 | 0.0000 | 2020-02-03 20:45:59 | 2020-02-03 20:45:59 |
| NULL | 5820f411e67a393f987c6be5d81a011d | SHOW TABLES FROM `performance_schema` | 1 | 0.0008 | 0.0008 | 0.0008 | 0.0008 | 0.0002 | 2020-02-03 20:46:11 | 2020-02-03 20:46:11 |
| NULL | a022a0ab966c51eb820da1521349c7ef | SELECT SCHEMA ( ) | 1 | 0.0005 | 0.0005 | 0.0005 | 0.0005 | 0.0000 | 2020-02-03 20:46:29 | 2020-02-03 20:46:29 |
| performance_schema | e4833a7c1365b0b4492e9a514f7b3bd4 | SHOW SCHEMAS | 1 | 0.1167 | 0.1167 | 0.1167 | 0.1167 | 0.0001 | 2020-02-03 20:46:29 | 2020-02-03 20:46:29 |
| performance_schema | 1107f048fe6d970cb6a553bd4727a1b4 | SHOW TABLES | 1 | 0.0002 | 0.0002 | 0.0002 | 0.0002 | 0.0000 | 2020-02-03 20:46:29 | 2020-02-03 20:46:29 |
...Você pode usar a tabela performance_schema.events_statements_summary_by_digest. Embora haja chances de que as entradas nas tabelas de performance_schema sejam niveladas, você pode decidir salvá-las em uma tabela específica. Dê uma olhada neste post externo do Percona MySQL query digest with Performance Schema.
Caso você esteja se perguntando por que precisamos dividir as colunas de tempo de espera (SUM_TIMER_WAIT, MIN_TIMER_WAIT_SEC, AVG_TIMER_WAIT_SEC), essas colunas estão usando picossegundos. mais legível para você.
Analisando consultas lentas usando ClusterControl Se você estiver usando o ClusterControl, existem diferentes maneiras de lidar com isso. Por exemplo, em um cluster MariaDB que tenho abaixo, ele mostra a seguinte guia (Query Monitor) e seus itens suspensos (Top Queries, Running Queries, Query Outliers):
Principais consultas - lista agregada de todas as suas principais consultas executadas em todos os nós do cluster de banco de dados
Consultas em execução - Visualize as consultas em execução atuais em seu cluster de banco de dados semelhante ao comando SHOW FULL PROCESSLIST no MySQL
Consultas atípicas - Mostra as consultas que são atípicas. Um outlier é uma consulta que leva mais tempo do que a consulta normal desse tipo.
Além disso, o ClusterControl também captura o desempenho da consulta usando gráficos que fornecem uma visão rápida do desempenho do seu sistema de banco de dados em relação ao desempenho da consulta. Ver abaixo,
Espere, ainda não acabou. O ClusterControl também oferece uma métrica de alta resolução usando o Prometheus e apresenta métricas muito detalhadas e captura estatísticas em tempo real do servidor. Discutimos isso em nossos blogs anteriores, que são divididos em duas séries de blogs. Confira a parte 1 e depois a parte 2 blogs. Ele oferece a você como monitorar com eficiência não apenas as consultas lentas, mas o desempenho geral de seus servidores de banco de dados MySQL, MariaDB ou Percona.
Há também outras ferramentas no ClusterControl que fornecem ponteiros e dicas que podem causar um desempenho de consulta lento, mesmo que ainda não tenha ocorrido ou capturado pelo log de consulta lento. Confira a guia Desempenho como visto abaixo,
estes itens fornecem o seguinte:
Visão geral - Você pode visualizar gráficos de diferentes contadores de banco de dados nesta página
Advisors - Listas de resultados de advisors agendados criados em ClusterControl> Manage> Developer Studio usando ClusterControl DSL.
Status do banco de dados - o status do banco de dados fornece uma visão geral rápida do status do MySQL em todos os nós do banco de dados, semelhante à instrução SHOW STATUS
Variáveis de banco de dados - Variáveis de banco de dados fornecem uma visão geral rápida das variáveis do MySQL que são definidas em todos os nós do banco de dados, semelhante à instrução SHOW GLOBAL VARIABLES
Crescimento do banco de dados - Fornece um resumo do crescimento do banco de dados e da tabela diariamente nos últimos 30 dias.
InnoDB Status - Busca a saída atual do monitor InnoDB para o host selecionado, semelhante ao comando SHOW ENGINE INNODB STATUS.
Schema Analyzer - Analisa seus esquemas de banco de dados em busca de chaves primárias ausentes, índices redundantes e tabelas usando o mecanismo de armazenamento MyISAM.
Registro de transações - lista as transações de longa duração e os deadlocks no cluster de banco de dados, onde você pode visualizar facilmente quais transações estão causando os deadlocks. O limite de tempo de consulta padrão é de 30 segundos.
Conclusão
