Much slower sync with Google Drive after update to Rclone v1.66

Help and Support
1

What is the problem you are having with rclone?

I updated from rclone v1.61 to v1.66, and instead of about 5 minutes sync time it takes about 30 minutes only to sync a few files. Going back to rclone v1.61 does not seem to help, as it takes about the samt time for both versions to sync now. The first time I run rclone v1.66 it took over two hours, which I suppose had to do with the Rclone now syncing directory modification times if the backend supports it. When I perform a sync with MEGA it is as fast as before also for rclone v1.66.

Can anything be done for faster sync with Google Drive (and OneDrive), using the latest version of Rclone?

Run the command 'rclone version' and share the full output of the command.

rclone v1.66.0

  • os/version: Microsoft Windows 8.1 Connected (64 bit)
  • os/kernel: 6.3.9600.20778 (x86_64)
  • os/type: windows
  • os/arch: amd64
  • go/version: go1.22.1
  • go/linking: static
  • go/tags: cmount

Which cloud storage system are you using? (eg Google Drive)

Google Drive

The command you were trying to run (eg rclone copy /tmp remote:tmp)

rclone sync --progress --stats=5s --transfers=1 --max-age 1M "C:\local_folder" gdriveremote:bkpj/Doks --backup-dir=gdriveremote:bkpj/oldj --suffix "_%date:~2,2%%date:~5,2%%date:~8,2%-%time::=%.bak" -v --log-file=gdriveremote.log.csv --no-update-dir-modtime

Please run 'rclone config redacted' and share the full output. If you get command not found, please make sure to update rclone.

[gdriveremote]
type = drive
scope = drive
token = XXX
team_drive = 

### Double check the config for sensitive info before posting publicly

A log from the command that you were trying to run with the -vv flag

2024/04/13 14:18:02 DEBUG : --max-age 1M to 2024-03-14 13:18:02.529226 +0100 CET m=-2591999.004051799
2024/04/13 14:18:02 DEBUG : rclone: Version "v1.66.0" starting with parameters ["rclone" "sync" "--progress" "--stats=5s" "--transfers=1" "--max-age" "1M" "C:\\local_folder" "gdriveremote:bkpj/Doks" "--backup-dir=gdriveremote:bkpj/oldj" "--suffix" "_240413-141800,69.bak" "-vv" "--log-file=gdriveremote_check.log.csv" "--no-update-dir-modtime" "--dry-run"]
2024/04/13 14:18:02 DEBUG : Creating backend with remote "C:\\local_folder"
2024/04/13 14:18:03 DEBUG : Using config file from "C:\\rclone_path\\rclone.conf"
2024/04/13 14:18:03 DEBUG : fs cache: renaming cache item "C:\\local_folder" to be canonical "//?/C:/local_folder"
2024/04/13 14:18:03 DEBUG : Creating backend with remote "gdriveremote:bkpj/Doks"
2024/04/13 14:18:03 DEBUG : gdriveremote: Loaded invalid token from config file - ignoring
2024/04/13 14:18:03 DEBUG : Saving config "token" in section "gdriveremote" of the config file
2024/04/13 14:18:03 DEBUG : Keeping previous permissions for config file: -rw-rw-rw-
2024/04/13 14:18:03 DEBUG : gdriveremote: Saved new token in config file
2024/04/13 14:18:04 DEBUG : Google drive root 'bkpj/Doks': 'root_folder_id = 0AFbeiTSffAumUk9PVA' - save this in the config to speed up startup
2024/04/13 14:18:04 DEBUG : Creating backend with remote "gdriveremote:bkpj/oldj"
2024/04/13 14:18:05 DEBUG : Google drive root 'bkpj/oldj': 'root_folder_id = 0AFbeiTSffAumUk9PVA' - save this in the config to speed up startup
2024/04/13 14:18:05 DEBUG : 141203_ Tarjeta XXXX.pdf: Excluded (ModTime Filter)
2024/04/13 14:18:05 DEBUG : 141203_ Tarjeta XXXX.pdf: Excluded
2024/04/13 14:18:05 DEBUG : 141215_Demanda XXXX.pdf: Excluded (ModTime Filter)
2024/04/13 14:18:05 DEBUG : 141215_Demanda XXXX.pdf: Excluded
2024/04/13 14:18:05 DEBUG : 150605_Manpower_XXXX.doc: Excluded (ModTime Filter)
2024/04/13 14:18:05 DEBUG : 150605_Manpower_XXXX.doc: Excluded
2024/04/13 14:18:05 DEBUG : 190906_XXXX contexts FULLTEXT01.pdf: Excluded (ModTime Filter)
2024/04/13 14:18:05 DEBUG : 190906_XXXX contexts FULLTEXT01.pdf: Excluded
2024/04/13 14:18:05 DEBUG : Desktop.ini: Excluded (ModTime Filter)
2024/04/13 14:18:05 DEBUG : Desktop.ini: Excluded
2024/04/13 14:18:05 DEBUG : Edlenskattning koll XXXX.xls: Excluded (ModTime Filter)
2024/04/13 14:18:05 DEBUG : Edlenskattning koll XXXX.xls: Excluded
2024/04/13 14:18:05 DEBUG : XXXX measurement.doc: Excluded (ModTime Filter)
2024/04/13 14:18:05 DEBUG : XXXX measurement.doc: Excluded
2024/04/13 14:18:05 DEBUG : XXXX_BQ.pdf: Excluded (ModTime Filter)
2024/04/13 14:18:05 DEBUG : XXXX_BQ.pdf: Excluded
2024/04/13 14:18:05 DEBUG : XXXX_BQ_2.pdf: Excluded (ModTime Filter)
2024/04/13 14:18:05 DEBUG : XXXX_BQ_2.pdf: Excluded
2024/04/13 14:18:05 DEBUG : MetXXXXtion.pdf: Excluded (ModTime Filter)
2024/04/13 14:18:05 DEBUG : MetXXXXtion.pdf: Excluded
2024/04/13 14:18:05 DEBUG : PublicaXXXXoduct_De.pdf: Excluded (ModTime Filter)
2024/04/13 14:18:05 DEBUG : PublicaXXXXoduct_De.pdf: Excluded
2024/04/13 14:18:05 DEBUG : SofXXXXmsc20.pdf: Excluded (ModTime Filter)
2024/04/13 14:18:05 DEBUG : SofXXXXmsc20.pdf: Excluded
2024/04/13 14:18:05 DEBUG : TiXXXXrvjun.doc: Excluded (ModTime Filter)
2024/04/13 14:18:05 DEBUG : TiXXXXrvjun.doc: Excluded
.
.
.
2024/04/13 14:46:53 NOTICE: XXXX/Foton: Skipped remove directory as --dry-run is set
2024/04/13 14:46:53 NOTICE: XXXX/Administration: Skipped remove directory as --dry-run is set
2024/04/13 14:46:53 NOTICE: XXXX: Skipped remove directory as --dry-run is set
2024/04/13 14:46:53 NOTICE: XXXX/e-post: Skipped remove directory as --dry-run is set
2024/04/13 14:46:53 DEBUG : Google drive root 'bkpj/XXXX': deleted 88 directories
2024/04/13 14:46:53 NOTICE: 
Transferred:   	    4.196 MiB / 4.196 MiB, 100%, 2.306 KiB/s, ETA 0s
Checks:               355 / 355, 100%
Deleted:                0 (files), 88 (dirs)
Renamed:                4
Transferred:           14 / 14, 100%
Elapsed time:     28m51.0s

