Delay immediately after start-up

Started by Jingo, April 01, 2019, 10:48:52 PM

Previous topic - Next topic

Jingo

Hi Mario - noticed that lately IMatch "freezes" immediately after starting the program.  Looking at the debug log, I only see tiny ms calls until I get to this block:

04.01 16:44:10+20078 [20D0] 10  I>                    Query Cache Memory used: 8536 KB for 885 entries and 8 tags. Scope size: 246
04.01 16:44:10+    0 [20D0] 10  M>                  < 17 [20125ms #sl] CIMQueryCache::Update
04.01 16:44:11+  562 [0B30] 10  M>                  > 17 CIMControlContainerWnd::InnerSetValues  'g:\v\develop\imatch5\src\imatchng\imcontrolcontainerwnd.cpp(956)'
04.01 16:44:11+  391 [0B30] 10  M>                  < 17 [391ms] CIMControlContainerWnd::InnerSetValues
04.01 16:44:11+   94 [0B30] 10  M>                  > 17 CIMResManager::TaskDialog  'g:\v\develop\imatch5\src\imatchng\imresmanager.cpp(1011)'
04.01 16:44:11+    0 [0B30] 10  I>                  PTR_MSG_DB_RUNDIAG
04.01 16:44:11+   78 [0B30] 10  M>                   > 18 CIMEngineUpdateQueue::Enable  'v:\develop\imatch5\src\imengine\imengineupdatequeue.cpp(2258)'
04.01 16:44:11+    0 [0B30] 10  M>                   < 18 CIMEngineUpdateQueue::Enable
04.01 16:44:11+    0 [0340] 10  M>                   > 18 CIMEngineFolderScanner::Invoke  'v:\develop\imatch5\src\imengine\imengine5.cpp(567)'
04.01 16:44:11+    0 [0340] 10  M>                    > 19 CIMSQLite::GrowInstancePool  'v:\develop\imatch5\src\imsq\imsqlite.cpp(2807)'
04.01 16:44:11+    0 [0340] 10  M>                     > 20 CIMSQLite::InnerOpen  'v:\develop\imatch5\src\imsq\imsqlite.cpp(2941)'
04.01 16:44:11+    0 [0340] 02  I>                     Locking mode is EXCLUSIVE
04.01 16:44:11+    0 [0340] 02  I>                     Locking mode is EXCLUSIVE
04.01 16:44:11+    0 [0340] 10  M>                     < 20 CIMSQLite::InnerOpen
04.01 16:44:11+    0 [0340] 10  M>                     > 20 CIMSQLite::InnerOpen  'v:\develop\imatch5\src\imsq\imsqlite.cpp(2941)'
04.01 16:44:11+    0 [0340] 02  I>                     Locking mode is EXCLUSIVE
04.01 16:44:11+    0 [0340] 10  M>                     < 20 CIMSQLite::InnerOpen
04.01 16:44:11+    0 [0340] 10  I>                    PTSQL::InstancePool: Grown to 2 instances
04.01 16:44:11+    0 [0340] 10  M>                    < 19 CIMSQLite::GrowInstancePool
04.01 16:44:11+   15 [10AC] 10  M>                     > 20 PTETWrapper::ProcessClose  'v:\develop\imatch5\src\imengine\ptetwrapper.cpp(3562)'
04.01 16:44:11+    0 [10AC] 10  M>                     < 20 PTETWrapper::ProcessClose
04.01 16:44:11+    0 [37B0] 10  M>                    > 19 PTETWrapper::ProcessClose  'v:\develop\imatch5\src\imengine\ptetwrapper.cpp(3562)'
04.01 16:44:11+    0 [37B0] 10  M>                    < 19 PTETWrapper::ProcessClose
04.01 16:44:16+ 4063 [0B30] 10  M>                   < 18 [4156ms] CIMResManager::TaskDialog
04.01 16:44:49+33687 [0B30] 00  M>                   > 18 CUpdateChecker::ShowResults  'g:\v\develop\imatch5\src\imatchng\updatechecker.cpp(181)'
04.01 16:44:49+    0 [0B30] 10  M>                    > 19 CIMResManager::TaskDialog  'g:\v\develop\imatch5\src\imatchng\imresmanager.cpp(1011)'
04.01 16:44:49+    0 [0B30] 10  I>                    PTR_MSG_APP_UPDATECHECK_OK
04.01 16:45:41+52188 [0B30] 10  M>                    < 19 [52188ms #sl] CIMResManager::TaskDialog
04.01 16:45:41+    0 [0B30] 00  M>                   < 18 [52188ms #sl] CUpdateChecker::ShowResults


Curious what the 20 second Query Cache Memory is doing that could be taking some time... also see about 33 seconds for the Update Checker to do it's thing... are these normal delays that I should expect after startup?   Rest of log is attached too.  Thx!

Mario

#1
IMatch updates an internal cache used for searching, Metadata Panel, Keyword Panel etc.
This does not block IMatch, it runs in a separate background thread and thus IMatch does other things while this is running.
20 seconds is quite slow for such a database. Is this a fast disk? Virus checker set to ignore the folder containing the database?

Maybe a log file in debug logging mode (see log file) reveals more details.
Typically, the most time during startup is required for setting up the UI, load all panels etc.
There are expensive panels like categories, keywords which require IMatch to load and process a lot of data initially. Maybe this is something to check, which panels are visible when IMatch comes up, how many panels are open...
-- Mario
IMatch Developer
Forum Administrator
http://www.photools.com  -  Contact & Support - Follow me on 𝕏 - Like photools.com on Facebook