Trinidev

Yii a beau être un framework particulièrement véloce, un défaut de programmation ou une mauvaise requête SQL restent possibles. On n’est jamais à l’abris d’un bug sournois.

Lorsque des ralentissements surviennent, on se retrouve alors face à la question : « Mais ou mon programme passe tant de temps ? ».

On peut alors truffer son code de traces dans tous les sens afin d’aider à la résolution du mystère, mais cela est insuffisant lorsque la source du problème est externe au programme (mauvaise optimisation SQL, appel de web services peu réactifs…)

Yii propose un outil très intéressant permettant de répondre précisément à ce problème : le « Performance profiling« .

Il s’agit d’un type particulier d’enregistrement de traces, permettant de mesurer précisément le temps passé par l’exécution d’un bloc de code. Comment ça marche ?

1. Activation des messages de performance

Comme souvent dans Yii, direction le fichier de configuration de l’application.

Prenons comme exemple le fichier de configuration de l’application dé démonstration « blog » et modifions celui-ci de la manière suivante :

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57

return array(
	'basePath'=>dirname(__FILE__).DIRECTORY_SEPARATOR.'..',
	'name'=>'blog',
	'defaultController'=>'post',
 
	// preloading 'log' component
	'preload'=>array('log'),
 
	// autoloading model and component classes
	'import'=>array(
		'application.models.*',
		'application.components.*',
	),
 
	// application-level parameters that can be accessed
	// using Yii::app()->params['paramName']
	'params'=>require(dirname(__FILE__).'/params.php'),
 
	// application components
	'components'=>array(
		'log'=>array(
			'class'=>'CLogRouter',
			'routes'=>array(
				array(
					'class'=>'CFileLogRoute',
					'levels'=>'error, warning',
				),
				array(
					'class'=>'CProfileLogRoute',
				)
			),
		),
		'user'=>array(
			// enable cookie-based authentication
			'allowAutoLogin'=>true,
			// force 401 HTTP error if authentication needed
			'loginUrl'=>null,
		),
		'db'=>array(
			'connectionString'=>'sqlite:'.dirname(__FILE__).'/../data/blog.db',
			/* uncomment the following to use MySQL as database
			'connectionString'=>'mysql:host=localhost;dbname=blog',
			'username'=>'xyz',
			'password'=>'xxx',
			*/
		),
		'urlManager'=>array(
			'urlFormat'=>'path',
			'rules'=>array(
				'tag/'=>'post/list',
				'posts'=>'post/list',
				'post/'=>'post/show',
				'post/update/'=>'post/update',
			),
		),
	),
);

Ligne 28, le CLogRouter CProfileLogRoute a été ajouté. Cela permet d’activer les fonctions de profiling. Mais ça n’est pas suffisant. Il faut maintenant indiquer à Yii les blocs nécessitant les mesures de performance.

2. Marquage des blocs de code

Dans l’application blog, intéressons-nous au composant « TagCloud ». Supposons que nous souhaitions savoir combien de temps est passé à afficher cet élément. Rien de plus simple. Il suffit d’ouvrir le code du composant (protected/components/TagCloud.php) et de modifier la méthode renderContent en encadrant l’appel à la méthode render par des instruction Yii::beginProfile et Yii::endProfile comme suit :

1
2
3
4
5
6

	protected function renderContent()
	{
		Yii::beginProfile('Render tag cloud');
		$this->render('tagCloud');
		Yii::endProfile('Render tag cloud');
	}

En paramètre, on passe un identifiant (qui doit être unique au sein d’une même application) du bloc à faire apparaître dans le rapport. Pas plus compliqué que ça.

Allez hop, on affiche une page du blog pour voir…

3. Analyse des résultats.

… et voila le résultat :

Les informations de statistiques ont été ajoutées à la fin de la page (dans le même style que les messages de traces quand ils sont activés). On peut voir que la page a pris 0,15332 secondes et 1,4 Mo de mémoire au total pour s’exécuter. Et le bloc « Render tag cloud » que nous avons surveillé a mis 0,00923 secondes du temps total d’exécution. Si ce bloc avait été appelé plusieurs fois (dans une boucle par exemple), on pourrait également voir le temps moyen, minimum et maximum d’exécution du bloc en question.

Rien n’empêche d’ajouter autant de blocs que souhaités à condition que ceux-ci ne se chevauchent pas.

Voila un outil particulièrement utile pendant les phases de d’ajustement des performances d’une application. Je vous laisse consulter la documentation officielle de la classe CProfileLogRoute pour voir les différents paramètres possibles (dont l’affichage des résultats directement dans Firebug s’il est disponible).