"./vfs.test -test.v -test.timeout 2h0m0s -remote TestInternxt: -list-retries 5 -verbose -test.run '^(TestFileReadAtNonZeroLength|TestFileReadAtZeroLength|TestWriteFileHandleRelease|TestWriteFileModTimeWithOpenWriters)$|^TestFileSetModTime$/^(cache=off,open=false,write=false|cache=off,open=true,write=false)$'" - Starting (try 2/5)
2026/09/25 01:56:13 DEBUG : Creating backend with remote "TestInternxt:rclone-test-tukifup1gune"
2026/09/25 01:56:13 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/09/25 01:56:16 DEBUG : User info: rootFolderId=2661cf64-e104-478b-b737-48c3ac8984d2, bucket=697358bf16ceabcf39af85f2
2026/09/25 01:56:16 DEBUG : Saving config "token" in section "TestInternxt" of the config file
2026/09/25 01:56:16 DEBUG : TestInternxt: Saved new token in config file
2026/09/25 01:56:16 DEBUG : Internxt root 'rclone-test-tukifup1gune': Persisted rotated token from user info, expiry: 2026-10-02 01:56:16 +0000 UTC
2026/09/25 01:56:16 DEBUG : Creating backend with remote "/tmp/rclone2916188698"
=== RUN   TestFileSetModTime
=== RUN   TestFileSetModTime/cache=off,open=false,write=false
    run.go:198: Remote "Internxt root 'rclone-test-tukifup1gune'", Local "Local file system at /tmp/rclone2916188698", Modify Window "876000h0m0s"
2026/09/25 01:56:16 INFO  : Internxt root 'rclone-test-tukifup1gune': poll-interval is not supported by this remote
2026/09/25 01:56:16 NOTICE: Internxt root 'rclone-test-tukifup1gune': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
FileLimitsResponse {
  "maxUploadFileSize": 107374182400,
  "versioning": {
    "enabled": true,
    "maxFileSize": 20971520,
    "retentionDays": 30,
    "maxVersions": 20
  }
}
2026/09/25 01:56:23 DEBUG : Can set mod time: false
    file_test.go:97: can't set mod time
2026/09/25 01:56:23 DEBUG : WaitForWriters: timeout=30s
2026/09/25 01:56:23 DEBUG : dir: Looking for writers
2026/09/25 01:56:23 DEBUG : file1: reading active writers
2026/09/25 01:56:23 DEBUG : Looking for writers
2026/09/25 01:56:23 DEBUG : dir: reading active writers
2026/09/25 01:56:23 DEBUG : >WaitForWriters: 
=== RUN   TestFileSetModTime/cache=off,open=true,write=false
    file_test.go:93: can't set mod time
--- PASS: TestFileSetModTime (7.84s)
    --- SKIP: TestFileSetModTime/cache=off,open=false,write=false (7.84s)
    --- SKIP: TestFileSetModTime/cache=off,open=true,write=false (0.00s)
=== RUN   TestWriteFileHandleRelease
    run.go:198: Remote "Internxt root 'rclone-test-tukifup1gune'", Local "Local file system at /tmp/rclone2916188698", Modify Window "876000h0m0s"
2026/09/25 01:56:24 INFO  : Internxt root 'rclone-test-tukifup1gune': poll-interval is not supported by this remote
2026/09/25 01:56:24 NOTICE: Internxt root 'rclone-test-tukifup1gune': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/09/25 01:56:24 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2026/09/25 01:56:25 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2026/09/25 01:56:25 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/09/25 01:56:25 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2026/09/25 01:56:25 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2026/09/25 01:56:25 DEBUG : file1: WriteFileHandle.Release closing
2026/09/25 01:56:25 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/09/25 01:56:25 DEBUG : Internxt root 'rclone-test-tukifup1gune': File to upload is small (0 bytes), uploading instead of streaming
2026/09/25 01:56:25 DEBUG : file1: size = 0 OK
2026/09/25 01:56:25 NOTICE: Internxt root 'rclone-test-tukifup1gune': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2026/09/25 01:56:25 DEBUG : file1: Size of src and dst objects identical
2026/09/25 01:56:25 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/09/25 01:56:25 DEBUG : file1: WriteFileHandle.Release nothing to do
2026/09/25 01:56:25 DEBUG : WaitForWriters: timeout=30s
2026/09/25 01:56:25 DEBUG : Looking for writers
2026/09/25 01:56:25 DEBUG : file1: reading active writers
2026/09/25 01:56:25 DEBUG : >WaitForWriters: 
--- PASS: TestWriteFileHandleRelease (2.65s)
=== RUN   TestWriteFileModTimeWithOpenWriters
    run.go:198: Remote "Internxt root 'rclone-test-tukifup1gune'", Local "Local file system at /tmp/rclone2916188698", Modify Window "876000h0m0s"
2026/09/25 01:56:27 INFO  : Internxt root 'rclone-test-tukifup1gune': poll-interval is not supported by this remote
2026/09/25 01:56:27 NOTICE: Internxt root 'rclone-test-tukifup1gune': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/09/25 01:56:27 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2026/09/25 01:56:27 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2026/09/25 01:56:27 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/09/25 01:56:27 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2026/09/25 01:56:27 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
    write_test.go:363: can't set mod time
2026/09/25 01:56:27 DEBUG : WaitForWriters: timeout=30s
2026/09/25 01:56:27 DEBUG : Looking for writers
2026/09/25 01:56:27 DEBUG : file1: reading active writers
2026/09/25 01:56:27 DEBUG : file1: active writers 1
2026/09/25 01:56:27 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms
2026/09/25 01:56:28 DEBUG : Looking for writers
2026/09/25 01:56:28 DEBUG : file1: reading active writers
2026/09/25 01:56:28 DEBUG : file1: active writers 1
2026/09/25 01:56:28 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms
2026/09/25 01:56:28 DEBUG : Looking for writers
2026/09/25 01:56:28 DEBUG : file1: reading active writers
2026/09/25 01:56:28 DEBUG : file1: active writers 1
2026/09/25 01:56:28 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms
2026/09/25 01:56:28 DEBUG : Looking for writers
2026/09/25 01:56:28 DEBUG : file1: reading active writers
2026/09/25 01:56:28 DEBUG : file1: active writers 1
2026/09/25 01:56:28 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms
2026/09/25 01:56:28 DEBUG : Looking for writers
2026/09/25 01:56:28 DEBUG : file1: reading active writers
2026/09/25 01:56:28 DEBUG : file1: active writers 1
2026/09/25 01:56:28 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms
2026/09/25 01:56:28 DEBUG : Looking for writers
2026/09/25 01:56:28 DEBUG : file1: reading active writers
2026/09/25 01:56:28 DEBUG : file1: active writers 1
2026/09/25 01:56:28 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms
2026/09/25 01:56:28 DEBUG : Looking for writers
2026/09/25 01:56:28 DEBUG : file1: reading active writers
2026/09/25 01:56:28 DEBUG : file1: active writers 1
2026/09/25 01:56:28 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms
2026/09/25 01:56:29 DEBUG : Looking for writers
2026/09/25 01:56:29 DEBUG : file1: reading active writers
2026/09/25 01:56:29 DEBUG : file1: active writers 1
2026/09/25 01:56:29 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:30 DEBUG : Looking for writers
2026/09/25 01:56:30 DEBUG : file1: reading active writers
2026/09/25 01:56:30 DEBUG : file1: active writers 1
2026/09/25 01:56:30 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:31 DEBUG : Looking for writers
2026/09/25 01:56:31 DEBUG : file1: reading active writers
2026/09/25 01:56:31 DEBUG : file1: active writers 1
2026/09/25 01:56:31 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:32 DEBUG : Looking for writers
2026/09/25 01:56:32 DEBUG : file1: reading active writers
2026/09/25 01:56:32 DEBUG : file1: active writers 1
2026/09/25 01:56:32 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:33 DEBUG : Looking for writers
2026/09/25 01:56:33 DEBUG : file1: reading active writers
2026/09/25 01:56:33 DEBUG : file1: active writers 1
2026/09/25 01:56:33 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:34 DEBUG : Looking for writers
2026/09/25 01:56:34 DEBUG : file1: reading active writers
2026/09/25 01:56:34 DEBUG : file1: active writers 1
2026/09/25 01:56:34 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:35 DEBUG : Looking for writers
2026/09/25 01:56:35 DEBUG : file1: reading active writers
2026/09/25 01:56:35 DEBUG : file1: active writers 1
2026/09/25 01:56:35 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:36 DEBUG : Looking for writers
2026/09/25 01:56:36 DEBUG : file1: reading active writers
2026/09/25 01:56:36 DEBUG : file1: active writers 1
2026/09/25 01:56:36 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:37 DEBUG : Looking for writers
2026/09/25 01:56:37 DEBUG : file1: reading active writers
2026/09/25 01:56:37 DEBUG : file1: active writers 1
2026/09/25 01:56:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:38 DEBUG : Looking for writers
2026/09/25 01:56:38 DEBUG : file1: reading active writers
2026/09/25 01:56:38 DEBUG : file1: active writers 1
2026/09/25 01:56:38 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:39 DEBUG : Looking for writers
2026/09/25 01:56:39 DEBUG : file1: reading active writers
2026/09/25 01:56:39 DEBUG : file1: active writers 1
2026/09/25 01:56:39 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:40 DEBUG : Looking for writers
2026/09/25 01:56:40 DEBUG : file1: reading active writers
2026/09/25 01:56:40 DEBUG : file1: active writers 1
2026/09/25 01:56:40 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:41 DEBUG : Looking for writers
2026/09/25 01:56:41 DEBUG : file1: reading active writers
2026/09/25 01:56:41 DEBUG : file1: active writers 1
2026/09/25 01:56:41 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:42 DEBUG : Looking for writers
2026/09/25 01:56:42 DEBUG : file1: reading active writers
2026/09/25 01:56:42 DEBUG : file1: active writers 1
2026/09/25 01:56:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:43 DEBUG : Looking for writers
2026/09/25 01:56:43 DEBUG : file1: reading active writers
2026/09/25 01:56:43 DEBUG : file1: active writers 1
2026/09/25 01:56:43 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:44 DEBUG : Looking for writers
2026/09/25 01:56:44 DEBUG : file1: reading active writers
2026/09/25 01:56:44 DEBUG : file1: active writers 1
2026/09/25 01:56:44 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:45 DEBUG : Looking for writers
2026/09/25 01:56:45 DEBUG : file1: reading active writers
2026/09/25 01:56:45 DEBUG : file1: active writers 1
2026/09/25 01:56:45 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:46 DEBUG : Looking for writers
2026/09/25 01:56:46 DEBUG : file1: reading active writers
2026/09/25 01:56:46 DEBUG : file1: active writers 1
2026/09/25 01:56:46 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:47 DEBUG : Looking for writers
2026/09/25 01:56:47 DEBUG : file1: reading active writers
2026/09/25 01:56:47 DEBUG : file1: active writers 1
2026/09/25 01:56:47 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:48 DEBUG : Looking for writers
2026/09/25 01:56:48 DEBUG : file1: reading active writers
2026/09/25 01:56:48 DEBUG : file1: active writers 1
2026/09/25 01:56:48 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:49 DEBUG : Looking for writers
2026/09/25 01:56:49 DEBUG : file1: reading active writers
2026/09/25 01:56:49 DEBUG : file1: active writers 1
2026/09/25 01:56:49 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:50 DEBUG : Looking for writers
2026/09/25 01:56:50 DEBUG : file1: reading active writers
2026/09/25 01:56:50 DEBUG : file1: active writers 1
2026/09/25 01:56:50 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:51 DEBUG : Looking for writers
2026/09/25 01:56:51 DEBUG : file1: reading active writers
2026/09/25 01:56:51 DEBUG : file1: active writers 1
2026/09/25 01:56:51 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:52 DEBUG : Looking for writers
2026/09/25 01:56:52 DEBUG : file1: reading active writers
2026/09/25 01:56:52 DEBUG : file1: active writers 1
2026/09/25 01:56:52 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:53 DEBUG : Looking for writers
2026/09/25 01:56:53 DEBUG : file1: reading active writers
2026/09/25 01:56:53 DEBUG : file1: active writers 1
2026/09/25 01:56:53 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:54 DEBUG : Looking for writers
2026/09/25 01:56:54 DEBUG : file1: reading active writers
2026/09/25 01:56:54 DEBUG : file1: active writers 1
2026/09/25 01:56:54 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:55 DEBUG : Looking for writers
2026/09/25 01:56:55 DEBUG : file1: reading active writers
2026/09/25 01:56:55 DEBUG : file1: active writers 1
2026/09/25 01:56:55 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:56 DEBUG : Looking for writers
2026/09/25 01:56:56 DEBUG : file1: reading active writers
2026/09/25 01:56:56 DEBUG : file1: active writers 1
2026/09/25 01:56:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:57 DEBUG : Looking for writers
2026/09/25 01:56:57 DEBUG : file1: reading active writers
2026/09/25 01:56:57 DEBUG : file1: active writers 1
2026/09/25 01:56:57 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:56:57 ERROR : Exiting even though 1 writers active and 0 cache items in use after 30s
Cache: <nil>
2026/09/25 01:56:57 DEBUG : >WaitForWriters: 
--- SKIP: TestWriteFileModTimeWithOpenWriters (30.97s)
=== RUN   TestFileReadAtZeroLength
    run.go:198: Remote "Internxt root 'rclone-test-tukifup1gune'", Local "Local file system at /tmp/rclone2916188698", Modify Window "876000h0m0s"
