Dropbox rate limiting for upload

Any idea on the issue here?

This is a network error. Maybe Dropbox cut you off, but it could be anything in between like your router or your ISP.

Does your ISP limit traffic? Can you try a different one or a VPN?

Interesting. I've just uploaded a few large files to Google Drive without issues -- I don't think my broadband provider is limiting me. I suspect it's Dropbox resetting the connection - could this be a new type of rate limiting for relatively large files?

Is it possible to make rclone not reset the whole file upload when Dropbox does this?

That's unlikely.

No, they document limits and such very well.

No. You want resumable uploads. There already is a feature request for that.

Issue seems local to your setup.

As a test exercise, I tried to copy some large files from Google Drive to Dropbox, i.e. from one remote to another remote. The transfer also got reset. Can I conclude based on that, that my local ISP connection is not the reason for the reset?

Do they actually? Could you please send the link on the limits? I thought they don't make the limits public so users can't abuse, no?

Any idea what maybe the issue here?

Seems likely.

Dropbox File Size Limit | How Much Can I Upload? | Dropbox Help

They don't release API limits as that's not related to upload/download limits which they share.

Not offhand. Try rebooting, checking cables, IT 101 stuff and maybe complain to your ISP.

Already checked and rebooted :slight_smile:

The fact that exactly the same files (same size) succeeds for Google Drive and not Dropbox suggests Google servers are more stable and not loosing connection?

Looking back through your log with fresh eyes, I think this is a bug in rclone...

First rclone gets an error on a chunk

Whether that is dropbox, or your ISP or whatever, it doesn't matter. Rclone then retries that chunk, however it gets a different error in return

That error means that the offset rclone is sending data from is not the offset dropbox is expecting to receive:

I had a go at fixing this here - rclone will shift its offset to match the offset received in the error message.

v1.59.0-beta.6038.131e00ad1.fix-dropbox-retry on branch fix-dropbox-retry (uploaded in 15-30 mins)

Can you give it a go with -vv and look through the logs for the low level retries. Hopefully you will see the incorrect_offset error being retried with the correct offset and everything will work properly!

This is a complicated little patch with lots of boundary conditions - I did my best to test it using error injection but there could still be problems with it.

Hey Nick, thanks so much. I will be able to test it in 2-3 hours. I will post the results here.

Got the same initial issue in the log, but no subsequent offset issues and most importantly the file has not reset to 0% while uploading, but carried on uploading. I will wait until the whole file uploads, but this looks very promising. Thanks Nick.

Partial log:
2022-03-21 13:55:12 DEBUG : 2df1jur4oaudnpol0jj8iqoukse3dh8sq3hujpksp1j6s32qnot0: Uploading chunk 65/171
2022-03-21 13:55:27 DEBUG : pacer: low level retry 1/10 (error Post "https://content.dropboxapi.com/2/files/upload_session/append_v2": read tcp 5.0.0.9:51704->162.125.65.14:443: read: connection reset by peer)
2022-03-21 13:55:27 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2022-03-21 13:55:35 DEBUG : rd92nop3827pt1o59objvm8868fpss3v9g62q7j1o85197s77qh0: incorrect offset error receved: sent 2818572288, need 2868903936, skip 50331648: chunk received OK - continuing
2022-03-21 13:55:35 DEBUG : pacer: Reducing sleep to 15ms
2022-03-21 13:55:35 DEBUG : rd92nop3827pt1o59objvm8868fpss3v9g62q7j1o85197s77qh0: Uploading chunk 58/171

That looks like it is working as intended :smiley:

Let me know how the whole upload turns out.

Hi NIck, all files uploaded successfully. Thanks so much for the fix.

It's actually nice to realise such an incredible piece of software is developed in the UK. Nick, if you based in London, I am happy to catch up in person and buy you a pint or two. Let me know.

Thank you for testing.

I've merged this to master now which means it will be in the latest beta in 15-30 minutes and released in v1.59. I'll stick it in v1.58.1 when that gets released too.

Thank you for the offer :slight_smile: I'm based in Guildford which is not too far away from London but I don't get to London very often now-a-days alas.

Hi Nick,
I am not sure I need to raise a new topic for this. I noticed some of the new files failed to upload with the version you provided:
rclone v1.59.0-beta.6038.131e00ad1.fix-dropbox-retry

  • os/version: darwin 12.3.1 (64 bit)
  • os/kernel: 21.4.0 (x86_64)
  • os/type: darwin
  • os/arch: amd64
  • go/version: go1.18
  • go/linking: dynamic
  • go/tags: cmount

