Sylvestre's blog

Revenu dans le monde de l'informatique.

Je commence ma semaine par regarder les différents outils de profiling. Outils qui servent à indiquer où le système a passé le plus de temps. Par exemple, si on voit que la fonction/méthode est appelée 6 milliard de fois, on se dit que l'optimiser peut être interessant.

J'ai donc regardé un peu ce qui se fait dans le monde libre.
En ressortent principalement deux outils & méthodes :
- la méthode gprof qui consiste à compiler le programme avec une option spécifique (-pg) et à l'exécuter ce qui produira un fichier contenant le graphe des appels de fonctions. - Commence à être déprécié pour le suivant.
- la méthode callgrind/cachegrind (fournie par valgrind) qui lui va fournir un environnement d'execution et regarder tout ce qui se passe (et aussi regarder les fuites de mémoire (memory leaks)).

gprof
Pour cet exemple, j'utilise un programme de test qui génere pleins de threads et leur fait faire de longs calculs.

La ligne de compilation est :
g++ -pg -o calcul_multithread_detached calcul_multithread_detached.cpp

Ainsi, on va générer le code nécessaire pour produire les informations dont gprof a besoin.

On lance le programme
# ./calcul_multithread_detached
ce qui va produire un fichier dans le répertoire courant appellé par defaut gmon.out

gprof attend le nom de l'exécutable :
gprof calcul_multithread_detached

Ceci va produire l'output suivant :

Chaque échantillon dénombre 0.01 seconds.
  %    cumulatif   auto              auto     total           
temps   seconds   seconds   appels us/appel us/appel  nom     
 50.06      0.01     0.01                             main
 25.03      0.02     0.01     1125     4.45     4.45  threadTemplate::getThreadNo()
 25.03      0.02     0.01     1125     4.45     4.45  calcul::calcul(int, double, int)
  0.00      0.02     0.00     1125     0.00     0.00  threadTemplate::launch(__pthread_attr_s)
  0.00      0.02     0.00     1125     0.00     0.00  threadTemplate::threadTemplate(int)
  0.00      0.02     0.00     1125     0.00     4.45  threadEnvironnement::addThread(threadTemplate*)
  0.00      0.02     0.00     1125     0.00     0.00  calcul::testfunc()
  0.00      0.02     0.00        1     0.00     0.00  global constructors keyed to _ZN14threadTemplateC2Ei
  0.00      0.02     0.00        1     0.00     0.00  __static_initialization_and_destruction_0(int, int)
  0.00      0.02     0.00        1     0.00     0.00  threadTemplate::~threadTemplate()
  0.00      0.02     0.00        1     0.00     0.00  threadEnvironnement::threadEnvironnement(int)
  0.00      0.02     0.00        1     0.00     0.00  threadEnvironnement::~threadEnvironnement()

Ceci dit nous permet de voir les fonctions les plus souvent appellés et le temps passé dans chacune.
D'autres résultats sont aussi fourni par cet outil comme l'arbre d'appel des fonctions.

Il existe des fronts end permettant de mieux lire ses résultats.
Par exemple, kprof ( http://kprof.sourceforge.net/ ) :

Kprof

Graphe de Kprof

Un des problèmes de ce programme est qu'il faut que le programme et les bibliothèques aient été compilés avec. Ce qui limite les possibilités et la faciliter d'utilisation.

valgrind - http://valgrind.kde.org/

valgrind est résolument différent de part son approche.
Pour effectuer le profiling de son application, il n'y a pas besoin d'option particulière. L'option -g (débug) n'est même pas nécessaire (sauf pour accéder aux sources dans kcachegrind).

Pour le lancer, la commande suivante suffit :
callgrind --dump-instr=yes -v calcul

Il va exécuter le programme calcul (qui fait de bêtes et longues additions) dans son environnement. C'est entre 20 et 100 fois plus lent.
Il va produire un fichier callgrind.out.<pid> contenant la liste des systèmes call. C'est carrement indigeste (certains diront que tout mon article l'est).

[...]
fn=(3790) calcul(double)
0x804D464 0 1
+1 0 1
+2 0 1
+3 0 1
+3 0 1
+3 0 1
+2 0 1
+3 0 1
+7 0 1
+3 0 1
+3 0 1
+2 0 1
+2 0 1
+1 0 1
-11 0 1124250000
+3 0 1124250000
+3 0 1124250000
[...]

Ne m'amusant pas à lire le code machine ni ce genre de trucs, il faut utiliser un programme tier pour analyser ces informations.
Ce programme s'appelle kcachegrind http://kcachegrind.sourceforge.net/cgi-bin/show.cgi
Il va lire le fichier généré par callgrind/valgrind et présenter les valeurs.

kcachegrind <path vers le fichier callgrind.out>

Ce programme va lire le dump des appels systèmes et autres plaisirs du genre et les présenter (d'une manière plus efficace que kprof).

Ainsi, il fournit grosso modo le même genre d'information que kprof mais en plus poussé (il est possible de voir pas à pas le coup de chaque instruction), il est ainsi possible de descendre dans les libraires (sans avoir à recompiler). Les graphes produits sont bien plus parlant et contiennent bien plus d'informations qu'avec kprof. Et il est possible de parcourir les sources (quand l'application est compilée avec l'option -g).

kcachegrind

Voila le source code de ma superbe application :

#include <iostream>
using namespace std;

double process(double i) {
	double j;
	j=i+1;
	return j;
}

double calcul(double iteration) {
	int i;
	double result=0;
	for (i=0; i<iteration; i++) {
		result=result+i;
		if (i%2==0) {
			result=process(result);
		}
	}
	return result;
}

int main (int argc, char **argv) {
	double itera=112425;
	cout << "Calcul ( "<< itera << " ) = " << calcul(itera) << endl;
	return 0;
}

En exécutant kcachegrind, on peut voir que la fonction process est appellée 56123 fois. Il faut donc se concentrer sur cette fonction si on cherche à l'optimiser (dans notre cas, on pourrait se débarasser de la variable temporaire qui ne sert à rien du tout).

Voila tout pour cette brève introduction (bon, je dis ça, je suis sur que personne ne lira jusqu'à là ).

Edit :
J'ai entendu parlé de sysprof qui aurait bonne réputation aussi ...