RCD yields different results with same params (color smoothing)

[kofa73]

Describe the bug Changing the color smoothing parameter of RCD gives semi-random results, same parameters leading to different result.

To Reproduce

1. Import the raw + sidecar from https://tech.kovacs-telekes.org/files/2021-01-08-darktable-rcd/
2. Select RCD demosaicing
3. Using the mouse scroll wheel, choose different smoothing levels, sometimes resetting the module, switching to another demosaic method
4. You'll sometimes see the edge of the pavement, illuminated by the tram's lights, change: -- smoothing = 2 -- smoothing = 3 -- smoothing = 1 -- smoothing = 2 again (compare with 1st screenshot)

Expected behavior Consistent behaviour

Platform (please complete the following information):

• Darktable Version: 3.5.0+492~g04eca63b3-dirty (dirty because of local application of f5502e1a as test)
• OS: Ubuntu 20.10
• OpenCL: active, but RCD is CPU-only, right?

[kofa73]

Not specific to smoothing = 2, I first saw this with smoothing = 5.

[jenshannoschwalm]

Hi, i am also aware of this since yesterday. There is something wrong with optimizing code and i am already working on that...

[jenshannoschwalm]

@kofa73 could you please check if this fixes your issue? (I tested your image and could not reproduce any longer, at least what i detected)

If it persists, i would

1. need your memory size to check whether this might be a dt tiling issue
2. cpu?
3. graphics card?

[kofa73]

3.5.0+530~g7c6069cde Still reproducible. Memory size is 4 GB, CPU is Core2 Duo

$ cat /proc/cpuinfo 
processor       : 0
vendor_id       : GenuineIntel
cpu family      : 6
model           : 15
model name      : Intel(R) Core(TM)2 Duo CPU     E6550  @ 2.33GHz
stepping        : 11
microcode       : 0xba
cpu MHz         : 2000.083
cache size      : 4096 KB
physical id     : 0
siblings        : 2
core id         : 0
cpu cores       : 2
apicid          : 0
initial apicid  : 0
fpu             : yes
fpu_exception   : yes
cpuid level     : 10
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ht tm pbe syscall nx lm constant_tsc arch_perfmon pebs bts rep_good nopl cpuid aperfmperf pni dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm lahf_lm pti tpr_shadow vnmi flexpriority vpid dtherm
vmx flags       : vnmi flexpriority tsc_offset vtpr vapic
bugs            : cpu_meltdown spectre_v1 spectre_v2 spec_store_bypass l1tf mds swapgs itlb_multihit
bogomips        : 4666.86
clflush size    : 64
cache_alignment : 64
address sizes   : 36 bits physical, 48 bits virtual

Graphics card is Nvidia 1060/6GB, driver: 450.102.04-0ubuntu0.20.10.1, nvidia-opencl-dev:amd64 11.0.3-1ubuntu1

[kofa73]

If it helps: PPG, Amaze, VZG and RCD all looks more or less the same without smoothing (I mean that they all have a brighter area surrounded by a distinct grey outline):

Turning on smoothing:

• PPG does not really change (retains the distinct outline):
• Amaze changes (it appears brighter to me, and the outline is gone):
• RCD sometimes changes (losing the outline, like Amaze), sometimes does not:

[kofa73]

Could it be a concurrency issue? Performing the calculation, but failing to propagate the result? This is what I see on the console:

1033.970640 [dev] took 0.000 secs (0.000 CPU) to load the image.
1033.970834 [pixelpipe_process] [preview] using device 0
 CPU    `RCD' did 1.1mpix, 0.0985 secs (0.1514 CPU), 10.98 pix/us
1034.421355 [dev_pixelpipe] took 0.450 secs (0.753 CPU) processed `demosaic' on CPU, blended on CPU [preview]
1034.451491 [dev_pixelpipe] took 0.030 secs (0.015 CPU) processed `denoise (profiled)' on GPU, blended on GPU [preview]
1034.453276 [dev_pixelpipe] took 0.002 secs (0.001 CPU) processed `exposure' on GPU, blended on GPU [preview]
1034.508392 [dev_pixelpipe] took 0.055 secs (0.086 CPU) processed `tone equalizer' on CPU, blended on CPU [preview]
1034.521741 [dev_pixelpipe] took 0.013 secs (0.008 CPU) processed `input color profile' on GPU, blended on GPU [preview]
1034.614498 [dev_pixelpipe] took 0.093 secs (0.155 CPU) processed `color zones' on GPU, collected histogram on GPU, blended on GPU [preview]
image colorspace transform Lab-->RGB took 0.027 secs (0.047 CPU) [channelmixerrgb ]
1034.927461 [dev_pixelpipe] took 0.313 secs (0.585 CPU) processed `color calibration' on CPU, blended on CPU [preview]
1035.004359 [pixelpipe_process] [full] using device -1
 CPU    `RCD' did 0.0mpix, 0.0025 secs (0.0065 CPU), 7.21 pix/us
1035.019372 [dev_pixelpipe] took 0.015 secs (0.029 CPU) processed `demosaic' on CPU, blended on CPU [full]

But sometimes the full pipeline runs on device 0 as well (does this matter? RCD is CPU-only, it seems):

998.404742 [dev_process_image] pixel pipeline processing took 0.929 secs (1.359 CPU)
scope draw took 0.001 secs (0.001 CPU)
1000.450282 [dev] took 0.000 secs (0.000 CPU) to load the image.
1000.450366 [pixelpipe_process] [full] using device 0
 CPU    `RCD' did 0.0mpix, 0.0028 secs (0.0024 CPU), 6.27 pix/us
1000.465860 [dev_pixelpipe] took 0.015 secs (0.019 CPU) processed `demosaic' on CPU, blended on CPU [full]

At the end, OpenCL seems to be fine:

2152.542968 [opencl_summary_statistics] device 'GeForce GTX 1060 6GB' (0): 8578 out of 8578 events were successful and 0 events lost

[jenshannoschwalm]

This is not the problem as you probably have set OpenCL schedule set to default. So the main windows renders via CL code and the preview takes CPU. I will investigate further

[jenshannoschwalm]

Can you confirm that the issue is not present if you do a "menu selection" instead of mouse scroll?

[jenshannoschwalm]

It is pretty easy to reproduce by inserting

fprintf(stderr,"\n commit smoothing %i", d->color_smoothing);

into commit_params in demosaic.c at around L.4910

It pretty ease to trigger when scrolling via mouse through the color smoothing menu. If you scroll slowly or select "as a menu item" this simply works, if you scroll fast it may happen that a) the gtk menu is updated correctly, b) the parameter is committed but c) there is no reprocessing of the pipeline.

[kofa73]

Can you confirm that the issue is not present if you do a "menu selection" instead of mouse scroll?

Nope. I have just triggered it by selecting from the menu, without the use of the mouse wheel.

[kofa73]

This is not the problem as you probably have set OpenCL schedule set to default. So the main windows renders via CL code and the preview takes CPU. I will investigate further

I meant these lines:

1000.450366 [pixelpipe_process] [full] using device 0
 CPU    `RCD' did 0.0mpix, 0.0028 secs (0.0024 CPU), 6.27 pix/us

and

1035.004359 [pixelpipe_process] [full] using device -1
 CPU    `RCD' did 0.0mpix, 0.0025 secs (0.0065 CPU), 7.21 pix/us

The preview was

