Error message when starting rclone and opening folder takes a long time

What is the problem you are having with rclone?

rclone is started but throwing error on console and when opening a folder takes a long time

error message : 2021/02/11 15:31:12 ERROR : Computer/rclone id legalic.txt: vfs cache: failed to reload item: reload: failed to add virtual dir entry: file does not exist

What is your rclone version (output from rclone version)

rclone v1.54.0

  • os/arch: windows/amd64
  • go version: go1.15.7

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

Windows 10 64bit

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

google drive gsuite

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

rclone mount remote: X: --vfs-cache-mode full --fuse-flag --VolumePrefix=\server\share -vv

The rclone config contents with secrets removed.

type = drive
client_id = 305925211631-tdt6ifndhp7e3mrovf41ktucrbv1gao9.apps.googleusercontent.com
client_secret = xxx
scope = drive
root_folder_id = 1ZfbIq4apRMIxWuxYvRKdLtOD5XNxodcq
token = {"access_token":"ya29.a0AfH6SMBJaZdE-_RnSb_OzBREu19JXMmIr9dwwA0feocjJMxRbiECF1kMfZZMt4FyTZAOroL_5H9J7zsuQ_00kLZHsmfhZeOGXGKNMafXfSJl18PoynDS35SL5I5oRa_n1TUB8ai0A6apyzam3VynkyLxstGOkn5X4NuV4GsdgNE","token_type":"Bearer","refresh_token":"1//0gJuAX2e_s4N7CgYIARAAGBASNwF-L9IrxLMTJHF0X14eiRtS-ZGSX6MnN0Q4l5PwsNVdSFcbTHMeEiY3vUa-R4fofUujteLVLRM","expiry":"2021-02-11T13:53:53.3372469+07:00"}

A log from the command with the -vv flag

