As of 9/19ish, Rclone upload to Gdrive incredibly slow, download is fine

faaaaq · September 22, 2022, 11:01pm

What is the problem you are having with rclone?

Uploads via Rclone to my mounted Google Drive are incredibly slow as of sometime on 9/19. Per the -P output in console the speed (almost exactly every time) starts at 20mbit/s, then 10, then 8, then 6, dropping to 1 BIT per second before eventually failing altogether if the file is large enough because it seems Rclone just gives up after a while. Smaller files the speek will bounce around a bit, between 1bit/s and maybe 100kbit/s, but usually running in the bits-per-second range. The transfer does "work" as the drive shows the file at the size that Rclone reported it had transferred. Attempted across three machines and two different networks (two local machines and one remote server in Europe) and all faced the exact same issue. Uploads to Drive via the web UI are fine, and downloads from Drive are fine in all regards, it is just uploading to Drive via Rclone that is slow. Tried setting up brand new OAuth creds and everything, no change. Been running perfectly fine for years till it took a dump on Tuesday. Very odd. Also confirmed I am nowhere near any limits in Gdrive, peak use in the 2 years Ive had it were under 7%. Was running Rclone 1.50 till I started troubleshooting this issue so doesn't seem to be anything related to a given version of Rclone.

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

rclone v1.59.2

os/version: ubuntu 20.04 (64 bit)
os/kernel: 5.19.3-051903-generic (x86_64)
os/type: linux
os/arch: amd64
go/version: go1.18.6
go/linking: static
go/tags: none

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

Google Drive

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

rclone copy "/home/faaaaq/downloads/migrate/Call of the Night - 03.mkv" "/home/faaaaq/gcrypt/Anime/" -P

The rclone config contents with secrets removed.

[gdrive]
type = drive
client_id = 970265983607-l3udpgh9p3uvlao2sv9mm1fm5s5qrre9.apps.googleusercontent.com
client_secret = ###
scope = drive
token = ###
team_drive = 0AJ5H9JWnjxp9Uk9PVA
root_folder_id = 

[gcrypt]
type = crypt
remote = gdrive:/
filename_encryption = standard
directory_name_encryption = true
password = ###
password2 = ###

A log from the command with the `-vv` flag

faaaaq@SCAREY:~$ rclone copy "/home/faaaaq/downloads/migrate/Call of the Night - 03.mkv" "/home/faaaaq/gcrypt/Anime/" -P -vv
2022/09/23 00:43:08 DEBUG : rclone: Version "v1.59.2" starting with parameters ["rclone" "copy" "/home/faaaaq/downloads/migrate/Call of the Night - 03.mkv" "/home/faaaaq/gcrypt/Anime/" "-P" "-vv"]
2022/09/23 00:43:08 DEBUG : Creating backend with remote "/home/faaaaq/downloads/migrate/Call of the Night - 03.mkv"
2022/09/23 00:43:08 DEBUG : Using config file from "/home/faaaaq/.config/rclone/rclone.conf"
2022/09/23 00:43:08 DEBUG : fs cache: adding new entry for parent of "/home/faaaaq/downloads/migrate/Call of the Night - 03.mkv", "/home/faaaaq/downloads/migrate"
2022/09/23 00:43:08 DEBUG : Creating backend with remote "/home/faaaaq/gcrypt/Anime/"
2022-09-23 00:43:10 DEBUG : Call of the Night - 03.mkv: Need to transfer - File not found at Destination
2022-09-23 00:43:10 DEBUG : preAllocate: got error on fallocate, trying combination 1/2: operation not supported
2022-09-23 00:43:10 DEBUG : preAllocate: got error on fallocate, trying combination 2/2: operation not supported
Transferred:       40.027 MiB / 268.046 MiB, 15%, 45 B/s, ETA 8w5d3h50m29s
Transferred:            0 / 1, 0%
Elapsed time:      8m43.5s
Transferring:
 *                    Call of the Night - 03.mkv: 14% /268.046Mi, 42/s, 1565h42m29s

Animosity022 · September 23, 2022, 3:27am

Are you using a mount as well? There is no remote in the copy so I'm guessing you are using a mount.

If so, what's the mount command. Can you share a debug log of the mount? Why not copy directly to the remote?

macvirii · September 23, 2022, 3:06pm

I'm having the same problem, also using mount.
Was using rclone 1.53.1
Updated to 1.59.2
Created brand new credentials.
Nothing worked.

Download speed is good.
Server upload speed is good, so network card is good.
Server memory and processing is about 20% used

Dedicated server on a Finland Datacenter

J_Jordan · September 23, 2022, 8:41pm

Finally ...

I have the same issue since 9/19.

Also using mount on Linux Debian on a headless dedicated server in a Finland Datacenter.
Download works flawless, only the upload seems throttled. Nowhere near any daily GDrive limits.

Uploads from home with Rclone Browser seem to work perfectly.

faaaaq · September 23, 2022, 10:30pm

Yes, I am using a mount. Drive is mounted to /home/faaaaq/gcrypt . For the sake of troubleshooting, I tried the absolute most basic mount,
rclone mount gcrypt: /home/faaaaq/gcrypt
and the exact issue persisted.
I have been having issues getting it to log anything as well, sorry about that. It worked for a short moment then stopped.. If I can get it to start logging again I will post back with the logs.

