Hi
Thank you for reading. My use case and background: I like to do an encrypted backups on google drive: crypt -> cache -> drive. Total around 20 GB. To test, I started with around 700 MB, around 10 k files. The initial rclone copy was slow, understandably. But rclone sync is also slow even if no files were changed. Originally I tried without cache, then added cache, hoping to cache the file size and timestamp (I do no downloads /reads, except when my local harddisk would fail; thus a download cache is not relevant to me). But the sync performance did not improve.
Thanks for any hints how to dig deeper.
Al_
What is the problem you are having with rclone?
Trying to find the reason for the slow sync performance, I did a file listing (rclone lsl) that took around 14 minutes for 10 k lines. It is not the connection to Google drive: when using directly the drive backend, lsl takes only a few seconds. Using cache -> drive increases to 14 minutes. Using crypt -> cache -> drive again around 14 minutes (all three copied below). My conclusion: neither encryption nor Google drive access is the bottle neck, but the cache is slowing instead of speeding up.
What am I doing wrong? Is a cache only for downloaded data or also to locally cache filesize and timestamp? My hope was the latter, so that rclone sync would only need to check locally, whether a file needs to be uploaded.
What is your rclone version (output from rclone version)
rclone v1.50.2 (not the latest, but the newest in the repository provided by the newest Ubuntu LTS version)
Which OS you are using and how many bits (eg Windows 7, 64 bit)
Linux 5.8.0-48-generic #54~20.04.1-Ubuntu x86_64 GNU/Linux
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)
buero:~$ date ; rclone lsl mygdrive:Backups | wc --lines ; date
Fr 02 Apr 2021 14:39:46 CEST
10186
Fr 02 Apr 2021 14:39:59 CEST
buero:~$ date ; rclone lsl cachegdrive: | wc --lines ; date
Fr 02 Apr 2021 14:40:30 CEST
10186
Fr 02 Apr 2021 14:54:18 CEST
buero:~$ date ; rclone lsl encryptgdrive: | wc --lines ; date
Fr 02 Apr 2021 14:55:16 CEST
10186
Fr 02 Apr 2021 15:08:55 CEST
The rclone config contents with secrets removed.
[mygdrive]
type = drive
scope = drive
export_formats = odt,ods,odp,svg
token = {"access_token":"xxx","token_type":"Bearer","refresh_token":"xxx","expiry":"2021-04-02T16:03:46.114500395+02:00"}
root_folder_id = xxx
[encryptgdrive]
type = crypt
remote = cachegdrive:
filename_encryption = standard
directory_name_encryption = true
password = xxx
password2 = xxx
[cachegdrive]
type = cache
remote = mygdrive:Backups
info_age = 10y
plex_insecure = y
A log from the command with the -vv flag
buero:~$ cat Heimnetzwerk/BackupConfig/rclone_mygdrive.log
2021/04/02 16:08:34 DEBUG : rclone: Version "v1.50.2" starting with parameters ["rclone" "--log-file=Heimnetzwerk/BackupConfig/rclone_mygdrive.log" "-vv" "lsl" "mygdrive:"]
2021/04/02 16:08:34 DEBUG : Using config file from "/home/xxx/.config/rclone/rclone.conf"
2021/04/02 16:08:46 DEBUG : 19 go routines active
2021/04/02 16:08:46 DEBUG : rclone: Version "v1.50.2" finishing with parameters ["rclone" "--log-file=Heimnetzwerk/BackupConfig/rclone_mygdrive.log" "-vv" "lsl" "mygdrive:"]
buero:~$ cat Heimnetzwerk/BackupConfig/rclone_cachegdrive.log
2021/04/02 16:10:27 DEBUG : rclone: Version "v1.50.2" starting with parameters ["rclone" "--log-file=Heimnetzwerk/BackupConfig/rclone_cachegdrive.log" "-vv" "lsl" "cachegdrive:"]
2021/04/02 16:10:27 DEBUG : Using config file from "/home/xxx/.config/rclone/rclone.conf"
2021/04/02 16:10:27 DEBUG : cachegdrive: wrapped mygdrive:Backups at root
2021/04/02 16:10:27 INFO : cachegdrive: Cache DB path: /home/xxx/.cache/rclone/cache-backend/cachegdrive.db
2021/04/02 16:10:27 INFO : cachegdrive: Cache chunk path: /home/xxx/.cache/rclone/cache-backend/cachegdrive
2021/04/02 16:10:27 INFO : cachegdrive: Chunk Memory: true
2021/04/02 16:10:27 INFO : cachegdrive: Chunk Size: 5M
2021/04/02 16:10:27 INFO : cachegdrive: Chunk Total Size: 10G
2021/04/02 16:10:27 INFO : cachegdrive: Chunk Clean Interval: 1m0s
2021/04/02 16:10:27 INFO : cachegdrive: Workers: 4
2021/04/02 16:10:27 INFO : cachegdrive: File Age: 10y
2021/04/02 16:10:27 DEBUG : Adding path "cache/expire" to remote control registry
2021/04/02 16:10:27 DEBUG : Adding path "cache/stats" to remote control registry
2021/04/02 16:10:27 DEBUG : Adding path "cache/fetch" to remote control registry
2021/04/02 16:10:27 DEBUG : Cache remote cachegdrive:: list recursively from ''
2021/04/02 16:10:40 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded)
2021/04/02 16:10:40 DEBUG : pacer: Rate limited, increasing sleep to 1.376772584s
2021/04/02 16:10:40 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded)
2021/04/02 16:10:40 DEBUG : pacer: Rate limited, increasing sleep to 2.106247786s
2021/04/02 16:10:43 DEBUG : pacer: Reducing sleep to 0s
2021/04/02 16:11:27 DEBUG : Cache remote cachegdrive:: starting cleanup
2021/04/02 16:11:27 DEBUG : Google drive root 'Backups': Checking for changes on remote
2021/04/02 16:12:27 DEBUG : Cache remote cachegdrive:: starting cleanup
2021/04/02 16:12:27 DEBUG : Google drive root 'Backups': Checking for changes on remote
2021/04/02 16:13:27 DEBUG : Cache remote cachegdrive:: starting cleanup
2021/04/02 16:13:27 DEBUG : Google drive root 'Backups': Checking for changes on remote
2021/04/02 16:14:27 DEBUG : Google drive root 'Backups': Checking for changes on remote
2021/04/02 16:14:27 DEBUG : Cache remote cachegdrive:: starting cleanup
2021/04/02 16:15:27 DEBUG : Google drive root 'Backups': Checking for changes on remote
2021/04/02 16:15:27 DEBUG : Cache remote cachegdrive:: starting cleanup
2021/04/02 16:16:27 DEBUG : Google drive root 'Backups': Checking for changes on remote
2021/04/02 16:16:27 DEBUG : Cache remote cachegdrive:: starting cleanup
2021/04/02 16:17:27 DEBUG : Google drive root 'Backups': Checking for changes on remote
2021/04/02 16:17:28 DEBUG : Cache remote cachegdrive:: starting cleanup
2021/04/02 16:18:27 DEBUG : Google drive root 'Backups': Checking for changes on remote
2021/04/02 16:18:28 DEBUG : Cache remote cachegdrive:: starting cleanup
2021/04/02 16:19:27 DEBUG : Google drive root 'Backups': Checking for changes on remote
2021/04/02 16:19:28 DEBUG : Cache remote cachegdrive:: starting cleanup
2021/04/02 16:20:10 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded)
2021/04/02 16:20:10 DEBUG : pacer: Rate limited, increasing sleep to 1.133341738s
2021/04/02 16:20:10 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded)
2021/04/02 16:20:10 DEBUG : pacer: Rate limited, increasing sleep to 2.285578359s
2021/04/02 16:20:10 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded)
2021/04/02 16:20:10 DEBUG : pacer: Rate limited, increasing sleep to 4.586895785s
2021/04/02 16:20:13 DEBUG : pacer: Reducing sleep to 0s
2021/04/02 16:20:27 DEBUG : Google drive root 'Backups': Checking for changes on remote
2021/04/02 16:20:28 DEBUG : Cache remote cachegdrive:: starting cleanup
2021/04/02 16:21:27 DEBUG : Google drive root 'Backups': Checking for changes on remote
2021/04/02 16:21:28 DEBUG : Cache remote cachegdrive:: starting cleanup
2021/04/02 16:22:27 DEBUG : Google drive root 'Backups': Checking for changes on remote
2021/04/02 16:22:28 DEBUG : Cache remote cachegdrive:: starting cleanup
2021/04/02 16:23:27 DEBUG : Google drive root 'Backups': Checking for changes on remote
2021/04/02 16:23:28 DEBUG : Cache remote cachegdrive:: starting cleanup
2021/04/02 16:24:15 DEBUG : 23 go routines active
2021/04/02 16:24:15 DEBUG : rclone: Version "v1.50.2" finishing with parameters ["rclone" "--log-file=Heimnetzwerk/BackupConfig/rclone_cachegdrive.log" "-vv" "lsl" "cachegdrive:"]
2021/04/02 16:24:15 DEBUG : Cache remote cachegdrive:: Services stopped