Bug 124688

yes. but nothing have been changed about tags management between 0.8.x and 0.9.0-svn. In others words, nothing have been changed in database for next release.

Can you check if you have the same result with current stable implementation ?

Gille Caulier

Fixed by commit to revision 525672:

Fix spurious "Failed to find parent for Tag" warning from imagedescedittab:
Move adding code to slotAlbumAdded, call this from populateTags,
dont ignore root in slotAlbumAdded, so dont warn for main view side bar at
startup when filled by AlbumManager signal.

Ok after this fix, I tried 0.9svn, I do not get the spurious messages any more. But digikam is still very long to load. I stays about 20-30 seconds in the "loading cameras" state as shown on splashscreen and nothing appears in the terminal. I will try 0.8.2 later.

[jnarboux@narboux ~]$ digikam
digikam: ScanLib: Finding non-existing Albums: 22 ms
digikam: ScanLib: Finding items not in the database or disk: 1485 ms
digikam: ScanLib: Updating items without date: 49 ms
digikam: Cannot parse EXIF metadata using Exiv2
QMultiInputContext::changeInputMethod(): index=0, slave=xim
QMultiInputContext::changeInputMethod(): index=0, slave=xim

This step takes 30 seconds.

KIPI (loading): KIPI::PluginLoader: plugin KameraKlient is in the ignore list for host application
KIPI (loading): Plugin_JPEGLossless plugin loaded
KIPI (loading): KIPI::PluginLoader: Loaded plugin JPEGLossless
KIPI (loading): Plugin_CDArchiving plugin loaded
KIPI (loading): KIPI::PluginLoader: Loaded plugin CDArchiving
KIPI (loading): Plugin_Imagesgallery plugin loaded
KIPI (loading): KIPI::PluginLoader: Loaded plugin ImagesGallery
KIPI (loading): Plugin_SendImages plugin loaded
...

Ok, the warning was not related to your problem (I intended to fix the warning, not this bug), reopening.
First thing is, "Loading cameras" is misleading because other actions did not display splash messages, so loading cameras would be displayed much longer than it takes. This is fixed now in svn.
Second, please check either by looking at the (now more correct) splash screen, or by applying the patch I will attach, what is taking so long.

Created attachment 15454 [details]
debugging statements

Thank you for your patch, i applied it (by hand ;-), here what i get :

