A long wait occurred when non-existent files were accessed from a file system mounted through "rclone mount"

What is the problem you are having with rclone?

I use "rclone mount" to mount Huawei cloud OBS storage, the storage capacity is about 200 TB, contains more than 20 million objects, when I run the "ls -l" command to display a file, if the file does not exist, the command execution will be stuck for 7 seconds, and then an error message will be displayed. (This process is actually performed in the program of the website). This results in a poor experience for website users. So I would like to ask what can be done to solve this problem?

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

rclone v1.63.0

  • os/version: centos 7.9.2009 (64 bit)
  • os/kernel: 3.10.0-1160.88.1.el7.x86_64 (x86_64)
  • os/type: linux
  • os/arch: amd64
  • go/version: go1.20.5
  • go/linking: static
  • go/tags: none

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

Huaweicloud OBS

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

rclone mount obs://standard-data-processed/ /processed/ --read-only --allow-other
ls -l /processed/wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/MS23021572/MS23021572P3.recaled.bam
### the url is not exist

The rclone config contents with secrets removed.

[obs]
type = s3
provider = HuaweiOBS
env_auth = false
access_key_id = XXXXXXXXXXXXXXXXXX
secret_access_key = XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
region = ap-southeast-1
endpoint = obs.cn-east-3.myhuaweicloud.com

A log from the command with the -vv flag

### Run the command for the first time,after 16s,the error message displayed
2023/07/13 09:04:01 DEBUG : /: Lookup: name="wes"
2023/07/13 09:04:01 DEBUG : /: >Lookup: node=wes/, err=<nil>
2023/07/13 09:04:01 DEBUG : wes/: Attr: 
2023/07/13 09:04:01 DEBUG : wes/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/07/13 09:04:01 DEBUG : wes/: Lookup: name="hg38"
2023/07/13 09:04:01 DEBUG : wes/: >Lookup: node=wes/hg38/, err=<nil>
2023/07/13 09:04:01 DEBUG : wes/hg38/: Attr: 
2023/07/13 09:04:01 DEBUG : wes/hg38/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/07/13 09:04:01 DEBUG : wes/hg38/: Lookup: name="iWES_V2"
2023/07/13 09:04:02 DEBUG : wes/hg38/: >Lookup: node=wes/hg38/iWES_V2/, err=<nil>
2023/07/13 09:04:02 DEBUG : wes/hg38/iWES_V2/: Attr: 
2023/07/13 09:04:02 DEBUG : wes/hg38/iWES_V2/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/07/13 09:04:02 DEBUG : wes/hg38/iWES_V2/: Lookup: name="Result"
2023/07/13 09:04:02 DEBUG : wes/hg38/iWES_V2/: >Lookup: node=wes/hg38/iWES_V2/Result/, err=<nil>
2023/07/13 09:04:02 DEBUG : wes/hg38/iWES_V2/Result/: Attr: 
2023/07/13 09:04:02 DEBUG : wes/hg38/iWES_V2/Result/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/07/13 09:04:02 DEBUG : wes/hg38/iWES_V2/Result/: Lookup: name="MS23021572_20230622130113"
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/: >Lookup: node=wes/hg38/iWES_V2/Result/MS23021572_20230622130113/, err=<nil>
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/: Attr: 
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/: Lookup: name="08_Mito"
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/: >Lookup: node=wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/, err=<nil>
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/: Attr: 
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/: Lookup: name="Backup"
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/: >Lookup: node=wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/, err=<nil>
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/: Attr: 
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/: Lookup: name="BAM"
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/: >Lookup: node=wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/, err=<nil>
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/: Attr: 
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/: Lookup: name="MS23021572"
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/: >Lookup: node=wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/MS23021572/, err=<nil>
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/MS23021572/: Attr: 
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/MS23021572/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/MS23021572/: Lookup: name="MS23021572P3.recaled.bam"
2023/07/13 09:04:18 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/MS23021572/: >Lookup: node=<nil>, err=no such file or directory

#### Reexecute the command,The error message is displayed immediately, without waiting
2023/07/13 09:08:16 DEBUG : /: Lookup: name="wes"
2023/07/13 09:08:16 DEBUG : : Re-reading directory (7m11.586204524s old)
2023/07/13 09:08:16 DEBUG : /: >Lookup: node=wes/, err=<nil>
2023/07/13 09:08:16 DEBUG : wes/: Attr: 
2023/07/13 09:08:16 DEBUG : wes/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/07/13 09:08:16 DEBUG : wes/: Lookup: name="hg38"
2023/07/13 09:08:16 DEBUG : wes/: >Lookup: node=wes/hg38/, err=<nil>
2023/07/13 09:08:16 DEBUG : wes/hg38/: Attr: 
2023/07/13 09:08:16 DEBUG : wes/hg38/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/07/13 09:08:16 DEBUG : wes/hg38/: Lookup: name="iWES_V2"
2023/07/13 09:08:16 DEBUG : wes/hg38/: >Lookup: node=wes/hg38/iWES_V2/, err=<nil>
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/: Attr: 
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/: Lookup: name="Result"
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/: >Lookup: node=wes/hg38/iWES_V2/Result/, err=<nil>
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/: Attr: 
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/: Lookup: name="MS23021572_20230622130113"
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/: >Lookup: node=wes/hg38/iWES_V2/Result/MS23021572_20230622130113/, err=<nil>
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/: Attr: 
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/: Lookup: name="08_Mito"
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/: >Lookup: node=wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/, err=<nil>
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/: Attr: 
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/: Lookup: name="Backup"
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/: >Lookup: node=wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/, err=<nil>
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/: Attr: 
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/: Lookup: name="BAM"
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/: >Lookup: node=wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/, err=<nil>
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/: Attr: 
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/: Lookup: name="MS23021572"
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/: >Lookup: node=wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/MS23021572/, err=<nil>
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/MS23021572/: Attr: 
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/MS23021572/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/MS23021572/: Lookup: name="MS23021572P3.recaled.bam"
2023/07/13 09:08:16 DEBUG : wes/hg38/iWES_V2/Result/MS23021572_20230622130113/08_Mito/Backup/BAM/MS23021572/: >Lookup: node=<nil>, err=no such file or directory

for mount rclone caches files and directories structure in memory. First time ls run delay is caused by time it takes your S3 storage to respond. But subsequent runs are from cache hence are very fast.

You can pre-warm the cache with vfs/refresh

You can have a look here for example systemd service file.

Please note that cache takes about 1KiB of RAM per object so make sure you have enough RAM.

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