search

Beep6581 / RawTherapee

A powerful cross-platform raw photo processing program
https://rawtherapee.com
GNU General Public License v3.0
2.79k stars 316 forks source link

locallab issues when editing spot outline #5419

Open ff2000 opened 5 years ago

ff2000 commented 5 years ago

I just pulled the recent changes, especially those that fix the conflict with crop handle. #5354 is fixed now. THX! I recorded a video to document the issues I have just found: https://youtu.be/U8v-0T418tM In the beginning you see two crashes from previous runs. An assertion killed RT on startup. This is not specific to newlocallab, I get them occasionally.

(rawtherapee:13054): GLib-GObject-WARNING **: 09:14:22.929: instance of invalid non-instantiatable type 'gfloat'

(rawtherapee:13054): GLib-GObject-CRITICAL **: 09:14:22.929: g_signal_handlers_destroy: assertion 'G_TYPE_CHECK_INSTANCE (instance)' failed
[1]    13054 segmentation fault (core dumped)  ./Release/rawtherapee
./Release/rawtherapee  2,97s user 0,34s system 90% cpu 3,649 total

Then there is a reproducible crash that occurs everytime RT is closed with the locallab tab open. I will have to do a debug build to get a backtrace.

Now to the actual issues with editing. 1) Cursor and handle of the outline are not "synchronized". Especially visible in 100% view. After some moving around there is a big gap between cursor and point. It also happens in smaller zoom levels, but not as pronounced. 2) CPU usage when moving a handle is EXTREME! It fully uses all my available cores. 3) RAM usage has always been an issue for me with RT. I usually can edit one photo, then I have to restart RT. But now even moving around a handle will eat memory. Switching between "fit" and "100%" or zooming around will really quickly eat up my whole memory. You saw at the end of these 1:37 minutes I was at 26.5% (of 8GB) used RAM (~2.1GB), just from moving the handle and zooming in/out. A longer edit on one image with locallab usually has to be done in several steps, restarting RT inbetween (losing all the history).

At the end you also see that I did not do any actual local editing, just a naked spot, all tools disabled.

ff2000 commented 5 years ago

Here is the BT for the crash when closing RT with locallab tab open:

#0  0x00007f1240f059b5 in g_mutex_lock (mutex=mutex@entry=0x148) at /var/tmp/portage/dev-libs/glib-2.58.3-r1/work/glib-2.58.3/glib/gthread-posix.c:1343
        _g_boolean_var_ = <optimized out>
#1  0x00007f1240244375 in Glib::Threads::Mutex::lock (this=this@entry=0x148) at /var/tmp/portage/dev-cpp/glibmm-2.58.1/work/glibmm-2.58.1/glib/glibmm/threads.cc:175
No locals.
#2  0x000055697aff8d3f in MyMutex::lock (this=0x148) at ../rtengine/../rtgui/../rtengine/../rtgui/threadutils.h:195
No locals.
#3  MyMutex::MyLock::MyLock (mutex=..., this=<synthetic pointer>) at ../rtengine/../rtgui/../rtengine/../rtgui/threadutils.h:195
No locals.
#4  rtengine::Crop::setEditSubscriber (this=0x0, newSubscriber=0x0) at ../rtengine/dcrop.cc:112
        lock = {<rtengine::NonCopyable> = {<No data fields>}, mutex = @0x148, locked = true}
        oldSubscriber = <optimized out>
#5  0x000055697ac8b22c in CropHandler::setEditSubscriber (this=<optimized out>, newSubscriber=<optimized out>) at ../rtgui/crophandler.cc:86
No locals.
#6  0x000055697ac8f1bb in CropWindow::setEditSubscriber (this=<optimized out>, newSubscriber=<optimized out>) at ../rtgui/cropwindow.cc:1982
No locals.
#7  0x000055697ad99fdf in ImageArea::unsubscribe (this=0x556989c69640) at ../rtgui/imagearea.cc:385
        wasObjectType = true
        oldSubscriber = <optimized out>
