Set --vfs-write-back to hours issue

rclone v1.55.1
ubuntu 20.04 lts server
google cloud storage

  • case 1

RCLONE_CACHE_DIR=/var/cache/rclone
RCLONE_VFS_CACHE_MODE=full
RCLONE_VFS_CACHE_MAX_AGE=175200h
RCLONE_VFS_MAX_SIZE=1024G
RCLONE_VFS_POLL_INTERVAL=24h

[Service]
Type=notify
User=root
Group=root
ExecStart=/usr/bin/rclone mount gcloud:bucket /gcloud --umask=0002 --allow-other --default-permissions
ExecStop=/bin/fusermount -uz $PATH_LOCAL
Restart=on-failure
RestartSec=5

all long day production (lot of files). The service is running OK with clean log.
find /var/cache/rclone/ -type f | wc -l
164318
du -sh /var/cache/rclone/
17G

restart the service. It take a bit long to start (about 2 minutes) and I have to add TimeoutStartSec=infinity on the .service file
But no errors.

  • case 2

all exactly case 1
just add parameter RCLONE_VFS_WRITE_BACK=12h changing the default 5s.

all long day production (lot of files). The service is running OK with clean log.
find /var/cache/rclone/ -type f | wc -l
363654
du -sh /var/cache/rclone/
33G

restart the service. 20 minutes and no start success.
bellow the log...

2021/05/20 21:52:06 DEBUG : Using config file from "/etc/gcloud/rclone.conf"
2021/05/20 21:52:06 DEBUG : rclone: Version "v1.55.1" starting with parameters ["/usr/bin/rclone" "mount" "gcloud:bucket" "/gcloud" "--umask=0002" "--allow-other" "--default-permissions" "-vv"]
2021/05/20 21:52:06 DEBUG : Creating backend with remote "gcloud:bucket"
2021/05/20 21:52:06 INFO : GCS bucket bucket: poll-interval is not supported by this remote
2021/05/20 21:52:06 DEBUG : vfs cache: root is "/var/cache/animati/gcloud/rclone/vfs/gcloud/bucket"
2021/05/20 21:52:06 DEBUG : vfs cache: metadata root is "/var/cache/animati/gcloud/rclone/vfs/gcloud/bucket"
2021/05/20 21:52:06 DEBUG : Creating backend with remote "/var/cache/animati/gcloud/rclone/vfs/gcloud/bucket"
.
.
.

lot of entries...

2021/05/20 21:52:52 DEBUG : archive/2021/5/18/15/2C4D1BB5/4D7578D8/4D774693: vfs cache: checking remote fingerprint "211014,2021-05-18 19:47:58.677642226 +0000 UTC,d61a883b5a8fa0a417432c1082265542" against cached fingerprint "211014,2021-05-18 19:47:58.677642226 +0000 UTC,d61a883b5a8fa0a417432c1082265542"
2021/05/20 21:52:52 DEBUG : archive/2021/5/18/15/2C4D1BB5/4D7578D8/4D774693: vfs cache: truncate to size=211018
2021/05/20 21:52:52 DEBUG : vfs cache: looking for range={Pos:0 Size:211018} in [{Pos:0 Size:211018}] - present true
2021/05/20 21:52:52 DEBUG : archive/2021/5/18/15/2C4D1BB5/4D7578D8/4D774693: vfs cache: setting modification time to 2021-05-20 15:19:49.624083479 -0400 -04
2021/05/20 21:52:52 INFO : archive/2021/5/18/15/2C4D1BB5/4D7578D8/4D774693: vfs cache: queuing for upload in 12h0m0s
2021/05/20 21:52:52 DEBUG : archive/2021/5/18/15/2C4D1BB5/4D7578D8: Added virtual directory entry vAddFile: "4D774693"
2021/05/20 21:52:53 DEBUG : archive/2021/5/18/15/2C4D1BB5/4D7578D8/4D774694: vfs cache: checking remote fingerprint "211002,2021-05-18 19:47:58.808320788 +0000 UTC,8d7daf1e317cfb3285fae269e98e7b5f" against cached fingerprint "211002,2021-05-18 19:47:58.808320788 +0000 UTC,8d7daf1e317cfb3285fae269e98e7b5f"
2021/05/20 21:52:53 DEBUG : archive/2021/5/18/15/2C4D1BB5/4D7578D8/4D774694: vfs cache: truncate to size=211006
2021/05/20 21:52:53 DEBUG : vfs cache: looking for range={Pos:0 Size:211006} in [{Pos:0 Size:211006}] - present true
2021/05/20 21:52:53 DEBUG : archive/2021/5/18/15/2C4D1BB5/4D7578D8/4D774694: vfs cache: setting modification time to 2021-05-20 15:19:49.630611107 -0400 -04
2021/05/20 21:52:53 INFO : archive/2021/5/18/15/2C4D1BB5/4D7578D8/4D774694: vfs cache: queuing for upload in 12h0m0s
.
.
.

lot of entries...

2021/05/20 22:00:11 DEBUG : archive/2021/5/20/10/8290EAB0/22016D92/D8A07F55: vfs cache: truncate to size=169544
2021/05/20 22:00:11 DEBUG : archive/2021/5/20/10/8290EAB0/22016D92/D8A07F55: vfs cache: setting modification time to 2021-05-20 15:58:41.313997003 -0400 -04
2021/05/20 22:00:11 INFO : archive/2021/5/20/10/8290EAB0/22016D92/D8A07F55: vfs cache: queuing for upload in 12h0m0s
2021/05/20 22:00:11 ERROR : archive/2021/5/20/10/8290EAB0/22016D92/D8A07F55: vfs cache: failed to reload item: reload: failed to add virtual dir entry: file does not exist
2021/05/20 22:00:11 DEBUG : archive/2021/5/20/10/8290EAB0/22016D92/D8A07F56: vfs cache: truncate to size=169444
2021/05/20 22:00:11 DEBUG : archive/2021/5/20/10/8290EAB0/22016D92/D8A07F56: vfs cache: setting modification time to 2021-05-20 15:58:41.32036777 -0400 -04
2021/05/20 22:00:11 INFO : archive/2021/5/20/10/8290EAB0/22016D92/D8A07F56: vfs cache: queuing for upload in 12h0m0s
2021/05/20 22:00:11 ERROR : archive/2021/5/20/10/8290EAB0/22016D92/D8A07F56: vfs cache: failed to reload item: reload: failed to add virtual dir entry: file does not exist
.
.
.

3 questions...
in this case with a lot of small files maybe we can't use hours on --vfs-write-back. is it?
why we are getting lot of "file does not exist" in the "case 2" with --vfs-write-back=12h?
is there a way to tuning it and so we can use hour in --vfs-write-back?

It should work...

I think that is probably a bug. It looks like by the time the writeback happens the parent directory is missing from the cache. It should fail quietly here rather than returning an error.

Can you open a new issue on Github about this and I'll fix it.

1 Like

the great of using 12h is to send the all day production during the nigh.

new issue created #5348 . Thanks a lot.

1 Like

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