PhotoFlow: new caching mechanism - TESTING NEEDED!

[afre (Alan)]

Grateful for the stable branch.

I won’t be able to roll up my sleeves on this one but if there are simple things you would like me to check let me know. (I noticed that Paul and Gustavo aren’t using win10.)

[Carmelo_DrRaw]

@gadolf

I did it and got a new freeze, although I was able to do more work this time.

Sorry, I should have written more explicit instructions…
Run photoflow as you are doing already. Once there is a crash and you get back to the gdb prompt, type the following:

set pagination off
set logging file log.txt
set logging on
info threads
thread apply all bt full

The first three commands instruct gdb to write the subsequent output directly to a log file, and not the terminal. The last two print some information about the running threads and the the full backtrace from all threads.

Your latest log file only provides the reason for the crash and the latest offending function call, which is however just marked as ?? ().

By the way, it seems that the crash happened once more when deleting a gradient layer. Is that correct?

@afre

I won’t be able to roll up my sleeves on this one but if there are simple things you would like me to check let me know.

The description of any reproducible crash would already be extremely useful, particularly since you are using win10.
Thanks!

[gadolf (Gustavo Adolfo)]

@Carmelo_DrRaw

Sorry, I should have written more explicit instructions…

My sorry, you had already pointed to the rawpedia instructions and I didn’t read it. Btw, a typical example of how users refuse to read manuals and eagerly start doing things without knowing exactly what they’re doing , much like what is being currently discussed on this thread.

Can we make RawTherapee look less complex on very first sight (for brand new users)?

One comment I see quite often when people try RT for the first time, is that it looks way too complex to them. Of course RT has many controls, but maybe not that much compared to Darktable, which often people find less complex on first sight than RT. I think that this first “bad” impression comes from the fact that on first launch and opening a image in the editor, all the modules are unfolded, showing all the controls. The tool panel looks like this on first launch: [Screenshot_1] Yeah, I c…

Never mind, I’ll follow those steps from now on, and here’s a new one, where the crash happened while deleting a layer.
log.txt (41.4 KB)

[gadolf (Gustavo Adolfo)]

Another one that happened when I was tweaking local contrast sliders.

IMG_5719.cr2 (13.2 MB)
IMG_5719.pfi (72.5 KB) (not sure it it’s up-to-date)
log.txt (100.1 KB)

[paulmiller]

I’m not seeing any crashes or freezes (running photoflow in normal mode) with HEAD-ccb0c.

Odd behaviours:

Perspective Correction - doesn’t update the image unless you hide and show another layer to force a cache rebuild.

