MySQL Netzwerk Traffic analysieren mit tcpdump und mk-query-digest
Vor ein paar Wochen wollte ich den Traffic eines MySQL Server analysieren, da er meiner Ansicht nach zu viel davon verursachte und ich raus finden wollte was dafür verantwortlich war. Zu Anfang hatte ich nicht wirklich einen Plan wie man vorgehen sollte, aber glücklicherweise habe ich mich dann an mk-query-digest erinnert. mk-query-digest kann man nicht nur zum analysieren von Slowlogs benutzten, sondern man kann auch den Output von tcpdump auswerten. Es kann noch mehr, aber das reichte für meine Zwecke. Der MySQL Server wird per TCP/IP von mehreren Webservern benutzt und so konnte ich den Traffic direkt am betreffenden Netzwerkinterface abfangen und auswerten.
Installation von mk-query-digest
Bei Debian Lenny gibt es zwar ein Maatkit Paket, aber mk-query-digest ist nicht dabei. In der Debian Squeeze Version ist es dabei. Das macht aber nichts, da man die Tools auch direkt von der Maatkit Seite runter laden kann wenn man sie braucht. So hat man auch gleich die aktuellste Version und die meisten haben nicht viele Dependencies. In diesem Fall eigentlich nur Perl.
$ wget http://www.maatkit.org/get/mk-query-digest $ chmod 700 mk-query-digest
MySQL Traffic aufzeichnen
Jetzt muss man nur noch den Netzwerk Traffic für eine bestimmte Zeit aufzeichnen. Das macht man mit tcpdump. Das funktioniert natürlich nur wenn man auch per TCP mit dem MySQL Server kommuniziert. Wird ein Socket benutzt klappt das nicht.
$ aptitude install tcpdump
Und los gehts.
$ tcpdump -i eth1 port 3306 -s 65535 -x -n -q -tttt > tcpdump.out
- -1 eth1: gibt das Interface an
- port 3306: nur der Port 3306 (Standard MySQL Port)
- -s 65535: gibt die Paketgröße an (Standard ist 65535 Byte)
- -x: speichert die Paketdaten zusätzlich zum Header
- -n: schaltet das umwandeln von ip/ports in Namen aus
- -q: print less protocol information so output lines are shorter
- -tttt: Zeitanzeige auf Mikro Sekunden Basis
Nach einer gewissen Zeit bricht man die Aufzeichnung ab und kann sie dann analysieren lassen. Wer auf der Manpage von tcpdump.
tcpdump Output mit mk-query-digest analysieren
$ ./mk-query-digest --type=tcpdump tcpdump.out # 9.8s user time, 70ms system time, 23.42M rss, 62.73M vsz # Current date: Mon Nov 29 13:33:28 2010 # Hostname: # Files: tcpdump.out # Overall: 5.62k total, 263 unique, 164.53 QPS, 6.15x concurrency ________ # Time range: 2010-11-29 13:29:50.925841 to 13:30:25.053095 # Attribute total min max avg 95% stddev median # ============ ======= ======= ======= ======= ======= ======= ======= # Exec time 210s 0 5s 37ms 12ms 324ms 185us # Rows affecte 2.59k 0 487 0.47 1.96 8.07 0 # Query size 3.15M 27 32.33k 587.40 2.50k 1.46k 151.03 # Warning coun 135 0 2 0.02 0 0.16 0 # Boolean: # No index use 8% yes, 91% no # Profile # Rank Query ID Response time Calls R/Call Apdx V/M Item # ==== ================== ================ ===== ======== ==== ===== ===== # 1 0x5D51E5F01B88B79E 180.2087 85.9% 332 0.5428 0.90 2.74 SQL QUERY1 # 2 0x1EC1F09FDCEF5DB2 14.3511 6.8% 74 0.1939 1.00 0.32 SQL QUERY2 # 3 0x6F892C0B0A7C11D6 2.5145 1.2% 30 0.0838 1.00 0.06 SQL QUERY3 # 4 0x1C8D8CB6747168AF 1.8098 0.9% 27 0.0670 1.00 0.02 SQL QUERY4 # 5 0x4196B98354B9878A 1.0103 0.5% 12 0.0842 1.00 0.03 SQL QUERY5 # MISC 0xMISC 9.9940 4.8% 5140 0.0019 NS 0.0 <258 ITEMS> ... Detailinformationen der einzelnen Querys ...
Über den Operator --report-format kann man angeben was man genau sehen möchte. In diesem Aufruf wird nach Response time DESC sortiert, aber ich möchte ja den Traffic analysieren. Die Sortierung kann man mit --order-by beeinflussen. Welche Attribute man benutzen kann steht hier.
$ ./mk-query-digest --type=tcpdump --report-format=query_report \ --order-by=bytes:sum tcpdump.out # Query 1: 4.69 QPS, 27.21kx concurrency, ID 0x77AF7411127E6BE3 at byte 18056163 # This item is included in the report because it matches --limit. # Scores: Apdex = 1.00 [1.0], V/M = 0.00 # Time range: 2010-11-29 13:29:51.065241 to 13:30:24.976428 # Attribute pct total min max avg 95% stddev median # ============ === ======= ======= ======= ======= ======= ======= ======= # Count 2 159 # Exec time 0 102ms 103us 13ms 638us 1ms 1ms 287us # Rows affecte 11 315 1 2 1.98 1.96 0.13 1.96 # Query size 27 901.00k 784 12.51k 5.67k 12.50k 3.72k 4.49k # Warning coun 0 0 0 0 0 0 0 0
Mit diesem Befehl sortiert man die Query Liste nach der Bytes Summe. Am Ende steht immer der SQL Query und so findet man sehr schnell den Übeltäter. In meinem Fall sind die ersten 6 Plätze alles Session Querys gewesen. Hat man was man wollte, entfernt man die beiden Dateien einfach.
$ rm mk-query-digest tcpdump.out