Refonte complète du pipeline

Depuis que j’ai commencé à utiliser Darktable, vers 2012, j’ai toujours été surpris par la très faible quantité de RAM qu’il utilisait. Les gens pensent qu’il est bon qu’une application utilise la mémoire avec parcimonie, et c’est certainement vrai lorsqu’on parle de votre environnement de bureau. Mais pour un logiciel de production qui fait du rendu pixel lourd sur des images de 12 à 54 mégapixels, cela signifie que les mêmes calculs coûteux sont refaits encore et encore au lieu d’être enregistrés pour être réutilisés plus tard. C’est précisément à cela que sert un cache : éviter des calculs coûteux. Et il devrait utiliser toute la RAM disponible pour cela, parce que calculer gaspille de l’énergie, ce qui a un impact concret si vous travaillez sur batterie. En plus, vous avez payé cette RAM et l’utiliser ne vide pas votre batterie. Le CPU et le GPU, eux…

Oui, les photo-reporters et de nombreux nomades numériques retouchent sur des ordinateurs portables sur batterie, sur le terrain. Il est temps que le monde open source réalise que tous les photographes ne sont pas assis à leur bureau le soir et le week-end, après leur « vrai » travail de journée. Donc calculer et recalculer les mêmes choses sans arrêt revient simplement à gaspiller de l’énergie, que vous soyez branché au secteur ou sur batterie.

Entre-temps, Darktable a toujours eu ce petit réglage étrange de RAM qui vous permettait de définir combien vous vouliez qu’il en utilise. Sauf qu’il n’avait absolument aucun moyen de suivre combien de RAM il utilisait réellement, donc c’était davantage une indication qu’une règle. Cela a ensuite été remplacé par une préférence qualitative « ressources » complètement idiote, qui ne veut rien dire et qui ne vous indique toujours pas la quantité de RAM que vous allouez au logiciel.

Le cache RAM de Darktable n’a donc jamais vraiment fonctionné, il était sous-utilisé et il fallait le réparer. Parce qu’en conséquence, tout était recalculé en permanence sans raison.

Mais… il y avait une raison pour laquelle le cache était sous-utilisé et ne fonctionnait pas vraiment : ce logiciel n’avait aucune visibilité sur le cycle de vie des données, ce qui est quand même un prérequis si vous voulez stocker des données pour les réutiliser. Cela venait d’un pipeline pixel vraiment alambiqué, je me demande sincèrement si quelqu’un parmi les « développeurs » de Darktable est capable de dessiner l’organigramme complet de ce que nous faisons subir aux pixels du début à la fin, mais aussi de métadonnées d’image calculées à plusieurs endroits, copiées et stockées à plusieurs endroits, puis partiellement mises à jour à plusieurs endroits…

Le cache du pipeline n’avait qu’un seul but : allouer les tampons d’entrée et de sortie des modules, et éventuellement les réutiliser s’ils étaient déjà disponibles. Mais sa taille était définie en nombre d’entrées, ce qui était très limité, et non en quantité de mémoire allouée. Cela le rendait à peine utile et nous obligeait à l’utiliser de façon beaucoup trop conservatrice, parce que sa taille mémoire réelle était totalement imprévisible.

Inutile de dire que « réparer le cache » impliquait « réparer le pipeline », ce qui impliquait à son tour de « rendre le cycle de vie des données visible, traçable et géré globalement », ce qui impliquait de repenser l’architecture de haut niveau du logiciel. Comme nous allons le voir, cela a eu des bénéfices inattendus sur les performances, qui dépassent largement les optimisations internes module par module que Darktable a faites dans le même temps.

Ce qui a changé depuis 2022

Cet article est la suite directe de Réparer le cache du pipeline et des bugs vieux de 10 ans. Le chapitre précédent consistait à trouver la pourriture et à arrêter les pannes les plus embarrassantes. Celui-ci raconte ce qui s’est passé ensuite, lorsqu’il est devenu évident que les bugs du cache n’étaient pas du tout des bugs isolés, mais les symptômes d’un moteur de rendu dont les responsabilités avaient été mélangées bien trop longtemps.

Où cela s’inscrit historiquement

Le problème d’origine n’était pas simplement que « le cache ne met pas assez en cache ». Le vrai problème, c’est que toute la pile du pipeline avait grossi autour de comportements accidentels. Des redessins de l’interface pouvaient finir par déclencher du traitement d’image, de manière non régulée. L’aperçu des masques faisait fuiter l’état de l’interface dans le moteur de rendu. La logique des histogrammes et de la pipette dépendait d’effets de bord particuliers du pipeline. Export, vignettes, aperçu et chambre noire avaient chacun leurs petites variantes de « on peut sûrement recopier ce tampon encore une fois ». Et chaque fois que la cohérence devenait difficile à prouver, lors de l’affichage des masques ou des changements de recadrage, la stratégie de repli consistait souvent à vider les lignes de cache et à tout recalculer, parce qu’apparemment « tout incendier et recommencer » a compté un temps comme de l’architecture.

Certains commentaires du code disaient déjà exactement cela. Il y avait des avertissements à propos des recomputations déclenchées par les redessins. Il y avait même une vieille note indiquant que le cache devrait devenir global un jour. Donc ces dernières années n’ont pas consisté à inventer une nouvelle théorie à partir de rien. Elles ont surtout consisté à enfin faire le nettoyage que le code réclamait depuis les années 2010.

Le basculement historique essentiel, c’est que le pipeline a cessé d’être traité comme un gros blob récursif censé découvrir ses propres besoins pendant qu’il s’exécute. Il a été progressivement scindé en chemins d’exécution plus clairs pour le rendu interactif, le rendu headless, le traitement GPU, le traitement CPU et les consommateurs côté interface. En même temps, le comportement d’interface a été renvoyé vers l’interface. Le dessin est redevenu du dessin. Le traitement est redevenu du traitement. Cela paraît banal, ce qui est généralement le signe que la conception précédente était devenue absurde.

Sommes de contrôle, ou comment la validité a cessé d’être un jeu de devinettes

Une fois que le moteur de rendu n’a plus été empêtré avec chaque widget et chaque canal parallèle, il est devenu possible de définir explicitement l’état de l’image. Chaque entrée d’historique porte désormais une somme de contrôle de module construite à partir des paramètres du module, des paramètres de fusion et de toute forme de masque pertinente. Cela donne à chaque état de module une empreinte canonique dès son entrée dans l’historique, au lieu de laisser sa validité être déduite plus tard à partir de ce qui a bien voulu s’exécuter.

Cela seul ne suffisait pas, parce qu’un pipeline n’est pas juste un tas de réglages de modules. Il dépend aussi de l’ordre, de la région d’intérêt, des contrats de tampons et de l’état lié à l’affichage. La phase de planification accumule donc ces empreintes au niveau des modules tout au long de la chaîne et y intègre le reste du contrat d’exécution avant qu’aucun pixel ne bouge. Le résultat est une identité stable par étape et une identité finale du pipeline.

C’est là que la visibilité apparaît enfin. Le pipeline peut savoir s’il est encore valide en comparant le hash de son historique. Le backbuffer affiché peut savoir s’il correspond toujours à l’état courant du pipeline et de l’historique. Une ligne de cache peut savoir si elle appartient réellement à l’étape exacte, à la région d’intérêt et aux paramètres actuellement demandés. Cela semble presque offensivement raisonnable, mais cela a d’abord demandé beaucoup de nettoyage : la synchronisation entre historique et pipeline a dû être rendue explicite, le contournement du cache a dû être déclaré à l’avance, pour l’aperçu des masques et les modifications de recadrage, l’affichage des masques ne pouvait plus muter les règles en plein milieu de l’exécution, et les vieux effets de bord déclenchés par les redessins ont dû disparaître. On n’obtient pas des hashes fiables sur un flux de contrôle qui ne l’est pas.

L’avantage pratique, c’est que la cohérence n’est plus maintenue par superstition. Nous n’avons plus besoin de nous demander « l’interface a-t-elle probablement invalidé la bonne chose au bon moment ? ». La réponse est dans les sommes de contrôle. Soit l’état correspond, soit non. Et nous pouvons récupérer n’importe quelle sortie de module depuis la couche interface sans exécuter de pipeline, parce que la somme de contrôle du module est prévisible et peut être calculée avant le rendu, ou en parallèle.

L’architecture cache-first

Des hashes fiables changent l’architecture presque par la force. Une fois que chaque état significatif du pipeline possède une identité stable connue à l’avance, le cache cesse d’être une optimisation au mieux opportuniste et devient le centre du flux de données.

C’est pourquoi le pipeline possède maintenant une vraie phase de planification avant l’exécution. L’historique est d’abord synchronisé. Les régions d’intérêt sont propagées à travers toute la chaîne. Chaque étape reçoit un contrat d’entrée et de sortie explicite. La politique de cache côté hôte est figée avant l’exécution. Les hashes globaux sont calculés avant le lancement. Autrement dit, le moteur sait ce qu’il s’apprête à faire avant de commencer à le faire, ce qui tranche agréablement avec l’ancienne méthode consistant à le découvrir en plein vol puis à compenser avec des rustines.

À partir de là, les recherches dans le cache deviennent déterministes. Une étape peut rouvrir exactement le tampon qui correspond à son état, de sorte qu’un module peut contourner complètement le calcul en regardant simplement dans le cache si une ligne correspond déjà à son état interne via une recherche par somme de contrôle. Les consommateurs en aval peuvent rouvrir des résultats publiés par hash au lieu de demander au moteur de rendu d’exécuter une nouvelle danse spéciale juste pour eux. Le cache cesse d’être un amas de mémoire vaguement réutilisable et devient le registre faisant autorité des résultats intermédiaires et finaux valides.

Cela explique aussi pourquoi autant de code a pu être supprimé ou simplifié. Une fois la validité centralisée, il faut moins d’heuristiques, moins de branches spéciales, moins de clauses « sauf lorsque l’interface est dans ce mode », et moins de purges d’urgence. Le code se raccourcit non pas parce que le problème a rétréci, mais parce qu’il a cessé d’être résolu à la fois dans six endroits contradictoires.

Les lignes de cache lient aussi la mémoire GPU et CPU, ce qui nous permet d’utiliser la mémoire épinglée d’OpenCL. Il existait depuis toujours une préférence utilisateur OpenCL permettant d’activer ou non cette mémoire épinglée, mais j’ai découvert qu’elle n’était utilisée que pour le traitement par tuiles, lorsque les modules ne pouvaient pas faire tenir tous leurs besoins mémoire sur le GPU. La mémoire épinglée a maintenant été étendue aux opérations normales, puisqu’elle permet de mapper RAM et VRAM sans copie. L’utilisation de mémoire épinglée sur un pipeline GPU entièrement mis en cache réduit jusqu’à un facteur 7 le temps passé à déplacer des tampons mémoire.

Mais forcer la mise en cache des sorties de modules OpenCL, même avec des tampons épinglés sans copie, a quand même un coût, et ce coût est plus élevé que de sauter complètement le cache. Pour certains modules lourds, comme denoise profiled, diffuse or sharpen ou contrast equalizer, le surcoût du cache vaut clairement la peine, mais pour les modules rapides, balance des blancs, exposition, profil de couleur d’entrée, le coût de mise en cache des tampons OpenCL rend en pratique ces modules plus lents sur GPU que sur CPU.

Nous avons donc désormais des heuristiques par module qui décident si un module OpenCL publiera ou non son tampon de sortie dans le cache RAM. Les modules lourds et tous ceux qui alimentent la pipette ou les histogrammes sont publiés par défaut. Pour les autres, les utilisateurs peuvent décider eux-mêmes :

Cela permettra aussi aux utilisateurs de désactiver OpenCL de manière sélective sur certains modules lorsqu’ils rencontrent des problèmes récurrents avec eux. Par exemple, denoise profiled et dehaze consomment beaucoup de mémoire GPU et peuvent échouer à l’exécution faute de mémoire disponible, même si la planification initiale estimait qu’il devrait y en avoir assez. Quand cela se produit, le module a déjà commencé à calculer depuis un moment et repasse ensuite sur CPU. Si cela arrive souvent, autant contourner le GPU pour ce module en permanence plutôt que de payer deux fois la pénalité.

Mais cela ne s’arrête pas là. Les tampons GPU restent aussi vivants sur le GPU. Cela signifie que le redémarrage d’un pipeline partiel depuis un module OpenCL récupère directement son entrée sur le GPU lorsque c’est possible, sans aucune copie depuis la RAM. Cela signifie aussi que les modules légers peuvent réutiliser leur précédent tampon GPU s’il convient, au lieu d’en allouer un nouveau. Rien que cela ouvre la possibilité d’avoir un pipeline temps réel, nécessaire au nouveau module Dessin, avec environ 60 à 80 ms de latence entre les coups de pinceau et la mise à jour de l’image. Je n’aurais jamais cru cela possible un jour.

La même réallocation mémoire se fait en RAM puisque Ansel héberge désormais tout le cache dans sa propre arène mémoire . Ce schéma nous permet non seulement de pré-réserver auprès du système d’exploitation un bloc mémoire contigu au lancement de l’application, ce qui accélère les allocations, mais il garantit aussi que nous ne dépassons pas le volume mémoire défini par l’utilisateur. Ainsi, lorsque vous décidez d’allouer 8 Go de RAM à Ansel, nous sommes maintenant capables de garantir que cela se produira réellement : nous remplirons tout ce volume jusqu’à saturation, après quoi nous commencerons à recycler les tampons les plus anciens. Tous les tampons de pixels, les entrées et sorties des modules, mais aussi les zones de travail temporaires internes, sont alloués dans notre arène mémoire.

Et, enfin, il n’y a plus qu’un seul cache de pipeline pour toute l’application, ce qui signifie que tous les types de pipelines, aperçu de chambre noire, image principale de chambre noire, export de vignettes et export de fichiers, partagent le même cache. Bien que cela ait demandé une gestion correcte des accès concurrents multithread, cela veut dire que si un pipeline a besoin de la sortie d’un module déjà calculée à la même taille par un autre pipeline, il peut directement récupérer la ligne de cache et éviter son propre recalcul.

Pour tirer parti de cela, l’« aperçu » de chambre noire, auparavant de taille fixe, c’est-à-dire la version réduite de l’image complète utilisée dans le widget de navigation, pour échantillonner les histogrammes et la pipette, et comme remplissage transitoire « flou » lorsque l’image principale est en cours de recomputation, a été modifié pour adopter dynamiquement la taille correspondant au niveau de zoom « ajuster » de l’image principale, celle affichée au centre de la chambre noire. Le résultat, c’est qu’une seule image doit être calculée à l’entrée dans la chambre noire, et revenir au zoom « ajuster » devient instantané.

Mais comme cet aperçu à taille fixe avait été paresseusement utilisé à de nombreux endroits de l’interface pour remapper les coordonnées du curseur dans l’espace des widgets vers les coordonnées pleine résolution de l’image RAW, au moyen du même bloc de code hideux copié-collé partout, allant jusqu’à recopier le commentaire disant « je ne comprends pas ce que cela fait », tout le système de coordonnées a dû être refait pour absorber ce changement. Et, encore une fois, ces coordonnées n’étaient calculées qu’à l’intérieur d’un pipeline, donc l’interface devait attendre que le pipeline recalcule les nouvelles tailles pour savoir où positionner les objets, ce qui déclenchait des glitches d’interface, en particulier lors d’un changement de recadrage. Maintenant, tout cela est calculé à l’avance depuis une API unifiée, donc plus de copier-coller idiot multiplié par le nombre de modules.

