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