Cloud Intelligence™

SQL-Statements mit AWS RDS MySQL erfassen

By Ronald BradfordNov 9, 202321 min read

Diese Seite ist auch in English, Español, Français, Italiano, 日本語 und Português verfügbar.

SQL-Statements mit RDS MySQL erfassen

In diesem Artikel zeige ich alle nativen Möglichkeiten von MySQL, um SQL-Statements unter AWS Relational Database Service (RDS) zu erfassen. Das Identifizieren von SQL-Statements ist ein zentrales Design- und Betriebsprinzip, um Anwendungsnutzung, Last, Performance-Auswirkungen und Konfigurationsengpässe der Datenbank zu verstehen.

Ziel dieses Artikels ist es zu zeigen, wie sich Informationen zu SQL-Statements "erfassen" lassen. Auf zusätzliche Begleitinformationen, die Sie zu einem SQL-Statement gewinnen können, gehe ich hier nicht ein. Dazu zählen unter anderem der Query Execution Plan (QEP), die Tabellenstruktur, die Index-Kardinalität, die Optimizer-Konfiguration und Statistiken. Diese Themen behandle ich in einem späteren Beitrag.

SQL-Statements sammeln

MySQL bietet mehrere Möglichkeiten, gerade laufende oder bereits ausgeführte SQL-Statements zu erfassen. Keine Methode ist allen anderen überlegen, und oft braucht es mehrere Verfahren parallel, um genug Informationen für eine fundierte Beobachtbarkeit des Systems und eine tiefergehende Analyse von SQL-Statements zu gewinnen. Folgende Methoden stehen zur Auswahl, wobei jede wiederum mehrere Wege bietet, dieselben Details abzurufen.

Processlist
Performance Schema
Sys Schema
Slow Query Log
General Query Log
Binary Log

Sofern nicht anders angegeben, wird in den folgenden Beispielen der mysql-Kommandozeilenclient verwendet.

HINWEIS: Die hier gezeigten SQL-Beispiele sind sowohl mit MySQL 5.7 als auch mit MySQL 8.0 kompatibel. Wegen des End-of-Life (EOL) der Community Edition von MySQL 5.7 sowie des bevorstehenden EOL von AWS RDS MySQL 5.7 beziehen sich alle Beispielausgaben und Dokumentationsverweise auf die aktuelle Version MySQL 8.0. Manche Ausgaben in diesem Artikel können sich von denen unter MySQL 5.7 unterscheiden.

1\. SQL über die MySQL Processlist

Die MySQL Processlist zeigt die aktuell laufenden SQL-Statements – also jene, die zum Zeitpunkt der Ausführung des Processlist-Befehls gerade verarbeitet werden. Bei lang laufenden Abfragen ist das ein einfacher Weg, SQL-Statements aufzuspüren. Bei hochfrequenten, schnell abgeschlossenen Statements ist die Beobachtung über die MySQL Processlist hingegen schwierig. Neben dem ausgeführten SQL-Statement erhalten Sie Angaben zu Quelluser und -host, dem genutzten Datenbankschema, der Ausführungszeit (in Sekunden) und dem aktuellen internen Status der Abfrage.

Die Ausgabe der MySQL Processlist lässt sich auf folgenden Wegen abrufen:

Performance Schema
Sys Schema
Information Schema
SHOW-Statement
mysqladmin-Kommando

Liefern die Ausgaben dieselben Spalten, gibt es keinen besonderen Vorteil einer Variante gegenüber den anderen. Einige davon waren in älteren MySQL-Versionen nicht verfügbar und wurden ergänzt, um den allgemein anerkannten Industriestandards in Form gültiger ISO-SQL-Statements zu entsprechen – was bei SHOW nicht der Fall ist. Das Kommando mysqladmin bietet weitere administrative Optionen und erlaubt die Kombination mehrerer Ausgaben, wie das Beispiel zeigt.

Processlist über das Performance Schema

Wenn aktiviert, liefern die Tabellen threads und processlist des performance_schema diese Informationen.

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                                                                                                                              |
+-----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+

Weitere Informationen finden Sie im MySQL 8.0 Reference Manual.

Processlist über das Sys Schema

Die Views processlist und session im Sys Schema bieten Zugriff auf SQL-Statements und ergänzende Informationen. Sie setzen auf dem Performance Schema auf, das aktiviert sein muss, damit über das Sys Schema SQL erfasst werden kann. Außerdem liefern diese Views weitere Metadatenattribute zum SQL-Statement. Hier ein Beispiel mit der View 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

Der Statement-Terminator oben erzeugt ein vertikales Tabellenformat – also "Spalte: Wert" pro Zeile – statt des klassischen horizontalen Formats mit Spalten und Zeilen. Dafür kommt hier der SQL-Statement-Terminator ‘\G’ statt des üblichen Semikolons ‘;’ zum Einsatz. Diese Syntax ist spezifisch für den mysql-Client und wird von anderen GUI-Clients von Drittanbietern nicht unterstützt.

HINWEIS: Wenn Sie folgende Fehlermeldung erhalten, können Sie vor dem obigen SQL-Statement bedenkenlos SET SQL_BIG_SELECTS=1; ausführen.

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

Weitere Informationen finden Sie im MySQL 8.0 Reference Manual.

Processlist über das Information Schema

Das Information Schema ist in vielen RDBMS-Produkten ein De-facto-Standard, die Tabelle processlist jedoch nicht. In MySQL rufen Sie diese Informationen mit folgendem Statement ab.

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                                                                                                                                                                      |
+----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+

Weitere Informationen finden Sie im MySQL 8.0 Reference Manual.

Processlist über SHOW-Statement

Bevor mit Version 5.1 das Information Schema und mit Version 5.5 das Performance Schema eingeführt wurden, war das SHOW-Kommando das wichtigste Mittel, um die Processlist in MySQL abzufragen.

mysql> SHOW FULL PROCESSLIST;

Das Ergebnis ist identisch mit dem oben gezeigten SELECT * FROM performance_schema.processlist;. Das Schlüsselwort FULL ist nötig, damit Statements nicht abgeschnitten werden.

Weitere Informationen finden Sie im MySQL 8.0 Reference Manual.

Processlist über den _mysqladmin_-Client

Auch das zusätzliche MySQL-Clienttool mysqladmin, das verschiedene administrative Aufgaben übernimmt, kann eine laufende Processlist in tabellarischer Form ausgeben.

$ 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

Ohne --verbose erhalten Sie abgeschnittene SQL-Statements, selbst bei diesem kurzen Beispiel:

| 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 |

Weitere Informationen finden Sie im MySQL 8.0 Reference Manual.

2\. SQL über das Performance Schema

Sind das Performance Schema und die passenden Consumer aktiviert, lassen sich über mehrere Tabellen detaillierte Informationen zu ausgeführten und gerade laufenden SQL-Statements gewinnen.

Konfigurationsoptionen

Im nativen MySQL aktivieren Sie das Performance Schema wie folgt.

mysql> SET GLOBAL performance_schema=1;

Im Managed Service AWS RDS müssen Parameteränderungen über Parameter Groups erfolgen. Beispiel:

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

HINWEIS: Bei einer RDS-Instanz ist damit die Instance Parameter Group gemeint. Gehört die Instanz zu einem AWS RDS Aurora Cluster, gibt es eine Cluster Parameter Group, die standardmäßig greift, sofern die Werte nicht durch die Instance Parameter Group überschrieben werden.

Wird das Performance Schema erstmals aktiviert, muss die MySQL-Instanz – und damit die AWS-RDS-Instanz – neu gestartet werden.

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

Die Performance-Schema-Consumer und -Instruments für die SQL-Erfassung sind standardmäßig aktiv, lassen sich aber bei laufender MySQL-Instanz anpassen. Die aktuelle Konfiguration prüfen Sie so:

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

Einstellungen prüfen

Mit folgendem Statement prüfen Sie, ob das Performance Schema aktiviert ist.

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

Performance-Schema-Tabelle processlist

Wie zuvor gezeigt, liefert die Tabelle processlist Basisinformationen zu den aktuell laufenden Statements.

Performance-Schema-Tabelle threads

Die Tabelle threads zeigt zusätzliche Attribute zu den aktuell laufenden SQL-Statements.

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

Performance-Schema-Tabellen events_statements_*

Die wahre Stärke des Performance Schema liegt darin, kürzlich ausgeführte SQL-Statements zu erfassen – ein unverzichtbares Werkzeug bei sehr schnell ablaufenden Statements.

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)

Weitere Performance-Tabellen mit ausgeführten SQL-Statements sind unter anderem events_statements_current, events_statements_history und events_statements_long. Weitere Informationen finden Sie im MySQL 8.0 Reference Manual.

3\. SQL über das Sys Schema

Das MySQL Sys Schema ist eine Sammlung von Objekten und Views, die die Daten des Performance Schema interpretieren und in einer benutzerfreundlicheren Form aufbereiten. Auch hier sehen Sie ausgeführte SQL-Statements sowie aggregierte Statistiken zu deren Ausführungen. Die erste interessante View ist statement_analysis bzw. 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

Viele weitere Sys-Schema-Tabellen enthalten ausgeführte SQL-Statements und Aggregationen bestimmter Teilmengen davon. Beispiele sind statements_with_full_table_scans und statements_with_temp_tables. Weitere Informationen finden Sie im MySQL 8.0 Reference Manual.

4\. SQL über das Slow Query Log

Wenn aktiviert, tut das Slow Query Log genau das, was sein Name verspricht: Es protokolliert alle Abfragen, die länger als eine vordefinierte Ausführungszeit dauern. In älteren Versionen war diese Zeit in Sekunden angegeben, ab MySQL 5.7 in Mikrosekunden. Auch der Wert 0 ist gültig und bedeutet, dass alle ausgeführten SQL-Statements protokolliert werden. Das ist allerdings mit Performance-Overhead und zusätzlichen Kosten in stark frequentierten Datenbanken verbunden.

Konfigurationsoptionen

Im nativen MySQL aktivieren Sie das Slow Query Log mit:

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 */

Im Managed Service AWS RDS erfolgen Parameteränderungen über Parameter Groups. Diese Änderungen greifen sofort. Beispiel:

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

Es gibt einige weitere Konfigurationsparameter, auf die wir hier nicht eingehen, darunter slow_query_log_file, log_queries_not_using_indexes und log_slow_admin_statements.

HINWEIS: Wägen Sie die Auswirkungen dieser zusätzlichen Slow-Query-Log-Optionen sorgfältig ab. Jede einzelne kann große Mengen an SQL-Statements erzeugen und so die Logfile-Größe in die Höhe treiben. Auch Abfragen, die wegen geringer Zeilenzahlen bewusst einen Full Table Scan durchführen, oder häufige administrative Statements, die für Instrumentierung und Beobachtbarkeit durch Monitoring-Tools nötig sind, können dadurch protokolliert werden.

Einstellungen prüfen

So prüfen Sie, ob Ihr Slow Query Log aktiviert und konfiguriert ist:

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

Weitere Informationen finden Sie im MySQL 8.0 Reference Manual.

Slow Query Log aus AWS RDS herunterladen

Wenn aktiviert, schreibt das Slow Query Log in eine Logdatei auf Ihrer RDS-Instanz. Diese rufen Sie mit der AWS CLI ab.

$ 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

Die RDS-Slow-Log-Dateien werden stündlich rotiert. Mit folgendem Befehl listen Sie alle zum Download verfügbaren Logdateien auf:

$ 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\
        }\
    ]
}

Verfügbare Informationen im Slow Query Log

Ein einzelnes SQL-Statement im Slow Query Log enthält folgende Informationen:

Ausführungszeitpunkt
User und Host
Thread-ID
Query-Zeit
Lock-Zeit
Gesendete Zeilen (Rows sent)
Untersuchte Zeilen (Rows examined)
Vollständiges SQL-Statement

Beispielausgabe 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;

HINWEIS: Das Slow Query Log ist klar strukturiert: Alle nicht auskommentierten Zeilen sind tatsächliche SQL-Statements und korrekt mit Statement-Terminator versehen. So lassen sich diese Statements sehr einfach sammeln, protokollieren und erneut ausführen. Einzige Einschränkung: Sind Tabellen nicht mit dem Schema qualifiziert, müssen Sie das Datenbankschema Ihrer Tabellen kennen.

Slow Query Log über SQL-Tabelle

Auch wenn nicht generell empfohlen, lassen sich Slow Queries per SQL-Statement erfassen, sofern das Slow Query Log aktiv ist und die Konfiguration log_output=TABLE gesetzt ist.

SQL-basierter Abruf der Slow-Query-Log-Informationen

Mit folgendem SQL-Statement rufen Sie die Abfragen ab, die in der Tabelle mysql.slow_log protokolliert wurden.

# 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

Beispielausgabe Slow Query Log über Tabelle

    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 über das General Query Log

Bei entsprechender Konfiguration kann MySQL alle SQL-Statements im General Query Log protokollieren.

HINWEIS: Überlegen Sie sich gut, in welcher Umgebung und für wie lange Sie das General Query Log aktivieren. Das folgende Beispiel stammt aus einem zu 100 % im Leerlauf befindlichen System – und enthält dennoch 12 zusätzliche SQL-Statements, die innerhalb derselben Sekunde wie unser Beispiel-Statement ausgeführt wurden.

WARNUNG: Wie beim Slow Query Log lässt sich auch diese Ausgabe in eine MySQL-Tabelle schreiben. Davon ist abzuraten, da es die Performance eines laufenden Systems erheblich beeinträchtigen kann.

Konfigurationsoptionen

Im nativen MySQL aktivieren Sie das General Query Log mit:

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

Im Managed Service AWS RDS erfolgen Parameteränderungen über Parameter Groups. Diese Änderungen greifen sofort. Beispiel:

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

Auf einen weiteren Konfigurationsparameter gehen wir hier nicht ein: die Variable general_log_file.

Einstellungen prüfen

So prüfen Sie, ob Ihr General Query Log aktiviert und konfiguriert ist:

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

Weitere Informationen finden Sie im MySQL 8.0 Reference Manual.

General Query Log aus AWS RDS herunterladen

Wenn aktiviert, schreibt das General Query Log in eine Logdatei auf Ihrer RDS-Instanz. Diese rufen Sie mit der AWS CLI ab.

$ 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

Wie im vorherigen Abschnitt erwähnt, listen Sie mit dem Argument describe-db-log-files die rotierten General-Query-Log-Dateien auf.

Beispielausgabe 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

HINWEIS: Das General Query Log ist nur halb-strukturiert. SQL-Statements können sich über mehrere Zeilen erstrecken und behalten das Format, in dem Ihr Client sie an MySQL übergibt. Es reicht daher nicht, einfach die ersten 41 Zeichen jeder Zeile abzuschneiden, um SQL-Statements zu extrahieren.

Weitere Informationen finden Sie im MySQL 8.0 Reference Manual.

6\. SQL über das Binary Log

Oft übersehen, ist das MySQL Binary Log – sofern aktiviert – eine wahre Fundgrube an SQL-Statements für all jene Abfragen, die schreibend auf Ihre Datenbank zugreifen. Es kann entscheidend sein, um Transaktionsgrenzen und die Reihenfolge von SQL-Statements innerhalb einer Transaktion nachzuvollziehen, etwa bei der Analyse von Locking. Außerdem liefert das Binary Log die vollständigen Spaltendetails von INSERT-, UPDATE- und DELETE-Statements.

Jede RDS-Instanzkonfiguration mit Read Replicas hat das Binary Logging standardmäßig aktiviert.

Einstellungen prüfen

So prüfen Sie, ob Ihr Binary Log aktiviert und konfiguriert ist:

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 |
+-----------+-----------------+------------------------------------+-----------------------------------+

Die auf Ihrer MySQL-Instanz verfügbaren Binary Logs ermitteln Sie mit:

mysql> SHOW BINARY LOGS;

Die Binary Logs laden Sie mit dem Befehl mysqlbinlog herunter. Beispiel:

$ 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 $?

Den Inhalt des Binary Logs zeigen Sie ebenfalls mit mysqlbinlog an. Je nach Konfiguration sind unterschiedliche Argumente sinnvoll – diese Variante eignet sich aber generell für alle Formate:

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

Die Analyse des Binary Logs ist ein komplexerer Vorgang, den wir hier nicht im Detail behandeln. Sie hängt zudem vom Wert der Konfigurationsvariable für das Binary-Log-Row-Format ab. Mit zusätzlichen Argumenten lassen sich Tabellenübersichten für eine einzelne Datei oder einen Zeitraum mit mehreren Dateien erstellen. Folgendes Snippet liefert eine Tabellenübersicht bei binlog_format=ROW:

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

Das vollständige Skript inklusive Download und Verarbeitung einer Binary-Log-Datei finden Sie in diesem GitHub Gist.

Weitere Informationen finden Sie im MySQL 8.0 Reference Manual.

Überblick: Optionen zur SQL-Erfassung

Hier die wichtigsten Vorteile und Einschränkungen jeder Option im Überblick. Welche für Sie die richtige ist, finden Sie am besten heraus, indem Sie sie nach den in diesem Artikel beschriebenen Schritten ausprobieren.

Vorteile der Processlist

Standardmäßig aktiviert

Einschränkungen der Processlist

Erfasst nur SQL-Statements, die gerade ausgeführt werden
Erweiterte Berechtigungen erforderlich, um alle Abfragen aller User zu sehen

Vorteile des Performance Schema

Erfasst zusätzlich zu laufenden auch zuvor ausgeführte Statements
Liefert aggregierte Ergebnisse – ideal für hochfrequente Abfragen

Einschränkungen des Performance Schema

Muss aktiviert werden; bei Erstaktivierung ist ein Neustart erforderlich
In stark beanspruchten Systemen ist Tuning nötig, um den Ressourcen-Overhead zu begrenzen

Vorteile des Sys Schema

Erweitert das Performance Schema um sehr gut benannte, gut nutzbare Views und Objekte für konkrete Anwendungsfälle

Einschränkungen des Sys Schema

Setzt voraus, dass das Performance Schema aktiviert ist

Vorteile des Slow Query Log

Erfasst alle langsamen Abfragen, die eine vordefinierte Ausführungszeit überschreiten

Einschränkungen des Slow Query Log

Eigentlich keine. Es sollte in jeder MySQL-Instanz mit einem geeigneten Schwellenwert dauerhaft aktiviert sein.

Vorteile des General Query Log

Liefert eine vollständige, sequenzielle Liste aller SQL-Statements – ideal für Transaktionsanalysen und das Aufspüren von Antipatterns beim Datenzugriff.

Einschränkungen des General Query Log

Erheblicher Overhead in stark genutzten Produktivsystemen. Empfohlen ist der Einsatz mit einer Test-Suite, idealerweise im Single-Thread-Betrieb.

Vorteile des Binary Log

In der Regel ohnehin aktiviert, um HA- und PITR-Funktionen sicherzustellen

Einschränkungen des Binary Log

Erfasst, sofern aktiviert, ausschließlich Schreibzugriffe
Komplexeres Format bei der Verarbeitung vollständiger SQL-Statements

Anhang

Verwendete Beispieldaten

Für diesen Artikel haben wir den folgenden Airport-Datensatz verwendet, verfügbar unter https://github.com/ronaldbradford/data/tree/main/mysql-data/airport.

Verwendetes Beispiel-SQL

Für jede Erfassungsmethode wurde dasselbe SQL-Beispiel verwendet:

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;

Dieses SQL-Statement liefert ein Ergebnis wie folgt:

+--------------+----------------+-------+
| 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)

HINWEIS: Die tatsächlichen Flughafenzahlen und die Reihenfolge der Länder können je nach Zeitpunkt des Datenabrufs variieren.

SQL-Erfassung

Da es sich um ein Testsystem mit minimaler Last handelt, geben einige Statements alle möglichen Zeilen zurück, während andere mit einer WHERE-Klausel gezielt auf das Beispiel-Statement eingegrenzt sind. Wenn Sie SQL-Statements in Ihrem System erfassen, müssen Sie ggf. passende Filterbedingungen einsetzen, um die Ausgabe einzugrenzen.

Bash-Hilfsfunktion modify-parameter

Folgende Funktion vereinfacht in diesem Artikel die Syntax für das Anpassen von Variablen in AWS-RDS-Parameter-Groups.

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}'`]'
}

Weitere Informationen finden Sie in der AWS-CLI-Referenz zu modify-db-parameter-group und describe-db-parameters.

Tipp zur SQL-Identifikation

MySQL erlaubt es, Kommentare in SQL-Statements einzubetten – allerdings erfassen und protokollieren nicht alle Tools diese Information. Es hat sich im Engineering bewährt, jedem SQL-Statement eine eindeutige Kennung mitzugeben. Der konkrete Inhalt des Kommentars ist dabei nicht entscheidend, sondern seine Eindeutigkeit. Wer eine Abfrage anhand des Kommentars im Quellcode wiederfindet, verkürzt die Identifikationszeit und die Mean Time to Resolve (MTTR) im Fehlerfall deutlich.

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;

Weitere Informationen finden Sie im MySQL 8.0 Reference Manual.

Es gibt mehrere native Möglichkeiten, mit MySQL-Clienttools SQL-Statements aus einer auf AWS RDS laufenden MySQL-Instanz zu erfassen. Daneben existieren weitere Tools und Techniken, die in diesem Artikel nicht behandelt werden.

Das Erfassen eines SQL-Statements ist der erste, unverzichtbare Schritt, um aus Ihrer Anwendung ausreichend Informationen über Datenzugriffsmuster zu gewinnen. Diese Informationen sind essenziell für Architekturentscheidungen, Tests und Performance-Analysen.

In einem Folgeartikel gehe ich darauf ein, wie sich die zu jedem SQL-Statement nötigen Begleitmetadaten für eine Performance-Analyse erfassen lassen. Dazu zählen der Query Execution Plan (QEP), Tabellen- und Indexmetadaten, Spaltenverteilungsstatistiken sowie spezifische Konfigurationsoptionen, die die Ausführung eines SQL-Statements beeinflussen können.