profil_apres.txt : profil gprof de la version finale (0,32 s profilées contre 28,87 s). COMPTE_RENDU.md : temps avant/après, analyse du profil, pistes classées par gain attendu, optimisations réalisées et gains mesurés (6,25 s → 0,18 s en -O0, 1,72 s → 0,11 s en -O2, empreinte inchangée). Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
20 KiB
Compte rendu — TD1 : profiling avec gprof
R5.A.04 · Qualité Algorithmique — Ryad MEHIRI
Programme étudié : analyseur.c, un analyseur de fréquence de mots. Il génère un texte pseudo-aléatoire de 250 000 mots (graine fixe), le découpe en lignes et le normalise, compte les mots, les trie, calcule des statistiques, cherche le trigramme le plus fréquent, puis écrit rapport.txt. L'empreinte affichée à la fin (un hachage FNV-1a du rapport) doit rester identique après optimisation.
Résumé
| Avant | Après | Gain | |
|---|---|---|---|
Temps, compilé en -O0 (médiane de 10 exécutions) |
6,25 s | 0,18 s | ×35 |
Temps, compilé en -O2 (médiane de 10 exécutions) |
1,72 s | 0,11 s | ×15 |
| Empreinte du rapport | 1d53de903efd2b7c |
1d53de903efd2b7c |
identique ✔ |
Durée de l'exécution profilée (-pg) |
28,87 s | 0,32 s |
Six optimisations ont été réalisées, une par commit. Les cinq premières corrigent l'algorithme : elles suppriment des parcours quadratiques ou répétés inutilement. La sixième est un simple filtre qui évite des comparaisons inutiles. Les deux premières viennent directement du profil. La troisième corrige un point chaud que gprof sous-estimait fortement (partie 3.3).
1. Environnement et scénario de mesure
| Machine | Intel Core i7-1165G7 (4 cœurs / 8 threads, 2,8 GHz), 7,8 Go de RAM |
| Système | Windows 11 Professionnel (10.0.26200) |
| Compilateur | gcc 15.3.0, environnement MSYS de MSYS2 (couche POSIX dérivée de Cygwin) |
| Profiler | GNU gprof 2.47 |
Scénario reproductible : le programme n'a pas d'entrée. Il génère toujours le même texte grâce à sa graine fixe, donc chaque exécution fait exactement le même travail. Chaque version est compilée de la même façon, sur la même machine, puis lancée plusieurs fois. On retient la médiane des temps réels (5 exécutions par étape, 10 pour la validation finale).
Pourquoi l'environnement MSYS et pas MinGW ? J'ai d'abord compilé avec le gcc MinGW (Windows natif). Le programme y donnait Mots distincts : 0 et l'empreinte 00000000e1d9de1f. Sous Windows natif, unsigned long fait 32 bits (modèle LLP64), contre 64 bits sous Linux (LP64). Le générateur alea() renvoie etat_alea >> 33 : un décalage de 33 bits sur un entier de 32 bits ne renvoie que des zéros, et le texte généré n'a plus aucun sens. L'environnement MSYS suit le modèle LP64 comme Linux (sizeof(long) = 8, vérifié), et le programme s'y comporte normalement. Le code d'origine n'est donc pas portable : il faudrait utiliser uint64_t. Je ne l'ai pas modifié, car cela sortait du cadre du TD.
Commandes utilisées :
# Mesure (sans instrumentation)
gcc -O0 -g analyseur.c -o analyseur
time ./analyseur # répété 5 fois (10 pour la validation)
# Profil
gcc -O0 -g -pg analyseur.c -o analyseur
./analyseur # écrit gmon.out
gprof -b ./analyseur gmon.out > profil_avant.txt
2. Mesure initiale
| Exécution | 1 | 2 | 3 | 4 | 5 | Médiane |
|---|---|---|---|---|---|---|
| Temps réel (s) | 9,84 | 7,24 | 7,63 | 7,73 | 6,85 | 7,63 |
La première exécution est plus lente (9,8 s), sans doute à cause du cache froid ou de la fréquence du processeur pas encore stabilisée. C'est pour cela qu'on prend la médiane plutôt qu'une seule mesure.
Sortie du programme (identique avant et après optimisation) :
Lignes analysées : 21746
Mots au total : 250000
Mots distincts : 5866
Longueur moyenne : 6.712 (écart-type 1.873)
Bigramme le + courant : "me" (17607 fois, souvent suivi de 'n')
Top 10 :
1. rane 287
2. fasi 241
3. tata 219
4. mopo 214
5. cofi 180
6. vesi 179
7. laganomo 177
8. boto 172
9. nopebo 169
10. rotion 165
Empreinte du rapport : 1d53de903efd2b7c
3. Analyse du profil initial (profil_avant.txt)
3.1 Profil plat et effet de sonde
% cumulative self self total
time seconds seconds calls s/call s/call name
58.02 16.75 16.75 _mcount_private
14.86 21.04 4.29 36009819 0.00 0.00 longueur
9.85 23.89 2.85 308701874 0.00 0.00 egales
6.51 25.77 1.88 __fentry__
4.33 27.02 1.25 150182 0.00 0.00 chercher_mot
2.01 27.59 0.58 12172087 0.00 0.00 comparer
1.80 28.11 0.52 5867 0.00 0.00 longueur_moyenne
0.83 28.36 0.24 1 0.24 0.93 trier_entrees
Les deux lignes _mcount_private et __fentry__ ne sont pas du code du programme. C'est le code ajouté par -pg, exécuté à chaque entrée de fonction pour compter les appels. Elles pèsent 18,63 s sur 28,87 s, soit 64,5 % du temps profilé. L'exécution profilée dure 28,9 s, contre 7,6 s sans -pg.
C'est l'effet de sonde vu en cours. Ici, il est énorme parce que le programme fait plus de 400 millions d'appels à de toutes petites fonctions (egales à elle seule : 308 millions). Sous Linux, mcount est dans la libc et n'apparaît pas dans le profil, mais il a lui aussi un coût.
Pour l'analyse, on raisonne donc sur les 10,24 s de temps propre au programme, c'est-à-dire le temps total de main dans le graphe d'appels.
3.2 Graphe d'appels : où passe le temps, et pourquoi
| Rang | Fonction (avec ses enfants) | Temps total | Part des 10,24 s | Appels | Cause |
|---|---|---|---|---|---|
| 1 | ecart_type_longueur → longueur_moyenne → longueur |
4,62 s | 45 % | 5 866 appels à longueur_moyenne, 34,4 millions à longueur |
longueur_moyenne est appelée dans la boucle : la table est reparcourue pour chaque mot, soit 5 866 × 5 866 parcours. O(n²) au lieu de O(n). |
| 2 | compter_mot → chercher_mot → egales |
4,04 s | 39 % | 150 182 recherches, 296,7 millions d'appels à egales |
Recherche linéaire dans la table : environ 1 975 comparaisons de chaînes par mot. O(N × n). |
| 3 | trier_entrees → doit_echanger → comparer |
0,93 s | 9 % | 17 202 045 appels à doit_echanger |
Tri à bulles : exactement n(n−1)/2 = 5 866 × 5 865 / 2 comparaisons. O(n²). |
| 4 | normaliser_ligne → longueur |
0,21 s | 2 % | 1 561 330 appels à longueur |
longueur(ligne) est dans la condition de boucle, donc recalculée à chaque caractère. O(L²) par ligne. |
| 5 | est_mot_vide → egales |
0,17 s | 1,7 % | 12 045 671 appels à egales |
Chaque mot est comparé aux 60 mots vides. |
| 6 | generer_vocabulaire |
0,13 s | 1,3 % | 20 934 appels à ajouter |
Génération des données de test. |
| 7 | construire_rapport → ajouter → longueur |
0,04 s (affiché) | 0,4 % (affiché) | 5 867 appels à ajouter |
ajouter recalcule la longueur du rapport, qui grandit jusqu'à 89 Ko, à chaque ligne ajoutée. O(n²) en caractères. Voir 3.3. |
3.3 Les limites de gprof rencontrées
1. Le temps d'un enfant est réparti au prorata du nombre d'appels. gprof mesure le temps propre de longueur (4,29 s), puis le partage entre ses appelants selon leur nombre d'appels, comme si tous les appels coûtaient pareil. Or :
- les 34,4 millions d'appels venant de
longueur_moyenneparcourent chacun un mot d'environ 7 caractères ; - les 5 867 appels venant de
construire_rapport(viaajouter) parcourent chacun tout le rapport déjà écrit, qui grandit jusqu'à 89 376 octets : 44 500 caractères en moyenne. Au total, cela fait 2,61 × 10⁸ caractères, presque autant que les 34,4 millions d'appels delongueur_moyenneréunis (2,65 × 10⁸ caractères).
gprof attribue donc 4,10 s à longueur_moyenne et presque rien à construire_rapport (0,04 s), ce qui est faux.
Je l'ai vu au premier re-profilage. Après l'optimisation 1, longueur n'était plus appelée que 1,6 million de fois, mais elle gardait 2,94 s de temps propre. L'optimisation 3 l'a confirmé par la mesure : corriger construire_rapport a fait gagner 0,97 s, alors que gprof lui attribuait 0,04 s. Cela explique aussi pourquoi l'optimisation 1 a fait gagner moins que les 45 % prévus (27 %) : une partie de ce temps appartenait en réalité à construire_rapport.
2. gprof ne voit pas la libc. Après le passage à qsort, la fonction de comparaison comparer_entrees apparaît dans le profil sans nombre d'appels : elle est appelée depuis qsort, qui n'est pas instrumentée. Le temps passé dans qsort et sprintf n'est pas compté non plus.
3. Le profil est statistique. Un échantillon vaut 0,01 s. Le profil final ne contient que 32 échantillons au total : la répartition entre fonctions n'y est plus fiable. Par exemple, egales y apparaît à 0,00 s malgré ses 873 485 appels.
4. Pistes d'amélioration, classées par gain attendu
Le classement vient du profil initial, corrigé par la lecture du code pour construire_rapport (dont le coût réel est masqué par gprof, voir 3.3).
| Rang | Piste | Fonction | Complexité | Gain attendu | Réalisée |
|---|---|---|---|---|---|
| 1 | Calculer la moyenne une seule fois, avant la boucle | ecart_type_longueur |
O(n²) → O(n) | ~45 % d'après gprof | ✔ commit 1 |
| 2 | Indexer les mots avec une table de hachage | chercher_mot, compter_mot |
O(N × n) → O(N) en moyenne | ~39 % | ✔ commit 2 |
| 3 | Écrire à la fin du rapport sans recalculer sa longueur | construire_rapport |
O(n²) → O(n) en caractères | 0,4 % d'après gprof, mais 2,61 × 10⁸ caractères parcourus : autant que la piste 1 | ✔ commit 3 |
| 4 | Remplacer le tri à bulles par qsort |
trier_entrees |
O(n²) → O(n log n) | ~9 % | ✔ commit 5 |
| 5 | Ne plus recalculer la longueur de la ligne à chaque tour | normaliser_ligne |
O(L²) → O(L) par ligne | ~2 % (sous-estimé de la même façon que la piste 3) | ✔ commit 4 |
| 6 | Ne comparer qu'aux mots vides de même première lettre | est_mot_vide |
60 → 2,9 comparaisons complètes par mot en moyenne | ~2 % | ✔ commit 6 |
| 7 | Compiler la version livrée en -O2 |
— | — | voir partie 6 | mesuré, sans changer le code |
| 8 | Table de hachage dédiée aux mots vides | est_mot_vide |
O(60) → O(1) | marginal après la piste 6 | non |
| 9 | Écrire à la fin des mots dans generer_vocabulaire |
ajouter |
— | ~1 %, et c'est la génération des données de test | non |
| 10 | Fusionner découpage, normalisation et comptage en une seule passe | plusieurs | O(texte) inchangé | faible, et moins lisible | non |
Après chaque optimisation, j'ai re-profilé pour choisir la suivante. C'est ce qui a fait passer normaliser_ligne avant le tri : après le commit 3, longueur (appelée presque uniquement par normaliser_ligne) pesait plus que trier_entrees.
5. Optimisations réalisées (un commit par optimisation)
Pour chaque étape, j'ai vérifié trois choses : l'empreinte reste 1d53de903efd2b7c, rapport.txt est identique octet par octet à celui de la version d'origine, et la sortie console est identique.
Commit 1 — 330254a : calculer la moyenne une seule fois
double moyenne = longueur_moyenne(table, n); /* calculée une seule fois */
double somme = 0.0;
for (int i = 0; i < n; i++) {
double ecart = longueur(table[i].mot) - moyenne;
La moyenne ne dépend pas de i : il suffit de la calculer une fois avant la boucle. On passe de 34,4 millions d'appels à longueur à 17 598. Le résultat en virgule flottante est exactement le même, puisque la valeur soustraite est identique.
7,63 s → 5,58 s (−27 %)
Commit 2 — 255a739 : table de hachage pour compter les mots
#define TAILLE_HACHAGE 32768
static int index_mots[TAILLE_HACHAGE]; /* indice + 1 dans table, 0 = case vide */
unsigned long chercher_mot(const Entree *table, const char *mot)
{
unsigned long h = empreinte(mot) & (TAILLE_HACHAGE - 1);
while (index_mots[h] != 0 && !egales(table[index_mots[h] - 1].mot, mot))
h = (h + 1) & (TAILLE_HACHAGE - 1);
return h;
}
C'est une table à adressage ouvert (sondage linéaire), qui réutilise la fonction de hachage FNV-1a empreinte déjà présente dans le programme. Sa taille est une puissance de 2 pour que le modulo devienne un simple &. Elle est remplie au plus à 18 % (5 866 mots pour 32 768 cases), donc les sondages restent courts. L'ordre d'insertion dans table ne change pas. Les appels à egales tombent de 308,7 millions à 12,2 millions.
5,58 s → 2,03 s (−64 %)
Commit 3 — cd34f39 : construire le rapport en temps linéaire
char *fin = rapport; /* position du '\0' final : on écrit directement à la suite */
fin += sprintf(fin, "rang;mot;occurrences\n");
for (int i = 0; i < n; i++)
fin += sprintf(fin, "%d;%s;%d\n", i + 1, table[i].mot, table[i].occurrences);
ajouter (copier(dest + longueur(dest), src)) reparcourait tout le rapport à chaque ligne. On garde plutôt un pointeur sur la fin. Une ligne fait au plus 45 caractères (rang sur 5 chiffres, mot de 31 caractères, 6 chiffres d'occurrences) et 23 en pratique ici. Le tampon prévoit 64 octets par mot, donc il n'y a pas de risque de débordement.
2,03 s → 1,06 s (−48 %). C'est le gain que gprof ne laissait pas prévoir (partie 3.3).
Commit 4 — 9966c6f : ne plus recalculer la longueur de la ligne
for (int i = 0; ligne[i] != '\0'; i++) { /* sans recalculer la longueur à chaque tour */
La normalisation remplace des caractères par des lettres ou des espaces, jamais par '\0'. La longueur de la ligne ne change donc pas, et s'arrêter sur le '\0' donne le même résultat. On supprime 1,56 million de parcours de lignes d'environ 71 caractères.
1,06 s → 0,53 s (−50 %)
Commit 5 — f6d43c1 : qsort au lieu du tri à bulles
int comparer_entrees(const void *pa, const void *pb)
{
const Entree *a = pa, *b = pb;
if (a->occurrences != b->occurrences)
return b->occurrences - a->occurrences;
return comparer(a->mot, b->mot);
}
L'ordre est le même que celui de doit_echanger : occurrences décroissantes, puis ordre alphabétique. Les mots de la table sont tous distincts, donc cet ordre est total. qsort n'est pas stable, mais il produit exactement le même classement que le tri à bulles. La fonction comparer passe de 12,2 millions d'appels à 37 530.
0,53 s → 0,20 s (−62 %)
Commit 6 — 872935c : filtrer les mots vides sur la première lettre
if (MOTS_VIDES[i][0] == mot[0] && egales(mot, MOTS_VIDES[i]))
On ne fait la comparaison complète que si la première lettre correspond. Les appels à egales passent de 12,2 millions à 873 485.
0,200 s → 0,153 s (−24 %). À ce niveau, le bruit de mesure (environ ±0,05 s) devient du même ordre que le gain : c'est le signe qu'il faut s'arrêter.
Évolution du temps
| Étape | Commit | Temps (médiane de 5) | Gain de l'étape | Accélération cumulée |
|---|---|---|---|---|
| Version d'origine | — | 7,63 s | — | ×1 |
| 1. Moyenne calculée une fois | 330254a |
5,58 s | −2,05 s | ×1,4 |
| 2. Table de hachage | 255a739 |
2,03 s | −3,54 s | ×3,8 |
| 3. Rapport en temps linéaire | cd34f39 |
1,06 s | −0,97 s | ×7,2 |
4. normaliser_ligne |
9966c6f |
0,53 s | −0,54 s | ×14 |
5. qsort |
f6d43c1 |
0,20 s | −0,33 s | ×38 |
| 6. Mots vides | 872935c |
0,15 s | −0,05 s | ×50 |
Ce tableau illustre les rendements décroissants. Chaque étape supprime une bonne part du temps qui reste (entre 24 % et 64 %), mais le gain en secondes diminue à chaque fois, puisqu'il reste de moins en moins de temps à gagner. Les deux premières étapes font à elles seules 75 % du gain total. Comme le prévoit la loi d'Amdahl, l'accélération globale d'une étape dépend de la part du temps qu'elle touche : l'étape 2 (64 % du temps de l'époque) rapporte 3,5 s, l'étape 6 (24 % de 0,2 s) seulement 0,05 s.
6. Validation (profil_apres.txt)
Temps avant / après
Pour cette validation, j'ai lancé les deux versions 10 fois chacune, à la suite, dans la même session, en -O0 puis en -O2. C'est la comparaison avant/après la plus fiable.
| Compilation | Avant : médiane (min – max) | Après : médiane (min – max) | Accélération | Empreinte |
|---|---|---|---|---|
-O0 -g |
6,25 s (5,55 – 9,34) | 0,18 s (0,15 – 0,26) | ×35 | 1d53de903efd2b7c ✔ |
-O2 -g |
1,72 s (1,66 – 1,90) | 0,11 s (0,08 – 0,19) | ×15 | 1d53de903efd2b7c ✔ |
- La version d'origine met ici 6,25 s, contre 7,63 s lors de la mesure initiale. C'est le bruit de mesure vu en cours : sur un portable, la fréquence du processeur varie probablement d'une session à l'autre (turbo, température, autres processus). C'est pour cela que je compare des médianes mesurées dans la même session, et que les facteurs du tableau de la partie 5 (mesurés à des moments différents) ne sont qu'indicatifs.
-O2accélère à lui seul la version d'origine (×3,6), mais il ne corrige pas la complexité : les boucles quadratiques sont toujours là. Les optimisations algorithmiques apportent encore ×15 en-O2. En combinant les deux, on passe de 6,25 s à 0,11 s (×56).
Profil après optimisation
% cumulative self self total
time seconds seconds calls ms/call ms/call name
37.50 0.12 0.12 _mcount_private
18.75 0.18 0.06 __fentry__
12.50 0.22 0.04 21746 0.00 0.00 compter_mots_ligne
6.25 0.24 0.02 928117 0.00 0.00 alea
6.25 0.26 0.02 250000 0.00 0.00 est_mot_vide
6.25 0.28 0.02 150183 0.00 0.00 empreinte
6.25 0.30 0.02 1 20.00 20.00 decouper_lignes
| Indicateur | Avant | Après |
|---|---|---|
| Durée de l'exécution profilée | 28,87 s | 0,32 s |
Temps propre au programme (total de main) |
10,24 s | 0,14 s |
Appels à egales |
308 701 874 | 873 485 |
Appels à longueur |
36 009 819 | 38 532 |
Appels à comparer |
12 172 087 | 37 530 |
Avec seulement 32 échantillons, la répartition entre fonctions est imprécise, mais aucun point chaud ne se détache. Le temps restant se répartit entre des passes linéaires sur le texte : génération, découpage, normalisation, comptage et trigrammes. On ne peut pas les supprimer sans changer le travail que fait le programme.
7. Bilan
- Résultat : de 6,25 s à 0,18 s en
-O0(×35) et de 1,72 s à 0,11 s en-O2(×15), avec un résultat strictement identique (même empreinte, mêmerapport.txt, même sortie). - Ce qui a payé : corriger la complexité des algorithmes. Les cinq premières optimisations suppriment un parcours répété inutilement (boucle dans une boucle, recherche linéaire, tri quadratique, longueur recalculée) et font presque tout le gain. Aucune ne touche aux détails de bas niveau.
- Mesurer avant d'optimiser, et re-mesurer après : le profil a désigné les deux premiers points chauds. Mais c'est la mesure après chaque commit qui a révélé le coût réel de
construire_rapport, que gprof masquait en répartissant le temps delongueurselon le nombre d'appels. - Coût des optimisations : la table de hachage ajoute une quinzaine de lignes et 128 Ko de mémoire fixe (32 768 entiers). Elle repose aussi sur une hypothèse : au plus
MAX_MOTS_UNIQUES(20 000) mots distincts. Au-delà de 32 768 mots, la recherche bouclerait sans fin. Le code d'origine ne vérifie pas non plus cette limite, puisqu'il déborderait déjà du tableautable. Les autres changements raccourcissent ou simplifient le code. Le tri en une ligne avecqsortest plus lisible que le tri à bulles. - Limite rencontrée : le code d'origine suppose un
unsigned longde 64 bits et ne donne pas le bon résultat sous Windows natif (partie 1).