with this message:
2022-04-11 12:03:30 ERROR : 6b45619d2d92vbch2piq9o9tpo9e76hlc4nolk3gt38jhg9k33l0: Failed to copy: upload failed: can't seek backwards to correct offset: incorrect offset error receved: sent 1157627904, need 1157611520, skip -16384
2022-04-11 12:03:30 ERROR : 6b45619d2d92vbch2piq9o9tpo9e76hlc4nolk3gt38jhg9k33l0: Not deleting source as copy failed: upload failed: can't seek backwards to correct offset: incorrect offset error receved: sent 1157627904, need 1157611520, skip -16384

is this something related to the original issue and the fix?

Hmm interesting...

I'd like to see a complete log with -vv of that happening if possible.

That means, I think, that dropbox accepted the previous block, rclone moved on, but then said it is missing the last 16k of the block. Rclone doesn't have the previous block at this point, hence the error.

Yes it is.

This fixed is merged to the beta now, so if you could try the latest beta with -vv and see if you can reproduce, I'd be very interested to see the log.

Thanks

sure, will test it and comeback. Is this the latest beta?
v1.59.0-beta.6065.27176cc6b

Hi Nick, the log is below. I cut it because it's very long, as it happens usually towards the middle of the file upload. I have set --transfers=2 as with --transfers=1 I couldn't reproduce the issue -- maybe I didn't wait long enough.

u0nbo7hqvh7842kjk7om83s68epmqct -- is the file name that is being uploaded. All other files with longer names are chunks.

2022/04/11 18:46:46 DEBUG : rclone: Version "v1.59.0-beta.6065.27176cc6b" starting with parameters ["rclone" "copy" "bluray_backup" "dropbox:bluray_backup" "--progress" "-vv" "--transfers=2"]
2022/04/11 18:46:46 DEBUG : Creating backend with remote "bluray_backup"
2022/04/11 18:46:46 DEBUG : Using config file from "/Users/mike/.config/rclone/rclone.conf"
2022/04/11 18:46:46 DEBUG : fs cache: renaming cache item "bluray_backup" to be canonical "/Volume/bluray/bluray_backup"
2022/04/11 18:46:46 DEBUG : Creating backend with remote "dropbox:bluray_backup"
2022/04/11 18:46:47 DEBUG : Dropbox root '': Using root namespace "..."
2022-04-11 19:08:20 DEBUG : m3ui35nncn13lt09p87c0ehtrqbld8j8nn83oskg2mccj690vnug: Uploading chunk 138/171
2022-04-11 19:08:21 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 143/171
2022-04-11 19:08:22 DEBUG : m3ui35nncn13lt09p87c0ehtrqbld8j8nn83oskg2mccj690vnug: Uploading chunk 139/171
2022-04-11 19:08:24 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 144/171
2022-04-11 19:08:26 DEBUG : m3ui35nncn13lt09p87c0ehtrqbld8j8nn83oskg2mccj690vnug: Uploading chunk 140/171
2022-04-11 19:08:28 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 145/171
2022-04-11 19:08:28 DEBUG : m3ui35nncn13lt09p87c0ehtrqbld8j8nn83oskg2mccj690vnug: Uploading chunk 141/171
2022-04-11 19:08:32 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 146/171
2022-04-11 19:08:32 DEBUG : m3ui35nncn13lt09p87c0ehtrqbld8j8nn83oskg2mccj690vnug: Uploading chunk 142/171
2022-04-11 19:08:35 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 147/171
2022-04-11 19:08:36 DEBUG : m3ui35nncn13lt09p87c0ehtrqbld8j8nn83oskg2mccj690vnug: Uploading chunk 143/171
2022-04-11 19:08:39 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 148/171

...

