Removed object still alive on mounted remote

Help and Support
1 
test@client $ rclone mount -v --vfs-cache-mode=minimal  home:misc /s3
test@client $ cd /s3
test@client $ touch test
test@client $ ls -l
-rw-rw-rw- 1 test NESSUNO 0 Dec 26 10:09 test

now remove test file from s3 bucket:

test@server $ mc ls local/misc
[2020-12-26 10:09:56 CET]     0B test
$ mc rm local/misc/test
Removing `local/misc/test`.

back to client:

test@client $ ls -la /s3/test
-rw-rw-rw-  1 test                   NESSUNO                     0 Dec 26 10:09 test

Logs:

2020/12/26 10:17:36 INFO  : vfs cache: cleaned: objects 3 (was 3) in use 0, to upload 0, uploading 0, total size 242.063k (was 242.063k)
2020/12/26 10:18:36 INFO  : vfs cache: cleaned: objects 3 (was 3) in use 0, to upload 0, uploading 0, total size 242.063k (was 242.063k)

rclone version
rclone v1.53.3
- os/arch: windows/amd64
- go version: go1.15.5

where am i wrong?

thnx.

2

If you post the full debug log, you can see what's going on much better which is why we ask for it.

What's 'mc'? and why is that before every command you are running?

S3 is a non polling remote so if you remove it elsewhere from the mount directly, you have to wait for dir-cache time to expire for something to be removed from the mount.

3

mc is minio client (s3 Object Storage), debug log:

