Closed thierry0601 closed 2 months ago
ralfbrown
commented
2 months ago Since we haven't had any other reports of this kind of slowness, it's probably something specific to your system. To rule out an issue with the darktable database, do you still have the slowness if you rename the darktable configuration directory (so it creates fresh, default copies) and import a folder's worth of images? The config directory will typically be C:\Users\<username>\AppData\Local\darktable.
thierry0601
commented
2 months ago Hello, Thanks a lot for your very quick feedback. You proposed a very good test to narrow the issue. Unfortunately I have exactely the same behaviour after a directory rename and a reload of 1000 pictures (JPG of 8GB each) Best Regards
kofa73
commented
2 months ago Either those are gigantic JPGs, or something's wrong.
Also, your performance log misses lots of details.
Maybe try pasting it between ``` marks. This is what I get (with -d opencl -d perf) when I open an image in the darkroom:
```
8.1654 [dt_dev_load_raw] loading the image. took 0.011 secs (0.016 CPU)
8.6927 [histogram] took 0.000 secs (0.000 CPU) scope draw
8.7300 [dt_dev_process_image_job] loading image. took 0.000 secs (0.000 CPU)
8.7470 [dev_pixelpipe] took 0.000 secs (0.000 CPU) initing base buffer [full]
8.7488 [dev_pixelpipe] took 0.002 secs (0.002 CPU) [full] processed `rawprepare' on GPU, blended on GPU
8.7496 [dev_pixelpipe] took 0.001 secs (0.000 CPU) [full] processed `temperature' on GPU, blended on GPU
8.7517 [dev_pixelpipe] took 0.002 secs (0.000 CPU) [full] processed `highlights' on GPU, blended on GPU
8.7590 [resample_cl] plan 0.000 secs (0.001 CPU) resample 0.000 secs (0.000 CPU)
8.7677 [dev_pixelpipe] took 0.016 secs (0.012 CPU) [full] processed `demosaic' on GPU, blended on GPU
8.7692 [dev_pixelpipe] took 0.001 secs (0.001 CPU) [full] processed `exposure' on GPU, blended on GPU
8.7724 [dev_pixelpipe] took 0.003 secs (0.001 CPU) [full] processed `colorin' on GPU, blended on GPU
8.7752 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_LAB-->IOP_CS_RGB took 0.002 secs (0.001 GPU) [channelmixerrgb]
8.7813 [dev_pixelpipe] took 0.009 secs (0.008 CPU) [full] processed `channelmixerrgb' on GPU, blended on GPU
8.7861 [dev_pixelpipe] took 0.005 secs (0.008 CPU) [full] processed `filmicrgb' on GPU, blended on GPU
8.7866 [histogram] took 0.000 secs (0.000 CPU) scope draw
8.8256 [dt_ioppr_transform_image_colorspace] IOP_CS_RGB-->IOP_CS_LAB took 0.005 secs (0.038 CPU) [colorout]
8.8425 [histogram] took 0.000 secs (0.000 CPU) scope draw
8.9017 [dev_pixelpipe] took 0.116 secs (0.763 CPU) [full] processed `colorout' on CPU, blended on CPU
8.9106 [dev_pixelpipe] took 0.009 secs (0.056 CPU) [full] processed `gamma' on CPU, blended on CPU
8.9106 [opencl_profiling] profiling device 0 ('NVIDIA CUDA NVIDIA GeForce GTX 1060 6GB'):
8.9106 [opencl_profiling] spent 0.0006 seconds in [Write Image (from host to device)]
8.9106 [opencl_profiling] spent 0.0001 seconds in rawprepare_1f
8.9106 [opencl_profiling] spent 0.0001 seconds in whitebalance_1f
8.9106 [opencl_profiling] spent 0.0001 seconds in highlights_initmask
8.9106 [opencl_profiling] spent 0.0001 seconds in highlights_dilatemask
8.9106 [opencl_profiling] spent 0.0000 seconds in [Write Buffer (from host to device)]
8.9106 [opencl_profiling] spent 0.0009 seconds in highlights_chroma
8.9106 [opencl_profiling] spent 0.0000 seconds in [Read Buffer (from device to host)]
8.9106 [opencl_profiling] spent 0.0002 seconds in highlights_opposed
8.9106 [opencl_profiling] spent 0.0001 seconds in border_interpolate
8.9106 [opencl_profiling] spent 0.0002 seconds in rcd_border_green
8.9107 [opencl_profiling] spent 0.0003 seconds in rcd_border_redblue
8.9107 [opencl_profiling] spent 0.0003 seconds in rcd_populate
8.9107 [opencl_profiling] spent 0.0002 seconds in rcd_step_1_1
8.9107 [opencl_profiling] spent 0.0002 seconds in rcd_step_1_2
8.9107 [opencl_profiling] spent 0.0001 seconds in rcd_step_2_1
8.9107 [opencl_profiling] spent 0.0003 seconds in rcd_step_3_1
8.9107 [opencl_profiling] spent 0.0002 seconds in rcd_step_4_1
8.9107 [opencl_profiling] spent 0.0001 seconds in rcd_step_4_2
8.9107 [opencl_profiling] spent 0.0003 seconds in rcd_step_5_1
8.9107 [opencl_profiling] spent 0.0004 seconds in rcd_step_5_2
8.9107 [opencl_profiling] spent 0.0004 seconds in rcd_write_output
8.9107 [opencl_profiling] spent 0.0076 seconds in interpolation_resample
8.9107 [opencl_profiling] spent 0.0009 seconds in exposure
8.9107 [opencl_profiling] spent 0.0010 seconds in colorin_unbound
8.9107 [opencl_profiling] spent 0.0009 seconds in [Copy Image (on device)]
8.9107 [opencl_profiling] spent 0.0009 seconds in colorspaces_transform_lab_to_rgb_matrix
8.9107 [opencl_profiling] spent 0.0010 seconds in channelmixerrgb_CAT16
8.9107 [opencl_profiling] spent 0.0006 seconds in filmic_mask_clipped_pixels
8.9107 [opencl_profiling] spent 0.0013 seconds in filmicrgb_chroma
8.9107 [opencl_profiling] spent 0.0332 seconds in [Read Image (from device to host)]
8.9107 [opencl_profiling] spent 0.0526 seconds totally in command queue (with 0 events missing)
8.9179 [dev_process_image] pixel pipeline took 0.171 secs (0.852 CPU) processing `2024-07-14-15-18-34-P1040073.RW2'
8.9222 [histogram] took 0.000 secs (0.000 CPU) scope draw
8.9313 [dt_dev_process_image_job] loading image. took 0.000 secs (0.000 CPU)
8.9313 [dt_dev_process_image_job] loading image. took 0.000 secs (0.000 CPU)
8.9419 [dev_process_image] pixel pipeline took 0.011 secs (0.028 CPU) processing `2024-07-14-15-18-34-P1040073.RW2'
8.9539 [histogram] took 0.000 secs (0.000 CPU) scope draw
8.9572 [dt_dev_process_image_job] loading image. took 0.000 secs (0.000 CPU)
8.9763 [dev_pixelpipe] took 0.000 secs (0.000 CPU) initing base buffer [preview]
8.9776 [dev_pixelpipe] took 0.001 secs (0.001 CPU) [preview] processed `rawprepare' on GPU, blended on GPU
8.9782 [dev_pixelpipe] took 0.001 secs (0.000 CPU) [preview] processed `temperature' on GPU, blended on GPU
8.9789 [dev_pixelpipe] took 0.001 secs (0.000 CPU) [preview] processed `highlights' on GPU, blended on GPU
8.9825 [dev_pixelpipe] took 0.004 secs (0.002 CPU) [preview] processed `demosaic' on GPU, blended on GPU
8.9832 [dev_pixelpipe] took 0.001 secs (0.000 CPU) [preview] processed `exposure' on GPU, blended on GPU
8.9848 [dev_pixelpipe] took 0.002 secs (0.000 CPU) [preview] processed `colorin' on GPU, blended on GPU
8.9867 [dt_ioppr_transform_image_colorspace_cl] IOP_CS_LAB-->IOP_CS_RGB took 0.002 secs (0.000 GPU) [channelmixerrgb]
8.9881 [dev_pixelpipe] took 0.003 secs (0.000 CPU) [preview] processed `channelmixerrgb' on GPU, blended on GPU
8.9910 [dev_pixelpipe] took 0.003 secs (0.001 CPU) [preview] processed `filmicrgb' on GPU, blended on GPU
9.0011 [dt_ioppr_transform_image_colorspace] IOP_CS_RGB-->IOP_CS_LAB took 0.001 secs (0.011 CPU) [colorout]
9.0242 [dev_pixelpipe] took 0.033 secs (0.196 CPU) [preview] processed `colorout' on CPU, blended on CPU
9.0264 [dev_pixelpipe] took 0.002 secs (0.015 CPU) [preview] processed `gamma' on CPU, blended on CPU
9.0580 [dt_ioppr_transform_image_colorspace_rgb_lcms2] `system display profile' -> `linear Rec2020 RGB' took 0.031 secs (0.252 CPU) [final histogram]
9.1231 [histogram] took 0.097 secs (0.327 CPU) final RGB parade
9.1231 [opencl_profiling] profiling device 0 ('NVIDIA CUDA NVIDIA GeForce GTX 1060 6GB'):
9.1231 [opencl_profiling] spent 0.0002 seconds in [Write Image (from host to device)]
9.1231 [opencl_profiling] spent 0.0001 seconds in rawprepare_1f
9.1231 [opencl_profiling] spent 0.0001 seconds in whitebalance_1f
9.1231 [opencl_profiling] spent 0.0001 seconds in highlights_opposed
9.1231 [opencl_profiling] spent 0.0000 seconds in border_interpolate
9.1231 [opencl_profiling] spent 0.0001 seconds in rcd_border_green
9.1231 [opencl_profiling] spent 0.0001 seconds in rcd_border_redblue
9.1231 [opencl_profiling] spent 0.0001 seconds in rcd_populate
9.1231 [opencl_profiling] spent 0.0001 seconds in rcd_step_1_1
9.1231 [opencl_profiling] spent 0.0001 seconds in rcd_step_1_2
9.1231 [opencl_profiling] spent 0.0001 seconds in rcd_step_2_1
9.1231 [opencl_profiling] spent 0.0001 seconds in rcd_step_3_1
9.1231 [opencl_profiling] spent 0.0001 seconds in rcd_step_4_1
9.1231 [opencl_profiling] spent 0.0000 seconds in rcd_step_4_2
9.1231 [opencl_profiling] spent 0.0001 seconds in rcd_step_5_1
9.1231 [opencl_profiling] spent 0.0002 seconds in rcd_step_5_2
9.1231 [opencl_profiling] spent 0.0002 seconds in rcd_write_output
9.1231 [opencl_profiling] spent 0.0002 seconds in exposure
9.1231 [opencl_profiling] spent 0.0003 seconds in colorin_unbound
9.1231 [opencl_profiling] spent 0.0002 seconds in [Copy Image (on device)]
9.1231 [opencl_profiling] spent 0.0002 seconds in colorspaces_transform_lab_to_rgb_matrix
9.1231 [opencl_profiling] spent 0.0003 seconds in channelmixerrgb_CAT16
9.1231 [opencl_profiling] spent 0.0000 seconds in [Write Buffer (from host to device)]
9.1231 [opencl_profiling] spent 0.0002 seconds in filmic_mask_clipped_pixels
9.1231 [opencl_profiling] spent 0.0000 seconds in [Read Buffer (from device to host)]
9.1231 [opencl_profiling] spent 0.0003 seconds in filmicrgb_chroma
9.1231 [opencl_profiling] spent 0.0078 seconds in [Read Image (from device to host)]
9.1231 [opencl_profiling] spent 0.0113 seconds totally in command queue (with 0 events missing)
9.1248 [dev_process_image] pixel pipeline took 0.149 secs (0.544 CPU) processing `2024-07-14-15-18-34-P1040073.RW2'
9.1352 [histogram] took 0.004 secs (0.004 CPU) scope draw
10.2756 [histogram] took 0.004 secs (0.004 CPU) scope draw
10.3236 [histogram] took 0.003 secs (0.002 CPU) scope draw
10.3494 [histogram] took 0.003 secs (0.003 CPU) scope draw
10.3747 [histogram] took 0.003 secs (0.002 CPU) scope draw
10.4002 [histogram] took 0.003 secs (0.003 CPU) scope draw
```
jenshannoschwalm
commented
2 months ago Could it be you have the HQ processing toggled on in darkroom?
thierry0601
commented
2 months ago Thanks for your feedback Jens, but I don't understand which parameter I have to toggle for this HQ processing
jenshannoschwalm
commented
2 months ago It's one of the buttons at the lower border in darkroom.
thierry0601
commented
2 months ago I just resolved the slowness issue on my W10 PC by upgrading the driver of the Nvidia GTX760 graphic card that was +3 years old. I think the issue came following the background upgrades of windows because deploying older versions of DK didn't change the behavior.
For me we can close the case. May be reading this case can be usefull if someone falls in same issue...
Thanks a lot for your support, Best Regards
Describe the bug
It is too much slow (around 7seconds) to open the darkroom. On same PC and environment this was not the case in previous version; I don't remember when it started to occur (4.6 ?)
Steps to reproduce
Reproducer is to select an image in the lighttable then to click on the darkroom button. It takes 7 sec to display the image. when it start to display on screen it is very fast to have the full image. Switching image within the darkroom with back or arrow key is faster (2sec) but still very slower compare to previous darktable version.
Expected behavior
go faster :)
Logfile | Screenshot | Screencast
darktable -d perf 1004,5706 [dt_dev_load_raw] loading the image. took 0,637 secs (1,031 CPU) ( click on darkroom after selecting image) Whey 7sec here ??????? 1011,0323 [histogram] took 0,000 secs (0,000 CPU) scope draw 1011,5321 [dt_dev_process_image_job] loading image. took 0,000 secs (0,000 CPU) ( image is displayed)
darktable -d perf -d opencl -d common
327,8256 [dt_dev_load_raw] loading the image. took 0,684 secs (1,000 CPU) (** click on darkroom after selecting image around here) 327,8277 [dt_dev_read_history_ext] temporary history deleted 327,8278 [dt_iop_reload_defaults] defaults reloaded for filmicrgb 327,8279 [dt_iop_reload_defaults] defaults reloaded for colormapping 327,8279 [dt_iop_reload_defaults] defaults reloaded for colorequal 327,8280 [dt_iop_reload_defaults] defaults reloaded for channelmixerrgb 327,8354 [dt_iop_reload_defaults] defaults reloaded for colorin 327,8357 [dt_iop_reload_defaults] defaults reloaded for basecurve 327,8358 [dt_iop_reload_defaults] defaults reloaded for overlay 327,8359 [dt_iop_reload_defaults] defaults reloaded for crop 327,8359 [dt_iop_reload_defaults] defaults reloaded for clipping 327,8360 [dt_iop_reload_defaults] defaults reloaded for flip 327,8360 [dt_iop_reload_defaults] defaults reloaded for rotatepixels 327,8361 [dt_iop_reload_defaults] defaults reloaded for ashift 327,8361 [dt_iop_reload_defaults] defaults reloaded for cacorrectrgb 327,8428 [dt_iop_reload_defaults] defaults reloaded for lens 327,8429 [dt_iop_reload_defaults] defaults reloaded for retouch 327,8429 [dt_iop_reload_defaults] defaults reloaded for exposure 327,8432 [dt_iop_reload_defaults] defaults reloaded for denoiseprofile 327,8434 [dt_iop_reload_defaults] defaults reloaded for demosaic 327,8434 [dt_iop_reload_defaults] defaults reloaded for rawdenoise 327,8435 [dt_iop_reload_defaults] defaults reloaded for hotpixels 327,8435 [dt_iop_reload_defaults] defaults reloaded for cacorrect 327,8436 [dt_iop_reload_defaults] defaults reloaded for highlights 327,8437 [dt_iop_reload_defaults] scene=YES, modern=YES, CAT=NO. D65 1,000 1,000 1,000, AS-SHOT 1,000 1,000 1,000 327,8438 [dt_iop_reload_defaults] defaults reloaded for temperature 327,8438 [dt_iop_reload_defaults] defaults reloaded for invert 327,8439 [dt_iop_reload_defaults] defaults reloaded for rawprepare 327,9208 [dt_dev_read_history_ext] temporary history initialised with default params and presets 327,9210 [dt_dev_read_history_ext] temporary history merged with image history 327,9219 [history] successfully loaded module colorin from history blendop v. 11: version WRONG params ok params v. 7: version ok params ok 327,9221 [history] successfully loaded module colorout from history blendop v. 11: version WRONG params ok params v. 5: version ok params ok 327,9221 [history] successfully loaded module gamma from history blendop v. 11: version WRONG params ok params v. 1: version ok params ok 327,9222 [history] successfully loaded module flip from history blendop v. 11: version WRONG params ok params v. 2: version ok params ok 327,9223 [history] successfully loaded module crop from history blendop v. 11: version WRONG params ok params v. 1: version ok params ok 327,9223 [history] successfully loaded module watermark from history blendop v. 11: version WRONG params ok params v. 5: version WRONG params WRONG ?????????????????????? 329,2153 [dt_iop_reload_defaults] defaults reloaded for filmicrgb 329,9247 [dt_iop_reload_defaults] defaults reloaded for colormapping 330,1909 [dt_iop_reload_defaults] defaults reloaded for colorequal 330,9120 changed CAT for channelmixerrgb from 0000000000000000 to 00000163f45de740 330,9123 [dt_iop_reload_defaults] defaults reloaded for channelmixerrgb 330,9252 [dt_iop_reload_defaults] defaults reloaded for colorin 331,0805 [dt_iop_reload_defaults] defaults reloaded for basecurve 331,1761 [dt_iop_reload_defaults] defaults reloaded for overlay 331,1843 [dt_iop_reload_defaults] defaults reloaded for crop 331,2768 [dt_iop_reload_defaults] defaults reloaded for clipping 331,2892 [dt_iop_reload_defaults] defaults reloaded for flip 331,2963 [dt_iop_reload_defaults] defaults reloaded for rotatepixels 331,3486 [dt_iop_reload_defaults] defaults reloaded for ashift 331,3819 [dt_iop_reload_defaults] defaults reloaded for cacorrectrgb 331,4092 [dt_iop_reload_defaults] defaults reloaded for lens 331,4762 [dt_iop_reload_defaults] defaults reloaded for retouch 331,5952 [dt_iop_reload_defaults] defaults reloaded for exposure 331,7898 [dt_iop_reload_defaults] defaults reloaded for denoiseprofile 331,7974 [dt_iop_reload_defaults] defaults reloaded for demosaic 331,8417 [dt_iop_reload_defaults] defaults reloaded for rawdenoise 331,8654 [dt_iop_reload_defaults] defaults reloaded for hotpixels 331,8742 [dt_iop_reload_defaults] defaults reloaded for cacorrect 331,8971 [dt_iop_reload_defaults] defaults reloaded for highlights 331,9144 [dt_iop_reload_defaults] scene=YES, modern=YES, CAT=NO. D65 1,000 1,000 1,000, AS-SHOT 1,000 1,000 1,000 331,9147 [dt_iop_reload_defaults] defaults reloaded for temperature 331,9360 [dt_iop_reload_defaults] defaults reloaded for invert 331,9443 [dt_iop_reload_defaults] defaults reloaded for rawprepare 331,9708 used preset temperature preset='as shot': D65 1,000 1,000 1,000, AS-SHOT 1,000 1,000 1,000 ???????????????????????????? 334,4089 [histogram] took 0,001 secs (0,000 CPU) scope draw 334,9734 [dt_dev_process_image_job] loading image. took 0,000 secs (0,000 CPU) 334,9849 pipe state changing [full] zoomed, synch all, 334,9853 synch all module defaults [full] 335,0729 [histogram] took 0,000 secs (0,000 CPU) scope draw (*** Image displayed around here) 335,3101 synch all module history [full] 335,3994 dt_dev_pixelpipe_synch [full] colorin enabled, order=32, piece hash=f37e20e0ceb424c3, 335,5300 dt_dev_pixelpipe_synch [full] colorout enabled, order=77, piece hash=8e5a0f73242a7524, 335,5301 dt_dev_pixelpipe_synch [full] gamma enabled, order=90, piece hash=1ae2f37bb34a05, 335,5302 dt_dev_pixelpipe_synch [full] flip disabled, order=21, piece hash=0, 335,5303 dt_dev_pixelpipe_synch [full] crop enabled, order=25, piece hash=7d20eb890d15a5aa, 335,5304 [iop_validate_params]
watermark' failed for type "dt_iop_watermark_img_scale_t", field: scale_img 335,5304 [iop_validate_params]watermark' failed for type "dt_iop_watermark_svg_scale_t", field: scale_svg 335,5305 [iop_validate_params] `watermark' failed for type "dt_iop_watermark_params_t" 335,5305 dt_dev_pixelpipe_synch [full] watermark enabled, order=89, piece hash=b89e844aa40fb75e, 335,5306 synch all modules done [full] defaults 0,3249s, history 0,2204s 335,5306 modify roi OUT [full] crop ( 0/ 0) 5472x3648 scale=1,0000 --> ( 169/ 113) 5303x3535 scale=1,0000 ID=28892 335,5346 pipe cache check [full] 64 lines (important=1, used=6). Freed 0MB. Using using 45MB, limit=255MB 335,5348 pipe starting CL0 [full] ( 0/ 0) 861x 574 scale=0,1624 --> ( 0/ 0) 861x 574 scale=0,1624 ID=28892, nvidiacudageforcegtx760 335,5349 modify roi IN [full] crop ( 27/ 18) 861x 574 scale=0,1624 --> ( 0/ 0) 861x 574 scale=0,1624 ID=28892 335,5351 pipe data: clip&zoom CPU [full] ( 166/ 110) 5472x3648 scale=1,0000 --> ( 27/ 18) 861x 574 scale=0,1624Commit
4.8 or earlier
Where did you obtain darktable from?
downloaded from www.darktable.org
darktable version
version: darktable 4.8.0
What OS are you using?
Windows
What is the version of your OS?
Window 10.0.19045
Describe your system?
16GB Intel Core i7-6700K
250 GB SSD 850 EVO M2 for system, application darktable DB HDD for images
Graphical card GTX 760 2GB
Are you using OpenCL GPU in darktable?
Yes
If yes, what is the GPU card and driver?
GTX 760 2GB
Please provide additional context if applicable. You can attach files too, but might need to rename to .txt or .zip
No response