Accessing file metadata via Rclone Mount is extremely slow (both Windows Explorer and PowerShell)

Help and Support
1

What is the problem you are having with rclone?

Windows Explorer and PowerShell both experience slow speeds when retrieving file information via the rclone mount tool.

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

rclone v1.57.0
- os/version: Microsoft Windows 10 Pro 2009 (64 bit)
- os/kernel: 10.0.22523.1000 (x86_64)
- os/type: windows
- os/arch: amd64
- go/version: go1.17.2
- go/linking: dynamic
- go/tags: cmount

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

Filebase.com (S3-compatible APIs)

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

First, mount the Filebase bucket (config is included below):

rclone mount --config=z:\rclone.config mount filebase:trevor x:

In PowerShell, the following command takes about 17 seconds to run (make sure to restart rclone mount each time, to prevent WinFsp caching:

PS /> measure-command { gci x: | % { Write-Host $PSItem.Length } }

Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 17
Milliseconds      : 848
Ticks             : 178483175
TotalDays         : 0.000206577748842593
TotalHours        : 0.00495786597222222
TotalMinutes      : 0.297471958333333
TotalSeconds      : 17.8483175
TotalMilliseconds : 17848.3175

Instead, using the Amazon S3-compatible APIs, it's much faster:

PS /> Measure-Command { $Result3 = Get-S3Object -EndpointUrl https://s3.filebase.com -BucketName trevor -ProfileName filebase -Region us-east-1 }

Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 1
Milliseconds      : 266
Ticks             : 12664253
TotalDays         : 1.46577002314815E-05
TotalHours        : 0.000351784805555556
TotalMinutes      : 0.0211070883333333
TotalSeconds      : 1.2664253
TotalMilliseconds : 1266.4253

The rclone config contents with secrets removed.

[filebase]
type = s3
provider = other
endpoint = https://s3.filebase.com
region = us-east-1
access_key_id = xxxxxxxxxxxxxxxxxxxx
secret_access_key=xxxxxxxxxxxxxxxxx

A log from the command with the -vv flag

2022/02/03 12:35:07 DEBUG : rclone: Version "v1.57.0" starting with parameters ["C:\\Users\\cloud\\scoop\\apps\\rclone\\current\\rclone.exe" "--config=z:\\rclone.config" "mount" "filebase:trevor" "x:" "-vv"]
2022/02/03 12:35:07 DEBUG : Creating backend with remote "filebase:trevor"
2022/02/03 12:35:07 DEBUG : Using config file from "z:\\rclone.config"
2022/02/03 12:35:07 INFO  : S3 bucket trevor: poll-interval is not supported by this remote
2022/02/03 12:35:07 DEBUG : Network mode mounting is disabled
2022/02/03 12:35:07 DEBUG : Mounting on "x:" ("filebase trevor")
2022/02/03 12:35:07 DEBUG : S3 bucket trevor: Mounting with options: ["-o" "attr_timeout=1" "-o" "uid=-1" "-o" "gid=-1" "--FileSystemName=rclone" "-o" "volname=filebase trevor"]
2022/02/03 12:35:07 DEBUG : S3 bucket trevor: Init:
2022/02/03 12:35:07 DEBUG : S3 bucket trevor: >Init:
2022/02/03 12:35:07 DEBUG : /: Statfs:
2022/02/03 12:35:07 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2022/02/03 12:35:07 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:07 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:07 DEBUG : /: Readlink:
2022/02/03 12:35:07 DEBUG : /: >Readlink: linkPath="", errc=-40
The service rclone has been started.
2022/02/03 12:35:07 DEBUG : /: Statfs:
2022/02/03 12:35:07 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2022/02/03 12:35:07 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:07 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:07 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:07 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:07 DEBUG : /: Opendir:
2022/02/03 12:35:07 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:07 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:07 DEBUG : /: >Opendir: errc=0, fh=0x0
2022/02/03 12:35:07 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:07 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:07 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:07 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:07 DEBUG : /: Opendir:
2022/02/03 12:35:07 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:07 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:07 DEBUG : /: >Opendir: errc=0, fh=0x1
2022/02/03 12:35:07 DEBUG : /: Releasedir: fh=0x0
2022/02/03 12:35:07 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:07 DEBUG : /: Releasedir: fh=0x1
2022/02/03 12:35:07 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:07 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:07 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:07 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:07 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:07 DEBUG : /: Opendir:
2022/02/03 12:35:07 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:07 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:07 DEBUG : /: >Opendir: errc=0, fh=0x0
2022/02/03 12:35:07 DEBUG : /: Releasedir: fh=0x0
2022/02/03 12:35:07 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:11 DEBUG : /autorun.inf: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:11 DEBUG : /desktop.ini: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:12 DEBUG : /autorun.inf: >Getattr: errc=-2
2022/02/03 12:35:12 DEBUG : /desktop.ini: >Getattr: errc=-2
2022/02/03 12:35:12 DEBUG : /autorun.inf: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:12 DEBUG : /autorun.inf: >Getattr: errc=-2
2022/02/03 12:35:12 DEBUG : /autorun.inf: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:12 DEBUG : /autorun.inf: >Getattr: errc=-2
2022/02/03 12:35:12 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:12 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:12 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:12 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:12 DEBUG : /: Opendir:
2022/02/03 12:35:12 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:12 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:12 DEBUG : /: >Opendir: errc=0, fh=0x0
2022/02/03 12:35:12 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:12 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:12 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:12 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:12 DEBUG : /: Opendir:
2022/02/03 12:35:12 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:12 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:12 DEBUG : /: >Opendir: errc=0, fh=0x1
2022/02/03 12:35:12 DEBUG : /: Readdir: ofst=0, fh=0x0
2022/02/03 12:35:13 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:13 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:13 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:13 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:13 DEBUG : /: Opendir:
2022/02/03 12:35:13 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:13 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:13 DEBUG : /: >Opendir: errc=0, fh=0x2
2022/02/03 12:35:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:16 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:16 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:16 DEBUG : /: Opendir:
2022/02/03 12:35:16 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:16 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:16 DEBUG : /: >Opendir: errc=0, fh=0x3
2022/02/03 12:35:29 DEBUG : /: >Readdir: items=122, errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Statfs:
2022/02/03 12:35:29 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x2
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /AutoRun.inf: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /AutoRun.inf: >Getattr: errc=-2
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x1
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x3
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Opendir:
2022/02/03 12:35:29 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:29 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:29 DEBUG : /: >Opendir: errc=0, fh=0x1
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x1
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Opendir:
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:29 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:29 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:29 DEBUG : /: >Opendir: errc=0, fh=0x1
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x1
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Opendir:
2022/02/03 12:35:29 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:29 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:29 DEBUG : /: >Opendir: errc=0, fh=0x1
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x1
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x0
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: Opendir:
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Opendir:
2022/02/03 12:35:29 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:29 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:29 DEBUG : /: >Opendir: errc=0, fh=0x0
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x0
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:29 DEBUG : /: Opendir:
2022/02/03 12:35:29 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:29 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:29 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:29 DEBUG : /: >Opendir: errc=0, fh=0x0
2022/02/03 12:35:29 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:29 DEBUG : /: >Opendir: errc=0, fh=0x1
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x1
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x0
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:29 DEBUG : /: Opendir:
2022/02/03 12:35:29 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:29 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:29 DEBUG : /: >Opendir: errc=0, fh=0x0
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x0
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Opendir:
2022/02/03 12:35:29 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:29 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:29 DEBUG : /: >Opendir: errc=0, fh=0x0
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Opendir:
2022/02/03 12:35:29 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:29 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:29 DEBUG : /: >Opendir: errc=0, fh=0x0
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Opendir:
2022/02/03 12:35:29 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:29 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:29 DEBUG : /: >Opendir: errc=0, fh=0x1
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Opendir:
2022/02/03 12:35:29 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:29 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:29 DEBUG : /: >Opendir: errc=0, fh=0x2
2022/02/03 12:35:29 DEBUG : /: Readdir: ofst=0, fh=0x0
2022/02/03 12:35:29 DEBUG : /: >Readdir: items=122, errc=0
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x0
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x1
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x2
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Opendir:
2022/02/03 12:35:29 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:29 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:29 DEBUG : /: >Opendir: errc=0, fh=0x0
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x0
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Opendir:
2022/02/03 12:35:29 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:29 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:29 DEBUG : /: >Opendir: errc=0, fh=0x0
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x0
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Opendir:
2022/02/03 12:35:29 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:29 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:29 DEBUG : /: >Opendir: errc=0, fh=0x0
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x0
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Opendir:
2022/02/03 12:35:29 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:29 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:29 DEBUG : /: >Opendir: errc=0, fh=0x0
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x0
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Opendir:
2022/02/03 12:35:29 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:29 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:29 DEBUG : /: >Opendir: errc=0, fh=0x0
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x0
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/03 12:35:29 DEBUG : /: >Getattr: errc=0
2022/02/03 12:35:29 DEBUG : /: Opendir:
2022/02/03 12:35:29 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/03 12:35:29 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/03 12:35:29 DEBUG : /: >Opendir: errc=0, fh=0x0
2022/02/03 12:35:29 DEBUG : /: Releasedir: fh=0x0
2022/02/03 12:35:29 DEBUG : /: >Releasedir: errc=0
The service rclone has been stopped.
2022/02/03 12:35:31 DEBUG : S3 bucket trevor: Destroy:
2022/02/03 12:35:31 DEBUG : S3 bucket trevor: >Destroy:
2022/02/03 12:35:31 DEBUG : Not calling host.Unmount as mount already Destroyed
2022/02/03 12:35:31 DEBUG : Unmounted successfully
2022/02/03 12:35:31 ERROR : x:: Unmounted rclone mount
2022/02/03 12:35:31 DEBUG : rclone: Version "v1.57.0" finishing with parameters ["C:\\Users\\cloud\\scoop\\apps\\rclone\\current\\rclone.exe" "--config=z:\\rclone.config" "mount" "filebase:trevor" "x:" "-vv"]
2

What does the "gci" thing do?

Not that 17 seconds feels right, but comparing a mount to a direct API call for results isn't quite the same.

To compare that, you'd use rclone ls and not a mount albeit a mount doesn't add that much overhead.

3

gci is an alias for Get-ChildItem in PowerShell. It's the typical command you use to list items in a directory as an array of objects.

Using rclone mount uses WinFsp, whereas rclone ls almost certainly does not.

PS /> measure-command { rclone --config=z:\rclone.config ls filebase:trevor }

Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 1
Milliseconds      : 191
Ticks             : 11915228
TotalDays         : 1.37907731481481E-05
TotalHours        : 0.000330978555555556
TotalMinutes      : 0.0198587133333333
TotalSeconds      : 1.1915228
TotalMilliseconds : 1191.5228

My guess is the performance problem lies with WinFsp?

Edit:

4

So I'm not a Windows guy by any means so I'm assuming that's doing a recursive listing of a directory and getting the attributes of the files?

On Linux, you'll see one call for listing out the directory and an attr check on each file give you the metadata on the file.

felix@gemini:~$ rclone mount DB:test /home/felix/test -vvv
2022/02/04 14:20:35 DEBUG : Setting --config "/opt/rclone/rclone.conf" from environment variable RCLONE_CONFIG="/opt/rclone/rclone.conf"
2022/02/04 14:20:35 DEBUG : rclone: Version "v1.57.0" starting with parameters ["rclone" "mount" "DB:test" "/home/felix/test" "-vvv"]
2022/02/04 14:20:35 DEBUG : Creating backend with remote "DB:test"
2022/02/04 14:20:35 DEBUG : Using config file from "/opt/rclone/rclone.conf"
2022/02/04 14:20:35 DEBUG : Dropbox root 'test': Mounting on "/home/felix/test"
2022/02/04 14:20:35 DEBUG : : Root:
2022/02/04 14:20:35 DEBUG : : >Root: node=/, err=<nil>
2022/02/04 14:20:37 DEBUG : /: Attr:
2022/02/04 14:20:37 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2022/02/04 14:20:38 DEBUG : /: Attr:
2022/02/04 14:20:38 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2022/02/04 14:20:38 DEBUG : /: ReadDirAll:
2022/02/04 14:20:39 DEBUG : /: >ReadDirAll: item=5, err=<nil>
2022/02/04 14:20:39 DEBUG : /: Attr:
2022/02/04 14:20:39 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2022/02/04 14:20:39 DEBUG : /: Lookup: name="one"
2022/02/04 14:20:39 DEBUG : /: >Lookup: node=one, err=<nil>
2022/02/04 14:20:39 DEBUG : one: Attr:
2022/02/04 14:20:39 DEBUG : one: >Attr: a=valid=1s ino=0 size=107 mode=-rw-rw-r--, err=<nil>
2022/02/04 14:20:39 DEBUG : /: Lookup: name="three"
2022/02/04 14:20:39 DEBUG : /: >Lookup: node=three, err=<nil>
2022/02/04 14:20:39 DEBUG : three: Attr:
2022/02/04 14:20:39 DEBUG : three: >Attr: a=valid=1s ino=0 size=107 mode=-rw-rw-r--, err=<nil>
2022/02/04 14:20:39 DEBUG : /: Lookup: name="two"
2022/02/04 14:20:39 DEBUG : /: >Lookup: node=two, err=<nil>
2022/02/04 14:20:39 DEBUG : two: Attr:
2022/02/04 14:20:39 DEBUG : two: >Attr: a=valid=1s ino=0 size=107 mode=-rw-rw-r--, err=<nil>
2022/02/04 14:20:39 DEBUG : : Statfs:
2022/02/04 14:20:39 DEBUG : : >Statfs: stat={Blocks:53207891968 Bfree:1416702613 Bavail:1416702613 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>
^C2022/02/04 14:20:42 INFO  : Signal received: interrupt
2022/02/04 14:20:42 INFO  : Dropbox root 'test': Commiting uploads - please wait...
2022/02/04 14:20:42 ERROR : /home/felix/test: Failed to unmount: exit status 1: fusermount: failed to unmount /home/felix/test: Device or resource busy
2022/02/04 14:20:42 INFO  : Exiting...

So listing

felix@gemini:~/test$ ls -al
total 2
drwxrwxr-x 1 felix felix   0 Feb  4 14:20 .
drwxr-xr-x 1 felix felix 412 Feb  4 11:56 ..
-rw-rw-r-- 1 felix felix 107 Feb  4 14:20 one
-rw-rw-r-- 1 felix felix 107 Feb  4 14:20 three
-rw-rw-r-- 1 felix felix 107 Feb  4 14:20 two

Is that basically what you are doing? Just trying to make sure I understand what is being done.

5

It's not recursive by default (same as Unix ls command, without -R flag), and there aren't any "folders" (key prefixes) in my S3-compatible remote. If you wanted the operation to be recursive, you'd do:

Get-ChildItem -Recurse -Path x:\

PowerShell is open source and cross-platform; it runs on Linux natively. The only thing that's specific to Windows, in this issue, is WinFsp. Maybe I should try the same scenario from a Linux VM.

6

There's zero reason for me to run / learn / ever use powershell so I can with almost 100% certainty tell you, I won't be putting it on my Linux box :slight_smile:

Perhaps if you entice @asdffdsa to stop in as he is a big Windows/S3 user and can test out and run something similar.

I'm not using S3 so that's not quite fair compare on my side

Let's piece through the log though.

That is what reads the directory in one shot in my log. I see no ReadDirAll in your log.

What's actually in the bucket you are listing?

I don't see any Lookups for file metadata.

As an example from my log.

Can you share the rclone ls output of the bucket?

7

A bunch of RAW image files. Somewhere around 100 at the time, I think. I'm uploading more images today, so there's more now.

Here's the output of the rclone ls command. It doesn't contain anything useful.

2022/02/04 12:41:10 DEBUG : rclone: Version "v1.57.0" starting with parameters ["C:\\Users\\TrevorSullivan\\scoop\\apps\\rclone\\current\\rclone.exe" "--config=z:\\rclone.config" "ls" "filebase:trevor" "-vv"]
2022/02/04 12:41:10 DEBUG : Creating backend with remote "filebase:trevor"
2022/02/04 12:41:10 DEBUG : Using config file from "z:\\rclone.config"
  6154752 P1000853.JPG
  5761024 P1000868.JPG
  5517824 P1000869.JPG
  5567488 P1000870.JPG
  5799936 P1000871.JPG
  7981568 P1000872.JPG
  6700544 P1000873.JPG
  7129088 P1000874.JPG
  6211072 P1000875.JPG
  5623296 P1000876.JPG
  5281792 P1000877.JPG
  7032832 P1000878.JPG
  5360128 P1000879.JPG
  5606912 P1000880.JPG
  6580224 P1000881.JPG
  5772800 P1000882.JPG
  5646848 P1000883.JPG
  5974016 P1000884.JPG
  5820928 P1000885.JPG
  5859328 P1000886.JPG
  6592512 P1000887.JPG
 19595264 P1010135.RW2
 19598336 P1010136.RW2
 19558400 P1010137.RW2
 19609088 P1010138.RW2
 19583488 P1010139.RW2
 19603968 P1010140.RW2
 19580416 P1010141.RW2
 19621888 P1010142.RW2
 19593216 P1010143.RW2
 19615232 P1010144.RW2
 19634176 P1010145.RW2
 19653120 P1010146.RW2
 19639808 P1010147.RW2
 19659264 P1010148.RW2
 19696128 P1010149.RW2
 19690496 P1010150.RW2
 19666944 P1010151.RW2
 19654144 P1010152.RW2
 19661824 P1010153.RW2
 19618304 P1010154.RW2
 19707392 P1010155.RW2
 19653632 P1010156.RW2
 19693568 P1010157.RW2
 19781632 P1010158.RW2
 19726336 P1010159.RW2
 19807744 P1010160.RW2
 19755008 P1010161.RW2
 19689984 P1010162.RW2
 19691520 P1010163.RW2
 19714048 P1010164.RW2
 19681792 P1010165.RW2
 19689984 P1010166.RW2
 19731968 P1010167.RW2
 19689472 P1010168.RW2
 19738112 P1010169.RW2
 19802112 P1010170.RW2
 19777536 P1010171.RW2
 19694592 P1010172.RW2
 19753984 P1010173.RW2
 19770880 P1010174.RW2
 19779584 P1010175.RW2
 19708928 P1010176.RW2
 19654656 P1010177.RW2
 19635200 P1010178.RW2
 19645440 P1010179.RW2
 19661312 P1010180.RW2
 19622400 P1010181.RW2
 19572736 P1010182.RW2
 19576832 P1010183.RW2
 19661824 P1010184.RW2
 19666432 P1010185.RW2
 19665408 P1010186.RW2
 19575296 P1010187.RW2
 19636736 P1010188.RW2
 19679744 P1010189.RW2
 19724800 P1010190.RW2
 19686912 P1010191.RW2
 19729920 P1010192.RW2
 19811840 P1010193.RW2
 19841024 P1010194.RW2
 19808256 P1010195.RW2
 19825152 P1010196.RW2
 19804160 P1010197.RW2
 19696640 P1010198.RW2
 19722752 P1010199.RW2
 19825152 P1010200.RW2
 19832832 P1010201.RW2
 19822592 P1010202.RW2
 19815424 P1010203.RW2
 19785728 P1010204.RW2
 19773952 P1010205.RW2
 19708928 P1010206.RW2
 19655680 P1010207.RW2
 19804672 P1010208.RW2
 19527168 P1010209.RW2
 19534336 P1010210.RW2
 19745792 P1010211.RW2
 19780608 P1010212.RW2
 19756544 P1010213.RW2
 19837440 P1010214.RW2
 19734528 P1010215.RW2
 19753984 P1010216.RW2
 19759616 P1010217.RW2
 19751936 P1010218.RW2
 19761664 P1010219.RW2
 19792384 P1010220.RW2
 19532800 P1010221.RW2
 19526144 P1010222.RW2
 19745280 P1010223.RW2
 19837440 P1010224.RW2
 19848192 P1010225.RW2
 19793920 P1010226.RW2
 19648000 P1010227.RW2
 19396608 P1010228.RW2
 19409408 P1010229.RW2
 19431936 P1010230.RW2
 19569664 P1010231.RW2
 19759104 P1010232.RW2
 19778048 P1010233.RW2
 19537408 P1010234.RW2
 19548672 P1010235.RW2
 19443200 P1010236.RW2
 19440640 P1010237.RW2
 19440640 P1010238.RW2
 19412992 P1010239.RW2
 19399680 P1010240.RW2
 19834368 P1010242.RW2
 19731456 P1010404.RW2
 19792896 P1010405.RW2
 19564032 P1010406.RW2
 19712000 P1010407.RW2
 19667968 P1010408.RW2
 19788800 P1010409.RW2
 19711488 P1010410.RW2
 19828736 P1010411.RW2
 19806720 P1010412.RW2
 19852288 P1010413.RW2
 19486720 P1010415.RW2
 19591680 P1010416.RW2
 19714048 P1010417.RW2
 19794432 P1010418.RW2
 19795456 P1010419.RW2
 19769344 P1010420.RW2
 19786240 P1010421.RW2
 19741184 P1010422.RW2
 19808256 P1010423.RW2
 19805184 P1010424.RW2
 19819008 P1010425.RW2
 19770368 P1010426.RW2
 19817984 P1010427.RW2
 19807232 P1010428.RW2
 19806720 P1010429.RW2
 19788288 P1010430.RW2
 19800576 P1010431.RW2
 19811328 P1010432.RW2
 19846144 P1010433.RW2
 19614720 P1010434.RW2
 19674624 P1010435.RW2
 19582976 P1010436.RW2
 19711488 P1010437.RW2
 19703808 P1010438.RW2
 19565056 P1010439.RW2
 19546624 P1010440.RW2
 19622912 P1010441.RW2
 19731968 P1010442.RW2
 19729408 P1010443.RW2
 19572224 P1010444.RW2
 19567616 P1010445.RW2
 19570176 P1010446.RW2
 19584000 P1010447.RW2
 19585536 P1010448.RW2
 19579392 P1010449.RW2
 19772416 P1010451.RW2
 19763200 P1010452.RW2
 19761664 P1010453.RW2
 19767296 P1010454.RW2
 19771392 P1010455.RW2
 19753984 P1010456.RW2
 19751424 P1010457.RW2
 19729408 P1010458.RW2
 19749888 P1010459.RW2
 19766784 P1010460.RW2
 19759616 P1010461.RW2
 19740160 P1010462.RW2
 19756544 P1010463.RW2
 19821056 P1010464.RW2
 19852288 P1010465.RW2
 19826688 P1010466.RW2
 19715584 P1010467.RW2
 19732480 P1010468.RW2
 19714048 P1010469.RW2
 19717120 P1010470.RW2
 19707904 P1010471.RW2
 19710464 P1010472.RW2
 19766272 P1010473.RW2
 19750400 P1010474.RW2
 19776512 P1010475.RW2
 19853824 P1010476.RW2
 19825152 P1010477.RW2
 19828736 P1010478.RW2
 19794432 P1010479.RW2
 19812864 P1010480.RW2
 19793408 P1010481.RW2
 19796992 P1010482.RW2
 19804672 P1010483.RW2
 19782144 P1010484.RW2
 19770368 P1010485.RW2
 19685888 P1010486.RW2
 19692544 P1010487.RW2
 19682304 P1010488.RW2
 19650560 P1010489.RW2
 19622912 P1010490.RW2
 19579904 P1010491.RW2
 19666432 P1010492.RW2
 19823104 P1010494.RW2
 19827200 P1010495.RW2
 19744256 P1010496.RW2
 19758592 P1010497.RW2
 19564032 P1010498.RW2
 19643904 P1010499.RW2
 19737088 P1010500.RW2
 19734528 P1010501.RW2
2022/02/04 12:41:12 DEBUG : 3 go routines active
8

hello and welcome to the forum,

sure, rclone mount will not perform as well as a simple ls or equivalent command.

tho i gave up on windows explorer over a decade ago, if that is what you use, then try --network-mode
that will prevent windows explorer from the overhead of creating icons/thumbnails.

and to speed dir/file listing on rclone mount, can pre-cache the info using
rclone rc vfs/refresh

and might take a read of this, tweaks to speed up listing
https://rclone.org/s3/#reducing-costs

1 Like
9

If you are mounting the same bucket, your mount debug log does not match the ls output. If you were listing out the same bucket, you'd have an entry in the debug log for each one of those files similar to my debug log.

Something doesn't quite add up so far.

10

It's the exact same bucket. It's named trevor and it's in my Filebase account. There is no ambiguity.

The output I have contributed in this post has been a direct copy-paste of the output from rclone. Not sure what to tell you.

11

I'm just going by what the mount debug you shared shows. There are no files listed out there in the log.

Perhaps try to make a new debug log and open up a command prompt and 'dir' in there and share that log.

I can only go by what the logs show and the mount log you shared, shows none of the files you've listed in the rclone ls output.

12

Okay maybe I accidentally left off the -vv or something. Here's what I think you're looking for.

2022/02/04 12:51:35 INFO  : S3 bucket trevor: poll-interval is not supported by this remote
2022/02/04 12:51:35 DEBUG : Network mode mounting is disabled
2022/02/04 12:51:35 DEBUG : Mounting on "x:" ("filebase trevor")
2022/02/04 12:51:35 DEBUG : S3 bucket trevor: Mounting with options: ["-o" "attr_timeout=1" "-o" "uid=-1" "-o" "gid=-1" "--FileSystemName=rclone" "-o" "volname=filebase trevor"]
2022/02/04 12:51:35 DEBUG : S3 bucket trevor: Init:
2022/02/04 12:51:35 DEBUG : S3 bucket trevor: >Init:
2022/02/04 12:51:35 DEBUG : /: Statfs:
2022/02/04 12:51:35 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2022/02/04 12:51:35 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:35 DEBUG : /: >Getattr: errc=0
2022/02/04 12:51:35 DEBUG : /: Readlink:
2022/02/04 12:51:35 DEBUG : /: >Readlink: linkPath="", errc=-40
The service rclone has been started.
2022/02/04 12:51:35 DEBUG : /: Statfs:
2022/02/04 12:51:35 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2022/02/04 12:51:35 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:35 DEBUG : /: >Getattr: errc=0
2022/02/04 12:51:35 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:35 DEBUG : /: >Getattr: errc=0
2022/02/04 12:51:35 DEBUG : /: Opendir:
2022/02/04 12:51:35 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:51:35 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/04 12:51:35 DEBUG : /: >Opendir: errc=0, fh=0x0
2022/02/04 12:51:35 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:35 DEBUG : /: >Getattr: errc=0
2022/02/04 12:51:35 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:35 DEBUG : /: >Getattr: errc=0
2022/02/04 12:51:35 DEBUG : /: Opendir:
2022/02/04 12:51:35 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:51:35 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/04 12:51:35 DEBUG : /: >Opendir: errc=0, fh=0x1
2022/02/04 12:51:35 DEBUG : /: Releasedir: fh=0x0
2022/02/04 12:51:35 DEBUG : /: Releasedir: fh=0x1
2022/02/04 12:51:35 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:35 DEBUG : /: >Getattr: errc=0
2022/02/04 12:51:35 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:35 DEBUG : /: >Getattr: errc=0
2022/02/04 12:51:35 DEBUG : /: Opendir:
2022/02/04 12:51:35 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:51:35 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/04 12:51:35 DEBUG : /: >Opendir: errc=0, fh=0x0
2022/02/04 12:51:35 DEBUG : /: >Releasedir: errc=0
2022/02/04 12:51:35 DEBUG : /: >Releasedir: errc=0
2022/02/04 12:51:35 DEBUG : /: Releasedir: fh=0x0
2022/02/04 12:51:35 DEBUG : /: >Releasedir: errc=0
2022/02/04 12:51:39 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:39 DEBUG : /: >Getattr: errc=0
2022/02/04 12:51:39 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:39 DEBUG : /: >Getattr: errc=0
2022/02/04 12:51:39 DEBUG : /: Opendir:
2022/02/04 12:51:39 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:51:39 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/04 12:51:39 DEBUG : /: >Opendir: errc=0, fh=0x0
2022/02/04 12:51:39 DEBUG : /: Releasedir: fh=0x0
2022/02/04 12:51:39 DEBUG : /: >Releasedir: errc=0
2022/02/04 12:51:39 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:39 DEBUG : /: >Getattr: errc=0
2022/02/04 12:51:39 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:39 DEBUG : /: >Getattr: errc=0
2022/02/04 12:51:39 DEBUG : /: Opendir:
2022/02/04 12:51:39 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:51:39 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/04 12:51:39 DEBUG : /: >Opendir: errc=0, fh=0x0
2022/02/04 12:51:39 DEBUG : /: Statfs:
2022/02/04 12:51:39 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2022/02/04 12:51:39 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:39 DEBUG : /: >Getattr: errc=0
2022/02/04 12:51:39 DEBUG : /: Releasedir: fh=0x0
2022/02/04 12:51:39 DEBUG : /: >Releasedir: errc=0
2022/02/04 12:51:39 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:39 DEBUG : /: >Getattr: errc=0
2022/02/04 12:51:39 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:39 DEBUG : /: >Getattr: errc=0
2022/02/04 12:51:39 DEBUG : /: Opendir:
2022/02/04 12:51:39 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:51:39 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/04 12:51:39 DEBUG : /: >Opendir: errc=0, fh=0x0
2022/02/04 12:51:39 DEBUG : /: Releasedir: fh=0x0
2022/02/04 12:51:39 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:39 DEBUG : /: >Getattr: errc=0
2022/02/04 12:51:39 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:39 DEBUG : /: >Getattr: errc=0
2022/02/04 12:51:39 DEBUG : /: Opendir:
2022/02/04 12:51:39 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:51:39 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/04 12:51:39 DEBUG : /: >Opendir: errc=0, fh=0x0
2022/02/04 12:51:39 DEBUG : /: >Releasedir: errc=0
2022/02/04 12:51:39 DEBUG : /: Readdir: ofst=0, fh=0x0
2022/02/04 12:51:39 DEBUG : /autorun.inf: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:39 DEBUG : /desktop.ini: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:40 DEBUG : /autorun.inf: >Getattr: errc=-2
2022/02/04 12:51:40 DEBUG : /desktop.ini: >Getattr: errc=-2
2022/02/04 12:51:40 DEBUG : /autorun.inf: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:40 DEBUG : /autorun.inf: >Getattr: errc=-2
2022/02/04 12:51:40 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:40 DEBUG : /: >Getattr: errc=0
2022/02/04 12:51:40 DEBUG : /autorun.inf: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:40 DEBUG : /autorun.inf: >Getattr: errc=-2
2022/02/04 12:51:40 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:40 DEBUG : /: >Getattr: errc=0
2022/02/04 12:51:40 DEBUG : /: Opendir:
2022/02/04 12:51:40 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:51:40 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/04 12:51:40 DEBUG : /: >Opendir: errc=0, fh=0x1
2022/02/04 12:51:40 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:40 DEBUG : /: >Getattr: errc=0
2022/02/04 12:51:40 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:51:40 DEBUG : /: >Getattr: errc=0
2022/02/04 12:51:40 DEBUG : /: Opendir:
2022/02/04 12:51:40 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:51:40 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/04 12:51:40 DEBUG : /: >Opendir: errc=0, fh=0x2
2022/02/04 12:52:00 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:00 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:00 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:00 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:00 DEBUG : /: Opendir:
2022/02/04 12:52:00 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:52:00 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/04 12:52:00 DEBUG : /: >Opendir: errc=0, fh=0x3
2022/02/04 12:52:16 DEBUG : /: >Readdir: items=236, errc=0
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Statfs:
2022/02/04 12:52:16 DEBUG : /: >Statfs: stat={Bsize:4096 Frsize:4096 Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Favail:0 Fsid:0 Flag:0 Namemax:255}, errc=0
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: OpenEx: flags=0x0
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /AutoRun.inf: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: Releasedir: fh=0x3
2022/02/04 12:52:16 DEBUG : /: >Releasedir: errc=0
2022/02/04 12:52:16 DEBUG : /: Releasedir: fh=0x2
2022/02/04 12:52:16 DEBUG : /: Opendir:
2022/02/04 12:52:16 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:52:16 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/04 12:52:16 DEBUG : /: >Opendir: errc=0, fh=0x2
2022/02/04 12:52:16 DEBUG : P1000853.JPG: Open: flags=O_RDONLY
2022/02/04 12:52:16 DEBUG : /: Releasedir: fh=0x2
2022/02/04 12:52:16 DEBUG : /: >Releasedir: errc=0
2022/02/04 12:52:16 DEBUG : P1000853.JPG: >Open: fd=P1000853.JPG (r), err=<nil>
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: >OpenFile: fd=P1000853.JPG (r), err=<nil>
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: >OpenEx: errc=0, fh=0x2
2022/02/04 12:52:16 DEBUG : /: >Releasedir: errc=0
2022/02/04 12:52:16 DEBUG : /AutoRun.inf: >Getattr: errc=-2
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: OpenEx: flags=0x0
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:52:16 DEBUG : P1000853.JPG: Open: flags=O_RDONLY
2022/02/04 12:52:16 DEBUG : P1000853.JPG: >Open: fd=P1000853.JPG (r), err=<nil>
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: >OpenFile: fd=P1000853.JPG (r), err=<nil>
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: Flush: fh=0x2
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: >Flush: errc=0
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: Release: fh=0x2
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: >Release: errc=0
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: >OpenEx: errc=0, fh=0x3
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: Getattr: fh=0x3
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Opendir:
2022/02/04 12:52:16 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:52:16 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/04 12:52:16 DEBUG : /: >Opendir: errc=0, fh=0x2
2022/02/04 12:52:16 DEBUG : /: Readdir: ofst=0, fh=0x1
2022/02/04 12:52:16 DEBUG : /: >Readdir: items=236, errc=0
2022/02/04 12:52:16 DEBUG : /P1000853.JPG: Read: ofst=0, fh=0x3
2022/02/04 12:52:16 DEBUG : /: Releasedir: fh=0x2
2022/02/04 12:52:16 DEBUG : /: >Releasedir: errc=0
2022/02/04 12:52:16 DEBUG : P1000853.JPG: ChunkedReader.openRange at 0 length 134217728
2022/02/04 12:52:16 DEBUG : /: Releasedir: fh=0x1
2022/02/04 12:52:16 DEBUG : /: >Releasedir: errc=0
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Opendir:
2022/02/04 12:52:16 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:52:16 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/04 12:52:16 DEBUG : /: >Opendir: errc=0, fh=0x1
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Opendir:
2022/02/04 12:52:16 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:52:16 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/04 12:52:16 DEBUG : /: >Opendir: errc=0, fh=0x2
2022/02/04 12:52:16 DEBUG : /: Releasedir: fh=0x1
2022/02/04 12:52:16 DEBUG : /: >Releasedir: errc=0
2022/02/04 12:52:16 DEBUG : /: Releasedir: fh=0x2
2022/02/04 12:52:16 DEBUG : /: >Releasedir: errc=0
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Opendir:
2022/02/04 12:52:16 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:52:16 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/04 12:52:16 DEBUG : /: >Opendir: errc=0, fh=0x1
2022/02/04 12:52:16 DEBUG : /: Releasedir: fh=0x1
2022/02/04 12:52:16 DEBUG : /: >Releasedir: errc=0
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Opendir:
2022/02/04 12:52:16 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:52:16 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/04 12:52:16 DEBUG : /: >Opendir: errc=0, fh=0x1
2022/02/04 12:52:16 DEBUG : /: Releasedir: fh=0x1
2022/02/04 12:52:16 DEBUG : /: >Releasedir: errc=0
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Opendir:
2022/02/04 12:52:16 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:52:16 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/04 12:52:16 DEBUG : /: >Opendir: errc=0, fh=0x1
2022/02/04 12:52:16 DEBUG : /: Releasedir: fh=0x1
2022/02/04 12:52:16 DEBUG : /: >Releasedir: errc=0
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Opendir:
2022/02/04 12:52:16 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:52:16 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/04 12:52:16 DEBUG : /: >Opendir: errc=0, fh=0x1
2022/02/04 12:52:16 DEBUG : /: Releasedir: fh=0x1
2022/02/04 12:52:16 DEBUG : /: >Releasedir: errc=0
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Opendir:
2022/02/04 12:52:16 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:52:16 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/04 12:52:16 DEBUG : /: >Opendir: errc=0, fh=0x1
2022/02/04 12:52:16 DEBUG : /: Releasedir: fh=0x1
2022/02/04 12:52:16 DEBUG : /: >Releasedir: errc=0
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Getattr: fh=0xFFFFFFFFFFFFFFFF
2022/02/04 12:52:16 DEBUG : /: >Getattr: errc=0
2022/02/04 12:52:16 DEBUG : /: Opendir:
2022/02/04 12:52:16 DEBUG : /: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2022/02/04 12:52:16 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2022/02/04 12:52:16 DEBUG : /: >Opendir: errc=0, fh=0x1
2022/02/04 12:52:16 DEBUG : /: Releasedir: fh=0x1
2022/02/04 12:52:16 DEBUG : /: >Releasedir: errc=0
2022/02/04 12:52:17 DEBUG : P1000853.JPG: ChunkedReader.Read at 0 length 4096 chunkOffset 0 chunkSize 134217728
13

That is a snippet but shows it's actually reading the file not just grabbing the attributes.

Is that the gci command or a dir command?

I think @asdffdsa shared as well as you have explorer doing some things which could be confusing things.

That's all explorer stuff acting on it I'd imagine.

14

Oooooo that's a good point. I should disable autorun in Windows 11. You're probably right about Windows Explorer doing some other junk as well, like maybe trying to generate preview images or something ..... I'll have to research if there's a way to disable Windows Explorer screwing around with the data.

Is that the gci command or a dir command?

It's the Get-ChildItem command. I did NOT wrap it in the Measure-Command this time, so it actually returned the results ... maybe that's why there's more information in this last run.

15

I'd say it's not powershell either:

PS /home/felix> measure-command { gci /home/felix/test | % { Write-Host $PSItem.Length } }
107
107
107

Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 0
Milliseconds      : 144
Ticks             : 1448006
TotalDays         : 1.67593287037037E-06
TotalHours        : 4.02223888888889E-05
TotalMinutes      : 0.00241334333333333
TotalSeconds      : 0.1448006
TotalMilliseconds : 144.8006


PS /home/felix>

and I get the following debug log:

felix@gemini:~$ rclone mount DB:test /home/felix/test -vvv
2022/02/04 15:09:09 DEBUG : Setting --config "/opt/rclone/rclone.conf" from environment variable RCLONE_CONFIG="/opt/rclone/rclone.conf"
2022/02/04 15:09:09 DEBUG : rclone: Version "v1.57.0" starting with parameters ["rclone" "mount" "DB:test" "/home/felix/test" "-vvv"]
2022/02/04 15:09:09 DEBUG : Creating backend with remote "DB:test"
2022/02/04 15:09:09 DEBUG : Using config file from "/opt/rclone/rclone.conf"
2022/02/04 15:09:10 DEBUG : Dropbox root 'test': Mounting on "/home/felix/test"
2022/02/04 15:09:10 DEBUG : : Root:
2022/02/04 15:09:10 DEBUG : : >Root: node=/, err=<nil>
2022/02/04 15:09:17 DEBUG : : Statfs:
2022/02/04 15:09:17 DEBUG : : >Statfs: stat={Blocks:53207891968 Bfree:1413235715 Bavail:1413235715 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>
2022/02/04 15:09:17 DEBUG : : Statfs:
2022/02/04 15:09:17 DEBUG : : >Statfs: stat={Blocks:53207891968 Bfree:1413235715 Bavail:1413235715 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>
2022/02/04 15:09:24 DEBUG : : Statfs:
2022/02/04 15:09:24 DEBUG : : >Statfs: stat={Blocks:53207891968 Bfree:1413235715 Bavail:1413235715 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>
2022/02/04 15:09:39 DEBUG : : Statfs:
2022/02/04 15:09:39 DEBUG : : >Statfs: stat={Blocks:53207891968 Bfree:1413235715 Bavail:1413235715 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>
2022/02/04 15:09:54 DEBUG : : Statfs:
2022/02/04 15:09:54 DEBUG : : >Statfs: stat={Blocks:53207891968 Bfree:1413235715 Bavail:1413235715 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>
2022/02/04 15:09:59 DEBUG : /: Attr:
2022/02/04 15:09:59 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2022/02/04 15:09:59 DEBUG : /: ReadDirAll:
2022/02/04 15:09:59 DEBUG : /: >ReadDirAll: item=5, err=<nil>
2022/02/04 15:09:59 DEBUG : /: ReadDirAll:
2022/02/04 15:09:59 DEBUG : /: >ReadDirAll: item=5, err=<nil>
2022/02/04 15:09:59 DEBUG : /: Lookup: name="one"
2022/02/04 15:09:59 DEBUG : /: >Lookup: node=one, err=<nil>
2022/02/04 15:09:59 DEBUG : one: Attr:
2022/02/04 15:09:59 DEBUG : one: >Attr: a=valid=1s ino=0 size=107 mode=-rw-rw-r--, err=<nil>
2022/02/04 15:09:59 DEBUG : /: Lookup: name="three"
2022/02/04 15:09:59 DEBUG : /: >Lookup: node=three, err=<nil>
2022/02/04 15:09:59 DEBUG : three: Attr:
2022/02/04 15:09:59 DEBUG : three: >Attr: a=valid=1s ino=0 size=107 mode=-rw-rw-r--, err=<nil>
2022/02/04 15:09:59 DEBUG : /: Lookup: name="two"
2022/02/04 15:09:59 DEBUG : /: >Lookup: node=two, err=<nil>
2022/02/04 15:09:59 DEBUG : two: Attr:
2022/02/04 15:09:59 DEBUG : two: >Attr: a=valid=1s ino=0 size=107 mode=-rw-rw-r--, err=<nil>
2022/02/04 15:10:09 DEBUG : : Statfs:
2022/02/04 15:10:09 DEBUG : : >Statfs: stat={Blocks:53207891968 Bfree:1413235715 Bavail:1413235715 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>
2022/02/04 15:10:10 DEBUG : Dropbox root 'test': Checking for changes on remote
2022/02/04 15:10:24 DEBUG : : Statfs:
2022/02/04 15:10:24 DEBUG : : >Statfs: stat={Blocks:53207891968 Bfree:1413235715 Bavail:1413235715 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>
2022/02/04 15:10:39 DEBUG : : Statfs:
2022/02/04 15:10:39 DEBUG : : >Statfs: stat={Blocks:53207891968 Bfree:1413235715 Bavail:1413235715 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>

So seems good to me.

16

i would
--- kill the mount
--- add --rc --network-mode to the mount command
--- start the mount
--- run rclone rc vfs/refresh to pre-cache the vfs dir cache.
--- test using good ole limited dir x:, not using windows explorer.

17

--- run rclone rc vfs/refresh to pre-cache the vfs dir cache.

Ideally I would prefer not to use the VFS cache at all. I'd rather work with non-cached data.

At some point, I am going to wipe my system and put the production release version of Windows 11 on, instead of the Developer Preview. Maybe something on the Dev Preview is just screwing with my system. However, before I do that, let me try installing rclone and winfsp using the Windows Sandbox VM. Sandbox creates a fresh environment every time you launch it.

I'd say it's not powershell either:

Nice. That is more like what I expect to see.

not using windows explorer.

I am not using Windows Explorer at all, other than the fact that it's the Windows UI Shell.

18

there are two caches,
--- vfs dir cache - always active
--- vfs file cache - optional

take a quick read of my post

1 Like
19

I just spun up a fresh Windows Server 2022 VM on AWS, and experienced the exact same behavior there. Ugh, I've wasted enough time on this for now. Thanks for the attempts to help.

20

and none of my suggestions made a practical difference?