Graphes d’appels
Motivation
Dans la partie sur perf trace
, nous avons vu que la mesure de graphes
d’appels nous permet de comprendre l’origine d’une activité
système. Dans le cadre de perf report
, cette
mesure est aussi possible, et même très utile :
- Elle nous permet de discriminer des appels à une fonction qui surviennent pour différentes raisons. Dans notre exemple, nous pouvons ainsi savoir quelles parties du code passent le plus de temps à appeler l’allocateur mémoire, afin de prioriser les optimisations associées.
- Elle nous permet d’acquérir une vision plus haut niveau de l’activité système de notre programme. Dans notre exemple, nous n’avons plus besoin de nous préoccuper de détails d’implémentation de l’allocateur mémoire pour effectuer notre analyse.
Cependant, il y a aussi quelques nouvelles précautions à prendre par rapport à
perf trace
, qui sont principalement liées au fait que…
perf record
est généralement utilisée pour échantillonner à haute fréquence (ex: par défaut, on échantillonne le pointeur d’instruction à plusieurs kHz), là oùperf trace
est principalement pensée pour suivre des appels système relativement peu fréquents.perf record
produit un fichierperf.data
en sortie au lieu de traiter les données à la volée, ce qui peut créer un goulot d’étranglement en termes de bande passante de stockage ou bien perturber l’exécution d’un benchmark sensible à la performance de stockage.
Pour éviter ces problèmes, on voudra généralement spécifier manuellement une fréquence d’échantillonnage peu élevée et parfois écrire les données de sortie en RAM.
Exemple DWARF
Voici un premier exemple de cycle perf record
/report
qui prend ces deux
précautions, en utilisant des graphes d’appels basées sur les informations de
déboguage
(qui constituent, pour rappel, le meilleur choix par défaut quand on est
indécis) :
srun --pty \
perf record -F 1000 --call-graph=dwarf -o /dev/shm/${USER}/perf.data \
./TPhysics.bin 500 100 \
&& mv /dev/shm/${USER}/perf.data . \
&& perf report
On peut constater la présence de nombreuses nouveautés dans l’affichage :
- L’ancienne colonne
Overhead
est renommée enSelf
et placée en 2e position. - Il y a une nouvelle colonne
Children
, qui représente une estimation du temps passé dans une fonction X ainsi que dans l’ensemble des fonctions directement ou indirectement appelées par X. Cette colonne est la nouvelle clé de tri. - Au niveau des symboles, le code de discrimination entre fonctions utilisateur
et noyau cette version de
perf
semble un peu bogué… perf
est parfois (hélas pas à tous les coups) en mesure d’estimer le temps CPU consommé par les fonctions inlinées, ce qui est utile car elles sont souvent critiques pour les performances.
Une lettre +
a également fait son apparition sur la gauche de l’affichage. Ce
signe nous indique qu’en mettant en surbrillance une fonction et en appuyant sur
la touche Entrée, on peut afficher la répartition du temps CPU entre les
fonctions appelées, et ce récursivement si on le souhaite :
Limites du DWARF
Voilà pour les bonnes nouvelles. Maintenant, la grosse mauvaise nouvelle. Il ne
vous aura pas échappé que seulement 79% des piles d’appels ont correctement été
reconstruites jusqu’à la fonction main
. Ceci est une occasion de plus de
répéter un point central dans l’interprétation de toutes les mesures perf
basées sur l’analyse des informations de déboguage :
Les analyses basées sur les informations de déboguage sont loin d’être infaillibles, et ce pour toutes sortes de raisons difficiles à analyser pour le non-expert : bogues du compilateur, de
binutils
, deperf
, ou taille d’échantillon de pile insuffisante.
En pratique, pour les 21% de piles d’appels restantes, la remontée de la pile
d’appels a bien fonctionné jusqu’à un certain point, puis une erreur s’est
produite en cours de route et perf
a atterri à une adresse d’instruction
insensée avant d’abandonner, comme on peut s’en convaincre avec une analyse à
gros grain de ces échantillons pathologiques basée sur le binaire source :
perf report --call-graph=comm,dso
La conséquence de cela, c’est que les pourcentages Children
obtenus sur un
graphe d’appels DWARF ne sont pas fiables à 100%. Au mieux, les échantillons
mal reconstruits sont équirépartis dans le programme et on a “juste” besoin de
normaliser les valeurs obtenues dans le graphe d’appels qui commence à main
par 1/79% = 1.26. Au pire on a un problème qui se produit toujours au même
endroit du code, et cela créera un biais systématique d’au plus 21% dans les
mesures.
Sans information complémentaire, une façon prudente d’interpréter les données
est de conclure quel les pourcentages “Children” que l’on obtiendrait avec une
mesure parfaite sont compris entre la valeur mesurée X et X+(100-M) où M est
le pourcentage “Children” mesuré pour la fonction main
(qui devrait être ~100%
pour tout programme dont le temps d’exécution n’est pas négligeable, en
l’absence d’erreur de reconstruction des piles d’appels).
Pour faire mieux, il faut avoir sous la main une deuxième technique de
profilage qui n’est pas sujette aux mêmes biais que les graphes d’appels DWARF
afin d’évaluer le niveau de biais lié aux piles d’appels tronquées. Cela peut
être un profilage manuel au sein de l’application, mais dans le cadre de
perf report
, on peut aussi parfois utiliser les
graphes d’appels LBR.
Exemple LBR
Au niveau de perf record
, on utilise ce style de graphe d’appels avec l’option
--call-graph=lbr
:
srun --pty \
perf record --call-graph=lbr \
./TPhysics.bin 500 100 \
&& perf report
Sur ce programme qui reste relativement simple, et donc sous la limite des 32 appels de fonction imbriqués supportés par le LBR de notre CPU, le graphe d’appels par LBR produit de bons résultats. On peut observer les différences suivantes avec le graphe d’appels par information de déboguage :
- Presque toutes les piles d’appels sont ici reconstruites jusqu’à
main
. - La discrimination entre code applicatif et code du noyau Linux fonctionne à tous les coups.
- On n’a plus de visibilité sur les fonctions inlinées.
- L’information LBR est beaucoup plus légère que les copies de piles requises
pour l’analyse DWARF, donc on n’a plus besoin d’imposer une limite de
fréquence d’échantillonnage ou d’émettre le fichier de sortie sur
/dev/shm
. L’analyse parperf report
est aussi plus rapide.
Au niveau du résultat, on peut comparer le premier niveau de hiérarchie sous
main
pour les deux techniques, en descendant jusqu’à la première fonction non
inlinée dans le cas du graphe d’appels DWARF pour faciliter la comparaison :
Une petite règle de trois permet de se convaincre qu’il n’y a pas de biais
systématique majeur ici : en renormalisant les pourcentages “Children” du graphe
d’appels DWARF par 1/0.7978 (l’inverse du pourcentage d’échantillons correctement
reconstruit jusqu’à main
), on trouve…
- 40.6% pour
TProton::interaction
- 19.3% pour
TNucleon::interaction
- 14.1% pour
TChargedParticle::interaction
- 8.5% pour
TVector::vectorOp
- 1.8% pour
std::vector<double>::operator=
…ce qui est en plutôt bon accord avec le profil mesuré par la méthode LBR. On
notera cependant quelques différences. Par exemple l’approche DWARF attribue le
coût de déallocation des std::vector
à la fonction _int_free
de la glibc
alors que l’approche LBR l’attribue à l’opérateur delete
de la libstdc++
, et
il semblerait que l’approche DWARF ne parvienne pas à reconstruire les piles
d’appels passant par la méthode virtuelle TChargedParticle::interaction
.
Exercice : Répétez cette analyse avec les enfants de la fonction
TParticle::reidInteraction
.
Notez la présence d’une indication _start
dans la visualisation de
perf report
, qui représente la pile d’appels au-dessus de la fonction
courante (de _start
jusqu’à la fonction active).
Contourner la limite de taille du LBR
Sur des programmes plus complexes, l’approche LBR n’est souvent pas directement applicable, car les piles d’appels sont profondes et dépassent largement la limite de 32 appels de fonction du matériel. C’est particulièrement vrai quand on profile un framework scripté avec du Python, car l’implémentation de l’interpréteur CPython utilise beaucoup d’appels récursifs.
Dans ce genre de cas, on peut demander à perf report
de tenter de reconstruire
les piles d’appels tronquées via une technique astucieuse, le LBR-stitching.
L’idée est la suivante : considérons un CPU avec une capacité LBR de 4 appels et
supposons que l’on ait un programme effectuant la série d’appels imbriqués
suivante :
- A1 appelle A2…
- …qui appelle A3
- …qui appelle A4
- …qui appelle A5
- …qui appelle A6
- …qui appelle A5
- …qui appelle A4
- …qui appelle A3
En supposant qu’un temps CPU significatif soit écoulé dans toutes les fonctions,
perf
observera dans ses échantillons les piles d’appels suivantes:
- A1
- A1 → A2
- A1 → A2 → A3
- A1 → A2 → A3 → A4
- A2 → A3 → A4 → A5 (tronqué par le LBR)
- A3 → A4 → A5 → A6 (tronqué par le LBR)
En corrélant les piles d’appels observées dans différents échantillons, perf
pourra alors reconstruire les piles d’appels tronquées en déduisant que A2
a probablement été appelée par A1 et A3 a probablement été appelée par A2.
L’opération est moins hasardeuse que cette description simplifiée ne pourrait
le laisser paraître, car perf
n’a pas seulement accès au nom de la fonction
appelante, mais plus précisément à l’adresse de l’instruction CALL
associée.
Mais cela reste un post-traitement dont la fiabilité n’est pas parfaite :
- En cas d’appel à des méthodes virtuelles dans du code orienté objet, une même
instruction
CALL
peut appeler plusieurs fonctions différentes. - Si beaucoup de fonctions ne font rien d’autre qu’appeler d’autres fonctions
(cas de codes appliquant les bonnes pratiques d’ingénierie logicielle de façon
un peu trop orthodoxe),
perf
aura peu d’échantillons à ces endroits, ce qui limitera l’applicabilité du stitching. - Plus la fréquence d’échantillonnage est faible, moins cette approche fonctionne.
- Ce post-traitement est plus vulnérable que l’approche LBR pure au code “pathologique” (ex: lancement et capture d’exceptions).
On peut activer le stitching en passant l’option --stitch-lbr
à
perf report
. Et quand cela ne fonctionne pas, une alternative courante pour
valider les résultats des graphes d’appels DWARF est de profiler manuellement son
code, par exemple en minutant et affichant le temps écoulé pendant l’exécution
d’étapes de traitement de haut niveau (idéalement au moins 100ms).
Options d’affichage du graphe d’appels
perf report
dispose de plusieurs options pour configurer l’affichage des
graphes d’appels. On peut notamment mentionner…
- L’option
--call-graph
qui se compose de plusieurs sous-options séparées par des virgules (--call-graph=x,y,z,...
). Les quatre premières sont les plus importantes :- La sous-option
print_type
définit le comportement global quand on appuie sur Entrée après avoir mis une fonction en surbrillance. Les choix les plus utiles sont :fractal
: Les pourcentages de temps CPU ne sont plus absolus, mais relatifs à la fonction choisie. Soyez prudent avec ce mode, il est facile de s’y laisser piéger par un gros pourcentage relatif qui correspond en fait à un faible pourcentage absolu (qui peut ne même pas être statistiquement significatif).flat
: La vue n’est plus hiérarchique et on a directement une liste de toutes les piles d’appels associées à la fonction sélectionnée. Ce mode est utile pour des programmes avec des piles d’appels très profondes.graph
: Mode par défaut (vue hiérarchique avec des pourcentages absolus), utile quand on veut configurer les autres sous-options.
- La sous-option
threshold
, définit en dessous de quel pourcentage de temps CPU une fonction sera supprimée de l’affichage (0.5% par défaut). Cela permet d’obtenir un affichage plus ou moins détaillé. - La sous-option
print_limit
n’est considérée qu’en mode--stdio
et limite le nombre de piles d’appels enfant affichées par parent (0 = illimité est le choix par défaut) - La sous-option
order
permet de basculer entre un affichage basé sur les enfants et un affichage basé sur les parents :- Le mode par défaut est
caller
, où l’on affiche les fonctions appelées par la fonction sélectionnée (fonctions enfants, caller-based call graph). - En mode
callee
,perf
affiche quelles fonctions font le plus souvent appel à la fonction sélectionnée (fonctions parents, callee-based call graph). Ce mode est utile quand on veut savoir qui fait le plus souvent appel à une fonction utilitaire. Il est aussi plus proche du fonctionnement interne deperf report
(partir d’un échantillon CPU et remonter la pile d’appels), donc utile pour déboguer.
- Le mode par défaut est
- La sous-option
- L’option
--percent-limit
a un effet analogue à la sous-optionthreshold
de--call-graph
, mais s’applique aux entrées d’histogramme (la liste affichée lors de l’ouverture deperf report
), alors quethreshold
s’applique aux entrées parent/enfant affichées quand on parcourt la hiérarchie des appels avec la touche Entrée. - L’option
--max-stack
permet de contrôler la limite de taille de pile d’appels après laquelleperf report
abandonnera l’idée de remonter jusqu’au point d’entrée (127 par défaut).
Exercice : Affichez quelles parties du code font le plus appel à
_int_malloc
, free
et __dynamic_cast
, et dans quelles proportions.
Liste des binaires utilisées
Quand on utilise des graphes d’appels basés sur les informations de déboguage DWARF (ce qu’on est souvent amené à faire sur les gros programmes), on est fréquemment confronté au besoin d’installer des paquets de déboguage, et donc de savoir quels paquets il faut installer.
Dans cette optique, la commande perf buildid-list
peut être utilisée pour
savoir quels binaires ont été utilisés lors de l’exécution d’un programme et
quels sont les build-id associés :
perf buildid-list
Le build-id est une somme de contrôle d’un binaire qui permet de différencier différents binaires qui portent le même nom mais ne correspondent pas exactement à la même version du code source ou n’ont pas été compilés avec les mêmes options. Le gestionnaire de paquets de certaines distributions Linux, dont openSUSE, peut installer des symboles de déboguage sur la base d’un build-id sans avoir besoin de chercher le nom et la version du paquet associé.