Wie man MySQL-Probleme mit pt-stalk und pt-query-digest identifiziert

Das Percona Toolkit ist eine Sammlung fortschrittlicher Kommandozeilen-Tools, entwickelt und gepflegt von Percona. Diese Tools sind für Datenbankadministratoren, Entwickler und Systemadministratoren gedacht, die MySQL-Systeme über die Kommandozeile mit einfach verfügbaren GUI-Tools verwalten müssen.

Besonders hervorzuheben sind zwei Tools aus dem Percona Toolkit: pt-stalk und pt-query-digest.

pt-stalk: pt-stalk ist ein unverzichtbares Tool für proaktives Monitoring und Troubleshooting von Datenbanken. Es ist besonders nützlich, um Leistungsprobleme in MySQL-Datenbanken zu entdecken und zu diagnostizieren. Pt-stalk erfasst Diagnosedaten wie Linux-Systemstatistiken, SHOW ENGINE INNODB STATUS, SHOW OPEN TABLES und andere in regelmäßigen Abständen oder wenn bestimmte Bedingungen erfüllt sind (z.B. Aborted Connections). Dieses Tool zeichnet den Zustand der Datenbank auf, sobald vordefinierte Schwellenwerte oder Ereignisse eintreten, was eine präzise Problemanalyse ermöglicht.

pt-query-digest: pt-query-digest ist ein unverzichtbares Tool zur Analyse und Optimierung von SQL-Abfragen in MySQL-Datenbanken. Es fungiert als Lastanalyse- und Leistungsbericht-Tool für MySQL. pt-query-digest analysiert die Ausführungszeiten von Abfragen sowie die Nutzung von Indizes und verwendet Abfragen aus der Slow Query Log-Datei, um Ergebnisse zu erzielen. Es bietet wertvolle Einblicke in Abfragemuster und hilft Administratoren, fundierte Entscheidungen zur Leistungsoptimierung der Datenbank im Kontext ihrer Anwendung zu treffen.

Mit diesen leistungsstarken Tools können MySQL-Engpässe effektiv identifiziert und behoben werden, was zu einer signifikanten Verbesserung der Datenbankleistung führt. Das richtige Verständnis und die Anwendung von pt-stalk und pt-query-digest sind entscheidend für jeden, der das Maximum aus seiner MySQL-Datenbank herausholen möchte.

pt-stalk Übersicht:

Pt-stalk wird verwendet, um während der Fehlersuche Informationen über MySQL/MariaDB und das O zu sammeln, da es manchmal nicht ausreicht, nur die Fehlermeldungen zu haben. Es bietet zwei Betriebsmodi:

Daemon-Modus: pt-stalk kann als Daemon ausgeführt werden, der auf eine bestimmte Bedingung wartet, um dann Informationen zu sammeln.
Sofortige Ausführung: Das Tool kann sofort ausgeführt werden, um alle notwendigen Daten unmittelbar zu sammeln.

Um pt-stalk sofort ohne eine Trigger-Option auszuführen, verwenden Sie den folgenden Befehl. In diesem Fall werden alle Daten im Ordner /tmp/pt-stalk gesammelt:

pt-stalk --iterations=1 --no-stalk --dest=/tmp/pt-stalk

Im Daemon-Modus kann pt-stalk so konfiguriert werden, dass es auf eine bestimmte Bedingung wartet, bevor es beginnt, Daten zu sammeln. Im folgenden Beispiel wird pt-stalk angewiesen, zu warten, bis der globale Status "threads_running " den Schwellenwert von 100 erreicht. Sobald dies geschieht, beginnt es mit der Datenerfassung:

pt-stalk --function=status --variable=Threads_running --threshold=100 --cycles=5 --interval=1 --iterations=2 --dest=/tmp/pt-stalk --daemonize --user=root --ask-pass

Mit diesen Optionen kann pt-stalk flexibel auf verschiedene Szenarien reagieren und stellt sicher, dass alle relevanten Daten für eine gründliche Analyse verfügbar sind.

Kommandooptionen:

--function=status:
Überwacht eine MySQL-Statusvariable.

