Un battement de cœur pour le thread principal

Sans mesure, pas de correction.

La barre latérale ramait. Ni systématiquement, ni de façon prévisible. Pendant les gros scans, quand la détection de doublons tournait, elle saccadait : le défilement accrochait, les sélections traînaient. L’application bossait en coulisse, mais l’interface décrochait. Sous macOS, le thread principal est le seul à pouvoir mettre à jour l’interface : le bloquer, c’est tout figer : frames, défilement, sélections.

« Lent », ce n’est pas un rapport de bug. On ne corrige pas « lent » : on corrige « thread principal bloqué 340 ms à chaque résolution de hash ».

PerfLogWriter, c’est la première chose que j’ai construite. Pas un correctif : un instrument.

C’est un logger fichier tout bête. Les événements sont écrits sur disque avec horodatage et catégorie. Chaque fichier de log est plafonné en taille (écriture stoppée au-delà), et les anciens fichiers sont purgés d’une session à l’autre : les logs ne grossissent pas indéfiniment. Des entrées structurées, une par ligne, exploitables par les scripts d’analyse dans Scripts/Performance/.

Le vrai apport, c’est le battement de cœur. Même principe qu’un health check : si la réponse arrive en retard, quelque chose bloque.

Un timer GCD (Grand Central Dispatch) sur DispatchQueue.main se déclenche toutes les 500 ms. À chaque déclenchement, il note combien de temps s’est réellement écoulé. Si le thread principal est libre, le timer se déclenche à l’heure ; s’il est occupé, il arrive en retard : l’écart entre l’intervalle prévu et l’intervalle réel, c’est la durée du blocage.¹

Voici à quoi ressemble une entrée. Sur un scan de 5,2M nœuds (M3 Pro, compilation Debug), six workers de hachage concurrents alimentant l’interface, le battement de cœur a capturé ceci :

MAIN_THREAD_BLOCKED 840ms (expected 500ms)

Le timer devait se déclencher après 500 ms, il s’est déclenché après 840 ms : le thread principal était bloqué pendant les 340 ms supplémentaires. Si cette ligne n’apparaît pas, le thread principal n’a pas été bloqué ; si elle est là, on sait exactement quand et pendant combien de temps : le flou devient un fait horodaté.

Les logs ont pointé droit sur la cause.

La détection de doublons lance un TaskGroup à six workers. Chaque worker hashe un fichier et renvoie le condensat, six flux de résultats à plein régime. L’implémentation d’origine rappelait le ViewModel à chaque résultat :

// Bad: per-result mutation triggers a SwiftUI diff on every iteration
for await result in group {
    self.cleanupResult = result  // triggers re-render every time
}

Avec des milliers de candidats doublons, ça faisait des milliers de sauts forcés vers le thread principal. Avec la concurrence structurée de Swift, chaque reprise d’await dans une boucle for await rend la main à la run loop², et SwiftUI programme un nouveau rendu à chaque résultat.

Si les mutations tombent dans le même tour de run loop, SwiftUI les regroupe en un seul diff. L’itération asynchrone casse ce mécanisme. Le thread principal ne trouvait jamais un instant de répit.

Le remède : regrouper par lots.

// Good: batch updates every 250ms (simplifié ; le vrai code utilise une boucle Task.sleep)
@MainActor
func flushResults(_ pending: [Result]) {
    self.results.append(contentsOf: pending)
}

// Dans le contexte du TaskGroup :
var buffer: [Result] = []
// Une Task séparée vide périodiquement le tampon vers l'état @MainActor.
// Toutes les mutations d'un seul vidage tombent dans un même tour de run loop,
// donc SwiftUI les regroupe en un seul diff.
for await result in group {
    buffer.append(result)
}

Au lieu de mettre à jour l’état à chaque résultat, on accumule dans un tampon local. Toutes les 250 ms, on vide le tampon vers l’état @MainActor (le contexte réservé au thread principal) en une seule fournée. SwiftUI fait un diff par vidage, pas un par résultat. Entre deux lots, le thread principal a le temps de souffler.

Après cette correction, les entrées MAIN_THREAD_BLOCKED ont disparu de la phase de détection de doublons. Avant : 200–400 ms de blocage par tick du battement de cœur, trois blocages sévères (>2 s) par session. Après le vidage par lots : zéro événement de blocage sur trois exécutions consécutives. La barre latérale défilait sans accroc pendant les scans.

