Darktable speed


#21

Hi chiraag, thanks for an interesting workaroud. I may use this when working on my 15-inch laptop (which isn’t often), but my main desktop display is a 31-inch one, so unfortunately 1920x1080 would be too huge and ugly.

Weird thing though - with resolution set to 1920x1080 lighttable seems a bit snappier than on full 4K with darktable window resized to one quarter of the screen (which should result to about the same number of the redrawn pixels). Maybe something else is in play as well.


(ಚಿರಾಗ್ ನಟರಾಜ್) #22

firejail does not slow down darktable at all (one of the first things I tried was running darktable without firejail - it didn’t help). I’ve never noticed a performance impact of firejail on any application (including darktable).


(ಚಿರಾಗ್ ನಟರಾಜ್) #23

What is your native resolution? I use awesome window manager, so if I hide the top bar, the only indication that anything’s changed is that the wallpaper looks horrendous. But given that I reset it right back after darktable ends, as long as I don’t switch applications, I don’t think anything should be too noticeable? I think anything that’s DPI-aware shouldn’t have too many problems (although you would have to reset e.g. GDK_SCALE if you want to start a new program while darktable is running).

Huh, that is weird. I wouldn’t really know since I use a tiling window manager (so I don’t normally resize clients manually).


(Pascal Obry) #24

Driver Nouveau has poor perfs on 4K display maybe? Have you tried the proprietary Nvidia driver?


(ಚಿರಾಗ್ ನಟರಾಜ್) #25
  1. I was initially running this on my on-board GPU (Intel).
  2. No other application had problems with 4K, either on nouveau or intel.
  3. I switched to running the Nvidia driver because I wanted OpenCL.
  4. Neither of those had an effect on darktable’s issue with 4K monitors. Changing the resolution did.

#26

My native resolution is 4096x2160. I wasn’t able to set the resolution to exactly half (2048x1080), looks like my GPU card does not support it. But anyway, I tested with 1920x1080 and the pixels are just too large on the 31 inch display - the fonts look ugly etc. Also I often switch windows from darktable to a file manager etc, so unfortunately this solution is not suitable for me.

FYI I’m using Radeon RX-480 with the AMDGPU-PRO driver.


(ಚಿರಾಗ್ ನಟರಾಜ್) #27

Damn, that’s a pity.

Yeah, that makes sense. For me, if I’m in darktable, I often don’t leave it until I’m done editing my photos. Here’s to hoping performance is fixed on 4K monitors in the near future :beers:


(Mica) #28

To fix it, we’d need to know exactly what is wrong, that it is actually a problem in darktable and not in another library in debian sid or a gtk issue. So best as I can see, there isn’t information this precise, but sounds like you’re narrowing it down.

Have you tried to run strace yet? What version of GTK is running in sid?


(Roman Lebedev) #29

It’s https://redmine.darktable.org/issues/10764.
That is a true, valid issue. That code is … retarded, not in a good way.


(ಚಿರಾಗ್ ನಟರಾಜ್) #30

Most likely it’s tied to this (especially since changing the resolution largely fixes the problem). I can certainly upload strace logs here or to that bug report…which is preferred? The current version of GTK+ is 3.22.26 in sid, but I’m pretty sure (looking at the changelog) that there hasn’t been an update to libgtk-3-0 since November (and my old laptop died towards the end of January).


(ಚಿರಾಗ್ ನಟರಾಜ್) #31

I’d love to help resolve this issue in any way I can :slight_smile: What needs to happen for progress to be made on this? Will this require refactoring a large portion or is this a fairly self-contained issue?


(Mica) #32

I stand corrected, sorry @chiraag! Thanks @LebedevRI


(Pascal Obry) #33

To assess if this is really only the redraw lightable issue you may want to try this branch:

Note that this is not a proper fix (has some redraw issue IIRC) and it won’t be merged. But if testing this code you do not see anymore the sluggishness of the lighttable then we are talking about the same issue.


#34

Thanks for this suggestion, I’ve compiled the faster-lighttable branch and tested. There is some change, but unfortunately it didn’t solve the slow responsiveness problem. Although it helped with the high CPU usage when mouse moves only within the same thumbnail:

On regular dt 2.4.1 log like this (with “-d all”) keeps repeating whenever mouse moves inside one thumb:

