Rclone mount takes a long time

BenjiBoy · December 31, 2022, 3:53am

What is the problem you are having with rclone?

rclone mount takes a long time to remount when there is a large amount of files to upload. Before the remount, many files were copied to the previous mount (about 100GB worth of files).

Run the command 'rclone version' and share the full output of the command.

rclone v1.61.0
- os/version: Microsoft Windows 10 Home 22H2 (64 bit)
- os/kernel: 10.0.19045.2364 (x86_64)
- os/type: windows
- os/arch: amd64
- go/version: go1.19.4
- go/linking: static
- go/tags: cmount

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

pCloud

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

rclone mount "pcloud-crypt:" "C:\root\rclone\pcloud-crypt" --vfs-cache-mode full --file-perms 0777 --dir-perms 0777 --cache-dir "C:\root\rclone\cache" --stats-log-level NOTICE --stats 1m

The rclone config contents with secrets removed.

[pcloud]
type = pcloud
hostname = xxx
token = {"access_token":"xxx","token_type":"xxx","expiry":"xxx"}

[pcloud-crypt]
type = crypt
remote = pcloud:rclone-crypt
password = xxx

A log from the command with the `-vv` flag

2022/12/30 21:58:29 DEBUG : rclone: Version "v1.61.0" starting with parameters ["rclone" "mount" "pcloud-crypt:" "C:\\root\\rclone\\pcloud-crypt" "--vfs-cache-mode" "full" "--file-perms" "0777" "--dir-perms" "0777" "--cache-dir" "C:\\root\\rclone\\cache" "--stats-log-level" "NOTICE" "--stats" "1m" "-vv" "--log-file=mylogfile.txt"]
2022/12/30 21:58:29 DEBUG : Creating backend with remote "pcloud-crypt:"
2022/12/30 21:58:29 DEBUG : Using config file from "C:\\Users\\user01\\AppData\\Roaming\\rclone\\rclone.conf"
2022/12/30 21:58:29 DEBUG : Creating backend with remote "pcloud:rclone-crypt"
2022/12/30 21:58:29 INFO  : Encrypted drive 'pcloud-crypt:': poll-interval is not supported by this remote
2022/12/30 21:58:29 DEBUG : vfs cache: root is "C:\\root\\rclone\\cache"
2022/12/30 21:58:29 DEBUG : vfs cache: data root is "\\\\?\\C:\\root\\rclone\\cache\\vfs\\pcloud-crypt"
2022/12/30 21:58:29 DEBUG : vfs cache: metadata root is "\\\\?\\C:\\root\\rclone\\cache\\vfsMeta\\pcloud-crypt"
2022/12/30 21:58:29 DEBUG : Creating backend with remote "C:/root/rclone/cache/vfs/pcloud-crypt/"
2022/12/30 21:58:30 DEBUG : fs cache: renaming cache item "C:/root/rclone/cache/vfs/pcloud-crypt/" to be canonical "//?/C:/root/rclone/cache/vfs/pcloud-crypt"
2022/12/30 21:58:30 DEBUG : Creating backend with remote "C:/root/rclone/cache/vfsMeta/pcloud-crypt/"
2022/12/30 21:58:30 DEBUG : fs cache: renaming cache item "C:/root/rclone/cache/vfsMeta/pcloud-crypt/" to be canonical "//?/C:/root/rclone/cache/vfsMeta/pcloud-crypt"
2022/12/30 21:58:43 DEBUG : xxx: vfs cache: checking remote fingerprint "500924400,2018-02-21 02:55:41 +0000 UTC" against cached fingerprint ""
2022/12/30 21:58:43 DEBUG : xxx: vfs cache: truncate to size=526586752 (not needed as size correct)
2022/12/30 21:58:43 DEBUG : vfs cache: looking for range={Pos:0 Size:526586752} in [{Pos:0 Size:526586752}] - present true
2022/12/30 21:58:43 DEBUG : xxx: vfs cache: setting modification time to 2018-02-20 21:55:41 -0500 EST
2022/12/30 21:58:43 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:45 DEBUG : xxx: Added virtual directory entry vAddFile: xxx
2022/12/30 21:58:45 DEBUG : xxx: vfs cache: checking remote fingerprint "203177968,2018-02-18 23:43:21 +0000 UTC" against cached fingerprint ""
2022/12/30 21:58:45 DEBUG : xxx: vfs cache: truncate to size=280935397 (not needed as size correct)
2022/12/30 21:58:45 DEBUG : vfs cache: looking for range={Pos:0 Size:280935397} in [{Pos:0 Size:280935397}] - present true
2022/12/30 21:58:45 DEBUG : xxx: vfs cache: setting modification time to 2018-02-18 18:43:21 -0500 EST
2022/12/30 21:58:45 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:45 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:45 DEBUG : xxx: vfs cache: checking remote fingerprint "172359680,2018-02-11 18:53:06 +0000 UTC" against cached fingerprint ""
2022/12/30 21:58:45 DEBUG : xxx: vfs cache: truncate to size=679757005 (not needed as size correct)
2022/12/30 21:58:45 DEBUG : vfs cache: looking for range={Pos:0 Size:679757005} in [{Pos:0 Size:679757005}] - present true
2022/12/30 21:58:45 DEBUG : xxx: vfs cache: setting modification time to 2018-02-11 13:53:06 -0500 EST
2022/12/30 21:58:45 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:45 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:46 DEBUG : xxx: vfs cache: checking remote fingerprint "589824,2016-08-23 22:48:28 +0000 UTC" against cached fingerprint ""
2022/12/30 21:58:46 DEBUG : xxx: vfs cache: truncate to size=16229108 (not needed as size correct)
2022/12/30 21:58:46 DEBUG : vfs cache: looking for range={Pos:0 Size:16229108} in [{Pos:0 Size:16229108}] - present true
2022/12/30 21:58:46 DEBUG : xxx: vfs cache: setting modification time to 2016-08-23 18:48:28 -0400 EDT
2022/12/30 21:58:46 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:46 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:47 DEBUG : xxx: vfs cache: truncate to size=14402108 (not needed as size correct)
2022/12/30 21:58:47 DEBUG : xxx: vfs cache: setting modification time to 2016-08-23 18:48:44 -0400 EDT
2022/12/30 21:58:47 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:47 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:47 DEBUG : xxx: vfs cache: truncate to size=12389276 (not needed as size correct)
2022/12/30 21:58:47 DEBUG : xxx: vfs cache: setting modification time to 2016-08-23 18:49:32 -0400 EDT
2022/12/30 21:58:47 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:47 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:47 DEBUG : xxx: vfs cache: truncate to size=15031640 (not needed as size correct)
2022/12/30 21:58:47 DEBUG : xxx: vfs cache: setting modification time to 2016-08-23 18:49:48 -0400 EDT
2022/12/30 21:58:47 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:47 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:48 DEBUG : xxx: vfs cache: truncate to size=13107548 (not needed as size correct)
2022/12/30 21:58:48 DEBUG : xxx: vfs cache: setting modification time to 2016-08-23 18:50:20 -0400 EDT
2022/12/30 21:58:48 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:48 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:48 DEBUG : xxx: vfs cache: truncate to size=17612408 (not needed as size correct)
2022/12/30 21:58:48 DEBUG : xxx: vfs cache: setting modification time to 2016-08-23 18:51:00 -0400 EDT
2022/12/30 21:58:48 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:48 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:48 DEBUG : xxx: vfs cache: truncate to size=18703388 (not needed as size correct)
2022/12/30 21:58:48 DEBUG : xxx: vfs cache: setting modification time to 2016-08-23 18:51:38 -0400 EDT
2022/12/30 21:58:48 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:48 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:48 DEBUG : xxx: vfs cache: starting upload
2022/12/30 21:58:48 DEBUG : xxx: vfs cache: truncate to size=10727228 (not needed as size correct)
2022/12/30 21:58:48 DEBUG : xxx: vfs cache: setting modification time to 2016-08-23 18:41:30 -0400 EDT
2022/12/30 21:58:48 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:48 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:49 DEBUG : xxx: vfs cache: truncate to size=14237156 (not needed as size correct)
2022/12/30 21:58:49 DEBUG : xxx: vfs cache: setting modification time to 2016-08-23 18:52:10 -0400 EDT
2022/12/30 21:58:49 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:49 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:49 DEBUG : xxx: vfs cache: truncate to size=11997776 (not needed as size correct)
2022/12/30 21:58:49 DEBUG : xxx: vfs cache: setting modification time to 2016-08-23 18:52:42 -0400 EDT
2022/12/30 21:58:49 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:49 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:50 DEBUG : xxx: vfs cache: truncate to size=14582720 (not needed as size correct)
2022/12/30 21:58:50 DEBUG : xxx: vfs cache: setting modification time to 2016-08-23 18:42:04 -0400 EDT
2022/12/30 21:58:50 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:50 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:50 DEBUG : xxx: vfs cache: truncate to size=20361260 (not needed as size correct)
2022/12/30 21:58:50 DEBUG : xxx: vfs cache: setting modification time to 2016-08-23 18:42:24 -0400 EDT
2022/12/30 21:58:50 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:50 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:50 DEBUG : xxx: vfs cache: starting upload
2022/12/30 21:58:50 DEBUG : xxx: vfs cache: truncate to size=18498764 (not needed as size correct)
2022/12/30 21:58:50 DEBUG : xxx: vfs cache: setting modification time to 2016-08-23 18:43:02 -0400 EDT
2022/12/30 21:58:50 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:50 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:50 DEBUG : xxx: vfs cache: starting upload
2022/12/30 21:58:51 DEBUG : xxx: vfs cache: truncate to size=26443604 (not needed as size correct)
2022/12/30 21:58:51 DEBUG : xxx: vfs cache: setting modification time to 2016-08-23 18:44:06 -0400 EDT
2022/12/30 21:58:51 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:51 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:51 DEBUG : xxx: vfs cache: starting upload
2022/12/30 21:58:51 DEBUG : xxx: vfs cache: truncate to size=19085492 (not needed as size correct)
2022/12/30 21:58:51 DEBUG : xxx: vfs cache: setting modification time to 2016-08-23 18:44:38 -0400 EDT
2022/12/30 21:58:51 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:51 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:52 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:58:52 DEBUG : xxx: vfs cache: truncate to size=25218992 (not needed as size correct)
2022/12/30 21:58:52 DEBUG : xxx: vfs cache: setting modification time to 2016-08-23 18:45:24 -0400 EDT
2022/12/30 21:58:52 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:52 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:52 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:58:52 DEBUG : xxx: vfs cache: truncate to size=16482800 (not needed as size correct)
2022/12/30 21:58:53 DEBUG : xxx: vfs cache: setting modification time to 2016-08-23 18:46:04 -0400 EDT
2022/12/30 21:58:53 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:53 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:53 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:58:53 DEBUG : xxx: vfs cache: truncate to size=721532 (not needed as size correct)
2022/12/30 21:58:53 DEBUG : xxx: vfs cache: setting modification time to 2016-08-23 18:52:48 -0400 EDT
2022/12/30 21:58:53 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:53 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:53 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:58:53 DEBUG : xxx: vfs cache: truncate to size=13761092 (not needed as size correct)
2022/12/30 21:58:53 DEBUG : xxx: vfs cache: setting modification time to 2016-08-23 18:53:24 -0400 EDT
2022/12/30 21:58:53 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:53 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:58:53 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:54 DEBUG : xxx/John_Opening Credits.mp3: vfs cache: truncate to size=486632 (not needed as size correct)
2022/12/30 21:58:54 DEBUG : xxx/John_Opening Credits.mp3: vfs cache: setting modification time to 2016-08-23 18:53:36 -0400 EDT
2022/12/30 21:58:54 INFO  : xxx/John_Opening Credits.mp3: vfs cache: queuing for upload in 5s
2022/12/30 21:58:54 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:58:54 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:54 DEBUG : xxx: vfs cache: truncate to size=2178458 (not needed as size correct)
2022/12/30 21:58:54 DEBUG : xxx: vfs cache: setting modification time to 2016-08-23 18:36:58 -0400 EDT
2022/12/30 21:58:54 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:54 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:58:54 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:55 DEBUG : xxx: vfs cache: checking remote fingerprint "220446704,2018-03-30 04:29:45 +0000 UTC" against cached fingerprint "220446704,2018-03-30 04:29:45 +0000 UTC"
2022/12/30 21:58:55 DEBUG : xxx: vfs cache: truncate to size=707663680 (not needed as size correct)
2022/12/30 21:58:55 DEBUG : vfs cache: looking for range={Pos:0 Size:707663680} in [{Pos:0 Size:707663680}] - present true
2022/12/30 21:58:55 DEBUG : xxx: vfs cache: setting modification time to 2018-03-30 00:29:45 -0400 EDT
2022/12/30 21:58:55 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:55 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:58:56 DEBUG : xxx: vfs cache: truncate to size=296684 (not needed as size correct)
2022/12/30 21:58:56 DEBUG : xxx: vfs cache: setting modification time to 2018-06-04 00:57:34 -0400 EDT
2022/12/30 21:58:56 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:56 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:58:56 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:56 DEBUG : xxx: vfs cache: truncate to size=5409593 (not needed as size correct)
2022/12/30 21:58:56 DEBUG : xxx: vfs cache: setting modification time to 2018-05-30 22:41:18 -0400 EDT
2022/12/30 21:58:56 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:56 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:58:56 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:56 DEBUG : xxx: vfs cache: truncate to size=5493320 (not needed as size correct)
2022/12/30 21:58:56 DEBUG : xxx: vfs cache: setting modification time to 2018-05-30 22:41:50 -0400 EDT
2022/12/30 21:58:56 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:56 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:56 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:58:57 DEBUG : xxx: vfs cache: truncate to size=73548 (not needed as size correct)
2022/12/30 21:58:57 DEBUG : xxx: vfs cache: setting modification time to 2018-04-23 19:43:56 -0400 EDT
2022/12/30 21:58:57 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:57 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:58:58 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:58 DEBUG : xxx: vfs cache: truncate to size=58532 (not needed as size correct)
2022/12/30 21:58:58 DEBUG : xxx: vfs cache: setting modification time to 2018-04-23 19:43:45 -0400 EDT
2022/12/30 21:58:58 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:58 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:58 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:58:59 DEBUG : xxx: vfs cache: truncate to size=54563 (not needed as size correct)
2022/12/30 21:58:59 DEBUG : xxx: vfs cache: setting modification time to 2018-04-23 19:44:14 -0400 EDT
2022/12/30 21:58:59 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:59 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:58:59 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:58:59 DEBUG : xxx: vfs cache: truncate to size=61641 (not needed as size correct)
2022/12/30 21:58:59 DEBUG : xxx: vfs cache: setting modification time to 2018-04-23 19:44:08 -0400 EDT
2022/12/30 21:58:59 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:58:59 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:58:59 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:59:01 DEBUG : xxx: vfs cache: truncate to size=79331 (not needed as size correct)
2022/12/30 21:59:01 DEBUG : xxx: vfs cache: setting modification time to 2018-04-23 19:43:51 -0400 EDT
2022/12/30 21:59:01 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:59:01 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:59:01 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:59:05 DEBUG : xxx: vfs cache: truncate to size=84239 (not needed as size correct)
2022/12/30 21:59:05 DEBUG : xxx: vfs cache: setting modification time to 2018-04-23 19:44:02 -0400 EDT
2022/12/30 21:59:05 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:59:05 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:59:05 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:59:05 DEBUG : xxx: vfs cache: truncate to size=56193 (not needed as size correct)
2022/12/30 21:59:05 DEBUG : xxx: vfs cache: setting modification time to 2018-04-23 19:43:32 -0400 EDT
2022/12/30 21:59:05 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:59:05 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:59:05 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:59:06 DEBUG : xxx: vfs cache: truncate to size=56983 (not needed as size correct)
2022/12/30 21:59:06 DEBUG : xxx: vfs cache: setting modification time to 2018-04-23 19:43:38 -0400 EDT
2022/12/30 21:59:06 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:59:06 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:59:06 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:59:06 DEBUG : xxx: vfs cache: truncate to size=21692958 (not needed as size correct)
2022/12/30 21:59:06 DEBUG : xxx: vfs cache: setting modification time to 2018-05-30 23:06:49 -0400 EDT
2022/12/30 21:59:06 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:59:06 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:59:06 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:59:07 DEBUG : xxx: vfs cache: truncate to size=786078 (not needed as size correct)
2022/12/30 21:59:07 DEBUG : xxx: vfs cache: setting modification time to 2014-05-28 18:23:45 -0400 EDT
2022/12/30 21:59:07 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:59:07 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:59:08 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:59:09 DEBUG : xxx: vfs cache: truncate to size=786142 (not needed as size correct)
2022/12/30 21:59:09 DEBUG : xxx: vfs cache: setting modification time to 2014-05-28 18:23:59 -0400 EDT
2022/12/30 21:59:09 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:59:09 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:59:09 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:59:09 DEBUG : xxx: vfs cache: truncate to size=1815766 (not needed as size correct)
2022/12/30 21:59:09 DEBUG : xxx: vfs cache: setting modification time to 2014-05-30 20:39:49 -0400 EDT
2022/12/30 21:59:09 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:59:09 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:59:09 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:59:10 DEBUG : xxx: vfs cache: truncate to size=57198 (not needed as size correct)
2022/12/30 21:59:10 DEBUG : xxx: vfs cache: setting modification time to 2014-06-05 14:01:41 -0400 EDT
2022/12/30 21:59:10 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:59:10 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:59:10 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:59:10 DEBUG : xxx: vfs cache: truncate to size=53140 (not needed as size correct)
2022/12/30 21:59:10 DEBUG : xxx: vfs cache: setting modification time to 2014-06-05 14:01:48 -0400 EDT
2022/12/30 21:59:10 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:59:10 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:59:10 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:59:15 DEBUG : xxx: vfs cache: truncate to size=55906 (not needed as size correct)
2022/12/30 21:59:15 DEBUG : xxx: vfs cache: setting modification time to 2014-06-05 14:01:57 -0400 EDT
2022/12/30 21:59:15 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/30 21:59:15 DEBUG : xxx: vfs cache: delaying writeback as --transfers exceeded
2022/12/30 21:59:15 DEBUG : xxx: Added virtual directory entry vAddFile: "xxx"
2022/12/30 21:59:29 NOTICE: 
Transferred:   	    7.596 MiB / 1.400 GiB, 1%, 147.621 KiB/s, ETA 2h44m53s
Transferred:            0 / 4, 0%
Elapsed time:       1m0.1s
Transferring:
 * xxx:  0% /502.192Mi, 58.850Ki/s, 2h24m50s
 * xxx:  0% /267.921Mi, 26.337Ki/s, 2h52m39s
 * xxx:  0% /648.267Mi, 40.557Ki/s, 4h31m57s
 * xxx:  8% /15.477Mi, 24.682Ki/s, 9m45s

