Callgrind est un outil de la famille de valgrind. Il permet de faire du profilage à grain assez fin. Cet outil est très portable et permet en combinaison avec l’outil Kcachegrind de visualiser de manière assez précise des profils de performance.
L’inconvénient principal de cet outil est son surcoût relativement important, il faut donc veiller à cibler un cas test de taille limitée et non un cas représentatif. Aprés avoir exposé le processus d’installation, nous allons présenter les processus de mesure puis comment les résultats peuvent être analysés.
Installation de Callgrind et Kcachegrind
Dans ce tutoriel nous allons utiliser deux outils, valgrind qui fournit Callgrind et Kcachegrind qui est une interface graphique permettant de visualiser les fichiers de sortie générés par Callgrind.
Sur Centos 7:
yum install kdesdk-kcachegrind valgrind graphviz
Sur Ubuntu:
apt-get install kcachegrind valgrind graphviz
Vérifiez ensuite que les commandes « valgrind » et kcachegrind sont bien présentes.
Instrumenter avec Callgrind
Le processus d’instrumentation de callgrind est très simple. Il suffit de rajouter l’invocation de Callgrind avant le programme cible. Par exemple:
valgrind --tool=callgrind ./test
Prenons maintenant un code simple pour tester le profilage (test.c):
#include <stdio.h> int main(int argc, char **argv) { int i; int j; double result = 0.0; for (i = 0; i < 100000; ++i) { for (j = 0; j < 10000; ++j) { result += i + j * 0,1; } } printf("--> %g\n", result ); return 0; }
Compilons le code en mode débug :
gcc -g -O3 -o test ./test.c
Puis instrumentons le avec Callgrind, notez que l’exécution est ralentie.
valgrind --tool=callgrind ./test
Remarquez qu’un fichier callgrind.out.PID a maintenant été généré dans le répertoire courant. Ce fichier contient les informations mesurées lors de l’éxécution.
Visualisation en Console
Il est possible de consulter le contenu du profil en console en utilisant callgrind_anotate. Cet outil s’utilise comme suit:
callgrind_annotate ./callgrind.out.31458
Cela produira une sortie assez compacte:
——————————————————————————–
Profile data file ‘./callgrind.out.31458’ (creator: callgrind-3.11.0)
——————————————————————————–
I1 cache:
D1 cache:
LL cache:
Timerange: Basic block 0 – 1000321106
Trigger: Program termination
Profiled target: ./a.out (PID 31458, part 1)
Events recorded: Ir
Events shown: Ir
Event sort order: Ir
Thresholds: 99
Include dirs:
User annotated:
Auto-annotation: off——————————————————————————–
Ir
——————————————————————————–
7,000,800,236 PROGRAM TOTALS——————————————————————————–
Ir file:function
——————————————————————————–
7,000,700,025 ./test.c:main [/home/jbbesnard/a.out]
On y trouve peu d’information pour l’instant, uniquement dans la partie basse le fait que tous les échantillons étaient dans la fonction main. Pour obtenir des informations plus intéressantes, il faut passer des paramètre au programme.
Par exemple pour visualiser les fonction appelantes et les fonction appelées:
callgrind_annotate --tree=both ./callgrind.out.31458
On obtient les fonction appelées dans le main (ici printf):
——————————————————————————–
Ir file:function
——————————————————————————–7,000,700,025 * ./test.c:main [/home/jbbesnard/a.out]
3,900 > ???:printf (1x) [/usr/lib64/libc-2.17.so]
776 > ???:_dl_runtime_resolve (1x) [/usr/lib64/ld-2.17.so]
Mais on peut aller plus loin en ayant un code annoté pour les principales fonction :
callgrind_annotate --auto=yes ./callgrind.out.31458
On obtient en complément de la sortie précédente:
-------------------------------------------------------------------------------- -- Auto-annotated source: ./test.c -------------------------------------------------------------------------------- Ir . . int main(int argc, char **argv) 5 { . int i; . int j; . 2 double result = 0.0; . 300,004 for (i = 0; i < 100000; ++i) . { 7,000,400,011 for (j = 0; j < 10000; ++j) { result += i + j * 0,1; } } printf("--> %g\n", result ); 3,900 => ???:printf (1x) 776 => ???:_dl_runtime_resolve (1x) . 1 return 0; 2 } -------------------------------------------------------------------------------- Ir -------------------------------------------------------------------------------- 100 percentage of events annotated
On voit ici que la majorité des échantillons sont dans leur grande majorité regrouppés dans la boucle interne faisant le calcul. Cela permet de pointer précisément le point chaud du code.
Controller Callgrind
Calgrind fournit également un outil callgrind_control pour interragir avec un programme en cours de profilage. Pour illustre ce point, nous allons volontairement créer un situation de bloquage dans le programme cible. Nous proposons le code suivant:
#include <stdio.h> void bar() { while(1) { /* BLOCAGE */ sleep(1); } } int main(int argc, char **argv) { bar(); return 0; }
Compilons le code en mode débug :
gcc -g -O3 -o ddlk ./d.c
Et lançons le dans Callgrind:
valgrind --tool=callgrind ./ddlk
Ce programme ne se terminera jamais, par contre il est possible de le surveiller à « distance » avec l’outil callgrind_control. Ce outils est très utiles pour différentes manipulation. Pour ce faire, nous allons laisser le programme bloqué s’éxécuter et ouvrir une autre console.
On peut tout d’abord observer l’état du programme:
callgrind_control -s
PID 31946: ./ddlk
sending command status internal to pid 31946
Number of running threads: 1, thread IDs: 1
Events collected: Ir
Functions: 129 (executed 2,337, contexts 129)
Basic blocks: 1,435 (executed 22,738, call sites 198)
On peut ensuite demander la génération d’un backtrace à distance:
callgrind_control -s
PID 31946: ./ddlk
sending command status internal to pid 31946Frame: Backtrace for Thread 1
[ 0] __nanosleep_nocancel (148 x)
[ 1] nanosleep (148 x)
[ 2] sleep (147 x)
[ 3] bar (1 x)
[ 4] main (1 x)
[ 5] (below main) (1 x)
[ 6] 0x000000000040044b (1 x)
[ 7] 0x00000000000011e0
Ici on voit clairement que le code est bloqué dans bar. Ceci peut être très pratique pour comprendre pourquoi un code bloque. Il est également possible de forcer l’écriture des évènement et de désactiver/réactiver l’instrumentation (voir aide -h).
Visualiser avec Kcachegrind
Il est également possible d’utliser une interface graphique pour observer un profil Valgrind. Pour ce faire, on utilise la commande suivante:
kcachegrind ./callgrind.out.31458
Vous obtiendrez alors une sortie telle que celle-ci:
Vous pouvez consulter un profil de plus grande taille en téléchargeant ce fichier callgrind.out généré sur l’application Lulesh.
Conclusion
Ce tutoriel a rapidement présenté l’utilisation de Callgrind qui bien que ralentissant l’éxécutio n du code est tout à fait capable de fournir des informations détaillées sur son comportement. Couplé à Kcachegrind, c’est un outils indispensable. De plus valgrind fait bien plus que du profilage …