How cheap a GPU will still speed up darktable?

Hardware
50

@g-man , @hannoschwalm thanks for the suggestions. It’s 8AM, and I’ve just been through the same steps as yesterday, after starting dt with -d tiling and -d opencl.
BUT
dt is stubbornly refusing to produce the problems I had yesterday. Maybe the reboot changed something… I don’t know whether to be pleased or not :slightly_smiling_face:
Here’s the log, showing a bunch of exports with different opencl settings as I tried to get it to ‘crash’.
Just in case it’s useful:

[dt_pthread_create] info: bumping pthread's stacksize from 0 to 2097152
[dt_pthread_create] info: bumping pthread's stacksize from 0 to 2097152
[dt_pthread_create] info: bumping pthread's stacksize from 0 to 2097152
[dt_pthread_create] info: bumping pthread's stacksize from 0 to 2097152
[dt_pthread_create] info: bumping pthread's stacksize from 0 to 2097152
[dt_pthread_create] info: bumping pthread's stacksize from 0 to 2097152
[dt_pthread_create] info: bumping pthread's stacksize from 0 to 2097152
[dt_pthread_create] info: bumping pthread's stacksize from 0 to 2097152
[dt_pthread_create] info: bumping pthread's stacksize from 0 to 2097152
[dt_get_sysresource_level] switched to 1 as `default'
  total mem:       16340MB
  mipmap cache:    2042MB
  available mem:   8170MB
  singlebuff:      127MB
  OpenCL tune mem: OFF
  OpenCL pinned:   OFF
[opencl_init] opencl related configuration options:
[opencl_init] opencl: ON
[opencl_init] opencl_scheduling_profile: 'very fast GPU'
[opencl_init] opencl_library: 'default path'
[opencl_init] opencl_device_priority: '*/!0,*/*/*/!0,*'
[opencl_init] opencl_mandatory_timeout: 400
[opencl_init] opencl library 'OpenCL.dll' found on your system and loaded
[opencl_init] found 2 platforms
[opencl_init] found 2 devices

[dt_opencl_device_init]
   DEVICE:                   0: 'NVIDIA GeForce GTX 1650'
   CANONICAL NAME:           nvidiageforcegtx1650
   PLATFORM NAME & VENDOR:   NVIDIA CUDA, NVIDIA Corporation
   DRIVER VERSION:           526.98
   DEVICE VERSION:           OpenCL 3.0 CUDA, SM_20 SUPPORT
   DEVICE_TYPE:              GPU
   GLOBAL MEM SIZE:          4096 MB
   MAX MEM ALLOC:            1024 MB
   MAX IMAGE SIZE:           32768 x 32768
   MAX WORK GROUP SIZE:      1024
   MAX WORK ITEM DIMENSIONS: 3
   MAX WORK ITEM SIZES:      [ 1024 1024 64 ]
   ASYNC PIXELPIPE:          NO
   PINNED MEMORY TRANSFER:   NO
   MEMORY TUNING:            NO
   FORCED HEADROOM:          400
   AVOID ATOMICS:            NO
   MICRO NAP:                250
   ROUNDUP WIDTH:            16
   ROUNDUP HEIGHT:           16
   CHECK EVENT HANDLES:      128
   PERFORMANCE:              1.682
   TILING ADVANTAGE:         0.000
   DEFAULT DEVICE:           NO
   KERNEL DIRECTORY:         C:\Program Files\darktable4.1weekly4-12-22\share\darktable\kernels
   CL COMPILER OPTION:       -cl-fast-relaxed-math
   KERNEL LOADING TIME:       0.9518 sec

[dt_opencl_device_init]
   DEVICE:                   1: '        Intel(R) Core(TM) i5-2400 CPU @ 3.10GHz'
   CANONICAL NAME:           intelrcoretmi52400cpu310ghz
   PLATFORM NAME & VENDOR:   AMD Accelerated Parallel Processing, Advanced Micro Devices, Inc.
   DRIVER VERSION:           1800.11 (sse2,avx)
   DEVICE VERSION:           OpenCL 1.2 AMD-APP (1800.11)
   DEVICE_TYPE:              CPU
   GLOBAL MEM SIZE:          16341 MB
   MAX MEM ALLOC:            4085 MB
   MAX IMAGE SIZE:           8192 x 8192
   MAX WORK GROUP SIZE:      1024
   MAX WORK ITEM DIMENSIONS: 3
   MAX WORK ITEM SIZES:      [ 1024 1024 1024 ]
   ASYNC PIXELPIPE:          NO
   PINNED MEMORY TRANSFER:   NO
   MEMORY TUNING:            NO
   FORCED HEADROOM:          400
   AVOID ATOMICS:            NO
   MICRO NAP:                1000
   ROUNDUP WIDTH:            16
   ROUNDUP HEIGHT:           16
   CHECK EVENT HANDLES:      128
   TILING ADVANTAGE:         0.000
   DEFAULT DEVICE:           NO
   *** marked as disabled ***
[opencl_init] OpenCL successfully initialized.
[opencl_init] here are the internal numbers and names of OpenCL devices available to darktable:
[opencl_init]		0	'NVIDIA GeForce GTX 1650'
[opencl_init] FINALLY: opencl is AVAILABLE on this system.
[opencl_init] initial status of opencl enabled flag is ON.
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		1	1	1	1	1
[opencl_synchronization_timeout] synchronization timeout set to 0
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		1	1	1	1	1
[opencl_synchronization_timeout] synchronization timeout set to 0
16.803714 [dt_opencl_check_tuning] use 2526MB (tunemem=OFF, pinning=OFF) on device `NVIDIA GeForce GTX 1650' id=0
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		1	1	1	1	1
[opencl_synchronization_timeout] synchronization timeout set to 0
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		1	1	1	1	1
[opencl_synchronization_timeout] synchronization timeout set to 0
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		1	1	1	1	1
[opencl_synchronization_timeout] synchronization timeout set to 0
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		1	1	1	1	1
[opencl_synchronization_timeout] synchronization timeout set to 0
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		1	1	1	1	1
[opencl_synchronization_timeout] synchronization timeout set to 0
48.276153 [default_process_tiling_cl_ptp] [export] **** tiling module 'diffuse' for image with size 6036x4020 --> 6036x4020
48.276223 [default_process_tiling_cl_ptp] [export] (2x1) tiles with max dimensions 3660x4020, pinned=OFF, good 3596x3956 and overlap 32
48.276245 [default_process_tiling_cl_ptp] [export] tile (0,0) size 3660x4020 at origin [0,0]
48.745262 [default_process_tiling_cl_ptp] [export] tile (1,0) size 2440x4020 at origin [3596,0]
49.013072 [default_process_tiling_cl_ptp] [export] **** tiling module 'diffuse' for image with size 6036x4020 --> 6036x4020
49.013156 [default_process_tiling_cl_ptp] [export] (3x1) tiles with max dimensions 2888x4020, pinned=OFF, good 2376x3508 and overlap 256
49.013183 [default_process_tiling_cl_ptp] [export] tile (0,0) size 2888x4020 at origin [0,0]
50.099507 [default_process_tiling_cl_ptp] [export] tile (1,0) size 2888x4020 at origin [2376,0]
51.185570 [default_process_tiling_cl_ptp] [export] tile (2,0) size 1284x4020 at origin [4752,0]
51.743138 [default_process_tiling_cl_ptp] [export] **** tiling module 'filmicrgb' for image with size 6036x4020 --> 6036x4020
51.743222 [default_process_tiling_cl_ptp] [export] (2x1) tiles with max dimensions 4576x4020, pinned=OFF, good 3552x2996 and overlap 512
51.743250 [default_process_tiling_cl_ptp] [export] tile (0,0) size 4576x4020 at origin [0,0]
51.895824 [default_process_tiling_cl_ptp] [export] tile (1,0) size 2484x4020 at origin [3552,0]
[export_job] exported to `F:\All Sorted Photos starting 2021\2022-12-03 ND incl. Alpine Rally\tt2\DSC_9618_09.jpg'
[dt_get_sysresource_level] switched to 1 as `default'
  total mem:       16340MB
  mipmap cache:    2042MB
  available mem:   8170MB
  singlebuff:      127MB
  OpenCL tune mem: OFF
  OpenCL pinned:   WANTED
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		1	1	1	1	1
[opencl_synchronization_timeout] synchronization timeout set to 0
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		1	1	1	1	1
[opencl_synchronization_timeout] synchronization timeout set to 0
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		1	1	1	1	1
[opencl_synchronization_timeout] synchronization timeout set to 0
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		1	1	1	1	1
[opencl_synchronization_timeout] synchronization timeout set to 0
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		1	1	1	1	1
[opencl_synchronization_timeout] synchronization timeout set to 0
78.973249 [dt_opencl_check_tuning] use 2526MB (tunemem=OFF, pinning=ON) on device `NVIDIA GeForce GTX 1650' id=0
79.956947 [default_process_tiling_cl_ptp] [export] **** tiling module 'diffuse' for image with size 6036x4020 --> 6036x4020
79.957025 [default_process_tiling_cl_ptp] [export] (2x1) tiles with max dimensions 3108x4020, pinned=ON, good 3044x3956 and overlap 32
80.164576 [default_process_tiling_cl_ptp] [export] tile (0,0) size 3108x4020 at origin [0,0]
80.603055 [default_process_tiling_cl_ptp] [export] tile (1,0) size 2992x4020 at origin [3044,0]
81.081513 [default_process_tiling_cl_ptp] [export] **** tiling module 'diffuse' for image with size 6036x4020 --> 6036x4020
81.081591 [default_process_tiling_cl_ptp] [export] (3x1) tiles with max dimensions 2532x4020, pinned=ON, good 2020x3508 and overlap 256
81.258634 [default_process_tiling_cl_ptp] [export] tile (0,0) size 2532x4020 at origin [0,0]
82.173119 [default_process_tiling_cl_ptp] [export] tile (1,0) size 2532x4020 at origin [2020,0]
83.091343 [default_process_tiling_cl_ptp] [export] tile (2,0) size 1996x4020 at origin [4040,0]
84.000919 [default_process_tiling_cl_ptp] [export] **** tiling module 'filmicrgb' for image with size 6036x4020 --> 6036x4020
84.000995 [default_process_tiling_cl_ptp] [export] (3x1) tiles with max dimensions 3744x4020, pinned=ON, good 2720x2996 and overlap 512
84.239275 [default_process_tiling_cl_ptp] [export] tile (0,0) size 3744x4020 at origin [0,0]
84.444296 [default_process_tiling_cl_ptp] [export] tile (1,0) size 3316x4020 at origin [2720,0]
[export_job] exported to `F:\All Sorted Photos starting 2021\2022-12-03 ND incl. Alpine Rally\tt2\DSC_9618_10.jpg'
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	-1	0	0	-1
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[opencl_synchronization_timeout] synchronization timeout set to 200
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	-1	0	0	-1
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[opencl_synchronization_timeout] synchronization timeout set to 200
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	-1	0	0	-1
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[opencl_synchronization_timeout] synchronization timeout set to 200
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	-1	0	0	-1
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[opencl_synchronization_timeout] synchronization timeout set to 200
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	-1	0	0	-1
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[opencl_synchronization_timeout] synchronization timeout set to 200
110.460371 [default_process_tiling_cl_ptp] [export] **** tiling module 'diffuse' for image with size 6036x4020 --> 6036x4020
110.460475 [default_process_tiling_cl_ptp] [export] (2x1) tiles with max dimensions 3108x4020, pinned=ON, good 3044x3956 and overlap 32
110.665993 [default_process_tiling_cl_ptp] [export] tile (0,0) size 3108x4020 at origin [0,0]
111.103985 [default_process_tiling_cl_ptp] [export] tile (1,0) size 2992x4020 at origin [3044,0]
111.581497 [default_process_tiling_cl_ptp] [export] **** tiling module 'diffuse' for image with size 6036x4020 --> 6036x4020
111.581577 [default_process_tiling_cl_ptp] [export] (3x1) tiles with max dimensions 2532x4020, pinned=ON, good 2020x3508 and overlap 256
111.760082 [default_process_tiling_cl_ptp] [export] tile (0,0) size 2532x4020 at origin [0,0]
112.663831 [default_process_tiling_cl_ptp] [export] tile (1,0) size 2532x4020 at origin [2020,0]
113.565153 [default_process_tiling_cl_ptp] [export] tile (2,0) size 1996x4020 at origin [4040,0]
114.460019 [default_process_tiling_cl_ptp] [export] **** tiling module 'filmicrgb' for image with size 6036x4020 --> 6036x4020
114.460110 [default_process_tiling_cl_ptp] [export] (3x1) tiles with max dimensions 3744x4020, pinned=ON, good 2720x2996 and overlap 512
114.711460 [default_process_tiling_cl_ptp] [export] tile (0,0) size 3744x4020 at origin [0,0]
114.909146 [default_process_tiling_cl_ptp] [export] tile (1,0) size 3316x4020 at origin [2720,0]
[export_job] exported to `F:\All Sorted Photos starting 2021\2022-12-03 ND incl. Alpine Rally\tt2\DSC_9618_11.jpg'
[dt_get_sysresource_level] switched to 1 as `default'
  total mem:       16340MB
  mipmap cache:    2042MB
  available mem:   8170MB
  singlebuff:      127MB
  OpenCL tune mem: WANTED
  OpenCL pinned:   WANTED
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	-1	0	0	-1
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[opencl_synchronization_timeout] synchronization timeout set to 200
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	-1	0	0	-1
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[opencl_synchronization_timeout] synchronization timeout set to 200
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	-1	0	0	-1
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[opencl_synchronization_timeout] synchronization timeout set to 200
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	-1	0	0	-1
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[opencl_synchronization_timeout] synchronization timeout set to 200
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	-1	0	0	-1
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[opencl_synchronization_timeout] synchronization timeout set to 200
135.869293 [dt_opencl_check_tuning] use 3695MB (tunemem=ON, pinning=ON) on device `NVIDIA GeForce GTX 1650' id=0
136.804689 [default_process_tiling_cl_ptp] [export] **** tiling module 'diffuse' for image with size 6036x4020 --> 6036x4020
136.804764 [default_process_tiling_cl_ptp] [export] (2x1) tiles with max dimensions 4544x4020, pinned=ON, good 4480x3956 and overlap 32
137.105735 [default_process_tiling_cl_ptp] [export] tile (0,0) size 4544x4020 at origin [0,0]
137.819249 [default_process_tiling_cl_ptp] [export] tile (1,0) size 1556x4020 at origin [4480,0]
138.100985 [default_process_tiling_cl_ptp] [export] **** tiling module 'diffuse' for image with size 6036x4020 --> 6036x4020
138.101070 [default_process_tiling_cl_ptp] [export] (2x1) tiles with max dimensions 3704x4020, pinned=ON, good 3192x3508 and overlap 256
138.321231 [default_process_tiling_cl_ptp] [export] tile (0,0) size 3704x4020 at origin [0,0]
138.479931 [dt_opencl_enqueue_kernel_2d_with_local] kernel 178 on device 0: CL_MEM_OBJECT_ALLOCATION_FAILURE
139.901242 [opencl_diffuse] couldn't enqueue kernel! CL_MEM_OBJECT_ALLOCATION_FAILURE
139.983595 [default_process_tiling_opencl_ptp] [export] couldn't run process_cl() for module 'diffuse' in tiling mode: DT_OPENCL_PROCESS_CL
139.983672 [opencl_pixelpipe] [export] could not run module `diffuse' on gpu. falling back to cpu path
[export_job] exported to `F:\All Sorted Photos starting 2021\2022-12-03 ND incl. Alpine Rally\tt2\DSC_9618_12.jpg'
[dt_get_sysresource_level] switched to 1 as `default'
  total mem:       16340MB
  mipmap cache:    2042MB
  available mem:   8170MB
  singlebuff:      127MB
  OpenCL tune mem: OFF
  OpenCL pinned:   WANTED
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	-1	0	0	-1
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[opencl_synchronization_timeout] synchronization timeout set to 200
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	-1	0	0	-1
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[opencl_synchronization_timeout] synchronization timeout set to 200
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	-1	0	0	-1
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[opencl_synchronization_timeout] synchronization timeout set to 200
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	-1	0	0	-1
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[opencl_synchronization_timeout] synchronization timeout set to 200
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	-1	0	0	-1
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[opencl_synchronization_timeout] synchronization timeout set to 200
171.662991 [dt_opencl_check_tuning] use 2526MB (tunemem=OFF, pinning=ON) on device `NVIDIA GeForce GTX 1650' id=0
172.544917 [default_process_tiling_cl_ptp] [export] **** tiling module 'diffuse' for image with size 6036x4020 --> 6036x4020
172.545007 [default_process_tiling_cl_ptp] [export] (2x1) tiles with max dimensions 3108x4020, pinned=ON, good 3044x3956 and overlap 32
172.757025 [default_process_tiling_cl_ptp] [export] tile (0,0) size 3108x4020 at origin [0,0]
173.195085 [default_process_tiling_cl_ptp] [export] tile (1,0) size 2992x4020 at origin [3044,0]
173.672189 [default_process_tiling_cl_ptp] [export] **** tiling module 'diffuse' for image with size 6036x4020 --> 6036x4020
173.672282 [default_process_tiling_cl_ptp] [export] (3x1) tiles with max dimensions 2532x4020, pinned=ON, good 2020x3508 and overlap 256
173.855535 [default_process_tiling_cl_ptp] [export] tile (0,0) size 2532x4020 at origin [0,0]
174.763129 [default_process_tiling_cl_ptp] [export] tile (1,0) size 2532x4020 at origin [2020,0]
175.664341 [default_process_tiling_cl_ptp] [export] tile (2,0) size 1996x4020 at origin [4040,0]
176.568046 [default_process_tiling_cl_ptp] [export] **** tiling module 'filmicrgb' for image with size 6036x4020 --> 6036x4020
176.568135 [default_process_tiling_cl_ptp] [export] (3x1) tiles with max dimensions 3744x4020, pinned=ON, good 2720x2996 and overlap 512
176.842936 [default_process_tiling_cl_ptp] [export] tile (0,0) size 3744x4020 at origin [0,0]
177.042686 [default_process_tiling_cl_ptp] [export] tile (1,0) size 3316x4020 at origin [2720,0]
[export_job] exported to `F:\All Sorted Photos starting 2021\2022-12-03 ND incl. Alpine Rally\tt2\DSC_9618_13.jpg'
[dt_get_sysresource_level] switched to 1 as `default'
  total mem:       16340MB
  mipmap cache:    2042MB
  available mem:   8170MB
  singlebuff:      127MB
  OpenCL tune mem: WANTED
  OpenCL pinned:   OFF
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	-1	0	0	-1
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[opencl_synchronization_timeout] synchronization timeout set to 200
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	-1	0	0	-1
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[opencl_synchronization_timeout] synchronization timeout set to 200
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	-1	0	0	-1
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[opencl_synchronization_timeout] synchronization timeout set to 200
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	-1	0	0	-1
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[opencl_synchronization_timeout] synchronization timeout set to 200
[dt_opencl_update_priorities] these are your device priorities:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	-1	0	0	-1
[dt_opencl_update_priorities] show if opencl use is mandatory for a given pixelpipe:
[dt_opencl_update_priorities] 		image	preview	export	thumbs	preview2
[dt_opencl_update_priorities]		0	0	0	0	0
[opencl_synchronization_timeout] synchronization timeout set to 200
193.892699 [dt_opencl_check_tuning] use 3295MB (tunemem=ON, pinning=OFF) on device `NVIDIA GeForce GTX 1650' id=0
194.798830 [default_process_tiling_cl_ptp] [export] **** tiling module 'diffuse' for image with size 6036x4020 --> 6036x4020
194.798914 [default_process_tiling_cl_ptp] [export] (2x1) tiles with max dimensions 4772x4020, pinned=OFF, good 4708x3956 and overlap 32
194.798942 [default_process_tiling_cl_ptp] [export] tile (0,0) size 4772x4020 at origin [0,0]
195.454371 [default_process_tiling_cl_ptp] [export] tile (1,0) size 1328x4020 at origin [4708,0]
195.588295 [default_process_tiling_cl_ptp] [export] **** tiling module 'diffuse' for image with size 6036x4020 --> 6036x4020
195.588387 [default_process_tiling_cl_ptp] [export] (2x1) tiles with max dimensions 3768x4020, pinned=OFF, good 3256x3508 and overlap 256
195.588422 [default_process_tiling_cl_ptp] [export] tile (0,0) size 3768x4020 at origin [0,0]
197.195720 [default_process_tiling_cl_ptp] [export] tile (1,0) size 2780x4020 at origin [3256,0]
[export_job] exported to `F:\All Sorted Photos starting 2021\2022-12-03 ND incl. Alpine Rally\tt2\DSC_9618_14.jpg'

UPDATE after writing all this I went back to dt, and opened another image (the first one I posted) in darkroom, and dt has frozen in darkroom view showing “working…”

51

Just tried that - and it’s working perfectly. No probs at all. But then, this morning, it was working well (mostly) with D&S in too.

52

Can you check on NVidia control the amount of VRAM that’s being used? “It works after restart and then it stops working later, but works again when I disable D&S” maybe poins to a memory leak somewhere filling the VRAM (very uneducated guess).

1 Like
53

D&S can be very demanding even for fast / large cards depending on settings as it may go into heavy tiling.

Or your system takes more vram, that could be Firefox running as one example. Don’t tune memory and no transfer tuning, Stay with defaults.

Please report again logs in case of errors.

1 Like
54

Leave it set to none. I have a 3060TI and it’s not a big deal one or two seconds but none is always faster.

1 Like
55

I discovered than nvidia released a new driver yesterday, so I installed that. I was able to create the issue of OpenCL failing when exporting with memory tuning in use. See the log below, with -d perf, -d tiling and -d opencl. It looks to my uneducated eye like it may be revealing! I do understand (I think) that all this is just the result of unsuitable settings being used, still it might be of interest.

I don’t seem to be able to check that on nvidia software… Windows task manager tells me though. I just tried to recreate the problem again, and now it won’t do it! I’m not sure what a memory leak would look like, but I’ve only seen spikes in usage during export, no sustained high usage.

374.628925 [histogram] took 0.001 secs (0.000 CPU) scope draw
390.769204 [histogram] took 0.001 secs (0.000 CPU) scope draw
398.492730 [dev] took 0.000 secs (0.000 CPU) to load the image.
398.741773 [export] creating pixelpipe took 0.231 secs (0.375 CPU)
398.741915 [dev_pixelpipe] took 0.000 secs (0.000 CPU) initing base buffer [export]
398.784122 [dev_pixelpipe] took 0.042 secs (0.078 CPU) [export] processed `raw black/white point' on GPU, blended on GPU
398.811941 [dev_pixelpipe] took 0.028 secs (0.047 CPU) [export] processed `white balance' on GPU, blended on GPU
399.044796 [dev_pixelpipe] took 0.233 secs (0.531 CPU) [export] processed `highlight reconstruction' on CPU, blended on CPU
399.226194 [dev_pixelpipe] took 0.181 secs (0.234 CPU) [export] processed `demosaic' on GPU, blended on GPU
399.265812 [dev_pixelpipe] took 0.040 secs (0.062 CPU) [export] processed `exposure' on GPU, blended on GPU
399.299824 [dev_pixelpipe] took 0.034 secs (0.062 CPU) [export] processed `input color profile' on GPU, blended on GPU
image colorspace transform Lab-->RGB took 0.226 secs (0.656 CPU) [diffuse ]
399.680791 [default_process_tiling_cl_ptp] [export] **** tiling module 'diffuse' for image with size 6036x4020 --> 6036x4020
399.680835 [default_process_tiling_cl_ptp] [export] (2x1) tiles with max dimensions 5352x4020, pinned=OFF, good 5288x3956 and overlap 32
399.680863 [default_process_tiling_cl_ptp] [export] tile (0,0) size 5352x4020 at origin [0,0]
400.596336 [default_process_tiling_cl_ptp] [export] tile (1,0) size 748x4020 at origin [5288,0]
400.685832 [dev_pixelpipe] took 1.386 secs (2.234 CPU) [export] processed `diffuse or sharpen' on GPU with tiling, blended on CPU
400.687681 [default_process_tiling_cl_ptp] [export] **** tiling module 'diffuse' for image with size 6036x4020 --> 6036x4020
400.687814 [default_process_tiling_cl_ptp] [export] (2x1) tiles with max dimensions 4224x4020, pinned=OFF, good 3712x3508 and overlap 256
400.687849 [default_process_tiling_cl_ptp] [export] tile (0,0) size 4224x4020 at origin [0,0]
401.000391 [dt_opencl_enqueue_kernel_2d_with_local] kernel 178 on device 0: CL_MEM_OBJECT_ALLOCATION_FAILURE
402.796371 [opencl_diffuse] couldn't enqueue kernel! CL_MEM_OBJECT_ALLOCATION_FAILURE
402.799277 [default_process_tiling_opencl_ptp] [export] couldn't run process_cl() for module 'diffuse' in tiling mode: DT_OPENCL_PROCESS_CL
402.799333 [opencl_pixelpipe] [export] could not run module `diffuse' on gpu. falling back to cpu path
419.308192 [dev_pixelpipe] took 18.622 secs (62.688 CPU) [export] processed `diffuse or sharpen 1' on CPU, blended on CPU
419.546856 [dev_pixelpipe] took 0.239 secs (0.219 CPU) [export] processed `color balance rgb' on GPU, blended on GPU
419.595520 [dev_pixelpipe] took 0.049 secs (0.047 CPU) [export] processed `filmic rgb' on GPU, blended on GPU
image colorspace transform RGB-->Lab took 0.032 secs (0.016 GPU) [colorout ]
419.686204 [dev_pixelpipe] took 0.091 secs (0.078 CPU) [export] processed `output color profile' on GPU, blended on GPU
419.856893 [dev_pixelpipe] took 0.171 secs (0.453 CPU) [export] processed `display encoding' on CPU, blended on CPU
419.856980 [opencl_profiling] profiling device 0 ('NVIDIA GeForce GTX 1650'):
419.857011 [opencl_profiling] spent  0.3429 seconds in [Write Image (from host to device)]
419.857036 [opencl_profiling] spent  0.0093 seconds in rawprepare_1f
419.857060 [opencl_profiling] spent  0.0159 seconds in whitebalance_1f
419.857083 [opencl_profiling] spent  0.4757 seconds in [Read Image (from device to host)]
419.857113 [opencl_profiling] spent  0.0008 seconds in border_interpolate
419.857142 [opencl_profiling] spent  0.0040 seconds in rcd_border_green
419.857171 [opencl_profiling] spent  0.0071 seconds in rcd_border_redblue
419.857200 [opencl_profiling] spent  0.0053 seconds in rcd_populate
419.857232 [opencl_profiling] spent  0.0038 seconds in rcd_step_1_1
419.857262 [opencl_profiling] spent  0.0046 seconds in rcd_step_1_2
419.857291 [opencl_profiling] spent  0.0023 seconds in rcd_step_2_1
419.857320 [opencl_profiling] spent  0.0050 seconds in rcd_step_3_1
419.857349 [opencl_profiling] spent  0.0040 seconds in rcd_step_4_1
419.857378 [opencl_profiling] spent  0.0013 seconds in rcd_step_4_2
419.857407 [opencl_profiling] spent  0.0066 seconds in rcd_step_5_1
419.857436 [opencl_profiling] spent  0.0069 seconds in rcd_step_5_2
419.857465 [opencl_profiling] spent  0.0090 seconds in rcd_write_output
419.857506 [opencl_profiling] spent  0.0092 seconds in exposure
419.857535 [opencl_profiling] spent  0.0078 seconds in colorin_unbound
419.857558 [opencl_profiling] spent  0.2223 seconds in blur_2D_Bspline_horizontal
419.857587 [opencl_profiling] spent  0.8761 seconds in blur_2D_Bspline_vertical
419.857616 [opencl_profiling] spent  0.3367 seconds in wavelets_detail_level
419.857639 [opencl_profiling] spent  1.1452 seconds in diffuse_pde
419.857662 [opencl_profiling] spent  0.0104 seconds in colorbalancergb
419.857686 [opencl_profiling] spent  0.0045 seconds in filmic_mask_clipped_pixels
419.857715 [opencl_profiling] spent  0.0080 seconds in filmicrgb_chroma
419.857744 [opencl_profiling] spent  0.0073 seconds in [Copy Image (on device)]
419.857773 [opencl_profiling] spent  0.0075 seconds in colorspaces_transform_rgb_matrix_to_lab
419.857796 [opencl_profiling] spent  0.0175 seconds in colorout
419.857826 [opencl_profiling] spent  3.5571 seconds totally in command queue (with 1 event missing)
419.857867 [dev_process_export] pixel pipeline processing took 21.116 secs (66.734 CPU)
[export_job] exported to `F:\All Sorted Photos starting 2021\2022-12-03 ND incl. Alpine Rally\tt2\DSC_9618_22.jpg'
426.582373 [dev] took 0.000 secs (0.000 CPU) to load the image.
428.233713 [histogram] took 0.001 secs (0.000 CPU) scope draw
428.290238 [dev] took 0.000 secs (0.000 CPU) to load the image.
428.423829 [dev_pixelpipe] took 0.000 secs (0.000 CPU) initing base buffer [full]
428.500894 [dev_pixelpipe] took 0.077 secs (0.141 CPU) [full] processed `raw black/white point' on GPU, blended on GPU
428.544420 [dev_pixelpipe] took 0.043 secs (0.047 CPU) [full] processed `white balance' on GPU, blended on GPU
428.700526 [dev_pixelpipe] took 0.156 secs (0.422 CPU) [full] processed `highlight reconstruction' on CPU, blended on CPU
429.048390 [dev_pixelpipe] took 0.348 secs (0.312 CPU) [full] processed `demosaic' on GPU, blended on GPU
429.053135 [dev_pixelpipe] took 0.005 secs (0.000 CPU) [full] processed `exposure' on GPU, blended on GPU
429.060282 [dev_pixelpipe] took 0.007 secs (0.016 CPU) [full] processed `input color profile' on GPU, blended on GPU
image colorspace transform Lab-->RGB took 0.004 secs (0.000 GPU) [diffuse ]
429.095816 [dev_pixelpipe] took 0.035 secs (0.016 CPU) [full] processed `diffuse or sharpen' on GPU, blended on GPU
429.188572 [dev_pixelpipe] took 0.093 secs (0.094 CPU) [full] processed `diffuse or sharpen 1' on GPU, blended on GPU
429.200644 [dev_pixelpipe] took 0.012 secs (0.016 CPU) [full] processed `color balance rgb' on GPU, blended on GPU
429.209050 [dev_pixelpipe] took 0.008 secs (0.000 CPU) [full] processed `filmic rgb' on GPU, blended on GPU
image colorspace transform RGB-->Lab took 0.004 secs (0.016 GPU) [colorout ]
429.219809 [dev_pixelpipe] took 0.011 secs (0.016 CPU) [full] processed `output color profile' on GPU, blended on GPU
429.233573 [dev_pixelpipe] took 0.014 secs (0.062 CPU) [full] processed `display encoding' on CPU, blended on CPU
429.233658 [opencl_profiling] profiling device 0 ('NVIDIA GeForce GTX 1650'):
429.233690 [opencl_profiling] spent  0.0497 seconds in [Write Image (from host to device)]
429.233715 [opencl_profiling] spent  0.0277 seconds in rawprepare_1f
429.233740 [opencl_profiling] spent  0.0277 seconds in whitebalance_1f
429.233764 [opencl_profiling] spent  0.0499 seconds in [Read Image (from device to host)]
429.233795 [opencl_profiling] spent  0.0035 seconds in border_interpolate
429.233832 [opencl_profiling] spent  0.1021 seconds in rcd_border_green
429.233862 [opencl_profiling] spent  0.0052 seconds in rcd_border_redblue
429.233898 [opencl_profiling] spent  0.0058 seconds in rcd_populate
429.233926 [opencl_profiling] spent  0.0043 seconds in rcd_step_1_1
429.233954 [opencl_profiling] spent  0.0029 seconds in rcd_step_1_2
429.233983 [opencl_profiling] spent  0.0014 seconds in rcd_step_2_1
429.234011 [opencl_profiling] spent  0.0038 seconds in rcd_step_3_1
429.234039 [opencl_profiling] spent  0.0031 seconds in rcd_step_4_1
429.234068 [opencl_profiling] spent  0.0013 seconds in rcd_step_4_2
429.234109 [opencl_profiling] spent  0.0032 seconds in rcd_step_5_1
429.234137 [opencl_profiling] spent  0.0055 seconds in rcd_step_5_2
429.234165 [opencl_profiling] spent  0.0065 seconds in rcd_write_output
429.234194 [opencl_profiling] spent  0.0325 seconds in interpolation_resample
429.234222 [opencl_profiling] spent  0.0006 seconds in exposure
429.234250 [opencl_profiling] spent  0.0007 seconds in colorin_unbound
429.234273 [opencl_profiling] spent  0.0011 seconds in [Copy Image (on device)]
429.234301 [opencl_profiling] spent  0.0005 seconds in colorspaces_transform_lab_to_rgb_matrix
429.234324 [opencl_profiling] spent  0.0146 seconds in blur_2D_Bspline_horizontal
429.234352 [opencl_profiling] spent  0.0247 seconds in blur_2D_Bspline_vertical
429.234380 [opencl_profiling] spent  0.0197 seconds in wavelets_detail_level
429.234410 [opencl_profiling] spent  0.0400 seconds in diffuse_pde
429.234442 [opencl_profiling] spent  0.0007 seconds in colorbalancergb
429.234465 [opencl_profiling] spent  0.0004 seconds in filmic_mask_clipped_pixels
429.234493 [opencl_profiling] spent  0.0006 seconds in filmicrgb_chroma
429.234522 [opencl_profiling] spent  0.0006 seconds in colorspaces_transform_rgb_matrix_to_lab
429.234545 [opencl_profiling] spent  0.0010 seconds in colorout
429.234573 [opencl_profiling] spent  0.4413 seconds totally in command queue (with 0 events missing)
429.236904 [dev_process_image] pixel pipeline processing took 0.820 secs (1.156 CPU)
429.380465 [dev_pixelpipe] took 0.000 secs (0.000 CPU) initing base buffer [preview]
430.834442 [dev] took 0.000 secs (0.000 CPU) to load the image.
432.925396 [opencl_lock_device] reached opencl_mandatory_timeout trying to lock mandatory device, fallback to CPU
432.933924 [dev_pixelpipe] took 0.000 secs (0.000 CPU) initing base buffer [full]
432.951561 [dev_pixelpipe] took 0.018 secs (0.000 CPU) [full] processed `raw black/white point' on CPU, blended on CPU
432.968121 [dev_pixelpipe] took 0.016 secs (0.062 CPU) [full] processed `white balance' on CPU, blended on CPU
433.086464 [dev_pixelpipe] took 0.118 secs (0.375 CPU) [full] processed `highlight reconstruction' on CPU, blended on CPU
433.533914 [dev_pixelpipe] took 0.447 secs (1.469 CPU) [full] processed `demosaic' on CPU, blended on CPU
433.539954 [dev_pixelpipe] took 0.006 secs (0.000 CPU) [full] processed `exposure' on CPU, blended on CPU
433.577151 [dev_pixelpipe] took 0.037 secs (0.188 CPU) [full] processed `input color profile' on CPU, blended on CPU
image colorspace transform Lab-->RGB took 0.013 secs (0.062 CPU) [diffuse ]
433.817790 [dev_pixelpipe] took 0.241 secs (0.750 CPU) [full] processed `diffuse or sharpen' on CPU, blended on CPU
434.868149 [dev_pixelpipe] took 1.050 secs (3.938 CPU) [full] processed `diffuse or sharpen 1' on CPU, blended on CPU
435.943366 [dev_pixelpipe] took 1.075 secs (4.203 CPU) [full] processed `color balance rgb' on CPU, blended on CPU
436.176887 [dev_pixelpipe] took 0.233 secs (0.938 CPU) [full] processed `filmic rgb' on CPU, blended on CPU
image colorspace transform RGB-->Lab took 0.008 secs (0.062 CPU) [colorout ]
436.199259 [dev_pixelpipe] took 0.022 secs (0.094 CPU) [full] processed `output color profile' on CPU, blended on CPU
436.207964 [dev_pixelpipe] took 0.009 secs (0.000 CPU) [full] processed `display encoding' on CPU, blended on CPU
436.210798 [dev_process_image] pixel pipeline processing took 5.376 secs (12.297 CPU)
436.754195 [dev] took 0.000 secs (0.000 CPU) to load the image.
438.883302 [opencl_lock_device] reached opencl_mandatory_timeout trying to lock mandatory device, fallback to CPU
438.890503 [dev_pixelpipe] took 0.000 secs (0.000 CPU) initing base buffer [full]
438.913821 [dev_pixelpipe] took 0.023 secs (0.031 CPU) [full] processed `raw black/white point' on CPU, blended on CPU
438.932782 [dev_pixelpipe] took 0.019 secs (0.031 CPU) [full] processed `white balance' on CPU, blended on CPU
438.992605 [dev_pixelpipe] took 0.060 secs (0.188 CPU) [full] processed `highlight reconstruction' on CPU, blended on CPU
439.318811 [dev_pixelpipe] took 0.326 secs (0.984 CPU) [full] processed `demosaic' on CPU, blended on CPU
439.325063 [dev_pixelpipe] took 0.006 secs (0.062 CPU) [full] processed `exposure' on CPU, blended on CPU
439.366492 [dev_pixelpipe] took 0.041 secs (0.125 CPU) [full] processed `input color profile' on CPU, blended on CPU
image colorspace transform Lab-->RGB took 0.013 secs (0.062 CPU) [diffuse ]
439.617175 [dev_pixelpipe] took 0.251 secs (0.859 CPU) [full] processed `diffuse or sharpen' on CPU, blended on CPU
440.711612 [dev_pixelpipe] took 1.094 secs (3.766 CPU) [full] processed `diffuse or sharpen 1' on CPU, blended on CPU
441.228913 [histogram] took 0.001 secs (0.000 CPU) scope draw
441.981444 [dev_pixelpipe] took 1.270 secs (4.719 CPU) [full] processed `color balance rgb' on CPU, blended on CPU
442.230370 [dev_pixelpipe] took 0.249 secs (0.906 CPU) [full] processed `filmic rgb' on CPU, blended on CPU
image colorspace transform RGB-->Lab took 0.009 secs (0.000 CPU) [colorout ]
442.255004 [dev_pixelpipe] took 0.025 secs (0.016 CPU) [full] processed `output color profile' on CPU, blended on CPU
442.264248 [dev_pixelpipe] took 0.009 secs (0.062 CPU) [full] processed `display encoding' on CPU, blended on CPU
442.265744 [dev_process_image] pixel pipeline processing took 5.511 secs (12.125 CPU)
442.666386 [histogram] took 0.001 secs (0.000 CPU) scope draw
442.701087 [histogram] took 0.001 secs (0.000 CPU) scope draw
442.720714 [histogram] took 0.001 secs (0.000 CPU) scope draw
442.736800 [histogram] took 0.001 secs (0.000 CPU) scope draw
56

Won’t nvidia-smi show it?

1 Like
57

Yep! First time I’d heard of it… but works, and corresponds to the Task manager readout too, as far as I can tell. Has more info though, like fan% and a list of programs.

58

I think the problem is here.

1 Like
59

I thought that looked a bit “???” I’m not sure what it implies though. And, I should say again, that I only get this with the tuning on, which I shouldn’t be using - I think only when it’s on ‘memory transfer’ but can’t say 100% that it only does it there, because it seems a little intermittent.

60

Well the message tells it’s the mem transfer failing. That could be a kernel error - you should remove old dt CL kernels after updating nvidia drivers. Also reboot before doing so.

1 Like
61

It looks after the error, the GPU is no longer available, so the system uses the CPU path.

432.925396 [opencl_lock_device] reached opencl_mandatory_timeout trying to lock mandatory device, fallback to CPU

1 Like
62

If you only get that message after the error, I’d assume it’s genuine. However…

If you are processing multiple pipelines (for example, the darkroom uses one for the top-left small preview, and one for the editor area), darktable will try to work on them in parallel.
The GPU will start working on a module, in one of the pipelines. If GPU processing is mandatory (e.g., when using the very fast GPU scheduling profile, or using the default scheduling profile with an appropriately configured priority string), the 2nd pipeline will:

  • first wait for the GPU to become available (see opencl_mandatory_timeout in darktablerc - the default value is 400, the unit is 5 ms).
  • if the timeout (400 * 5 ms = 2 s) expires, and the GPU is still busy, it’ll fall back to the CPU path. This is when you see reached opencl_mandatory_timeout trying to lock mandatory device, fallback to CPU in the log, if you have OpenCL debug logging enabled.

In some cases (e.g., when you are processing large files with heavy modules, like diffuse or sharpen or highlight reconstruction with guided laplacians), a timeout will occur even if everything is OK.
Now, if your GPU is faster than your CPU (which is usually the case), this may be detrimental:

  • 2nd pipeline waits for 2 seconds
  • starts processing on the CPU, let’s say 20 seconds
  • total time is 22 seconds
  • if it waited, and got the GPU after, say, 5 seconds, and then took 5 seconds to process the module on the GPU, the total time would have been 10 seconds.

So, you may want to increase that timeout significantly. It will either cause a hang (in that case, simply back out the change), or, possibly, a speed-up (like it did for me - OpenCL is mandatory, yet CPU is used (solved) - #4 by kofa).

1 Like
63

In this case, the first lockout was at 432. Then the system used CPU. The second was at 438, so 6seconds later and the GPU was still not available? It is like the kernel fault is keeping the GPU unavailable.

2 Likes
64

I get no issue with your NEF and XMP. NVidia 1060/6GB, driver v525.

Export: 
2133.631487 [dev] took 0.000 secs (0.000 CPU) to load the image.
2133.671617 [export] creating pixelpipe took 0.036 secs (0.043 CPU)
2133.671655 [dev_pixelpipe] took 0.000 secs (0.000 CPU) initing base buffer [export]
2133.679577 [dev_pixelpipe] took 0.008 secs (0.008 CPU) [export] processed `raw black/white point' on GPU, blended on GPU
2133.682465 [dev_pixelpipe] took 0.003 secs (0.000 CPU) [export] processed `white balance' on GPU, blended on GPU
2133.772011 [dev_pixelpipe] took 0.090 secs (0.337 CPU) [export] processed `highlight reconstruction' on CPU, blended on CPU
2133.859552 [dev_pixelpipe] took 0.088 secs (0.057 CPU) [export] processed `demosaic' on GPU, blended on GPU
2133.871214 [dev_pixelpipe] took 0.012 secs (0.003 CPU) [export] processed `exposure' on GPU, blended on GPU
2133.888416 [dev_pixelpipe] took 0.017 secs (0.005 CPU) [export] processed `input color profile' on GPU, blended on GPU
image colorspace transform Lab-->RGB took 0.013 secs (0.005 GPU) [diffuse ]
2134.327287 [dev_pixelpipe] took 0.439 secs (0.380 CPU) [export] processed `diffuse or sharpen' on GPU, blended on GPU
2136.258503 [dev_pixelpipe] took 1.931 secs (1.968 CPU) [export] processed `diffuse or sharpen 1' on GPU, blended on GPU
2136.296198 [dev_pixelpipe] took 0.038 secs (0.013 CPU) [export] processed `color balance rgb' on GPU, blended on GPU
2136.336304 [dev_pixelpipe] took 0.040 secs (0.016 CPU) [export] processed `filmic rgb' on GPU, blended on GPU
image colorspace transform RGB-->Lab took 0.014 secs (0.006 GPU) [colorout ]
2136.376052 [dev_pixelpipe] took 0.040 secs (0.019 CPU) [export] processed `output color profile' on GPU, blended on GPU
2136.408767 [dev_pixelpipe] took 0.033 secs (0.021 CPU) [export] processed `scale into final size' on GPU, blended on GPU
2136.430748 [dev_pixelpipe] took 0.022 secs (0.014 CPU) [export] processed `dithering' on CPU, blended on CPU
2136.430777 [opencl_profiling] profiling device 0 ('NVIDIA GeForce GTX 1060 6GB'):
2136.430783 [opencl_profiling] spent  0.0154 seconds in [Write Image (from host to device)]
2136.430785 [opencl_profiling] spent  0.0014 seconds in rawprepare_1f
2136.430787 [opencl_profiling] spent  0.0015 seconds in whitebalance_1f
2136.430788 [opencl_profiling] spent  0.0348 seconds in [Read Image (from device to host)]
2136.430789 [opencl_profiling] spent  0.0005 seconds in border_interpolate
2136.430790 [opencl_profiling] spent  0.0026 seconds in rcd_border_green
2136.430791 [opencl_profiling] spent  0.0035 seconds in rcd_border_redblue
2136.430793 [opencl_profiling] spent  0.0027 seconds in rcd_populate
2136.430794 [opencl_profiling] spent  0.0027 seconds in rcd_step_1_1
2136.430795 [opencl_profiling] spent  0.0020 seconds in rcd_step_1_2
2136.430797 [opencl_profiling] spent  0.0013 seconds in rcd_step_2_1
2136.430799 [opencl_profiling] spent  0.0035 seconds in rcd_step_3_1
2136.430800 [opencl_profiling] spent  0.0019 seconds in rcd_step_4_1
2136.430801 [opencl_profiling] spent  0.0010 seconds in rcd_step_4_2
2136.430802 [opencl_profiling] spent  0.0029 seconds in rcd_step_5_1
2136.430803 [opencl_profiling] spent  0.0046 seconds in rcd_step_5_2
2136.430803 [opencl_profiling] spent  0.0048 seconds in rcd_write_output
2136.430804 [opencl_profiling] spent  0.0182 seconds in [Copy Image (on device)]
2136.430807 [opencl_profiling] spent  0.0054 seconds in exposure
2136.430808 [opencl_profiling] spent  0.0068 seconds in colorin_unbound
2136.430809 [opencl_profiling] spent  0.0055 seconds in colorspaces_transform_lab_to_rgb_matrix
2136.430810 [opencl_profiling] spent  0.1759 seconds in blur_2D_Bspline_horizontal
2136.430811 [opencl_profiling] spent  0.6118 seconds in blur_2D_Bspline_vertical
2136.430812 [opencl_profiling] spent  0.2600 seconds in wavelets_detail_level
2136.430813 [opencl_profiling] spent  1.1835 seconds in diffuse_pde
2136.430814 [opencl_profiling] spent  0.0087 seconds in colorbalancergb
2136.430815 [opencl_profiling] spent  0.0053 seconds in filmic_mask_clipped_pixels
2136.430818 [opencl_profiling] spent  0.0073 seconds in filmicrgb_chroma
2136.430819 [opencl_profiling] spent  0.0055 seconds in colorspaces_transform_rgb_matrix_to_lab
2136.430820 [opencl_profiling] spent  0.0102 seconds in colorout
2136.430821 [opencl_profiling] spent  0.0231 seconds in interpolation_resample
2136.430822 [opencl_profiling] spent  2.4144 seconds totally in command queue (with 0 events missing)
2136.430838 [dev_process_export] pixel pipeline processing took 2.759 secs (2.841 CPU)
[export_job] exported to `/tmp/darktable_exported/DSC_9619.jpg'
Open in darkroom: 
2245.463973 [dev] took 0.000 secs (0.000 CPU) to load the image.
2245.818420 [histogram] took 0.002 secs (0.002 CPU) scope draw
2245.832930 [dev] took 0.000 secs (0.000 CPU) to load the image.
2245.844915 [histogram] took 0.002 secs (0.005 CPU) scope draw
2245.858378 [histogram] took 0.002 secs (0.006 CPU) scope draw
2245.875788 [histogram] took 0.003 secs (0.001 CPU) scope draw
2245.893706 [histogram] took 0.004 secs (0.008 CPU) scope draw
2245.908368 [histogram] took 0.003 secs (0.006 CPU) scope draw
2245.925496 [histogram] took 0.003 secs (0.007 CPU) scope draw
2245.940832 [histogram] took 0.002 secs (0.006 CPU) scope draw
2245.957964 [histogram] took 0.003 secs (0.002 CPU) scope draw
2245.973814 [histogram] took 0.002 secs (0.004 CPU) scope draw
2245.991754 [histogram] took 0.003 secs (0.003 CPU) scope draw
2245.998469 [dev_pixelpipe] took 0.127 secs (0.130 CPU) [full] processed `demosaic' on GPU, blended on GPU
2246.005656 [dev_pixelpipe] took 0.007 secs (0.000 CPU) [full] processed `exposure' on GPU, blended on GPU
2246.006978 [dev_pixelpipe] took 0.001 secs (0.001 CPU) [full] processed `input color profile' on GPU, blended on GPU
2246.007378 [histogram] took 0.002 secs (0.003 CPU) scope draw
image colorspace transform Lab-->RGB took 0.002 secs (0.005 GPU) [diffuse ]
2246.024243 [dev_pixelpipe] took 0.017 secs (0.017 CPU) [full] processed `diffuse or sharpen' on GPU, blended on GPU
2246.024665 [histogram] took 0.003 secs (0.007 CPU) scope draw
2246.068068 [dev_pixelpipe] took 0.044 secs (0.043 CPU) [full] processed `diffuse or sharpen 1' on GPU, blended on GPU
2246.075405 [dev_pixelpipe] took 0.007 secs (0.003 CPU) [full] processed `color balance rgb' on GPU, blended on GPU
2246.077777 [dev_pixelpipe] took 0.002 secs (0.000 CPU) [full] processed `filmic rgb' on GPU, blended on GPU
image colorspace transform RGB-->Lab took 0.001 secs (0.000 GPU) [colorout ]
2246.080886 [dev_pixelpipe] took 0.003 secs (0.001 CPU) [full] processed `output color profile' on GPU, blended on GPU
2246.087558 [dev_pixelpipe] took 0.007 secs (0.016 CPU) [full] processed `display encoding' on CPU, blended on CPU
2246.087571 [opencl_profiling] profiling device 0 ('NVIDIA GeForce GTX 1060 6GB'):
2246.087573 [opencl_profiling] spent  0.0097 seconds in [Write Image (from host to device)]
2246.087575 [opencl_profiling] spent  0.0005 seconds in border_interpolate
2246.087576 [opencl_profiling] spent  0.0028 seconds in rcd_border_green
2246.087578 [opencl_profiling] spent  0.0061 seconds in rcd_border_redblue
2246.087579 [opencl_profiling] spent  0.0039 seconds in rcd_populate
2246.087580 [opencl_profiling] spent  0.0034 seconds in rcd_step_1_1
2246.087581 [opencl_profiling] spent  0.0022 seconds in rcd_step_1_2
2246.087583 [opencl_profiling] spent  0.0016 seconds in rcd_step_2_1
2246.087585 [opencl_profiling] spent  0.0038 seconds in rcd_step_3_1
2246.087586 [opencl_profiling] spent  0.0023 seconds in rcd_step_4_1
2246.087587 [opencl_profiling] spent  0.0012 seconds in rcd_step_4_2
2246.087588 [opencl_profiling] spent  0.0043 seconds in rcd_step_5_1
2246.087590 [opencl_profiling] spent  0.0073 seconds in rcd_step_5_2
2246.087591 [opencl_profiling] spent  0.0082 seconds in rcd_write_output
2246.087592 [opencl_profiling] spent  0.0202 seconds in interpolation_resample
2246.087593 [opencl_profiling] spent  0.0003 seconds in exposure
2246.087595 [opencl_profiling] spent  0.0003 seconds in colorin_unbound
2246.087596 [opencl_profiling] spent  0.0004 seconds in [Copy Image (on device)]
2246.087598 [opencl_profiling] spent  0.0002 seconds in colorspaces_transform_lab_to_rgb_matrix
2246.087599 [opencl_profiling] spent  0.0045 seconds in blur_2D_Bspline_horizontal
2246.087600 [opencl_profiling] spent  0.0068 seconds in blur_2D_Bspline_vertical
2246.087601 [opencl_profiling] spent  0.0064 seconds in wavelets_detail_level
2246.087603 [opencl_profiling] spent  0.0266 seconds in diffuse_pde
2246.087604 [opencl_profiling] spent  0.0144 seconds in [Read Image (from device to host)]
2246.087606 [opencl_profiling] spent  0.0004 seconds in colorbalancergb
2246.087607 [opencl_profiling] spent  0.0001 seconds in filmic_mask_clipped_pixels
2246.087608 [opencl_profiling] spent  0.0003 seconds in filmicrgb_chroma
2246.087609 [opencl_profiling] spent  0.0002 seconds in colorspaces_transform_rgb_matrix_to_lab
2246.087610 [opencl_profiling] spent  0.0004 seconds in colorout
2246.087612 [opencl_profiling] spent  0.1389 seconds totally in command queue (with 0 events missing)
2246.087886 [dev_process_image] pixel pipeline processing took 0.225 secs (0.213 CPU)
2246.113429 [histogram] took 0.002 secs (0.005 CPU) scope draw
2246.128578 [dev_pixelpipe] took 0.000 secs (0.000 CPU) initing base buffer [preview]
2246.129828 [dev_pixelpipe] took 0.001 secs (0.001 CPU) [preview] processed `raw black/white point' on GPU, blended on GPU
2246.130457 [dev_pixelpipe] took 0.001 secs (0.000 CPU) [preview] processed `white balance' on GPU, blended on GPU
2246.134592 [dev_pixelpipe] took 0.004 secs (0.016 CPU) [preview] processed `highlight reconstruction' on CPU, blended on CPU
2246.139789 [dev_pixelpipe] took 0.005 secs (0.001 CPU) [preview] processed `demosaic' on GPU, blended on GPU
2246.140581 [dev_pixelpipe] took 0.001 secs (0.000 CPU) [preview] processed `exposure' on GPU, blended on GPU
2246.141943 [dev_pixelpipe] took 0.001 secs (0.001 CPU) [preview] processed `input color profile' on GPU, blended on GPU
image colorspace transform Lab-->RGB took 0.001 secs (0.001 GPU) [diffuse ]
2246.156519 [dev_pixelpipe] took 0.015 secs (0.007 CPU) [preview] processed `diffuse or sharpen' on GPU, blended on GPU
2246.214564 [dev_pixelpipe] took 0.058 secs (0.046 CPU) [preview] processed `diffuse or sharpen 1' on GPU, blended on GPU
2246.218650 [dev_pixelpipe] took 0.004 secs (0.004 CPU) [preview] processed `color balance rgb' on GPU, blended on GPU
2246.220866 [dev_pixelpipe] took 0.002 secs (0.002 CPU) [preview] processed `filmic rgb' on GPU, blended on GPU
image colorspace transform RGB-->Lab took 0.001 secs (0.001 GPU) [colorout ]
2246.224093 [dev_pixelpipe] took 0.003 secs (0.003 CPU) [preview] processed `output color profile' on GPU, blended on GPU
2246.228642 [dev_pixelpipe] took 0.005 secs (0.020 CPU) [preview] processed `display encoding' on CPU, blended on CPU
image colorspace transform RGB-->RGB took 0.003 secs (0.026 CPU) [final histogram]
2246.237154 [histogram] took 0.009 secs (0.035 CPU) final rgb parade
2246.237168 [opencl_profiling] profiling device 0 ('NVIDIA GeForce GTX 1060 6GB'):
2246.237171 [opencl_profiling] spent  0.0006 seconds in [Write Image (from host to device)]
2246.237173 [opencl_profiling] spent  0.0001 seconds in rawprepare_1f
2246.237174 [opencl_profiling] spent  0.0001 seconds in whitebalance_1f
2246.237175 [opencl_profiling] spent  0.0068 seconds in [Read Image (from device to host)]
2246.237177 [opencl_profiling] spent  0.0001 seconds in border_interpolate
2246.237178 [opencl_profiling] spent  0.0001 seconds in rcd_border_green
2246.237179 [opencl_profiling] spent  0.0002 seconds in rcd_border_redblue
2246.237181 [opencl_profiling] spent  0.0001 seconds in rcd_populate
2246.237182 [opencl_profiling] spent  0.0001 seconds in rcd_step_1_1
2246.237184 [opencl_profiling] spent  0.0001 seconds in rcd_step_1_2
2246.237185 [opencl_profiling] spent  0.0001 seconds in rcd_step_2_1
2246.237186 [opencl_profiling] spent  0.0002 seconds in rcd_step_3_1
2246.237188 [opencl_profiling] spent  0.0001 seconds in rcd_step_4_1
2246.237189 [opencl_profiling] spent  0.0001 seconds in rcd_step_4_2
2246.237190 [opencl_profiling] spent  0.0001 seconds in rcd_step_5_1
2246.237191 [opencl_profiling] spent  0.0002 seconds in rcd_step_5_2
2246.237192 [opencl_profiling] spent  0.0002 seconds in rcd_write_output
2246.237193 [opencl_profiling] spent  0.0003 seconds in exposure
2246.237194 [opencl_profiling] spent  0.0003 seconds in colorin_unbound
2246.237195 [opencl_profiling] spent  0.0006 seconds in [Copy Image (on device)]
2246.237196 [opencl_profiling] spent  0.0003 seconds in colorspaces_transform_lab_to_rgb_matrix
2246.237198 [opencl_profiling] spent  0.0058 seconds in blur_2D_Bspline_horizontal
2246.237199 [opencl_profiling] spent  0.0091 seconds in blur_2D_Bspline_vertical
2246.237199 [opencl_profiling] spent  0.0081 seconds in wavelets_detail_level
2246.237201 [opencl_profiling] spent  0.0309 seconds in diffuse_pde
2246.237202 [opencl_profiling] spent  0.0005 seconds in colorbalancergb
2246.237203 [opencl_profiling] spent  0.0002 seconds in filmic_mask_clipped_pixels
2246.237205 [opencl_profiling] spent  0.0004 seconds in filmicrgb_chroma
2246.237206 [opencl_profiling] spent  0.0003 seconds in colorspaces_transform_rgb_matrix_to_lab
2246.237208 [opencl_profiling] spent  0.0005 seconds in colorout
2246.237209 [opencl_profiling] spent  0.0666 seconds totally in command queue (with 0 events missing)
2246.237720 [dev_process_preview] pixel pipeline processing took 0.137 secs (0.184 CPU)
2246.247594 [histogram] took 0.002 secs (0.002 CPU) scope draw
2247.913691 [histogram] took 0.002 secs (0.002 CPU) scope draw
2247.934520 [histogram] took 0.002 secs (0.002 CPU) scope draw
2247.950246 [histogram] took 0.003 secs (0.003 CPU) scope draw
2247.966070 [histogram] took 0.002 secs (0.002 CPU) scope draw
2247.986156 [histogram] took 0.003 secs (0.003 CPU) scope draw
2248.000026 [histogram] took 0.002 secs (0.002 CPU) scope draw
2248.016939 [histogram] took 0.002 secs (0.002 CPU) scope draw
2248.038371 [histogram] took 0.003 secs (0.003 CPU) scope draw
2248.054564 [histogram] took 0.003 secs (0.003 CPU) scope draw
2248.067630 [histogram] took 0.002 secs (0.002 CPU) scope draw
2248.083854 [histogram] took 0.002 secs (0.002 CPU) scope draw
1 Like
65

Kofa, I can’t get it to crash either. Can you try with OpenCL tunning on?

66

Mine is set to
image

67

On my system, setting it to memory transfer seemed the ‘best’ way to make it break.

68

NVidia does not benefit from that, as far as I know – on the contrary.

69

Yes, sorry, I had gathered that - it didn’t speed it up anyway and from reading this thread I actually thought that might be the cause of my ‘issue’. User error, in other words.
I only mentioned it, because as I said above (somewhere…) that seems to be the setting that reproduces the problem. In the weekly build thread I noticed that @Bernhard_Vogler has a similar issue - which might be tied in to the same thing?