var_debug et var_profile

L’outil actuel de debug et profilage est appelé lorsqu’on ajoute dans l’url appelée les paramétres suivants :
-  var_mode=debug
-  var_profile=1 ou var_profile=sql
_ (vérifier ce dernier point )

Sont alors affichés ou accessibles des informations techniques avancées comme :
-  les temps de compilation
-  les temps d’exécution
-  les codes sources SPIP, PHP, (MY)SQL

Ces informations sont affichées pour chaque molécule élémentaire de code spip :
-  boucles
-  inclusions
-  appels de balise en dehors d’une boucle (vérifier)

Différents temps de calculs

Il y a

1. ) les temps de « recalcul » : compilation des squelettes SPIP afin de créer un cache php.
   cette phase est ensuite suivie du calcul afin d’afficher le résultat
2. ) les temps de calcul : exécution du cache php calculé en 1) et qui fournit le code HTML
3. ) les temps de service du cache : simple restitution du précédent calcul du HTML

Les recalculs sont les plus coûteux puisqu’ils partent du code spip.
L’impact global sur un serveur dépendent dépend aussi de la lourdeur et de la fréquence de chacun...

Les recalculs sont les plus coûteux puisqu’ils partent des squelettes spip pour les compiler puis interroger la base de donnée et servir le html final. Ils sont toutefois exceptionnels.

La fréquence des calculs, quand à elle , et recalculs dépend des durées de valeurs indiquées dans les instructions #CACHE paramétrées dans chacun des éléments {} en début de chaque squelette, et de des modifications apportées à la fréquence base de donnée ( création de nouveaux contenus ( via les forums publics d’article , l’interface dépot de saisie ou autres interfaces accessibles sur le site ) dans la base de donnée forum , qui invalide le cache . ... ) qui invalident le cache.

Il faudra donc tester dans ces différentes situations, avec :
-   ?var_profile=1 (service du cache)
-   ?var_profile=1&var_mode=calcul (prise en compte des nouveautés de la base de donnée)
-   ?var_profile=1&var_mode=recalcul (recompilation = prise en compte des modifications du squelette)

A noter que ce qui est appelé « code HTML » peut contenir des morceaux de php si il y en a dans le squelette. C’est pour cela que cette pratique est fortement déconseillée.

Relevé des compteurs

Simon Camerlo a édité spip.php pour rajouter une mesure de chaque calcul en phase de bench :

<?php
   $begin=time();


/***************************************************************************\
*  SPIP, Systeme de publication pour l'internet                           *
*                                                                         *
*  Copyright (c) 2001-2007                                                *
*  Arnaud Martin, Antoine Pitrou, Philippe Riviere, Emmanuel Saint-James  *
*                                                                         *
*  Ce programme est un logiciel libre distribue sous licence GNU/GPL.     *
*  Pour plus de details voir le fichier COPYING.txt ou l'aide en ligne.   *
\***************************************************************************/


# ou est l'espace prive ?
@define('_DIR_RESTREINT_ABS', 'ecrire/');
include_once _DIR_RESTREINT_ABS.'inc_version.php';


# rediriger les anciens URLs de la forme page.php3fond=xxx
if (isset($_GET['fond'])) {
   include_spip('inc/headers');
   redirige_par_entete(generer_url_public($_GET['fond']));
}


# au travail...
include _DIR_RESTREINT_ABS.'public.php';


spip_log((time() - $begin) . " s || " . $_SERVER['HTTP_HOST'] . $_SERVER['REQUEST_URI'],'bench');
?>

Le résultat est visible dans le fichier tmp/bench.log

Limitations techniques

ESJ :

Le vocabulaire standard considère que « le temps de compilation » est le temps que met le compilateur à traduire le langage-source (ici le langage des squelettes) dans le langage-cible (ici PHP) et il est de peu d’intérêt ici puisque la compilation intervient rarement en production : une fois compilé, c’est le code PHP qui est exécuté. Le temps intéresant à afficher est le temps d’exécution du code PHP compilé, et c’est ce que veut faire SPIP en mesurant le temps au niveau de la fonction inc_parametrer et non ailleurs.

Malheureusement, le temps qu’il affiche est biaisé de plusieurs manières :

1. par définition, le mode debug recompile tous les squelettes pour être certain d’avoir la dernière version ; résultat : le temps d’exécution d’un squelette incluant va être plombé par le temps de compilation des squelettes inclus, bien qu’il ne compte pas son propre temps de compilation.

2. on se sert de la fonction time(), qui donne seulement l’heure qu’il est, autrement dit on mesure la charge globale du serveur, pas le temps CPU spécifique au code PHP exécuté.

3. si un squelette est inclus dans une boucle, le temps affiché par le débusqueur est celui du dernier passage dans la boucle,
non pas le temps cumulé de tous les passages (ça c’est un choix arbitraire qui pourrait être différent, mais il faut en être conscient).

Optimiser ensuite

Le mod profile permet de détecter quelles sont les boucles et les inclure les plus consommatrices. Il sera alors possible de chercher à les optimiser.

Par exemple : si une noisette incluse dans une page est fortement consommatrice de ressources, et qu’elle ne dépend pas du contexte, alors il vaut mieux le mettre dans un  : ainsi, le même cache sera partagé pour tous ses différents appels. ( Au contraire, avec un #INCLURE, le cache de la noisette sera recalculé pour chaque recalcul du squelette appelant. )