Need help with Imatch showing blue circle

[hluxem]

Imatch worked well till about a week ago. The last couple of days I have a lot of issues with Imatch becoming unresponsive and showing the blue circle. When I leave it running it will become responsive after some time, that could be 5 minutes or an hour. Sometimes I can work normally, sometimes I get the blue circle with any action in Imatch. 

I excluded the program folder from Windows defender, run diagnosis and compact and optimize, reset the workspace and shut down the computer several times. So far nothing has changed. I switched to debug logging; the attached log file is from today. Most of the day I saw the blue circle. Is there anything in the logfile pointing to a problem? 

I think I started a folder rescan at 13:42 to import some new files, Imatch was unresponsive till ~ 14:20. During that time Imatch wrote a lot of entries in the logfile, don't know what the entries mean. When I clicked on the quick filter, the blue circle came back, this time the entry says purging temp cache files.

The last entry is:

06.06 14:22:43+26063 [1120] 10  M> >  0 CIMCacheManager::PurgeTempCacheFiles  'V:\develop\IMatch5\src\IMEngine\IMCacheManager.cpp(1598)'
06.06 14:22:43+    0 [1120] 10  M>  <  0 CIMCacheManager::PurgeTempCacheFiles
06.06 14:27:43+300265 [1120] 10  M> >  0 CIMCacheManager::PurgeTempCacheFiles  'V:\develop\IMatch5\src\IMEngine\IMCacheManager.cpp(1598)'
06.06 14:27:43+    0 [1120] 10  M>  <  0 CIMCacheManager::PurgeTempCacheFiles
06.06 14:32:44+300250 [1120] 10  M> >  0 CIMCacheManager::PurgeTempCacheFiles  'V:\develop\IMatch5\src\IMEngine\IMCacheManager.cpp(1598)'
06.06 14:32:44+  16 [1120] 10  M>  <  0 [16ms] CIMCacheManager::PurgeTempCacheFiles

It's now 14:34 and Imatch is still not responding.

I had similar problems on a different computer before:
https://www.photools.com/community/index.php/topic,14102.msg99198.html#msg99198

Please let me know if there is anything in the logfile pointing to a problem or if you have any other suggestion how I can troubleshoot this.
Thanks a lot,
Heiner

[Mario]

The computer reports 20 processor cores and 64GB RAM.
The database manages about 450,000 files, with a size of 20GB on disk. IMatch starts up fully in about 15 seconds. Quite a beefy computer.

I see no warnings in the log file, except for the standard ones (no spell checker dictionary installed, spell checking disabled all over IMatch). And some warnings that IMatch uses more then 2.5 GB of RAM.

CIMCacheManager::PurgeTempCacheFiles  is a function that is regularly called from a background thread when the IMatch engine is idle. It checks if there are any temporary cache files to delete. It is only logged when the log level is above normal (your log file is in debug logging mode).

I see this:

RefreshGroup-Completed: '7 Online Information' in 511062 ms.

511 seconds (!) to recalculate this category. It uses the variable {File.Offline}, which is NOT a good idea!
This variable checks if a file exists on disk. This means it has to ask the file system for information. And you use that in a data-driven category. Which means every time this category updates, IMatch has to do 450,000 (!) queries against the File System. This will slow down anything. And the data-driven category is updated many times, since indexing new files invalidates all data-driven categories.

Don't do this. Or at least set the category to manual update and update it only when you really, really need it.

Many other custom data-driven categories are updated, taking 2 to 10 seconds each.
450,000 files to process for each category takes its toll.

Then

Parsing variable '{File.MD.Exif::Main\40962\ExifImageWidth\0|numcomp:lt,1,No Width, {File.MD.Exif::Main\40962\ExifImageWidth\0| numformat:int,0;numcomp:gt, {File.MD.Exif::Main\40963\ExifImageHeight\0|numformat:int,0},{ File.MD.Exif::Main\274\Orientation\0|value:formatted;contains:C,Portrait,Landscape},{ File.MD.Exif::Main\274\Orientation\0|value:formatted;contains:C,Landscape,Potrait}}}'

RefreshGroup-Completed: 'Layout' in 268468 ms.

Another slow variable-based category. Using complex variables like this and letting IMatch parse and resolve it 450,000 times to update a data-driven category works, but is really slow.
Again, maybe set it to manual and update it only when really needed?

Having data-driven categories which take 260 to 500 seconds will slow down the database and thus all operations in IMatch.

Please resolve this by setting the categories to manual. Then monitor if this solves the slow-down problem.

[hluxem]

Thanks for pointing out that the categories were set to auto refresh. Normally I set them to manual, but I missed this. Important to keep in mind that I have not touched these categories for a while and Imatch worked fine up to last week.
After trying different things, I believe I finally found the issue. 

