[mount] Stale/missing current working directory. (Makes git unusable)

What is the problem you are having with rclone?

If you mount a remote (Box, in my case), and try to git init in an existing directory, it fails with an error saying unable to get current working directory.

This is not a git issue, of course. I just listed that as others may have a similar problem and find this by searching. There's something about the way rclone mounts the filesystem that is causing the problem. On subsequent mounts, if you change to an existing directory and inspect /proc/$$/cwd it says it is "deleted". Sometimes it works the first time, but if you want for a bit and look again it shows as deleted.

What is your rclone version (output from rclone version)

rclone v1.45
- os/arch: linux/amd64
- go version: go1.11.6

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

Linux 4.19.0-9-amd64 #1 SMP
Debian 4.19.118-2+deb10u1 (2020-06-07)
x86_64 GNU/Linux

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

Box

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

$ rclone mount -vv --vfs-cache-mode full --allow-other \
--write-back-cache --cache-writes cmubox: ~/net/box

Open a new tab and then:

$ mkdir ~/net/box/test
$ touch ~/net/box/test/test.txt
$ fusermount -u net/box

Now switch back to the first tab and re-mount:

$ rclone mount -vv --vfs-cache-mode full --allow-other \
--write-back-cache --cache-writes cmubox: ~/net/box

Open a new tab and then:

$ cd net/box/test
$ git init
fatal: unable to get current working directory: No such file or directory