[sql] /build/darktable-CEnZBI/darktable-2.4.1/src/common/image.c:632, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0244 sec
[sql] /build/darktable-CEnZBI/darktable-2.4.1/src/common/image.c:632, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0248 sec
[sql] /build/darktable-CEnZBI/darktable-2.4.1/src/common/image.c:632, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0284 sec
[sql] /build/darktable-CEnZBI/darktable-2.4.1/src/common/image.c:632, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0305 sec
[sql] /build/darktable-CEnZBI/darktable-2.4.1/src/common/image.c:632, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0270 sec
[sql] /build/darktable-CEnZBI/darktable-2.4.1/src/common/image.c:632, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0253 sec
[sql] /build/darktable-CEnZBI/darktable-2.4.1/src/common/image.c:632, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0249 sec
[sql] /build/darktable-CEnZBI/darktable-2.4.1/src/common/image.c:632, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0245 sec
[sql] /build/darktable-CEnZBI/darktable-2.4.1/src/common/image.c:632, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0134 sec
[sql] /build/darktable-CEnZBI/darktable-2.4.1/src/common/image.c:632, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0134 sec
[sql] /build/darktable-CEnZBI/darktable-2.4.1/src/common/image.c:632, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0141 sec
[sql] /build/darktable-CEnZBI/darktable-2.4.1/src/common/image.c:632, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0156 sec
[mipmap_cache] thumbs fill 98,88/2048,00 MB (4,83%)
[mipmap_cache] float fill 0/4 slots (0,00%)
[mipmap_cache] full  fill 1/4 slots (25,00%)
[mipmap_cache] level | near match | miss | stand-in | fetches | total rq
[mipmap_cache] thumb |   3,23% |   3,23% |   -nan%  |   0,00% | 100,00%
[mipmap_cache] float |   -nan% |   -nan% |   -nan%  |   0,00% |   0,00%
[mipmap_cache] full  |   -nan% |   -nan% |   -nan%  | 100,00% |   0,00%


[lighttable] expose took 0,2732 sec

With faster-lighttable log changes to only this (again, repeating while mouse moves):
[lighttable] expose took 0,0000 sec

Also the CPU consumption went down from ~200% to ~40% (on a quad-core intel i5). This does not affect the user experience much, but indeed lowers the overall CPU usage.

Hovever when moving between thumbs (with mouse or with an arrow key) the CPU usage is still around 200% and this is logged once on every jump to a neighbouring thumb:

[sql] /home/mimo/tmp/dt/darktable/src/libs/metadata_view.c:222, function _metadata_view_update_values(): prepare "SELECT imgid FROM main.selected_images LIMIT 1"
[sql] /home/mimo/tmp/dt/darktable/src/common/image.c:151, function dt_image_film_roll(): prepare "SELECT folder FROM main.film_rolls WHERE id = ?1"
[sql] /home/mimo/tmp/dt/darktable/src/common/image.c:196, function dt_image_full_path(): prepare "SELECT folder || '/' || filename FROM main.images i, main.film_rolls f WHERE i.film_id = f.id and i.id = ?1"
[sql] /home/mimo/tmp/dt/darktable/src/common/metadata.c:179, function dt_metadata_get_xmp(): prepare "SELECT value FROM main.meta_data WHERE id = ?1 AND key = ?2 ORDER BY value"
[sql] /home/mimo/tmp/dt/darktable/src/common/metadata.c:179, function dt_metadata_get_xmp(): prepare "SELECT value FROM main.meta_data WHERE id = ?1 AND key = ?2 ORDER BY value"
[sql] /home/mimo/tmp/dt/darktable/src/common/metadata.c:179, function dt_metadata_get_xmp(): prepare "SELECT value FROM main.meta_data WHERE id = ?1 AND key = ?2 ORDER BY value"
[sql] /home/mimo/tmp/dt/darktable/src/common/tags.c:351, function dt_tag_get_attached(): prepare "SELECT DISTINCT T.id, T.name FROM main.tagged_images AS I, data.tags AS T WHERE I.imgid IN (SELECT imgid FROM main.selected_images) AND T.id = I.tagid ORDER BY T.name"
[sql] /home/mimo/tmp/dt/darktable/src/common/image.c:675, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0248 sec
[sql] /home/mimo/tmp/dt/darktable/src/common/image.c:675, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0246 sec
[sql] /home/mimo/tmp/dt/darktable/src/common/image.c:675, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0256 sec
[sql] /home/mimo/tmp/dt/darktable/src/common/image.c:675, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0274 sec
[sql] /home/mimo/tmp/dt/darktable/src/common/image.c:675, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0268 sec
[sql] /home/mimo/tmp/dt/darktable/src/common/image.c:151, function dt_image_film_roll(): prepare "SELECT folder FROM main.film_rolls WHERE id = ?1"
[sql] /home/mimo/tmp/dt/darktable/src/common/image.c:196, function dt_image_full_path(): prepare "SELECT folder || '/' || filename FROM main.images i, main.film_rolls f WHERE i.film_id = f.id and i.id = ?1"
[sql] /home/mimo/tmp/dt/darktable/src/common/metadata.c:179, function dt_metadata_get_xmp(): prepare "SELECT value FROM main.meta_data WHERE id = ?1 AND key = ?2 ORDER BY value"
[sql] /home/mimo/tmp/dt/darktable/src/common/metadata.c:179, function dt_metadata_get_xmp(): prepare "SELECT value FROM main.meta_data WHERE id = ?1 AND key = ?2 ORDER BY value"
[sql] /home/mimo/tmp/dt/darktable/src/common/metadata.c:179, function dt_metadata_get_xmp(): prepare "SELECT value FROM main.meta_data WHERE id = ?1 AND key = ?2 ORDER BY value"
[sql] /home/mimo/tmp/dt/darktable/src/common/tags.c:333, function dt_tag_get_attached(): prepare "SELECT DISTINCT T.id, T.name FROM main.tagged_images AS I JOIN data.tags T on T.id = I.tagid WHERE I.imgid = 4430  ORDER BY T.name"
[sql] /home/mimo/tmp/dt/darktable/src/common/image.c:675, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0249 sec
[sql] /home/mimo/tmp/dt/darktable/src/common/image.c:675, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0245 sec
[sql] /home/mimo/tmp/dt/darktable/src/common/image.c:675, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0245 sec
[sql] /home/mimo/tmp/dt/darktable/src/common/image.c:675, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0135 sec
[sql] /home/mimo/tmp/dt/darktable/src/common/image.c:675, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0135 sec
[sql] /home/mimo/tmp/dt/darktable/src/common/image.c:675, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0170 sec
[sql] /home/mimo/tmp/dt/darktable/src/common/image.c:675, function dt_image_altered(): prepare "SELECT operation FROM main.history WHERE imgid = ?1"
[lighttable] image expose took 0,0138 sec
[mipmap_cache] thumbs fill 98,88/2048,00 MB (4,83%)
[mipmap_cache] float fill 0/4 slots (0,00%)
[mipmap_cache] full  fill 1/4 slots (25,00%)
[mipmap_cache] level | near match | miss | stand-in | fetches | total rq
[mipmap_cache] thumb |   1,79% |   1,79% |   -nan%  |   0,00% | 100,00%
[mipmap_cache] float |   -nan% |   -nan% |   -nan%  |   0,00% |   0,00%
[mipmap_cache] full  |   -nan% |   -nan% |   -nan%  | 100,00% |   0,00%


