XHProf est un outil de profilage hiérarchique pour PHP. Il relève
+les appels au niveau des fonctions et mesure inclusivement et
+exclusivement des métriques telles que le temps écoulé
+la charge CPU ou l’usage de la mémoire. Un profil de fonction peut être divisé selon ses appelants, ou ses appelés. Le composant qui extrait les données brutes est écrit en C
+et implémenté telle une extension PHP Zend.
+xhprof. XHProf a une interface utilisateur simple en HTML, (écrite en PHP).
+L’interface permet de visualiser et de partager facilement le résultat des profilages dans un navigateur.
+Un rendu sous forme de graphique est également disponible.
+
+
Les rapports fournis par XHProf permettent souvent de mieux comprendre +la structure du code qui est éxécuté. +Le rendu hiérarchique des rapports permet par exemple de déterminer +quelle chaîne d’appels mène à une fonction particulière. + +
XHProf propose également de comparer deux runs (résultat de profilage) +pour analyser les différences ou aggréger les résultat de multiples runs afin +d’analyser des données consolidées. +Les comparaisons et aggrégations de données permettent surtout de visualiser des données plates + +
XHProf est un outil de profilage très léger. Pendant la phase de collecte +Il garde une trace du nombre d’appels et des métriques inclusives viualisables en courbes dans le graphe d’appels dynamique d’un programme. +Il calcule les métriques exclusives dans la phase de rapport. +XHProf supporte les fonctions recursives en détectant les cycles dans la pile d’appels dès la capture des données et en utilisant un nom unique pour l’invocation principale.
+ +La nature légère d’XHProf, ses performances et ses possibilités de consolidations de données +en font un outil taillé pour les environnements de production [Voir les notes sur l’usage en production.] + +
XHProfLive (qui ne fait pas partie de ce kit open source), par exemple, +est un système de monitoring de performance utilsé chez Facebook et qui est bâti sur XHProf. +XHProfLive récupère en permanence les données de profilage en production en lançant XHProf sur un échantillon de pages +XHProfLive aggrège ensuite les données suivant des critères tels que le temps, type de pages, et peut aider à répondre à tout type de questions comme : +Quel est le profil de la pile d’appel pour une page spécifique ? Quel est le coût de la méthode "foo" dans toutes les pages, ou sur une page spécifique ? quelles fonctions ont régressé le plus depuis une heure, un jour pou un mois ? Quel est l’historique des tendances, des temps d’executions pour une page ou une fonction … + +
Développé à l’origine par Facebook, XHProf est maintenant open source depuis mars 2009.
+ + + + + +XHProf offre: + +
Un résumé des appels de fonctions avec des informations telles que le nombre d’appels, +inclusivement et exclusivement, les temps, la charge mémoire, et le temps processeur. + +
Pour chaque fonction, il fournit le détail des appels et le temps par +parent (appelant) & enfant (appelé), tel que : + +
Vous pouvez comparer les données de deux appels à XHProf pour des raisons diverses; +Pour voir ce qui cause une régression entre une version du code et une autre, +Pour évaluer l’impact sur les performances d’une évolution dans le code … + +
Une comparaison de rapport prends deux runs en entrée et produit à la fois des informations différencielles au niveau de la fonction, mais aussi des informations hiérarchiques (séparation des différences par fonction parente/enfant) pour chaque fonction. + +
La vue tabulaire (copie d’écran) du rapport différentiel pointe les plus grosses améliorations et régressions. + +
Cliquer sur un nom de fonction dans la bue tabulaire du rapport différentiel, mène à la vue hiérarchique +(ou vue parent/enfant) différentielle d’une fonction (copie d’écran). On peut ainsi avoir une séparation des différences par fonctions parent/enfant. + +
Les données du rapport peuvent également être visualisées sous forme de graphique. +Cette vue permet de mettre en lumière les chemins crtiques du programme. + +
Le mode profilage mémoire d’XHProf aide à isoler les fonctions qui occupent trop de mémoire. + +
On ne peut pas dire qu’XHProf trace exactement chaque opération +d’allocation/libération de mémoire, en effet il utilise un schéma simplistique; +Il trace les hausses et les baisse de besoin en mémoire allouée à PHP à chaque entré ou sortie de fonction. +Il trace aussi les hausses et baisses de pics mémoire alloués à chaque fonction PHP. + +
include, include_once, require and
+require_once comme si c’était des fonctions. Le nom du fichier inclus est utilisé pour nommer "fausses" fonctions.
+
+
+main(): Une fonction fictive qui est à la racine de la pile d’appel.
+
+
+load::<filename>
+et run_init::<filename>:
+
+XHProf trace les appels include/require comme des appels de fonction.
+
+
Par exemple, une inclusion include "lib/common.php"; va donner deux entrées pour XHProf : + +
load::lib/common.php - Cela représente le travail fait par l’interpréteur pour charger et compiler le fichier.
+[Note: Si vous utilisez un cache d’opcode PHP comme APC, alors la compilation intervient uniquement si le cahce est manquant dans APC.]
+
+run_init::lib/common.php - Cela répresente le code exécuté au niveau du fichier, soit le résultat de l’inclusion.
+
+foo@<n>: Implique un appel récursif de foo(), ou <n> représente le niveau de récursion.
+Cette récursion peut être directe comme foo() --> foo()), ou indirecte comme foo() --> goo() --> foo().
+
+Un vrai profileur hiérarchique trace toute la pile d’appel pour chaque donnée., et est capables de répondre aux questions comme : Quel était le coût du 3e appel de foo(), ou quel était le coût de bar() quand il était appelé par a()->b()->bar()? + +
+ +XHProf garde une trace d’un seul niveau dans le contexte de l’appel et est seulement capable de répondre aux questions à propos +d’une fonction qui regarde un niveau en dessus ou en dessous. +Il appraît que dans la majorité des cas c’est bien suffisant. +
+ +Pour mieux comprendre, regaredez l’exemple suivant : +
+ ++Vous avez: + 1 appel de a() --> c() + 1 appel de b() --> c() + 50 appels de c() --> d() ++ +
Quand XHProf peut vous dire que d() a été appelé par c() 50 fois, il ne peut pas vous dire +combien d’appels dont dus à a() ou b(). +[On peut imaginer que c’est peut être 25 pour a() et 25 pour b(), mais ce n’est pas nécéssairement vrai.] +
+ +De toutes façons en pratique ce n’est pas vraiment une limitation. +
+ +L’extension se trouve dans le sous-répertoire "extension/". + +
Note: Le portage pour Windows n’est pas encore implémenté. Nous avons testé XHProf sur Linux/FreeBSD.
+[NDT : Il existe un fork avec un portage Windows sur Github]
+
+
La version 0.9.2 et les précédentes sont aussi censées fonctionner sur Mac +OS. [Cela a été testé sur Mac OS 10.5.] + +
Note: XHProf utilise les insctructions RDTSC (time stamp counter)
+pour implémenter un compteur de temps vraiment bas niveau. C’est pourquoi actuellement xhprof fonctionne uniquement sur une architecture x86.
+Aussi tant que les valeurs de RDTSC ne pourront pas être synchronisées entre plusieurs CPUs,
+xhprof n’en utilisera qu’un seul lors du profilage.
+
+
Le timer XHProf bzasé sur RDTSC ne fonctionen pas parfaitement si la techno +SpeedStep est activée. Cette technologie est disponible sur certains processeurs Intel. +[Note: Les Macs ont typiquement cette fonctionnalité d’activée par défaut, il faut donc la désactiver pour utiliser XHProf.] + +
Les étapes suivantes sont prévues pour un environnement Linux/Unix. + + +
+% cd <repertoire_source_xhprof>/extension/ +% phpize +% ./configure --with-php-config=<chemin vers php-config> +% make +% make install +% make test ++ + +
php.ini file: Vous pouvez mettre à jour votre fichier +php.ini file afin qu’il charge automatiquement votre extension en ajoutant le code suivant : + +
+[xhprof] +extension=xhprof.so +; +; répertoire utilisé par l’implémentation par défaut de l’interface iXHProfRuns +; (nommée, XHProfRuns_Default class) pour stocker les runs XHProf. +; +xhprof.output_dir=<repertoire_pour_stocker_les_runs_xhprof> ++ + +
Test de génération de donées brutes avec l’exemple simple d’un programme tel que : + +
foo.php +
+<?php
+
+function bar($x) {
+ if ($x > 0) {
+ bar($x - 1);
+ }
+}
+
+function foo() {
+ for ($idx = 0; $idx < 2; $idx++) {
+ bar($idx);
+ $x = strlen("abc");
+ }
+}
+
+// début du profileur
+xhprof_enable();
+
+// début du programme
+foo();
+
+// attêt du profileur
+$xhprof_data = xhprof_disable();
+
+// affichage des données de profilage brutes
+print_r($xhprof_data);
+
+
+
+Lancez ce programme : + +
+% php -dextension=xhprof.so foo.php ++ +
Vous devez avoir un résultat tel que : + +
+Array +( + [foo==>bar] => Array + ( + [ct] => 2 # 2 appels de bar() depuis foo() + [wt] => 27 # temps inclusif dans bar() quand il est appelé par foo() + ) + + [foo==>strlen] => Array + ( + [ct] => 2 + [wt] => 2 + ) + + [bar==>bar@1] => Array # un appelrécursif à bar() + ( + [ct] => 1 + [wt] => 2 + ) + + [main()==>foo] => Array + ( + [ct] => 1 + [wt] => 74 + ) + + [main()==>xhprof_disable] => Array + ( + [ct] => 1 + [wt] => 0 + ) + + [main()] => Array # fausse fonction représentant la racine + ( + [ct] => 1 + [wt] => 83 + ) + +) ++ +
Note: Les données brutes contienent uniquement les métriques inclusives. +Par exemple les données brutes du tableau de données temporelles represente les temps inclusifs en microsecondes. +Les temps exclusifs sont calculés pour chaque fonction lors de la phase d’analyse et de rapport. + +
Note: Par défault suelemnt le nombre d’appel & et le temps passé sont profilés. +Vous pouvez aussi profilerle temps CPU et/ou la charge mémoire. Remplacez, + +
+xhprof_enable(); ++dans le programme précédent avec, par exemple : +
+xhprof_enable(XHPROF_FLAGS_CPU + XHPROF_FLAGS_MEMORY); ++ +
Vous aurez en sortie : + +
+Array +( + [foo==>bar] => Array + ( + [ct] => 2 # nombre d’appel à bar() depuis foo() + [wt] => 37 # tempas passé dans bar() quand appel de foo() + [cpu] => 0 # temps cpu time dans bar() quand appel de foo() + [mu] => 2208 # changement dans l’usage de la mémoire par PHP dans bar() quand appel de foo() + [pmu] => 0 # changement dans l’usage de pic mémoire par PHP pour bar() quand appel de foo() + ) + + [foo==>strlen] => Array + ( + [ct] => 2 + [wt] => 3 + [cpu] => 0 + [mu] => 624 + [pmu] => 0 + ) + + [bar==>bar@1] => Array + ( + [ct] => 1 + [wt] => 2 + [cpu] => 0 + [mu] => 856 + [pmu] => 0 + ) + + [main()==>foo] => Array + ( + [ct] => 1 + [wt] => 104 + [cpu] => 0 + [mu] => 4168 + [pmu] => 0 + ) + + [main()==>xhprof_disable] => Array + ( + [ct] => 1 + [wt] => 1 + [cpu] => 0 + [mu] => 344 + [pmu] => 0 + ) + + [main()] => Array + ( + [ct] => 1 + [wt] => 139 + [cpu] => 0 + [mu] => 5936 + [pmu] => 0 + ) + +) ++ +
Éviter les fonctions natives lors du profilage + +
Par défault les fonctions natives de PHP (comme strlen) sont profilées.
+Si vous ne voulez pas les profiler (pour simplifier le résultat et la taille des données brutes générées),
+Vous pouvez utiliser le drapeau XHPROF_FLAGS_NO_BUILTINS comme dans l’exemple ci-dessous :
+
+
+// ne pas profiler les fonctions natives +xhprof_enable(XHPROF_FLAGS_NO_BUILTINS); ++ + +
Ignorer des fonctions spécfiques lors du profilage (0.9.2 ou plus récent) + +
À partir de la version 0.9.2 d’XHProf, vous pouvez spécifier une liste de
+fonctions à ignorer pendant le profilage. Cela vous permet de ne pas prendre en compte par exemple
+des fonctions utilisées pour des appels indirects comme call_user_func et call_user_func_array.
+Ces fonctions intermédiaires compliquent inutilement la hirarchie des appels et rendent plus ardue l’interprétation des rapports en brouillant les relations parent/enfant.
+
+
Pour spécifier cette liste de fonctions à ignorer durant le profilage, il suffit d’utiliser le second paramètre (optionnel) de xhprof_enable.
+Par exemple,
+
+
+
+
+// temps passé en profilage; ignore les appels de call_user_func* pendant le profilage
+xhprof_enable(0,
+ array('ignored_functions' => array('call_user_func',
+ 'call_user_func_array')));
+
+or,
+
+// tempas pasé en profilage + profilage mémoire; ignore call_user_func* durant le profilage
+xhprof_enable(XHPROF_FLAGS_MEMORY,
+ array('ignored_functions' => array('call_user_func',
+ 'call_user_func_array')));
+
+
+
+
+l’interface graphique d’XHProf est implémentée en PHP. Le code est divisé en deux sous-répertoires,
+xhprof_html/ and xhprof_lib/.
+
+
Le répertoire xhprof_html contient les 3 pages PHP principales.
+
+
index.php: Pour visualiser un run ou un différentiel entre deux runs.
+callgraph.php: Pour visualiser sous la forme de graphique avec un rendu en image.
+typeahead.php: Utilisé implicitement pour les fonctions de gestion de pile sur un rapport XHProf.
+Le répertoire xhprof_lib contient le code pour l’analyse et l’affichage.
+(calcul sur les informations de profilage, calcul des différentiels, aggrégation de données, etc.).
+
+
Configuration du server web : Vous devez vous assurer que le répertoire
+xhprof_html/ est accessible depuis le serveur web, et qu’il est configuré pour éxécuter des scripts PHP.
+
+
Gérer les runs XHProf + +
Les clients web ont une certaine souplesse dans la manière de sauvegarder les données brutes fournies par XHProf. +XHProf expose une interface utilisateur nommée iXHProfRuns (voir xhprof_lib/utils/xhprof_runs.php) que les clients peuvent implémenter. +Cela permet aux clients de préciser comment afficher les donées des runs. + +
L’interface utilisateur d’XHProf fournit une implementation par défaut nommée, +"XHProfRuns_Default" (aussi dans xhprof_lib/utils/xhprof_runs.php). +L’implementation par d"faut stocke les runs dans le répertoire définit par le paramètre INI : +xhprof.output_dir. + +
Un run XHProf doit être définit de manière unique par un espace de nom et un identifiant de run. + +
a) Sauver les données XHProf de façon persistente : + +
Soit si vous utilisez l’interface par défaut,
+XHProfRuns_Default qui implémente
+iXHProfRuns, Un run XHProf sauvegardé ressemble au code suivant :
+
+
+
+// début du profilage +xhprof_enable(); + +// lancement du programme +... + +// fin du profilage +$xhprof_data = xhprof_disable(); + +// +// Sauvegarde du run XHProf +// en utilisant l’implementation par défaut de iXHProfRuns. +// +include_once $XHPROF_ROOT . "/xhprof_lib/utils/xhprof_lib.php"; +include_once $XHPROF_ROOT . "/xhprof_lib/utils/xhprof_runs.php"; + +$xhprof_runs = new XHProfRuns_Default(); + +// sauvegarde du run avec l’espace de nom "xhprof_foo". +// +// **NOTE**: +// par défault save_run() va automatiquement générer un identifiant de run +// unique. [Vous pouvez surcharger cette donnée en passant l’identifiant en paramètre optionnel +// à la méthode save_run().] +// +$run_id = $xhprof_runs->save_run($xhprof_data, "xhprof_foo"); + +echo "---------------\n". + "En partant du principe que vous avez parametré l’interface utilisateur http \n". + "XHProf, vous pouvez visualiser les runs avec l’adresse : \n". + "http://<adresse-interface-utilisateur-xhprof>/index.php?run=$run_id&source=xhprof_foo\n". + "---------------\n"; + ++ +
La suite permet de sauvegarder le run sous forme d’un fichier dans le répertoire spécifié
+par le paramètre ini xhprof.output_dir. Le nom du fichier doit être de la forme
+49bafaa3a3f66.xhprof_foo; Les deux parties du nom sont formées par l’identifiant du run
+("49bafaa3a3f66") et l’espace de nom ("xhprof_foo"). [Si vous souhaitez créer un identifiant de run vous-même
+(comme une sequence de base de données, ou un timestamp), vous pouvez explicitementpasser l’identifiant
+du run à la méthode save_run.
+
+
b) En utilisant votre propre implementation d’iXHProfRuns + +
Si vous décidez de stocker différement les runs XHProf +(soit dans un format compressé, dans une base de données, +etc.), vous aurez besoin d’implémenter une classe qui implémente l’interface +iXHProfRuns(). + +
Vous devrez également modifier les 3 pages PHP d’entrée (index.php,
+callgraph.php, typeahead.php) dans le répertoire "xhprof_html/" pour utiliser la
+nouvelle interface au lieu de celle par défaut (XHProfRuns_Default),
+changez cette ligne dans les 3 fichier.
+
+
+$xhprof_runs_impl = new XHProfRuns_Default(); ++ +
Vous aurez aussi besoin d’inclure le fichier qui implémente votre classe dans les fichiers cités. + +
Acceéder aux runs depuis l’interface utilisateur + +
a) Voir un rapport simple + +
Pour voir un rapport avec l’identifiant <run_id> et l’espace de nom +<namespace> utilisez une url de la forme : + +
+http://<adresse-interface-utilisateur-xhprof>/index.php?run=<run_id>&source=<namespace>
+
+
+
Par example, +
+http://<adresse-interface-utilisateur-xhprof>/index.php?run=49bafaa3a3f66&source=xhprof_foo
+
+
+
b) Voir un rapport différentiel + +
Pour voir un rapport avec les identifiants <run_id1> et +<run_id2> et l’espace de nom <namespace> utilisez une url de la forme : + +
+http://<adresse-interface-utilisateur-xhprof>/index.php?run1=<run_id1>&run2=<run_id2>&source=<namespace>
+
+
+
c) Voir un rapport d’aggrégation + +
Vous pouvez aussi spécifier un ensemble de runspour lesquels vous souhaitez un rapport d’aggrégation. + +
Si vous avez trois runs XHProf avec les identifiants 1, 2 & 3 pour l’espace de noms +"benchmark". Pour voir l’aggrégation de ces trois runs : + +
+http://<adresse-interface-utilisateur-xhprof>/index.php?run=1,2,3&source=benchmark
+
Aggrégations pondérées: En supposant que les trois runs +correspondent à trois types de programmes p1.php, p2.php and p3.php +qui occupent chacun respectivement 20%, 30% et 50%. Pour voir un rapport d’aggrégation +pondéré par les poids des runs : + +
+http://<adresse-interface-utilisateur-xhprof>/index.php?run=1,2,3&wts=20,30,50&source=benchmark
+
Quelques observations qui peuvent faire varier votre expérience : + +
Nous recommandons d’utiliser le mode de profilage "temps passé" + "memoire" en production. +[Note: Le surplus de temps passé par le mode de profilage mémoire est non significatif.] + +
+ // profilage du temps passé (par défault) + profilage mémoire + xhprof_enable(XHPROF_FLAGS_MEMORY); ++
Pour profiler 1/10000 de vos requêtes, définissez le début du profilage avec un code dans l’esprit de celui-ci : + +
+ if (mt_rand(1, 10000) == 1) {
+ xhprof_enable(XHPROF_FLAGS_MEMORY);
+ $xhprof_on = true;
+ }
+À la fin de la requête (ou dans une fonction de finalisation de la requête), vous pouvez faire quelque chose comme : + +
+ if ($xhprof_on) {
+ // fin du profilage
+ $xhprof_data = xhprof_disable();
+
+ // sauvegarde $xhprof_data quelquepart (base de données centralisée …)
+ ...
+ }
+ Vous pouvez alors récupérer et aggréger ces profilages par horaire
+(par exemple 5 minutes, par jour, par jour …), par page ou type de requête, ou n’importe quel
+paramètre utilisé par xhprof_aggregate_runs().
+
+
+
+
L’extension XHProf propose aussi un mode très léger d’échantillonage. +L’intervalle est de 0,1 seconde. Les échantillons enregistrent l’ensemble des données. +Ce mode peut être très utile pour avoir un impact le plus négligeable possible, et permettre +Le mode sample peut être utile si vous désirez un moyen avec peu de dépassement de faire de la surveillance de performances et des diagnostics. + +
Les très pertinentes fonctions utilisées par l’extension pour utiliser le mode
+d’échantillonage sont xhprof_sample_enable() et xhprof_sample_disable().
+
+
[TBD: Documentation plus détaillée pour le mode d’échantillonage.] + +
Le fichier XHProf_lib/utils/xhprof_lib.php contient
+des librairies de fonctions additionellesqui peuvent être utilisées pour manipuler
+et aggréger les runs XHProf.
+
+
Par exemple: + +
xhprof_aggregate_runs():
+peut être utilisé pour aggréger de multiples runs XHProf runs dans un seul run.
+Cela peut être très utile pour fabriquer un outil de monitoring utilisant XHProf et à l’échelle voulue.
+[Par exemple, vous pouvez mixer des runs XHProf issus périodiquement
+d’échantillonage de la production pour générer des rapport journalier.]
+
+xhprof_prune_run(): Aggréger une grande quantité de runs
+(particulièrement si ils correspondent à des zones différentes du programme) peut créer un rendu
+graphique beaucoup trop gros. Vous pouvez donc utiliser la fonction xhprof_prune_run
+élaguer les données à afficher. En supprimant des branches qui compte pour une partie négligeable du temps passé.
+
+xhprof_html/jquery.
+
+Le rendu HTML et l’interface de navigation pour consulter les résultat du profilage sont inspirés par un outil similaire +qui existe pour les procédures stockées PL/SQL d’Oracle. Mais c’est là que la comparaison s’arrête; +Le fonctionnement interne du profileur étant assez différent + +[NDT : Merci à Rudy Rigot (@rudyrigot) pour sa relecture attentive ] +
XHProf is a hierarchical profiler for PHP. It reports
+function-level call counts and inclusive and
+exclusive metrics such as wall (elapsed)
+time, CPU time and memory usage. A function's profile can be broken
+down by callers or callees. The raw data collection component is
+implemented in C as a PHP Zend extension called
+xhprof. XHProf has a simple HTML based user
+interface (written in PHP). The browser based UI for viewing profiler
+results makes it easy to view results or to share results with peers.
+A callgraph image view is also supported.
+
+
XHProf reports can often be helpful in understanding the structure +of the code being executed. The hierarchical nature of the reports can +be used to determine, for example, what chain of calls led to a +particular function getting called. + +
XHProf supports ability to compare two runs (a.k.a. "diff" reports) +or aggregate data from multiple runs. Diff and aggregate reports, much +like single run reports, offer "flat" as well as "hierarchical" views +of the profile. + +
XHProf is a light-weight instrumentation based profiler. During the +data collection phase, it keeps track of call counts and inclusive +metrics for arcs in the dynamic callgraph of a program. It computes +exclusive metrics in the reporting/post processing phase. XHProf +handles recursive functions by detecting cycles in the callgraph at +data collection time itself and avoiding the cycles by giving unique +depth qualified names for the recursive invocations. +
+ +XHProf's light-weight nature and aggregation capabilities make it +well suited for collecting "function-level" performance statistics +from production environments. [See additional notes for use in production.] + +
XHProfLive (not part of the open source kit), for example, is a +system-wide performance monitoring system in use at Facebook that is +built on top of XHProf. XHProfLive continually gathers function-level +profiler data from production tier by running a sample of page +requests under XHProf. XHProfLive then aggregates the profile data +corresponding to individual requests by various dimensions such as +time, page type, and can help answer a variety of questions such as: +What is the function-level profile for a specific page? How expensive +is function "foo" across all pages, or on a specific page? What +functions regressed most in the last hour/day/week? What is the +historical trend for execution time of a page/function? and so on. + +
Originally developed at Facebook, XHProf was open sourced in Mar, 2009.
+ + + + + +XHProf provides: + +
Function-level summary information such as number of calls, +inclusive/exclusive wall time, memory usage, and CPU time. + +
For each function, it provides a breakdown of calls and times per +parent (caller) & child (callee), such as: + +
You may want to compare data from two XHProf runs for various +reasons-- to figure out what's causing a regression between one +version of the code base to another, to evaluate the performance +improvement of a code change you are making, and so on. + +
A diff report takes two runs as input and provides both flat +function-level diff information, and hierarchical information +(breakdown of diff by parent/children functions) for each function. + +
The "flat" view (sample screenshot) in the diff report points out the top +regressions & improvements. + +
Clicking on functions in the "flat" view of the diff report, leads +to the "hierarchical" (or parent/child) diff view of a function (sample screenshot). We can get a +breakdown of the diff by parent/children functions. + + +
The profile data can also be viewed as a callgraph. The callgraph +view highlights the critical path of the program. + + +
XHProf's memory profile mode helps track functions that +allocate lots of memory. + +
It is worth clarifying that that XHProf doesn't strictly track each +allocation/free operation. Rather it uses a more simplistic +scheme. It tracks the increase/decrease in the amount of memory +allocated to PHP between each function's entry and exit. It also +tracks increase/decrease in the amount of peak memory allocated to +PHP for each function. + +
include, include_once, require and
+require_once operations as if they were functions. The name of
+the file being included is used to generate the name for these "fake" functions.
+
+
+main(): a fictitious function that is at the root of the call graph.
+
+
+load::<filename>
+and run_init::<filename>:
+
+XHProf tracks PHP include/require operations as
+function calls.
+
+
For example, an include "lib/common.php"; operation will +result in two XHProf function entries: + +
load::lib/common.php - This represents the work done by the
+interpreter to compile/load the file. [Note: If you are using a PHP
+opcode cache like APC, then the compile only happens on a cache miss
+in APC.]
+
+run_init::lib/common.php - This represents
+initialization code executed at the file scope as a result of the
+include operation.
+
+foo@<n>: Implies that this is a
+recursive invocation of foo(), where <n> represents
+the recursion depth. The recursion may be direct (such as due to
+foo() --> foo()), or indirect (such as
+due to foo() --> goo() --> foo()).
+
+True hierarchical profilers keep track of a full call stack at +every data gathering point, and are later able to answer questions +like: what was the cost of the 3rd invokation of foo()? or what was +the cost of bar() when the call stack looked like +a()->b()->bar()? + +
+ +XHProf keeps track of only 1-level of calling context and is +therefore only able to answer questions about a function looking +either 1-level up or 1-level down. It turns out that in practice this +is sufficient for most use cases. +
+ +To make this more concrete, take for instance the following +example. +
+ ++Say you have: + 1 call from a() --> c() + 1 call from b() --> c() + 50 calls from c() --> d() ++ +
While XHProf can tell you that d() was called from c() 50 times, it +cannot tell you how many of those calls were triggered due to a() +vs. b(). [We could speculate that perhaps 25 were due to a() and 25 +due to b(), but that's not necessarily true.] +
+ +In practice however, this isn't a very big limitation. +
+ +The extension lives in the "extension/" sub-directory. + +
Note: A windows port hasn't been implemented yet. We have
+tested xhprof on Linux/FreeBSD so far.
+
+
Version 0.9.2 and above of XHProf is also expected to work on Mac +OS. [We have tested on Mac OS 10.5.] + +
Note: XHProf uses the RDTSC instruction (time stamp counter)
+to implement a really low overhead timer for elapsed time. So at the
+moment xhprof only works on x86 architecture.
+Also, since RDTSC values may not be synchronized across CPUs,
+xhprof binds the program to a single CPU during the
+profiling period.
+
+
XHProf's RDTSC based timer functionality doesn't work correctly if +SpeedStep technology is turned on. This technology is available on +some Intel processors. [Note: Mac desktops and laptops typically have +SpeedStep turned on by default. To use XHProf, you'll need to disable +SpeedStep.] + +
The steps +below should work for Linux/Unix environments. + + +
+% cd <xhprof_source_directory>/extension/ +% phpize +% ./configure --with-php-config=<path to php-config> +% make +% make install +% make test ++ + +
php.ini file: You can update your +php.ini file to automatically load your extension. Add the following +to your php.ini file. + +
+[xhprof] +extension=xhprof.so +; +; directory used by default implementation of the iXHProfRuns +; interface (namely, the XHProfRuns_Default class) for storing +; XHProf runs. +; +xhprof.output_dir=<directory_for_storing_xhprof_runs> ++ + +
Test generating raw profiler data using a sample test program like: + +
foo.php +
+<?php
+
+function bar($x) {
+ if ($x > 0) {
+ bar($x - 1);
+ }
+}
+
+function foo() {
+ for ($idx = 0; $idx < 2; $idx++) {
+ bar($idx);
+ $x = strlen("abc");
+ }
+}
+
+// start profiling
+xhprof_enable();
+
+// run program
+foo();
+
+// stop profiler
+$xhprof_data = xhprof_disable();
+
+// display raw xhprof data for the profiler run
+print_r($xhprof_data);
+
+
+
+Run the above test program: + +
+% php -dextension=xhprof.so foo.php ++ +
You should get an output like: + +
+Array +( + [foo==>bar] => Array + ( + [ct] => 2 # 2 calls to bar() from foo() + [wt] => 27 # inclusive time in bar() when called from foo() + ) + + [foo==>strlen] => Array + ( + [ct] => 2 + [wt] => 2 + ) + + [bar==>bar@1] => Array # a recursive call to bar() + ( + [ct] => 1 + [wt] => 2 + ) + + [main()==>foo] => Array + ( + [ct] => 1 + [wt] => 74 + ) + + [main()==>xhprof_disable] => Array + ( + [ct] => 1 + [wt] => 0 + ) + + [main()] => Array # fake symbol representing root + ( + [ct] => 1 + [wt] => 83 + ) + +) ++ +
Note: The raw data only contains "inclusive" metrics. For +example, the wall time metric in the raw data represents inclusive +time in microsecs. Exclusive times for any function are computed +during the analysis/reporting phase. + +
Note: By default only call counts & elapsed time is profiled. +You can optionally also profile CPU time and/or memory usage. Replace, + +
+xhprof_enable(); ++in the above program with, for example: +
+xhprof_enable(XHPROF_FLAGS_CPU + XHPROF_FLAGS_MEMORY); ++ +
You should now get an output like: + +
+Array +( + [foo==>bar] => Array + ( + [ct] => 2 # number of calls to bar() from foo() + [wt] => 37 # time in bar() when called from foo() + [cpu] => 0 # cpu time in bar() when called from foo() + [mu] => 2208 # change in PHP memory usage in bar() when called from foo() + [pmu] => 0 # change in PHP peak memory usage in bar() when called from foo() + ) + + [foo==>strlen] => Array + ( + [ct] => 2 + [wt] => 3 + [cpu] => 0 + [mu] => 624 + [pmu] => 0 + ) + + [bar==>bar@1] => Array + ( + [ct] => 1 + [wt] => 2 + [cpu] => 0 + [mu] => 856 + [pmu] => 0 + ) + + [main()==>foo] => Array + ( + [ct] => 1 + [wt] => 104 + [cpu] => 0 + [mu] => 4168 + [pmu] => 0 + ) + + [main()==>xhprof_disable] => Array + ( + [ct] => 1 + [wt] => 1 + [cpu] => 0 + [mu] => 344 + [pmu] => 0 + ) + + [main()] => Array + ( + [ct] => 1 + [wt] => 139 + [cpu] => 0 + [mu] => 5936 + [pmu] => 0 + ) + +) ++ +
Skipping builtin functions during profiling + +
By default PHP builtin functions (such as strlen) are
+profiled. If you do not want to profile builtin functions (to either
+reduce the overhead of profiling further or size of generated raw
+data), you can use the XHPROF_FLAGS_NO_BUILTINS
+flag as in for example:
+
+
+// do not profile builtin functions +xhprof_enable(XHPROF_FLAGS_NO_BUILTINS); ++ + +
Ignoring specific functions during profiling (0.9.2 or higher) + +
Starting with release 0.9.2 of xhprof, you can tell XHProf to
+ignore a specified list of functions during profiling. This allows you
+to ignore, for example, functions used for indirect function calls
+such as call_user_func and
+call_user_func_array. These intermediate functions
+unnecessarily complicate the call hierarchy and make the XHProf
+reports harder to interpret since they muddle the parent-child
+relationship for functions called indirectly.
+
+
To specify the list of functions to be ignored during profiling
+use the 2nd (optional) argument to xhprof_enable.
+For example,
+
+
+
+
+// elapsed time profiling; ignore call_user_func* during profiling
+xhprof_enable(0,
+ array('ignored_functions' => array('call_user_func',
+ 'call_user_func_array')));
+
+or,
+
+// elapsed time + memory profiling; ignore call_user_func* during profiling
+xhprof_enable(XHPROF_FLAGS_MEMORY,
+ array('ignored_functions' => array('call_user_func',
+ 'call_user_func_array')));
+
+
+
+
+The XHProf UI is implemented in PHP. The code resides in two
+subdirectories, xhprof_html/ and xhprof_lib/.
+
+
The xhprof_html directory contains the 3 top-level PHP pages.
+
+
index.php: For viewing a single run or diff report.
+callgraph.php: For viewing a callgraph of a XHProf run as an image.
+typeahead.php: Used implicitly for the function typeahead form
+on a XHProf report.
+The xhprof_lib directory contains supporting code for
+display as well as analysis (computing flat profile info, computing
+diffs, aggregating data from multiple runs, etc.).
+
+
Web server config: You'll need to make sure that the
+xhprof_html/ directory is accessible from your web server, and that
+your web server is setup to serve PHP scripts.
+
+
Managing XHProf Runs + +
Clients have flexibility in how they save the XHProf raw data +obtained from an XHProf run. The XHProf UI layer exposes an interface +iXHProfRuns (see xhprof_lib/utils/xhprof_runs.php) that clients can +implement. This allows the clients to tell the UI layer how to fetch +the data corresponding to a XHProf run. + +
The XHProf UI libaries come with a default file based +implementation of the iXHProfRuns interface, namely +"XHProfRuns_Default" (also in xhprof_lib/utils/xhprof_runs.php). +This default implementation stores runs in the directory specified by +xhprof.output_dir INI parameter. + +
A XHProf run must be uniquely identified by a namespace and a run +id. + + + +
a) Saving XHProf data persistently: + +
Assuming you are using the default implementation
+XHProfRuns_Default of the
+iXHProfRuns interface, a typical XHProf run
+followed by the save step might look something like:
+
+
+
+// start profiling +xhprof_enable(); + +// run program +.... + +// stop profiler +$xhprof_data = xhprof_disable(); + +// +// Saving the XHProf run +// using the default implementation of iXHProfRuns. +// +include_once $XHPROF_ROOT . "/xhprof_lib/utils/xhprof_lib.php"; +include_once $XHPROF_ROOT . "/xhprof_lib/utils/xhprof_runs.php"; + +$xhprof_runs = new XHProfRuns_Default(); + +// Save the run under a namespace "xhprof_foo". +// +// **NOTE**: +// By default save_run() will automatically generate a unique +// run id for you. [You can override that behavior by passing +// a run id (optional arg) to the save_run() method instead.] +// +$run_id = $xhprof_runs->save_run($xhprof_data, "xhprof_foo"); + +echo "---------------\n". + "Assuming you have set up the http based UI for \n". + "XHProf at some address, you can view run at \n". + "http://<xhprof-ui-address>/index.php?run=$run_id&source=xhprof_foo\n". + "---------------\n"; + ++ +
The above should save the run as a file in the directory specified
+by the xhprof.output_dir INI parameter. The file's
+name might be something like
+49bafaa3a3f66.xhprof_foo; the two parts being the
+run id ("49bafaa3a3f66") and the namespace ("xhprof_foo"). [If you
+want to create/assign run ids yourself (such as a database sequence
+number, or a timestamp), you can explicitly pass in the run id to the
+save_run method.
+
+
+
b) Using your own implementation of iXHProfRuns + +
If you decide you want your XHProf runs to be stored differently +(either in a compressed format, in an alternate place such as DB, +etc.) database, you'll need to implement a class that implements the +iXHProfRuns() interface. + +
You'll also need to modify the 3 main PHP entry pages (index.php,
+callgraph.php, typeahead.php) in the "xhprof_html/" directory to use
+the new class instead of the default class XHProfRuns_Default.
+Change this line in the 3 files.
+
+
+$xhprof_runs_impl = new XHProfRuns_Default(); ++ +
You'll also need to "include" the file that implements your class in +the above files. + + +
Accessing runs from UI + +
a) Viewing a Single Run Report + +
To view the report for run id say <run_id> and namespace +<namespace> use a URL of the form: + +
+http://<xhprof-ui-address>/index.php?run=<run_id>&source=<namespace>
+
+
+
For example, +
+http://<xhprof-ui-address>/index.php?run=49bafaa3a3f66&source=xhprof_foo
+
+
+
+
b) Viewing a Diff Report + +
To view the report for run ids say <run_id1> and +<run_id2> in namespace <namespace> use a URL of the form: + +
+http://<xhprof-ui-address>/index.php?run1=<run_id1>&run2=<run_id2>&source=<namespace>
+
+
+
c) Aggregate Report + +
You can also specify a set of run ids for which you want an aggregated view/report. + +
Say you have three XHProf runs with ids 1, 2 & 3 in namespace +"benchmark". To view an aggregate report of these runs: + +
+http://<xhprof-ui-address>/index.php?run=1,2,3&source=benchmark
+
Weighted aggregations: Further suppose that the above three runs +correspond to three types of programs p1.php, p2.php and p3.php that +typically occur in a mix of 20%, 30%, 50% respectively. To view an +aggregate report that corresponds to a weighted average of these runs +using: + +
+http://<xhprof-ui-address>/index.php?run=1,2,3&wts=20,30,50&source=benchmark
+
Some observations/guidelines. Your mileage may vary: + +
We recommend using elapsed time + memory profiling mode in +production. [Note: The additional overhead of memory profiling +mode is really low.] + +
+ // elapsed time profiling (default) + memory profiling + xhprof_enable(XHPROF_FLAGS_MEMORY); ++
To profile say 1/10000 of your requests, instrument the beginning of +your request processing with something along the lines of: + +
+ if (mt_rand(1, 10000) == 1) {
+ xhprof_enable(XHPROF_FLAGS_MEMORY);
+ $xhprof_on = true;
+ }
+At the end of the request (or in a request shutdown function), you might +then do something like: + +
+ if ($xhprof_on) {
+ // stop profiler
+ $xhprof_data = xhprof_disable();
+
+ // save $xhprof_data somewhere (say a central DB)
+ ...
+ }
+ You can then rollup/aggregate these individual profiles by time
+(e.g., 5 minutely/hourly/daily basis), page/request type,or other
+dimensions using xhprof_aggregate_runs().
+
+
+
+
+
The xhprof extension also provides a very light weight sampling +mode. The sampling interval is 0.1 secs. Samples record the full +function call stack. The sampling mode can be useful if an extremely +low overhead means of doing performance monitoring and diagnostics is +desired. + +
The relevant functions exposed by the extension for using the
+sampling mode are xhprof_sample_enable() and
+xhprof_sample_disable().
+
+
+
[TBD: more detailed documentation on sampling mode.] + + +
The xhprof_lib/utils/xhprof_lib.php file contains
+additional library functions that can be used for manipulating/
+aggregating XHProf runs.
+
+
For example: + +
xhprof_aggregate_runs():
+can be used to aggregate multiple XHProf runs into a single run. This
+can be helpful for building a system-wide "function-level" performance
+monitoring tool using XHProf. [For example, you might to roll up
+XHProf runs sampled from production periodically to generate hourly,
+daily, reports.]
+
+xhprof_prune_run(): Aggregating large number of
+XHProf runs (especially if they correspond to different types of
+programs) can result in the callgraph size becoming too large. You can
+use xhprof_prune_run function to prune the callgraph data
+by editing out subtrees that account for a very small portion of the
+total time.
+
+xhprof_html/jquery subdirectory.
+
+The HTML-based navigational interface for browsing profiler results +is inspired by that of a similar tool that exists for Oracle's stored +procedure language, PL/SQL. But that's where the similarity ends; the +internals of the profiler itself are quite different. + +