🚧 Attention, peinture fraîche !

Cette page a été traduite par une seule personne et n'a pas été relue et vérifiée par quelqu'un d'autre ! Les informations peuvent par exemple être erronées, être formulées maladroitement, ou contenir d'autres types de fautes.

🚧 Les captures d'écran de cette page n'ont pas encore été traduites !

Le profilage temporel

Dans ce chapitre, nous allons améliorer la performance de l'implémentation de notre jeu de la vie. Nous allons utiliser le profilage temporel pour orienter notre travail.

Avant de continuer, familiarisez-vous avec [les outils disponibles pour le profilage temporel pour le code Rust et WebAssembly].

Créer un compteur d'images par seconde avec window.performance.now

Ce compteur d'images par seconde sera un indicateur utile lors de nos recherches d'améliorations de performances du rendu de notre jeu de la vie.

Nous allons commencer par rajouter un objet ips (pour Images Par Seconde) à wasm-jeu-de-la-vie/www/index.js :

const ips = new class {
  constructor() {
    this.ips = document.getElementById("ips");
    this.images = [];
    this.timeStampDeLaDerniereImage = performance.now();
  }

  afficher() {
    // Convertit la différence de temps entre la dernière image en
    // images par seconde.
    const maintenant = performance.now();
    const difference = maintenant - this.timeStampDeLaDerniereImage;
    this.timeStampDeLaDerniereImage = maintenant;
    const ips = 1 / difference * 1000;

    // Ne conserve que les 100 dernières images.
    this.images.push(ips);
    if (this.images.length > 100) {
      this.images.shift();
    }

    // Trouve la valeur minimale, maximale, et la moyenne des
    // 100 dernières images.
    let min = Infinity;
    let max = -Infinity;
    let somme = 0;
    for (let i = 0; i < this.images.length; i++) {
      somme += this.images[i];
      min = Math.min(this.images[i], min);
      max = Math.max(this.images[i], max);
    }
    let moyenne = somme / this.images.length;

    // Affiche les statistiques.
    this.ips.textContent = `
Images Par Seconde :
                           actuel = ${Math.round(ips)}
 moyenne des 100 dernières images = ${Math.round(moyenne)}
mininima des 100 dernières images = ${Math.round(min)}
  maxima des 100 dernières images = ${Math.round(max)}
`.trim();
  }
};

Ensuite, nous devons appeler la fonction afficher à chaque itération de boucleDeRendu :

const boucleDeRendu = () => {
    ips.afficher(); //new

    univers.tick();
    dessinerGrille();
    dessinerCellules();

    animationId = requestAnimationFrame(boucleDeRendu);
};

Enfin, n'oubliez pas d'ajouter le noeud #ips à wasm-jeu-de-la-vie/www/index.html, juste au-dessus du <canvas> :

<div id="ips"></div>

Ainsi qu'un peu de style CSS pour améliorer son rendu :

#ips {
  white-space: pre;
  font-family: monospace;
}

Et voilà ! Rafraîchissez la page http://localhost:8080 et vous avez maintenant un compteur d'images par seconde !

Chronomètrer chaque Univers::tick avec console.time et console.timeEnd

Pour mesurer la durée que prends chaque appel à Univers::tick, nous pouvons utiliser console.time et console.timeEnd avec la crate web-sys.

Pour commencer, ajoutez la dépendance web-sys dans wasm-jeu-de-la-vie/Cargo.toml :

[dependencies.web-sys]
version = "0.3"
features = [
  "console",
]

Comme nous aurons un appel à console.timeEnd correspondant à chaque appel à console.time, il nous est plus pratique de les intégrer dans un type qui implémente le concept de RAII :


#![allow(unused)]
fn main() {
extern crate web_sys;
use web_sys::console;

pub struct Chronometre<'a> {
    nom: &'a str,
}

impl<'a> Chronometre<'a> {
    pub fn new(nom: &'a str) -> Chronometre<'a> {
        console::time_with_label(nom);
        Chronometre { nom }
    }
}

impl<'a> Drop for Chronometre<'a> {
    fn drop(&mut self) {
        console::time_end_with_label(self.nom);
    }
}
}

Maintenant, nous pouvons chronométrer le temps que prend Univers::tick en ajoutant ceci en haut de la méthode :


#![allow(unused)]
fn main() {
let _chronometre = Chronometre::new("Univers::tick");
}

La durée de chaque appel à Univers::tick est maintenant affichée dans la console :

Capture d'écran des journaux de console.time

