Files
Ryad Mehiri 484c2749d8 Profil après optimisation et compte rendu du TD1
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>
2026-10-14 14:06:17 +02:00

20 KiB
Raw Permalink Blame History

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_moyenne parcourent chacun un mot d'environ 7 caractères ;
  • les 5 867 appels venant de construire_rapport (via ajouter) 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 de longueur_moyenne ré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.
  • -O2 accé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ême rapport.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 de longueur selon 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 tableau table. Les autres changements raccourcissent ou simplifient le code. Le tri en une ligne avec qsort est plus lisible que le tri à bulles.
  • Limite rencontrée : le code d'origine suppose un unsigned long de 64 bits et ne donne pas le bon résultat sous Windows natif (partie 1).