Note: File names were replaced with "xxx".
1 minute worth of logging was posted as the log just repeated itself with different files.

Extra info

I have looked at these two threads but no solution was found:

Here is a screenshot of how long I was waiting for the mount to appear in the nonexistent subdirectory.

As the amount of data transferred comes closer to the total amount to be transferred, the total amount rises. I have had the same issue before, but I just had to wait about 10 minutes for the mount to appear because the amount of files I've transferred to the mount before remounting was smaller (4GB worth of files). Usually, the mount command I use above just takes about 5 seconds to appear.

Animosity022 · December 31, 2022, 3:56am

It's checking your files to be uploaded vs the remote.

There isn't anyway around that as you'd get data loss if the files are not checked. I'd imagine pcloud isn't super fast? I don't use it so not sure.

BenjiBoy · December 31, 2022, 4:19am

Ok, thank you for this info. This was what I was looking for. pCloud isn't slow. They do not limit your transfer speeds. It's just that I have a slow upload speed of 10 mbps, so 1.25mb/s of upload.

Animosity022 · December 31, 2022, 4:27am

How many files are waiting to be checked? By slow, I wasn't sure how fast the API is or if we have a large number of files to be checked.

BenjiBoy · December 31, 2022, 4:40am

How can I check the amount of files waiting to be checked?

