Consistent problem with Google Drive via Rclone mount

Help and Support
1

What is the problem you are having with rclone?

Hello. I have a strange issue when I use Rclone mount with Google Drive.

# rclone mount ...
# cd Upload
# ls
Test <- There is a folder in the current directory

I deleted the folder "Test" on Google Drive (Web, Backup and Sync, etc)
Now wait for the dir cache to expire

# ls <- Nothing here
# mkdir Test
# ls
Test

I created a folder with the same name from Rclone mount. However, this folder disappeared on Google Drive.

# cd Test
# touch a

Any files I create in this folder will appear in Trash.
After the directory cache expires, the directory disappears from the local.

Any ideas? I can no longer create a directory with the same name after deleting it from the remote. Even refresh the directory cache it doesn't work for me. (kill -SIGHUP $(pidof rclone))

What is your rclone version (output from rclone version)

rclone v1.52.2

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

Debian 10

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 --allow-other --daemon --vfs-cache-mode writes
2

Can you please replicate the issue and include a log with -vv so we can see the debug.

3

Done.

2020/07/13 14:45:07 DEBUG : : Statfs:
2020/07/13 14:45:07 DEBUG : : >Statfs: stat={Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>
...
2020/07/13 14:45:13 DEBUG : Google drive root 'Drive': Checking for changes on remote
2020/07/13 14:45:13 DEBUG : : changeNotify: relativePath="Upload/Test", type=2
2020/07/13 14:45:13 DEBUG : Upload: invalidating directory cache
2020/07/13 14:45:13 DEBUG : : >changeNotify:
2020/07/13 14:45:13 DEBUG : : changeNotify: relativePath="Upload", type=2
2020/07/13 14:45:13 DEBUG : : invalidating directory cache
2020/07/13 14:45:13 DEBUG : : >changeNotify:
...
2020/07/13 14:45:26 DEBUG : Upload/: Attr:
2020/07/13 14:45:26 DEBUG : Upload/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/13 14:45:26 DEBUG : Upload/: ReadDirAll:
2020/07/13 14:45:27 DEBUG : Upload/: >ReadDirAll: item=0, err=<nil>
2020/07/13 14:45:27 DEBUG : /: Lookup: name="Upload"
...
2020/07/13 14:45:27 DEBUG : /: >Lookup: node=Upload/, err=<nil>
2020/07/13 14:45:27 DEBUG : Upload/: Attr:
2020/07/13 14:45:27 DEBUG : Upload/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
...
2020/07/13 14:45:27 DEBUG : /: Attr:
2020/07/13 14:45:27 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
...
2020/07/13 14:45:29 DEBUG : Upload/: Lookup: name="Test"
2020/07/13 14:45:29 DEBUG : Upload/: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:29 DEBUG : Upload/: Lookup: name="Test"
2020/07/13 14:45:29 DEBUG : Upload/: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:29 DEBUG : Upload/: Mkdir: name="Test"
2020/07/13 14:45:29 DEBUG : Upload/: >Mkdir: node=Upload/Test/, err=<nil>
2020/07/13 14:45:29 DEBUG : Upload/Test/: Attr:
2020/07/13 14:45:29 DEBUG : Upload/Test/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/13 14:45:29 DEBUG : /: Lookup: name="Upload"
2020/07/13 14:45:29 DEBUG : /: >Lookup: node=Upload/, err=<nil>
2020/07/13 14:45:29 DEBUG : Upload/: Attr:
2020/07/13 14:45:29 DEBUG : Upload/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
...
2020/07/13 14:45:29 DEBUG : /: Attr:
2020/07/13 14:45:29 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
...
2020/07/13 14:45:31 DEBUG : Upload/: Attr:
2020/07/13 14:45:31 DEBUG : Upload/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/13 14:45:31 DEBUG : /: Lookup: name="Upload"
2020/07/13 14:45:31 DEBUG : /: >Lookup: node=Upload/, err=<nil>
2020/07/13 14:45:31 DEBUG : Upload/: Attr:
2020/07/13 14:45:31 DEBUG : Upload/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/13 14:45:31 DEBUG : Upload/Test/: Attr:
2020/07/13 14:45:31 DEBUG : Upload/Test/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
...
2020/07/13 14:45:33 DEBUG : Upload/Test/: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:33 DEBUG : /: Lookup: name="Upload"
2020/07/13 14:45:33 DEBUG : /: >Lookup: node=Upload/, err=<nil>
2020/07/13 14:45:33 DEBUG : Upload/: Attr:
2020/07/13 14:45:33 DEBUG : Upload/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
...
2020/07/13 14:45:33 DEBUG : /: Attr:
2020/07/13 14:45:33 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
...
2020/07/13 14:45:33 DEBUG : Upload/Test/: Attr:
2020/07/13 14:45:33 DEBUG : Upload/Test/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
...
2020/07/13 14:45:34 DEBUG : Upload/Test/: Lookup: name="a"
2020/07/13 14:45:34 DEBUG : Upload/Test/: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:34 DEBUG : Upload/Test/: Create: name="a"
2020/07/13 14:45:34 DEBUG : Upload/Test/a: Open: flags=O_WRONLY|O_CREATE|0x800
2020/07/13 14:45:34 DEBUG : Upload/Test/a(0xc0004b0740): Opening cached copy with flags=O_WRONLY|O_CREATE|0x800
2020/07/13 14:45:34 DEBUG : Upload/Test/a: >Open: fd=Upload/Test/a (rw), err=<nil>
2020/07/13 14:45:34 DEBUG : Upload/Test/: >Create: node=Upload/Test/a, handle=&{Upload/Test/a (rw)}, err=<nil>
2020/07/13 14:45:34 DEBUG : Upload/Test/a: Attr:
2020/07/13 14:45:34 DEBUG : Upload/Test/a: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
2020/07/13 14:45:34 DEBUG : &{Upload/Test/a (rw)}: Flush:
2020/07/13 14:45:34 DEBUG : Upload/Test/a(0xc0004b0740): RWFileHandle.Flush ignoring flush on unwritten handle
2020/07/13 14:45:34 DEBUG : &{Upload/Test/a (rw)}: >Flush: err=<nil>
2020/07/13 14:45:34 DEBUG : Upload/Test/a: Setattr: a=Setattr [ID=0xe3 Node=0xc Uid=0 Gid=0 Pid=3458] atime=2020-07-13 14:45:34.915567811 +0000 UTC atime=now mtime=2020-07-13 14:45:34.915567811 +0000 UTC mtime=now handle=INVALID-0x0
2020/07/13 14:45:34 DEBUG : Upload/Test/a: >Setattr: err=<nil>
2020/07/13 14:45:34 DEBUG : Upload/Test/a: Attr:
2020/07/13 14:45:34 DEBUG : Upload/Test/a: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
2020/07/13 14:45:34 DEBUG : &{Upload/Test/a (rw)}: Flush:
2020/07/13 14:45:34 DEBUG : Upload/Test/a(0xc0004b0740): RWFileHandle.Flush ignoring flush on unwritten handle
2020/07/13 14:45:34 DEBUG : &{Upload/Test/a (rw)}: >Flush: err=<nil>
2020/07/13 14:45:34 DEBUG : &{Upload/Test/a (rw)}: Release:
2020/07/13 14:45:34 DEBUG : Upload/Test/a(0xc0004b0740): RWFileHandle.Release closing
2020/07/13 14:45:34 DEBUG : Upload/Test/a(0xc0004b0740): close:
2020/07/13 14:45:34 DEBUG : Upload/Test/a: Need to transfer - File not found at Destination
2020/07/13 14:45:34 DEBUG : /: Lookup: name="Upload"
2020/07/13 14:45:34 DEBUG : /: >Lookup: node=Upload/, err=<nil>
2020/07/13 14:45:34 DEBUG : Upload/: Attr:
2020/07/13 14:45:34 DEBUG : Upload/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/13 14:45:34 DEBUG : Upload/Test/: Attr:
2020/07/13 14:45:34 DEBUG : Upload/Test/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
...
2020/07/13 14:45:34 DEBUG : /: Attr:
2020/07/13 14:45:34 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
...
2020/07/13 14:45:37 DEBUG : Upload/Test/a: MD5 = d41d8cd98f00b204e9800998ecf8427e OK
2020/07/13 14:45:37 INFO  : Upload/Test/a: Copied (new)
2020/07/13 14:45:37 DEBUG : /: Lookup: name="Upload"
2020/07/13 14:45:37 DEBUG : /: >Lookup: node=Upload/, err=<nil>
2020/07/13 14:45:37 DEBUG : Upload/: Attr:
2020/07/13 14:45:37 DEBUG : Upload/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/13 14:45:37 DEBUG : Upload/Test/: Attr:
2020/07/13 14:45:37 DEBUG : Upload/Test/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
...
2020/07/13 14:45:37 DEBUG : /: Attr:
2020/07/13 14:45:37 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
...
2020/07/13 14:45:38 DEBUG : Upload/Test/a: File._applyPendingModTime OK
2020/07/13 14:45:38 DEBUG : Upload/Test/a: transferred to remote
2020/07/13 14:45:38 DEBUG : Upload/Test/a(0xc0004b0740): >close: err=<nil>
2020/07/13 14:45:38 DEBUG : &{Upload/Test/a (rw)}: >Release: err=<nil>
...
2020/07/13 14:45:38 DEBUG : Upload/: ReadDirAll:
2020/07/13 14:45:38 DEBUG : Upload/: >ReadDirAll: item=1, err=<nil>
2020/07/13 14:45:38 DEBUG : Upload/: Attr:
2020/07/13 14:45:38 DEBUG : Upload/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
...
2020/07/13 14:46:04 DEBUG : Upload/: Attr:
2020/07/13 14:46:04 DEBUG : Upload/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/13 14:46:04 DEBUG : Upload/: ReadDirAll:
2020/07/13 14:46:04 DEBUG : Upload/: >ReadDirAll: item=1, err=<nil>
2020/07/13 14:46:04 DEBUG : Upload/Test/: Attr:
2020/07/13 14:46:04 DEBUG : Upload/Test/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/13 14:46:04 DEBUG : /: Lookup: name="Upload"
2020/07/13 14:46:04 DEBUG : /: >Lookup: node=Upload/, err=<nil>
2020/07/13 14:46:04 DEBUG : Upload/: Attr:
2020/07/13 14:46:04 DEBUG : Upload/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
...
2020/07/13 14:46:04 DEBUG : /: Attr:
2020/07/13 14:46:04 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
...
2020/07/13 14:46:13 DEBUG : Google drive root 'Drive': Checking for changes on remote
2020/07/13 14:46:13 INFO  : Upload/Test/a: Removed from cache
2020/07/13 14:46:13 DEBUG : Upload/Test: Removed empty directory
2020/07/13 14:46:13 DEBUG : Upload: Removed empty directory
2020/07/13 14:46:13 DEBUG : : Removed empty directory
2020/07/13 14:46:13 INFO  : Cleaned the cache: objects 0 (was 4), total size 0 (was 0)
2020/07/13 14:46:13 DEBUG : : changeNotify: relativePath="Upload/Test/a", type=3
2020/07/13 14:46:13 DEBUG : Upload/Test: invalidating directory cache
2020/07/13 14:46:13 DEBUG : : >changeNotify:
2020/07/13 14:46:13 DEBUG : : changeNotify: relativePath="Upload", type=2
2020/07/13 14:46:13 DEBUG : : invalidating directory cache
2020/07/13 14:46:13 DEBUG : Upload: invalidating directory cache
2020/07/13 14:46:13 DEBUG : : >changeNotify:
2020/07/13 14:46:14 DEBUG : : Statfs:
2020/07/13 14:46:14 DEBUG : : >Statfs: stat={Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>
...
4

That's just a snippet of the log, can please post the full log.

5

There is no more useful information in the log.
I deleted some duplicate lines.

2020/07/13 14:45:07 DEBUG : : >Statfs: stat={Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>
2020/07/13 14:45:08 DEBUG : : Statfs:
2020/07/13 14:45:08 DEBUG : : >Statfs: stat={Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>
2020/07/13 14:45:09 DEBUG : : Statfs:
2020/07/13 14:45:09 DEBUG : : >Statfs: stat={Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>
2020/07/13 14:45:10 DEBUG : : Statfs:
2020/07/13 14:45:10 DEBUG : : >Statfs: stat={Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>
2020/07/13 14:45:11 DEBUG : : Statfs:
2020/07/13 14:45:11 DEBUG : : >Statfs: stat={Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>
2020/07/13 14:45:12 DEBUG : : Statfs:
2020/07/13 14:45:12 DEBUG : : >Statfs: stat={Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>

2020/07/13 14:45:27 DEBUG : /: >Lookup: node=Upload/, err=<nil>
2020/07/13 14:45:27 DEBUG : Upload/: Attr:
2020/07/13 14:45:27 DEBUG : Upload/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/13 14:45:27 DEBUG : Upload/: Lookup: name=".git"
2020/07/13 14:45:27 DEBUG : Upload/: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:27 DEBUG : Upload/: Lookup: name=".git"
2020/07/13 14:45:27 DEBUG : Upload/: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:27 DEBUG : Upload/: Lookup: name="HEAD"
2020/07/13 14:45:27 DEBUG : Upload/: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:27 DEBUG : /: Attr:
2020/07/13 14:45:27 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/13 14:45:27 DEBUG : /: Lookup: name=".git"
2020/07/13 14:45:27 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:27 DEBUG : /: Lookup: name=".git"
2020/07/13 14:45:27 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:27 DEBUG : /: Lookup: name="HEAD"
2020/07/13 14:45:27 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:27 DEBUG : Upload/: Lookup: name=".git"
2020/07/13 14:45:27 DEBUG : Upload/: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:27 DEBUG : Upload/: Lookup: name=".git"
2020/07/13 14:45:27 DEBUG : Upload/: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:27 DEBUG : Upload/: Lookup: name="HEAD"
2020/07/13 14:45:27 DEBUG : Upload/: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:27 DEBUG : /: Lookup: name=".git"
2020/07/13 14:45:27 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:27 DEBUG : /: Lookup: name=".git"
2020/07/13 14:45:27 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:27 DEBUG : /: Lookup: name="HEAD"
2020/07/13 14:45:27 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:27 DEBUG : Upload/: Lookup: name=".git"
2020/07/13 14:45:27 DEBUG : Upload/: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:27 DEBUG : Upload/: Lookup: name=".git"
2020/07/13 14:45:27 DEBUG : Upload/: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:27 DEBUG : Upload/: Lookup: name="HEAD"
2020/07/13 14:45:27 DEBUG : Upload/: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:27 DEBUG : /: Lookup: name=".git"
2020/07/13 14:45:27 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:27 DEBUG : /: Lookup: name=".git"
2020/07/13 14:45:27 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:27 DEBUG : /: Lookup: name="HEAD"
2020/07/13 14:45:27 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/13 14:45:28 DEBUG : : Statfs:
2020/07/13 14:45:28 DEBUG : : >Statfs: stat={Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>
2020/07/13 14:45:29 DEBUG : : Statfs:
2020/07/13 14:45:29 DEBUG : : >Statfs: stat={Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>
6

I'm just trying to help and if you can share the full log, that would be super appreciated.

7

Only these things in the log. Due to the character limit, I have to delete some duplicate logs.

8

Use pastebin / dropbox / google drive link.

9

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