De plus, les coupes de console.time et de console.timeEnd vont être mis en évidence dans la vue "timeline" ou "chronologie" du profileur du navigateur :

Capture d'écran des journaux de console.time

Agrandir l'univers de notre jeu de la vie

⚠️ Cette section utilise des captures d'écran de Firefox comme exemples. Bien que tous les navigateurs ont des outils qui se ressemblent, il peut y avoir quelques petites différences lorsque vous travaillez avec des outils de développements différents. Les informations du profilage que vous allez récupérer sera généralement le même, mais sa représentation peut changer en fonction des vues des différents outils que vous aurez et leur façon de nommer les choses.

Que va-t-il se passer si nous agrandissons l'univers de notre jeu de la vie ? Remplacer l'univers de 64 par 64 par un univers de 128 par 128 (en modifiant Univers::new dans wasm-jeu-de-la-vie/src/lib.rs) va réduire drastiquement les images par seconde de 60 ips fluide à un 40 ips trouble sur certaines machines.

Si nous générons un profilage et regardons la vue "chronologie", nous pouvons constater que chaque image de l'animation prend plus de 20 millisecondes de calcul. Retenez que 60 images par seconde signifie qu'il se passe environ 16 millisecondes entre chaque image. Cela ne s'applique pas uniquement aux calculs du JavaScript et du WebAssembly, mais aussi à tout ce que le navigateur fait d'autre pendant ce temps, comme le rendu et l'affichage à l'écran.

Capture d'écran de la vue chronologie du rendu d'une image

Si nous analysons ce qui se passe à chaque image de l'animation, on peut voir que le mutateur CanvasRenderingContext2D.fillStyle prend beaucoup de temps !

⚠️ Dans Firefox, si vous voyez une ligne qui dit simplement "DOM" au lieu du canvasRenderingContext2D.filleStyle que nous avons mentionné précédemment, vous devriez activer l'option "Afficher les données de la plate-forme Gecko" dans les options de vos outils de développement :

Activation de l'option afficher les données de la plate-forme Gecko

Capture d'écran d'une vue flamegraph du rendu d'une image

Et nous pouvons confirmer que ce n'est pas une anomalie en analysant l'agrégation de l'arbre d'appels de plusieurs images :

Capture d'écran d'une vue flamegraph du rendu d'une image

On passe presque 40% du temps dans ce mutateur !

⚡ Nous pourrions nous attendre à ce que la méthode tick explique la perte de performances, mais ce n'est pas le cas. Ayez toujours le réflexe d'utiliser le profileur pour orienter vos efforts, autrement vous risquez de perdre votre temps à optimiser des parties qui sont négligeables en terme de performance.

Dans la fonction dessinerCellules de wasm-jeu-de-la-vie/www/index.js, la propriété fillStyle est définie pour chaque cellule de l'univers, à chaque image de l'animation.

for (let ligne = 0; ligne < hauteur; ligne++) {
  for (let colonne = 0; colonne < largeur; colonne++) {
    const indice = calculerIndice(ligne, colonne);

    ctx.fillStyle = cellules[indice] === Cellule.Morte
      ? COULEUR_MORTE
      : COULEUR_VIVANTE;

    ctx.fillRect(
      colonne * (TAILLE_CELLULE + 1) + 1,
      ligne * (TAILLE_CELLULE + 1) + 1,
      TAILLE_CELLULE,
      TAILLE_CELLULE
    );
  }
}

Maintenant que nous avons découvert qu'utiliser fillStyle est très chronophage, qu'est-ce que nous pouvons faire pour éviter de l'utiliser aussi souvent ? Nous devons changer fillStyle si une cellule est vivante ou morte. Si nous faisons en sorte que fillStyle = COULEUR_VIVANTE et que nous dessinons ensuite toutes les cellules vivantes en une seule fois sur une première passe, et que nous faisons ensuite en sorte que fillStyle = COULEUR_MORTE puis que nous dessinons toutes les cellules mortes en une deuxième passe, alors nous utilisons fillStyle seulement deux fois, plutôt qu'une fois sur chaque cellule.

// Cellules vivantes.
ctx.fillStyle = COULEUR_VIVANTE;
for (let ligne = 0; ligne < hauteur; ligne++) {
  for (let colonne = 0; colonne < largeur; colonne++) {
    const indice = calculerIndice(ligne, colonne);
    if (cellules[indice] !== Cellule.Vivante) {
      continue;
    }

    ctx.fillRect(
      colonne * (TAILLE_CELLULE + 1) + 1,
      ligne * (TAILLE_CELLULE + 1) + 1,
      TAILLE_CELLULE,
      TAILLE_CELLULE
    );
  }
}