2024/04/13 14:46:53 DEBUG : 18 go routines active
2

welcome to the forum,

that does seem very slow, given the small count of files.
might try --fast-list

should create your own client id+secret, as per the rclone docs
https://rclone.org/drive/#making-your-own-client-id

i guess you have a reason to use --transfers=1

that log is just a short snippet for a few seconds.

and debug log with timestamps. that way you can compare debug logs
--log-level=DEBUG --log-file="gdriveremote_%date:~2,2%%date:~5,2%%date:~8,2%-%time::=%.log"

3

Thanks a lot for a quick answer! The "--fast-list" got the time again down to about 5 minutes for Google Drive.:slight_smile:

I tried the same for Onedrive, but unfortunately it did not have the same effect, and it takes about 10 minutes even if no file is to be transferred. (MEGA makes the same sync in about 1 minute.) Before the update to Rclone v1.66 I can see in the logs that it took about 4-5 minutes with the same sync command, which means that for me Rclone v1.66 is about 100 % slower. I have in total about 35000 objects with a size of 7.3 GB on Onedrive. Considering the number of files this is certainly fine with me, but just in case anybody has an idea if it is possible to "reach the previous performance", I include the debug file (cleaned from sensitive information). Else this topic can be considered solved.

2024/04/16 14:09:00 DEBUG : --max-age 1M to 2024-03-17 13:09:00.4281119 +0100 CET m=-2591999.335256399
2024/04/16 14:09:00 DEBUG : rclone: Version "v1.66.0" starting with parameters ["rclone" "sync" "--progress" "--stats=5s" "--max-age" "1M" "C:\Path" "onedriveremote:bkpj/DocJob" "--backup-dir=onedriveremote:bkpj/oldj" "--suffix" "240416-140854,84.bak" "-vv" "--log-file=.\logs\onedriveremote_240416-140854,84.log.csv" "--fast-list"]
2024/04/16 14:09:00 DEBUG : Creating backend with remote "C:\Path"
2024/04/16 14:09:01 DEBUG : Using config file from "C:\Path\rclone.conf"
2024/04/16 14:09:01 DEBUG : fs cache: renaming cache item "C:\Path" to be canonical "//?/C:/Path"
2024/04/16 14:09:01 DEBUG : Creating backend with remote "onedriveremote:bkpj/DocJob"
2024/04/16 14:09:01 DEBUG : OneDrive root 'bkpj/DocJob': Token expired but no uploads in progress - doing nothing
2024/04/16 14:09:01 DEBUG : onedriveremote: Loaded invalid token from config file - ignoring
2024/04/16 14:09:01 DEBUG : Saving config "token" in section "onedriveremote" of the config file
2024/04/16 14:09:02 DEBUG : Keeping previous permissions for config file: -rw-rw-rw-
2024/04/16 14:09:02 DEBUG : onedriveremote: Saved new token in config file
2024/04/16 14:09:03 DEBUG : Creating backend with remote "onedriveremote:bkpj/oldj"
2024/04/16 14:09:04 DEBUG : 141203 File1.pdf: Excluded (ModTime Filter)
2024/04/16 14:09:04 DEBUG : 141203_ File1.pdf: Excluded
2024/04/16 14:09:04 DEBUG : 141215_File2.pdf: Excluded (ModTime Filter)
2024/04/16 14:09:04 DEBUG : 141215_File2.pdf: Excluded
...
Aprox 340000 similar rows with "Excluded", like above.
...
2024/04/16 14:09:05 DEBUG : _rteon: Directory modification time the same (differ by -416.1µs, within tolerance 1ms)
2024/04/16 14:09:05 DEBUG : Acoustics: Directory modification time the same (differ by -736.1µs, within tolerance 1ms)
2024/04/16 14:09:05 DEBUG : Dir3: Directory modification time the same (differ by -399.6µs, within tolerance 1ms)
2024/04/16 14:09:05 DEBUG : Dir4: Directory modification time the same (differ by -446.4µs, within tolerance 1ms)
...
Aprox 18200 similar rows with "Directory modification time the same", like above.
...
2024/04/16 14:09:05 DEBUG : Path/File3.xls: Modification times differ by -33m57.97s: 2024-04-16 00:49:19.502 +0200 CEST, 2024-04-15 22:15:21.532 +0000 UTC
2024/04/16 14:09:06 DEBUG : Path/File3.xls: quickxor = 8b9363099741c39533898ebf7862f5a32701977e (Local file system at //?/C:/Path)
2024/04/16 14:09:06 DEBUG : Path/File3.xls: quickxor = b2c9b56b11aed17e6d671213b5b0ca6f19b48d92 (OneDrive root 'bkpj/DocJob')
2024/04/16 14:09:06 DEBUG : Path/File3.xls: quickxor differ
2024/04/16 14:09:07 INFO : Path/File3.xls: Moved (server-side) to: Path/File3.xls_240416-140854,84.bak
2024/04/16 14:09:07 DEBUG : Path/File3.xls: Starting multipart upload
2024/04/16 14:09:08 DEBUG : Path/File3.xls: Uploading segment 0/102912 size 102912
2024/04/16 14:09:08 DEBUG : Path/File3.xls: quickxor = 8b9363099741c39533898ebf7862f5a32701977e OK
2024/04/16 14:09:08 INFO : Path/File3.xls: Copied (new)
...
2024/04/16 14:17:46 DEBUG : Path/capture_20240404-125649.jpg: Unchanged skipping
2024/04/16 14:17:46 DEBUG : Path/capture_20240404-125749.jpg: Unchanged skipping
2024/04/16 14:17:46 DEBUG : Path/capture_20240404-125849.jpg: Unchanged skipping
2024/04/16 14:17:46 DEBUG : Path/capture_20240404-130249.jpg: Unchanged skipping
...
Aprox 350 similar rows with "skipping", like above.
...
2024/04/16 14:19:13 DEBUG : OneDrive root 'bkpj/DocJob': Waiting for checks to finish
2024/04/16 14:19:13 DEBUG : OneDrive root 'bkpj/DocJob': Waiting for transfers to finish
2024/04/16 14:19:13 DEBUG : Waiting for deletions to finish
...
2024/04/16 14:19:15 INFO : Path/Dir5: Removing directory
2024/04/16 14:19:16 DEBUG : Path/Dir5: Failed to Rmdir: directory not empty
2024/04/16 14:19:16 INFO : Path/Administration: Removing directory
2024/04/16 14:19:16 DEBUG : Path/Administration: Failed to Rmdir: directory not empty
2024/04/16 14:19:16 INFO : Path: Removing directory
2024/04/16 14:19:16 DEBUG : Path: Failed to Rmdir: directory not empty
2024/04/16 14:19:16 INFO : Path/Dir6: Removing directory
...
Aprox 200 similar rows with "Failed to Rmdir", like above.
...
2024/04/16 14:19:36 DEBUG : OneDrive root 'bkpj/DocJob': failed to delete 87 directories
2024/04/16 14:19:36 INFO :
Transferred: 100.500 KiB / 100.500 KiB, 100%, 352 B/s, ETA 0s
Checks: 382 / 382, 100%
Deleted: 0 (files), 87 (dirs)
Renamed: 1
Transferred: 1 / 1, 100%
Server Side Moves: 1 @ 100.500 KiB
Elapsed time: 10m35.9s
...
2024/04/16 14:19:36 DEBUG : 6 go routines active

4

nice,

the command for gdrive has --no-update-dir-modtime but the command for onedrive does not?

and can you post rclone config redacted onedriveremote:

5

The config redacted is:

[onedriveremote]
type = onedrive
token = XXX
drive_id = XXX
drive_type = personal

I removed "--no-update-dir-modtime" and "--transfers" as there were no time difference when using them for Google Drive. I just made a test using "--no-update-dir-modtime", but neither there I see any time difference. It took 10m55.8s this time.

When I run the "size" command (to see how many objects I have) it also took a long time to get the results. Maybe there is a limitation on Onedrive which makes it take about 10 minutes only to get the file list of 35000 files? The strange thing is that the time was doubled right after changing to the latest version of Rclone, but it may be a coincidence. I neither know if Rclone needs to get the full list of 35000 files, or if it is possible to only compare the files to be uploaded.

6

if you can reproduce the issue, then post the debug logs. we can take a look.

and in the first post, i mentioned, best to create your own client id+secret.
for both, gdrive and onedrive.

7

Using Rclone v1.61 now also takes 10 minutes, even when only a couple of files shall be transferred, although my logs before updating to v1.66 shows about 5 minutes. It seems that the full file list of about 35000 files is downloaded every time, while in my case only 376 files had to be checked.

(Date 17.04.2024)
Transferred: 100.500 KiB / 100.500 KiB, 100%, 352 B/s, ETA 0s
Checks: 376 / 376, 100%
Deleted: 0 (files), 87 (dirs)
Renamed: 1
Transferred: 1 / 1, 100%
Server Side Moves: 1 @ 100.500 KiB
Elapsed time: 10m3.0s

Is there any way to prevent checking the full file list, and only check the files that are chosen from the filter, i.e. in my case above check on the remote the 376 files out of the 35000 files? I assume that would speed up the process? The Debug log shows a list of all files, giving almost all files as excluded. During the checking it seems about 31 MB is downloaded and 5 MB is uploaded.

8

After some further reading and tweaking I added "--onedrive-delta --checkers 20" to the command, and have got the time down to 3-4 minutes, like before with Rclone v1.61.:slight_smile: I therefore consider the problem solved also for Onedrive, although it is not clear what was the reason for the slowdown.

However, something has most likely happened when updating, as now testing with a Webdav server, which earlier took about 1-2 minutes takes about 12-14 minutes. With "--checkers 16" it takes now about 6 minutes to check (but not copy any file). MEGA is not influenced at all from the update, and is as fast as before, taking less than a minute to check the files.

Before update: Webdav (Infinicloud) with --max-age 1M
2024/04/02 20:42:36 INFO :
Transferred: 7.508 MiB / 7.508 MiB, 100%, 50.239 KiB/s, ETA 0s
Checks: 104 / 104, 100%
Renamed: 1
Transferred: 31 / 31, 100%
Elapsed time: 1m18.4s

After update: Webdav (Infinicloud) with --max-age 1M
2024/04/17 22:41:04 INFO :
Transferred: 576.093 KiB / 576.093 KiB, 100%, 403 B/s, ETA 0s
Checks: 173 / 173, 100%
Renamed: 5
Transferred: 8 / 8, 100%
Server Side Moves: 5 @ 433.862 KiB
Elapsed time: 13m15.1s

MEGA with --max-age 3M (no speed change observed)
2024/04/17 22:27:08 INFO :
Transferred: 383.130 KiB / 383.130 KiB, 100%, 44.798 KiB/s, ETA 0s
Checks: 2020 / 2020, 100%
Deleted: 0 (files), 10 (dirs)
Renamed: 4
Transferred: 6 / 6, 100%
Server Side Moves: 4 @ 371.845 KiB
Elapsed time: 44.7s