Erratic vfs-cache behavior: 'file has changed'

[piscator]

What is the problem you are having with rclone?

I am using rclone with "--vfs-cache-mode full" caching on "Google Drive". The problem I am having when making multiple edits to a markdown (*.md) file, the file ends up being truncated / completely empty.

I have isolated the problem to the following reproducible steps (that probably causes this problem).

1. Just create a text file with echo blabla > test.txt.
2. Edit the file with nano test.txt. Make a change and exit ---> file gets correctly saved.
3. Make an edit again with nano test.txt. Make a change and exit --> nano gives an error that the the file has changed (???). Expected behavior: the file should not have changed.

Notes.

• If you resave fast enough in step 3, the file is not changed. So I expect that would have to do with the "WriteWait" and "WriteBack" parameters. Bottomline is the file should not have been changed between step 2 and step 3 (and likely the unexpected file change causes the application I use for markdown to truncate the file).
• If you do step 3 too slow (for example wait a minute before starting nano again), there is also no problem. So for reproducing, immediately start nano again after "exit &save" in step 2.

I use the following options to mount the cloud drive

rclone rc options/set --json '{"main": { "Transfers": 4 }, "vfs": {"UID": '$PUID', "GID": '$PGID', "Umask": 23, "CacheMode": 3, "CacheMaxAge": 31622400000000000, "DirCacheTime": 31536000000000000}, "mount": {"AllowOther": true}}' $AUTH

What is your rclone version (output from rclone version)

rclone v1.53.2

• os/arch: linux/amd64
• go version: go1.15.3

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

Docker in QNAP

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

Google Drive

[ncw (Nick Craig-Wood)]

I can replicate this.

rclone mount -vv --vfs-cache-mode full --dir-cache-time 10s s3:rclone /mnt/tmp/

The minimal steps are

• edit file with nano
• change the file
• write it out with ^O
• wait for the writeback period (5s by default)
• change the file
• write it out with ^O
• get error that the the file has changed

I ran

$ while true ; do ls -l --full-time /mnt/tmp/text.txt ; sleep 1 ; done

In a terminal while doing this and I see

-rw-rw-r-- 1 ncw ncw 13 2020-11-12 12:32:59.325780069 +0000 /mnt/tmp/text.txt
-rw-rw-r-- 1 ncw ncw 13 2020-11-12 12:32:59.325780069 +0000 /mnt/tmp/text.txt
-rw-rw-r-- 1 ncw ncw 13 2020-11-12 12:32:59.325780069 +0000 /mnt/tmp/text.txt
-rw-rw-r-- 1 ncw ncw 13 2020-11-12 12:32:59.325780069 +0000 /mnt/tmp/text.txt
-rw-rw-r-- 1 ncw ncw 14 2020-11-12 12:32:59.325780069 +0000 /mnt/tmp/text.txt <- save from nano here at 2020/11/12 12:35:16
-rw-rw-r-- 1 ncw ncw 14 2020-11-12 12:32:59.325780069 +0000 /mnt/tmp/text.txt
-rw-rw-r-- 1 ncw ncw 14 2020-11-12 12:32:59.325780069 +0000 /mnt/tmp/text.txt
-rw-rw-r-- 1 ncw ncw 14 2020-11-12 12:32:59.325780069 +0000 /mnt/tmp/text.txt
-rw-rw-r-- 1 ncw ncw 14 2020-11-12 12:32:59.325780069 +0000 /mnt/tmp/text.txt
-rw-rw-r-- 1 ncw ncw 14 2020-11-12 12:35:16.499006400 +0000 /mnt/tmp/text.txt <- writeback completes
-rw-rw-r-- 1 ncw ncw 14 2020-11-12 12:35:16.499006400 +0000 /mnt/tmp/text.txt
-rw-rw-r-- 1 ncw ncw 14 2020-11-12 12:35:16.499006400 +0000 /mnt/tmp/text.txt
-rw-rw-r-- 1 ncw ncw 14 2020-11-12 12:35:16.499006400 +0000 /mnt/tmp/text.txt

So what it looks like happened is that the modification time wasn't updated until the writeback completed rather than when the file was written.

Can you please make a new issue on github about this and put a link to the forum in it

Thank you

[piscator]

Thanks for replicating.
I have added the issue on GitHub