// Cellules mortes.
ctx.fillStyle = COULEUR_MORTE;
for (let ligne = 0; ligne < hauteur; ligne++) {
  for (let colonne = 0; colonne < largeur; colonne++) {
    const indice = calculerIndice(ligne, colonne);
    if (cellules[indice] !== Cellule.Morte) {
      continue;
    }

    ctx.fillRect(
      colonne * (TAILLE_CELLULE + 1) + 1,
      ligne * (TAILLE_CELLULE + 1) + 1,
      TAILLE_CELLULE,
      TAILLE_CELLULE
    );
  }
}

Après avoir sauvegardé ces changements et rafraîchi http://localhost:8080/, le rendu est à nouveau fluide à 60 images par secondes.

Si nous générons un nouveau profilage, nous pouvons constater que maintenant seulement 10 millisecondes se passent entre chaque image.

Capture d'écran de la vue chronologie du rendu d'une image après les modifications sur dessinerCellules

En décomposant image par image, on constate que cette utilisation de fillStyle n'a plus de impact lourd, et que la plupart du temps de calcul de notre image se passe dans fillRect, qui dessine le rectangle de chaque cellule.

Capture d'écran d'une vue flamegraph du rendu après les changements apportés à dessinerCellules

Faire en sorte que le temps s'accélère

Certaines personnes n'aiment pas attendre, et préfèrent qu'au lieu d'un seul tick de l'univers se déroule à chaque image de l'animation, il se passe neuf ticks. Nous pouvons modifier la fonction boucleDeRendu dans wasm-jeu-de-la-vie/www/index.js pour implémenter cela facilement :

for (let i = 0; i < 9; i++) {
  univers.tick();
}

Sur certaines machines, cela nous ralentit à seulement 35 images par secondes. Ce n'est pas bon, nous voulons en avoir 60 !

Nous savons maintenant que le calcul de Univers::tick prend plus de temps, donc nous allons ajouter quelques chronomètres pour couvrir certaines de ses parties avec les appels à console.time et console.timeEnd pour voir ce que cela peut nous apprendre. Notre hypothèse est que l'allocation d'un nouveau vecteur de cellules et le nettoyage de l'ancien vecteur à chaque tick est coûteux, et nous impute d'une partie importante de notre enveloppe de temps.


#![allow(unused)]
fn main() {
pub fn tick(&mut self) {
    let _chronometre = Chronometre::new("Univers::tick");

    let mut generation_suivante = {
        let _chronometre = Chronometre::new("création cellules prochaine génération");
        self.cellules.clone()
    };

    {
        let _chronometre = Chronometre::new("calcul nouvelle génération");
        for ligne in 0..self.hauteur {
            for colonne in 0..self.largeur {
                let indice = self.calculer_indice(ligne, colonne);
                let cellule = self.cellules[indice];
                let voisines_vivantes = self.compter_voisines_vivantes(ligne, colonne);

                let prochain_etat = match (cellule, voisines_vivantes) {
                    // Règle 1 : toute cellule vivante avec moins de deux
                    // voisines vivantes meurt, comme si cela était un effet de
                    //  sous-population.
                    (Cellule::Vivante, x) if x < 2 => Cellule::Morte,
                    // Règle 2 : toute cellule vivante avec deux ou trois
                    // voisines vivantes survit jusqu'à la prochaine génération.
                    (Cellule::Vivante, 2) | (Cellule::Vivante, 3) => Cellule::Vivante,
                    // Règle 3 : toute cellule vivante avec plus de trois
                    // voisines vivantes meurt, comme si cela était un effet de
                    // surpopulation.
                    (Cellule::Vivante, x) if x > 3 => Cellule::Morte,
                    // Règle 4 : toute cellule morte avec exactement trois
                    // voisines vivantes devient une cellule vivante, comme si
                    // cela était un effet de reproduction.
                    (Cellule::Morte, 3) => Cellule::Vivante,
                    // Les cellules qui ne répondent à aucune de ces conditions
                    // restent dans le même état.
                    (statut, _) => statut,
                };

                generation_suivante[indice] = prochain_etat;
            }
        }
    }

    let _chronometre = Chronometre::new("nettoyage des anciennes cellules");
    self.cellules = generation_suivante;
}
}

