"./vfs.test -test.v -test.timeout 1h0m0s -remote TestInternxt: -list-retries 5 -verbose -test.run '^(TestCaseSensitivity|TestFileReadAtZeroLength|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileModTimeWithOpenWriters)$|^TestFileSetModTime$/^(cache=off,open=false,write=false|cache=off,open=true,write=false)$'" - Starting (try 2/5) 2026/03/10 03:09:08 DEBUG : Creating backend with remote "TestInternxt:rclone-test-petuhen9kipa" 2026/03/10 03:09:08 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/03/10 03:09:09 DEBUG : User info: rootFolderId=2661cf64-e104-478b-b737-48c3ac8984d2, bucket=697358bf16ceabcf39af85f2 2026/03/10 03:09:10 DEBUG : Creating backend with remote "/tmp/rclone3592506148" === RUN TestFileSetModTime === RUN TestFileSetModTime/cache=off,open=false,write=false run.go:185: Remote "Internxt root 'rclone-test-petuhen9kipa'", Local "Local file system at /tmp/rclone3592506148", Modify Window "876000h0m0s" 2026/03/10 03:09:10 INFO : Internxt root 'rclone-test-petuhen9kipa': poll-interval is not supported by this remote 2026/03/10 03:09:10 NOTICE: Internxt root 'rclone-test-petuhen9kipa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/03/10 03:09:13 DEBUG : Can set mod time: false file_test.go:97: can't set mod time 2026/03/10 03:09:13 DEBUG : WaitForWriters: timeout=30s 2026/03/10 03:09:13 DEBUG : dir: Looking for writers 2026/03/10 03:09:13 DEBUG : file1: reading active writers 2026/03/10 03:09:13 DEBUG : Looking for writers 2026/03/10 03:09:13 DEBUG : dir: reading active writers 2026/03/10 03:09:13 DEBUG : >WaitForWriters: 2026/03/10 03:09:14 ERROR : dir: error listing: directory not found fstest.go:298: Sleeping for 1s for list eventual consistency: 1/5 fstest.go:292: Sleeping for 6s just to make sure === RUN TestFileSetModTime/cache=off,open=true,write=false file_test.go:93: can't set mod time --- PASS: TestFileSetModTime (12.07s) --- SKIP: TestFileSetModTime/cache=off,open=false,write=false (12.07s) --- SKIP: TestFileSetModTime/cache=off,open=true,write=false (0.00s) === RUN TestCaseSensitivity run.go:185: Remote "Internxt root 'rclone-test-petuhen9kipa'", Local "Local file system at /tmp/rclone3592506148", Modify Window "876000h0m0s" 2026/03/10 03:09:24 INFO : Internxt root 'rclone-test-petuhen9kipa': poll-interval is not supported by this remote 2026/03/10 03:09:24 NOTICE: Internxt root 'rclone-test-petuhen9kipa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/03/10 03:09:24 INFO : Internxt root 'rclone-test-petuhen9kipa': poll-interval is not supported by this remote 2026/03/10 03:09:24 NOTICE: Internxt root 'rclone-test-petuhen9kipa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/03/10 03:09:24 DEBUG : FiLeA: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:24 DEBUG : FiLeA: Open: flags=O_RDONLY 2026/03/10 03:09:24 DEBUG : FiLeA: >Open: fd=FiLeA (r), err= 2026/03/10 03:09:24 DEBUG : FiLeA: >OpenFile: fd=FiLeA (r), err= 2026/03/10 03:09:24 DEBUG : FiLeA: ChunkedReader.openRange at 0 length 134217728 2026/03/10 03:09:25 DEBUG : FiLeA: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2026/03/10 03:09:25 DEBUG : FiLeA: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:25 DEBUG : FiLeA: Open: flags=O_RDONLY 2026/03/10 03:09:25 DEBUG : FiLeA: >Open: fd=FiLeA (r), err= 2026/03/10 03:09:25 DEBUG : FiLeA: >OpenFile: fd=FiLeA (r), err= 2026/03/10 03:09:25 DEBUG : FiLeA: ChunkedReader.openRange at 0 length 134217728 2026/03/10 03:09:25 DEBUG : FiLeA: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2026/03/10 03:09:25 DEBUG : FiLeA: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:25 DEBUG : FiLeA: Open: flags=O_RDONLY 2026/03/10 03:09:25 DEBUG : FiLeA: >Open: fd=FiLeA (r), err= 2026/03/10 03:09:25 DEBUG : FiLeA: >OpenFile: fd=FiLeA (r), err= 2026/03/10 03:09:25 DEBUG : FiLeA: ChunkedReader.openRange at 0 length 134217728 2026/03/10 03:09:26 DEBUG : FiLeA: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2026/03/10 03:09:26 DEBUG : FiLeB: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:26 DEBUG : FiLeB: Open: flags=O_RDONLY 2026/03/10 03:09:26 DEBUG : FiLeB: >Open: fd=FiLeB (r), err= 2026/03/10 03:09:26 DEBUG : FiLeB: >OpenFile: fd=FiLeB (r), err= 2026/03/10 03:09:26 DEBUG : FiLeB: ChunkedReader.openRange at 0 length 134217728 2026/03/10 03:09:26 DEBUG : FiLeB: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2026/03/10 03:09:26 DEBUG : FilEb: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:26 DEBUG : FilEb: Open: flags=O_RDONLY 2026/03/10 03:09:26 DEBUG : FilEb: >Open: fd=FilEb (r), err= 2026/03/10 03:09:26 DEBUG : FilEb: >OpenFile: fd=FilEb (r), err= 2026/03/10 03:09:26 DEBUG : FilEb: ChunkedReader.openRange at 0 length 134217728 2026/03/10 03:09:27 DEBUG : FilEb: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2026/03/10 03:09:27 DEBUG : FiLeA: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:27 DEBUG : FiLeA: Open: flags=O_RDONLY 2026/03/10 03:09:27 DEBUG : FiLeA: >Open: fd=FiLeA (r), err= 2026/03/10 03:09:27 DEBUG : FiLeA: >OpenFile: fd=FiLeA (r), err= 2026/03/10 03:09:27 DEBUG : FiLeA: ChunkedReader.openRange at 0 length 134217728 2026/03/10 03:09:27 DEBUG : FiLeA: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2026/03/10 03:09:27 DEBUG : fileA: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:27 DEBUG : FiLeA: Open: flags=O_RDONLY 2026/03/10 03:09:27 DEBUG : FiLeA: >Open: fd=FiLeA (r), err= 2026/03/10 03:09:27 DEBUG : fileA: >OpenFile: fd=FiLeA (r), err= 2026/03/10 03:09:27 DEBUG : FiLeA: ChunkedReader.openRange at 0 length 134217728 2026/03/10 03:09:28 DEBUG : FiLeA: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2026/03/10 03:09:28 DEBUG : filea: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:28 DEBUG : FiLeA: Open: flags=O_RDONLY 2026/03/10 03:09:28 DEBUG : FiLeA: >Open: fd=FiLeA (r), err= 2026/03/10 03:09:28 DEBUG : filea: >OpenFile: fd=FiLeA (r), err= 2026/03/10 03:09:28 DEBUG : FiLeA: ChunkedReader.openRange at 0 length 134217728 2026/03/10 03:09:28 DEBUG : FiLeA: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2026/03/10 03:09:28 DEBUG : FILEA: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:28 DEBUG : FiLeA: Open: flags=O_RDONLY 2026/03/10 03:09:28 DEBUG : FiLeA: >Open: fd=FiLeA (r), err= 2026/03/10 03:09:28 DEBUG : FILEA: >OpenFile: fd=FiLeA (r), err= 2026/03/10 03:09:28 DEBUG : FiLeA: ChunkedReader.openRange at 0 length 134217728 2026/03/10 03:09:28 DEBUG : FiLeA: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2026/03/10 03:09:28 DEBUG : FiLeB: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:28 DEBUG : FiLeB: Open: flags=O_RDONLY 2026/03/10 03:09:28 DEBUG : FiLeB: >Open: fd=FiLeB (r), err= 2026/03/10 03:09:28 DEBUG : FiLeB: >OpenFile: fd=FiLeB (r), err= 2026/03/10 03:09:28 DEBUG : FiLeB: ChunkedReader.openRange at 0 length 134217728 2026/03/10 03:09:29 DEBUG : FiLeB: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2026/03/10 03:09:29 DEBUG : FilEb: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:29 DEBUG : FilEb: Open: flags=O_RDONLY 2026/03/10 03:09:29 DEBUG : FilEb: >Open: fd=FilEb (r), err= 2026/03/10 03:09:29 DEBUG : FilEb: >OpenFile: fd=FilEb (r), err= 2026/03/10 03:09:29 DEBUG : FilEb: ChunkedReader.openRange at 0 length 134217728 2026/03/10 03:09:29 DEBUG : FilEb: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2026/03/10 03:09:29 DEBUG : fileb: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:29 ERROR : /: Dir.Stat error: duplicate filename "fileb" detected with case/unicode normalization settings 2026/03/10 03:09:29 DEBUG : fileb: >OpenFile: fd=, err=duplicate filename "fileb" detected with case/unicode normalization settings 2026/03/10 03:09:29 DEBUG : FILEB: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:29 ERROR : /: Dir.Stat error: duplicate filename "FILEB" detected with case/unicode normalization settings 2026/03/10 03:09:29 DEBUG : FILEB: >OpenFile: fd=, err=duplicate filename "FILEB" detected with case/unicode normalization settings 2026/03/10 03:09:29 DEBUG : FiLeA: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:29 DEBUG : FiLeA: Open: flags=O_RDONLY 2026/03/10 03:09:29 DEBUG : FiLeA: >Open: fd=FiLeA (r), err= 2026/03/10 03:09:29 DEBUG : FiLeA: >OpenFile: fd=FiLeA (r), err= 2026/03/10 03:09:29 DEBUG : FiLeA: ChunkedReader.openRange at 0 length 134217728 2026/03/10 03:09:29 DEBUG : FiLeA: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2026/03/10 03:09:29 DEBUG : fileA: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:29 DEBUG : fileA: >OpenFile: fd=, err=file does not exist 2026/03/10 03:09:29 DEBUG : filea: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:29 DEBUG : filea: >OpenFile: fd=, err=file does not exist 2026/03/10 03:09:29 DEBUG : FILEA: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:29 DEBUG : FILEA: >OpenFile: fd=, err=file does not exist 2026/03/10 03:09:29 DEBUG : FiLeB: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:29 DEBUG : FiLeB: Open: flags=O_RDONLY 2026/03/10 03:09:29 DEBUG : FiLeB: >Open: fd=FiLeB (r), err= 2026/03/10 03:09:29 DEBUG : FiLeB: >OpenFile: fd=FiLeB (r), err= 2026/03/10 03:09:29 DEBUG : FiLeB: ChunkedReader.openRange at 0 length 134217728 2026/03/10 03:09:30 DEBUG : FiLeB: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2026/03/10 03:09:30 DEBUG : FilEb: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:30 DEBUG : FilEb: Open: flags=O_RDONLY 2026/03/10 03:09:30 DEBUG : FilEb: >Open: fd=FilEb (r), err= 2026/03/10 03:09:30 DEBUG : FilEb: >OpenFile: fd=FilEb (r), err= 2026/03/10 03:09:30 DEBUG : FilEb: ChunkedReader.openRange at 0 length 134217728 2026/03/10 03:09:30 DEBUG : FilEb: ChunkedReader.Read at 0 length 5 chunkOffset 0 chunkSize 134217728 2026/03/10 03:09:30 DEBUG : fileb: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:30 DEBUG : fileb: >OpenFile: fd=, err=file does not exist 2026/03/10 03:09:30 DEBUG : FILEB: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/03/10 03:09:30 DEBUG : FILEB: >OpenFile: fd=, err=file does not exist 2026/03/10 03:09:30 DEBUG : WaitForWriters: timeout=30s 2026/03/10 03:09:30 DEBUG : Looking for writers 2026/03/10 03:09:30 DEBUG : FiLeB: reading active writers 2026/03/10 03:09:30 DEBUG : FilEb: reading active writers 2026/03/10 03:09:30 DEBUG : FiLeA: reading active writers 2026/03/10 03:09:30 DEBUG : >WaitForWriters: 2026/03/10 03:09:30 DEBUG : WaitForWriters: timeout=30s 2026/03/10 03:09:30 DEBUG : Looking for writers 2026/03/10 03:09:30 DEBUG : FiLeA: reading active writers 2026/03/10 03:09:30 DEBUG : FiLeB: reading active writers 2026/03/10 03:09:30 DEBUG : FilEb: reading active writers 2026/03/10 03:09:30 DEBUG : >WaitForWriters: --- PASS: TestCaseSensitivity (9.30s) === RUN TestWriteFileHandleMethods run.go:185: Remote "Internxt root 'rclone-test-petuhen9kipa'", Local "Local file system at /tmp/rclone3592506148", Modify Window "876000h0m0s" 2026/03/10 03:09:31 INFO : Internxt root 'rclone-test-petuhen9kipa': poll-interval is not supported by this remote 2026/03/10 03:09:31 NOTICE: Internxt root 'rclone-test-petuhen9kipa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/03/10 03:09:31 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/03/10 03:09:31 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2026/03/10 03:09:31 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 03:09:31 DEBUG : file1: >Open: fd=file1 (w), err= 2026/03/10 03:09:31 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2026/03/10 03:09:31 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 03:09:31 ERROR : file1: WriteFileHandle: Read: Can't read and write to file without --vfs-cache-mode >= minimal 2026/03/10 03:09:31 ERROR : file1: WriteFileHandle: ReadAt: Can't read and write to file without --vfs-cache-mode >= minimal 2026/03/10 03:09:31 ERROR : file1: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes 2026/03/10 03:09:31 DEBUG : Internxt root 'rclone-test-petuhen9kipa': File to upload is small (5 bytes), uploading instead of streaming 2026/03/10 03:09:32 DEBUG : file1: size = 5 OK 2026/03/10 03:09:32 NOTICE: Internxt root 'rclone-test-petuhen9kipa': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2026/03/10 03:09:32 DEBUG : file1: Size of src and dst objects identical 2026/03/10 03:09:32 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 03:09:32 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/03/10 03:09:32 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2026/03/10 03:09:32 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 03:09:32 DEBUG : file1: >Open: fd=file1 (w), err= 2026/03/10 03:09:32 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2026/03/10 03:09:32 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/03/10 03:09:32 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2026/03/10 03:09:32 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 03:09:32 DEBUG : file1: >Open: fd=file1 (w), err= 2026/03/10 03:09:32 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2026/03/10 03:09:32 ERROR : file1: WriteFileHandle: Can't open for write without O_TRUNC on existing file without --vfs-cache-mode >= writes 2026/03/10 03:09:32 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx 2026/03/10 03:09:32 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE|O_TRUNC 2026/03/10 03:09:32 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 03:09:32 DEBUG : file1: >Open: fd=file1 (w), err= 2026/03/10 03:09:32 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2026/03/10 03:09:32 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 03:09:32 DEBUG : Internxt root 'rclone-test-petuhen9kipa': File to upload is small (0 bytes), uploading instead of streaming 2026/03/10 03:09:32 DEBUG : Internxt root 'rclone-test-petuhen9kipa': Renamed existing file file1 to backup file1.rclone-backup-colijuh3. (UUID: 4f5a62ba-cdc5-4ee7-afe4-ea638ef71af4) 2026/03/10 03:09:33 ERROR : file1: WriteFileHandle.New Rcat failed: failed to create empty file metadata: create meta: File already exists (status 409) write_test.go:181: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:181 Error: Received unexpected error: failed to create empty file metadata: create meta: File already exists (status 409) Test: TestWriteFileHandleMethods dir_test.go:250: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:250 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:182 Error: Not equal: expected: []string{"file1,0,false"} actual : []string{"file1,5,false"} Diff: --- Expected +++ Actual @@ -1,3 +1,3 @@ ([]string) (len=1) { - (string) (len=13) "file1,0,false" + (string) (len=13) "file1,5,false" } Test: TestWriteFileHandleMethods 2026/03/10 03:09:33 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx 2026/03/10 03:09:33 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE|O_TRUNC 2026/03/10 03:09:33 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 03:09:33 DEBUG : file1: >Open: fd=file1 (w), err= 2026/03/10 03:09:33 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2026/03/10 03:09:33 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 03:09:33 DEBUG : Internxt root 'rclone-test-petuhen9kipa': File to upload is small (7 bytes), uploading instead of streaming 2026/03/10 03:09:33 DEBUG : Internxt root 'rclone-test-petuhen9kipa': Renamed existing file file1 to backup file1.rclone-backup-tibimet9. (UUID: 4f5a62ba-cdc5-4ee7-afe4-ea638ef71af4) 2026/03/10 03:09:34 DEBUG : Internxt root 'rclone-test-petuhen9kipa': Upload succeeded, deleting backup file file1.rclone-backup-tibimet9. (UUID: 4f5a62ba-cdc5-4ee7-afe4-ea638ef71af4) 2026/03/10 03:09:34 DEBUG : Internxt root 'rclone-test-petuhen9kipa': Successfully deleted backup file 2026/03/10 03:09:34 DEBUG : file1: size = 7 OK 2026/03/10 03:09:34 DEBUG : file1: Size of src and dst objects identical 2026/03/10 03:09:34 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 03:09:34 DEBUG : WaitForWriters: timeout=30s 2026/03/10 03:09:34 DEBUG : Looking for writers 2026/03/10 03:09:34 DEBUG : file1: reading active writers 2026/03/10 03:09:34 DEBUG : >WaitForWriters: run.go:130: removing file "file1.rclone-backup-tibimet9" failed - try 1/5: delete file: File not found (status 404) run.go:130: removing file "file1.rclone-backup-tibimet9" failed - try 2/5: delete file: File not found (status 404) run.go:130: removing file "file1.rclone-backup-tibimet9" failed - try 3/5: delete file: File not found (status 404) run.go:130: removing file "file1.rclone-backup-tibimet9" failed - try 4/5: delete file: File not found (status 404) run.go:130: removing file "file1.rclone-backup-tibimet9" failed - try 5/5: delete file: File not found (status 404) run.go:133: removing file "file1.rclone-backup-tibimet9" failed: delete file: File not found (status 404) --- FAIL: TestWriteFileHandleMethods (8.88s) === RUN TestWriteFileHandleFlush run.go:185: Remote "Internxt root 'rclone-test-petuhen9kipa'", Local "Local file system at /tmp/rclone3592506148", Modify Window "876000h0m0s" 2026/03/10 03:09:40 INFO : Internxt root 'rclone-test-petuhen9kipa': poll-interval is not supported by this remote 2026/03/10 03:09:40 NOTICE: Internxt root 'rclone-test-petuhen9kipa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/03/10 03:09:40 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/03/10 03:09:40 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2026/03/10 03:09:40 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 03:09:40 DEBUG : file1: >Open: fd=file1 (w), err= 2026/03/10 03:09:40 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2026/03/10 03:09:40 DEBUG : file1: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions 2026/03/10 03:09:40 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 03:09:40 DEBUG : Internxt root 'rclone-test-petuhen9kipa': File to upload is small (5 bytes), uploading instead of streaming 2026/03/10 03:09:41 DEBUG : file1: size = 5 OK 2026/03/10 03:09:41 DEBUG : file1: Size of src and dst objects identical 2026/03/10 03:09:41 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 03:09:41 DEBUG : file1: WriteFileHandle.Flush nothing to do 2026/03/10 03:09:41 DEBUG : WaitForWriters: timeout=30s 2026/03/10 03:09:41 DEBUG : Looking for writers 2026/03/10 03:09:41 DEBUG : file1: reading active writers 2026/03/10 03:09:41 DEBUG : >WaitForWriters: --- PASS: TestWriteFileHandleFlush (1.93s) === RUN TestWriteFileModTimeWithOpenWriters run.go:185: Remote "Internxt root 'rclone-test-petuhen9kipa'", Local "Local file system at /tmp/rclone3592506148", Modify Window "876000h0m0s" 2026/03/10 03:09:42 INFO : Internxt root 'rclone-test-petuhen9kipa': poll-interval is not supported by this remote 2026/03/10 03:09:42 NOTICE: Internxt root 'rclone-test-petuhen9kipa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/03/10 03:09:42 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/03/10 03:09:42 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2026/03/10 03:09:42 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 03:09:42 DEBUG : file1: >Open: fd=file1 (w), err= 2026/03/10 03:09:42 DEBUG : file1: >OpenFile: fd=file1 (w), err= write_test.go:321: can't set mod time 2026/03/10 03:09:42 DEBUG : WaitForWriters: timeout=30s 2026/03/10 03:09:42 DEBUG : Looking for writers 2026/03/10 03:09:42 DEBUG : file1: reading active writers 2026/03/10 03:09:42 DEBUG : file1: active writers 1 2026/03/10 03:09:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2026/03/10 03:09:42 DEBUG : Looking for writers 2026/03/10 03:09:42 DEBUG : file1: reading active writers 2026/03/10 03:09:42 DEBUG : file1: active writers 1 2026/03/10 03:09:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2026/03/10 03:09:42 DEBUG : Looking for writers 2026/03/10 03:09:42 DEBUG : file1: reading active writers 2026/03/10 03:09:42 DEBUG : file1: active writers 1 2026/03/10 03:09:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2026/03/10 03:09:42 DEBUG : Looking for writers 2026/03/10 03:09:42 DEBUG : file1: reading active writers 2026/03/10 03:09:42 DEBUG : file1: active writers 1 2026/03/10 03:09:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2026/03/10 03:09:42 DEBUG : Looking for writers 2026/03/10 03:09:42 DEBUG : file1: reading active writers 2026/03/10 03:09:42 DEBUG : file1: active writers 1 2026/03/10 03:09:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2026/03/10 03:09:42 DEBUG : Looking for writers 2026/03/10 03:09:42 DEBUG : file1: reading active writers 2026/03/10 03:09:42 DEBUG : file1: active writers 1 2026/03/10 03:09:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2026/03/10 03:09:43 DEBUG : Looking for writers 2026/03/10 03:09:43 DEBUG : file1: reading active writers 2026/03/10 03:09:43 DEBUG : file1: active writers 1 2026/03/10 03:09:43 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2026/03/10 03:09:43 DEBUG : Looking for writers 2026/03/10 03:09:43 DEBUG : file1: reading active writers 2026/03/10 03:09:43 DEBUG : file1: active writers 1 2026/03/10 03:09:43 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:09:44 DEBUG : Looking for writers 2026/03/10 03:09:44 DEBUG : file1: reading active writers 2026/03/10 03:09:44 DEBUG : file1: active writers 1 2026/03/10 03:09:44 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:09:45 DEBUG : Looking for writers 2026/03/10 03:09:45 DEBUG : file1: reading active writers 2026/03/10 03:09:45 DEBUG : file1: active writers 1 2026/03/10 03:09:45 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:09:46 DEBUG : Looking for writers 2026/03/10 03:09:46 DEBUG : file1: reading active writers 2026/03/10 03:09:46 DEBUG : file1: active writers 1 2026/03/10 03:09:46 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:09:47 DEBUG : Looking for writers 2026/03/10 03:09:47 DEBUG : file1: reading active writers 2026/03/10 03:09:47 DEBUG : file1: active writers 1 2026/03/10 03:09:47 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:09:48 DEBUG : Looking for writers 2026/03/10 03:09:48 DEBUG : file1: reading active writers 2026/03/10 03:09:48 DEBUG : file1: active writers 1 2026/03/10 03:09:48 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:09:49 DEBUG : Looking for writers 2026/03/10 03:09:49 DEBUG : file1: reading active writers 2026/03/10 03:09:49 DEBUG : file1: active writers 1 2026/03/10 03:09:49 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:09:50 DEBUG : Looking for writers 2026/03/10 03:09:50 DEBUG : file1: reading active writers 2026/03/10 03:09:50 DEBUG : file1: active writers 1 2026/03/10 03:09:50 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:09:51 DEBUG : Looking for writers 2026/03/10 03:09:51 DEBUG : file1: reading active writers 2026/03/10 03:09:51 DEBUG : file1: active writers 1 2026/03/10 03:09:51 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:09:52 DEBUG : Looking for writers 2026/03/10 03:09:52 DEBUG : file1: reading active writers 2026/03/10 03:09:52 DEBUG : file1: active writers 1 2026/03/10 03:09:52 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:09:53 DEBUG : Looking for writers 2026/03/10 03:09:53 DEBUG : file1: reading active writers 2026/03/10 03:09:53 DEBUG : file1: active writers 1 2026/03/10 03:09:53 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:09:54 DEBUG : Looking for writers 2026/03/10 03:09:54 DEBUG : file1: reading active writers 2026/03/10 03:09:54 DEBUG : file1: active writers 1 2026/03/10 03:09:54 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:09:55 DEBUG : Looking for writers 2026/03/10 03:09:55 DEBUG : file1: reading active writers 2026/03/10 03:09:55 DEBUG : file1: active writers 1 2026/03/10 03:09:55 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:09:56 DEBUG : Looking for writers 2026/03/10 03:09:56 DEBUG : file1: reading active writers 2026/03/10 03:09:56 DEBUG : file1: active writers 1 2026/03/10 03:09:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:09:57 DEBUG : Looking for writers 2026/03/10 03:09:57 DEBUG : file1: reading active writers 2026/03/10 03:09:57 DEBUG : file1: active writers 1 2026/03/10 03:09:57 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:09:58 DEBUG : Looking for writers 2026/03/10 03:09:58 DEBUG : file1: reading active writers 2026/03/10 03:09:58 DEBUG : file1: active writers 1 2026/03/10 03:09:58 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:09:59 DEBUG : Looking for writers 2026/03/10 03:09:59 DEBUG : file1: reading active writers 2026/03/10 03:09:59 DEBUG : file1: active writers 1 2026/03/10 03:09:59 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:10:00 DEBUG : Looking for writers 2026/03/10 03:10:00 DEBUG : file1: reading active writers 2026/03/10 03:10:00 DEBUG : file1: active writers 1 2026/03/10 03:10:00 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:10:01 DEBUG : Looking for writers 2026/03/10 03:10:01 DEBUG : file1: reading active writers 2026/03/10 03:10:01 DEBUG : file1: active writers 1 2026/03/10 03:10:01 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:10:02 DEBUG : Looking for writers 2026/03/10 03:10:02 DEBUG : file1: reading active writers 2026/03/10 03:10:02 DEBUG : file1: active writers 1 2026/03/10 03:10:02 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:10:03 DEBUG : Looking for writers 2026/03/10 03:10:03 DEBUG : file1: reading active writers 2026/03/10 03:10:03 DEBUG : file1: active writers 1 2026/03/10 03:10:03 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:10:04 DEBUG : Looking for writers 2026/03/10 03:10:04 DEBUG : file1: reading active writers 2026/03/10 03:10:04 DEBUG : file1: active writers 1 2026/03/10 03:10:04 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:10:05 DEBUG : Looking for writers 2026/03/10 03:10:05 DEBUG : file1: reading active writers 2026/03/10 03:10:05 DEBUG : file1: active writers 1 2026/03/10 03:10:05 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:10:06 DEBUG : Looking for writers 2026/03/10 03:10:06 DEBUG : file1: reading active writers 2026/03/10 03:10:06 DEBUG : file1: active writers 1 2026/03/10 03:10:06 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:10:07 DEBUG : Looking for writers 2026/03/10 03:10:07 DEBUG : file1: reading active writers 2026/03/10 03:10:07 DEBUG : file1: active writers 1 2026/03/10 03:10:07 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:10:08 DEBUG : Looking for writers 2026/03/10 03:10:08 DEBUG : file1: reading active writers 2026/03/10 03:10:08 DEBUG : file1: active writers 1 2026/03/10 03:10:08 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:10:09 DEBUG : Looking for writers 2026/03/10 03:10:09 DEBUG : file1: reading active writers 2026/03/10 03:10:09 DEBUG : file1: active writers 1 2026/03/10 03:10:09 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:10:10 DEBUG : Looking for writers 2026/03/10 03:10:10 DEBUG : file1: reading active writers 2026/03/10 03:10:10 DEBUG : file1: active writers 1 2026/03/10 03:10:10 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:10:11 DEBUG : Looking for writers 2026/03/10 03:10:11 DEBUG : file1: reading active writers 2026/03/10 03:10:11 DEBUG : file1: active writers 1 2026/03/10 03:10:11 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/03/10 03:10:12 ERROR : Exiting even though 1 writers active and 0 cache items in use after 30s Cache: 2026/03/10 03:10:12 DEBUG : >WaitForWriters: --- SKIP: TestWriteFileModTimeWithOpenWriters (30.60s) === RUN TestFileReadAtZeroLength run.go:185: Remote "Internxt root 'rclone-test-petuhen9kipa'", Local "Local file system at /tmp/rclone3592506148", Modify Window "876000h0m0s" 2026/03/10 03:10:12 INFO : Internxt root 'rclone-test-petuhen9kipa': poll-interval is not supported by this remote 2026/03/10 03:10:12 NOTICE: Internxt root 'rclone-test-petuhen9kipa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/03/10 03:10:12 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/03/10 03:10:13 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2026/03/10 03:10:13 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 03:10:13 DEBUG : file1: >Open: fd=file1 (w), err= 2026/03/10 03:10:13 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2026/03/10 03:10:13 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 03:10:13 DEBUG : Internxt root 'rclone-test-petuhen9kipa': File to upload is small (0 bytes), uploading instead of streaming 2026/03/10 03:10:18 DEBUG : file1: size = 0 OK 2026/03/10 03:10:18 DEBUG : file1: Size of src and dst objects identical 2026/03/10 03:10:18 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/03/10 03:10:18 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2026/03/10 03:10:18 DEBUG : file1: Open: flags=O_RDONLY 2026/03/10 03:10:18 DEBUG : file1: >Open: fd=file1 (r), err= 2026/03/10 03:10:18 DEBUG : file1: >OpenFile: fd=file1 (r), err= 2026/03/10 03:10:18 DEBUG : file1: ChunkedReader.openRange at 0 length 134217728 2026/03/10 03:10:18 DEBUG : file1: ChunkedReader.Read at 0 length 1024 chunkOffset 0 chunkSize 134217728 2026/03/10 03:10:18 DEBUG : WaitForWriters: timeout=30s 2026/03/10 03:10:18 DEBUG : Looking for writers 2026/03/10 03:10:18 DEBUG : file1: reading active writers 2026/03/10 03:10:18 DEBUG : >WaitForWriters: --- PASS: TestFileReadAtZeroLength (6.46s) FAIL 2026/03/10 03:10:19 DEBUG : Internxt root 'rclone-test-petuhen9kipa': Purge dir "" "./vfs.test -test.v -test.timeout 1h0m0s -remote TestInternxt: -list-retries 5 -verbose -test.run '^(TestCaseSensitivity|TestFileReadAtZeroLength|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileModTimeWithOpenWriters)$|^TestFileSetModTime$/^(cache=off,open=false,write=false|cache=off,open=true,write=false)$'" - Finished ERROR in 1m11.053908026s (try 2/5): exit status 1: Failed [TestWriteFileHandleMethods]