#8  0x000055697acd28a6 in EditorPanel::close (this=0x556981768900) at ../rtgui/editorpanel.cc:1094
        is = <optimized out>
#9  0x000055697acd72e0 in EditorPanel::~EditorPanel (this=0x556981768900, __in_chrg=<optimized out>, __vtt_parm=<optimized out>) at ../rtgui/editorpanel.cc:876
No locals.
#10 0x000055697acd7659 in EditorPanel::~EditorPanel (this=0x556981768900, __in_chrg=<optimized out>, __vtt_parm=<optimized out>) at ../rtgui/editorpanel.cc:846
No locals.
#11 0x00007f1240ea09bb in g_datalist_clear (datalist=<optimized out>) at /var/tmp/portage/dev-libs/glib-2.58.3-r1/work/glib-2.58.3/glib/gdataset.c:273
        data = 0x55698d8efab0
        i = 0
        __func__ = "g_datalist_clear"
#12 0x00007f1240fa5d22 in g_object_unref (_object=<optimized out>) at /var/tmp/portage/dev-libs/glib-2.58.3-r1/work/glib-2.58.3/gobject/gobject.c:3346
        weak_locations = <optimized out>
        object = <optimized out>
        old_ref = 1
        object = <optimized out>
--Type <RET> for more, q to quit, c to continue without paging--c
        old_ref = <optimized out>
        __func__ = "g_object_unref"
        _g_boolean_var_ = <optimized out>
        _g_boolean_var_ = <optimized out>
        has_toggle_ref = <optimized out>
        weak_locations = <optimized out>
        weak_ref_location = <optimized out>
        has_toggle_ref = <optimized out>
        _g_boolean_var_ = <optimized out>
#13 g_object_unref (_object=0x556980cec470) at /var/tmp/portage/dev-libs/glib-2.58.3-r1/work/glib-2.58.3/gobject/gobject.c:3238
        object = 0x556980cec470
        old_ref = <optimized out>
        __func__ = "g_object_unref"
        _g_boolean_var_ = <optimized out>
        _g_boolean_var_ = <optimized out>
        has_toggle_ref = <optimized out>
        weak_locations = <optimized out>
        weak_ref_location = <optimized out>
        has_toggle_ref = <optimized out>
        _g_boolean_var_ = <optimized out>
#14 0x00007f12416c359e in gtk_notebook_forall (container=<optimized out>, include_internals=0, callback=0x7f12417e0730 <gtk_widget_destroy>, callback_data=0x0) at /var/tmp/portage/x11-libs/gtk+-3.24.8/work/gtk+-3.24.8/gtk/gtknotebook.c:4580
        page = 0x55698be65ad0
        notebook = <optimized out>
        priv = 0x55697d91e0d0
        children = 0x0
        i = <optimized out>
#15 0x00007f12415d6e66 in gtk_container_destroy (widget=0x55697d91e2d0) at /var/tmp/portage/x11-libs/gtk+-3.24.8/work/gtk+-3.24.8/gtk/gtkcontainer.c:1701
        container = 0x55697d91e2d0
        priv = 0x55697d91e1c0
#16 0x00007f1240fa0ad1 in g_closure_invoke (closure=0x55697d759c90, return_value=0x0, n_param_values=1, param_values=0x7ffdb6248060, invocation_hint=0x7ffdb6247fd0) at /var/tmp/portage/dev-libs/glib-2.58.3-r1/work/glib-2.58.3/gobject/gclosure.c:810
        marshal = 0x7f1240f9f0a0 <g_type_class_meta_marshal>
        marshal_data = 0x98
        in_marshal = 1
        real_closure = 0x55697d759c70
        __func__ = "g_closure_invoke"