Vu les résultats des chronomètres, il est clair que notre hypothèse est incorrecte : l'écrasante majorité du temps est consacré à calculer la prochaine génération des cellules. L'allocation et le nettoyage d'un vecteur à chaque tick est un coût négligeable, contre toute attente. Voilà une bonne raison de toujours orienter vos efforts avec le profilage !

Capture d'écran des résultats du chronomètre Univers::tick

Ecrivons un code natif avec #[bench] qui fait les mêmes choses que notre WebAssembly, mais où nous pouvons utiliser des outils de profilage plus mâtures. Voici le nouveau fichier wasm-jeu-de-la-vie/benches/bench.rs :


#![allow(unused)]
#![feature(test)]

fn main() {
extern crate test;
extern crate wasm_jeu_de_la_vie;

#[bench]
fn ticks_univers(b: &mut test::Bencher) {
    let mut univers = wasm_jeu_de_la_vie::Univers::new();

    b.iter(|| {
        univers.tick();
    });
}
}

Nous devons également commenter toutes les annotations #[wasm_bindgen], et les parties "cdylib" dans le Cargo.toml, car sinon la compilation du code natif va échouer et aura des erreurs de liaisons avec des bibliothèques.

Une fois ceci en place, nous pouvons exécuter cargo bench | tee avant.txt pour compiler et exécuter notre comparatif ! La partie | tee avant.txt va récupérer la sortie de cargo bench et l'écrire dans le fichier avant.txt.

$ cargo bench | tee avant.txt
    Finished release [optimized + debuginfo] target(s) in 0.0 secs
     Running target/release/deps/wasm_jeu_de_la_vie-91574dfbe2b5a124

running 0 tests

test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out

     Running target/release/deps/bench-8474091a05cfa2d9

running 1 test
test ticks_univers ... bench:     664,421 ns/iter (+/- 51,926)

test result: ok. 0 passed; 0 failed; 0 ignored; 1 measured; 0 filtered out

Cela va aussi nous indiquer où est le binaire, et nous pourrons à nouveau exécuter le comparatif, mais cette fois avec le profileur de notre système d'exploitation. Dans notre cas, nous l'exécutons sous Linux, donc nous allons utiliser perf :

$ perf record -g target/release/deps/bench-8474091a05cfa2d9 --bench
running 1 test
test ticks_univers ... bench:     635,061 ns/iter (+/- 38,764)

test result: ok. 0 passed; 0 failed; 0 ignored; 1 measured; 0 filtered out

[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.178 MB perf.data (2349 samples) ]

L'ouverture du profil avec perf report nous montre que tout le temps est passé dans Univers::tick, comme nous nous y attendions :

Capture d'écran de perf report

perf va annoter quel temp est passé dans chaque instruction si vous appuyez sur a :

Capture d'écran de l'annotation d'instruction de perf

On apprend donc que 26.67% du temps est passé au comptage des cellules voisines, que 23.41% du temps est consacré à calculer l'indice de la colonne correspondante à la cellule voisine, et que 15.42% du temps en plus est passé à obtenir l'indice de la ligne de la voisine. Parmi ces trois instructions coûteuses, la seconde et la troisième sont des instructions div (pour division) assez coûteuses. Ces divisions sont implémentées dans la logique d'indexation faisant appel aux modulos, dans Univers::compter_voisines_vivantes.

Souvenez-vous de la définition de compter_voisines_vivantes dans wasm-jeu-de-la-vie/src/lib.rs :


#![allow(unused)]
fn main() {
fn compter_voisines_vivantes(&self, ligne: u32, colonne: u32) -> u8 {
    let mut compteur = 0;
    for delta_ligne in [self.hauteur - 1, 0, 1].iter().cloned() {
        for delta_colonne in [self.largeur - 1, 0, 1].iter().cloned() {
            if delta_ligne == 0 && delta_colonne == 0 {
                continue;
            }

            let ligne_voisine = (ligne + delta_ligne) % self.hauteur;
            let colonne_voisine = (colonne + delta_colonne) % self.largeur;
            let indice = self.calculer_indice(ligne_voisine, colonne_voisine);
            compteur += self.cellules[indice] as u8;
        }
    }
    compteur
}
}

La raison pour laquelle nous avions utilisé le modulo était d'éviter d'encombrer le code avec des branches if pour gérer les cas des bords des premières lignes et colonnes. Mais nous payons le prix de l'utilisation des instructions de division même pour les cas les plus courants, c'est-à-dire lorsque ni ligne, ni la colonne ne se trouvent pas sur les bords de l'univers et n'ont pas besoin du traitement du rebouclage avec le modulo. Mais si à la place nous utilisons des if pour détecter les cas des bordures et dérouler cette boucle, les branches devraient être bien appréhendées par le prédicteur de branches du CPU.

