Replicate old union behavior

Help and Support
1

I upgraded rclone to the latest version

rclone v1.53.0

  • os/arch: windows/amd64
  • go version: go1.15

I have this in my config from an older version before union was updated.

[rclone_union_upload]
type = union
remotes = gdrive2: U:\rclone_upload

gdrive2 = google drive
U:\rclone_upload = local disk

What syntax gets me the same behavior as above? Do I need to change anything at all?

I think maybe i just need to use no create and leave the defaults for create/action/search policies, maybe like this below, but i'm fairly confused after reading through the documentation.

[rclone_union_upload]
type = union
upstreams = gdrive2::nc U:\rclone_upload
2

I think you shouldn't need to change anything, it is supposed to be backwards compatible.

I may be wrong about that though...

3

After some testing i'm pretty sure it's not backwards compatible, for example if I use this:

[rclone_union_upload]
type = union
upstreams = gdrive2: U:\rclone_upload

And mount the union (sorry for formatting)

$DriveLetter = 'G:'
$RcloneEXE = "c:\rclone\rclone.exe"
$RcloneConfig = "c:\rclone\.rclone.conf"
$RemotePath = 'rclone_union_upload:'
$Log = 'C:\rclone\logs\Rclone-MOUNT-rclone_union_upload.log'
$LogLevel = 'INFO'
if (!(Test-Path -Path $DriveLetter))
{
	& $RcloneEXE --config=$RcloneConfig mount $RemotePath $DriveLetter `
	--log-level $LogLevel `
	--log-file $Log `
	--dir-cache-time 168h `
	--vfs-cache-mode writes `
	--vfs-cache-max-age 30m `
	--cache-dir Z:\rclone `
	--allow-root `
	--allow-other 
}

And I write to the union mount, I end up writing to the first upstream which in my example is google drive, previously I would of been writing to the last remote in the list which is the local disk. I think this is because of the default create policy epmfs choosing google drive because of the amount of free space but i'm confused what I should be setting it to?

Additionally I thought I could fix this using no create like below, this works when I write files, they go the local disk "U:\rclone_upload":

[rclone_union_upload]
type = union
upstreams = gdrive2::nc U:\rclone_upload

However it breaks when I try and rclone move files from U:\rclone_upload into gdrive. For example:

  1. Mount union
  2. Write file to mount
  3. File is written to local disk and accessible in the mount
  4. Separate process performs rclone move on local path
  5. I get errors when i try and access the file in the mount

Before the union changes I'm fairly sure i just had to wait for poll-interval to expire and the file would be accessible.

2020/09/06 10:22:59 INFO  : TEST.txt: vfs cache: removed cache file as stale (remote is different)
2020/09/06 10:22:59 INFO  : TEST.txt: vfs cache: downloader: error count now 1: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : TEST.txt: vfs cache: failed to download: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 INFO  : TEST.txt: vfs cache: downloader: error count now 2: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : TEST.txt: vfs cache: failed to download: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 INFO  : TEST.txt: vfs cache: downloader: error count now 3: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : TEST.txt: vfs cache: failed to download: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 INFO  : TEST.txt: vfs cache: downloader: error count now 4: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : TEST.txt: vfs cache: failed to download: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 INFO  : TEST.txt: vfs cache: downloader: error count now 5: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : TEST.txt: vfs cache: failed to download: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 INFO  : TEST.txt: vfs cache: downloader: error count now 6: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : TEST.txt: vfs cache: failed to download: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 INFO  : TEST.txt: vfs cache: downloader: error count now 7: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : TEST.txt: vfs cache: failed to download: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 INFO  : TEST.txt: vfs cache: downloader: error count now 8: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : TEST.txt: vfs cache: failed to download: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 INFO  : TEST.txt: vfs cache: downloader: error count now 9: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : TEST.txt: vfs cache: failed to download: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 INFO  : TEST.txt: vfs cache: downloader: error count now 10: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : TEST.txt: vfs cache: failed to download: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 INFO  : TEST.txt: vfs cache: downloader: error count now 11: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : TEST.txt: vfs cache: failed to download: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : TEST.txt: vfs cache: too many errors 11/10: last error: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : TEST.txt: vfs cache: failed to kick waiters: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 INFO  : TEST.txt: vfs cache: downloader: error count now 12: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : TEST.txt: vfs cache: failed to download: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : TEST.txt: vfs cache: failed to _ensure cache vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : IO error: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 INFO  : TEST.txt: vfs cache: downloader: error count now 13: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : TEST.txt: vfs cache: failed to download: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : TEST.txt: vfs cache: too many errors 13/10: last error: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : TEST.txt: vfs cache: failed to kick waiters: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : TEST.txt: vfs cache: failed to _ensure cache vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : IO error: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 INFO  : TEST.txt: vfs cache: downloader: error count now 14: vfs reader: failed to write to cache file: The system cannot find the file specified.
2020/09/06 10:22:59 ERROR : TEST.txt: vfs cache: failed to download: vfs reader: failed to write to cache file: The system cannot find the file specified.
4

