Plans to resolve Google Drive 403?

ncw · July 14, 2017, 12:42am

I have realised I have made an error - if you set the interval to below 1s it will cap it at 1s.

Will post a new beta when I’ve worked out how to fix it!

ncw · July 14, 2017, 1:05am

Here is a new beta which will work if you set the limit to under 1s, and also defaults to the limiter being off.

https://pub.rclone.org/v1.36-251-g0b2b4243-tps-limitβ/

I’m afraid you’ll have to re-do your tests if you were using 100ms or 200ms - sorry!

aj1252 · July 14, 2017, 6:51am

Thank started testing the new one now

blc · July 14, 2017, 7:17am

Did some testing with 100ms limit and it seems to be working very nicely. I’m using it together with MediaPortal. It does similar scans like plex.

This very good addition because I can now simplify my setup by getting rid off plexdrive and unionfs-fuse. Thanks!

aj1252 · July 14, 2017, 7:21am

Initial tests looks good:
rclone size against one of my folders, 8000 subfolders, 7770 files, 14 TB

1.36-250-gb5002eb6β
~30 req/sec
5 minutes

No parameters
~30 req/sec
5 minutes

10 ms
~30 req/sec
5 minutes

100 ms
~10 req/sec
13,5 minutes

1 sec
~1 req/sec
Estimated 2 hours

aj1252 · July 14, 2017, 7:57am

Copy new large files Amazon > Google

1.36-250-gb5002eb6β
0-1 req/s
120 MB/s

No parameters
0-1 req/s
120 MB/s

10 ms
0-1 req/s
114 MB/s

100 ms
0-1 req/s
77 MB/s

1 sec
0-1 req/s
6 MB/s

aj1252 · July 14, 2017, 8:22am

Copy checking excisting files Amazon > Google
1800 folders 40000 files

1.36-250-gb5002eb6β
13-17 req/s
1,3 minutes

No parameters
10-20 req/s
1,2 minutes

10 ms
10-20 req/s
1,2 minutes

100 ms
5 req/s
6 minutes

1 sec
0-1 req/s
Estimated 1 hour

aj1252 · July 14, 2017, 8:24am

Looks like 100ms is a sweet spot between performance and API limits.
Testing mount now with 100ms…

aj1252 · July 14, 2017, 8:46am

Mount
Plex scan, Plex playing 1 movie, Sonarr scan and Radarr scan

100 ms
Highest observed: 0,8 req/sec
Time to start movie: 30 seconds

10 ms
Same result

@ncw Looks like the mount is still stuck on 1sec

ncw · July 14, 2017, 1:16pm

Great testing thanks @aj1252. How are you measuring requests/second?

This is how I’ve been doing it. Here is a test I just did with mount

rclone --dump-headers --min-transaction-interval 100ms -vv mount remote:path /mnt/tmp 2>&1 | grep REQUEST

And in another window (to do a directory scan)

find /mnt/tmp -ls

I can see that with 100ms it does 10 requests per second and 500ms it does 2, so I think the limiting is working with mount, eg this for 500ms


2017/07/14 14:09:08 DEBUG : HTTP REQUEST (req 0xc42006a700)
2017/07/14 14:09:08 DEBUG : HTTP REQUEST (req 0xc4204ac800)
2017/07/14 14:09:09 DEBUG : HTTP REQUEST (req 0xc4204aca00)
2017/07/14 14:09:09 DEBUG : HTTP REQUEST (req 0xc420165500)
2017/07/14 14:09:10 DEBUG : HTTP REQUEST (req 0xc420628300)
2017/07/14 14:09:10 DEBUG : HTTP REQUEST (req 0xc4204acd00)
2017/07/14 14:09:11 DEBUG : HTTP REQUEST (req 0xc42028dc00)
2017/07/14 14:09:11 DEBUG : HTTP REQUEST (req 0xc42028de00)
2017/07/14 14:09:12 DEBUG : HTTP REQUEST (req 0xc4204ad100)
2017/07/14 14:09:12 DEBUG : HTTP REQUEST (req 0xc4204ad300)
2017/07/14 14:09:13 DEBUG : HTTP REQUEST (req 0xc420628e00)
2017/07/14 14:09:13 DEBUG : HTTP REQUEST (req 0xc42000ab00)
2017/07/14 14:09:14 DEBUG : HTTP REQUEST (req 0xc420629000)
2017/07/14 14:09:14 DEBUG : HTTP REQUEST (req 0xc42028c000)

