Am Freitag habe ich mich entschieden, eine bisher nur auf meinem lokalen Mac mini in einem Vagrant-Container laufende Web-Applikation auf meinen „produktiven“ Web-Server bei der Cyon GmbH zu verschieben.
Es handelt sich um eine Applikation, mit welcher Fragen einer Zertifizierungsprüfung mittels Multiple Choice beantwortet werden können. Eine Unterseite der Applikation berechnet aus dem Log der bisher getätigten Antworten Statistiken.
Nach einigen Minuten lief die Web-Applikation und der aktuellste MySQL-Dump war ebenfalls auf dem Server eingespielt. Doch dann kam das böse Erwachen: Beim Aufruf einer neuen Frage wartete ich unzählige Sekunden auf eine Antwort des Servers, bis die Ausführung des PHP-Scripts dann mit einem Timeout abbrach.
Was zum Teufel? Rasch war klar, dass ein SQL-Query zur Berechnung von Statistiken der Übeltäter war.
Auf Dev lief das MySQL-Query folgendermassen rasch durch:
[12-Dec-2014 13:22:18 Europe/Zurich] I - mysql->query() took 0.1694 secs in /var/www/apps/%APP%/inc/%APP%.class.php:343 for URI (Referer: unknown) from IP 192.168.1.1 with User Agent "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/600.1.17 (KHTML, like Gecko) Version/7.1 Safari/537.85.10"
Auf Prod hingegen loggte ich diesen Zeitwert:
[12-Dec-2014 12:40:18 Europe/Zurich] I - mysql->query() took 47.8917 secs in %PATH%%APP%.class.php:343 for URI <%URI%> (Referer: %REFERER%) from IP %IP% with User Agent "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/600.1.17 (KHTML, like Gecko) Version/7.1 Safari/537.85.10"
Eine Verlangsamung von mehr als dem 200-fachen!
Als erstes prüfte ich die Versionen der Datenbank-Software:
Dev
-- Server version 5.6.21-1~dotdeb.1
Prod
-- Server version 5.5.40-cll
Ich verwendete also eine Zehntelsversion bessere Datenbank.
Anschliessend liess ich mir das Query sowohl in Dev als auch in der Produktion „erklären“ (EXPLAIN):
Dev
Prod
Der Unterschied: Auf Prod führte MySQL ein „Dependent Subquery“ aus, auf Dev „nur“ (?) ein „Subquery“. War das das Problem?
Da mir EXPLAIN hier nun wirklich nicht weiterhalf, wendete ich mich Google zu. Folgende zwei Stackexchange-Artikel erheischten meine Aufmerksamkeit:
Beim Lesen der Antworten kam mir plötzlich die Idee: Vielleicht sind INDEXe deine Freunde? Ich wählte die Spalte Questions-id (`Questions-id` varchar(64) NOT NULL, CLSIDs enthaltend) aus und versah sie mit einem Index.
Und siehe da, beim nächstem Aufruf der Web-Seite wurde folgender Zeitwert registriert:
[12-Dec-2014 23:33:09 Europe/Zurich] I - mysql->query() took 0.0412 secs in %PATH%%APP%.class.php:343 for URI <%URI%> (Referer: %REFERER%) from IP %IP% with User Agent "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/600.1.17 (KHTML, like Gecko) Version/7.1 Safari/537.85.10"
Der zusätzliche Index auf einer Spalte auf hat mein Performance-Problem zu meiner vollsten Zufriedenheit gelöst. Wieso der Index aber in Version 5.6 von MySQL nicht mehr benötigt wird, ist mir derzeit noch ein Rätsel. Wahrscheinlich haben die Entwickler die Subquery-Performance in dieser Version stark verbessert?
