Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[mob][Photos] CreationDate gets (randomly?) changed when downloading remote photo/video #4296

Open
simondubrulle opened this issue Dec 3, 2024 · 6 comments · May be fixed by #4369
Open
Labels

Comments

@simondubrulle
Copy link
Contributor

Description

It is now the second time in only a few trials that this behaviour occurs.

Whenever I download remote files that are in my timeline (and not from a public shared album) but not yet on my device, the files get propely downloaded in the "Pictures" folder (assets are created) but some of the tiles will (likely) move to the top of the timeline in the "today" section. Looking at the photos info, the creation time is now today (at the time of the download). If I check the web app, it will also appear in the "today" section, like if it has been changed in the DB as well.

Steps to reproduce :

  1. Delete application cache (to make sure the remote files are not cached somewhere)
  2. From the timeline, or from an album view, Multi select files which you know are not yet on your device (and let's assume photos were taken in 2019)
  3. Click "Download" from the selection tab and let it download them all
  4. Some of them will "likely" have their creation time changed to today, at the time you clicked the download button
  5. You will therefore find some of these downloaded photos in "today" section of the album/timeline.

Expected behaviour :
Since Ente was already "aware" of the correct date, it should not change it when I download the photo locally.

Extra info :
I also noticed that in the "Pictures" album (which is not selected for backup), some of the downloaded photos will have the proper creation date assigned (in 2019, for example) but most of them will be in the "Today" section as well. At first I thought it was only pictures with no EXIF data but I can find some with Exif data as well. Actually, some photos from the same moment (few seconds apart) with both Exif data, same filename structure, do have both behaviour (one is in the "today" section, and the other one in the right day in 2019).

I was downloading +- 130 photos.

It also occured for videos.

I tried to have a look at the code, but apparently all it does is downloading the asset and update the file local_id with the one from the asset:

if (savedAsset != null) {
file.localID = savedAsset.id;
await FilesDB.instance.insert(file);
Bus.instance.fire(
LocalPhotosUpdatedEvent(
[file],
source: "download",
),
);

I am not sure of how the sync process is handling those events but it might be that some events are not processed properly.

Version

v0.9.65

What product are you using?

Ente Photos

What platform are you using?

Mobile - Android

@ua741
Copy link
Member

ua741 commented Dec 4, 2024

Can you confirm if the original file has exif date?
Usually, when exif date is not present, we try to derive the date from file name or fallback to creation time given by the system.

@simondubrulle
Copy link
Contributor Author

The original file does have EXIF date. It was taken from a OnePlus 5T and has following EXIF (date) keys:

  • Image Datetime
  • Thumbnail DateTime
  • EXIF DateTimeOriginal
  • EXIF DateTimeDigitized

I also notice that some (quite a lot) of the files that were selected for download appear with the "not backed up" icon (striked cloud icon) in the "Pictures" folder (and those are the ones which appear in the "Today" section of the Pictures folder, eventhough most of them appear in the right date in the home timeline). Their unique album is "Pictures". As mentionned, I also find photos with EXIF dates in that section.

The rest of the downloaded photos does not have the "not backed up" icon (striked cloud icon) in the "Pictures" folder and they appear in the right date in the pictures folder (and timeline). Their album is not "pictures" but the one(s) which were already set before downloading. There I find photos with and without EXIF dates.

I will setup a test environment where I can mess a bit with the data to try to replicate, and will use the debug app to check if I can see something in the debug logs.

@simondubrulle
Copy link
Contributor Author

simondubrulle commented Dec 6, 2024

@ua741 I was able to easily replicate the issue (multiple times) in a test environment and I am quite confident I understand what is happening. Let me first explain high level, then I'll show some logs.

  1. When I select one or multiple photos and click on "Download" button, this function gets triggered:

Future<void> downloadToGallery(EnteFile file) async {

Which is downloading/decrypting all assets localy, and evenutally inserting those files in the FilesDB (so far so good) :

if (savedAsset != null) {
file.localID = savedAsset.id;
await FilesDB.instance.insert(file);
Bus.instance.fire(
LocalPhotosUpdatedEvent(
[file],
source: "download",
),
);

  1. The LocalSyncService is/was/will be triggered and sync() function will run:

Future<void> sync() async {

  1. In that function, we retrieve the list of existing Local File IDs:

final existingLocalFileIDs = await _db.getExistingLocalFileIDs(ownerID);

This is simply done by collecting unique localIds in the FilesDB:

Future<Set<String>> getExistingLocalFileIDs(int ownerID) async {
final db = await instance.sqliteAsyncDB;
final rows = await db.getAll(
'SELECT DISTINCT $columnLocalID FROM $filesTable '
'WHERE $columnLocalID IS NOT NULL AND ($columnOwnerID IS NULL OR '
'$columnOwnerID = ?)',
[ownerID],
);
final result = <String>{};
for (final row in rows) {
result.add(row[columnLocalID] as String);
}
return result;
}

  1. Then this same sync() function also triggers _loadAndStoreDiff function which takes as input the previous existingLocalFileIDs
    await _loadAndStoreDiff(

This is starting by getting the list of all local assets using getLocalPathAssetsAndFiles

Future<void> _loadAndStoreDiff(
Set<String> existingLocalDs, {
required int fromTime,
required int toTime,
}) async {
final Tuple2<List<LocalPathAsset>, List<EnteFile>> result =
await getLocalPathAssetsAndFiles(fromTime, toTime);
final List<EnteFile> files = result.item2;

  1. It will create new entries in the FilesDB for assets which were not yet in the existingLocalFileIDs.

files.removeWhere((file) => existingLocalDs.contains(file.localID));
await _db.insertMultiple(
files,
conflictAlgorithm: SqliteAsyncConflictAlgorithm.ignore,
);

  1. So far, so good, it makes sense to me.

  2. The issue is that, even though the new downloaded file was inserted in the FilesDB in step 1, the existingLocalFileIDs computed in step 3 does not contain the localFileId. This leads to step 5 creating an new entry in FilesDB, this file has almost no information (no collectionID, no uploadedfileid, no hash, ..., only localId and some other info). In other words it is creating a second entry for the same file (even though it was already inserted. before), but that entry has almost no information.

  3. It will not directly appear in the timeline, but if I close/open the app, some sync will make those entries appear in the timeline/gallery.

  4. At some point, this new file entry will be marked for reuploading because hash (null) will not match the one from the asset:

Future<void> _checkAndMarkFilesWithDifferentHashForFileUpdate(

  1. Eventually it will be reuploaded and it should disappear (I am not sure yet if this is removing the entry in step 7). But it is only 10 files at a time, and it can take multiple syncs to reupload all marked files.

  2. Final point is that step 5 should not be triggered for that file, and the corrective actions should not occur in the first place.

Logs

Here is the important part of the logs, with timings, excluding unecessary parts:

I have selected multiple files, and clicked on "download". File is downloaded/decrypted, and finally inserted in FilesDB (step 1) :

12-06 09:01:33.157  2807  2842 I flutter :  [FilesDB] [INFO] [2024-12-06 09:01:33.157519] Inserting File(generatedID: 7171, localID: 1000026607, title: Screenshot_20240124-100457.png, 
12-06 09:01:33.157  2807  2842 I flutter :       type: FileType.image, uploadedFileId: 10000510, modificationTime: 1733318035000000, 
12-06 09:01:33.157  2807  2842 I flutter :       ownerID: 1580559962386438, collectionID: 1580559962386440, updationTime: 1733321482249173)
12-06 09:01:33.157  2807  2842 I flutter :  [FilesDB] [INFO] [2024-12-06 09:01:33.157619] Inserting data simon: [7171, 1000026607, 10000510, 1580559962386438, 1580559962386440, Screenshot_20240124-100457.png, Screenshots (1), 0.0, 0.0, 0, 1733318035000000, JapJdKm2d9NLk2LqYFc92lmMb1EQ2Pyxds1W9UiFz44Ql4oByz8XKctlFpTAdOMg, H6JeMqFRrxL89m6MyD70sMSz2vVwmTMA, S5I3LinVA+uP208Nd/lNmHDqF8aiBAK4, R/+KpiaxMbBJWGoUsfscpvfS8RE4Jn0/, 3aFEtkjWH9aCJxsmy1FLayjAPpaJrmgd, 1706087097000000, 1733321482249173, 0, 0, null, QDz4nkP1nC5K8I/5cp+f8CC1AZQHIoQZG0EWjG+hzCoqpVs9MfF/2/jx29I1L5Zub4lNy9zxXbhIl1vlRD6C3g==, 2, {}, 0, 0, {"h":2400,"w":1080,"mediaType":0}, 1, 150610, 1733309142909927]

Then step 2 and 3 will be triggered and will compute the list of existing local file ids (which I display). This list does not contain the above local file id 1000026607:

12-06 09:01:33.250  2807  2842 I flutter :  [LocalSyncService] [INFO] [2024-12-06 09:01:33.250052] 7406 localIDs were discovered
12-06 09:01:33.250  2807  2842 I flutter :  [LocalSyncService] [INFO] [2024-12-06 09:01:33.250552] SIMON - existingLocalFileIDs: {1000000021, 1000000022, 1000000024, 1000000025, 1000000026, 1000000027, 1000000028, 1000000029, 1000000030, 1000000031, 1000000032, 1000000033, 1000000034, 1000000035, 1000000036, 1000000037, 1000000038, 1000000039, 1000000040, 1000000041, 1000000042, 1000000043, 1000000044, 1000000045, 1000000046, 1000000047, 1000000048, 1000000049, 1000000050, 1000000051, 1000000053, 1000000054, 1000000055, 1000000056, 1000000057, 1000000058, 1000000059, 1000000061, 1000000062, 1000000063, 1000000064, 1000000065, 1000000066, 1000000067, 1000000068, 1000000069, 1000000070, 1000000071, 1000000072, 1000000073, 1000000074, 1000000075, 1000000076, 1000000077, 1000000078, 1000000079, 1000000080, 1000000081, 1000000082, 10000
12-06 09:01:33.250  2807  2842 I flutter : 00083, 1000000084, 1000000085, 1000000086, .........., 1000026603, 1000026604]

It is then considered as a new file according to step 5 and it will get inserted (along with other "new" files, in a batch) in the FilesDB (with new generatedId, and almost no information, no hash as mentioned, etc). I am printing the query "values" :

12-06 09:01:35.618  2807  2842 I flutter :  [FilesDB] [INFO] [2024-12-06 09:01:35.618708] SIMON _insertBatch #: [[1000026613, -1, null, -1, Screenshot_20240206-221408.png, Pictures, null, null, 0, 1733472093000000, null, null, null, null, null, 1733472093000000, null, 0, 0, null, null, 2, {}, 0, 0, {}, 0, null, 1733472095617102], [1000026612, -1, null, -1, Screenshot_20230808-153020.png, Pictures, null, null, 0, 1733472093000000, null, null, null, null, null, 1691501420000000, null, 0, 0, null, null, 2, {}, 0, 0, {}, 0, null, 1733472095617696], [1000026611, -1, null, -1, Screenshot_20240907-121455.png, Pictures, null, null, 0, 1733472093000000, null, null, null, null, null, 1725704095000000, null, 0, 0, null, null, 2, {}, 0, 0, {}, 0, null, 1733472095617765], [1000026610, -1, null, -1, Screenshot_20240202-164020.png, Pictures, null
12-06 09:01:35.618  2807  2842 I flutter : , null, 0, 1733472093000000, null, null, null, null, null, 1706888420000000, null, 0, 0, null, null, 2, {}, 0, 0, {}, 0, null, 1733472095617908], [1000026609, -1, null, -1, Screenshot_20240305-141302.png, Pictures, null, null, 0, 1733472093000000, null, null, null, null, null, 1709644382000000, null, 0, 0, null, null, 2, {}, 0, 0, {}, 0, null, 1733472095617968], [1000026608, -1, null, -1, Screenshot_20240814-182250.png, Pictures, null, null, 0, 1733472093000000, null, null, null, null, null, 1723652570000000, null, 0, 0, null, null, 2, {}, 0, 0, {}, 0, null, 1733472095618025], [1000026607, -1, null, -1, Screenshot_20240124-100457.png, Pictures, null, null, 0, 1733472093000000, null, null, null, null, null, 1706087097000000, null, 0, 0, null, null, 2, {}, 0, 0, {}, 0, null, 1733472095618087
12-06 09:01:35.618  2807  2842 I flutter : ], [1000026606, -1, null, -1, Screenshot_20230816-191508.png, Pictures, null, null, 0, 1733472092000000, null, null, null, null, null, 1692206108000000, null, 0, 0, null, null, 2, {}, 0, 0, {}, 0, null, 1733472095618148], [1000026605, -1, null, -1, Screenshot_20240927-113012.png, Pictures, null, null, 0, 1733472092000000, null, null, null, null, null, 1727429412000000, null, 0, 0, null, null, 2, {}, 0, 0, {}, 0, null, 1733472095618209]]

As mentioned in step 9, the file gets flag (it has another generatedId 8274) :

12-06 09:10:30.148 11291 11322 I flutter :  [LocalFileUpdateService] [INFO] [2024-12-06 09:10:30.148701] Marking for file update as hash did not match local_1000026607:remote_null:generated_8274

Corrective actions will eventually occur but I would say it is already way after the issue I want to point.

I am not sure why it does not show in the existing local file ids, it should already be in the table, even though it was only some ms before.

My guess is that the download process is running concurrently to the sync process, and the insertion of the file in step 1 actually ended (or was commited) after computation of the list in step 3.

The issue is that according to the DB it is not there, but looking at the assets, it is already there and it gets "flagged" as a new file.

What I can tell is that I can replicate the issue every time I try to download lots of photos.

I hope this helps.

@simondubrulle
Copy link
Contributor Author

@ua741 Is PhotoManager shared globally?

Because I see the comment in here which is linked to the issue :

//Disabling notifications for assets changing to insert the file into
//files db before triggering a sync.
await PhotoManager.stopChangeNotify();
if (type == FileType.image) {
savedAsset = await PhotoManager.editor
.saveImageWithPath(fileToSave!.path, title: file.title!);
} else if (type == FileType.video) {

And what I see, with extra log info, is that it gets stopped by one file, then directly started by another file (that finished its downloading) while the first has not yet finished its part that should not trigger a sync.

Can this be linked?

@ua741
Copy link
Member

ua741 commented Dec 6, 2024

@simondubrulle Thank you taking time, and digging through this complex maze ;).

From initial look at your comment, and from whatever I can recall, your analysis is correct.

PhotoManager shared globally?

Yes. We can may be put startChangeNotify inside a debouncer. That won't fully solve the issue, but should significantly reduce the chances. It's not the perfect solution here, but looks good enough to me. In my head, any other solution will be a much bigger change.

PS: In the future, we do plan to completely separate the local files & remote files. That would simplify many things, and help us avoid such bugs.

@simondubrulle
Copy link
Contributor Author

Thank you for the feedback . I think it is a great suggestion, it should already reduce significantly the likelihood of such events while not introducing big changes 😊

@simondubrulle simondubrulle linked a pull request Dec 10, 2024 that will close this issue
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants