Copying failing via rclone mount on windows using Encrypted google drive

Help and Support
1

Hi,
As the title says, I’m getting a lot of hanging recently when copying files from a mounted google drive session.
The remote is encrypted. I’m not sure how to get errors/logs and I’m likely doing something very wrong but any help is appreciated.
I am using the latest rclone (1.44) and my mount sequence is very basic. Up until now, it worked perfectly but recently, windows explorer hangs while copying files to it. It often times requires a restart of explorer - which sometimes causes the machine to become unresponsive. This is windows server 2012 r2.

Again - my mount script is likely one of the most basic folks have seen on here so any hints/tips are very, very much appreciated.

mount drive-cript: i: --config “c:\rclone\rclone.conf” --vfs-cache-mode writes --fast-list

Note that I have tried it with and without fast-list and both net the same results. I’m not sure if mounting under windows is able to utilize this feature, though, since the machine doesn’t seem to be using any more memory than usual. I’m also using NSSM to mount this as a service if that helps any.

thanks a ton for any help. I know I’m likely not providing all the relevant details such as logs. Am not sure how to get detailed logs, though, since even when this script is used without being run as a service I it just tells me the mount was successful and nothing else - no errors, etc.

Again thanks for any help.

2

It looks fine your mount script.

If you add -vv --log-file rclone.log then it will make a debug log for you to look at. Check for any ERROR lines in there.

3

Hi,
I have a debug log file here. Do you want me to upload the entire contents? Is there anything that must be taken out for privacy purposes?

I am getting the following a few times intermittently.

2018/10/25 17:49:09 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded)
2018/10/25 17:49:09 DEBUG : pacer: Rate limited, sleeping for 2.382296772s (2 consecutive low level retries)
2018/10/25 17:49:09 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded)
2018/10/25 17:49:10 DEBUG : pacer: Resetting sleep to minimum 10ms on success
2018/10/25 17:49:10 INFO : books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 030.mp3: Copied (new)
2018/10/25 17:49:11 DEBUG : pacer: Rate limited, sleeping for 1.282133841s (1 consecutive low level retries)
2018/10/25 17:49:11 DEBUG : pacer: low level retry 3/10 (error googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded)
2018/10/25 17:49:11 DEBUG : pacer: Rate limited, sleeping for 2.112915807s (2 consecutive low level retries)
2018/10/25 17:49:11 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded)
2018/10/25 17:49:11 DEBUG : pacer: Rate limited, sleeping for 4.605444712s (3 consecutive low level retries)
2018/10/25 17:49:11 DEBUG : pacer: low level retry 4/10 (error googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded)
2018/10/25 17:49:12 DEBUG : pacer: Rate limited, sleeping for 8.873711347s (4 consecutive low level retries)
2018/10/25 17:49:12 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded)
2018/10/25 17:49:17 DEBUG : pacer: Resetting sleep to minimum 10ms on success
2018/10/25 17:49:17 DEBUG : books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 029.mp3: File.applyPendingModTime OK
2018/10/25 17:49:17 DEBUG : books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 029.mp3: transferred to remote
2018/10/25 17:49:17 DEBUG : books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 029.mp3(0xc000467e60): >close: err=

For the record, I have not uploaded 700+ GB in 24 hours. I’m also not sure what download limits are or if I’m exceeding some sort of API call limit. Maybe google has changed something in recent months?

Thanks for all the help. This is my first time on this forum as previously, rclone was working absolutely wonderfully.

For reference, here is the last part of the log before the copy dialogue hung indefinitely.

2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: >Write: n=65536
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: Getattr: fh=0x0
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: >Getattr: errc=0
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: Write: ofst=6029312, fh=0x0
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: >Write: n=65536
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: Getattr: fh=0x0
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: >Getattr: errc=0
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: Write: ofst=6094848, fh=0x0
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: >Write: n=65536
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: Getattr: fh=0x0
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: >Getattr: errc=0
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: Write: ofst=6160384, fh=0x0
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: >Write: n=65536
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: Getattr: fh=0x0
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: >Getattr: errc=0
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: Write: ofst=6225920, fh=0x0
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: >Write: n=65536
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: Getattr: fh=0x0
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: >Getattr: errc=0
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: Write: ofst=6291456, fh=0x0
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: >Write: n=5209
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: Getattr: fh=0x0
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: >Getattr: errc=0
2018/10/25 17:50:38 DEBUG : /books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: Utimens: tmsp=[{Sec:1540499809 Nsec:742000000} {Sec:1528913912 Nsec:0}]
2018/10/25 17:50:38 DEBUG : books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 041.mp3: File.applyPendingModTime OK
2018/10/25 17:51:25 DEBUG : Google drive root ‘srv’: Checking for changes on remote
2018/10/25 17:51:25 DEBUG : Cleaning the cache
2018/10/25 17:51:25 DEBUG : books/audiobooks/D/D. K. Hood/03 Follow Me Home/Follow Me Home Detectives Kane and Alton, Book 3 (Unabridged) - 042.mp3: updateTime: setting atime to 2018-10-25 17:50:38.13302 -0300 ADT
2018/10/25 17:52:25 DEBUG : Cleaning the cache
2018/10/25 17:53:25 DEBUG : Cleaning the cache
2018/10/25 17:54:25 DEBUG : Cleaning the cache

This went on indefinitely with no other entries in the log.

4

Great! I don't actually see any problems in the parts you uploaded :frowning: Can you grep the file for the string "ERROR", so grep ERROR rclone.log to see if there are any errors in the file and post those?