#17 0x00007f1240fb3cd6 in signal_emit_unlocked_R (node=node@entry=0x55697d7cb080, detail=detail@entry=0, instance=instance@entry=0x55697d91e2d0, emission_return=emission_return@entry=0x0, instance_and_params=instance_and_params@entry=0x7ffdb6248060) at /var/tmp/portage/dev-libs/glib-2.58.3-r1/work/glib-2.58.3/gobject/gsignal.c:3549
        need_unset = 0
        accumulator = 0x0
        emission = {next = 0x7ffdb62484e0, instance = 0x55697d91e2d0, ihint = {signal_id = 57, detail = 0, run_type = G_SIGNAL_RUN_CLEANUP}, state = EMISSION_STOP, chain_type = 93911564781360}
        class_closure = 0x55697d759c90
        hlist = <optimized out>
        handler_list = 0x0
        return_accu = 0x0
        accu = {g_type = 0, data = {{v_int = 0, v_uint = 0, v_long = 0, v_ulong = 0, v_int64 = 0, v_uint64 = 0, v_float = 0, v_double = 0, v_pointer = 0x0}, {v_int = 0, v_uint = 0, v_long = 0, v_ulong = 0, v_int64 = 0, v_uint64 = 0, v_float = 0, v_double = 0, v_pointer = 0x0}}}
        signal_id = 57
        max_sequential_handler_number = 174484
        return_value_altered = <optimized out>
#18 0x00007f1240fbc8da in g_signal_emit_valist (instance=<optimized out>, signal_id=<optimized out>, detail=<optimized out>, var_args=var_args@entry=0x7ffdb6248210) at /var/tmp/portage/dev-libs/glib-2.58.3-r1/work/glib-2.58.3/gobject/gsignal.c:3391
        instance_and_params = 0x7ffdb6248060
        signal_return_type = <optimized out>
        param_values = <optimized out>
        node = <optimized out>
        i = <optimized out>
        n_params = <optimized out>
        __func__ = "g_signal_emit_valist"
#19 0x00007f1240fbcf37 in g_signal_emit (instance=instance@entry=0x55697d91e2d0, signal_id=<optimized out>, detail=detail@entry=0) at /var/tmp/portage/dev-libs/glib-2.58.3-r1/work/glib-2.58.3/gobject/gsignal.c:3447
        var_args = {{gp_offset = 24, fp_offset = 48, overflow_arg_area = 0x7ffdb62482f0, reg_save_area = 0x7ffdb6248230}}
#20 0x00007f12417e8cec in gtk_widget_dispose (object=0x55697d91e2d0) at /var/tmp/portage/x11-libs/gtk+-3.24.8/work/gtk+-3.24.8/gtk/gtkwidget.c:12098
        widget = 0x55697d91e2d0
        priv = 0x55697d91e1e0
        sizegroups = <optimized out>
#21 0x00007f1240fa74b8 in g_object_run_dispose (object=0x55697d91e2d0) at /var/tmp/portage/dev-libs/glib-2.58.3-r1/work/glib-2.58.3/gobject/gobject.c:1108
        __func__ = "g_object_run_dispose"
#22 0x00007f12417f4dd9 in gtk_window_forall (container=0x55697d688270, include_internals=0, callback=0x7f12417e0730 <gtk_widget_destroy>, callback_data=0x0) at /var/tmp/portage/x11-libs/gtk+-3.24.8/work/gtk+-3.24.8/gtk/gtkwindow.c:8592
        window = 0x55697d688270
        priv = 0x55697d688010
        child = <optimized out>
#23 0x00007f123fb92aa8 in Gtk::Container_Class::forall_vfunc_callback (self=0x55697d688270, include_internals=0, callback=0x7f12417e0730 <gtk_widget_destroy>, callback_data=0x0) at /var/tmp/portage/dev-cpp/gtkmm-3.24.1/work/gtkmm-3.24.1/gtk/gtkmm/container.cc:485
        obj = <optimized out>
        obj_base = 0x55697d7a1bd0
        base = <optimized out>
#24 0x00007f12415d6e66 in gtk_container_destroy (widget=0x55697d688270) at /var/tmp/portage/x11-libs/gtk+-3.24.8/work/gtk+-3.24.8/gtk/gtkcontainer.c:1701
        container = 0x55697d688270
        priv = 0x55697d688160
