Cloud Intelligence™

Comment capturer les requêtes SQL avec AWS RDS MySQL

By Ronald BradfordNov 9, 202321 min read

Cette page est également disponible en English, Deutsch, Español, Italiano, 日本語 et Português.

Capturer vos requêtes SQL avec RDS MySQL

Dans cet article, je présente toutes les fonctionnalités natives de MySQL pour capturer les requêtes SQL sur AWS Relational Database Service (RDS). Identifier les requêtes SQL est un principe essentiel de conception et d'exploitation : cela permet de comprendre l'usage de votre application, sa charge, l'impact sur les performances et les goulots d'étranglement liés à la configuration de la base de données.

L'objectif ici est de montrer comment capturer les informations relatives aux requêtes SQL. Je n'aborderai pas les informations complémentaires que l'on peut également obtenir avec une requête SQL : plan d'exécution (QEP), structure des tables, cardinalité des index, configuration de l'optimiseur et statistiques. Ces sujets feront l'objet d'un prochain article.

Collecte des requêtes SQL

MySQL propose plusieurs moyens de collecter les requêtes SQL en cours d'exécution ou déjà exécutées. Aucune méthode n'est supérieure à toutes les autres ; il est souvent nécessaire d'en combiner plusieurs pour obtenir une observabilité fine du système et une analyse détaillée des requêtes SQL. Vous pouvez utiliser ces différentes méthodes, chacune offrant elle-même plusieurs façons d'obtenir les mêmes informations.

Processlist
Performance Schema
Sys Schema
Slow query log
General query log
Binary log

Sauf indication contraire, le client en ligne de commande mysql est utilisé pour les exemples de sortie qui suivent.

NOTE : les exemples SQL présentés ici sont compatibles avec MySQL 5.7 et MySQL 8.0. En raison de la fin de vie (EOL) de MySQL 5.7 community edition et de la prochaine EOL d'AWS RDS MySQL 5.7, l'ensemble des sorties et des références documentaires utilisent la version actuelle MySQL 8.0. Certaines sorties présentées ici peuvent différer de celles produites avec MySQL 5.7.

1\. SQL avec le processlist MySQL

Le processlist MySQL affiche les requêtes SQL en cours d'exécution, c'est-à-dire celles qui s'exécutent au moment où la commande processlist est lancée. Pour les requêtes longues, c'est une approche simple pour repérer du SQL. En revanche, pour des requêtes à haute fréquence et faible latence, il devient très difficile de les observer via le processlist MySQL. Outre la requête en cours d'exécution, vous pouvez obtenir des détails sur l'utilisateur source et l'hôte, le schéma de base utilisé, le temps d'exécution (en secondes) et l'état interne courant de la requête.

Vous pouvez récupérer la sortie du processlist MySQL par différents moyens.

performance schema
sys schema
information schema
commande SHOW
commande mysqladmin

Aucune option n'a d'avantage spécifique sur les autres lorsqu'elles fournissent les mêmes colonnes d'information. Certaines de ces options n'étaient pas disponibles dans les versions plus anciennes de MySQL et ont été ajoutées pour se conformer aux standards de l'industrie via des requêtes ISO SQL valides — ce qui n'est pas le cas de SHOW. La commande mysqladmin propose plusieurs options d'administration et permet de combiner plusieurs sorties, comme le montre l'exemple.

Processlist via Performance Schema

Lorsqu'il est activé, le performance_schema fournit ces informations via les tables threads et processlist.

mysql> SELECT * FROM performance_schema.processlist;
+-----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| ID  | USER            | HOST               | DB      | COMMAND | TIME | STATE                  | INFO                                                                                                                                                                      |
+-----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
|   5 | event_scheduler | localhost          | NULL    | Daemon  |  456 | Waiting on empty queue | NULL                                                                                                                                                                      |
|   9 | rdsadmin        | localhost          | NULL    | Sleep   |    0 |                        | NULL                                                                                                                                                                      |
|  11 | rdsadmin        | localhost          | NULL    | Sleep   |    0 |                        | NULL                                                                                                                                                                      |
|  19 | rdsadmin        | localhost          | NULL    | Sleep   |    3 |                        | NULL                                                                                                                                                                      |
|  23 | rdsadmin        | localhost          | NULL    | Sleep   |   65 |                        | NULL                                                                                                                                                                      |
| 263 | rdsadmin        | localhost          | NULL    | Sleep   |    0 |                        | NULL                                                                                                                                                                      |
| 404 | dba             | 172.31.16.14:43464 | airport | Query   |    0 | executing              | SELECT SQL_NO_CACHE a.country_code, c.name, COUNT(*) AS cnt FROM airport a INNER JOIN country c USING (country_code) GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10 |
| 406 | dba             | 172.31.16.14:43484 | airport | Query   |    0 | executing              | SELECT * FROM performance_schema.processlist                                                                                                                              |
+-----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+

Pour plus d'informations, consultez le MySQL 8.0 Reference Manual.

Processlist via Sys Schema

Les vues processlist et session du sys schema donnent accès aux requêtes SQL et à des informations complémentaires. Ces vues s'appuient sur le performance schema, qui doit donc être activé pour capturer les requêtes via le sys schema. Elles fournissent également des attributs de métadonnées supplémentaires associés à la requête SQL. Voici un exemple utilisant la vue sys.x$processlist.

mysql> SELECT * FROM sys.x$processlist WHERE command = 'Query'\G
*************************** 1. row ***************************
                thd_id: 675
               conn_id: 650
                  user: [email protected]
                    db: airport
               command: Query
                 state: executing
                  time: 0
     current_statement: SELECT a.country_code, c.name, COUNT(*) AS cnt FROM airport a INNER JOIN country c USING (country_code) GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10
     statement_latency: 116727428000
              progress: NULL
          lock_latency: 506000000
         rows_examined: 0
             rows_sent: 0
         rows_affected: 0
            tmp_tables: 1
       tmp_disk_tables: 0
             full_scan: YES
        last_statement: NULL
last_statement_latency: NULL
        current_memory: 165019
             last_wait: NULL
     last_wait_latency: NULL
                source: NULL
           trx_latency: 116250140000
             trx_state: ACTIVE
        trx_autocommit: YES
                   pid: 15730
          program_name: mysql

Le terminateur ci-dessus produit un format de table vertical (colonne : valeur par ligne) plutôt que le format horizontal classique en colonnes et lignes. Le terminateur SQL \G est utilisé ici à la place du point-virgule habituel ;. Cette syntaxe est spécifique au client mysql et n'est pas prise en charge par les clients GUI tiers.

NOTE : si vous obtenez le message d'erreur suivant, vous pouvez exécuter sans risque l'instruction SET SQL_BIG_SELECTS=1; avant la requête ci-dessus.

ERROR 1104 (42000) at line 1: The SELECT would examine more than
MAX_JOIN_SIZE rows; check your WHERE and use SET SQL_BIG_SELECTS=1
or SET MAX_JOIN_SIZE=# if the SELECT is okay

Pour plus d'informations, consultez le MySQL 8.0 Reference Manual.

Processlist via Information Schema

Bien que l'Information Schema soit un standard de fait utilisé dans de nombreux SGBDR, la table processlist n'est pas standard. Dans MySQL, vous pouvez consulter ces informations avec la requête suivante.

mysql > SELECT * FROM information_schema.processlist;
+----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| ID | USER            | HOST               | DB      | COMMAND | TIME | STATE                  | INFO                                                                                                                                                                      |
+----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| 88 | dba             | 172.31.16.14:59474 | airport | Query   |    0 | executing              | SELECT SQL_NO_CACHE a.country_code, c.name, COUNT(*) AS cnt FROM airport a INNER JOIN country c USING (country_code) GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10 |
|  9 | rdsadmin        | localhost          | NULL    | Sleep   |    0 |                        | NULL                                                                                                                                                                      |
| 26 | rdsadmin        | localhost          | NULL    | Sleep   |    1 |                        | NULL                                                                                                                                                                      |
| 11 | rdsadmin        | localhost          | NULL    | Sleep   |    0 |                        | NULL                                                                                                                                                                      |
| 19 | rdsadmin        | localhost          | NULL    | Sleep   |    9 |                        | NULL                                                                                                                                                                      |
|  5 | event_scheduler | localhost          | NULL    | Daemon  |  352 | Waiting on empty queue | NULL                                                                                                                                                                      |
| 94 | dba             | 172.31.16.14:59522 | airport | Query   |    0 | executing              | SELECT * FROM information_schema.processlist                                                                                                                              |
| 23 | rdsadmin        | localhost          | NULL    | Sleep   |  261 |                        | NULL                                                                                                                                                                      |
+----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+

Pour plus d'informations, consultez le MySQL 8.0 Reference Manual

Processlist via la commande SHOW

Avant l'introduction de l'Information Schema en version 5.1 et du Performance Schema en version 5.5, le principal moyen de capturer le processlist dans MySQL était la commande SHOW.

mysql> SHOW FULL PROCESSLIST;

Cette sortie est identique au résultat de SELECT * FROM performance_schema.processlist; présenté plus haut. Le mot-clé FULL est nécessaire pour obtenir des requêtes non tronquées.

Pour plus d'informations, consultez le MySQL 8.0 Reference Manual.

Processlist via le client _mysqladmin_

Un autre client MySQL, mysqladmin, utilisé pour effectuer diverses opérations d'administration, peut également produire une sortie du processlist en cours, sous forme tabulaire.