Ce que cela a changé hors du cœur du moteur

La première conséquence externe, c’est que les copies ont cessé de se faire passer pour des fonctionnalités. La chambre noire n’a plus besoin d’un backbuffer d’interface dédié pour afficher ce que le moteur de rendu a déjà produit. Elle peut récupérer l’image publiée directement depuis le cache, y associer une surface Cairo et l’afficher en quelques millisecondes. Auparavant, ce chemin était plus lent et saturé de copies sans autre raison qu’une confusion de conception héritée. La chambre noire peut aussi vérifier directement si un backbuffer donné du pipeline est à jour par rapport à l’historique de développement courant, au moyen des sommes de contrôle. Avant, cela reposait sur un indicateur « dirty » qui pouvait être écrasé par plusieurs threads et empêchait tout redessin « au mieux », c’est-à-dire afficher le dernier backbuffer valide connu en attendant la recomputation de la version à jour. C’était important quand l’utilisateur modifiait les paramètres de modules plus vite que le pipeline ne pouvait recalculer : il nous faut toujours quelque chose pour remplir la vue et éviter le scintillement.

La même logique s’étend maintenant à l’export et aux vignettes, qui peuvent rouvrir le résultat final publié au lieu de reconstruire leur propre réalité privée. Le code des histogrammes et de la pipette a lui aussi cessé de se greffer sur l’exécution du pipeline. Les scopes suivent des signaux explicites d’achèvement provenant du chemin d’aperçu, mettent en cache leur propre surface Cairo par rapport à l’état source et échantillonnent directement depuis les backbuffers alimentés par le cache. Un histogramme RAW, échantillonné après le module demosaic, a été ajouté à l’ancienne sortie du pipeline : passer de l’un à l’autre ne nécessite pas de recomputation du pipeline, pas plus que l’utilisation de la pipette sur l’un ou l’autre. C’est une conception beaucoup plus ennuyeuse, et c’est exactement pour cela qu’elle est meilleure.

Une autre conséquence majeure, c’est que les différentes variantes du pipeline ne vivent plus dans des silos de cache isolés. L’aperçu, la chambre noire, l’export, les vignettes et les consommateurs d’histogrammes peuvent désormais partager le même état de cache. C’était l’intention déjà suggérée il y a longtemps dans le code du cache ; il a simplement fallu un nettoyage complet du suivi de validité pour le rendre réel. Une fois que tous ces consommateurs s’accordent sur les mêmes hashes, ils peuvent enfin s’accorder sur les mêmes tampons. L’avantage, c’est qu’un pipeline peut réutiliser une ligne de cache déjà calculée par un autre pipeline si elle convient, mêmes paramètres, mêmes tailles d’entrée et de sortie. Le début des pipelines de chambre noire a donc été basculé en pleine résolution : le dématriçage et le débruitage seront plus lents à l’entrée dans la chambre noire, mais ensuite le zoom et le panoramique deviennent instantanés. Et l’export d’une image récupérera lui aussi directement ces premières étapes depuis le cache. Au passage, exporter la même image deux fois à deux résolutions différentes ne recalculera qu’à partir du module de mise à l’échelle, à la fin du pipeline.

La gestion de la mémoire a suivi la même logique. Les lignes de cache sont devenues des objets réutilisables, verrouillables et munis d’un comptage de références, au lieu d’être des blobs jetables transportés dans des stockages annexes bricolés. Les chemins CPU et GPU partagent maintenant beaucoup plus le même modèle de propriété. Côté OpenCL, les tampons hôte et périphérique sont gérés avec des règles de durée de vie explicites, la mémoire épinglée est réutilisée au lieu d’être constamment recréée, et la RAM comme la VRAM restent synchronisées par des transferts épinglés et sans copie lorsque c’est possible, au lieu d’être dupliquées via des copies intermédiaires inutiles. Cela ne rend pas le GPU magiquement meilleur en calcul. Cela empêche surtout toute la tuyauterie autour de lui de gaspiller les gains.

Le bénéfice ne se limite pas à la vitesse dans les benchmarks. Il touche aussi la latence, la robustesse et la consommation d’énergie. Le démarrage de la chambre noire se raccourcit parce qu’il y a moins de copies et moins de passes dupliquées. Le zoom, le panoramique, l’aperçu des masques et la navigation dans l’historique cessent d’invalider la moitié de l’univers simplement parce qu’il était autrefois trop difficile de prouver la correction. OpenCL devient moins aléatoire parce que les replis, le tuilage et la propriété mémoire sont exprimés plus explicitement. Le logiciel passe moins de temps à déplacer des pixels juste pour se rassurer sur le fait qu’ils existent encore quelque part.

Comme effet de bord positif, la gestion des erreurs a été améliorée dans le pipeline. Les modules qui échouent à allouer de la mémoire déclenchent désormais immédiatement une erreur et interrompent le pipeline. Auparavant, les échecs d’allocation n’étaient pas vérifiés partout, et tout un pipeline pouvait transporter un tampon NULL jusqu’au bout… ou s’écraser franchement sur une erreur de type segmentation fault. Cela est maintenant empêché en amont de manière uniforme dans tout le logiciel.

L’échantillonnage de la pipette et des histogrammes peut maintenant lire les données sans déclencher de recomputation du pipeline en récupérant directement le cache, si la ligne de cache demandée existe. Le panneau global des scopes vous permet de choisir entre le RGB RAW, échantillonné après demosaicing, et le RGB final du pipeline, soit échantillonné après output color profile en flottant 32 bits, soit dans le backbuffer en entiers 8 bits : passer de l’un à l’autre ne redémarre pas un pipeline, cela charge simplement une autre ligne de cache, et la pipette s’applique sur cette ligne de cache de manière transparente.

Ce qui a réellement été corrigé en le faisant correctement

Beaucoup d’ennuis visibles découlent davantage de cette refonte que d’une quelconque micro-optimisation isolée. La gestion des régions d’intérêt en haute résolution s’est améliorée parce que la propriété de la géométrie est devenue plus claire et que la correspondance des coordonnées entre l’interface et l’image RAW est maintenant gérée dans une API centrale. La resynchronisation entre historique et pipeline est devenue moins fragile parce que l’historique a cessé d’être un effet de bord accessoire du flux d’interface pour devenir une entrée de premier ordre de la planification. L’aperçu de masque en temps réel n’a plus besoin de lutter contre un modèle de cache conçu pour une autre époque. Le rafraîchissement de l’histogramme est devenu prévisible parce qu’il consomme maintenant des données publiées, au lieu d’espérer que le bon tampon intermédiaire soit encore vivant quelque part. Les boucles infinies, les lignes de cache périmées, les backbuffers invalides et le classique « l’aperçu a recalculé tout le pipeline depuis le module 0 sans raison évidente » deviennent tous plus faciles à diagnostiquer une fois que le cycle de vie est explicite.

La partie intéressante ici n’est donc pas qu’une grosse refactorisation se soit produite isolément. C’est qu’une longue série de nettoyages s’est finalement alignée autour d’une idée : la validité doit être calculée, nommée et partagée à l’avance. Une fois cela en place, le reste a suivi presque mécaniquement. Le cache est devenu central parce que les hashes étaient dignes de confiance. Les consommateurs externes ont pu cesser de copier parce que les tampons publiés par le cache sont devenus faisant autorité. Les chemins CPU et GPU ont pu partager davantage d’état parce que la propriété est devenue explicite. Et le moteur de rendu a cessé de se comporter comme une maison hantée où bouger un curseur pouvait réveiller trois sous-systèmes sans rapport et un callback de redessin datant de 2013.

Benchmarks

Benchmarks are done on both applications compiled locally with Release build and GCC14 using their respective build.sh --build-type Release script.

Config 1

The hardware is a Thinkpad P51, with 8 × Intel Xeon CPU E3-1505M v6 @ 3.00GHz and GPU Nvidia Quadro M2200, running on Fedora 41 Plasma with Wayland. Nvidia driver version is 580.105.08. The Intel Xeon is an high-end CPU released in 2015. The Quadro M2200 is a mid-range professionnal CPU released in 2017.

Config 2

The hardware is a desktop PC with 4 × Intel Core i3-4130 and GPU AMD Radeon RX 580 Polaris 10, running on Ubuntu 24.04 LTS with Wayland. AMD driver version is RustiCL 25.2.8. The Core i3 is a mid-range CPU released in 2013. The AMD Polaris 10 is a mid-high-range GPU released in 2017.

We show here the output of ansel -d perf and darktable -d perf. Both Ansel and Darktable config files are set with this script  to ensure the same config baseline. The 45 Mpx test picture is taken from here  and the editing XMP can be downloaded here.

Chargement initial dans la chambre noire

Attention : dans Ansel, il est important d’exécuter ce test sans qu’aucun module ne soit focalisé dans l’interface, c’est-à-dire sans module déplié. Dans cette situation, Ansel met toujours en cache la sortie du module précédent, ce qui garantit que lorsque des modifications sont effectuées dans ce module focalisé, les calculs redémarrent toujours depuis son entrée immédiate. Mais forcer ainsi le cache déclenche un surcoût mémoire qui peut être visible sur les modules légers.

Config 1

• Ansel Master GPU
• Darktable 5.4.1 GPU
• Ansel Master CPU
• Darktable 5.4.1 CPU

 13.690316 [dev_pixelpipe] took 0.000 secs (0.000 CPU) to load the image.
 24.201079 [dev_pixelpipe] pipeline resync with history took 0.029 secs (0.026 CPU) for pipe virtual-preview
 34.260916 [dev_pixelpipe] pipeline resync with history took 0.000 secs (0.000 CPU) for pipe virtual-preview
 44.260963 [dev_pixelpipe] pipeline resync with history took 0.000 secs (0.000 CPU) for pipe virtual-preview
 54.327523 [dev_pixelpipe] pipeline resync with history took 0.019 secs (0.025 CPU) for pipe preview
 64.384013 [dev_pixelpipe] took 0.056 secs (0.072 CPU) initing base buffer [preview]
 74.402520 [dev_pixelpipe] took 0.018 secs (0.031 CPU) processed `Raw settings' on GPU, blended on  [preview]
 84.421489 [dev_pixelpipe] took 0.016 secs (0.012 CPU) processed `white balance' on GPU, blended on  [preview]
 96.912680 [dev_pixelpipe] took 2.491 secs (2.470 CPU) processed `highlight reconstruction' on GPU, blended on GPU [preview]
107.167233 [dev_pixelpipe] took 0.254 secs (0.144 CPU) processed `demosaic' on GPU, blended on  [preview]
117.470521 [dev_pixelpipe] took 0.303 secs (0.173 CPU) processed `lens correction' on GPU, blended on  [preview]
127.629764 [dev_pixelpipe] took 0.159 secs (0.172 CPU) processed `Initial resampling' on GPU, blended on  [preview]
137.635593 [dev_pixelpipe] took 0.006 secs (0.006 CPU) processed `exposure' on GPU, blended on GPU [preview]
147.638110 [dev_pixelpipe] took 0.002 secs (0.001 CPU) processed `input color profile' on GPU, blended on  [preview]
157.639667 [dev_pixelpipe] took 0.002 secs (0.002 CPU) processed `color calibration' on GPU, blended on GPU [preview]
168.726634 [dev_pixelpipe] took 1.087 secs (1.090 CPU) processed `diffuse or sharpen' on GPU, blended on GPU [preview]
178.735900 [dev_pixelpipe] took 0.009 secs (0.009 CPU) processed `color balance rgb' on GPU, blended on GPU [preview]
188.742309 [dev_pixelpipe] took 0.006 secs (0.007 CPU) processed `filmic rgb' on GPU, blended on GPU [preview]
198.765175 [dev_pixelpipe] took 0.023 secs (0.029 CPU) processed `output color profile' on GPU, blended on  [preview]
208.808546 [dev_pixelpipe] took 0.043 secs (0.049 CPU) processed `dithering' on CPU, blended on  [preview]
218.820376 [dev_pixelpipe] took 0.012 secs (0.061 CPU) processed `display encoding' on CPU, blended on  [preview]
228.820439 [pixelpipe] preview internal pixel pipeline processing took 4.493 secs (4.332 CPU)
238.820483 [dev_process_preview] pipeline processing thread took 4.493 secs (4.333 CPU)
248.858716 [dev_pixelpipe] pipeline resync with history took 0.026 secs (0.032 CPU) for pipe full
258.858805 [dev_process_full] pipeline processing thread took 0.000 secs (0.000 CPU)

 110,5815 [dt_dev_process_image_job] loading image. took 0,000 secs (0,000 CPU)
 210,6799 [dev_pixelpipe] took 0,018 secs (0,029 CPU) initing base buffer [full]
 310,6968 [dev_pixelpipe] took 0,017 secs (0,020 CPU) [full] processed `rawprepare' on GPU, blended on GPU
 410,7094 [dev_pixelpipe] took 0,013 secs (0,011 CPU) [full] processed `temperature' on GPU, blended on GPU
 514,4091 [dev_pixelpipe] took 3,700 secs (3,719 CPU) [full] processed `highlights' on GPU with tiling, blended on CPU
 614,8078 [resample_cl] plan 0,000 secs (0,000 CPU) resample 0,010 secs (0,002 CPU)
 714,8988 [dev_pixelpipe] took 0,490 secs (0,349 CPU) [full] processed `demosaic' on GPU, blended on GPU
 814,9094 [dev_pixelpipe] took 0,010 secs (0,001 CPU) [full] processed `lens' on GPU, blended on GPU
 914,9200 [dev_pixelpipe] took 0,010 secs (0,002 CPU) [full] processed `exposure' on GPU, blended on GPU
1014,9516 [dev_pixelpipe] took 0,032 secs (0,010 CPU) [full] processed `colorin' on GPU, blended on GPU
1114,9654 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_LAB-->IOP_CS_RGB took 0,013 secs (0,000 GPU) [channelmixerrgb]
1214,9902 [dev_pixelpipe] took 0,039 secs (0,006 CPU) [full] processed `channelmixerrgb' on GPU, blended on GPU
1316,6800 [dev_pixelpipe] took 1,690 secs (1,745 CPU) [full] processed `diffuse' on GPU, blended on GPU
1416,6923 [dev_pixelpipe] took 0,012 secs (0,007 CPU) [full] processed `colorbalancergb' on GPU, blended on GPU
1516,7037 [dev_pixelpipe] took 0,011 secs (0,005 CPU) [full] processed `filmicrgb' on GPU, blended on GPU
1616,7100 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_RGB-->IOP_CS_LAB took 0,006 secs (0,000 GPU) [colorout]
1716,7555 [dev_pixelpipe] took 0,052 secs (0,020 CPU) [full] processed `colorout' on GPU, blended on GPU
1816,8435 [dev_pixelpipe] took 0,088 secs (0,052 CPU) [full] processed `dither' on CPU, blended on CPU
1916,8525 [dev_pixelpipe] took 0,009 secs (0,066 CPU) [full] processed `gamma' on CPU, blended on CPU
2016,8594 [dev_process_image] pixel pipeline took 6,197 secs (6,048 CPU) processing `2022-06-17__DSC00078.arw'
21
2216,8918 [dt_dev_process_image_job] loading image. took 0,000 secs (0,000 CPU)
2316,9470 [dt_dev_process_image_job] loading image. took 0,000 secs (0,000 CPU)
2416,9968 [dev_pixelpipe] took 0,000 secs (0,000 CPU) initing base buffer [preview]
2516,9986 [dev_pixelpipe] took 0,002 secs (0,002 CPU) [preview] processed `rawprepare' on GPU, blended on GPU
2616,9995 [dev_pixelpipe] took 0,001 secs (0,001 CPU) [preview] processed `temperature' on GPU, blended on GPU
2717,0698 [dev_pixelpipe] took 0,070 secs (0,081 CPU) [preview] processed `highlights' on GPU, blended on GPU
2817,0811 [dev_pixelpipe] took 0,011 secs (0,005 CPU) [preview] processed `demosaic' on GPU, blended on GPU
2917,0829 [dev_pixelpipe] took 0,002 secs (0,000 CPU) [preview] processed `lens' on GPU, blended on GPU
3017,0853 [dev_pixelpipe] took 0,002 secs (0,001 CPU) [preview] processed `exposure' on GPU, blended on GPU
3117,0886 [dev_pixelpipe] took 0,003 secs (0,001 CPU) [preview] processed `colorin' on GPU, blended on GPU
3217,0915 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_LAB-->IOP_CS_RGB took 0,003 secs (0,000 GPU) [channelmixerrgb]
3317,0952 [dev_pixelpipe] took 0,007 secs (0,002 CPU) [preview] processed `channelmixerrgb' on GPU, blended on GPU
3417,4667 [dev_pixelpipe] took 0,371 secs (0,354 CPU) [preview] processed `diffuse' on GPU, blended on GPU
3517,4702 [dev_pixelpipe] took 0,003 secs (0,001 CPU) [preview] processed `colorbalancergb' on GPU, blended on GPU
3617,4748 [dev_pixelpipe] took 0,004 secs (0,001 CPU) [preview] processed `filmicrgb' on GPU, blended on GPU
3717,4776 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_RGB-->IOP_CS_LAB took 0,002 secs (0,000 GPU) [colorout]
3817,4939 [dev_pixelpipe] took 0,019 secs (0,009 CPU) [preview] processed `colorout' on GPU, blended on GPU
3917,5141 [dev_pixelpipe] took 0,020 secs (0,007 CPU) [preview] processed `dither' on CPU, blended on CPU
4017,5195 [dev_pixelpipe] took 0,005 secs (0,021 CPU) [preview] processed `gamma' on CPU, blended on CPU
4117,5355 [dt_ioppr_transform_image_colorspace_rgb] `Système' -> `sRVB' took 0,016 secs (0,067 CPU) [final histogram]
4217,6218 [dev_process_image] pixel pipeline took 0,625 secs (0,657 CPU) processing `2022-06-17__DSC00078.arw'

 14.146713 [dev_pixelpipe] took 0.000 secs (0.000 CPU) to load the image.
 24.642451 [dev_pixelpipe] pipeline resync with history took 0.029 secs (0.026 CPU) for pipe virtual-preview
 34.703889 [dev_pixelpipe] pipeline resync with history took 0.000 secs (0.000 CPU) for pipe virtual-preview
 44.703915 [dev_pixelpipe] pipeline resync with history took 0.000 secs (0.000 CPU) for pipe virtual-preview
 54.782635 [dev_pixelpipe] pipeline resync with history took 0.033 secs (0.041 CPU) for pipe preview
 64.796521 [dev_pixelpipe] took 0.014 secs (0.018 CPU) initing base buffer [preview]
 74.831601 [dev_pixelpipe] took 0.035 secs (0.061 CPU) processed `Raw settings' on CPU, blended on  [preview]
 84.862626 [dev_pixelpipe] took 0.031 secs (0.077 CPU) processed `white balance' on CPU, blended on  [preview]
 910.978874 [dev_pixelpipe] took 6.116 secs (43.505 CPU) processed `highlight reconstruction' on CPU, blended on CPU [preview]
1011.369357 [dev_pixelpipe] took 0.390 secs (2.623 CPU) processed `demosaic' on CPU, blended on  [preview]
1111.449953 [dev_pixelpipe] took 0.081 secs (0.474 CPU) processed `lens correction' on CPU, blended on  [preview]
1211.797645 [dev_pixelpipe] took 0.348 secs (2.088 CPU) processed `Initial resampling' on CPU, blended on  [preview]
1311.802788 [dev_pixelpipe] took 0.005 secs (0.025 CPU) processed `exposure' on CPU, blended on CPU [preview]
1411.807751 [dev_pixelpipe] took 0.005 secs (0.024 CPU) processed `input color profile' on CPU, blended on  [preview]
1511.877682 [dev_pixelpipe] took 0.070 secs (0.361 CPU) processed `color calibration' on CPU, blended on CPU [preview]
1615.025427 [dev_pixelpipe] took 3.148 secs (23.610 CPU) processed `diffuse or sharpen' on CPU, blended on CPU [preview]
1715.290600 [dev_pixelpipe] took 0.262 secs (1.469 CPU) processed `color balance rgb' on CPU, blended on CPU [preview]
1815.425400 [dev_pixelpipe] took 0.135 secs (0.761 CPU) processed `filmic rgb' on CPU, blended on CPU [preview]
1915.438259 [dev_pixelpipe] took 0.013 secs (0.072 CPU) processed `output color profile' on CPU, blended on  [preview]
2015.463031 [dev_pixelpipe] took 0.025 secs (0.039 CPU) processed `dithering' on CPU, blended on  [preview]
2115.474803 [dev_pixelpipe] took 0.012 secs (0.058 CPU) processed `display encoding' on CPU, blended on  [preview]
2215.474885 [pixelpipe] preview internal pixel pipeline processing took 10.692 secs (75.269 CPU)
2315.474906 [dev_process_preview] pipeline processing thread took 10.692 secs (75.269 CPU)
2415.522324 [dev_pixelpipe] pipeline resync with history took 0.037 secs (0.047 CPU) for pipe full
2515.522431 [dev_process_full] pipeline processing thread took 0.000 secs (0.000 CPU)

 14,5577 [dt_dev_load_raw] loading the image. took 0,131 secs (0,040 CPU)
 25,4913 [dt_dev_process_image_job] loading image. took 0,000 secs (0,000 CPU)
 35,6087 [dev_pixelpipe] took 0,017 secs (0,029 CPU) initing base buffer [full]
 45,6491 [dev_pixelpipe] took 0,040 secs (0,120 CPU) [full] processed `rawprepare' on CPU, blended on CPU
 55,6782 [dev_pixelpipe] took 0,029 secs (0,061 CPU) [full] processed `temperature' on CPU, blended on CPU
 612,0060 [dev_pixelpipe] took 6,328 secs (45,005 CPU) [full] processed `highlights' on CPU, blended on CPU
 712,6762 [resample_plain] plan 0,001 secs (0,001 CPU) resample 0,249 secs (1,829 CPU)
 812,7230 [dev_pixelpipe] took 0,717 secs (4,499 CPU) [full] processed `demosaic' on CPU, blended on CPU
 912,7370 [dev_pixelpipe] took 0,013 secs (0,029 CPU) [full] processed `lens' on CPU, blended on CPU
1012,7487 [dev_pixelpipe] took 0,012 secs (0,029 CPU) [full] processed `exposure' on CPU, blended on CPU
1112,7637 [dev_pixelpipe] took 0,015 secs (0,045 CPU) [full] processed `colorin' on CPU, blended on CPU
1212,7693 [dt_ioppr_transform_image_colorspace] IOP_CS_LAB-->IOP_CS_RGB took 0,006 secs (0,028 CPU) [channelmixerrgb]
1312,8473 [dev_pixelpipe] took 0,084 secs (0,438 CPU) [full] processed `channelmixerrgb' on CPU, blended on CPU
1417,0570 [dev_pixelpipe] took 4,210 secs (32,406 CPU) [full] processed `diffuse' on CPU, blended on CPU
1517,3181 [dev_pixelpipe] took 0,261 secs (1,872 CPU) [full] processed `colorbalancergb' on CPU, blended on CPU
1617,4583 [dev_pixelpipe] took 0,140 secs (0,898 CPU) [full] processed `filmicrgb' on CPU, blended on CPU
1717,4634 [dt_ioppr_transform_image_colorspace] IOP_CS_RGB-->IOP_CS_LAB took 0,005 secs (0,033 CPU) [colorout]
1817,4792 [dev_pixelpipe] took 0,021 secs (0,116 CPU) [full] processed `colorout' on CPU, blended on CPU
1917,5381 [dev_pixelpipe] took 0,059 secs (0,037 CPU) [full] processed `dither' on CPU, blended on CPU
2017,5472 [dev_pixelpipe] took 0,009 secs (0,061 CPU) [full] processed `gamma' on CPU, blended on CPU
2117,5543 [dev_process_image] pixel pipeline took 11,962 secs (85,649 CPU) processing `2022-06-17__DSC00078.arw'
22
2317,5861 [dt_dev_process_image_job] loading image. took 0,000 secs (0,000 CPU)
2417,6428 [dt_dev_process_image_job] loading image. took 0,000 secs (0,000 CPU)
2517,6993 [dev_pixelpipe] took 0,000 secs (0,000 CPU) initing base buffer [preview]
2617,7004 [dev_pixelpipe] took 0,001 secs (0,002 CPU) [preview] processed `rawprepare' on CPU, blended on CPU
2717,7015 [dev_pixelpipe] took 0,001 secs (0,004 CPU) [preview] processed `temperature' on CPU, blended on CPU
2817,8101 [dev_pixelpipe] took 0,109 secs (0,570 CPU) [preview] processed `highlights' on CPU, blended on CPU
2917,8261 [dev_pixelpipe] took 0,016 secs (0,071 CPU) [preview] processed `demosaic' on CPU, blended on CPU
3017,8308 [dev_pixelpipe] took 0,005 secs (0,006 CPU) [preview] processed `lens' on CPU, blended on CPU
3117,8345 [dev_pixelpipe] took 0,004 secs (0,006 CPU) [preview] processed `exposure' on CPU, blended on CPU
3217,8393 [dev_pixelpipe] took 0,005 secs (0,016 CPU) [preview] processed `colorin' on CPU, blended on CPU
3317,8411 [dt_ioppr_transform_image_colorspace] IOP_CS_LAB-->IOP_CS_RGB took 0,002 secs (0,008 CPU) [channelmixerrgb]
3417,8670 [dev_pixelpipe] took 0,028 secs (0,144 CPU) [preview] processed `channelmixerrgb' on CPU, blended on CPU
3519,0763 [dev_pixelpipe] took 1,209 secs (8,091 CPU) [preview] processed `diffuse' on CPU, blended on CPU
3619,1926 [dev_pixelpipe] took 0,116 secs (0,708 CPU) [preview] processed `colorbalancergb' on CPU, blended on CPU
3719,2628 [dev_pixelpipe] took 0,070 secs (0,342 CPU) [preview] processed `filmicrgb' on CPU, blended on CPU
3819,2667 [dt_ioppr_transform_image_colorspace] IOP_CS_RGB-->IOP_CS_LAB took 0,003 secs (0,012 CPU) [colorout]
3919,2758 [dev_pixelpipe] took 0,012 secs (0,045 CPU) [preview] processed `colorout' on CPU, blended on CPU
4019,2860 [dev_pixelpipe] took 0,010 secs (0,003 CPU) [preview] processed `dither' on CPU, blended on CPU
4119,2907 [dev_pixelpipe] took 0,005 secs (0,020 CPU) [preview] processed `gamma' on CPU, blended on CPU
4219,3052 [dt_ioppr_transform_image_colorspace_rgb] `Système' -> `sRVB' took 0,014 secs (0,071 CPU) [final histogram]
4319,3928 [dev_process_image] pixel pipeline took 1,694 secs (10,211 CPU) processing `2022-06-17__DSC00078.arw'

Config 2

• Ansel Master GPU
• Darktable 5.4.1 GPU
• Ansel Master CPU
• Darktable 5.4.1 CPU

 136.764111 [dev_pixelpipe] took 0.313 secs (0.056 CPU) to load the image.
 237.528673 [dev_pixelpipe] pipeline resync with history took 0.044 secs (0.040 CPU) for pipe virtual-preview
 337.691646 [dev_pixelpipe] pipeline resync with history took 0.000 secs (0.000 CPU) for pipe virtual-preview
 437.691699 [dev_pixelpipe] pipeline resync with history took 0.000 secs (0.000 CPU) for pipe virtual-preview
 537.745145 [dev_pixelpipe] pipeline resync with history took 0.036 secs (0.043 CPU) for pipe preview
 637.916228 [dev_pixelpipe] took 0.171 secs (0.115 CPU) initing base buffer [preview]
 737.953157 [dev_pixelpipe] took 0.037 secs (0.024 CPU) processed `Raw settings' on GPU, blended on  [preview]
 837.959823 [dev_pixelpipe] took 0.007 secs (0.002 CPU) processed `white balance' on GPU, blended on  [preview]
 939.377680 [dev_pixelpipe] took 1.418 secs (0.196 CPU) processed `highlight reconstruction' on GPU, blended on GPU [preview]
1039.526422 [dev_pixelpipe] took 0.149 secs (0.039 CPU) processed `demosaic' on GPU, blended on  [preview]
1141.012847 [dev_pixelpipe] took 1.486 secs (0.271 CPU) processed `lens correction' on GPU, blended on  [preview]
1241.266624 [dev_pixelpipe] took 0.254 secs (0.110 CPU) processed `Initial resampling' on GPU, blended on  [preview]
1341.299983 [dev_pixelpipe] took 0.033 secs (0.025 CPU) processed `exposure' on GPU, blended on GPU [preview]
1441.311230 [dev_pixelpipe] took 0.011 secs (0.009 CPU) processed `input color profile' on GPU, blended on  [preview]
1541.313526 [dev_pixelpipe] took 0.002 secs (0.002 CPU) processed `color calibration' on GPU, blended on GPU [preview]
1641.471857 [dev_pixelpipe] took 0.158 secs (0.049 CPU) processed `diffuse or sharpen' on GPU, blended on GPU [preview]
1741.482377 [dev_pixelpipe] took 0.010 secs (0.008 CPU) processed `color balance rgb' on GPU, blended on GPU [preview]
1841.486457 [dev_pixelpipe] took 0.004 secs (0.007 CPU) processed `filmic rgb' on GPU, blended on GPU [preview]
1941.508325 [dev_pixelpipe] took 0.022 secs (0.018 CPU) processed `output color profile' on GPU, blended on  [preview]
2041.521171 [dev_pixelpipe] took 0.013 secs (0.016 CPU) processed `dithering' on CPU, blended on  [preview]
2141.529057 [dev_pixelpipe] took 0.008 secs (0.014 CPU) processed `display encoding' on CPU, blended on  [preview]
2241.529178 [pixelpipe] preview internal pixel pipeline processing took 3.784 secs (0.906 CPU)
2341.529291 [dev_process_preview] pipeline processing thread took 3.784 secs (0.906 CPU)
2441.576629 [dev_pixelpipe] pipeline resync with history took 0.036 secs (0.049 CPU) for pipe full
2541.579279 [dev_process_full] pipeline processing thread took 0.000 secs (0.000 CPU)

 123.6180 [dt_dev_load_raw] loading the image. took 0.290 secs (0.055 CPU)
 224.6549 [dt_dev_process_image_job] loading image. took 0.000 secs (0.000 CPU)
 324.7621 [dev_pixelpipe] took 0.023 secs (0.034 CPU) initing base buffer [full]
 424.8212 [dev_pixelpipe] took 0.059 secs (0.022 CPU) [full] processed `rawprepare' on GPU, blended on GPU
 524.8286 [dev_pixelpipe] took 0.007 secs (0.000 CPU) [full] processed `temperature' on GPU, blended on GPU
 626.6983 [dev_pixelpipe] took 1.870 secs (0.433 CPU) [full] processed `highlights' on GPU, blended on GPU
 726.7416 [resample_cl] plan 0.002 secs (0.001 CPU) resample 0.032 secs (0.000 CPU)
 826.8215 [dev_pixelpipe] took 0.123 secs (0.009 CPU) [full] processed `demosaic' on GPU, blended on GPU
 926.8260 [dev_pixelpipe] took 0.004 secs (0.001 CPU) [full] processed `lens' on GPU, blended on GPU
1026.8282 [dev_pixelpipe] took 0.002 secs (0.001 CPU) [full] processed `ashift' on GPU, blended on GPU
1126.8306 [dev_pixelpipe] took 0.002 secs (0.001 CPU) [full] processed `exposure' on GPU, blended on GPU
1226.8347 [dev_pixelpipe] took 0.004 secs (0.001 CPU) [full] processed `colorin' on GPU, blended on GPU
1326.8370 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_LAB-->IOP_CS_RGB took 0.002 secs (0.001 GPU) [channelmixerrgb]
1426.8384 [dev_pixelpipe] took 0.004 secs (0.001 CPU) [full] processed `channelmixerrgb' on GPU, blended on GPU
1527.3567 [dev_pixelpipe] took 0.518 secs (0.022 CPU) [full] processed `diffuse' on GPU, blended on GPU
1627.3613 [dev_pixelpipe] took 0.004 secs (0.001 CPU) [full] processed `colorbalancergb' on GPU, blended on GPU
1727.4019 [dev_pixelpipe] took 0.041 secs (0.011 CPU) [full] processed `filmicrgb' on GPU, blended on GPU
1827.4053 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_RGB-->IOP_CS_LAB took 0.003 secs (0.001 GPU) [colorout]
1927.4345 [dev_pixelpipe] took 0.032 secs (0.009 CPU) [full] processed `colorout' on GPU, blended on GPU
2027.4814 [dev_pixelpipe] took 0.047 secs (0.025 CPU) [full] processed `dither' on CPU, blended on CPU
2127.4962 [dev_pixelpipe] took 0.015 secs (0.045 CPU) [full] processed `gamma' on CPU, blended on CPU
2227.4990 [dev_process_image] pixel pipeline took 2.760 secs (0.618 CPU) processing `2022-06-17__DSC00078.arw'
23
2427.5249 [dt_dev_process_image_job] loading image. took 0.005 secs (0.013 CPU)
2527.5866 [dt_dev_process_image_job] loading image. took 0.000 secs (0.000 CPU)
2627.6513 [dev_pixelpipe] took 0.000 secs (0.000 CPU) initing base buffer [preview]
2727.6561 [dev_pixelpipe] took 0.005 secs (0.006 CPU) [preview] processed `rawprepare' on GPU, blended on GPU
2827.6580 [dev_pixelpipe] took 0.002 secs (0.001 CPU) [preview] processed `temperature' on GPU, blended on GPU
2927.7797 [dev_pixelpipe] took 0.122 secs (0.062 CPU) [preview] processed `highlights' on GPU, blended on GPU
3027.7845 [dev_pixelpipe] took 0.005 secs (0.002 CPU) [preview] processed `demosaic' on GPU, blended on GPU
3127.7854 [dev_pixelpipe] took 0.001 secs (0.000 CPU) [preview] processed `lens' on GPU, blended on GPU
3227.8023 [dev_pixelpipe] took 0.017 secs (0.002 CPU) [preview] processed `ashift' on GPU, blended on GPU
3327.8034 [dev_pixelpipe] took 0.001 secs (0.000 CPU) [preview] processed `exposure' on GPU, blended on GPU
3427.8058 [dev_pixelpipe] took 0.002 secs (0.000 CPU) [preview] processed `colorin' on GPU, blended on GPU
3527.8077 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_LAB-->IOP_CS_RGB took 0.001 secs (0.000 GPU) [channelmixerrgb]
3627.8089 [dev_pixelpipe] took 0.003 secs (0.000 CPU) [preview] processed `channelmixerrgb' on GPU, blended on GPU
3728.5157 [dev_pixelpipe] took 0.707 secs (0.076 CPU) [preview] processed `diffuse' on GPU, blended on GPU
3828.5240 [dev_pixelpipe] took 0.008 secs (0.004 CPU) [preview] processed `colorbalancergb' on GPU, blended on GPU
3928.6037 [dev_pixelpipe] took 0.079 secs (0.031 CPU) [preview] processed `filmicrgb' on GPU, blended on GPU
4028.6092 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_RGB-->IOP_CS_LAB took 0.005 secs (0.000 GPU) [colorout]
4128.6323 [dev_pixelpipe] took 0.028 secs (0.007 CPU) [preview] processed `colorout' on GPU, blended on GPU
4228.6675 [dev_pixelpipe] took 0.035 secs (0.010 CPU) [preview] processed `dither' on CPU, blended on CPU
4328.6881 [dev_pixelpipe] took 0.021 secs (0.066 CPU) [preview] processed `gamma' on CPU, blended on CPU
4428.8183 [dev_process_image] pixel pipeline took 1.167 secs (0.442 CPU) processing `2022-06-17__DSC00078.arw'

 113.969925 [dev_pixelpipe] took 0.271 secs (0.044 CPU) to load the image.
 214.519352 [dev_pixelpipe] pipeline resync with history took 0.039 secs (0.037 CPU) for pipe virtual-preview
 314.609258 [dev_pixelpipe] pipeline resync with history took 0.000 secs (0.000 CPU) for pipe virtual-preview
 414.609291 [dev_pixelpipe] pipeline resync with history took 0.000 secs (0.000 CPU) for pipe virtual-preview
 514.685917 [dev_pixelpipe] pipeline resync with history took 0.036 secs (0.048 CPU) for pipe preview
 614.724434 [dev_pixelpipe] took 0.038 secs (0.024 CPU) initing base buffer [preview]
 714.787570 [dev_pixelpipe] took 0.063 secs (0.064 CPU) processed `Raw settings' on CPU, blended on  [preview]
 814.857062 [dev_pixelpipe] took 0.069 secs (0.080 CPU) processed `white balance' on CPU, blended on  [preview]
 927.961302 [dev_pixelpipe] took 13.104 secs (32.983 CPU) processed `highlight reconstruction' on CPU, blended on CPU [preview]
1028.949286 [dev_pixelpipe] took 0.988 secs (3.057 CPU) processed `demosaic' on CPU, blended on  [preview]
1129.075925 [dev_pixelpipe] took 0.127 secs (0.326 CPU) processed `lens correction' on CPU, blended on  [preview]
1230.176998 [dev_pixelpipe] took 1.101 secs (3.061 CPU) processed `Initial resampling' on CPU, blended on  [preview]
1330.190589 [dev_pixelpipe] took 0.013 secs (0.024 CPU) processed `exposure' on CPU, blended on CPU [preview]
1430.192681 [dev_pixelpipe] took 0.002 secs (0.005 CPU) processed `input color profile' on CPU, blended on  [preview]
1530.239877 [dev_pixelpipe] took 0.047 secs (0.103 CPU) processed `color calibration' on CPU, blended on CPU [preview]
1631.944712 [dev_pixelpipe] took 1.705 secs (4.286 CPU) processed `diffuse or sharpen' on CPU, blended on CPU [preview]
1732.096771 [dev_pixelpipe] took 0.152 secs (0.407 CPU) processed `color balance rgb' on CPU, blended on CPU [preview]
1832.190015 [dev_pixelpipe] took 0.093 secs (0.228 CPU) processed `filmic rgb' on CPU, blended on CPU [preview]
1932.205505 [dev_pixelpipe] took 0.015 secs (0.028 CPU) processed `output color profile' on CPU, blended on  [preview]
2032.214424 [dev_pixelpipe] took 0.009 secs (0.011 CPU) processed `dithering' on CPU, blended on  [preview]
2132.223982 [dev_pixelpipe] took 0.009 secs (0.021 CPU) processed `display encoding' on CPU, blended on  [preview]
2232.224049 [pixelpipe] preview internal pixel pipeline processing took 17.538 secs (44.709 CPU)
2332.224090 [dev_process_preview] pipeline processing thread took 17.538 secs (44.710 CPU)
2432.276027 [dev_pixelpipe] pipeline resync with history took 0.042 secs (0.054 CPU) for pipe full
2532.276152 [dev_process_full] pipeline processing thread took 0.000 secs (0.000 CPU)

 112.5778 [dt_dev_process_image_job] loading image. took 0.000 secs (0.000 CPU)
 212.6692 [dt_dev_process_image_job] loading image. took 0.000 secs (0.000 CPU)
 312.7607 [dev_pixelpipe] took 0.018 secs (0.022 CPU) initing base buffer [full]
 412.8098 [dev_pixelpipe] took 0.049 secs (0.105 CPU) [full] processed `rawprepare' on CPU
 512.8448 [dev_pixelpipe] took 0.035 secs (0.042 CPU) [full] processed `temperature' on CPU
 625.7535 [dev_pixelpipe] took 12.909 secs (44.992 CPU) [full] processed `highlights' on CPU
 727.5129 [resample_plain] plan 0.001 secs (0.001 CPU) resample 0.732 secs (2.749 CPU)
 827.5515 [dev_pixelpipe] took 1.798 secs (6.012 CPU) [full] processed `demosaic' on CPU
 927.5571 [dev_pixelpipe] took 0.006 secs (0.005 CPU) [full] processed `lens' on CPU
1027.5603 [dev_pixelpipe] took 0.003 secs (0.003 CPU) [full] processed `ashift' on CPU
1127.5634 [dev_pixelpipe] took 0.003 secs (0.005 CPU) [full] processed `exposure' on CPU
1227.5963 [dev_pixelpipe] took 0.033 secs (0.100 CPU) [full] processed `colorin' on CPU
1327.6038 [dt_ioppr_transform_image_colorspace] IOP_CS_LAB-->IOP_CS_RGB took 0.007 secs (0.018 CPU) [channelmixerrgb]
1427.6464 [dev_pixelpipe] took 0.050 secs (0.163 CPU) [full] processed `channelmixerrgb' on CPU
1531.0132 [dev_pixelpipe] took 3.367 secs (12.611 CPU) [full] processed `diffuse' on CPU
1631.1921 [dev_pixelpipe] took 0.179 secs (0.647 CPU) [full] processed `colorbalancergb' on CPU
1731.3065 [dev_pixelpipe] took 0.114 secs (0.406 CPU) [full] processed `filmicrgb' on CPU
1831.3321 [dt_ioppr_transform_image_colorspace] IOP_CS_RGB-->IOP_CS_LAB took 0.025 secs (0.091 CPU) [colorout]
1931.3475 [dev_pixelpipe] took 0.041 secs (0.124 CPU) [full] processed `colorout' on CPU
2031.3754 [dev_pixelpipe] took 0.028 secs (0.020 CPU) [full] processed `dither' on CPU
2131.3849 [dev_pixelpipe] took 0.009 secs (0.034 CPU) [full] processed `gamma' on CPU
2231.3870 [dev_process_image] pixel pipeline took 18.644 secs (65.292 CPU) processing `2022-06-17__DSC00078.arw'
23
2431.4040 [dt_dev_process_image_job] loading image. took 0.000 secs (0.000 CPU)
2531.5018 [dt_dev_process_image_job] loading image. took 0.000 secs (0.000 CPU)
2631.5722 [dev_pixelpipe] took 0.000 secs (0.000 CPU) initing base buffer [preview]
2731.5824 [dev_pixelpipe] took 0.010 secs (0.014 CPU) [preview] processed `rawprepare' on CPU
2831.5861 [dev_pixelpipe] took 0.004 secs (0.008 CPU) [preview] processed `temperature' on CPU
2932.7796 [dev_pixelpipe] took 1.193 secs (4.129 CPU) [preview] processed `highlights' on CPU
3032.8917 [dev_pixelpipe] took 0.112 secs (0.387 CPU) [preview] processed `demosaic' on CPU
3132.9099 [dev_pixelpipe] took 0.018 secs (0.031 CPU) [preview] processed `lens' on CPU
3232.9433 [dev_pixelpipe] took 0.033 secs (0.050 CPU) [preview] processed `ashift' on CPU
3332.9610 [dev_pixelpipe] took 0.018 secs (0.023 CPU) [preview] processed `exposure' on CPU
3433.1087 [dev_pixelpipe] took 0.148 secs (0.532 CPU) [preview] processed `colorin' on CPU
3533.1362 [dt_ioppr_transform_image_colorspace] IOP_CS_LAB-->IOP_CS_RGB took 0.027 secs (0.096 CPU) [channelmixerrgb]
3633.3353 [dev_pixelpipe] took 0.227 secs (0.825 CPU) [preview] processed `channelmixerrgb' on CPU
3755.6386 [dev_pixelpipe] took 22.303 secs (82.427 CPU) [preview] processed `diffuse' on CPU
3856.4763 [dev_pixelpipe] took 0.837 secs (3.180 CPU) [preview] processed `colorbalancergb' on CPU
3957.0002 [dev_pixelpipe] took 0.523 secs (1.966 CPU) [preview] processed `filmicrgb' on CPU
4057.1225 [dt_ioppr_transform_image_colorspace] IOP_CS_RGB-->IOP_CS_LAB took 0.122 secs (0.437 CPU) [colorout]
4157.1852 [dev_pixelpipe] took 0.184 secs (0.637 CPU) [preview] processed `colorout' on CPU
4257.2043 [dev_pixelpipe] took 0.019 secs (0.018 CPU) [preview] processed `dither' on CPU
4357.2471 [dev_pixelpipe] took 0.043 secs (0.155 CPU) [preview] processed `gamma' on CPU
4457.4090 [dev_process_image] pixel pipeline took 25.837 secs (94.647 CPU) processing `2022-06-17__DSC00078.arw'

Report

D’abord, en entrant dans la chambre noire, Darktable calcule 2 pipelines pour obtenir le même résultat qu’Ansel, qui n’en calcule qu’un seul. Donc, indépendamment des temps d’exécution réels, cela représente déjà deux fois plus de calculs inutiles.

Then, Ansel computes the full-resolution image up to the initial resampling module, while Darktable does it only until before demosaic. This is important to the comparison.

• Config 1
• Config 2

On config 1, Darktable manages to be slower than Ansel on GPU even looking only at the single main pipeline rendering and even downscaling the picture to display resolution earlier in the pipeline. But we actually see the same effect on CPU, despite all the alleged “optimizations” done on CPU-only modules circa 2023-2024 in Darktable. Overall, Darktable will freeze your computer 2.3 to 3.0 s longer.

On config 2, the CPU path shows 0.8 s penalty for Ansel on the main pipeline only. The AMD GPU shows a bad hit on the lens correction module, that processes full-resolution on Ansel while it processes at screen resolution in Darktable. Taking into account the second pipeline that Darktable runs, Ansel is faster by 0.14 s on GPU. On CPU however, Darktable now freezes the machine 27.07 s longer because of that duplicated pipeline work. Anyway, the slow modules are at the beginning of the pipeline and will not be recomputed for the whole session.

That gives us the following side-by-side module comparisons. We compare only modules running at the same resolution for the main image pipeline only. In the averages tab, factors are averaged with a geometric mean and relative differences with a harmonic mean:

• Config 1
• Config 2
• Averages

Ansel shows GPU performance improvements even on kernels that didn’t change since Darktable 4.0. The speed-ups we see are clearly the benefit of the high-level memory management, using pinned OpenCL memory or plain device-only memory buffers where relevant.

Across all modules, Ansel is 1.6 times faster than Darktable on GPU (geometric mean).

On CPU, things are more nuanced.

Darktable 5.x is supposed to have received CPU optimizations for dithering and demosaicing (RCD), yet both those modules perform worse than Ansel’s on both configs.

Ansel has manually-vectorized CPU pixel code for color balance RGB, color calibration, input/output color profile, raw settings, white balance, exposure and filmic, while Darktable’s uses compiler hints to achieve vectorization. All of them perform better than Darktable’s on the Intel Xeon. On the Intel i3, for basic color matrix work, Ansel performs (much) better, but it’s slightly harming basic modules like raw settings, exposure or white balance.

Diffuse or sharpen should still use the same Darktable 4.0 code on Ansel and on Darktable 5.4, but Ansel is faster on both configs, which shows the benefit of using our own pre-allocated memory array for the cache, and allocating memory buffers out of the OS circuitery. This shows that optimizing at the module level is the wrong scope, and that global pipeline needed an overhaul first.

Mais il est évidemment plus facile de s’attaquer à des optimisations module par module parce que les modules sont… modulaires, c’est-à-dire autonomes et auto-contenus. Il y a peu de risques de casser l’ensemble du logiciel quand on travaille sur les modules, puisqu’ils sont isolés du reste. Les changements d’architecture à l’échelle de l’application, à l’inverse, sont dangereux, compliqués et exigeants. Et ils imposent d’arrêter complètement le développement de nouveaux modules tant que l’architecture n’est pas stabilisée. Darktable n’aura jamais la discipline de faire cela, parce que le projet n’est pas géré et que des pull requests aléatoires apparaissent sur GitHub à des moments aléatoires, proposées par des contributeurs aléatoires.

Across all modules, Ansel is 1.8 times faster than Darktable on CPU (geometric mean).

Combining GPU and CPU pathes over both config, opening the darkroom is 1.5 times faster on Ansel (geometric mean).

Zoom à 100 %

Dans la chambre noire, à partir du mode « ajuster à la fenêtre », zoomez à 100 % en un clic avec le bouton du milieu de la souris.

• Ansel Master GPU
• Darktable 5.4.1 GPU

 112.083270 [dev_pixelpipe] pipeline resync with history took 0.000 secs (0.000 CPU) for pipe virtual-preview
 212.111607 [dev_pixelpipe] pipeline resync with history took 0.000 secs (0.000 CPU) for pipe full
 312.177976 [dev_pixelpipe] took 0.066 secs (0.095 CPU) processed `Initial resampling' on GPU, blended on  [full]
 412.179976 [dev_pixelpipe] took 0.002 secs (0.002 CPU) processed `exposure' on GPU, blended on GPU [full]
 512.183194 [dev_pixelpipe] took 0.003 secs (0.005 CPU) processed `input color profile' on GPU, blended on  [full]
 612.185327 [dev_pixelpipe] took 0.002 secs (0.002 CPU) processed `color calibration' on GPU, blended on GPU [full]
 714.887725 [dev_pixelpipe] took 2.702 secs (2.705 CPU) processed `diffuse or sharpen' on GPU, blended on GPU [full]
 814.899213 [dev_pixelpipe] took 0.011 secs (0.013 CPU) processed `color balance rgb' on GPU, blended on GPU [full]
 914.907159 [dev_pixelpipe] took 0.008 secs (0.008 CPU) processed `filmic rgb' on GPU, blended on GPU [full]