[lighttable] expose took 0,2702 sec

So it seems that the actual slow-down is caused by “expose” when skipping to next thumb, not the constant redraw. Quarter of a second may not seem like much, but when mouse moves quickly by several thumbs the highlight can take up to few seconds to catch up.

Is this something that can be optimized, or maybe influenced by some configuration? Thanks!


(Pascal Obry) #35

Thanks for the experiment. I’m not sure there configuration option to optimize this.


#36

I tried to profile darktable with valgrind/kcachegrind (just moving around in lighttable) and I’ve found that a lot of time was spent somewhere in liblcms2. darktablerc setting cache_color_managed sounds like it could be related, so I tried to disable it - I guess I can live without color managed thumbnails if that means better responsiveness. Indeed liblcms2 calls disappeared from the profiler output and it had some positive effect (roughly 25-30% faster expose), but unfortunately it’s still not enough to make lighttable feel comfortably fast:

With cache_color_managed=TRUE:
[lighttable] expose took 0,2752 sec

With cache_color_managed=FALSE:
[lighttable] expose took 0,1912 sec

The top kcachegrind calls (sorted by Self) now look like this:

Is anyone able to describe what exactly is done when one moves around lighttable? From a layman’s point of view it seems like dt does a whole lot of processing for what appears like highliting a differnt thumbnail and displaying its metadata. But I understand it may need to do a lot of “invisible” things.


#37

As @LebedevRI and others said, the code is stupid and recomputes a lot of things all the time. The whole logic needs to be rewritten I guess. A big task no one has dared to start yet.


#38

Thanks, that makes sense.

Seems I’ve found a strange sweet spot for the lighttable zoom - having 5x3 thumbs on screen gives me the best response speed, with disabled color management expose takes just 0.04s, which is actually quite usable. Anything smaller or larger results in significantly worse delays (between 0.15s and 0.2s).

Also FWIW I’ve found that the faster-lighttable branch actually does have impact on user experience. With the regular build it often happens that I move the mouse to a neigbouring thumbnail and stop there, but the highlight stays on the previous thumb. I have to move the mouse again a bit to update. This does not happen with faster-lighttable.


(Glenn Butcher) #39

Yes, I found all sorts of little decisions when putting LittleCMS in rawproc that affected display times, e.g., don’t transform the floating point native image for display, wait until it’s been converted to the 8-bit/channel wxImage. Further, if it has to be cropped for a high display magnification, wait for that operation and transform the smaller image.

I also put in a property called display.cms.transform if =set do the display transform when the display image is set by the processing pipeline, if =render do the display transform at each display change, e.g. pan or zoom. Jury is still out on the usefulness of this setting.

Finally, in my colorspace tool instead of cmsTransform-ing the whole image I let the OpenMP break it into chunks and send them to the cores. LittleCMS uses pthreads somehow, but it’s not evident in the speedup I get just using OpenMP. I’m gradually making all my cmsTransforms OpenMP-chunkable, all done for the next release.

Yes, I could be putting these brain cells to better use doing this for darktable. I’m considering digging into the dt codebase, but it may have to wait until my day job is no longer part of my day… :smile:


#40

For the thumbnails we are talking about, that’s what is already done in darktable.

Those thumbnails are coming from an image cache and are not fetched from the processing pipeline directly. They might also come from the disk cache. So in order to show the right colors even when changing monitors we keep the thumbnails in either sRGB or AdobeRGB and transform them whenever they are shown. Of course, we could transform them to the display profile when loading the file, but then we would have to invalidate the whole cache whenever the display profile changes.

darktable already does that.