Propagate data to versions is really slow

[Thomas]

Propagate data to versions (from .orf to .jpg, Categories, Attributes, Bookmarks, Flag, Dot, Pins, Rating, Label, File Protection, XMP Title, XMP Description, XMP Author, XMP Location, EXIF GPS Data) takes 3 minutes for about 200 images on an I7 (16 cores), 16GB RAM, images and database on fast SSD harddisks.

During the data propagation, processor load does not exceed 10% (looks like only 2 cores are used at all), same for file I/O.

The same often (but not always) applies to the subsequent reading of the metadata (number of processes for EXIF tool set to default 0). Although processor load is really low too, IMatch feels like frozen, you can't really work while metadata is read.

Is there any chance to speed this up? Any settings to change?

The logfile attached contains two examples (the first one with normal logging, second with debug logging, starts at 21:16). At the first time, metadata read was slow as described above. In the second example, it was quite fast, although I didn't change anything (except activate debug logging).

Version: IMatch 2020.14.2

[Mario]

The database performs poorly for such a fast system with SSD storage and only 120K files.
Have you configured the database folder as an exception in your virus checker? In 90% of all "IMatch is slow" cases, the virus checker constantly scanning the database is the cause.

That the CPU usage is low during ingest and write back is normal. This is an almost 100% disk I/O bound process.

Is F: really a SSD? ExifTool takes 2-3 seconds to import metadata for 5 files, which is rather on the slowish side.
The write-back times reported are about 0.2 to 0.3 seconds per fíle, which is OK.

I see several temporarily blocked or unusually slow database operations. This may slow down every operation.
A typical sign for a virus checker or similar security software slowing down IMatch's disk access considerably.
See IMPORTANT: Virus Checkers for more info.

[Thomas]

Hello Mario,

thanks for your quick response.

I'm using Windows Defender as virus checker. The database folder is excluded.

Both disks are SSDs (but C is much faster). I checked the speed with winsat disk -seq -read -drive x and winsat disk -seq -write -drive x: Here the results:

c:
Disk  Sequential 64.0 Read                   1288.38 MB/s
Disk  Sequential 64.0 Write                  1533.99 MB/s

f:
Disk  Sequential 64.0 Read                   443.30 MB/s
Disk  Sequential 64.0 Write                  411.00 MB/s


I did the following tests (see imatch_log20210307).

Copied a folder with 200 images (100x .orf, 100x .jpg) outside IMatch and imported the folder into IMatch. The .orf-Files already had a rating, the .jpg-Files not.

Then I selected all .orf-Files and hit Commands → Relations → Propagate data to versions. Start time: 20:43

This took about 4 min., the following reading of metadata about 10s.

I started the propagation a second time. Now it took 26s.

Then I did exactly the same with a folder on drive C: which is much faster, see above (same content). But the results are almost the same. Start time: 20:52

So I don't think this has anything to do with the disk speed.

In both cases during propagation task manager shows a CPU load < 10% and disk i/o (on c: as well as f:) < 3%.

An now the really strange thing: I did the same tests a few days ago. Propagation times were almost the same. But the metadata reading during the second test took several minutes for both drive f: and drive c:. During this reading process (that runs in background) IMatch was like frozen. It took up to 20s until IMatch even reacted on a mouse click. Examples see in imatch_log20210303. Unfortunately I can't reproduce this behaviour right now.

What do you mean with "I see several temporarily blocked or unusually slow database operations."

Who can block database operations except maybe the virus checker?

Thanks in advance for your help.

Thomas

[Mario]

I see some warnings about broken External application Favorites. You want to remove them. Search the log for W> to find them. Picasa, PDF Creator etc.

IMatch needs about 3 seconds to extract metadata from 5 files, at about 250 to 300 tags per file.
Propagation is reported as taking between 0.2s to 1.5s per file.

Propagation is quite slow. Show us all your propagation rules. Anything unusual you do?
You write back 100 ORF files. This causes the ORF file to be written, then the JPEG files to be written, then the ORF and JPEG files to be re-imported.
So, 200 files written, 200 files read. Plus invalidation of all categories and collections in your database. Lots of stuff happening.

[Thomas]

Where can I remove these external application favorites? None of the mentioned applications was installed on this computer (but probably on my old one where I used IMatch before).

The logfile refers to C:\Users\thomas\AppData\Roaming\photools.com\IMatch5 *five*. Even this directory does not exist. IMatch uses C:\Users\thomas\AppData\Roaming\photools.com\IMatch6 *six*

Propagation rules for .orf to .jpg (settings in field "What to propagate") are set to:
- Categories
- Attributes
- Bookmarks
- Flag
- Dot
- Pins
- Rating
- Label
- File Protection
- XMP Title
- XMP Description
- XMP Author
- XMP Location Data
- EXIF GPS Data

Settings in field "Categories to propagate":
- All

So (at least in my opinion) nothing special.

I understand that there is a lot do do. My point is that according to the Windows Task Manager almost nothing happens. It looks like IMatch is waiting for something most of the time.

You wrote that  "This is an almost 100% disk I/O bound process." But the maximum disk i/o rate I saw during propagation was less than 3%.

And as I wrote, sometime (but not always) the subsequent metadata reading is extremly slow. Attached is another log file where it took more than 8 minutes for the 200 files! No CPU load, no disk i/o load, it looks like nothing happens. But still IMatch reacts only after several seconds.

[Mario]

Just remove the favorites for these applications in the Favorites panel.

IMatch idling at low CPU/disk usually means it is waiting for something, like a Windows file system call. Or it must wait for ExifTool to finish whatever ExifTool is doing.
But IMatch monitors ExifTool's disk and CPU usage to detect a crashed or hanging instance - but no corresponding events are logged.
A typical reason for IMatch becoming very slow with anything related to disk activity is the virus checker interfering, stalling or even blocking IMatch.

I don't know how long the process took, but writing 200 files and reading 200 files usually takes only a few seconds. Unless the files are on a NAS, the virus checker is scanning each file on each write/read or similar.
I assume you have not changed the default process control settings for IMatch under Edit > Preferences > Application. IMatch usually writes back in multiple separate processes.
Note also that Windows TaskMan may not attribute CPU cycles or IO to the IMatch process when IMatch is spawning external helper processes.