After testing this a bit more, I think this is either the same bug or similar to this from a while ago: https://github.com/rclone/rclone/issues/2837

union mounts don't seem to support poll interval anymore unless i'm doing something wrong.

If I rclone move a file inside one of the union upstreams I now have to wait for dir-cache-time to expire or the file is not accessible inside the union mount.

5

Union mounts will support poll-interval, but the local backend doesn't support poll-interval which is probably where the problem lies.

Does that make sense?

6

Thanks for your help ncw but I actually don't understand :frowning: what is the local backend just so I understand in this example?

If i roll back to the previous version I was using which is v1.50.2 it works fine. I haven't tried anything newer but I had assumed the union changes in 1.52 had changed something with poll-interval.

7

This one is a local backend:

8

Thanks, so is this a bug or intended? poll interval use to work with a union with a local backend. It works if i swap between v1.50.2 and 1.53

9

Hmm, maybe that is due to the VFS changes.

Can you try the intermediate versions of rclone and see where it went wrong?

10

It doesn't seem to work properly after 1.51.0. Either I can't read the files or I can't delete files from the union mount.

This is how I am testing:

  1. Mount the union

In 1.50.2 / 1.51.0 I have this syntax in my config

[rclone_union_upload]
type = union
remotes = gdrive2: U:\rclone_upload

From 1.52.0 onwards I have this:

[rclone_union_upload]
type = union
upstreams = gdrive2::nc U:\rclone_upload
  1. Copy test.txt to mount
  2. Verify it's written to local backend path
  3. Run rclone move, move the file into the remote path
  4. Verify its written to the remote path in the union (google drive) and is no longer in the local path in the union.
  5. Attempt to read file from the union mount
  6. Attempt to delete file from the union mount

This is the result

1.50.2 = Read is OK, Delete is OK
1.51.0 = Read is OK, Delete is OK
1.52.0 = Read is OK, Delete FAIL
1.53.0 = Read FAIL, Delete FAIL

Read = Opening the .txt file in notepad in windows.
Delete = Deleting via windows explorer.

Full debug logs for process above:

version link
rclone v1.50.2 https://pastebin.pl/view/2158016d
rclone v1.51.0 https://pastebin.pl/view/d002bf71
rclone v1.52.0 https://pastebin.pl/view/b89cd8ec
rclone v1.53.0 https://pastebin.pl/view/3201ec53
11

Thanks for writing that up in such a clear way - much appreciated.

Can you try your steps 2-7 without the mount, so using rclone commands directly on the rclone_union_upload: remote.

Something like

  1. rclone copy test.txt rclone_union_upload:
  2. rclone lsf U:\rclone_upload
  3. rclone move
  4. rclone lsf gdrive2:
  5. rclone cat rclone_union_upload:test.txt
  6. rclone delete rclone_union_upload:test.txt

That will let us separate which problems are caused by the VFS changes and which by the union changes.

When you are running the mount, can you try the test but after step 4. run rclone rc vfs/forget - you'll have to add --rc --rc-no-auth to the mount to get the rc to work if you aren't using it already.

12

Yes looks like it works without the mount:

c:\rclone>rclone --config=c:\rclone\.rclone.conf copy test.txt rclone_union_upload: -vv
2020/09/09 18:48:18 DEBUG : rclone: Version "v1.53.0" starting with parameters ["rclone" "--config=c:\\rclone\\.rclone.conf" "copy" "test.txt" "rclone_union_upload:" "-vv"]
2020/09/09 18:48:18 DEBUG : Creating backend with remote "test.txt"
2020/09/09 18:48:18 DEBUG : Using config file from "c:\\rclone\\.rclone.conf"
2020/09/09 18:48:18 DEBUG : fs cache: adding new entry for parent of "test.txt", "//?/c:/rclone"
2020/09/09 18:48:18 DEBUG : Creating backend with remote "rclone_union_upload:"
2020/09/09 18:48:18 DEBUG : Creating backend with remote "U:/rclone_upload"
2020/09/09 18:48:18 DEBUG : Creating backend with remote "gdrive2:"
2020/09/09 18:48:18 DEBUG : fs cache: renaming cache item "U:/rclone_upload" to be canonical "//?/U:/rclone_upload"
2020/09/09 18:48:18 DEBUG : fs cache: switching user supplied name "U:/rclone_upload" for canonical name "//?/U:/rclone_upload"
2020/09/09 18:48:18 DEBUG : test.txt: Need to transfer - File not found at Destination
2020/09/09 18:48:19 DEBUG : test.txt: MD5 = 5a105e8b9d40e1329780d62ea2265d8a OK
2020/09/09 18:48:19 INFO  : test.txt: Copied (new)
2020/09/09 18:48:19 INFO  :
Transferred:             5 / 5 Bytes, 100%, 18 Bytes/s, ETA 0s
Transferred:            1 / 1, 100%
Elapsed time:         0.8s

2020/09/09 18:48:19 DEBUG : 4 go routines active

c:\rclone>rclone --config=c:\rclone\.rclone.conf lsf U:\rclone_upload -vv
2020/09/09 18:49:22 DEBUG : rclone: Version "v1.53.0" starting with parameters ["rclone" "--config=c:\\rclone\\.rclone.conf" "lsf" "U:\\rclone_upload" "-vv"]
2020/09/09 18:49:22 DEBUG : Creating backend with remote "U:\\rclone_upload"
2020/09/09 18:49:22 DEBUG : Using config file from "c:\\rclone\\.rclone.conf"
2020/09/09 18:49:22 DEBUG : fs cache: renaming cache item "U:\\rclone_upload" to be canonical "//?/U:/rclone_upload"
test.txt
2020/09/09 18:49:22 DEBUG : 2 go routines active

c:\rclone>rclone --config=c:\rclone\.rclone.conf move U:\rclone_upload gdrive2: -vv
2020/09/09 18:53:01 DEBUG : rclone: Version "v1.53.0" starting with parameters ["rclone" "--config=c:\\rclone\\.rclone.conf" "move" "U:\\rclone_upload" "gdrive2:" "-vv"]
2020/09/09 18:53:01 DEBUG : Creating backend with remote "U:\\rclone_upload"
2020/09/09 18:53:01 DEBUG : Using config file from "c:\\rclone\\.rclone.conf"
2020/09/09 18:53:01 DEBUG : fs cache: renaming cache item "U:\\rclone_upload" to be canonical "//?/U:/rclone_upload"
2020/09/09 18:53:01 DEBUG : Creating backend with remote "gdrive2:"
2020/09/09 18:53:02 DEBUG : Google drive root '': Waiting for checks to finish
2020/09/09 18:53:02 DEBUG : Google drive root '': Waiting for transfers to finish
2020/09/09 18:53:03 DEBUG : test.txt: MD5 = 5a105e8b9d40e1329780d62ea2265d8a OK
2020/09/09 18:53:03 INFO  : test.txt: Copied (new)
2020/09/09 18:53:03 INFO  : test.txt: Deleted
2020/09/09 18:53:03 INFO  :
Transferred:             5 / 5 Bytes, 100%, 2 Bytes/s, ETA 0s
Checks:                 2 / 2, 100%
Deleted:                1
Renamed:                1
Transferred:            1 / 1, 100%
Elapsed time:         2.4s