--variable=Threads_running:
Threads_running repräsentiert die Anzahl der Threads, die derzeit in MySQL ausgeführt werden.

--threshold=100:
Die Datenerfassung wird ausgelöst, wenn die Variable Threads_running den Wert 100 überschreitet.

--cycles=5:
pt-stalk überprüft die Variable Threads_running fünfmal, bevor entschieden wird, ob die Datenerfassung ausgelöst wird.

--interval=1:
Es gibt ein 1-Sekunden-Intervall zwischen jeder der fünf Überprüfungen.

--iterations=2:
Der Überwachungs- und potenzielle Auslöseprozess wird zweimal wiederholt.

--dest=/tmp/pt-stalk:
Alle von pt-stalk gesammelten Daten werden im Verzeichnis /tmp/pt-stalk gespeichert.

--daemonize:
Ermöglicht pt-stalk, kontinuierlich im Hintergrund zu laufen, den MySQL-Server zu überwachen und bei Bedarf Daten zu sammeln, ohne das Terminal zu blockieren.

pt-stalk kann auch die Prozessliste überwachen oder sogar benutzerdefinierten Code ausführen. Die gesammelten Informationen können während der Fehlersuche verwendet werden.

Die Funktionalität von pt-stalk kann erweitert werden. Mit der Option ”--plugin” können benutzerdefinierte Funktionen implementiert werden, um das Tool an spezielle Anforderungen anzupassen.

before_stalk() {
  :
}


before_collect() {
    # $EXT_ARGV contains access credentials
    (mysql $EXT_ARGV -e 'show master logs' > /tmp/master-logs) &
}


after_collect() {
  :
}


after_collect_sleep() {
  :
}


after_stalk() {
  :
}

Wir können auch ein Bash-Skript mit der Option “--function” verwenden, um weitere Informationen zu erhalten. Zum Beispiel:

pt-stalk --function=additional-metrics.sh --function=status --variable=Threads_running --threshold=100 --cycles=5 --interval=1 --iterations=2 --dest=/tmp/pt-stalk --user=root --ask-pass

Hierbei kann “additional-metrics.sh” beliebige zusätzliche Funktionalitäten enthalten, um weitere Daten zu erfassen.

Verwenden Sie die Option "--collect-strace," um umfassende Diagnosedaten zu sammeln. Diese Option erfasst umfangreiche Metriken sowohl für MySQL als auch für das OS und bietet somit eine detaillierte Momentaufnahme, die bei der Fehlersuche hilfreich ist.

Durch die Kombination dieser erweiterten Funktionen mit den Standardoptionen von pt-stalk können Sie eine noch präzisere und detailliertere Analyse Ihrer MySQL-Datenbank durchführen. Dies erhöht die Effizienz der Fehlerbehebung und optimiert die Leistung Ihrer Datenbank erheblich.

# pt-stalk --user root --password='Root@123' --variable Threads_running --threshold 1 --cycles 1 --interval 1 --collect-strace --dest=/pt-stalk/log
mysql: [Warning] Using a password on the command line interface can be insecure.
Overwriting PID file /var/run/pt-stalk.pid because its PID (63917) is not running
2024_05_28_08_58_03 Starting /opt/homebrew/Cellar/percona-toolkit/3.5.5_2/libexec/bin/pt-stalk --function=status --variable=Threads_running --threshold=1 --match= --cycles=1 --interval=1 --iterations= --run-time=30 --sleep=300 --dest=/pt-stalk/log --prefix= --notify-by-email= --log=/var/log/pt-stalk.log --pid=/var/run/pt-stalk.pid --plugin=
mysqladmin: [Warning] Using a password on the command line interface can be insecure.
2024_05_28_08_58_03 Check results: status(Threads_running)=2, matched=yes, cycles_true=1
2024_05_28_08_58_03 Collect 1 triggered
2024_05_28_08_58_03 Collect 1 PID 66376
2024_05_28_08_58_03 Collect 1 done
2024_05_28_08_58_03 Sleeping 300 seconds after collect
mysqladmin: [Warning] Using a password on the command line interface can be insecure.
2024_05_28_09_03_03 Check results: status(Threads_running)=2, matched=yes, cycles_true=1
2024_05_28_09_03_03 Collect 2 triggered
2024_05_28_09_03_03 Collect 2 PID 68035
2024_05_28_09_03_03 Collect 2 done
2024_05_28_09_03_03 Sleeping 300 seconds after collect
mysqladmin: [Warning] Using a password on the command line interface can be insecure.
2024_05_28_09_08_03 Check results: status(Threads_running)=2, matched=yes, cycles_true=1
2024_05_28_09_08_03 Collect 3 triggered
2024_05_28_09_08_03 Collect 3 PID 69566
2024_05_28_09_08_03 Collect 3 done
2024_05_28_09_08_03 Sleeping 300 seconds after collect

Alle Ausgabedateien werden im Verzeichnis gespeichert, das mit der Option --dest angegeben wird. Die Dateien sind in Unterverzeichnissen organisiert, die im Format

timestamp-process benannt sind.

Durch diese strukturierte Speicherung und die Möglichkeit, umfassende Diagnosedaten zu sammeln, bietet pt-stalk eine effiziente Lösung zur Leistungsüberwachung und -optimierung von MySQL-Datenbanken.

lab@localhost log % ls -ltrh
total 47752
-rw-r--r--@ 1 root  staff   484B May 28 08:58 2024_05_28_08_58_03-trigger
-rw-r--r--@ 1 root  staff    49K May 28 08:58 2024_05_28_08_58_03-variables
-rw-r--r--@ 1 root  staff   4.3K May 28 08:58 2024_05_28_08_58_03-innodbstatus1
-rw-r--r--@ 1 root  staff    59B May 28 08:58 2024_05_28_08_58_03-mutex-status1
-rw-r--r--@ 1 root  staff   2.6K May 28 08:58 2024_05_28_08_58_03-opentables1
-rw-r--r--@ 1 root  staff   6.1K May 28 08:58 2024_05_28_08_58_03-lsof
-rw-r--r--@ 1 root  staff   128K May 28 08:58 2024_05_28_08_58_03-dmesg
-rw-r--r--@ 1 root  staff    54K May 28 08:58 2024_05_28_08_58_03-sysctl
-rw-r--r--@ 1 root  staff   142B May 28 08:58 2024_05_28_08_58_03-disk-space
-rw-r--r--@ 1 root  staff   7.3M May 28 08:58 2024_05_28_08_58_03-mysqladmin
-rw-r--r--@ 1 root  staff   633K May 28 08:58 2024_05_28_08_58_03-netstat_s
-rw-r--r--@ 1 root  staff    55K May 28 08:58 2024_05_28_08_58_03-df
-rw-r--r--@ 1 root  staff    40K May 28 08:58 2024_05_28_08_58_03-processlist
-rw-r--r--@ 1 root  staff   318K May 28 08:58 2024_05_28_08_58_03-ps-locks-transactions
-rw-r--r--@ 1 root  staff    10K May 28 08:58 2024_05_28_08_58_03-slave-status
-rw-r--r--@ 1 root  staff   4.4K May 28 08:58 2024_05_28_08_58_03-innodbstatus2
-rw-r--r--@ 1 root  staff    27B May 28 08:58 2024_05_28_08_58_03-hostname
-rw-r--r--@ 1 root  staff    59B May 28 08:58 2024_05_28_08_58_03-mutex-status2
-rw-r--r--@ 1 root  staff   2.6K May 28 08:58 2024_05_28_08_58_03-opentables2
-rw-r--r--@ 1 root  staff    51K May 28 08:58 2024_05_28_08_58_03-output
-rw-r--r--@ 1 root  staff   484B May 28 09:03 2024_05_28_09_03_03-trigger
-rw-r--r--@ 1 root  staff    49K May 28 09:03 2024_05_28_09_03_03-variables
-rw-r--r--@ 1 root  staff   4.3K May 28 09:03 2024_05_28_09_03_03-innodbstatus1
-rw-r--r--@ 1 root  staff    59B May 28 09:03 2024_05_28_09_03_03-mutex-status1
-rw-r--r--@ 1 root  staff   2.6K May 28 09:03 2024_05_28_09_03_03-opentables1
-rw-r--r--@ 1 root  staff   128K May 28 09:03 2024_05_28_09_03_03-dmesg
-rw-r--r--@ 1 root  staff   6.1K May 28 09:03 2024_05_28_09_03_03-lsof
-rw-r--r--@ 1 root  staff    54K May 28 09:03 2024_05_28_09_03_03-sysctl
-rw-r--r--@ 1 root  staff   142B May 28 09:03 2024_05_28_09_03_03-disk-space
-rw-r--r--@ 1 root  staff   610K May 28 09:03 2024_05_28_09_03_03-netstat_s
-rw-r--r--@ 1 root  staff    53K May 28 09:03 2024_05_28_09_03_03-df
-rw-r--r--@ 1 root  staff    39K May 28 09:03 2024_05_28_09_03_03-processlist
-rw-r--r--@ 1 root  staff   307K May 28 09:03 2024_05_28_09_03_03-ps-locks-transactions
-rw-r--r--@ 1 root  staff   9.9K May 28 09:03 2024_05_28_09_03_03-slave-status
-rw-r--r--@ 1 root  staff   4.4K May 28 09:03 2024_05_28_09_03_03-innodbstatus2
-rw-r--r--@ 1 root  staff   7.3M May 28 09:03 2024_05_28_09_03_03-mysqladmin
-rw-r--r--@ 1 root  staff    27B May 28 09:03 2024_05_28_09_03_03-hostname
-rw-r--r--@ 1 root  staff    59B May 28 09:03 2024_05_28_09_03_03-mutex-status2
-rw-r--r--@ 1 root  staff   2.6K May 28 09:03 2024_05_28_09_03_03-opentables2
-rw-r--r--@ 1 root  staff    49K May 28 09:03 2024_05_28_09_03_03-output

