Vfs/refresh lists lots of files that do not exist in logs

jennec · October 5, 2019, 12:27pm

What is the problem you are having with rclone?

when running the command: rclone rc vfs/refresh recursive=true --rc-addr localhost:port my log file is filled with the following entires:
DEBUG : old/Movies/Captain Phillips (2013)/.wdmc/transcoded_files: Skipping undecryptable dir name: illegal base32 data at input byte 3

The folder old/movies was created when I had originally uploaded non-encrypted files to gdrive. I renamed the folder after creating an encrypted remote and moved the files from the old/movies folder to the encrypted folder. Then I deleted the folder "old" and all its contents. This was some months ago.

Today I noticed that when running the vfs/refresh command my log filled up with hundreds of these entries.

I checked google drive and this folder path does not exist. I emptied any trash on there just incase it was reading it from somewhere. But this has not resolved the problem.

Can anyone advise why rclone is even seeing this path when it doesn't exist?

What is your rclone version (output from `rclone version`)

rclone v1.47.0

os/arch: linux/amd64
go version: go1.12.4

Which OS you are using and how many bits (eg Windows 7, 64 bit)

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 rc vfs/refresh recursive=true --rc-addr localhost:port

A log from the command with the `-vv` flag (eg output from `rclone -vv copy /tmp remote:tmp`)

