Analyse de Zend Framework avec XDebug
Etant donné les piètres performances constatées lors de l'utilisation même basique de Zend Framework et pour évaluer la possibilité d'optimiser mon code, j'ai décidé d'installer XDebug.
XDebug va nous permettre d'analyser de manière très précise la consommation mémoire et les temps d'exécution. On pourra ainsi déterminer où se trouve les goulets d'étranglement et ce qui ralenti l'exécution de l'application ou alors détecter les pertes de mémoire importante.
XDebug peut s'utiliser sans modifier une seule ligne de code. Mais il est également possible de l'utiliser à des niveaux plus précis, à l'intérieur du code, pour étudier, par exemple, qu'un petit ensemble de fonctions. Il est bien entendu possible de l'utiliser dans toute application PHP sans pour autant utiliser Zend Framework.
Je vous explique dans cet article la manière de procéder pour installer XDebug et vous donne quelques exemples de l'utilisation du profiler et du traceur d'exécution.
Installation
XDebug est un module PHP qui s'installe très facilement. Sous Windows, copiez simplement la DLL téléchargées dans un répertoire (c:/php/modules par exemple) puis ajoutez cette ligne dans votre php.ini :
zend_extension_ts="c:/php/modules/php_xdebug-2.0.4-5.2.8.dll"
Redémarrez ensuite votre serveur web et le tour est joué. Attention toutefois à la version téléchargée. Elle doit correspondre à votre version de PHP. Si vous avez PHP 5.2, téléchargez la version 5.2 de XDebug.
Pour vous assurer que tout se soit bien passer, et avant de continuer à lire, vérifiez en affichant un phpinfo() que le module a été correctement chargé.
Profiling
XDebug est un outils puissant et étendu mais nous nous intéresseront uniquement à deux de ses fonctions pour l'instant. La première est le profiler. Cette fonctionnalité va nous permettre d'analyser le temps d'exécution de notre code.
Une première bonne surprise, il n'est pas nécessaire de modifier son code PHP pour utiliser le profiler. Il suffit simplement de l'activer. Pour ce faire, si vous avez des droits de configuration par l'intermédiaire d'un .htaccess il vous suffit d'ajouter ces lignes :
php_flag xdebug.profiler_enable On php_value xdebug.profiler_output_dir "c:/php/modules/xdebug"
La première ligne active le profiler. La seconde ligne spécifie un répertoire dans lequel les différentes analyses seront placées. Si vous affichez maintenant à nouveau votre site, vous verrez un fichier apparaître dans le répertoire spécifier.
Vous pouvez également connaître le nom du fichier généré par le chargement de la page en utilisant la fonction xdebug_get_profiler_filename( )
Les fichiers générés par XDebug ne sont pas très parlant en mode texte. Heureusement, des programmes existent pour les lire et mieux comprendre ce qu'il se passe. Sous Windows (il existe des version Linux et Mac également), vous pouvez télécharger WinCacheGrind. Installez le puis ouvrez le fichier généré.
Vous aurez devant vous l'analyse dans un mode de lecture plus "humain". Sur votre gauche, l'arbre des appels réalisés par le chargement de votre page. Sur la droite, le détail des chargements du niveau sélectionné. Vous pouvez dupliquer sur un niveau pour ouvrir son enfant.
L'onglet "Line by Line", comme son nom l'indique, vous présente ligne par ligne les appels effectués. L'onglet "Overall" vous permet d'afficher de manière synthétisée la totalité des appels afin d'analyser de manière plus globale l'exécution de votre code.
Les colonnes "Self" indique le temps de chargement de l'occurrence seule, sans ses enfants. La colonne "Cum." affiche le temps d'exécution cumulé jusqu'à l'occurrence.
Dans l'onglet "Overall", la colonne "Avg. Self" affiche le temps moyen d'exécution de l'occurrence et "Total Self" la somme du temps d'exécution de tous les appels à l'occurrence. La dernière colonne "Calls" affiche le nombre d'appels à l'occurrence.
Function Traces
Le profiler nous a permis d'identifier les goulets d'étranglement dans l'arbre d'exécution. Il est maintenant possible de dire quel partie de notre code prend plus de temps. Par contre, un autre problème rencontré lors de l'utilisation du framework Zend est sa consommation mémoire. Pour analyser cet autre donnée, nous allons utiliser la fonctionnalité Function Traces de XDebug.
Pour activer cette fonctionnalité, nous allons à nouveau modifier notre fichier .htaccess et ajouter les deux lignes suivantes :
php_flag xdebug.auto_trace On php_flag xdebug.show_mem_delta On php_value xdebug.trace_output_dir "c:/php/modules/xdebug"
La première ligne permet d'activer le log des appels avant l'exécution du script donc comprenant votre fichier prepend si vous en utilisez un. La seconde ligne permet l'affichage des deltas de la mémoire utilisée par chaque appel de fonction. La troisième ligne spécifie le répertoire dans lequel nous retrouveront notre log.
Toutefois il est possible de tracer qu'une petite partie de votre code en utilisant les fonctions xdebug_start_trace() et xdebug_stop_trace(). Vous pouvez par exemple insérer ces fonctions juste avant et après l'appelle à Zend_Controller_Front::dispatch().
Si nous retournons dans notre répertoire où sont créés les fichiers, nous découvrons un fichier .xt. Il est assez facile de l'ouvrir dans OpenOffice Calc par exemple pour avoir une meilleur visibilité et pouvoir ordonnancer les données.
Voici un exemple de trace réalisée avec XDebug :
TRACE START [2009-03-12 21:28:23]
0.0010 74648 +74648 -> {main}() E:\Projects\zend_skeleton\www\index.php:0
0.0010 76032 +1384 -> define() E:\Projects\zend_skeleton\www\index.php:15
0.0011 76048 +16 -> define() E:\Projects\zend_skeleton\www\index.php:16
0.0011 76064 +16 -> dirname() E:\Projects\zend_skeleton\www\index.php:19
0.0011 76064 +0 -> dirname() E:\Projects\zend_skeleton\www\index.php:19
0.0011 76064 +0 -> define() E:\Projects\zend_skeleton\www\index.php:19
0.0012 76064 +0 -> define() E:\Projects\zend_skeleton\www\index.php:20
0.0012 76088 +24 -> define() E:\Projects\zend_skeleton\www\index.php:23
0.0012 76376 +288 -> get_include_path() E:\Projects\zend_skeleton\www\index.php:29
0.0012 76480 +104 -> set_include_path() E:\Projects\zend_skeleton\www\index.php:30
0.0019 130032 +53552 -> require_once(E:\Projects\zend_skeleton\library\Zend\Loader.php) E:\Projects\zend_skeleton\www\index.php:33
0.0019 129640 -392 -> Zend_Loader::registerAutoload() E:\Projects\zend_skeleton\www\index.php:34
0.0019 130280 +640 -> function_exists() E:\Projects\zend_skeleton\library\Zend\Loader.php:204
0.0020 130360 +80 -> Zend_Loader::loadClass() E:\Projects\zend_skeleton\library\Zend\Loader.php:209
0.0020 131816 +1456 -> class_exists() E:\Projects\zend_skeleton\library\Zend\Loader.php:54
0.0020 131840 +24 -> interface_exists() E:\Projects\zend_skeleton\library\Zend\Loader.php:54
0.0020 131840 +0 -> str_replace() E:\Projects\zend_skeleton\library\Zend\Loader.php:64
0.0021 132008 +168 -> Zend_Loader::_securityCheck() E:\Projects\zend_skeleton\library\Zend\Loader.php:82
0.0021 132224 +216 -> preg_match() E:\Projects\zend_skeleton\library\Zend\Loader.php:235
La première colonne est le temps d'exécution. La seconde est la mémoire utilisée cumulée et la troisième colonne représente le delta de mémoire utilisée.
Résultats
Après avoir analysé un code simple de Zend Framework, j'ai pu aisément constater où se trouve les goulets d'étranglement. Cette analyse fera toutefois l'objet d'un prochain article.
Fil des commentaires de ce billet