2020/12/26 14:18:49 DEBUG : test: MD5 = d41d8cd98f00b204e9800998ecf8427e OK
2020/12/26 14:18:49 INFO  : test: Copied (new)
2020/12/26 14:18:50 DEBUG : test: Applied pending mod time 2020-12-26 14:18:49.3109599 +0100 CET OK
2020/12/26 14:18:50 DEBUG : : Added virtual directory entry vAdd: "test"
2020/12/26 14:18:50 DEBUG : /test: >Release: errc=0
2020/12/26 14:18:54 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:18:54 DEBUG : /: >Getattr: errc=0
2020/12/26 14:18:54 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:18:54 DEBUG : /: >Getattr: errc=0
2020/12/26 14:18:54 DEBUG : /: Opendir:
2020/12/26 14:18:54 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/12/26 14:18:54 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/12/26 14:18:54 DEBUG : /: >Opendir: errc=0, fh=0x1
2020/12/26 14:18:54 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:18:54 DEBUG : /: >Getattr: errc=0
2020/12/26 14:18:54 DEBUG : /: Releasedir: fh=0x1
2020/12/26 14:18:54 DEBUG : /: >Releasedir: errc=0
2020/12/26 14:18:54 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:18:54 DEBUG : /: >Getattr: errc=0
2020/12/26 14:18:54 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:18:54 DEBUG : /: >Getattr: errc=0
2020/12/26 14:18:54 DEBUG : /: Opendir:
2020/12/26 14:18:54 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/12/26 14:18:54 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/12/26 14:18:54 DEBUG : /: >Opendir: errc=0, fh=0x1
2020/12/26 14:18:54 DEBUG : /: Releasedir: fh=0x1
2020/12/26 14:18:54 DEBUG : /: >Releasedir: errc=0
2020/12/26 14:18:54 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:18:54 DEBUG : /: >Getattr: errc=0
2020/12/26 14:18:54 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:18:54 DEBUG : /: >Getattr: errc=0
2020/12/26 14:18:54 DEBUG : /: Opendir:
2020/12/26 14:18:54 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/12/26 14:18:54 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/12/26 14:18:54 DEBUG : /: >Opendir: errc=0, fh=0x1
2020/12/26 14:18:54 DEBUG : /: Readdir: ofst=0, fh=0x1
2020/12/26 14:18:54 DEBUG : /: >Readdir: items=1, errc=0
2020/12/26 14:18:54 DEBUG : /test: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:18:54 DEBUG : /test: >Getattr: errc=0
2020/12/26 14:18:54 DEBUG : /test: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:18:54 DEBUG : /test: >Getattr: errc=0
2020/12/26 14:18:54 DEBUG : /test: OpenEx: flags=0x0
2020/12/26 14:18:54 DEBUG : /test: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/12/26 14:18:54 DEBUG : test: Open: flags=O_RDONLY
2020/12/26 14:18:54 DEBUG : test: >Open: fd=test (r), err=<nil>
2020/12/26 14:18:54 DEBUG : /test: >OpenFile: fd=test (r), err=<nil>
2020/12/26 14:18:54 DEBUG : /test: >OpenEx: errc=0, fh=0x2
2020/12/26 14:18:54 DEBUG : /: Statfs:
2020/12/26 14:18:54 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2020/12/26 14:18:54 DEBUG : /test: Getattr: fh=0x2
2020/12/26 14:18:54 DEBUG : /test: >Getattr: errc=0
2020/12/26 14:18:54 DEBUG : /test: Flush: fh=0x2
2020/12/26 14:18:54 DEBUG : /test: >Flush: errc=0
2020/12/26 14:18:54 DEBUG : /test: Release: fh=0x2
2020/12/26 14:18:54 DEBUG : /test: >Release: errc=0
2020/12/26 14:18:54 DEBUG : /test: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:18:54 DEBUG : /test: >Getattr: errc=0
2020/12/26 14:18:54 DEBUG : /test: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:18:54 DEBUG : /test: >Getattr: errc=0
2020/12/26 14:18:54 DEBUG : /test: OpenEx: flags=0x0
2020/12/26 14:18:54 DEBUG : /test: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/12/26 14:18:54 DEBUG : test: Open: flags=O_RDONLY
2020/12/26 14:18:54 DEBUG : test: >Open: fd=test (r), err=<nil>
2020/12/26 14:18:54 DEBUG : /test: >OpenFile: fd=test (r), err=<nil>
2020/12/26 14:18:54 DEBUG : /test: >OpenEx: errc=0, fh=0x2
2020/12/26 14:18:54 DEBUG : /test: Getattr: fh=0x2
2020/12/26 14:18:54 DEBUG : /test: >Getattr: errc=0
2020/12/26 14:18:54 DEBUG : /test: Flush: fh=0x2
2020/12/26 14:18:54 DEBUG : /test: >Flush: errc=0
2020/12/26 14:18:54 DEBUG : /test: Release: fh=0x2
2020/12/26 14:18:54 DEBUG : /test: >Release: errc=0
2020/12/26 14:18:54 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:18:54 DEBUG : /: >Getattr: errc=0
2020/12/26 14:18:54 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:18:54 DEBUG : /: >Getattr: errc=0
2020/12/26 14:18:54 DEBUG : /: Opendir:
2020/12/26 14:18:54 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/12/26 14:18:54 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/12/26 14:18:54 DEBUG : /: >Opendir: errc=0, fh=0x2
2020/12/26 14:18:54 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:18:54 DEBUG : /: >Getattr: errc=0
2020/12/26 14:18:54 DEBUG : /: Releasedir: fh=0x2
2020/12/26 14:18:54 DEBUG : /: >Releasedir: errc=0
2020/12/26 14:18:54 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:18:54 DEBUG : /: >Getattr: errc=0
2020/12/26 14:18:54 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:18:54 DEBUG : /: >Getattr: errc=0
2020/12/26 14:18:54 DEBUG : /: Opendir:
2020/12/26 14:18:54 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/12/26 14:18:54 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/12/26 14:18:54 DEBUG : /: >Opendir: errc=0, fh=0x2
2020/12/26 14:18:54 DEBUG : /: Releasedir: fh=0x2
2020/12/26 14:18:54 DEBUG : /: >Releasedir: errc=0
2020/12/26 14:18:54 DEBUG : /: Releasedir: fh=0x1
2020/12/26 14:18:54 DEBUG : /: >Releasedir: errc=0
2020/12/26 14:18:54 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:18:54 DEBUG : /: >Getattr: errc=0
2020/12/26 14:18:54 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:18:54 DEBUG : /: >Getattr: errc=0
2020/12/26 14:18:54 DEBUG : /: Opendir:
2020/12/26 14:18:54 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/12/26 14:18:54 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/12/26 14:18:54 DEBUG : /: >Opendir: errc=0, fh=0x1
2020/12/26 14:18:54 DEBUG : /: Releasedir: fh=0x1
2020/12/26 14:18:54 DEBUG : /: >Releasedir: errc=0
2020/12/26 14:19:34 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:19:34 DEBUG : /: >Getattr: errc=0
2020/12/26 14:19:34 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:19:34 DEBUG : /: >Getattr: errc=0
2020/12/26 14:19:34 DEBUG : /: Opendir:
2020/12/26 14:19:34 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/12/26 14:19:34 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/12/26 14:19:34 DEBUG : /: >Opendir: errc=0, fh=0x1
2020/12/26 14:19:34 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:19:34 DEBUG : /: >Getattr: errc=0
2020/12/26 14:19:34 DEBUG : /: Releasedir: fh=0x1
2020/12/26 14:19:34 DEBUG : /: >Releasedir: errc=0
2020/12/26 14:19:34 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:19:34 DEBUG : /: >Getattr: errc=0
2020/12/26 14:19:34 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:19:34 DEBUG : /: >Getattr: errc=0
2020/12/26 14:19:34 DEBUG : /: Opendir:
2020/12/26 14:19:34 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/12/26 14:19:34 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/12/26 14:19:34 DEBUG : /: >Opendir: errc=0, fh=0x1
2020/12/26 14:19:34 DEBUG : /: Releasedir: fh=0x1
2020/12/26 14:19:34 DEBUG : /: >Releasedir: errc=0
2020/12/26 14:19:34 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:19:34 DEBUG : /: >Getattr: errc=0
2020/12/26 14:19:34 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:19:34 DEBUG : /: >Getattr: errc=0
2020/12/26 14:19:34 DEBUG : /: Opendir:
2020/12/26 14:19:34 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/12/26 14:19:34 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/12/26 14:19:34 DEBUG : /: >Opendir: errc=0, fh=0x1
2020/12/26 14:19:34 DEBUG : /: Readdir: ofst=0, fh=0x1
2020/12/26 14:19:34 DEBUG : /: >Readdir: items=1, errc=0
2020/12/26 14:19:34 DEBUG : /test: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:19:34 DEBUG : /test: >Getattr: errc=0
2020/12/26 14:19:34 DEBUG : /test: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:19:34 DEBUG : /test: >Getattr: errc=0
2020/12/26 14:19:34 DEBUG : /test: OpenEx: flags=0x0
2020/12/26 14:19:34 DEBUG : /test: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/12/26 14:19:34 DEBUG : test: Open: flags=O_RDONLY
2020/12/26 14:19:34 DEBUG : test: >Open: fd=test (r), err=<nil>
2020/12/26 14:19:34 DEBUG : /test: >OpenFile: fd=test (r), err=<nil>
2020/12/26 14:19:34 DEBUG : /test: >OpenEx: errc=0, fh=0x2
2020/12/26 14:19:34 DEBUG : /: Statfs:
2020/12/26 14:19:34 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2020/12/26 14:19:34 DEBUG : /test: Getattr: fh=0x2
2020/12/26 14:19:34 DEBUG : /test: >Getattr: errc=0
2020/12/26 14:19:34 DEBUG : /test: Flush: fh=0x2
2020/12/26 14:19:34 DEBUG : /test: >Flush: errc=0
2020/12/26 14:19:34 DEBUG : /test: Release: fh=0x2
2020/12/26 14:19:34 DEBUG : /test: >Release: errc=0
2020/12/26 14:19:34 DEBUG : /test: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:19:34 DEBUG : /test: >Getattr: errc=0
2020/12/26 14:19:34 DEBUG : /test: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:19:34 DEBUG : /test: >Getattr: errc=0
2020/12/26 14:19:34 DEBUG : /test: OpenEx: flags=0x0
2020/12/26 14:19:34 DEBUG : /test: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/12/26 14:19:34 DEBUG : test: Open: flags=O_RDONLY
2020/12/26 14:19:34 DEBUG : test: >Open: fd=test (r), err=<nil>
2020/12/26 14:19:34 DEBUG : /test: >OpenFile: fd=test (r), err=<nil>
2020/12/26 14:19:34 DEBUG : /test: >OpenEx: errc=0, fh=0x2
2020/12/26 14:19:34 DEBUG : /test: Getattr: fh=0x2
2020/12/26 14:19:34 DEBUG : /test: >Getattr: errc=0
2020/12/26 14:19:34 DEBUG : /test: Flush: fh=0x2
2020/12/26 14:19:34 DEBUG : /test: >Flush: errc=0
2020/12/26 14:19:34 DEBUG : /test: Release: fh=0x2
2020/12/26 14:19:34 DEBUG : /test: >Release: errc=0
2020/12/26 14:19:34 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:19:34 DEBUG : /: >Getattr: errc=0
2020/12/26 14:19:34 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:19:34 DEBUG : /: >Getattr: errc=0
2020/12/26 14:19:34 DEBUG : /: Opendir:
2020/12/26 14:19:34 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/12/26 14:19:34 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/12/26 14:19:34 DEBUG : /: >Opendir: errc=0, fh=0x2
2020/12/26 14:19:34 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:19:34 DEBUG : /: >Getattr: errc=0
2020/12/26 14:19:34 DEBUG : /: Releasedir: fh=0x2
2020/12/26 14:19:34 DEBUG : /: >Releasedir: errc=0
2020/12/26 14:19:34 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:19:34 DEBUG : /: >Getattr: errc=0
2020/12/26 14:19:34 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:19:34 DEBUG : /: >Getattr: errc=0
2020/12/26 14:19:34 DEBUG : /: Opendir:
2020/12/26 14:19:34 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/12/26 14:19:34 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/12/26 14:19:34 DEBUG : /: >Opendir: errc=0, fh=0x2
2020/12/26 14:19:34 DEBUG : /: Releasedir: fh=0x2
2020/12/26 14:19:34 DEBUG : /: >Releasedir: errc=0
2020/12/26 14:19:34 DEBUG : /: Releasedir: fh=0x1
2020/12/26 14:19:34 DEBUG : /: >Releasedir: errc=0
2020/12/26 14:19:34 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:19:34 DEBUG : /: >Getattr: errc=0
2020/12/26 14:19:34 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2020/12/26 14:19:34 DEBUG : /: >Getattr: errc=0
2020/12/26 14:19:34 DEBUG : /: Opendir:
2020/12/26 14:19:34 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2020/12/26 14:19:34 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2020/12/26 14:19:34 DEBUG : /: >Opendir: errc=0, fh=0x1
2020/12/26 14:19:34 DEBUG : /: Releasedir: fh=0x1
2020/12/26 14:19:34 DEBUG : /: >Releasedir: errc=0
4

Ah, so yeah dir-cache would explain it.

  • You have a non polling mounted remote
  • You create a file on the mount or anywhere else and it's "there"
  • You use some 3rd party to delete it other than on the mount itself
  • You have to wait for dir-cache time to expire before you see change on the mount
--dir-cache-time duration   Time to cache directory entries for. (default 5m0s)

You only included a snippet of the debug log as the information as the beginning is what I would show you.

1 Like
5

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