Rclone serve webdav + OneDrive: Expecting fs.Object or fs.Directory, got <nil>

Help and Support
1

What is the problem you are having with rclone?

I have issues with rclone serve webdav.
I get errors like Expecting fs.Object or fs.Directory, got <nil>
A few files synchronize correctly. But just 20 MiB of the 2GiB.

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

rclone v1.62.2
- os/version: alpine 3.17.2 (64 bit)
- os/kernel: 3.10.108 (x86_64)
- os/type: linux
- os/arch: amd64
- go/version: go1.20.2
- go/linking: static
- go/tags: none

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

Multiple OneDrive Personal. Some have 1TiB storage (8 accounts), and two with free 5 GiB (1 accounts).
Also, I have the same issue with another rclone.conf with just 2 OneDrive Personal free 5GiB accounts.

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

I am running rclone inside a docker.
The docker is from Docker
I am using docker pull rclone/rclone:latest, which is digest.

Inside the docker the command I am running is:

serve webdav hotmail_union: -vv --log-file /temp/rclone_serve_webdav.log

I have my docker configured with the following Environmental Variables:

Variable Value
PATH /usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
XDG_CONFIG_HOME /config
RCLONE_USER xxx
RCLONE_PASS xxx
RCLONE_ADDR :8080
RCLONE_VFS_CACHE_MODE full
RCLONE_UNION_ACTION_POLICY mfs
RCLONE_UNION_CREATE_POLICY mfs
RCLONE_CACHE_DIR /temp

By the way, I am using mfs, to solve the issue mentioned at Union: OneDrive Personal: quotaLimitReached: Why? [continuation] - #5 by juanbretti

The rclone config contents with secrets removed.

[hotmail_06]
type = onedrive
client_id = j...
client_secret = B...
token = {"access_token":"..."}
drive_id = 5...
drive_type = personal

[hotmail_09]
type = onedrive
client_id = m...
client_secret = A...
token = {"access_token":"..."}
drive_id = 2...
drive_type = personal

[hotmail_union]
type = union
upstreams = hotmail_06:union_test hotmail_09:union_test

A log from the command with the -vv flag

2

I think this is the same bug we were talking about in this thread

Just expressed in a different way.

Somehow the union has returned a nil object which it should never do. This is confusing the rest of rclone.

3

@ncw , thank you for your response.

I tried using a remote directly to OneDrive Personal, i.e. hotmail_06, and still the same issue.
Take a look:

2023/04/08 12:37:11 DEBUG : OneDrive root '': Checking for changes on remote
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Config/index_ver.json.1 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Guard/cloud/0_file.db.4 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Config/@Share/@AppConfig/complete_list.db.4 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Pool/0/0/2.bucket.2 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Pool/0/0/1.bucket.2 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Pool/bucketID.counter.4 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Pool/file_pool/file_pool_map.db.4 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/SynologyHyperBackup.bkpi not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Config/@Share/temp/2.db.3 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Pool/0/0/3.bucket.2 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/synobkpinfo.db not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Config/@Share/@AppConfig/3.db.4 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Config/file_chunk2.index/0.idx.3 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Pool/0/0/0.bucket.2 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Pool/0/0/3.index.2 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Control/@writer/v1.4.-1.0.0.none.none.cinfo not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Config/@Share/temp/1.db.2 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Config/@Share/@AppConfig/2.db.3 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Config/target_ver.json.1 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Pool/0/0/1.index.2 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Pool/0/0/2.index.2 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Pool/file_pool/1.file.2 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/_Syno_TaskConfig not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Config/target_info.db.1 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Pool/file_pool/file_id.counter.2 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Config/version_info.db.4 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/storage_statistics.db.4 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Config/file_chunk1.index/0.idx.2 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Config/file_chunk4.index/0.idx.2 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Control/@writer/v1.cformat not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Guard/cloud/0_bucket.db.2 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Config/target_recover.info.1 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Config/file_chunk3.index/0.idx.4 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Config/@Share/temp/3.db.4 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Pool/0/0/0.index.2 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Config/@Share/temp/complete_list.db.4 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Config/@Share/@AppConfig/1.db.2 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Pool/chunk_index/0.idx.2 not removed, freed 0 bytes
2023/04/08 12:37:11 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item union_test/rclone_06.hbk/Config/virtual_file.index/0.idx.4 not removed, freed 0 bytes
2023/04/08 12:37:11 INFO  : vfs cache: cleaned: objects 39 (was 39) in use 0, to upload 0, uploading 0, total size 22.090Mi (was 22.090Mi)
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="root", type=0
2023/04/08 12:37:12 DEBUG : : invalidating directory cache
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test", type=0
2023/04/08 12:37:12 DEBUG : union_test: invalidating directory cache
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk", type=0
2023/04/08 12:37:12 DEBUG : union_test/rclone_06.hbk: invalidating directory cache
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Pool", type=0
2023/04/08 12:37:12 DEBUG : union_test/rclone_06.hbk/Pool: invalidating directory cache
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Config", type=0
2023/04/08 12:37:12 DEBUG : union_test/rclone_06.hbk/Config: invalidating directory cache
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/storage_statistics.db.4", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Guard", type=0
2023/04/08 12:37:12 DEBUG : union_test/rclone_06.hbk/Guard: invalidating directory cache
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Control", type=0
2023/04/08 12:37:12 DEBUG : union_test/rclone_06.hbk/Control: invalidating directory cache
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/_Syno_TaskConfig", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Pool/bucketID.counter.4", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Pool/file_pool", type=0
2023/04/08 12:37:12 DEBUG : union_test/rclone_06.hbk/Pool/file_pool: invalidating directory cache
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Control/lock", type=0
2023/04/08 12:37:12 DEBUG : union_test/rclone_06.hbk/Control/lock: invalidating directory cache
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Config/virtual_file.index", type=0
2023/04/08 12:37:12 DEBUG : union_test/rclone_06.hbk/Config/virtual_file.index: invalidating directory cache
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Config/version_info.db.4", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Config/@Share", type=0
2023/04/08 12:37:12 DEBUG : union_test/rclone_06.hbk/Config/@Share: invalidating directory cache
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Config/file_chunk3.index", type=0
2023/04/08 12:37:12 DEBUG : union_test/rclone_06.hbk/Config/file_chunk3.index: invalidating directory cache
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Guard/cloud", type=0
2023/04/08 12:37:12 DEBUG : union_test/rclone_06.hbk/Guard/cloud: invalidating directory cache
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Control/@writer", type=0
2023/04/08 12:37:12 DEBUG : union_test/rclone_06.hbk/Control/@writer: invalidating directory cache
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Pool/file_pool/file_pool_map.db.4", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Config/virtual_file.index/0.idx.4", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Config/@Share/@AppConfig", type=0
2023/04/08 12:37:12 DEBUG : union_test/rclone_06.hbk/Config/@Share/@AppConfig: invalidating directory cache
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Config/@Share/temp", type=0
2023/04/08 12:37:12 DEBUG : union_test/rclone_06.hbk/Config/@Share/temp: invalidating directory cache
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Config/file_chunk3.index/0.idx.4", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Guard/cloud/0_file.db.4", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Control/@writer/v1.4.-1.0.0.none.none.cinfo", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Config/@Share/@AppConfig/3.db.4", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Config/@Share/@AppConfig/complete_list.db.4", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Config/@Share/temp/complete_list.db.4", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="union_test/rclone_06.hbk/Config/@Share/temp/3.db.4", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="storage_statistics.db.3", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="bucketID.counter.3", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="version_info.db.3", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="file_pool_map.db.3", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="0.idx.3", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="0.idx.2", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="0_file.db.3", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="v1.3.-1.0.0.none.none.cinfo", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="v1.3.4.1.0.backup.chunking.cinfo", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="v1.3.4.2.3.backup.chunking.cinfo", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="v1.3.4.3.3.backup.only_upload.cinfo", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="lock_keep_alive.@writer_version_0.18199389-a1ce-4028-9618-9121d7c9153e", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="complete_list.db.3", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:12 DEBUG : : changeNotify: relativePath="complete_list.db.3", type=1
2023/04/08 12:37:12 DEBUG : : >changeNotify: 
2023/04/08 12:37:39 INFO  : /: 192.168.x.x:34527: Unauthorized request from 
2023/04/08 12:37:39 DEBUG : /: OpenFile: flags=O_RDONLY, perm=----------
2023/04/08 12:37:39 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2023/04/08 12:37:39 DEBUG : /: OpenFile: flags=O_RDONLY, perm=----------
2023/04/08 12:37:39 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2023/04/08 12:37:39 INFO  : /: PROPFIND from 192.168.x.x:34528
2023/04/08 12:37:40 DEBUG : Getting started with OneDrive.pdf: Reset virtual modtime
2023/04/08 12:37:40 DEBUG : union_test/rclone_06.hbk: Removed virtual directory entry vAddFile: "storage_statistics.db.4"
2023/04/08 12:37:40 DEBUG : union_test/rclone_06.hbk: Removed virtual directory entry vDel: "storage_statistics.db.3"
2023/04/08 12:37:40 DEBUG : union_test/rclone_06.hbk: Removed virtual directory entry vAddFile: "_Syno_TaskConfig"
2023/04/08 12:37:40 DEBUG : union_test/rclone_06.hbk/SynologyHyperBackup.bkpi: Reset virtual modtime
2023/04/08 12:37:40 DEBUG : union_test/rclone_06.hbk/_Syno_TaskConfig: Reset virtual modtime
2023/04/08 12:37:40 DEBUG : union_test/rclone_06.hbk/storage_statistics.db.4: Reset virtual modtime
2023/04/08 12:37:40 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db: Reset virtual modtime
2023/04/08 12:37:40 DEBUG : /union_test/rclone_06.hbk/synobkpinfo.db: OpenFile: flags=O_RDONLY, perm=----------
2023/04/08 12:37:40 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db: Open: flags=O_RDONLY
2023/04/08 12:37:40 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db: newRWFileHandle: 
2023/04/08 12:37:40 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db: >newRWFileHandle: err=<nil>
2023/04/08 12:37:40 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db: >Open: fd=union_test/rclone_06.hbk/synobkpinfo.db (rw), err=<nil>
2023/04/08 12:37:40 DEBUG : /union_test/rclone_06.hbk/synobkpinfo.db: >OpenFile: fd=union_test/rclone_06.hbk/synobkpinfo.db (rw), err=<nil>
2023/04/08 12:37:40 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db(0xc000c29340): close: 
2023/04/08 12:37:40 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db(0xc000c29340): >close: err=<nil>
2023/04/08 12:37:40 DEBUG : /union_test/rclone_06.hbk/synobkpinfo.db: OpenFile: flags=O_RDONLY, perm=----------
2023/04/08 12:37:40 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db: Open: flags=O_RDONLY
2023/04/08 12:37:40 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db: newRWFileHandle: 
2023/04/08 12:37:40 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db: >newRWFileHandle: err=<nil>
2023/04/08 12:37:40 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db: >Open: fd=union_test/rclone_06.hbk/synobkpinfo.db (rw), err=<nil>
2023/04/08 12:37:40 DEBUG : /union_test/rclone_06.hbk/synobkpinfo.db: >OpenFile: fd=union_test/rclone_06.hbk/synobkpinfo.db (rw), err=<nil>
2023/04/08 12:37:40 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db(0xc000c29380): close: 
2023/04/08 12:37:40 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db(0xc000c29380): >close: err=<nil>
2023/04/08 12:37:40 INFO  : /union_test/rclone_06.hbk/synobkpinfo.db: PROPFIND from 192.168.x.x:34529
2023/04/08 12:38:13 INFO  : /: 192.168.x.x:34547: Unauthorized request from 
2023/04/08 12:38:13 DEBUG : /: OpenFile: flags=O_RDONLY, perm=----------
2023/04/08 12:38:13 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2023/04/08 12:38:13 DEBUG : /: OpenFile: flags=O_RDONLY, perm=----------
2023/04/08 12:38:13 DEBUG : /: >OpenFile: fd=/ (r), err=<nil>
2023/04/08 12:38:13 INFO  : /: PROPFIND from 192.168.x.x:34548
2023/04/08 12:38:13 DEBUG : /union_test/rclone_06.hbk/synobkpinfo.db: OpenFile: flags=O_RDONLY, perm=----------
2023/04/08 12:38:13 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db: Open: flags=O_RDONLY
2023/04/08 12:38:13 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db: newRWFileHandle: 
2023/04/08 12:38:13 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db: >newRWFileHandle: err=<nil>
2023/04/08 12:38:13 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db: >Open: fd=union_test/rclone_06.hbk/synobkpinfo.db (rw), err=<nil>
2023/04/08 12:38:13 DEBUG : /union_test/rclone_06.hbk/synobkpinfo.db: >OpenFile: fd=union_test/rclone_06.hbk/synobkpinfo.db (rw), err=<nil>
2023/04/08 12:38:13 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db(0xc000f5a7c0): close: 
2023/04/08 12:38:13 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db(0xc000f5a7c0): >close: err=<nil>
2023/04/08 12:38:13 DEBUG : /union_test/rclone_06.hbk/synobkpinfo.db: OpenFile: flags=O_RDONLY, perm=----------
2023/04/08 12:38:13 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db: Open: flags=O_RDONLY
2023/04/08 12:38:13 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db: newRWFileHandle: 
2023/04/08 12:38:13 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db: >newRWFileHandle: err=<nil>
2023/04/08 12:38:13 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db: >Open: fd=union_test/rclone_06.hbk/synobkpinfo.db (rw), err=<nil>
2023/04/08 12:38:13 DEBUG : /union_test/rclone_06.hbk/synobkpinfo.db: >OpenFile: fd=union_test/rclone_06.hbk/synobkpinfo.db (rw), err=<nil>
2023/04/08 12:38:13 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db(0xc000f5a800): close: 
2023/04/08 12:38:13 DEBUG : union_test/rclone_06.hbk/synobkpinfo.db(0xc000f5a800): >close: err=<nil>
2023/04/08 12:38:13 INFO  : /union_test/rclone_06.hbk/synobkpinfo.db: PROPFIND from 192.168.x.x:34549

