Les problèmes de performances sont des problèmes courants lors de l'administration des bases de données MySQL. Parfois, ces problèmes sont en fait dus à des requêtes lentes. Dans ce blog, nous traiterons des requêtes lentes et comment les identifier.
Vérification de vos journaux de requêtes lentes
MySQL a la capacité de filtrer et de consigner les requêtes lentes. Il existe différentes manières d'enquêter sur celles-ci, mais la manière la plus courante et la plus efficace consiste à utiliser les journaux de requêtes lentes.
Vous devez d'abord déterminer si vos journaux de requêtes lentes sont activés. Pour faire face à cela, vous pouvez vous rendre sur votre serveur et interroger la variable suivante :
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)
Vous devez vous assurer que la variable slow_query_log est définie sur ON, tandis que slow_query_log_file détermine le chemin où vous devez placer vos journaux de requêtes lentes. Si cette variable n'est pas définie, elle utilisera le DATA_DIR de votre répertoire de données MySQL.
Avec la variable slow_query_log se trouvent long_query_time et min_examined_row_limit qui ont un impact sur le fonctionnement de la journalisation des requêtes lentes. Fondamentalement, les journaux de requêtes lentes fonctionnent comme des instructions SQL qui prennent plus de long_query_time secondes pour s'exécuter et nécessitent également l'examen d'au moins min_examined_row_limit lignes. Il peut être utilisé pour trouver des requêtes qui prennent beaucoup de temps à s'exécuter et sont donc candidates à l'optimisation et vous pouvez ensuite utiliser des outils externes pour apporter le rapport pour vous, qui parlera plus tard.
Par défaut, les instructions administratives (ALTER TABLE, ANALYZE TABLE, CHECK TABLE, CREATE INDEX, DROP INDEX, OPTIMIZE TABLE et REPAIR TABLE) ne tombent pas dans les journaux de requêtes lentes. Pour ce faire, vous devez activer la variable log_slow_admin_statements.
Interroger la liste des processus et le moniteur d'état InnoDB
Dans une routine DBA normale, cette étape est le moyen le plus courant de déterminer les requêtes de longue durée ou les requêtes en cours d'exécution actives qui entraînent une dégradation des performances. Cela pourrait même entraîner le blocage de votre serveur, suivi de files d'attente empilées qui augmentent lentement en raison d'un verrou couvert par une requête en cours d'exécution. Vous pouvez simplement courir,
SHOW [FULL] PROCESSLIST;
ou
SHOW ENGINE INNODB STATUS \G
Si vous utilisez ClusterControl, vous pouvez le trouver en utilisant
ou en utilisant → Query Monitor → Running Queries ( dont nous parlerons plus tard) pour afficher les processus actifs, tout comme le fonctionnement d'un SHOW PROCESSLIST mais avec un meilleur contrôle des requêtes.
Analyse des requêtes MySQL
Les journaux des requêtes lentes vous affichent une liste des requêtes identifiées comme lentes, en fonction des valeurs données dans les variables système, comme mentionné précédemment. La définition des requêtes lentes peut différer selon les cas, car il existe certaines occasions où même une requête de 10 secondes est acceptable et toujours pas lente. Cependant, si votre application est un OLTP, il est très courant qu'une requête de 10 secondes ou même de 5 secondes soit un problème ou entraîne une dégradation des performances de votre base de données. Le journal des requêtes MySQL vous aide, mais il ne suffit pas d'ouvrir le fichier journal car il ne vous donne pas un aperçu de ces requêtes, de leur fonctionnement et de leur fréquence d'occurrence. Par conséquent, des outils tiers peuvent vous y aider.
pt-query-digest
L'utilisation de Percona Toolkit, que je peux dire l'outil DBA le plus courant, consiste à utiliser pt-query-digest. pt-query-digest vous fournit un aperçu clair d'un rapport spécifique provenant de votre journal de requêtes lentes. Par exemple, ce rapport spécifique montre une perspective claire de compréhension des rapports de requête lente dans un nœud spécifique :
# 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
Utilisation de performance_schema
Les journaux de requêtes lents peuvent poser problème si vous n'avez pas un accès direct au fichier, par exemple en utilisant RDS ou en utilisant des services de base de données entièrement gérés tels que Google Cloud SQL ou Azure SQL. Bien qu'il puisse avoir besoin de certaines variables pour activer ces fonctionnalités, cela s'avère pratique lors de l'interrogation des requêtes enregistrées dans votre système. Vous pouvez le commander en utilisant une instruction SQL standard afin de récupérer un résultat partiel. Par exemple,
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 |
...
Vous pouvez utiliser la table performance_schema.events_statements_summary_by_digest. Bien qu'il y ait des chances que les entrées sur les tables de performance_schema soient vides, vous pouvez décider de les enregistrer dans une table spécifique. Jetez un œil à ce post externe de Percona MySQL query digest with Performance Schema.
Au cas où vous vous demanderiez pourquoi nous devons diviser les colonnes de temps d'attente (SUM_TIMER_WAIT, MIN_TIMER_WAIT_SEC, AVG_TIMER_WAIT_SEC), ces colonnes utilisent des picosecondes, vous devrez donc peut-être faire des calculs ou des arrondis pour faire plus lisible pour vous.
Analyse des requêtes lentes à l'aide de ClusterControl
Si vous utilisez ClusterControl, il existe différentes façons de gérer cela. Par exemple, dans un cluster MariaDB que j'ai ci-dessous, il vous montre l'onglet suivant (Moniteur de requête) et ses éléments déroulants (Requêtes principales, Requêtes en cours d'exécution, Valeurs aberrantes de la requête) :
- Principales requêtes – liste agrégée de toutes vos principales requêtes exécutées sur tous les nœuds de votre cluster de base de données
- Requêtes en cours d'exécution - Affichez les requêtes en cours d'exécution sur votre cluster de base de données similaires à la commande SHOW FULL PROCESSLIST dans MySQL
- Query Outliers :affiche les requêtes qui sont des valeurs aberrantes. Une valeur aberrante est une requête prenant plus de temps que la requête normale de ce type.
En plus de cela, ClusterControl capture également les performances des requêtes à l'aide de graphiques qui vous donnent un aperçu rapide des performances de votre système de base de données par rapport aux performances des requêtes. Voir ci-dessous,
Attendez, ce n'est pas encore fini. ClusterControl propose également une métrique haute résolution utilisant Prometheus et présente des métriques très détaillées et capture des statistiques en temps réel à partir du serveur. Nous en avons discuté dans nos blogs précédents qui sont divisés en deux séries de blogs. Découvrez la partie 1, puis les blogs de la partie 2. Il vous explique comment surveiller efficacement non seulement les requêtes lentes, mais aussi les performances globales de vos serveurs de base de données MySQL, MariaDB ou Percona.
Il existe également d'autres outils dans ClusterControl qui fournissent des pointeurs et des conseils qui peuvent ralentir les performances des requêtes même si cela ne s'est pas encore produit ou capturé par le journal des requêtes lentes. Consultez l'onglet Performances comme indiqué ci-dessous,
ces éléments vous fournissent ce qui suit :
- Vue d'ensemble :vous pouvez afficher les graphiques des différents compteurs de base de données sur cette page
- Conseillers – Listes des résultats des conseillers planifiés créés dans ClusterControl > Gérer > Developer Studio à l'aide de ClusterControl DSL.
- État de la base de données :l'état de la base de données fournit un aperçu rapide de l'état de MySQL sur tous vos nœuds de base de données, similaire à l'instruction SHOW STATUS
- Variables DB - Les variables DB fournissent un aperçu rapide des variables MySQL qui sont définies sur tous vos nœuds de base de données, similaires à l'instruction SHOW GLOBAL VARIABLES
- Croissance de la base de données :fournit un résumé de la croissance de votre base de données et de vos tables sur une base quotidienne au cours des 30 derniers jours.
- Statut InnoDB - Récupère la sortie actuelle du moniteur InnoDB pour l'hôte sélectionné, similaire à la commande SHOW ENGINE INNODB STATUS.
- Schema Analyzer :analyse les schémas de votre base de données à la recherche de clés primaires manquantes, d'index et de tables redondants à l'aide du moteur de stockage MyISAM.
- Journal des transactions :répertorie les transactions de longue durée et les blocages dans le cluster de bases de données, ce qui vous permet de visualiser facilement les transactions à l'origine des blocages. Le seuil de temps de requête par défaut est de 30 secondes.
Conclusion
Tracer votre problème de performances MySQL n'est pas vraiment difficile avec MySQL. Il existe divers outils externes qui vous offrent l'efficacité et les capacités que vous recherchez. La chose la plus importante est qu'il est facile à utiliser et que vous êtes en mesure d'assurer la productivité au travail. Résolvez les problèmes les plus importants ou évitez même un certain désastre avant qu'il ne se produise.