"./vfs.test -test.v -test.timeout 2h0m0s -remote TestDrime: -list-retries 5 -verbose -test.run '^(TestDirFileOpen|TestDirRemove|TestDirRemoveAll|TestDirRename|TestRWFileHandleReleaseRead|TestRWFileHandleSeek|TestReadFileHandleMethods|TestVFSMkdirAll|TestVFSOpenFile|TestZipDirsInRoot|TestZipLargeFiles)$|^TestFileRename$/^(full,forceCache=false|off,forceCache=false)$'" - Starting (try 2/5) 2026/08/16 03:28:44 DEBUG : Creating backend with remote "TestDrime:rclone-test-jayajov6xawo" 2026/08/16 03:28:44 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/08/16 03:28:45 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:28:45 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:28:46 DEBUG : pacer: low level retry 2/10 (error Error "Server Error") 2026/08/16 03:28:46 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:28:47 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:28:48 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:28:48 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:28:50 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:28:50 DEBUG : Creating backend with remote "/tmp/rclone1823064743" === RUN TestDirRemove run.go:198: Remote "drime root 'rclone-test-jayajov6xawo'", Local "Local file system at /tmp/rclone1823064743", Modify Window "876000h0m0s" 2026/08/16 03:28:50 INFO : drime root 'rclone-test-jayajov6xawo': poll-interval is not supported by this remote 2026/08/16 03:28:51 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:28:52 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:28:52 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:28:53 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:28:54 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:28:54 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:28:55 DEBUG : pacer: low level retry 2/10 (error Error "Server Error") 2026/08/16 03:28:55 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:28:55 DEBUG : pacer: low level retry 3/10 (error Error "Server Error") 2026/08/16 03:28:55 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2026/08/16 03:28:56 DEBUG : pacer: Reducing sleep to 40ms 2026/08/16 03:28:56 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:28:56 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2026/08/16 03:28:56 DEBUG : pacer: Reducing sleep to 40ms 2026/08/16 03:28:57 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:28:57 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:28:58 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:28:58 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:28:58 DEBUG : pacer: low level retry 2/10 (error Error "Server Error") 2026/08/16 03:28:58 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:28:59 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:28:59 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:28:59 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:29:00 DEBUG : pacer: low level retry 2/10 (error Error "Server Error") 2026/08/16 03:29:00 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2026/08/16 03:29:01 DEBUG : pacer: Reducing sleep to 40ms 2026/08/16 03:29:01 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:29:01 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:29:01 ERROR : dir/: Dir.Remove not empty 2026/08/16 03:29:01 DEBUG : dir/file1: Remove: 2026/08/16 03:29:18 DEBUG : dir: Added virtual directory entry vDel: "file1" 2026/08/16 03:29:18 DEBUG : dir/file1: >Remove: err= 2026/08/16 03:29:37 DEBUG : Added virtual directory entry vDel: "dir" 2026/08/16 03:29:37 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:29:37 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:29:38 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:29:38 DEBUG : WaitForWriters: timeout=30s 2026/08/16 03:29:38 DEBUG : Looking for writers 2026/08/16 03:29:38 DEBUG : >WaitForWriters: --- PASS: TestDirRemove (48.90s) === RUN TestDirRemoveAll run.go:198: Remote "drime root 'rclone-test-jayajov6xawo'", Local "Local file system at /tmp/rclone1823064743", Modify Window "876000h0m0s" 2026/08/16 03:29:39 INFO : drime root 'rclone-test-jayajov6xawo': poll-interval is not supported by this remote 2026/08/16 03:29:40 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:29:40 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:29:40 DEBUG : pacer: Reducing sleep to 10ms run.go:303: Failed to put "dir/file1" to "drime root 'rclone-test-jayajov6xawo'": failed to make directory: failed to create folder: Error "422 Unprocessable Entity (422): {\"message\":\"\",\"errors\":{\"name\":\"Folder with same name already exists.\"}}" 2026/08/16 03:29:40 DEBUG : WaitForWriters: timeout=30s 2026/08/16 03:29:40 DEBUG : Looking for writers 2026/08/16 03:29:40 DEBUG : >WaitForWriters: --- FAIL: TestDirRemoveAll (21.26s) === RUN TestDirRename run.go:198: Remote "drime root 'rclone-test-jayajov6xawo'", Local "Local file system at /tmp/rclone1823064743", Modify Window "876000h0m0s" 2026/08/16 03:30:00 INFO : drime root 'rclone-test-jayajov6xawo': poll-interval is not supported by this remote 2026/08/16 03:30:04 DEBUG : pacer: low level retry 1/1 (error Error "Server Error") 2026/08/16 03:30:04 DEBUG : pacer: Rate limited, increasing sleep to 20ms run.go:299: Retry Put of "dir/file1" to drime root 'rclone-test-jayajov6xawo': 1/10 (failed to upload file: Error "Server Error") 2026/08/16 03:30:07 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:30:08 DEBUG : pacer: low level retry 1/1 (error Error "Server Error") 2026/08/16 03:30:08 DEBUG : pacer: Rate limited, increasing sleep to 20ms run.go:299: Retry Put of "dir/file1" to drime root 'rclone-test-jayajov6xawo': 2/10 (failed to upload file: Error "Server Error") 2026/08/16 03:30:11 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:30:12 DEBUG : pacer: low level retry 1/1 (error Error "Server Error") 2026/08/16 03:30:12 DEBUG : pacer: Rate limited, increasing sleep to 20ms run.go:299: Retry Put of "dir/file1" to drime root 'rclone-test-jayajov6xawo': 3/10 (failed to upload file: Error "Server Error") 2026/08/16 03:30:15 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:30:15 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:30:16 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:30:16 DEBUG : pacer: low level retry 1/1 (error Error "Server Error") 2026/08/16 03:30:16 DEBUG : pacer: Rate limited, increasing sleep to 40ms run.go:299: Retry Put of "dir/file1" to drime root 'rclone-test-jayajov6xawo': 4/10 (failed to upload file: Error "Server Error") 2026/08/16 03:30:19 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:30:19 DEBUG : pacer: low level retry 1/1 (error Error "Server Error") 2026/08/16 03:30:19 DEBUG : pacer: Rate limited, increasing sleep to 40ms run.go:299: Retry Put of "dir/file1" to drime root 'rclone-test-jayajov6xawo': 5/10 (failed to upload file: Error "Server Error") 2026/08/16 03:30:22 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:30:24 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:30:24 DEBUG : dir/file1: Removing old object on successful upload 2026/08/16 03:30:25 DEBUG : dir/file1: Old object already deleted, safely ignoring 2026/08/16 03:30:29 DEBUG : pacer: low level retry 1/1 (error Error "Server Error") 2026/08/16 03:30:29 DEBUG : pacer: Rate limited, increasing sleep to 20ms run.go:299: Retry Put of "dir/file3" to drime root 'rclone-test-jayajov6xawo': 1/10 (failed to upload file: Error "Server Error") 2026/08/16 03:30:32 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:30:33 DEBUG : pacer: low level retry 1/1 (error Error "Server Error") 2026/08/16 03:30:33 DEBUG : pacer: Rate limited, increasing sleep to 20ms run.go:299: Retry Put of "dir/file3" to drime root 'rclone-test-jayajov6xawo': 2/10 (failed to upload file: Error "Server Error") 2026/08/16 03:30:36 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:30:36 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:30:36 DEBUG : pacer: low level retry 2/10 (error Error "Server Error") 2026/08/16 03:30:36 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2026/08/16 03:30:36 DEBUG : pacer: Reducing sleep to 40ms 2026/08/16 03:30:37 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:30:37 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:30:37 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:30:38 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:30:38 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:30:38 ERROR : dir/not found: Dir.Rename error: file does not exist 2026/08/16 03:30:38 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:30:38 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:30:39 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:30:39 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:30:39 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:30:40 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:30:41 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:30:41 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:30:41 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:30:41 DEBUG : dir: Updating dir with dir2 0x3ae7996e8900 2026/08/16 03:30:41 DEBUG : dir: forgetting directory cache 2026/08/16 03:30:41 DEBUG : Added virtual directory entry vDel: "dir" 2026/08/16 03:30:41 DEBUG : Added virtual directory entry vAddDir: "dir2" 2026/08/16 03:30:41 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:30:41 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:30:41 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:30:42 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:30:42 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:30:42 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:30:43 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:30:43 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:30:44 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:30:46 INFO : dir2/file1: Moved (server-side) to: file2 2026/08/16 03:30:46 DEBUG : file2: Updating file with file2 0x3ae79a0048f0 2026/08/16 03:30:46 DEBUG : dir2: Added virtual directory entry vDel: "file1" 2026/08/16 03:30:46 DEBUG : Added virtual directory entry vAddFile: "file2" 2026/08/16 03:30:47 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:30:47 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:30:48 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:30:48 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:30:48 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:30:49 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:31:07 INFO : dir2/file3: Deleted 2026/08/16 03:31:08 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:31:08 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:31:10 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:31:12 INFO : file2: Moved (server-side) to: dir2/file3 2026/08/16 03:31:12 DEBUG : dir2/file3: Updating file with dir2/file3 0x3ae79a0048f0 2026/08/16 03:31:12 DEBUG : Added virtual directory entry vDel: "file2" 2026/08/16 03:31:12 DEBUG : dir2: Added virtual directory entry vAddFile: "file3" 2026/08/16 03:31:17 DEBUG : Added virtual directory entry vAddDir: "empty directory" 2026/08/16 03:31:18 DEBUG : empty directory: Updating dir with renamed empty directory 0x3ae799fae300 2026/08/16 03:31:18 DEBUG : empty directory: forgetting directory cache 2026/08/16 03:31:18 DEBUG : Added virtual directory entry vDel: "empty directory" 2026/08/16 03:31:18 DEBUG : Added virtual directory entry vAddDir: "renamed empty directory" 2026/08/16 03:31:18 DEBUG : dir2: Renaming to "dir3" 2026/08/16 03:31:18 DEBUG : WaitForWriters: timeout=30s 2026/08/16 03:31:18 DEBUG : dir3: Looking for writers 2026/08/16 03:31:18 DEBUG : file3: reading active writers 2026/08/16 03:31:18 DEBUG : renamed empty directory: Looking for writers 2026/08/16 03:31:18 DEBUG : Looking for writers 2026/08/16 03:31:18 DEBUG : dir3: reading active writers 2026/08/16 03:31:18 DEBUG : renamed empty directory: reading active writers 2026/08/16 03:31:18 DEBUG : >WaitForWriters: 2026/08/16 03:31:19 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:31:19 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:31:20 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:31:20 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:31:20 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:31:20 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:31:20 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:31:21 DEBUG : pacer: low level retry 2/10 (error Error "Server Error") 2026/08/16 03:31:21 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2026/08/16 03:31:21 DEBUG : pacer: low level retry 2/10 (error Error "Server Error") 2026/08/16 03:31:21 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2026/08/16 03:31:21 DEBUG : pacer: low level retry 3/10 (error Error "Server Error") 2026/08/16 03:31:21 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2026/08/16 03:31:22 DEBUG : pacer: Reducing sleep to 160ms 2026/08/16 03:31:22 DEBUG : pacer: low level retry 4/10 (error Error "Server Error") 2026/08/16 03:31:22 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2026/08/16 03:31:23 DEBUG : pacer: low level retry 5/10 (error Error "Server Error") 2026/08/16 03:31:23 DEBUG : pacer: Rate limited, increasing sleep to 640ms 2026/08/16 03:31:23 DEBUG : pacer: low level retry 6/10 (error Error "Server Error") 2026/08/16 03:31:23 DEBUG : pacer: Rate limited, increasing sleep to 1.28s 2026/08/16 03:31:24 DEBUG : pacer: Reducing sleep to 640ms 2026/08/16 03:31:43 DEBUG : pacer: Reducing sleep to 320ms 2026/08/16 03:31:44 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:31:44 DEBUG : pacer: Rate limited, increasing sleep to 640ms 2026/08/16 03:31:45 DEBUG : pacer: Reducing sleep to 320ms 2026/08/16 03:31:46 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:31:46 DEBUG : pacer: Rate limited, increasing sleep to 640ms 2026/08/16 03:32:04 DEBUG : pacer: Reducing sleep to 320ms 2026/08/16 03:32:05 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:32:05 DEBUG : pacer: Rate limited, increasing sleep to 640ms 2026/08/16 03:32:06 DEBUG : pacer: Reducing sleep to 320ms 2026/08/16 03:32:25 DEBUG : pacer: Reducing sleep to 160ms 2026/08/16 03:32:26 DEBUG : pacer: Reducing sleep to 80ms --- PASS: TestDirRename (145.73s) === RUN TestDirFileOpen run.go:198: Remote "drime root 'rclone-test-jayajov6xawo'", Local "Local file system at /tmp/rclone1823064743", Modify Window "876000h0m0s" 2026/08/16 03:32:26 INFO : drime root 'rclone-test-jayajov6xawo': poll-interval is not supported by this remote 2026/08/16 03:32:26 DEBUG : pacer: Reducing sleep to 40ms 2026/08/16 03:32:27 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:32:27 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:32:28 DEBUG : pacer: low level retry 1/1 (error Error "Server Error") 2026/08/16 03:32:28 DEBUG : pacer: Rate limited, increasing sleep to 20ms run.go:299: Retry Put of "dir/file1" to drime root 'rclone-test-jayajov6xawo': 1/10 (failed to upload file: Error "Server Error") 2026/08/16 03:32:31 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:32:31 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:32:32 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:32:33 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:32:33 DEBUG : dir/file1: Removing old object on successful upload 2026/08/16 03:32:34 DEBUG : dir/file1: Old object already deleted, safely ignoring 2026/08/16 03:32:36 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:32:36 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:32:37 DEBUG : pacer: low level retry 2/10 (error Error "Server Error") 2026/08/16 03:32:37 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:32:38 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:32:38 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:32:38 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:32:39 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:32:40 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:32:41 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:32:41 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:32:41 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:32:41 ERROR : dir/: Dir.Mkdir failed to create directory: failed to make directory: failed to create folder: Error "422 Unprocessable Entity (422): {\"message\":\"\",\"errors\":{\"name\":\"Folder with same name already exists.\"}}" dir_test.go:622: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:622 Error: Received unexpected error: failed to make directory: failed to create folder: Error "422 Unprocessable Entity (422): {\"message\":\"\",\"errors\":{\"name\":\"Folder with same name already exists.\"}}" Test: TestDirFileOpen 2026/08/16 03:32:41 DEBUG : WaitForWriters: timeout=30s 2026/08/16 03:32:41 DEBUG : dir: Looking for writers 2026/08/16 03:32:41 DEBUG : file1: reading active writers 2026/08/16 03:32:41 DEBUG : Looking for writers 2026/08/16 03:32:41 DEBUG : dir: reading active writers 2026/08/16 03:32:41 DEBUG : >WaitForWriters: 2026/08/16 03:33:02 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:33:02 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:33:03 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:33:23 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:33:23 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:33:24 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:33:42 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:33:42 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:33:43 DEBUG : pacer: low level retry 2/10 (error Error "Server Error") 2026/08/16 03:33:43 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:33:44 DEBUG : pacer: Reducing sleep to 20ms --- FAIL: TestDirFileOpen (78.17s) === RUN TestFileRename === RUN TestFileRename/off,forceCache=false run.go:198: Remote "drime root 'rclone-test-jayajov6xawo'", Local "Local file system at /tmp/rclone1823064743", Modify Window "876000h0m0s" 2026/08/16 03:33:44 INFO : drime root 'rclone-test-jayajov6xawo': poll-interval is not supported by this remote 2026/08/16 03:33:44 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:33:44 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:33:45 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:33:46 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:33:47 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:33:47 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:33:48 DEBUG : pacer: Reducing sleep to 10ms run.go:303: Failed to put "dir/file1" to "drime root 'rclone-test-jayajov6xawo'": failed to make directory: failed to create folder: Error "422 Unprocessable Entity (422): {\"message\":\"\",\"errors\":{\"name\":\"Folder with same name already exists.\"}}" 2026/08/16 03:33:48 DEBUG : WaitForWriters: timeout=30s 2026/08/16 03:33:48 DEBUG : Looking for writers 2026/08/16 03:33:48 DEBUG : >WaitForWriters: === RUN TestFileRename/full,forceCache=false run.go:198: Remote "drime root 'rclone-test-jayajov6xawo'", Local "Local file system at /tmp/rclone1823064743", Modify Window "876000h0m0s" 2026/08/16 03:34:08 INFO : drime root 'rclone-test-jayajov6xawo': poll-interval is not supported by this remote 2026/08/16 03:34:08 DEBUG : drime root 'rclone-test-jayajov6xawo': vfs cache: root is "/home/rclone/.cache/rclone" 2026/08/16 03:34:08 DEBUG : drime root 'rclone-test-jayajov6xawo': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestDrime/rclone-test-jayajov6xawo" 2026/08/16 03:34:08 DEBUG : drime root 'rclone-test-jayajov6xawo': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestDrime/rclone-test-jayajov6xawo" 2026/08/16 03:34:08 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestDrime/rclone-test-jayajov6xawo" 2026/08/16 03:34:08 DEBUG : Config file has changed externally - reloading 2026/08/16 03:34:08 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/08/16 03:34:08 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestDrime/rclone-test-jayajov6xawo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestDrime/rclone-test-jayajov6xawo" 2026/08/16 03:34:08 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestDrime/rclone-test-jayajov6xawo" 2026/08/16 03:34:08 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/08/16 03:34:08 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestDrime/rclone-test-jayajov6xawo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestDrime/rclone-test-jayajov6xawo" 2026/08/16 03:34:08 INFO : drime root 'rclone-test-jayajov6xawo': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2026/08/16 03:34:08 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:34:08 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:34:08 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:34:08 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:34:08 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:34:08 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:34:08 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:34:08 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:34:09 DEBUG : pacer: Reducing sleep to 10ms run.go:303: Failed to put "dir/file1" to "drime root 'rclone-test-jayajov6xawo'": failed to make directory: failed to create folder: Error "422 Unprocessable Entity (422): {\"message\":\"\",\"errors\":{\"name\":\"Folder with same name already exists.\"}}" 2026/08/16 03:34:09 DEBUG : WaitForWriters: timeout=30s 2026/08/16 03:34:09 DEBUG : Looking for writers 2026/08/16 03:34:09 DEBUG : >WaitForWriters: 2026/08/16 03:34:09 DEBUG : drime root 'rclone-test-jayajov6xawo': vfs cache: cleaner exiting --- FAIL: TestFileRename (43.38s) --- FAIL: TestFileRename/off,forceCache=false (23.91s) --- FAIL: TestFileRename/full,forceCache=false (19.47s) === RUN TestReadFileHandleMethods run.go:198: Remote "drime root 'rclone-test-jayajov6xawo'", Local "Local file system at /tmp/rclone1823064743", Modify Window "876000h0m0s" 2026/08/16 03:34:27 INFO : drime root 'rclone-test-jayajov6xawo': poll-interval is not supported by this remote 2026/08/16 03:34:32 DEBUG : dir/file1: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/08/16 03:34:33 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:34:33 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:34:34 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:34:34 DEBUG : dir/file1: Open: flags=O_RDONLY 2026/08/16 03:34:34 DEBUG : dir/file1: >Open: fd=dir/file1 (r), err= 2026/08/16 03:34:34 DEBUG : dir/file1: >OpenFile: fd=dir/file1 (r), err= 2026/08/16 03:34:34 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728 2026/08/16 03:34:35 DEBUG : dir/file1: ChunkedReader.Read at 0 length 1 chunkOffset 0 chunkSize 134217728 2026/08/16 03:34:35 DEBUG : dir/file1: ChunkedReader.Read at 1 length 256 chunkOffset 0 chunkSize 134217728 2026/08/16 03:34:35 DEBUG : WaitForWriters: timeout=30s 2026/08/16 03:34:35 DEBUG : dir: Looking for writers 2026/08/16 03:34:35 DEBUG : file1: reading active writers 2026/08/16 03:34:35 DEBUG : Looking for writers 2026/08/16 03:34:35 DEBUG : dir: reading active writers 2026/08/16 03:34:35 DEBUG : >WaitForWriters: 2026/08/16 03:35:12 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:35:12 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:35:12 DEBUG : pacer: Reducing sleep to 10ms --- PASS: TestReadFileHandleMethods (45.04s) === RUN TestRWFileHandleSeek run.go:198: Remote "drime root 'rclone-test-jayajov6xawo'", Local "Local file system at /tmp/rclone1823064743", Modify Window "876000h0m0s" 2026/08/16 03:35:12 INFO : drime root 'rclone-test-jayajov6xawo': poll-interval is not supported by this remote 2026/08/16 03:35:12 DEBUG : drime root 'rclone-test-jayajov6xawo': vfs cache: root is "/home/rclone/.cache/rclone" 2026/08/16 03:35:12 DEBUG : drime root 'rclone-test-jayajov6xawo': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestDrime/rclone-test-jayajov6xawo" 2026/08/16 03:35:12 DEBUG : drime root 'rclone-test-jayajov6xawo': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestDrime/rclone-test-jayajov6xawo" 2026/08/16 03:35:12 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestDrime/rclone-test-jayajov6xawo" 2026/08/16 03:35:12 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/08/16 03:35:12 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestDrime/rclone-test-jayajov6xawo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestDrime/rclone-test-jayajov6xawo" 2026/08/16 03:35:12 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestDrime/rclone-test-jayajov6xawo" 2026/08/16 03:35:12 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/08/16 03:35:12 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestDrime/rclone-test-jayajov6xawo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestDrime/rclone-test-jayajov6xawo" 2026/08/16 03:35:12 INFO : drime root 'rclone-test-jayajov6xawo': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2026/08/16 03:35:13 DEBUG : pacer: low level retry 1/1 (error Error "Server Error") 2026/08/16 03:35:13 DEBUG : pacer: Rate limited, increasing sleep to 20ms run.go:299: Retry Put of "dir/file1" to drime root 'rclone-test-jayajov6xawo': 1/10 (failed to upload file: Error "Server Error") 2026/08/16 03:35:16 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:35:16 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:35:16 DEBUG : pacer: low level retry 2/10 (error Error "Server Error") 2026/08/16 03:35:16 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2026/08/16 03:35:17 DEBUG : pacer: Reducing sleep to 40ms 2026/08/16 03:35:18 DEBUG : pacer: low level retry 1/1 (error Error "Server Error") 2026/08/16 03:35:18 DEBUG : pacer: Rate limited, increasing sleep to 80ms run.go:299: Retry Put of "dir/file1" to drime root 'rclone-test-jayajov6xawo': 2/10 (failed to upload file: Error "Server Error") 2026/08/16 03:35:21 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:35:21 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2026/08/16 03:35:22 DEBUG : pacer: low level retry 2/10 (error Error "Server Error") 2026/08/16 03:35:22 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2026/08/16 03:35:23 DEBUG : pacer: Reducing sleep to 160ms 2026/08/16 03:35:24 DEBUG : pacer: low level retry 1/1 (error Error "Server Error") 2026/08/16 03:35:24 DEBUG : pacer: Rate limited, increasing sleep to 320ms run.go:299: Retry Put of "dir/file1" to drime root 'rclone-test-jayajov6xawo': 3/10 (failed to upload file: Error "Server Error") 2026/08/16 03:35:26 DEBUG : pacer: Reducing sleep to 160ms 2026/08/16 03:35:27 DEBUG : pacer: Reducing sleep to 80ms 2026/08/16 03:35:27 DEBUG : dir/file1: Removing old object on successful upload 2026/08/16 03:35:27 DEBUG : pacer: Reducing sleep to 40ms 2026/08/16 03:35:27 DEBUG : dir/file1: Old object already deleted, safely ignoring 2026/08/16 03:35:27 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:35:27 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2026/08/16 03:35:27 DEBUG : pacer: Reducing sleep to 40ms 2026/08/16 03:35:28 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:35:28 DEBUG : dir/file1: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/08/16 03:35:28 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:35:28 DEBUG : dir/file1: Open: flags=O_RDONLY 2026/08/16 03:35:28 DEBUG : dir/file1: newRWFileHandle: 2026/08/16 03:35:28 DEBUG : dir/file1: >newRWFileHandle: err= 2026/08/16 03:35:28 DEBUG : dir/file1: >Open: fd=dir/file1 (rw), err= 2026/08/16 03:35:28 DEBUG : dir/file1: >OpenFile: fd=dir/file1 (rw), err= 2026/08/16 03:35:28 DEBUG : dir/file1(0x3ae79a028740): _readAt: size=1, off=0 2026/08/16 03:35:28 DEBUG : dir/file1(0x3ae79a028740): openPending: 2026/08/16 03:35:28 DEBUG : dir/file1: vfs cache: checking remote fingerprint "16" against cached fingerprint "" 2026/08/16 03:35:28 DEBUG : dir/file1: vfs cache: truncate to size=16 2026/08/16 03:35:28 DEBUG : dir: Added virtual directory entry vAddFile: "file1" 2026/08/16 03:35:28 DEBUG : dir/file1(0x3ae79a028740): >openPending: err= 2026/08/16 03:35:28 DEBUG : vfs cache: looking for range={Pos:0 Size:1} in [] - present false 2026/08/16 03:35:28 DEBUG : dir/file1: ChunkedReader.RangeSeek from -1 to 0 length -1 2026/08/16 03:35:28 DEBUG : dir/file1: ChunkedReader.Read at -1 length 32768 chunkOffset 0 chunkSize 134217728 2026/08/16 03:35:28 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728 2026/08/16 03:35:29 DEBUG : dir/file1(0x3ae79a028740): >_readAt: n=1, err= 2026/08/16 03:35:29 DEBUG : dir/file1(0x3ae79a028740): _readAt: size=1, off=5 2026/08/16 03:35:29 DEBUG : vfs cache: looking for range={Pos:5 Size:1} in [{Pos:0 Size:16}] - present true 2026/08/16 03:35:29 DEBUG : dir/file1(0x3ae79a028740): >_readAt: n=1, err= 2026/08/16 03:35:29 DEBUG : dir/file1(0x3ae79a028740): _readAt: size=1, off=3 2026/08/16 03:35:29 DEBUG : vfs cache: looking for range={Pos:3 Size:1} in [{Pos:0 Size:16}] - present true 2026/08/16 03:35:29 DEBUG : dir/file1(0x3ae79a028740): >_readAt: n=1, err= 2026/08/16 03:35:29 DEBUG : dir/file1(0x3ae79a028740): _readAt: size=1, off=13 2026/08/16 03:35:29 DEBUG : vfs cache: looking for range={Pos:13 Size:1} in [{Pos:0 Size:16}] - present true 2026/08/16 03:35:29 DEBUG : dir/file1(0x3ae79a028740): >_readAt: n=1, err= 2026/08/16 03:35:29 DEBUG : dir/file1(0x3ae79a028740): _readAt: size=16, off=100 2026/08/16 03:35:29 DEBUG : dir/file1(0x3ae79a028740): >_readAt: n=0, err=EOF 2026/08/16 03:35:29 DEBUG : dir/file1(0x3ae79a028740): close: 2026/08/16 03:35:29 DEBUG : dir/file1(0x3ae79a028740): >close: err= 2026/08/16 03:35:29 DEBUG : WaitForWriters: timeout=30s 2026/08/16 03:35:29 DEBUG : dir: Looking for writers 2026/08/16 03:35:29 DEBUG : file1: reading active writers 2026/08/16 03:35:29 DEBUG : Looking for writers 2026/08/16 03:35:29 DEBUG : dir: reading active writers 2026/08/16 03:35:29 DEBUG : >WaitForWriters: 2026/08/16 03:35:29 DEBUG : drime root 'rclone-test-jayajov6xawo': vfs cache: cleaner exiting 2026/08/16 03:35:34 ERROR : dir/file1: vfs cache: item close failed: vfs cache item: failed to write metadata: open /home/rclone/.cache/rclone/vfsMeta/TestDrime/rclone-test-jayajov6xawo/dir/file1: no such file or directory 2026/08/16 03:35:34 ERROR : dir/file1: vfs cache: close after grace period failed: vfs cache item: failed to write metadata: open /home/rclone/.cache/rclone/vfsMeta/TestDrime/rclone-test-jayajov6xawo/dir/file1: no such file or directory 2026/08/16 03:35:49 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:35:49 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:35:50 DEBUG : pacer: Reducing sleep to 10ms --- PASS: TestRWFileHandleSeek (56.31s) === RUN TestRWFileHandleReleaseRead run.go:198: Remote "drime root 'rclone-test-jayajov6xawo'", Local "Local file system at /tmp/rclone1823064743", Modify Window "876000h0m0s" 2026/08/16 03:36:08 INFO : drime root 'rclone-test-jayajov6xawo': poll-interval is not supported by this remote 2026/08/16 03:36:08 DEBUG : drime root 'rclone-test-jayajov6xawo': vfs cache: root is "/home/rclone/.cache/rclone" 2026/08/16 03:36:08 DEBUG : drime root 'rclone-test-jayajov6xawo': vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestDrime/rclone-test-jayajov6xawo" 2026/08/16 03:36:08 DEBUG : drime root 'rclone-test-jayajov6xawo': vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestDrime/rclone-test-jayajov6xawo" 2026/08/16 03:36:08 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestDrime/rclone-test-jayajov6xawo" 2026/08/16 03:36:08 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/08/16 03:36:08 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestDrime/rclone-test-jayajov6xawo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestDrime/rclone-test-jayajov6xawo" 2026/08/16 03:36:08 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestDrime/rclone-test-jayajov6xawo" 2026/08/16 03:36:08 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/08/16 03:36:08 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestDrime/rclone-test-jayajov6xawo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestDrime/rclone-test-jayajov6xawo" 2026/08/16 03:36:08 INFO : drime root 'rclone-test-jayajov6xawo': vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2026/08/16 03:36:09 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:36:09 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:36:09 DEBUG : pacer: low level retry 2/10 (error Error "Server Error") 2026/08/16 03:36:09 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:36:10 DEBUG : pacer: low level retry 3/10 (error Error "Server Error") 2026/08/16 03:36:10 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2026/08/16 03:36:10 DEBUG : pacer: low level retry 4/10 (error Error "Server Error") 2026/08/16 03:36:10 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2026/08/16 03:36:11 DEBUG : pacer: Reducing sleep to 80ms 2026/08/16 03:36:11 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:36:11 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2026/08/16 03:36:11 DEBUG : pacer: Reducing sleep to 80ms 2026/08/16 03:36:11 DEBUG : pacer: Reducing sleep to 40ms 2026/08/16 03:36:12 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:36:12 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:36:12 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:36:12 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:36:12 DEBUG : pacer: low level retry 2/10 (error Error "Server Error") 2026/08/16 03:36:12 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:36:12 DEBUG : pacer: low level retry 3/10 (error Error "Server Error") 2026/08/16 03:36:12 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2026/08/16 03:36:13 DEBUG : pacer: low level retry 4/10 (error Error "Server Error") 2026/08/16 03:36:13 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2026/08/16 03:36:13 DEBUG : pacer: low level retry 5/10 (error Error "Server Error") 2026/08/16 03:36:13 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2026/08/16 03:36:13 DEBUG : pacer: Reducing sleep to 160ms 2026/08/16 03:36:13 DEBUG : dir/file1: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/08/16 03:36:13 DEBUG : pacer: Reducing sleep to 80ms 2026/08/16 03:36:13 DEBUG : pacer: Reducing sleep to 40ms 2026/08/16 03:36:13 DEBUG : dir/file1: Open: flags=O_RDONLY 2026/08/16 03:36:13 DEBUG : dir/file1: newRWFileHandle: 2026/08/16 03:36:13 DEBUG : dir/file1: >newRWFileHandle: err= 2026/08/16 03:36:13 DEBUG : dir/file1: >Open: fd=dir/file1 (rw), err= 2026/08/16 03:36:13 DEBUG : dir/file1: >OpenFile: fd=dir/file1 (rw), err= 2026/08/16 03:36:13 DEBUG : dir/file1(0x3ae799f6b440): _readAt: size=256, off=0 2026/08/16 03:36:13 DEBUG : dir/file1(0x3ae799f6b440): openPending: 2026/08/16 03:36:13 DEBUG : dir/file1: vfs cache: checking remote fingerprint "16" against cached fingerprint "" 2026/08/16 03:36:13 DEBUG : dir/file1: vfs cache: truncate to size=16 2026/08/16 03:36:13 DEBUG : dir: Added virtual directory entry vAddFile: "file1" 2026/08/16 03:36:13 DEBUG : dir/file1(0x3ae799f6b440): >openPending: err= 2026/08/16 03:36:13 DEBUG : vfs cache: looking for range={Pos:0 Size:16} in [] - present false 2026/08/16 03:36:13 DEBUG : dir/file1: ChunkedReader.RangeSeek from -1 to 0 length -1 2026/08/16 03:36:13 DEBUG : dir/file1: ChunkedReader.Read at -1 length 32768 chunkOffset 0 chunkSize 134217728 2026/08/16 03:36:13 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728 2026/08/16 03:36:14 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:36:14 DEBUG : dir/file1(0x3ae799f6b440): >_readAt: n=16, err=EOF 2026/08/16 03:36:14 DEBUG : dir/file1(0x3ae799f6b440): RWFileHandle.Release 2026/08/16 03:36:14 DEBUG : dir/file1(0x3ae799f6b440): close: 2026/08/16 03:36:14 DEBUG : dir/file1(0x3ae799f6b440): >close: err= 2026/08/16 03:36:14 DEBUG : dir/file1(0x3ae799f6b440): RWFileHandle.Release 2026/08/16 03:36:14 DEBUG : WaitForWriters: timeout=30s 2026/08/16 03:36:14 DEBUG : dir: Looking for writers 2026/08/16 03:36:14 DEBUG : file1: reading active writers 2026/08/16 03:36:14 DEBUG : Looking for writers 2026/08/16 03:36:14 DEBUG : dir: reading active writers 2026/08/16 03:36:14 DEBUG : >WaitForWriters: 2026/08/16 03:36:14 DEBUG : drime root 'rclone-test-jayajov6xawo': vfs cache: cleaner exiting 2026/08/16 03:36:14 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:36:14 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:36:14 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:36:14 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:36:19 ERROR : dir/file1: vfs cache: item close failed: vfs cache item: failed to write metadata: open /home/rclone/.cache/rclone/vfsMeta/TestDrime/rclone-test-jayajov6xawo/dir/file1: no such file or directory 2026/08/16 03:36:19 ERROR : dir/file1: vfs cache: close after grace period failed: vfs cache item: failed to write metadata: open /home/rclone/.cache/rclone/vfsMeta/TestDrime/rclone-test-jayajov6xawo/dir/file1: no such file or directory 2026/08/16 03:36:33 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:36:33 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:36:34 DEBUG : pacer: low level retry 2/10 (error Error "Server Error") 2026/08/16 03:36:34 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:36:52 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:36:53 DEBUG : pacer: Reducing sleep to 10ms --- PASS: TestRWFileHandleReleaseRead (44.08s) === RUN TestVFSOpenFile run.go:198: Remote "drime root 'rclone-test-jayajov6xawo'", Local "Local file system at /tmp/rclone1823064743", Modify Window "876000h0m0s" 2026/08/16 03:36:53 INFO : drime root 'rclone-test-jayajov6xawo': poll-interval is not supported by this remote 2026/08/16 03:36:54 DEBUG : pacer: low level retry 1/1 (error Error "Server Error") 2026/08/16 03:36:54 DEBUG : pacer: Rate limited, increasing sleep to 20ms run.go:299: Retry Put of "file1" to drime root 'rclone-test-jayajov6xawo': 1/10 (failed to upload file: Error "Server Error") 2026/08/16 03:36:56 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:36:57 DEBUG : pacer: low level retry 1/1 (error Error "Server Error") 2026/08/16 03:36:57 DEBUG : pacer: Rate limited, increasing sleep to 20ms run.go:299: Retry Put of "file1" to drime root 'rclone-test-jayajov6xawo': 2/10 (failed to upload file: Error "Server Error") 2026/08/16 03:37:00 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:37:01 DEBUG : pacer: low level retry 1/1 (error Error "Server Error") 2026/08/16 03:37:01 DEBUG : pacer: Rate limited, increasing sleep to 20ms run.go:299: Retry Put of "file1" to drime root 'rclone-test-jayajov6xawo': 3/10 (failed to upload file: Error "Server Error") 2026/08/16 03:37:03 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:37:03 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:37:04 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:37:04 DEBUG : pacer: low level retry 1/1 (error Error "Server Error") 2026/08/16 03:37:04 DEBUG : pacer: Rate limited, increasing sleep to 40ms run.go:299: Retry Put of "file1" to drime root 'rclone-test-jayajov6xawo': 4/10 (failed to upload file: Error "Server Error") 2026/08/16 03:37:06 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:37:06 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2026/08/16 03:37:06 DEBUG : pacer: low level retry 2/10 (error Error "Server Error") 2026/08/16 03:37:06 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2026/08/16 03:37:07 DEBUG : pacer: Reducing sleep to 80ms 2026/08/16 03:37:07 DEBUG : pacer: low level retry 1/1 (error Error "Server Error") 2026/08/16 03:37:07 DEBUG : pacer: Rate limited, increasing sleep to 160ms run.go:299: Retry Put of "file1" to drime root 'rclone-test-jayajov6xawo': 5/10 (failed to upload file: Error "Server Error") 2026/08/16 03:37:09 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:37:09 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2026/08/16 03:37:09 DEBUG : pacer: Reducing sleep to 160ms 2026/08/16 03:37:09 DEBUG : pacer: low level retry 1/1 (error Error "Server Error") 2026/08/16 03:37:09 DEBUG : pacer: Rate limited, increasing sleep to 320ms run.go:299: Retry Put of "file1" to drime root 'rclone-test-jayajov6xawo': 6/10 (failed to upload file: Error "Server Error") 2026/08/16 03:37:12 DEBUG : pacer: Reducing sleep to 160ms 2026/08/16 03:37:13 DEBUG : pacer: low level retry 1/1 (error Error "Server Error") 2026/08/16 03:37:13 DEBUG : pacer: Rate limited, increasing sleep to 320ms run.go:299: Retry Put of "file1" to drime root 'rclone-test-jayajov6xawo': 7/10 (failed to upload file: Error "Server Error") 2026/08/16 03:37:15 DEBUG : pacer: Reducing sleep to 160ms 2026/08/16 03:37:16 DEBUG : pacer: Reducing sleep to 80ms 2026/08/16 03:37:16 DEBUG : file1: Removing old object on successful upload 2026/08/16 03:37:16 DEBUG : pacer: Reducing sleep to 40ms 2026/08/16 03:37:16 DEBUG : file1: Old object already deleted, safely ignoring 2026/08/16 03:37:16 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:37:17 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:37:20 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/08/16 03:37:20 DEBUG : file1: Open: flags=O_RDONLY 2026/08/16 03:37:20 DEBUG : file1: >Open: fd=file1 (r), err= 2026/08/16 03:37:20 DEBUG : file1: >OpenFile: fd=file1 (r), err= 2026/08/16 03:37:20 DEBUG : dir: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/08/16 03:37:20 DEBUG : dir: >OpenFile: fd=dir/ (r), err= 2026/08/16 03:37:20 DEBUG : dir/new_file.txt: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2026/08/16 03:37:20 DEBUG : dir/new_file.txt: >OpenFile: fd=, err=file does not exist 2026/08/16 03:37:20 DEBUG : dir/new_file.txt: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/08/16 03:37:20 DEBUG : dir/new_file.txt: Open: flags=O_WRONLY|O_CREATE 2026/08/16 03:37:20 DEBUG : dir: Added virtual directory entry vAddFile: "new_file.txt" 2026/08/16 03:37:20 DEBUG : dir/new_file.txt: >Open: fd=dir/new_file.txt (w), err= 2026/08/16 03:37:20 DEBUG : dir/new_file.txt: >OpenFile: fd=dir/new_file.txt (w), err= 2026/08/16 03:37:20 DEBUG : dir: Added virtual directory entry vAddFile: "new_file.txt" 2026/08/16 03:37:20 DEBUG : drime root 'rclone-test-jayajov6xawo': File to upload is small (0 bytes), uploading instead of streaming 2026/08/16 03:37:21 DEBUG : dir/new_file.txt: size = 0 OK 2026/08/16 03:37:21 NOTICE: drime root 'rclone-test-jayajov6xawo': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2026/08/16 03:37:21 DEBUG : dir/new_file.txt: Size of src and dst objects identical 2026/08/16 03:37:21 DEBUG : dir: Added virtual directory entry vAddFile: "new_file.txt" 2026/08/16 03:37:21 DEBUG : not found/new_file.txt: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/08/16 03:37:21 DEBUG : not found/new_file.txt: >OpenFile: fd=, err=file does not exist 2026/08/16 03:37:21 DEBUG : WaitForWriters: timeout=30s 2026/08/16 03:37:21 DEBUG : dir: Looking for writers 2026/08/16 03:37:21 DEBUG : file2: reading active writers 2026/08/16 03:37:21 DEBUG : new_file.txt: reading active writers 2026/08/16 03:37:21 DEBUG : Looking for writers 2026/08/16 03:37:21 DEBUG : file1: reading active writers 2026/08/16 03:37:21 DEBUG : dir: reading active writers 2026/08/16 03:37:21 DEBUG : >WaitForWriters: 2026/08/16 03:37:21 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:37:21 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:37:21 DEBUG : pacer: Reducing sleep to 10ms --- PASS: TestVFSOpenFile (102.64s) === RUN TestVFSMkdirAll run.go:198: Remote "drime root 'rclone-test-jayajov6xawo'", Local "Local file system at /tmp/rclone1823064743", Modify Window "876000h0m0s" 2026/08/16 03:38:35 INFO : drime root 'rclone-test-jayajov6xawo': poll-interval is not supported by this remote 2026/08/16 03:38:35 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:38:35 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:38:36 DEBUG : pacer: low level retry 2/10 (error Error "Server Error") 2026/08/16 03:38:36 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:38:36 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:38:36 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:38:36 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:38:36 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:38:36 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:38:36 ERROR : /: Dir.Mkdir failed to create directory: failed to make directory: failed to create folder: Error "422 Unprocessable Entity (422): {\"message\":\"\",\"errors\":{\"name\":\"Folder with same name already exists.\"}}" vfs_test.go:425: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/vfs_test.go:425 Error: Received unexpected error: failed to make directory: failed to create folder: Error "422 Unprocessable Entity (422): {\"message\":\"\",\"errors\":{\"name\":\"Folder with same name already exists.\"}}" Test: TestVFSMkdirAll 2026/08/16 03:38:36 DEBUG : WaitForWriters: timeout=30s 2026/08/16 03:38:36 DEBUG : Looking for writers 2026/08/16 03:38:36 DEBUG : >WaitForWriters: fstest.go:298: Sleeping for 1s for list eventual consistency: 1/5 fstest.go:301: Flushing the directory cache 2026/08/16 03:38:39 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:38:39 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:38:39 DEBUG : pacer: low level retry 2/10 (error Error "Server Error") 2026/08/16 03:38:39 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:38:40 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:38:40 DEBUG : pacer: Reducing sleep to 10ms fstest.go:298: Sleeping for 2s for list eventual consistency: 2/5 fstest.go:301: Flushing the directory cache fstest.go:298: Sleeping for 4s for list eventual consistency: 3/5 fstest.go:301: Flushing the directory cache 2026/08/16 03:38:47 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:38:47 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:38:48 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:38:49 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:38:49 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:38:49 DEBUG : pacer: low level retry 2/10 (error Error "Server Error") 2026/08/16 03:38:49 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:38:50 DEBUG : pacer: Reducing sleep to 20ms fstest.go:298: Sleeping for 8s for list eventual consistency: 4/5 fstest.go:301: Flushing the directory cache 2026/08/16 03:38:58 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:38:58 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:38:59 DEBUG : pacer: low level retry 2/10 (error Error "Server Error") 2026/08/16 03:38:59 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2026/08/16 03:39:00 DEBUG : pacer: Reducing sleep to 40ms 2026/08/16 03:39:01 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:39:01 DEBUG : forgetting directory cache 2026/08/16 03:39:01 DEBUG : Removed virtual directory entry vDel: "dir" 2026/08/16 03:39:01 DEBUG : dir: forgetting directory cache 2026/08/16 03:39:01 DEBUG : dir: Removed virtual directory entry vDel: "file1" 2026/08/16 03:39:01 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:39:01 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:39:02 DEBUG : pacer: Reducing sleep to 20ms fstest.go:298: Sleeping for 16s for list eventual consistency: 5/5 fstest.go:301: Flushing the directory cache fstest.go:327: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:327 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /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:1317 /usr/local/go/src/testing/testing.go:1667 /usr/local/go/src/testing/testing.go:2030 /usr/local/go/src/runtime/panic.go:694 /usr/local/go/src/testing/testing.go:1022 /home/rclone/go/src/github.com/rclone/rclone/vfs/vfs_test.go:425 Error: Not equal: expected: []string{} actual : []string{"a"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) { +([]string) (len=1) { + (string) (len=1) "a" } Test: TestVFSMkdirAll Messages: directories --- FAIL: TestVFSMkdirAll (42.61s) === RUN TestZipLargeFiles run.go:198: Remote "drime root 'rclone-test-jayajov6xawo'", Local "Local file system at /tmp/rclone1823064743", Modify Window "876000h0m0s" 2026/08/16 03:39:18 INFO : drime root 'rclone-test-jayajov6xawo': poll-interval is not supported by this remote 2026/08/16 03:39:18 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:39:18 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:39:18 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:39:19 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:39:21 DEBUG : bigdir/big.bin: Open: flags=O_RDONLY 2026/08/16 03:39:21 DEBUG : bigdir/big.bin: >Open: fd=bigdir/big.bin (r), err= 2026/08/16 03:39:21 DEBUG : bigdir/big.bin: Set virtual modtime to 2026-08-16 03:39:20 +0000 UTC 2026/08/16 03:39:21 DEBUG : bigdir/big.bin: ChunkedReader.openRange at 0 length 134217728 2026/08/16 03:39:21 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:39:21 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:39:21 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:39:21 DEBUG : bigdir/big.bin: ChunkedReader.Read at 0 length 4096 chunkOffset 0 chunkSize 134217728 2026/08/16 03:39:21 DEBUG : bigdir/big.bin: ChunkedReader.Read at 4096 length 8192 chunkOffset 0 chunkSize 134217728 2026/08/16 03:39:21 DEBUG : bigdir/big.bin: ChunkedReader.Read at 12288 length 16384 chunkOffset 0 chunkSize 134217728 2026/08/16 03:39:21 DEBUG : bigdir/big.bin: ChunkedReader.Read at 28672 length 32768 chunkOffset 0 chunkSize 134217728 2026/08/16 03:39:21 DEBUG : bigdir/big.bin: ChunkedReader.Read at 61440 length 65536 chunkOffset 0 chunkSize 134217728 2026/08/16 03:39:21 DEBUG : bigdir/big.bin: ChunkedReader.Read at 126976 length 131072 chunkOffset 0 chunkSize 134217728 2026/08/16 03:39:21 DEBUG : bigdir/big.bin: ChunkedReader.Read at 258048 length 262144 chunkOffset 0 chunkSize 134217728 2026/08/16 03:39:21 DEBUG : bigdir/big.bin: ChunkedReader.Read at 520192 length 524288 chunkOffset 0 chunkSize 134217728 2026/08/16 03:39:21 DEBUG : bigdir/big.bin: ChunkedReader.Read at 1044480 length 1048576 chunkOffset 0 chunkSize 134217728 2026/08/16 03:39:21 DEBUG : bigdir/big.bin: ChunkedReader.Read at 2093056 length 1048576 chunkOffset 0 chunkSize 134217728 2026/08/16 03:39:21 DEBUG : bigdir/big.bin: ChunkedReader.Read at 3141632 length 1048576 chunkOffset 0 chunkSize 134217728 2026/08/16 03:39:21 DEBUG : bigdir/big.bin: ChunkedReader.Read at 4190208 length 1048576 chunkOffset 0 chunkSize 134217728 2026/08/16 03:39:21 DEBUG : bigdir/big.bin: ChunkedReader.Read at 5238784 length 1048576 chunkOffset 0 chunkSize 134217728 2026/08/16 03:39:22 DEBUG : WaitForWriters: timeout=30s 2026/08/16 03:39:22 DEBUG : a: Looking for writers 2026/08/16 03:39:22 DEBUG : bigdir: Looking for writers 2026/08/16 03:39:22 DEBUG : big.bin: reading active writers 2026/08/16 03:39:22 DEBUG : Looking for writers 2026/08/16 03:39:22 DEBUG : a: reading active writers 2026/08/16 03:39:22 DEBUG : bigdir: reading active writers 2026/08/16 03:39:22 DEBUG : >WaitForWriters: 2026/08/16 03:39:39 DEBUG : forgetting directory cache --- PASS: TestZipLargeFiles (64.11s) === RUN TestZipDirsInRoot run.go:198: Remote "drime root 'rclone-test-jayajov6xawo'", Local "Local file system at /tmp/rclone1823064743", Modify Window "876000h0m0s" 2026/08/16 03:40:22 INFO : drime root 'rclone-test-jayajov6xawo': poll-interval is not supported by this remote 2026/08/16 03:40:23 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:40:23 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:40:23 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:40:25 DEBUG : pacer: low level retry 1/1 (error Error "Server Error") 2026/08/16 03:40:25 DEBUG : pacer: Rate limited, increasing sleep to 20ms run.go:299: Retry Put of "dir2/b.txt" to drime root 'rclone-test-jayajov6xawo': 1/10 (failed to upload file: Error "Server Error") 2026/08/16 03:40:28 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:40:28 DEBUG : forgetting directory cache 2026/08/16 03:40:28 DEBUG : dir3: forgetting directory cache 2026/08/16 03:40:28 DEBUG : dir3: Removed virtual directory entry vAddFile: "file3" 2026/08/16 03:40:28 DEBUG : dir3: Removed virtual directory entry vDel: "file1" 2026/08/16 03:40:28 DEBUG : renamed empty directory: forgetting directory cache 2026/08/16 03:40:28 DEBUG : Removed virtual directory entry vAddDir: "renamed empty directory" 2026/08/16 03:40:28 DEBUG : Removed virtual directory entry vDel: "dir" 2026/08/16 03:40:28 DEBUG : Removed virtual directory entry vAddDir: "dir2" 2026/08/16 03:40:28 DEBUG : Removed virtual directory entry vDel: "file2" 2026/08/16 03:40:28 DEBUG : Removed virtual directory entry vDel: "empty directory" 2026/08/16 03:40:29 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:40:29 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:40:29 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:40:30 DEBUG : dir1/a.txt: Open: flags=O_RDONLY 2026/08/16 03:40:30 DEBUG : dir1/a.txt: >Open: fd=dir1/a.txt (r), err= 2026/08/16 03:40:30 DEBUG : dir1/a.txt: Set virtual modtime to 2026-08-16 03:40:24 +0000 UTC 2026/08/16 03:40:30 DEBUG : dir1/a.txt: ChunkedReader.openRange at 0 length 134217728 2026/08/16 03:40:30 DEBUG : dir1/a.txt: ChunkedReader.Read at 0 length 32768 chunkOffset 0 chunkSize 134217728 2026/08/16 03:40:31 DEBUG : dir2/b.txt: Open: flags=O_RDONLY 2026/08/16 03:40:31 DEBUG : dir2/b.txt: >Open: fd=dir2/b.txt (r), err= 2026/08/16 03:40:31 DEBUG : dir2/b.txt: Set virtual modtime to 2026-08-16 03:40:28 +0000 UTC 2026/08/16 03:40:31 DEBUG : dir2/b.txt: ChunkedReader.openRange at 0 length 134217728 2026/08/16 03:40:31 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:40:31 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:40:31 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:40:31 DEBUG : dir2/b.txt: ChunkedReader.Read at 0 length 32768 chunkOffset 0 chunkSize 134217728 2026/08/16 03:40:32 DEBUG : dir3/c.txt: Open: flags=O_RDONLY 2026/08/16 03:40:32 DEBUG : dir3/c.txt: >Open: fd=dir3/c.txt (r), err= 2026/08/16 03:40:32 DEBUG : dir3/c.txt: Set virtual modtime to 2026-08-16 03:40:29 +0000 UTC 2026/08/16 03:40:32 DEBUG : dir3/c.txt: ChunkedReader.openRange at 0 length 134217728 2026/08/16 03:40:32 DEBUG : dir3/c.txt: ChunkedReader.Read at 0 length 32768 chunkOffset 0 chunkSize 134217728 2026/08/16 03:40:32 DEBUG : WaitForWriters: timeout=30s 2026/08/16 03:40:32 DEBUG : dir1: Looking for writers 2026/08/16 03:40:32 DEBUG : a.txt: reading active writers 2026/08/16 03:40:32 DEBUG : dir2: Looking for writers 2026/08/16 03:40:32 DEBUG : b.txt: reading active writers 2026/08/16 03:40:32 DEBUG : dir3: Looking for writers 2026/08/16 03:40:32 DEBUG : c.txt: reading active writers 2026/08/16 03:40:32 DEBUG : Looking for writers 2026/08/16 03:40:32 DEBUG : dir1: reading active writers 2026/08/16 03:40:32 DEBUG : dir2: reading active writers 2026/08/16 03:40:32 DEBUG : dir3: reading active writers 2026/08/16 03:40:32 DEBUG : >WaitForWriters: 2026/08/16 03:40:50 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:40:50 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:41:07 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:41:25 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:41:25 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:41:26 DEBUG : pacer: low level retry 2/10 (error Error "Server Error") 2026/08/16 03:41:26 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/08/16 03:41:27 DEBUG : pacer: Reducing sleep to 20ms 2026/08/16 03:41:46 DEBUG : pacer: Reducing sleep to 10ms 2026/08/16 03:42:06 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:42:06 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:42:07 DEBUG : pacer: Reducing sleep to 10ms --- PASS: TestZipDirsInRoot (123.17s) FAIL 2026/08/16 03:42:25 DEBUG : drime root 'rclone-test-jayajov6xawo': Purge remote 2026/08/16 03:42:26 DEBUG : pacer: low level retry 1/10 (error Error "Server Error") 2026/08/16 03:42:26 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/16 03:42:39 DEBUG : forgetting directory cache 2026/08/16 03:42:39 DEBUG : dir: forgetting directory cache 2026/08/16 03:42:43 DEBUG : pacer: Reducing sleep to 10ms "./vfs.test -test.v -test.timeout 2h0m0s -remote TestDrime: -list-retries 5 -verbose -test.run '^(TestDirFileOpen|TestDirRemove|TestDirRemoveAll|TestDirRename|TestRWFileHandleReleaseRead|TestRWFileHandleSeek|TestReadFileHandleMethods|TestVFSMkdirAll|TestVFSOpenFile|TestZipDirsInRoot|TestZipLargeFiles)$|^TestFileRename$/^(full,forceCache=false|off,forceCache=false)$'" - Finished ERROR in 13m59.403637951s (try 2/5): exit status 1: Failed [TestDirRemoveAll TestDirFileOpen TestFileRename/off,forceCache=false TestFileRename/full,forceCache=false TestVFSMkdirAll]