Bug: Online date being changed in download-only mode #2591
Comments
|
|
|
It would be interesting to track back what happenend when the file was actually downloaded. When the file was written to disk, the online timestamp data should have been used to reset timestamp of the newly written file. Either that didnt happen - or it did ... and something else modified the file locally post download. Are you using any file indexing tooling? Some linux indexing tooling (search issues) will modify the file / timestamp to indicate it has been indexed .... which is 100% the wrong way to do that. Need to rule out this is not the cause. |
|
@robertschulze Creation of file online
So this is when the file was created online | uploaded for the first time. Online Filesystem Info
The Last Modification Info
This date differs to the filesystem info by approx +1.2 seconds The application, for consistency, will always use the So when this is compared, the application does the following: So this is working correctly. However, if you are using So that in itself is a bug (the code is not looking for When a file is downloaded, a function called setTimes() uses the JSON data and sets the local file time to that Do you have any log that shows the very initial download of the file to your system? I agree that there is a bug - the correction of the data online in a |
|
@robertschulze Whilst I have not been able to reproduce this (as I do not use any GUI or file indexing) - please can you use this version to validate the fix. The why still needs to be understood as well - as if you are not making changes to a file locally, and using |
|
@abraunegg I don't know fully sure how the modified file date (it is two years, not just seconds) came about. I am not using any such Indexing software and since onedrive 2.5 I am using no GUI either. However, I recall noticing wrong file dates after synchronization with a prior version of onedrive (not sure whether <2.5 or 2.5-alpha-X), so my guess would be that at some point when downloading the files, the time of the download was used instead of the time stored in OneDrive Online. |
|
@robertschulze Older versions of the client, especially the Ubuntu Universe packages have all sorts of bugs that have been fixed. I have double checked the v2.5.x code and setTimes() is used post file download - so unless something else is going on it is difficult to pinpoint a cause. What client version were you using around that timeframe? |
|
I think it happened with either alpha-3 or already alpha-4, because I posted the following log with alpha-4 cf. the log [here] (#2562 (comment)) where the wrong file date was freshly in place. |
Whilst this was 'setting' the online date (as per this bug) to something incorrect - the file was already potentially present on your local filesystem - so the bad time change is not occurring here for the first time ... and it is still unknown what set that date. What is interesting is that there appears to be a double DB write as well - one with the corrected date data, but also one for the original comparison ... that should not be happening either: This will need some thought on how to handle this to avoid writing 2 different DB records for the same item, but with different data. |
|
Please can you rebuild your client to I have corrected the double DB writes, and ensured that in a If you can help validate this against your current issue that would be greatly appreciated. |
Yes, that's what I meant. In the given log (which is from alpha-4) the offline date was already wrong, so the creation of the wrong offline date must have happened before. Unfortunately I cannot recall whether I did a prior run with alpha-4 but for sure one with alpha-3. Since either of the two would have changed the online date due to the I have recompiled to in fact the message also appears for all other files (i.e. ones which I did not change) I then changed to date of instead there is a different section taking care of this now: So far so good, but I noticed that there are many cases like The thing is: the files actually have to correct file date, so the determined modified time
I guess the wrong determination of the local file data could have been the vector for the modified online dates. |
|
@robertschulze
RE Point 1: A safe backup should be occurring - as an atomic operation is used to ensure that the target file (the copy) is missing. I would be looking to ensure you have no filesystem issues going on here. When my system creates a backup, this is correctly created: Filesystem: RE Point 2: The 'localModifiedTime' is taken again from the underlying filesystem. When viewing the files in a CLI, use stat I would suspect that your file has a modify time of I would perform a filesystem integrity check, ensure that you do not have a background running process of 'onedrive' lurking around or something else going on. Post the |
|
@robertschulze The time comparison here is the same - so in reality, there should be no further action. This has been fixed in |
|
Your hunch appears to be correct. Cleaning up and performing a new resync If I understood correctly, for you all the dates are equal. The only reason I can think of is that the drive I am storing the backup on is mounted via Windows Filesharing (Samda/CIFS) |
|
@robertschulze Samba | SMB Mounted DirectorySamba Mount Files before run Application Run: File post run with corrected timestamp NFS Mounted DirectoryNFS Mount Files before run Application Run: File post run with corrected timestamp In both instances, the application is resetting the file modified time to If you still think you have an issue, then I would be looking at your Samba and/or Ubuntu platform for time sync issues and ensure that all your platforms are reporting the correct time. It must also be noted that you are also specifying to use version 2.1 of the SMB protocol for the connection for your SMB mount. You should be using something higher for this connection. I cannot find or see any further problem here with the 'onedrive' application. |
|
@robertschulze |
|
Strange, even with samba 3.1.1 I get the same result: Host platform for the Samba share is a Windows Server 2019, so actually nothing exotic. How is onedrive setting the file Change date? Maybe I can reproduce a minimal example outside of onedrive to debug the issue more efficiently. Although setting this attribute appears to be quite difficult, cf. here or here. So not sure whether Modify date would be the better attribute. |
|
@abraunegg I upgraded to -45 but now all my local files synced by a first Also, looking at the output of a is not in the stat dates (even when shifted +1h) nor does it appear further up the logfile |
|
@robertschulze You need to convert
The application does not use The client, when performing any timestamp comparison is only looking at the
If you were running this client version your output would also be different - as the log output specifies that the comparison timestamps are in UTC ... so you are not running that client version in your debug logs. Consider this 'newfile.txt' that I just created locally: The The initial upload JSON to OneDrive, as responded by the API The critical filesystem info aspects:
The The Now, if I delete 'newfile.txt' locally, the only reference of this file exists online. If I now run When The 'birth' and 'change' of the file is from the local filesystem as to when the file was created on the local filesystem. The 'modify' item (the one we care about) matches the 'fileSystemInfo' lastModifiedDateTime value. If I If I run the command and the relevant debug log lines (redoing the touch as well): This proves the 'modify' timestamp of the file in question is being updated to the correct value from online data.
I do not see this in your log output, nor can I replicate this ... please double check what is going on as I suspect you are being caught up with something else going on a the same time. |
and and the log file claims What could I have done wrong? Maybe it's the wrong PR? |
|
@robertschulze Maybe you have an installed older version somewhere and did not use the PR version? |
|
@abraunegg Just to be sure, I sent two log files via wetransfer, maybe this helps to clarify? Edited: I just also deleted my locally installed onedrive from Ubuntu and re-executed the steps, however, the behaviour stays the same and log files are identical up to crypto and (run)time strings. |
In your second logfile there is this entry: This means you must be setting This is why files are being deleted: So for all intents and purposes - at this stage, the application is operating 100% correct based on your application configuration .. however as the 'file' is technically in a shared folder, it should be also 'found', but the logs are indicating otherwise. I will run some further testing tomorrow, to ensure some other logic is correct surrounding this. However, as this issue is now 100% different from your original problem, I am closing this issue (dates being changed online) as it is resolved. |
|
This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs. |
Describe the bug
Hello again,
there may be another problem: I am running onedrive with in download-only mode but online OneDrive dates are being modified, e.g. cf. below
The original file date was something from 2007. So not sure what happened in the first place that the local file date was set to 2024-Jan-14 22:17:47Z but in any case in download-only mode the updated file date should not be uploaded, shouldn't it?
Thanks,
Robert
Operating System Details
Linux atom 5.15.0-91-generic #101-Ubuntu SMP Tue Nov 14 13:30:08 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux No LSB modules are available. Distributor ID: Ubuntu Description: Ubuntu 22.04.3 LTS Release: 22.04 Codename: jammyClient Installation Method
From Source
OneDrive Account Type
Personal
What is your OneDrive Application Version
v2.5.0-alpha-5 GitHub version: v2.4.25-34-ga5be48d
What is your OneDrive Application Configuration
What is your 'curl' version
Where is your 'sync_dir' located
Local
What are all your system 'mount points'
//hyperv/3 on /media/3 type cifs (rw,relatime,vers=2.1,cache=strict,username=Administrator,uid=1000,noforceuid,gid=100,noforcegid,addr=192.168.3.11,file_mode=0777,dir_mode=0777,soft,nounix,serverino,mapposix,rsize=1048576,wsize=1048576,bsize=1048576,echo_interval=60,actimeo=1,closetimeo=1)What are all your local file system partition types
How do you use 'onedrive'
./onedrive --confdir='/home/robert/.config/onedrive/accounts/robert@guitaronline.de' --synchronize --verbose --verbose --resync > debug_output.log 2>&1Steps to reproduce the behaviour
run from console as above
Complete Verbose Log Output
DEBUG: ------------------------------------------------------------------ DEBUG: Processing OneDrive JSON item 6 of 83 as part of JSON Item Batch 1 of 1 DEBUG: Raw JSON OneDrive Item: {"@microsoft.graph.downloadUrl":"https:\/\/public.dm.files.1drv.com\/y4momfUOb2DmzAKUI6gNus-csUf9jXZ3rvW1Q6XFFdLJRRzQb-Zg6_2rgdPV9klxhoWaaEgks2LZS8l69_Z9XaPYwzWU6qcYV30JFQc2uYb4GXHu69AQkwDOtc9YNoReSbuXDcGm3GUTfZD5twaOBRgJDaobhVYrAZ8XJNO7KCojkoF2stlqEfsQYdauDNLbB9ykGjau-gTdDW9KkWKknK6Qk4s9jDF21sAaW6eum8H5B05Hf7pIvrQ2NE5JVfGC5wRl6EKKd83sZ08py-VZ-aq4g","cTag":"aYzpGMzAyOEJENzU4NTUyRkFGITY4Mi4yNTc","createdBy":{"application":{"displayName":"MSOffice15","id":"480728c5"},"device":{"id":"188006267c0904"},"oneDriveSync":{"@odata.type":"#microsoft.graph.identity","id":"0cf2e7c6-beb9-4dd9-aab2-ffff3a010000"},"user":{"displayName":"Robert Schulze","id":"9ba6f07668ba1ff7"}},"createdDateTime":"2022-11-13T22:54:06.153Z","eTag":"aRjMwMjhCRDc1ODU1MkZBRiE2ODIuMzc","file":{"hashes":{"quickXorHash":"6VgxIHZd1xZDn1OQ9yXABPCh2z8=","sha1Hash":"5383CEEF4DC78D6A340F7A331B8E8E77F36BA0AC","sha256Hash":"D85C5D6659E36D910D85F1C02E2764BA03A72C8600DD1BB38242F4ADBBE2FEC3"},"mimeType":"application\/octet-stream"},"fileSystemInfo":{"createdDateTime":"2022-11-13T22:54:06.153Z","lastModifiedDateTime":"2024-01-14T21:28:12Z"},"id":"F3028BD758552FAF!682","lastModifiedBy":{"application":{"displayName":"OneDrive Client for Linux","id":"4035b959"},"user":{"displayName":"Robert Schulze","id":"9ba6f07668ba1ff7"}},"lastModifiedDateTime":"2024-01-14T21:28:13.233Z","name":"dsc00018.cpg","parentReference":{"driveId":"f3028bd758552faf","driveType":"personal","id":"F3028BD758552FAF!574","name":"thumb","path":"\/drives\/f3028bd758552faf\/items\/F3028BD758552FAF!4690:\/Datenbanken\/Memory%20Stick%20altes%20Handy\/DCIM\/100MSDCF\/thumb"},"reactions":{"commentCount":0},"shared":{"owner":{"user":{"displayName":"Constanze Schulze","id":"f3028bd758552faf"}},"scope":"users"},"size":3088,"webUrl":"https:\/\/1drv.ms\/u\/s!AK8vVVjXiwLzhSo"} DEBUG: Attempting to calculate local filesystem path for f3028bd758552faf and F3028BD758552FAF!574 DEBUG: New Item calculated full path is: OneDrive - Constanze/Datenbanken/Memory Stick altes Handy/DCIM/100MSDCF/thumb/dsc00018.cpg DEBUG: The item we are syncing is a file DEBUG: skip_file item to check: /OneDrive - Constanze/Datenbanken/Memory Stick altes Handy/DCIM/100MSDCF/thumb/dsc00018.cpg DEBUG: skip_file evaluation for: /OneDrive - Constanze/Datenbanken/Memory Stick altes Handy/DCIM/100MSDCF/thumb/dsc00018.cpg DEBUG: Result: false DEBUG: sync_list item to check: OneDrive - Constanze/Datenbanken/Memory Stick altes Handy/DCIM/100MSDCF/thumb/dsc00018.cpg DEBUG: Evaluation against 'sync_list' for this path: OneDrive - Constanze/Datenbanken/Memory Stick altes Handy/DCIM/100MSDCF/thumb/dsc00018.cpg DEBUG: [S]exclude = false DEBUG: [S]exludeDirectMatch = false DEBUG: [S]excludeMatched = false DEBUG: Evaluation against 'sync_list' entry: OneDrive-Constanze/Datenbanken/* DEBUG: Evaluation against 'sync_list' entry: OneDrive - Constanze/Datenbanken/* DEBUG: Evaluation against 'sync_list' result: wildcard pattern match DEBUG: Evaluation against 'sync_list' entry: Datenbanken/* DEBUG: Evaluation against 'sync_list' result: wildcard pattern match DEBUG: [F]exclude = false DEBUG: [F]exludeDirectMatch = false DEBUG: [F]excludeMatched = false DEBUG: Evaluation against 'sync_list' final result: included for sync DEBUG: Flagging object as a file DEBUG: OneDrive change is potentially a new local item DEBUG: Local item time discrepancy detected: OneDrive - Constanze/Datenbanken/Memory Stick altes Handy/DCIM/100MSDCF/thumb/dsc00018.cpg DEBUG: This local item has a different modified time 2024-Jan-14 22:17:47Z when compared to remote modified time 2024-Jan-14 21:28:12Z DEBUG: Local item has the same hash value as the item online - correcting timestamp DEBUG: The source of the incorrect timestamp was OneDrive online - correcting timestamp online DEBUG: Read token from appConfig DEBUG: Authorised State: true DEBUG: Existing Microsoft OneDrive Access Token Expires: 2024-Jan-15 00:17:37.6221615 DEBUG: No valid Microsoft OneDrive webhook subscription to delete DEBUG: saveItem - creating DB item from this JSON: {"@microsoft.graph.downloadUrl":"https:\/\/xqxz3a.DM.files.1drv.com\/y4pHzbCBD-iHFYMGShnQAEqsg-oiVwj6igq3PMkfDHXfQAVw1z0Bzz9x77RxzAb0_TRXiPcDIs0gYCHuxroZPMwIu9hghw5_QARY8118oUtvi1eMm-k2W-0c8P0r1iqSjNCK05T7rb2m3bv5I7AHWi6P1jy5DFWhwu-TdWF_xwXdtTlWlYOM_S_fCq2ez7-VcBR2x8y2nx8eHjdYBVY6-OcrBIELZOtuD5Kq2Rm5LywvEF7cBF4MAojKODEdoBTYfw0","@odata.context":"https:\/\/graph.m  icrosoft.com\/v1.0\/$metadata#drives('f3028bd758552faf')\/items\/$entity","cTag":"aYzpGMzAyOEJENzU4NTUyRkFGITY4Mi4yNTc","createdBy":{"application":{"displayName":"MSOffice15","id":"480728c5"},"device":{"id":"188006267c0904"},"oneDriveSync":{"@odata.type":"#microsoft.graph.identity","id":"0cf2e7c6-beb9-4dd9-aab2-ffff3a010000"},"user":{"displayName":"Robert Schulze","id":"9ba6f07668ba1ff7"}},"createdDateTime":"2022-11-13T22:54:06.153Z","eTag":"aRjMwMjhCRDc1ODU1MkZBRiE2ODIuMzg","file":{"hashes":{"quickXorHash":"6VgxIHZd1xZDn1OQ9yXABPCh2z8=","sha1Hash":"5383CEEF4DC78D6A340F7A331B8E8E77F36BA0AC","sha256Hash":"D85C5D6659E36D910D85F1C02E2764BA03A72C8600DD1BB38242F4ADBBE2FEC3"},"mimeType":"application\/octet-stream"},"fileSystemInfo":{"createdDateTime":"2022-11-13T22:54:06.153Z","lastModifiedDateTime":"2024-01-14T22:17:47Z"},"id":"F3028BD758552FAF!682","lastModifiedBy":{"application":{"displayName":"OneDrive Client for Linux","id":"4035b959"},"user":{"displayName":"Robert Schulze","id":"9ba6f07668ba1ff7"}},"lastModifiedDateTime":"2024-01-14T22:17:47.38Z","name":"dsc00018.cpg","parentReference":{"driveId":"f3028bd758552faf","driveType":"personal","id":"F3028BD758552FAF!574","name":"thumb","path":"\/drives\/f3028bd758552faf\/items\/F3028BD758552FAF!4690:\/Datenbanken\/Memory%20Stick%20altes%20Handy\/DCIM\/100MSDCF\/thumb"},"reactions":{"commentCount":0},"shared":{"owner":{"user":{"displayName":"Constanze Schulze","id":"f3028bd758552faf"}},"scope":"users"},"size":3088,"webUrl":"https:\/\/1drv.ms\/u\/s!AK8vVVjXiwLzhSo"} DEBUG: Flagging object as a file DEBUG: Adding to database: Item("f3028bd758552faf", "F3028BD758552FAF!682", "dsc00018.cpg", "", file, "aRjMwMjhCRDc1ODU1MkZBRiE2ODIuMzg", "aYzpGMzAyOEJENzU4NTUyRkFGITY4Mi4yNTc", 2024-Jan-14 22:17:47Z, "F3028BD758552FAF!574", "6VgxIHZd1xZDn1OQ9yXABPCh2z8=", "", "", "", "Y", "3088") DEBUG: The item to sync is already present on the local filesystem and is in-sync with what is reported online DEBUG: Update/Insert local database with item details: Item("f3028bd758552faf", "F3028BD758552FAF!682", "dsc00018.cpg", "", file, "aRjMwMjhCRDc1ODU1MkZBRiE2ODIuMzc", "aYzpGMzAyOEJENzU4NTUyRkFGITY4Mi4yNTc", 2024-Jan-14 21:28:12Z, "F3028BD758552FAF!574", "6VgxIHZd1xZDn1OQ9yXABPCh2z8=", "", "", "", "Y", "3088") DEBUG: ------------------------------------------------------------------Screenshots
Other Log Information or Details
No response
Additional context
No response
The text was updated successfully, but these errors were encountered: