Los problemas de rendimiento son problemas comunes al administrar bases de datos MySQL. A veces, estos problemas se deben, de hecho, a consultas lentas. En este blog, trataremos las consultas lentas y cómo identificarlas.
Comprobación de los registros de consultas lentas
MySQL tiene la capacidad de filtrar y registrar consultas lentas. Hay varias formas de investigar esto, pero la forma más común y eficiente es usar los registros de consultas lentas.
Primero debe determinar si sus registros de consultas lentas están habilitados. Para lidiar con esto, puede ir a su servidor y consultar la siguiente variable:
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)
Debe asegurarse de que la variable slow_query_log esté activada, mientras que slow_query_log_file determina la ruta donde debe colocar sus registros de consultas lentas. Si esta variable no está configurada, usará DATA_DIR de su directorio de datos MySQL.
Acompañado por la variable slow_query_log están long_query_time y min_examined_row_limit, que afectan el funcionamiento del registro lento de consultas. Básicamente, los registros de consultas lentos funcionan como instrucciones SQL que tardan más de long_query_time segundos en ejecutarse y también requieren al menos filas min_examined_row_limit para ser examinadas. Se puede usar para encontrar consultas que toman mucho tiempo en ejecutarse y, por lo tanto, son candidatas para la optimización y luego puede usar herramientas externas para generar el informe, del que hablaremos más adelante.
De forma predeterminada, las instrucciones administrativas (ALTER TABLE, ANALYZE TABLE, CHECK TABLE, CREATE INDEX, DROP INDEX, OPTIMIZE TABLE y REPAIR TABLE) no caen en registros de consultas lentas. Para hacer esto, debe habilitar la variable log_slow_admin_statements.
Lista de procesos de consulta y Monitor de estado de InnoDB
En una rutina DBA normal, este paso es la forma más común de determinar las consultas de ejecución prolongada o las consultas de ejecución activa que causan la degradación del rendimiento. Incluso podría causar que su servidor se atasque seguido de colas acumuladas que aumentan lentamente debido a un bloqueo cubierto por una consulta en ejecución. Simplemente puede ejecutar,
SHOW [FULL] PROCESSLIST;
o
SHOW ENGINE INNODB STATUS \G
Si está usando ClusterControl, puede encontrarlo usando
o usando
Análisis de consultas MySQL
Los registros de consultas lentas le mostrarán una lista de consultas que se identificaron como lentas, según los valores proporcionados en las variables del sistema, como se mencionó anteriormente. La definición de consultas lentas puede diferir en diferentes casos, ya que hay ciertas ocasiones en las que incluso una consulta de 10 segundos es aceptable y aún así no es lenta. Sin embargo, si su aplicación es un OLTP, es muy común que una consulta de 10 segundos o incluso de 5 segundos sea un problema o provoque una degradación del rendimiento de su base de datos. El registro de consultas de MySQL lo ayuda, pero no es suficiente para abrir el archivo de registro, ya que no le proporciona una descripción general de cuáles son esas consultas, cómo funcionan y cuál es la frecuencia de su ocurrencia. Por lo tanto, las herramientas de terceros pueden ayudarlo con esto.
pt-query-digest
Usar Percona Toolkit, que puedo decir que es la herramienta DBA más común, es usar pt-query-digest. pt-query-digest le brinda una descripción clara de un informe específico que proviene de su registro de consultas lentas. Por ejemplo, este informe específico muestra una perspectiva clara de la comprensión de los informes de consultas lentas en un nodo 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\G
Usando performance_schema
Los registros de consultas lentos pueden ser un problema si no tiene acceso directo al archivo, como usar RDS o usar servicios de base de datos completamente administrados como Google Cloud SQL o Azure SQL. Aunque es posible que necesite algunas variables para habilitar estas funciones, es útil cuando consulta consultas registradas en su sistema. Puede ordenarlo utilizando una instrucción SQL estándar para recuperar un resultado parcial. Por ejemplo,
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 |
...
Puede utilizar la tabla performance_schema.events_statements_summary_by_digest. Aunque hay posibilidades de que las entradas en las tablas de performance_schema estén al ras, puede decidir guardar esto en una tabla específica. Eche un vistazo a esta publicación externa del resumen de consultas de Percona MySQL con Performance Schema.
En caso de que se pregunte por qué necesitamos dividir las columnas de tiempo de espera (SUM_TIMER_WAIT, MIN_TIMER_WAIT_SEC, AVG_TIMER_WAIT_SEC), estas columnas usan picosegundos, por lo que es posible que deba hacer algunos cálculos o redondear para hacer es más legible para ti.
Análisis de consultas lentas mediante ClusterControl
Si está utilizando ClusterControl, hay diferentes formas de lidiar con esto. Por ejemplo, en un clúster de MariaDB que tengo a continuación, se muestra la siguiente pestaña (Monitor de consultas) y sus elementos desplegables (Consultas principales, Consultas en ejecución, Valores atípicos de consultas):
- Consultas principales:lista agregada de todas sus consultas principales que se ejecutan en todos los nodos de su clúster de base de datos
- Consultas en ejecución:vea las consultas en ejecución actuales en su clúster de base de datos similar al comando SHOW FULL PROCESSLIST en MySQL
- Valores atípicos de consulta:muestra las consultas que son atípicos. Un valor atípico es una consulta que tarda más tiempo que la consulta normal de ese tipo.
Además de eso, ClusterControl también captura el rendimiento de las consultas mediante gráficos que le brindan una visión general rápida del rendimiento de su sistema de base de datos en relación con el rendimiento de las consultas. Véase más abajo,
Espera, aún no ha terminado. ClusterControl también ofrece una métrica de alta resolución usando Prometheus y muestra métricas muy detalladas y captura estadísticas en tiempo real del servidor. Hemos discutido esto en nuestros blogs anteriores, que se dividen en dos series de blogs. Echa un vistazo a la parte 1 y luego a los blogs de la parte 2. Le ofrece cómo monitorear de manera eficiente no solo las consultas lentas, sino también el rendimiento general de sus servidores de bases de datos MySQL, MariaDB o Percona.
También hay otras herramientas en ClusterControl que proporcionan punteros y sugerencias que pueden provocar un rendimiento lento de las consultas incluso si aún no se ha producido o capturado por el registro de consultas lentas. Echa un vistazo a la pestaña Rendimiento como se ve a continuación,
estos elementos le proporcionan lo siguiente:
- Descripción general:puede ver gráficos de diferentes contadores de bases de datos en esta página
- Asesores:listas de resultados de asesores programados creados en ClusterControl> Administrar> Developer Studio utilizando ClusterControl DSL.
- Estado de la base de datos:el estado de la base de datos proporciona una descripción general rápida del estado de MySQL en todos los nodos de la base de datos, similar a la instrucción SHOW STATUS
- Variables de base de datos:las variables de base de datos brindan una descripción general rápida de las variables de MySQL que se establecen en todos los nodos de su base de datos, similar a la instrucción SHOW GLOBAL VARIABLES
- Crecimiento de la base de datos:proporciona un resumen del crecimiento diario de su base de datos y tablas durante los últimos 30 días.
- Estado de InnoDB:obtiene la salida del monitor InnoDB actual para el host seleccionado, similar al comando SHOW ENGINE INNODB STATUS.
- Analizador de esquemas:analiza los esquemas de su base de datos en busca de claves principales faltantes, índices y tablas redundantes mediante el motor de almacenamiento MyISAM.
- Registro de transacciones:enumera las transacciones de ejecución prolongada y los interbloqueos en el clúster de la base de datos donde puede ver fácilmente qué transacciones están provocando los interbloqueos. El umbral de tiempo de consulta predeterminado es de 30 segundos.
Conclusión
Rastrear su problema de rendimiento de MySQL no es realmente difícil con MySQL. Existen varias herramientas externas que le brindan la eficiencia y las capacidades que está buscando. Lo más importante es que es fácil de usar y puede proporcionar productividad en el trabajo. Soluciona los problemas más destacados o incluso evita un determinado desastre antes de que pueda ocurrir.