Bug 322789

Summary: Enabling "color managed view" in editor slows down tool startup
Product: digikam Reporter: Peter Albrecht <px79>
Component: ColorManagement-ViewsAssignee: Digikam Developers <digikam-bugs-null>
Status: RESOLVED FIXED    
Severity: minor CC: caulier.gilles, dilfridge, kensington, vivo75+kde
Priority: NOR    
Version: 3.5.0   
Target Milestone: ---   
Platform: Gentoo Packages   
OS: Linux   
Latest Commit: Version Fixed In: 4.3.0
Attachments: The ICC file used by dispcalGUI
color profile computed with ColorHug device on my LG IPS LED 27EA33 monitor
Valgrind dump with callgrind of digikams main thread during editor tool opening

Description Peter Albrecht 2013-07-24 20:42:34 UTC
With digiKam 3.2.0 I encountered the following "problem": Open an image with the "Image Editor". Having "Color Managed View" enabled, the startup of tools like "Brightness / Contrast / Gamma" takes a lot of time. The time from clicking the menu item until having the tool ready to be used, ranges from 4 seconds to even 12 seconds.

Doing a parallel "strace -fp <digikam-pid>" gives me 86 times the line
  open("/usr/share/apps/libkdcraw/profiles/srgb-d65.icm", O_RDONLY|O_CLOEXEC) = 23

This does not seem to be intended and could explain the long delay for the tool startup.

If I disable "Color Managed View" in the "Image Editor" with the small toggle button in the lower right corner, the tool "Brightness / Contrast / Gamma" starts up in less than 1 second.

Similar effect for tools "White Balance" or "Hue / Saturation / Lightness" but with these the delay it at max by 6 seconds.

I'm using digiKam 3.2.0 with KDE 4.10.4 at the moment. This problem did not occur with digiKam 3.1.0 and KDE 4.10.3.

Reproducible: Always
Comment 1 Peter Albrecht 2013-07-24 20:47:41 UTC
Someone else has reported digiKam slowdown because of Color Management on the mailing list:
  http://mail.kde.org/pipermail/digikam-users/2013-March/017555.html
Maybe these issues are related.
Comment 2 Peter Albrecht 2013-07-25 19:17:53 UTC
Another interesting issue:
I load an image in the Image Editor. Toggling "Color Managed View" on/off via the little button in the lower right corner (or keyboard shortcut F12) is in effect almost immediately (less than 1 second).

When I have started the tool "Brightness / Contrast / Gamma", disabling "Color Managed View" is in effect in also no time (less than 1 second). But enabling "Color Managed View" again take 4 to 6 seconds.
Comment 3 Peter Albrecht 2013-07-26 15:08:30 UTC
I guess my digiKam is using lcms 2.3 (version 2030):

digiKam version 3.2.0
Exiv2 can write to Jp2: Yes
Exiv2 can write to Jpeg: Yes
Exiv2 can write to Pgf: Yes
Exiv2 can write to Png: Yes
Exiv2 can write to Tiff: Yes
Exiv2 supports XMP metadata: Yes
LibCImg: 130
LibEigen: 3.0.6
LibExiv2: 0.23
LibJPEG: 80
LibJasper: 1.900.1
LibKDE: 4.10.4
LibKExiv2: 2.3.0
LibKGeoMap: 2.0.0
LibKdcraw: 2.2.0
LibLCMS: 2030
LibPGF: 6.12.27 - external shared library
LibPNG: 1.5.15
LibQt: 4.8.4
LibRaw: 0.15.0-Beta1
LibTIFF: LIBTIFF, Version 4.0.3 Copyright (c) 1988-1996 Sam Leffler Copyright (c) 1991-1996 Silicon Graphics, Inc.
Marble Widget: 0.15.1 (stable version)
Parallelized PGF codec: No
Parallelized demosaicing: No
RawSpeed codec support: No
Database backend: QSQLITE
Kipi-Plugins: 3.2.0
LibKface: 2.0.0
LibKipi: 2.0.0
LibOpenCV: 2.4.5
Libface: 0.2

But there is also a lcms 1.19 installed on my  computer.

Is it a problem, that the different lcms-versions a used by different digikam compontents?
  media-gfx/digikam-3.2.0 (media-libs/lcms:2)
  kde-base/libkdcraw-4.10.4 (media-libs/lcms:0)
  kde-base/libkexiv2-4.10.4 (media-libs/lcms:0)
Slot 0 means lcms 1.19, slot 2 means lcms 2.3
Comment 4 caulier.gilles 2013-07-27 09:33:37 UTC
No. LCMS 1 and 2 can be installed at the same time. digiKam will be compile with 1 or 2. There is no risk of dysfunction. It work fine here under Linux like this.

