Rclone mount failing to upload certain files with Japanese characters in filename

Help and Support
1

What is the problem you are having with rclone?

A rclone mount is failing to upload or even acknowledge past storing in the cache some files that have Japanese characters or non-english characters in the filenames. No errors in logs or in console, vfs states that 0 files are in the cache even though there are 34 files still waiting to be uploaded sitting in the cache folder

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

rclone v1.60.0

  • os/version: Microsoft Windows 11 Pro 22H2 (64 bit)
  • os/kernel: 10.0.22621.675 (x86_64)
  • os/type: windows
  • os/arch: amd64
  • go/version: go1.19.2
  • go/linking: static
  • go/tags: cmount

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 mount "archiveenc:" X: -vvvvvvvv --vfs-cache-mode full --vfs-read-chunk-size 200M --vfs-cache-max-age 30m --vfs-cache-poll-interval 1h --volname 'The Archive' --attr-timeout 1h --drive-skip-gdocs --drive-skip-shortcuts --dir-cache-time 5h --cache-dir 'Z:\rclone' --rc --rc-web-gui --rc-user=admin --rc-pass=admin --transfers 2 --order-by 'size,ascending'

The rclone config contents with secrets removed.

[archive]
type = drive
client_id = 
client_secret = 
scope = drive
token = 
team_drive = 

[archiveenc]
type = crypt
remote = archive:Encrypted
filename_encryption = standard
directory_name_encryption = true
password = 
password2 =

A log from the command with the -vv flag

2022/11/06 00:13:58 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2022/11/06 00:14:20 DEBUG : Google drive root 'Encrypted': Checking for changes on remote
2022/11/06 00:15:20 DEBUG : Google drive root 'Encrypted': Checking for changes on remote
2022/11/06 00:16:20 DEBUG : Google drive root 'Encrypted': Checking for changes on remote
2022/11/06 00:17:20 DEBUG : Google drive root 'Encrypted': Checking for changes on remote
2022/11/06 00:18:20 DEBUG : Google drive root 'Encrypted': Checking for changes on remote
2

Hi Masamune3210,

How do you know the mount is failing to upload those files?

Please share the command(s) and output used to identify (atleast) one of the 34 files waiting to be uploaded.

I suggest you start the mount without tuning parameters while troubleshooting, that is something like this:

rclone mount "archiveenc:" X: -vv --vfs-cache-mode full --volname 'The Archive' --drive-skip-gdocs --drive-skip-shortcuts  --cache-dir 'Z:\rclone' --rc --rc-web-gui --rc-user=admin --rc-pass=admin --transfers 2

This way we have an easier to understand situation where the delay between updates to/from the cloud is reduced to approximately 5 minutes.

3

You have a max age of 30 minutes but are checking

Once per hour.

If a file was uploaded, it wouldn't get removed from the cache area until it checks the cache every 1 hour and the log only has a few minutes of data.

That's generally bad to change unless you are 100% nothing is being changed outside the mount. Why did you change that?

Does nothing on an encrypted mount,

I'm like 99% sure this does nothing on a mount either as it's used for rclone sync/copy/move commands.

If you have files you are concerned about not copying, just test of them via a rclone copy archiveenc: -vv and share the output.

4

Starting this, the cache cleaner almost immediately fires, but doesn't clean anything or attempt to start uploading the files, acting like they are still pending even though no uploads are taking place.

image
image933×62 4.48 KB

5

I'll clean up my command, its acquired quite a lot of guff around the edges.

rclone copy:
Attempting to copy the specific file provides a directory not found, but specifying the folder the file is in and leaving the filename off allows rclone to start copying the file. Maybe something to do with filename parsing and starting a copy that is worked around my copying the folder instead?

6

Where do you see the files pending upload?

All I can see is a cache with 162 objects which that have been either downloaded/uploaded from/to the cloud. They are in the cache because they were used in the past hour, because of --vfs-cache-mode=full and the default --vfs-cache-max-age=1h. Note: Explorer may use files in the background, and this will also cause files to stay in the cache.

I suggest you try stopping the mount and then start it after 2 minutes with --vfs-cache-max-age=1m without pointing Explorer or anything else toward the mounted drive (X:).

7

This is with the command you put in your comment, which doesn't have any cache arguments other than the directory. No explorer windows open, no uploads being attempted.
The upload part of the mount just seemingly does not acknowledge anything waiting to be uploaded. The files exist in the correct folder on the mount, and no corruption is present, it just seems like rclone is arguing with itself. The cache layer sees that there are files in the cache that have not been uploaded yet, but the upload part doesn't see them so it never tries to upload them

This is all that the console keeps repeating, which is just the normal stuff the mount spits out when you have max verbosity and the remote control turned on.

image
image926×823 50.5 KB

8

Log here because I tried to let it run long enough for the default cache timeout to definitely occur

9

How do you see that? I see the 162 in the cache, but I don't see any that have not been uploaded yet.

Did you try my experiment:

10

Through rc-gui

image
image1061×838 22.2 KB

I am trying your experiment right now

11

Nope, still says the files are in the cache but doesn't try to upload them or do anything with them

12

OK, that sounds strange to me.

I would like you to try stopping the mount again, wait 2 minutes and then start using this very simple command:

rclone mount "archiveenc:" X: -vv --vfs-cache-mode full --cache-dir 'Z:\rclone' --vfs-cache-max-age=1m

I would like to see the last lines of the mount stopping and the full log from the first 2 minutes of the newly started log, both as "preformatted text" here in the thread.

15

hi,
for --cache-dir 'Z:\rclone'

perhaps change that to
--cache-dir "Z:\rclone"
or
--cache-dir Z:\rclone

16

