"./vfs.test -test.v -test.timeout 2h0m0s -remote TestInternxt: -list-retries 5 -verbose -test.run '^(TestFileReadAtNonZeroLength|TestFileReadAtZeroLength)$'" - Starting (try 3/5) 2026/09/25 01:58:04 DEBUG : Creating backend with remote "TestInternxt:rclone-test-zicayaj8xeka" 2026/09/25 01:58:04 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/09/25 01:58:04 DEBUG : User info: rootFolderId=2661cf64-e104-478b-b737-48c3ac8984d2, bucket=697358bf16ceabcf39af85f2 2026/09/25 01:58:04 DEBUG : Saving config "token" in section "TestInternxt" of the config file 2026/09/25 01:58:04 DEBUG : TestInternxt: Saved new token in config file 2026/09/25 01:58:04 DEBUG : Internxt root 'rclone-test-zicayaj8xeka': Persisted rotated token from user info, expiry: 2026-10-02 01:58:04 +0000 UTC 2026/09/25 01:58:04 DEBUG : Creating backend with remote "/tmp/rclone213707432" === RUN TestFileReadAtZeroLength run.go:198: Remote "Internxt root 'rclone-test-zicayaj8xeka'", Local "Local file system at /tmp/rclone213707432", Modify Window "876000h0m0s" 2026/09/25 01:58:04 INFO : Internxt root 'rclone-test-zicayaj8xeka': poll-interval is not supported by this remote 2026/09/25 01:58:04 NOTICE: Internxt root 'rclone-test-zicayaj8xeka': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/09/25 01:58:04 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/09/25 01:58:05 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2026/09/25 01:58:05 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/09/25 01:58:05 DEBUG : file1: >Open: fd=file1 (w), err= 2026/09/25 01:58:05 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2026/09/25 01:58:05 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/09/25 01:58:05 DEBUG : Internxt root 'rclone-test-zicayaj8xeka': File to upload is small (0 bytes), uploading instead of streaming 2026/09/25 01:58:06 DEBUG : file1: size = 0 OK 2026/09/25 01:58:06 NOTICE: Internxt root 'rclone-test-zicayaj8xeka': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2026/09/25 01:58:06 DEBUG : file1: Size of src and dst objects identical 2026/09/25 01:58:06 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/09/25 01:58:06 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2026/09/25 01:58:06 DEBUG : file1: Open: flags=O_RDONLY 2026/09/25 01:58:06 DEBUG : file1: >Open: fd=file1 (r), err= 2026/09/25 01:58:06 DEBUG : file1: >OpenFile: fd=file1 (r), err= 2026/09/25 01:58:06 DEBUG : file1: ChunkedReader.openRange at 0 length 134217728 2026/09/25 01:58:06 DEBUG : file1: ChunkedReader.Read at 0 length 1024 chunkOffset 0 chunkSize 134217728 2026/09/25 01:58:06 DEBUG : WaitForWriters: timeout=30s 2026/09/25 01:58:06 DEBUG : Looking for writers 2026/09/25 01:58:06 DEBUG : file1: reading active writers 2026/09/25 01:58:06 DEBUG : >WaitForWriters: fstest.go:299: Sleeping for 1s for list eventual consistency: 1/5 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/5 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/5 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 8s for list eventual consistency: 4/5 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 16s for list eventual consistency: 5/5 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:306 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:339 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:191 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:406 /usr/local/go/src/testing/testing.go:1460 /usr/local/go/src/testing/testing.go:1820 /usr/local/go/src/testing/testing.go:2187 Error: Should be true Test: TestFileReadAtZeroLength Messages: listing wrong, want got file1 (0) fstest.go:192: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:192 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:309 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:339 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:191 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:406 /usr/local/go/src/testing/testing.go:1460 /usr/local/go/src/testing/testing.go:1820 /usr/local/go/src/testing/testing.go:2187 Error: Should be true Test: TestFileReadAtZeroLength Messages: Unexpected file "file1" --- FAIL: TestFileReadAtZeroLength (37.39s) === RUN TestFileReadAtNonZeroLength run.go:198: Remote "Internxt root 'rclone-test-zicayaj8xeka'", Local "Local file system at /tmp/rclone213707432", Modify Window "876000h0m0s" 2026/09/25 01:58:42 INFO : Internxt root 'rclone-test-zicayaj8xeka': poll-interval is not supported by this remote 2026/09/25 01:58:42 NOTICE: Internxt root 'rclone-test-zicayaj8xeka': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2026/09/25 01:58:42 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/09/25 01:58:42 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2026/09/25 01:58:42 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/09/25 01:58:42 DEBUG : file1: >Open: fd=file1 (w), err= 2026/09/25 01:58:42 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2026/09/25 01:58:42 ERROR : file1: WriteFileHandle: Can't open for write without O_TRUNC on existing file without --vfs-cache-mode >= writes write_test.go:392: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:392 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:426 Error: Received unexpected error: permission denied Test: TestFileReadAtNonZeroLength 2026/09/25 01:58:42 DEBUG : WaitForWriters: timeout=30s 2026/09/25 01:58:42 DEBUG : Looking for writers 2026/09/25 01:58:42 DEBUG : file1: reading active writers 2026/09/25 01:58:42 DEBUG : file1: active writers 1 2026/09/25 01:58:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2026/09/25 01:58:42 DEBUG : Looking for writers 2026/09/25 01:58:42 DEBUG : file1: reading active writers 2026/09/25 01:58:42 DEBUG : file1: active writers 1 2026/09/25 01:58:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2026/09/25 01:58:42 DEBUG : Looking for writers 2026/09/25 01:58:42 DEBUG : file1: reading active writers 2026/09/25 01:58:42 DEBUG : file1: active writers 1 2026/09/25 01:58:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2026/09/25 01:58:42 DEBUG : Looking for writers 2026/09/25 01:58:42 DEBUG : file1: reading active writers 2026/09/25 01:58:42 DEBUG : file1: active writers 1 2026/09/25 01:58:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2026/09/25 01:58:42 DEBUG : Looking for writers 2026/09/25 01:58:42 DEBUG : file1: reading active writers 2026/09/25 01:58:42 DEBUG : file1: active writers 1 2026/09/25 01:58:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2026/09/25 01:58:42 DEBUG : Looking for writers 2026/09/25 01:58:42 DEBUG : file1: reading active writers 2026/09/25 01:58:42 DEBUG : file1: active writers 1 2026/09/25 01:58:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2026/09/25 01:58:43 DEBUG : Looking for writers 2026/09/25 01:58:43 DEBUG : file1: reading active writers 2026/09/25 01:58:43 DEBUG : file1: active writers 1 2026/09/25 01:58:43 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2026/09/25 01:58:43 DEBUG : Looking for writers 2026/09/25 01:58:43 DEBUG : file1: reading active writers 2026/09/25 01:58:43 DEBUG : file1: active writers 1 2026/09/25 01:58:43 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:58:44 DEBUG : Looking for writers 2026/09/25 01:58:44 DEBUG : file1: reading active writers 2026/09/25 01:58:44 DEBUG : file1: active writers 1 2026/09/25 01:58:44 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:58:45 DEBUG : Looking for writers 2026/09/25 01:58:45 DEBUG : file1: reading active writers 2026/09/25 01:58:45 DEBUG : file1: active writers 1 2026/09/25 01:58:45 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:58:46 DEBUG : Looking for writers 2026/09/25 01:58:46 DEBUG : file1: reading active writers 2026/09/25 01:58:46 DEBUG : file1: active writers 1 2026/09/25 01:58:46 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:58:47 DEBUG : Looking for writers 2026/09/25 01:58:47 DEBUG : file1: reading active writers 2026/09/25 01:58:47 DEBUG : file1: active writers 1 2026/09/25 01:58:47 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:58:48 DEBUG : Looking for writers 2026/09/25 01:58:48 DEBUG : file1: reading active writers 2026/09/25 01:58:48 DEBUG : file1: active writers 1 2026/09/25 01:58:48 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:58:49 DEBUG : Looking for writers 2026/09/25 01:58:49 DEBUG : file1: reading active writers 2026/09/25 01:58:49 DEBUG : file1: active writers 1 2026/09/25 01:58:49 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:58:50 DEBUG : Looking for writers 2026/09/25 01:58:50 DEBUG : file1: reading active writers 2026/09/25 01:58:50 DEBUG : file1: active writers 1 2026/09/25 01:58:50 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:58:51 DEBUG : Looking for writers 2026/09/25 01:58:51 DEBUG : file1: reading active writers 2026/09/25 01:58:51 DEBUG : file1: active writers 1 2026/09/25 01:58:51 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:58:52 DEBUG : Looking for writers 2026/09/25 01:58:52 DEBUG : file1: reading active writers 2026/09/25 01:58:52 DEBUG : file1: active writers 1 2026/09/25 01:58:52 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:58:53 DEBUG : Looking for writers 2026/09/25 01:58:53 DEBUG : file1: reading active writers 2026/09/25 01:58:53 DEBUG : file1: active writers 1 2026/09/25 01:58:53 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:58:54 DEBUG : Looking for writers 2026/09/25 01:58:54 DEBUG : file1: reading active writers 2026/09/25 01:58:54 DEBUG : file1: active writers 1 2026/09/25 01:58:54 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:58:55 DEBUG : Looking for writers 2026/09/25 01:58:55 DEBUG : file1: reading active writers 2026/09/25 01:58:55 DEBUG : file1: active writers 1 2026/09/25 01:58:55 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:58:56 DEBUG : Looking for writers 2026/09/25 01:58:56 DEBUG : file1: reading active writers 2026/09/25 01:58:56 DEBUG : file1: active writers 1 2026/09/25 01:58:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:58:57 DEBUG : Looking for writers 2026/09/25 01:58:57 DEBUG : file1: reading active writers 2026/09/25 01:58:57 DEBUG : file1: active writers 1 2026/09/25 01:58:57 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:58:58 DEBUG : Looking for writers 2026/09/25 01:58:58 DEBUG : file1: reading active writers 2026/09/25 01:58:58 DEBUG : file1: active writers 1 2026/09/25 01:58:58 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:58:59 DEBUG : Looking for writers 2026/09/25 01:58:59 DEBUG : file1: reading active writers 2026/09/25 01:58:59 DEBUG : file1: active writers 1 2026/09/25 01:58:59 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:59:00 DEBUG : Looking for writers 2026/09/25 01:59:00 DEBUG : file1: reading active writers 2026/09/25 01:59:00 DEBUG : file1: active writers 1 2026/09/25 01:59:00 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:59:01 DEBUG : Looking for writers 2026/09/25 01:59:01 DEBUG : file1: reading active writers 2026/09/25 01:59:01 DEBUG : file1: active writers 1 2026/09/25 01:59:01 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:59:02 DEBUG : Looking for writers 2026/09/25 01:59:02 DEBUG : file1: reading active writers 2026/09/25 01:59:02 DEBUG : file1: active writers 1 2026/09/25 01:59:02 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:59:03 DEBUG : Looking for writers 2026/09/25 01:59:03 DEBUG : file1: reading active writers 2026/09/25 01:59:03 DEBUG : file1: active writers 1 2026/09/25 01:59:03 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:59:04 DEBUG : Looking for writers 2026/09/25 01:59:04 DEBUG : file1: reading active writers 2026/09/25 01:59:04 DEBUG : file1: active writers 1 2026/09/25 01:59:04 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:59:05 DEBUG : Looking for writers 2026/09/25 01:59:05 DEBUG : file1: reading active writers 2026/09/25 01:59:05 DEBUG : file1: active writers 1 2026/09/25 01:59:05 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:59:06 DEBUG : Looking for writers 2026/09/25 01:59:06 DEBUG : file1: reading active writers 2026/09/25 01:59:06 DEBUG : file1: active writers 1 2026/09/25 01:59:06 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:59:07 DEBUG : Looking for writers 2026/09/25 01:59:07 DEBUG : file1: reading active writers 2026/09/25 01:59:07 DEBUG : file1: active writers 1 2026/09/25 01:59:07 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:59:08 DEBUG : Looking for writers 2026/09/25 01:59:08 DEBUG : file1: reading active writers 2026/09/25 01:59:08 DEBUG : file1: active writers 1 2026/09/25 01:59:08 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:59:09 DEBUG : Looking for writers 2026/09/25 01:59:09 DEBUG : file1: reading active writers 2026/09/25 01:59:09 DEBUG : file1: active writers 1 2026/09/25 01:59:09 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:59:10 DEBUG : Looking for writers 2026/09/25 01:59:10 DEBUG : file1: reading active writers 2026/09/25 01:59:10 DEBUG : file1: active writers 1 2026/09/25 01:59:10 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:59:11 DEBUG : Looking for writers 2026/09/25 01:59:11 DEBUG : file1: reading active writers 2026/09/25 01:59:11 DEBUG : file1: active writers 1 2026/09/25 01:59:11 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2026/09/25 01:59:12 ERROR : Exiting even though 1 writers active and 0 cache items in use after 30s Cache: 2026/09/25 01:59:12 DEBUG : >WaitForWriters: --- FAIL: TestFileReadAtNonZeroLength (31.03s) FAIL 2026/09/25 01:59:13 DEBUG : Internxt root 'rclone-test-zicayaj8xeka': Purge dir "" "./vfs.test -test.v -test.timeout 2h0m0s -remote TestInternxt: -list-retries 5 -verbose -test.run '^(TestFileReadAtNonZeroLength|TestFileReadAtZeroLength)$'" - Finished ERROR in 1m9.841127196s (try 3/5): exit status 1: Failed [TestFileReadAtZeroLength TestFileReadAtNonZeroLength]