OliverL
November 12, 2024, 8:59pm
1
Used rclone sync to upload a local directory to the remote.
Usingrclone sync again copies all files instead of skiping previously copied files.
Used rclone ls over the remote directory to troubleshoot. The directory is seen as empty by rclone but I can see all files from OneDrive web client.
rclone v1.68.1
- os/version: Microsoft Windows 10 Pro 22H2 (64 bit)
- os/kernel: 10.0.19045.5011 (x86_64)
- os/type: windows
- os/arch: amd64
- go/version: go1.23.1
- go/linking: static
- go/tags: cmount
OneDrive
rclone copy /tmp remote:tmp)The sync command
./rclone sync --progress --fast-list --onedrive-chunk-size 65536000 --transfers 20 --checkers 20 --copy-links --log-level INFO --log-file rclone_log.txt "C:\Users\olive\Desktop\Oliver" "OneDriveArchivo:/Compartidas/Japon 2024/Oliver"
The ls command
./rclone ls "OneDriveArchivo:/Compartidas/Japon 2024/Oliver"
[OneDrive]
type = onedrive
client_id = REMOVED
client_secret = REMOVED
token = {"access_token":"REMOVED","expiry":"2024-09-06T17:12:54.52663+02:00"}
drive_id = c7071e38386b99f5
drive_type = personal
[OneDriveArchivo]
type = onedrive
client_id = REMOVED
client_secret = REMOVED
token = {"access_token":"REMOVED","expiry":"2024-11-12T22:37:23.3939036+01:00"}
drive_id = REMOVED
drive_type = personal
-vv flagBeggining of the log of the sync (there are a lot of files there)
2024/11/12 21:57:08 DEBUG : rclone: Version "v1.68.1" starting with parameters ["C:\\Users\\olive\\rclone.exe" "sync" "--progress" "--fast-list" "--onedrive-chunk-size" "65536000" "--transfers" "20" "--checkers" "20" "--copy-links" "-vv" "--log-file" "rclone_log.txt" "C:\\Users\\olive\\Desktop\\Oliver" "OneDriveArchivo:/Compartidas/Japon 2024/Oliver"]
2024/11/12 21:57:09 DEBUG : Creating backend with remote "C:\\Users\\olive\\Desktop\\Oliver"
2024/11/12 21:57:09 DEBUG : Using config file from "C:\\Users\\olive\\AppData\\Roaming\\rclone\\rclone.conf"
2024/11/12 21:57:09 DEBUG : local: detected overridden config - adding "{12rtk}" suffix to name
2024/11/12 21:57:09 DEBUG : fs cache: renaming cache item "C:\\Users\\olive\\Desktop\\Oliver" to be canonical "local{12rtk}://?/C:/Users/olive/Desktop/Oliver"
2024/11/12 21:57:09 DEBUG : Creating backend with remote "OneDriveArchivo:/Compartidas/Japon 2024/Oliver"
2024/11/12 21:57:09 DEBUG : OneDriveArchivo: detected overridden config - adding "{VGGR9}" suffix to name
2024/11/12 21:57:09 DEBUG : fs cache: renaming cache item "OneDriveArchivo:/Compartidas/Japon 2024/Oliver" to be canonical "OneDriveArchivo{VGGR9}:Compartidas/Japon 2024/Oliver"
2024/11/12 21:57:11 DEBUG : 2024-09-18_IMG20240918101217.jpg: Need to transfer - File not found at Destination
2024/11/12 21:57:11 DEBUG : 2024-09-18_IMG20240918135715.jpg: Need to transfer - File not found at Destination
2024/11/12 21:57:11 DEBUG : 2024-09-18_IMG20240918145352.jpg: Need to transfer - File not found at Destination
2024/11/12 21:57:11 DEBUG : 2024-09-18_IMG20240918150932.jpg: Need to transfer - File not found at Destination
2024/11/12 21:57:11 DEBUG : 2024-09-18_IMG20240918164817.jpg: Need to transfer - File not found at Destination
2024/11/12 21:57:11 DEBUG : 2024-09-19_IMG20240919021805.jpg: Need to transfer - File not found at Destination
2024/11/12 21:57:11 DEBUG : 2024-09-19_IMG20240919053808.jpg: Need to transfer - File not found at Destination
2024/11/12 21:57:11 DEBUG : 2024-09-19_IMG20240919054013.jpg: Need to transfer - File not found at Destination
2024/11/12 21:57:11 DEBUG : 2024-09-19_IMG20240919101026.jpg: Need to transfer - File not found at Destination
2024/11/12 21:57:11 DEBUG : 2024-09-19_IMG20240919101208.jpg: Need to transfer - File not found at Destination
2024/11/12 21:57:11 DEBUG : 2024-09-19_IMG20240919101307.jpg: Need to transfer - File not found at Destination
2024/11/12 21:57:11 DEBUG : 2024-09-19_IMG20240919101446.jpg: Need to transfer - File not found at Destination
The log of the ls command
2024/11/12 21:55:24 DEBUG : rclone: Version "v1.68.1" starting with parameters ["C:\\Users\\olive\\rclone.exe" "ls" "-vv" "OneDriveArchivo:/Compartidas/Japon 2024/Oliver"]
2024/11/12 21:55:24 DEBUG : Creating backend with remote "OneDriveArchivo:/Compartidas/Japon 2024/Oliver"
2024/11/12 21:55:24 DEBUG : Using config file from "C:\\Users\\olive\\AppData\\Roaming\\rclone\\rclone.conf"
2024/11/12 21:55:25 DEBUG : fs cache: renaming cache item "OneDriveArchivo:/Compartidas/Japon 2024/Oliver" to be canonical "OneDriveArchivo:Compartidas/Japon 2024/Oliver"
2024/11/12 21:55:25 DEBUG : 4 go routines activ
asdffdsa
November 12, 2024, 9:05pm
2
hi,
perhaps for testing,rclone copy and rclone ls a single file and post complete debug logs, not snippets.
1 Like
Try your sycn with --modify-window 1s flag. It is quite big subject I am not following in depth but here you can start your reading if interested in details:
opened 06:57AM - 22 Sep 24 UTC
closed 11:09AM - 25 Sep 24 UTC
<!--
We understand you are having a problem with rclone; we want to help you … with that!
**STOP and READ**
**YOUR POST WILL BE REMOVED IF IT IS LOW QUALITY**:
Please show the effort you've put into solving the problem and please be specific.
People are volunteering their time to help! Low effort posts are not likely to get good answers!
If you think you might have found a bug, try to replicate it with the latest beta (or stable).
The update instructions are available at https://rclone.org/commands/rclone_selfupdate/
If you can still replicate it or just got a question then please use the rclone forum:
https://forum.rclone.org/
for a quick response instead of filing an issue on this repo.
If nothing else helps, then please fill in the info below which helps us help you.
**DO NOT REDACT** any information except passwords/keys/personal info.
You should use 3 backticks to begin and end your paste to make it readable.
Make sure to include a log obtained with '-vv'.
You can also use '-vv --log-file bug.log' and a service such as https://pastebin.com or https://gist.github.com/
Thank you
The Rclone Developers
-->
#### The associated forum post URL from `https://forum.rclone.org`
https://forum.rclone.org/t/after-upgrade-rclone-sync-wants-to-do-a-full-copy-not-just-of-deltas/47864
https://forum.rclone.org/t/rclone-v1-68-0-release/47643/7
https://forum.rclone.org/t/onedrive-modified-time-tolerance-change/45356/2
#### What is the problem you are having with rclone?
After an upgrade to the latest rclone, an rclone sync to an encrypted OneDrive remote is attempting upload everything again rather than only the deltas. This is going to take six weeks according to rclone's ETA.
The root cause seems to be that the source file has mtime resolution down to milliseconds, but the file on onedrive only has resolution down to seconds. There is then a sub-second mismatch in mtime, causing the file to be reuploaded
I've reduced it to a sync of a single file which copies it again, each time the command is run.
I can do a workaround using `--modify-window 1s` but that surely isn't the proper way to solve this?
#### What is your rclone version (output from `rclone version`)
```
rclone v1.68.0
- os/version: ubuntu 22.04 (64 bit)
- os/kernel: 5.15.0-101-generic (x86_64)
- os/type: linux
- os/arch: amd64
- go/version: go1.23.1
- go/linking: static
- go/tags: none
```
#### Which OS you are using and how many bits (e.g. Windows 7, 64 bit)
Ubuntu 22.04.2 LTS, 64-bit
#### Which cloud storage system are you using? (e.g. Google Drive)
OneDrive (encrypted)
#### The command you were trying to run (e.g. `rclone copy /tmp remote:tmp`)
```
borg@host:/tmp$ rclone -vv sync ~/repos/photos/data/1/1202 onedrive:repos/photos/data/1
```
#### A log from the command with the `-vv` flag (e.g. output from `rclone -vv copy /tmp remote:tmp`)
First run, showing time mismatch and therefore new upload
```
borg@host:/tmp$ rclone -vv sync ~/repos/photos/data/1/1202 onedrive:repos/photos/data/1
2024/09/22 16:48:07 DEBUG : rclone: Version "v1.68.0" starting with parameters ["rclone" "-vv" "sync" "/home/borg/repos/photos/data/1/1202" "onedrive:repos/photos/data/1"]
2024/09/22 16:48:07 DEBUG : Creating backend with remote "/home/borg/repos/photos/data/1/1202"
2024/09/22 16:48:07 DEBUG : Using config file from "/home/borg/.config/rclone/rclone.conf"
2024/09/22 16:48:07 DEBUG : fs cache: adding new entry for parent of "/home/borg/repos/photos/data/1/1202", "/home/borg/repos/photos/data/1"
2024/09/22 16:48:07 DEBUG : Creating backend with remote "onedrive:repos/photos/data/1"
2024/09/22 16:48:07 DEBUG : Creating backend with remote "onedriveunderlying:rclonebackups/qtvah5opb18p4g4ve2i0lh4mio/vptothej6ciusdjpca3agsgj5o/u58r1pkbe9ip1vlcarj5tntqqs/s4s1q07jvge4ij8b60qlddrsf8"
2024/09/22 16:48:10 DEBUG : 1202: Modification times differ by -143.88454ms: 2023-02-17 21:00:17.14388454 +1100 AEDT, 2023-02-17 10:00:17 +0000 UTC
2024/09/22 16:48:10 DEBUG : vknf9rh5le44k0v06gdv2ri0ts: Starting multipart upload
2024/09/22 16:48:10 DEBUG : vknf9rh5le44k0v06gdv2ri0ts: Uploading segment 0/147937 size 147937
2024/09/22 16:48:12 DEBUG : 1202: quickxor = cc7c7a7cd3296c4ce22217158ee76efcbec317c5 OK
2024/09/22 16:48:12 INFO : 1202: Copied (replaced existing)
2024/09/22 16:48:12 INFO :
Transferred: 144.470 KiB / 144.470 KiB, 100%, 112.047 KiB/s, ETA 0s
Transferred: 1 / 1, 100%
Elapsed time: 4.6s
2024/09/22 16:48:12 DEBUG : 9 go routines active
```
Second run showing that even though it was uploaded the first time, it gets reuploaded:
```
borg@host:/tmp$ rclone -vv sync ~/repos/photos/data/1/1202 onedrive:repos/photos/data/1
2024/09/22 16:48:17 DEBUG : rclone: Version "v1.68.0" starting with parameters ["rclone" "-vv" "sync" "/home/borg/repos/photos/data/1/1202" "onedrive:repos/photos/data/1"]
2024/09/22 16:48:17 DEBUG : Creating backend with remote "/home/borg/repos/photos/data/1/1202"
2024/09/22 16:48:17 DEBUG : Using config file from "/home/borg/.config/rclone/rclone.conf"
2024/09/22 16:48:17 DEBUG : fs cache: adding new entry for parent of "/home/borg/repos/photos/data/1/1202", "/home/borg/repos/photos/data/1"
2024/09/22 16:48:17 DEBUG : Creating backend with remote "onedrive:repos/photos/data/1"
2024/09/22 16:48:17 DEBUG : Creating backend with remote "onedriveunderlying:rclonebackups/qtvah5opb18p4g4ve2i0lh4mio/vptothej6ciusdjpca3agsgj5o/u58r1pkbe9ip1vlcarj5tntqqs/s4s1q07jvge4ij8b60qlddrsf8"
2024/09/22 16:48:20 DEBUG : 1202: Modification times differ by -143.88454ms: 2023-02-17 21:00:17.14388454 +1100 AEDT, 2023-02-17 10:00:17 +0000 UTC
2024/09/22 16:48:20 DEBUG : vknf9rh5le44k0v06gdv2ri0ts: Starting multipart upload
2024/09/22 16:48:20 DEBUG : vknf9rh5le44k0v06gdv2ri0ts: Uploading segment 0/147937 size 147937
2024/09/22 16:48:21 DEBUG : 1202: quickxor = b93d44af98526f074f808342a06fcb2ccc70396b OK
2024/09/22 16:48:21 INFO : 1202: Copied (replaced existing)
2024/09/22 16:48:21 INFO :
Transferred: 144.470 KiB / 144.470 KiB, 100%, 144.470 KiB/s, ETA 0s
Transferred: 1 / 1, 100%
Elapsed time: 4.0s
2024/09/22 16:48:21 DEBUG : 9 go routines active
```
Run using `--modify-window 1s`:
```
borg@host:/tmp$ rclone -vv sync --modify-window 1s ~/repos/photos/data/1/1202 onedrive:repos/photos/data/1
2024/09/22 16:48:32 DEBUG : rclone: Version "v1.68.0" starting with parameters ["rclone" "-vv" "sync" "--modify-window" "1s" "/home/borg/repos/photos/data/1/1202" "onedrive:repos/photos/data/1"]
2024/09/22 16:48:32 DEBUG : Creating backend with remote "/home/borg/repos/photos/data/1/1202"
2024/09/22 16:48:32 DEBUG : Using config file from "/home/borg/.config/rclone/rclone.conf"
2024/09/22 16:48:32 DEBUG : fs cache: adding new entry for parent of "/home/borg/repos/photos/data/1/1202", "/home/borg/repos/photos/data/1"
2024/09/22 16:48:32 DEBUG : Creating backend with remote "onedrive:repos/photos/data/1"
2024/09/22 16:48:32 DEBUG : Creating backend with remote "onedriveunderlying:rclonebackups/qtvah5opb18p4g4ve2i0lh4mio/vptothej6ciusdjpca3agsgj5o/u58r1pkbe9ip1vlcarj5tntqqs/s4s1q07jvge4ij8b60qlddrsf8"
2024/09/22 16:48:34 DEBUG : 1202: Size and modification time the same (differ by -143.88454ms, within tolerance 1s)
2024/09/22 16:48:34 DEBUG : 1202: Unchanged skipping
2024/09/22 16:48:34 INFO :
Transferred: 0 B / 0 B, -, 0 B/s, ETA -
Elapsed time: 2.4s
2024/09/22 16:48:34 DEBUG : 6 go routines active
```
`lsl` showing the mismatching modification times:
```
borg@host:/tmp$ rclone lsl onedrive:repos/photos/data/1/1202
147857 2023-02-17 21:00:17.000000000 1202
borg@host:/tmp$ rclone lsl ~/repos/photos/data/1/1202
147857 2023-02-17 21:00:17.143884540 1202
```
#### How to use GitHub
* Please use the 👍 [reaction](https://blog.github.com/2016-03-10-add-reactions-to-pull-requests-issues-and-comments/) to show that you are affected by the same issue.
* Please don't comment if you have no relevant information to add. It's just extra noise for everyone subscribed to this issue.
* Subscribe to receive notifications on status change and new comments.
Not sure if it is fixed in the latest beta - you can try.
1 Like
OliverL
November 12, 2024, 9:15pm
4
Hello, thanks for taking the time to answer
Here are the outputs when picking a single file
Sync, in this case the file is found
C:\Users\olive> ./rclone sync -vv "C:\Users\olive\Desktop\Oliver\2024-09-18_IMG20240918145352.jpg" "OneDriveArchivo:/Compartidas/Japon 2024/Oliver"
2024/11/12 22:10:46 DEBUG : rclone: Version "v1.68.1" starting with parameters ["C:\\Users\\olive\\rclone.exe" "sync" "-vv" "C:\\Users\\olive\\Desktop\\Oliver\\2024-09-18_IMG20240918145352.jpg" "OneDriveArchivo:/Compartidas/Japon 2024/Oliver"]
2024/11/12 22:10:46 DEBUG : Creating backend with remote "C:\\Users\\olive\\Desktop\\Oliver\\2024-09-18_IMG20240918145352.jpg"
2024/11/12 22:10:46 DEBUG : Using config file from "C:\\Users\\olive\\AppData\\Roaming\\rclone\\rclone.conf"
2024/11/12 22:10:46 DEBUG : fs cache: adding new entry for parent of "C:\\Users\\olive\\Desktop\\Oliver\\2024-09-18_IMG20240918145352.jpg", "//?/C:/Users/olive/Desktop/Oliver"
2024/11/12 22:10:46 DEBUG : Creating backend with remote "OneDriveArchivo:/Compartidas/Japon 2024/Oliver"
2024/11/12 22:10:47 DEBUG : fs cache: renaming cache item "OneDriveArchivo:/Compartidas/Japon 2024/Oliver" to be canonical "OneDriveArchivo:Compartidas/Japon 2024/Oliver"
2024/11/12 22:10:47 DEBUG : 2024-09-18_IMG20240918145352.jpg: Size and modification time the same (differ
by 0s, within tolerance 1ms)
2024/11/12 22:10:47 DEBUG : 2024-09-18_IMG20240918145352.jpg: Unchanged skipping
2024/11/12 22:10:47 INFO :
Transferred: 0 B / 0 B, -, 0 B/s, ETA -
Elapsed time: 1.1s
2024/11/12 22:10:47 DEBUG : 4 go routines active
ls
PS C:\Users\olive> ./rclone ls -vv "OneDriveArchivo:/Compartidas/Japon 2024/Oliver/2024-09-18_IMG20240918145352.jpg"
2024/11/12 22:13:25 DEBUG : rclone: Version "v1.68.1" starting with parameters ["C:\\Users\\olive\\rclone.exe" "ls" "-vv" "OneDriveArchivo:/Compartidas/Japon 2024/Oliver/2024-09-18_IMG20240918145352.jpg"]
2024/11/12 22:13:25 DEBUG : Creating backend with remote "OneDriveArchivo:/Compartidas/Japon 2024/Oliver/2024-09-18_IMG20240918145352.jpg"
2024/11/12 22:13:25 DEBUG : Using config file from "C:\\Users\\olive\\AppData\\Roaming\\rclone\\rclone.conf"
2024/11/12 22:13:27 DEBUG : fs cache: adding new entry for parent of "OneDriveArchivo:/Compartidas/Japon 2024/Oliver/2024-09-18_IMG20240918145352.jpg", "OneDriveArchivo:Compartidas/Japon 2024/Oliver"
2024/11/12 22:13:28 DEBUG : 4 go routines active
asdffdsa
November 12, 2024, 9:20pm
5
now, i see your issue, but not sure what is the cause
OliverL
November 12, 2024, 9:24pm
6
Tried but without luck. Thanks anyway
rclone ls is not even listing the files, that may be the root cause of the issue.
I see... this is real strange. But I can not reproduce it.
Could you try the same rclone ls using the latest rclone beta?
OliverL
November 13, 2024, 7:29am
8
Here is the output for the beta:
./rclone ls -vv "OneDriveArchivo:/Compartidas/Japon 2024/Oliver"
2024/11/13 08:26:18 DEBUG : rclone: Version "v1.69.0-beta.8402.f639cd9c7" starting with parameters ["C:\\Users\\olive\\Desktop\\rclone-v1.69.0-beta.8402.f639cd9c7-windows-amd64\\rclone.exe" "ls" "-vv" "OneDriveArchivo:/Compartidas/Japon 2024/Oliver"]
2024/11/13 08:26:18 DEBUG : Creating backend with remote "OneDriveArchivo:/Compartidas/Japon 2024/Oliver"
2024/11/13 08:26:18 DEBUG : Using config file from "C:\\Users\\olive\\AppData\\Roaming\\rclone\\rclone.conf"
2024/11/13 08:26:19 DEBUG : fs cache: renaming cache item "OneDriveArchivo:/Compartidas/Japon 2024/Oliver" to be canonical "OneDriveArchivo:Compartidas/Japon 2024/Oliver"
2024/11/13 08:26:19 DEBUG : 4 go routines active
Thank you. Not that it solves the problem but at least we know that it is not something fixed in the latest beta (there are few OneDrive fixes there)
ncw
November 13, 2024, 8:40am
10
Files missing with rclone ls is definitely a problem.
Can you run your test ls with -vv --dump bodies and post the output. That will hopefully show what is going on.