Crop - still confused if you try to edit an existing crop (get the crop box offset on top of the cropped image, as if crop is treating the cropped image as the original {maybe it is showing the cached image}. When testing, make sure the top,left of the crop box is not at the top left of the original image. Turning the crop layer off and on again fixes this.

Colourspace Conversion - very strange if you enable ‘assign profile’. The image changes as you would expect, but then you cant turn the colour space conversion off, if you turn the layer off the image does not change.

[paulmiller]

I don’t think this one is specific to the new caching mechanism:

Gaussian blur with radius 30 looks wrong:

The same blur applied using a GMIC interpreter layer (-blur 30,1,1):

I have had a couple of failures now in photoflow where a Segfault exception is raised, unfortunately photoflow seems to be catching these internally and not letting them propagate out to the OS so I haven’t got a macOS crash report, and the log only shows a boring stack trace of the thread that caught the signal. Unlike @gadolf, photoflow is terminating immedately rather than freezing.
I’ll try running under lldb (don’t have gdb installed) and see if I can catch the crash. Launching with lldb doesn’t work on macOS because the ‘binary’ in the photoflow.app is actually a shell script, instead I’m launching photoflow and then attaching the debugger to the apppropriate process id.

[Carmelo_DrRaw]

@gadolf
both crash logs seem to indicate that the pipeline was updated while the image was still processed. The first crash was apparently happening while deleting a gradient layer, right?

Anyhow, I am investigating… if you happen to have new crash logs, I’ll be happy to look into them. It would be also useful to have the last 10 or so lines of the terminal output in addition to the backtrace, if possible…

@paulmiller
concerning the crop tool, in fact my previous commit was missing two essential files to make it work correctly. Now it should behave ok. I do not want to give you details about the expected behavior, because I’d like to see if it is sufficiently intuitive for you…

I have also committed some changes that should fix the “colour shifts” in the preview at less than 1:1. Now the RAW image is always demosaiced and processed at full resolution, and re-scaled only afterwards. A side effect is that the update of the histogram became very slow, so at the moment the histogram is disabled in the new-caching branch. I have a proper solution in mind, but it will require some coding and it is not for tomorrow…

Concerning the perspective correction tool and the odd behavior of the “assign profile”, I will have a look.

I am also aware of the bad quality of the gaussian blur at large radii, I think I am using a fast but sub-optimal algorithm… I should simply get some code for RT, I’m sure those guys did it properly

Finally, I the latest OSX package is compiled with debugging symbols included.
I suggest you to edit the /Applications/photoflow.app/Contents/MacOS/photoflow script, and replace the last line:

$EXEC "$bundle_contents/Resources/bin/$name" "$@" $EXTRA_ARGS

by

lldb "$bundle_contents/Resources/bin/$name"

to automatically start the program through the debugger.
The launch the software from the command line:

$ /Applications/photoflow.app/Contents/MacOS/photoflow

Hope this is clear.

Thanks to all of you for your help!

[heckflosse (Ingo Weyrich)]

@Carmelo_DrRaw

At zoom levels below 1:1 a simple fast demosaicing is used. With the past caching mechanism, the cached image was computed at 1:1 and the re-scaled, while not the caching happens at the zoom level requested by the preview. I need to find a proper fix for this, that is force the demosaicing at 1:1 and re-scale on the fly.

I will post an update once this is done…

My 2 cents: On fast machines (and I don’t speak about really fast machines, just about my Bulldozer from 2013), even Amaze is fast enough to be used from the beginning (even for large files). If Amaze is not fast enough, use RCD as a faster demosaic algorithm for < 100%

[Carmelo_DrRaw]

@heckflosse

My 2 cents: On fast machines (and I don’t speak about really fast machines, just about my Bulldozer from 2013), even Amaze is fast enough to be used from the beginning

In fact, it is not just the demosaicing, but also the impulse NR, the CA correction, the WB and the exposure compensation that are processed at 1:1. But that is actually still fine, especially since the output is then cached and not re-computed each time.
The main problem is that the 1:1 RAW data is currently processed twice, once for the preview and the other for the histogram, and the histogram version gets dropped from the cache because the tiles are re-used. Once I will manage to fix this double processing, things will be much smoother and re-integrating the histogram will not be an issue…

Anyhow I really appreciate the suggestion. Considering that Amaze is practically the only algorithm in PhF that takes advantage of explicit SSE2 optimizations, there is definitely room for improvement. The main limitation, as I see it, is that VIPS requires buffers in RGBRGBRGB format, which is not ideal for SSE as far as I understand it.

[heckflosse (Ingo Weyrich)]

@Carmelo_DrRaw

Anyhow I really appreciate the suggestion. Considering that Amaze is practically the only algorithm in PhF that takes advantage of explicit SSE2 optimizations, there is definitely room for improvement. The main limitation, as I see it, is that VIPS requires buffers in RGBRGBRGB format, which is not ideal for SSE as far as I understand it.

Well, a bayer demosaicer gets something like RGRG (GBGB in next row) as input and has to spit out three values for each of the input values. So I would not think, the output format is the factor which increases processing time (maybe a little bit, but not much).

[paulmiller]

@Carmelo_DrRaw

Finally, I the latest OSX package is compiled with debugging symbols included.
I suggest you to edit the /Applications/photoflow.app/Contents/MacOS/photoflow script, and replace the last line:

$EXEC "$bundle_contents/Resources/bin/$name" "$@" $EXTRA_ARGS

by

lldb "$bundle_contents/Resources/bin/$name"

to automatically start the program through the debugger.

[edited to fix problems with SIP on macOS 10.11 and newer]

On macOS 10.11 (El Capitan) and newer, SIP blocks changes to DYLD* environment variables from being passed through lldb. To fix this, you have to set DYLD_LIBRARY_PATH from inside lldb before launching photoflow:

osascript -e 'display alert "DEBUG VERSION!! Launch from terminal"'
lldb "$bundle_contents/Resources/bin/$name" -o "process launch --environment DYLD_LIBRARY_PATH=\"$bundle_lib\" -- \"$@\" $EXTRA_ARGS"

The osascript command reminds me to run this version from a terminal if I forget and double click the application icon instead.

I’ll let you know how I get on.

[gadolf (Gustavo Adolfo)]

@paulmiller

Unlike @gadolf, photoflow is terminating immedately rather than freezing.

I think the freezing it’s because of gdb, as stated in the Rawtherapee doc:

Do what you did to trigger the crash, and when RawTherapee does crash, its window will just freeze, it won’t close. You can tell that it crashed by the fact that everything in that window will have stopped responding. Alt+Tab back to the GDB terminal window.

https://rawpedia.rawtherapee.com/How_to_write_useful_bug_reports

@Carmelo_DrRaw

if you happen to have new crash logs, I’ll be happy to look into them. It would be also useful to have the last 10 or so lines of the terminal output in addition to the backtrace, if possible…

I still have the terminal open, is this what you want?

phf_tile_cache_build(): out ref count: 0x7fffa52051a0->1
OpParBase::build_many_internal(): adding tilecache for output image #0, padding=0
phf_tile_cache_build(): out ref count: 0x7fff67014980->1
OpParBase::build_many_internal(): added tilecache for output image #0, padding=0
ICCTransformPar::build(): matching input and output profiles, no transform needed

(photoflow:6877): GLib-GObject-WARNING **: 07:47:21.715: value "-1" of type 'gint' is invalid or out of range for property 'width' of type 'gint'
[New Thread 0x7fffbffff700 (LWP 3184)]
[New Thread 0x7fffd8d20700 (LWP 3185)]
[New Thread 0x7fffbf7fe700 (LWP 3186)]
[New Thread 0x7fffd9521700 (LWP 3187)]
[Thread 0x7fffd8d20700 (LWP 3185) exited]
[Thread 0x7fffd9521700 (LWP 3187) exited]
[Thread 0x7fffbffff700 (LWP 3184) exited]
[Thread 0x7fffbf7fe700 (LWP 3186) exited]
[New Thread 0x7fffd9521700 (LWP 3188)]
[New Thread 0x7fffbf7fe700 (LWP 3189)]
[Thread 0x7fffd9521700 (LWP 3188) exited]
[New Thread 0x7fffd8d20700 (LWP 3190)]
[New Thread 0x7fffbffff700 (LWP 3191)]
[Thread 0x7fffd8d20700 (LWP 3190) exited]
[Thread 0x7fffbffff700 (LWP 3191) exited]
[Thread 0x7fffbf7fe700 (LWP 3189) exited]
[New Thread 0x7fffbffff700 (LWP 3194)]
[New Thread 0x7fffd8d20700 (LWP 3196)]
[New Thread 0x7fffbf7fe700 (LWP 3197)]
[New Thread 0x7fffd9521700 (LWP 3198)]

Thread 7341 "worker" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7fffd8d20700 (LWP 3196)]
0x0000555555d92ec9 in LUT<float>::operator[]<float, void> (
    index=-nan(0x400000), this=0x7fffa503d0a0)
    at /home/gustavo/PhotoFlow/src/base/../rt/rtengine/LUT.h:449
