Downloaded files marked as new - Mk2

I see this subject has appeared before and I have something very similar, but quite repeatable. I first tried RPD some years ago but it didn’t fit my workflow and am now trying again with v0.9.17 so the sqlite databases are still small.
The symptom is that after a successful download, adding even a single extra photo to the SDCard, all photos on the card are reselected for downloading again. Remove that photo and all is fine again after a rescan with nothing selected for download. Add it back and the problem returns.
Examining the downloaded_files.sqlite database it contains the expected data with previous downloads recorded correctly.
However examining the thumbnail_cache.sqlite database will now show a duplicate row for every file on the card but with the new row having a different mtime field value. All other fields are the same. The difference in time is exactly one hour and I suspect may be due to an error in summer time evaluation on the second scan.
A comparison of mtime between two such duplicate rows is shown below:

date -d @1568892080
Thu 19 Sep 12:21:20 BST 2019
and
date -d @1568895680
Thu 19 Sep 13:21:20 BST 2019

I can furnish logs and the databases if it may help.
Steve

Hi @scash and welcome!

Might it be that your camera is set to a different time zone then your computer? Or are you double-booting Linux/Windows? For many years there has been a feud going on wether the computer clock is to be set in GMT or local time :slight_smile:

Have fun!
Claes in Lund, Sweden

Thanks for the welcome!

No I don’t double boot Linux/Windows. I’ve used Linux almost exclusively for over 25 years!

I don’t think this could be a factor as the problem only occurs on the second scan after the successful first download. The only file changing on the source is the additional photo. Remove it and the previously downloaded files are once again shown de-selected.

I’ll browse through the source to see if I can figure out what’s happening. Clearly other people have no such problem but it makes the app unusable for me. If I can’t make any headway I’ll probably abandon the effort and revert to my hotch-potch of scripts cobbled together over the years. Functional but not as pretty.

The problem is certainly related to time zones & daylight savings. It could be a time zone setting in your camera, on your computer, or a bug in Rapid Photo Downloader — but it’s interesting that it does not affect others (or at least, many others).

I suspect the root cause of all of this is that FAT32 timestamps are time zone / DST naive. It’s a real PITA.

Thanks Damon. In the interest of finding out what’s going wrong I’m trying to understand how RPD processes the date stamps on successive passes of the same files. It’s the changed behaviour between successive passes that puzzles me. I’m assuming a different mechanism is in play between the two.

e.g. I’m guessing initially RPD takes a filesystem snapshot of mtime to insert into one of the databases using perhaps stat()? Then on the second scan does it use some cached exif data? If so which exif data?

If I use exiftool to show the FileModifyDate on one file it’s presented as ‘2019:09:19 18:06:10+01:00’ in accordance with the current daylight savings time. ls -al shows the source file as ‘2019:09:19 18:06:10’. Since exiftool gets the FileModifyDate from stat that makes sense.

Is there any documentation showing how the files are processed? I will take a look through the source when I have time but a pointer would help.

Thanks again

All files on cameras and memory cards / SSDs / HDDs are scanned using this code:

https://bazaar.launchpad.net/~dlynch3/rapid/zeromq_pyqt/view/head:/raphodo/scan.py

If you know Python you can make your way through the code to see how it’s handled. See in particular sample_camera_metadata() and sample_non_camera_metadata().

Also if you are downloading from a memory card, try downloading directly from the camera, or vice versa. See what difference it makes.

Replying to myself. There’s something wrong with those two dates I gave. I’ve just invoked a factory reset on the camera, the only one I have with me, and taken another photo. Now the FileModifyDate is rendered as ‘2019:09:24 23:44:36+01:00’ at a local time of 22:44:36. So maybe there IS or at least WAS something wrong with the way the camera was recording dates.
I’m going to repeat the whole exercise again in the light of what appears to be a different behaviour from the camera. I’ll report back if the situation has changed and eat humble pie if the camera reset has fixed things!

1 Like

Well the camera reset was a red herring, as were most of the other avenues I’ve tripped down.

