Mittlerweile gibt es unterschiedliche Werkzeuge, um Performance-Probleme in MySQL aufzudecken. Nicht immer stehen diese jedoch ad hoc bei unseren Analysen auf Kundensystemen zur Verfügung. Zwar ist beispielsweise das „performance_schema" in den aktuellen MySQL-Version per default aktiviert, jedoch nutzen viele unser Kunden noch ältere MySQL-Versionen, wo dies nicht der Fall war. Zum Glück gibt es aber aber auch etablierte, althergebrachte Werkzeuge, die unmittelbar genutzt werden können und immer noch gute Dienste leisten.

Mach mal langsam:  Slow Query Log

Die Aufgabe des Slow Query Log (slow_query_log) besteht darin, langlaufende SQL-Statements zu protokollieren. Über den Parameter „long_query_time" kann dabei definiert werden, ab wie vielen Sekunden eine Query als „langsam" interpretiert wird. Zusätzlich können auch noch einige weitere Einstellungen vorgenommen werden. So kann beispielsweise dafür gesorgt werden, dass SQL-Statements generell protokolliert werden, wenn diese keinen Index benutzen („log_queries_not_using_indexes").

Eine vollständige Liste von weiteren Konfigurationsmöglichkeiten des Slow Query Logs finden Sie hier: https://dev.mysql.com/doc/refman/8.0/en/slow-query-log.html

Immer schön flexibel bleiben!

Besonders schön ist die Tatsache, dass alle relevanten Parameter des Slow Query Logs online (also ohne Neustart des Servers) zu konfigurieren sind. Dies erlaubt eine unverzügliche Aktvierung der Parameter, um mit der Sammlung von Statements direkt beginnen zu können.

Ab diesem Moment werden Statements dokumentiert, die länger laufen als 0.001 Sekunden. Dieser Schwellwert ist natürlich extrem niedrig und dient hier nur zur Veranschaulichung. In der Praxis muss diese Metrik mit den erwarteten Antwortzeiten der Applikation abgestimmt werden. Per default landen diese in einem Logfile im Datenbankverzeichnis („ac45b902f5d7" ist in diesem Fall der Hostname in unserem MySQL-Docker-Container).

Dies kann natürlich anders konfiguriert werden. Im Prinzip können die Informationen auch in eine Systemtabelle „mysql.slow_log" geschrieben werden. Dazu muss der Parameter „log_output" auf „table" gesetzt werden. In unserem Fall wäre dies jedoch kontraproduktiv, da unser Auswertungswerkzeug im nächsten Schritt ausschließlich mit Log-Dateien arbeitet.

Keinem zur Last fallen.

Nachdem wir das Slow Query Log mit sehr niedrigen Schwellwerten konfiguriert haben, sorgen wir nun dafür, dass wir ein paar Daten (Langläufer) generieren. Wir nutzen dafür die MySQL-Beispiel-Datenbank „sakila". Sie kann über die folgende URL bezogen werden:

https://dev.mysql.com/doc/sakila/en/sakila-installation.html

Zusätzlich nutzen wir einige Beispiel-Queries, die von Joel Sotelo (joelsotelods) über GitHub bereit gestellt wurden.

https://github.com/joelsotelods/sakila-db-queries

Die entsprechenden Statements haben wir mehrere Minuten in einer Endlosschleife (Shell) gegen die MySQL-Datenbank ausgeführt, um ein paar MB an Daten im Slow Query Log zu erzeugen.

Diese Daten sollen nun ausgewertet werden.

Wer suchet, der findet…

MySQL liefert mit dem Werkzeug „mysqldumpslow" ein sehr geeignetes Werkzeug, um die Daten aus dem Slow Query Log auszuwerten. Generell aggregiert „mysqldumpslow" gleichartige Statements und gibt das Ergebnis sortiert zurück. Zusätzlich lassen sich bei der Analyse einige Filter definieren (Größe der Ergebnismenge oder bestimmte Pattern im SQL-Statement; z.b. Tabellennamen o.ä.). Bei der Aggregation von Statements werden Strings und numerische Werte „standardisiert".

So werden die folgenden drei SELECTs beispielsweise in der Auswertung zusammengefasst (Ausgaben vereinfacht):

Auf Wunsch kann aber auch dieses Verhalten verändert werden.

Die Ausgaben können nach vier Kriterien sortiert dargestellt werden:

• Laufzeit der Statements
• Sperrzeit (Locks) der Statements
• gesendete Ergebnismengen (Anzahl von Datensätzen) der Statements
• Häufigkeit der Ausführung von Statements

Dabei kann bei jedem Parameter gewählt werden, ob dies nach dem maximalen oder durchschnittlichen Wert für die Statements erfolgen soll.

Im oben stehenden Beispiel wurden die Ergebnisse des Logs nach der durchschnittlichen Laufzeit der SQLs sortiert (-a at; Average Time) und bei der Ergebnismenge auf die TOP 3 Queries begrenzt (-t 3).

Eine Übersicht über das Tool „mysqldumpslow" und alle möglichen Parameter finden Sie hier:

https://dev.mysql.com/doc/refman/5.7/en/mysqldumpslow.html

Fazit: Oldie but Goldie

Natürlich gibt es heute schönere Wege, um problematische Statements in einer MySQL-Datenbank zu finden (z.B: das „performance_schema"). Trotzdem erfüllt das Slow Query Log immer noch für viele Kunden seinen Sinn (gerade bei älteren Installationen). Es kann unkompliziert (online) aktiviert und direkt ausgewertet werden (auch für spezifische Zeiträume; z.B. während einer bestimmten Verarbeitung der Applikation). Darüber hinaus können alle Einstellungen wahlweise serverweit (global) oder auch nur für die eigene Session (local) konfiguriert werden.