Imatch becomes unresponsive

[hluxem]

Yesterday I had some Issues with Imatch becoming not responsive. I closed Imatch with the taskmanager and switched debug logging on. 
Imatch again became unresponsive after Iused the quick filter with a stored filter on a folder with 350 images. The quickfilter is checking if the tag "LocationCreated" has a value. I left the computer running, the blue circle was gone this morning but as soon as I tried to change a folder it started again.
While the blue circle is running Imatch logs the following over and over.

03.14 22:54:03+  672 [40A8] 50  M> >  0 PTMetabase::ValueCachePurge  'V:\develop\IMatch5\src\IMEngine\PTMetabase2.cpp(3777)'
03.14 22:54:03+  15 [40A8] 02  I>    47 of 1954 purged.

I attached the log file, maybe there is a hint what's going on when this happens.

Thanks,

Heiner

[Mario]

Nothing unusual in this log file (except you have disabled all spell checking features in IMatch by not installing a dictionary for your language).

ValueCachePurge is a function that is regularly called when the cache for metadata tag values in memory exceeds a certain threshold. The IMatch engine then removes entries that have not been used for a certain time from memory.
This is a performance feature that reduces database round trips.

In your log file this function is called very often, constantly adding new values to the cache and removing old ones. Quite unusual.

I understand you work with the experimental QuickFilter feature in the File Window?
And you use a user-defined filter than checks a tag value? How have you defined this filter, exactly?

Since the scope has only 350 files, I don't see why IMatch should have to free cache memory at all. Give me detailed information on how to reproduce this and maybe I can figure out what the issue is.

Your database has 400K files, which is large.
When IMatch starts, 74% of the available memory are already in use! Which is not good. Only 8 GB of 32GB are available.
IMatch peaks at about 1GB memory usage, which is fine for a database with more than 400K.

Which other memory-hungry applications where you running at the time? Something from Adobe?

At the time IMatch starts calling ValueCachePurge, files were imported in the background, XMP regions were extracted, file data is deleted and finally metadata is processed and updated in the database. All pretty normal, except for the many calls to ValueCachePurge. Maybe IMatch reacted on Windows "memory running low" events, trying to free memory, which was counter-productive at a time when IMatch was in full flight adding files to the database.
Or maybe the purge threshold is too conservative and I should increase.

I can tell more when I know how to reproduce this.

[Mario]

I've made some tests with ValueCachePurge and why it might be called so often.
Finally found a situation while running a database diagnosis for a 150K files database.

Basically, one step in the diagnosis reads all metadata in the database in batches.
This causes the cache to become full very often and in quick succession. The purge operation used a time window to determine which cache entries to remove (the oldest) and in this particular situation, the time stamps of all entries were basically apart only a few ms. This resulted in only a few entries being removed in the ValueCachePurge call, causing it to be triggered again quickly.

The absolute runtime of the ValueCachePurge function is very fast, but it has to lock the cache while it is running. This means that other parts of IMatch which run in parallel will be blocked from getting / setting / removing cache entries. And that's something that needs improvement.

I have modified the algorithm to detect such constant fill/purge scenarios and clear the cache completely and quickly.

So far, I could not reproduce the "ValueCachePurge called too often" elsewhere.
Data-driven categories might be able to produce this, but none of my databases showed the behavior you are reporting.
I've also created a filter than checks for values in the LocationCreated tag. Even applying it to the entire database does not call ValueCachePurge.

If you have further details on how to reproduce this, let me know.

Do you actually use the structured tag LocationCreated? This tag is only filled when the file already had location data or after a write-back, when IMatch recombines the individual elements of this structured tag into the XMP struct tag.

[hluxem]

I have modified the algorithm to detect such constant fill/purge scenarios and clear the cache completely and quickly.

That's great, right now I can only wait for a longtime or kill Imatch.

How have you defined this filter, exactly?

I used the variable filter, see attached screenshot. Not sure why I didn't use the value filter, would that be faster?

Which other memory-hungry applications where you running at the time? Something from Adobe?

Looks like the most memory hungry application according to the task manager is Edge. I did have Photo Lab running in the background exporting images. This only happens with this computer. Only a restart of Windows helps once it starts happening. I can't reproduce this behavior.

Do you actually use the structured tag LocationCreated?

The tag  {File.MD.XMP::iptcExt\LocationCreatedLocationName\LocationCreatedLocationName\0} is part of the structured tag I think. It's filled for my CR3 raw files, but when the image is exported with Photo Lab it seems the tag is emptied.

[Mario]

Not sure why I didn't use the value filter, would that be faster?

A lot!

The performance warning in the Variable Filter help topic exists for a reason.

The Value filter can optimize this into one database access. The Variable filter must parse the variable for each file in the scope, make one database access for each file, consolidate the results over all files to produce the filter result. Very expensive, 
performance-wise. I recommend to switch to the Value filter.

Variables Filters are problem solvers. Very powerful, but comparatively slow.
Use them only when there is no other way.

Evaluating a variable for each file in a scope may call the purge quite often, if there are more than 2,000 files in the scope.
I see no calls for a scope with 500 files, and you said your scope was only 350. One purge call, perhaps. But not that many.

When I switch to a scope with 50,000 files, the purge operation is called quite often, every 2000 variables processed.
This is now substantially faster.