Anwendungsfall für Dateien:

Dateiname	Beschreibung
Trigger	Erfasst die Bedingungen, die zur Erfassung der Daten führten.
Variables	Listet alle MySQL-Gerätevariablen und deren Werte zum Zeitpunkt der Datenerfassung auf.
Innodbstatus1	Enthält die Ausgabe von SHOW ENGINE INNODB STATUS.
Mutex-status1	Enthält InnoDB Mutex-Statusstatistiken.
Opentables1	Zeigt die derzeit in MySQL geöffneten Tabellen an.
lsof	Enthält die Ausgabe des lsof-Befehls, der offene Dateien auflistet.
Dmesg	Erfasst Kernel-Ringpuffer-Nachrichten unter Verwendung des dmesg-Befehls.
Sysctl	Enthält die Ausgabe des sysctl-Befehls.
Disk-space	Enthält Statistiken zur Festplattenspeichernutzung.
Mysqladmin	Enthält die Ausgabe verschiedener mysqladmin-Befehle.
Netstat-s	Enthält die Ausgabe des netstat -s-Befehls.
Df	Enthält die Ausgabe des df-Befehls.
Processlist	Enthält die Ausgabe von SHOW FULL PROCESSLIST.
ps-locks-transactions	Enthält Statistiken über Sperren und Transaktionen.
Slave-status	Enthält die Ausgabe von SHOW SLAVE STATUS.
Innodbstatus2	Erfasst die Ausgabe von SHOW ENGINE INNODB STATUS.
Hostname	Enthält die Ausgabe des hostname-Befehls.
Mutex-status2	Erfasst den InnoDB Mutex-Status.
Opentables2	Erfasst die derzeit geöffneten Tabellen.
Output	Enthält die gesamte Ausgabe und Zusammenfassung des pt-stalk-Laufs.

Fehlerprotokoll & Protokollwarnstufen:

Das MySQL/MariaDB-Fehlerprotokoll enthält spezifische Informationen über das Stoppen/Starten von mysqld. Es enthält auch Diagnosemeldungen wie Hinweise, Warnungen und Fehler, die während des Betriebs des Servers auftreten. Zum Beispiel enthält es Informationen über den Replikationsstatus oder abgebrochene Verbindungen.

Das Fehlerprotokoll kann in einer Datei oder in einer Tabelle namens “error_log” gespeichert werden.

MySQL bietet auch eine Option, um zusätzliche Meldungen im Fehlerprotokoll zu erzeugen. Vor Version 5.7 konnten wir die Variable “log_warnings” verwenden, ab Version 5.7 können wir “log_error_verbosity” verwenden. Mit “log_error_verbosity” auf 3 gesetzt, wird MySQL Fehler, Warnungen und Informationsmeldungen im Fehlerprotokoll erzeugen. Damit dies funktioniert, muss jedoch auch “log_filter_internal” aktiviert sein.

Der Standort des Fehlerprotokolls kann mit folgendem Befehl abgerufen werden:

mysql -u root -p -e 'select @@log_error'
+--------------------------------+
| @@log_error                    |
+--------------------------------+
| /var/log/mysql/mysql-error.log |
+--------------------------------+

Diese Informationen sind entscheidend für die Fehlersuche und das Monitoring von MySQL/MariaDB-Datenbanken.

Langsame Abfrageprotokollierung:

Die Protokollierung langsamer Abfragen kann aktiviert werden, indem die Variable “slow_query_log” auf 1 gesetzt und “long_query_time” auf den gewünschten Wert eingestellt wird. Es ist sinnvoll, long_query_time auf 0 zu setzen.

Das Protokoll langsamer Abfragen sollte regelmäßig überprüft werden, um herauszufinden, welche Abfragen Leistungsprobleme verursachen. Der häufigste Fall ist eine hohe CPU-Auslastung, die möglicherweise auf fehlende Indizes hinweist. Um die Suche nach solchen Abfragen zu vereinfachen, können wir “pt-query-digest” aus dem Percona Toolkit verwenden.

Einfache Anwendungsfälle

pt-query-digest /var/log/mysql/slow.log


Report provides overview of the whole slow query log. Here we can find the general statistics
# 333.6s user time, 3.2s system time, 42.29M rss, 255.46M vsz
# Current date: Thu Nov  4 10:00:13 2021
# Hostname: db1
# Files: /var/log/mysql/slow.log
# Overall: 962.13k total, 308 unique, 290.59 QPS, 0.53x concurrency ______
# Time range: 2021-11-04 09:05:02 to 10:00:13
# Attribute         total   min     max     avg     95%  stddev  median
# ============  ======= ======= ======= ======= ======= ======= =======
# Exec time         1768s   32us    62s     2ms     2ms 66ms    1ms
# Lock time         115s    11us    17ms   119us   185us    57us   119us
# Rows sent         19.83M      0  89.27k   21.61   28.75  295.77       0
# Rows examine      1.59G       0   1.90M   1.73k   5.20k  21.36k  420.77
# Rows affecte      840     0   168 0.00    0   0.38    0
# Bytes sent    1023.12M    11   6.49M   1.09k   2.62k  12.12k   76.28
# Query size    724.91M     31  23.94k  790.04   1.96k  476.80  755.64




Profile shows the top N queries.


# Profile
# Rank Query ID                 Response time  Calls  R/Call  V/M   Ite
# ==== =========================== ============== ====== ======= ===== ===
#   1 0x76BD685795C8E349A7D674... 563.8500 31.9% 443072  0.0013  0.00 query 1
#   2 0x686E927C3596D99477FA99... 340.1520 19.2%   1000  0.3402  0.11 query 2
#   3 0xD8BDBBC16F544B415A2933... 212.9846 12.0% 188505  0.0011  0.00 query 3
#   4 0x65B5510218A1559FF23BB7... 102.8174  5.8%   1104  0.0931  0.00 query 4
#   5 0xB50E6DB8C88BA536C8A9E0...  82.2197  4.7%  65449  0.0013  0.00 query 5
#   6 0x9969FEF92CC8C8095BAFBC...  64.9858  3.7%    55  1.1816  0.01 query 6
#   7 0xE0ED29B8DF7CBD33497A34...  61.9152  3.5%    1 61.9152  0.00 query 7
#   8 0x7D8C1ED96E50D8BB465180...  59.1116  3.3%   7728  0.0076  0.01 query 8
....
#   19 0x31DB055F8054CFAD763CAC...   7.4954  0.4%   8281  0.0009  0.00 query 19
# MISC 0xMISC                       86.0445  4.9% 108443  0.0008   0.0 <289 ITEMS>






Below we could see all queries fingertips


# Query 1: 133.82 QPS, 0.17x concurrency, ID 0x76BD685795C8E349A7D674D1C851CDF7 at byte 0
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2021-11-04 09:05:02 to 10:00:13
# Attribute pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         46  443072
# Exec time     31  564s   527us    26ms    1ms     2ms   330us     1ms
# Lock time     50  58s 98us    17ms   131us   159us    37us   125us
# Rows sent     8   1.70M       0   72  4.02   28.75    9.21    0
# Rows examine   9 150.84M      40  586  356.98  487.09  154.49  463.90
# Rows affecte   0      0       0       0       0       0       0       0
# Bytes sent    4  44.34M   70  716  104.93  313.99   80.68   69.19
# Query size    45 332.20M  785     787  786.20  755.64     0  755.64
# String:
# Databases db
# Hosts     1.1.1.1
# Last errno   0
# Users     user1
# Query_time distribution
#   1us
#  10us
# 100us  #######################
#   1ms  ################################################################
#  10ms  #
# 100ms
#   1s
#  10s+
# Tables
#   ....
# EXPLAIN /*!50100 PARTITIONS*/


Query text

Hier sind einige Beispiele, wie Sie pt-query-digest ausführen können:

Top 50 queries ordered by rows_examined
pt-query-digest --limit=50  --group-by fingerprint --order-by Rows_examined:sum slog.log


# Filter queries for specific period of time
pt-query-digest --since='2021-05-21 00:40:00' --until='2021-05-21 00:50:00' slow.log


# build report for all queries
pt-query-digest --limit=100% slow.log


# build report only for queries with execution time higher than 5s
pt-query-digest --filter '$event->{Query_time} > 5' slow.log


# build report only for queries executed by specific user
pt-query-digest --filter '$event->{user} =~ /myuser/' slow.log


# build report only for specific database
pt-query-digest  --filter '$event->{db} eq ""'


# To collect slow query directly from the processlist for 60 min
pt-query-digest --processlist --interval=0.2  --iterations 1 --run-time 60m --user=root --ask-pass > slow.txt


# --filter option allows to combine several conditions, for example.
pt-query-digest --filter '$event->{user} =~ /myuser/ && $event->{Query_time} > 5' slow.log


# if you need to get a list of all attributes for the event run the following command:
pt-query-digest  --filter 'print Dumper $event' --no-report --sample 1 slow.log
$VAR1 = {
 Bytes_sent => '148',
 Filesort => 'No',
 Filesort_on_disk => 'No',
 Full_join => 'No',
 Full_scan => 'Yes',
 Lock_time => '0.000048',
 Merge_passes => '0',
 Priority_queue => 'No',
 QC_hit => 'No',
 Query_time => '0.000184',
 Rows_affected => '0',
 Rows_examined => '0',
 Rows_sent => '0',
 Thread_id => '85778229',
 Tmp_table => 'No',
 Tmp_table_on_disk => 'No',
 arg => 'query',
 bytes => 218,
 cmd => 'Query',
 db =>'db_name',
 fingerprint => 'fingerprint of the query',
 host => '8.8.8.8,
 ip => '8.8.8.8',
 pos_in_log => 26187012,
 timestamp => '1627462800',
 ts => '210728  9:00:00',
 user => 'user_name'
};

Danke fürs Lesen! Sollten Sie Probleme mit Ihrer Datenbank haben, zögern Sie nicht, uns zu kontaktieren. Einen Blick auf unsere Kontaktseite lohnt sich!