1014.940617 [dev_pixelpipe] took 0.033 secs (0.039 CPU) processed `output color profile' on GPU, blended on  [full]
1115.005967 [dev_pixelpipe] took 0.065 secs (0.057 CPU) processed `dithering' on CPU, blended on  [full]
1215.030966 [dev_pixelpipe] took 0.025 secs (0.036 CPU) processed `display encoding' on GPU, blended on  [full]
1315.031021 [pixelpipe] full internal pixel pipeline processing took 2.919 secs (2.963 CPU)
1415.031080 [dev_process_full] pipeline processing thread took 2.919 secs (2.963 CPU)

 189,3415 [dt_dev_process_image_job] loading image. took 0,000 secs (0,000 CPU)
 289,3440 [dev_pixelpipe] took 0,002 secs (0,001 CPU) initing base buffer [full]
 389,3544 [dev_pixelpipe] took 0,010 secs (0,008 CPU) [full] processed `rawprepare' on GPU, blended on GPU
 489,3573 [dev_pixelpipe] took 0,003 secs (0,001 CPU) [full] processed `temperature' on GPU, blended on GPU
 589,8611 [dev_pixelpipe] took 0,504 secs (0,511 CPU) [full] processed `highlights' on GPU, blended on GPU
 689,9200 [dev_pixelpipe] took 0,059 secs (0,023 CPU) [full] processed `demosaic' on GPU, blended on GPU
 789,9251 [dev_pixelpipe] took 0,005 secs (0,003 CPU) [full] processed `lens' on GPU, blended on GPU
 889,9346 [dev_pixelpipe] took 0,009 secs (0,003 CPU) [full] processed `exposure' on GPU, blended on GPU
 989,9480 [dev_pixelpipe] took 0,013 secs (0,003 CPU) [full] processed `colorin' on GPU, blended on GPU
1089,9576 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_LAB-->IOP_CS_RGB took 0,009 secs (0,002 GPU) [channelmixerrgb]
1189,9736 [dev_pixelpipe] took 0,026 secs (0,008 CPU) [full] processed `channelmixerrgb' on GPU, blended on GPU
1294,9286 [dev_pixelpipe] took 4,955 secs (5,096 CPU) [full] processed `diffuse' on GPU, blended on GPU
1394,9528 [dev_pixelpipe] took 0,024 secs (0,007 CPU) [full] processed `colorbalancergb' on GPU, blended on GPU
1494,9836 [dev_pixelpipe] took 0,031 secs (0,009 CPU) [full] processed `filmicrgb' on GPU, blended on GPU
1594,9925 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_RGB-->IOP_CS_LAB took 0,009 secs (0,000 GPU) [colorout]
1695,0700 [dev_pixelpipe] took 0,086 secs (0,028 CPU) [full] processed `colorout' on GPU, blended on GPU
1795,2184 [dev_pixelpipe] took 0,148 secs (0,093 CPU) [full] processed `dither' on CPU, blended on CPU
1895,2404 [dev_pixelpipe] took 0,022 secs (0,104 CPU) [full] processed `gamma' on CPU, blended on CPU
1995,2537 [dev_process_image] pixel pipeline took 5,912 secs (5,904 CPU) processing `2022-06-17__DSC00078.arw'
2095,2634 [dev_process_image] pixel pipeline took 0,010 secs (0,004 CPU) processing `2022-06-17__DSC00078.arw'

Comme Ansel traite les premières étapes du pipeline en pleine résolution, elles sont elles aussi mises en cache en pleine résolution. Cela signifie que le panoramique et le zoom récupèrent le cache en amont du module de rééchantillonnage initial et ne recalculent que l’aval. Le rendu prend donc 2,9 s. Darktable, en revanche, a un cache non fonctionnel, il recalcule donc tout depuis le début, ce qui lui prend 5,9 s pour afficher exactement la même chose. Cela représente une pénalité de performance de ×2 pour Darktable.

Panoramique à 100 %

• Ansel master GPU
• Darktable 5.4.1 GPU

 155.456510 [dev_pixelpipe] pipeline resync with history took 0.000 secs (0.000 CPU) for pipe full
 255.536149 [dev_pixelpipe] took 0.080 secs (0.121 CPU) processed `Initial resampling' on GPU, blended on  [full]
 355.541720 [dev_pixelpipe] took 0.005 secs (0.003 CPU) processed `exposure' on GPU, recycled cacheline, blended on GPU [full]
 455.551346 [dev_pixelpipe] took 0.009 secs (0.006 CPU) processed `input color profile' on GPU, recycled cacheline, blended on  [full]
 555.559669 [dev_pixelpipe] took 0.008 secs (0.005 CPU) processed `color calibration' on GPU, recycled cacheline, blended on GPU [full]
 658.290943 [dev_pixelpipe] took 2.731 secs (2.819 CPU) processed `diffuse or sharpen' on GPU, blended on GPU [full]
 758.310400 [dev_pixelpipe] took 0.016 secs (0.017 CPU) processed `color balance rgb' on GPU, recycled cacheline, blended on GPU [full]
 858.322514 [dev_pixelpipe] took 0.012 secs (0.014 CPU) processed `filmic rgb' on GPU, recycled cacheline, blended on GPU [full]
 958.364803 [dev_pixelpipe] took 0.042 secs (0.054 CPU) processed `output color profile' on GPU, blended on  [full]
1058.411730 [dev_pixelpipe] took 0.045 secs (0.052 CPU) processed `dithering' on CPU, recycled cacheline, blended on  [full]
1158.440432 [dev_pixelpipe] took 0.029 secs (0.042 CPU) processed `display encoding' on GPU, blended on  [full]
1258.440478 [pixelpipe] full internal pixel pipeline processing took 2.984 secs (3.133 CPU)
1358.440516 [dev_process_full] pipeline processing thread took 2.984 secs (3.133 CPU)

 1253,1082 [dev_pixelpipe] took 0,003 secs (0,004 CPU) initing base buffer [full]
 2253,1132 [dev_pixelpipe] took 0,005 secs (0,004 CPU) [full] processed `rawprepare' on GPU, blended on GPU
 3253,1152 [dev_pixelpipe] took 0,002 secs (0,001 CPU) [full] processed `temperature' on GPU, blended on GPU
 4253,5743 [dev_pixelpipe] took 0,459 secs (0,441 CPU) [full] processed `highlights' on GPU, blended on GPU
 5253,6257 [dev_pixelpipe] took 0,051 secs (0,022 CPU) [full] processed `demosaic' on GPU, blended on GPU
 6253,6307 [dev_pixelpipe] took 0,005 secs (0,002 CPU) [full] processed `lens' on GPU, blended on GPU
 7253,6394 [dev_pixelpipe] took 0,009 secs (0,003 CPU) [full] processed `exposure' on GPU, blended on GPU
 8253,6521 [dev_pixelpipe] took 0,013 secs (0,003 CPU) [full] processed `colorin' on GPU, blended on GPU
 9253,6610 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_LAB-->IOP_CS_RGB took 0,008 secs (0,001 GPU) [channelmixerrgb]
10253,6760 [dev_pixelpipe] took 0,024 secs (0,005 CPU) [full] processed `channelmixerrgb' on GPU, blended on GPU
11258,6306 [dev_pixelpipe] took 4,954 secs (4,882 CPU) [full] processed `diffuse' on GPU, blended on GPU
12258,6548 [dev_pixelpipe] took 0,024 secs (0,005 CPU) [full] processed `colorbalancergb' on GPU, blended on GPU
13258,6857 [dev_pixelpipe] took 0,031 secs (0,009 CPU) [full] processed `filmicrgb' on GPU, blended on GPU
14258,6945 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_RGB-->IOP_CS_LAB took 0,009 secs (0,000 GPU) [colorout]
15258,7725 [dev_pixelpipe] took 0,087 secs (0,034 CPU) [full] processed `colorout' on GPU, blended on GPU
16258,9198 [dev_pixelpipe] took 0,147 secs (0,086 CPU) [full] processed `dither' on CPU, blended on CPU
17258,9373 [dev_pixelpipe] took 0,017 secs (0,110 CPU) [full] processed `gamma' on CPU, blended on CPU
18258,9407 [dev_process_image] pixel pipeline took 5,859 secs (5,614 CPU) processing `2022-06-17__DSC00078.arw'
19258,9735 [dev_process_image] pixel pipeline took 0,033 secs (0,014 CPU) processing `2022-06-17__DSC00078.arw'

Le panoramique conduit à la même situation que le zoom : Ansel a l’image en pleine résolution en cache, donc nous recalculons à partir du rééchantillonnage initial, ce qui prend 3 s. Darktable est incapable de gérer correctement un cache, donc vous repartez pour un recalcul complet et 5,9 s d’ordinateur figé.

Aller-retour vers la table lumineuse

• Ansel master GPU
• Darktable 5.4.1 GPU

1184.536988 [dev_pixelpipe] took 0.000 secs (0.000 CPU) to load the image.
2184.574776 [dev_pixelpipe] pipeline resync with history took 0.019 secs (0.016 CPU) for pipe virtual-preview
3185.012395 [dev_pixelpipe] pipeline resync with history took 0.020 secs (0.017 CPU) for pipe virtual-preview
4185.046379 [dev_pixelpipe] pipeline resync with history took 0.000 secs (0.000 CPU) for pipe virtual-preview
5185.046424 [dev_pixelpipe] pipeline resync with history took 0.000 secs (0.000 CPU) for pipe virtual-preview
6185.049883 [dev_pixelpipe] pipeline resync with history took 0.026 secs (0.049 CPU) for pipe preview
7185.049931 [dev_pixelpipe] pipeline resync with history took 0.000 secs (0.000 CPU) for pipe preview
8185.068516 [dev_pixelpipe] pipeline resync with history took 0.019 secs (0.020 CPU) for pipe full
9185.068568 [dev_process_full] pipeline processing thread took 0.000 secs (0.000 CPU)

 13324,5295 [histogram] took 0,006 secs (0,005 CPU) scope draw
 23324,5837 [dt_dev_process_image_job] loading image. took 0,000 secs (0,000 CPU)
 33324,6371 [dev_process_image] pixel pipeline took 0,002 secs (0,001 CPU) processing `2022-06-17__DSC00078.arw'
 4
 53324,7352 [dt_dev_process_image_job] loading image. took 0,000 secs (0,000 CPU)
 63324,8074 [dev_pixelpipe] took 0,000 secs (0,000 CPU) initing base buffer [preview]
 73324,8155 [dev_pixelpipe] took 0,008 secs (0,005 CPU) [preview] processed `rawprepare' on GPU, blended on GPU
 83324,8165 [dev_pixelpipe] took 0,001 secs (0,001 CPU) [preview] processed `temperature' on GPU, blended on GPU
 93324,8178 [dev_pixelpipe] took 0,001 secs (0,003 CPU) [preview] processed `highlights' on GPU, blended on GPU
103324,8337 [dev_pixelpipe] took 0,016 secs (0,021 CPU) [preview] processed `demosaic' on GPU, blended on GPU
113324,8351 [dev_pixelpipe] took 0,001 secs (0,002 CPU) [preview] processed `lens' on GPU, blended on GPU
123324,8387 [dev_pixelpipe] took 0,003 secs (0,013 CPU) [preview] processed `exposure' on GPU, blended on GPU
133324,8440 [dev_pixelpipe] took 0,005 secs (0,015 CPU) [preview] processed `colorin' on GPU, blended on GPU
143324,8491 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_LAB-->IOP_CS_RGB took 0,005 secs (0,012 GPU) [channelmixerrgb]
153324,8545 [dev_pixelpipe] took 0,010 secs (0,019 CPU) [preview] processed `channelmixerrgb' on GPU, blended on GPU
163325,6440 [dev_pixelpipe] took 0,789 secs (0,921 CPU) [preview] processed `diffuse' on GPU, blended on GPU
173325,6482 [dev_pixelpipe] took 0,004 secs (0,003 CPU) [preview] processed `colorbalancergb' on GPU, blended on GPU
183325,6534 [dev_pixelpipe] took 0,005 secs (0,003 CPU) [preview] processed `filmicrgb' on GPU, blended on GPU
193325,6569 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_RGB-->IOP_CS_LAB took 0,003 secs (0,002 GPU) [colorout]
203325,6747 [dev_pixelpipe] took 0,021 secs (0,008 CPU) [preview] processed `colorout' on GPU, blended on GPU
213325,6979 [dev_pixelpipe] took 0,023 secs (0,009 CPU) [preview] processed `dither' on CPU, blended on CPU
223325,7061 [dev_pixelpipe] took 0,008 secs (0,029 CPU) [preview] processed `gamma' on CPU, blended on CPU
233325,7263 [dt_ioppr_transform_image_colorspace_rgb] `Système' -> `sRVB' took 0,020 secs (0,068 CPU) [final histogram]
243325,7357 [dev_process_image] pixel pipeline took 0,935 secs (1,152 CPU) processing `2022-06-17__DSC00078.arw'

Le cache du pipeline d’Ansel survit aux pipelines eux-mêmes, ce qui signifie que sortir de la chambre noire puis y revenir est quasi instantané : il suffit de 60 ms pour resynchroniser tous les pipelines avec l’historique de développement et constater, via leur somme de contrôle, que la sortie du pipeline est déjà en cache. Notez qu’il n’y a ici aucun traitement spécial, c’est simplement le comportement générique du cache.

Pour Darktable, cela marche presque pour l’image principale, mais pas pour l’aperçu, ce qui vous vaut 1 s de recalcul inutile. Étant donné que cela fonctionne sur un pipeline mais pas sur l’autre, je parierais que c’est géré par des cas particuliers. Comparé à Ansel, cela représente une pénalité de performance de ×1,75.

Désactiver un module au milieu du pipeline

J’ai désactivé diffusion ou netteté en étant zoomé à la taille « remplir ».

• Ansel master GPU
• Darktable 5.4.1 GPU

 1124.206298 [dev_pixelpipe] pipeline resync with history took 0.011 secs (0.010 CPU) for pipe virtual-preview
 2124.237640 [dev_pixelpipe] pipeline resync with history took 0.011 secs (0.028 CPU) for pipe preview
 3124.290940 [dev_pixelpipe] took 0.023 secs (0.028 CPU) processed `color balance rgb' on GPU, recycled cacheline, blended on GPU [preview]
 4124.303176 [dev_pixelpipe] took 0.012 secs (0.012 CPU) processed `filmic rgb' on GPU, recycled cacheline, blended on GPU [preview]
 5124.331334 [dev_pixelpipe] took 0.028 secs (0.030 CPU) processed `output color profile' on GPU, blended on  [preview]
 6124.370193 [darkroom] took 0.007 secs (0.011 CPU) redraw
 7124.382425 [dev_pixelpipe] took 0.051 secs (0.055 CPU) processed `dithering' on CPU, blended on  [preview]
 8124.410053 [dev_pixelpipe] took 0.028 secs (0.028 CPU) processed `display encoding' on GPU, blended on  [preview]
 9124.410088 [pixelpipe] preview internal pixel pipeline processing took 0.172 secs (0.197 CPU)
