Outils de debug

, par Matthieu Marcillaud

Hier encore, nous avons vu comment créer une première interface pour un plugin permettant d’être affichée dans l’espace privé de SPIP (Créer une interface d’administration). Nous avons aussi créé un premier formulaire pour gérer quelques données.

Nous allons maintenant tenter d’améliorer un peu le fonctionnement du plugin Champs Extras et de son interface. Mais...

Aujourd’hui, en démarrant votre navigateur sur le site qui utilise le plugin d’interface pour champs extras créé hier et en allant dans la partie privée, vous arrivez malencontreusement sur une page blanche !

Aïe !

¿ Que pasa ?

Opération débugguage

Perplexe comme jamais, mais ne vous laissant pas abattre, vous regardez les logs (petites informations écrites par SPIP pour signaler ce qu’il fait) générés par SPIP ou par des plugins. Ces logs se trouvent être les fichiers *.log contenus dans le répertoire tmp/.

En se basant sur l’heure actuelle, vous regardez ce qu’à écrit SPIP, dans le fichier spip.log, qui accumule l’ensemble des écritures des différents fichiers de log.

Justement... SPIP n’a rien écrit ! Gasp !

Toujours serein, vous commencez par supprimer quelques fichiers temporaires : tmp/cache/*, tmp/charger_*, tmp/meta_cache.txt (tiens, celui là est vide ? étrange !)

Vous actualisez, SPIP reconstruit les fichiers... et affiche page blanche toujours... Rho le bougre ! Vous remarquez que tmp/meta_cache.txt est encore vide... ce qui n’est pas normal. Il doit bien se passer quelque chose...

Comment savoir ?

Dire à PHP d’afficher toutes les erreurs !

Il se trouve que lorsque SPIP construit ses pipelines, les erreurs PHP ne sont volontairement pas affichées par défaut. Nous allons changer cela. Pour ça, on édite/crée le fichier config/mes_options.php pour ajouter :

  1. <?php
  2. // augmenter la taille des logs
  3. $GLOBALS['taille_des_logs'] = 5000;
  4.  
  5. // afficher toutes les erreurs
  6. error_reporting(E_ALL);
  7. @ini_set("display_errors", "On");
  8.  
  9. // afficher toutes les erreurs dans SPIP aussi
  10. define('SPIP_ERREUR_REPORT',E_ALL);
  11. // afficher toutes les erreurs dans les pipelines aussi
  12. define('SPIP_ERREUR_REPORT_INCLUDE_PLUGINS',E_ALL);
  13. ?>

Télécharger

Avec ceci, on indique que les fichiers de logs peuvent atteindre 5000 lignes avant de se reconstruire (ce qui laisse de la marge). On indique à PHP d’afficher systematiquement toutes les erreurs, même les plus farfelues ’notices’ (comme une variable non initialisée). Enfin, on indique à SPIP aussi d’afficher toutes les erreurs.

Et maintenant, on recharge la page, et on découvre un joli fatal error :

  1. Fatal error: Call to undefined function iextra_get_extras() in /home/marcimat/www/zone/_plugins_/_dev_/champs_extras/extensions/interface/base/iextra.php on line 6

On ouvre alors le fichier en question qui comporte le code suivant :

  1. <?php
  2. if (!defined("_ECRIRE_INC_VERSION")) return;
  3.  
  4. function iextra_declarer_champs_extras($champs=array()) {
  5. include_spip('inc/iextra');
  6. $extras = iextra_get_extras();
  7. foreach($extras as $e) {
  8. $champs[] = new ChampExtra($e);
  9. }
  10. return $champs;
  11. }
  12. ?>

Télécharger

Là, on se dit que quelque chose ne va pas... La fonction devrait être connue, vu qu’on inclue la librairie juste avant...

Je vous passe les détails de debugguage qui rentrent dans les méandres du fonctionnement de SPIP, mais il se trouve que SPIP dispose de plusieurs nombres aléatoires mis à jour régulièrement afin d’assurer certaines sécurités anti-piratage. L’un d’eux concerne le site. Lors de la mise à jour de cet « alea », SPIP, très tôt dans son processus de chargement appelle la fonction ecrire_meta() qui écrit une information en base. Pour une raison que j’ignore encore, appelant une requête via une fonction sql_*, SPIP demande à lire les champs et tables déclarées (je pense que ça doit être la toute première requête alors exécutée). En faisant cela, il appelle le pipeline ’declarer_tables_principales’ qui appelle le pipeline du plugin champs extras ’declarer_champs_extras’ qui appelle la fonction écrite au dessus...

Tout devrait aller bien... Sauf que... Sauf que l’appel est tellement tôt dans le processus de SPIP que les plugins ne sont pas encore définis, et du coup, l’inclusion de ’inc/iextra’ ne fait rien car SPIP ne trouve pas le fichier... Ballot.

Signaler les erreurs

Bref, comme ça ne semble pas prévu, et en bon Spipeur, je signale l’information sur la liste de développement de SPIP (http://listes.rezo.net/mailman/listinfo/spip-dev). On peut aussi rechercher si quelqu’un a déjà abordé ce sujet en effectuant une recherche ici : http://blog.gmane.org/gmane.comp.web.spip.devel . Enfin, on peut aussi créer un ticket dans le trac de SPIP, toujours en vérifiant qu’il n’y en a pas déjà un identique (vive la fonction recherche !), à cette adresse : http://trac.rezo.net/trac/spip/report/3 (s’inscrire ici pour pouvoir poster : http://trac.rezo.net/ )

En attendant, je corrige le problème localement comme ceci, après le include_spip :

  1. // lors du renouvellement de l'alea, au demarrage de SPIP
  2. // les chemins de plugins ne sont pas encore connus.
  3. // il faut se mefier et charger tout de meme la fonction, sinon page blanche.
  4. if (!function_exists('iextra_get_extras')) {
  5. include_once(dirname(__file__).'/../inc/iextra.php');
  6. }

Télécharger

Créer des logs

Ce problème corrigé ne doit pas vous faire oublier que SPIP dispose d’un outil, « spip_log » pour écrire des informations de log. Très pratique pendant les phases de debugguage.

Cette fonction prend 1 ou 2 arguments. Un seul, elle écrira dans le fichier spip.log. Deux, elle écrira dans un fichier séparé et aussi dans spip.log.

Exemples :

  1. <?php
  2. spip_log($tableau);
  3. spip_log($tableau, 'extras');
  4. spip_log("ajout de $champ dans $table","extras");
  5. ?>

Télécharger

Lorsqu’un tableau est transmis à la fonction de log, SPIP écrira le résultat d’une print_r() dans le fichier de log.
Pour chaque fichiers demandé, ici spip (par défaut) et extras, SPIP créera ou ajoutera le contenu du premier argument, mais pas n’importe où. Si le script est dans l’interface privée, il écrira dans « prive_spip.log » ou « prive_extras.log », sinon dans « spip.log » ou « extras.log ».

Ne pas écrire n’importe quand les log

Évidemment, on ne souhaite pas toujours que tous les logs s’écrivent en permanence, mais seulement certains, et parfois tous. On peut donc imaginer, pour son plugin, une fonction spéciale de log :

  1. function extras_log($contenu, $important=false) {
  2. if ($important
  3. OR (defined('EXTRAS_DEBUG') and EXTRAS_DEBUG)) {
  4. spip_log($contenu,'extras');
  5. }
  6. }

Télécharger

Ainsi, un plugin peut avoir deux types de log : importants, donc toujours écrits, et les autres, écrits seulement en mode debug.

  1. define('EXTRAS_DEBUG', true); // ou false
  2.  
  3. extra_debug($tableau);
  4. extra_debug("ajout de $champ dans $table", true);

Télécharger

Trouver depuis une erreur, la fonction fautive

Sujet un peu plus complexe : en PHP, debug_backtrace() liste les fonctions qui ont été appelées pour arriver à l’endroit où nous sommes dans le code. On peut appeler cela la pile d’appel. On peut donc à l’intérieur d’une fonction lister cette pile, utile pour retrouver l’appelant qui a passé de mauvais paramètres à une fonction par exemple :

  1. function quelconque($argument='') {
  2. // quelque part dans le code
  3. spip_log(debug_backtrace());
  4. // ou encore
  5. if ($j_ai_mon_erreur) {
  6. spip_log(debug_backtrace());
  7. }
  8. }

Télécharger

On aura ainsi dans ses logs qui a appelé la fonction « quelconque » et avec quels arguments.

Autres outils, les tests unitaires

Les tests unitaires sont des moyen de vérifier qu’un code fonctionne toujours même après des modifications apportées. On modifie, on lance la batterie de tests, et s’ils sont bons, c’est qu’on a rien cassé.

Un plugin SPIP existe pour utiliser la librairie simpleTest décrit ici : http://www.spip-contrib.net/Les-tests-unitaires . Ceci dit, ce n’est pas toujours évident de tester, mais par contre, qu’est-ce que c’est performant quand on doit modifier un plugin pour conserver la compatibilité avec ce qui était codé !

De la constance...

Parce que SPIP, c’est surtout rempli de douceurs, voici un petit blues de denisb. Bel encouragement ! (et grand merci !)

Coup de pouce

Pour me maintenir en éveil et en pleine forme physique et mentale, vous pouvez me faire le cadeau d'un jus de fruit pressé.

En plus de m'hydrater, de m'offrir une alimentation saine crudivore et frugivore, cela peut aussi me motiver à produire d'autres documentations ou peut-être à prendre des vacances ! :)

Vous pouvez également me « Flattrer » si vous utilisez le service en ligne très malin Flattr de microdonations qui permet d'allouer un budget mensuel à des créateurs de contenu. Votre budget est partagé chaque mois entre toutes les personnes que vous avez flattées ce mois là.