[jnarboux@narboux ~]$ digikam
digikam: ScanLib: Finding non-existing Albums: 22 ms
digikam: ScanLib: Finding items not in the database or disk: 1887 ms
digikam: ScanLib: Updating items without date: 49 ms
digikam: Setting up App 0
digikam: Setting up album manager 91
digikam: Set up album manager 91
digikam: Set up camera list 92
digikam: Cannot parse EXIF metadata using Exiv2
QMultiInputContext::changeInputMethod(): index=0, slave=xim
QMultiInputContext::changeInputMethod(): index=0, slave=xim
digikam: Set up view 889
digikam: Set up actions 1024
digikam: Starting scan 1029
digikam: left scan 27933
KIPI (loading): KIPI::PluginLoader: plugin KameraKlient is in the ignore list for host application
KIPI (loading): Plugin_JPEGLossless plugin loaded
KIPI (loading): KIPI::PluginLoader: Loaded plugin JPEGLossless
KIPI (loading): Plugin_CDArchiving plugin loaded
KIPI (loading): KIPI::PluginLoader: Loaded plugin CDArchiving
KIPI (loading): Plugin_Imagesgallery plugin loaded
KIPI (loading): KIPI::PluginLoader: Loaded plugin ImagesGallery
KIPI (loading): Plugin_SendImages plugin loaded
KIPI (loading): KIPI::PluginLoader: Loaded plugin SendImages
KIPI (loading): Plugin_FlickrExport plugin loaded
KIPI (loading): KIPI::PluginLoader: Loaded plugin FlickrExport
KIPI (loading): Loaded Plugin_Calendar
KIPI (loading): KIPI::PluginLoader: Loaded plugin Calendar
KIPI (loading): Plugin_Mpegencoder plugin loaded
KIPI (loading): KIPI::PluginLoader: Loaded plugin MPEGEncoder
KIPI (loading): Plugin_AcquireImages plugin loaded
KIPI (loading): KIPI::PluginLoader: Loaded plugin AcquireImages
KIPI (loading): Plugin_GalleryExport plugin loaded
KIPI (loading): KIPI::PluginLoader: Loaded plugin GalleryExport
KIPI (loading): Plugin_TimeAdjust plugin loaded
KIPI (loading): KIPI::PluginLoader: Loaded plugin TimeAdjust
KIPI (loading): Plugin_FindImages plugin loaded
KIPI (loading): KIPI::PluginLoader: Loaded plugin FindImages
KIPI (loading): Plugin_PrintWizard plugin loaded
KIPI (loading): KIPI::PluginLoader: Loaded plugin PrintWizard
KIPI (loading): Plugin_WallPaper plugin loaded
KIPI (loading): KIPI::PluginLoader: Loaded plugin WallPaper
KIPI (loading): Plugin_SlideShow plugin loaded
KIPI (loading): KIPI::PluginLoader: Loaded plugin SlideShow
KIPI (loading): Plugin_BatchProcessImages plugin loaded
KIPI (loading): KIPI::PluginLoader: Loaded plugin BatchProcessImages
KIPI (loading): Plugin_SimpleViewer plugin loaded
KIPI (loading): KIPI::PluginLoader: Loaded plugin SimpleViewer
KIPI (loading): Loaded RawConverter
KIPI (loading): KIPI::PluginLoader: Loaded plugin RawConverter
digikam: ImagePlugin_Core plugin loaded
digikam: ImagePluginLoader: Loaded plugin ImagePlugin_Core
digikam: ImagePlugin_InPainting plugin loaded
digikam: ImagePluginLoader: Loaded plugin ImagePlugin_InPainting
digikam: ImagePlugin_Border plugin loaded
digikam: ImagePluginLoader: Loaded plugin ImagePlugin_Border
digikam: ImagePlugin_InsertText plugin loaded
digikam: ImagePluginLoader: Loaded plugin ImagePlugin_InsertText
digikam: ImagePlugin_NoiseReduction plugin loaded
digikam: ImagePluginLoader: Loaded plugin ImagePlugin_NoiseReduction
digikam: ImagePlugin_Unsharp plugin loaded
digikam: ImagePluginLoader: Loaded plugin ImagePlugin_Unsharp
digikam: ImagePlugin_AdjustLevels plugin loaded
digikam: ImagePluginLoader: Loaded plugin ImagePlugin_AdjustLevels
digikam: ImagePlugin_ShearTool plugin loaded
digikam: ImagePluginLoader: Loaded plugin ImagePlugin_ShearTool
digikam: ImagePlugin_DistortionFX plugin loaded
digikam: ImagePluginLoader: Loaded plugin ImagePlugin_DistortionFX
digikam: ImagePlugin_LensDistortion plugin loaded
digikam: ImagePluginLoader: Loaded plugin ImagePlugin_LensDistortion
digikam: ImagePlugin_BlowUp plugin loaded
digikam: ImagePluginLoader: Loaded plugin ImagePlugin_BlowUp
digikam: ImagePlugin_Restoration plugin loaded
digikam: ImagePluginLoader: Loaded plugin ImagePlugin_Restoration
digikam: ImagePlugin_Refocus plugin loaded
digikam: ImagePluginLoader: Loaded plugin ImagePlugin_Refocus
digikam: ImagePlugin_WhiteBalance plugin loaded
digikam: ImagePluginLoader: Loaded plugin ImagePlugin_WhiteBalance
digikam: ImagePlugin_AntiVignetting plugin loaded
digikam: ImagePluginLoader: Loaded plugin ImagePlugin_AntiVignetting
digikam: ImagePlugin_AdjustCurves plugin loaded
digikam: ImagePluginLoader: Loaded plugin ImagePlugin_AdjustCurves
digikam: ImagePlugin_FreeRotation plugin loaded
digikam: ImagePluginLoader: Loaded plugin ImagePlugin_FreeRotation
digikam: ImagePlugin_Perspective plugin loaded
digikam: ImagePluginLoader: Loaded plugin ImagePlugin_Perspective
digikam: ImagePlugin_ChannelMixer plugin loaded
digikam: ImagePluginLoader: Loaded plugin ImagePlugin_ChannelMixer
digikam: LoadedPlugins 29010
digikam: Populated themes 29023
digikam: Set up App 29029