So, currently doing the test, but doing it made me notice something. Rclone says its removing the files out of the cache correctly, but its saying that the files are 0 bytes and failing to remove them. Have to use gist because the log is too long, even only at 2min run time

17

Since its failing to remove the files, rclone sees them as never leaving the cache and thus never vacates the vfsmeta files and sees them every cache check

18

perhaps this corrupted the cache and/or confused rclone

2022/11/06 09:33:27 DEBUG : vfs cache: root is "C:\\Users\\Johnny\\'Z:\\rclone'"
2022/11/06 09:33:27 ERROR : Failed to create vfs cache - disabling: failed to create data cache directory: mkdir \\?\C:\Users\Johnny\'Z:: The filename, directory name, or volume label syntax is incorrect.
19

Thanks for the full log, looks good and like your cache finally cleaned!

I cannot explain why it didn't clean immediately, but looks like all the 162 files cleaned after a minute:

2022/11/06 09:45:35 INFO  : vfs cache: cleaned: objects 162 (was 162) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2022/11/06 09:46:35 INFO  : vfs cache: cleaned: objects 0 (was 162) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2022/11/06 09:47:35 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
20

Problem is, it only thinks they are gone. The files are still there and as soon as I restart the mount they will show back up

21

See

image
image925×63 4.56 KB

22

Perhaps, but that cannot be concluded from the information you shared with me, the files could also be reloaded into the cache by some other program.

I would like to see a continuous log sequence containing the cleaned mount closing and the new mount starting and the following 2 minutes, something like this (in a single gist):

...
2022/11/06 09:44:17 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
The service rclone has been stopped.
2022/11/06 09:45:31 DEBUG : Encrypted drive 'archiveenc:': Destroy:
2022/11/06 09:45:31 DEBUG : Encrypted drive 'archiveenc:': >Destroy:
2022/11/06 09:45:31 DEBUG : Not calling host.Unmount as mount already Destroyed
2022/11/06 09:45:31 DEBUG : Unmounted successfully
2022/11/06 09:45:31 DEBUG : vfs cache: cleaner exiting
2022/11/06 09:45:31 ERROR : X:: Unmounted rclone mount
2022/11/06 09:45:31 DEBUG : rclone: Version "v1.60.0" finishing with parameters ["C:\\Tools\\rclone\\rclone.exe" "mount" "archiveenc:" "X:" "-vv" "--vfs-cache-mode" "full" "--cache-dir" "Z:\\rclone" "--vfs-cache-max-age=1m"]

2022/11/06 09:45:34 DEBUG : rclone: Version "v1.60.0" starting with parameters ["C:\\Tools\\rclone\\rclone.exe" "mount" "archiveenc:" "X:" "-vv" "--vfs-cache-mode" "full" "--cache-dir" "Z:\\rclone" "--vfs-cache-max-age=1m"]
2022/11/06 09:45:34 DEBUG : Creating backend with remote "archiveenc:"
2022/11/06 09:45:34 DEBUG : Using config file from "C:\\Users\\Johnny\\.config\\rclone\\rclone.conf"
2022/11/06 09:45:34 DEBUG : Creating backend with remote "archive:Encrypted"
2022/11/06 09:45:35 DEBUG : Google drive root 'Encrypted': 'root_folder_id = 0ADu6Yc36eQosUk9PVA' - save this in the config to speed up startup
2022/11/06 09:45:35 DEBUG : vfs cache: root is "Z:\\rclone"
2022/11/06 09:45:35 DEBUG : vfs cache: data root is "\\\\?\\Z:\\rclone\\vfs\\archiveenc"
2022/11/06 09:45:35 DEBUG : vfs cache: metadata root is "\\\\?\\Z:\\rclone\\vfsMeta\\archiveenc"
2022/11/06 09:45:35 DEBUG : Creating backend with remote "Z:/rclone/vfs/archiveenc/"
2022/11/06 09:45:35 DEBUG : fs cache: renaming cache item "Z:/rclone/vfs/archiveenc/" to be canonical "//?/Z:/rclone/vfs/archiveenc/"
2022/11/06 09:45:35 DEBUG : Creating backend with remote "Z:/rclone/vfsMeta/archiveenc/"
2022/11/06 09:45:35 DEBUG : fs cache: renaming cache item "Z:/rclone/vfsMeta/archiveenc/" to be canonical "//?/Z:/rclone/vfsMeta/archiveenc/"
2022/11/06 09:45:35 DEBUG : Network mode mounting is disabled
2022/11/06 09:45:35 DEBUG : Mounting on "X:" ("archiveenc")
2022/11/06 09:45:35 DEBUG : vfs cache RemoveNotInUse (maxAge=60000000000, emptyOnly=false): item Synced/Roms Cloned/Nintendo Switch/to be finished/to be finished/Bloodstained Ritual of the Night - [010025A00DF2A000]/血咒之城‛‛‛：暗夜儀式 [010025A00DF2A800][v589824].nsz not removed, freed 0 bytes
2022/11/06 09:45:35 DEBUG : vfs cache RemoveNotInUse (maxAge=60000000000, emptyOnly=false): item Synced/Roms Cloned/Nintendo Switch/to be finished/to be finished/Fit Boxing 2 - Rhythm & Exercise - - [0100060011108000]/Fit Boxing 2 -リズム＆エクササイズ- [鬼モード‛‛‛：ベルナルド] [0100060011109005][v0].nsz not removed, freed 0 bytes
...
2022/11/06 09:45:35 INFO  : vfs cache: cleaned: objects 162 (was 162) in use 0, to upload 0, uploading 0, total size 0 (was 0)
...
2022/11/06 09:46:35 INFO  : vfs cache: cleaned: objects 0 (was 162) in use 0, to upload 0, uploading 0, total size 0 (was 0)
...
2022/11/06 09:47:35 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)