Rclone is very slow to opening files

brunoadan · October 7, 2022, 7:36pm

What is the problem you are having with rclone?

Rclone is very slow to opening any files, even small files.

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

rclone v1.59.2

os/version: Microsoft Windows 11 Home Single Language 22H2 (64 bit)
os/kernel: 10.0.22621.521 (x86_64)
os/type: windows
os/arch: amd64
go/version: go1.18.6
go/linking: static
go/tags: cmount

Which cloud storage system are you using?

OneDrive Business

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

Click on a file to open it, after mounted unit as a service (using nssm).

rclone mount --log-file "C:\rcloneE\rcloneOneDrive.log" --log-level DEBUG --dir-cache-time=1h --buffer-size=64M --vfs-cache-mode writes --file-perms=0777 --cache-dir "c:\onedriveRDN"  onedrive:RDN E: --volname RDN --config "C:\rcloneE\rclone.conf"

The rclone config contents with secrets removed.

[onedrive]
type = onedrive
region = global
link_type = edit
token = {"access_token":"***"}
drive_id = ***
drive_type = business

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


2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >Getattr: errc=0
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >Getattr: errc=0
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: OpenEx: flags=0x0
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/10/07 16:15:08 DEBUG : DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: Open: flags=O_RDONLY
2022/10/07 16:15:08 DEBUG : DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >Open: fd=DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx (r), err=<nil>
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >OpenFile: fd=DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx (r), err=<nil>
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >OpenEx: errc=0, fh=0x3
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: Flush: fh=0x3
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >Flush: errc=0
2022/10/07 16:15:08 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/10/07 16:15:08 DEBUG : /: >Getattr: errc=0
2022/10/07 16:15:08 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/10/07 16:15:08 DEBUG : /: >Getattr: errc=0
2022/10/07 16:15:08 DEBUG : /: Opendir: 
2022/10/07 16:15:08 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/10/07 16:15:08 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/10/07 16:15:08 DEBUG : /: >Opendir: errc=0, fh=0x5
2022/10/07 16:15:08 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/10/07 16:15:08 DEBUG : /: >Getattr: errc=0
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: Release: fh=0x3
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >Release: errc=0
2022/10/07 16:15:08 DEBUG : /: Readdir: ofst=0, fh=0x5
2022/10/07 16:15:08 DEBUG : /: >Readdir: items=6, errc=0
2022/10/07 16:15:08 DEBUG : /: Releasedir: fh=0x5
2022/10/07 16:15:08 DEBUG : /: >Releasedir: errc=0
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >Getattr: errc=0
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >Getattr: errc=0
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >Getattr: errc=0
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: OpenEx: flags=0x0
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/10/07 16:15:08 DEBUG : DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: Open: flags=O_RDONLY
2022/10/07 16:15:08 DEBUG : DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >Open: fd=DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx (r), err=<nil>
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >Getattr: errc=0
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >OpenFile: fd=DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx (r), err=<nil>
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >OpenEx: errc=0, fh=0x3
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: OpenEx: flags=0x0
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/10/07 16:15:08 DEBUG : DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: Open: flags=O_RDONLY
2022/10/07 16:15:08 DEBUG : DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >Open: fd=DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx (r), err=<nil>
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: Getattr: fh=0x3
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >Getattr: errc=0
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >OpenFile: fd=DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx (r), err=<nil>
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >OpenEx: errc=0, fh=0x5
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: Flush: fh=0x3
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >Flush: errc=0
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: Release: fh=0x3
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: Getattr: fh=0x5
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >Getattr: errc=0
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >Getattr: errc=0
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >Release: errc=0
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: Flush: fh=0x5
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: >Flush: errc=0
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: Release: fh=0x5
2022/10/07 16:15:08 DEBUG : /DocCont/Controle de Documentos (Atualizado 23.09.22).xlsx: Getattr: fh=0xFFFFFFFFFFFFFFFF
partial log

asdffdsa · October 7, 2022, 8:07pm

hello and welcome to the forum,

what type of file, .doc, .pdf or what?

what app is used to open the file?

how much time is needed to open the file?

update: did a quick test using
rclone mount onedrivevb:zork b:\rclone\mount\onedrivevb.zork --vfs-cache-mode=full --log-level=DEBUG --log-file=.\\log.mount.onedrivevb.zork.txt --cache-dir=d:\rclone\cache\onedrivevb.zork

i can open a .docx and .pdf in less than two seconds

brunoadan · October 7, 2022, 8:36pm

Dear @asdffdsa,
in advance, thank you for your help.

what type of file, .doc, .pdf or what?
all types... .xlsx, .doc, .pdf...

what app is used to open the file?
Microsoft Excel, Word and to pdf I am using Fox It.

how much time is needed to open the file?
3 for 5 minutes. While charging, window of Explorer get status Not respondig.

update: did a quick test using
result....