Note: If you mount, make a new directory, change to it and git init, it works. (It's super slow, but it works.). The above problem only appears if you create a directory, then unmount the remote, remount the remote, and then try git init in there.

You don't need git to see this problem. You can just ls -l /proc/$$/cwd a few times after you remount, and it says deleted on the second try.

The rclone config contents with secrets removed.

[cmubox]
type = box
client_id = 
client_secret = 
token = {"access_token":"(removed)","token_type":"bearer","refresh_token":"(removed)","expiry":"2020-07-31T11:46:15.15979174-04:00"}

A log from the command with the -vv flag

>rclone mount -vv --vfs-cache-mode full --allow-other --write-back-cache --cache-writes cmubox: ~/net/box
2020/07/31 11:39:53 DEBUG : rclone: Version "v1.45" starting with parameters ["rclone" "mount" "-vv" "--vfs-cache-mode" "full" "--allow-other" "--write-back-cache" "--cache-writes" "cmubox:" "/home/gi1242/net/box"]
2020/07/31 11:39:53 DEBUG : Using config file from "/home/gi1242/.config/rclone/rclone.conf"
2020/07/31 11:39:53 DEBUG : box root '': Mounting on "/home/gi1242/net/box"
2020/07/31 11:39:53 INFO  : box root '': poll-interval is not supported by this remote
2020/07/31 11:39:53 DEBUG : vfs cache root is "/home/gi1242/.cache/rclone/vfs/cmubox"
2020/07/31 11:39:53 DEBUG : Adding path "vfs/forget" to remote control registry
2020/07/31 11:39:53 DEBUG : Adding path "vfs/refresh" to remote control registry
2020/07/31 11:39:53 DEBUG : Adding path "vfs/poll-interval" to remote control registry
2020/07/31 11:39:53 DEBUG : : Root: 
2020/07/31 11:39:53 DEBUG : : >Root: node=/, err=<nil>
2020/07/31 11:39:53 DEBUG : Cleaning the cache
2020/07/31 11:39:53 DEBUG : grad students per area.txt: updateTime: setting atime to 2019-01-29 15:05:48 -0500 EST
2020/07/31 11:39:53 DEBUG : test/.git/HEAD.lock: updateTime: setting atime to 2020-07-31 11:20:30.380661465 -0400 EDT
2020/07/31 11:39:53 DEBUG : test/.git/config.lock: updateTime: setting atime to 2020-07-31 11:20:33.756798164 -0400 EDT
2020/07/31 11:39:53 DEBUG : test2/.git/HEAD.lock: updateTime: setting atime to 2020-07-31 11:22:06.844567352 -0400 EDT
2020/07/31 11:39:53 DEBUG : test2/.git/config.lock: updateTime: setting atime to 2020-07-31 11:22:09.812687535 -0400 EDT
2020/07/31 11:39:53 DEBUG : grad students per area.txt: Removed from cache
2020/07/31 11:39:53 DEBUG : /: Lookup: name=".Trash"
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/31 11:39:53 DEBUG : /: Lookup: name="BDMV"
2020/07/31 11:39:53 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/31 11:39:53 DEBUG : /: Lookup: name=".xdg-volume-info"
2020/07/31 11:39:53 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/31 11:39:53 DEBUG : /: Lookup: name="autorun.inf"
2020/07/31 11:39:53 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Lookup: name=".Trash-1000"
2020/07/31 11:39:53 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Attr: 
2020/07/31 11:39:53 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:39:53 DEBUG : /: ReadDirAll: 
2020/07/31 11:39:53 DEBUG : /: >ReadDirAll: item=18, err=<nil>
2020/07/31 11:39:53 DEBUG : /: Lookup: name="autorun.inf"
2020/07/31 11:39:53 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/31 11:40:14 DEBUG : /: Lookup: name="test"
2020/07/31 11:40:14 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/31 11:40:14 DEBUG : /: Mkdir: name="test"
2020/07/31 11:40:15 DEBUG : /: >Mkdir: node=test/, err=<nil>
2020/07/31 11:40:15 DEBUG : test/: Attr: 
2020/07/31 11:40:15 DEBUG : test/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:40:26 DEBUG : test/: Lookup: name="test.txt"
2020/07/31 11:40:26 DEBUG : test/: >Lookup: node=<nil>, err=no such file or directory
2020/07/31 11:40:26 DEBUG : test/: Create: name="test.txt"
2020/07/31 11:40:26 DEBUG : test/test.txt: Open: flags=O_WRONLY|O_CREATE|0x800
2020/07/31 11:40:26 DEBUG : test/test.txt(0xc0002f61e0): Opening cached copy with flags=O_WRONLY|O_CREATE|0x800
2020/07/31 11:40:26 DEBUG : test/test.txt: >Open: fd=test/test.txt (rw), err=<nil>
2020/07/31 11:40:26 DEBUG : test/: >Create: node=test/test.txt, handle=&{test/test.txt (rw)}, err=<nil>
2020/07/31 11:40:26 DEBUG : test/test.txt: Attr: 
2020/07/31 11:40:26 DEBUG : test/test.txt: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
2020/07/31 11:40:26 DEBUG : &{test/test.txt (rw)}: Flush: 
2020/07/31 11:40:26 DEBUG : test/test.txt(0xc0002f61e0): RWFileHandle.Flush ignoring flush on unwritten handle
2020/07/31 11:40:26 DEBUG : &{test/test.txt (rw)}: >Flush: err=<nil>
2020/07/31 11:40:26 DEBUG : test/test.txt: Setattr: a=Setattr [ID=0x98 Node=0x3 Uid=1000 Gid=100 Pid=1874] atime=2020-07-31 11:40:26.876265999 -0400 EDT atime=now mtime=2020-07-31 11:40:26.876265999 -0400 EDT handle=INVALID-0x0
2020/07/31 11:40:26 DEBUG : test/test.txt: >Setattr: err=<nil>
2020/07/31 11:40:26 DEBUG : test/test.txt: Attr: 
2020/07/31 11:40:26 DEBUG : test/test.txt: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
2020/07/31 11:40:26 DEBUG : &{test/test.txt (rw)}: Flush: 
2020/07/31 11:40:26 DEBUG : test/test.txt(0xc0002f61e0): RWFileHandle.Flush ignoring flush on unwritten handle
2020/07/31 11:40:26 DEBUG : &{test/test.txt (rw)}: >Flush: err=<nil>
2020/07/31 11:40:26 DEBUG : &{test/test.txt (rw)}: Release: 
2020/07/31 11:40:26 DEBUG : test/test.txt(0xc0002f61e0): RWFileHandle.Release closing
2020/07/31 11:40:26 DEBUG : test/test.txt(0xc0002f61e0): close: 
2020/07/31 11:40:26 DEBUG : test/test.txt: Couldn't find file - need to transfer
2020/07/31 11:40:28 INFO  : test/test.txt: Copied (new)
2020/07/31 11:40:29 DEBUG : test/test.txt: File.applyPendingModTime OK
2020/07/31 11:40:29 DEBUG : test/test.txt: transferred to remote
2020/07/31 11:40:29 DEBUG : test/test.txt(0xc0002f61e0): >close: err=<nil>
2020/07/31 11:40:29 DEBUG : &{test/test.txt (rw)}: >Release: err=<nil>
2020/07/31 11:40:38 DEBUG : rclone: Version "v1.45" finishing with parameters ["rclone" "mount" "-vv" "--vfs-cache-mode" "full" "--allow-other" "--write-back-cache" "--cache-writes" "cmubox:" "/home/gi1242/net/box"]
>rclone mount -vv --vfs-cache-mode full --allow-other --write-back-cache --cache-writes cmubox: ~/net/box
2020/07/31 11:41:04 DEBUG : rclone: Version "v1.45" starting with parameters ["rclone" "mount" "-vv" "--vfs-cache-mode" "full" "--allow-other" "--write-back-cache" "--cache-writes" "cmubox:" "/home/gi1242/net/box"]
2020/07/31 11:41:04 DEBUG : Using config file from "/home/gi1242/.config/rclone/rclone.conf"
2020/07/31 11:41:04 DEBUG : box root '': Mounting on "/home/gi1242/net/box"
2020/07/31 11:41:04 INFO  : box root '': poll-interval is not supported by this remote
2020/07/31 11:41:04 DEBUG : vfs cache root is "/home/gi1242/.cache/rclone/vfs/cmubox"
2020/07/31 11:41:04 DEBUG : Adding path "vfs/forget" to remote control registry
2020/07/31 11:41:04 DEBUG : Adding path "vfs/refresh" to remote control registry
2020/07/31 11:41:04 DEBUG : Adding path "vfs/poll-interval" to remote control registry
2020/07/31 11:41:04 DEBUG : : Root: 
2020/07/31 11:41:04 DEBUG : : >Root: node=/, err=<nil>
2020/07/31 11:41:04 DEBUG : Cleaning the cache
2020/07/31 11:41:04 DEBUG : test/.git/HEAD.lock: updateTime: setting atime to 2020-07-31 11:20:30.380661465 -0400 EDT
2020/07/31 11:41:04 DEBUG : test/.git/config.lock: updateTime: setting atime to 2020-07-31 11:20:33.756798164 -0400 EDT
2020/07/31 11:41:04 DEBUG : test/test.txt: updateTime: setting atime to 2020-07-31 11:40:26.87226607 -0400 EDT
2020/07/31 11:41:04 DEBUG : test2/.git/HEAD.lock: updateTime: setting atime to 2020-07-31 11:22:06.844567352 -0400 EDT
2020/07/31 11:41:04 DEBUG : test2/.git/config.lock: updateTime: setting atime to 2020-07-31 11:22:09.812687535 -0400 EDT
2020/07/31 11:41:04 DEBUG : /: Lookup: name="BDMV"
2020/07/31 11:41:04 DEBUG : /: Attr: 
2020/07/31 11:41:04 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/31 11:41:05 DEBUG : /: Lookup: name=".xdg-volume-info"
2020/07/31 11:41:05 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/31 11:41:05 DEBUG : /: Lookup: name="autorun.inf"
2020/07/31 11:41:05 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/31 11:41:05 DEBUG : /: Lookup: name=".Trash"
2020/07/31 11:41:05 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Lookup: name=".Trash-1000"
2020/07/31 11:41:05 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Attr: 
2020/07/31 11:41:05 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:05 DEBUG : /: ReadDirAll: 
2020/07/31 11:41:05 DEBUG : /: >ReadDirAll: item=19, err=<nil>
2020/07/31 11:41:05 DEBUG : /: Lookup: name="autorun.inf"
2020/07/31 11:41:05 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/07/31 11:41:18 DEBUG : /: Lookup: name="test"
2020/07/31 11:41:18 DEBUG : /: >Lookup: node=test/, err=<nil>
2020/07/31 11:41:18 DEBUG : test/: Attr: 
2020/07/31 11:41:18 DEBUG : test/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:22 DEBUG : test/: Lookup: name="git"
2020/07/31 11:41:22 DEBUG : test/: >Lookup: node=<nil>, err=no such file or directory
2020/07/31 11:41:22 DEBUG : test/: Lookup: name="git"
2020/07/31 11:41:22 DEBUG : test/: >Lookup: node=<nil>, err=no such file or directory
2020/07/31 11:41:22 DEBUG : /: Attr: 
2020/07/31 11:41:22 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:22 DEBUG : /: Lookup: name="test"
2020/07/31 11:41:22 DEBUG : /: >Lookup: node=test/, err=<nil>
2020/07/31 11:41:22 DEBUG : test/: Attr: 
2020/07/31 11:41:22 DEBUG : test/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:22 DEBUG : /: Lookup: name="test"
2020/07/31 11:41:22 DEBUG : /: >Lookup: node=test/, err=<nil>
2020/07/31 11:41:22 DEBUG : test/: Attr: 
2020/07/31 11:41:22 DEBUG : test/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:29 DEBUG : test/: Attr: 
2020/07/31 11:41:29 DEBUG : test/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/07/31 11:41:33 DEBUG : rclone: Version "v1.45" finishing with parameters ["rclone" "mount" "-vv" "--vfs-cache-mode" "full" "--allow-other" "--write-back-cache" "--cache-writes" "cmubox:" "/home/gi1242/net/box"]

hello,

is 20 months old.

Oops. That's the most recent version in Debian buster. I just tried with 1.52.2, and it appears to be working. (git init is painfully slow though, and I'm not sure if anything can be done about that.)

