"./vfs.test -test.v -test.timeout 1h0m0s -remote TestLinkbox: -verbose -test.run '^(TestDirRemoveAll|TestFileReadAtNonZeroLength|TestFileReadAtZeroLength|TestWriteFileHandleFlush|TestWriteFileHandleRelease|TestWriteFileHandleWriteAt|TestWriteFileModTimeWithOpenWriters|TestZipDirsInRoot|TestZipLargeFiles|TestZipManyFiles|TestZipManySubDirs)$'" - Starting (try 4/5)
2026/08/03 06:26:00 DEBUG : Creating backend with remote "TestLinkbox:rclone-test-fivobef7mahu"
2026/08/03 06:26:00 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/08/03 06:26:00 DEBUG : Linkbox root 'rclone-test-fivobef7mahu': Using cached web token
2026/08/03 06:26:02 DEBUG : Creating backend with remote "/tmp/rclone2547905945"
=== RUN   TestDirRemoveAll
    run.go:198: Remote "Linkbox root 'rclone-test-fivobef7mahu'", Local "Local file system at /tmp/rclone2547905945", Modify Window "876000h0m0s"
2026/08/03 06:26:02 INFO  : Linkbox root 'rclone-test-fivobef7mahu': poll-interval is not supported by this remote
2026/08/03 06:26:02 NOTICE: Linkbox root 'rclone-test-fivobef7mahu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/03 06:26:07 DEBUG : dir/file1: Trying to read object after upload: try again in 100ms (1/10)
2026/08/03 06:26:07 DEBUG : dir/file1: Trying to read object after upload: try again in 200ms (2/10)
    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
2026/08/03 06:26:17 DEBUG : dir/file1: Remove: 
2026/08/03 06:26:18 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/08/03 06:26:18 DEBUG : dir/file1: >Remove: err=<nil>
2026/08/03 06:26:18 ERROR : dir/: Dir.Remove failed to remove directory: directory not empty
    dir_test.go:481: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:481
        	Error:      	Received unexpected error:
        	            	directory not empty
        	Test:       	TestDirRemoveAll
2026/08/03 06:26:18 DEBUG : WaitForWriters: timeout=30s
2026/08/03 06:26:18 DEBUG : dir: Looking for writers
2026/08/03 06:26:18 DEBUG : Looking for writers
2026/08/03 06:26:18 DEBUG : dir: reading active writers
2026/08/03 06:26:18 DEBUG : >WaitForWriters: 
--- FAIL: TestDirRemoveAll (18.38s)
=== RUN   TestWriteFileHandleWriteAt
    run.go:198: Remote "Linkbox root 'rclone-test-fivobef7mahu'", Local "Local file system at /tmp/rclone2547905945", Modify Window "876000h0m0s"
2026/08/03 06:26:20 INFO  : Linkbox root 'rclone-test-fivobef7mahu': poll-interval is not supported by this remote
2026/08/03 06:26:20 NOTICE: Linkbox root 'rclone-test-fivobef7mahu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/03 06:26:20 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2026/08/03 06:26:20 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2026/08/03 06:26:20 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/08/03 06:26:20 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2026/08/03 06:26:20 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2026/08/03 06:26:20 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/08/03 06:26:20 DEBUG : file1: waiting for in-sequence write to 100 for 1s
2026/08/03 06:26:21 DEBUG : file1: aborting in-sequence write wait, off=100
2026/08/03 06:26:21 DEBUG : file1: failed to wait for in-sequence write to 100
2026/08/03 06:26:21 ERROR : file1: WriteFileHandle.Write: can't seek in file without --vfs-cache-mode >= writes
2026/08/03 06:26:21 DEBUG : Linkbox root 'rclone-test-fivobef7mahu': File to upload is small (11 bytes), uploading instead of streaming
2026/08/03 06:26:23 DEBUG : file1: size = 11 OK
2026/08/03 06:26:23 NOTICE: Linkbox root 'rclone-test-fivobef7mahu': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2026/08/03 06:26:23 DEBUG : file1: Size of src and dst objects identical
2026/08/03 06:26:23 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/08/03 06:26:23 ERROR : file1: WriteFileHandle.Write: error: Bad file descriptor
2026/08/03 06:26:24 DEBUG : WaitForWriters: timeout=30s
2026/08/03 06:26:24 DEBUG : Looking for writers
2026/08/03 06:26:24 DEBUG : file1: reading active writers
2026/08/03 06:26:24 DEBUG : >WaitForWriters: 
    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: TestWriteFileHandleWriteAt (12.77s)
=== RUN   TestWriteFileHandleFlush
    run.go:198: Remote "Linkbox root 'rclone-test-fivobef7mahu'", Local "Local file system at /tmp/rclone2547905945", Modify Window "876000h0m0s"
2026/08/03 06:26:33 INFO  : Linkbox root 'rclone-test-fivobef7mahu': poll-interval is not supported by this remote
2026/08/03 06:26:33 NOTICE: Linkbox root 'rclone-test-fivobef7mahu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/03 06:26:33 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2026/08/03 06:26:33 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2026/08/03 06:26:33 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/08/03 06:26:33 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2026/08/03 06:26:33 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2026/08/03 06:26:33 DEBUG : file1: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions
2026/08/03 06:26:33 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/08/03 06:26:33 DEBUG : Linkbox root 'rclone-test-fivobef7mahu': File to upload is small (5 bytes), uploading instead of streaming
2026/08/03 06:26:35 DEBUG : file1: size = 5 OK
2026/08/03 06:26:35 DEBUG : file1: Size of src and dst objects identical
2026/08/03 06:26:35 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/08/03 06:26:35 DEBUG : file1: WriteFileHandle.Flush nothing to do
2026/08/03 06:26:35 DEBUG : WaitForWriters: timeout=30s
2026/08/03 06:26:35 DEBUG : Looking for writers
2026/08/03 06:26:35 DEBUG : file1: reading active writers
2026/08/03 06:26:35 DEBUG : >WaitForWriters: 
    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: TestWriteFileHandleFlush (11.70s)
=== RUN   TestWriteFileHandleRelease
    run.go:198: Remote "Linkbox root 'rclone-test-fivobef7mahu'", Local "Local file system at /tmp/rclone2547905945", Modify Window "876000h0m0s"
2026/08/03 06:26:45 INFO  : Linkbox root 'rclone-test-fivobef7mahu': poll-interval is not supported by this remote
2026/08/03 06:26:45 NOTICE: Linkbox root 'rclone-test-fivobef7mahu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/03 06:26:45 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2026/08/03 06:26:45 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2026/08/03 06:26:45 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/08/03 06:26:45 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2026/08/03 06:26:45 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2026/08/03 06:26:45 DEBUG : file1: WriteFileHandle.Release closing
2026/08/03 06:26:45 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/08/03 06:26:45 DEBUG : Linkbox root 'rclone-test-fivobef7mahu': File to upload is small (0 bytes), uploading instead of streaming
2026/08/03 06:26:45 ERROR : file1: WriteFileHandle.New Rcat failed: can't upload empty files to this remote
2026/08/03 06:26:45 DEBUG : file1: Remove: 
2026/08/03 06:26:45 DEBUG : Added virtual directory entry vDel: "file1"
2026/08/03 06:26:45 DEBUG : file1: >Remove: err=<nil>
2026/08/03 06:26:45 ERROR : file1: WriteFileHandle.Release error: can't upload empty files to this remote
    write_test.go:276: skipping test: can't upload empty files to this remote
2026/08/03 06:26:45 DEBUG : WaitForWriters: timeout=30s
2026/08/03 06:26:45 DEBUG : Looking for writers
2026/08/03 06:26:45 DEBUG : >WaitForWriters: 
--- PASS: TestWriteFileHandleRelease (0.63s)
=== RUN   TestWriteFileModTimeWithOpenWriters
    run.go:198: Remote "Linkbox root 'rclone-test-fivobef7mahu'", Local "Local file system at /tmp/rclone2547905945", Modify Window "876000h0m0s"
2026/08/03 06:26:45 INFO  : Linkbox root 'rclone-test-fivobef7mahu': poll-interval is not supported by this remote
2026/08/03 06:26:45 NOTICE: Linkbox root 'rclone-test-fivobef7mahu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/03 06:26:45 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2026/08/03 06:26:46 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2026/08/03 06:26:46 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/08/03 06:26:46 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2026/08/03 06:26:46 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2026/08/03 06:26:49 DEBUG : Can set mod time: false
    write_test.go:321: can't set mod time
2026/08/03 06:26:49 DEBUG : WaitForWriters: timeout=30s
2026/08/03 06:26:49 DEBUG : Looking for writers
2026/08/03 06:26:49 DEBUG : file1: reading active writers
2026/08/03 06:26:49 DEBUG : file1: active writers 1
2026/08/03 06:26:49 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms
2026/08/03 06:26:49 DEBUG : Looking for writers
2026/08/03 06:26:49 DEBUG : file1: reading active writers
2026/08/03 06:26:49 DEBUG : file1: active writers 1
2026/08/03 06:26:49 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms
2026/08/03 06:26:49 DEBUG : Looking for writers
2026/08/03 06:26:49 DEBUG : file1: reading active writers
2026/08/03 06:26:49 DEBUG : file1: active writers 1
2026/08/03 06:26:49 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms
2026/08/03 06:26:49 DEBUG : Looking for writers
2026/08/03 06:26:49 DEBUG : file1: reading active writers
2026/08/03 06:26:49 DEBUG : file1: active writers 1
2026/08/03 06:26:49 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms
2026/08/03 06:26:49 DEBUG : Looking for writers
2026/08/03 06:26:49 DEBUG : file1: reading active writers
2026/08/03 06:26:49 DEBUG : file1: active writers 1
2026/08/03 06:26:49 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms
2026/08/03 06:26:49 DEBUG : Looking for writers
2026/08/03 06:26:49 DEBUG : file1: reading active writers
2026/08/03 06:26:49 DEBUG : file1: active writers 1
2026/08/03 06:26:49 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms
2026/08/03 06:26:50 DEBUG : Looking for writers
2026/08/03 06:26:50 DEBUG : file1: reading active writers
2026/08/03 06:26:50 DEBUG : file1: active writers 1
2026/08/03 06:26:50 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms
2026/08/03 06:26:50 DEBUG : Looking for writers
2026/08/03 06:26:50 DEBUG : file1: reading active writers
2026/08/03 06:26:50 DEBUG : file1: active writers 1
2026/08/03 06:26:50 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:26:51 DEBUG : Looking for writers
2026/08/03 06:26:51 DEBUG : file1: reading active writers
2026/08/03 06:26:51 DEBUG : file1: active writers 1
2026/08/03 06:26:51 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:26:52 DEBUG : Looking for writers
2026/08/03 06:26:52 DEBUG : file1: reading active writers
2026/08/03 06:26:52 DEBUG : file1: active writers 1
2026/08/03 06:26:52 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:26:53 DEBUG : Looking for writers
2026/08/03 06:26:53 DEBUG : file1: reading active writers
2026/08/03 06:26:53 DEBUG : file1: active writers 1
2026/08/03 06:26:53 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:26:54 DEBUG : Looking for writers
2026/08/03 06:26:54 DEBUG : file1: reading active writers
2026/08/03 06:26:54 DEBUG : file1: active writers 1
2026/08/03 06:26:54 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:26:55 DEBUG : Looking for writers
2026/08/03 06:26:55 DEBUG : file1: reading active writers
2026/08/03 06:26:55 DEBUG : file1: active writers 1
2026/08/03 06:26:55 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:26:56 DEBUG : Looking for writers
2026/08/03 06:26:56 DEBUG : file1: reading active writers
2026/08/03 06:26:56 DEBUG : file1: active writers 1
2026/08/03 06:26:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:26:57 DEBUG : Looking for writers
2026/08/03 06:26:57 DEBUG : file1: reading active writers
2026/08/03 06:26:57 DEBUG : file1: active writers 1
2026/08/03 06:26:57 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:26:58 DEBUG : Looking for writers
2026/08/03 06:26:58 DEBUG : file1: reading active writers
2026/08/03 06:26:58 DEBUG : file1: active writers 1
2026/08/03 06:26:58 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:26:59 DEBUG : Looking for writers
2026/08/03 06:26:59 DEBUG : file1: reading active writers
2026/08/03 06:26:59 DEBUG : file1: active writers 1
2026/08/03 06:26:59 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:27:00 DEBUG : Looking for writers
2026/08/03 06:27:00 DEBUG : file1: reading active writers
2026/08/03 06:27:00 DEBUG : file1: active writers 1
2026/08/03 06:27:00 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:27:01 DEBUG : Looking for writers
2026/08/03 06:27:01 DEBUG : file1: reading active writers
2026/08/03 06:27:01 DEBUG : file1: active writers 1
2026/08/03 06:27:01 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:27:02 DEBUG : Looking for writers
2026/08/03 06:27:02 DEBUG : file1: reading active writers
2026/08/03 06:27:02 DEBUG : file1: active writers 1
2026/08/03 06:27:02 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:27:03 DEBUG : Looking for writers
2026/08/03 06:27:03 DEBUG : file1: reading active writers
2026/08/03 06:27:03 DEBUG : file1: active writers 1
2026/08/03 06:27:03 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:27:04 DEBUG : Looking for writers
2026/08/03 06:27:04 DEBUG : file1: reading active writers
2026/08/03 06:27:04 DEBUG : file1: active writers 1
2026/08/03 06:27:04 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:27:05 DEBUG : Looking for writers
2026/08/03 06:27:05 DEBUG : file1: reading active writers
2026/08/03 06:27:05 DEBUG : file1: active writers 1
2026/08/03 06:27:05 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:27:06 DEBUG : Looking for writers
2026/08/03 06:27:06 DEBUG : file1: reading active writers
2026/08/03 06:27:06 DEBUG : file1: active writers 1
2026/08/03 06:27:06 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:27:07 DEBUG : Looking for writers
2026/08/03 06:27:07 DEBUG : file1: reading active writers
2026/08/03 06:27:07 DEBUG : file1: active writers 1
2026/08/03 06:27:07 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:27:08 DEBUG : Looking for writers
2026/08/03 06:27:08 DEBUG : file1: reading active writers
2026/08/03 06:27:08 DEBUG : file1: active writers 1
2026/08/03 06:27:08 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:27:09 DEBUG : Looking for writers
2026/08/03 06:27:09 DEBUG : file1: reading active writers
2026/08/03 06:27:09 DEBUG : file1: active writers 1
2026/08/03 06:27:09 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:27:10 DEBUG : Looking for writers
2026/08/03 06:27:10 DEBUG : file1: reading active writers
2026/08/03 06:27:10 DEBUG : file1: active writers 1
2026/08/03 06:27:10 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:27:11 DEBUG : Looking for writers
2026/08/03 06:27:11 DEBUG : file1: reading active writers
2026/08/03 06:27:11 DEBUG : file1: active writers 1
2026/08/03 06:27:11 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:27:12 DEBUG : Looking for writers
2026/08/03 06:27:12 DEBUG : file1: reading active writers
2026/08/03 06:27:12 DEBUG : file1: active writers 1
2026/08/03 06:27:12 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:27:13 DEBUG : Looking for writers
2026/08/03 06:27:13 DEBUG : file1: reading active writers
2026/08/03 06:27:13 DEBUG : file1: active writers 1
2026/08/03 06:27:13 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:27:14 DEBUG : Looking for writers
2026/08/03 06:27:14 DEBUG : file1: reading active writers
2026/08/03 06:27:14 DEBUG : file1: active writers 1
2026/08/03 06:27:14 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:27:15 DEBUG : Looking for writers
2026/08/03 06:27:15 DEBUG : file1: reading active writers
2026/08/03 06:27:15 DEBUG : file1: active writers 1
2026/08/03 06:27:15 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:27:16 DEBUG : Looking for writers
2026/08/03 06:27:16 DEBUG : file1: reading active writers
2026/08/03 06:27:16 DEBUG : file1: active writers 1
2026/08/03 06:27:16 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:27:17 DEBUG : Looking for writers
2026/08/03 06:27:17 DEBUG : file1: reading active writers
2026/08/03 06:27:17 DEBUG : file1: active writers 1
2026/08/03 06:27:17 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:27:18 DEBUG : Looking for writers
2026/08/03 06:27:18 DEBUG : file1: reading active writers
2026/08/03 06:27:18 DEBUG : file1: active writers 1
2026/08/03 06:27:18 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/08/03 06:27:19 ERROR : Exiting even though 1 writers active and 0 cache items in use after 30s
Cache: <nil>
2026/08/03 06:27:19 DEBUG : >WaitForWriters: 
--- SKIP: TestWriteFileModTimeWithOpenWriters (34.14s)
=== RUN   TestFileReadAtZeroLength
    run.go:198: Remote "Linkbox root 'rclone-test-fivobef7mahu'", Local "Local file system at /tmp/rclone2547905945", Modify Window "876000h0m0s"
2026/08/03 06:27:19 INFO  : Linkbox root 'rclone-test-fivobef7mahu': poll-interval is not supported by this remote
2026/08/03 06:27:19 NOTICE: Linkbox root 'rclone-test-fivobef7mahu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/03 06:27:19 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2026/08/03 06:27:20 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2026/08/03 06:27:20 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/08/03 06:27:20 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2026/08/03 06:27:20 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2026/08/03 06:27:20 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/08/03 06:27:20 DEBUG : Linkbox root 'rclone-test-fivobef7mahu': File to upload is small (0 bytes), uploading instead of streaming
2026/08/03 06:27:20 ERROR : file1: WriteFileHandle.New Rcat failed: can't upload empty files to this remote
2026/08/03 06:27:20 DEBUG : file1: Remove: 
2026/08/03 06:27:20 DEBUG : Added virtual directory entry vDel: "file1"
2026/08/03 06:27:20 DEBUG : file1: >Remove: err=<nil>
    write_test.go:357: skipping test: can't upload empty files to this remote
2026/08/03 06:27:20 DEBUG : WaitForWriters: timeout=30s
2026/08/03 06:27:20 DEBUG : Looking for writers
2026/08/03 06:27:20 DEBUG : >WaitForWriters: 
--- PASS: TestFileReadAtZeroLength (0.63s)
=== RUN   TestFileReadAtNonZeroLength
    run.go:198: Remote "Linkbox root 'rclone-test-fivobef7mahu'", Local "Local file system at /tmp/rclone2547905945", Modify Window "876000h0m0s"
2026/08/03 06:27:20 INFO  : Linkbox root 'rclone-test-fivobef7mahu': poll-interval is not supported by this remote
2026/08/03 06:27:20 NOTICE: Linkbox root 'rclone-test-fivobef7mahu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/03 06:27:20 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2026/08/03 06:27:20 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2026/08/03 06:27:20 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/08/03 06:27:20 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2026/08/03 06:27:20 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2026/08/03 06:27:20 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/08/03 06:27:20 DEBUG : Linkbox root 'rclone-test-fivobef7mahu': File to upload is small (100 bytes), uploading instead of streaming
2026/08/03 06:27:24 DEBUG : file1: size = 100 OK
2026/08/03 06:27:24 DEBUG : file1: Size of src and dst objects identical
2026/08/03 06:27:24 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/08/03 06:27:24 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=----------
2026/08/03 06:27:24 DEBUG : file1: Open: flags=O_RDONLY
2026/08/03 06:27:24 DEBUG : file1: >Open: fd=file1 (r), err=<nil>
2026/08/03 06:27:24 DEBUG : file1: >OpenFile: fd=file1 (r), err=<nil>
2026/08/03 06:27:24 DEBUG : file1: ChunkedReader.openRange at 0 length 134217728
2026/08/03 06:27:24 DEBUG : file1: ChunkedReader.Read at 0 length 1024 chunkOffset 0 chunkSize 134217728
2026/08/03 06:27:25 DEBUG : WaitForWriters: timeout=30s
2026/08/03 06:27:25 DEBUG : Looking for writers
2026/08/03 06:27:25 DEBUG : file1: reading active writers
2026/08/03 06:27:25 DEBUG : >WaitForWriters: 
    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: TestFileReadAtNonZeroLength (13.92s)
=== RUN   TestZipManyFiles
    run.go:198: Remote "Linkbox root 'rclone-test-fivobef7mahu'", Local "Local file system at /tmp/rclone2547905945", Modify Window "876000h0m0s"
2026/08/03 06:27:34 INFO  : Linkbox root 'rclone-test-fivobef7mahu': poll-interval is not supported by this remote
2026/08/03 06:27:34 NOTICE: Linkbox root 'rclone-test-fivobef7mahu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/03 06:27:38 DEBUG : flat/f000.txt: Trying to read object after upload: try again in 100ms (1/10)
2026/08/03 06:27:40 DEBUG : flat/f001.txt: Trying to read object after upload: try again in 100ms (1/10)
2026/08/03 06:27:44 DEBUG : flat/f003.txt: Trying to read object after upload: try again in 100ms (1/10)
2026/08/03 06:27:45 DEBUG : flat/f003.txt: Trying to read object after upload: try again in 200ms (2/10)
2026/08/03 06:27:45 DEBUG : flat/f003.txt: Trying to read object after upload: try again in 400ms (3/10)
2026/08/03 06:27:49 DEBUG : flat/f000.txt: Open: flags=O_RDONLY
2026/08/03 06:27:49 DEBUG : flat/f000.txt: >Open: fd=flat/f000.txt (r), err=<nil>
2026/08/03 06:27:49 DEBUG : flat/f000.txt: Set virtual modtime to 2026-08-03 06:27:36 +0000 UTC
2026/08/03 06:27:49 DEBUG : flat/f000.txt: ChunkedReader.openRange at 0 length 134217728
2026/08/03 06:27:49 DEBUG : flat/f000.txt: ChunkedReader.Read at 0 length 32768 chunkOffset 0 chunkSize 134217728
2026/08/03 06:27:49 DEBUG : flat/f001.txt: Open: flags=O_RDONLY
2026/08/03 06:27:49 DEBUG : flat/f001.txt: >Open: fd=flat/f001.txt (r), err=<nil>
2026/08/03 06:27:49 DEBUG : flat/f001.txt: Set virtual modtime to 2026-08-03 06:27:39 +0000 UTC
2026/08/03 06:27:49 DEBUG : flat/f001.txt: ChunkedReader.openRange at 0 length 134217728
2026/08/03 06:27:49 DEBUG : flat/f001.txt: ChunkedReader.Read at 0 length 32768 chunkOffset 0 chunkSize 134217728
2026/08/03 06:27:49 DEBUG : flat/f002.txt: Open: flags=O_RDONLY
2026/08/03 06:27:49 DEBUG : flat/f002.txt: >Open: fd=flat/f002.txt (r), err=<nil>
2026/08/03 06:27:49 DEBUG : flat/f002.txt: Set virtual modtime to 2026-08-03 06:27:41 +0000 UTC
2026/08/03 06:27:49 DEBUG : flat/f002.txt: ChunkedReader.openRange at 0 length 134217728
2026/08/03 06:27:49 DEBUG : flat/f002.txt: ChunkedReader.Read at 0 length 32768 chunkOffset 0 chunkSize 134217728
2026/08/03 06:27:49 DEBUG : flat/f003.txt: Open: flags=O_RDONLY
2026/08/03 06:27:49 DEBUG : flat/f003.txt: >Open: fd=flat/f003.txt (r), err=<nil>
2026/08/03 06:27:49 DEBUG : flat/f003.txt: Set virtual modtime to 2026-08-03 06:27:43 +0000 UTC
2026/08/03 06:27:49 DEBUG : flat/f003.txt: ChunkedReader.openRange at 0 length 134217728
2026/08/03 06:27:50 DEBUG : flat/f003.txt: ChunkedReader.Read at 0 length 32768 chunkOffset 0 chunkSize 134217728
2026/08/03 06:27:50 DEBUG : flat/f004.txt: Open: flags=O_RDONLY
2026/08/03 06:27:50 DEBUG : flat/f004.txt: >Open: fd=flat/f004.txt (r), err=<nil>
2026/08/03 06:27:50 DEBUG : flat/f004.txt: Set virtual modtime to 2026-08-03 06:27:47 +0000 UTC
2026/08/03 06:27:50 DEBUG : flat/f004.txt: ChunkedReader.openRange at 0 length 134217728
2026/08/03 06:27:50 DEBUG : flat/f004.txt: ChunkedReader.Read at 0 length 32768 chunkOffset 0 chunkSize 134217728
2026/08/03 06:27:50 DEBUG : WaitForWriters: timeout=30s
2026/08/03 06:27:50 DEBUG : flat: Looking for writers
2026/08/03 06:27:50 DEBUG : f000.txt: reading active writers
2026/08/03 06:27:50 DEBUG : f001.txt: reading active writers
2026/08/03 06:27:50 DEBUG : f002.txt: reading active writers
2026/08/03 06:27:50 DEBUG : f003.txt: reading active writers
2026/08/03 06:27:50 DEBUG : f004.txt: reading active writers
2026/08/03 06:27:50 DEBUG : Looking for writers
2026/08/03 06:27:50 DEBUG : flat: reading active writers
2026/08/03 06:27:50 DEBUG : >WaitForWriters: 
--- PASS: TestZipManyFiles (24.80s)
=== RUN   TestZipManySubDirs
    run.go:198: Remote "Linkbox root 'rclone-test-fivobef7mahu'", Local "Local file system at /tmp/rclone2547905945", Modify Window "876000h0m0s"
2026/08/03 06:27:59 INFO  : Linkbox root 'rclone-test-fivobef7mahu': poll-interval is not supported by this remote
2026/08/03 06:27:59 NOTICE: Linkbox root 'rclone-test-fivobef7mahu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/03 06:28:02 DEBUG : a/top.txt: Trying to read object after upload: try again in 100ms (1/10)
2026/08/03 06:28:03 DEBUG : a/top.txt: Trying to read object after upload: try again in 200ms (2/10)
2026/08/03 06:28:10 DEBUG : a/b/c/deep.txt: Trying to read object after upload: try again in 100ms (1/10)
2026/08/03 06:28:11 DEBUG : a/b/c/deep.txt: Open: flags=O_RDONLY
2026/08/03 06:28:11 DEBUG : a/b/c/deep.txt: >Open: fd=a/b/c/deep.txt (r), err=<nil>
2026/08/03 06:28:11 DEBUG : a/b/c/deep.txt: Set virtual modtime to 2026-08-03 06:28:09 +0000 UTC
2026/08/03 06:28:11 DEBUG : a/b/c/deep.txt: ChunkedReader.openRange at 0 length 134217728
2026/08/03 06:28:12 DEBUG : a/b/c/deep.txt: ChunkedReader.Read at 0 length 32768 chunkOffset 0 chunkSize 134217728
2026/08/03 06:28:12 DEBUG : a/b/mid.txt: Open: flags=O_RDONLY
2026/08/03 06:28:12 DEBUG : a/b/mid.txt: >Open: fd=a/b/mid.txt (r), err=<nil>
2026/08/03 06:28:12 DEBUG : a/b/mid.txt: Set virtual modtime to 2026-08-03 06:28:05 +0000 UTC
2026/08/03 06:28:12 DEBUG : a/b/mid.txt: ChunkedReader.openRange at 0 length 134217728
2026/08/03 06:28:12 DEBUG : a/b/mid.txt: ChunkedReader.Read at 0 length 32768 chunkOffset 0 chunkSize 134217728
2026/08/03 06:28:12 DEBUG : a/top.txt: Open: flags=O_RDONLY
2026/08/03 06:28:12 DEBUG : a/top.txt: >Open: fd=a/top.txt (r), err=<nil>
2026/08/03 06:28:12 DEBUG : a/top.txt: Set virtual modtime to 2026-08-03 06:28:01 +0000 UTC
2026/08/03 06:28:12 DEBUG : a/top.txt: ChunkedReader.openRange at 0 length 134217728
2026/08/03 06:28:12 DEBUG : a/top.txt: ChunkedReader.Read at 0 length 32768 chunkOffset 0 chunkSize 134217728
2026/08/03 06:28:12 DEBUG : WaitForWriters: timeout=30s
2026/08/03 06:28:12 DEBUG : a/b/c: Looking for writers
2026/08/03 06:28:12 DEBUG : deep.txt: reading active writers
2026/08/03 06:28:12 DEBUG : a/b: Looking for writers
2026/08/03 06:28:12 DEBUG : c: reading active writers
2026/08/03 06:28:12 DEBUG : mid.txt: reading active writers
2026/08/03 06:28:12 DEBUG : a: Looking for writers
2026/08/03 06:28:12 DEBUG : b: reading active writers
2026/08/03 06:28:12 DEBUG : top.txt: reading active writers
2026/08/03 06:28:12 DEBUG : Looking for writers
2026/08/03 06:28:12 DEBUG : a: reading active writers
2026/08/03 06:28:12 DEBUG : >WaitForWriters: 
    run.go:186: removing dir "a/b/c" failed - try 1/3: sleeping 1s: directory not empty
--- PASS: TestZipManySubDirs (24.00s)
=== RUN   TestZipLargeFiles
    run.go:198: Remote "Linkbox root 'rclone-test-fivobef7mahu'", Local "Local file system at /tmp/rclone2547905945", Modify Window "876000h0m0s"
2026/08/03 06:28:23 INFO  : Linkbox root 'rclone-test-fivobef7mahu': poll-interval is not supported by this remote
2026/08/03 06:28:23 NOTICE: Linkbox root 'rclone-test-fivobef7mahu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/03 06:28:29 DEBUG : bigdir/big.bin: Trying to read object after upload: try again in 100ms (1/10)
2026/08/03 06:28:29 DEBUG : bigdir/big.bin: Trying to read object after upload: try again in 200ms (2/10)
2026/08/03 06:28:30 DEBUG : bigdir/big.bin: Open: flags=O_RDONLY
2026/08/03 06:28:30 DEBUG : bigdir/big.bin: >Open: fd=bigdir/big.bin (r), err=<nil>
2026/08/03 06:28:30 DEBUG : bigdir/big.bin: Set virtual modtime to 2026-08-03 06:28:27 +0000 UTC
2026/08/03 06:28:30 DEBUG : bigdir/big.bin: ChunkedReader.openRange at 0 length 134217728
2026/08/03 06:28:31 DEBUG : bigdir/big.bin: ChunkedReader.Read at 0 length 4096 chunkOffset 0 chunkSize 134217728
2026/08/03 06:28:31 DEBUG : bigdir/big.bin: ChunkedReader.Read at 4096 length 8192 chunkOffset 0 chunkSize 134217728
2026/08/03 06:28:31 DEBUG : bigdir/big.bin: ChunkedReader.Read at 12288 length 16384 chunkOffset 0 chunkSize 134217728
2026/08/03 06:28:31 DEBUG : bigdir/big.bin: ChunkedReader.Read at 28672 length 32768 chunkOffset 0 chunkSize 134217728
2026/08/03 06:28:31 DEBUG : bigdir/big.bin: ChunkedReader.Read at 61440 length 65536 chunkOffset 0 chunkSize 134217728
2026/08/03 06:28:31 DEBUG : bigdir/big.bin: ChunkedReader.Read at 126976 length 131072 chunkOffset 0 chunkSize 134217728
2026/08/03 06:28:31 DEBUG : bigdir/big.bin: ChunkedReader.Read at 258048 length 262144 chunkOffset 0 chunkSize 134217728
2026/08/03 06:28:31 DEBUG : bigdir/big.bin: ChunkedReader.Read at 520192 length 524288 chunkOffset 0 chunkSize 134217728
2026/08/03 06:28:31 DEBUG : bigdir/big.bin: ChunkedReader.Read at 1044480 length 1048576 chunkOffset 0 chunkSize 134217728
2026/08/03 06:28:31 DEBUG : bigdir/big.bin: ChunkedReader.Read at 2093056 length 1048576 chunkOffset 0 chunkSize 134217728
2026/08/03 06:28:31 DEBUG : bigdir/big.bin: ChunkedReader.Read at 3141632 length 1048576 chunkOffset 0 chunkSize 134217728
2026/08/03 06:28:32 DEBUG : bigdir/big.bin: ChunkedReader.Read at 4190208 length 1048576 chunkOffset 0 chunkSize 134217728
2026/08/03 06:28:32 DEBUG : bigdir/big.bin: ChunkedReader.Read at 5238784 length 1048576 chunkOffset 0 chunkSize 134217728
2026/08/03 06:28:33 DEBUG : WaitForWriters: timeout=30s
2026/08/03 06:28:33 DEBUG : bigdir: Looking for writers
2026/08/03 06:28:33 DEBUG : big.bin: reading active writers
2026/08/03 06:28:33 DEBUG : Looking for writers
2026/08/03 06:28:33 DEBUG : bigdir: reading active writers
2026/08/03 06:28:33 DEBUG : >WaitForWriters: 
--- PASS: TestZipLargeFiles (13.23s)
=== RUN   TestZipDirsInRoot
    run.go:198: Remote "Linkbox root 'rclone-test-fivobef7mahu'", Local "Local file system at /tmp/rclone2547905945", Modify Window "876000h0m0s"
2026/08/03 06:28:36 INFO  : Linkbox root 'rclone-test-fivobef7mahu': poll-interval is not supported by this remote
2026/08/03 06:28:36 NOTICE: Linkbox root 'rclone-test-fivobef7mahu': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/08/03 06:28:40 DEBUG : dir1/a.txt: Trying to read object after upload: try again in 100ms (1/10)
2026/08/03 06:28:48 DEBUG : dir3/c.txt: Trying to read object after upload: try again in 100ms (1/10)
2026/08/03 06:28:48 DEBUG : dir1/a.txt: Open: flags=O_RDONLY
2026/08/03 06:28:48 DEBUG : dir1/a.txt: >Open: fd=dir1/a.txt (r), err=<nil>
2026/08/03 06:28:48 DEBUG : dir1/a.txt: Set virtual modtime to 2026-08-03 06:28:38 +0000 UTC
2026/08/03 06:28:48 DEBUG : dir1/a.txt: ChunkedReader.openRange at 0 length 134217728
2026/08/03 06:28:48 DEBUG : dir1/a.txt: ChunkedReader.Read at 0 length 32768 chunkOffset 0 chunkSize 134217728
2026/08/03 06:28:49 DEBUG : dir2/b.txt: Open: flags=O_RDONLY
2026/08/03 06:28:49 DEBUG : dir2/b.txt: >Open: fd=dir2/b.txt (r), err=<nil>
2026/08/03 06:28:49 DEBUG : dir2/b.txt: Set virtual modtime to 2026-08-03 06:28:42 +0000 UTC
2026/08/03 06:28:49 DEBUG : dir2/b.txt: ChunkedReader.openRange at 0 length 134217728
2026/08/03 06:28:49 DEBUG : dir2/b.txt: ChunkedReader.Read at 0 length 32768 chunkOffset 0 chunkSize 134217728
2026/08/03 06:28:49 DEBUG : dir3/c.txt: Open: flags=O_RDONLY
2026/08/03 06:28:49 DEBUG : dir3/c.txt: >Open: fd=dir3/c.txt (r), err=<nil>
2026/08/03 06:28:49 DEBUG : dir3/c.txt: Set virtual modtime to 2026-08-03 06:28:46 +0000 UTC
2026/08/03 06:28:49 DEBUG : dir3/c.txt: ChunkedReader.openRange at 0 length 134217728
2026/08/03 06:28:49 DEBUG : dir3/c.txt: ChunkedReader.Read at 0 length 32768 chunkOffset 0 chunkSize 134217728
2026/08/03 06:28:49 DEBUG : WaitForWriters: timeout=30s
2026/08/03 06:28:49 DEBUG : dir3: Looking for writers
2026/08/03 06:28:49 DEBUG : c.txt: reading active writers
2026/08/03 06:28:49 DEBUG : dir1: Looking for writers
2026/08/03 06:28:49 DEBUG : a.txt: reading active writers
2026/08/03 06:28:49 DEBUG : dir2: Looking for writers
2026/08/03 06:28:49 DEBUG : b.txt: reading active writers
2026/08/03 06:28:49 DEBUG : Looking for writers
2026/08/03 06:28:49 DEBUG : dir1: reading active writers
2026/08/03 06:28:49 DEBUG : dir2: reading active writers
2026/08/03 06:28:49 DEBUG : dir3: reading active writers
2026/08/03 06:28:49 DEBUG : >WaitForWriters: 
--- PASS: TestZipDirsInRoot (22.76s)
FAIL
2026/08/03 06:28:59 DEBUG : Linkbox root 'rclone-test-fivobef7mahu': Purge remote
"./vfs.test -test.v -test.timeout 1h0m0s -remote TestLinkbox: -verbose -test.run '^(TestDirRemoveAll|TestFileReadAtNonZeroLength|TestFileReadAtZeroLength|TestWriteFileHandleFlush|TestWriteFileHandleRelease|TestWriteFileHandleWriteAt|TestWriteFileModTimeWithOpenWriters|TestZipDirsInRoot|TestZipLargeFiles|TestZipManyFiles|TestZipManySubDirs)$'" - Finished ERROR in 2m59.835274165s (try 4/5): exit status 1: Failed [TestDirRemoveAll]