I tried deleting the vfs and vfsMeta. And the same response.

What is strange are these requests:

2023/04/08 12:37:39 INFO  : /: 192.168.x.x:34527: Unauthorized request from 
2023/04/08 12:37:39 INFO  : /: PROPFIND from 192.168.x.x:34528
2023/04/08 12:37:40 INFO  : /union_test/rclone_06.hbk/synobkpinfo.db: PROPFIND from 192.168.x.x:34529
2023/04/08 12:38:13 INFO  : /: 192.168.x.x:34547: Unauthorized request from 
2023/04/08 12:38:13 INFO  : /: PROPFIND from 192.168.x.x:34548
2023/04/08 12:38:13 INFO  : /union_test/rclone_06.hbk/synobkpinfo.db: PROPFIND from 192.168.x.x:34549

I am not using that port on my application (Synology HyperBackup).
I am connecting using port 8080 and 8089.

Any other ideas to try? Thanks!
For sure it is a configuration issue.

4

Those ports are the source ports not the destination ports so they likely are your app.

I don't see any errors there - what is the problem? What doesn't work?

5

@ncw , thank you as usual for your reply.

Regarding the ports, I will do a deeper investigation.
Thank you for confirming that rclone does not use any other ports.

And you are right.
The backup/sync works even with those err=<nil>.
I did some consistency check, and worked well.

I will mark your reply as the solution to this thread, because all is solved. Thanks.

1 Like
6

There is still that funny union thing which I need to get to the bottom of...

7

Please, let me know how I can help.
What should I test?

8

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