that flag is for a the cache backend only and based on your config file you are not using the cache backend?

how big is the git database? perhaps just keep it local and use rclone sync to get it into box

not sure box is a good fit for something like a git repository which expects a local file system.

Thanks. I had no idea, so I just spammed all options with cache in it to improve performance.

It's ridiculously small. Directory with just one file, and git init takes upwards of a minute. Placing the .git directory on a local system speeds it up a lot. The bottleneck seems to be file creation. It looks like it takes about one second to create a file on box. I've no idea if this is an API limitation, or if it can be sped up in any way... (I tried using --vfs-write-wait 40ms and it didn't help; I also don't know if its a good idea since the default 1s was probably chosen for a reason.)

Yes, you're preaching to the choir... I hate box more than I can describe using polite language. Unfortunately this is what our university uses, and I have no choice but to find a way to use it. rclone makes it almost usable on my system, so thanks a lot for all your hard work and for a quality product.

GI

This was fixed recently. It turned out to be rather a tricky bug!

You'll probably get better performance with --vfs-cache-mode writes and the latest beta

Thanks. I tried creating 10 files with the latest beta:

for (( i=0; i< 10; i++ )); do echo "file $i" >> file$i.txt; done

Here are the results:

v1.52.2			: 13.514s (--vfs-cache-mode writes)
v1.52.2-277-ga2afa9aa-beta	:  0.016s (--vfs-cache-mode writes)
v1.52.2-277-ga2afa9aa-beta	:  0.017s (--vfs-cache-mode full)
v1.52.2-277-ga2afa9aa-beta	:  0.017s (--vfs-cache-mode full)

which is a massive speedup! Thank you so much!!

However, deleting files is still super slow. With v1.52.2-277-ga2afa9aa-beta I did

rm file*.txt #10 files total

resulting in:

v1.52.2-277-ga2afa9aa-beta	:  4.995s (--vfs-cache-mode writes)
v1.52.2-277-ga2afa9aa-beta	:  5.652s (--vfs-cache-mode full)

which is still massively slow. That's about half a second to delete a file! Is it possible to speed this up in any way, or is there some API limitation?

Thanks again,

GI

Great!

Deletes are done synchronously so each delete is a round trip to cloud storage.

I guess it would be possible to do them asynchronously... Interesting idea but a lot of work!