Folder out of sync

Started by rolandgifford, February 07, 2025, 10:51:30 AM

Previous topic - Next topic

rolandgifford

I'm getting a lot of instances of folders being flagged as being out of sync even though I have done nothing to the images in those folders.

After updating to 2025 I rescanned every folder (about 200,000 images) as past experience tells me that defaults etc change with releases and it made sense to me to have everything tidy. This took several hours. After that rescan there were some images which were reluctant to write back (usually GPS image direction and distance, always the raw file withing a version set) but I have resolved all those.

What I'm now getting is apparently random flagging of folders to be rescanned. I have turned on debug logging to scan a couple of folders this morning. In the first all images logged as current. In the second several raw files were flagged as having a different date between DB and disk so needed rescanning. An entry along the lines of this snip:

02.07 09:26:34+    0 [F1E0] 10  I>     AddOrUpdate: E:\Selected Photos\Holidays\2011_1215 Ghana\RolandGhana 2011_1217_182628.RW2
02.07 09:26:34+    0 [F1E0] 02  I>     File needs update: db: 04/02/2025 15:42:03, disk: 06/02/2025 21:00:32, diff: 05:18:29

There isn't any mention of any differences found which is fair enough and is the main reason I haven't bothered uploading the log file.

I'm happy to provide logs or anything else which helps.

I'm not running anything other than IMatch on this PC. The second folder I scanned (with logged file differences) is still flagged as needing a rescan.

Why are these date/times different? It is always the raw file in the examples I have seen. It is always the raw file.

I had this issue sometimes with 2023 as well, it isn't a brand new issue with 2025.

rolandgifford

I've had more of a look at the log and every raw file in that folder was updated, none of the JPGs. 174 out of 1230 images

Mario

#2
Did you read release note #2661


IMatch may just have missed many changes you've done over the years while it was not running and folder timestamps were not updated as expected by Windows.

rolandgifford

Quote from: Mario on February 07, 2025, 02:43:05 PMDid you read release note #2661

I did read that (and remember the discussions when the problem was detected/fixed) and it is one of the reasons that I did a rescan of every folder after updating to 2025.

This problem I have now is after having done that. This is the third time since updating that I have had a batch of 'folder needs a rescan' since updating. I just did the rescan the other two times. Both of those found files where the date on disk was different to the date in the database.

Mario

Switch to debug logging and when this happens again, search for the folder names.
The folder scanner only does a deep scan (checking for the newest file in each folder to determine if it needs to be rescanned) when the database is loaded.

Later folder scans, e.g. in response to Windows messages, work as in IMatch 2023.

The deep scan logs additional details, like the difference between the folder "last modified" timestamp and the "last modified" timestamp of the newest file found in the folder.

rolandgifford

I ran in debug mode for this scan. No indication of the 'new method' deep scan for any specific folder

The first folder scan mentioned that there was one folder requiring a deep check but doesn't say which one:

02.07 09:23:05+  563 [044C] 02  I> FolderSweeper: processed 348 folders in 0ms. Deepcheck: 1

After that all of the checks have Deepcheck: 0

The folders themselves are logged as:

02.07 09:22:56+ 2156 [044C] 10  I> FolderSweeper: Folder [51] 'E:\Selected Photos\Holidays\2011_1215 Ghana\' modified.
02.07 09:22:56+  234 [044C] 10  I> FolderSweeper: Folder [64] 'E:\Selected Photos\Holidays\2014_0920 Ecuador\' modified.
02.07 09:22:56+   16 [044C] 10  I> FolderSweeper: Folder [74] 'E:\Selected Photos\Holidays\2016_1225 India\' modified.
02.07 09:22:56+   16 [044C] 10  I> FolderSweeper: Folder [97] 'E:\Selected Photos\Holidays\2019_0222 Berlin\' modified.
02.07 09:22:57+  109 [044C] 10  I> FolderSweeper: Folder [136] 'E:\Selected Photos\Holidays\2022_0916 Argentina\' modified.

I have found a possible issue with a utility I use to mirror the image folders to another PC and will try using SyncToy to do that and see if that makes the problem go away. I remember there being a problem with SyncToy when I last looked at it but can't remember what, it was several years ago. Being every single raw file in a folder and none of the jpgs doesn't make any sense.

I'll rescan the folders which are currently flagged and monitor whether it happens again or not. Please ignore this for now, I'll ask again if I want you to look.

Mario

Deepcheck 1 is the initial deep scan after database loaded.
When the folder sweeper reports "modified", the last modified timestamp of the folder on disk does not match the corresponding timestamp in the database.

If this would be detected DeepSeek 1, IMatch would loc the time delta between the folder and the newest file. Since there is no such log, the folder's "last modified on disk" has changed.