Ah, ok. I'm not really familiar with the term "API", so I'm not really sure what you are talking about here.

Animosity022 · December 31, 2022, 5:09am

I run at INFO log level so I see:

2022/10/03 00:04:45 INFO  : vfs cache: cleaned: objects 6669 (was 6669) in use 2, to upload 0, uploading 0, total size 799.267Gi (was 799.267Gi)

That will show you how many are there.

BenjiBoy · December 31, 2022, 5:44am

Running --log-level INFO does not show me what you showed above. I assume it needs to load all my files before giving that line. Currently it only shows these:

2022/12/31 00:40:45 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/31 00:40:46 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/31 00:40:46 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/31 00:40:47 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/31 00:40:48 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/31 00:40:48 INFO  : xxx: Copied (new)
2022/12/31 00:40:48 INFO  : xxx: vfs cache: upload succeeded try #1
2022/12/31 00:40:48 INFO  : xxx: Copied (new)
2022/12/31 00:40:48 INFO  : xxx: vfs cache: upload succeeded try #1
2022/12/31 00:40:48 INFO  : xxx: Copied (new)
2022/12/31 00:40:48 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/31 00:40:48 INFO  : xxx: vfs cache: upload succeeded try #1
2022/12/31 00:40:50 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/31 00:40:51 INFO  : xxx: Copied (new)
2022/12/31 00:40:51 INFO  : xxx: vfs cache: upload succeeded try #1
2022/12/31 00:40:53 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/31 00:40:54 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/31 00:40:55 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/31 00:40:56 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/31 00:40:56 INFO  : xxx: Copied (new)
2022/12/31 00:40:56 INFO  : xxx: vfs cache: upload succeeded try #1
2022/12/31 00:40:57 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/31 00:40:58 INFO  : xxx: vfs cache: queuing for upload in 5s
2022/12/31 00:40:59 INFO  : xxx: vfs cache: queuing for upload in 5s