C:\Users\Administrator\Downloads\rclone-v1.54.0-windows-amd64>rclone mount remote: X: --vfs-cache-mode full --fuse-flag --VolumePrefix=\server\share -vv
2021/02/11 15:43:25 DEBUG : rclone: Version "v1.54.0" starting with parameters ["rclone" "mount" "remote:" "X:" "--vfs-cache-mode" "full" "--fuse-flag" "--VolumePrefix=\\server\\share" "-vv"]
2021/02/11 15:43:25 DEBUG : Creating backend with remote "remote:"
2021/02/11 15:43:25 DEBUG : Using config file from "C:\\Users\\Administrator\\.config\\rclone\\rclone.conf"
2021/02/11 15:43:25 DEBUG : vfs cache: root is "\\\\?\\C:\\Users\\Administrator\\AppData\\Local\\rclone\\vfs\\remote"
2021/02/11 15:43:25 DEBUG : vfs cache: metadata root is "\\\\?\\C:\\Users\\Administrator\\AppData\\Local\\rclone\\vfs\\remote"
2021/02/11 15:43:25 DEBUG : Creating backend with remote "\\\\?\\C:\\Users\\Administrator\\AppData\\Local\\rclone\\vfs\\remote"
2021/02/11 15:43:25 DEBUG : fs cache: renaming cache item "\\\\?\\C:\\Users\\Administrator\\AppData\\Local\\rclone\\vfs\\remote" to be canonical "//?/C:/Users/Administrator/AppData/Local/rclone/vfs/remote"
2021/02/11 15:43:25 DEBUG : fs cache: switching user supplied name "\\\\?\\C:\\Users\\Administrator\\AppData\\Local\\rclone\\vfs\\remote" for canonical name "//?/C:/Users/Administrator/AppData/Local/rclone/vfs/remote"
2021/02/11 15:43:26 DEBUG : Computer/rclone id legalic.txt: vfs cache: truncate to size=142
2021/02/11 15:43:26 DEBUG : Computer/rclone id legalic.txt: vfs cache: setting modification time to 2021-02-11 10:13:54.2787192 +0700 +07
2021/02/11 15:43:26 INFO  : Computer/rclone id legalic.txt: vfs cache: queuing for upload in 5s
2021/02/11 15:43:26 ERROR : Computer/rclone id legalic.txt: vfs cache: failed to reload item: reload: failed to add virtual dir entry: file does not exist
2021/02/11 15:43:26 DEBUG : Network mode mounting is disabled
2021/02/11 15:43:26 DEBUG : Mounting on "X:" ("remote")
2021/02/11 15:43:26 DEBUG : Google drive root '': Mounting with options: ["-o" "attr_timeout=1" "-o" "uid=-1" "-o" "gid=-1" "--FileSystemName=rclone" "-o" "volname=remote" "--VolumePrefix=\\server\\share"]
2021/02/11 15:43:26 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item Computer/rclone id legalic.txt not removed, freed 0 bytes
2021/02/11 15:43:26 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item Install Program/7z1900-x64.exe not removed, freed 0 bytes
2021/02/11 15:43:26 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item Install Program/setup-lightshot.exe not removed, freed 0 bytes
2021/02/11 15:43:26 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item Install Program/wireguard-installer.exe not removed, freed 0 bytes
2021/02/11 15:43:26 INFO  : vfs cache: cleaned: objects 4 (was 4) in use 1, to upload 1, uploading 0, total size 4.115M (was 4.115M)
2021/02/11 15:43:26 DEBUG : Google drive root '': Init:
2021/02/11 15:43:26 DEBUG : Google drive root '': >Init:
2021/02/11 15:43:26 DEBUG : /: Statfs:
2021/02/11 15:43:26 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:7864320 Bfree:4644247 Bavail:4644247 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2021/02/11 15:43:26 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:26 DEBUG : /: >Getattr: errc=0
2021/02/11 15:43:26 DEBUG : /: Readlink:
2021/02/11 15:43:26 DEBUG : /: >Readlink: linkPath="", errc=-40
The service rclone has been started.
2021/02/11 15:43:26 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:26 DEBUG : /: >Getattr: errc=0
2021/02/11 15:43:26 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:26 DEBUG : /: >Getattr: errc=0
2021/02/11 15:43:26 DEBUG : /: Opendir:
2021/02/11 15:43:26 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2021/02/11 15:43:26 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2021/02/11 15:43:26 DEBUG : /: >Opendir: errc=0, fh=0x0
2021/02/11 15:43:26 DEBUG : /: Statfs:
2021/02/11 15:43:26 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:7864320 Bfree:4644247 Bavail:4644247 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2021/02/11 15:43:26 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:26 DEBUG : /: >Getattr: errc=0
2021/02/11 15:43:26 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:26 DEBUG : /: >Getattr: errc=0
2021/02/11 15:43:26 DEBUG : /: Opendir:
2021/02/11 15:43:26 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2021/02/11 15:43:26 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2021/02/11 15:43:26 DEBUG : /: >Opendir: errc=0, fh=0x1
2021/02/11 15:43:26 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:26 DEBUG : /: >Getattr: errc=0
2021/02/11 15:43:26 DEBUG : /: Releasedir: fh=0x1
2021/02/11 15:43:26 DEBUG : /: >Releasedir: errc=0
2021/02/11 15:43:26 DEBUG : /: Releasedir: fh=0x0
2021/02/11 15:43:26 DEBUG : /: >Releasedir: errc=0
2021/02/11 15:43:26 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:26 DEBUG : /: >Getattr: errc=0
2021/02/11 15:43:26 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:26 DEBUG : /: >Getattr: errc=0
2021/02/11 15:43:26 DEBUG : /: Opendir:
2021/02/11 15:43:26 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2021/02/11 15:43:26 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2021/02/11 15:43:26 DEBUG : /: >Opendir: errc=0, fh=0x0
2021/02/11 15:43:26 DEBUG : /: Releasedir: fh=0x0
2021/02/11 15:43:26 DEBUG : /: >Releasedir: errc=0
2021/02/11 15:43:26 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:26 DEBUG : /: >Getattr: errc=0
2021/02/11 15:43:26 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:26 DEBUG : /: >Getattr: errc=0
2021/02/11 15:43:26 DEBUG : /: Opendir:
2021/02/11 15:43:26 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2021/02/11 15:43:26 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2021/02/11 15:43:26 DEBUG : /: >Opendir: errc=0, fh=0x0
2021/02/11 15:43:26 DEBUG : /: Releasedir: fh=0x0
2021/02/11 15:43:26 DEBUG : /: >Releasedir: errc=0
2021/02/11 15:43:26 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:26 DEBUG : /: >Getattr: errc=0
2021/02/11 15:43:26 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:26 DEBUG : /: >Getattr: errc=0
2021/02/11 15:43:26 DEBUG : /: Opendir:
2021/02/11 15:43:26 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2021/02/11 15:43:27 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2021/02/11 15:43:27 DEBUG : /: >Opendir: errc=0, fh=0x0
2021/02/11 15:43:27 DEBUG : /: Releasedir: fh=0x0
2021/02/11 15:43:27 DEBUG : /: >Releasedir: errc=0
2021/02/11 15:43:27 DEBUG : /Desktop.ini: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:27 DEBUG : /Desktop.ini: >Getattr: errc=-2
2021/02/11 15:43:27 DEBUG : /Desktop.ini: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:27 DEBUG : /Desktop.ini: >Getattr: errc=-2
2021/02/11 15:43:27 DEBUG : /AutoRun.inf: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:27 DEBUG : /AutoRun.inf: >Getattr: errc=-2
2021/02/11 15:43:27 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:27 DEBUG : /: >Getattr: errc=0
2021/02/11 15:43:27 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:27 DEBUG : /: >Getattr: errc=0
2021/02/11 15:43:27 DEBUG : /: Opendir:
2021/02/11 15:43:27 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2021/02/11 15:43:27 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2021/02/11 15:43:27 DEBUG : /: >Opendir: errc=0, fh=0x0
2021/02/11 15:43:27 DEBUG : /: Releasedir: fh=0x0
2021/02/11 15:43:27 DEBUG : /: >Releasedir: errc=0
2021/02/11 15:43:27 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:27 DEBUG : /: >Getattr: errc=0
2021/02/11 15:43:27 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:27 DEBUG : /: >Getattr: errc=0
2021/02/11 15:43:27 DEBUG : /: Opendir:
2021/02/11 15:43:27 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2021/02/11 15:43:27 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2021/02/11 15:43:27 DEBUG : /: >Opendir: errc=0, fh=0x0
2021/02/11 15:43:27 DEBUG : /: Releasedir: fh=0x0
2021/02/11 15:43:27 DEBUG : /: >Releasedir: errc=0
2021/02/11 15:43:27 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:27 DEBUG : /: >Getattr: errc=0
2021/02/11 15:43:27 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:27 DEBUG : /: >Getattr: errc=0
2021/02/11 15:43:27 DEBUG : /: Opendir:
2021/02/11 15:43:27 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2021/02/11 15:43:27 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2021/02/11 15:43:27 DEBUG : /: >Opendir: errc=0, fh=0x0
2021/02/11 15:43:27 DEBUG : /: Releasedir: fh=0x0
2021/02/11 15:43:27 DEBUG : /: >Releasedir: errc=0
2021/02/11 15:43:27 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:27 DEBUG : /: >Getattr: errc=0
2021/02/11 15:43:27 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2021/02/11 15:43:27 DEBUG : /: >Getattr: errc=0
2021/02/11 15:43:27 DEBUG : /: Opendir:
2021/02/11 15:43:27 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2021/02/11 15:43:27 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2021/02/11 15:43:27 DEBUG : /: >Opendir: errc=0, fh=0x0
2021/02/11 15:43:27 DEBUG : /: Releasedir: fh=0x0
2021/02/11 15:43:27 DEBUG : /: >Releasedir: errc=0
2021/02/11 15:43:31 DEBUG : Computer/rclone id legalic.txt: vfs cache: starting upload
2021/02/11 15:43:32 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 500: Internal Error, internalError)
2021/02/11 15:43:32 DEBUG : pacer: Rate limited, increasing sleep to 1.070083747s
2021/02/11 15:43:32 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 500: Internal Error, internalError)
2021/02/11 15:43:32 DEBUG : pacer: Rate limited, increasing sleep to 2.093180107s
2021/02/11 15:43:33 DEBUG : pacer: low level retry 3/10 (error googleapi: Error 500: Internal Error, internalError)
2021/02/11 15:43:33 DEBUG : pacer: Rate limited, increasing sleep to 4.612482379s
2021/02/11 15:43:35 DEBUG : pacer: low level retry 4/10 (error googleapi: Error 500: Internal Error, internalError)
2021/02/11 15:43:35 DEBUG : pacer: Rate limited, increasing sleep to 8.148719308s
2021/02/11 15:43:40 DEBUG : pacer: low level retry 5/10 (error googleapi: Error 500: Internal Error, internalError)
2021/02/11 15:43:40 DEBUG : pacer: Rate limited, increasing sleep to 16.152484465s
2021/02/11 15:43:48 DEBUG : pacer: low level retry 6/10 (error googleapi: Error 500: Internal Error, internalError)
2021/02/11 15:43:48 DEBUG : pacer: Rate limited, increasing sleep to 16.061852725s
2021/02/11 15:44:04 DEBUG : pacer: low level retry 7/10 (error googleapi: Error 500: Internal Error, internalError)
2021/02/11 15:44:04 DEBUG : pacer: Rate limited, increasing sleep to 16.545539788s
2021/02/11 15:44:20 DEBUG : pacer: low level retry 8/10 (error googleapi: Error 500: Internal Error, internalError)
2021/02/11 15:44:20 DEBUG : pacer: Rate limited, increasing sleep to 16.641912044s
2021/02/11 15:44:25 DEBUG : Google drive root '': Checking for changes on remote
2021/02/11 15:44:26 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item Computer/rclone id legalic.txt not removed, freed 0 bytes
2021/02/11 15:44:26 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item Install Program/7z1900-x64.exe not removed, freed 0 bytes
2021/02/11 15:44:26 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item Install Program/setup-lightshot.exe not removed, freed 0 bytes
2021/02/11 15:44:26 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item Install Program/wireguard-installer.exe not removed, freed 0 bytes
2021/02/11 15:44:26 INFO  : vfs cache: cleaned: objects 4 (was 4) in use 1, to upload 0, uploading 1, total size 4.115M (was 4.115M)
2021/02/11 15:44:37 DEBUG : pacer: low level retry 9/10 (error googleapi: Error 500: Internal Error, internalError)
2021/02/11 15:44:37 DEBUG : pacer: Rate limited, increasing sleep to 16.905489505s
2021/02/11 15:44:54 DEBUG : pacer: Reducing sleep to 0s

Did you manually remove from the cache?

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