"./vfs.test -test.v -test.timeout 1h0m0s -remote TestLinkbox: -verbose -test.run '^(TestFileOpen|TestFileOpenRead|TestFileOpenWrite|TestFileRemove|TestFileRemoveAll|TestRWFileHandleFlushRead|TestRWFileHandleMethodsRead|TestRWFileHandleReadAt|TestRWFileHandleReleaseRead|TestRWFileHandleSeek|TestReadFileHandleFlush|TestReadFileHandleMethods|TestReadFileHandleReadAt|TestReadFileHandleRelease|TestReadFileHandleSeek)$|^TestFileRename$/^(full,forceCache=false|minimal,forceCache=false|minimal,forceCache=true|off,forceCache=false|writes,forceCache=false|writes,forceCache=true)$|^TestFileSetModTime$/^cache=off,open=false,write=false$'" - Starting (try 4/5)
2026/08/02 02:41:17 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-vutatin1moca"
2026/08/02 02:41:17 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/08/02 02:41:17 DEBUG : Linkbox root 'rclone-test-vutatin1moca': Using cached web token
2026/08/02 02:41:18 DEBUG : Creating backend with remote "/tmp/rclone3665607315"
=== RUN   TestFileSetModTime
=== RUN   TestFileSetModTime/cache=off,open=false,write=false
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:41:18 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:41:18 NOTICE: Linkbox root 'rclone-test-vutatin1moca': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/02 02:41:28 DEBUG : Can set mod time: false
    file_test.go:97: can't set mod time
2026/08/02 02:41:28 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:41:28 DEBUG : dir: Looking for writers
2026/08/02 02:41:28 DEBUG : file1: reading active writers
2026/08/02 02:41:28 DEBUG : Looking for writers
2026/08/02 02:41:28 DEBUG : dir: reading active writers
2026/08/02 02:41:28 DEBUG : >WaitForWriters: 
--- PASS: TestFileSetModTime (13.80s)
    --- SKIP: TestFileSetModTime/cache=off,open=false,write=false (13.80s)
=== RUN   TestFileOpenRead
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:41:32 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:41:32 NOTICE: Linkbox root 'rclone-test-vutatin1moca': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/02 02:41:36 DEBUG : dir/file1: Open: flags=O_RDONLY
2026/08/02 02:41:36 DEBUG : dir/file1: >Open: fd=dir/file1 (r), err=<nil>
2026/08/02 02:41:36 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728
2026/08/02 02:41:36 NOTICE: Time may be set wrong - time from "aht.nuplink3.net" is 1222h3m22.848473866s different from this computer
2026/08/02 02:41:36 DEBUG : dir/file1: ChunkedReader.Read at 0 length 512 chunkOffset 0 chunkSize 134217728
2026/08/02 02:41:36 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:41:36 DEBUG : dir: Looking for writers
2026/08/02 02:41:36 DEBUG : file1: reading active writers
2026/08/02 02:41:36 DEBUG : Looking for writers
2026/08/02 02:41:36 DEBUG : dir: reading active writers
2026/08/02 02:41:36 DEBUG : >WaitForWriters: 
--- PASS: TestFileOpenRead (8.22s)
=== RUN   TestFileOpenWrite
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:41:40 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:41:40 NOTICE: Linkbox root 'rclone-test-vutatin1moca': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/02 02:41:44 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2026/08/02 02:41:44 DEBUG : Linkbox root 'rclone-test-vutatin1moca': File to upload is small (25 bytes), uploading instead of streaming
2026/08/02 02:41:45 DEBUG : dir/file1: Update: removing old file
2026/08/02 02:41:48 DEBUG : dir/file1: size = 25 OK
2026/08/02 02:41:48 NOTICE: Linkbox root 'rclone-test-vutatin1moca': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2026/08/02 02:41:48 DEBUG : dir/file1: Size of src and dst objects identical
2026/08/02 02:41:48 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2026/08/02 02:41:48 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:41:48 DEBUG : dir: Looking for writers
2026/08/02 02:41:48 DEBUG : file1: reading active writers
2026/08/02 02:41:48 DEBUG : Looking for writers
2026/08/02 02:41:48 DEBUG : dir: reading active writers
2026/08/02 02:41:48 DEBUG : >WaitForWriters: 
2026/08/02 02:41:48 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/08/02 02:41:48 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/08/02 02:41:48 DEBUG : pacer: Reducing sleep to 300ms
2026/08/02 02:41:50 DEBUG : pacer: Reducing sleep to 225ms
2026/08/02 02:41:50 DEBUG : pacer: Reducing sleep to 200ms
--- PASS: TestFileOpenWrite (11.72s)
=== RUN   TestFileRemove
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:41:52 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:41:52 NOTICE: Linkbox root 'rclone-test-vutatin1moca': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/02 02:41:56 DEBUG : dir/file1: Remove: 
2026/08/02 02:41:57 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/08/02 02:41:57 DEBUG : dir/file1: >Remove: err=<nil>
2026/08/02 02:41:58 DEBUG : dir/file1: Remove: 
2026/08/02 02:41:58 DEBUG : dir/file1: >Remove: err=Read only file system
2026/08/02 02:41:58 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:41:58 DEBUG : dir: Looking for writers
2026/08/02 02:41:58 DEBUG : Looking for writers
2026/08/02 02:41:58 DEBUG : dir: reading active writers
2026/08/02 02:41:58 DEBUG : >WaitForWriters: 
--- PASS: TestFileRemove (8.32s)
=== RUN   TestFileRemoveAll
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:42:00 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:42:00 NOTICE: Linkbox root 'rclone-test-vutatin1moca': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/02 02:42:05 DEBUG : dir/file1: Remove: 
2026/08/02 02:42:06 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/08/02 02:42:06 DEBUG : dir/file1: >Remove: err=<nil>
2026/08/02 02:42:06 DEBUG : dir/file1: Remove: 
2026/08/02 02:42:06 DEBUG : dir/file1: >Remove: err=Read only file system
2026/08/02 02:42:06 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:42:06 DEBUG : dir: Looking for writers
2026/08/02 02:42:06 DEBUG : Looking for writers
2026/08/02 02:42:06 DEBUG : dir: reading active writers
2026/08/02 02:42:06 DEBUG : >WaitForWriters: 
--- PASS: TestFileRemoveAll (8.73s)
=== RUN   TestFileOpen
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:42:09 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:42:09 NOTICE: Linkbox root 'rclone-test-vutatin1moca': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/02 02:42:13 DEBUG : dir/file1: Open: flags=O_RDONLY
2026/08/02 02:42:13 DEBUG : dir/file1: >Open: fd=dir/file1 (r), err=<nil>
2026/08/02 02:42:13 DEBUG : dir/file1: Open: flags=O_WRONLY
2026/08/02 02:42:13 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err=<nil>
2026/08/02 02:42:13 DEBUG : dir/file1: Open: flags=O_RDWR
2026/08/02 02:42:13 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err=<nil>
2026/08/02 02:42:13 DEBUG : dir/file1: Open: flags=0x3
2026/08/02 02:42:13 DEBUG : dir/file1: Can't figure out how to open with flags: 0x3
2026/08/02 02:42:13 DEBUG : dir/file1: >Open: fd=<nil>, err=permission denied
2026/08/02 02:42:13 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:42:13 DEBUG : dir: Looking for writers
2026/08/02 02:42:13 DEBUG : file1: reading active writers
2026/08/02 02:42:13 DEBUG : Looking for writers
2026/08/02 02:42:13 DEBUG : dir: reading active writers
2026/08/02 02:42:13 DEBUG : >WaitForWriters: 
--- PASS: TestFileOpen (7.94s)
=== RUN   TestFileRename
=== RUN   TestFileRename/off,forceCache=false
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:42:17 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:42:17 NOTICE: Linkbox root 'rclone-test-vutatin1moca': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
    file_test.go:305: skip as can't rename files
2026/08/02 02:42:21 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:42:21 DEBUG : dir: Looking for writers
2026/08/02 02:42:21 DEBUG : file1: reading active writers
2026/08/02 02:42:21 DEBUG : Looking for writers
2026/08/02 02:42:21 DEBUG : dir: reading active writers
2026/08/02 02:42:21 DEBUG : >WaitForWriters: 
=== RUN   TestFileRename/minimal,forceCache=false
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:42:25 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:42:25 NOTICE: Linkbox root 'rclone-test-vutatin1moca': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/02 02:42:25 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: root is "/home/rclone/.cache/rclone"
2026/08/02 02:42:25 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:42:25 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:42:25 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:42:25 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/08/02 02:42:25 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:42:25 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:42:25 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/08/02 02:42:25 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:42:25 INFO  : Linkbox root 'rclone-test-vutatin1moca': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
    file_test.go:305: skip as can't rename files
2026/08/02 02:42:29 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:42:29 DEBUG : dir: Looking for writers
2026/08/02 02:42:29 DEBUG : file1: reading active writers
2026/08/02 02:42:29 DEBUG : Looking for writers
2026/08/02 02:42:29 DEBUG : dir: reading active writers
2026/08/02 02:42:29 DEBUG : >WaitForWriters: 
2026/08/02 02:42:29 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: cleaner exiting
=== RUN   TestFileRename/minimal,forceCache=true
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:42:33 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:42:33 NOTICE: Linkbox root 'rclone-test-vutatin1moca': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/02 02:42:33 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: root is "/home/rclone/.cache/rclone"
2026/08/02 02:42:33 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:42:33 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:42:33 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:42:33 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/08/02 02:42:33 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:42:33 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:42:33 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/08/02 02:42:33 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:42:33 INFO  : Linkbox root 'rclone-test-vutatin1moca': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
    file_test.go:305: skip as can't rename files
2026/08/02 02:42:37 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:42:37 DEBUG : dir: Looking for writers
2026/08/02 02:42:37 DEBUG : file1: reading active writers
2026/08/02 02:42:37 DEBUG : Looking for writers
2026/08/02 02:42:37 DEBUG : dir: reading active writers
2026/08/02 02:42:37 DEBUG : >WaitForWriters: 
2026/08/02 02:42:37 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: cleaner exiting
2026/08/02 02:42:39 DEBUG : pacer: low level retry 1/10 (error invalid character '<' looking for beginning of value)
2026/08/02 02:42:39 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2026/08/02 02:42:39 DEBUG : pacer: low level retry 2/10 (error invalid character '<' looking for beginning of value)
2026/08/02 02:42:39 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2026/08/02 02:42:39 DEBUG : pacer: low level retry 3/10 (error invalid character '<' looking for beginning of value)
2026/08/02 02:42:39 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2026/08/02 02:42:40 DEBUG : pacer: low level retry 4/10 (error invalid character '<' looking for beginning of value)
2026/08/02 02:42:40 DEBUG : pacer: Rate limited, increasing sleep to 2s
2026/08/02 02:42:42 DEBUG : pacer: low level retry 5/10 (error invalid character '<' looking for beginning of value)
2026/08/02 02:42:44 DEBUG : pacer: low level retry 6/10 (error invalid character '<' looking for beginning of value)
2026/08/02 02:42:46 DEBUG : pacer: low level retry 7/10 (error invalid character '<' looking for beginning of value)
2026/08/02 02:42:48 DEBUG : pacer: low level retry 8/10 (error invalid character '<' looking for beginning of value)
2026/08/02 02:42:50 DEBUG : pacer: Reducing sleep to 1.5s
2026/08/02 02:42:53 DEBUG : pacer: Reducing sleep to 1.125s
2026/08/02 02:42:53 DEBUG : pacer: Reducing sleep to 843.75ms
=== RUN   TestFileRename/writes,forceCache=false
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:42:53 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:42:53 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: root is "/home/rclone/.cache/rclone"
2026/08/02 02:42:53 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:42:53 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:42:53 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:42:53 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/08/02 02:42:53 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:42:53 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:42:53 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/08/02 02:42:53 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:42:53 INFO  : Linkbox root 'rclone-test-vutatin1moca': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2026/08/02 02:42:55 DEBUG : pacer: Reducing sleep to 632.8125ms
2026/08/02 02:42:56 DEBUG : pacer: Reducing sleep to 474.609375ms
2026/08/02 02:42:57 DEBUG : pacer: Reducing sleep to 355.957031ms
2026/08/02 02:42:57 DEBUG : pacer: Reducing sleep to 266.967773ms
2026/08/02 02:42:59 DEBUG : pacer: Reducing sleep to 200.225829ms
2026/08/02 02:42:59 DEBUG : pacer: Reducing sleep to 200ms
    file_test.go:305: skip as can't rename files
2026/08/02 02:43:00 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:43:00 DEBUG : dir: Looking for writers
2026/08/02 02:43:00 DEBUG : file1: reading active writers
2026/08/02 02:43:00 DEBUG : Looking for writers
2026/08/02 02:43:00 DEBUG : dir: reading active writers
2026/08/02 02:43:00 DEBUG : >WaitForWriters: 
2026/08/02 02:43:00 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: cleaner exiting
=== RUN   TestFileRename/writes,forceCache=true
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:43:04 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:43:04 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: root is "/home/rclone/.cache/rclone"
2026/08/02 02:43:04 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:43:04 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:43:04 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:43:04 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/08/02 02:43:04 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:43:04 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:43:04 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/08/02 02:43:04 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:43:04 INFO  : Linkbox root 'rclone-test-vutatin1moca': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
    file_test.go:305: skip as can't rename files
2026/08/02 02:43:08 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:43:08 DEBUG : dir: Looking for writers
2026/08/02 02:43:08 DEBUG : file1: reading active writers
2026/08/02 02:43:08 DEBUG : Looking for writers
2026/08/02 02:43:08 DEBUG : dir: reading active writers
2026/08/02 02:43:08 DEBUG : >WaitForWriters: 
2026/08/02 02:43:08 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: cleaner exiting
=== RUN   TestFileRename/full,forceCache=false
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:43:12 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:43:12 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: root is "/home/rclone/.cache/rclone"
2026/08/02 02:43:12 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:43:12 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:43:12 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:43:12 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/08/02 02:43:12 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:43:12 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:43:12 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/08/02 02:43:12 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:43:12 INFO  : Linkbox root 'rclone-test-vutatin1moca': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
    file_test.go:305: skip as can't rename files
2026/08/02 02:43:16 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:43:16 DEBUG : dir: Looking for writers
2026/08/02 02:43:16 DEBUG : file1: reading active writers
2026/08/02 02:43:16 DEBUG : Looking for writers
2026/08/02 02:43:16 DEBUG : dir: reading active writers
2026/08/02 02:43:16 DEBUG : >WaitForWriters: 
2026/08/02 02:43:16 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: cleaner exiting
    run.go:186: removing dir "dir" failed - try 1/3: sleeping 1s: directory not empty
--- PASS: TestFileRename (64.02s)
    --- SKIP: TestFileRename/off,forceCache=false (8.04s)
    --- SKIP: TestFileRename/minimal,forceCache=false (7.83s)
    --- SKIP: TestFileRename/minimal,forceCache=true (20.90s)
    --- SKIP: TestFileRename/writes,forceCache=false (10.20s)
    --- SKIP: TestFileRename/writes,forceCache=true (7.98s)
    --- SKIP: TestFileRename/full,forceCache=false (9.06s)
=== RUN   TestReadFileHandleMethods
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:43:21 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:43:21 NOTICE: Linkbox root 'rclone-test-vutatin1moca': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/02 02:43:25 DEBUG : dir/file1: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2026/08/02 02:43:25 DEBUG : dir/file1: Open: flags=O_RDONLY
2026/08/02 02:43:25 DEBUG : dir/file1: >Open: fd=dir/file1 (r), err=<nil>
2026/08/02 02:43:25 DEBUG : dir/file1: >OpenFile: fd=dir/file1 (r), err=<nil>
2026/08/02 02:43:25 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728
2026/08/02 02:43:25 DEBUG : dir/file1: ChunkedReader.Read at 0 length 1 chunkOffset 0 chunkSize 134217728
2026/08/02 02:43:25 DEBUG : dir/file1: ChunkedReader.Read at 1 length 256 chunkOffset 0 chunkSize 134217728
2026/08/02 02:43:25 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:43:25 DEBUG : dir: Looking for writers
2026/08/02 02:43:25 DEBUG : file1: reading active writers
2026/08/02 02:43:25 DEBUG : Looking for writers
2026/08/02 02:43:25 DEBUG : dir: reading active writers
2026/08/02 02:43:25 DEBUG : >WaitForWriters: 
    run.go:186: removing dir "dir" failed - try 1/3: sleeping 1s: directory not empty
--- PASS: TestReadFileHandleMethods (9.25s)
=== RUN   TestReadFileHandleSeek
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:43:30 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:43:30 NOTICE: Linkbox root 'rclone-test-vutatin1moca': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/02 02:43:34 DEBUG : dir/file1: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2026/08/02 02:43:34 DEBUG : dir/file1: Open: flags=O_RDONLY
2026/08/02 02:43:34 DEBUG : dir/file1: >Open: fd=dir/file1 (r), err=<nil>
2026/08/02 02:43:34 DEBUG : dir/file1: >OpenFile: fd=dir/file1 (r), err=<nil>
2026/08/02 02:43:34 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728
2026/08/02 02:43:34 DEBUG : dir/file1: ChunkedReader.Read at 0 length 1 chunkOffset 0 chunkSize 134217728
2026/08/02 02:43:34 DEBUG : dir/file1: waiting for in-sequence read to 5 for 20ms
2026/08/02 02:43:34 DEBUG : dir/file1: aborting in-sequence read wait, off=5
2026/08/02 02:43:34 DEBUG : dir/file1: failed to wait for in-sequence read to 5
2026/08/02 02:43:34 DEBUG : dir/file1: ReadFileHandle.seek from 1 to 5 (fs.RangeSeeker)
2026/08/02 02:43:34 DEBUG : dir/file1: ChunkedReader.RangeSeek from 1 to 5 length -1
2026/08/02 02:43:34 DEBUG : dir/file1: ChunkedReader.Read at -1 length 1 chunkOffset 5 chunkSize 134217728
2026/08/02 02:43:34 DEBUG : dir/file1: ChunkedReader.openRange at 5 length 134217728
2026/08/02 02:43:35 DEBUG : dir/file1: ReadFileHandle.seek from 6 to 3 (fs.RangeSeeker)
2026/08/02 02:43:35 DEBUG : dir/file1: ChunkedReader.RangeSeek from 6 to 3 length -1
2026/08/02 02:43:35 DEBUG : dir/file1: ChunkedReader.Read at -1 length 1 chunkOffset 3 chunkSize 134217728
2026/08/02 02:43:35 DEBUG : dir/file1: ChunkedReader.openRange at 3 length 134217728
2026/08/02 02:43:35 DEBUG : dir/file1: ReadFileHandle.seek from 4 to 13 (fs.RangeSeeker)
2026/08/02 02:43:35 DEBUG : dir/file1: ChunkedReader.RangeSeek from 4 to 13 length -1
2026/08/02 02:43:35 DEBUG : dir/file1: ChunkedReader.Read at -1 length 1 chunkOffset 13 chunkSize 134217728
2026/08/02 02:43:35 DEBUG : dir/file1: ChunkedReader.openRange at 13 length 134217728
2026/08/02 02:43:35 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:43:35 DEBUG : dir: Looking for writers
2026/08/02 02:43:35 DEBUG : file1: reading active writers
2026/08/02 02:43:35 DEBUG : Looking for writers
2026/08/02 02:43:35 DEBUG : dir: reading active writers
2026/08/02 02:43:35 DEBUG : >WaitForWriters: 
--- PASS: TestReadFileHandleSeek (8.65s)
=== RUN   TestReadFileHandleReadAt
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:43:39 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:43:39 NOTICE: Linkbox root 'rclone-test-vutatin1moca': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/02 02:43:43 DEBUG : dir/file1: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2026/08/02 02:43:43 DEBUG : dir/file1: Open: flags=O_RDONLY
2026/08/02 02:43:43 DEBUG : dir/file1: >Open: fd=dir/file1 (r), err=<nil>
2026/08/02 02:43:43 DEBUG : dir/file1: >OpenFile: fd=dir/file1 (r), err=<nil>
2026/08/02 02:43:43 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728
2026/08/02 02:43:43 DEBUG : dir/file1: ChunkedReader.Read at 0 length 1 chunkOffset 0 chunkSize 134217728
2026/08/02 02:43:43 DEBUG : dir/file1: waiting for in-sequence read to 5 for 20ms
2026/08/02 02:43:43 DEBUG : dir/file1: aborting in-sequence read wait, off=5
2026/08/02 02:43:43 DEBUG : dir/file1: failed to wait for in-sequence read to 5
2026/08/02 02:43:43 DEBUG : dir/file1: ReadFileHandle.seek from 1 to 5 (fs.RangeSeeker)
2026/08/02 02:43:43 DEBUG : dir/file1: ChunkedReader.RangeSeek from 1 to 5 length -1
2026/08/02 02:43:43 DEBUG : dir/file1: ChunkedReader.Read at -1 length 1 chunkOffset 5 chunkSize 134217728
2026/08/02 02:43:43 DEBUG : dir/file1: ChunkedReader.openRange at 5 length 134217728
2026/08/02 02:43:43 DEBUG : dir/file1: ReadFileHandle.seek from 6 to 1 (fs.RangeSeeker)
2026/08/02 02:43:43 DEBUG : dir/file1: ChunkedReader.RangeSeek from 6 to 1 length -1
2026/08/02 02:43:43 DEBUG : dir/file1: ChunkedReader.Read at -1 length 1 chunkOffset 1 chunkSize 134217728
2026/08/02 02:43:43 DEBUG : dir/file1: ChunkedReader.openRange at 1 length 134217728
2026/08/02 02:43:44 DEBUG : dir/file1: waiting for in-sequence read to 10 for 20ms
2026/08/02 02:43:44 DEBUG : dir/file1: aborting in-sequence read wait, off=10
2026/08/02 02:43:44 DEBUG : dir/file1: failed to wait for in-sequence read to 10
2026/08/02 02:43:44 DEBUG : dir/file1: ReadFileHandle.seek from 2 to 10 (fs.RangeSeeker)
2026/08/02 02:43:44 DEBUG : dir/file1: ChunkedReader.RangeSeek from 2 to 10 length -1
2026/08/02 02:43:44 DEBUG : dir/file1: ChunkedReader.Read at -1 length 6 chunkOffset 10 chunkSize 134217728
2026/08/02 02:43:44 DEBUG : dir/file1: ChunkedReader.openRange at 10 length 134217728
2026/08/02 02:43:44 DEBUG : dir/file1: ReadFileHandle.seek from 16 to 10 (fs.RangeSeeker)
2026/08/02 02:43:44 DEBUG : dir/file1: ChunkedReader.RangeSeek from 16 to 10 length -1
2026/08/02 02:43:44 DEBUG : dir/file1: ChunkedReader.Read at -1 length 256 chunkOffset 10 chunkSize 134217728
2026/08/02 02:43:44 DEBUG : dir/file1: ChunkedReader.openRange at 10 length 134217728
2026/08/02 02:43:44 DEBUG : dir/file1: waiting for in-sequence read to 100 for 20ms
2026/08/02 02:43:44 DEBUG : dir/file1: aborting in-sequence read wait, off=100
2026/08/02 02:43:44 DEBUG : dir/file1: failed to wait for in-sequence read to 100
2026/08/02 02:43:44 DEBUG : dir/file1: ReadFileHandle.Read attempt to read beyond end of file: 100 > 16
2026/08/02 02:43:44 DEBUG : dir/file1: waiting for in-sequence read to 100 for 20ms
2026/08/02 02:43:44 DEBUG : dir/file1: aborting in-sequence read wait, off=100
2026/08/02 02:43:44 DEBUG : dir/file1: failed to wait for in-sequence read to 100
2026/08/02 02:43:44 ERROR : dir/file1: ReadFileHandle.Read error: Bad file descriptor
2026/08/02 02:43:44 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:43:44 DEBUG : dir: Looking for writers
2026/08/02 02:43:44 DEBUG : file1: reading active writers
2026/08/02 02:43:44 DEBUG : Looking for writers
2026/08/02 02:43:44 DEBUG : dir: reading active writers
2026/08/02 02:43:44 DEBUG : >WaitForWriters: 
--- PASS: TestReadFileHandleReadAt (8.89s)
=== RUN   TestReadFileHandleFlush
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:43:47 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:43:47 NOTICE: Linkbox root 'rclone-test-vutatin1moca': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/02 02:43:51 DEBUG : dir/file1: Trying to read object after upload: try again in 100ms (1/10)
2026/08/02 02:43:51 DEBUG : dir/file1: Trying to read object after upload: try again in 200ms (2/10)
2026/08/02 02:43:52 DEBUG : dir/file1: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2026/08/02 02:43:53 DEBUG : dir/file1: Open: flags=O_RDONLY
2026/08/02 02:43:53 DEBUG : dir/file1: >Open: fd=dir/file1 (r), err=<nil>
2026/08/02 02:43:53 DEBUG : dir/file1: >OpenFile: fd=dir/file1 (r), err=<nil>
2026/08/02 02:43:53 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728
2026/08/02 02:43:53 DEBUG : dir/file1: ChunkedReader.Read at 0 length 256 chunkOffset 0 chunkSize 134217728
2026/08/02 02:43:53 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:43:53 DEBUG : dir: Looking for writers
2026/08/02 02:43:53 DEBUG : file1: reading active writers
2026/08/02 02:43:53 DEBUG : Looking for writers
2026/08/02 02:43:53 DEBUG : dir: reading active writers
2026/08/02 02:43:53 DEBUG : >WaitForWriters: 
--- PASS: TestReadFileHandleFlush (8.86s)
=== RUN   TestReadFileHandleRelease
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:43:56 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:43:56 NOTICE: Linkbox root 'rclone-test-vutatin1moca': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/02 02:44:00 DEBUG : dir/file1: Trying to read object after upload: try again in 100ms (1/10)
2026/08/02 02:44:00 DEBUG : dir/file1: Trying to read object after upload: try again in 200ms (2/10)
2026/08/02 02:44:01 DEBUG : dir/file1: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2026/08/02 02:44:02 DEBUG : dir/file1: Open: flags=O_RDONLY
2026/08/02 02:44:02 DEBUG : dir/file1: >Open: fd=dir/file1 (r), err=<nil>
2026/08/02 02:44:02 DEBUG : dir/file1: >OpenFile: fd=dir/file1 (r), err=<nil>
2026/08/02 02:44:02 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728
2026/08/02 02:44:02 DEBUG : dir/file1: ChunkedReader.Read at 0 length 256 chunkOffset 0 chunkSize 134217728
2026/08/02 02:44:02 DEBUG : dir/file1: ReadFileHandle.Release closing
2026/08/02 02:44:02 DEBUG : dir/file1: ReadFileHandle.Release nothing to do
2026/08/02 02:44:02 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:44:02 DEBUG : dir: Looking for writers
2026/08/02 02:44:02 DEBUG : file1: reading active writers
2026/08/02 02:44:02 DEBUG : Looking for writers
2026/08/02 02:44:02 DEBUG : dir: reading active writers
2026/08/02 02:44:02 DEBUG : >WaitForWriters: 
--- PASS: TestReadFileHandleRelease (9.22s)
=== RUN   TestRWFileHandleMethodsRead
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:44:06 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:44:06 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: root is "/home/rclone/.cache/rclone"
2026/08/02 02:44:06 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:06 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:06 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:06 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/08/02 02:44:06 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:06 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:06 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/08/02 02:44:06 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:06 INFO  : Linkbox root 'rclone-test-vutatin1moca': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2026/08/02 02:44:10 DEBUG : dir/file1: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2026/08/02 02:44:10 DEBUG : dir/file1: Open: flags=O_RDONLY
2026/08/02 02:44:10 DEBUG : dir/file1: newRWFileHandle: 
2026/08/02 02:44:10 DEBUG : dir/file1: >newRWFileHandle: err=<nil>
2026/08/02 02:44:10 DEBUG : dir/file1: >Open: fd=dir/file1 (rw), err=<nil>
2026/08/02 02:44:10 DEBUG : dir/file1: >OpenFile: fd=dir/file1 (rw), err=<nil>
2026/08/02 02:44:10 DEBUG : dir/file1(0x1118f6e32280): _readAt: size=1, off=0
2026/08/02 02:44:10 DEBUG : dir/file1(0x1118f6e32280): openPending: 
2026/08/02 02:44:10 DEBUG : dir/file1: vfs cache: checking remote fingerprint "16" against cached fingerprint ""
2026/08/02 02:44:10 DEBUG : dir/file1: vfs cache: truncate to size=16
2026/08/02 02:44:10 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2026/08/02 02:44:10 DEBUG : dir/file1(0x1118f6e32280): >openPending: err=<nil>
2026/08/02 02:44:10 DEBUG : vfs cache: looking for range={Pos:0 Size:1} in [] - present false
2026/08/02 02:44:10 DEBUG : dir/file1: ChunkedReader.RangeSeek from -1 to 0 length -1
2026/08/02 02:44:10 DEBUG : dir/file1: ChunkedReader.Read at -1 length 32768 chunkOffset 0 chunkSize 134217728
2026/08/02 02:44:10 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728
2026/08/02 02:44:10 DEBUG : dir/file1(0x1118f6e32280): >_readAt: n=1, err=<nil>
2026/08/02 02:44:10 DEBUG : dir/file1(0x1118f6e32280): _readAt: size=256, off=1
2026/08/02 02:44:10 DEBUG : vfs cache: looking for range={Pos:1 Size:15} in [{Pos:0 Size:16}] - present true
2026/08/02 02:44:10 DEBUG : dir/file1(0x1118f6e32280): >_readAt: n=15, err=EOF
2026/08/02 02:44:10 DEBUG : dir/file1(0x1118f6e32280): _readAt: size=16, off=16
2026/08/02 02:44:10 DEBUG : dir/file1(0x1118f6e32280): >_readAt: n=0, err=EOF
2026/08/02 02:44:10 DEBUG : dir/file1(0x1118f6e32280): close: 
2026/08/02 02:44:10 DEBUG : dir/file1(0x1118f6e32280): >close: err=<nil>
2026/08/02 02:44:10 DEBUG : dir/file1(0x1118f6e32280): close: 
2026/08/02 02:44:10 DEBUG : dir/file1(0x1118f6e32280): >close: err=file already closed
2026/08/02 02:44:10 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:44:10 DEBUG : dir: Looking for writers
2026/08/02 02:44:10 DEBUG : file1: reading active writers
2026/08/02 02:44:10 DEBUG : Looking for writers
2026/08/02 02:44:10 DEBUG : dir: reading active writers
2026/08/02 02:44:10 DEBUG : >WaitForWriters: 
2026/08/02 02:44:10 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: cleaner exiting
    run.go:186: removing dir "dir" failed - try 1/3: sleeping 1s: directory not empty
--- PASS: TestRWFileHandleMethodsRead (9.42s)
=== RUN   TestRWFileHandleSeek
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:44:15 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:44:15 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: root is "/home/rclone/.cache/rclone"
2026/08/02 02:44:15 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:15 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:15 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:15 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/08/02 02:44:15 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:15 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:15 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/08/02 02:44:15 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:15 INFO  : Linkbox root 'rclone-test-vutatin1moca': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2026/08/02 02:44:15 ERROR : dir/file1: vfs cache: item close failed: vfs cache item: failed to write metadata: open /home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca/dir/file1: no such file or directory
2026/08/02 02:44:15 ERROR : dir/file1: vfs cache: close after grace period failed: vfs cache item: failed to write metadata: open /home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca/dir/file1: no such file or directory
2026/08/02 02:44:19 DEBUG : dir/file1: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2026/08/02 02:44:19 DEBUG : dir/file1: Open: flags=O_RDONLY
2026/08/02 02:44:19 DEBUG : dir/file1: newRWFileHandle: 
2026/08/02 02:44:19 DEBUG : dir/file1: >newRWFileHandle: err=<nil>
2026/08/02 02:44:19 DEBUG : dir/file1: >Open: fd=dir/file1 (rw), err=<nil>
2026/08/02 02:44:19 DEBUG : dir/file1: >OpenFile: fd=dir/file1 (rw), err=<nil>
2026/08/02 02:44:19 DEBUG : dir/file1(0x1118f680f480): _readAt: size=1, off=0
2026/08/02 02:44:19 DEBUG : dir/file1(0x1118f680f480): openPending: 
2026/08/02 02:44:19 DEBUG : dir/file1: vfs cache: checking remote fingerprint "16" against cached fingerprint ""
2026/08/02 02:44:19 DEBUG : dir/file1: vfs cache: truncate to size=16
2026/08/02 02:44:19 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2026/08/02 02:44:19 DEBUG : dir/file1(0x1118f680f480): >openPending: err=<nil>
2026/08/02 02:44:19 DEBUG : vfs cache: looking for range={Pos:0 Size:1} in [] - present false
2026/08/02 02:44:19 DEBUG : dir/file1: ChunkedReader.RangeSeek from -1 to 0 length -1
2026/08/02 02:44:19 DEBUG : dir/file1: ChunkedReader.Read at -1 length 32768 chunkOffset 0 chunkSize 134217728
2026/08/02 02:44:19 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728
2026/08/02 02:44:19 DEBUG : dir/file1(0x1118f680f480): >_readAt: n=1, err=<nil>
2026/08/02 02:44:19 DEBUG : dir/file1(0x1118f680f480): _readAt: size=1, off=5
2026/08/02 02:44:19 DEBUG : vfs cache: looking for range={Pos:5 Size:1} in [{Pos:0 Size:16}] - present true
2026/08/02 02:44:19 DEBUG : dir/file1(0x1118f680f480): >_readAt: n=1, err=<nil>
2026/08/02 02:44:19 DEBUG : dir/file1(0x1118f680f480): _readAt: size=1, off=3
2026/08/02 02:44:19 DEBUG : vfs cache: looking for range={Pos:3 Size:1} in [{Pos:0 Size:16}] - present true
2026/08/02 02:44:19 DEBUG : dir/file1(0x1118f680f480): >_readAt: n=1, err=<nil>
2026/08/02 02:44:19 DEBUG : dir/file1(0x1118f680f480): _readAt: size=1, off=13
2026/08/02 02:44:19 DEBUG : vfs cache: looking for range={Pos:13 Size:1} in [{Pos:0 Size:16}] - present true
2026/08/02 02:44:19 DEBUG : dir/file1(0x1118f680f480): >_readAt: n=1, err=<nil>
2026/08/02 02:44:19 DEBUG : dir/file1(0x1118f680f480): _readAt: size=16, off=100
2026/08/02 02:44:19 DEBUG : dir/file1(0x1118f680f480): >_readAt: n=0, err=EOF
2026/08/02 02:44:19 DEBUG : dir/file1(0x1118f680f480): close: 
2026/08/02 02:44:19 DEBUG : dir/file1(0x1118f680f480): >close: err=<nil>
2026/08/02 02:44:19 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:44:19 DEBUG : dir: Looking for writers
2026/08/02 02:44:19 DEBUG : file1: reading active writers
2026/08/02 02:44:19 DEBUG : Looking for writers
2026/08/02 02:44:19 DEBUG : dir: reading active writers
2026/08/02 02:44:19 DEBUG : >WaitForWriters: 
2026/08/02 02:44:19 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: cleaner exiting
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
2026/08/02 02:44:24 ERROR : dir/file1: vfs cache: item close failed: vfs cache item: failed to write metadata: open /home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca/dir/file1: no such file or directory
2026/08/02 02:44:24 ERROR : dir/file1: vfs cache: close after grace period failed: vfs cache item: failed to write metadata: open /home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca/dir/file1: no such file or directory
    fstest.go:292: Sleeping for 6s just to make sure
--- PASS: TestRWFileHandleSeek (15.95s)
=== RUN   TestRWFileHandleReadAt
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:44:31 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:44:31 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: root is "/home/rclone/.cache/rclone"
2026/08/02 02:44:31 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:31 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:31 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:31 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/08/02 02:44:31 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:31 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:31 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/08/02 02:44:31 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:31 INFO  : Linkbox root 'rclone-test-vutatin1moca': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2026/08/02 02:44:35 DEBUG : dir/file1: Trying to read object after upload: try again in 100ms (1/10)
2026/08/02 02:44:35 DEBUG : dir/file1: Trying to read object after upload: try again in 200ms (2/10)
2026/08/02 02:44:37 DEBUG : dir/file1: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2026/08/02 02:44:37 DEBUG : dir/file1: Open: flags=O_RDONLY
2026/08/02 02:44:37 DEBUG : dir/file1: newRWFileHandle: 
2026/08/02 02:44:37 DEBUG : dir/file1: >newRWFileHandle: err=<nil>
2026/08/02 02:44:37 DEBUG : dir/file1: >Open: fd=dir/file1 (rw), err=<nil>
2026/08/02 02:44:37 DEBUG : dir/file1: >OpenFile: fd=dir/file1 (rw), err=<nil>
2026/08/02 02:44:37 DEBUG : dir/file1(0x1118f6d94b00): _readAt: size=1, off=0
2026/08/02 02:44:37 DEBUG : dir/file1(0x1118f6d94b00): openPending: 
2026/08/02 02:44:37 DEBUG : dir/file1: vfs cache: checking remote fingerprint "16" against cached fingerprint ""
2026/08/02 02:44:37 DEBUG : dir/file1: vfs cache: truncate to size=16
2026/08/02 02:44:37 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2026/08/02 02:44:37 DEBUG : dir/file1(0x1118f6d94b00): >openPending: err=<nil>
2026/08/02 02:44:37 DEBUG : vfs cache: looking for range={Pos:0 Size:1} in [] - present false
2026/08/02 02:44:37 DEBUG : dir/file1: ChunkedReader.RangeSeek from -1 to 0 length -1
2026/08/02 02:44:37 DEBUG : dir/file1: ChunkedReader.Read at -1 length 32768 chunkOffset 0 chunkSize 134217728
2026/08/02 02:44:37 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728
2026/08/02 02:44:37 DEBUG : dir/file1(0x1118f6d94b00): >_readAt: n=1, err=<nil>
2026/08/02 02:44:37 DEBUG : dir/file1(0x1118f6d94b00): _readAt: size=1, off=5
2026/08/02 02:44:37 DEBUG : vfs cache: looking for range={Pos:5 Size:1} in [{Pos:0 Size:16}] - present true
2026/08/02 02:44:37 DEBUG : dir/file1(0x1118f6d94b00): >_readAt: n=1, err=<nil>
2026/08/02 02:44:37 DEBUG : dir/file1(0x1118f6d94b00): _readAt: size=1, off=1
2026/08/02 02:44:37 DEBUG : vfs cache: looking for range={Pos:1 Size:1} in [{Pos:0 Size:16}] - present true
2026/08/02 02:44:37 DEBUG : dir/file1(0x1118f6d94b00): >_readAt: n=1, err=<nil>
2026/08/02 02:44:37 DEBUG : dir/file1(0x1118f6d94b00): _readAt: size=6, off=10
2026/08/02 02:44:37 DEBUG : vfs cache: looking for range={Pos:10 Size:6} in [{Pos:0 Size:16}] - present true
2026/08/02 02:44:37 DEBUG : dir/file1(0x1118f6d94b00): >_readAt: n=6, err=<nil>
2026/08/02 02:44:37 DEBUG : dir/file1(0x1118f6d94b00): _readAt: size=256, off=10
2026/08/02 02:44:37 DEBUG : vfs cache: looking for range={Pos:10 Size:6} in [{Pos:0 Size:16}] - present true
2026/08/02 02:44:37 DEBUG : dir/file1(0x1118f6d94b00): >_readAt: n=6, err=EOF
2026/08/02 02:44:37 DEBUG : dir/file1(0x1118f6d94b00): _readAt: size=256, off=100
2026/08/02 02:44:37 DEBUG : dir/file1(0x1118f6d94b00): >_readAt: n=0, err=EOF
2026/08/02 02:44:37 DEBUG : dir/file1(0x1118f6d94b00): close: 
2026/08/02 02:44:37 DEBUG : dir/file1(0x1118f6d94b00): >close: err=<nil>
2026/08/02 02:44:37 DEBUG : dir/file1(0x1118f6d94b00): _readAt: size=256, off=100
2026/08/02 02:44:37 DEBUG : dir/file1(0x1118f6d94b00): >_readAt: n=0, err=file already closed
2026/08/02 02:44:37 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:44:37 DEBUG : dir: Looking for writers
2026/08/02 02:44:37 DEBUG : file1: reading active writers
2026/08/02 02:44:37 DEBUG : Looking for writers
2026/08/02 02:44:37 DEBUG : dir: reading active writers
2026/08/02 02:44:37 DEBUG : >WaitForWriters: 
2026/08/02 02:44:37 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: cleaner exiting
    run.go:186: removing dir "dir" failed - try 1/3: sleeping 1s: directory not empty
    run.go:186: removing dir "dir" failed - try 2/3: sleeping 1.5s: directory not empty
2026/08/02 02:44:42 ERROR : dir/file1: vfs cache: item close failed: vfs cache item: failed to write metadata: open /home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca/dir/file1: no such file or directory
2026/08/02 02:44:42 ERROR : dir/file1: vfs cache: close after grace period failed: vfs cache item: failed to write metadata: open /home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca/dir/file1: no such file or directory
    fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:301: Flushing the directory cache
    fstest.go:292: Sleeping for 6s just to make sure
--- PASS: TestRWFileHandleReadAt (20.63s)
=== RUN   TestRWFileHandleFlushRead
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:44:52 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:44:52 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: root is "/home/rclone/.cache/rclone"
2026/08/02 02:44:52 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:52 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:52 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:52 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/08/02 02:44:52 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:52 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:52 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/08/02 02:44:52 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:44:52 INFO  : Linkbox root 'rclone-test-vutatin1moca': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2026/08/02 02:44:55 DEBUG : dir/file1: Trying to read object after upload: try again in 100ms (1/10)
2026/08/02 02:44:55 DEBUG : dir/file1: Trying to read object after upload: try again in 200ms (2/10)
2026/08/02 02:44:56 DEBUG : dir/file1: Trying to read object after upload: try again in 400ms (3/10)
2026/08/02 02:44:56 DEBUG : dir/file1: Trying to read object after upload: try again in 800ms (4/10)
2026/08/02 02:44:58 DEBUG : dir/file1: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2026/08/02 02:44:58 DEBUG : dir/file1: Open: flags=O_RDONLY
2026/08/02 02:44:58 DEBUG : dir/file1: newRWFileHandle: 
2026/08/02 02:44:58 DEBUG : dir/file1: >newRWFileHandle: err=<nil>
2026/08/02 02:44:58 DEBUG : dir/file1: >Open: fd=dir/file1 (rw), err=<nil>
2026/08/02 02:44:58 DEBUG : dir/file1: >OpenFile: fd=dir/file1 (rw), err=<nil>
2026/08/02 02:44:58 DEBUG : dir/file1(0x1118f6e335c0): RWFileHandle.Flush
2026/08/02 02:44:58 DEBUG : dir/file1(0x1118f6e335c0): _readAt: size=256, off=0
2026/08/02 02:44:58 DEBUG : dir/file1(0x1118f6e335c0): openPending: 
2026/08/02 02:44:58 DEBUG : dir/file1: vfs cache: checking remote fingerprint "16" against cached fingerprint ""
2026/08/02 02:44:58 DEBUG : dir/file1: vfs cache: truncate to size=16
2026/08/02 02:44:58 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2026/08/02 02:44:58 DEBUG : dir/file1(0x1118f6e335c0): >openPending: err=<nil>
2026/08/02 02:44:58 DEBUG : vfs cache: looking for range={Pos:0 Size:16} in [] - present false
2026/08/02 02:44:58 DEBUG : dir/file1: ChunkedReader.RangeSeek from -1 to 0 length -1
2026/08/02 02:44:58 DEBUG : dir/file1: ChunkedReader.Read at -1 length 32768 chunkOffset 0 chunkSize 134217728
2026/08/02 02:44:58 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728
2026/08/02 02:44:58 DEBUG : dir/file1(0x1118f6e335c0): >_readAt: n=16, err=EOF
2026/08/02 02:44:58 DEBUG : dir/file1(0x1118f6e335c0): RWFileHandle.Flush
2026/08/02 02:44:58 DEBUG : dir/file1(0x1118f6e335c0): RWFileHandle.Flush
2026/08/02 02:44:58 DEBUG : dir/file1(0x1118f6e335c0): close: 
2026/08/02 02:44:58 DEBUG : dir/file1(0x1118f6e335c0): >close: err=<nil>
2026/08/02 02:44:58 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:44:58 DEBUG : dir: Looking for writers
2026/08/02 02:44:58 DEBUG : file1: reading active writers
2026/08/02 02:44:58 DEBUG : Looking for writers
2026/08/02 02:44:58 DEBUG : dir: reading active writers
2026/08/02 02:44:58 DEBUG : >WaitForWriters: 
2026/08/02 02:44:58 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: cleaner exiting
    run.go:186: removing dir "dir" failed - try 1/3: sleeping 1s: directory not empty
--- PASS: TestRWFileHandleFlushRead (11.82s)
=== RUN   TestRWFileHandleReleaseRead
    run.go:198: Remote "Linkbox root 'rclone-test-vutatin1moca'", Local "Local file system at /tmp/rclone3665607315", Modify Window "876000h0m0s"
2026/08/02 02:45:03 INFO  : Linkbox root 'rclone-test-vutatin1moca': poll-interval is not supported by this remote
2026/08/02 02:45:03 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: root is "/home/rclone/.cache/rclone"
2026/08/02 02:45:03 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:45:03 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:45:03 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:45:03 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/08/02 02:45:03 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:45:03 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:45:03 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/08/02 02:45:03 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca"
2026/08/02 02:45:03 INFO  : Linkbox root 'rclone-test-vutatin1moca': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2026/08/02 02:45:03 ERROR : dir/file1: vfs cache: item close failed: vfs cache item: failed to write metadata: open /home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca/dir/file1: no such file or directory
2026/08/02 02:45:03 ERROR : dir/file1: vfs cache: close after grace period failed: vfs cache item: failed to write metadata: open /home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca/dir/file1: no such file or directory
2026/08/02 02:45:07 DEBUG : dir/file1: Trying to read object after upload: try again in 100ms (1/10)
2026/08/02 02:45:08 DEBUG : dir/file1: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx
2026/08/02 02:45:08 DEBUG : dir/file1: Open: flags=O_RDONLY
2026/08/02 02:45:08 DEBUG : dir/file1: newRWFileHandle: 
2026/08/02 02:45:08 DEBUG : dir/file1: >newRWFileHandle: err=<nil>
2026/08/02 02:45:08 DEBUG : dir/file1: >Open: fd=dir/file1 (rw), err=<nil>
2026/08/02 02:45:08 DEBUG : dir/file1: >OpenFile: fd=dir/file1 (rw), err=<nil>
2026/08/02 02:45:08 DEBUG : dir/file1(0x1118f6422780): _readAt: size=256, off=0
2026/08/02 02:45:08 DEBUG : dir/file1(0x1118f6422780): openPending: 
2026/08/02 02:45:08 DEBUG : dir/file1: vfs cache: checking remote fingerprint "16" against cached fingerprint ""
2026/08/02 02:45:08 DEBUG : dir/file1: vfs cache: truncate to size=16
2026/08/02 02:45:08 DEBUG : dir: Added virtual directory entry vAddFile: "file1"
2026/08/02 02:45:08 DEBUG : dir/file1(0x1118f6422780): >openPending: err=<nil>
2026/08/02 02:45:08 DEBUG : vfs cache: looking for range={Pos:0 Size:16} in [] - present false
2026/08/02 02:45:08 DEBUG : dir/file1: ChunkedReader.RangeSeek from -1 to 0 length -1
2026/08/02 02:45:08 DEBUG : dir/file1: ChunkedReader.Read at -1 length 32768 chunkOffset 0 chunkSize 134217728
2026/08/02 02:45:08 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728
2026/08/02 02:45:08 DEBUG : dir/file1(0x1118f6422780): >_readAt: n=16, err=EOF
2026/08/02 02:45:08 DEBUG : dir/file1(0x1118f6422780): RWFileHandle.Release
2026/08/02 02:45:08 DEBUG : dir/file1(0x1118f6422780): close: 
2026/08/02 02:45:08 DEBUG : dir/file1(0x1118f6422780): >close: err=<nil>
2026/08/02 02:45:08 DEBUG : dir/file1(0x1118f6422780): RWFileHandle.Release
2026/08/02 02:45:08 DEBUG : WaitForWriters: timeout=30s
2026/08/02 02:45:08 DEBUG : dir: Looking for writers
2026/08/02 02:45:08 DEBUG : file1: reading active writers
2026/08/02 02:45:08 DEBUG : Looking for writers
2026/08/02 02:45:08 DEBUG : dir: reading active writers
2026/08/02 02:45:08 DEBUG : >WaitForWriters: 
2026/08/02 02:45:08 DEBUG : Linkbox root 'rclone-test-vutatin1moca': vfs cache: cleaner exiting
    run.go:186: removing dir "dir" failed - try 1/3: sleeping 1s: directory not empty
    run.go:186: removing dir "dir" failed - try 2/3: sleeping 1.5s: directory not empty
2026/08/02 02:45:13 ERROR : dir/file1: vfs cache: item close failed: vfs cache item: failed to write metadata: open /home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca/dir/file1: no such file or directory
2026/08/02 02:45:13 ERROR : dir/file1: vfs cache: close after grace period failed: vfs cache item: failed to write metadata: open /home/rclone/.cache/rclone/vfsMeta/TestLinkbox/rclone-test-vutatin1moca/dir/file1: no such file or directory
--- PASS: TestRWFileHandleReleaseRead (11.43s)
PASS
2026/08/02 02:45:15 DEBUG : Linkbox root 'rclone-test-vutatin1moca': Purge remote
"./vfs.test -test.v -test.timeout 1h0m0s -remote TestLinkbox: -verbose -test.run '^(TestFileOpen|TestFileOpenRead|TestFileOpenWrite|TestFileRemove|TestFileRemoveAll|TestRWFileHandleFlushRead|TestRWFileHandleMethodsRead|TestRWFileHandleReadAt|TestRWFileHandleReleaseRead|TestRWFileHandleSeek|TestReadFileHandleFlush|TestReadFileHandleMethods|TestReadFileHandleReadAt|TestReadFileHandleRelease|TestReadFileHandleSeek)$|^TestFileRename$/^(full,forceCache=false|minimal,forceCache=false|minimal,forceCache=true|off,forceCache=false|writes,forceCache=false|writes,forceCache=true)$|^TestFileSetModTime$/^cache=off,open=false,write=false$'" - Finished OK in 3m59.2323621s (try 4/5)