search

rclone / rclone

"rsync for cloud storage" - Google Drive, S3, Dropbox, Backblaze B2, One Drive, Swift, Hubic, Wasabi, Google Cloud Storage, Azure Blob, Azure Files, Yandex Files
https://rclone.org
MIT License
47.25k stars 4.23k forks source link

Rclone stop or stuck upload copy using onedrive #4176

Open acdcjavier opened 4 years ago

acdcjavier commented 4 years ago

Hello I'm using rclone installed into raspberry pi 4 4GB and i'm trying to copy larges files (above 5 GB) into my onedrive student account.

The problem is that sometimes the upload stops or stuck and didn't copy the contents. When the upload arrives about 170Mb, it stops and sometimes continues but slowly

I upload an image when it stops the upload

https://ibb.co/yXhNVT1

My rclone version is:

rclone v1.51.0

darthShadow commented 4 years ago

Please add the debug logs that were requested when you opened the issue.

acdcjavier commented 4 years ago

Please add the debug logs that were requested when you opened the issue.

I can't take logs because rclone "keep" transfer and I can't stop it using CRTL + C It keeps similar to a loop transfer

https://ibb.co/TT2R0Mc

darthShadow commented 4 years ago

https://rclone.org/docs/#log-file-file

acdcjavier commented 4 years ago

Sorry my late posting Here's the log

I don't know what is pacer