2026/09/25 01:56:58 INFO  : Internxt root 'rclone-test-tukifup1gune': poll-interval is not supported by this remote
2026/09/25 01:56:58 NOTICE: Internxt root 'rclone-test-tukifup1gune': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/09/25 01:56:58 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2026/09/25 01:56:58 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2026/09/25 01:56:58 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/09/25 01:56:58 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2026/09/25 01:56:58 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2026/09/25 01:56:58 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/09/25 01:56:58 DEBUG : Internxt root 'rclone-test-tukifup1gune': File to upload is small (0 bytes), uploading instead of streaming
2026/09/25 01:56:59 DEBUG : file1: size = 0 OK
2026/09/25 01:56:59 DEBUG : file1: Size of src and dst objects identical
2026/09/25 01:56:59 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/09/25 01:56:59 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=----------
2026/09/25 01:56:59 DEBUG : file1: Open: flags=O_RDONLY
2026/09/25 01:56:59 DEBUG : file1: >Open: fd=file1 (r), err=<nil>
2026/09/25 01:56:59 DEBUG : file1: >OpenFile: fd=file1 (r), err=<nil>
2026/09/25 01:56:59 DEBUG : file1: ChunkedReader.openRange at 0 length 134217728
2026/09/25 01:56:59 DEBUG : file1: ChunkedReader.Read at 0 length 1024 chunkOffset 0 chunkSize 134217728
2026/09/25 01:56:59 DEBUG : WaitForWriters: timeout=30s
2026/09/25 01:56:59 DEBUG : Looking for writers
2026/09/25 01:56:59 DEBUG : file1: reading active writers
2026/09/25 01:56:59 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 (33.61s)
=== RUN   TestFileReadAtNonZeroLength
    run.go:198: Remote "Internxt root 'rclone-test-tukifup1gune'", Local "Local file system at /tmp/rclone2916188698", Modify Window "876000h0m0s"