Created attachment 15455 [details]
some more debugging

So you are spending 27s in reading the database. You did not create a few
million tags, did you :-)
So here is the next set of debugging (you can remove the first one) to find out
if a specific part takes excessively long. If you know C++ you might want to
further narrow this down on your own if this patch is missing it, otherwise
just post the results.

I will try later to understand what is going on here. Here is the results.

By the way mi digikam3.db file is 1.6mb, is this normal ? i have got about 8000 pictures and less than 200 tags.

Perhaps my database is corrupted somehow. Because I remember that when I was using a older version of digikam, sometimes several instances of digikam were starting automatically after relogin into kde and I had to do a killall digikam. I thought it was because kde somehow thought i had several instance running before login out and wanted to "restore the session". 

Anyway here are the results :

[jnarboux@narboux ~]$ digikam
digikam: ScanLib: Finding non-existing Albums: 1869 ms
digikam: ScanLib: Finding items not in the database or disk: 6969 ms
digikam: ScanLib: Updating items without date: 39 ms
digikam: Setting up App 0
digikam: Setting up album manager 113
digikam: Set up album manager 113
digikam: Set up camera list 114
digikam: Cannot parse EXIF metadata using Exiv2
QMultiInputContext::changeInputMethod(): index=0, slave=xim
QMultiInputContext::changeInputMethod(): index=0, slave=xim
digikam: Set up view 1556
digikam: Set up actions 1704
digikam: Starting scan 1737
digikam: startScan 0
digikam: created dirwatch 3
digikam: created roots 52
digikam: refresh - time 2 0
digikam: scanned P - time 2 717
digikam: scanTAlbums - time 3 0
digikam: set up map - time 3 0
digikam: scanned list - time 3 32
digikam: inserted tags - time 3 33
digikam: built tree - time 3 33
digikam: inserted to list - time 3 34
digikam: Returning from scanTAlbums - that was time 3 21189
digikam: scanned T - time 2 21907
digikam: scanned S - time 2 21942
digikam: scanned D - time 2 21942
digikam: returning from refresh - that was time 2 21942
digikam: refreshed 21995
digikam: left scan 30346

I have about 11000 pics and 200 tags and it takes about 22 sec until after the scan plus 23 sec until the plugins are starting to load. 3GHz i586 and enough RAM. My database is 2.7MB. This means I confirm this problem. All-in-all digiKam takes ~50 sec to start.

Created attachment 15475 [details]
some more debugging

There is 20s for time3 in the loop of scanTAlbums. That code is not directly
related to the database, it is creating the album objects from the info read
from the db. Here is another round of debugging (you can "svn revert" the
previous patches before). It creates a long list, cut it to some samples when
posting here. I have 91 tags (value is output by a debug statement). The values
I get are similar to

digikam: enter loop 0
digikam:  checked map 0
digikam:  found parent 1
digikam:  created album 1
digikam:  inserted album 171
digikam:  insert to map 171

for the entries 4,5,6,7 and then only values like

digikam: enter loop 0
digikam:  checked map 0
digikam:  found parent 0
digikam:  created album 0
digikam:  inserted album 1
digikam:  insert to map 1