I suspect really a problem with you ICC settings (color profiles) which can be not handle properly by LCMS. In fact, in backgroung, digiKam delegate CM to LCMS...

Gilles Caulier
Comment 5 Peter Albrecht 2013-07-29 17:06:33 UTC
Created attachment 81425 [details]
The ICC file used by dispcalGUI

So, if you suspect the problem to be with the ICC file, I guess, it is a good idea to post this here. ;)

Maybe someone can reproduce this bug with my ICC file. I have no deep knowledge about color management, so if you need more files or settings to reproduce, I am glad to provide those.

I used a colorhug and Dmitri's tutorial (http://scribblesandsnaps.com/tag/colorhug/) to create this profile. I don't remember all the details, since this profile is from February 2013.

At the moment, I use:
  - dispcalGUI - 1.2.7.0
  - argyllcms - 1.4.0-r1
Comment 6 Peter Albrecht 2013-08-01 19:46:37 UTC
I downgraded digikam from 3.2.0 back to 3.1.0. (No other changes on the system.) And now the problem is gone: Starting the tool "Brightness / Contrast / Gamma" take only 2 seconds. this is acceptable. (Instead of 10 seconds with digikam 3.2.0).

So this seems to be a bug, introduced with digikam 3.2.0. :(


(In reply to comment #0)
> Doing a parallel "strace -fp <digikam-pid>" gives me 86 times the line
>   open("/usr/share/apps/libkdcraw/profiles/srgb-d65.icm",
> O_RDONLY|O_CLOEXEC) = 23
> 
> This does not seem to be intended and could explain the long delay for the
> tool startup.

I have to revert this statement. With digikam 3.1.0, I see the line 
  open("/usr/share/apps/libkdcraw/profiles/srgb-d65.icm", O_RDONLY|O_CLOEXEC) = 24
to appear 156 times, while starting the tool "Brightness / Contrast / Gamma". But it only takes 2 seconds!?!?
So this seems not to be the culprit.
Comment 7 Peter Albrecht 2013-12-13 15:45:14 UTC
The problem still exists with digiKam 3.5.0, KDE 4.10.5, LCMS 2.5.

(In reply to comment #4)
> I suspect really a problem with you ICC settings (color profiles) which can
> be not handle properly by LCMS. In fact, in backgroung, digiKam delegate CM
> to LCMS...
> Gilles Caulier

Gilles, do you use color profiles? Could you send me / post one of yours? It would lead to wrong colors on my monitor, of course, but I could test whether my color profile is broken / incompatible.

Another fact:
The time to wait depends on the size of the area, the image occupies on the screen. Having the image editor maximized, I have to wait up to 10 seconds. Shrinking the window to the lowest possible size, waiting time shrinks to 2 seconds, too.
Comment 8 caulier.gilles 2013-12-13 16:26:45 UTC
yes, i use CM, with profile done by me using ColorHug device :

http://www.hughski.com/

I will attach my monitor profile to this entry...

Gilles Caulier
Comment 9 caulier.gilles 2013-12-13 16:28:53 UTC
Created attachment 84075 [details]
color profile computed with ColorHug device on my LG IPS LED 27EA33 monitor
Comment 10 Peter Albrecht 2013-12-14 10:00:53 UTC
Gilles, thanks a lot for posting your icc profile! (I use a ColorHug, too ;)
Unfortunately using your icc profile leads to the same, long waitingtime.

But I have discovered another interesting fact for this issue:
DigiKam 3.1.0, which worked fine for me, in gentoo linux was build with LCMS 1.19 (http://sources.gentoo.org/cgi-bin/viewvc.cgi/gentoo-x86/media-gfx/digikam/digikam-3.1.0.ebuild?view=markup says "media-libs/lcms:0" which is "slot 0" containing version LCMS 1.19)

DigiKam 3.2.0 and digiKam 3.5.0, which both lead to long waitingtimes for me, in gentoo linux are build with LCMS 2.x.
(Both http://sources.gentoo.org/cgi-bin/viewvc.cgi/gentoo-x86/media-gfx/digikam/digikam-3.2.0.ebuild?revision=1.6&view=markup and http://sources.gentoo.org/cgi-bin/viewvc.cgi/gentoo-x86/media-gfx/digikam/digikam-3.5.0.ebuild?revision=1.2&view=markup depend on "media-libs/lcms:2" which is "slot 2" containing version LCMS 2.x)

I tested digiKam with LCMS versions 2.3 and 2.5, which lead both to long waitingtimes at opening Tools like "Brightness / Contrast / Gamma" in Image Editor.

In comment #4 you wrote:
> No. LCMS 1 and 2 can be installed at the same time. digiKam will be compile
> with 1 or 2. There is no risk of dysfunction...
Is this still valid for digiKam 3.5.0? If, yes, I could build my digiKam with LCMS 1.19 and get rid of the long waiting times, again.

Which version of LCMS do you use with digiKam?
Comment 11 caulier.gilles 2013-12-14 10:21:00 UTC
I use LCMS2 :

digiKam version 4.0.0-beta2
Demosaic GPL2 pack support: No
Demosaic GPL3 pack support: No
Exiv2 can write to Jp2: Yes
Exiv2 can write to Jpeg: Yes
Exiv2 can write to Pgf: Yes
Exiv2 can write to Png: Yes
Exiv2 can write to Tiff: Yes
Exiv2 supports XMP metadata: Yes
LibCImg: 130
LibEigen: 3.1.2
LibExiv2: 0.23
LibJPEG: 80
LibJasper: 1.900.1
LibKDE: 4.10.5
LibKExiv2: 2.3.1
LibKGeoMap: 2.0.0
LibKdcraw: 2.4.2
LibLCMS: 2050    <<<<<<<<<<<<<<<<<<<<<<<<<<<!!!!!!!!!!!!!!!!!!!!!!!!
LibLensFun: 0.2.6-0
LibPGF: 6.13.45 - internal library
LibPNG: 1.5.13
LibQt: 4.8.5
LibRaw: 0.16.0-Alpha2
LibTIFF: LIBTIFF, Version 4.0.3 Copyright (c) 1988-1996 Sam Leffler Copyright (c) 1991-1996 Silicon Graphics, Inc.
Marble Widget: 0.15.1 (stable version)
Parallelized PGF codec: No
Parallelized demosaicing: Yes
RawSpeed codec support: No
Database backend: QSQLITE
Kipi-Plugins: 4.0.0-beta2
LibGphoto2: 2.5.2
LibKface: 3.0.0
LibKipi: 2.1.0
LibOpenCV: 2.4.3
Comment 12 Peter Albrecht 2013-12-14 12:40:09 UTC
Same version here:
digiKam version 3.5.0
Exiv2 can write to Jp2: Yes
Exiv2 can write to Jpeg: Yes
Exiv2 can write to Pgf: Yes
Exiv2 can write to Png: Yes
Exiv2 can write to Tiff: Yes
Exiv2 supports XMP metadata: Yes
LibCImg: 130
LibEigen: 3.0.6
LibExiv2: 0.23
LibJPEG: 80
LibJasper: 1.900.1
LibKDE: 4.10.5
LibKExiv2: 2.3.0
LibKGeoMap: 2.0.0
LibKdcraw: 2.2.0
LibLCMS: 2050         <------------------------------------------------
LibPGF: 6.12.27 - external shared library
LibPNG: 1.5.17
LibQt: 4.8.5
LibRaw: 0.15.2
LibTIFF: LIBTIFF, Version 4.0.3 Copyright (c) 1988-1996 Sam Leffler Copyright (c) 1991-1996 Silicon Graphics, Inc.
Marble Widget: 0.15.1 (stable version)
Parallelized PGF codec: No
Parallelized demosaicing: Yes
RawSpeed codec support: No
Database backend: QSQLITE
Kipi-Plugins: 3.2.0
LibKface: 3.0.0
LibKipi: 2.0.0
LibOpenCV: 2.4.5
Comment 13 caulier.gilles 2013-12-14 22:21:10 UTC
As CM is relevant of screen, perhaps there is a problem with your video driver... But not sure.

Can you reproduce this dysfunction on a different computer or in a VM ?

Gilles Caulier
Comment 14 Peter Albrecht 2013-12-21 20:59:43 UTC
Another interesting fact on this issue:
When I open digikam and start Image Editor on an image with 4752 x 3168 pixel, Image Editor is ready to use in about 1 second. And the Image Editor also shows me a color managed image. So this is no sole LCMS-problem, but something "special" with the Image Editor tools.

(I updated to KDE 4.11.2 in the meantime. Problem still there)
Comment 15 Peter Albrecht 2013-12-27 09:39:25 UTC
I have reported this bug at gentoo's bug-tracker, too:
https://bugs.gentoo.org/show_bug.cgi?id=496140

Maybe it is gentoo specific and another gentoo user can reproduce this.

(In reply to comment #13)
> Can you reproduce this dysfunction on a different computer or in a VM ?

Installing gentoo on a different computer / VM is a lot of work, so I try to avoid it. But if this is the last chance to identify this bug, I might go this step, too.
Comment 16 Peter Albrecht 2013-12-27 21:51:21 UTC
Update:
Andreas K. Hüttel (Gentoo KDE Team) had the great idea to do an strace on this strange digiKam / LCMS behaviour. See https://bugs.gentoo.org/show_bug.cgi?id=496140#c5

The result is very interesting: During one start of the tool "Brightness / Contrast / Gamma..." you can find 464 times the following lines in the strace log:
------------------------------------- 8< -------------------------------------
open("/usr/share/apps/libkdcraw/profiles/srgb-d65.icm", O_RDONLY|O_CLOEXEC) = 65
fcntl(65, F_SETFD, FD_CLOEXEC) = 0
fstat(65, {st_mode=S_IFREG|0644, st_size=6924, ...}) = 0
fstat(65, {st_mode=S_IFREG|0644, st_size=6924, ...}) = 0
fstat(65, {st_mode=S_IFREG|0644, st_size=6924, ...}) = 0
read(65, "\0\0\33\flcms\0020\0\0mntrRGB XYZ \7\324\0\10\0\r\0\f"..., 16384) = 6924
read(65, "", 9460)      = 0
close(65)               = 0
------------------------------------- >8 -------------------------------------
The whole content of 6924 bytes is compleately read 464 times.

Does some have an idea, why? Normally you would load a file once and keep it in memory.
Comment 17 Peter Albrecht 2014-01-04 15:22:52 UTC
Hi Gilles,

I tried some debugging. (I never wrote a KDE programm, nor did I debug one, so I may be wrong).

When I open the "Brightness / Contrast / Gamma..." tool in Image Editor, gdb comes along the following positions.

*** Position A:
digikam-3.5.0/core/utilities/imageeditor/editor/editortool.cpp, line 98
void EditorTool::init()
{
    QTimer::singleShot(0, this, SLOT(slotInit()));
}

*** Position B:
digikam-3.5.0/core/utilities/imageeditor/editor/editortool.cpp, line 414
void EditorToolThreaded::slotInit()
{
    EditorTool::slotInit();
    ...
}

Beeing at postion A (breakpoint) and pressing "continue" in KDevelop/GDB, I have to wait 5 seconds, until position B (breakpoint) is reached. But I don't know, why. I guess there are other events waiting in an eventloop. But I don't know how to debug/find those. Do you have any hint/trick for me?
Comment 18 Peter Albrecht 2014-01-04 20:57:18 UTC
Ok, I am one step further: Valgrind can generate a very nice call graph. ;)

Based on the positions in comment #17:
Between position A and position B, I get about ~70 calls to "IccTransform::apply (DImg& image, DImgLoaderObserver* const observer)"
The callstack is every time:
      #0 Digikam::IccTransform::apply() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/libs/dimg/filters/icc/icctransform.cpp:615
      #1 Digikam::DImg::convertToPixmap() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/libs/dimg/dimg.cpp:2038
      #2 Digikam::EditorCore::convertToPixmap() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/utilities/imageeditor/core/editorcore.cpp:999
      #3 Digikam::ImageIface::convertToPixmap() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/utilities/imageeditor/plugin/imageiface.cpp:309
      #4 Digikam::ImageRegionWidget::paintPreview() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/utilities/imageeditor/q3support/imageregionwidget.cpp:141
      #5 Digikam::PreviewWidget::viewportPaintEvent() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/utilities/imageeditor/q3support/previewwidget.cpp:591
      (#6 qt4 event handling ...)

After the breakpoint at position B, there are another ~70 calls to "IccTransform::apply" with the exact same backtrace.

After those second ~70 calls, there is one further call to "IccTransform::apply" with backtrace:
      #0 Digikam::IccTransform::apply() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/libs/dimg/filters/icc/icctransform.cpp:615
      #1 Digikam::DImg::convertToPixmap() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/libs/dimg/dimg.cpp:2038
      #2 Digikam::EditorCore::convertToPixmap() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/utilities/imageeditor/core/editorcore.cpp:999
      #3 Digikam::ImageIface::convertToPixmap() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/utilities/imageeditor/plugin/imageiface.cpp:309
      #4 Digikam::ImageRegionWidget::setPreviewImage() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/utilities/imageeditor/q3support/imageregionwidget.cpp:446
      #5 DigikamColorImagePlugin::BCGTool::setPreviewImage() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/imageplugins/color/bcgtool.cpp:174
      #6 Digikam::EditorToolThreaded::slotFilterFinished() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/utilities/imageeditor/editor/editortool.cpp:535

After this one call, the "Brightness / Contrast / Gamma..." tool in Image Editor is ready to be used.

I don't believe, all those ~140 calls to "IccTransform::apply" are correct. So I'll try to find out, who's firing those "viewportPaintEvent"s. Hints on finding the sender of those events are welcome, of course. ;)
Comment 19 caulier.gilles 2014-01-04 23:28:38 UTC
You have right. IccTransform::apply() must be called one time, for whole image.

It sound like a initialization problem in GUI which call back canvas widget drawing when it display on screen. An editor tool has a dedicated canvas view. It's not the same than main canvas view of editor. Both are displayed using a stack. It's designed in editor tool core. When tool is done, it's applied to main image and lead canvas is displayed again.

I suspect that dysfunction have been introduced by my fix from bug #323498.

Gilles Caulier
Comment 20 caulier.gilles 2014-01-04 23:33:17 UTC
The fix is this one :

https://projects.kde.org/projects/extragear/graphics/digikam/repository/revisions/aa796e8a553b94da6c2b05a24ba66a94673171b1

Look code in EditorTool especially. The commit have been designed to fix Inpainting and Restoration tool initialization. Sound like this have side effect to others tools...

Gilles Caulier
Comment 21 Peter Albrecht 2014-01-05 12:53:04 UTC
Gilles, thanks for your reply. 

Your bugfix (git commit aa796e8a) is not the reason for my bug:
I took digikam 3.5.0 source code, reverted your bugfix-changes in "editortool.cpp" and "editortool.h" and compiled digikam from this source. The long waiting time caused by many "IccTransform::apply()" calls is still there.

Another fact for "your bugfix not causing my bug":
You commit your bugfix 2013-07-23 for a bugreport in digikam 3.3.0. 
I encounted "my bug" with digikam 3.2.0 on 2013-07-18 and reported my bug on 2013-07-24.
So "my digikam" was already broken as you commited this bugfix.

But nevertheless, thanks for the hint. It could have saved a few hours of searching. ;)
Comment 22 Peter Albrecht 2014-01-05 22:21:06 UTC
Created attachment 84472 [details]
Valgrind dump with callgrind of digikams main thread during editor tool opening
Comment 23 Peter Albrecht 2014-01-05 22:32:33 UTC
Update:
I found the reason, why there are 70 calls to "IccTransform::apply()": Tiling!
 - the PreviewWidget is based on Q3ScrollView.
 - during opening of an image editor tool, this Q3ScrollView recieves a QEvent::Paint
 - in Q3ScrollView::eventFilter(), there is a call to PreviewWidget::viewportPaintEvent()
 - and in this function, there are two nested for-loops which seem to split the image in tiles of 128x128 pixels
 - in case of my screen resolution (image size on screen: width ~= 1280, height ~= 896) there are 10 * 7 for-loop iterations => 70 iterations
 - and every iteration calls paintPreview(), which itself calls "IccTransform::apply()"

=> one Paint-Event causes 70 "IccTransform::apply()".
Comment 24 Peter Albrecht 2014-01-05 22:50:46 UTC
In sequence to comment #23:
On the call stack from "ImageRegionWidget::paintPreview()" to "IccTransform::apply()", in "EditorCore::convertToPixmap()" you can find a fresh reinitialisation of IccManager and IccTransform.

This may be the reason for those many syscalls of
  open("/usr/share/apps/libkdcraw/profiles/srgb-d65.icm", O_RDONLY|O_CLOEXEC) = 65
in the strace snipped of comment #16.

Those many reinitialisation look bad, but according to my valgrind/callgrind dump (see  attachment #84472 [details]) (very nice to look at with KCachegrind) relative cost of "IccManager::displayTransform()" is 0.00% (391.390 of 74.381.518.896). The total cost is the process from "opening the tool Brightness/Contrast/Gamma" to "tool ready to be used".

The main consumer according to the valgrind-dump is lcms' "cmsReverseToneCurveEx()", which eats up 76.62%!

So one important question comes to my mind: What does this function do? 
A) Is this part of the initialisation process of lcms? (performance loss, cause of tiling)
B) Or is it part of the pixel-crunching, which processes my image pixels? (no effect, cause of tiling)
In case of question A == Yes, the amount of 70 lcms initialisations per Paint-Event would be fatal!

The API (http://www.littlecms.com/LittleCMS2.5%20API.pdf) I found, reads like A == Yes. 

But I know almost nothing about color management and lcms. So please, Gilles, redirect this question to one of digikam's colormanagement experts.
Comment 25 caulier.gilles 2014-01-05 23:04:14 UTC
Very good investigations Peter.

I CC Francesco Riosa who has written digiKam lcms1/2 wrapper (look core/libs/dklcms/ for details)

Gilles Caulier
Comment 26 Peter Albrecht 2014-01-06 10:18:39 UTC
I did some more testing: Tiling is definitely a problem with colormanagement on my machine.

I changed "digikam-3.5.0/core/utilities/imageeditor/q3support/previewwidget.cpp" line 65
from
     tileSize(128), zoomMultiplier(1.2)
to
     tileSize(1280), zoomMultiplier(1.2)
This effectively disables tiling, since all image fits in one tile.

I compiled this source and now tool starting in Image Editor is as fast as before (about 1 second).

So I have found a first personal workaround. ;)
But, of course we/I should investigate further. It must have a reason, why tiling was introduced first.

What bothers me, too, is that this bug can't be reproduced by you, Gilles and Andreas. Are your CPUs that more powerful than mine? I use a "Intel(R) Core(TM)2 Duo CPU, E8400 @ 3.00GHz".
Comment 27 caulier.gilles 2014-01-06 10:56:16 UTC
Tiling in image editor canvas exist still a very long time, before 1.0.0 release. So tiling is not the problem really...

Gilles Caulier
Comment 28 Peter Albrecht 2014-01-06 18:16:35 UTC
I guess, the problem is, that lcms' "cmsReverseToneCurveEx()" is called for every single tile.
I'm curious about, what Francesco Riosa is saying.
Comment 29 Marcel Wiesweg 2014-01-06 20:56:08 UTC
Why do we not encounter these problems with other places where images are drawn, mainly the preview view?
1) color correction is applied as part of the loading process on the whole picture.
2) there is no tiling, but of course painting region optimization, and there is caching of scaled pixmap content
3) All is redrawn when CM settings change.

Apparently point 1) cannot be fully transferred to the editor, where we must edit the original data. Color correction could yet be done on the preview, before displaying it.
Pixmap caching should come for free if the new branch should be successfully integrated at some time.
Comment 30 Marcel Wiesweg 2014-01-06 20:58:31 UTC
Not to forget, color correction for viewing is a computing intensive task.
Letting the GPU do this may be a possibility that opens for us on KDE when frameworks 5 arrives and if the work on CM in KWin is continued.
Comment 31 Francesco Riosa 2014-01-07 12:57:44 UTC
Francesco Riosa has to say he forgot almost everything about the matter.
should I try to recap, there is also the lcms1 ban to commit, possibly from every component in the digikam universe
Comment 32 Peter Albrecht 2014-01-07 20:44:21 UTC
(In reply to comment #31)
> Francesco Riosa has to say he forgot almost everything about the matter.
> should I try to recap, there is also the lcms1 ban to commit, possibly from
> every component in the digikam universe
It's a pity. But thanks for your reply. And thanks for implementing it at all. :)
Comment 33 Peter Albrecht 2014-01-07 21:11:59 UTC
(In reply to comment #29)
> Why do we not encounter these problems with other places where images are
> drawn, mainly the preview view?

That's a good point! As I posted in comment #2: The Image Editor itself starts very fast (~1 second), although its image is also color corrected. So I compared the "editor loading" process with the "tool loading" process.

EDITOR:
      #0 Digikam::IccTransform::apply() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/libs/dimg/filters/icc/icctransform.cpp:615
      #1 Digikam::DImg::convertToPixmap() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/libs/dimg/dimg.cpp:2038
      #2 Digikam::EditorCore::paintOnDevice() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/utilities/imageeditor/core/editorcore.cpp:666
      #3 Digikam::Canvas::paintViewport() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/utilities/imageeditor/q3support/canvas.cpp:622
      #4 Digikam::Canvas::viewportPaintEvent() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/utilities/imageeditor/q3support/canvas.cpp:514

PREVIEW WIDGET:
      #0 Digikam::IccTransform::apply() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/libs/dimg/filters/icc/icctransform.cpp:615
      #1 Digikam::DImg::convertToPixmap() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/libs/dimg/dimg.cpp:2038
      #2 Digikam::EditorCore::convertToPixmap() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/utilities/imageeditor/core/editorcore.cpp:999
      #3 Digikam::ImageIface::convertToPixmap() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/utilities/imageeditor/plugin/imageiface.cpp:309
      #4 Digikam::ImageRegionWidget::paintPreview() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/utilities/imageeditor/q3support/imageregionwidget.cpp:141
      #5 Digikam::PreviewWidget::viewportPaintEvent() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/utilities/imageeditor/q3support/previewwidget.cpp:591

Both processes call "IccTransform::apply()". And both use tiling. So both call "IccTransform::apply()" 70 times (for my screen resolution). So why is "editor loading" faster than "tool loading"?

Further debugging shows: 
Every call to "IccTransform::apply()" in "tool loading" (PreviewWidget) causes 6 calls to "cmsReverseToneCurveEx()". (Two times three color channels.) 
For "editor loading", only the first call to "IccTransform::apply()" causes 6 calls to "cmsReverseToneCurveEx()". The other 69 calls to "IccTransform::apply()" do not cause calls to "cmsReverseToneCurveEx()"!?!?

apply() calls open():
#0 Digikam::IccTransform::open() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/libs/dimg/filters/icc/icctransform.cpp:550
#1 Digikam::IccTransform::apply() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/libs/dimg/filters/icc/icctransform.cpp:636
and open()'s first lines are:
bool IccTransform::open(TransformDescription& description) {
    if (d->handle)
    {
        if (d->currentDescription == description)
        {
            return true;
        }
     ...

The big difference is: 
In case of "tool loading", d->handle is always "0x0", so the IccTransformation is created via dkCmsCreateTransform() every time of the 70 calls of IccTransform::apply(). Leading to 70 x 6 = 420 calls to cmsReverseToneCurveEx().
In case of "editor loading", digikam realizes that an IccTransformation has already been created and leaves "IccTransform::open()" with the "return true" mentioned in the code snipped above. So "editor loading" produces 1 x 6 = 6 calls to cmsReverseToneCurveEx().

So, the next question seems to be: Why does the "tool loading" process lose "d->handle"?
It is set in IccTransform::open(), in line 543: d->handle = dkCmsCreateTransform(...);
Comment 34 caulier.gilles 2014-01-08 09:18:40 UTC
>So why is "editor loading" faster than "tool loading"?

Because, as i explained before, canvas from editor tool (which is not the same widget than editor main canvas) is redraw more than one time due to signal/slots problem at init. I suspect something wrong with widget style which send a lots of signal to widget at init (i don't know why).

This is true with CM on or off. As CM is time consuming, this affect tool time loading.

Just to be sure, change your KDE widget style. Go to digiKam setup misc. Here i use Oxygen widget.

Note : in all case, i suspect something wrong in EditorTool.cpp implementation about tool initialization.

Gilles Caulier
Comment 35 Peter Albrecht 2014-01-09 20:21:34 UTC
(In reply to comment #34)
> >So why is "editor loading" faster than "tool loading"?
> Because, as i explained before, ...

This was meant as a "rhetorical question" to show my chain of thoughts. ;)
Sorry, I won't use such sentence stile any more, since it can easily be misunderstood.
Comment 36 Peter Albrecht 2014-01-09 20:22:09 UTC
(In reply to comment #34)
> I suspect something wrong with widget style which send a lots of signal to widget at init (i don't know why).
> ...
> Just to be sure, change your KDE widget style. Go to digiKam setup misc.
> Here i use Oxygen widget.

Gilles, you are right! I use widget style "QtCurve" (gentoo ebuilds: x11-themes/gtk-engines-qtcurve-1.8.16 and x11-themes/qtcurve-1.8.14). And there is definitely a problem with this style and digikam: It adds one redundant call to PreviewWidget::viewportPaintEvent() to the "editor tool opening" process!

Using digikam with "Oxygen" widget style, PreviewWidget::viewportPaintEvent() is called ONCE, while editor tool is beeing opened.
Using digikam with "QtCurve" widget style, PreviewWidget::viewportPaintEvent() is called TWICE, while editor tool is beeing opened.

But there is also another, more important bug in PreviewWidget::viewportPaintEvent() and its called functions: See 
> d->handle is always "0x0"
in comment #33.

This "viewportPaintEvent()" bug makes me wait 6 seconds for one call to PreviewWidget::viewportPaintEvent().

So fixing the "QtCurve widget bug" will reduce my waiting time from 12 to 6 seconds, while fixing the "viewportPaintEvent() bug" will reduce waiting time to 1 second. That's the time the editor needs to process its Canvas::viewportPaintEvent(), so I guess viewportPaintEvent() can get as fast as that, if d->handle is not always "0x0".

So I'll concentrate on viewportPaintEvent() first. Also the "QtCurve widget bug" seems to be more complicated to solve, since you need good KDE knowledge, which I don't have (yet ;).
Should I open a separate bug: "QtCurve widget: calling PreviewWidget::viewportPaintEvent() twice on editor tool opening"  ?
Comment 37 Peter Albrecht 2014-01-09 21:17:09 UTC
I guess, I finally found the problem:

*** Short version (if you know the whole comment history) ***
The IccTransform object is created on the stack in 
 #2 Digikam::EditorCore::convertToPixmap() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/utilities/imageeditor/core/editorcore.cpp:999
See stacktrace "PREVIEW WIDGET:" in comment #33
So it gets created and deleted for every tile of the preview beeing processed.


*** Long version (if you don't want to read the whole comment history) ***
cmsReverseToneCurveEx() is a quite time consuming function.

Problematic stacktrace:
#0 cmsReverseToneCurveEx() at /srv/local/debug/media-libs/lcms-2.5-r1/work/lcms2-2.5/src/cmsgamma.c:867
#1 BuildRGBOutputMatrixShaper() at /srv/local/debug/media-libs/lcms-2.5-r1/work/lcms2-2.5/src/cmsio1.c:476
#2 _cmsReadOutputLUT() at /srv/local/debug/media-libs/lcms-2.5-r1/work/lcms2-2.5/src/cmsio1.c:644
#3 DefaultICCintents() at /srv/local/debug/media-libs/lcms-2.5-r1/work/lcms2-2.5/src/cmscnvrt.c:561
#4 cmsCreateExtendedTransform() at /srv/local/debug/media-libs/lcms-2.5-r1/work/lcms2-2.5/src/cmsxform.c:692
#5 cmsCreateMultiprofileTransformTHR() at /srv/local/debug/media-libs/lcms-2.5-r1/work/lcms2-2.5/src/cmsxform.c:807
#6 cmsCreateTransformTHR() at /srv/local/debug/media-libs/lcms-2.5-r1/work/lcms2-2.5/src/cmsxform.c:848
#7 cmsCreateTransform() at /srv/local/debug/media-libs/lcms-2.5-r1/work/lcms2-2.5/src/cmsxform.c:858
#8 Digikam::IccTransform::open() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/libs/dimg/filters/icc/icctransform.cpp:541
#9 Digikam::IccTransform::apply() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/libs/dimg/filters/icc/icctransform.cpp:636
#10 Digikam::DImg::convertToPixmap() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/libs/dimg/dimg.cpp:2038
#11 Digikam::EditorCore::convertToPixmap() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/utilities/imageeditor/core/editorcore.cpp:999
#12 Digikam::ImageIface::convertToPixmap() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/utilities/imageeditor/plugin/imageiface.cpp:309
#13 Digikam::ImageRegionWidget::paintPreview() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/utilities/imageeditor/q3support/imageregionwidget.cpp:141
#14 Digikam::PreviewWidget::viewportPaintEvent() at /srv/local/debug/media-gfx/digikam-3.5.0/work/digikam-3.5.0/core/utilities/imageeditor/q3support/previewwidget.cpp:591

Opening an editor tool in digikam's image editor calls PreviewWidget::viewportPaintEvent().
This function uses tiling, so the subsequent called functions are all called 70 times in my case. (see comment #23)
In EditorCore::convertToPixmap() an IccTransform object is created and placed on the stack.
In IccTransform::open() this IccTransform object realizes, that no color profile has been loaded yet.
So the color profile gets loaded which leads to calls to cmsReverseToneCurveEx().
This color profile then is applied to the current tile.
When done with this tile, the execution pointer climbs up the stacktrace again to PreviewWidget::viewportPaintEvent(), where the next tile will be processed this way.

The problem is: When climbing up the stacktrace and returning from EditorCore::convertToPixmap(), the IccTransform object gets
deleted from the stack. And together with this object, the loaded color profile gets deleted. So for the next tile to be processed, 
an new IccTransform object gets created, which again loads the color profile. Again leading to time consuming calls to
cmsReverseToneCurveEx().


*** Solution ***
The IccTransform object someway needs to be kept alive for the whole tile-processing of PreviewWidget::viewportPaintEvent().
Since I am not very familiar with KDE programming itself nor do I know the digikam architecture very well, I need 
your help Gilles, Marcel or whoever wants to help.
Comment 38 caulier.gilles 2014-06-16 12:46:45 UTC
Peter,

With 4.0.0, we have ported image editor to Qt4 model/view. A lots of code have changed here.

Can you reproduce the problem with this release ?

Gilles Caulier
Comment 39 Peter Albrecht 2014-07-02 20:13:18 UTC
Sorry for the late reply. I'll test it as sone as I have enough spare time again.
Comment 40 caulier.gilles 2014-07-02 21:46:22 UTC
Peter,

digiKam 4.1.0 is just out. Please test with this release if you can...

Gilles Caulier
Comment 41 Peter Albrecht 2014-08-23 18:51:55 UTC
I finally found time to install digiKam 4.2.0 and test this bug.

Good news: With digiKam 4.2.0 this bug is gone! :)

(I did not test versions 4.0.0 or 4.1.0.)

Having "Color Managed View" enabled, starting tools like "Brightness / Contrast / Gamma" in "Image Editor" is fast again. It still takes 2 seconds, but this is acceptable for me in "Color Managed View" on my old machine.

Thanks for your good work.