PHP xdebug et profiling
Hop, un coup de apt-get install et quelques minutes plus tard je suis dans le concret du profiling et du xdebug :o)
Attention ce billet est long et explosif !
Étant dans des très gros projets de développements php j'ai enfin pris le temps de partir à la recherche d'un système de debug et par la même occasion d'un "truc" qui pourrait m'aider à optimiser le tout.
1. Le debug
Le debug basic en php c'est d'avoir une variable "$ryxeo_debug" qu'on met à 1 si on veut passer en mode debug et à 0 si on n'en veut plus ... voir mettre à plus de 1 si on veut avoir des niveaux de debug.
Ok mais bon, en langage C ou C++ on peut jouer à ça parcequ'au moment de la compilation on peut demander au compilateur de virer les bouts de codes de debug ... en php ce n'est pas le cas, on aura donc toujours une perte de perfs liée aux x centaines de if($debug) ...
Et puis vous le savez sans doute il nous manque *toujours* le debug important, on a forcément oublié de rajouter un blog de debug autour de la fonction qui déconne ... bref un vrai système de debug ça serait quand même mieux.
Je vous propose de vous lancer sur XDebug, ça marche très très bien.
2. L'optimisation
Maintenant, l'optimisation, ça c'est vraiment "le pied" ... vous avez une application qui est de plus en plus leeeeeente ? vous ne savez pas trop où chercher ? sans doute une petite fonction cachée au beau milieu de 10.000 lignes de codes où vous auriez bien fait de mettre un commentaire du genre
//a optimiser
Configuration de xdebug pour php
zend_extension=/usr/lib/php5/xxx/xdebug.so [debug] ; Remote settings xdebug.remote_autostart=on xdebug.remote_enable=on xdebug.remote_handler=dbgp ;xdebug.remote_handler=gdb xdebug.remote_mode=req xdebug.remote_host=localhost xdebug.remote_port=9000 ; General xdebug.auto_trace=on xdebug.collect_includes=on xdebug.collect_params=on xdebug.collect_vars=on xdebug.collect_return=on xdebug.default_enable=on xdebug.extended_info=1 xdebug.manual_url=http://www.php.net xdebug.show_local_vars=1 xdebug.show_mem_delta=1 xdebug.max_nesting_level=100 ; Trace options xdebug.trace_format=1 xdebug.trace_output_dir=/tmp xdebug.trace_options=1 xdebug.trace_output_name=callgrind.out ; Profiling xdebug.profiler_append=1 xdebug.profiler_enable=1 xdebug.profiler_enable_trigger=1 xdebug.profiler_output_dir=/tmp xdebug.profiler_output_name=callgrind.out
Après avoir configuré php pour qu'il utilise xdebug il faut penser à relancer apache (si on décide de debugger une application web) ...
Premier lancement
Après la 1ère page web traitée par apache+php le fichier /tmp/callgrind.out est là, la taille de ce fichier est très variable en fonction de la complexité de la page qu'il vient d'analyser.
Analyse du fichier callgrind.out
Il existe des logiciels spécifiques pour analyser ces fichiers de debug: kcachegrind en fait partie. Un petit coup de apt-get install kcachegrind et nous voici avec un logiciel d'analyse de fichiers de debug.
Exemple d'utilisation
Par exemple, pour le projet AbulÉdu j'ai pris l'habitude de développer en mode prototype-fonctionnel ... je code une fonctionnalité, je la met chez tous les utilisateurs qui font une mise à jour et si ça plait j'optimise, si ça ne sert à rien, je vire. L'avantage c'est que je n'ai pas perdu de temps à optimiser un truc qui ne sert à rien ...
Il y a quelques semaines j'ai ajouté des informations sur la page qui liste tous les utilisateurs d'AbulÉdu: les responsables apparaissent en gras et les invités en italique. Cette manière de faire n'a pas été très rusée: une personne qui est membre d'un groupe ET qui en a la responsabilité apparait deux fois dans la liste !
D'autre part cet ajout a été très couteux en performances: la liste qui était déjà assez longue à arriver est maintenant très très très lente (surtout visiblement sur les serveurs un peu anciens).
Le recours à xdebug et l'analyse des informations que kcachegrind nous a retourné m'a permis d'améliorer pas mal les performances générales: d'après le retour de François sur la liste.
| Opération / Durée en secondes | Avant | Après |
|---|---|---|
| Afficher 100 comptes : 90 éleves et 10 profs | 74 | 6 |
| Filtrer une classe "classecm" de 30 élèves | 10 | 2 |
| Filtrer une classe "école de 80 noms" | 58 | 2 |
| Filtrer les comptes enseignants | 35 | 2 |
| Suppression du compte et affichage de tous les comptes | 149 | 8 |
Les informations traitées par kcachegrind
Ce logiciel permet d'exporter les graphes qu'il génère, graphe des appels des fonctions de votre code php ... par exemple sur le 1er graphe on peut remarquer les choses suivantes:
- l'appel à shell_exec est hallucinant: 2823 appels depuis la fonction to_group ! Il faut absolument faire un gros travail sur cette partie, ça représente 57,66% du temps d'exécution de la page;
- les 872 appels à GetUser, ListeGroupes, ListeInvitations, ListeResponsabilites, Reset, ça laisse penser à des boucles qui tournent un peu trop ou des appels qu'on pourrait simplifier dans le code;
- les 899 appels à SetGroupes, SetInvitations et SetResponsabilités, même remarque mais dès lors qu'on aura optimisé les appels aux fonctions précédentes celles-ci devraient également être moins utilisées;
À côté de ça on rigole devant les 35752 appels à la fonction eregi qui ne "coûte" que 0,93% du temps d'exécution du script. À l'aide de ce graphe on sait sur quoi il faut se focaliser.
Après amélioration du code source, la réimplémentation de la fonction to_group le nouveau graphique nous donne encore quelques pistes d'optimisations possibles:
- Les appels à ListeResponsabilites doivent être revus, ce n'est pas normal qu'on ait 2194 accès à cette fonction !
- ListeGroupes et ListeInvitations peut-être amélioré
- Il y a encore 12% de temps pris par les appels systèmes mais ça ... c'est d'avoir viré les variables de configuration d'abuledu et de les avoir remplacées par des appels systèmes ... bref d'ici peu je vais faire ce qu'il faut :p
Conclusion
Ça y est, les solutions de debug et d'optimisation pour le PHP sont réellement utilisables et permettent d'avoir des résultats bien réels ...