10124.410115 [dev_process_preview] pipeline processing thread took 0.172 secs (0.197 CPU)
11124.433186 [dev_pixelpipe] pipeline resync with history took 0.013 secs (0.017 CPU) for pipe full
12124.433286 [dev_process_full] pipeline processing thread took 0.000 secs (0.000 CPU)

 1300,9771 [dt_dev_process_image_job] loading image. took 0,000 secs (0,000 CPU)
 2301,0564 [dev_pixelpipe] took 0,016 secs (0,028 CPU) initing base buffer [full]
 3301,0936 [dev_pixelpipe] took 0,037 secs (0,037 CPU) [full] processed `rawprepare' on GPU, blended on GPU
 4301,1102 [dev_pixelpipe] took 0,017 secs (0,017 CPU) [full] processed `temperature' on GPU, blended on GPU
 5304,8700 [dev_pixelpipe] took 3,760 secs (3,786 CPU) [full] processed `highlights' on GPU with tiling, blended on CPU
 6305,2630 [resample_cl] plan 0,001 secs (0,000 CPU) resample 0,010 secs (0,001 CPU)
 7305,3543 [dev_pixelpipe] took 0,484 secs (0,284 CPU) [full] processed `demosaic' on GPU, blended on GPU
 8305,3648 [dev_pixelpipe] took 0,010 secs (0,002 CPU) [full] processed `lens' on GPU, blended on GPU
 9305,3764 [dev_pixelpipe] took 0,012 secs (0,001 CPU) [full] processed `exposure' on GPU, blended on GPU
10305,4083 [dev_pixelpipe] took 0,032 secs (0,007 CPU) [full] processed `colorin' on GPU, blended on GPU
11305,4220 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_LAB-->IOP_CS_RGB took 0,013 secs (0,001 GPU) [channelmixerrgb]
12305,4460 [dev_pixelpipe] took 0,038 secs (0,008 CPU) [full] processed `channelmixerrgb' on GPU, blended on GPU
13307,1388 [dev_pixelpipe] took 1,693 secs (1,645 CPU) [full] processed `diffuse' on GPU, blended on GPU
14307,1500 [dev_pixelpipe] took 0,011 secs (0,003 CPU) [full] processed `colorbalancergb' on GPU, blended on GPU
15307,1612 [dev_pixelpipe] took 0,011 secs (0,003 CPU) [full] processed `filmicrgb' on GPU, blended on GPU
16307,1675 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_RGB-->IOP_CS_LAB took 0,006 secs (0,001 GPU) [colorout]
17307,2185 [dev_pixelpipe] took 0,057 secs (0,020 CPU) [full] processed `colorout' on GPU, blended on GPU
18307,3095 [dev_pixelpipe] took 0,091 secs (0,056 CPU) [full] processed `dither' on CPU, blended on CPU
19307,3235 [dev_pixelpipe] took 0,014 secs (0,065 CPU) [full] processed `gamma' on CPU, blended on CPU
20307,3333 [dev_process_image] pixel pipeline took 6,293 secs (5,969 CPU) processing `2022-06-17__DSC00078.arw'
21307,3843 [dev_process_image] pixel pipeline took 0,051 secs (0,018 CPU) processing `2022-06-17__DSC00078.arw'
22
23307,4258 [dt_dev_process_image_job] loading image. took 0,000 secs (0,000 CPU)
24307,4875 [dev_pixelpipe] took 0,000 secs (0,000 CPU) initing base buffer [preview]
25307,4895 [dev_pixelpipe] took 0,002 secs (0,002 CPU) [preview] processed `rawprepare' on GPU, blended on GPU
26307,4906 [dev_pixelpipe] took 0,001 secs (0,001 CPU) [preview] processed `temperature' on GPU, blended on GPU
27307,5609 [dev_pixelpipe] took 0,070 secs (0,072 CPU) [preview] processed `highlights' on GPU, blended on GPU
28307,5722 [dev_pixelpipe] took 0,011 secs (0,005 CPU) [preview] processed `demosaic' on GPU, blended on GPU
29307,5740 [dev_pixelpipe] took 0,002 secs (0,000 CPU) [preview] processed `lens' on GPU, blended on GPU
30307,5765 [dev_pixelpipe] took 0,002 secs (0,001 CPU) [preview] processed `exposure' on GPU, blended on GPU
31307,5798 [dev_pixelpipe] took 0,003 secs (0,002 CPU) [preview] processed `colorin' on GPU, blended on GPU
32307,5827 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_LAB-->IOP_CS_RGB took 0,002 secs (0,002 GPU) [channelmixerrgb]
33307,5864 [dev_pixelpipe] took 0,007 secs (0,003 CPU) [preview] processed `channelmixerrgb' on GPU, blended on GPU
34307,9576 [dev_pixelpipe] took 0,371 secs (0,356 CPU) [preview] processed `diffuse' on GPU, blended on GPU
35307,9613 [dev_pixelpipe] took 0,003 secs (0,002 CPU) [preview] processed `colorbalancergb' on GPU, blended on GPU
36307,9659 [dev_pixelpipe] took 0,005 secs (0,000 CPU) [preview] processed `filmicrgb' on GPU, blended on GPU
37307,9686 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_RGB-->IOP_CS_LAB took 0,002 secs (0,000 GPU) [colorout]
38307,9847 [dev_pixelpipe] took 0,019 secs (0,008 CPU) [preview] processed `colorout' on GPU, blended on GPU
39308,0043 [dev_pixelpipe] took 0,020 secs (0,011 CPU) [preview] processed `dither' on CPU, blended on CPU
40308,0103 [dev_pixelpipe] took 0,006 secs (0,023 CPU) [preview] processed `gamma' on CPU, blended on CPU
41308,0244 [dt_ioppr_transform_image_colorspace_rgb] `Système' -> `sRVB' took 0,014 secs (0,081 CPU) [final histogram]
42308,0353 [dev_process_image] pixel pipeline took 0,553 secs (0,604 CPU) processing `2022-06-17__DSC00078.arw'

Une fois encore, le cache d’Ansel fonctionne tout simplement : désactiver diffusion ou netteté ne conduit à recalculer que les modules situés en aval, ce qui prend 172 ms. Une fois encore, le cache de Darktable ne fonctionne pas, ce qui conduit à recalculer l’ensemble des 2 pipelines (aperçu et principal), pour un coût total de 6,9 s. Cela représente une pénalité de performance de ×40, tout de même ! Tous les pseudo gains de +15 % de Ralf Brown deviennent donc totalement insignifiants. Mais bon ! Continuez à chercher vos clés là où vous voyez vos pieds plutôt que là où vous les avez perdues ! .

Pipette couleur dans un module

Nous réglons la balance des blancs dans calibration des couleurs à l’aide de la pipette, au niveau de zoom « ajuster à la fenêtre ».

• Ansel master GPU
• Darktable 5.4.1 GPU

 1colorpicker stats reading took 0.020 secs (0.088 CPU)
 2colorpicker stats reading took 0.018 secs (0.087 CPU)
 312.128030 [dev_pixelpipe] pipeline resync with history took 0.024 secs (0.037 CPU) for pipe virtual-preview
 412.137829 [dev_pixelpipe] pipeline resync with history took 0.024 secs (0.056 CPU) for pipe preview
 512.157665 [dev_pixelpipe] took 0.020 secs (0.048 CPU) processed `color calibration' on GPU, blended on GPU [preview]
 613.327326 [dev_pixelpipe] took 1.170 secs (1.231 CPU) processed `diffuse or sharpen' on GPU, blended on GPU [preview]
 713.336618 [dev_pixelpipe] took 0.009 secs (0.008 CPU) processed `color balance rgb' on GPU, recycled cacheline, blended on GPU [preview]
 813.345393 [dev_pixelpipe] took 0.009 secs (0.007 CPU) processed `filmic rgb' on GPU, recycled cacheline, blended on GPU [preview]
 913.368053 [dev_pixelpipe] took 0.023 secs (0.030 CPU) processed `output color profile' on GPU, blended on  [preview]
1013.418643 [dev_pixelpipe] took 0.050 secs (0.061 CPU) processed `dithering' on CPU, blended on  [preview]
1113.435846 [dev_pixelpipe] took 0.017 secs (0.024 CPU) processed `display encoding' on GPU, blended on  [preview]
1213.435919 [pixelpipe] preview internal pixel pipeline processing took 1.298 secs (1.408 CPU)
1313.435949 [dev_process_preview] pipeline processing thread took 1.298 secs (1.408 CPU)
1413.526316 [dev_pixelpipe] pipeline resync with history took 0.080 secs (0.376 CPU) for pipe full
1513.526443 [dev_process_full] pipeline processing thread took 0.000 secs (0.000 CPU)
16colorpicker stats reading took 0.185 secs (0.741 CPU)
17image colorspace transform RGB-->RGB took 0.000 secs (0.000 CPU) [[histogram] sample swatch]
18image colorspace transform RGB-->RGB took 0.000 secs (0.000 CPU) [[histogram] sample swatch]
19image colorspace transform RGB-->RGB took 0.000 secs (0.000 CPU) [[histogram] sample swatch]

 116,1190 [dt_dev_process_image_job] loading image. took 0,000 secs (0,000 CPU)
 216,1364 dt_color_picker_helper stats reading 4 channels (filters 2492765332) cst 2 -> 2 size 1118880 denoised 0 took 0,001 secs (0,005 CPU)
 316,1396 [dev_pixelpipe] took 0,020 secs (0,025 CPU) [preview] processed `channelmixerrgb' on GPU, blended on GPU
 416,2071 [dt_dev_process_image_job] loading image. took 0,000 secs (0,000 CPU)
 516,6064 [dev_pixelpipe] took 0,467 secs (0,567 CPU) [preview] processed `diffuse' on GPU, blended on GPU
 616,6106 [dev_pixelpipe] took 0,004 secs (0,004 CPU) [preview] processed `colorbalancergb' on GPU, blended on GPU
 716,6160 [dev_pixelpipe] took 0,005 secs (0,001 CPU) [preview] processed `filmicrgb' on GPU, blended on GPU
 816,6192 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_RGB-->IOP_CS_LAB took 0,003 secs (0,002 GPU) [colorout]
 916,6364 [dev_pixelpipe] took 0,020 secs (0,010 CPU) [preview] processed `colorout' on GPU, blended on GPU
1016,6513 [dev_pixelpipe] took 0,015 secs (0,005 CPU) [preview] processed `dither' on CPU, blended on CPU
1116,6572 [dev_pixelpipe] took 0,006 secs (0,023 CPU) [preview] processed `gamma' on CPU, blended on CPU
1216,6584 dt_color_picker_helper stats reading 4 channels (filters 2492765332) cst 2 -> 2 size 1118880 denoised 0 took 0,001 secs (0,005 CPU)
1316,6586 [dt_ioppr_transform_image_colorspace] IOP_CS_RGB-->IOP_CS_LAB took 0,000 secs (0,000 CPU) [gamma]
1416,6587 [dt_ioppr_transform_image_colorspace_rgb] `Système' -> `sRVB' took 0,000 secs (0,000 CPU) [primary picker]
1516,6754 [dt_ioppr_transform_image_colorspace_rgb] `Système' -> `sRVB' took 0,017 secs (0,063 CPU) [final histogram]
1616,6843 [histogram] took 0,026 secs (0,093 CPU) final waveform
1716,6847 [dev_process_image] pixel pipeline took 0,566 secs (0,733 CPU) processing `2022-06-17__DSC00078.arw'
18
1916,6854 [dt_dev_process_image_job] loading image. took 0,000 secs (0,000 CPU)
2020,3395 [dev_pixelpipe] took 3,606 secs (3,778 CPU) [full] processed `highlights' on GPU with tiling, blended on CPU
2120,7350 [resample_cl] plan 0,001 secs (0,000 CPU) resample 0,010 secs (0,001 CPU)
2220,8263 [dev_pixelpipe] took 0,487 secs (0,285 CPU) [full] processed `demosaic' on GPU, blended on GPU
2320,8389 [dev_pixelpipe] took 0,012 secs (0,002 CPU) [full] processed `lens' on GPU, blended on GPU
2420,8505 [dev_pixelpipe] took 0,012 secs (0,002 CPU) [full] processed `exposure' on GPU, blended on GPU
2520,8812 [dev_pixelpipe] took 0,031 secs (0,008 CPU) [full] processed `colorin' on GPU, blended on GPU
2620,8972 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_LAB-->IOP_CS_RGB took 0,016 secs (0,004 GPU) [channelmixerrgb]
2720,9551 [dev_pixelpipe] took 0,074 secs (0,023 CPU) [full] processed `channelmixerrgb' on GPU, blended on GPU
2821,8137 [dev_pixelpipe] took 0,000 secs (0,000 CPU) initing base buffer [preview]
2921,8160 [dev_pixelpipe] took 0,001 secs (0,005 CPU) [preview] processed `rawprepare' on CPU, blended on CPU
3021,8173 [dev_pixelpipe] took 0,001 secs (0,001 CPU) [preview] processed `temperature' on CPU, blended on CPU
3121,9879 [dev_pixelpipe] took 0,171 secs (0,758 CPU) [preview] processed `highlights' on CPU, blended on CPU
3222,0020 [dev_pixelpipe] took 0,014 secs (0,080 CPU) [preview] processed `demosaic' on CPU, blended on CPU
3322,0103 [dev_pixelpipe] took 0,008 secs (0,016 CPU) [preview] processed `lens' on CPU, blended on CPU
3422,0127 [dev_pixelpipe] took 0,002 secs (0,014 CPU) [preview] processed `exposure' on CPU, blended on CPU
3522,0155 [dev_pixelpipe] took 0,003 secs (0,015 CPU) [preview] processed `colorin' on CPU, blended on CPU
3622,0172 [dt_ioppr_transform_image_colorspace] IOP_CS_LAB-->IOP_CS_RGB took 0,002 secs (0,009 CPU) [channelmixerrgb]
3722,0457 dt_color_picker_helper stats reading 4 channels (filters 2492765332) cst 2 -> 2 size 1118880 denoised 0 took 0,002 secs (0,013 CPU)
3822,0458 [dev_pixelpipe] took 0,030 secs (0,180 CPU) [preview] processed `channelmixerrgb' on CPU, blended on CPU
3922,6461 [dev_pixelpipe] took 1,691 secs (5,549 CPU) [full] processed `diffuse' on GPU, blended on GPU
4022,6595 [dev_pixelpipe] took 0,013 secs (0,079 CPU) [full] processed `colorbalancergb' on GPU, blended on GPU
4122,6725 [dev_pixelpipe] took 0,013 secs (0,073 CPU) [full] processed `filmicrgb' on GPU, blended on GPU
4222,6824 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_RGB-->IOP_CS_LAB took 0,007 secs (0,041 GPU) [colorout]
4322,7443 [dev_pixelpipe] took 0,072 secs (0,398 CPU) [full] processed `colorout' on GPU, blended on GPU
4422,8624 [dev_pixelpipe] took 0,118 secs (0,664 CPU) [full] processed `dither' on CPU, blended on CPU
4522,8878 [dev_pixelpipe] took 0,025 secs (0,172 CPU) [full] processed `gamma' on CPU, blended on CPU
4622,8894 [dev_process_image] pixel pipeline took 6,637 secs (11,596 CPU) processing `2022-06-17__DSC00078.arw'
4723,4204 [dev_pixelpipe] took 1,374 secs (8,556 CPU) [preview] processed `diffuse' on CPU, blended on CPU
4823,5271 [dev_pixelpipe] took 0,106 secs (0,617 CPU) [preview] processed `colorbalancergb' on CPU, blended on CPU
4923,5788 [dev_pixelpipe] took 0,051 secs (0,291 CPU) [preview] processed `filmicrgb' on CPU, blended on CPU
5023,5817 [dt_ioppr_transform_image_colorspace] IOP_CS_RGB-->IOP_CS_LAB took 0,003 secs (0,011 CPU) [colorout]
5123,5870 [dev_pixelpipe] took 0,008 secs (0,037 CPU) [preview] processed `colorout' on CPU, blended on CPU
5223,5913 [dev_pixelpipe] took 0,004 secs (0,004 CPU) [preview] processed `dither' on CPU, blended on CPU
5323,5964 [dev_pixelpipe] took 0,005 secs (0,021 CPU) [preview] processed `gamma' on CPU, blended on CPU
5423,5973 dt_color_picker_helper stats reading 4 channels (filters 2492765332) cst 2 -> 2 size 1118880 denoised 0 took 0,001 secs (0,006 CPU)
5523,5976 [dt_ioppr_transform_image_colorspace] IOP_CS_RGB-->IOP_CS_LAB took 0,000 secs (0,000 CPU) [gamma]
5623,5977 [dt_ioppr_transform_image_colorspace_rgb] `Système' -> `sRVB' took 0,000 secs (0,000 CPU) [primary picker]
5723,6099 [dt_ioppr_transform_image_colorspace_rgb] `Système' -> `sRVB' took 0,012 secs (0,067 CPU) [final histogram]
5823,6215 [histogram] took 0,024 secs (0,097 CPU) final waveform
5923,6219 [dev_process_image] pixel pipeline took 6,889 secs (15,651 CPU) processing `2022-06-17__DSC00078.arw'

Ansel n’a pas besoin de relancer un rendu de pipeline pour échantillonner avec la pipette, car l’entrée et la sortie du module sont encore en cache. L’échantillonnage prend donc 40 ms au total. Ensuite, les nouveaux paramètres sont enregistrés dans le module, ce qui modifie l’historique et déclenche un recalcul du module calibration des couleurs ainsi que de tous les modules situés en aval. Temps total passé : 1,4 s.

Darktable doit relancer un nouveau rendu de pipeline pour échantillonner avec la pipette, parce que pourquoi pas ? Cela prend 0,6 s. Vous serez ravi d’apprendre que Darktable échantillonne la couleur sur GPU, ce qui ne prend qu'1 ms, au milieu de ces 0,6 s de rendu de pipeline, tandis qu’Ansel échantillonne sur CPU en 20 ms. Ensuite, les paramètres de la pipette sont enregistrés dans l’historique, ce qui relance un recalcul complet des 2 pipelines. Temps total passé : 7,5 s.

Cela représente une pénalité de ×5,4 pour Darktable, tout cela parce qu’ils n’améliorent pas leurs pipelines mais poursuivent toutes les fausses pistes possibles.

Export en pleine résolution

Nous exportons après avoir ouvert l’image dans la chambre noire. C’est important. Dans Darktable, l’échantillonnage « haute qualité » est utilisé ; dans Ansel, c’est le seul mode.

• Ansel Master GPU
• Darktable 5.4.1 GPU

 118.917740 [dev_pixelpipe] took 0.000 secs (0.000 CPU) to load the image.
 218.970877 [export] creating pixelpipe took 0.054 secs (0.074 CPU)
 319.215438 [dev_pixelpipe] took 0.244 secs (0.222 CPU) processed `exposure' on GPU, blended on GPU [export]
 419.241544 [dev_pixelpipe] took 0.026 secs (0.025 CPU) processed `input color profile' on GPU, blended on  [export]
 519.267887 [dev_pixelpipe] took 0.026 secs (0.026 CPU) processed `color calibration' on GPU, blended on GPU [export]
 656.171662 [dev_pixelpipe] took 36.904 secs (36.592 CPU) processed `diffuse or sharpen' on GPU with tiling, blended on CPU [export]
 756.364588 [dev_pixelpipe] took 0.193 secs (0.156 CPU) processed `color balance rgb' on GPU, blended on GPU [export]
 857.293819 [dev_pixelpipe] took 0.929 secs (0.468 CPU) processed `filmic rgb' on GPU with tiling, blended on CPU [export]
 957.516252 [dev_pixelpipe] took 0.222 secs (0.176 CPU) processed `output color profile' on GPU, blended on  [export]
1057.534628 [dev_pixelpipe] took 0.018 secs (0.017 CPU) processed `Final resampling' on GPU, blended on  [export]
1158.462789 [dev_pixelpipe] took 0.928 secs (0.544 CPU) processed `dithering' on CPU, blended on  [export]
1258.462829 [pixelpipe] export internal pixel pipeline processing took 39.492 secs (38.227 CPU)
1358.462898 [dev_process_export] pixel pipeline processing thread took 39.492 secs (38.227 CPU)
14[export_job] exported to `/home/aurelienpierre/Téléchargements/2022-06-17__DSC00078_08.jpg'

 1526,9861 [export] creating pixelpipe took 0,063 secs (0,091 CPU)
 2526,9862 [dev_pixelpipe] took 0,000 secs (0,000 CPU) initing base buffer [export]
 3527,0072 [dev_pixelpipe] took 0,021 secs (0,020 CPU) [export] processed `rawprepare' on GPU, blended on GPU
 4527,0237 [dev_pixelpipe] took 0,016 secs (0,007 CPU) [export] processed `temperature' on GPU, blended on GPU
 5530,7560 [dev_pixelpipe] took 3,732 secs (3,868 CPU) [export] processed `highlights' on GPU with tiling, blended on CPU
 6531,1444 [dev_pixelpipe] took 0,388 secs (0,201 CPU) [export] processed `demosaic' on GPU, blended on GPU
 7531,9899 [dev_pixelpipe] took 0,845 secs (0,493 CPU) [export] processed `lens' on GPU with tiling, blended on CPU
 8532,1378 [dev_pixelpipe] took 0,148 secs (0,139 CPU) [export] processed `exposure' on GPU, blended on GPU
 9532,1968 [dev_pixelpipe] took 0,059 secs (0,047 CPU) [export] processed `colorin' on GPU, blended on GPU
10532,2287 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_LAB-->IOP_CS_RGB took 0,031 secs (0,019 GPU) [channelmixerrgb]
11532,3206 [dev_pixelpipe] took 0,124 secs (0,089 CPU) [export] processed `channelmixerrgb' on GPU, blended on GPU
12575,5645 [dev_pixelpipe] took 43,244 secs (43,220 CPU) [export] processed `diffuse' on GPU with tiling, blended on CPU
13575,7422 [dev_pixelpipe] took 0,178 secs (0,167 CPU) [export] processed `colorbalancergb' on GPU, blended on GPU
14576,2975 [dev_pixelpipe] took 0,555 secs (0,474 CPU) [export] processed `filmicrgb' on GPU with tiling, blended on CPU
15576,3897 [resample_cl] took 0,000 secs (0,000 CPU) 1:1 copy/crop of 7968x5320 pixels
16576,4081 [dev_pixelpipe] took 0,111 secs (0,101 CPU) [export] processed `finalscale' on GPU, blended on GPU
17576,4403 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_RGB-->IOP_CS_LAB took 0,032 secs (0,020 GPU) [colorout]
18576,5618 [dev_pixelpipe] took 0,154 secs (0,120 CPU) [export] processed `colorout' on GPU, blended on GPU
19577,0202 [dev_pixelpipe] took 0,458 secs (0,456 CPU) [export] processed `dither' on CPU, blended on CPU
20577,0204 [dev_process_export] pixel pipeline processing took 50,034 secs (49,403 CPU)
21578,2407 [export_job] exported to `/home/aurelienpierre/Téléchargements/2022-06-17__DSC00078_06.jpg'

Dans Ansel, puisque nous avons ouvert l’image auparavant dans la chambre noire, les premières étapes du pipeline sont encore en cache, donc l’export démarre au module exposition et prend 39,5 s. Dans Darktable, eh bien… comme d’habitude : c’est un recalcul complet du pipeline qui prend 50 s.

Exporter à nouveau en demi-résolution

Nous exportons en demi-résolution juste après avoir exporté en pleine résolution.

• Ansel master GPU
• Darktable 5.4.1 GPU

