Rclone mount: 'preserving times', 'preserving permissions': 'Operation not permitted'

febeling · January 25, 2021, 4:07pm

What is the problem you are having with rclone?

I'm using rclone as peertube storage via rclone mount. Background jobs crash due to EPERM exception.

The mount is established correctly, and can be read and written to, from the user in question.

I'm able to reproduce the error message from the shell. A file touch or a 'cp' works without error. When using 'mv' for the same operation, this (below) warning is printed to the shell. See the following terminal session:

$ touch test1 
$ cp test1 /rclonevol/ # <- works 
$ mv test1 /rclonevol/test2 # <- emits warnings below
mv: preserving times for '/rclonevol/test2': Operation not permitted
mv: preserving permissions for ‘/rclonevol/test2’: Operation not permitted

$ echo $? # does this produce error exit code? - no
0

$ ll /rclonevol/ # both operations seem successful
total 4
drwxrwxrwx  1 root root    0 Jan 25 15:17 ./
drwxr-xr-x 20 root root 4096 Jan 25 10:47 ../
drwxrwxrwx  1 root root    0 Jan 25 15:25 storage/
-rw-rw-rw-  1 root root    0 Jan 25 15:17 test1
-rw-rw-rw-  1 root root    0 Jan 25 15:17 test2

I'm just assuming at this stage that the warning above is related to the error, because the message is the same wording when node.js raises it ('operation not permitted', EPERM).

In the shell it's not changing the shell operations exit code to non-zero, but node might map this differently to an error state.

At any rate, I'd like to understand and remove the cause for this permission warning.

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

$ rclone version
rclone v1.53.4

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

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

Ubuntu 20.04.1 LTS 64bit

Which cloud storage system are you using? (eg Google Drive)

DigitalOcean

The command you were trying to run (eg `rclone copy /tmp remote:tmp`)

Jan 25 15:17:56 prototube rclone[36072]: 2021/01/25 15:17:56 DEBUG : rclone: Version "v1.53.4"
 starting with parameters [
 "/usr/bin/rclone" "mount" "dospace:/peertube-space" "/rclonevol" "-vv"
 "--config=/var/lib/rclone/.config/rclone/rclone.conf"
 "--allow-other"
 "--allow-root"
 "--default-permissions"
 "--cache-tmp-upload-path=/tmp/rclone/root/dospace/upload"
 "--cache-chunk-path=/tmp/rclone/root/dospace/chunks"
 "--cache-workers=8"
 "--cache-writes"
 "--cache-dir=/tmp/rclone/root/dospace/vfs"
 "--cache-db-path=/tmp/rclone/root/dospace/db"
 "--no-seek"
 "--no-modtime"
 "--stats=1m"
 "--checkers=16"
 "--bwlimit=40M"
 "--cache-info-age=60m"
 "--attr-timeout=1s"
 "--dir-cache-time=60m"
 "--dir-perms=0777"
 "--file-perms=0666"
 "--gid=0"
 "--max-read-ahead=128k"
 "--poll-interval=1m0s"
 "--uid=0"
 "--umask=000"
 "--vfs-cache-max-age=1h0m0s"
 "--vfs-cache-max-size=off"
 "--vfs-cache-mode=full"
 "--vfs-cache-poll-interval=1m0s"
 "--vfs-read-chunk-size=128M"
 "--vfs-read-chunk-size-limit=off"
]

The command is generated by systemd config, a modified version from the one offered in the wiki. It's adapted to allow access by other users (/etc/fuse.conf change too).

The rclone config contents with secrets removed.

[dospace]
type = s3
provider = DigitalOcean
env_auth = false
access_key_id = ***
secret_access_key = ***
region = fra1
endpoint = fra1.digitaloceanspaces.com
location_constraint = fra1
acl = private