If you want to redact things out of the log that is fine. It won't have any passwords or token in, but it will show file names etc.

If you prefer you could also email the log to me at nick@craig-wood.com - please put a link to this forum post in the email for context - thanks.

5

Log is now sent.
Thanks for any help. Pulling my hair out here.

6

Thanks for the log. Unfortunately there are no clues it in I can see :frowning:

Have you got the latest version of WinFSP? That would be worth checking (though I expect you already have).

If you add --stats 1m rclone will output statistics every minute - it would be interesting to see what they say when it has come to a halt.

You'll probably find using rclone copy to copy the files rather than rclone mount works fine - it would be interesting to try that too.

7

Hi,
Sent that log as well. My apologies, the transfers went on for quite some time. 700 or so out of the 800+ MB were transferred until everything stopped in the copy dialogue, so the log file is quite big.

So I did end up trying rclone copy and that worked just fine (see below, though).

A few interesting observations here, though…

Rclone copy still moves significantly slower than it used to for me.
Normally my upload rate doesn’t fluctuate when I use the command but there are now quite a few seconds (sometimes up to half a minute) where there is no network activity from rclone. It took just around 40 minutes to copy 25 gb of content on a hetzner dedicated server whereas normally that’s done in a matter of minutes. Similar results on an OVH box. If I stop the rcloneMount service (as that is what I normally use to mount gdrive with nssm) and restart it, copy progress takes off again once I hit try again under windows. I’m not sure if the file that ended up failing gets copied - judging from the log files I am thinking not - but I could be wrong. I wonder if this is making windows struggle, since gdrive is still technically there, just not responding quick enough? You’d think it would throw up an error if so, though.

I am using winfsp-1.3.18160. Is there a beta version?

I haven’t added a ton of new content but could this have something to do with my config file or password for the crypted remote? Might google be throttling my API calls (or whatever rclone uses to access it)?

I’ve tried this on a variety of machines and internet connections. Would changing cache settings fix anything? E.g. any of the time related settings? Everything from a 5 mbit upload speed here at home to 1 gbit on the hetzner (in theory anyway).

Now that I think of it, I’m also noticing significantly longer wait times when loading files into a media player or browsing folders in general via the mount. Has google changed anything on the backend?

I’m sorry for all the questions. Normally, I set rclone up and forget it. I would run a batch file and just use rclone copy, except files and folders are so case sensitive I don’t want to run the risk of ending up with duplicate files/folders. Plus I’m just really baffled as to why this is happening now.

thanks again

8

Thank you for the log :slight_smile: Unfortunately I can't see a smoking gun in there, it just seems to tail off. There aren't any stuck transfers so I haven't worked out what is going on yet.

From the logs you seem to be copying files to the mount - is that correct?

Good... So this problem is something to do with the vfs or mount layer in rclone.

There have been lots of reports of google drive erratic speeds with rclone and I don't think this is rclone's fault, rather google drive being either rate limited or overloaded.

That could be the problem...

Just checking - you are using your own client_id - if not I suggest you make one as that will make a lot of difference.

That is my thinking...

I think rclone should deal with that now - if copying from a case insenstive drive (like Windows) to a case sensitive one (like Google drive) it should match the files in a case insensitive way. Is that not what you see?

9

Hi,
Yes, I am attempting to copy files to the remote.

I have not made my own client ID. I just attempted this.

I was having issues with authorizing at first but soon realized I was using two different conf files.

I’ll report back if this fixes the issues or not. Does --fast-list work on mounted rclone instances in windows?

Edit: Issue is still happening for me despite the new client ID and secret. Copy progress is now hanging at 60 items remaining out of a total of 109.

Regarding upper and lower case, y:\directory\E and y:\directory\e will both show up in windows explorer instead of merging when gdrive is mounted.

Edit 2: I just sent you a log file from a few minutes ago. I’m not sure if there are any differences but this time it is with the new client ID and secret.

There was a total of 1.03 gb to be copied - but as you can see it didn’t make it past 91 mb this time.

I might try updating to a beta version to see if there are any differences. Unless google drive has not been modified?

Right now I’m mainly thinking google modified something on their end. Even listing directories with 10 subdirectories via windows mount is far slower than it used to be for me. I know it’s windows, and windows mounting is, from what I have heard anyway, far less efficient than linux. Sttill…

10

Thanks for testing the new client ID. I was hoping that would fix it but it doesn't look like it :frowning:

I recommend people use rclone copy for this as it has a better retry strategy than rclone mount.

It doesn't do anything unless you use the remote control prefil the cache.

Hmm, I think it should be working better than that!

I don't know if you've got access to a different windows machine you could try it on to see if it is something to do with your specific OS? One thing that seems to cause a lot of problems on Windows are anti virus tools - can you try disabling those?

11

What is remote control prefil the cache? I have never used the remote control function.

I have tried several different machines ranging from Windows 7 without antivirus to windows 10 which has the default Windows defender in use. Similarly I have tried a variety of internet connections, all netting the same results.

Do you recommend a retry strategy in regards to mounting or is there nothing I can do as far as that goes?

12

This is what I was talking about: Remote Control / API

Hmm, I can't think of what to try next. It might be, as you say, the slow response of rclone which is causing the problem with explorer.

What you could try is do a local mount and see if that has the same problems, so do

mount C:\path\to\some\files Z: --config “c:\rclone\rclone.conf” --vfs-cache-mode writes

And see if that has the same problem or not - if that works then it probably means you are right it is the slow responses of google drive, if not, then there is a bug to fix in rclone.