PHP RAM-Verbrauch in Logfile protokollieren

PHP RAM-Verbrauch in Logfile protokollieren

Beim Debugging eines aktuellen Problems, fiel uns auf, dass PHP Prozesse auf dem betroffenen Drupal Application Server ungewöhnlich viel Arbeitsspeicher verschlungen haben. Üblicherweise rechnen wir mit zwischen 20 und 60 MB pro Apache (PHP) Prozess. Hier fanden sich Ausreißer mit teilweise über 200 MB.

Zuordnung zu URLs

In der Prozessliste fehlt uns jedoch eine entscheidende Information: Welche URL hat diesen Prozess ausgelöst, der außergewöhnlich viel Arbeitsspeicher verbraucht? Was wir suchen ist eine Zuordnung zwischen dem Prozess und der im Browser aufgerufenen URL. Da alle Zugriffe auf die Webseite im Apache Logfile protokoliert werden, liegt Nahe an dieser Stelle anzusetzen.
Unser Ziel ist also, innerhalb der Applikation den maximal verbrauchten Arbeitsspeicher zu ermitteln und den Wert an Apache zu übergeben, damit dieser im Logfile protokoliert werden kann. Wir nutzen hierfür die beiden PHP Funktionen memory_get_peak_usage() und apache_note():

# get the maximum ram
$debug_ram = memory_get_peak_usage();

# make it visible to apache
apache_note(“x-php-ram”, $debug_ram);

Implementierung in die Applikation

Wir wollen natürlich nicht in der Applikation suchen, an wie vielen Stellen wir den Code einfügen müssen, damit wir bei jedem Aufruf den RAM-Verbrauch messen können. Für unsere Debugzwecke machen wir uns eine globale Funktion zu nutze: In der php.ini können wir definieren, dass am Ende von jedem PHP Aufruf zusätzlicher Code ausgeführt wird:

; Automatically add files
;auto_prepend_file =
auto_append_file = /var/www/x-php-ram.php

Implementierung in Apache

Um die Werte auch wirklich im Logfile zu sehen, verändern wir das Logfileformat in Apache:

LogFormat "%h %l %u %t "%r" %>s %b "%{Referer}i" "%{User-agent}i" PHP-RAM: %{x-php-ram}n" combined_memory

CustomLog /var/log/apache2/access.log combined_memory

Ergebnis

Jetzt sehen wir wie viel Arbeitsspeicher jeder einzelne Aufruf einer Webseite verbraucht hat:

/ PHP-RAM: 91106128
/fotos/deutschland-besiegt-kanada PHP-RAM: 110486240
/page/hitfinder PHP-RAM: 81736024
/fotos/wetten-dass-abschied PHP-RAM: 96412776
/shows/schreckliche-urlaubsmode PHP-RAM: 98604800
/musik PHP-RAM: 95526032

In diesem konkreten Fall hat uns diese Debug-Information leider nicht weitergeholfen. Es gab keine Ausreißer, im Grunde haben alle Aufrufe ungewöhnlich viel Arbeitsspeicher verbraucht. In dieser Drupal-Installation sind sehr viele Module installiert, so dass tatsächlich viel RAM verbraucht wird. Durch den Einsatz von APC konnten wir letztendlich den RAM-Verbrauch auf die Hälfte reduzieren und das Problem entschärfen. Dazu aber mehr in einem anderen Blogpost…

Share this post