#25 0x00007f1240fa0bbd in g_closure_invoke (closure=0x55697d759c90, return_value=0x0, n_param_values=1, param_values=0x7ffdb6248580, invocation_hint=0x7ffdb62484f0) at /var/tmp/portage/dev-libs/glib-2.58.3-r1/work/glib-2.58.3/gobject/gclosure.c:810
        marshal = 0x7f1240f9f0a0 <g_type_class_meta_marshal>
        marshal_data = 0x98
        in_marshal = 0
        real_closure = 0x55697d759c70
        __func__ = "g_closure_invoke"
#26 0x00007f1240fb3cd6 in signal_emit_unlocked_R (node=node@entry=0x55697d7cb080, detail=detail@entry=0, instance=instance@entry=0x55697d688270, emission_return=emission_return@entry=0x0, instance_and_params=instance_and_params@entry=0x7ffdb6248580) at /var/tmp/portage/dev-libs/glib-2.58.3-r1/work/glib-2.58.3/gobject/gsignal.c:3549
        need_unset = 0
        accumulator = 0x0
        emission = {next = 0x0, instance = 0x55697d688270, ihint = {signal_id = 57, detail = 0, run_type = G_SIGNAL_RUN_CLEANUP}, state = EMISSION_STOP, chain_type = 93911564487200}
        class_closure = 0x55697d759c90
        hlist = <optimized out>
        handler_list = 0x5569817bc980
        return_accu = 0x0
        accu = {g_type = 0, data = {{v_int = 0, v_uint = 0, v_long = 0, v_ulong = 0, v_int64 = 0, v_uint64 = 0, v_float = 0, v_double = 0, v_pointer = 0x0}, {v_int = 0, v_uint = 0, v_long = 0, v_ulong = 0, v_int64 = 0, v_uint64 = 0, v_float = 0, v_double = 0, v_pointer = 0x0}}}
        signal_id = 57
        max_sequential_handler_number = 174484
        return_value_altered = <optimized out>
#27 0x00007f1240fbc8da in g_signal_emit_valist (instance=<optimized out>, signal_id=<optimized out>, detail=<optimized out>, var_args=var_args@entry=0x7ffdb6248730) at /var/tmp/portage/dev-libs/glib-2.58.3-r1/work/glib-2.58.3/gobject/gsignal.c:3391
        instance_and_params = 0x7ffdb6248580
        signal_return_type = <optimized out>
        param_values = <optimized out>
        node = <optimized out>
        i = <optimized out>
        n_params = <optimized out>
        __func__ = "g_signal_emit_valist"
#28 0x00007f1240fbcf37 in g_signal_emit (instance=instance@entry=0x55697d688270, signal_id=<optimized out>, detail=detail@entry=0) at /var/tmp/portage/dev-libs/glib-2.58.3-r1/work/glib-2.58.3/gobject/gsignal.c:3447
        var_args = {{gp_offset = 24, fp_offset = 48, overflow_arg_area = 0x7ffdb6248810, reg_save_area = 0x7ffdb6248750}}
#29 0x00007f12417e8cec in gtk_widget_dispose (object=0x55697d688270) at /var/tmp/portage/x11-libs/gtk+-3.24.8/work/gtk+-3.24.8/gtk/gtkwidget.c:12098
        widget = 0x55697d688270
        priv = 0x55697d688180
        sizegroups = <optimized out>
#30 0x00007f12417fbf28 in gtk_window_dispose (object=0x55697d688270) at /var/tmp/portage/x11-libs/gtk+-3.24.8/work/gtk+-3.24.8/gtk/gtkwindow.c:3164
        window = 0x55697d688270
        priv = 0x55697d688010
#31 0x00007f1240fa74b8 in g_object_run_dispose (object=0x55697d688270) at /var/tmp/portage/dev-libs/glib-2.58.3-r1/work/glib-2.58.3/gobject/gobject.c:1108
        __func__ = "g_object_run_dispose"
#32 0x00007f12417e0799 in gtk_widget_destroy (widget=<optimized out>) at /var/tmp/portage/x11-libs/gtk+-3.24.8/work/gtk+-3.24.8/gtk/gtkwidget.c:4728
        __func__ = "gtk_widget_destroy"