2020/05/05 01:26:47 DEBUG : 9 go routines active
2020/05/05 01:26:47 DEBUG : rclone: Version "v1.51.0" finishing with parameters ["rclone" "copy" "/media/pi/My Passport/ACDC/15GB" "OD:ACDC/Video/15GB" "-P" "--ignore-existing" "-vv" "--log-file=test.txt"]
2020/05/05 01:27:18 DEBUG : rclone: Version "v1.51.0" starting with parameters ["rclone" "copy" "/media/pi/My Passport/ACDC/Video" "OD:ACDC/Video/" "-P" "--ignore-existing" "-vv" "--log-file=test.txt"]
2020/05/05 01:27:18 DEBUG : Using config file from "/home/pi/.config/rclone/rclone.conf"
2020/05/05 01:27:20 DEBUG : Too many requests. Trying again in 120 seconds.
2020/05/05 01:27:20 DEBUG : pacer: low level retry 1/10 (error activityLimitReached: The request has been throttled)
2020/05/05 01:27:20 DEBUG : pacer: Rate limited, increasing sleep to 2m0s
2020/05/05 01:27:20 DEBUG : pacer: Reducing sleep to 1m30s
2020/05/05 01:29:21 DEBUG : pacer: Reducing sleep to 1m7.5s
2020/05/05 01:30:53 DEBUG : pacer: Reducing sleep to 50.625s
2020/05/05 01:30:53 DEBUG : 1991-03-28 - Palais Omnisports De Paris, Paris, France [3-DVD Master][Stage Left Recording].tar.zst: Destination exists, skipping
2020/05/05 01:30:53 DEBUG : 2008-11-13 - Madison Square Garden, New York, NY, USA [1-DVD][Multisources].tar.lz4: Destination exists, skipping
2020/05/05 01:30:53 DEBUG : 2009-03-09 - KoPi Arena, Oberhausen, Germany [2-DVD][Stage Right Recording][Jean Philippe Source].tar.zst: Destination exists, skipping
2020/05/05 01:30:53 DEBUG : 1996-06-02 - EOC, Aberdeen, Scotland [3-DVD][stage left from the floor][Authored by Davod25-Trasnfer by Stephan].tar.lz4: Destination exists, skipping
2020/05/05 01:30:53 DEBUG : 2010-03-02 - Adelaide Oval, Adelaide, Australia [2-DVD][Far Left Stage Recording][Jean Philippe Source].tar.zst: Destination exists, skipping
2020/05/05 01:30:53 DEBUG : 2000-10-14 - Flanders Expo, Ghent, Belgium [2-DVD][Authored by davod25].tar.lz4: Destination exists, skipping
2020/05/05 01:30:53 DEBUG : 2010-05-22- Air Field (Flugplatz Wels), Wels, Austria [2-DVD][Floor Stage Left Recording][Thumraider taper].tar.lz4: Destination exists, skipping
2020/05/05 01:30:53 DEBUG : 2010-06-22 - Olympiastadion, Berlin, Germany.tar.zst: Destination exists, skipping
2020/05/05 01:30:53 INFO  : One drive root 'ACDC/Video': Waiting for checks to finish
2020/05/05 01:30:53 DEBUG : 2015-07-12 - Veltins-Arena, Gelsenkirchen, Germany.tar.zst: Destination exists, skipping
2020/05/05 01:30:53 DEBUG : 2016-02-11 - Fargodome, Fargo, ND, USA [1-DVDDL][Stage right][bignate film].tar.zst: Destination exists, skipping
2020/05/05 01:30:53 INFO  : One drive root 'ACDC/Video': Waiting for transfers to finish
2020/05/05 01:30:53 DEBUG : 1991-08-10 - Gentofte Stadion, Copenhagen, Denmark [2-DVD][Far Stage Right recording][From Master].tar.zst: Starting multipart upload
2020/05/05 01:30:53 DEBUG : 2010-06-15 - Parc des Sports Charles Ehrmann, Nice, France [AVi Files][DV Transfer].tar.lz4: Starting multipart upload
2020/05/05 01:32:00 DEBUG : pacer: Reducing sleep to 37.96875s
2020/05/05 01:32:00 DEBUG : 1991-08-10 - Gentofte Stadion, Copenhagen, Denmark [2-DVD][Far Stage Right recording][From Master].tar.zst: Uploading segment 0/6625713449 size 10485760
2020/05/05 01:32:50 DEBUG : pacer: Reducing sleep to 28.4765625s
2020/05/05 01:32:50 DEBUG : 2010-06-15 - Parc des Sports Charles Ehrmann, Nice, France [AVi Files][DV Transfer].tar.lz4: Uploading segment 0/5413396159 size 10485760
2020/05/05 01:33:34 DEBUG : pacer: Reducing sleep to 21.357421875s
2020/05/05 01:33:34 DEBUG : 1991-08-10 - Gentofte Stadion, Copenhagen, Denmark [2-DVD][Far Stage Right recording][From Master].tar.zst: Uploading segment 10485760/6625713449 size 10485760
2020/05/05 01:34:00 DEBUG : pacer: Reducing sleep to 16.018066406s
2020/05/05 01:34:00 DEBUG : 2010-06-15 - Parc des Sports Charles Ehrmann, Nice, France [AVi Files][DV Transfer].tar.lz4: Uploading segment 10485760/5413396159 size 10485760
2020/05/05 01:34:21 DEBUG : pacer: Reducing sleep to 12.013549804s
2020/05/05 01:34:21 DEBUG : 1991-08-10 - Gentofte Stadion, Copenhagen, Denmark [2-DVD][Far Stage Right recording][From Master].tar.zst: Uploading segment 20971520/6625713449 size 10485760
2020/05/05 01:34:37 DEBUG : pacer: Reducing sleep to 9.010162353s
2020/05/05 01:34:37 DEBUG : 2010-06-15 - Parc des Sports Charles Ehrmann, Nice, France [AVi Files][DV Transfer].tar.lz4: Uploading segment 20971520/5413396159 size 10485760
2020/05/05 01:35:00 DEBUG : pacer: Reducing sleep to 6.757621764s
2020/05/05 01:35:00 DEBUG : 2010-06-15 - Parc des Sports Charles Ehrmann, Nice, France [AVi Files][DV Transfer].tar.lz4: Uploading segment 31457280/5413396159 size 10485760
2020/05/05 01:35:03 DEBUG : pacer: Reducing sleep to 5.068216323s
2020/05/05 01:35:03 DEBUG : 1991-08-10 - Gentofte Stadion, Copenhagen, Denmark [2-DVD][Far Stage Right recording][From Master].tar.zst: Uploading segment 31457280/6625713449 size 10485760
2020/05/05 01:35:05 DEBUG : pacer: Reducing sleep to 3.801162242s
2020/05/05 01:35:05 DEBUG : 2010-06-15 - Parc des Sports Charles Ehrmann, Nice, France [AVi Files][DV Transfer].tar.lz4: Uploading segment 41943040/5413396159 size 10485760
2020/05/05 01:35:13 DEBUG : pacer: Reducing sleep to 2.850871681s
2020/05/05 01:35:13 DEBUG : 1991-08-10 - Gentofte Stadion, Copenhagen, Denmark [2-DVD][Far Stage Right recording][From Master].tar.zst: Uploading segment 41943040/6625713449 size 10485760
2020/05/05 01:35:21 DEBUG : pacer: Reducing sleep to 2.13815376s
2020/05/05 01:35:21 DEBUG : 1991-08-10 - Gentofte Stadion, Copenhagen, Denmark [2-DVD][Far Stage Right recording][From Master].tar.zst: Uploading segment 52428800/6625713449 size 10485760
2020/05/05 01:35:24 DEBUG : pacer: Reducing sleep to 1.60361532s
2020/05/05 01:35:24 DEBUG : 1991-08-10 - Gentofte Stadion, Copenhagen, Denmark [2-DVD][Far Stage Right recording][From Master].tar.zst: Uploading segment 62914560/6625713449 size 10485760
2020/05/05 01:35:28 DEBUG : pacer: Reducing sleep to 1.20271149s
2020/05/05 01:35:28 DEBUG : 2010-06-15 - Parc des Sports Charles Ehrmann, Nice, France [AVi Files][DV Transfer].tar.lz4: Uploading segment 52428800/5413396159 size 10485760
2020/05/05 01:35:28 DEBUG : pacer: Reducing sleep to 902.033617ms
2020/05/05 01:35:28 DEBUG : 1991-08-10 - Gentofte Stadion, Copenhagen, Denmark [2-DVD][Far Stage Right recording][From Master].tar.zst: Uploading segment 73400320/6625713449 size 10485760
2020/05/05 01:35:33 DEBUG : pacer: Reducing sleep to 676.525212ms
2020/05/05 01:35:33 DEBUG : 1991-08-10 - Gentofte Stadion, Copenhagen, Denmark [2-DVD][Far Stage Right recording][From Master].tar.zst: Uploading segment 83886080/6625713449 size 10485760
2020/05/05 01:35:33 DEBUG : Too many requests. Trying again in 120 seconds.
2020/05/05 01:35:33 DEBUG : pacer: low level retry 1/10 (error activityLimitReached: throttledRequest: The request has been throttled)
2020/05/05 01:35:33 DEBUG : pacer: Rate limited, increasing sleep to 2m0s
2020/05/05 01:35:36 DEBUG : pacer: Reducing sleep to 1m30s
2020/05/05 01:35:36 DEBUG : 2010-06-15 - Parc des Sports Charles Ehrmann, Nice, France [AVi Files][DV Transfer].tar.lz4: Uploading segment 62914560/5413396159 size 10485760
2020/05/05 01:35:50 DEBUG : pacer: Reducing sleep to 1m7.5s
2020/05/05 01:35:50 DEBUG : 1991-08-10 - Gentofte Stadion, Copenhagen, Denmark [2-DVD][Far Stage Right recording][From Master].tar.zst: Uploading segment 94371840/6625713449 size 10485760
2020/05/05 01:37:40 DEBUG : pacer: Reducing sleep to 50.625s
2020/05/05 01:37:40 DEBUG : 2010-06-15 - Parc des Sports Charles Ehrmann, Nice, France [AVi Files][DV Transfer].tar.lz4: Uploading segment 73400320/5413396159 size 10485760
2020/05/05 01:37:53 INFO  : Signal received: interrupt
2020/05/05 01:37:53 DEBUG : 1991-08-10 - Gentofte Stadion, Copenhagen, Denmark [2-DVD][Far Stage Right recording][From Master].tar.zst: Cancelling multipart upload
ncw commented 4 years ago