It is both good and bad to see others with the same issue haha.. I have so far enjoyed Rclone and had zero issues for a LONG time, till sometime between 9/19 and 9/20 (I have been sick all night so not sure exactly when it started).

macvirii · September 23, 2022, 10:42pm

I'm on Hetzner Finland.
as @J_Jordan that might be why... The problem might be on the datacenter.
I can get about 500 kb/s at max.
It is uploading but very slowly.
Honestly, I just opened a ticket at hetzner, let's see if they will do something.
Seeing my daily stats, it really tanked on sep/21 but that was only because alerts started only then.

macvirii · September 23, 2022, 11:52pm

I got results using this script from nebarik: mediscripts-shared/googleapis.sh at main · Nebarik/mediscripts-shared (github.com)
It found a better server to access the googleapis and now everything is working as expected.

faaaaq · September 24, 2022, 3:27am

I can try that, but my issue is identical whether I use a local (Wisconsin, USA) Windows machine, a local Ubuntu machine, or a remote (also Hetzner) Ubuntu machine. In all three cases the reported speed by Rclone starts high, but immediately drops to 20mb, 10mb, 8, 6, 4, 2, etc etc, almost always in those exact increments. I currently have a transfer running, via rclone copy, of a 5.9gb file. It has been running for 4 hours and 40 minutes, has transferred 16%, and is currently running at between 20Ki/s and 5 bits per second. Waiting for it to fail outright so I can see if the log shows any error.
This is how the log started:

2022/09/24 00:43:53 DEBUG : Creating backend with remote "gcrypt:"
2022/09/24 00:43:53 DEBUG : Using config file from "/home/faaaaq/.config/rclone/rclone.conf"
2022/09/24 00:43:53 DEBUG : Creating backend with remote "gdrive:/"
2022/09/24 00:43:53 DEBUG : fs cache: renaming cache item "gdrive:/" to be canonical "gdrive:"
2022/09/24 00:43:53 DEBUG : Encrypted drive 'gcrypt:': Mounting on "/home/faaaaq/temp2"
2022/09/24 00:43:53 DEBUG : : Root: 
2022/09/24 00:43:53 DEBUG : : >Root: node=/, err=<nil>
2022/09/24 00:44:15 DEBUG : /: Attr: 
2022/09/24 00:44:15 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2022/09/24 00:44:37 DEBUG : /: Attr: 
2022/09/24 00:44:37 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2022/09/24 00:44:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 00:45:12 DEBUG : /: Attr: 
2022/09/24 00:45:12 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2022/09/24 00:45:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 00:46:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 00:47:01 DEBUG : /: Attr: 
2022/09/24 00:47:01 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2022/09/24 00:47:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 00:48:38 DEBUG : /: Attr: 
2022/09/24 00:48:38 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2022/09/24 00:48:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 00:49:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 00:50:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 00:51:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 00:52:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 00:53:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 00:54:53 DEBUG : Google drive root '': Checking for changes on remote

And since then, the log just shows these messages over and over:


2022/09/24 05:00:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:01:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:02:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:03:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:04:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:05:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:06:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:07:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:08:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:09:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:10:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:11:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:12:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:13:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:14:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:15:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:16:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:17:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:17:53 DEBUG : Config file has changed externaly - reloading
2022/09/24 05:17:53 DEBUG : gdrive: Loaded fresh token from config file
2022/09/24 05:18:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:19:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:20:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:21:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:22:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:23:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:24:53 DEBUG : Google drive root '': Checking for changes on remote
2022/09/24 05:25:47 DEBUG : /: Attr: 
2022/09/24 05:25:47 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>

So, logs aren't much help so far

Friday13th · September 24, 2022, 7:49pm

Same issue here with hetzner finland.
This is only happening while using the ipv6 network. So if you have a ipv4 address you can try running rclone with --bind and the server IP or by (temporarily) disabling the ipv6 completely

sudo sysctl -w net.ipv6.conf.all.disable_ipv6=1
sudo sysctl -w net.ipv6.conf.default.disable_ipv6=1

faaaaq · September 24, 2022, 11:33pm

You are the MAN (or woman, or whatever), wow. Thank you, that absolutely fixed the issue... Is there any issue forcing rclone to permanently mind to my IP instead of going thru ipv6? if not I will just run it like that from now on.

J_Jordan · September 25, 2022, 1:07pm

Thanks for this answer ... it works indeed !
IPv4 is the way to go.

probablysomeone · September 25, 2022, 10:54pm

Same issue and same fix, thanks!

delamoe · September 28, 2022, 2:01am

Thank you Friday,

--bind "${ipv4_address}" fixes the slow transfer for me as well.

Funny thing is; After I remove --bind and run the test again, transfer speeds remain high.

This "feels" like Google is throttling Drive uploads, but after opening a ticket with them, I suspect it is just an bug in the API.

Friday13th · September 28, 2022, 1:15pm

i am pretty sure that this has nothing to do with google.
if you used rclone with the binding to ipv4 and afterwards after the binding command you still have good upload speeds you should first check which connection is basically used then. Most probably you are using ipv4 afterwards as well and you are not directly falling back to ipv6.

system · October 28, 2022, 1:16pm

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