rolandgifford

I think that my mirroring software was changing the activity date on the source files (which I don't want it to do) but I'm not 100% sure. I'm avoiding the time investigating by using different mirroring software which is both current and supported.

I am however left with a slightly different out of sync error so I'm adding a post here rather than a new thread. I can start a new thread if you would prefer.

I had the top level of a folder tree flagged as needing re-scanning. None of the children were flagged. I selected to re-scan (menu/mouse rather than keyboard) which scanned everything and flagged 1791 files (all mp4 files) out of 119798 files as needing updating. After the re-scan 1791 files were marked as Pending Metadata Write-back

Writing back all outstanding left 1665 of those still pending
Writing back again left 15 outstanding
Subsequent write-backs of all outstanding still left these 15 in the queue but selecting them all and writing-back selected cleared them.

After this I turned on debug logging and again re-scanned the top level folder (which wasn't flagged as needing it) and again 1791 files were found and are now pending metadata write-back. I have hovered over the pen icon for several of these and it doesn't tell me what is out of sync.

I have looked at sample files in the log and all of the files say "File is current" but the ones in the write-back queue also say "Cache image outdated or missing".

I would like these mp4 files not to be selected as requiring update by a re-scan and the multiple write-backs of metadata are irritating (and I'm puzzled why they are required at all) as these files have been in sync for quite a while in most cases

Mario

I seem to have lost track of what the questions is?
IMatch rescans a folder. 

It finds files not in the database => new file, add.
It finds files with a newer "last modified" timestamp than recorded in the database => rescan file.
It finds files with the same timestamp as in the database => file is current, no action required.

rolandgifford

Quote from: Mario on February 08, 2025, 09:07:07 PMI seem to have lost track of what the questions is?

My fault

IMatch is supposed to do what you describe on a Rescan, I'm sure it does.

In this case it is doing somethings else as well, badly.

There are no images with different dates - timestamps on disk match the database

What the Rescan is finding are lots of MP4 files where "Cache image outdated or missing" and is treating those as if the dates don't match. Metadata is rescanned (lots of EXIFTOOL activity) but the cache image is presumably not fixed as every rescan of this folder finds the same 1791 MP4 files.

After the rescan these files are flagged for Pending Metadata Write-back

That process is also not working well as the first request to write back all queued files only clears 126 images. The next write back of all queued files apart from 15 and all subsequent requests to write back all queued files don't successfully write back any. Selecting the 15 and writing back selected files does clear them.

Mario

QuoteWhat the Rescan is finding are lots of MP4 files where "Cache image outdated or missing" 
When caching is enabled, IMatch by default creates a cache image when the file is added to the database.
It updates the cache image if the file is rescanned for some reason, or when the cache file is found missing or outdated.

IMatch logs file rescans, if a file is found outdated or current, if a cache file is missing etc.
Recreating a cache file does not involve ExifTool and does not modify metadata.
When IMatch runs ExifTool for a file, it logs that.
When a cache file is created, IMatch logs that. When it fails, IMatch logs that.

I don't have the log file of your IMatch session so I have zero info.
Without having a complete log file from the IMatch session where all this occured, in debug mode when possible, everything is guesswork.

Which tags are shown for the pending files (point the mouse cursor at the write-back icon)?

rolandgifford

Log file attached

This time I ran a slightly different test to reduce the size of the log file. I scanned a single sub-folder which I know contains some problem MP4 files

The scan flagged/updated 678 files

Initial write back of all pending reduced this to 678
The next write back of all pending cleared them all

Hovering over the pen for any image before the first write back showd no pop-up. Even after closing and restarting IMatch. After the first write back hovering showed:
exif\DateTimeOriginal
photoshop\DateCreated
xmp\CreateDate

After all pending metadata had been written back I scanned the folder again and it again found 678 files.

rolandgifford

A smaller log file attached showing all the problems.

I scanned two sub-folders

17 files pending metadata write-back after the scan. Hovering over the pen icon for theses shows nothing, no pop-up at all

Write back all pending reduces this 17 to 6. Hovering over the pen icon shows the three date tags in my previous post

The next write back all pending leaves the 6 in the list

Selecting them all and write back selected clears them

Mario

#13
Multiple write-backs are sometimes need to clean up differences in metadata tags that need synching.
MP4 files add to metadata complexity because some may contain an embedded JPG preview that ExifTool can read (and deliver the metadata to IMatch) but cannot write (attempts of IMatch to write back are (silently) ignored (in part) by ExifTool.

Video metadata mess is even worse than image metadata mess, because there are far less standards and device vendors bother even less than for images. I no longer waste my time with that.

Looking at the log, I see a number of warnings about IMatch being unable to create a cache image for "...2020_1220_100532_Rotated.MP4". Maybe this file is special and FFMeg cannot read it. I suggest to re-encode the file with Handbrake to hopefully fix what's wrong with it. Unless then, IMatch will find a "missing cache file" for this file on every folder rescan.

There are quite a number warnings about invalid timestamps for some MP4 files. Check the files in IMatch and make sure to write a valid Create Date and Date Subject created (set in Metadata Panel, write back). Search your log file for W> to find the filenames.

After fixing these metadata problems, retry again.

No file is found that requires an update. For several of your MP4 files no cache files exist or they are outdated. IMatch schedules these files for a rescan / cache file generation. If IMatch cannot create cache files the file remains in the current state.

Looking at some FFMPEG operations in the log, it seems that IMatch can create the cache files, at least I see no errors or warnings.

rolandgifford

Thanks for these, I will work through them and get back.

The invalid dates refer to ModifyDate which the Metadata panel is showing as 0000:00:00 00:00:00.453 and similar values. Blanking them out in the metadata panel and writing back just restores this value.

How do I get rid of them?

Mario

Which ModifyDate? There are several. Show the tag key always to avoid confusion (right-click the tag header in the MD panel > Copy as Variable). The Modify date is read by ExifTool and updated by ExifTool, not IMatch. Do you files contain embedded JPG previews? Did you follow my advice to re-encode with handbrake to get rid of potentially broken metadata or embedded previews which may irritate ExifTool?

rolandgifford

Quote from: Mario on February 09, 2025, 01:31:57 PMWhich ModifyDate? There are several. Show the tag key always to avoid confusion (right-click the tag header in the MD panel > Copy as Variable). The Modify date is read by ExifTool and updated by ExifTool, not IMatch. Do you files contain embedded JPG previews? Did you follow my advice to re-encode with handbrake to get rid of potentially broken metadata or embedded previews which may irritate ExifTool?

I am reencoding the files where required with Handbrake. Those weren't flagged for update by the rescan (but need fixing nevertheless). Were you suggesting reencoding the ones selected by the rescan as well, I read you to only meant the 'Rotated' ones?

The invalid ModifyDates are different files

The two modifyable fields in the Metadata Browser are:

{File.MD.Composite\MWG-ModifyDate\ModifyDate\0}
{File.MD.Composite\Exif-SubSecModifyDate\SubSecModifyDate\0}

There are three locked 'Sub Sec Time' tags with a value of 453 in the example I quoted

{File.MD.Exif::Main\37520\SubSecTime\0}
{File.MD.Exif::Main\37522\SubSecTimeDigitized\0}
{File.MD.Exif::Main\37521\SubSecTimeOriginal\0}

Mario

Do not update Composite tags. There are made-up on-the-fly by ExifTool from a wide range of sources. Writing Composite tags may do nothing or stuff you don't want.

What is a "locked up" tag?
Do your MP4 files contain an EXIF metadata record (check in ExifTool Command Processor) and where?
As I explained, embedded previews may upset ExifTool. It reads and delivers the info from them to IMatch, but cannot write or update the data. Which results in an infinite cycle. Re-encoding with Handbrake should get rid of the non-standard EXIF data / preview.

rolandgifford

Quote from: Mario on February 09, 2025, 02:02:46 PMWhat is a "locked up" tag?

A tag with a closed padlock next to it in the metadata Panel

I'll do lots of Handbrake re-encoding (including the ones flagged with invalid dates) and get back, it will be a while

Mario

Ah, a non-writable tag. Got it. It's always words ;)

rolandgifford

Much progress and faster than I expected when I decided to re-encode all MP4 files in a folder using Handbrake rather than selecting just the problem ones.

Re-scanning this particular folder reliably adds 20 MP4 files to Metadata write-back. Selecting to write back all outstanding clears these 20 on the first attempt.

I can't see what in the log is marking them as Metadata out of sync.

Mario

Maybe related to https://www.photools.com/community/index.php/topic,14863.0.html ?
Writeback pen tooltips empty?
Do you have XMP face region import enabled? Default is on.

rolandgifford

Quote from: Mario on February 09, 2025, 02:58:07 PMWriteback pen tooltips empty?
Do you have XMP face region import enabled? Default is on.

Yes the pen tooltip is empty (or more accurately there is no tooltip when hovering over the pen)

Import IPTC PersonInImage in Metadata2 is off - or is it set somewhere else?

Mario

Import XMP face regions, same dialog box.

rolandgifford

Quote from: Mario on February 09, 2025, 03:19:00 PMImport XMP face regions, same dialog box.

I couldn't see that. I'll have another look when I get back home

Hopefully off, I don't use face recognition at all

kevintrickey

I don't know if this applies in your case but last night I was messing around with a new folder structure and was seeing behaviour that looks very similar to what you're describing.

In my case I'd pointed IMatch at a folder managed by OneDrive and it looks like OneDrive was touching the files after syncing in some way that made IMatch think they'd changed. Windows explorer was actually showing the last modified date as the sync time rather than the real modified time, so hardly surprising IMatch thought they needed updating.

I moved the files to a non OneDrive folder, the correct last modified times returned and I haven't had IMatch tell me that metadata needs updating for those file since.

Mario

OneDrive does sometimes strange things to files, including modifying them or trimming (some) metadata. We have seen reports here about these issues.

rolandgifford

Quote from: Mario on February 09, 2025, 03:19:00 PMImport XMP face regions, same dialog box.

I still can't see anything called that. Can you do a screen shot please?

Will the fix to the TIF problem in the other thread fix this too?

rolandgifford

Quote from: kevintrickey on February 09, 2025, 04:43:29 PMIn my case I'd pointed IMatch at a folder managed by OneDrive and it looks like OneDrive was touching the files after syncing in some way that made IMatch think they'd changed. Windows explorer was actually showing the last modified date as the sync time rather than the real modified time, so hardly surprising IMatch thought they needed updating.

A similar problem/cause at the beginning but the problem has now moved.

Initially files were being marked as requiring rescan by my mirroring software. I've fixed that by using something different.

Then I'm not sure why images were being being scanned as the log was logging something different. The write back wasn't working correctly either - similar to the behaviour in the TIF file thread. Flagging the files seems to be because the MP4 files have been written in some sort of non-standard way which is fixable by re-encoding with Handbrake. I'm working through that.

I now have one final problem which appears very similar to the TIF problem in the other thread.

Mario

If the files are marked as pending but show no tooltip, run a database diagnosis.
It will fix the ghost write-backs for you and log the issue. If this helps, see release note 2692 in https://www.photools.com/release-notes/

rolandgifford

Quote from: Mario on February 09, 2025, 06:59:30 PMIf the files are marked as pending but show no tooltip, run a database diagnosis.
It will fix the ghost write-backs for you and log the issue. If this helps, see release note 2692 in https://www.photools.com/release-notes/

Thanks. Importing isn't likely to be the problem for me as I expect face areas aren't relevant to MP4 files anyway. I still can't find the setting on the Metadata2 tab

PandDLong

Quote from: Mario on February 09, 2025, 05:13:20 PMOneDrive does sometimes strange things to files, including modifying them or trimming (some) metadata. We have seen reports here about these issues.

I had this experience with OneDrive.  I wasn't using OneDrive for IMatch managed folders, just as a backup/internet accessible copy - so I never spent the time to sort out the when, why and specifics of these OneDrive induced changes. 

However, I did change my backup strategy as I would not want to re-index a large group of files into IMatch from OneDrive as I would not be sure of the metadata quality.

Michael

graham1

The 2025 version is obviously much better at detecting changes. When I first installed the 2025 version, it found about 33,000 images to update (out of a total of 850,000), and about 13,000 which needed a metadata update. Fortunately I had read the release notes and was not unduly surprised by this. I had to leave it almost 24 hours to complete updating, but thereafter it has been fine and feels more snappy and responsive than the 2023 version. It was comforting to see from the resource monitor that all 20 cores were being used.

Graham

Mario

Quote from: graham1 on February 09, 2025, 07:08:10 PMThe 2025 version is obviously much better at detecting changes. When I first installed the 2025 version, it found about 33,000 images to update (out of a total of 850,000), and about 13,000 which needed a metadata update. Fortunately I had read the release notes and was not unduly surprised by this. I had to leave it almost 24 hours to complete updating, but thereafter it has been fine and feels more snappy and responsive than the 2023 version. It was comforting to see from the resource monitor that all 20 cores were being used.

Graham
That's a good result. The "Windows does not necessarily update the folder's "last modified" timestamp when the user modifies a file" was indeed unexpected and probably left many changes go unnoticed over time.

IMatch 2025 resolves this via the initial deep scan, as in your case, and then this is done. Unless you modify files outside of IMatch when it is not running. I will detect this now reliably and rescan the file(s).

Utilizing all processor cores was a key of the redesign. Even notebooks now have 8, 10, 12 or more cores, and utilizing them all so much better makes IMatch really fast :D

rolandgifford

Quote from: Mario on February 09, 2025, 03:19:00 PMImport XMP face regions, same dialog box.

Only if Expert Mode is changed to Yes. Otherwise it isn't shown. I've turned it off as I have no current interest in face recognition.

2025.1.10 appears to have fixed the problem of incorrect flagging of changes of MP4 files when re-scanning. These are the original MP4 files not updated by HandBrake.