Extremely slow upload speed with OneDrive

What is the problem you are having with rclone?

Hello,
Last night after setting up rclone with OneDrive for business, I had very fast upload speeds (I didn't check what they were, I just know a few large directories (40+ GB) uploaded in less than 2 hrs.) and now I have upload speeds from 600 kBps to 1.9 MBps. Encryption for files, file names, and directories is enabled, but I'm assuming this does not affect upload speed. Uploading from my phone using the client RCX also had poor results.

What is your rclone version (output from rclone version)

rclone v1.55.1-DEV

  • os/type: freebsd
  • os/arch: amd64
  • go/version: go1.17
  • go/linking: dynamic
  • go/tags: none

Note: This is the most up-to-date version from the FreeBSD repository.

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

OneDrive for Business

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

rclone --drive-chunk-size 128M mount --daemon --vfs-cache-mode full onedrive-crypt:/ /home/username/onedrive

The rclone config contents with secrets removed.

[onedrive]
type = onedrive
region = global
token =
drive_id =
drive_type = business

[onedrive-crypt]
type = crypt
remote = onedrive:/
filename_encryption = standard
directory_name_encryption = true
password =
password2 =
server_side_across_configs = false
no_data_encryption = false

A log from the command with the -vv flag

2021/09/05 22:34:17 DEBUG : Creating backend with remote "onedrive-crypt:/"
2021/09/05 22:34:17 DEBUG : Creating backend with remote "onedrive:/"
2021/09/05 22:34:18 DEBUG : fs cache: renaming cache item "onedrive:/" to be canonical "onedrive:"
2021/09/05 22:34:18 DEBUG : fs cache: switching user supplied name "onedrive:/" for canonical name "onedrive:"
2021/09/05 22:34:18 INFO  : Encrypted drive 'onedrive-crypt:/': poll-interval is not supported by this remote
2021/09/05 22:34:18 DEBUG : vfs cache: root is "/home/username/.cache/rclone/vfs/onedrive-crypt"
2021/09/05 22:34:18 DEBUG : vfs cache: metadata root is "/home/username/.cache/rclone/vfs/onedrive-crypt"
2021/09/05 22:34:18 DEBUG : Creating backend with remote "/home/username/.cache/rclone/vfs/onedrive-crypt"

Hi, welcome to the forum,

It sounds like you are being throttled by OneDrive. This typically happens when you suddenly increase your activity - or do extremely large up/downloads.

You can check by looking after "pacer" entries when starting with the -vv flag. The pacer basicly adjusts the speed based on the feedback/responses it gets from OneDrive. You can see an (extreme) example here:

2021/06/26 14:03:00 DEBUG : Too many requests. Trying again in 120296 seconds.
2021/06/26 14:03:00 DEBUG : pacer: low level retry 1/10 (error accessDenied: throttledRequest: Too Many Requests)
2021/06/26 14:03:00 DEBUG : pacer: Rate limited, increasing sleep to 33h24m56s
2021/06/26 14:03:00 DEBUG : pacer: Reducing sleep to 25h3m42s
2021/06/26 14:03:00 DEBUG : pacer: Reducing sleep to 18h47m46.5s
2021/06/26 14:03:00 DEBUG : pacer: Reducing sleep to 14h5m49.875s

and find some experiences and advice here:

and here:

You can read more about throttling here:

How did that happen? That is very odd!

The example is copied from the initial post in this thread:
https://forum.rclone.org/t/rclone-v1-55-1-throttling-and-worse-on-onedrive-copy-to-gd/25018

Yes, the pacing seen in the log is somewhat odd. This is what I see:

rclone receives a http response code 429 (Too many requests) having retry-after=120296 seconds (33h24m56s). It is my understanding that retry-after period as a (minimum) period where the client shouldn't make any requests to avoid further throttling or to get blocked.

The pacer correctly increases the wait time accordingly, however it does immediately start an exponential reduction of the wait time, so the wait time is reduced to 14h5m49.875s (that is halved) within a second. This will make rclone retry to early and then the server responds with a another and much longer retry-after.

The log therefore indicates a possible bug in the way rclone handles http 429 responses that may lead to rapidly escalating throttling issues - ending with retry-after times in hours and days.

This behavior could also explain the experienced importance of staying below the throttling limits at all times.

Do you (or other rcloners) see the same?

I will try to find some time to investigate/reproduce, if you or others can confirm the observation/suspicion.

Setting the user agent to "ISV|rclone.org|rclone/v1.55.1" improved the speed with another upload operation I started to test it. I'll check again after a 15 GiB file finishes uploading; it's taken more than 10 hrs. to get to 90% and I do not want to restart that upload. I'll run another browser upload test to see what the speed is when uploading directly to OneDrive. On the throttled upload, Rclone Browser reports that each file is uploading at 200-300 kBps, with 4 files uploading at a time.

Thanks for the update.

Are you able to post app. 20 lines from a part of the debug log where you experience the slow upload speed? Preferably grep'ed for "pacer". I would like to see how rclone sets/increases/decreases the sleep times.

I can only manage to get logs after my remote has been mounted from the terminal. Rclone Browser doesn't seem to be logging, even with the log flag. The only things in the log are errors about path length.

I created a new remote with an application ID from Active Directory, and there has been no increase in speed.

I just had a look through the code and I can't see anything obviously wrong with it.

I'd love to see a log, preferably with -vv --dump headers of this happening.

Another user here having the same problem. OneDrive for Business throttling my Rclone uploads. I upload with defaults, and Im running rclone 1.54.0 inside a freenas jail. I didnt use it for about 2 years, but last time it was working just fine. My upstream bandwidth is supposed to be 12 Mbits, and rclone uploads reflect that on my router, but after about 10 minutes, then it goes down to 6kbits, it is unusable that way. Im kind of lost and not sure what to do to make it work.

I did refresh the token today. Im not quite sure about the "client id". My uploads are initially working fine, they slow down after a few minutes, is it possible that there is an issue with the 'client id' ? how do I check that?

@DotTest37 Please start a new issue, you are hijacking another discussion!

I thought I came here for "Extremely slow upload speed with OneDrive". Not sure how is that Im highjacking anything. I just said Im having the same problem other people on this thread has.

I just ran rclone config and if I edit my existing onedrive remote I see Im using the proper client id : Value "client_id" = "1ftttff445-c34d-1t55-2b2343-s2354234534634". (edited for obvious reasons)

I finally found pacer in my rclone log file.
2021/09/22 11:07:23 DEBUG : pacer: low level retry 1/10 (error Put "[URL]"
2021/09/22 11:07:23 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2021/09/22 11:07:23 DEBUG : pacer: Rate limited, increasing sleep to 40ms

2021/09/22 11:08:03 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2021/09/22 11:08:03 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2021/09/22 11:08:03 DEBUG : pacer: low level retry 2/10 (error Put "[URL]": dial tcp: lookup [organization].sharepoint.com on [IP address]:53: read udp [IP address]:62035->[IP address]:53: i/o timeout)
2021/09/22 11:08:03 DEBUG : pacer: Rate limited, increasing sleep to 2s
2021/09/22 11:08:17 DEBUG : pacer: Reducing sleep to 1.5s
2021/09/22 11:08:20 DEBUG : pacer: Reducing sleep to 1.125s
2021/09/22 11:08:24 DEBUG : pacer: Reducing sleep to 843.75ms
2021/09/22 11:08:24 DEBUG : pacer: Reducing sleep to 632.8125ms
2021/09/22 11:08:35 DEBUG : pacer: Reducing sleep to 474.609375ms
2021/09/22 11:08:39 DEBUG : pacer: Reducing sleep to 355.957031ms
2021/09/22 11:08:42 DEBUG : pacer: Reducing sleep to 266.967773ms
2021/09/22 11:08:44 DEBUG : pacer: Reducing sleep to 200.225829ms
2021/09/22 11:08:54 DEBUG : pacer: Reducing sleep to 150.169371ms
2021/09/22 11:09:00 DEBUG : pacer: Reducing sleep to 112.627028ms
2021/09/22 11:09:01 DEBUG : pacer: Reducing sleep to 84.470271ms
2021/09/22 11:09:03 DEBUG : pacer: Reducing sleep to 63.352703ms
2021/09/22 11:09:12 DEBUG : pacer: Reducing sleep to 47.514527ms
2021/09/22 11:09:20 DEBUG : pacer: Reducing sleep to 35.635895ms
2021/09/22 11:09:21 DEBUG : pacer: Reducing sleep to 26.726921ms
2021/09/22 11:09:22 DEBUG : pacer: Reducing sleep to 20.04519ms
2021/09/22 11:09:22 DEBUG : pacer: Reducing sleep to 15.033892ms
2021/09/22 11:09:29 DEBUG : pacer: Reducing sleep to 11.275419ms
2021/09/22 11:09:37 DEBUG : pacer: Reducing sleep to 10ms

please post

  • config file, redact id/secret/password/token
  • top lines of a rclone debug log

@NotaNorthKorean

Thanks for reporting back.

This looks like a normal rate reduction after a series of errors (possibly a short network outage). The errors happen in the time span from 11:07:23 to 11:08:17 and then stops. Then rclone gradually increases speed again until full speed at 11:09:37. This happens once in a while and everything is handled as it should.

PS: A careful look reveals that there are no pacing delays after 11:08:17, because the requests happen at longer intervals than the limit set by the rclone pacer.

@ncw @asdffdsa @NotaNorthKorean

I have managed to reproduce the above mentioned issue where a HTTP 429 with Retry-After above 2 seconds results in somewhat random behavior during back-off and the following resuming of speed. I have a working fix and is now refining the code to further improve the handling of the outer ends of pacing, that is throttling and bursts - for all REST API backends and OneDrive specifically.

I am aiming to get something ready for review/discussion later this week - I may well be too optimistic.

The config file is the same as in my first post in this thread. My log file is over 3 GB, and the top lines of it are from a few days before pacer was in the file.

ok. after the 19 days, just wanted to be sure that the config and rclone command have not changed from your first post in this thread.

I believe uploads to OneDrive have been faster over the past few weeks; I'll need to check if that is in fact the case