A log from the command with the `-vv` flag

Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : /: Attr:
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxrwx, err=<nil>
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : /: Lookup: name="test1"
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : /: >Lookup: node=test1, err=<nil>
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test1: Attr:
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test1: >Attr: a=valid=1s ino=0 size=0 mode=-rw-rw-rw-, err=<nil>
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test1: Open: flags=OpenWriteOnly
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test1: Open: flags=O_WRONLY
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test1: >Open: fd=test1 (w), err=<nil>
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test1: >Open: fh=&{test1 (w)}, err=<nil>
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test1: Setattr: a=Setattr [ID=0x104 Node=0x3 Uid=1001 Gid=116 Pid=36617] size=0 handle=INVALID-0x0 lockowner
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test1: Truncating 1 file handles
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test1: >Setattr: err=<nil>
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test1: Attr:
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test1: >Attr: a=valid=1s ino=0 size=0 mode=-rw-rw-rw-, err=<nil>
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : &{test1 (w)}: Flush:
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test1: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : : Added virtual directory entry vAdd: "test1"
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : &{test1 (w)}: >Flush: err=<nil>
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : &{test1 (w)}: Release:
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test1: WriteFileHandle.Release closing
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : S3 bucket peertube-space: File to upload is small (0 bytes), uploading instead of streaming
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test2: Attr:
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test2: >Attr: a=valid=1s ino=0 size=0 mode=-rw-rw-rw-, err=<nil>
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : /: Remove: name="test2"
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test2: Remove:
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : : Added virtual directory entry vDel: "test2"
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test2: >Remove: err=<nil>
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : /: >Remove: err=<nil>
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : /: Attr:
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxrwx, err=<nil>
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : /: Lookup: name="test2"
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : /: Create: name="test2"
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test2: Open: flags=O_WRONLY|O_CREATE|O_EXCL
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : : Added virtual directory entry vAdd: "test2"
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test2: >Open: fd=test2 (w), err=<nil>
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : /: >Create: node=test2, handle=&{test2 (w)}, err=<nil>
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test2: Attr:
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test2: >Attr: a=valid=1s ino=0 size=0 mode=-rw-rw-rw-, err=<nil>
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test2: Attr:
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test2: >Attr: a=valid=1s ino=0 size=0 mode=-rw-rw-rw-, err=<nil>
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test2: Attr:
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test2: >Attr: a=valid=1s ino=0 size=0 mode=-rw-rw-rw-, err=<nil>
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : &{test2 (w)}: Flush:
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test2: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : : Added virtual directory entry vAdd: "test2"
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : &{test2 (w)}: >Flush: err=<nil>
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : &{test2 (w)}: Release:
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test2: WriteFileHandle.Release closing
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : S3 bucket peertube-space: File to upload is small (0 bytes), uploading instead of streaming
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test2: MD5 = d41d8cd98f00b204e9800998ecf8427e OK
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 INFO  : test2: Copied (new)
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : : Added virtual directory entry vAdd: "test2"
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : &{test2 (w)}: >Release: err=<nil>
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : test1: MD5 = d41d8cd98f00b204e9800998ecf8427e OK
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 INFO  : test1: Copied (new)
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : : Added virtual directory entry vAdd: "test1"
Jan 25 15:55:09 protophont rclone[36072]: 2021/01/25 15:55:09 DEBUG : &{test1 (w)}: >Release: err=<nil>

Animosity022 · January 25, 2021, 4:13pm

You have so many flags that aren't needed/do nothing your setup, it's a bit tough to tell if a particular flag is doing.

Can you trip that down to just the mount with:

you config file location

--cache-dir=/tmp/rclone/root/dospace/vfs
--vfs-cache-mode=full

And run that with -vv and share the log?

febeling · January 25, 2021, 4:36pm