where you can see 2 reqests every second.

aj1252 · July 14, 2017, 1:22pm

I’m using Google API Manager (https://console.developers.google.com/apis/api/) to measure, it give you a pretty decent picture of whats going on:

I’ll try dump header and grep the requests

calisro · July 14, 2017, 1:49pm

Just so I am clear. This helps with too many API calls and a 24-hour ban from Plex but it doesn’t help with that initial plex scan where plex ffprobes all the files (essentially downloading them). Is that correct?

aj1252 · July 14, 2017, 2:01pm

Here is my result from a Google Compute instance not running anything.
ls -alR on a folder containing many folders with only a few files.
As you can see I get more than one a second.
The API manager only reported around 1/sec hence why I though it was only 1req/1sec
I looks like it need datapoints over some time to give a more accurate picture.

aj@instance-1:~/rclone-v1.36-251-g0b2b4243-tps-limitβ-linux-amd64$ ./rclone mount --min-transaction-interval 10ms --log-level DEBUG --dump-headers GCE1AJIN: /media/TEST/ 2>&1 | grep REQUEST
2017/07/14 13:40:23 DEBUG : HTTP REQUEST (req 0xc4200fb700)
2017/07/14 13:40:23 DEBUG : HTTP REQUEST (req 0xc4200fbc00)
2017/07/14 13:40:24 DEBUG : HTTP REQUEST (req 0xc4200c1c00)
2017/07/14 13:40:24 DEBUG : HTTP REQUEST (req 0xc420367200)
2017/07/14 13:40:24 DEBUG : HTTP REQUEST (req 0xc420826a00)
2017/07/14 13:40:25 DEBUG : HTTP REQUEST (req 0xc420826d00)
2017/07/14 13:40:25 DEBUG : HTTP REQUEST (req 0xc420367400)
2017/07/14 13:40:25 DEBUG : HTTP REQUEST (req 0xc4200c1e00)
2017/07/14 13:40:26 DEBUG : HTTP REQUEST (req 0xc4200fbe00)
2017/07/14 13:40:26 DEBUG : HTTP REQUEST (req 0xc420826b00)
2017/07/14 13:40:27 DEBUG : HTTP REQUEST (req 0xc420826e00)
2017/07/14 13:40:28 DEBUG : HTTP REQUEST (req 0xc4200c1e00)
2017/07/14 13:40:28 DEBUG : HTTP REQUEST (req 0xc420308a00)
2017/07/14 13:40:29 DEBUG : HTTP REQUEST (req 0xc420308e00)
2017/07/14 13:40:29 DEBUG : HTTP REQUEST (req 0xc420826b00)
2017/07/14 13:40:30 DEBUG : HTTP REQUEST (req 0xc420308b00)
2017/07/14 13:40:30 DEBUG : HTTP REQUEST (req 0xc420308f00)
2017/07/14 13:40:31 DEBUG : HTTP REQUEST (req 0xc420900b00)
2017/07/14 13:40:31 DEBUG : HTTP REQUEST (req 0xc420792100)
2017/07/14 13:40:31 DEBUG : HTTP REQUEST (req 0xc4208aff00)
2017/07/14 13:40:32 DEBUG : HTTP REQUEST (req 0xc420726200)
2017/07/14 13:40:32 DEBUG : HTTP REQUEST (req 0xc420726600)
2017/07/14 13:40:32 DEBUG : HTTP REQUEST (req 0xc420308900)
2017/07/14 13:40:33 DEBUG : HTTP REQUEST (req 0xc420900b00)
2017/07/14 13:40:33 DEBUG : HTTP REQUEST (req 0xc42085ac00)
2017/07/14 13:40:33 DEBUG : HTTP REQUEST (req 0xc420727d00)
2017/07/14 13:40:33 DEBUG : HTTP REQUEST (req 0xc4203dc800)
2017/07/14 13:40:34 DEBUG : HTTP REQUEST (req 0xc42085b800)
2017/07/14 13:40:34 DEBUG : HTTP REQUEST (req 0xc4203dcc00)
2017/07/14 13:40:35 DEBUG : HTTP REQUEST (req 0xc4204be900)
2017/07/14 13:40:35 DEBUG : HTTP REQUEST (req 0xc4204bf300)
2017/07/14 13:40:35 DEBUG : HTTP REQUEST (req 0xc4204bfa00)
2017/07/14 13:40:35 DEBUG : HTTP REQUEST (req 0xc4203dd100)
2017/07/14 13:40:36 DEBUG : HTTP REQUEST (req 0xc420a3c300)
2017/07/14 13:40:37 DEBUG : HTTP REQUEST (req 0xc420727400)
2017/07/14 13:40:37 DEBUG : HTTP REQUEST (req 0xc42085b900)
2017/07/14 13:40:37 DEBUG : HTTP REQUEST (req 0xc420793e00)
2017/07/14 13:40:37 DEBUG : HTTP REQUEST (req 0xc420900c00)
2017/07/14 13:40:38 DEBUG : HTTP REQUEST (req 0xc4203dce00)
2017/07/14 13:40:38 DEBUG : HTTP REQUEST (req 0xc4204bf400)
2017/07/14 13:40:38 DEBUG : HTTP REQUEST (req 0xc42091e600)
2017/07/14 13:40:39 DEBUG : HTTP REQUEST (req 0xc42091fa00)
2017/07/14 13:40:39 DEBUG : HTTP REQUEST (req 0xc4204ce800)
2017/07/14 13:40:39 DEBUG : HTTP REQUEST (req 0xc4204ceb00)
2017/07/14 13:40:40 DEBUG : HTTP REQUEST (req 0xc420762500)
2017/07/14 13:40:40 DEBUG : HTTP REQUEST (req 0xc420900a00)
2017/07/14 13:40:40 DEBUG : HTTP REQUEST (req 0xc420308900)

aj1252 · July 14, 2017, 2:10pm

Only applies to the ban.
From my experience the probing really depends on the file (container, codec or something), some it one checks a few chunks and are happy, other it looks like it downloads the whole file.

ncw · July 14, 2017, 2:59pm

I conjecture it might help with that too as it will rate limit those. An experiment will tell though!

ncw · July 14, 2017, 2:59pm

Good test - thanks. Grepping the REQUEST is a bit crude but it should be accurate.

djsecrist · July 14, 2017, 3:21pm

Good stuff, guys! I am holding off testing the new version since I don’t want to risk a ban heading into the weekend.

aj1252, is it really taking 30 seconds to start a movie playing? Mine are starting in 3-4 seconds for Direct Play and 5-6 for transcodes. What is your typical experience without a min transaction interval? Or using an alternative mounting option?

Here are my other settings.
–allow-non-empty
–allow-other
–no-traverse
–buffer-size 1G
–max-read-ahead 1G
–checkers 16
–retries 3
–low-level-retries 12
–log-level INFO
–stats 0 \

aj1252 · July 14, 2017, 3:39pm

I was running three scans at the same time to simulate the worst-case scenario against the mount. In addition, my home internet is not that fast and the server is in a datacenter. Therefore, it is not representative for normal operation. Was just using it for test comparisons.

I am currently running at 100ms, good performance, and no bans even when trying to get one. So I wouldn’t worry about that.

I do however have some issues with the mount getting unresponsive, and needs to be remounted, but that is some other issue since I have the same on another server running the normal v250.

calisro · July 14, 2017, 3:47pm

A burst option would be good I would think.

aj1252 · July 14, 2017, 4:01pm

Anyone else get 3-4 request/sec on Google? I think thats a little low, the excact same test on Amazon Im getting 10-15 req/sec.

Edit: Might be the instance I got assigned, usually getting 500-700MB copying between drives, but this only does 150MB. Testing another one…

Edit2: Nope same 3-4 req/s both on another instance and a hetzner server