#33 0x00007f123fc32510 in Gtk::Window::_release_c_instance (this=0x55697d7a1a80) at /var/tmp/portage/dev-cpp/gtkmm-3.24.1/work/gtkmm-3.24.1/gtk/gtkmm/window.cc:113
        object = <optimized out>
#34 0x00007f123fc32551 in Gtk::Window::destroy_ (this=<optimized out>) at /var/tmp/portage/dev-cpp/gtkmm-3.24.1/work/gtkmm-3.24.1/gtk/gtkmm/window.cc:88
No locals.
#35 0x00007f123fc32afc in Gtk::Window::~Window (this=0x55697d7a1a80, __vtt_parm=0x55697b4b0638 <VTT for RTWindow+8>, __in_chrg=<optimized out>) at /var/tmp/portage/dev-cpp/gtkmm-3.24.1/work/gtkmm-3.24.1/gtk/gtkmm/window.cc:403
No locals.
#36 0x000055697af21da5 in RTWindow::~RTWindow (this=0x55697d7a1a80, __in_chrg=<optimized out>, __vtt_parm=<optimized out>) at ../rtgui/../rtengine/rtengine.h:182
No locals.
#37 0x000055697af21e19 in RTWindow::~RTWindow (this=0x55697d7a1a80, __in_chrg=<optimized out>, __vtt_parm=<optimized out>) at ../rtgui/rtwindow.cc:445
No locals.
#38 0x000055697abdcd2d in std::default_delete<RTWindow>::operator() (this=<synthetic pointer>, __ptr=0x55697d7a1a80) at /usr/lib/gcc/x86_64-pc-linux-gnu/8.3.0/include/g++-v8/bits/unique_ptr.h:347
No locals.
#39 std::unique_ptr<RTWindow, std::default_delete<RTWindow> >::~unique_ptr (this=<synthetic pointer>, __in_chrg=<optimized out>) at /usr/lib/gcc/x86_64-pc-linux-gnu/8.3.0/include/g++-v8/bits/unique_ptr.h:274
        __ptr = <synthetic pointer>: 0x55697d7a1a80
#40 main (argc=<optimized out>, argv=<optimized out>) at ../rtgui/main.cc:561
        m = {<sigc::trackable> = {callback_list_ = 0x55697d840500}, _vptr.Main = 0x7f123ff64940 <vtable for Gtk::Main+16>, static signal_key_snooper_ = {<No data fields>}, static instance_ = 0x7ffdb62488f0}
        rtWindow = std::unique_ptr<RTWindow> = {get() = 0x55697d7a1a80}
        exname = "/home/franz/src/RawTherapee/build/RelWithDebInfo/rawtherapee", '\000' <repeats 451 times>
        exePath = {static npos = 18446744073709551615, string_ = "/home/franz/src/RawTherapee/build/RelWithDebInfo"}
        fatalError = {static npos = 18446744073709551615, string_ = ""}
        ret = 0

Crash not in locallab but crophandler. Made me think... Opened an unedited raw, enabled crop, enabled gradient, showed the gradient editor overlay tool, closed RT - Boom! Looks suspiciously similar!

