[Dcmlib] valgrind / callgrind / gdcm

[Mathieu Malaterre]

Ok,

	J'ai fais un petit test sur le prog de JP:

$ valgrind --tool=callgrind --dump-instr=yes --trace-jump=yes -v 
./bin/TestPrintTime

(gdcm compile' en shared lib + CMAKE_RELEASE:=DEBUG)


La plus grosse difference est:

US-GE-4AICL142.dcm   2619 vs  24      with clock time : 2661 vs 25


--------------------------------------

Sinon pour l'utilisation de kcachegrind/callgrind (il y a moins d'un an 
ces outils etaient encore appelle kcachegrind et calltree ...). J'admet 
que c'est installe sur vos machines.

La maniere la plus simple d'executer le profiler est de faire:


$ valgrind --tool=callgrind ./bin/TestPrintTime

ca va generer un fichier: callgrind.out.'???'  (??? = PID number je crois)
Ce fichier texte peut etre ouvert avec vim sans probleme mais c'est pas 
vraiment le but. Il vaut mieux utiliser kachegrind qui est une GUI pour 
lire ce genre de fichier.

$ kcachegrind

(par defaut il prend le dernier fichier callgrind.out.??? ecris mais 
juste pour etre parano il vaut mieux detruire tous les fichiers 
callgrind.out.??? avant de lancer un autre profile).

Apres avoir ajuster les differents menus, j'aime bien avoir plein 
d'espace pour la colone de gauche (avec la liste d'appel). On voit que 
tout en haut l'appel principal est 'main' (doh !). C'est celui qui prend 
99.5% du temps. Juste en dessous j'ai le deuxieme appel qui prends le 
plus de temps : Load. Attention le pourcentage est calculer en fonction 
du temps d'appel et du nombre d'appels (des fois on ne se rend pas 
compte combien de fois peut etre appele un fonction).

Dans la colone de gauche je vois que Load prens 87% du temps, et qu'il 
est appelle 556 fois... il y a de s grande chance que ca corresponde a 
un multiple du nombre de fichiers.

Juste en dessous j'ai dans l'ordre: Load/ParseDES/ReadNextDocEntry.
ReadNextDocEntry est plus interressant a etudier. Il prend 56.01% du 
temps. Pour une raison simple: il est appeller 94648 fois !


Maintenant je clique sur 'ReadNextDocEntry' dans la colonne de gauche. 
Les colones de droite sont mise a jour automatiquement. Et par defaut la 
colone en haut a droite est sur l'onglet 'Source' (enfin je crois). Ca 
permet d'avoir un appercu du source de ReadNextDocEntry. Ce qui de mieux 
encore c'est que kachegrind se place (toujours dans cette colonne) sur 
l'appel le plus couteux de ReadNextDocEntry:

    newEntry = NewValEntry(group, elem, vr);

Si je lis dans la colone en haut a droite, juste en dessous de la ligne 
NewValEntry: je lis

23.97% du temps est passer sur cet appel
et il y eu 82022 appel a NewValEntry

A titre de comparaison NewBinEntry (juste en dessous) est:
5.5% du temps
10966 appels a cette fonction.

Toujours a titre de comparaison, l'appel:

Global::GetVR()->IsVROfStringRepresentable(realVR) prend:
5.24% du temps
92988 appels a cette fonction

Meme chose :
    if (vr == GDCM_UNKNOWN)
represente .51% du temps.


J'espere que cette courte introduction vous aidera a prendre en main cet 
outil genial.

Mathieu
-------------- next part --------------
A non-text attachment was scrubbed...
Name: val.log
Type: text/x-log
Size: 20537 bytes
Desc: not available
URL: <http://www.creatis.insa-lyon.fr/pipermail/dcmlib/attachments/20050510/d824c5f2/attachment.bin>