449	        int idx = (int)index;  // don't use floor! The difference in negative space is no problems here
(gdb) set pagination off
(gdb) set logging file log.txt
(gdb) set logging on
Copying output to log.txt.
(gdb) info threads
  Id   Target Id         Frame 
  1    Thread 0x7ffff7fada00 (LWP 6877) "photoflow" 0x00007ffff60a7607 in __libc_sendmsg (fd=11, msg=0x7fffffff9a70, flags=16384) at ../sysdeps/unix/sysv/linux/sendmsg.c:28
  2    Thread 0x7fffe94a7700 (LWP 6881) "image_processor" syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
  3    Thread 0x7fffe1b1c700 (LWP 6882) "gmain" 0x00007ffff2f9dbf9 in __GI___poll (fds=0x555558e17690, nfds=2, timeout=-1) at ../sysdeps/unix/sysv/linux/poll.c:

[Morgan_Hardwood]

@gadolf you’ve missed step 8 - upload log.txt.

[gadolf (Gustavo Adolfo)]

@Morgan_Hardwood

you’ve missed step 8 - upload log.txt .

I have already done it.
It’s the same crash.
Thanks anyway.

[gadolf (Gustavo Adolfo)]

Here’s another one, when trying to delete a curves layer.

[Thread 0x7fffd8b9f700 (LWP 16561) exited]
[Thread 0x7fffdaffd700 (LWP 16564) exited]