Jan 25 16:31:52 prototube systemd[1]: Stopping RClone mount...
Jan 25 16:31:52 prototube rclone[37378]: 2021/01/25 16:31:52 DEBUG : vfs cache: cleaner exiting
Jan 25 16:31:52 prototube rclone[37378]: 2021/01/25 16:31:52 DEBUG : rclone: Version "v1.53.4" finishing with parameters ["/usr/bin/rclone" "mount" "dospace:/peertube-space" "/rclonevol" "-vv" "--config=/var/lib/rclone/.config/rclone/rclone.conf" "--cache-dir=/tmp/rclone/root/dospace/vfs" "--vfs-cache-mode=full"]
Jan 25 16:31:52 prototube systemd[1]: rclone.service: Succeeded.
Jan 25 16:31:52 prototube systemd[1]: Stopped RClone mount.
Jan 25 16:31:52 prototube systemd[1]: Starting RClone mount...
Jan 25 16:31:52 prototube rclone[37438]: 2021/01/25 16:31:52 DEBUG : rclone: Version "v1.53.4" starting with parameters ["/usr/bin/rclone" "mount" "dospace:/peertube-space" "/rclonevol" "-vv" "--config=/var/lib/rclone/.config/rclone/rclone.conf" "--cache-dir=/tmp/rclone/root/dospace/vfs" "--vfs-cache-mode=full"]
Jan 25 16:31:52 prototube rclone[37438]: 2021/01/25 16:31:52 DEBUG : Creating backend with remote "dospace:/peertube-space"
Jan 25 16:31:52 prototube rclone[37438]: 2021/01/25 16:31:52 DEBUG : Using config file from "/var/lib/rclone/.config/rclone/rclone.conf"
Jan 25 16:31:52 prototube rclone[37438]: 2021/01/25 16:31:52 DEBUG : fs cache: renaming cache item "dospace:/peertube-space" to be canonical "dospace:peertube-space"
Jan 25 16:31:52 prototube rclone[37438]: 2021/01/25 16:31:52 INFO  : S3 bucket peertube-space: poll-interval is not supported by this remote
Jan 25 16:31:52 prototube rclone[37438]: 2021/01/25 16:31:52 DEBUG : vfs cache: root is "/tmp/rclone/root/dospace/vfs/vfs/dospace/peertube-space"
Jan 25 16:31:52 prototube rclone[37438]: 2021/01/25 16:31:52 DEBUG : vfs cache: metadata root is "/tmp/rclone/root/dospace/vfs/vfs/dospace/peertube-space"
Jan 25 16:31:52 prototube rclone[37438]: 2021/01/25 16:31:52 DEBUG : Creating backend with remote "/tmp/rclone/root/dospace/vfs/vfs/dospace/peertube-space"
Jan 25 16:31:52 prototube rclone[37438]: 2021/01/25 16:31:52 DEBUG : S3 bucket peertube-space: Mounting on "/rclonevol"
Jan 25 16:31:52 prototube rclone[37438]: 2021/01/25 16:31:52 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
Jan 25 16:31:52 prototube rclone[37438]: 2021/01/25 16:31:52 DEBUG : : Root:
Jan 25 16:31:52 prototube rclone[37438]: 2021/01/25 16:31:52 DEBUG : : >Root: node=/, err=<nil>
Jan 25 16:31:52 prototube systemd[1]: Started RClone mount.

The operations from the test now fail hard, and already on the 'cp', due to lack of permission.

$ ./optest.sh 
+ set -e
+ cd /tmp
+ touch test1
+ rm -f '/rclone/test*'
+ cp test1 /rclonevol/
cp: failed to access '/rclonevol/': Permission denied

I know that the setup is a bit verbose. It's based on the systemd config from the wiki, which makes a point to document defaults. I'd be interested which flags would be commonly/typically recommended.

Animosity022 · January 25, 2021, 4:38pm

Are you copying as the same user running the mount?

febeling · January 25, 2021, 4:52pm

I was using a different user, which is my desired setup. Here the output if I run without setting 'User' and 'Group' in systemd config and operate the shell as root:

# ./optest.sh 
+ set -e
+ cd /tmp
+ touch test1
+ rm -f '/rclone/test*'
+ cp test1 /rclonevol/
+ mv test1 /rclonevol/test2

No warning, no error!