Le battement de cœur attrapait des problèmes que mes propres habitudes d’utilisation ne déclenchaient jamais de manière reproductible.

Les logs ont aussi révélé une métrique que j’avais mal interprétée.

sidebar body_eval selection_roundtrip=Xms enregistre le temps écoulé depuis la dernière évaluation de la barre latérale. En voyant des valeurs comme 17000ms, j’ai d’abord cru à un problème : aucun calcul de rendu ne devrait prendre 17 secondes.

Ce n’est pas ce que ça veut dire. Le chiffre mesure le temps écoulé depuis la dernière évaluation, pas la durée de l’évaluation. 17 000 ms signifie que la barre latérale n’a pas été réévaluée pendant 17 secondes, parce que rien n’y avait changé. Quand le scan tourne et que la barre latérale n’a pas encore reçu de nouvelles données, il n’y a rien à réévaluer. Pas de réévaluation ? Ce n’est pas un bug : le suivi @Observable de SwiftUI ne réévalue que les vues dont l’état a réellement changé. Rien de neuf, rien à redessiner.

Me fier à cette lecture m’aurait coûté deux jours à optimiser du code qui marchait très bien. La métrique de performance la plus dangereuse, c’est celle qu’on croit comprendre.

Un piège pratique : l’application est sandboxée, les logs atterrissent donc dans le chemin du conteneur, pas là où on les cherche.³ Si on surveille les logs et qu’ils ne bougent pas, on regarde probablement au mauvais endroit.

Le motif de vidage par lots s’applique partout où un producteur haute fréquence alimente un consommateur d’interface. La règle : ne jamais laisser le travail d’arrière-plan dicter la cadence de l’interface. 250 ms, c’est imperceptible pour un humain et ça suffit au thread principal pour absorber les interactions. Les compteurs de progression avancent par paliers au lieu de défiler en continu, mais personne ne s’en aperçoit.

Sans le log de battement de cœur, j’aurais optimisé le rendu de la barre latérale. J’avais déjà commencé à examiner les performances de List, les structures de données, le chargement paresseux. Des théories, j’en avais : toutes fausses. Le rendu était irréprochable ; le problème, c’est qu’il se déclenchait des milliers de fois par seconde.

Pourquoi construire un logger de battement de cœur artisanal quand Instruments existe ? J’ai utilisé Instruments (Time Profiler, Allocations, le modèle de détection de blocages). Ils ont confirmé ce que les logs montraient déjà. Mais l’approche PerfLogWriter + battement de cœur avait un avantage décisif en pratique : elle tournait en permanence. Ni processus Instruments en lice pour le CPU, ni analyse de trace a posteriori : juste un grep dans un fichier de log. Pour la boucle quotidienne (lancer, reproduire, vérifier le log), cette immédiateté valait davantage que les visualisations plus riches d’Instruments. Le compromis : le timer de 500 ms du battement de cœur concurrence lui-même l’ordonnancement du thread principal. Plus léger qu’Instruments, pas gratuit.

PerfLogWriter a démarré comme un bricolage : un logger fichier et un timer. Il a grandi. L’optimisation de la barre latérale qui a suivi (rendu en liste plate, un seul appel à filterTree(), 67 % de réduction CPU par frappe) découlait directement ce que le battement de cœur avait mis au jour. Au fil du temps, des lignes de base systématiques ont remplacé l’inspection ad hoc des logs : chaque release candidate passait un profilage sur un scan de référence, et les régressions se voyaient en chiffres, pas à l’intuition.

Instruments est venu après, pour les problèmes que la granularité de 500 ms ne pouvait pas capturer : profilage par arbre d’appels pour les points chauds, corrélation système pour l’ordonnancement des threads. Avec le recul, j’aurais dû y recourir plus tôt, surtout pour les problèmes d’ordonnancement les plus subtils. Les deux approches se complètent : le battement de cœur pour la surveillance continue à faible coût, Instruments pour les plongées chirurgicales. J’ai choisi la plus simple d’abord, et elle a suffi pour la première salve de corrections.

Références

• Analyze hangs with Instruments: WWDC 2023
• Track down hangs with Xcode and on-device detection: WWDC 2022
• Instruments: Apple Developer Documentation
• Event loop: Wikipedia