The problem is that onedrive keeps telling you to slow down as it thinks you are over using the service.

You could try adding --tpslimit 3 which will slow things right down but it might stop onedrive throttling you.

acdcjavier commented 4 years ago

Thanks but the problem still persist, it stops when I goes 120MB transfer

krsche commented 4 years ago

Situation I encountered the same problem. Transferring few, large files does seem to work just fine, but copying lots of files results in heavy throttling from OneDrive (Business) for me. I am trying to copy ~1TB of data (~20000) files from Onedrive (Business) to Dropbox via a Cloud VM.
My initial test run worked just fine with the following command transferring 33GB, 34 files with ~200MB/s:

rclone --checkers=32 --transfers=32 -vvc --log-file=rclone.log --progress copy onedrive:PATH dropbox:PATH

I know, 32 transfers and checkers is bold, correct me if I'm wrong, but that shouldn't result in throttling I find. Using my own client_id and secret of course. Copying the real data however resulted in a few problems. One outlined here # 4139

Problem related to this issue The other one beeing the heavy throttling from OneDrive. Adding --tpslimit=3 seems to work but is just horribly slow. Microsoft gives a couple best-practices for interfacing the API here: https://docs.microsoft.com/de-de/sharepoint/dev/general-development/how-to-avoid-getting-throttled-or-blocked-in-sharepoint-online
One of them beeing that the client should use the Retry-After HTTP-Header. From the log output it seems to me that this is not implemented.

2020/11/11 18:45:08 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2020/11/11 18:45:47 DEBUG : pacer: Reducing sleep to 240ms
2020/11/11 18:45:47 DEBUG : pacer: Reducing sleep to 180ms

@ncw Would using that header be a valid feature-request and improve the situation? Can I measure the HTTP calls made from rclone inherently? Thanks