Jan 25 16:48:29 prototube systemd[1]: Stopping RClone mount...
Jan 25 16:48:29 prototube rclone[37644]: 2021/01/25 16:48:29 DEBUG : vfs cache: cleaner exiting
Jan 25 16:48:29 prototube rclone[37644]: 2021/01/25 16:48:29 DEBUG : rclone: Version "v1.53.4" finishing with parameters ["/usr/bin/rclone" "mount" "dospace:/peertube-space" "/rclonevol" "-vv" "--config=/var/lib/rclone/.config/rclone/rclone.conf" "--cache-dir=/tmp/rclone/root/dospace/vfs" "--vfs-cache-mode=full"]
Jan 25 16:48:29 prototube systemd[1]: rclone.service: Succeeded.
Jan 25 16:48:29 prototube systemd[1]: Stopped RClone mount.
Jan 25 16:48:29 prototube systemd[1]: Starting RClone mount...
Jan 25 16:48:29 prototube rclone[37721]: 2021/01/25 16:48:29 DEBUG : rclone: Version "v1.53.4" starting with parameters ["/usr/bin/rclone" "mount" "dospace:/peertube-space" "/rclonevol" "-vv" "--config=/var/lib/rclone/.config/rclone/rclone.conf" "--cache-dir=/tmp/rclone/root/dospace/vfs" "--vfs-cache-mode=full"]
Jan 25 16:48:29 prototube rclone[37721]: 2021/01/25 16:48:29 DEBUG : Creating backend with remote "dospace:/peertube-space"
Jan 25 16:48:29 prototube rclone[37721]: 2021/01/25 16:48:29 DEBUG : Using config file from "/var/lib/rclone/.config/rclone/rclone.conf"
Jan 25 16:48:29 prototube rclone[37721]: 2021/01/25 16:48:29 DEBUG : fs cache: renaming cache item "dospace:/peertube-space" to be canonical "dospace:peertube-space"
Jan 25 16:48:29 prototube rclone[37721]: 2021/01/25 16:48:29 INFO  : S3 bucket peertube-space: poll-interval is not supported by this remote
Jan 25 16:48:29 prototube rclone[37721]: 2021/01/25 16:48:29 DEBUG : vfs cache: root is "/tmp/rclone/root/dospace/vfs/vfs/dospace/peertube-space"
Jan 25 16:48:29 prototube rclone[37721]: 2021/01/25 16:48:29 DEBUG : vfs cache: metadata root is "/tmp/rclone/root/dospace/vfs/vfs/dospace/peertube-space"
Jan 25 16:48:29 prototube rclone[37721]: 2021/01/25 16:48:29 DEBUG : Creating backend with remote "/tmp/rclone/root/dospace/vfs/vfs/dospace/peertube-space"
Jan 25 16:48:29 prototube rclone[37721]: 2021/01/25 16:48:29 DEBUG : S3 bucket peertube-space: Mounting on "/rclonevol"
Jan 25 16:48:29 prototube rclone[37721]: 2021/01/25 16:48:29 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item test1 not removed, freed 0 bytes
Jan 25 16:48:29 prototube rclone[37721]: 2021/01/25 16:48:29 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item test2 not removed, freed 0 bytes
Jan 25 16:48:29 prototube rclone[37721]: 2021/01/25 16:48:29 INFO  : vfs cache: cleaned: objects 2 (was 2) in use 0, to upload 0, uploading 0, total size 0 (was 0)
Jan 25 16:48:29 prototube rclone[37721]: 2021/01/25 16:48:29 DEBUG : : Root:
Jan 25 16:48:29 prototube rclone[37721]: 2021/01/25 16:48:29 DEBUG : : >Root: node=/, err=<nil>
Jan 25 16:48:29 prototube systemd[1]: Started RClone mount.
Jan 25 16:48:33 prototube rclone[37721]: 2021/01/25 16:48:33 DEBUG : /: Attr:
Jan 25 16:48:33 prototube rclone[37721]: 2021/01/25 16:48:33 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Jan 25 16:48:33 prototube rclone[37721]: 2021/01/25 16:48:33 DEBUG : /: Lookup: name="test1"
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : /: >Lookup: node=test1, err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1: Attr:
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1: Open: flags=OpenWriteOnly
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1: Open: flags=O_WRONLY
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1: newRWFileHandle:
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1: >newRWFileHandle: err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1: >Open: fd=test1 (rw), err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1: >Open: fh=&{test1 (rw)}, err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1: Setattr: a=Setattr [ID=0xc Node=0x2 Uid=0 Gid=0 Pid=37739] size=0 handle=INVALID-0x0 lockowner
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1: Truncating 1 file handles
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1(0xc00043c2c0): openPending:
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1: vfs cache: checking remote fingerprint "0,2021-01-25 15:55:09.47385455 +0000 UTC,d41d8cd98f00b204e9800998ecf8427e" against cached fingerprint "0,2021-01-25 15:55:09.47385455 +0000 UTC,d41d8cd98f00b204e9800998ecf8427e"
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1: vfs cache: truncate to size=0
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : : Added virtual directory entry vAdd: "test1"
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1(0xc00043c2c0): >openPending: err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1: >Setattr: err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1: Attr:
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : &{test1 (rw)}: Flush:
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1(0xc00043c2c0): RWFileHandle.Flush
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : &{test1 (rw)}: >Flush: err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : &{test1 (rw)}: Release:
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1(0xc00043c2c0): RWFileHandle.Release
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1(0xc00043c2c0): close:
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1: vfs cache: setting modification time to 2021-01-25 15:55:09.47385455 +0000 UTC
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test1(0xc00043c2c0): >close: err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : &{test1 (rw)}: >Release: err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : /: Lookup: name="test2"
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : /: >Lookup: node=test2, err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: Attr:
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : /: Remove: name="test2"
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: Remove:
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 INFO  : test2: vfs cache: removed cache file as file deleted
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: vfs cache: removed metadata from cache as file deleted
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : : Added virtual directory entry vDel: "test2"
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: >Remove: err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : /: >Remove: err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : /: Lookup: name="test2"
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : /: Create: name="test2"
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: Open: flags=O_WRONLY|O_CREATE|O_EXCL
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: newRWFileHandle:
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2(0xc0000acc80): openPending:
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: vfs cache: truncate to size=0
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : : Added virtual directory entry vAdd: "test2"
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2(0xc0000acc80): >openPending: err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: >newRWFileHandle: err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : : Added virtual directory entry vAdd: "test2"
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: >Open: fd=test2 (rw), err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : /: >Create: node=test2, handle=&{test2 (rw)}, err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: Attr:
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: Setattr: a=Setattr [ID=0x1c Node=0x3 Uid=0 Gid=0 Pid=37742] atime=2021-01-25 16:48:34.077910529 +0000 UTC mtime=2021-01-25 16:48:33.933910507 +0000 UTC handle=INVALID-0x0
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: vfs cache: setting modification time to 2021-01-25 16:48:33.933910507 +0000 UTC
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: >Setattr: err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: Attr:
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: Setattr: a=Setattr [ID=0x20 Node=0x3 Uid=0 Gid=0 Pid=37742] mode=-rw-r--r-- handle=INVALID-0x0
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: >Setattr: err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: Attr:
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : &{test2 (rw)}: Flush:
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2(0xc0000acc80): RWFileHandle.Flush
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : &{test2 (rw)}: >Flush: err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : &{test2 (rw)}: Release:
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2(0xc0000acc80): RWFileHandle.Release
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2(0xc0000acc80): close:
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2: vfs cache: setting modification time to 2021-01-25 16:48:33.933910507 +0000 UTC
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 INFO  : test2: vfs cache: queuing for upload in 5s
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : test2(0xc0000acc80): >close: err=<nil>
Jan 25 16:48:34 prototube rclone[37721]: 2021/01/25 16:48:34 DEBUG : &{test2 (rw)}: >Release: err=<nil>

