Imatch Froze after Geolocation

[Jingo]

Hi Mario - had something strange happen today.. had 2 files highlighted and did a reverse geo-lookup on them.  Selected Lookup All and hit ok... Imatch froze for about 20-30 seconds.. the only thing I can see in the log file is this (didn't have debug logging turned on unfortunately):

Code Select Expand

05.19 20:21:53+  265 [00D0] 02  I>   Caches started in 281ms.
05.19 20:21:55+ 1875 [00D0] 00  I>   # Process Memory Info: WSC: 332MB, WSP: 361MB (NEW PEAK), PF: 984480
05.19 20:21:55+   16 [00D0] 00  M>   <  2 [4641ms] CMainFrame::LoadDatabase
05.19 20:21:55+    0 [00D0] 00  M>  <  1 [6844ms #sl] CIMatchApp::InitInstance
05.19 20:21:56+ 1609 [1E04] 00  M>  >  1 CIMGeoLocationManager::GetLocations  'IMGeoLocation.cpp(179)'
05.19 20:21:56+    0 [1E04] 00  M>  <  1 CIMGeoLocationManager::GetLocations
05.19 20:22:10+13485 [00D0] 02  I> E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\74\74263.jpg loaded in 516ms. Result: 2
05.19 20:22:10+  672 [00D0] 02  I> E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\74\74263.jpg loaded in 516ms. Result: 2
05.19 20:23:19+68906 [00D0] 02  I> E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\67\67428.jpg loaded in 188ms. Result: 2
05.19 20:23:28+ 8578 [00D0] 02  I> E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\67\67428.jpg loaded in 172ms. Result: 2
05.21 07:54:27+127859250 [00D0] 02  I> E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\74\74263.jpg loaded in 969ms. Result: 2
05.21 07:54:34+ 7172 [00D0] 02  I> E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\74\74262.jpg loaded in 922ms. Result: 2
05.21 07:54:36+ 1937 [00D0] 02  I> E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\74\74261.jpg loaded in 578ms. Result: 2
05.21 07:54:40+ 4235 [00D0] 02  I> E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\74\74265.jpg loaded in 734ms. Result: 2
05.21 07:54:48+ 7687 [00D0] 02  I> E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\74\74276.jpg loaded in 578ms. Result: 2
05.21 07:54:52+ 3438 [00D0] 02  I> E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\74\74268.jpg loaded in 438ms. Result: 2
05.21 07:54:53+ 1281 [00D0] 02  I> E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\74\74276.jpg loaded in 578ms. Result: 2
05.21 07:56:26+92672 [00D0] 02  I> E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\74\74293.jpg loaded in 656ms. Result: 2
05.21 07:56:45+19016 [1CE0] 02  I> Locking mode is EXCLUSIVE
05.21 07:56:45+    0 [1CE0] 02  I> Locking mode is EXCLUSIVE
05.21 07:56:45+    0 [1CE0] 02  I> Locking mode is EXCLUSIVE
  UNITED STATES
  worthington center
  other
05.21 07:57:13+28875 [00D0] 00  I> # Loglevel changed to 50.
05.21 07:57:29+15421 [00D0] 00  I> # Loglevel changed to 10.
05.21 07:59:33+124204 [00D0] 10  M>  >  1 CViewPaneFileWndContainerPreviewDX::ShowPlayer  'ViewPaneFileWndContainerPreviewDX.cpp(1452)'
05.21 07:59:33+    0 [00D0] 10  M>  <  1 CViewPaneFileWndContainerPreviewDX::ShowPlayer
05.21 07:59:33+    0 [00D0] 05  M>  >  1 CIMDXWnd::LoadFile  'IMDXWnd.cpp(778)'
05.21 07:59:33+    0 [00D0] 02  I>  E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\74\74294.jpg loaded in 594ms. Result: 2
05.21 07:59:33+    0 [00D0] 05  M>  <  1 CIMDXWnd::LoadFile
05.21 07:59:33+    0 [00D0] 10  M>  >  1 CIMAnnoManager::GetContainer  'IMAnnoManager.cpp(194)'
05.21 07:59:33+    0 [00D0] 10  M>  <  1 CIMAnnoManager::GetContainer
05.21 07:59:33+    0 [05D0] 02  I> E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\74\74304.jpg
05.21 07:59:33+    0 [2D64] 10  M>  >  1 PTMetabase::GetGPSCoordinates  'PTMetabase2.cpp(2286)'
05.21 07:59:33+    0 [2D64] 10  M>  <  1 PTMetabase::GetGPSCoordinates
05.21 07:59:33+   15 [2D64] 10  M>  >  1 PTMetabase::GetGPSCoordinates  'PTMetabase2.cpp(2286)'
05.21 07:59:33+    0 [2D64] 10  M>  <  1 PTMetabase::GetGPSCoordinates
05.21 07:59:33+   47 [05D0] 02  I> Purge-Stats: 10 entries in cache (604 MB). 1 items released.
05.21 07:59:33+  141 [00D0] 10  M>  >  1 CIMControlContainerWnd::InnerSetValues  'IMControlContainerWnd.cpp(954)'
05.21 07:59:33+   47 [00D0] 10  M>  <  1 [47ms] CIMControlContainerWnd::InnerSetValues
05.21 07:59:34+  468 [00D0] 10  M>  >  1 CIMControlContainerWnd::InnerSetValues  'IMControlContainerWnd.cpp(954)'
05.21 07:59:34+   16 [00D0] 10  M>  <  1 [16ms] CIMControlContainerWnd::InnerSetValues
05.21 07:59:34+   16 [00D0] 10  M>  >  1 CViewPaneFileWndContainerPreviewDX::ShowPlayer  'ViewPaneFileWndContainerPreviewDX.cpp(1452)'
05.21 07:59:34+    0 [00D0] 10  M>  <  1 CViewPaneFileWndContainerPreviewDX::ShowPlayer
05.21 07:59:34+    0 [00D0] 05  M>  >  1 CIMDXWnd::LoadFile  'IMDXWnd.cpp(778)'
05.21 07:59:34+    0 [00D0] 02  I>  E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\74\74295.jpg loaded in 672ms. Result: 2
05.21 07:59:34+    0 [00D0] 05  M>  <  1 CIMDXWnd::LoadFile
05.21 07:59:34+    0 [00D0] 10  M>  >  1 CIMAnnoManager::GetContainer  'IMAnnoManager.cpp(194)'
05.21 07:59:34+    0 [00D0] 10  M>  <  1 CIMAnnoManager::GetContainer
05.21 07:59:34+    0 [05D0] 02  I> E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\74\74305.jpg
05.21 07:59:34+    0 [2D64] 10  M>  >  1 PTMetabase::GetGPSCoordinates  'PTMetabase2.cpp(2286)'
05.21 07:59:34+    0 [2D64] 10  M>  <  1 PTMetabase::GetGPSCoordinates
05.21 07:59:34+   15 [2D64] 10  M>  >  1 PTMetabase::GetGPSCoordinates  'PTMetabase2.cpp(2286)'
05.21 07:59:34+    0 [2D64] 10  M>  <  1 PTMetabase::GetGPSCoordinates
05.21 07:59:34+  188 [00D0] 10  M>  >  1 CIMControlContainerWnd::InnerSetValues  'IMControlContainerWnd.cpp(954)'
05.21 07:59:34+   47 [00D0] 10  M>  <  1 [47ms] CIMControlContainerWnd::InnerSetValues
05.21 07:59:34+  265 [00D0] 10  M>  >  1 CIMControlContainerWnd::InnerSetValues  'IMControlContainerWnd.cpp(954)'
05.21 07:59:34+    0 [00D0] 10  M>  <  1 CIMControlContainerWnd::InnerSetValues
05.21 07:59:36+ 1453 [00D0] 10  M>  >  1 CViewPaneFileWndContainerPreviewDX::ShowPlayer  'ViewPaneFileWndContainerPreviewDX.cpp(1452)'
05.21 07:59:36+    0 [00D0] 10  M>  <  1 CViewPaneFileWndContainerPreviewDX::ShowPlayer
05.21 07:59:36+    0 [00D0] 05  M>  >  1 CIMDXWnd::LoadFile  'IMDXWnd.cpp(778)'
05.21 07:59:36+    0 [00D0] 05  M>  <  1 CIMDXWnd::LoadFile
05.21 07:59:36+    0 [00D0] 10  M>  >  1 CIMAnnoManager::GetContainer  'IMAnnoManager.cpp(194)'
05.21 07:59:36+    0 [00D0] 10  M>  <  1 CIMAnnoManager::GetContainer
05.21 07:59:36+    0 [05D0] 02  I> E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\74\74288.jpg
05.21 07:59:36+    0 [2D64] 10  M>  >  1 PTMetabase::GetGPSCoordinates  'PTMetabase2.cpp(2286)'
05.21 07:59:36+    0 [2D64] 10  M>  <  1 PTMetabase::GetGPSCoordinates
05.21 07:59:36+    0 [2D64] 10  M>  >  1 PTMetabase::GetGPSCoordinates  'PTMetabase2.cpp(2286)'
05.21 07:59:36+    0 [2D64] 10  M>  <  1 PTMetabase::GetGPSCoordinates
05.21 07:59:36+  203 [00D0] 10  M>  >  1 CIMControlContainerWnd::InnerSetValues  'IMControlContainerWnd.cpp(954)'
05.21 07:59:36+   47 [00D0] 10  M>  <  1 [47ms] CIMControlContainerWnd::InnerSetValues
05.21 07:59:36+  297 [00D0] 02  I> E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\74\74288.jpg loaded in 547ms. Result: 2
05.21 07:59:36+    0 [05D0] 02  I> E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\74\74289.jpg
05.21 07:59:37+  172 [00D0] 10  M>  >  1 CIMControlContainerWnd::InnerSetValues  'IMControlContainerWnd.cpp(954)'
05.21 07:59:37+    0 [00D0] 10  M>  <  1 CIMControlContainerWnd::InnerSetValues
05.21 07:59:37+  516 [05D0] 02  I> E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\74\74290.jpg
05.21 07:59:38+  718 [05D0] 02  I> E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\74\74291.jpg
05.21 07:59:38+  594 [05D0] 02  I> E:\photools.com\previewcache\8EF3810B-3F63-4B0C-B38C-00A2E120A15B\74\74292.jpg


Those ms look crazy in there.. really slow any thoughts?  Also - why are these previewcache files being hit anyway?   DB on SSD.. image on local 7200 spin disk. 

Thx - Andy.

[Mario]

The "crazy" ms are just periods of inactivity. Nothing was logged during these periods.
IMatch needs 47 ms to load metadata an fill in the Metadata Panel / Keyword Panel. Normal.

The log jumps from 05.19 20:23:2 to 05.21 07:54:27 which I guess is caused by you hibernating your computer.
The reminder of the log file covers only 5 seconds in total. Nothing much happens, except that several images are pulled from the cache and that the GPS coordinates of two (?) images are set in no time (< 50 ms).

Nothing that would indicate IMatch freezing or anything.
When did IMatch freeze exactly? After the reverse geo-coding dialog was closed?
How many files does this database have?
How many data-driven categories do you use?
How is your workspace configured?

If the database is huge, your PC is slow, you have many panels open which force an immediate update of data-driven categories affected by you changing GPS coordinates and other metadata of files, IMatch may be busy for some time. Try to repeat with debug logging enabled, then we'll now more. Include the full log!


Note:
Please don't just copy/paste a fragment of the log file into your post.
1. There is important info at the beginning of the log I can't see. For example, if your database has 50,000 files or 500,000 files.
2. All the log junk ends up in the community search engine, making it less useful for all users.
Always ZIP and ATTACH log files. Thank you.