2026/09/25 01:57:32 INFO  : Internxt root 'rclone-test-tukifup1gune': poll-interval is not supported by this remote
2026/09/25 01:57:32 NOTICE: Internxt root 'rclone-test-tukifup1gune': --vfs-cache-mode writes or full is recommended for this remote as it can't stream
2026/09/25 01:57:32 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2026/09/25 01:57:32 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2026/09/25 01:57:32 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/09/25 01:57:32 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2026/09/25 01:57:32 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2026/09/25 01:57:32 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:57:32 DEBUG : WaitForWriters: timeout=30s
2026/09/25 01:57:32 DEBUG : Looking for writers
2026/09/25 01:57:32 DEBUG : file1: reading active writers
2026/09/25 01:57:32 DEBUG : file1: active writers 1
2026/09/25 01:57:32 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms
2026/09/25 01:57:32 DEBUG : Looking for writers
2026/09/25 01:57:32 DEBUG : file1: reading active writers
2026/09/25 01:57:32 DEBUG : file1: active writers 1
2026/09/25 01:57:32 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms
2026/09/25 01:57:32 DEBUG : Looking for writers
2026/09/25 01:57:32 DEBUG : file1: reading active writers
2026/09/25 01:57:32 DEBUG : file1: active writers 1
2026/09/25 01:57:32 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms
2026/09/25 01:57:32 DEBUG : Looking for writers
2026/09/25 01:57:32 DEBUG : file1: reading active writers
2026/09/25 01:57:32 DEBUG : file1: active writers 1
2026/09/25 01:57:32 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms
2026/09/25 01:57:32 DEBUG : Looking for writers
2026/09/25 01:57:32 DEBUG : file1: reading active writers
2026/09/25 01:57:32 DEBUG : file1: active writers 1
2026/09/25 01:57:32 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms
2026/09/25 01:57:32 DEBUG : Looking for writers
2026/09/25 01:57:32 DEBUG : file1: reading active writers
2026/09/25 01:57:32 DEBUG : file1: active writers 1
2026/09/25 01:57:32 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms
2026/09/25 01:57:33 DEBUG : Looking for writers
2026/09/25 01:57:33 DEBUG : file1: reading active writers
2026/09/25 01:57:33 DEBUG : file1: active writers 1
2026/09/25 01:57:33 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms
2026/09/25 01:57:33 DEBUG : Looking for writers
2026/09/25 01:57:33 DEBUG : file1: reading active writers
2026/09/25 01:57:33 DEBUG : file1: active writers 1
2026/09/25 01:57:33 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:34 DEBUG : Looking for writers
2026/09/25 01:57:34 DEBUG : file1: reading active writers
2026/09/25 01:57:34 DEBUG : file1: active writers 1
2026/09/25 01:57:34 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:35 DEBUG : Looking for writers
2026/09/25 01:57:35 DEBUG : file1: reading active writers
2026/09/25 01:57:35 DEBUG : file1: active writers 1
2026/09/25 01:57:35 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:36 DEBUG : Looking for writers
2026/09/25 01:57:36 DEBUG : file1: reading active writers
2026/09/25 01:57:36 DEBUG : file1: active writers 1
2026/09/25 01:57:36 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:37 DEBUG : Looking for writers
2026/09/25 01:57:37 DEBUG : file1: reading active writers
2026/09/25 01:57:37 DEBUG : file1: active writers 1
2026/09/25 01:57:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:38 DEBUG : Looking for writers
2026/09/25 01:57:38 DEBUG : file1: reading active writers
2026/09/25 01:57:38 DEBUG : file1: active writers 1
2026/09/25 01:57:38 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:39 DEBUG : Looking for writers
2026/09/25 01:57:39 DEBUG : file1: reading active writers
2026/09/25 01:57:39 DEBUG : file1: active writers 1
2026/09/25 01:57:39 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:40 DEBUG : Looking for writers
2026/09/25 01:57:40 DEBUG : file1: reading active writers
2026/09/25 01:57:40 DEBUG : file1: active writers 1
2026/09/25 01:57:40 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:41 DEBUG : Looking for writers
2026/09/25 01:57:41 DEBUG : file1: reading active writers
2026/09/25 01:57:41 DEBUG : file1: active writers 1
2026/09/25 01:57:41 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:42 DEBUG : Looking for writers
2026/09/25 01:57:42 DEBUG : file1: reading active writers
2026/09/25 01:57:42 DEBUG : file1: active writers 1
2026/09/25 01:57:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:43 DEBUG : Looking for writers
2026/09/25 01:57:43 DEBUG : file1: reading active writers
2026/09/25 01:57:43 DEBUG : file1: active writers 1
2026/09/25 01:57:43 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:44 DEBUG : Looking for writers
2026/09/25 01:57:44 DEBUG : file1: reading active writers
2026/09/25 01:57:44 DEBUG : file1: active writers 1
2026/09/25 01:57:44 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:45 DEBUG : Looking for writers
2026/09/25 01:57:45 DEBUG : file1: reading active writers
2026/09/25 01:57:45 DEBUG : file1: active writers 1
2026/09/25 01:57:45 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:46 DEBUG : Looking for writers
2026/09/25 01:57:46 DEBUG : file1: reading active writers
2026/09/25 01:57:46 DEBUG : file1: active writers 1
2026/09/25 01:57:46 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:47 DEBUG : Looking for writers
2026/09/25 01:57:47 DEBUG : file1: reading active writers
2026/09/25 01:57:47 DEBUG : file1: active writers 1
2026/09/25 01:57:47 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:48 DEBUG : Looking for writers
2026/09/25 01:57:48 DEBUG : file1: reading active writers
2026/09/25 01:57:48 DEBUG : file1: active writers 1
2026/09/25 01:57:48 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:49 DEBUG : Looking for writers
2026/09/25 01:57:49 DEBUG : file1: reading active writers
2026/09/25 01:57:49 DEBUG : file1: active writers 1
2026/09/25 01:57:49 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:50 DEBUG : Looking for writers
2026/09/25 01:57:50 DEBUG : file1: reading active writers
2026/09/25 01:57:50 DEBUG : file1: active writers 1
2026/09/25 01:57:50 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:51 DEBUG : Looking for writers
2026/09/25 01:57:51 DEBUG : file1: reading active writers
2026/09/25 01:57:51 DEBUG : file1: active writers 1
2026/09/25 01:57:51 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:52 DEBUG : Looking for writers
2026/09/25 01:57:52 DEBUG : file1: reading active writers
2026/09/25 01:57:52 DEBUG : file1: active writers 1
2026/09/25 01:57:52 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:53 DEBUG : Looking for writers
2026/09/25 01:57:53 DEBUG : file1: reading active writers
2026/09/25 01:57:53 DEBUG : file1: active writers 1
2026/09/25 01:57:53 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:54 DEBUG : Looking for writers
2026/09/25 01:57:54 DEBUG : file1: reading active writers
2026/09/25 01:57:54 DEBUG : file1: active writers 1
2026/09/25 01:57:54 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:55 DEBUG : Looking for writers
2026/09/25 01:57:55 DEBUG : file1: reading active writers
2026/09/25 01:57:55 DEBUG : file1: active writers 1
2026/09/25 01:57:55 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:56 DEBUG : Looking for writers
2026/09/25 01:57:56 DEBUG : file1: reading active writers
2026/09/25 01:57:56 DEBUG : file1: active writers 1
2026/09/25 01:57:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:57 DEBUG : Looking for writers
2026/09/25 01:57:57 DEBUG : file1: reading active writers
2026/09/25 01:57:57 DEBUG : file1: active writers 1
2026/09/25 01:57:57 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:58 DEBUG : Looking for writers
2026/09/25 01:57:58 DEBUG : file1: reading active writers
2026/09/25 01:57:58 DEBUG : file1: active writers 1
2026/09/25 01:57:58 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:57:59 DEBUG : Looking for writers
2026/09/25 01:57:59 DEBUG : file1: reading active writers
2026/09/25 01:57:59 DEBUG : file1: active writers 1
2026/09/25 01:57:59 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:58:00 DEBUG : Looking for writers
2026/09/25 01:58:00 DEBUG : file1: reading active writers
2026/09/25 01:58:00 DEBUG : file1: active writers 1
2026/09/25 01:58:00 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:58:01 DEBUG : Looking for writers
2026/09/25 01:58:01 DEBUG : file1: reading active writers
2026/09/25 01:58:01 DEBUG : file1: active writers 1
2026/09/25 01:58:01 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2026/09/25 01:58:02 ERROR : Exiting even though 1 writers active and 0 cache items in use after 30s
Cache: <nil>
2026/09/25 01:58:02 DEBUG : >WaitForWriters: 
--- FAIL: TestFileReadAtNonZeroLength (31.20s)
FAIL
2026/09/25 01:58:03 DEBUG : Internxt root 'rclone-test-tukifup1gune': Purge dir ""
"./vfs.test -test.v -test.timeout 2h0m0s -remote TestInternxt: -list-retries 5 -verbose -test.run '^(TestFileReadAtNonZeroLength|TestFileReadAtZeroLength|TestWriteFileHandleRelease|TestWriteFileModTimeWithOpenWriters)$|^TestFileSetModTime$/^(cache=off,open=false,write=false|cache=off,open=true,write=false)$'" - Finished ERROR in 1m50.548740599s (try 2/5): exit status 1: Failed [TestFileReadAtZeroLength TestFileReadAtNonZeroLength]