Animosity022 · January 25, 2021, 4:56pm

Ok, if you add in --allow-other to the mount and retest with the different, can you test that?

The way fuse mounts work is they are user based and allow-other is what lets another user see the filesystem.

febeling · January 25, 2021, 5:07pm

That works smoothly. Thank you!

For completeness sake the logs.

Jan 25 16:58:55 prototube systemd[1]: Starting RClone mount...
Jan 25 16:58:55 prototube rclone[37946]: 2021/01/25 16:58:55 DEBUG : rclone: Version "v1.53.4" starting with parameters ["/usr/bin/rclone" "mount" "dospace:/peertube-space" "/rclonevol" "-vv" "--config=/var/lib/rclone/.config/rclone/rclone.conf" "--allow-other" "--cache-dir=/tmp/rclone/root/dospace/vfs" "--vfs-cache-mode=full"]
Jan 25 16:58:55 prototube rclone[37946]: 2021/01/25 16:58:55 DEBUG : Creating backend with remote "dospace:/peertube-space"
Jan 25 16:58:55 prototube rclone[37946]: 2021/01/25 16:58:55 DEBUG : Using config file from "/var/lib/rclone/.config/rclone/rclone.conf"
Jan 25 16:58:55 prototube rclone[37946]: 2021/01/25 16:58:55 DEBUG : fs cache: renaming cache item "dospace:/peertube-space" to be canonical "dospace:peertube-space"
Jan 25 16:58:55 prototube rclone[37946]: 2021/01/25 16:58:55 INFO  : S3 bucket peertube-space: poll-interval is not supported by this remote
Jan 25 16:58:55 prototube rclone[37946]: 2021/01/25 16:58:55 DEBUG : vfs cache: root is "/tmp/rclone/root/dospace/vfs/vfs/dospace/peertube-space"
Jan 25 16:58:55 prototube rclone[37946]: 2021/01/25 16:58:55 DEBUG : vfs cache: metadata root is "/tmp/rclone/root/dospace/vfs/vfs/dospace/peertube-space"
Jan 25 16:58:55 prototube rclone[37946]: 2021/01/25 16:58:55 DEBUG : Creating backend with remote "/tmp/rclone/root/dospace/vfs/vfs/dospace/peertube-space"
Jan 25 16:58:55 prototube rclone[37946]: 2021/01/25 16:58:55 DEBUG : S3 bucket peertube-space: Mounting on "/rclonevol"
Jan 25 16:58:55 prototube rclone[37946]: 2021/01/25 16:58:55 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item test1 not removed, freed 0 bytes
Jan 25 16:58:55 prototube rclone[37946]: 2021/01/25 16:58:55 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item test2 not removed, freed 0 bytes
Jan 25 16:58:55 prototube rclone[37946]: 2021/01/25 16:58:55 INFO  : vfs cache: cleaned: objects 2 (was 2) in use 0, to upload 0, uploading 0, total size 0 (was 0)
Jan 25 16:58:55 prototube rclone[37946]: 2021/01/25 16:58:55 DEBUG : : Root:
Jan 25 16:58:55 prototube rclone[37946]: 2021/01/25 16:58:55 DEBUG : : >Root: node=/, err=<nil>
Jan 25 16:58:55 prototube systemd[1]: Started RClone mount.
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : /: Attr:
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : /: Lookup: name="test1"
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : /: >Lookup: node=test1, err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1: Attr:
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1: Open: flags=OpenWriteOnly
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1: Open: flags=O_WRONLY
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1: newRWFileHandle:
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1: >newRWFileHandle: err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1: >Open: fd=test1 (rw), err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1: >Open: fh=&{test1 (rw)}, err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1: Setattr: a=Setattr [ID=0xc Node=0x2 Uid=1001 Gid=116 Pid=37958] size=0 handle=INVALID-0x0 lockowner
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1: Truncating 1 file handles
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1(0xc0000a01c0): openPending:
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1: vfs cache: checking remote fingerprint "0,2021-01-25 15:55:09.47385455 +0000 UTC,d41d8cd98f00b204e9800998ecf8427e" against cached fingerprint "0,2021-01-25 15:55:09.47385455 +0000 UTC,d41d8cd98f00b204e9800998ecf8427e"
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1: vfs cache: truncate to size=0
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : : Added virtual directory entry vAdd: "test1"
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1(0xc0000a01c0): >openPending: err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1: >Setattr: err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1: Attr:
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : &{test1 (rw)}: Flush:
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1(0xc0000a01c0): RWFileHandle.Flush
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : &{test1 (rw)}: >Flush: err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : &{test1 (rw)}: Release:
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1(0xc0000a01c0): RWFileHandle.Release
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1(0xc0000a01c0): close:
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1: vfs cache: setting modification time to 2021-01-25 15:55:09.47385455 +0000 UTC
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test1(0xc0000a01c0): >close: err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : &{test1 (rw)}: >Release: err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : /: Lookup: name="test2"
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : /: >Lookup: node=test2, err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: Attr:
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : /: Remove: name="test2"
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: Remove:
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 INFO  : test2: vfs cache: removed cache file as file deleted
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: vfs cache: removed metadata from cache as file deleted
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : : Added virtual directory entry vDel: "test2"
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: >Remove: err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : /: >Remove: err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : /: Lookup: name="test2"
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : /: Create: name="test2"
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: Open: flags=O_WRONLY|O_CREATE|O_EXCL
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: newRWFileHandle:
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2(0xc0000a0e80): openPending:
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: vfs cache: truncate to size=0
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : : Added virtual directory entry vAdd: "test2"
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2(0xc0000a0e80): >openPending: err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: >newRWFileHandle: err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : : Added virtual directory entry vAdd: "test2"
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: >Open: fd=test2 (rw), err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : /: >Create: node=test2, handle=&{test2 (rw)}, err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: Attr:
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: Setattr: a=Setattr [ID=0x1e Node=0x3 Uid=1001 Gid=116 Pid=37962] atime=2021-01-25 16:59:05.905905309 +0000 UTC mtime=2021-01-25 16:59:05.689905334 +0000 UTC handle=INVALID-0x0
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: vfs cache: setting modification time to 2021-01-25 16:59:05.689905334 +0000 UTC
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: >Setattr: err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: Attr:
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: Attr:
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: Setattr: a=Setattr [ID=0x22 Node=0x3 Uid=1001 Gid=116 Pid=37962] uid=1001 gid=116 handle=INVALID-0x0
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: >Setattr: err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: Attr:
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: Setattr: a=Setattr [ID=0x26 Node=0x3 Uid=1001 Gid=116 Pid=37962] mode=-rw-r--r-- handle=INVALID-0x0
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: >Setattr: err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: Attr:
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : &{test2 (rw)}: Flush:
Jan 25 16:59:05 prototube rclone[37946]: 2021/01/25 16:59:05 DEBUG : test2(0xc0000a0e80): RWFileHandle.Flush
Jan 25 16:59:06 prototube rclone[37946]: 2021/01/25 16:59:06 DEBUG : &{test2 (rw)}: >Flush: err=<nil>
Jan 25 16:59:06 prototube rclone[37946]: 2021/01/25 16:59:06 DEBUG : &{test2 (rw)}: Release:
Jan 25 16:59:06 prototube rclone[37946]: 2021/01/25 16:59:06 DEBUG : test2(0xc0000a0e80): RWFileHandle.Release
Jan 25 16:59:06 prototube rclone[37946]: 2021/01/25 16:59:06 DEBUG : test2(0xc0000a0e80): close:
Jan 25 16:59:06 prototube rclone[37946]: 2021/01/25 16:59:06 DEBUG : test2: vfs cache: setting modification time to 2021-01-25 16:59:05.689905334 +0000 UTC
Jan 25 16:59:06 prototube rclone[37946]: 2021/01/25 16:59:06 INFO  : test2: vfs cache: queuing for upload in 5s
Jan 25 16:59:06 prototube rclone[37946]: 2021/01/25 16:59:06 DEBUG : test2(0xc0000a0e80): >close: err=<nil>
Jan 25 16:59:06 prototube rclone[37946]: 2021/01/25 16:59:06 DEBUG : &{test2 (rw)}: >Release: err=<nil>
Jan 25 16:59:11 prototube rclone[37946]: 2021/01/25 16:59:11 DEBUG : test2: vfs cache: starting upload
Jan 25 16:59:11 prototube rclone[37946]: 2021/01/25 16:59:11 DEBUG : test2: MD5 = d41d8cd98f00b204e9800998ecf8427e OK
Jan 25 16:59:11 prototube rclone[37946]: 2021/01/25 16:59:11 INFO  : test2: Copied (new)
Jan 25 16:59:11 prototube rclone[37946]: 2021/01/25 16:59:11 DEBUG : test2: vfs cache: fingerprint now "0,2021-01-25 16:59:05.689905334 +0000 UTC,d41d8cd98f00b204e9800998ecf8427e"
Jan 25 16:59:11 prototube rclone[37946]: 2021/01/25 16:59:11 DEBUG : test2: vfs cache: writeback object to VFS layer
Jan 25 16:59:11 prototube rclone[37946]: 2021/01/25 16:59:11 DEBUG : test2: Applied pending mod time 2021-01-25 16:59:05.689905334 +0000 UTC OK
Jan 25 16:59:11 prototube rclone[37946]: 2021/01/25 16:59:11 DEBUG : : Added virtual directory entry vAdd: "test2"
Jan 25 16:59:11 prototube rclone[37946]: 2021/01/25 16:59:11 INFO  : test2: vfs cache: upload succeeded try #1

Animosity022 · January 25, 2021, 5:13pm

Ok. I'd guess one of those flags before was causing the problem. I personally wouldn't add them all back, but a few you can tweak based on your needs.

I tweak how long you want to to remain cached locally which is the first item and the second limits the storage size:

--vfs-cache-max-age duration         Max age of objects in the cache. (default 1h0m0s)
--vfs-cache-max-size SizeSuffix      Max total size of objects in the cache. (default off)

You want adjust the size based on how much space you want rclone to consume locally before it cleans itself up.

DO is a S3 remote? I think those are non polling so you dir-cache time is default 5 minutes so if you added something outside the remote, it would take ~5 minutes to show up.

My general thought process is less flags unless I know why I am changing it.

febeling · January 25, 2021, 5:20pm

Yes, they are S3 compatible, and I saw a polling-related warning somewhere in the logs.

I generally want to cache a lot locally, so I'll increase those accordingly.

Thank you for the recommendations, much appreciated!

system · March 27, 2021, 1:20pm

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