"./vfs.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestDirEntryModTimeInvalidation|TestDirMkdir|TestDirRemove|TestDirRename|TestFileOpen|TestFileRemove|TestReadFileHandleSeek)$|^TestDirReadDirAll$/^Virtual$'" - Starting (try 2/5) 2026/05/09 04:06:30 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-rabesam1qadu" 2026/05/09 04:06:30 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/05/09 04:06:31 DEBUG : Creating backend with remote "/tmp/rclone251561233" === RUN TestDirReadDirAll run.go:198: Remote "files root 'rclone-test-rabesam1qadu'", Local "Local file system at /tmp/rclone251561233", Modify Window "1s" 2026/05/09 04:06:31 INFO : files root 'rclone-test-rabesam1qadu': poll-interval is not supported by this remote === RUN TestDirReadDirAll/Virtual 2026/05/09 04:06:36 DEBUG : dir: Added virtual directory entry vAddFile: "virtualFile" 2026/05/09 04:06:36 DEBUG : dir: Added virtual directory entry vAddDir: "virtualDir" 2026/05/09 04:06:36 DEBUG : dir: Added virtual directory entry vDel: "file2" 2026/05/09 04:06:36 DEBUG : dir: Added virtual directory entry vDel: "subdir" 2026/05/09 04:06:38 DEBUG : dir: invalidating directory cache 2026/05/09 04:06:38 DEBUG : dir: Removed virtual directory entry vAddDir: "virtualDir" 2026/05/09 04:06:38 DEBUG : dir: Removed virtual directory entry vDel: "file2" 2026/05/09 04:06:38 DEBUG : dir: Removed virtual directory entry vDel: "subdir" 2026/05/09 04:06:38 DEBUG : dir/file1: Reset virtual modtime 2026/05/09 04:06:38 DEBUG : dir: Removed virtual directory entry vAddFile: "virtualFile" 2026/05/09 04:06:38 DEBUG : dir/virtualFile: Reset virtual modtime 2026/05/09 04:06:38 DEBUG : dir: Added virtual directory entry vAddFile: "virtualFile2" 2026/05/09 04:06:38 DEBUG : dir: Added virtual directory entry vAddDir: "virtualDir2" 2026/05/09 04:06:38 DEBUG : dir: Added virtual directory entry vDel: "file1" 2026/05/09 04:06:38 DEBUG : dir: invalidating directory cache 2026/05/09 04:06:38 DEBUG : dir: Removed virtual directory entry vAddDir: "virtualDir2" 2026/05/09 04:06:38 DEBUG : dir: Removed virtual directory entry vDel: "file1" 2026/05/09 04:06:38 DEBUG : dir/virtualFile: Reset virtual modtime 2026/05/09 04:06:38 DEBUG : forgetting directory cache 2026/05/09 04:06:38 DEBUG : dir: forgetting directory cache 2026/05/09 04:06:38 DEBUG : dir/virtualDir: forgetting directory cache 2026/05/09 04:06:38 DEBUG : WaitForWriters: timeout=30s 2026/05/09 04:06:38 DEBUG : dir/virtualDir: Looking for writers 2026/05/09 04:06:38 DEBUG : dir: Looking for writers 2026/05/09 04:06:38 DEBUG : virtualDir: reading active writers 2026/05/09 04:06:38 DEBUG : file1: reading active writers 2026/05/09 04:06:38 DEBUG : virtualFile2: reading active writers 2026/05/09 04:06:38 DEBUG : virtualFile: reading active writers 2026/05/09 04:06:38 DEBUG : Looking for writers 2026/05/09 04:06:38 DEBUG : dir: reading active writers 2026/05/09 04:06:38 DEBUG : >WaitForWriters: --- PASS: TestDirReadDirAll (8.65s) --- PASS: TestDirReadDirAll/Virtual (2.26s) === RUN TestDirMkdir run.go:198: Remote "files root 'rclone-test-rabesam1qadu'", Local "Local file system at /tmp/rclone251561233", Modify Window "1s" 2026/05/09 04:06:39 INFO : files root 'rclone-test-rabesam1qadu': poll-interval is not supported by this remote fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:298: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:298: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:305: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:358 /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:26 /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:389 /usr/local/go/src/runtime/asm_amd64.s:1771 Error: Should be true Test: TestDirMkdir Messages: listing wrong, want dir/file1 (14) got fstest.go:203: Not found "dir/file1" fstest.go:206: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:206 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:310 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:358 /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:26 /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:389 Error: Not equal: expected: 0 actual : 1 Test: TestDirMkdir Messages: 1 objects not found dir_test.go:29: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:29 /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:389 Error: Received unexpected error: file does not exist Test: TestDirMkdir 2026/05/09 04:06:48 DEBUG : WaitForWriters: timeout=30s 2026/05/09 04:06:48 DEBUG : Looking for writers 2026/05/09 04:06:48 DEBUG : >WaitForWriters: --- FAIL: TestDirMkdir (8.96s) === RUN TestDirRemove run.go:198: Remote "files root 'rclone-test-rabesam1qadu'", Local "Local file system at /tmp/rclone251561233", Modify Window "1s" 2026/05/09 04:06:48 INFO : files root 'rclone-test-rabesam1qadu': poll-interval is not supported by this remote 2026/05/09 04:06:51 ERROR : dir/: Dir.Remove not empty 2026/05/09 04:06:51 DEBUG : dir/file1: Remove: 2026/05/09 04:06:51 DEBUG : dir: Added virtual directory entry vDel: "file1" 2026/05/09 04:06:51 DEBUG : dir/file1: >Remove: err= 2026/05/09 04:06:52 DEBUG : Added virtual directory entry vDel: "dir" 2026/05/09 04:06:52 DEBUG : WaitForWriters: timeout=30s 2026/05/09 04:06:52 DEBUG : Looking for writers 2026/05/09 04:06:52 DEBUG : >WaitForWriters: --- PASS: TestDirRemove (3.55s) === RUN TestDirRename run.go:198: Remote "files root 'rclone-test-rabesam1qadu'", Local "Local file system at /tmp/rclone251561233", Modify Window "1s" 2026/05/09 04:06:52 INFO : files root 'rclone-test-rabesam1qadu': poll-interval is not supported by this remote 2026/05/09 04:06:54 ERROR : dir/not found: Dir.Rename error: file does not exist 2026/05/09 04:06:55 DEBUG : dir: Updating dir with dir2 0x310d13d23c70 2026/05/09 04:06:55 DEBUG : dir: forgetting directory cache 2026/05/09 04:06:55 DEBUG : Added virtual directory entry vDel: "dir" 2026/05/09 04:06:55 DEBUG : Added virtual directory entry vAddDir: "dir2" 2026/05/09 04:06:56 INFO : dir2/file1: Moved (server-side) to: file2 2026/05/09 04:06:56 DEBUG : file2: Updating file with file2 0x310d13a82a90 2026/05/09 04:06:56 DEBUG : dir2: Added virtual directory entry vDel: "file1" 2026/05/09 04:06:56 DEBUG : Added virtual directory entry vAddFile: "file2" 2026/05/09 04:06:57 INFO : dir2/file3: Deleted 2026/05/09 04:06:57 INFO : file2: Moved (server-side) to: dir2/file3 2026/05/09 04:06:57 DEBUG : dir2/file3: Updating file with dir2/file3 0x310d13a82a90 2026/05/09 04:06:57 DEBUG : Added virtual directory entry vDel: "file2" 2026/05/09 04:06:57 DEBUG : dir2: Added virtual directory entry vAddFile: "file3" 2026/05/09 04:06:57 DEBUG : Added virtual directory entry vAddDir: "empty directory" 2026/05/09 04:06:58 DEBUG : empty directory: Updating dir with renamed empty directory 0x310d1389bd40 2026/05/09 04:06:58 DEBUG : empty directory: forgetting directory cache 2026/05/09 04:06:58 DEBUG : Added virtual directory entry vDel: "empty directory" 2026/05/09 04:06:58 DEBUG : Added virtual directory entry vAddDir: "renamed empty directory" 2026/05/09 04:06:58 DEBUG : dir2: Renaming to "dir3" 2026/05/09 04:06:58 DEBUG : WaitForWriters: timeout=30s 2026/05/09 04:06:58 DEBUG : dir3: Looking for writers 2026/05/09 04:06:58 DEBUG : file3: reading active writers 2026/05/09 04:06:58 DEBUG : renamed empty directory: Looking for writers 2026/05/09 04:06:58 DEBUG : Looking for writers 2026/05/09 04:06:58 DEBUG : dir3: reading active writers 2026/05/09 04:06:58 DEBUG : renamed empty directory: reading active writers 2026/05/09 04:06:58 DEBUG : >WaitForWriters: --- PASS: TestDirRename (6.92s) === RUN TestDirEntryModTimeInvalidation run.go:198: Remote "files root 'rclone-test-rabesam1qadu'", Local "Local file system at /tmp/rclone251561233", Modify Window "1s" 2026/05/09 04:06:59 INFO : files root 'rclone-test-rabesam1qadu': poll-interval is not supported by this remote 2026/05/09 04:07:00 DEBUG : forgetting directory cache 2026/05/09 04:07:02 DEBUG : forgetting directory cache 2026/05/09 04:07:02 DEBUG : dir: forgetting directory cache 2026/05/09 04:07:02 DEBUG : WaitForWriters: timeout=30s 2026/05/09 04:07:02 DEBUG : dir: Looking for writers 2026/05/09 04:07:02 DEBUG : Looking for writers 2026/05/09 04:07:02 DEBUG : dir: reading active writers 2026/05/09 04:07:02 DEBUG : >WaitForWriters: --- PASS: TestDirEntryModTimeInvalidation (3.81s) === RUN TestFileRemove run.go:198: Remote "files root 'rclone-test-rabesam1qadu'", Local "Local file system at /tmp/rclone251561233", Modify Window "1s" 2026/05/09 04:07:03 INFO : files root 'rclone-test-rabesam1qadu': poll-interval is not supported by this remote fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:298: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:298: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:305: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:358 /home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:28 /home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:251 /usr/local/go/src/runtime/asm_amd64.s:1771 Error: Should be true Test: TestFileRemove Messages: listing wrong, want dir/file1 (14) got fstest.go:203: Not found "dir/file1" fstest.go:206: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:206 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:310 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:358 /home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:28 /home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:251 Error: Not equal: expected: 0 actual : 1 Test: TestFileRemove Messages: 1 objects not found file_test.go:31: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:31 /home/rclone/go/src/github.com/rclone/rclone/vfs/file_test.go:251 Error: Received unexpected error: file does not exist Test: TestFileRemove 2026/05/09 04:07:11 DEBUG : WaitForWriters: timeout=30s 2026/05/09 04:07:11 DEBUG : Looking for writers 2026/05/09 04:07:11 DEBUG : >WaitForWriters: --- FAIL: TestFileRemove (8.98s) === RUN TestFileOpen run.go:198: Remote "files root 'rclone-test-rabesam1qadu'", Local "Local file system at /tmp/rclone251561233", Modify Window "1s" 2026/05/09 04:07:12 INFO : files root 'rclone-test-rabesam1qadu': poll-interval is not supported by this remote 2026/05/09 04:07:14 DEBUG : dir/file1: Open: flags=O_RDONLY 2026/05/09 04:07:14 DEBUG : dir/file1: >Open: fd=dir/file1 (r), err= 2026/05/09 04:07:14 DEBUG : dir/file1: Open: flags=O_WRONLY 2026/05/09 04:07:14 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err= 2026/05/09 04:07:14 DEBUG : dir/file1: Open: flags=O_RDWR 2026/05/09 04:07:14 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err= 2026/05/09 04:07:14 DEBUG : dir/file1: Open: flags=0x3 2026/05/09 04:07:14 DEBUG : dir/file1: Can't figure out how to open with flags: 0x3 2026/05/09 04:07:14 DEBUG : dir/file1: >Open: fd=, err=permission denied 2026/05/09 04:07:14 DEBUG : WaitForWriters: timeout=30s 2026/05/09 04:07:14 DEBUG : dir: Looking for writers 2026/05/09 04:07:14 DEBUG : file1: reading active writers 2026/05/09 04:07:14 DEBUG : Looking for writers 2026/05/09 04:07:14 DEBUG : dir: reading active writers 2026/05/09 04:07:14 DEBUG : >WaitForWriters: --- PASS: TestFileOpen (3.48s) === RUN TestReadFileHandleSeek run.go:198: Remote "files root 'rclone-test-rabesam1qadu'", Local "Local file system at /tmp/rclone251561233", Modify Window "1s" 2026/05/09 04:07:15 INFO : files root 'rclone-test-rabesam1qadu': poll-interval is not supported by this remote 2026/05/09 04:07:16 DEBUG : dir/file1: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/05/09 04:07:17 DEBUG : dir/file1: Open: flags=O_RDONLY 2026/05/09 04:07:17 DEBUG : dir/file1: >Open: fd=dir/file1 (r), err= 2026/05/09 04:07:17 DEBUG : dir/file1: >OpenFile: fd=dir/file1 (r), err= 2026/05/09 04:07:17 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728 2026/05/09 04:07:17 DEBUG : dir/file1: ChunkedReader.Read at 0 length 1 chunkOffset 0 chunkSize 134217728 2026/05/09 04:07:17 DEBUG : dir/file1: waiting for in-sequence read to 5 for 20ms 2026/05/09 04:07:17 DEBUG : dir/file1: aborting in-sequence read wait, off=5 2026/05/09 04:07:17 DEBUG : dir/file1: failed to wait for in-sequence read to 5 2026/05/09 04:07:17 DEBUG : dir/file1: ReadFileHandle.seek from 1 to 5 (fs.RangeSeeker) 2026/05/09 04:07:17 DEBUG : dir/file1: ChunkedReader.RangeSeek from 1 to 5 length -1 2026/05/09 04:07:17 DEBUG : dir/file1: ChunkedReader.Read at -1 length 1 chunkOffset 5 chunkSize 134217728 2026/05/09 04:07:17 DEBUG : dir/file1: ChunkedReader.openRange at 5 length 134217728 2026/05/09 04:07:17 DEBUG : dir/file1: ReadFileHandle.seek from 6 to 3 (fs.RangeSeeker) 2026/05/09 04:07:17 DEBUG : dir/file1: ChunkedReader.RangeSeek from 6 to 3 length -1 2026/05/09 04:07:17 DEBUG : dir/file1: ChunkedReader.Read at -1 length 1 chunkOffset 3 chunkSize 134217728 2026/05/09 04:07:17 DEBUG : dir/file1: ChunkedReader.openRange at 3 length 134217728 2026/05/09 04:07:18 DEBUG : dir/file1: ReadFileHandle.seek from 4 to 13 (fs.RangeSeeker) 2026/05/09 04:07:18 DEBUG : dir/file1: ChunkedReader.RangeSeek from 4 to 13 length -1 2026/05/09 04:07:18 DEBUG : dir/file1: ChunkedReader.Read at -1 length 1 chunkOffset 13 chunkSize 134217728 2026/05/09 04:07:18 DEBUG : dir/file1: ChunkedReader.openRange at 13 length 134217728 2026/05/09 04:07:18 DEBUG : WaitForWriters: timeout=30s 2026/05/09 04:07:18 DEBUG : dir: Looking for writers 2026/05/09 04:07:18 DEBUG : file1: reading active writers 2026/05/09 04:07:18 DEBUG : Looking for writers 2026/05/09 04:07:18 DEBUG : dir: reading active writers 2026/05/09 04:07:18 DEBUG : >WaitForWriters: --- PASS: TestReadFileHandleSeek (3.75s) FAIL 2026/05/09 04:07:19 DEBUG : files root 'rclone-test-rabesam1qadu': Purge remote "./vfs.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestDirEntryModTimeInvalidation|TestDirMkdir|TestDirRemove|TestDirRename|TestFileOpen|TestFileRemove|TestReadFileHandleSeek)$|^TestDirReadDirAll$/^Virtual$'" - Finished ERROR in 49.014767412s (try 2/5): exit status 1: Failed [TestDirMkdir TestFileRemove]