1033.970834 [pixelpipe_process] [preview] using device 0
 CPU    `RCD' did 1.1mpix, 0.0985 secs (0.1514 CPU), 10.98 pix/us

but the above two are the full pipeline.

[jenshannoschwalm]

Does this also happen if you switch on the green correction, this should disable tiling.

I will look deeper into this tomorrow.

[kofa73]

Yes, it happens with the green correction enabled, as well. I used the menu, not the mouse wheel:

[johnny-bit]

7765 has been merged... Can you still replicate the problem using current master?

[jenshannoschwalm]

@johnny-bit , it is still reproducable because the merged pr was only fixing a bad rcd demosaicer bug which i first thought would be the reason for that.

This real issue is something not related to rcd demosaicer at all, it can also be triggered using other demosaicers like amaze. I will push a pr soon that likely won't fix it but will give other devs an understanding whats going on.

Basically it comes down to:

1. change a bauhaus menu item
2. definitly commit_parameters follows the selection
3. a pipeline process is not triggered in some cases. This is something i don't yet understand so will do the pr which helps debugging demosaicers anyway and will make this easier to reproduce for us all.

[johnny-bit]

Ah, so probably some pipe caching issue is in play.

[jenshannoschwalm]

I have tested demosaicing quite a lot over the last weeks, I cant't confirm a pipeline caching problem any more and can't reproduce atm. Checked committing parameters extensively ...

Don't know what to do ...

[kofa73]

Still reproducible with a61521424d.

The log shows some very interesting commit lines (these are adjacent lines, note the timestamps - are those offsets since start of the applicatin?). I was not clicking wildly around: 97.797750 [demosaic] committed parameters: method: PPG', smooth 0, green 0, CL 1, tiling 1 97.799843 [dev] took 0.000 secs (0.000 CPU) to load the image. 97.848076 [demosaic] committed parameters: method:PPG', smooth 0, green 0, CL 1, tiling 1 97.901706 [demosaic] committed parameters: method: VNG4', smooth 0, green 0, CL 1, tiling 1 97.966955 [demosaic] committed parameters: method:AMaZE', smooth 4, green 2, CL 0, tiling 0 98.006017 [demosaic] committed parameters: method: AMaZE', smooth 4, green 2, CL 0, tiling 0 98.021597 [demosaic] committed parameters: method:RCD', smooth 5, green 0, CL 0, tiling 1 98.021624 [demosaic] committed parameters: method: RCD', smooth 1, green 0, CL 0, tiling 1 98.021641 [demosaic] committed parameters: method:RCD', smooth 5, green 0, CL 0, tiling 1 98.021656 [demosaic] committed parameters: method: RCD', smooth 5, green 0, CL 0, tiling 1 98.021672 [demosaic] committed parameters: method:RCD', smooth 2, green 3, CL 0, tiling 0 98.021688 [demosaic] committed parameters: method: RCD', smooth 0, green 3, CL 0, tiling 0 98.021734 [demosaic] committed parameters: method:PPG', smooth 0, green 0, CL 1, tiling 1

More log (I forgot to send to file, so this is a dump from the terminal, the beginning is missing): https://tech.kovacs-telekes.org/files/2021-01-08-darktable-rcd/console.log

[jenshannoschwalm]

Those lines are all fine, coming from history stack.

I am staring on the images and can't reproduce. What am i doing wrong ... how to debug pixelpipe caching ...

[kofa73]

I've added my darktablerc for reference.

[jenshannoschwalm]

@kofa73 this issue is really hunting me as i a) don't understand the reason for the problem and b) really can't reproduce. I see the subtle differences but i am not sure yet about what is behind that.

I think i know a way to test maybe better, the rcd demosaicer does a simple border approximation leading to "checkerboard" in the outermost 6 pixels. But we can use these pixels to better see the effect of smoothing. So please look out for an image with such patterns and enlarge to 1600% thus avoiding any later scaling algo. Here i used this region

Now the smoothing for all iterations becomes pretty obvious...

[kofa73]

I'm sorry, I can't figure out which part of which image this is :-) Above I posted a B&W conversion, but I see coloured pixels in your screenshot, and I have no idea if it's from the tram arriving at the stop (linked to this issue), or the other one from #8016. Could you please post a zoomed-out shot showing the position in the image? Or is it not one of mine?

[kofa73]

My build script, just in case you can spot something:

#!/bin/bash
renice -n 19 -p $$
ionice -c 3 -p $$

cd ~/darktable ; 
git clean -d -f -x ;
#git submodule init
git submodule update
git pull --rebase
# --recurse-submodules
./build.sh --disable-lua --disable-camera --disable-flickr --disable-kwallet --disable-libsecret --disable-map --disable-mac_integration --disable-webp --disable-game --prefix /home/kofa/darktable-master && rm -rf /home/kofa/darktable-master.backup ; mv /home/kofa/darktable-master /home/kofa/darktable-master.backup ; cmake --build "/home/kofa/darktable/build" --target install -- -j1

Is there any other file (CMakeCache.txt) that would help with the diagnosis? Or could we set up a remote debugging session somehow? Remote X? VNC?

[jenshannoschwalm]

Yes you posted b&w and a different image :-) If we want to reproduce any problem with demosaicer and smoothing a) choose an image and a region where pixel diferences are large so we can see better and b) use a scale that avoids later interpolation so 1600%

So your image in color shows "better to see" patterns in this region

I can't see any issue

[kofa73]

Perhaps it's easier to see if they are side-by-side (or download the screenshots and use them as layers in the Gimp):

I'm not sure we're after the same issue, though.

[kofa73]

Since with a minimal set of modules I can't reproduce, either, maybe it's some problem with caching when we have many modules on the pipe.

[jenshannoschwalm]

Yes, I am not sure either we look for the same problem. For me it is just, does changing any of the demosaic parameters leads to same pixels at this stage of the pipeline. And to discuss pixels we have to zoom in at least to 800% to be sure there is not interpolation afterwards.

So concider to close the issue and maybe open one after more understanding.

The other issue about interpolation really might interfere here.

[kofa73]

Not an issue with RCD