Ré-écrivons compter_voisines_vivantes de cette manière :


#![allow(unused)]
fn main() {
fn compter_voisines_vivantes(&self, ligne: u32, colonne: u32) -> u8 {
    let mut compteur = 0;

    let nord = if ligne == 0 {
        self.hauteur - 1
    } else {
        ligne - 1
    };

    let sud = if ligne == self.hauteur - 1 {
        0
    } else {
        ligne + 1
    };

    let ouest = if colonne == 0 {
        self.largeur - 1
    } else {
        colonne - 1
    };

    let est = if colonne == self.largeur - 1 {
        0
    } else {
        colonne + 1
    };

    let no = self.calculer_indice(nord, ouest);
    compteur += self.cellules[no] as u8;

    let n = self.calculer_indice(nord, colonne);
    compteur += self.cellules[n] as u8;

    let ne = self.calculer_indice(nord, est);
    compteur += self.cellules[ne] as u8;

    let o = self.calculer_indice(ligne, ouest);
    compteur += self.cellules[o] as u8;

    let e = self.calculer_indice(ligne, est);
    compteur += self.cellules[e] as u8;

    let so = self.calculer_indice(sud, ouest);
    compteur += self.cellules[so] as u8;

    let s = self.calculer_indice(sud, colonne);
    compteur += self.cellules[s] as u8;

    let se = self.calculer_indice(sud, est);
    compteur += self.cellules[se] as u8;

    compteur
}
}

Lançons à nouveau les comparatifs ! Et cette fois nous allons l'enregistrer dans apres.txt.

$ cargo bench | tee apres.txt
   Compiling wasm_jeu_de_la_vie v0.1.0 (file:///home/fitzgen/wasm_jeu_de_la_vie)
    Finished release [optimized + debuginfo] target(s) in 0.82 secs
     Running target/release/deps/wasm_jeu_de_la_vie-91574dfbe2b5a124

running 0 tests

test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out

     Running target/release/deps/bench-8474091a05cfa2d9

running 1 test
test ticks_univers ... bench:      87,258 ns/iter (+/- 14,632)

test result: ok. 0 passed; 0 failed; 0 ignored; 1 measured; 0 filtered out

On dirait que cela a fait du bien ! Nous pouvons constater les améliorations grâce à l'outil benchcmp et des deux fichiers texte que nous avons créé précédemment :

$ cargo benchcmp avant.txt apres.txt
 name            before.txt ns/iter  after.txt ns/iter  diff ns/iter   diff %  speedup
 universe_ticks  664,421             87,258                 -577,163  -86.87%   x 7.61

Ouah ! C'est 7.61 fois plus rapide !

Le WebAssembly aspire à ressembler au plus aux architectures matérielles les plus courantes, mais nous devons nous assurer que ces améliorations des performances s'appliquent aussi au WebAssembly.

Recompilons le .wasm avec wasm-pack build et rafraîchissons http://localhost:8080/. Sur certaines machines, cette page s'exécute à nouveau à 60 images par secondes, et l'enregistrement d'un nouveau profil avec le profileur du navigateur dans ce cas nous apprendra que chaque image de l'animation se calcule en environ dix millisecondes.

Victoire !

Capture d'écran de la vue waterfall du rendu d'une image après avoir remplacé les modulos par des branches

Exercices

  • A ce stade, l'optimisation la plus accessible pour Univers::tick est d'enlever l'allocation et la libération en mémoire. Pour cela, implémentez le double buffering des cellules, avec lequel Univers contient deux vecteurs, qui ne seront jamais libérés, et n'alloue jamais de nouveaux tampons dans la fonction tick.
  • Essayez d'implémenter une alternative, un concept du chapitre "Implémenter le jeu de la vie de Conway", basé sur les différences, dans lequel le code Rust retourne la liste des cellules qui ont changé d'état au JavaScript. Est-ce que cela améliore la rapidité du rendu du <canvas> ? Pouvez-vous implémenter ce concept sans allouer une nouvelle liste de différences à chaque tick ?
  • Comme le profilage nous l'as appris, le rendu 2D du <canvas> n'est pas particulièrement rapide. Essayez de remplacer le rendu 2D du canvas par un rendu avec WebGL. Quels sont les gains de performance ? A partir de quelle taille de l'univers le rendu en WebGL améliore les performances ?