(photoflow:14431): Gdk-WARNING **: 21:06:09.732: gdk_window_set_icon_list: icons too large
ICCTransformPar::build(): matching input and output profiles, no transform needed
[New Thread 0x7fffdaffd700 (LWP 16565)]
[New Thread 0x7fffdbfff700 (LWP 16566)]
[New Thread 0x7fffda7fc700 (LWP 16567)]
[New Thread 0x7fffd8b9f700 (LWP 16568)]
[Thread 0x7fffda7fc700 (LWP 16567) exited]
[Thread 0x7fffdaffd700 (LWP 16565) exited]
[Thread 0x7fffdbfff700 (LWP 16566) exited]
[Thread 0x7fffd8b9f700 (LWP 16568) exited]
[New Thread 0x7fffd8b9f700 (LWP 16569)]
[New Thread 0x7fffda7fc700 (LWP 16570)]
[New Thread 0x7fffdbfff700 (LWP 16571)]
[Thread 0x7fffd8b9f700 (LWP 16569) exited]
[Thread 0x7fffdbfff700 (LWP 16571) exited]
[Thread 0x7fffda7fc700 (LWP 16570) exited]
[New Thread 0x7fffdaffd700 (LWP 16572)]
[Thread 0x7fffdaffd700 (LWP 16572) exited]
[New Thread 0x7fffdaffd700 (LWP 16573)]
[New Thread 0x7fffdbfff700 (LWP 16574)]
[New Thread 0x7fffda7fc700 (LWP 16575)]
[New Thread 0x7fffd8b9f700 (LWP 16576)]
[Thread 0x7fffdaffd700 (LWP 16573) exited]
[Thread 0x7fffd8b9f700 (LWP 16576) exited]
[Thread 0x7fffdbfff700 (LWP 16574) exited]
[Thread 0x7fffda7fc700 (LWP 16575) exited]
OperationConfigGUI::disable_editing(): setting editing flag to false
ICCTransformPar::build(): matching input and output profiles, no transform needed
[New Thread 0x7fffd8b9f700 (LWP 16582)]
[New Thread 0x7fffda7fc700 (LWP 16583)]
[New Thread 0x7fffdbfff700 (LWP 16584)]
[New Thread 0x7fffdaffd700 (LWP 16585)]
[Thread 0x7fffdaffd700 (LWP 16585) exited]
[Thread 0x7fffdbfff700 (LWP 16584) exited]
[Thread 0x7fffda7fc700 (LWP 16583) exited]
[Thread 0x7fffd8b9f700 (LWP 16582) exited]
ControlsDialog::on_hide() called.
[New Thread 0x7fffdaffd700 (LWP 16586)]
[New Thread 0x7fffdbfff700 (LWP 16587)]
[New Thread 0x7fffda7fc700 (LWP 16588)]
[New Thread 0x7fffd8b9f700 (LWP 16589)]
[Thread 0x7fffdbfff700 (LWP 16587) exited]
[Thread 0x7fffdaffd700 (LWP 16586) exited]
[Thread 0x7fffd8b9f700 (LWP 16589) exited]
[Thread 0x7fffda7fc700 (LWP 16588) exited]
[New Thread 0x7fffd8b9f700 (LWP 16590)]
[New Thread 0x7fffda7fc700 (LWP 16591)]
[New Thread 0x7fffdbfff700 (LWP 16592)]
[New Thread 0x7fffdaffd700 (LWP 16593)]
[Thread 0x7fffda7fc700 (LWP 16591) exited]
[Thread 0x7fffd8b9f700 (LWP 16590) exited]
[Thread 0x7fffdbfff700 (LWP 16592) exited]
[Thread 0x7fffdaffd700 (LWP 16593) exited]
ControlsDialog::on_hide() called.
MainWindow::on_button_save_clicked(): editor->get_image()->get_filename()="/home/gustavo/Pictures/playraw/dreamy creek landscape/20190919-084717-IMG_0003.pfi"
ext: pfi
ControlsDialog::on_hide() called.
OperationConfigGUI::collapse(): resetting editing flag
~OpParBase(): deleting operation 0x7fff7c000040 (curves)
~OpParBase(): deleting operation 0x7fffe6cce870 (uniform)
~OpParBase(): deleting operation 0x7fff9d1cd230 (blender)
~OpParBase(): deleting operation 0x7fff7c303d90 (curves)
~OpParBase(): deleting operation 0x7fff9e2d49e0 (uniform)
~OpParBase(): deleting operation 0x7fff9d1fd330 (blender)
~OpParBase(): deleting operation 0x7fff9d25e8b0 (curves)
~OpParBase(): deleting operation 0x7fffe6909d50 (uniform)
~OpParBase(): deleting operation 0x7fffe6956070 (blender)
~OpParBase(): deleting operation 0x55555b8436d0 (curves)
~OpParBase(): deleting operation 0x55555b72e060 (uniform)
~OpParBase(): deleting operation 0x55555b5e5180 (blender)
ColorCorrectionPar::build(): 1  0  1
ConvertColorspacePar::build(): Getting built-in profile: sRGB
ConvertColorspacePar::build(): tr_par->get_LSh_format()=0
ColorCorrectionPar::build(): 1  0  1
ConvertColorspacePar::build(): Getting built-in profile: sRGB
ConvertColorspacePar::build(): tr_par->get_LSh_format()=0
ICCTransformPar::build(): matching input and output profiles, no transform needed
ColorCorrectionPar::build(): 1  0  1
ConvertColorspacePar::build(): Getting built-in profile: sRGB
ConvertColorspacePar::build(): tr_par->get_LSh_format()=0
[New Thread 0x7fffdaffd700 (LWP 16602)]
[New Thread 0x7fffdbfff700 (LWP 16603)]
[New Thread 0x7fffda7fc700 (LWP 16604)]
[New Thread 0x7fffd8b9f700 (LWP 16605)]