#0  0x00007f1e425069b5 in g_mutex_lock (mutex=mutex@entry=0x148) at /var/tmp/portage/dev-libs/glib-2.58.3-r1/work/glib-2.58.3/glib/gthread-posix.c:1343
#1  0x00007f1e41845375 in Glib::Threads::Mutex::lock (this=this@entry=0x148) at /var/tmp/portage/dev-cpp/glibmm-2.58.1/work/glibmm-2.58.1/glib/glibmm/threads.cc:175
#2  0x000055c64c897d3f in MyMutex::lock (this=0x148) at ../rtengine/../rtgui/../rtengine/../rtgui/threadutils.h:195
#3  MyMutex::MyLock::MyLock (mutex=..., this=<synthetic pointer>) at ../rtengine/../rtgui/../rtengine/../rtgui/threadutils.h:195
#4  rtengine::Crop::setEditSubscriber (this=0x0, newSubscriber=0x0) at ../rtengine/dcrop.cc:112
#5  0x000055c64c52a22c in CropHandler::setEditSubscriber (this=<optimized out>, newSubscriber=<optimized out>) at ../rtgui/crophandler.cc:86
#6  0x000055c64c52e1bb in CropWindow::setEditSubscriber (this=<optimized out>, newSubscriber=<optimized out>) at ../rtgui/cropwindow.cc:1982
#7  0x000055c64c638fdf in ImageArea::unsubscribe (this=0x55c65a6c4040) at ../rtgui/imagearea.cc:385
#8  0x000055c64c5718a6 in EditorPanel::close (this=0x55c651898c00) at ../rtgui/editorpanel.cc:1094
#9  0x000055c64c5762e0 in EditorPanel::~EditorPanel (this=0x55c651898c00, __in_chrg=<optimized out>, __vtt_parm=<optimized out>) at ../rtgui/editorpanel.cc:876
#10 0x000055c64c576659 in EditorPanel::~EditorPanel (this=0x55c651898c00, __in_chrg=<optimized out>, __vtt_parm=<optimized out>) at ../rtgui/editorpanel.cc:846
[... and so on ...]

So probably something with the patch fixing multiple edit overlays (crop + locallab, crop + gradient) is fishy.

Beep6581 commented 5 years ago

Segfault on exit confirmed in dev 5.6-263-g6c91abc3e using graduated filter.

ff2000 commented 5 years ago

@Beep6581 I just mentioned the crash as I thought it was in locallab. There are some other issues that I actually wanted to report specifically for locallab editing, so the locallab label should stay. Not that those issues stay unnoticed ;)

Hombre57 commented 5 years ago

@ff2000 Has the crash on exit been introduced by the fix from #5415 ?

Beep6581 commented 5 years ago

Right, let's stick to one problem per issue in the future.

ff2000 commented 5 years ago

@Hombre57 Yes. As I wrote in #5415 a revert to the last merge from dev in newlocallab (which got rid of editbuttonfix and objectprecedence) restored exit without crash.

Hombre57 commented 5 years ago

@ff2000 Have you correctly merged commit e2bfbbf9b146454b4cb6013f2e95ebfaa23a2211 into locallab ? Because this :

7 0x000055697ad99fdf in ImageArea::unsubscribe

is suspicious : EditorPanel::close doesn't call ImageArea::unsubscribe anymore (see the above mentioned commit.

Anyway, I confirm the crash when closing RT, introduced by that commit, and solved by commit 3a538b9b836761d5188d0d0e6fa131354db0fec1.

ff2000 commented 5 years ago

@Hombre57 I never made changes myself, always went with "git pull". I had to rebuild with debug symbols and cleaned up my build env. Also went with "reset --hard" to get back to a previous commit, with a subsequent "git pull" to reconfirm the crash. So yes, I think merges were all correct ;) Besides that I confirm that your fix fixes the crash. Thx!

ff2000 commented 5 years ago

Re CPU usage: It seems mouse movement trigger updates, not actual changes in outline shape. I went to the bottom control point of a sqaure spot, grabbed the point and moved it horizontally. There was no change in the outline but still it constantly recomputed the image. Is it possible to track the size of the spot and only trigger recomputation of the image when it actually changes?

Thanatomanic commented 4 years ago

@ff2000 The locallab tool has now been merged into dev. Can you please test if you still have this issue?

ff2000 commented 4 years ago

Yes, just tested and those issues are still present. 1) pulling around a handle and you get an offset. 2) CPU usage still extreme when moving the outline, even when there are no tools added to the spot. 3) memory usage, while better as it seems, still grows faster with locallab enabled than without.

Using tcmalloc made memory consumption of RT way more managable. Unfortunately now RT segfaults with tcmalloc enabled, which might be due to gcc-10.0.1. See also latest comment from guzzisti [from 2020-05-23 18:28] here: https://aur.archlinux.org/packages/art-rawconverter-git/ So I can't test if it's an actual leak or just the usual glibc-wont-free-unused-memory thingy.