Remember the problem was simply adding another photo to the sdcard caused ALL prior downloaded photos to appear as new including the new one. Also that the thumbnail_cache.sqlite database ended up with duplicate rows for each file.

  • I decided to move all the sdcard photos off to another location leaving it empty but for the containing directory.
  • I deleted both RPD databases and renamed the log file
  • I ran RPD once to create the empty databases, closed it and renamed the logfile
  • I move one of the original photos back to the sdcard and ran RPD
  • As expected a single candidate was displayed selected for download
  • I downloaded it and checked the databases. All data correct and only a single entry in each database
  • I moved the last original file that seemed to cause the problem back to the card and rescanned it
  • Again the correct photo was displayed selected as the sole candidate for download, so I did so
  • Again all databases had the right data and RPD correctly showed the two photos as greyed out and deselected

So I’m completely at a loss to explain the issue which was completely repeatable over the last few days. The tests have all been conducted with the original card and data. Yet now all is fine.

  1. The original logfile does include several repeats of the message “INFO scan.py 1354: Device timezone setting for LUMIX is unknown, because the file modification time and file’s time as recorded in metadata differ for sample file jpeg”. (This for the file P1020999.JPG)
  2. After the RPD cleanup a different message is logged “INFO thumbnaildisplay.py 793: Metadata time differs from file modification time for /media/steve/LUMIX/DCIM/P1020999.JPG (with possibly more to come, but these will not be logged)”. But there’s no log of a scan.py issue for that file.

I’m happy but feel a little unsure of future success. I’ll gradually reintroduce the other photos, wash and repeat. Probably in blocks rather than singly. btw there’s no problem indicated in a card fsck, I might just find a Windows machine to check the card too in case there is some intermittent read problem. But I feel the double recording of metadata in the database was just too repeatable to be an intermittent problem.

So thanks for the help and I’ll repost if I can retrigger the problem.

In a previous post I made a specific troubleshooting suggestion. Did you follow it?

Have you updated the firmware for your camera to the latest version?

Damon, sorry I haven’t been clear. I posted earlier that I have now re-conducted my original RPD tests with all the original ‘problematic’ data from the same card - but this time without problems. I don’t feel that changing camera software at this point can make any difference since I’m using the exact original files that previously gave me a problem. However the camera is using the most recent available.

I think the most likely problem was either some odd corruption in the original RPD database files, or an error when RPD read files from the SDCard. Although these files are the original, they have of course been re-written when placing them back onto the card.

If you were referring to your suggestion of downloading from the camera as a test I can’t do that. I’m travelling at the moment and don’t have the necessary cable with me. In fact further tests at this juncture are probably pointless since I can’t reproduce it!

Thanks again.

It’s extremely unlikely that Rapid Photo Downloader’s sqlite3 database was corrupted. When the program reports “the file modification time and file’s time as recorded in metadata differ for sample file jpeg” that means exactly what it says. You need to figure out why. It could be a problem with your camera’s firmware. It could be a problem with the way your memory card’s file system metadata is being read under Linux — you didn’t mention the memory card’s filesystem, so it’s difficult to know of it is using FAT32 or exfat. If exfat, there might be a problem there with buggy code in the kernel’s exfat driver. It could be a problem with exiv2 or ExifTool, which is unlikely as they’re both pretty robust (it’s hard to know which was used to finally determine the photograph’s metadata, because you didn’t attach the log files). It could be that the camera is including timezone information in its exif data in violation of exif standards, which is throwing off Rapid Photo Downloader. It’s hard to say without a lot more information. The good news is that with the proper steps, diagnosing the problem should not be difficult.

Fair enough.

That’s going to be tough though isn’t it? The issue no longer manifests.

FAT32

However, again - I can no longer reproduce the problem from the same data. The logs from the latest test with the same files no longer report "the file modification time and file’s time as recorded in metadata differ for sample file jpeg”. So unless the problem manifests again with the next few batches of photos, then I’ve got nothing to go on.

All that’s changed is the files were removed and then restored to the card and the RPD databases were first erased. Many thanks again for your valuable input, but at this point I think it’s a waiting game.