Thread 2011 "worker" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7fffdaffd700 (LWP 16602)]
0x0000555555de6f32 in vips_layer_gen (oreg=0x55555bba43a0, seq=0x7fffb04f89e0, 
    a=<optimized out>, b=0x7fff9f826590, stop=<optimized out>)
    at /home/gustavo/PhotoFlow/src/vips/layer.cc:192
192	      layer->processor->get_par()->transform_inv(r, &s, i);
(gdb) set pagination off
(gdb) set logging file log.txt
(gdb) set logging on
Copying output to log.txt.
(gdb) info threads
  Id   Target Id         Frame 
  1    Thread 0x7ffff7fada00 (LWP 14431) "photoflow" syscall () at ../sysdeps/unix/sysv/

log.txt (101.6 KB)

and what I had done so far:
20190919-084717-IMG_0003.pfi (31.3 KB)

The image is from the Dreamy Creek Landscape play raw.

I could reproduced the crash many times:
1 - Reopened the pfi file
2 - Answered yes to restore from the last crash
3 - Tried to delete the first curve from bottom to top

[Carmelo_DrRaw]

@gadolf

I could reproduced the crash many times:
1 - Reopened the pfi file
2 - Answered yes to restore from the last crash
3 - Tried to delete the first curve from bottom to top

Confirmed, I am looking into it.

[Carmelo_DrRaw]

@gadolf the crash when deleting layers should be fixed now. I have also fixed the Glib warning that appeared in the terminal output from time to time, although it was harmless…

new packages are ready for download.

Thanks!

[gadolf (Gustavo Adolfo)]

Thanks, eager to try it!

I started building it but I won’t be able to test it before tonight or tomorrow morning.

[paulmiller]

Can confirm that @gadolf’s test case is no longer crashing on macOS with the latest (9831e) version.
(well done finding a reproducable test case by the way)

The colour shift at non 1:1 scaling is fixed.
The crop tool is fixed.
The perspective correction tool is fixed.
“assign profile” is still strange

[paulmiller]

Just found a crash in (9831e):

(this is using the file I uploaded for the colour shift case)
DSC_1018_crash.pfi (47.4 KB)

Steps to reproduce:

1. Open DSC_1018_crash.pfi
2. Open the mask on the top ‘curves’ layer
3. Click ‘Show Mask’
4. Turn off the curves layer on the mask.

The log shows an assertion failure:

... layer "colorspace conversion" finished
PF::Image::do_update(): pipeline #0 updated.
PF::Image::do_update(): preparing pipeline #1
PF::Image::do_update(): updating pipeline #1
LayerManager::rebuild_chain(): rebuilding blender output for layer "curves"
LayerManager::rebuild_chain(): vips_image_invalidate_all() called on node->blended
Building layer "layer clone"...
... layer "layer clone" finished
Building layer "basic adjustments"...
... layer "basic adjustments" finished
Building layer "colorspace conversion"...
ConvertColorspacePar::build(): Getting built-in profile: sRGB
ConvertColorspacePar::build(): tr_par->get_LSh_format()=0
... layer "colorspace conversion" finished

(photoflow:22473): GLib-GObject-WARNING **: 11:27:30.564: invalid uninstantiatable type '<invalid>' in cast to 'GObject'
**
ERROR:/Users/travis/build/aferrero2707/PhotoFlow/src/base/photoflow.cc:443:void PF::pf_object_unref(GObject *, const char *): assertion failed: (object->ref_count > 0)

Crash report:

0   libsystem_kernel.dylib        	0x00007fff5f7952c6 __pthread_kill + 10
1   libsystem_pthread.dylib       	0x00007fff5f850bf1 pthread_kill + 284
2   libsystem_c.dylib             	0x00007fff5f6ff6a6 abort + 127
3   libglib-2.0.0.dylib           	0x0000000105304688 g_assertion_message + 423
4   libglib-2.0.0.dylib           	0x00000001053046e6 g_assertion_message_expr + 94
5   photoflow                     	0x00000001029fd12b PF::pf_object_unref(_GObject*, char const*) + 59

EDIT: Never mind, the source for the Clone Layer on the mask wasn’t set. If I set it then the crash goes away.