2020/09/09 18:53:03 DEBUG : 4 go routines active

c:\rclone>rclone --config=c:\rclone\.rclone.conf lsf gdrive2: -vv
2020/09/09 18:53:51 DEBUG : rclone: Version "v1.53.0" starting with parameters ["rclone" "--config=c:\\rclone\\.rclone.conf" "lsf" "gdrive2:" "-vv"]
2020/09/09 18:53:51 DEBUG : Using config file from "c:\\rclone\\.rclone.conf"
2020/09/09 18:53:51 DEBUG : Creating backend with remote "gdrive2:"
Media/
test.txt
2020/09/09 18:53:52 DEBUG : 4 go routines active

c:\rclone>rclone --config=c:\rclone\.rclone.conf cat rclone_union_upload:test.txt -vv
2020/09/09 18:54:53 DEBUG : rclone: Version "v1.53.0" starting with parameters ["rclone" "--config=c:\\rclone\\.rclone.conf" "cat" "rclone_union_upload:test.txt" "-vv"]
2020/09/09 18:54:53 DEBUG : Using config file from "c:\\rclone\\.rclone.conf"
2020/09/09 18:54:53 DEBUG : Creating backend with remote "rclone_union_upload:test.txt"
2020/09/09 18:54:53 DEBUG : Creating backend with remote "gdrive2:"
2020/09/09 18:54:53 DEBUG : Creating backend with remote "U:/rclone_upload"
2020/09/09 18:54:53 DEBUG : fs cache: renaming cache item "U:/rclone_upload" to be canonical "//?/U:/rclone_upload"
2020/09/09 18:54:53 DEBUG : Creating backend with remote "U:/rclone_upload/test.txt"
2020/09/09 18:54:53 DEBUG : Creating backend with remote "gdrive2:/test.txt"
2020/09/09 18:54:53 DEBUG : fs cache: renaming cache item "U:/rclone_upload/test.txt" to be canonical "//?/U:/rclone_upload/test.txt"
2020/09/09 18:54:54 DEBUG : fs cache: adding new entry for parent of "gdrive2:/test.txt", "gdrive2:"
2020/09/09 18:54:54 DEBUG : Media: Excluded
test12020/09/09 18:54:55 DEBUG : 4 go routines active

c:\rclone>rclone --config=c:\rclone\.rclone.conf delete rclone_union_upload:test.txt -vv
2020/09/09 18:55:31 DEBUG : rclone: Version "v1.53.0" starting with parameters ["rclone" "--config=c:\\rclone\\.rclone.conf" "delete" "rclone_union_upload:test.txt" "-vv"]
2020/09/09 18:55:31 DEBUG : Using config file from "c:\\rclone\\.rclone.conf"
2020/09/09 18:55:31 DEBUG : Creating backend with remote "rclone_union_upload:test.txt"
2020/09/09 18:55:31 DEBUG : Creating backend with remote "U:/rclone_upload"
2020/09/09 18:55:31 DEBUG : Creating backend with remote "gdrive2:"
2020/09/09 18:55:31 DEBUG : fs cache: renaming cache item "U:/rclone_upload" to be canonical "//?/U:/rclone_upload"
2020/09/09 18:55:31 DEBUG : Creating backend with remote "U:/rclone_upload/test.txt"
2020/09/09 18:55:31 DEBUG : Creating backend with remote "gdrive2:/test.txt"
2020/09/09 18:55:31 DEBUG : fs cache: renaming cache item "U:/rclone_upload/test.txt" to be canonical "//?/U:/rclone_upload/test.txt"
2020/09/09 18:55:32 DEBUG : fs cache: adding new entry for parent of "gdrive2:/test.txt", "gdrive2:"
2020/09/09 18:55:32 DEBUG : Waiting for deletions to finish
2020/09/09 18:55:33 DEBUG : Media: Excluded
2020/09/09 18:55:33 INFO  : test.txt: Deleted
2020/09/09 18:55:33 DEBUG : 4 go routines active

