What is the problem you are having with rclone?
I am attempting to perform rclone cleanup on my SharePoint remote that has ~1.5 million files / 7 TB, some of which have multiple versions that I am trying to remove, and am having performance issues with throttling. I'm using a distinct client ID / secret, decorated my traffic with the --user-agent and limited my transaction rate to 8/s, with checkers to 4, but am still triggering throttling every 10-15 min or so.
From the log, it looks like unlike the rclone copy command, rclone cleanup does not record names of files that are skipped (files that have only 1 version). Files for which the older versions were deleted have been logged. There seems to be some gap between when the throttling is invoked, which indicates that it's probably going through the file list and searching for files with multiple versions, paced by the intervals as logged. My guess is that the checker and the cleanup command are not bandwidth-limited, and thus are performing too many transactions, but I'm not sure why the pacer is allowing 10ms pacing when the tpslimit is set to 8/s. Maybe I should set the tpslimit to much lower...?
Any help is appreciated. Thank you!
What is your rclone version (output from rclone version)
rclone 1.53.4
Which OS you are using and how many bits (eg Windows 7, 64 bit)
Ubuntu 18.04.5 LTS Kernel: 5.4.0-62-generic x86_64
Which cloud storage system are you using? (eg Google Drive)
Microsoft OneDrive Business/SharePoint
The command you were trying to run (eg rclone copy /tmp remote:tmp)
rclone cleanup "sharepoint:/" -P --log-file="rclone_20210218_clean.log" --log-level DEBUG --max-backlog=-1 --retries 1 --user-agent "ISV|rclone.org|rclone/v1.53" --tpslimit 8 --checkers=4
The rclone config contents with secrets removed.
[sharepoint]
type = onedrive
token = {"access_token":"...","token_type":"Bearer","refresh_token":"...","expiry":"2021-02-18T18:47:09.5226483-06:00"}
drive_id = ...
drive_type = documentLibrary
client_id = ...
client_secret = ...
A log from the command with the -vv flag
2021/02/17 22:00:20 DEBUG : rclone: Version "v1.53.4" starting with parameters ["rclone" "cleanup" "sharepoint:/" "-P" "--log-file=rclone_20210218_clean.log" "--log-level" "DEBUG" "--max-backlog=-1" "--retries" "1" "--user-agent" "ISV|rclone.org|rclone/v1.53" "--tpslimit" "8" "--checkers=4"]
2021/02/17 22:00:20 DEBUG : Using config file from "/home/***/.config/rclone/rclone.conf"
2021/02/17 22:00:20 INFO : Starting HTTP transaction limiter: max 8 transactions/s with burst 1
2021/02/17 22:00:20 DEBUG : Creating backend with remote "sharepoint:/"
2021/02/17 22:00:21 DEBUG : fs cache: renaming cache item "sharepoint:/" to be canonical "sharepoint:"
<...>
2021/02/18 15:58:03 INFO : [filename]: removing version "1.0"
2021/02/18 16:01:08 DEBUG : pacer: low level retry 1/10 (error serviceNotAvailable: Service unavailable)
2021/02/18 16:01:08 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2021/02/18 16:01:08 DEBUG : pacer: low level retry 1/10 (error serviceNotAvailable: Service unavailable)
2021/02/18 16:01:08 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2021/02/18 16:01:08 DEBUG : pacer: low level retry 1/10 (error serviceNotAvailable: Service unavailable)
2021/02/18 16:01:08 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2021/02/18 16:01:08 DEBUG : pacer: low level retry 1/10 (error serviceNotAvailable: Service unavailable)
2021/02/18 16:01:08 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2021/02/18 16:01:08 DEBUG : pacer: low level retry 2/10 (error serviceNotAvailable: Service unavailable)
2021/02/18 16:01:08 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2021/02/18 16:01:09 DEBUG : pacer: low level retry 2/10 (error serviceNotAvailable: Service unavailable)
2021/02/18 16:01:09 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2021/02/18 16:01:09 DEBUG : pacer: low level retry 2/10 (error serviceNotAvailable: Service unavailable)
2021/02/18 16:01:09 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2021/02/18 16:01:09 DEBUG : pacer: low level retry 2/10 (error serviceNotAvailable: Service unavailable)
2021/02/18 16:01:09 DEBUG : pacer: Rate limited, increasing sleep to 2s
2021/02/18 16:01:09 DEBUG : pacer: low level retry 3/10 (error serviceNotAvailable: Service unavailable)
2021/02/18 16:01:09 DEBUG : pacer: low level retry 3/10 (error serviceNotAvailable: Service unavailable)
2021/02/18 16:01:10 DEBUG : pacer: low level retry 3/10 (error serviceNotAvailable: Service unavailable)
2021/02/18 16:01:12 DEBUG : pacer: low level retry 3/10 (error serviceNotAvailable: Service unavailable)
2021/02/18 16:01:14 DEBUG : pacer: low level retry 4/10 (error serviceNotAvailable: Service unavailable)
2021/02/18 16:01:16 DEBUG : pacer: low level retry 4/10 (error serviceNotAvailable: Service unavailable)
2021/02/18 16:01:18 DEBUG : pacer: low level retry 4/10 (error serviceNotAvailable: Service unavailable)
2021/02/18 16:01:20 DEBUG : pacer: low level retry 4/10 (error serviceNotAvailable: Service unavailable)
2021/02/18 16:01:22 DEBUG : pacer: low level retry 5/10 (error serviceNotAvailable: Service unavailable)
2021/02/18 16:01:24 DEBUG : pacer: low level retry 5/10 (error serviceNotAvailable: Service unavailable)
2021/02/18 16:01:26 DEBUG : pacer: low level retry 5/10 (error serviceNotAvailable: Service unavailable)
2021/02/18 16:01:28 DEBUG : pacer: Reducing sleep to 1.5s
2021/02/18 16:01:30 DEBUG : pacer: Reducing sleep to 1.125s
2021/02/18 16:01:32 DEBUG : pacer: Reducing sleep to 843.75ms
2021/02/18 16:01:33 DEBUG : pacer: Reducing sleep to 632.8125ms
2021/02/18 16:01:34 DEBUG : pacer: Reducing sleep to 474.609375ms
2021/02/18 16:01:34 DEBUG : pacer: Reducing sleep to 355.957031ms
2021/02/18 16:01:35 DEBUG : pacer: Reducing sleep to 266.967773ms
2021/02/18 16:01:35 DEBUG : pacer: Reducing sleep to 200.225829ms
2021/02/18 16:01:35 DEBUG : pacer: Reducing sleep to 150.169371ms
2021/02/18 16:01:36 DEBUG : pacer: Reducing sleep to 112.627028ms
2021/02/18 16:01:36 DEBUG : pacer: Reducing sleep to 84.470271ms
2021/02/18 16:01:36 DEBUG : pacer: Reducing sleep to 63.352703ms
2021/02/18 16:01:36 DEBUG : pacer: Reducing sleep to 47.514527ms
2021/02/18 16:01:36 DEBUG : pacer: Reducing sleep to 35.635895ms
2021/02/18 16:01:36 DEBUG : pacer: Reducing sleep to 26.726921ms
2021/02/18 16:01:36 DEBUG : pacer: Reducing sleep to 20.04519ms
2021/02/18 16:01:36 DEBUG : pacer: Reducing sleep to 15.033892ms
2021/02/18 16:01:37 DEBUG : pacer: Reducing sleep to 11.275419ms
2021/02/18 16:01:37 DEBUG : pacer: Reducing sleep to 10ms
2021/02/18 16:02:04 DEBUG : Too many requests. Trying again in 57 seconds.
2021/02/18 16:02:04 DEBUG : pacer: low level retry 1/10 (error activityLimitReached: throttledRequest: The request has been throttled)
2021/02/18 16:02:04 DEBUG : pacer: Rate limited, increasing sleep to 57s
2021/02/18 16:02:04 DEBUG : pacer: Reducing sleep to 42.75s
2021/02/18 16:02:04 DEBUG : Too many requests. Trying again in 52 seconds.
2021/02/18 16:02:04 DEBUG : pacer: low level retry 1/10 (error activityLimitReached: throttledRequest: The request has been throttled)
2021/02/18 16:02:04 DEBUG : pacer: Rate limited, increasing sleep to 52s
2021/02/18 16:02:04 DEBUG : pacer: Reducing sleep to 39s
2021/02/18 16:02:04 DEBUG : pacer: Reducing sleep to 29.25s
2021/02/18 16:03:01 DEBUG : pacer: Reducing sleep to 21.9375s
2021/02/18 16:03:30 DEBUG : pacer: Reducing sleep to 16.453125s
2021/02/18 16:03:52 DEBUG : pacer: Reducing sleep to 12.33984375s
2021/02/18 16:04:08 DEBUG : pacer: Reducing sleep to 9.254882812s
2021/02/18 16:04:21 DEBUG : pacer: Reducing sleep to 6.941162109s
2021/02/18 16:04:30 DEBUG : pacer: Reducing sleep to 5.205871581s
2021/02/18 16:04:37 DEBUG : pacer: Reducing sleep to 3.904403685s
2021/02/18 16:04:42 DEBUG : pacer: Reducing sleep to 2.928302763s
2021/02/18 16:04:46 DEBUG : pacer: Reducing sleep to 2.196227072s
2021/02/18 16:04:49 DEBUG : pacer: Reducing sleep to 1.647170304s
2021/02/18 16:04:51 DEBUG : pacer: Reducing sleep to 1.235377728s
2021/02/18 16:04:53 DEBUG : pacer: Reducing sleep to 926.533296ms
2021/02/18 16:04:54 DEBUG : pacer: Reducing sleep to 694.899972ms
2021/02/18 16:04:55 DEBUG : pacer: Reducing sleep to 521.174979ms
2021/02/18 16:04:56 DEBUG : pacer: Reducing sleep to 390.881234ms
2021/02/18 16:04:56 DEBUG : pacer: Reducing sleep to 293.160925ms
2021/02/18 16:04:57 DEBUG : pacer: Reducing sleep to 219.870693ms
2021/02/18 16:04:57 DEBUG : pacer: Reducing sleep to 164.903019ms
2021/02/18 16:04:57 DEBUG : pacer: Reducing sleep to 123.677264ms
2021/02/18 16:04:57 DEBUG : pacer: Reducing sleep to 92.757948ms
2021/02/18 16:04:57 DEBUG : pacer: Reducing sleep to 69.568461ms
2021/02/18 16:04:57 DEBUG : pacer: Reducing sleep to 52.176345ms
2021/02/18 16:04:58 DEBUG : pacer: Reducing sleep to 39.132258ms
2021/02/18 16:04:58 DEBUG : pacer: Reducing sleep to 29.349193ms
2021/02/18 16:04:58 DEBUG : pacer: Reducing sleep to 22.011894ms
2021/02/18 16:04:58 DEBUG : pacer: Reducing sleep to 16.50892ms
2021/02/18 16:04:58 DEBUG : pacer: Reducing sleep to 12.38169ms
2021/02/18 16:04:58 DEBUG : pacer: Reducing sleep to 10ms
2021/02/18 16:05:00 DEBUG : Too many requests. Trying again in 58 seconds.
2021/02/18 16:05:00 DEBUG : pacer: low level retry 1/10 (error activityLimitReached: throttledRequest: The request has been throttled)
2021/02/18 16:05:00 DEBUG : pacer: Rate limited, increasing sleep to 58s
2021/02/18 16:05:00 DEBUG : pacer: Reducing sleep to 43.5s
2021/02/18 16:05:00 DEBUG : Too many requests. Trying again in 41 seconds.
2021/02/18 16:05:00 DEBUG : pacer: low level retry 1/10 (error activityLimitReached: throttledRequest: The request has been throttled)
2021/02/18 16:05:00 DEBUG : pacer: Rate limited, increasing sleep to 41s
2021/02/18 16:05:00 DEBUG : pacer: Reducing sleep to 30.75s
2021/02/18 16:05:00 DEBUG : pacer: Reducing sleep to 23.0625s
2021/02/18 16:05:58 DEBUG : pacer: Reducing sleep to 17.296875s
2021/02/18 16:06:21 DEBUG : pacer: Reducing sleep to 12.97265625s
2021/02/18 16:06:38 DEBUG : pacer: Reducing sleep to 9.729492187s
2021/02/18 16:06:51 DEBUG : pacer: Reducing sleep to 7.29711914s
2021/02/18 16:07:01 DEBUG : pacer: Reducing sleep to 5.472839355s
2021/02/18 16:07:08 DEBUG : pacer: Reducing sleep to 4.104629516s
2021/02/18 16:07:14 DEBUG : pacer: Reducing sleep to 3.078472137s
2021/02/18 16:07:18 DEBUG : pacer: Reducing sleep to 2.308854102s
2021/02/18 16:07:21 DEBUG : pacer: Reducing sleep to 1.731640576s
2021/02/18 16:07:23 DEBUG : pacer: Reducing sleep to 1.298730432s
2021/02/18 16:07:25 DEBUG : pacer: Reducing sleep to 974.047824ms
2021/02/18 16:07:26 DEBUG : pacer: Reducing sleep to 730.535868ms
2021/02/18 16:07:27 DEBUG : pacer: Reducing sleep to 547.901901ms
2021/02/18 16:07:28 DEBUG : pacer: Reducing sleep to 410.926425ms
2021/02/18 16:07:28 DEBUG : pacer: Reducing sleep to 308.194818ms
2021/02/18 16:07:29 DEBUG : pacer: Reducing sleep to 231.146113ms
2021/02/18 16:07:29 DEBUG : pacer: Reducing sleep to 173.359584ms
2021/02/18 16:07:29 DEBUG : pacer: Reducing sleep to 130.019688ms
2021/02/18 16:07:30 DEBUG : Too many requests. Trying again in 304 seconds.
2021/02/18 16:07:30 DEBUG : pacer: low level retry 1/10 (error activityLimitReached: throttledRequest: The request has been throttled)
2021/02/18 16:07:30 DEBUG : pacer: Rate limited, increasing sleep to 5m4s
2021/02/18 16:07:30 DEBUG : pacer: Reducing sleep to 3m48s
2021/02/18 16:07:30 DEBUG : pacer: Reducing sleep to 2m51s
2021/02/18 16:12:34 DEBUG : pacer: Reducing sleep to 2m8.25s
2021/02/18 16:15:25 DEBUG : pacer: Reducing sleep to 1m36.1875s
2021/02/18 16:17:33 DEBUG : pacer: Reducing sleep to 1m12.140625s
2021/02/18 16:19:09 DEBUG : pacer: Reducing sleep to 54.10546875s
2021/02/18 16:20:21 DEBUG : pacer: Reducing sleep to 40.579101562s
2021/02/18 16:21:15 DEBUG : pacer: Reducing sleep to 30.434326171s
2021/02/18 16:21:56 DEBUG : pacer: Reducing sleep to 22.825744628s
2021/02/18 16:22:27 DEBUG : pacer: Reducing sleep to 17.119308471s
2021/02/18 16:22:49 DEBUG : pacer: Reducing sleep to 12.839481353s
2021/02/18 16:23:06 DEBUG : pacer: Reducing sleep to 9.629611014s
2021/02/18 16:23:19 DEBUG : pacer: Reducing sleep to 7.22220826s
2021/02/18 16:23:29 DEBUG : pacer: Reducing sleep to 5.416656195s
2021/02/18 16:23:36 DEBUG : pacer: Reducing sleep to 4.062492146s
2021/02/18 16:23:42 DEBUG : pacer: Reducing sleep to 3.046869109s
2021/02/18 16:23:46 DEBUG : pacer: Reducing sleep to 2.285151831s
2021/02/18 16:23:49 DEBUG : pacer: Reducing sleep to 1.713863873s
2021/02/18 16:23:51 DEBUG : pacer: Reducing sleep to 1.285397904s
2021/02/18 16:23:53 DEBUG : pacer: Reducing sleep to 964.048428ms
2021/02/18 16:23:54 DEBUG : pacer: Reducing sleep to 723.036321ms
2021/02/18 16:23:55 DEBUG : pacer: Reducing sleep to 542.27724ms
2021/02/18 16:23:56 DEBUG : pacer: Reducing sleep to 406.70793ms
2021/02/18 16:23:56 DEBUG : pacer: Reducing sleep to 305.030947ms
2021/02/18 16:23:56 DEBUG : pacer: Reducing sleep to 228.77321ms
2021/02/18 16:23:57 DEBUG : pacer: Reducing sleep to 171.579907ms
2021/02/18 16:23:57 DEBUG : pacer: Reducing sleep to 128.68493ms
2021/02/18 16:23:57 DEBUG : pacer: Reducing sleep to 96.513697ms
2021/02/18 16:23:57 DEBUG : pacer: Reducing sleep to 72.385272ms
2021/02/18 16:23:57 DEBUG : pacer: Reducing sleep to 54.288954ms
2021/02/18 16:23:58 DEBUG : pacer: Reducing sleep to 40.716715ms
2021/02/18 16:23:58 DEBUG : pacer: Reducing sleep to 30.537536ms
2021/02/18 16:23:58 DEBUG : pacer: Reducing sleep to 22.903152ms
2021/02/18 16:23:58 DEBUG : pacer: Reducing sleep to 17.177364ms
2021/02/18 16:23:58 DEBUG : pacer: Reducing sleep to 12.883023ms
2021/02/18 16:23:58 DEBUG : pacer: Reducing sleep to 10ms
2021/02/18 16:26:42 DEBUG : sharepoint: Loaded invalid token from config file - ignoring
2021/02/18 16:26:43 DEBUG : sharepoint: Saved new token in config file
2021/02/18 16:34:33 DEBUG : pacer: low level retry 1/10 (error serviceNotAvailable: Service unavailable)
<...>