BenjiBoy · December 31, 2022, 6:54am

Is there a way to remove files to be uploaded? Like to delete directories I no longer want uploaded to the cloud? For example, can I go to rclone's cache and delete the directories I don't want uploaded to the cloud from vfs and vfsMeta or would that mess up the way rclone works?

ncw · December 31, 2022, 9:40am

That will work, yes. It isn't recommended and may change in the future but yes, deleting stuff from vfs or vfsMeta directories will cause rclone to drop it from the cache.

Animosity022 · December 31, 2022, 12:24pm

You'd have to wait a few minutes so a clean happens.

And if you are running INFO, it won't work.

You need at least NOTICE as you can see from my log I shared.

BenjiBoy · December 31, 2022, 7:56pm

I've been running this command:

rclone mount "pcloud-crypt:" "C:\root\rclone\pcloud-crypt" --vfs-cache-mode full --file-perms 0777 --dir-perms 0777 --cache-dir "C:\root\rclone\cache" --stats-log-level NOTICE --stats 1m -v --log-file="C:\root\rclone\mylogfile.txt"

for about an hour, but that line still did not show up. I assume that rclone needs to be near its mounting point before cleaning its cache. And just for your info, to test if at least NOTICE was needed, I ran just INFO on my unencrypted remote that had no pending uploads, and it gave me the line you showed above. I ran this:

rclone mount "pcloud:" "C:\root\rclone\pcloud" --vfs-cache-mode full --file-perms 0777 --dir-perms 0777 --cache-dir "C:\root\rclone\cache" --stats-log-level NOTICE --stats 1m --log-level INFO --log-file="C:\root\rclone\mylogfile_pcloud.txt"

and the output I received was:

2022/12/31 13:51:38 INFO  : pcloud root '': poll-interval is not supported by this remote
2022/12/31 13:51:38 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
The service rclone has been started.

BenjiBoy · January 1, 2023, 2:54am

Continuing the discussion from Long delay in mount point showing up on Windows:

One thing I've been wondering about though, is that ncw said that rclone mount is supposed to mount and then upload from the queue, but it seems like it's doing the opposite. It's unfortunate. I've been trying to mount my remote for several days now but it still hasn't mounted. I can wait, but it might be problematic in the future (for me that is).

BenjiBoy · January 1, 2023, 4:23am

Hey Animosity, finally, after about 8 hours of waiting for rclone to mount, I was able to find several lines indicating the amount of files waiting to be uploaded and in the cache. Here is one of them:

2022/12/31 22:03:53 INFO  : vfs cache: cleaned: objects 9494 (was 48968) in use 9453, to upload 9449, uploading 4, total size 41.072Gi (was 60.057Gi)

I can also now see my remote mounted.

Animosity022 · January 1, 2023, 9:13pm

That would be it as it has to go through almost 50k files to validate if they are changed. It's not really the size of the cache nor the size of each object but the number of objects it has to check.

That's like 6.2k per hour or something if it was 8 hours.

system · January 4, 2023, 9:14pm

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