Version 8 — Janvier 2013 — 41.105.xx.xx
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
Voir la doc sur http://www.spip.net/fr_article4453.html
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)
var_mode=debug présente notamment le code de chaque boucle
- dans sa forme native de morceau de squelette SPIP
- sous la forme de la requête SQL générée par le compilateur : dans les cas critiques (jointure automatique notamment), cela permet de vérifier comment SPIP comprend une boucle.
- sous la forme du code PHP généré par le compilateur
- sous la forme du code HTML généré par l’exécution et l’interrogation de la base de donnée
Dans la suite on s’intéresse à var_profile qui permet d’optimiser la charge serveur.
Il y a
L’impact global sur un serveur dépendent 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, dépend des durées de #CACHE paramétrées dans chacun des éléments de squelette, et de la fréquence de création de nouveaux contenus (via les forums publics, l’interface de saisie ou autres interfaces accessibles sur le site) dans la base de donnée, qui invalide 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.
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
ESJ :
<blockquote class="spip">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).
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 <INCLURE ...> : 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. )
Lorsqu’avec une ancienne version de spip il fallait plusieurs boucles, ou plusieurs boucles avec doublons, des critères apparus dans les versions récentes de spip, utilisés à bon escient, peuvent permettre de diminuer le nombre de boucles et la charge serveur :
- les critères conditionnels cumulés (exemple : <BOUCLE_v(FORUMS){id_article ?}{id_rubrique ?}>)
- utilisation de {fusion champ_sql}
Lorsqu’on boucle sur des tables non spip, on voit très bien que l’existence d’une clé ou d’un index judicieusement choisi permet de diviser les temps d’exécution d’une requête par 5 ou 10. Le tableau présenté par var_profile indique pour chaque boucle quelles sont les clés possibles et laquelle est utilisée. On voit aussi quand il n’y a pas d’index, et qu’il y a intérêt à en créer un !