Cnly commented 3 years ago

@krsche Actually, the Retry-After header is already respected: https://github.com/rclone/rclone/blob/add7a35e5513e3059596ce6aff039a37007c37dd/backend/onedrive/onedrive.go#L445-L446

Together with your other post https://github.com/rclone/rclone/issues/4139#issuecomment-725557270, I'm thinking is there any chance that you're using a (really) old version?

krsche commented 3 years ago

Hey @Cnly , this is interesting. I was using v1.53.2

ivandeex commented 3 years ago

@Cnly

@krsche Actually, the Retry-After header is already respected: Together with your other post #4139 (comment), I'm thinking is there any chance that you're using a (really) old version?

Hey @Cnly , I was using v1.53.2

Cnly commented 3 years ago

Sorry for having taken so long. After re-reading this thread, I'm thinking maybe we can add a mechanism to notify the user that rclone is not actually uploading data but is waiting for a backoff?

@krsche The feature has been implemented in v1.51, so your rclone seems new enough... Another possibility is that Microsoft didn't sent us the Retry-After header at all.

F-TD5X commented 3 years ago

So we have to wait for near a minute to wait OneDrive send us a confirmation or something, then can we do the next upload?

Are there some methods to ignore the waiting and just upload the next chunk till get throttled?

Log ``` $rclone copy test OD:/test -P -vv 2021/05/12 14:12:20 DEBUG : rclone: Version "v1.54.1" starting with parameters ["rclone" "copy" "test" "OD:/test" "-P" "-vv"] 2021/05/12 14:12:20 DEBUG : Creating backend with remote "test" 2021/05/12 14:12:20 DEBUG : Using config file from "/home//.config/rclone/rclone.conf" 2021/05/12 14:12:20 DEBUG : fs cache: adding new entry for parent of "test", "/home//Downloads" 2021/05/12 14:12:20 DEBUG : Creating backend with remote "OD:/test" 2021/05/12 14:12:22 DEBUG : fs cache: renaming cache item "OD:/test" to be canonical "OD:test" 2021-05-12 14:12:23 DEBUG : test: Need to transfer - File not found at Destination 2021-05-12 14:12:23 DEBUG : test: Starting multipart upload 2021-05-12 14:12:27 DEBUG : test: Uploading segment 0/1583026872 size 262144000 2021-05-12 14:13:20 DEBUG : test: Uploading segment 262144000/1583026872 size 262144000 2021-05-12 14:15:23 DEBUG : test: Uploading segment 524288000/1583026872 size 262144000 2021-05-12 14:16:23 DEBUG : test: Uploading segment 786432000/1583026872 size 262144000 2021-05-12 14:18:48 DEBUG : test: Uploading segment 1048576000/1583026872 size 262144000 2021-05-12 14:19:34 DEBUG : test: Uploading segment 1310720000/1583026872 size 262144000 2021-05-12 14:21:16 DEBUG : test: Uploading segment 1572864000/1583026872 size 10162872 2021-05-12 14:21:23 DEBUG : test: QuickXorHash = 293a29c6325666711adf71d0f6edf424a7b91741 OK 2021-05-12 14:21:23 INFO : test: Copied (new) ```

Network Activity:

Network Activity

valschmidt commented 2 years ago

+1 for further review of this.

As far as I can tell, rclone is doing everything it should, but maybe its pacer algorithm, which I don't fully understand, is not well tuned to the throttling characteristics of Sharepoint. Even with --tsplimit=3 the pacer failed to prevent throttling and ends up sleeping for many minutes at a time. The throttle is applied dynamically based on the Sharepoint load, so I'm sure this is not easy, but for now rclone seems too aggressive. It may be that Sharepoint is just not intended for this kind of usage, which would be unfortunate.

olefrost commented 2 years ago

@valschmidt I suggest you create an issue in the rclone forum (https://forum.rclone.org/) so we can investigate and hopefully solve your throttling issue. Please remember to fill out all the information in the help and support template; that is rcone version, config, command line and debug log- it is all needed to understand your situation. It would also be nice to know your OneDrive activity in the 24 hours before executing the command because it sometimes takes 24 hours for OneDrive to cool down from overload/throttling. Feel free to ping me in the forum, my user is "Ole".

Even with --tsplimit=3 the pacer failed to prevent throttling and ends up sleeping for many minutes at a time.

I generally wouldn’t use --tps-limit to avoid OneDrive throttling, I find it better to do a balanced reduction of --transfers and --checkers. You can find additional OneDrive throttling tips in my forum posts: https://forum.rclone.org/search?expanded=true&q=onedrive%20throttling%20%40Ole%20order%3Alatest