2019/10/05 11:40:01 DEBUG : rclone: Version "v1.47.0" starting with parameters ["rclone" "mount" "--attr-timeout" "1000h" "--buffer-size" "0M" "--dir-cache-time" "1000h" "--vfs-cache-mode" "off" "--vfs-cache-max-age" "48h" "--vfs-read-chunk-size" "128M" "--vfs-read-chunk-size-limit=0" "--log-level" "DEBUG" "--umask" "0027" "--log-file=/home/jennec/logs/rclone.log" "--poll-interval" "15s" "--timeout" "1h" "--drive-skip-gdocs" "--fuse-flag" "sync_read" "--rc" "--rc-addr" "localhost:5572" "gdrive-media-enc:" "/home/jennec/rclone/gdrive-media-enc"]
2019/10/05 11:40:01 NOTICE: Serving remote control on http://127.0.0.1:5572/
2019/10/05 11:40:01 DEBUG : Using config file from "/home/jennec/.config/rclone/rclone.conf"
2019/10/05 11:40:02 DEBUG : Encrypted drive 'gdrive-media-enc:': Mounting on "/home/jennec/rclone/gdrive-media-enc"
2019/10/05 11:40:03 DEBUG : Adding path "vfs/forget" to remote control registry
2019/10/05 11:40:03 DEBUG : Adding path "vfs/refresh" to remote control registry
2019/10/05 11:40:03 DEBUG : Adding path "vfs/poll-interval" to remote control registry
2019/10/05 11:40:03 DEBUG : : Root:
2019/10/05 11:40:03 DEBUG : : >Root: node=/, err=
2019/10/05 11:40:04 DEBUG : /: Lookup: name="mountcheck.txt"
2019/10/05 11:40:05 DEBUG : This is the gdrive media folder: Skipping google document type "application/vnd.google-apps.document"
2019/10/05 11:40:05 DEBUG : old: Skipping undecryptable dir name: illegal base32 data at input byte 3
2019/10/05 11:40:05 DEBUG : /: >Lookup: node=mountcheck.txt, err=
2019/10/05 11:40:05 DEBUG : mountcheck.txt: Attr:
2019/10/05 11:40:05 DEBUG : mountcheck.txt: >Attr: a=valid=1000h0m0s ino=0 size=39 mode=-rw-r-----, err=
2019/10/05 11:40:05 DEBUG : rc: "vfs/refresh": with parameters map[recursive:true]
2019/10/05 11:40:05 DEBUG : : Reading directory tree
2019/10/05 11:40:05 DEBUG : This is the gdrive media folder: Skipping google document type "application/vnd.google-apps.document"
2019/10/05 11:40:06 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=536487538860, userRateLimitExceeded)
2019/10/05 11:40:06 DEBUG : pacer: Rate limited, increasing sleep to 1.712551731s
2019/10/05 11:40:06 DEBUG : pacer: Reducing sleep to 0s
2019/10/05 11:40:06 DEBUG : old: Skipping undecryptable dir name: illegal base32 data at input byte 3
2019/10/05 11:40:06 DEBUG : old/Movies: Skipping undecryptable dir name: illegal base32 data at input byte 3
skipping repeated errors for the thousands of entries for different old/* paths
2019/10/05 11:41:33 DEBUG : Google drive root '': Checking for changes on remote
2019/10/05 11:41:48 DEBUG : Google drive root '': Checking for changes on remote
2019/10/05 11:41:50 DEBUG : : Reading directory tree done in 1m44.695096611s
2019/10/05 11:41:50 DEBUG : rc: "vfs/refresh": reply map[result:map[:OK]]:

Animosity022 · October 5, 2019, 1:02pm

That means you usually have unencrypted files mixed in with encrypted files. You'd want to remove and not mix and match.

1.47 is pretty old so I'd upgrade.

Also, you want to get your own API key if you haven't.

https://rclone.org/drive/#making-your-own-client-id

jennec · October 5, 2019, 1:07pm

I don't have any unencrypted files or folder in my encrypted remote (that I am aware of). The encrypted remote has not been used for any othe purpose. The problem is that the path old/* doesn't exist either inside or outside of the encrypted remote.

I do have individual API Keys for different remotes. I just did something alittle stupid last night which seemed to trigger the quota limit.

I am can't upgrde rclone as I am using a shared server. Ican put a request in for it to be updated, but I am stuck with that verssion, for now.

Animosity022 · October 5, 2019, 1:19pm

What's you rclone,.conf look like without passwords/keys?

You'd want to:

rclone ls GoogleDrive:old probably or something along those lines.

The error is that you have an unecrypted file in a remote.

felix@gemini:~$ rclone lsd GD:
          -1 2019-09-29 21:57:58        -1 crypt
felix@gemini:~$ rclone copy /etc/hosts GD:crypt
felix@gemini:~$ rclone lsf -vv gcrypt:
2019/10/05 09:19:27 DEBUG : rclone: Version "v1.49.5" starting with parameters ["rclone" "lsf" "-vv" "gcrypt:"]
2019/10/05 09:19:27 DEBUG : Using config file from "/opt/rclone/rclone.conf"
2019/10/05 09:19:28 DEBUG : hosts: Skipping undecryptable file name: not a multiple of blocksize
Movies/
TV/
mounted
2019/10/05 09:19:28 DEBUG : 5 go routines active
2019/10/05 09:19:28 DEBUG : rclone: Version "v1.49.5" finishing with parameters ["rclone" "lsf" "-vv" "gcrypt:"]

jennec · October 5, 2019, 1:44pm

My conf file is setup as (was using cache, not currently, but config is still present:

[gdrive-media]
type = drive
client_id = clientid
client_secret = secret
scope = drive
root_folder_id = rootfolderid
token = access token

[gdrive-media-cache]
type = cache
remote = gdrive-media:
plex_url = serverurl
plex_username = username
plex_password = password
chunk_size = 10M
info_age = 1h0m0s
chunk_total_size = 10G

[gdrive-media-enc]
type = crypt
remote = gdrive-media:
filename_encryption = standard
directory_name_encryption = true
password = secret
password2 = secret

[gdrive-media-upload]
type = crypt
remote = gdrive-media:
filename_encryption = standard
directory_name_encryption = true
password = secret
password2 = secret

FYI, both crypt remotes use the same secrets.

When I run "rclone ls gdrive-media-enc:old" I get:

2019/10/05 13:32:54 DEBUG : rclone: Version "v1.47.0" starting with parameters ["rclone" "lsf" "-vv" "gdrive-media-enc:old"]
2019/10/05 13:32:54 DEBUG : Using config file from "/home/jennec/.config/rclone/rclone.conf"
2019/10/05 13:32:55 ERROR : : error listing: directory not found
2019/10/05 13:32:55 Failed to lsf: error in ListJSON: directory not found

When I run "rclone ls gdrive-media-enc:" I get:
2019/10/05 13:40:19 DEBUG : rclone: Version "v1.47.0" starting with parameters ["rclone" "lsf" "-vv" "gdrive-media-enc:"]
2019/10/05 13:40:19 DEBUG : Using config file from "/home/jennec/.config/rclone/rclone.conf"
2019/10/05 13:40:19 DEBUG : old: Skipping undecryptable dir name: illegal base32 data at input byte 3
2019/10/05 13:40:19 DEBUG : This is the gdrive media folder.docx: Skipping undecryptable file name: illegal base32 data at input byte 4
Audiobooks/
Books/
Movies/
Movies - Anime/
Music/
Music Videos/
StandUp/
TV/
TV - Anime/
mountcheck.txt
2019/10/05 13:40:19 DEBUG : 4 go routines active
2019/10/05 13:40:19 DEBUG : rclone: Version "v1.47.0" finishing with parameters ["rclone" "lsf" "-vv" "gdrive-media-enc:"]

***UPDATE: THis was me being a complete idot. This folder was actually still there. You were totally right. I could not see it using my Goole Drive app on Windows, but using the Web UI I could see it. I;ve removed it now and the problem has gone away. Apologies for wasting your time.

Animosity022 · October 5, 2019, 3:01pm

All good! Happy you figured it out