Also works if I follow the same process as my last post but run rclone rc vfs/forget at the end and then read/delete works OK.

full debug log: https://pastebin.pl/view/475c310c

All tested in 1.53.0

13

Thanks for that :slight_smile:

Both of those are pointing towards this being a VFS problem rather than a union problem, namely that the VFS is caching the file object when something external has happened to it so the file object becomes invalid.

In your case the something external is that the file was moved from local to gdrive but the object wasn't updated in the VFS cache.

So you have a work-around for this problem with vfs/forget.

I suspect this problem is effectively equivalent to this (without the union)

  1. Mount the remote
  2. Copy test.txt to mount
  3. Verify it's written to local backend path
  4. rclone remove test.txt from remote:
  5. skip
  6. Attempt to read file from the mount
  7. Attempt to delete file from the union mount

Which looks like this

$ rclone mount -vv /tmp/src /mnt/tmp

New terminal

$ echo hello > /mnt/tmp/test.txt
$ cat /mnt/tmp/test.txt
hello
$ cat /mnt/src/test.txt
cat: /mnt/src/test.txt: No such file or directory
$ cat /tmp/src/test.txt
hello
$ rm /tmp/src/test.txt
$ cat /mnt/tmp/test.txt
cat: /mnt/tmp/test.txt: Input/output error
$ rm /mnt/tmp/test.txt
rm: cannot remove '/mnt/tmp/test.txt': Input/output error
$

The log for this looks like

2020/09/09 15:00:26 DEBUG : /: Lookup: name="test.txt"
2020/09/09 15:00:26 DEBUG : /: >Lookup: node=test.txt, err=<nil>
2020/09/09 15:00:26 DEBUG : test.txt: Attr: 
2020/09/09 15:00:26 DEBUG : test.txt: >Attr: a=valid=1s ino=0 size=6 mode=-rw-rw-r--, err=<nil>
2020/09/09 15:00:26 DEBUG : test.txt: Open: flags=OpenReadOnly
2020/09/09 15:00:26 DEBUG : test.txt: Open: flags=O_RDONLY
2020/09/09 15:00:26 DEBUG : test.txt: >Open: fd=test.txt (r), err=<nil>
2020/09/09 15:00:26 DEBUG : test.txt: >Open: fh=&{test.txt (r)}, err=<nil>
2020/09/09 15:00:26 DEBUG : &{test.txt (r)}: Read: len=4096, offset=0
2020/09/09 15:00:26 DEBUG : test.txt: ChunkedReader.openRange at 0 length 134217728
2020/09/09 15:00:26 DEBUG : &{test.txt (r)}: >Read: read=0, err=open /tmp/src/test.txt: no such file or directory
2020/09/09 15:00:26 DEBUG : &{test.txt (r)}: Read: len=4096, offset=0
2020/09/09 15:00:26 DEBUG : test.txt: ChunkedReader.openRange at 0 length 134217728
2020/09/09 15:00:26 DEBUG : &{test.txt (r)}: >Read: read=0, err=open /tmp/src/test.txt: no such file or directory
2020/09/09 15:00:26 DEBUG : &{test.txt (r)}: Flush: 
2020/09/09 15:00:26 DEBUG : &{test.txt (r)}: >Flush: err=<nil>
2020/09/09 15:00:26 DEBUG : &{test.txt (r)}: Release: 
2020/09/09 15:00:26 DEBUG : &{test.txt (r)}: >Release: err=<nil>

So as I said earlier in the thread

If the local backend supported change notify then this would work as expected.

There is an issue about this

So fixing that issue would be the quickest way to get this working.

14

Thanks for looking into it, ill wait and see if that issue gets fixed.

I'm guessing running vfs/forgot for the entire mount every minute is probably a bad idea so I can probably work out a way to monitor the local path for files and run the vfs/forget command on just those files after i rclone move them.

15

You don't want to trash the cache if you can help it.

You can probably use inotify to forget just the right paths.

This is pretty much what rclone will do eventually!

16

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