Seit ein paar Tagen ging mir die Ladezeit meiner Page (~2,5 Sekunden Generierungszeit) extrem auf den Keks. Auf dem Server konnte ich keine Übeltäter erkennen, da andere Seiten mit deutlich mehr Queries extrem schnell geladen werden konnten. Daher schaltete ich kurzfristig Xdebug für meinen Webhost frei und zeichnete einen Request zum Zwecke des Profilings von Wordpress auf. Anschließend konnte ich diesen auswerten und ein Plugin namens “PHP Speedy WP” als den Haupt-Übeltäter indentifizieren. In der Version 0.4.5 benötigte dieses Plugin gut eine Sekunde für eine Prüfung, die eigentlich über einen cache laufen sollte. Im folgenden möchte ich kurz auf die Installation von Xdebug und die Auswertung der erstellten Logs eingehen.

Unter Gentoo gestaltet sich die Installation wie immer extrem einfach:

1

emerge -av xdebug

Damit ist xdebug für alle Webhosts installiert! Es ist noch nicht aktiviert! Noch ein Hinweis: Xdebug verträgt sich nicht mit Zend Optimizer, man kann nur eines gleichzeitig einschalten! (Logmeldung: “Zend Optimizer 3.3.3 is incompatible with Xdebug 2.0.2” kam bei mir)

Ich fahre ein komplexes Setup mit mod_fcgid, was mir erlaubt für jeden Webhost einzelne php.ini-Files anzulegen. Daher habe ich zunächst die extension wieder deaktiviert:

1
2

rm /etc/php/cgi-php5/ext-active/xdebug.ini
rm /etc/php/cli-php5/ext-active/xdebug.ini

Und anschließend die relevanten Daten der Config in der php.ini meines Webhosts eingetragen:

1
2
3
4
5

zend_extension=/usr/lib/php5/lib/php/extensions/no-debug-non-zts-20060613/xdebug.so
xdebug.profiler_enable="1"
xdebug.profiler_output_dir="/tmp"
xdebug.profiler_output_name="cachegrind.out.%u.%p"
xdebug.profiler_enable_trigger="1"

Was heissen diese Werte?

  • zend_extension: Lädt die Erweiterung
  • xdebug.profiler_enable Schaltet den Profiler ein
  • xdebug.profiler_output_dir In diesem Verzeichnis werden die Profiling-Log-Files abgelegt
  • xdebug.profiler_output_name Name der Profiling-Log-Files, folgende Platzhalter existieren:
    • %p Process-Id
    • %r Zufallszahl
    • %u Zeitstempel in Microsekunden
    • %H Wert von $_SERVER[‘HTTP_HOST’]
    • %R Wert von $_SERVER[‘REQUEST_URI’]
    • %s Name des Script mit vollem Pfad, Slashes werden in Unterstriche konvertiert
  • xdebug.profiler_enable_trigger Logfiles werden nur über das Auslösen eine Triggers geschrieben. Da diese Logfiles teilweise sehr groß sind, sollte man diesen Schalter einschalten, um nicht jeden Request eines jeden Besuchers aufzuzeichnen. Dieser Trigger lautet: http://url-des-webhosts/?XDEBUG_PROFILE

Welche weiteren Switches existieren?

  • xdebug.profiler_append Kann genutzt werden, um nur ein Logfile mit allen Profiling-Daten zu bekommen (xdebug.profiler_append=1). Neue Einträge werden dann (wenn der xdebug.profiler_output_name immer der gleiche ist) bei der Ausgabedatei einfach angehängt

Jetzt erstellen wir ein solches Profiling-Logfile indem wir http://url-des-webhosts/?XDEBUG_PROFILE aufrufen. Dieses hat bei mir für einen Request eine Größe von 17MB.

Übersicht

Die Auswertung wird unter Windows mittels WinCacheGrind  gemacht. Nach der Installation öffnet man das Programm und lädt die soeben erstellte Datei.

WinCacheGrind

Mein Tipp: Zuerstmal die schnellen Funktionen (d.h. <1ms) und die PHP-Funktionen ausschalten, denn an diesen hakt es meistens nicht. Das geht über das Menü “Profiler”.

Nun kann man sich einfach per Doppelklick durch die Funktionen hangeln.

Unter Linux existiert für die KDE-Umgebung ein Tool namens KCacheGrind , welches deutlich mehr als nur die Funktionalitäten von WinCacheGrind beinhaltet. Es kann auch die Profiling-Daten visualisieren und beispielsweise Aufrufe als Graphen zeichnen. Auf dieser Seite kann man das ein auch ansehen, ich habe es selbst nicht getestet ;)

Übrigens das Ergebnis des Abschaltens des Plugins: 2 Sekunden weniger fürs generieren der Seite! Jetzt könnte ich noch 400ms einsparen, wenn ich mein Template durchgehend auf Deutsch direkt übersetzen würde und keine Sprachdateien verwenden würde (Die Spracheengine ist nicht gerade nen Knaller…). Problem dabei ist, dass es häufige Updates für dieses Theme gibt und der Aufwand enorm ist…ne Sekunde für die Startseite ist tolerabel.