Tracing PHP memory usage with Xdebug


In addition to Xdebug’s great profiling and debugging features it also supports tracing memory usage. This helps to find functions which consume a lot of memory or to identify memory leaks. The following options enable tracing right away:

xdebug.auto_trace=1
xdebug.trace_format=1

Traces are written to /tmp by default. You may change this via the xdebug.trace_output_dir setting. With xdebug.trace_format=1 you tell Xdebug to write traces in an easy-to-parse tab separated format. The logged information includes the start and end times of function calls as well as the amount of used memory when entering and leaving the function. The last two numbers help to figure out which functions increase the memory usage a lot. Luckily you don’t have to interpret the traces yourself but use a script for that.
The script parses the trace files and aggregates the numbers by function name. It accepts a few different keys to sort the output: time-own, memory-own, time-inclusive, memory-inclusive and calls. You can also configure the number of elements to show:

php tracefile-analyser.php trace.662975268.xt memory-own 10
Showing the 10 most costly calls sorted by 'memory-own'.
                                                          Inclusive        Own
function                                          #calls  time     memory  time     memory
------------------------------------------------------------------------------------------
Icinga\Application\ClassLoader->loadClass             90  0.9151  2638176  0.0814  1262312
Zend_Loader::loadFile                                 17  0.1496  1183528  0.0345   882928
PDOStatement->execute                                 22  0.0102   395368  0.0102   395368
require                                               85  0.6066  1548112  0.0157   338512
require_once                                          22  0.0506   566296  0.0107   149128
Icinga\Application\ClassLoader->requireZendAutoloader  1  0.0045   154360  0.0023   120136
Composer\Autoload\includeFile                          8  0.0148    86544  0.0028    59448
Zend_Db_Select->_join                                 41  0.2599    59368  0.0627    57072
explode                                              135  0.0341    55672  0.0341    55672
Icinga\Application\Benchmark::measure                 94  0.2099    47448  0.0737    47352
Eric Lippmann
Eric Lippmann
Lead Senior Developer

Eric kam während seines ersten Lehrjahres zu NETWAYS und hat seine Ausbildung bereits 2011 sehr erfolgreich abgeschlossen. Seit Beginn arbeitet er in der Softwareentwicklung und dort an den unterschiedlichen NETWAYS Open Source Lösungen, insbesondere inGraph und im Icinga Team an Icinga Web. Darüber hinaus zeichnet er sich für viele Kundenentwicklungen in der Finanz- und Automobilbranche verantwortlich.

Weekly Snap: Puppet & Icinga, DevOps & OpenUp Camp

weekly snap11 – 15 November was a week of events, at home and abroad. Devops, Puppet and Icinga featured heavily, alongside PostgreSQL, Ansible and Xdebug.
Eva started the week by starting her countdown to the OSDC, at 148 days and with Jan-Piet Mens’ presentation -“Ansible: Configuration Management Doesn’t Have to be Complicated”.
Christian then posted a reminder for our webinar introducing Icinga 2 as Silke touted the last few places to our Puppet Advanced training workshop in Hamburg.
Markus M followed by bridging the two, offering his quick guide to managing Icinga configurations with Puppet.
Also on Puppet, Thomas reported back from Continuous Lifecycle 2013, where he gave a talk on “Puppet and Marionettes in the Deployment Pipeline”.
Continuing on the event circuit, Markus F reviewed the recent PGConf.DE and his favorite presentations, while Matthias played with Xdebug for remote debugging in PHP.
Finally, Bernd shared happy snaps from his trip to DevOpsDays London and talk on Icinga 2, and introduced the first OpenUp Camp held by OSBF in February next year.

Weekly Snap: Xdebug, Icinga-Web for Debian, New Icinga SLA Reporting & New Courses

13 – 17 August introduced new training courses, tips for Chrome and Mac users as well as developers, and even contributed a Debian package and new SLA ideas to the Icinga project.
Starting with events, Eva counted 65 days down to the OSMC 2012 with Michael Medin’s presentation on “Distributed Monitoring using NSClient” and introduced two new training courses – ‘Icinga Advanced’ and ‘Open Nebula.
Ronny shared a shortcut for personalised searches on Google Chrome while Bernd restored Git CLI tools after an upgrade to Mountain Lion.
On the community front, Thomas called out to beta testers to review his new SLA reporting concept for Icinga amd Markus announced his Icinga Web packages for Debian.
Meanwhile Marius recommended Xdebug for PHP profiling and Vanessa got a head start on preparations for our NETWAYS ski trip in January.

Profiling von PHP mit Xdebug

Oftmals fällt es gar nicht auf. Man entwickelt sein Programm und greift auf Funktionen zurück, die schon seit Dekaden bestens funktionieren. Allerdings stellt man irgendwann fest, daß alles immer langsamer wird. Auf den ersten Blick ist nicht ersichtlich warum es zu diesen Einbußen kommt. Der zweite Blick auf den Profiler zeigt das die vermeintlich robuste Funktion eigentlich langsam ist. Durch mehrmalige Verwendung zwingt es die ganze Applikation in die Knie.
Auch beim tunen hilft’s: PHP ist an vielen Stellen inkonsistent und reagiert entsprechend anders, wie schaut es mit der Geschwindigkeit von Iteratoren zu Schleifen aus – oder array_key_exists zu isset? Hier gibt der Profiler Aufschluss was man am besten vermeidet und was man lieber vermeidet.
Einen guten guten Profiler für PHP kommt von Xdebug (wahrscheinlich auch der einzige). Installiert kriegt man ihn am besten aus dem Distro Repository (z.B. von Ubuntu) oder einfach aus den Sourcen mit phpize && sh configure && make && make install. Nach dem er nicht dauerhaft benötigt kann man ihn mit einem Trigger über die URL aktivieren. Über die Kommandozeile setzt man einfach das entsprechende ini-flag und der Profiler schreibt Valgrind kompatible Ausgabe nach /tmp. Eine Standardkonfiguration für Xdebug schaut demnach folgendermaßen aus:

[xdebug]
xdebug.profiler_enable=0
xdebug.profiler_enable_trigger=1

Trigger Möglichkeiten:

wget http://localhost/myscript.php?XDEBUG_PROFILE=1
php -d xdebug.profiler_enable=On myscript.php

Die Datei (z.B. /tmp/cachegrind.out.24869) kann man mit WinCacheGrind oder KCachegrind einsehen und optimiert entweder anhand der Zeitabläufe oder anhand der Aufrufe. Je nach Menge spart das ordentlich Zeit.
Hier ein Beispiel anhand verschiedener Iterationsmöglichkeiten in PHP:

Der Test ist natürlich nicht objektiv, zeigt aber, daß die vermeintlich gleiche Aufgabe nicht gleich optimal abläuft. Häufig findet man mit dem Profiler dann Funktionen im Code welche gnadenlos vergewaltigt werden (oder für einen anderen Zweck entworfen wurden) – Und das verbrennt dann richtig Zeit!

Marius Hein
Marius Hein
Head of Development

Marius Hein ist schon seit 2003 bei NETWAYS. Er hat hier seine Ausbildung zum Fachinformatiker absolviert, dann als Application Developer gearbeitet und ist nun Leiter der Softwareentwicklung. Ausserdem ist er Mitglied im Icinga Team und verantwortet dort das Icinga Web.