2022-04-11 19:08:11 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 141/171
2022-04-11 19:08:15 DEBUG : m3ui35nncn13lt09p87c0ehtrqbld8j8nn83oskg2mccj690vnug: Uploading chunk 137/171
2022-04-11 19:08:17 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 142/171
2022-04-11 19:08:20 DEBUG : m3ui35nncn13lt09p87c0ehtrqbld8j8nn83oskg2mccj690vnug: Uploading chunk 138/171
2022-04-11 19:08:21 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 143/171
2022-04-11 19:08:22 DEBUG : m3ui35nncn13lt09p87c0ehtrqbld8j8nn83oskg2mccj690vnug: Uploading chunk 139/171
2022-04-11 19:08:24 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 144/171
2022-04-11 19:08:26 DEBUG : m3ui35nncn13lt09p87c0ehtrqbld8j8nn83oskg2mccj690vnug: Uploading chunk 140/171
2022-04-11 19:08:28 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 145/171
2022-04-11 19:08:28 DEBUG : m3ui35nncn13lt09p87c0ehtrqbld8j8nn83oskg2mccj690vnug: Uploading chunk 141/171
2022-04-11 19:08:32 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 146/171
2022-04-11 19:08:32 DEBUG : m3ui35nncn13lt09p87c0ehtrqbld8j8nn83oskg2mccj690vnug: Uploading chunk 142/171
2022-04-11 19:08:35 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 147/171
2022-04-11 19:08:36 DEBUG : m3ui35nncn13lt09p87c0ehtrqbld8j8nn83oskg2mccj690vnug: Uploading chunk 143/171
2022-04-11 19:08:39 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 148/171
2022-04-11 19:08:39 DEBUG : m3ui35nncn13lt09p87c0ehtrqbld8j8nn83oskg2mccj690vnug: Uploading chunk 144/171
2022-04-11 19:08:42 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 149/171
2022-04-11 19:08:44 DEBUG : m3ui35nncn13lt09p87c0ehtrqbld8j8nn83oskg2mccj690vnug: Uploading chunk 145/171
2022-04-11 19:08:46 DEBUG : m3ui35nncn13lt09p87c0ehtrqbld8j8nn83oskg2mccj690vnug: Uploading chunk 146/171
2022-04-11 19:08:48 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 150/171
2022-04-11 19:08:50 DEBUG : m3ui35nncn13lt09p87c0ehtrqbld8j8nn83oskg2mccj690vnug: Uploading chunk 147/171
2022-04-11 19:08:50 DEBUG : pacer: low level retry 1/10 (error )
2022-04-11 19:08:50 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2022-04-11 19:08:51 DEBUG : pacer: Reducing sleep to 15ms
2022-04-11 19:08:51 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 151/171
2022-04-11 19:08:53 DEBUG : pacer: Reducing sleep to 11.25ms
2022-04-11 19:08:53 DEBUG : m3ui35nncn13lt09p87c0ehtrqbld8j8nn83oskg2mccj690vnug: Uploading chunk 148/171
2022-04-11 19:08:54 DEBUG : pacer: Reducing sleep to 10ms
2022-04-11 19:08:54 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 152/171
2022-04-11 19:08:56 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 153/171
2022-04-11 19:09:00 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 154/171
2022-04-11 19:09:03 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 155/171
2022-04-11 19:09:05 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 156/171
2022-04-11 19:09:09 ERROR : u0nbo7hqvh7842kjk7om83s68epmqct: Failed to copy: upload failed: can't seek backwards to correct offset: incorrect offset error receved: sent 7398752256, need 7398735872, skip -16384
2022-04-11 19:09:09 ERROR : u0nbo7hqvh7842kjk7om83s68epmqct: Not deleting source as copy failed: upload failed: can't seek backwards to correct offset: incorrect offset error receved: sent 7398752256, need 7398735872, skip -16384
2022-04-11 19:09:09 DEBUG : l3js9r7r7ju7nllku03nj49h6m3bcvc: skip slow MD5 on source file, hashing in-transit
2022-04-11 19:09:09 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 157/171
2022-04-11 19:09:10 DEBUG : o0h429kag3t48ut3ei0ncvmd1ra88iucg54mpcmtd5u6vf3ijgf0: Uploading chunk 1/171
2022-04-11 19:09:13 DEBUG : 29s214quvqn38k2t220fo95pb6fo83ssmuc6ja4fdsl7kjkhmr1g: Uploading chunk 158/171
2022-04-11 19:09:13 DEBUG : o0h429kag3t48ut3ei0ncvmd1ra88iucg54mpcmtd5u6vf3ijgf0: Uploading chunk 2/171

I really need to see the whole log. Can you email it to me nick@craig-wood.com or share it to me there? Thanks