for the rest.

I get a lot of values of the form :

digikam: enter loop 0
digikam:  checked map 0
digikam:  found parent 0
digikam:  created album 0
digikam:  inserted album 235
digikam:  insert to map 236
digikam: enter loop 0
digikam:  checked map 0
digikam:  found parent 0
digikam:  created album 0
digikam:  inserted album 237
digikam:  insert to map 237
digikam: enter loop 0
digikam:  checked map 0
digikam:  found parent 0
digikam:  created album 0
digikam:  inserted album 237
digikam:  insert to map 237

and few 
digikam: enter loop 0
digikam:  checked map 0
digikam:  found parent 0
digikam:  created album 1
digikam:  inserted album 1
digikam:  insert to map 1

Hope it helps.

Best regards.

Have you set icons for many of your tags? May it be that the tags with icons are those that take the ~230ms?

You are right ! i have set icons (pictures in fact) to most of my tags. This may be the reason.

I deleted 20 tag and album icons of about 40 I had left. That speeded digiKam launch up from 23 sec to 15 sec (after scan). Incredible how much time those objects need to be generated.

Gerhard

Every thumbnail is loaded three times (three tag tree views), so for you that's 200 * 3 thumbnail images loaded.

Ok, we need to
- verify this, measure time for thumbnail loading
- delay loading of the tag thumbnails, use ioslave asynchronously
- cache thumbnails (pixmap cache as for main view)

I hope I find time for this at the weekend.

SVN commit 531701 by mwiesweg:

digikam from trunk:
Load tag thumbnails asynchronously, speed up startup

- add a new class AlbumThumbnailLoader and consolidate all
  tag and album thumbnail loading code
- use this class in TagFilterView, TagFolderView, ImgDescEditTag
- do no longer use syncjob for tag thumbnail loading,
  but use asynchronous mode for custom tag icons (as done for PAlbums)

Please check that this fixes the huge startup delays

TODO: Need to check that icons are actually loaded 
      only once by slave if added multiple times
      (not relevant to startup speed)
CCBUG: 124688



 M  +1 -0      digikam/Makefile.am  
 M  +18 -64    digikam/albumfolderview.cpp  
 M  +15 -15    digikam/albumfolderview.h  
 A             digikam/albumthumbnailloader.cpp   [License: GPL]
 A             digikam/albumthumbnailloader.h   [License: GPL]
 M  +73 -40    digikam/tagfilterview.cpp  
 M  +7 -2      digikam/tagfilterview.h  
 M  +75 -47    digikam/tagfolderview.cpp  
 M  +6 -2      digikam/tagfolderview.h  
 M  +54 -26    libs/imageproperties/imagedescedittab.cpp  
 M  +5 -1      libs/imageproperties/imagedescedittab.h  

Your patch solved the loading time problem !

but i noticed a small bug : when i click on an album to select it during 1/4 of second the icon shows the generic one (a folder) before showing again the icon i have set. 

I hope you understand what i mean.

Cheers

Julien

SVN commit 533114 by mwiesweg:

Do not re-set album thumbnail again from view,
disable slot_AlbumHighlight

Closing bug 124688 now.

BUG: 124688


 M  +5 -0      digikamview.cpp  


--- trunk/extragear/graphics/digikam/digikam/digikamview.cpp #533113:533114
@@ -653,11 +653,16 @@
 
 void DigikamView::slot_albumHighlight()
 {
+    // TODO:
+    // Don't know what this is supposed to do.
+    // Perhaps some flashing or other eye kandy
+    /*
     Album *album = mAlbumMan->currentAlbum();
     if (!album || !album->type() == Album::PHYSICAL)
         return;
 
     mFolderView->setAlbumThumbnail(dynamic_cast<PAlbum*>(album));
+    */
 }
 
 void DigikamView::slot_imageCopyResult(KIO::Job* job)