Summary:
A custom filter called "Hide offline files" (File Properties - Hide off-line files) enabled in the quick filter panel causes all the issues with the blue circle when changing folders or trying to move from image to image in the viewer. Disabling the quick filter and using the same filter in the filter panel works just fine. Other filters in the quick filter panel work fine too.

I took me quite a while to get to this point, maybe the log files and steps I wrote down below help you in tracking down a possible bug. For me it seems to be quite reproducible that this filter stalls Imatch to a halt when used from the quick filter drop down menu. If you like me to do some other tests, just let me know. 

Here is what I did:

Changed all categories to manual refresh
Closed database and shut down computer
Restarted Imatch, opened database
Run diagnostic
Run compact and optimize

After these steps, I could click on different images in the file window without a problem, changing folders or starting the viewer gave me the blue circle again.

If you look at the attached log file "IMATCH6_LOG 3", I changed the folder at 12:04, back at 12:06 and started the viewer at 12:26, closed the viewer at 12:31.

Not knowing what to do next, I switched off the experimental mode. I was using it since it is available. Then I closed the database and started Imatch again.

Strangely enough, no more blue circles and the database reacted like it used to be. See log file"IMATCH6_LOG 4 exp off".

So far so good, but even more strange was that after I enabled the experimental mode again, everything worked well. I was so happy that I didn't write down when exactly I tried to enable the Quick Filter. Somewhere in between 12:46 and 12:55. As soon as the quick filter was enabled the blue circle showed up. The blue circle stopped at 12:58, started again when I changed folder. At 11:15 I double-clicked one image to open the viewer, blue circle again.
Long story short, I had a filter called hide offline files in the quick panel enabled. The filter was created using "File Properties - Hide off-line files" in the filter panel. Switching it on in the filter panel works without issue. Logfile from the last session is "IMATCH6_LOG 5 exp on"
 

[Mario]

How many files are in the scope?
Are some or all of the files offline?
Local disk or network?

I wonder, since the Quick Filter Panel does exactly the same as the filter panel when you enable a stored filer.
It runs the filter.

I understand you see differences in runtime when you enable the same stored filter in the Quick Filter and the regular filter panel?

I've made a quick check with a scope of 2000 files and I see no difference whether I use my "Hide Off-line Files" stored filter in the Filter Panel or the Quick Filter. No other filters are active in the Filter Panel / Quick Filter ribbon.

~ 1 second to switch between a folder with 2000 files and one with 800 files for both Quick Filter and Filter Panel with enabled "Hide Offline files" filter.

[hluxem]

How many files are in the scope?

426

Are some or all of the files offline?

all online, I already removed the offline files

Local disk or network?

local

I understand you see differences in runtime when you enable the same stored filter in the Quick Filter and the regular filter panel?

I would not call it runtime difference. Imatch becomes not responding, the window is greyed out and the circle spins about 5 minutes. I just enabled the filter at 14:32 and it took to about 14:38 before Imatch responded again. Then I pause the quick filter and switched back and forth between the 2 folders instantly. Maybe the attached logfile shows something. At 14:37:38 it says 268062 and at 14:37:43 64656. If these numbers are ms that could make up for the long wait.

[hluxem]

Logfile for previous post attached.

[JohnZeman]

I had the same problem up until about 10 days ago.  For me the blue circle unresponsive IMatch problem began about 6 weeks ago on this new computer I recently put into service.  Oddly enough the problem disappeared when I put IMatch in debug mode which doesn't make any sense to me but in normal mode IMatch would freeze up once in awhile, in debug mode it never did.  The problem often occurred when I wasn't usng IMatch, when the program was running but idling in the background while I was using another program.  Then finally the problem just disappeared altogether.

After reading the above posts I just changed about 10 data-driven categories to manual update, maybe my problem was related to auto-updating those categories too?

[Mario]

I had the same problem up until about 10 days ago.  For me the blue circle unresponsive IMatch problem began about 6 weeks ago on this new computer

Debug logging actually costs time, since IMatch has to write so much data into the log file. It can severely reduce performance.
I guess this is rather a side effect of something.

Did you keep a log file from a session where this happened? This might allow us to see what keeps IMatch busy...

In case of the OP, data-driven categories which require 5 or 10 minutes (!) to process will for sure kill performance.
Even if this is not directly related to second the issue with the filter, calculating such expensive categories only on-demand will be good.

I will look into the Quick Filter issue shortly.

[Mario]

I have fixed the problem.

When the Quick Filter Ribbon was used with stored filters, the current scope (File Window contents) was not always applied correctly. This could cause the filter to run on all files in the database. And that in combination with a large database and a super-slow filter like "Hide Off-line Files" resulted in excessive execution times.

[hluxem]

Great, thank you!

This must have been a hard-to-find bug. I'm glad the "blue circle bug" is gone!

[Mario]

Was not hard to find after it has been reported.
The Quick Filter ribbon is available in experimental feature more for a few months, and you were the first stumbling on this particular problem.