165.601240 [dev_pixelpipe] took 0.000 secs (0.000 CPU) to load the image.
265.658874 [export] creating pixelpipe took 0.060 secs (0.079 CPU)
365.912677 [dev_pixelpipe] took 0.254 secs (0.233 CPU) processed `output color profile' on GPU, blended on  [export]
465.972780 [dev_pixelpipe] took 0.060 secs (0.073 CPU) processed `Final resampling' on GPU, blended on  [export]
566.160165 [dev_pixelpipe] took 0.187 secs (0.238 CPU) processed `dithering' on CPU, blended on  [export]
666.160184 [pixelpipe] export internal pixel pipeline processing took 0.501 secs (0.544 CPU)
766.160202 [dev_process_export] pixel pipeline processing thread took 0.501 secs (0.545 CPU)
8[export_job] exported to `/home/aurelienpierre/Téléchargements/2022-06-17__DSC00078_09.jpg'

 1607,7584 [export] creating pixelpipe took 0,064 secs (0,088 CPU)
 2607,7586 [dev_pixelpipe] took 0,000 secs (0,000 CPU) initing base buffer [export]
 3607,7918 [dev_pixelpipe] took 0,033 secs (0,028 CPU) [export] processed `rawprepare' on GPU, blended on GPU
 4607,8083 [dev_pixelpipe] took 0,016 secs (0,007 CPU) [export] processed `temperature' on GPU, blended on GPU
 5611,5555 [dev_pixelpipe] took 3,747 secs (3,865 CPU) [export] processed `highlights' on GPU with tiling, blended on CPU
 6611,9454 [dev_pixelpipe] took 0,390 secs (0,201 CPU) [export] processed `demosaic' on GPU, blended on GPU
 7612,7083 [dev_pixelpipe] took 0,763 secs (0,462 CPU) [export] processed `lens' on GPU with tiling, blended on CPU
 8612,8559 [dev_pixelpipe] took 0,148 secs (0,137 CPU) [export] processed `exposure' on GPU, blended on GPU
 9612,9149 [dev_pixelpipe] took 0,059 secs (0,045 CPU) [export] processed `colorin' on GPU, blended on GPU
10612,9468 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_LAB-->IOP_CS_RGB took 0,032 secs (0,021 GPU) [channelmixerrgb]
11613,0390 [dev_pixelpipe] took 0,124 secs (0,090 CPU) [export] processed `channelmixerrgb' on GPU, blended on GPU
12656,1897 [dev_pixelpipe] took 43,151 secs (42,852 CPU) [export] processed `diffuse' on GPU with tiling, blended on CPU
13656,3673 [dev_pixelpipe] took 0,178 secs (0,167 CPU) [export] processed `colorbalancergb' on GPU, blended on GPU
14656,9163 [dev_pixelpipe] took 0,549 secs (0,467 CPU) [export] processed `filmicrgb' on GPU with tiling, blended on CPU
15657,0078 [resample_cl] plan 0,001 secs (0,000 CPU) resample 0,001 secs (0,000 CPU)
16657,1070 [dev_pixelpipe] took 0,191 secs (0,181 CPU) [export] processed `finalscale' on GPU, blended on GPU
17657,1233 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_RGB-->IOP_CS_LAB took 0,016 secs (0,004 GPU) [colorout]
18657,1792 [dev_pixelpipe] took 0,072 secs (0,030 CPU) [export] processed `colorout' on GPU, blended on GPU
19657,3186 [dev_pixelpipe] took 0,139 secs (0,136 CPU) [export] processed `dither' on CPU, blended on CPU
20657,3187 [dev_process_export] pixel pipeline processing took 49,560 secs (48,669 CPU)
21657,8107 [export_job] exported to `/home/aurelienpierre/Téléchargements/2022-06-17__DSC00078_07.jpg'

Comme Ansel exporte toujours en pleine résolution jusqu’au module de rééchantillonnage final (le mode appelé « haute qualité » dans Darktable), le pipeline reste pour l’essentiel identique quelle que soit la taille finale. Comme le cache d’Ansel fonctionne, l’image pleine résolution précédemment exportée est encore en cache, donc nous ne recalculons que les dernières étapes : profil de couleur de sortie, réduction de résolution, tramage. Cela prend 0,5 s.

Darktable, comme d’habitude, ne gère pas ce qu’il a calculé auparavant, donc vous repartez pour un nouvel export complet de ~50 s. Autrement dit, une pénalité de performance de ×100.

Notez que le cache du pipeline d’Ansel possède un ramasse-miettes qui vide toutes les lignes de cache inutilisées depuis plus de 5 minutes, donc cela ne fonctionnerait plus si vous attendiez trop longtemps.

Conclusion

Il est assez hilarant de lire, sur des forums de tech-bros comme discuss.pixls.us , que des gens font davantage confiance à Darktable qu’à Ansel parce que le premier compte beaucoup plus de singes gesticulant dans tous les sens et faisant semblant de travailler, ce qui suffit apparemment à produire un sentiment totalement erroné de fiabilité et de confiance. C’est la preuve ultime que les gens n’ont aucune idée de ce qui se passe dans le code. Mais c’est une maladie capitaliste que de confondre agitation et travail, et un travail qui ne crée aucune valeur peut tout de même être vendu comme du progrès avec le marketing approprié.

Je ne fais pas dans l’opinion, je fais des benchmarks. Les chiffres que je publie ici peuvent être entièrement reproduits :

• individual modules are on average 1.4 times faster on Ansel CPU compared to Darktable CPU,
• individual modules are on average 1.6 times faster on Ansel GPU compared to Darktable GPU,
• full pipelines are anywhere between 1.5 times and 100 times faster on Ansel compared to Darktable GPU, because Ansel has a working cache,
• Ansel is not just faster, it’s also more energy-efficient, because fewer things are (re)computed.

Tout cela a été obtenu en retirant le code d’interface du code de rendu du pipeline, en rendant le cycle de vie des données plus clair, plus simple et plus robuste, et non en ajoutant davantage de cas particuliers et de contournements. Ansel est capable d’utiliser bien plus de RAM que Darktable, tout en tenant la comptabilité nécessaire pour savoir combien il utilise réellement et s’il doit commencer à recycler de la mémoire.

Tout cela prouve que « l’équipe » Darktable n’améliore pas le logiciel et que son absence de gestion nuit activement au logiciel. De nombreuses « optimisations » ont été annoncées dans les notes de version depuis 2022. Et pourtant, leur logiciel reste une bête d’inefficacité douloureusement lente.

Notez que les optimisations module par module réalisées dans Darktable peuvent être rétroportées dans Ansel, même si, au vu de ce qui est montré ici, toutes ne semblent pas correspondre à de vrais gains de vitesse. Certaines l’ont déjà été. En revanche, Darktable ne peut pas rétroporter l’architecture de pipeline d’Ansel, d’où provient l’essentiel de nos gains.

Au cours de ce travail, j’ai aussi perdu foi en Vkdt . Vkdt est une nouvelle tentative, par le fondateur de Darktable Johannes Hanika, de redémarrer un logiciel photo RAW depuis zéro et de le faire fonctionner entièrement sur GPU via Vulkan. Mais après 4 ans passés à nettoyer la merde des autres, il y a deux ou trois choses que j’ai apprises :

1. Les ralentissements de Darktable ne sont pas à mettre sur le dos de la pile GTK ni de la pile OpenCL. Certes, elles ne sont pas extraordinaires, mais cela se gère. Le problème vient d’erreurs de programmation et d’une mauvaise conception qui n’a pas été réévaluée à mesure que les besoins et les exigences du logiciel évoluaient.
2. Une conception orientée cache permet de masquer de nombreuses latences en évitant les recalculs, et un flux de travail entièrement sur GPU se heurtera bientôt aux limites mémoire des GPU.
3. Les GPU deviennent de plus en plus chers, après la ruée sur les cryptomonnaies et maintenant la ruée sur l’IA.
4. Ce qui a tué Darktable, c’est l’absence de gestion et l’absence de vision, une culture du « laissez-faire » et du hasard joyeux qui ne fonctionne qu’avec une poignée de développeurs se connaissant tous. Vkdt prend la même direction. Si le code et les fonctionnalités peuvent croître sans priorités ni resserrement des API, c’est un train qui déraille au ralenti. « plus récent = meilleur » n’est qu’un état transitoire. Le véritable défi, c’est de gérer la croissance.

Du point de vue du développeur, Darktable souffre de 3 maladies principales :

1. Ses développeurs manquent complètement, et depuis longtemps, des capacités d’abstraction nécessaires pour distinguer mentalement ce qui relève de la couche d’interface graphique et ce qui relève de la couche backend. Ainsi, on trouve des états GUI/GTK incrustés au plus profond du backend, ce qui est d’autant plus agaçant que darktable-cli fonctionne sans interface et oblige à gérer les deux modes. Mais on retrouve aussi sans cesse des problèmes d’interface « résolus » dans le backend, et inversement. Cela déclenche de vrais problèmes de fiabilité, en plus de rendre l’ensemble compliqué, illisible et emmêlé.
2. Ses développeurs ne comprennent pas le concept d’API privées et d’encapsulation : toutes les structures de données sont publiques, tous les fichiers d’en-tête sont importés dans l’ensemble du logiciel, si bien que tout le logiciel connaît tout le logiciel et est autorisé à modifier les structures de données sur place depuis n’importe où dans le code.
3. La complexité est « résolue » par davantage de complexité, et personne ne semble y voir un problème appelé dette technique.

Les bases de code saines protègent les données en les rendant privées et en imposant les interactions via des fonctions getter/setter définies comme API publiques. Cela permet de gérer facilement la sûreté vis-à-vis des threads quand le besoin apparaît, mais aussi de suivre depuis un point central qui écrit où et quand. Ensuite, on n’inclut dans chaque fichier que le jeu minimal d’API nécessaire, afin d’isoler le code autant que possible.

Au lieu de cela, le code source de Darktable écrit partout depuis n’importe où, sans interfaces correctes. Donc le moindre changement dans la base de code de Darktable déclenche systématiquement des effets de bord et casse quelque chose d’inattendu à l’autre bout du logiciel, dans des séances déprimantes de whack-a-mole nées de la paresse et de la stupidité.

C’est pourquoi beaucoup de travail ingrat a été réalisé dans Ansel pour resserrer les API, privatiser autant de structures de données que possible et isoler les bibliothèques les unes des autres afin de démêler quelque peu le graphe de dépendances.

Annexe : les schémas

Architecture générale

Voici l’organigramme de haut niveau de toute l’architecture, de la base de données jusqu’aux tampons de sortie. Nous pouvons enfin dessiner un schéma de ce bazar.

flowchart TD
  subgraph Module
    M["Module instance
dt_iop_module_t"]
  end

  subgraph Develop
    H["dev->history
history items"]
    D["dt_develop_t
history_end
history_hash"]
  end

  subgraph Persist["DB + image cache"]
    DB["SQLite history tables"]
    IC["image cache
dt_image_t"]
  end

  subgraph Pipeline
    F["Pipe dirty flags"]
    P["Pipe nodes / pieces"]
    G["global_hash"]
    B["Backbuf"]
  end

  subgraph Cache
    C["Pixelpipe cache"]
  end

  subgraph Consumers["Backbuffer consumers"]
    DR["darkroom.c"]
    NAV["navigation.c"]
    EXP["imageio.c"]
  end

  M -->|"write snapshot
dt_dev_add_history_item_real()"| H
  H -->|"update history_end / history_hash
dt_dev_add_history_item_real()"| D

  D -->|"write history
dt_dev_write_history_ext()"| DB
  D -->|"write image-side hash
dt_dev_write_history_ext()"| IC

  DB -.->|"read history
dt_dev_read_history_ext()"| H
  IC -.->|"read image metadata
dt_dev_read_history_ext()"| H

  H -->|"apply to modules
dt_dev_pop_history_items_ext()"| M

  D -->|"mark pipes dirty
dt_dev_add_history_item_real()"| F
  D -->|"check history mismatch
dt_dev_darkroom_pipeline()"| F

  H -->|"sync history into pipe
dt_dev_pixelpipe_change()"| P
  F -->|"consume dirty flags
dt_dev_pixelpipe_change()"| P

  P -->|"compute cache keys
dt_pixelpipe_get_global_hash()"| G
  G -->|"key cache entries
dt_dev_pixelpipe_process_rec()"| C

  C -.->|"read exact-hit / input
dt_dev_pixelpipe_process_rec()"| P
  P -->|"publish stage output
dt_dev_pixelpipe_process_rec()"| C

  C -->|"promote final output
dt_dev_pixelpipe_process()"| B

  B -->|"borrow main/preview backbuf
_darkroom_expose()"| DR
  B -->|"copy preview backbuf
_lib_navigation_draw_callback()"| NAV
  B -->|"borrow export backbuf
dt_imageio_export_with_flags()"| EXP

  EXP -->|"update mipmap hash
dt_imageio_export_with_flags()"| IC

Gestion de la mémoire RAM/vRAM

Gestion des tampons du cache :

flowchart TD
  H["CPU RAM buffer"]
  P["Pinned vRAM buffer
CL_MEM_USE_HOST_PTR"]
  V["Device-only vRAM buffer"]
  G["pixelpipe_process_on_GPU()"]
  C["pixelpipe_process_on_CPU()"]

  H -->|"prepare GPU input
dt_dev_pixelpipe_cache_prepare_cl_input()"| P
  P -->|"sync host/device if needed
dt_dev_pixelpipe_cache_sync_cl_buffer()"| G

  V -->|"reuse existing vRAM input
dt_dev_pixelpipe_cache_prepare_cl_input()"| G

  G -->|"publish pinned output
dt_dev_pixelpipe_cache_release_cl_buffer()"| P
  G -->|"publish device-only output
dt_dev_pixelpipe_cache_release_cl_buffer()"| V

  V -->|"GPU to CPU fallback copy
dt_dev_pixelpipe_cache_restore_cl_buffer()"| H
  H -->|"resume CPU processing
pixelpipe_process_on_CPU()"| C

Si la sortie du module est destinée à être mise en cache, en raison des préférences utilisateur, du besoin de ce tampon pour l’histogramme ou la pipette couleur, ou parce que le module suivant est celui qui est actif dans l’interface, OpenCL utilise un tampon mémoire épinglé, épinglé sur le cache RAM. Nous épinglons aussi les tampons d’entrée lorsque le GPU prend ses entrées depuis le cache RAM. C’est légèrement plus coûteux que d’utiliser un simple tampon réservé au périphérique, mais moins coûteux que de recopier ce tampon réservé au périphérique vers l’hôte. Si la sortie OpenCL n’est pas destinée à être mise en cache, nous utilisons un tampon réservé au périphérique qui pourra être recyclé plus tard mais ne sera jamais copié en RAM.

En cas d’erreur OpenCL sur un module donné, la plus évidente étant un manque de mémoire, le tampon d’entrée GPU est recopié de manière transparente dans le cache RAM avant de basculer vers le chemin d’exécution purement CPU.

Tous ces tampons sont suivis par des entrées de cache, qui associent un tampon RAM à un tampon vRAM, si les deux sont utilisés dans une situation épinglée, ou se contentent de suivre ce qui est alloué. Si une allocation mémoire GPU échoue, nous parcourons d’abord le cache pour libérer tous les tampons précédemment alloués. Si l’allocation mémoire GPU échoue encore après cela, nous revenons au CPU.

Entrées de cache

Le cache est une table de hachage d’entrées de cache. Leur clé est un hash ou une somme de contrôle. Nous avons 2 types d’entrées de cache :

• les internes, utilisées comme tampons réutilisables pour les entrées/sorties des modules,
• les externes, utilisées comme tampons jetables pour les calculs intermédiaires des modules.

Les entrées de cache internes sont indexées par le global_hash de leur module parent et peuvent être retrouvées plus tard, même depuis l’interface, parce que ce hash reste stable d’une exécution à l’autre et d’un pipeline à l’autre. Elles peuvent être réindexées si nous réutilisons leur tampon mémoire, afin que la nouvelle clé corresponde au nouvel état du module parent. Ces entrées de cache peuvent être verrouillées en lecture ou en écriture pour permettre un accès concurrent sûr entre threads parallèles. Un verrou d’écriture ne peut être pris que par un seul thread si aucun autre ne lit, tandis qu’un verrou de lecture peut être pris par plusieurs threads si aucun n’écrit. Comme le verrou d’écriture est relâché par le module qui écrit sa sortie avant que le verrou de lecture ne soit acquis par le module qui utilise la même entrée de cache comme entrée, avec un risque de suppression entre les deux, elles disposent aussi d’un mécanisme de refcount : le producteur de l’entrée de cache l’incrémente, le consommateur la décrémente. Le même mécanisme est utilisé par la chambre noire pour récupérer le backbuffer sans copie.

Les entrées de cache externes sont indexées par l’adresse mémoire de leur tampon de données. Elles sont supposées être de courte durée de vie.

L’ajout ou la suppression d’entrées de cache incrémente ou décrémente automatiquement la taille globale du cache. Nous continuons à ajouter de nouvelles entrées tant que la taille globale du cache reste sous le seuil autorisé, après quoi nous commençons à détruire les plus anciennes si leur refcount vaut 0 et qu’elles ne sont pas verrouillées.

flowchart TD
  A["absent"]
  B["reserved for write
refcount + 1
write-locked"]
  C["published
exact-hit eligible"]
  D["borrowed by consumer
refcount > 0"]
  E["backbuf-held
one display ref kept"]
  F["auto-destroy flagged"]
  G["removed / freed"]

  A -->|"create new entry
dt_dev_pixelpipe_cache_get()
dt_dev_pixelpipe_cache_get_writable()"| B
  C -->|"rekey reusable entry
dt_dev_pixelpipe_cache_get_writable()
dt_dev_pixelpipe_cache_rekey()"| B

  B -->|"backend finishes and unlocks
dt_dev_pixelpipe_process_rec()"| C

  C -->|"exact-hit / reopen / GUI read-only
dt_dev_pixelpipe_cache_peek()
dt_dev_pixelpipe_cache_get_read_only()"| D
  D -->|"release consumer ref
dt_dev_pixelpipe_cache_unref_hash()
dt_dev_pixelpipe_cache_close_read_only()"| C

  C -->|"keep final output alive for display
_update_backbuf_cache_reference()"| E
  E -->|"backbuf changes or invalidates
_update_backbuf_cache_reference()"| C

  C -->|"mark transient output
dt_dev_pixelpipe_cache_flag_auto_destroy()"| F
  F -->|"reap when no ref and no lock remain
dt_dev_pixelpipe_cache_auto_destroy_apply()"| G

  C -->|"explicit remove / GC / LRU
dt_dev_pixelpipe_cache_remove()
dt_dev_pixelpipe_cache_flush_old()
dt_dev_pixel_pipe_cache_remove_lru()"| G
  C -->|"invalid payload detected
dt_dev_pixelpipe_cache_peek()"| G

Une entrée de cache ne connaît pas la nature des données qu’elle contient. Elle ne connaît que l’adresse des tampons, leur taille, leur compteur de références et leur état de verrouillage. C’est donc une abstraction générique de choses stockées en mémoire.