Le profilage est un aspect important de la programmation logicielle. Grâce au profilage, on peut déterminer les parties du code du programme qui prennent du temps et doivent être réécrites. Cela permet d'accélérer l'exécution de votre programme, ce qui est toujours souhaité.
Dans les très grands projets, le profilage peut vous faire gagner du temps non seulement en déterminant les parties de votre programme dont l'exécution est plus lente que prévu, mais peut également vous aider vous trouverez de nombreuses autres statistiques grâce auxquelles de nombreux bogues potentiels peuvent être repérés et triés.
Dans cet article, nous allons explorer l'outil de profilage GNU "gprof".
Comment utiliser gprof
L'utilisation de l'outil gprof n'est pas du tout complexe. Il vous suffit de faire ce qui suit à un niveau élevé :
- Activer le profilage lors de la compilation du code
- Exécuter le code du programme pour produire les données de profilage
- Exécutez l'outil gprof sur le fichier de données de profilage (généré à l'étape ci-dessus).
La dernière étape ci-dessus produit un fichier d'analyse sous une forme lisible par l'homme. Ce fichier contient quelques tables (profil plat et graphique d'appel) en plus de quelques autres informations. Alors que le profil plat donne un aperçu des informations de synchronisation des fonctions telles que la consommation de temps pour l'exécution d'une fonction particulière, le nombre de fois qu'elle a été appelée, etc. fonction a été appelée, comment toutes les fonctions ont été appelées à partir de cette fonction particulière, etc. De cette façon, on peut également avoir une idée du temps d'exécution passé dans les sous-routines.
Essayons de comprendre les trois étapes énumérées ci-dessus à travers un exemple pratique. Le code de test suivant sera utilisé tout au long de l'article :
//test_gprof.c
#include<stdio.h>
void new_func1(void);
void func1(void)
{
printf("\n Inside func1 \n");
int i = 0;
for(;i<0xffffffff;i++);
new_func1();
return;
}
static void func2(void)
{
printf("\n Inside func2 \n");
int i = 0;
for(;i<0xffffffaa;i++);
return;
}
int main(void)
{
printf("\n Inside main()\n");
int i = 0;
for(;i<0xffffff;i++);
func1();
func2();
return 0;
} //test_gprof_new.c
#include<stdio.h>
void new_func1(void)
{
printf("\n Inside new_func1()\n");
int i = 0;
for(;i<0xffffffee;i++);
return;
} Notez que les boucles "for" à l'intérieur des fonctions sont là pour consommer du temps d'exécution.
Étape 1 :Profilage activé lors de la compilation
Dans cette première étape, nous devons nous assurer que le profilage est activé lorsque la compilation du code est terminée. Ceci est rendu possible en ajoutant l'option '-pg' dans l'étape de compilation.
Depuis la page de manuel de gcc :
-pg :génère du code supplémentaire pour écrire des informations de profil adaptées au programme d'analyse gprof. Vous devez utiliser cette option lors de la compilation des fichiers source sur lesquels vous souhaitez obtenir des données, et vous devez également l'utiliser lors de la liaison.
Alors, compilons notre code avec l'option '-pg' :
$ gcc -Wall -pg test_gprof.c test_gprof_new.c -o test_gprof $
Remarque :L'option '-pg' peut être utilisée avec la commande gcc qui compile (option -c), la commande gcc qui lie (option -o sur les fichiers objets) et avec la commande gcc qui fait les deux (comme dans l'exemple ci-dessus) .
Étape 2 :Exécutez le code
Dans la deuxième étape, le fichier binaire produit à la suite de l'étape 1 (ci-dessus) est exécuté afin que les informations de profilage puissent être générées.
$ ls test_gprof test_gprof.c test_gprof_new.c $ ./test_gprof Inside main() Inside func1 Inside new_func1() Inside func2 $ ls gmon.out test_gprof test_gprof.c test_gprof_new.c $
Nous voyons donc que lorsque le binaire a été exécuté, un nouveau fichier ‘gmon.out’ est généré dans le répertoire de travail courant.
Notez que lors de l'exécution, si le programme change le répertoire de travail actuel (en utilisant chdir), alors gmon.out sera produit dans le nouveau répertoire de travail actuel. De plus, votre programme doit disposer des autorisations suffisantes pour que gmon.out soit créé dans le répertoire de travail actuel.
Étape 3 :Exécutez l'outil gprof
Dans cette étape, l'outil gprof est exécuté avec le nom de l'exécutable et le "gmon.out" généré ci-dessus comme argument. Cela produit un fichier d'analyse qui contient toutes les informations de profilage souhaitées.
$ gprof test_gprof gmon.out > analysis.txt
Notez que l'on peut spécifier explicitement le fichier de sortie (comme dans l'exemple ci-dessus) ou l'information est produite sur stdout.
$ ls analysis.txt gmon.out test_gprof test_gprof.c test_gprof_new.c
Nous voyons donc qu'un fichier nommé "analysis.txt" a été généré.
Dans le même ordre d'idées, vous devez également comprendre comment déboguer votre programme C à l'aide de gdb.
Comprendre les informations de profilage
Comme indiqué ci-dessus, toutes les informations de profilage sont désormais présentes dans « analysis.txt ». Regardons ce fichier texte :
Flat profile:
Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls s/call s/call name
33.86 15.52 15.52 1 15.52 15.52 func2
33.82 31.02 15.50 1 15.50 15.50 new_func1
33.29 46.27 15.26 1 15.26 30.75 func1
0.07 46.30 0.03 main
% the percentage of the total running time of the
time program used by this function.
cumulative a running sum of the number of seconds accounted
seconds for by this function and those listed above it.
self the number of seconds accounted for by this
seconds function alone. This is the major sort for this
listing.
calls the number of times this function was invoked, if
this function is profiled, else blank.
self the average number of milliseconds spent in this
ms/call function per call, if this function is profiled,
else blank.
total the average number of milliseconds spent in this
ms/call function and its descendents per call, if this
function is profiled, else blank.
name the name of the function. This is the minor sort
for this listing. The index shows the location of
the function in the gprof listing. If the index is
in parenthesis it shows where it would appear in
the gprof listing if it were to be printed.
Call graph (explanation follows)
granularity: each sample hit covers 2 byte(s) for 0.02% of 46.30 seconds
index % time self children called name
[1] 100.0 0.03 46.27 main [1]
15.26 15.50 1/1 func1 [2]
15.52 0.00 1/1 func2 [3]
-----------------------------------------------
15.26 15.50 1/1 main [1]
[2] 66.4 15.26 15.50 1 func1 [2]
15.50 0.00 1/1 new_func1 [4]
-----------------------------------------------
15.52 0.00 1/1 main [1]
[3] 33.5 15.52 0.00 1 func2 [3]
-----------------------------------------------
15.50 0.00 1/1 func1 [2]
[4] 33.5 15.50 0.00 1 new_func1 [4]
-----------------------------------------------
This table describes the call tree of the program, and was sorted by
the total amount of time spent in each function and its children.
Each entry in this table consists of several lines. The line with the
index number at the left hand margin lists the current function.
The lines above it list the functions that called this function,
and the lines below it list the functions this one called.
This line lists:
index A unique number given to each element of the table.
Index numbers are sorted numerically.
The index number is printed next to every function name so
it is easier to look up where the function in the table.
% time This is the percentage of the `total' time that was spent
in this function and its children. Note that due to
different viewpoints, functions excluded by options, etc,
these numbers will NOT add up to 100%.
self This is the total amount of time spent in this function.
children This is the total amount of time propagated into this
function by its children.
called This is the number of times the function was called.
If the function called itself recursively, the number
only includes non-recursive calls, and is followed by
a `+' and the number of recursive calls.
name The name of the current function. The index number is
printed after it. If the function is a member of a
cycle, the cycle number is printed between the
function's name and the index number.
For the function's parents, the fields have the following meanings:
self This is the amount of time that was propagated directly
from the function into this parent.
children This is the amount of time that was propagated from
the function's children into this parent.
called This is the number of times this parent called the
function `/' the total number of times the function
was called. Recursive calls to the function are not
included in the number after the `/'.
name This is the name of the parent. The parent's index
number is printed after it. If the parent is a
member of a cycle, the cycle number is printed between
the name and the index number.
If the parents of the function cannot be determined, the word
`' is printed in the `name' field, and all the other
fields are blank.
For the function's children, the fields have the following meanings:
self This is the amount of time that was propagated directly
from the child into the function.
children This is the amount of time that was propagated from the
child's children to the function.
called This is the number of times the function called
this child `/' the total number of times the child
was called. Recursive calls by the child are not
listed in the number after the `/'.
name This is the name of the child. The child's index
number is printed after it. If the child is a
member of a cycle, the cycle number is printed
between the name and the index number.
If there are any cycles (circles) in the call graph, there is an
entry for the cycle-as-a-whole. This entry shows who called the
cycle (as parents) and the members of the cycle (as children.)
The `+' recursive calls entry shows the number of function calls that
were internal to the cycle, and the calls entry for each member shows,
for that member, how many times it was called from other members of
the cycle.
Index by function name
[2] func1 [1] main
[3] func2 [4] new_func1 Donc (comme déjà discuté) on voit que ce fichier est globalement divisé en deux parties :
1. Profil plat
2. Graphe d'appel
Les colonnes individuelles pour le (profil plat ainsi que le graphique des appels) sont très bien expliquées dans la sortie elle-même.
Personnaliser la sortie gprof à l'aide d'indicateurs
Il existe différents drapeaux disponibles pour personnaliser la sortie de l'outil gprof. Certains d'entre eux sont discutés ci-dessous :
1. Supprimer l'impression des fonctions déclarées statiquement (privées) à l'aide de -a
S'il existe des fonctions statiques dont vous n'avez pas besoin d'informations de profilage, cela peut être réalisé en utilisant l'option -a :
$ gprof -a test_gprof gmon.out > analysis.txt
Maintenant, si nous voyons ce fichier d'analyse :
Flat profile:
Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls s/call s/call name
67.15 30.77 30.77 2 15.39 23.14 func1
33.82 46.27 15.50 1 15.50 15.50 new_func1
0.07 46.30 0.03 main
...
...
...
Call graph (explanation follows)
granularity: each sample hit covers 2 byte(s) for 0.02% of 46.30 seconds
index %time self children called name
[1] 100.0 0.03 46.27 main [1]
30.77 15.50 2/2 func1 [2]
-----------------------------------------------------
30.77 15.50 2/2 main [1]
[2] 99.9 30.77 15.50 2 func1 [2]
15.50 0.00 1/1 new_func1 [3]
----------------------------------------------------
15.50 0.00 1/1 func1 [2]
[3] 33.5 15.50 0.00 1 new_func1 [3]
-----------------------------------------------
...
...
... On voit donc qu'il n'y a pas d'information liée à func2 (qui est défini statique)
2. Supprimer les textes de présentation détaillés à l'aide de -b
Comme vous l'avez déjà vu, gprof produit une sortie avec beaucoup d'informations détaillées, donc si ces informations ne sont pas requises, cela peut être réalisé en utilisant l'indicateur -b.
$ gprof -b test_gprof gmon.out > analysis.txt
Maintenant si on voit le fichier d'analyse :
Flat profile:
Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls s/call s/call name
33.86 15.52 15.52 1 15.52 15.52 func2
33.82 31.02 15.50 1 15.50 15.50 new_func1
33.29 46.27 15.26 1 15.26 30.75 func1
0.07 46.30 0.03 main
Call graph
granularity: each sample hit covers 2 byte(s) for 0.02% of 46.30 seconds
index % time self children called name
[1] 100.0 0.03 46.27 main [1]
15.26 15.50 1/1 func1 [2]
15.52 0.00 1/1 func2 [3]
-----------------------------------------------
15.26 15.50 1/1 main [1]
[2] 66.4 15.26 15.50 1 func1 [2]
15.50 0.00 1/1 new_func1 [4]
-----------------------------------------------
15.52 0.00 1/1 main [1]
[3] 33.5 15.52 0.00 1 func2 [3]
-----------------------------------------------
15.50 0.00 1/1 func1 [2]
[4] 33.5 15.50 0.00 1 new_func1 [4]
-----------------------------------------------
Index by function name
[2] func1 [1] main
[3] func2 [4] new_func1 On voit donc que toutes les informations verbeuses ne sont pas présentes dans le fichier d'analyse.
3. Imprimer uniquement le profil plat en utilisant -p
Dans le cas où seul un profil plat est requis, alors :
$ gprof -p -b test_gprof gmon.out > analysis.txt
Notez que j'ai utilisé (et utiliserai) l'option -b afin d'éviter des informations supplémentaires dans la sortie de l'analyse.
Maintenant, si nous voyons ce résultat d'analyse :
Flat profile: Each sample counts as 0.01 seconds. % cumulative self self total time seconds seconds calls s/call s/call name 33.86 15.52 15.52 1 15.52 15.52 func2 33.82 31.02 15.50 1 15.50 15.50 new_func1 33.29 46.27 15.26 1 15.26 30.75 func1 0.07 46.30 0.03 main
Nous voyons donc que seul le profil plat était là dans la sortie.
4. Imprimer les informations relatives à une fonction spécifique dans le profil plat
Ceci peut être réalisé en fournissant le nom de la fonction avec l'option -p :
$ gprof -pfunc1 -b test_gprof gmon.out > analysis.txt
Maintenant, si nous voyons cette sortie d'analyse :
Flat profile: Each sample counts as 0.01 seconds. % cumulative self self total time seconds seconds calls s/call s/call name 103.20 15.26 15.26 1 15.26 15.26 func1
Nous voyons donc qu'un profil plat contenant des informations relatives à la seule fonction func1 est affiché.
5. Supprimer le profil plat dans la sortie à l'aide de -P
Si le profil plat n'est pas requis, il peut être supprimé à l'aide de l'option -P :
$ gprof -P -b test_gprof gmon.out > analysis.txt
Maintenant, si nous voyons la sortie de l'analyse :
Call graph granularity: each sample hit covers 2 byte(s) for 0.02% of 46.30 seconds
index % time self children called name
[1] 100.0 0.03 46.27 main [1]
15.26 15.50 1/1 func1 [2]
15.52 0.00 1/1 func2 [3]
-----------------------------------------------
15.26 15.50 1/1 main [1]
[2] 66.4 15.26 15.50 1 func1 [2]
15.50 0.00 1/1 new_func1 [4]
-----------------------------------------------
15.52 0.00 1/1 main [1]
[3] 33.5 15.52 0.00 1 func2 [3]
-----------------------------------------------
15.50 0.00 1/1 func1 [2]
[4] 33.5 15.50 0.00 1 new_func1 [4]
-----------------------------------------------
Index by function name
[2] func1 [1] main
[3] func2 [4] new_func1 Nous voyons donc que le profil plat a été supprimé et que seul le graphique d'appel a été affiché dans la sortie.
De plus, s'il est nécessaire d'imprimer un profil plat mais en excluant une fonction particulière, cela est également possible en utilisant l'indicateur -P en lui transmettant le nom de la fonction (à exclure).
$ gprof -Pfunc1 -b test_gprof gmon.out > analysis.txt
Dans l'exemple ci-dessus, nous avons essayé d'exclure "func1" en le transmettant avec l'option -P à gprof. Voyons maintenant le résultat de l'analyse :
Flat profile: Each sample counts as 0.01 seconds. % cumulative self self total time seconds seconds calls s/call s/call name 50.76 15.52 15.52 1 15.52 15.52 func2 50.69 31.02 15.50 1 15.50 15.50 new_func1 0.10 31.05 0.03 main
Nous voyons donc que le profil plat a été affiché mais que les informations sur func1 ont été supprimées.
6. Afficher uniquement les informations du graphique des appels à l'aide de -q
gprof -q -b test_gprof gmon.out > analysis.txt
Dans l'exemple ci-dessus, l'option -q a été utilisée. Voyons quel effet cela produit sur le résultat de l'analyse :
Call graph
granularity: each sample hit covers 2 byte(s) for 0.02% of 46.30 seconds
index % time self children called name
[1] 100.0 0.03 46.27 main [1]
15.26 15.50 1/1 func1 [2]
15.52 0.00 1/1 func2 [3]
-----------------------------------------------
15.26 15.50 1/1 main [1]
[2] 66.4 15.26 15.50 1 func1 [2]
15.50 0.00 1/1 new_func1 [4]
-----------------------------------------------
15.52 0.00 1/1 main [1]
[3] 33.5 15.52 0.00 1 func2 [3]
-----------------------------------------------
15.50 0.00 1/1 func1 [2]
[4] 33.5 15.50 0.00 1 new_func1 [4]
-----------------------------------------------
Index by function name
[2] func1 [1] main
[3] func2 [4] new_func1 Nous voyons donc que seul le graphe d'appel a été imprimé dans la sortie.
7. Imprimer uniquement des informations de fonction spécifiques dans le graphique d'appel.
Ceci est possible en transmettant le nom de la fonction avec l'option -q.
$ gprof -qfunc1 -b test_gprof gmon.out > analysis.txt
Maintenant, si nous voyons le résultat de l'analyse :
Call graph
granularity: each sample hit covers 2 byte(s) for 0.02% of 46.30 seconds
index % time self children called name
15.26 15.50 1/1 main [1]
[2] 66.4 15.26 15.50 1 func1 [2]
15.50 0.00 1/1 new_func1 [4]
-----------------------------------------------
15.50 0.00 1/1 func1 [2]
[4] 33.5 15.50 0.00 1 new_func1 [4]
-----------------------------------------------
Index by function name
[2] func1 (1) main
(3) func2 [4] new_func1 Nous voyons donc que seules les informations relatives à func1 étaient affichées dans le graphique des appels.
8. Supprimer le graphique des appels à l'aide de -Q
Si les informations du graphique d'appel ne sont pas requises dans la sortie de l'analyse, l'option -Q peut être utilisée.
$ gprof -Q -b test_gprof gmon.out > analysis.txt
Maintenant, si nous voyons la sortie de l'analyse :
Flat profile: Each sample counts as 0.01 seconds. % cumulative self self total time seconds seconds calls s/call s/call name 33.86 15.52 15.52 1 15.52 15.52 func2 33.82 31.02 15.50 1 15.50 15.50 new_func1 33.29 46.27 15.26 1 15.26 30.75 func1 0.07 46.30 0.03 main
Nous voyons donc que seul le profil plat est là dans la sortie. Tout le graphique des appels a été supprimé.
De plus, si vous souhaitez supprimer une fonction spécifique du graphe d'appels, cela peut être réalisé en transmettant le nom de la fonction souhaitée avec l'option -Q à l'outil gprof.
$ gprof -Qfunc1 -b test_gprof gmon.out > analysis.txt
Dans l'exemple ci-dessus, le nom de fonction func1 est passé à l'option -Q.
Maintenant, si nous voyons le résultat de l'analyse :
Call graph
granularity: each sample hit covers 2 byte(s) for 0.02% of 46.30 seconds
index % time self children called name
[1] 100.0 0.03 46.27 main [1]
15.26 15.50 1/1 func1 [2]
15.52 0.00 1/1 func2 [3]
-----------------------------------------------
15.52 0.00 1/1 main [1]
[3] 33.5 15.52 0.00 1 func2 [3]
-----------------------------------------------
15.50 0.00 1/1 func1 [2]
[4] 33.5 15.50 0.00 1 new_func1 [4]
-----------------------------------------------
Index by function name
(2) func1 [1] main
[3] func2 [4] new_func1 Nous voyons donc que les informations du graphique d'appel liées à func1 ont été supprimées.