Onedrive 503 response Retry-After not used?

What is the problem you are having with rclone?

Trying to use rclone with onedrive but get 503 responses sometimes. I used --dump headers and I can see 503 Service not available responses coming back occasionally with the Retry-After value in the response header with values in the 20+ seconds. However, rclone doesn't seem to use this retry time and quickly burns through the low level backoff time up to 2 seconds. I can't find any way to tune the backoff behavior / retry behavior. Since the 503 is providing a Retry-After value similar to 429, I was hoping the 503 would be handled in a similar manner.

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

rclone v1.68.1

  • os/version: ubuntu 20.04 (64 bit)
  • os/kernel: 5.15.0-1073-azure (x86_64)
  • os/type: linux
  • os/arch: amd64
  • go/version: go1.23.1
  • go/linking: static
  • go/tags: none

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

Onedrive

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

rclone --checkers 1 --max-depth 1 --onedrive-list-chunk 500 --retries-sleep 30s --retries 4 --tpslimit 20 --log-file rclone.log --dump headers ls MyDrive:MySubfolder

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

[MyDrive]
type = onedrive
token = XXX
drive_id = XXX
drive_type = business

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

2024/10/02 16:16:14 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/10/02 16:16:14 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2024/10/02 16:16:14 DEBUG : HTTP REQUEST (req 0xc000b5ef00)
2024/10/02 16:16:14 DEBUG : GET /v1.0/drives/b!  REDACT  MDQ HTTP/1.1
Host: graph.microsoft.com
User-Agent: rclone/v1.68.1
Authorization: XXXX
Accept-Encoding: gzip

2024/10/02 16:16:14 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2024/10/02 16:16:20 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/10/02 16:16:20 DEBUG : HTTP RESPONSE (req 0xc000b5ef00)
2024/10/02 16:16:20 DEBUG : HTTP/2.0 200 OK
Cache-Control: no-store, no-cache
Client-Request-Id: ce9bfce2-b0f8-46b0-8a4c-1c7086093e70
Content-Type: application/json; odata.metadata=minimal; odata.streaming=true; IEEE754Compatible=false; charset=utf-8
Date: Wed, 02 Oct 2024 16:16:19 GMT
Request-Id: ce9bfce2-b0f8-46b0-8a4c-1c7086093e70
Strict-Transport-Security: max-age=31536000
X-Ms-Ags-Diagnostic: {"ServerInfo":{"DataCenter":"East US","Slice":"E","Ring":"5","ScaleUnit":"001","RoleInstance":"MN1PEPF000116AB"}}

2024/10/02 16:16:20 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/10/02 16:16:20 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2024/10/02 16:16:20 DEBUG : HTTP REQUEST (req 0xc000b5e280)
2024/10/02 16:16:20 DEBUG : GET /v1.0/drives/b! REDACT HTTP/1.1
Host: graph.microsoft.com
User-Agent: rclone/v1.68.1
Authorization: XXXX
Accept-Encoding: gzip

2024/10/02 16:16:20 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2024/10/02 16:16:20 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/10/02 16:16:20 DEBUG : HTTP RESPONSE (req 0xc000b5e280)
2024/10/02 16:16:20 DEBUG : HTTP/2.0 503 Service Unavailable
Cache-Control: private
Client-Request-Id: ae91404d-262b-4dd7-b1b6-def03f24d560
Content-Type: application/json; charset=utf-8
Date: Wed, 02 Oct 2024 16:16:19 GMT
Request-Id: ae91404d-262b-4dd7-b1b6-def03f24d560
Retry-After: 29
Strict-Transport-Security: max-age=31536000
Vary: Accept-Encoding
X-Ms-Ags-Diagnostic: {"ServerInfo":{"DataCenter":"East US","Slice":"E","Ring":"5","ScaleUnit":"001","RoleInstance":"MN1PEPF000116AB"}}

2024/10/02 16:16:20 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/10/02 16:16:20 DEBUG : pacer: low level retry 1/10 (error serviceNotAvailable: Service unavailable)
2024/10/02 16:16:20 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2024/10/02 16:16:20 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2024/10/02 16:16:20 DEBUG : HTTP REQUEST (req 0xc000c123c0)
2024/10/02 16:16:20 DEBUG : GET /v1.0/drives/b!  REDACT   HTTP/1.1
Host: graph.microsoft.com
User-Agent: rclone/v1.68.1
Authorization: XXXX
Accept-Encoding: gzip

2024/10/02 16:16:20 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2024/10/02 16:16:20 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/10/02 16:16:20 DEBUG : HTTP RESPONSE (req 0xc000c123c0)
2024/10/02 16:16:20 DEBUG : HTTP/2.0 503 Service Unavailable
Cache-Control: private
Client-Request-Id: 124679ee-c21b-4147-907e-14e7c5358fbe
Content-Type: application/json; charset=utf-8
Date: Wed, 02 Oct 2024 16:16:19 GMT
Request-Id: 124679ee-c21b-4147-907e-14e7c5358fbe
Retry-After: 23
Strict-Transport-Security: max-age=31536000
Vary: Accept-Encoding
X-Ms-Ags-Diagnostic: {"ServerInfo":{"DataCenter":"East US","Slice":"E","Ring":"5","ScaleUnit":"001","RoleInstance":"MN1PEPF000116AB"}}

2024/10/02 16:16:20 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/10/02 16:16:20 DEBUG : pacer: low level retry 2/10 (error serviceNotAvailable: Service unavailable)
2024/10/02 16:16:20 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2024/10/02 16:16:20 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
eventually....
2024/10/02 16:16:25 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2024/10/02 16:16:25 DEBUG : pacer: low level retry 10/10 (error serviceNotAvailable: Service unavailable)
2024/10/02 16:16:25 ERROR : : error listing: couldn't list files: serviceNotAvailable: Service unavailable
2024/10/02 16:16:25 DEBUG : 7 go routines active
2024/10/02 16:16:25 NOTICE: Failed to ls with 2 errors: last error was: couldn't list files: serviceNotAvailable: Service unavailable



Well spotted.

We do check for Retry-After headers but only on 429 errors.

A read of the docs indicates we should be checking on 503 errors too!

Please give this a go

v1.69.0-beta.8356.c02c3c013.fix-onedrive-retry-after on branch fix-onedrive-retry-after (uploaded in 15-30 mins)

This should hopefully help a lot with onedrive throttling which has been bothering rclone users for some time.

1 Like

Ok, I'll give it a try as soon as I can.

Nick, Wow, thank you for an amazing quick response!!! Thank you.

@dec - Thank you for investigating it and suggesting solution!

And of course thank you @ncw for implementing it immediately.

I will be one among many OneDrive users happy:) I have already put it into use. So far all looks perfect.

1 Like

Any plans to merge it to main (and release in v1.69)?

My testing is ok so far. @jcastill (forum onedrive expert:)) also reported no issues

1 Like

I can confirm no issues in my mounts and sync with no errors or running into any issues. I feel it's safe to merge and consider it for next release.

Thanks for testing everyone

I've merged this to master now which means it will be in the latest beta in 15-30 minutes and released in v1.69

2 Likes

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.