$ mysqladmin --verbose processlist status
+-----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Id  | User            | Host               | db      | Command | Time | State                  | Info                                                                                                                                                          |
+-----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------+
| 5   | event_scheduler | localhost          |         | Daemon  | 1419 | Waiting on empty queue |                                                                                                                                                               |
| 9   | rdsadmin        | localhost          |         | Sleep   | 1    |                        |                                                                                                                                                               |
| 11  | rdsadmin        | localhost          |         | Sleep   | 1    |                        |                                                                                                                                                               |
| 19  | rdsadmin        | localhost          |         | Sleep   | 6    |                        |                                                                                                                                                               |
| 23  | rdsadmin        | localhost          |         | Sleep   | 128  |                        |                                                                                                                                                               |
| 771 | rdsadmin        | localhost          |         | Sleep   | 3    |                        |                                                                                                                                                               |
| 830 | dba             | 172.31.16.14:54000 | airport | Query   | 0    | executing              | SELECT  a.country_code, c.name, COUNT(*) AS cnt FROM airport a INNER JOIN country c USING (country_code) GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10 |
| 832 | dba             | 172.31.16.14:54026 |         | Query   | 0    | init                   | show full processlist                                                                                                                                         |
+-----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------+
Uptime: 1421  Threads: 8  Questions: 14058  Slow queries: 1290  Opens: 261  Flush tables: 3  Open tables: 181  Queries per second avg: 9.893

Sans l'option --verbose, vous obtiendrez des requêtes SQL tronquées, même pour cette requête courte. Par exemple :

| 786 | dba             | 172.31.16.14:59446 | airport | Query   | 0    | executing              | SELECT  a.country_code, c.name, COUNT(*) AS cnt FROM airport a INNER JOIN country c USING (country_c |

Pour plus d'informations, consultez le MySQL 8.0 Reference Manual

2\. SQL avec le Performance Schema

Lorsque le Performance Schema est activé et que les consommateurs concernés le sont également, plusieurs tables permettent d'obtenir des informations détaillées sur les requêtes SQL exécutées et en cours d'exécution.

Options de configuration

Sur une instance MySQL native, on active le performance schema ainsi :

mysql> SET GLOBAL performance_schema=1;

Avec le service managé AWS RDS, vous devez passer par les parameter groups pour modifier les paramètres. Par exemple :

$ modify-parameter ${PG_NAME} performance_schema 1 pending-reboot

NOTE : pour une instance RDS, cela renvoie au parameter group d'instance. Lorsqu'une instance fait partie d'un cluster AWS RDS Aurora, il existe un parameter group de cluster qui s'applique par défaut, sauf si les valeurs sont surchargées par le parameter group d'instance.

Lorsque le performance schema est activé pour la première fois, l'instance MySQL — et donc l'instance AWS RDS — doit être redémarrée.

$ aws rds reboot-db-instance --db-instance-identifier ${INSTANCE_ID}

Les consommateurs et instruments du performance schema permettant de capturer les requêtes SQL sont activés par défaut, mais peuvent être modifiés sur une instance MySQL en cours d'exécution. Vous pouvez vérifier la configuration actuelle avec :

mysql> SELECT * FROM performance_schema.setup_instruments WHERE NAME LIKE 'statement/%';
mysql> SELECT * FROM performance_schema.setup_consumers WHERE NAME LIKE '%statements%';

Validation des paramètres

L'instruction suivante permet de confirmer que le performance schema est activé.

mysql> SELECT @@performance_schema;
+----------------------+
| @@performance_schema |
+----------------------+
|                    1 |
+----------------------+

Table processlist du Performance Schema

Comme démontré précédemment, la table processlist fournit les informations de base sur les requêtes en cours d'exécution.

Table threads du Performance Schema

La table threads expose des attributs supplémentaires pour les requêtes SQL en cours d'exécution.

mysql> SELECT * FROM performance_schema.threads WHERE PROCESSLIST_STATE="executing"\G
*************************** 1. row ***************************
          THREAD_ID: 960
               NAME: thread/sql/one_connection
               TYPE: FOREGROUND
     PROCESSLIST_ID: 935
   PROCESSLIST_USER: dba
   PROCESSLIST_HOST: 172.31.16.14
     PROCESSLIST_DB: airport
PROCESSLIST_COMMAND: Query
   PROCESSLIST_TIME: 0
  PROCESSLIST_STATE: executing
   PROCESSLIST_INFO: SELECT  a.country_code, c.name, COUNT(*) AS cnt FROM airport a INNER JOIN country c USING (country_code) GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10
   PARENT_THREAD_ID: NULL
               ROLE: NULL
       INSTRUMENTED: YES
            HISTORY: YES
    CONNECTION_TYPE: SSL/TLS
       THREAD_OS_ID: 353
     RESOURCE_GROUP: NULL

Tables events_statements_* du Performance Schema

Le grand atout du performance schema, c'est sa capacité à capturer les requêtes SQL récemment exécutées — un outil indispensable pour les requêtes très rapides.

mysql> SELECT * FROM performance_schema.events_statements_current WHERE SQL_TEXT like '%airport%'\G
*************************** 1. row ***************************
              THREAD_ID: 981
               EVENT_ID: 4
           END_EVENT_ID: NULL
             EVENT_NAME: statement/sql/select
                 SOURCE: init_net_server_extension.cc:110
            TIMER_START: 2471111163284000
              TIMER_END: 2471111453481000
             TIMER_WAIT: 290197000
              LOCK_TIME: 175000000
               SQL_TEXT: SELECT * FROM performance_schema.events_statements_current WHERE SQL_TEXT like '%airport%'
                 DIGEST: 2fdfe28204e80c382a14597873be575ea8c7ede6e4757e77700a333bbe50b025
            DIGEST_TEXT: SELECT * FROM `performance_schema` . `events_statements_current` WHERE `SQL_TEXT` LIKE ?
         CURRENT_SCHEMA: NULL
            OBJECT_TYPE: NULL
          OBJECT_SCHEMA: NULL
            OBJECT_NAME: NULL
  OBJECT_INSTANCE_BEGIN: NULL
            MYSQL_ERRNO: 0
      RETURNED_SQLSTATE: NULL
           MESSAGE_TEXT: NULL
                 ERRORS: 0
               WARNINGS: 0
          ROWS_AFFECTED: 0
              ROWS_SENT: 0
          ROWS_EXAMINED: 0
CREATED_TMP_DISK_TABLES: 0
     CREATED_TMP_TABLES: 0
       SELECT_FULL_JOIN: 0
 SELECT_FULL_RANGE_JOIN: 0
           SELECT_RANGE: 0
     SELECT_RANGE_CHECK: 0
            SELECT_SCAN: 1
      SORT_MERGE_PASSES: 0
             SORT_RANGE: 0
              SORT_ROWS: 0
              SORT_SCAN: 0
          NO_INDEX_USED: 1
     NO_GOOD_INDEX_USED: 0
       NESTING_EVENT_ID: NULL
     NESTING_EVENT_TYPE: NULL
    NESTING_EVENT_LEVEL: 0
           STATEMENT_ID: 22413
1 row in set (0.01 sec)

D'autres tables du Performance Schema contiennent des requêtes SQL exécutées : events_statements_current, events_statements_history et events_statements_long. Pour plus d'informations, consultez le MySQL 8.0 Reference Manual.

3\. SQL avec le Sys Schema

Le sys schema MySQL est un ensemble d'objets et de vues qui interprètent les données du Performance Schema et offrent une présentation plus accessible à l'utilisateur final. Il expose également les requêtes SQL exécutées et des statistiques d'exécution agrégées. La première vue à examiner est statement_analysis, ou x$statement_analysis.

mysql> select * from sys.x$statement_analysis where query like '%airport%'\G
*************************** 1. row ***************************
            query: SELECT `a` . `country_code` , `c` . `name` , COUNT ( * ) AS `cnt` FROM `airport` `a` INNER JOIN `country` `c` USING ( `country_code` ) GROUP BY `country_code` , NAME ORDER BY ? DESC LIMIT ?
               db: airport
        full_scan: *
       exec_count: 8
        err_count: 0
       warn_count: 0
    total_latency: 1330746923000
      max_latency: 304276507000
      avg_latency: 166343365000
     lock_latency: 1937000000
        rows_sent: 80
    rows_sent_avg: 10
    rows_examined: 1223680
rows_examined_avg: 152960
    rows_affected: 0
rows_affected_avg: 0
       tmp_tables: 8
  tmp_disk_tables: 0
      rows_sorted: 80
sort_merge_passes: 0
           digest: 616aa31e4f99b22a194c91ae9f1cfbfb95d6957621b55393b4a01603d8e1fd47
       first_seen: 2023-10-12 14:55:56.021003
        last_seen: 2023-10-12 15:23:14.225503

Beaucoup d'autres tables du sys schema contiennent des requêtes SQL exécutées et des agrégations de sous-ensembles de requêtes. Quelques exemples : statements_with_full_table_scans et statements_with_temp_tables. Pour plus d'informations, consultez le MySQL 8.0 Reference Manual.

4\. SQL avec le slow query log

Une fois activé, le slow query log fait exactement ce que son nom indique : il journalise toutes les requêtes lentes dépassant un temps d'exécution prédéfini. Dans les anciennes versions, l'unité était la seconde. Depuis MySQL 5.7, c'est la microseconde. La valeur 0 est également valide et signifie que toutes les requêtes SQL exécutées sont journalisées. Attention toutefois : cela représente un surcoût de performance non négligeable sur une base de données très concurrente.

Options de configuration

Sur une instance MySQL native, vous pouvez activer le slow query log avec :

mysql> SET GLOBAL slow_query_log=1;
mysql> SET GLOBAL long_query_time=0.001;
mysql> SET GLOBAL log_output=FILE;   /* This is the default */

Avec le service managé AWS RDS, vous devez passer par les parameter groups. Les modifications sont immédiates. Par exemple :

$ modify-parameter ${PG_NAME} slow_query_log 1
$ modify-parameter ${PG_NAME} long_query_time 0.001
$ modify-parameter ${PG_NAME} log_output FILE

Plusieurs paramètres de configuration supplémentaires ne seront pas abordés ici, dont slow_query_log_file, log_queries_not_using_indexes et log_slow_admin_statements.

NOTE : évaluez soigneusement l'impact d'activer ces options supplémentaires. Chacune peut produire des volumes importants de requêtes SQL qui alourdissent votre fichier de log. Des requêtes effectuant intentionnellement un full-table scan sur un faible nombre de lignes, ou des requêtes administratives fréquentes nécessaires à l'instrumentation et à l'observabilité avec des outils de monitoring, peuvent ainsi être journalisées.

Validation des paramètres

Pour confirmer que votre slow query log est activé et configuré.

mysql> SELECT @@slow_query_log, @@long_query_time, @@log_output;
+------------------+-------------------+--------------+
| @@slow_query_log | @@long_query_time | @@log_output |
+------------------+-------------------+--------------+
|                1 |          0.001000 | FILE         |
+------------------+-------------------+--------------+

Pour plus d'informations, consultez le MySQL 8.0 Reference Manual.

Télécharger le slow query log depuis AWS RDS

Une fois activé, le slow query log écrit dans un fichier de log sur votre instance RDS. Vous pouvez le récupérer avec l'AWS CLI.

$ INSTANCE_ID=
$ aws rds download-db-log-file-portion  \
   --db-instance-identifier ${INSTANCE_ID} \
   --starting-token 0 \
   --output text \
   --log-file-name slowquery/mysql-slowquery.log > slowquery.log

Les fichiers de slow log RDS font l'objet d'une rotation horaire. Vous pouvez utiliser les commandes suivantes pour lister tous les fichiers de log disponibles au téléchargement.

$ aws rds describe-db-log-files --db-instance-identifier ${INSTANCE_ID}

{
    "DescribeDBLogFiles": [\
...\
        {\
            "LogFileName": "slowquery/mysql-slowquery.log",\
            "LastWritten": 1697125638054,\
            "Size": 761426\
        },\
        {\
            "LogFileName": "slowquery/mysql-slowquery.log.2023-10-12.14",\
            "LastWritten": 1697121600696,\
            "Size": 60517\
        },\
        {\
            "LogFileName": "slowquery/mysql-slowquery.log.2023-10-12.15",\
            "LastWritten": 1697122801087,\
            "Size": 343085\
        }\
    ]
}

Informations disponibles dans le slow query log

Une requête SQL individuelle dans le slow query log inclut les informations suivantes :

Heure d'exécution
Utilisateur et hôte
Thread Id
Query time
Lock time
Rows sent
Rows examined
Requête SQL complète

Exemple de sortie du slow query log

# Time: 2023-10-05T15:56:58.831165Z
# User@Host: dba[dba] @  [172.31.16.14]  Id:   295
# Query_time: 0.259097  Lock_time: 0.000178 Rows_sent: 10  Rows_examined: 76733
SET timestamp=1696521418;
SELECT a.country_code, c.name, COUNT(*) AS cnt
FROM airport a
  INNER JOIN country c USING (country_code)
GROUP BY country_code, name
ORDER BY 3 DESC
LIMIT 10;

NOTE : le slow query log est bien structuré : toutes les lignes non commentées sont de véritables requêtes SQL, et ces requêtes sont correctement terminées, ce qui permet de les collecter, journaliser et rejouer très facilement. La seule limite intervient lorsque les tables ne sont pas qualifiées par leur schéma : il faut alors connaître le schéma de base de la table.

Slow query log via une table SQL

Bien que ce ne soit généralement pas recommandé, il est possible de collecter les requêtes lentes via une instruction SQL lorsque le slow query log est activé et configuré avec log_output=TABLE.

Collecte SQL des informations du slow query log

La requête SQL suivante permet de récupérer les requêtes journalisées dans la table mysql.slow_log.

# Table does not have a PK, so this is a crud hack
SELECT sl.*,
       CONVERT(q.sql_text USING utf8mb4)AS query
FROM mysql.slow_log sl
INNER JOIN mysql.slow_log q  USING (start_time)
WHERE CONVERT(q.sql_text USING utf8mb4) like '%airport%'\G

Exemple de sortie du slow query log via table

    start_time: 2023-10-05 15:59:30.878226
     user_host: dba[dba] @  [172.31.16.14]
    query_time: 00:00:00.295653
     lock_time: 00:00:00.000164
     rows_sent: 10
 rows_examined: 76733
            db: airport
last_insert_id: 0
     insert_id: 0
     server_id: 1843089174
      sql_text: 0x53454C45435420612E636F756E7472795F636F64652C20632E6E616D652C20434F554E54282A2920415320636E742046524F4D20616972706F72742061202020494E4E4552204A4F494E20636F756E7472792063205553494E472028636F756E7472795F636F6465292047524F555020425920636F756E7472795F636F64652C206E616D65204F5244455220425920332044455343204C494D4954203130
     thread_id: 295
         query: SELECT a.country_code, c.name, COUNT(*) AS cnt FROM airport a   INNER JOIN country c USING (country_code) GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10

5\. SQL avec le general query log

Une fois configuré, MySQL peut journaliser toutes les requêtes SQL dans le general query log.

NOTE : choisissez avec soin l'environnement où activer le general query log et la durée d'activation. L'exemple suivant correspond à un système 100 % inactif, avec les 12 requêtes SQL supplémentaires exécutées dans la même seconde que notre requête d'exemple.

AVERTISSEMENT : comme pour le slow query log, il est possible de journaliser cette sortie dans une table MySQL. Cette pratique est déconseillée, car elle peut fortement impacter les performances d'un système en production.

Options de configuration

Sur une instance MySQL native, vous pouvez activer le general query log avec :

mysql> SET GLOBAL general_log=1;
mysql> SET GLOBAL log_output=FILE;   /* This is the default */

Avec le service managé AWS RDS, vous devez passer par les parameter groups. Les modifications sont immédiates. Par exemple :

$ modify-parameter ${PG_NAME} general_log 1
$ modify-parameter ${PG_NAME} log_output FILE

Un paramètre de configuration supplémentaire ne sera pas abordé ici : la variable general_log_file.

Validation des paramètres

Pour confirmer que votre general query log est activé et configuré.

mysql> SELECT @@general_log, @@log_output, @@general_log_file;
+---------------+--------------+------------------------------------------+
| @@general_log | @@log_output | @@general_log_file                       |
+---------------+--------------+------------------------------------------+
|             1 | FILE         | /rdsdbdata/log/general/mysql-general.log |
+---------------+--------------+------------------------------------------+

Pour plus d'informations, consultez le MySQL 8.0 Reference Manual.

Télécharger le general query log depuis AWS RDS

Une fois activé, le general query log écrit dans un fichier de log sur votre instance RDS. Vous pouvez le récupérer avec l'AWS CLI.

$ INSTANCE_ID=
$ aws rds download-db-log-file-portion  \
   --db-instance-identifier ${INSTANCE_ID} \
   --starting-token 0 \
   --output text \
   --log-file-name general/mysql-general.log > general.log

Comme indiqué dans la section précédente, vous pouvez utiliser l'argument describe-db-log-files pour lister les fichiers de general query log qui ont fait l'objet d'une rotation.

Exemple de sortie du general query log

2023-10-05T17:31:06.006853Z         9 Query     set local oscar_local_only_replica_host_status=1;
2023-10-05T17:31:06.006963Z         9 Query     SELECT durable_lsn, current_read_point, server_id, last_update_timestamp FROM information_schema.replica_host_status;
2023-10-05T17:31:06.007500Z         9 Query     set local oscar_local_only_replica_host_status=0
2023-10-05T17:31:06.836552Z       540 Query     SELECT
       a.country_code, c.name, COUNT(*) AS cnt
FROM   airport a
INNER JOIN country c USING (country_code)
GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10
2023-10-05T17:31:06.932194Z         9 Query     set local oscar_local_only_replica_host_status=1;
2023-10-05T17:31:06.932368Z         9 Query     SELECT durable_lsn, current_read_point, server_id, last_update_timestamp FROM information_schema.replica_host_status;
2023-10-05T17:31:06.933104Z         9 Query     set local oscar_local_only_replica_host_status=0
2023-10-05T17:31:06.935817Z        11 Query     SET @@sql_log_bin=off
2023-10-05T17:31:06.936615Z        11 Query     select @@session.transaction_read_only
2023-10-05T17:31:06.937118Z        11 Query     INSERT INTO mysql.rds_heartbeat2(id, value) values (1,1696527066936) ON DUPLICATE KEY UPDATE value = 1696527066936
2023-10-05T17:31:06.947853Z        11 Query     select @@session.transaction_read_only
2023-10-05T17:31:06.948293Z        11 Query     COMMIT
2023-10-05T17:31:06.948725Z        11 Query     SET @@sql_log_bin=on

NOTE : le general query log est semi-structuré. Une requête SQL peut s'étendre sur plusieurs lignes, en conservant le format transmis à MySQL par votre programme client. Il ne suffit donc pas de retirer les 41 premiers caractères de chaque ligne pour récupérer les requêtes SQL.

Pour plus d'informations, consultez le MySQL 8.0 Reference Manual.

6\. SQL avec le binary log

Souvent négligé, le binary log MySQL — lorsqu'il est activé — est une mine d'informations sur les requêtes SQL effectuant des écritures sur votre base. Il peut s'avérer essentiel pour identifier les frontières de transaction et la séquence des requêtes SQL au sein d'une transaction, ce qui aide lors de l'analyse des verrous. Il fournit également les détails complets des colonnes pour les requêtes INSERT, UPDATE et DELETE.

Toute configuration d'instance RDS qui utilise des read replicas a la journalisation binaire activée par défaut.

Validation des paramètres

Pour confirmer que votre binary log est activé et configuré.

mysql> SELECT @@log_bin, @@binlog_format, @@log_statements_unsafe_for_binlog, @@log_bin_trust_function_creators;
+-----------+-----------------+------------------------------------+-----------------------------------+
| @@log_bin | @@binlog_format | @@log_statements_unsafe_for_binlog | @@log_bin_trust_function_creators |
+-----------+-----------------+------------------------------------+-----------------------------------+
|         0 | ROW             |                                  1 |                                 0 |
+-----------+-----------------+------------------------------------+-----------------------------------+

Vous pouvez identifier les binary logs disponibles sur votre instance MySQL avec :

mysql> SHOW BINARY LOGS;

Vous pouvez télécharger les binary logs avec la commande mysqlbinlog. Par exemple.

$ TMP_DIR=${TMP_DIR:-/tmp}
$ AUTHENTICATION="-h<host> -u<user> -p<password"
$ BINLOG_FILE="binlog.00042"
mysqlbinlog --read-from-remote-server --raw --result-file=${TMP_DIR}/ ${AUTHENTICATION} ${BINLOG_FILE} 2>/dev/null # Kill warning message and not mess with $?

Vous pouvez consulter le contenu du binary log avec la commande mysqlbinlog. Selon vos options de configuration, certains arguments seront plus pertinents, mais ce qui suit convient généralement à tous les formats :

$ mysqlbinlog -vvv --base64-output=DECODE-ROWS ${TMP_DIR}/${BINLOG_FILE}

L'analyse du binary log est un processus plus détaillé que nous n'aborderons pas ici. Cette analyse dépend également de la valeur de la variable de configuration définissant le format de ligne du binary log. Vous pouvez obtenir un récapitulatif par table pour un fichier donné, ou pour une période couvrant un ou plusieurs fichiers, à l'aide d'arguments supplémentaires. L'extrait suivant produit un récapitulatif par table lorsque binlog_format=ROW est utilisé.

mysqlbinlog ${BINLOG_ADDITIONAL_ARGS} ${TMP_DIR}/${BINLOG_FILE}  | \
  sed -e "s/^### //;" | \
  sed -e "/^#/d;s/\/\*.*\*\/[;]//;/^$/d" | \
  cut -c1-100 | \
  tr '[A-Z]' '[a-z]' | \
  egrep "^(insert|update|delete|replace|commit|alter|drop|create)" |  \
  sed -e "s/\t/ /g;s/\`//g;s/(.*$//;s/ set .*$//;s/ as .*$//;s/ join .*$//;s/ values .*$//;" | sed -e "s/ where .*$//;s/ignore //g;s/ inner//g;s/ left//g;s/ right//g;s/ from//g;s/ into//g" |  \
  sed -e "s/or replace//;s/sql security definer//;s/algorithm=.* //;s/definer=.* //g" |  \
  sed -e "s/ \w.*\.\*//" | \
  awk '{ print $1,$2 }' | \
  sort | uniq -c | sort -nr

Vous pouvez récupérer une copie du script complet — qui inclut le téléchargement et le traitement d'un fichier de binary log — depuis ce Github gist.

Pour plus d'informations, consultez le MySQL 8.0 Reference Manual.

Récapitulatif des options de collecte SQL

Voici les principaux avantages et limites de chaque option. La meilleure façon de déterminer celle qui correspond à vos besoins reste de toutes les essayer en suivant les étapes décrites dans cet article.

Avantages du Processlist

Activé par défaut

Limites du Processlist

Ne capture que les requêtes SQL en cours d'exécution
Nécessite des privilèges élevés pour voir toutes les requêtes de tous les utilisateurs

Avantages du Performance Schema

Capture les requêtes précédemment exécutées en plus de celles en cours d'exécution
Fournit des résultats agrégés, idéaux pour les requêtes à haute fréquence

Limites du Performance Schema

Doit être activé ; nécessite un redémarrage lors de la première activation
Demande un réglage fin sur les systèmes très performants pour limiter le surcoût en ressources

Avantages du Sys Schema

Étend le performance schema avec des vues et objets très exploitables, bien nommés et dédiés à des usages précis

Limites du Sys Schema

Nécessite que le performance schema soit activé

Avantages du slow query log

Capture toutes les requêtes lentes dépassant un temps d'exécution prédéfini

Limites du slow query log

Pas vraiment de limites. Il devrait toujours être activé avec un seuil approprié sur toutes les instances MySQL.

Avantages du general query log

Fournit la liste séquentielle complète de toutes les requêtes SQL. Idéal pour l'analyse de transactions et l'évaluation des antipatterns d'accès aux données.

Limites du general query log

Surcoût significatif sur des systèmes de production fortement sollicités. Il est recommandé de l'utiliser avec une suite de tests, idéalement en mono-thread.

Avantages du binary log

Généralement toujours activé pour assurer les capacités HA et PITR

Limites du binary log

Ne capture que les écritures lorsqu'il est activé
Format plus complexe à traiter pour récupérer les requêtes SQL complètes

Annexe

Données d'exemple utilisées

Pour cet article, nous avons utilisé le jeu de données airport disponible à l'adresse https://github.com/ronaldbradford/data/tree/main/mysql-data/airport

Requête SQL d'exemple

Pour chaque méthode de collecte, la requête SQL d'exemple suivante a été utilisée.

SELECT a.country_code, c.name, COUNT(*) AS cnt
FROM airport a
INNER JOIN country c USING (country_code)
GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10;

Cette requête SQL renvoie un ensemble de résultats du type :

+--------------+----------------+-------+
| country_code | name           | cnt   |
+--------------+----------------+-------+
| US           | United States  | 30581 |
| BR           | Brazil         |  6849 |
| JP           | Japan          |  3430 |
| CA           | Canada         |  3075 |
| AU           | Australia      |  2576 |
| MX           | Mexico         |  2288 |
| RU           | Russia         |  1556 |
| KR           | South Korea    |  1400 |
| GB           | United Kingdom |  1398 |
| DE           | Germany        |  1042 |
+--------------+----------------+-------+
10 rows in set (0.47 sec)

NOTE : le décompte exact des aéroports et l'ordre des pays peuvent varier selon la date à laquelle vous avez récupéré le jeu de données.

Collecte SQL

Comme il s'agit d'un système de test à usage minimal, certaines requêtes ont remonté toutes les lignes possibles, tandis que d'autres ont été restreintes par une clause WHERE permettant de cibler précisément cette requête SQL d'exemple. Lors de la capture SQL sur votre propre système, il vous faudra peut-être appliquer des filtres pertinents pour limiter le volume de sortie.

Fonction utilitaire Bash modify-parameter

La fonction suivante est utilisée dans cet article pour simplifier la syntaxe de modification des variables des parameter groups AWS RDS.

modify-parameter() {
  [[ $# -lt 3 ]] || [[ $# -gt 4 ]]  && echo "ERROR: <parameter-group> <parameter> <value> [pending-reboot]" && return 1

  local PARAMETER_GROUP="$1"
  local PARAMETER_NAME="$2"
  local PARAMETER_VALUE="$3"
  local APPLY_METHOD="immediate"

  [[ $# -eq 4 ]] && APPLY_METHOD="$4"
  aws rds modify-db-parameter-group --db-parameter-group-name ${PARAMETER_GROUP} --parameters "ParameterName=${PARAMETER_NAME},ParameterValue='${PARAMETER_VALUE}',ApplyMethod=${APPLY_METHOD}"
  aws rds describe-db-parameters --db-parameter-group-name ${PARAMETER_GROUP}  --query 'Parameters[] | [?ParameterName == `'${PARAMETER_NAME}'`]'
}

Pour plus d'informations, consultez la référence des commandes AWS CLI modify-db-parameter-group et describe-db-parameters.

Astuce d'identification SQL

MySQL permet d'embarquer un commentaire dans une requête SQL, mais tous les outils ne capturent ni ne journalisent cette information. Une bonne pratique côté engineering consiste à créer un identifiant unique pour chaque requête SQL. Le contenu du commentaire importe peu : c'est son unicité qui compte. Pouvoir voir une requête avec son commentaire et la localiser dans le code source réduit le temps d'identification et le mean-time-to-resolve (MTTR) des incidents.

SELECT /* Countries with the most airports */
       a.country_code, c.name, COUNT(*) AS cnt
FROM   airport a
INNER JOIN country c USING (country_code)
GROUP BY country_code, name
ORDER BY 3 DESC LIMIT 10;

Pour plus d'informations, consultez le MySQL 8.0 Reference Manual.

Il existe plusieurs méthodes natives, via les outils clients MySQL, pour collecter les requêtes SQL d'une instance MySQL hébergée sur AWS RDS. D'autres outils et techniques permettent également de collecter des requêtes SQL dans MySQL, mais ne seront pas abordés dans cet article.

La collecte d'une requête SQL est la première étape essentielle pour rassembler suffisamment d'informations sur les schémas d'accès aux données de votre application. Ces informations peuvent être déterminantes pour la conception architecturale, les tests et l'analyse de performance.

Dans un prochain article, j'aborderai la collecte des métadonnées complémentaires nécessaires à toute analyse de performance d'une requête SQL : plan d'exécution (QEP), métadonnées de tables et d'index, statistiques de distribution des colonnes, et options de configuration spécifiques susceptibles d'influencer l'exécution d'une requête SQL.