2022/10/07 17:34:08 DEBUG : rclone: Version "v1.59.2" starting with parameters ["rclone.exe" "mount" "onedrivevb:zork" "b:\rclone\mount\onedrivevb.zork" "--vfs-cache-mode=full" "--log-level=DEBUG" "--log-file=.\\log.mount.onedrivevb.zork.txt" "--cache-dir=d:\rclone\cache\onedrivevb.zork"]
2022/10/07 17:34:08 DEBUG : Creating backend with remote "onedrivevb:zork"
2022/10/07 17:34:08 DEBUG : Using config file from "C:\rcloneE\rclone.conf"
2022/10/07 17:34:08 Failed to create file system for "onedrivevb:zork": didn't find section in config file
2022/10/07 17:34:10 DEBUG : rclone: Version "v1.59.2" starting with parameters ["rclone.exe" "mount" "onedrivevb:zork" "b:\rclone\mount\onedrivevb.zork" "--vfs-cache-mode=full" "--log-level=DEBUG" "--log-file=.\\log.mount.onedrivevb.zork.txt" "--cache-dir=d:\rclone\cache\onedrivevb.zork"]
2022/10/07 17:34:10 DEBUG : Creating backend with remote "onedrivevb:zork"
2022/10/07 17:34:10 DEBUG : Using config file from "C:\rcloneE\rclone.conf"
2022/10/07 17:34:10 Failed to create file system for "onedrivevb:zork": didn't find section in config file
2022/10/07 17:34:14 DEBUG : rclone: Version "v1.59.2" starting with parameters ["rclone.exe" "mount" "onedrivevb:zork" "b:\rclone\mount\onedrivevb.zork" "--vfs-cache-mode=full" "--log-level=DEBUG" "--log-file=.\\log.mount.onedrivevb.zork.txt" "--cache-dir=d:\rclone\cache\onedrivevb.zork"]
2022/10/07 17:34:14 DEBUG : Creating backend with remote "onedrivevb:zork"
2022/10/07 17:34:14 DEBUG : Using config file from "C:\rcloneE\rclone.conf"
2022/10/07 17:34:14 Failed to create file system for "onedrivevb:zork": didn't find section in config file
2022/10/07 17:34:22 DEBUG : rclone: Version "v1.59.2" starting with parameters ["rclone.exe" "mount" "onedrivevb:zork" "b:\rclone\mount\onedrivevb.zork" "--vfs-cache-mode=full" "--log-level=DEBUG" "--log-file=.\\log.mount.onedrivevb.zork.txt" "--cache-dir=d:\rclone\cache\onedrivevb.zork"]
2022/10/07 17:34:22 DEBUG : Creating backend with remote "onedrivevb:zork"
2022/10/07 17:34:22 DEBUG : Using config file from "C:\rcloneE\rclone.conf"
2022/10/07 17:34:22 Failed to create file system for "onedrivevb:zork": didn't find section in config file
2022/10/07 17:34:39 DEBUG : rclone: Version "v1.59.2" starting with parameters ["rclone.exe" "mount" "onedrivevb:zork" "b:\rclone\mount\onedrivevb.zork" "--vfs-cache-mode=full" "--log-level=DEBUG" "--log-file=.\\log.mount.onedrivevb.zork.txt" "--cache-dir=d:\rclone\cache\onedrivevb.zork"]
2022/10/07 17:34:39 DEBUG : Creating backend with remote "onedrivevb:zork"
2022/10/07 17:34:39 DEBUG : Using config file from "C:\rcloneE\rclone.conf"
2022/10/07 17:34:39 Failed to create file system for "onedrivevb:zork": didn't find section in config file
2022/10/07 17:35:11 DEBUG : rclone: Version "v1.59.2" starting with parameters ["rclone.exe" "mount" "onedrivevb:zork" "b:\rclone\mount\onedrivevb.zork" "--vfs-cache-mode=full" "--log-level=DEBUG" "--log-file=.\\log.mount.onedrivevb.zork.txt" "--cache-dir=d:\rclone\cache\onedrivevb.zork"]
2022/10/07 17:35:11 DEBUG : Creating backend with remote "onedrivevb:zork"
2022/10/07 17:35:11 DEBUG : Using config file from "C:\rcloneE\rclone.conf"
2022/10/07 17:35:11 Failed to create file system for "onedrivevb:zork": didn't find section in config file

asdffdsa · October 7, 2022, 8:43pm

that command was run on my comptuer, will not work on yours
you need to change the source, dest and file system paths for your system
for example,
rclone mount onedrive:RDN E: --vfs-cache-mode full --log-level DEBUG --log-file "C:\rcloneE\rcloneOneDrive.log" --cache-dir "c:\onedriveRDN" --config "C:\rcloneE\rclone.conf"

about that debug log, it is just one second long.
try to find large time gaps between log entries and
text such as WARNING, ERROR, pacer

brunoadan · October 7, 2022, 8:45pm

Good news! I used flags that you indicated and now the files is opening fast!

new parameters:

mount --log-file "C:\rcloneE\rcloneOneDrive.log" --vfs-cache-mode=full --log-level DEBUG --cache-dir "c:\onedriveRDN" onedrive:RDN E: --volname RDN --config "C:\rcloneE\rclone.conf"

Thank you!

asdffdsa · October 7, 2022, 8:51pm

good, as --vfs-cache-mode=full seems to have fixed the issue.

system · October 10, 2022, 8:51pm

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