"./vfs.test -test.v -test.timeout 1h0m0s -remote TestKoofr: -verbose -test.run '^(TestDirCreate|TestDirFileOpen|TestDirForgetAll|TestDirForgetPath|TestDirHandleMethods|TestDirHandleReaddir|TestDirHandleReaddirnames|TestDirMetadataExtension|TestDirMethods|TestDirMkdir|TestDirMkdirSub|TestDirOpen|TestDirReadDirAll|TestDirRemove|TestDirRemoveAll|TestDirRemoveName|TestDirRename|TestDirSetModTime|TestDirStat|TestDirWalk|TestFileMethods|TestFileOpen|TestFileOpenRead|TestFileOpenWrite|TestFileReadAtNonZeroLength|TestFileRemove|TestFileRemoveAll|TestRWCacheUpdate|TestRWFileHandleFlushRead|TestRWFileHandleMethodsRead|TestRWFileHandleMethodsWrite|TestRWFileHandleReadAt|TestRWFileHandleReleaseRead|TestRWFileHandleSeek|TestRWFileHandleSizeCreateExisting|TestRWFileHandleSizeTruncateExisting|TestRWFileHandleWriteAt|TestRWFileModTimeWithOpenWriters|TestReadFileHandleFlush|TestReadFileHandleMethods|TestReadFileHandleReadAt|TestReadFileHandleRelease|TestReadFileHandleSeek|TestUnicodeNormalization|TestVFSOpenFile|TestVFSRename|TestVFSStat|TestVFSStatParent|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileHandleWriteAt|TestWriteFileModTimeWithOpenWriters|TestZipDirsInRoot|TestZipLargeFiles|TestZipManyFiles|TestZipManySubDirs)$|^TestFileRename$/^(full,forceCache=false|minimal,forceCache=false|minimal,forceCache=true|off,forceCache=false|writes,forceCache=false|writes,forceCache=true)$|^TestFileSetModTime$/^(cache=full,open=false,write=false|cache=full,open=true,write=false|cache=full,open=true,write=true|cache=off,open=false,write=false|cache=off,open=true,write=false|cache=off,open=true,write=true)$'" - Starting (try 2/5) 2026/07/18 02:10:31 DEBUG : Creating backend with remote "TestKoofr:rclone-test-puzexax4kelo" 2026/07/18 02:10:31 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/07/18 02:10:32 DEBUG : Creating backend with remote "/tmp/rclone1798279652" === RUN TestDirHandleMethods run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:32 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:32 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[477f6b56-199e-4c4c-a36a-a101cfbeea4b] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=477f6b56-199e-4c4c-a36a-a101cfbeea4b) 2026/07/18 02:10:32 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:32 DEBUG : Looking for writers 2026/07/18 02:10:32 DEBUG : >WaitForWriters: --- FAIL: TestDirHandleMethods (0.66s) === RUN TestDirHandleReaddir run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:32 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:33 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[725f073b-7746-4bf4-8295-494e33355e64] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=725f073b-7746-4bf4-8295-494e33355e64) 2026/07/18 02:10:33 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:33 DEBUG : Looking for writers 2026/07/18 02:10:33 DEBUG : >WaitForWriters: --- FAIL: TestDirHandleReaddir (0.57s) === RUN TestDirHandleReaddirnames run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:33 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:33 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[ddfbfe50-e123-41a1-9a5b-c1ae5c751c45] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=ddfbfe50-e123-41a1-9a5b-c1ae5c751c45) 2026/07/18 02:10:33 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:33 DEBUG : Looking for writers 2026/07/18 02:10:33 DEBUG : >WaitForWriters: --- FAIL: TestDirHandleReaddirnames (0.49s) === RUN TestDirMethods run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:33 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:34 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[93986e79-d3af-4e98-a3df-c8776c956587] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=93986e79-d3af-4e98-a3df-c8776c956587) 2026/07/18 02:10:34 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:34 DEBUG : Looking for writers 2026/07/18 02:10:34 DEBUG : >WaitForWriters: --- FAIL: TestDirMethods (0.48s) === RUN TestDirForgetAll run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:34 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:34 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[cc149a13-7b14-480e-b3cf-413530339d00] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=cc149a13-7b14-480e-b3cf-413530339d00) 2026/07/18 02:10:34 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:34 DEBUG : Looking for writers 2026/07/18 02:10:34 DEBUG : >WaitForWriters: --- FAIL: TestDirForgetAll (0.49s) === RUN TestDirForgetPath run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:34 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:35 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[37894a8f-1753-40b2-a0cf-819a1edb3ad7] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=37894a8f-1753-40b2-a0cf-819a1edb3ad7) 2026/07/18 02:10:35 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:35 DEBUG : Looking for writers 2026/07/18 02:10:35 DEBUG : >WaitForWriters: --- FAIL: TestDirForgetPath (0.48s) === RUN TestDirWalk run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:35 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:35 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[bb5ecd51-e11c-4d02-8ae7-78564361a43a] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=bb5ecd51-e11c-4d02-8ae7-78564361a43a) 2026/07/18 02:10:35 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:35 DEBUG : Looking for writers 2026/07/18 02:10:35 DEBUG : >WaitForWriters: --- FAIL: TestDirWalk (0.48s) === RUN TestDirSetModTime run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:35 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:35 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[e2e498f1-6347-4824-a072-33923c3ebcae] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=e2e498f1-6347-4824-a072-33923c3ebcae) 2026/07/18 02:10:36 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:36 DEBUG : Looking for writers 2026/07/18 02:10:36 DEBUG : >WaitForWriters: --- FAIL: TestDirSetModTime (0.47s) === RUN TestDirStat run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:36 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:36 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[bd522715-9e6b-4c35-805b-3508205a71e7] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=bd522715-9e6b-4c35-805b-3508205a71e7) 2026/07/18 02:10:36 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:36 DEBUG : Looking for writers 2026/07/18 02:10:36 DEBUG : >WaitForWriters: --- FAIL: TestDirStat (0.63s) === RUN TestDirReadDirAll run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:36 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:37 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[13b0894c-c597-4771-97c5-554ebcaeb60a] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=13b0894c-c597-4771-97c5-554ebcaeb60a) 2026/07/18 02:10:37 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:37 DEBUG : Looking for writers 2026/07/18 02:10:37 DEBUG : >WaitForWriters: --- FAIL: TestDirReadDirAll (0.51s) === RUN TestDirOpen run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:37 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:37 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[d3ca855c-f712-4703-83f3-c2ff24b0360f] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=d3ca855c-f712-4703-83f3-c2ff24b0360f) 2026/07/18 02:10:37 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:37 DEBUG : Looking for writers 2026/07/18 02:10:37 DEBUG : >WaitForWriters: --- FAIL: TestDirOpen (0.49s) === RUN TestDirCreate run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:37 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:38 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[ad5a184a-a42b-4bdb-af0b-be64cf74f1ff] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=ad5a184a-a42b-4bdb-af0b-be64cf74f1ff) 2026/07/18 02:10:38 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:38 DEBUG : Looking for writers 2026/07/18 02:10:38 DEBUG : >WaitForWriters: --- FAIL: TestDirCreate (0.48s) === RUN TestDirMkdir run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:38 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:38 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[4e5cf566-152e-4ee1-b6c8-99f0ef882ed8] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=4e5cf566-152e-4ee1-b6c8-99f0ef882ed8) 2026/07/18 02:10:38 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:38 DEBUG : Looking for writers 2026/07/18 02:10:38 DEBUG : >WaitForWriters: --- FAIL: TestDirMkdir (0.55s) === RUN TestDirMkdirSub run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:38 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:39 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[0f14da31-7b14-4862-a8cf-f006483d15c3] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=0f14da31-7b14-4862-a8cf-f006483d15c3) 2026/07/18 02:10:39 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:39 DEBUG : Looking for writers 2026/07/18 02:10:39 DEBUG : >WaitForWriters: --- FAIL: TestDirMkdirSub (0.48s) === RUN TestDirRemove run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:39 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:39 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[1ceb6027-10a3-4df3-9224-fa5697030ed0] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=1ceb6027-10a3-4df3-9224-fa5697030ed0) 2026/07/18 02:10:39 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:39 DEBUG : Looking for writers 2026/07/18 02:10:39 DEBUG : >WaitForWriters: --- FAIL: TestDirRemove (0.48s) === RUN TestDirRemoveAll run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:39 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:40 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[1a2630ce-1628-4710-8f0f-f6fa9ec4d2f3] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=1a2630ce-1628-4710-8f0f-f6fa9ec4d2f3) 2026/07/18 02:10:40 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:40 DEBUG : Looking for writers 2026/07/18 02:10:40 DEBUG : >WaitForWriters: --- FAIL: TestDirRemoveAll (0.52s) === RUN TestDirRemoveName run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:40 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:40 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[9a2b1384-a00e-47d2-a397-e66c5100bda6] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=9a2b1384-a00e-47d2-a397-e66c5100bda6) 2026/07/18 02:10:40 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:40 DEBUG : Looking for writers 2026/07/18 02:10:40 DEBUG : >WaitForWriters: --- FAIL: TestDirRemoveName (0.47s) === RUN TestDirRename run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:40 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:41 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[602540d4-467d-40bd-98a4-9936deb3c7e5] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=602540d4-467d-40bd-98a4-9936deb3c7e5) 2026/07/18 02:10:41 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:41 DEBUG : Looking for writers 2026/07/18 02:10:41 DEBUG : >WaitForWriters: --- FAIL: TestDirRename (0.46s) === RUN TestDirFileOpen run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:41 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:41 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[aba28ca9-be98-4740-8152-8e48c808893c] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=aba28ca9-be98-4740-8152-8e48c808893c) 2026/07/18 02:10:41 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:41 DEBUG : Looking for writers 2026/07/18 02:10:41 DEBUG : >WaitForWriters: --- FAIL: TestDirFileOpen (0.48s) === RUN TestDirMetadataExtension run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:41 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:42 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[ed37f726-8c79-4a0b-93c5-09a5f4b2bbf5] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=ed37f726-8c79-4a0b-93c5-09a5f4b2bbf5) 2026/07/18 02:10:42 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:42 DEBUG : Looking for writers 2026/07/18 02:10:42 DEBUG : >WaitForWriters: --- FAIL: TestDirMetadataExtension (0.47s) === RUN TestFileMethods run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:42 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:42 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[cde1cedb-a66d-4ca0-9aaf-0df857c009df] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=cde1cedb-a66d-4ca0-9aaf-0df857c009df) 2026/07/18 02:10:42 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:42 DEBUG : Looking for writers 2026/07/18 02:10:42 DEBUG : >WaitForWriters: --- FAIL: TestFileMethods (0.47s) === RUN TestFileSetModTime === RUN TestFileSetModTime/cache=off,open=false,write=false run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:42 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:42 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[f787002d-d111-4bc5-8264-d0b833296611] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=f787002d-d111-4bc5-8264-d0b833296611) 2026/07/18 02:10:43 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:43 DEBUG : Looking for writers 2026/07/18 02:10:43 DEBUG : >WaitForWriters: === RUN TestFileSetModTime/cache=off,open=true,write=false run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:43 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:43 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[7c0daca6-9729-4f2b-90b5-99f52e0e5a47] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=7c0daca6-9729-4f2b-90b5-99f52e0e5a47) 2026/07/18 02:10:43 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:43 DEBUG : Looking for writers 2026/07/18 02:10:43 DEBUG : >WaitForWriters: === RUN TestFileSetModTime/cache=off,open=true,write=true run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:43 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:43 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[a052f9b4-9a29-41a2-b1cf-2946813ea49c] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=a052f9b4-9a29-41a2-b1cf-2946813ea49c) 2026/07/18 02:10:43 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:43 DEBUG : Looking for writers 2026/07/18 02:10:43 DEBUG : >WaitForWriters: === RUN TestFileSetModTime/cache=full,open=false,write=false run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:44 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:10:44 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: root is "/home/rclone/.cache/rclone" 2026/07/18 02:10:44 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:44 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:44 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:44 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:44 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:44 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:44 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:44 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:44 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:44 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[cc44eb73-c61d-4749-af23-666e582fa2fb] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=cc44eb73-c61d-4749-af23-666e582fa2fb) 2026/07/18 02:10:44 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:44 DEBUG : Looking for writers 2026/07/18 02:10:44 DEBUG : >WaitForWriters: 2026/07/18 02:10:44 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaner exiting === RUN TestFileSetModTime/cache=full,open=true,write=false run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:44 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:10:44 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: root is "/home/rclone/.cache/rclone" 2026/07/18 02:10:44 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:44 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:44 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:44 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:44 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:44 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:44 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:44 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:44 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:44 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[1a70cfae-a08c-4c30-9ca7-b48e30053c82] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=1a70cfae-a08c-4c30-9ca7-b48e30053c82) 2026/07/18 02:10:44 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:44 DEBUG : Looking for writers 2026/07/18 02:10:44 DEBUG : >WaitForWriters: 2026/07/18 02:10:44 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaner exiting === RUN TestFileSetModTime/cache=full,open=true,write=true run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:45 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:10:45 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: root is "/home/rclone/.cache/rclone" 2026/07/18 02:10:45 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:45 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:45 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:45 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:45 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:45 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:45 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:45 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:45 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:45 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[8f1aadcf-68b6-44d8-a76f-595644c4154e] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=8f1aadcf-68b6-44d8-a76f-595644c4154e) 2026/07/18 02:10:45 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:45 DEBUG : Looking for writers 2026/07/18 02:10:45 DEBUG : >WaitForWriters: 2026/07/18 02:10:45 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaner exiting --- FAIL: TestFileSetModTime (2.80s) --- FAIL: TestFileSetModTime/cache=off,open=false,write=false (0.46s) --- FAIL: TestFileSetModTime/cache=off,open=true,write=false (0.47s) --- FAIL: TestFileSetModTime/cache=off,open=true,write=true (0.47s) --- FAIL: TestFileSetModTime/cache=full,open=false,write=false (0.48s) --- FAIL: TestFileSetModTime/cache=full,open=true,write=false (0.47s) --- FAIL: TestFileSetModTime/cache=full,open=true,write=true (0.46s) === RUN TestFileOpenRead run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:45 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:45 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[7dd764f0-2937-42a5-ad6b-7a040bbbcc26] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=7dd764f0-2937-42a5-ad6b-7a040bbbcc26) 2026/07/18 02:10:45 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:45 DEBUG : Looking for writers 2026/07/18 02:10:45 DEBUG : >WaitForWriters: --- FAIL: TestFileOpenRead (0.48s) === RUN TestFileOpenWrite run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:46 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:46 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[c57ba2f9-88ec-43f8-aff4-abeeaa3ad52d] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=c57ba2f9-88ec-43f8-aff4-abeeaa3ad52d) 2026/07/18 02:10:46 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:46 DEBUG : Looking for writers 2026/07/18 02:10:46 DEBUG : >WaitForWriters: --- FAIL: TestFileOpenWrite (0.49s) === RUN TestFileRemove run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:46 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:46 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[3e954cf6-2688-48ad-b0e9-1f1518c28b6d] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=3e954cf6-2688-48ad-b0e9-1f1518c28b6d) 2026/07/18 02:10:46 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:46 DEBUG : Looking for writers 2026/07/18 02:10:46 DEBUG : >WaitForWriters: --- FAIL: TestFileRemove (0.48s) === RUN TestFileRemoveAll run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:47 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:47 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[00b3fe38-5691-4838-86be-8453d114d33d] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=00b3fe38-5691-4838-86be-8453d114d33d) 2026/07/18 02:10:47 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:47 DEBUG : Looking for writers 2026/07/18 02:10:47 DEBUG : >WaitForWriters: --- FAIL: TestFileRemoveAll (0.46s) === RUN TestFileOpen run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:47 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:47 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[5c367865-5df6-4bfa-9f5e-9abcec744c26] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=5c367865-5df6-4bfa-9f5e-9abcec744c26) 2026/07/18 02:10:47 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:47 DEBUG : Looking for writers 2026/07/18 02:10:47 DEBUG : >WaitForWriters: --- FAIL: TestFileOpen (0.47s) === RUN TestFileRename === RUN TestFileRename/off,forceCache=false run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:47 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:48 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[5da89475-5d04-48fd-a1c2-90baa7a855de] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=5da89475-5d04-48fd-a1c2-90baa7a855de) 2026/07/18 02:10:48 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:48 DEBUG : Looking for writers 2026/07/18 02:10:48 DEBUG : >WaitForWriters: === RUN TestFileRename/minimal,forceCache=false run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:48 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:10:48 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: root is "/home/rclone/.cache/rclone" 2026/07/18 02:10:48 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:48 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:48 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:48 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:48 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:48 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:48 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:48 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:48 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:48 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[45ab38de-7724-45e7-afce-15a44de62852] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=45ab38de-7724-45e7-afce-15a44de62852) 2026/07/18 02:10:48 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:48 DEBUG : Looking for writers 2026/07/18 02:10:48 DEBUG : >WaitForWriters: 2026/07/18 02:10:48 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaner exiting === RUN TestFileRename/minimal,forceCache=true run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:48 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:10:48 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: root is "/home/rclone/.cache/rclone" 2026/07/18 02:10:48 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:48 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:48 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:48 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:48 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:48 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:48 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:48 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:48 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:49 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[7ff99b24-d953-4549-a823-138f7b7886c3] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=7ff99b24-d953-4549-a823-138f7b7886c3) 2026/07/18 02:10:49 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:49 DEBUG : Looking for writers 2026/07/18 02:10:49 DEBUG : >WaitForWriters: 2026/07/18 02:10:49 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaner exiting === RUN TestFileRename/writes,forceCache=false run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:49 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:10:49 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: root is "/home/rclone/.cache/rclone" 2026/07/18 02:10:49 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:49 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:49 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:49 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:49 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:49 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:49 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:49 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:49 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:49 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[e37323f8-d9ff-4c6f-a95d-aed8f241d0d4] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=e37323f8-d9ff-4c6f-a95d-aed8f241d0d4) 2026/07/18 02:10:49 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:49 DEBUG : Looking for writers 2026/07/18 02:10:49 DEBUG : >WaitForWriters: 2026/07/18 02:10:49 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaner exiting === RUN TestFileRename/writes,forceCache=true run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:49 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:10:49 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: root is "/home/rclone/.cache/rclone" 2026/07/18 02:10:49 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:49 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:49 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:49 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:49 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:49 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:49 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:49 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:49 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:50 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[5e4d6636-3a2e-4cbb-a1bb-e574975f3e33] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=5e4d6636-3a2e-4cbb-a1bb-e574975f3e33) 2026/07/18 02:10:50 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:50 DEBUG : Looking for writers 2026/07/18 02:10:50 DEBUG : >WaitForWriters: 2026/07/18 02:10:50 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaner exiting === RUN TestFileRename/full,forceCache=false run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:50 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:10:50 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: root is "/home/rclone/.cache/rclone" 2026/07/18 02:10:50 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:50 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:50 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:50 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:50 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:50 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:50 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:50 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:50 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:50 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[1a3f382a-6732-4c79-a4ab-86b51c0d9ba6] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=1a3f382a-6732-4c79-a4ab-86b51c0d9ba6) 2026/07/18 02:10:50 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:50 DEBUG : Looking for writers 2026/07/18 02:10:50 DEBUG : >WaitForWriters: 2026/07/18 02:10:50 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaner exiting --- FAIL: TestFileRename (2.95s) --- FAIL: TestFileRename/off,forceCache=false (0.50s) --- FAIL: TestFileRename/minimal,forceCache=false (0.47s) --- FAIL: TestFileRename/minimal,forceCache=true (0.53s) --- FAIL: TestFileRename/writes,forceCache=false (0.48s) --- FAIL: TestFileRename/writes,forceCache=true (0.51s) --- FAIL: TestFileRename/full,forceCache=false (0.47s) === RUN TestReadFileHandleMethods run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:50 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:51 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[9525b048-8ec5-4e55-9b58-97c13cde17dd] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=9525b048-8ec5-4e55-9b58-97c13cde17dd) 2026/07/18 02:10:51 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:51 DEBUG : Looking for writers 2026/07/18 02:10:51 DEBUG : >WaitForWriters: --- FAIL: TestReadFileHandleMethods (0.46s) === RUN TestReadFileHandleSeek run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:51 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:51 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[68aec045-5746-48dd-8524-9505b88b512b] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=68aec045-5746-48dd-8524-9505b88b512b) 2026/07/18 02:10:51 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:51 DEBUG : Looking for writers 2026/07/18 02:10:51 DEBUG : >WaitForWriters: --- FAIL: TestReadFileHandleSeek (0.47s) === RUN TestReadFileHandleReadAt run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:51 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:52 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[435826ca-7248-4411-b247-9d0caefc4f58] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=435826ca-7248-4411-b247-9d0caefc4f58) 2026/07/18 02:10:52 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:52 DEBUG : Looking for writers 2026/07/18 02:10:52 DEBUG : >WaitForWriters: --- FAIL: TestReadFileHandleReadAt (0.47s) === RUN TestReadFileHandleFlush run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:52 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:52 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[10fc9981-d572-4cf1-917d-ecf05d5220cb] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=10fc9981-d572-4cf1-917d-ecf05d5220cb) 2026/07/18 02:10:52 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:52 DEBUG : Looking for writers 2026/07/18 02:10:52 DEBUG : >WaitForWriters: --- FAIL: TestReadFileHandleFlush (0.47s) === RUN TestReadFileHandleRelease run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:52 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:52 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[ae0dec5b-cbc9-459f-a0b7-e5953225c8ca] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=ae0dec5b-cbc9-459f-a0b7-e5953225c8ca) 2026/07/18 02:10:53 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:53 DEBUG : Looking for writers 2026/07/18 02:10:53 DEBUG : >WaitForWriters: --- FAIL: TestReadFileHandleRelease (0.48s) === RUN TestRWFileHandleMethodsRead run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:53 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:10:53 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: root is "/home/rclone/.cache/rclone" 2026/07/18 02:10:53 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:53 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:53 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:53 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:53 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:53 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:53 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:53 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:53 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:53 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[80d7b572-3561-4151-bf60-6733b06dd49d] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=80d7b572-3561-4151-bf60-6733b06dd49d) 2026/07/18 02:10:53 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:53 DEBUG : Looking for writers 2026/07/18 02:10:53 DEBUG : >WaitForWriters: 2026/07/18 02:10:53 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaner exiting --- FAIL: TestRWFileHandleMethodsRead (0.49s) === RUN TestRWFileHandleSeek run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:53 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:10:53 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: root is "/home/rclone/.cache/rclone" 2026/07/18 02:10:53 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:53 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:53 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:53 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:53 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:53 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:53 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:53 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:53 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:53 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[6cdbfe28-ed61-4c90-9d03-c3b9ea2b68bb] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=6cdbfe28-ed61-4c90-9d03-c3b9ea2b68bb) 2026/07/18 02:10:53 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:53 DEBUG : Looking for writers 2026/07/18 02:10:53 DEBUG : >WaitForWriters: 2026/07/18 02:10:53 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaner exiting --- FAIL: TestRWFileHandleSeek (0.48s) === RUN TestRWFileHandleReadAt run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:54 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:10:54 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: root is "/home/rclone/.cache/rclone" 2026/07/18 02:10:54 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:54 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:54 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:54 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:54 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:54 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:54 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:54 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:54 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:54 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[34a2d864-6bb5-4f7f-92f1-157414d2ed7e] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=34a2d864-6bb5-4f7f-92f1-157414d2ed7e) 2026/07/18 02:10:54 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:54 DEBUG : Looking for writers 2026/07/18 02:10:54 DEBUG : >WaitForWriters: 2026/07/18 02:10:54 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaner exiting --- FAIL: TestRWFileHandleReadAt (0.46s) === RUN TestRWFileHandleFlushRead run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:54 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:10:54 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: root is "/home/rclone/.cache/rclone" 2026/07/18 02:10:54 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:54 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:54 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:54 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:54 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:54 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:54 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:54 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:54 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:54 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[39002ba8-b7ee-4cd6-a5a6-7791886ef9f9] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=39002ba8-b7ee-4cd6-a5a6-7791886ef9f9) 2026/07/18 02:10:54 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:54 DEBUG : Looking for writers 2026/07/18 02:10:54 DEBUG : >WaitForWriters: 2026/07/18 02:10:54 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaner exiting --- FAIL: TestRWFileHandleFlushRead (0.47s) === RUN TestRWFileHandleReleaseRead run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:55 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:10:55 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: root is "/home/rclone/.cache/rclone" 2026/07/18 02:10:55 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:55 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:55 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:55 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:55 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:55 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:55 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:55 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:55 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:55 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[91ffcbb7-0c16-4fe6-9435-005e95778f93] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=91ffcbb7-0c16-4fe6-9435-005e95778f93) 2026/07/18 02:10:55 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:55 DEBUG : Looking for writers 2026/07/18 02:10:55 DEBUG : >WaitForWriters: 2026/07/18 02:10:55 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaner exiting --- FAIL: TestRWFileHandleReleaseRead (0.50s) === RUN TestRWFileHandleMethodsWrite run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:10:55 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:10:55 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: root is "/home/rclone/.cache/rclone" 2026/07/18 02:10:55 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:55 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:55 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:55 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:55 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:55 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:55 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:10:55 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:10:55 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/07/18 02:10:55 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2026/07/18 02:10:55 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2026/07/18 02:10:55 DEBUG : file1: newRWFileHandle: 2026/07/18 02:10:55 DEBUG : file1(0x998d098a100): openPending: 2026/07/18 02:10:55 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct) 2026/07/18 02:10:55 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:10:55 DEBUG : file1(0x998d098a100): >openPending: err= 2026/07/18 02:10:55 DEBUG : file1: >newRWFileHandle: err= 2026/07/18 02:10:55 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:10:55 DEBUG : file1: >Open: fd=file1 (rw), err= 2026/07/18 02:10:55 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2026/07/18 02:10:55 DEBUG : file1(0x998d098a100): _writeAt: size=5, off=0 2026/07/18 02:10:55 DEBUG : file1(0x998d098a100): >_writeAt: n=5, err= 2026/07/18 02:10:55 DEBUG : file1(0x998d098a100): _writeAt: size=7, off=5 2026/07/18 02:10:55 DEBUG : file1(0x998d098a100): >_writeAt: n=7, err= 2026/07/18 02:10:55 DEBUG : file1: vfs cache: truncate to size=11 2026/07/18 02:10:55 DEBUG : file1(0x998d098a100): close: 2026/07/18 02:10:55 DEBUG : file1: vfs cache: setting modification time to 2026-07-18 02:10:55.713878922 +0000 UTC m=+23.763438524 2026/07/18 02:10:55 INFO : file1: vfs cache: queuing for upload in 100ms 2026/07/18 02:10:55 DEBUG : file1(0x998d098a100): >close: err= 2026/07/18 02:10:55 DEBUG : file1(0x998d098a100): close: 2026/07/18 02:10:55 DEBUG : file1(0x998d098a100): >close: err=file already closed 2026/07/18 02:10:55 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:10:55 DEBUG : Looking for writers 2026/07/18 02:10:55 DEBUG : file1: reading active writers 2026/07/18 02:10:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2026/07/18 02:10:55 DEBUG : Looking for writers 2026/07/18 02:10:55 DEBUG : file1: reading active writers 2026/07/18 02:10:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2026/07/18 02:10:55 DEBUG : Looking for writers 2026/07/18 02:10:55 DEBUG : file1: reading active writers 2026/07/18 02:10:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2026/07/18 02:10:55 DEBUG : Looking for writers 2026/07/18 02:10:55 DEBUG : file1: reading active writers 2026/07/18 02:10:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2026/07/18 02:10:55 DEBUG : file1: vfs cache: starting upload 2026/07/18 02:10:55 DEBUG : Looking for writers 2026/07/18 02:10:55 DEBUG : file1: reading active writers 2026/07/18 02:10:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2026/07/18 02:10:55 ERROR : file1: Failed to copy: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:55 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[067a20ac-b45d-45b0-83f5-bc40b0b35399] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=067a20ac-b45d-45b0-83f5-bc40b0b35399) 2026/07/18 02:10:55 ERROR : file1: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:55 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[067a20ac-b45d-45b0-83f5-bc40b0b35399] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=067a20ac-b45d-45b0-83f5-bc40b0b35399) 2026/07/18 02:10:56 DEBUG : Looking for writers 2026/07/18 02:10:56 DEBUG : file1: reading active writers 2026/07/18 02:10:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2026/07/18 02:10:56 DEBUG : file1: vfs cache: starting upload 2026/07/18 02:10:56 ERROR : file1: Failed to copy: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:56 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[83953b0e-94b1-40c9-9ca3-201e16838121] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=83953b0e-94b1-40c9-9ca3-201e16838121) 2026/07/18 02:10:56 ERROR : file1: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:56 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[83953b0e-94b1-40c9-9ca3-201e16838121] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=83953b0e-94b1-40c9-9ca3-201e16838121) 2026/07/18 02:10:56 DEBUG : Looking for writers 2026/07/18 02:10:56 DEBUG : file1: reading active writers 2026/07/18 02:10:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2026/07/18 02:10:56 DEBUG : file1: vfs cache: starting upload 2026/07/18 02:10:56 ERROR : file1: Failed to copy: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:56 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[acd0dfd5-39b4-4819-99b3-1f5e85f95d23] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=acd0dfd5-39b4-4819-99b3-1f5e85f95d23) 2026/07/18 02:10:56 ERROR : file1: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:56 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[acd0dfd5-39b4-4819-99b3-1f5e85f95d23] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=acd0dfd5-39b4-4819-99b3-1f5e85f95d23) 2026/07/18 02:10:56 DEBUG : Looking for writers 2026/07/18 02:10:56 DEBUG : file1: reading active writers 2026/07/18 02:10:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:10:57 DEBUG : file1: vfs cache: starting upload 2026/07/18 02:10:57 ERROR : file1: Failed to copy: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:57 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[4a7d8405-04c1-4065-acaf-d22ef59c2aba] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=4a7d8405-04c1-4065-acaf-d22ef59c2aba) 2026/07/18 02:10:57 ERROR : file1: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:57 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[4a7d8405-04c1-4065-acaf-d22ef59c2aba] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=4a7d8405-04c1-4065-acaf-d22ef59c2aba) 2026/07/18 02:10:57 DEBUG : Looking for writers 2026/07/18 02:10:57 DEBUG : file1: reading active writers 2026/07/18 02:10:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:10:58 DEBUG : Looking for writers 2026/07/18 02:10:58 DEBUG : file1: reading active writers 2026/07/18 02:10:58 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:10:59 DEBUG : file1: vfs cache: starting upload 2026/07/18 02:10:59 ERROR : file1: Failed to copy: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:59 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[0afe245b-788f-4ed0-983f-b9888d24cd09] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=0afe245b-788f-4ed0-983f-b9888d24cd09) 2026/07/18 02:10:59 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:10:59 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[0afe245b-788f-4ed0-983f-b9888d24cd09] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=0afe245b-788f-4ed0-983f-b9888d24cd09) 2026/07/18 02:10:59 DEBUG : Looking for writers 2026/07/18 02:10:59 DEBUG : file1: reading active writers 2026/07/18 02:10:59 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:00 DEBUG : Looking for writers 2026/07/18 02:11:00 DEBUG : file1: reading active writers 2026/07/18 02:11:00 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:01 DEBUG : Looking for writers 2026/07/18 02:11:01 DEBUG : file1: reading active writers 2026/07/18 02:11:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:02 DEBUG : file1: vfs cache: starting upload 2026/07/18 02:11:02 ERROR : file1: Failed to copy: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:11:02 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[8d905d83-109e-4128-8b25-00df17ef4832] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=8d905d83-109e-4128-8b25-00df17ef4832) 2026/07/18 02:11:02 ERROR : file1: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:11:02 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[8d905d83-109e-4128-8b25-00df17ef4832] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=8d905d83-109e-4128-8b25-00df17ef4832) 2026/07/18 02:11:02 DEBUG : Looking for writers 2026/07/18 02:11:02 DEBUG : file1: reading active writers 2026/07/18 02:11:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:03 DEBUG : Looking for writers 2026/07/18 02:11:03 DEBUG : file1: reading active writers 2026/07/18 02:11:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:04 DEBUG : Looking for writers 2026/07/18 02:11:04 DEBUG : file1: reading active writers 2026/07/18 02:11:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:05 DEBUG : Looking for writers 2026/07/18 02:11:05 DEBUG : file1: reading active writers 2026/07/18 02:11:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:06 DEBUG : Looking for writers 2026/07/18 02:11:06 DEBUG : file1: reading active writers 2026/07/18 02:11:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:07 DEBUG : Looking for writers 2026/07/18 02:11:07 DEBUG : file1: reading active writers 2026/07/18 02:11:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:08 DEBUG : file1: vfs cache: starting upload 2026/07/18 02:11:08 DEBUG : Looking for writers 2026/07/18 02:11:08 DEBUG : file1: reading active writers 2026/07/18 02:11:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:09 ERROR : file1: Failed to copy: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:11:09 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[bece8d69-d2ce-4e8d-9379-0d036ff08821] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=bece8d69-d2ce-4e8d-9379-0d036ff08821) 2026/07/18 02:11:09 ERROR : file1: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:11:09 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[bece8d69-d2ce-4e8d-9379-0d036ff08821] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=bece8d69-d2ce-4e8d-9379-0d036ff08821) 2026/07/18 02:11:09 DEBUG : Looking for writers 2026/07/18 02:11:10 DEBUG : file1: reading active writers 2026/07/18 02:11:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:11 DEBUG : Looking for writers 2026/07/18 02:11:11 DEBUG : file1: reading active writers 2026/07/18 02:11:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:12 DEBUG : Looking for writers 2026/07/18 02:11:12 DEBUG : file1: reading active writers 2026/07/18 02:11:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:13 DEBUG : Looking for writers 2026/07/18 02:11:13 DEBUG : file1: reading active writers 2026/07/18 02:11:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:14 DEBUG : Looking for writers 2026/07/18 02:11:14 DEBUG : file1: reading active writers 2026/07/18 02:11:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:15 DEBUG : Looking for writers 2026/07/18 02:11:15 DEBUG : file1: reading active writers 2026/07/18 02:11:15 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:16 DEBUG : Looking for writers 2026/07/18 02:11:16 DEBUG : file1: reading active writers 2026/07/18 02:11:16 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:17 DEBUG : Looking for writers 2026/07/18 02:11:17 DEBUG : file1: reading active writers 2026/07/18 02:11:17 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:18 DEBUG : Looking for writers 2026/07/18 02:11:18 DEBUG : file1: reading active writers 2026/07/18 02:11:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:19 DEBUG : Looking for writers 2026/07/18 02:11:19 DEBUG : file1: reading active writers 2026/07/18 02:11:19 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:20 DEBUG : Looking for writers 2026/07/18 02:11:20 DEBUG : file1: reading active writers 2026/07/18 02:11:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:21 DEBUG : Looking for writers 2026/07/18 02:11:21 DEBUG : file1: reading active writers 2026/07/18 02:11:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:21 DEBUG : file1: vfs cache: starting upload 2026/07/18 02:11:22 DEBUG : Looking for writers 2026/07/18 02:11:22 DEBUG : file1: reading active writers 2026/07/18 02:11:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:22 ERROR : file1: Failed to copy: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:11:22 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[5b7199f5-b396-4382-aa4b-41228ae8888e] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=5b7199f5-b396-4382-aa4b-41228ae8888e) 2026/07/18 02:11:22 ERROR : file1: vfs cache: failed to upload try #8, will retry in 25.6s: vfs cache: failed to transfer file from cache to remote: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:11:22 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[5b7199f5-b396-4382-aa4b-41228ae8888e] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=5b7199f5-b396-4382-aa4b-41228ae8888e) 2026/07/18 02:11:23 DEBUG : Looking for writers 2026/07/18 02:11:23 DEBUG : file1: reading active writers 2026/07/18 02:11:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:24 DEBUG : Looking for writers 2026/07/18 02:11:24 DEBUG : file1: reading active writers 2026/07/18 02:11:24 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:25 DEBUG : Looking for writers 2026/07/18 02:11:25 DEBUG : file1: reading active writers 2026/07/18 02:11:25 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:25 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0x998d07c3000 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0x998d09a2008 notify:{wait:0 notify:0 lock:0 head: tail:} checker:10551939440704} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:14019378036719021450 ext:23763438524 loc:0x47a3720} ATime:{wall:14019378036719070072 ext:23763487106 loc:0x47a3720} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false graceTimer: closing:}, } 2026/07/18 02:11:25 DEBUG : >WaitForWriters: 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/vfs/read_write_test.go:337 Error: Should be true Test: TestRWFileHandleMethodsWrite Messages: listing wrong, want file1 (11) got fstest.go:203: Not found "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/vfs/read_write_test.go:337 Error: Not equal: expected: 0 actual : 1 Test: TestRWFileHandleMethodsWrite Messages: 1 objects not found 2026/07/18 02:11:32 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:11:32 DEBUG : Looking for writers 2026/07/18 02:11:32 DEBUG : file1: reading active writers 2026/07/18 02:11:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2026/07/18 02:11:32 DEBUG : Looking for writers 2026/07/18 02:11:32 DEBUG : file1: reading active writers 2026/07/18 02:11:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2026/07/18 02:11:32 DEBUG : Looking for writers 2026/07/18 02:11:32 DEBUG : file1: reading active writers 2026/07/18 02:11:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2026/07/18 02:11:32 DEBUG : Looking for writers 2026/07/18 02:11:32 DEBUG : file1: reading active writers 2026/07/18 02:11:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2026/07/18 02:11:32 DEBUG : Looking for writers 2026/07/18 02:11:32 DEBUG : file1: reading active writers 2026/07/18 02:11:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2026/07/18 02:11:33 DEBUG : Looking for writers 2026/07/18 02:11:33 DEBUG : file1: reading active writers 2026/07/18 02:11:33 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2026/07/18 02:11:33 DEBUG : Looking for writers 2026/07/18 02:11:33 DEBUG : file1: reading active writers 2026/07/18 02:11:33 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2026/07/18 02:11:34 DEBUG : Looking for writers 2026/07/18 02:11:34 DEBUG : file1: reading active writers 2026/07/18 02:11:34 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:35 DEBUG : Looking for writers 2026/07/18 02:11:35 DEBUG : file1: reading active writers 2026/07/18 02:11:35 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:36 DEBUG : Looking for writers 2026/07/18 02:11:36 DEBUG : file1: reading active writers 2026/07/18 02:11:36 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:37 DEBUG : Looking for writers 2026/07/18 02:11:37 DEBUG : file1: reading active writers 2026/07/18 02:11:37 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:38 DEBUG : Looking for writers 2026/07/18 02:11:38 DEBUG : file1: reading active writers 2026/07/18 02:11:38 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:39 DEBUG : Looking for writers 2026/07/18 02:11:39 DEBUG : file1: reading active writers 2026/07/18 02:11:39 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:40 DEBUG : Looking for writers 2026/07/18 02:11:40 DEBUG : file1: reading active writers 2026/07/18 02:11:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:41 DEBUG : Looking for writers 2026/07/18 02:11:41 DEBUG : file1: reading active writers 2026/07/18 02:11:41 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:42 DEBUG : Looking for writers 2026/07/18 02:11:42 DEBUG : file1: reading active writers 2026/07/18 02:11:42 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:43 DEBUG : Looking for writers 2026/07/18 02:11:43 DEBUG : file1: reading active writers 2026/07/18 02:11:43 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:44 DEBUG : Looking for writers 2026/07/18 02:11:44 DEBUG : file1: reading active writers 2026/07/18 02:11:44 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:45 DEBUG : Looking for writers 2026/07/18 02:11:45 DEBUG : file1: reading active writers 2026/07/18 02:11:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:46 DEBUG : Looking for writers 2026/07/18 02:11:46 DEBUG : file1: reading active writers 2026/07/18 02:11:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:47 DEBUG : Looking for writers 2026/07/18 02:11:47 DEBUG : file1: reading active writers 2026/07/18 02:11:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:47 DEBUG : file1: vfs cache: starting upload 2026/07/18 02:11:47 ERROR : file1: Failed to copy: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:11:47 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[6f7bcc59-fabc-44ba-ad8e-a34ecd9cdc25] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=6f7bcc59-fabc-44ba-ad8e-a34ecd9cdc25) 2026/07/18 02:11:47 ERROR : file1: vfs cache: failed to upload try #9, will retry in 51.2s: vfs cache: failed to transfer file from cache to remote: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:11:47 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[6f7bcc59-fabc-44ba-ad8e-a34ecd9cdc25] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=6f7bcc59-fabc-44ba-ad8e-a34ecd9cdc25) 2026/07/18 02:11:48 DEBUG : Looking for writers 2026/07/18 02:11:48 DEBUG : file1: reading active writers 2026/07/18 02:11:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:49 DEBUG : Looking for writers 2026/07/18 02:11:49 DEBUG : file1: reading active writers 2026/07/18 02:11:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:50 DEBUG : Looking for writers 2026/07/18 02:11:50 DEBUG : file1: reading active writers 2026/07/18 02:11:50 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:51 DEBUG : Looking for writers 2026/07/18 02:11:51 DEBUG : file1: reading active writers 2026/07/18 02:11:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:52 DEBUG : Looking for writers 2026/07/18 02:11:52 DEBUG : file1: reading active writers 2026/07/18 02:11:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:53 DEBUG : Looking for writers 2026/07/18 02:11:53 DEBUG : file1: reading active writers 2026/07/18 02:11:53 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:54 DEBUG : Looking for writers 2026/07/18 02:11:54 DEBUG : file1: reading active writers 2026/07/18 02:11:54 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:55 DEBUG : Looking for writers 2026/07/18 02:11:55 DEBUG : file1: reading active writers 2026/07/18 02:11:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:55 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2026/07/18 02:11:55 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 1 (was 1) in use 1, to upload 1, uploading 0, total size 11 (was 11) 2026/07/18 02:11:56 DEBUG : Looking for writers 2026/07/18 02:11:56 DEBUG : file1: reading active writers 2026/07/18 02:11:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:57 DEBUG : Looking for writers 2026/07/18 02:11:57 DEBUG : file1: reading active writers 2026/07/18 02:11:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:58 DEBUG : Looking for writers 2026/07/18 02:11:58 DEBUG : file1: reading active writers 2026/07/18 02:11:58 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:11:59 DEBUG : Looking for writers 2026/07/18 02:11:59 DEBUG : file1: reading active writers 2026/07/18 02:11:59 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:00 DEBUG : Looking for writers 2026/07/18 02:12:00 DEBUG : file1: reading active writers 2026/07/18 02:12:00 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:01 DEBUG : Looking for writers 2026/07/18 02:12:01 DEBUG : file1: reading active writers 2026/07/18 02:12:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:02 DEBUG : Looking for writers 2026/07/18 02:12:02 DEBUG : file1: reading active writers 2026/07/18 02:12:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:02 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0x998d07c3000 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0x998d09a2008 notify:{wait:0 notify:0 lock:0 head: tail:} checker:10551939440704} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:14019378036719021450 ext:23763438524 loc:0x47a3720} ATime:{wall:14019378036719070072 ext:23763487106 loc:0x47a3720} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false graceTimer: closing:}, } 2026/07/18 02:12:02 DEBUG : >WaitForWriters: 2026/07/18 02:12:02 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaner exiting --- FAIL: TestRWFileHandleMethodsWrite (67.25s) === RUN TestRWFileHandleWriteAt run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:12:02 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:12:02 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: root is "/home/rclone/.cache/rclone" 2026/07/18 02:12:02 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:12:02 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:12:02 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:12:02 DEBUG : Config file has changed externally - reloading 2026/07/18 02:12:02 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:12:02 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:12:02 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:12:02 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:12:02 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:12:02 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/07/18 02:12:02 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2026/07/18 02:12:02 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2026/07/18 02:12:02 DEBUG : file1: newRWFileHandle: 2026/07/18 02:12:02 DEBUG : file1(0x998d058c580): openPending: 2026/07/18 02:12:02 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct) 2026/07/18 02:12:02 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:12:02 DEBUG : file1(0x998d058c580): >openPending: err= 2026/07/18 02:12:02 DEBUG : file1: >newRWFileHandle: err= 2026/07/18 02:12:02 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:12:02 DEBUG : file1: >Open: fd=file1 (rw), err= 2026/07/18 02:12:02 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2026/07/18 02:12:02 DEBUG : file1(0x998d058c580): _writeAt: size=7, off=0 2026/07/18 02:12:02 DEBUG : file1(0x998d058c580): >_writeAt: n=7, err= 2026/07/18 02:12:02 DEBUG : file1(0x998d058c580): _writeAt: size=6, off=5 2026/07/18 02:12:02 DEBUG : file1(0x998d058c580): >_writeAt: n=6, err= 2026/07/18 02:12:02 DEBUG : file1(0x998d058c580): close: 2026/07/18 02:12:02 DEBUG : file1: vfs cache: setting modification time to 2026-07-18 02:12:02.966683496 +0000 UTC m=+91.016243048 2026/07/18 02:12:02 INFO : file1: vfs cache: queuing for upload in 100ms 2026/07/18 02:12:02 DEBUG : file1(0x998d058c580): >close: err= 2026/07/18 02:12:02 DEBUG : file1(0x998d058c580): _writeAt: size=5, off=0 2026/07/18 02:12:02 DEBUG : file1(0x998d058c580): >_writeAt: n=0, err=file already closed 2026/07/18 02:12:02 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:12:02 DEBUG : Looking for writers 2026/07/18 02:12:02 DEBUG : file1: reading active writers 2026/07/18 02:12:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2026/07/18 02:12:02 DEBUG : Looking for writers 2026/07/18 02:12:02 DEBUG : file1: reading active writers 2026/07/18 02:12:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2026/07/18 02:12:02 DEBUG : Looking for writers 2026/07/18 02:12:02 DEBUG : file1: reading active writers 2026/07/18 02:12:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2026/07/18 02:12:03 DEBUG : Looking for writers 2026/07/18 02:12:03 DEBUG : file1: reading active writers 2026/07/18 02:12:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2026/07/18 02:12:03 DEBUG : file1: vfs cache: starting upload 2026/07/18 02:12:03 DEBUG : Looking for writers 2026/07/18 02:12:03 DEBUG : file1: reading active writers 2026/07/18 02:12:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2026/07/18 02:12:03 ERROR : file1: Failed to copy: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:12:03 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[ed38ab67-bd39-4886-907c-e634568df0fc] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=ed38ab67-bd39-4886-907c-e634568df0fc) 2026/07/18 02:12:03 ERROR : file1: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:12:03 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[ed38ab67-bd39-4886-907c-e634568df0fc] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=ed38ab67-bd39-4886-907c-e634568df0fc) 2026/07/18 02:12:03 DEBUG : Looking for writers 2026/07/18 02:12:03 DEBUG : file1: reading active writers 2026/07/18 02:12:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2026/07/18 02:12:03 DEBUG : file1: vfs cache: starting upload 2026/07/18 02:12:03 ERROR : file1: Failed to copy: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:12:03 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[4df6e8f8-1b24-4ec0-950b-95bd5b99933f] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=4df6e8f8-1b24-4ec0-950b-95bd5b99933f) 2026/07/18 02:12:03 ERROR : file1: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:12:03 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[4df6e8f8-1b24-4ec0-950b-95bd5b99933f] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=4df6e8f8-1b24-4ec0-950b-95bd5b99933f) 2026/07/18 02:12:03 DEBUG : Looking for writers 2026/07/18 02:12:03 DEBUG : file1: reading active writers 2026/07/18 02:12:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2026/07/18 02:12:03 DEBUG : file1: vfs cache: starting upload 2026/07/18 02:12:04 ERROR : file1: Failed to copy: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:12:03 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[debebd3b-eca1-4c8d-b989-6da24d13a832] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=debebd3b-eca1-4c8d-b989-6da24d13a832) 2026/07/18 02:12:04 ERROR : file1: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:12:03 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[debebd3b-eca1-4c8d-b989-6da24d13a832] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=debebd3b-eca1-4c8d-b989-6da24d13a832) 2026/07/18 02:12:04 DEBUG : Looking for writers 2026/07/18 02:12:04 DEBUG : file1: reading active writers 2026/07/18 02:12:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:04 DEBUG : file1: vfs cache: starting upload 2026/07/18 02:12:04 ERROR : file1: Failed to copy: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:12:04 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[ba5c3b8c-d29e-4cfb-80de-bebe092cf9b7] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=ba5c3b8c-d29e-4cfb-80de-bebe092cf9b7) 2026/07/18 02:12:04 ERROR : file1: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:12:04 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[ba5c3b8c-d29e-4cfb-80de-bebe092cf9b7] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=ba5c3b8c-d29e-4cfb-80de-bebe092cf9b7) 2026/07/18 02:12:05 DEBUG : Looking for writers 2026/07/18 02:12:05 DEBUG : file1: reading active writers 2026/07/18 02:12:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:06 DEBUG : Looking for writers 2026/07/18 02:12:06 DEBUG : file1: reading active writers 2026/07/18 02:12:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:06 DEBUG : file1: vfs cache: starting upload 2026/07/18 02:12:06 ERROR : file1: Failed to copy: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:12:06 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[23032bec-2173-458e-9eb6-560c57a5a271] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=23032bec-2173-458e-9eb6-560c57a5a271) 2026/07/18 02:12:06 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:12:06 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[23032bec-2173-458e-9eb6-560c57a5a271] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=23032bec-2173-458e-9eb6-560c57a5a271) 2026/07/18 02:12:07 DEBUG : Looking for writers 2026/07/18 02:12:07 DEBUG : file1: reading active writers 2026/07/18 02:12:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:08 DEBUG : Looking for writers 2026/07/18 02:12:08 DEBUG : file1: reading active writers 2026/07/18 02:12:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:09 DEBUG : Looking for writers 2026/07/18 02:12:09 DEBUG : file1: reading active writers 2026/07/18 02:12:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:09 DEBUG : file1: vfs cache: starting upload 2026/07/18 02:12:09 ERROR : file1: Failed to copy: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:12:09 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[925988b3-f531-4682-861e-154cb48eaa48] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=925988b3-f531-4682-861e-154cb48eaa48) 2026/07/18 02:12:09 ERROR : file1: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:12:09 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[925988b3-f531-4682-861e-154cb48eaa48] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=925988b3-f531-4682-861e-154cb48eaa48) 2026/07/18 02:12:10 DEBUG : Looking for writers 2026/07/18 02:12:10 DEBUG : file1: reading active writers 2026/07/18 02:12:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:11 DEBUG : Looking for writers 2026/07/18 02:12:11 DEBUG : file1: reading active writers 2026/07/18 02:12:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:12 DEBUG : Looking for writers 2026/07/18 02:12:12 DEBUG : file1: reading active writers 2026/07/18 02:12:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:13 DEBUG : Looking for writers 2026/07/18 02:12:13 DEBUG : file1: reading active writers 2026/07/18 02:12:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:14 DEBUG : Looking for writers 2026/07/18 02:12:14 DEBUG : file1: reading active writers 2026/07/18 02:12:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:15 DEBUG : Looking for writers 2026/07/18 02:12:15 DEBUG : file1: reading active writers 2026/07/18 02:12:15 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:16 DEBUG : Looking for writers 2026/07/18 02:12:16 DEBUG : file1: reading active writers 2026/07/18 02:12:16 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:16 DEBUG : file1: vfs cache: starting upload 2026/07/18 02:12:16 ERROR : file1: Failed to copy: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:12:16 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[3c2cecca-962b-4107-b619-e41bd135b498] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=3c2cecca-962b-4107-b619-e41bd135b498) 2026/07/18 02:12:16 ERROR : file1: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:12:16 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[3c2cecca-962b-4107-b619-e41bd135b498] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=3c2cecca-962b-4107-b619-e41bd135b498) 2026/07/18 02:12:17 DEBUG : Looking for writers 2026/07/18 02:12:17 DEBUG : file1: reading active writers 2026/07/18 02:12:17 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:18 DEBUG : Looking for writers 2026/07/18 02:12:18 DEBUG : file1: reading active writers 2026/07/18 02:12:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:19 DEBUG : Looking for writers 2026/07/18 02:12:19 DEBUG : file1: reading active writers 2026/07/18 02:12:19 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:20 DEBUG : Looking for writers 2026/07/18 02:12:20 DEBUG : file1: reading active writers 2026/07/18 02:12:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:21 DEBUG : Looking for writers 2026/07/18 02:12:21 DEBUG : file1: reading active writers 2026/07/18 02:12:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:22 DEBUG : Looking for writers 2026/07/18 02:12:22 DEBUG : file1: reading active writers 2026/07/18 02:12:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:23 DEBUG : Looking for writers 2026/07/18 02:12:23 DEBUG : file1: reading active writers 2026/07/18 02:12:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:24 DEBUG : Looking for writers 2026/07/18 02:12:24 DEBUG : file1: reading active writers 2026/07/18 02:12:24 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:25 DEBUG : Looking for writers 2026/07/18 02:12:25 DEBUG : file1: reading active writers 2026/07/18 02:12:25 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:26 DEBUG : Looking for writers 2026/07/18 02:12:26 DEBUG : file1: reading active writers 2026/07/18 02:12:26 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:27 DEBUG : Looking for writers 2026/07/18 02:12:27 DEBUG : file1: reading active writers 2026/07/18 02:12:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:28 DEBUG : Looking for writers 2026/07/18 02:12:28 DEBUG : file1: reading active writers 2026/07/18 02:12:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:29 DEBUG : file1: vfs cache: starting upload 2026/07/18 02:12:29 DEBUG : Looking for writers 2026/07/18 02:12:29 DEBUG : file1: reading active writers 2026/07/18 02:12:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:29 ERROR : file1: Failed to copy: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:12:29 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[ffd4126f-8327-471f-90de-091300019b34] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=ffd4126f-8327-471f-90de-091300019b34) 2026/07/18 02:12:29 ERROR : file1: vfs cache: failed to upload try #8, will retry in 25.6s: vfs cache: failed to transfer file from cache to remote: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:12:29 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[ffd4126f-8327-471f-90de-091300019b34] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=ffd4126f-8327-471f-90de-091300019b34) 2026/07/18 02:12:30 DEBUG : Looking for writers 2026/07/18 02:12:30 DEBUG : file1: reading active writers 2026/07/18 02:12:30 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:31 DEBUG : Looking for writers 2026/07/18 02:12:31 DEBUG : file1: reading active writers 2026/07/18 02:12:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:32 DEBUG : Looking for writers 2026/07/18 02:12:32 DEBUG : file1: reading active writers 2026/07/18 02:12:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:32 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0x998d0bc4c00 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0x998d08a8ea8 notify:{wait:0 notify:0 lock:0 head: tail:} checker:10551938420448} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:14019378108912528232 ext:91016243048 loc:0x47a3720} ATime:{wall:14019378108912545795 ext:91016260611 loc:0x47a3720} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false graceTimer: closing:}, } 2026/07/18 02:12:32 DEBUG : >WaitForWriters: 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/vfs/read_write_test.go:387 Error: Should be true Test: TestRWFileHandleWriteAt Messages: listing wrong, want file1 (11) got fstest.go:203: Not found "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/vfs/read_write_test.go:387 Error: Not equal: expected: 0 actual : 1 Test: TestRWFileHandleWriteAt Messages: 1 objects not found 2026/07/18 02:12:40 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:12:40 DEBUG : Looking for writers 2026/07/18 02:12:40 DEBUG : file1: reading active writers 2026/07/18 02:12:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2026/07/18 02:12:40 DEBUG : Looking for writers 2026/07/18 02:12:40 DEBUG : file1: reading active writers 2026/07/18 02:12:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2026/07/18 02:12:40 DEBUG : Looking for writers 2026/07/18 02:12:40 DEBUG : file1: reading active writers 2026/07/18 02:12:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2026/07/18 02:12:40 DEBUG : Looking for writers 2026/07/18 02:12:40 DEBUG : file1: reading active writers 2026/07/18 02:12:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2026/07/18 02:12:40 DEBUG : Looking for writers 2026/07/18 02:12:40 DEBUG : file1: reading active writers 2026/07/18 02:12:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2026/07/18 02:12:40 DEBUG : Looking for writers 2026/07/18 02:12:40 DEBUG : file1: reading active writers 2026/07/18 02:12:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2026/07/18 02:12:40 DEBUG : Looking for writers 2026/07/18 02:12:40 DEBUG : file1: reading active writers 2026/07/18 02:12:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2026/07/18 02:12:41 DEBUG : Looking for writers 2026/07/18 02:12:41 DEBUG : file1: reading active writers 2026/07/18 02:12:41 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:42 DEBUG : Looking for writers 2026/07/18 02:12:42 DEBUG : file1: reading active writers 2026/07/18 02:12:42 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:43 DEBUG : Looking for writers 2026/07/18 02:12:43 DEBUG : file1: reading active writers 2026/07/18 02:12:43 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:44 DEBUG : Looking for writers 2026/07/18 02:12:44 DEBUG : file1: reading active writers 2026/07/18 02:12:44 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:45 DEBUG : Looking for writers 2026/07/18 02:12:45 DEBUG : file1: reading active writers 2026/07/18 02:12:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:46 DEBUG : Looking for writers 2026/07/18 02:12:46 DEBUG : file1: reading active writers 2026/07/18 02:12:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:47 DEBUG : Looking for writers 2026/07/18 02:12:47 DEBUG : file1: reading active writers 2026/07/18 02:12:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:48 DEBUG : Looking for writers 2026/07/18 02:12:48 DEBUG : file1: reading active writers 2026/07/18 02:12:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:49 DEBUG : Looking for writers 2026/07/18 02:12:49 DEBUG : file1: reading active writers 2026/07/18 02:12:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:50 DEBUG : Looking for writers 2026/07/18 02:12:50 DEBUG : file1: reading active writers 2026/07/18 02:12:50 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:51 DEBUG : Looking for writers 2026/07/18 02:12:51 DEBUG : file1: reading active writers 2026/07/18 02:12:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:52 DEBUG : Looking for writers 2026/07/18 02:12:52 DEBUG : file1: reading active writers 2026/07/18 02:12:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:53 DEBUG : Looking for writers 2026/07/18 02:12:53 DEBUG : file1: reading active writers 2026/07/18 02:12:53 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:54 DEBUG : Looking for writers 2026/07/18 02:12:54 DEBUG : file1: reading active writers 2026/07/18 02:12:54 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:54 DEBUG : file1: vfs cache: starting upload 2026/07/18 02:12:55 ERROR : file1: Failed to copy: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:12:55 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[197dc80b-c28d-42c5-8947-92aff10e5d8c] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=197dc80b-c28d-42c5-8947-92aff10e5d8c) 2026/07/18 02:12:55 ERROR : file1: vfs cache: failed to upload try #9, will retry in 51.2s: vfs cache: failed to transfer file from cache to remote: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:12:55 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[197dc80b-c28d-42c5-8947-92aff10e5d8c] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=197dc80b-c28d-42c5-8947-92aff10e5d8c) 2026/07/18 02:12:55 DEBUG : Looking for writers 2026/07/18 02:12:55 DEBUG : file1: reading active writers 2026/07/18 02:12:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:56 DEBUG : Looking for writers 2026/07/18 02:12:56 DEBUG : file1: reading active writers 2026/07/18 02:12:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:57 DEBUG : Looking for writers 2026/07/18 02:12:57 DEBUG : file1: reading active writers 2026/07/18 02:12:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:58 DEBUG : Looking for writers 2026/07/18 02:12:58 DEBUG : file1: reading active writers 2026/07/18 02:12:58 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:12:59 DEBUG : Looking for writers 2026/07/18 02:12:59 DEBUG : file1: reading active writers 2026/07/18 02:12:59 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:00 DEBUG : Looking for writers 2026/07/18 02:13:00 DEBUG : file1: reading active writers 2026/07/18 02:13:00 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:01 DEBUG : Looking for writers 2026/07/18 02:13:01 DEBUG : file1: reading active writers 2026/07/18 02:13:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:02 DEBUG : Looking for writers 2026/07/18 02:13:02 DEBUG : file1: reading active writers 2026/07/18 02:13:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:02 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2026/07/18 02:13:02 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 1 (was 1) in use 1, to upload 1, uploading 0, total size 11 (was 11) 2026/07/18 02:13:03 DEBUG : Looking for writers 2026/07/18 02:13:03 DEBUG : file1: reading active writers 2026/07/18 02:13:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:04 DEBUG : Looking for writers 2026/07/18 02:13:04 DEBUG : file1: reading active writers 2026/07/18 02:13:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:05 DEBUG : Looking for writers 2026/07/18 02:13:05 DEBUG : file1: reading active writers 2026/07/18 02:13:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:06 DEBUG : Looking for writers 2026/07/18 02:13:06 DEBUG : file1: reading active writers 2026/07/18 02:13:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:07 DEBUG : Looking for writers 2026/07/18 02:13:07 DEBUG : file1: reading active writers 2026/07/18 02:13:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:08 DEBUG : Looking for writers 2026/07/18 02:13:08 DEBUG : file1: reading active writers 2026/07/18 02:13:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:09 DEBUG : Looking for writers 2026/07/18 02:13:09 DEBUG : file1: reading active writers 2026/07/18 02:13:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:10 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0x998d0bc4c00 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0x998d08a8ea8 notify:{wait:0 notify:0 lock:0 head: tail:} checker:10551938420448} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:14019378108912528232 ext:91016243048 loc:0x47a3720} ATime:{wall:14019378108912545795 ext:91016260611 loc:0x47a3720} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false graceTimer: closing:}, } 2026/07/18 02:13:10 DEBUG : >WaitForWriters: 2026/07/18 02:13:10 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaner exiting --- FAIL: TestRWFileHandleWriteAt (67.25s) === RUN TestRWFileHandleSizeTruncateExisting run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:13:10 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:13:10 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: root is "/home/rclone/.cache/rclone" 2026/07/18 02:13:10 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:10 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:10 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:10 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:13:10 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:10 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:10 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:13:10 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:10 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:10 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[ef16ca9e-ddfd-4011-bfc9-be9b70e312e3] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=ef16ca9e-ddfd-4011-bfc9-be9b70e312e3) 2026/07/18 02:13:10 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:13:10 DEBUG : Looking for writers 2026/07/18 02:13:10 DEBUG : >WaitForWriters: 2026/07/18 02:13:10 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaner exiting --- FAIL: TestRWFileHandleSizeTruncateExisting (0.49s) === RUN TestRWFileHandleSizeCreateExisting run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:13:10 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:13:10 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: root is "/home/rclone/.cache/rclone" 2026/07/18 02:13:10 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:10 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:10 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:10 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:13:10 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:10 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:10 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:13:10 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:10 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:303: Failed to put "dir/file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:10 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[4f97925e-58d6-46b6-8f05-31c073c3e7c3] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=4f97925e-58d6-46b6-8f05-31c073c3e7c3) 2026/07/18 02:13:10 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:13:10 DEBUG : Looking for writers 2026/07/18 02:13:10 DEBUG : >WaitForWriters: 2026/07/18 02:13:10 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaner exiting --- FAIL: TestRWFileHandleSizeCreateExisting (0.47s) === RUN TestRWFileModTimeWithOpenWriters run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:13:11 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:13:11 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: root is "/home/rclone/.cache/rclone" 2026/07/18 02:13:11 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:11 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:11 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:11 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:13:11 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:11 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:11 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:13:11 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:11 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/07/18 02:13:11 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2026/07/18 02:13:11 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2026/07/18 02:13:11 DEBUG : file1: newRWFileHandle: 2026/07/18 02:13:11 DEBUG : file1(0x998d0c02a80): openPending: 2026/07/18 02:13:11 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct) 2026/07/18 02:13:11 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:13:11 DEBUG : file1(0x998d0c02a80): >openPending: err= 2026/07/18 02:13:11 DEBUG : file1: >newRWFileHandle: err= 2026/07/18 02:13:11 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:13:11 DEBUG : file1: >Open: fd=file1 (rw), err= 2026/07/18 02:13:11 DEBUG : file1: >OpenFile: fd=file1 (rw), err= run.go:303: Failed to put "time_test" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:11 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[4101cafd-5944-464f-a1ba-b0ff1acfa51c] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=4101cafd-5944-464f-a1ba-b0ff1acfa51c) 2026/07/18 02:13:11 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:13:11 DEBUG : Looking for writers 2026/07/18 02:13:11 DEBUG : file1: reading active writers 2026/07/18 02:13:11 DEBUG : file1: active writers 1 2026/07/18 02:13:11 DEBUG : Still 1 writers active and 1 cache items in use, waiting 10ms 2026/07/18 02:13:11 DEBUG : Looking for writers 2026/07/18 02:13:11 DEBUG : file1: reading active writers 2026/07/18 02:13:11 DEBUG : file1: active writers 1 2026/07/18 02:13:11 DEBUG : Still 1 writers active and 1 cache items in use, waiting 20ms 2026/07/18 02:13:11 DEBUG : Looking for writers 2026/07/18 02:13:11 DEBUG : file1: reading active writers 2026/07/18 02:13:11 DEBUG : file1: active writers 1 2026/07/18 02:13:11 DEBUG : Still 1 writers active and 1 cache items in use, waiting 40ms 2026/07/18 02:13:11 DEBUG : Looking for writers 2026/07/18 02:13:11 DEBUG : file1: reading active writers 2026/07/18 02:13:11 DEBUG : file1: active writers 1 2026/07/18 02:13:11 DEBUG : Still 1 writers active and 1 cache items in use, waiting 80ms 2026/07/18 02:13:11 DEBUG : Looking for writers 2026/07/18 02:13:11 DEBUG : file1: reading active writers 2026/07/18 02:13:11 DEBUG : file1: active writers 1 2026/07/18 02:13:11 DEBUG : Still 1 writers active and 1 cache items in use, waiting 160ms 2026/07/18 02:13:11 DEBUG : Looking for writers 2026/07/18 02:13:11 DEBUG : file1: reading active writers 2026/07/18 02:13:11 DEBUG : file1: active writers 1 2026/07/18 02:13:11 DEBUG : Still 1 writers active and 1 cache items in use, waiting 320ms 2026/07/18 02:13:11 DEBUG : Looking for writers 2026/07/18 02:13:11 DEBUG : file1: reading active writers 2026/07/18 02:13:11 DEBUG : file1: active writers 1 2026/07/18 02:13:11 DEBUG : Still 1 writers active and 1 cache items in use, waiting 640ms 2026/07/18 02:13:12 DEBUG : Looking for writers 2026/07/18 02:13:12 DEBUG : file1: reading active writers 2026/07/18 02:13:12 DEBUG : file1: active writers 1 2026/07/18 02:13:12 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:13 DEBUG : Looking for writers 2026/07/18 02:13:13 DEBUG : file1: reading active writers 2026/07/18 02:13:13 DEBUG : file1: active writers 1 2026/07/18 02:13:13 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:14 DEBUG : Looking for writers 2026/07/18 02:13:14 DEBUG : file1: reading active writers 2026/07/18 02:13:14 DEBUG : file1: active writers 1 2026/07/18 02:13:14 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:15 DEBUG : Looking for writers 2026/07/18 02:13:15 DEBUG : file1: reading active writers 2026/07/18 02:13:15 DEBUG : file1: active writers 1 2026/07/18 02:13:15 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:16 DEBUG : Looking for writers 2026/07/18 02:13:16 DEBUG : file1: reading active writers 2026/07/18 02:13:16 DEBUG : file1: active writers 1 2026/07/18 02:13:16 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:17 DEBUG : Looking for writers 2026/07/18 02:13:17 DEBUG : file1: reading active writers 2026/07/18 02:13:17 DEBUG : file1: active writers 1 2026/07/18 02:13:17 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:18 DEBUG : Looking for writers 2026/07/18 02:13:18 DEBUG : file1: reading active writers 2026/07/18 02:13:18 DEBUG : file1: active writers 1 2026/07/18 02:13:18 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:19 DEBUG : Looking for writers 2026/07/18 02:13:19 DEBUG : file1: reading active writers 2026/07/18 02:13:19 DEBUG : file1: active writers 1 2026/07/18 02:13:19 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:20 DEBUG : Looking for writers 2026/07/18 02:13:20 DEBUG : file1: reading active writers 2026/07/18 02:13:20 DEBUG : file1: active writers 1 2026/07/18 02:13:20 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:21 DEBUG : Looking for writers 2026/07/18 02:13:21 DEBUG : file1: reading active writers 2026/07/18 02:13:21 DEBUG : file1: active writers 1 2026/07/18 02:13:21 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:22 DEBUG : Looking for writers 2026/07/18 02:13:22 DEBUG : file1: reading active writers 2026/07/18 02:13:22 DEBUG : file1: active writers 1 2026/07/18 02:13:22 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:23 DEBUG : Looking for writers 2026/07/18 02:13:23 DEBUG : file1: reading active writers 2026/07/18 02:13:23 DEBUG : file1: active writers 1 2026/07/18 02:13:23 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:24 DEBUG : Looking for writers 2026/07/18 02:13:24 DEBUG : file1: reading active writers 2026/07/18 02:13:24 DEBUG : file1: active writers 1 2026/07/18 02:13:24 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:25 DEBUG : Looking for writers 2026/07/18 02:13:25 DEBUG : file1: reading active writers 2026/07/18 02:13:25 DEBUG : file1: active writers 1 2026/07/18 02:13:25 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:26 DEBUG : Looking for writers 2026/07/18 02:13:26 DEBUG : file1: reading active writers 2026/07/18 02:13:26 DEBUG : file1: active writers 1 2026/07/18 02:13:26 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:27 DEBUG : Looking for writers 2026/07/18 02:13:27 DEBUG : file1: reading active writers 2026/07/18 02:13:27 DEBUG : file1: active writers 1 2026/07/18 02:13:27 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:28 DEBUG : Looking for writers 2026/07/18 02:13:28 DEBUG : file1: reading active writers 2026/07/18 02:13:28 DEBUG : file1: active writers 1 2026/07/18 02:13:28 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:29 DEBUG : Looking for writers 2026/07/18 02:13:29 DEBUG : file1: reading active writers 2026/07/18 02:13:29 DEBUG : file1: active writers 1 2026/07/18 02:13:29 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:30 DEBUG : Looking for writers 2026/07/18 02:13:30 DEBUG : file1: reading active writers 2026/07/18 02:13:30 DEBUG : file1: active writers 1 2026/07/18 02:13:30 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:31 DEBUG : Looking for writers 2026/07/18 02:13:31 DEBUG : file1: reading active writers 2026/07/18 02:13:31 DEBUG : file1: active writers 1 2026/07/18 02:13:31 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:32 DEBUG : Looking for writers 2026/07/18 02:13:32 DEBUG : file1: reading active writers 2026/07/18 02:13:32 DEBUG : file1: active writers 1 2026/07/18 02:13:32 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:33 DEBUG : Looking for writers 2026/07/18 02:13:33 DEBUG : file1: reading active writers 2026/07/18 02:13:33 DEBUG : file1: active writers 1 2026/07/18 02:13:33 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:34 DEBUG : Looking for writers 2026/07/18 02:13:34 DEBUG : file1: reading active writers 2026/07/18 02:13:34 DEBUG : file1: active writers 1 2026/07/18 02:13:34 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:35 DEBUG : Looking for writers 2026/07/18 02:13:35 DEBUG : file1: reading active writers 2026/07/18 02:13:35 DEBUG : file1: active writers 1 2026/07/18 02:13:35 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:36 DEBUG : Looking for writers 2026/07/18 02:13:36 DEBUG : file1: reading active writers 2026/07/18 02:13:36 DEBUG : file1: active writers 1 2026/07/18 02:13:36 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:37 DEBUG : Looking for writers 2026/07/18 02:13:37 DEBUG : file1: reading active writers 2026/07/18 02:13:37 DEBUG : file1: active writers 1 2026/07/18 02:13:37 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:38 DEBUG : Looking for writers 2026/07/18 02:13:38 DEBUG : file1: reading active writers 2026/07/18 02:13:38 DEBUG : file1: active writers 1 2026/07/18 02:13:38 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:39 DEBUG : Looking for writers 2026/07/18 02:13:39 DEBUG : file1: reading active writers 2026/07/18 02:13:39 DEBUG : file1: active writers 1 2026/07/18 02:13:39 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:40 DEBUG : Looking for writers 2026/07/18 02:13:40 DEBUG : file1: reading active writers 2026/07/18 02:13:40 DEBUG : file1: active writers 1 2026/07/18 02:13:40 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2026/07/18 02:13:41 ERROR : Exiting even though 1 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0x998d0ae2500 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0x998d08a8908 notify:{wait:0 notify:0 lock:0 head: tail:} checker:10551938419008} name:file1 opens:1 downloaders: o: fd:0x998d05a60e8 info:{ModTime:{wall:14019378182208452269 ext:159223981239 loc:0x47a3720} ATime:{wall:14019378182208452269 ext:159223981239 loc:0x47a3720} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:0 pendingAccesses:0 modified:true beingReset:false graceTimer: closing:}, } 2026/07/18 02:13:41 DEBUG : >WaitForWriters: 2026/07/18 02:13:41 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaner exiting --- FAIL: TestRWFileModTimeWithOpenWriters (30.27s) === RUN TestRWCacheUpdate run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:13:41 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:13:41 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: root is "/home/rclone/.cache/rclone" 2026/07/18 02:13:41 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:41 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:41 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:41 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:13:41 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:41 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:41 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2026/07/18 02:13:41 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-puzexax4kelo" 2026/07/18 02:13:41 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:303: Failed to put "TestRWCacheUpdate" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:41 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[6aa31640-ee80-4fb4-b17d-ac822c606d2b] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=6aa31640-ee80-4fb4-b17d-ac822c606d2b) 2026/07/18 02:13:41 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:13:41 DEBUG : Looking for writers 2026/07/18 02:13:41 DEBUG : >WaitForWriters: 2026/07/18 02:13:41 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: vfs cache: cleaner exiting --- FAIL: TestRWCacheUpdate (0.17s) === RUN TestUnicodeNormalization run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:13:41 DEBUG : forgetting directory cache run.go:303: Failed to put "normal name with no special characters.txt" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:41 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[2aeb8355-11da-4e6b-9518-60ca5c26632e] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=2aeb8355-11da-4e6b-9518-60ca5c26632e) --- FAIL: TestUnicodeNormalization (0.17s) === RUN TestVFSStat run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:13:41 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:41 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[c8da80b7-7834-400a-ac4b-7da108e9362f] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=c8da80b7-7834-400a-ac4b-7da108e9362f) 2026/07/18 02:13:41 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:13:41 DEBUG : Looking for writers 2026/07/18 02:13:41 DEBUG : >WaitForWriters: --- FAIL: TestVFSStat (0.17s) === RUN TestVFSStatParent run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:13:41 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:41 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[5cf32915-bf76-4ccc-856e-d67ce99a5056] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=5cf32915-bf76-4ccc-856e-d67ce99a5056) 2026/07/18 02:13:42 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:13:42 DEBUG : Looking for writers 2026/07/18 02:13:42 DEBUG : >WaitForWriters: --- FAIL: TestVFSStatParent (0.18s) === RUN TestVFSOpenFile run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:13:42 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:42 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[9458610a-e60b-4808-85e8-1234839d02e3] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=9458610a-e60b-4808-85e8-1234839d02e3) 2026/07/18 02:13:42 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:13:42 DEBUG : Looking for writers 2026/07/18 02:13:42 DEBUG : >WaitForWriters: --- FAIL: TestVFSOpenFile (0.17s) === RUN TestVFSRename run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:13:42 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir/file2" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:42 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[a89ad77d-d38a-4e2a-9228-383a08b18021] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=a89ad77d-d38a-4e2a-9228-383a08b18021) 2026/07/18 02:13:42 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:13:42 DEBUG : Looking for writers 2026/07/18 02:13:42 DEBUG : >WaitForWriters: --- FAIL: TestVFSRename (0.48s) === RUN TestWriteFileHandleMethods run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:13:42 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:13:42 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/07/18 02:13:42 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2026/07/18 02:13:42 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:13:42 DEBUG : file1: >Open: fd=file1 (w), err= 2026/07/18 02:13:42 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2026/07/18 02:13:42 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:13:42 ERROR : file1: WriteFileHandle: Read: Can't read and write to file without --vfs-cache-mode >= minimal 2026/07/18 02:13:42 ERROR : file1: WriteFileHandle: ReadAt: Can't read and write to file without --vfs-cache-mode >= minimal 2026/07/18 02:13:42 ERROR : file1: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes 2026/07/18 02:13:42 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: File to upload is small (5 bytes), uploading instead of streaming 2026/07/18 02:13:42 ERROR : file1: WriteFileHandle.New Rcat failed: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:42 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[b0018b3c-5cdc-48d4-8ea5-1bd90e75b779] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=b0018b3c-5cdc-48d4-8ea5-1bd90e75b779) 2026/07/18 02:13:42 DEBUG : file1: Remove: 2026/07/18 02:13:42 DEBUG : Added virtual directory entry vDel: "file1" 2026/07/18 02:13:42 DEBUG : file1: >Remove: err= write_test.go:144: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:144 Error: Received unexpected error: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:42 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[b0018b3c-5cdc-48d4-8ea5-1bd90e75b779] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=b0018b3c-5cdc-48d4-8ea5-1bd90e75b779) Test: TestWriteFileHandleMethods dir_test.go:250: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:250 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:153 Error: Not equal: expected: []string{"file1,5,false"} actual : []string(nil) Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=1) { - (string) (len=13) "file1,5,false" -} +([]string) Test: TestWriteFileHandleMethods 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/vfs/write_test.go:157 Error: Should be true Test: TestWriteFileHandleMethods Messages: listing wrong, want file1 (5) got fstest.go:203: Not found "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/vfs/write_test.go:157 Error: Not equal: expected: 0 actual : 1 Test: TestWriteFileHandleMethods Messages: 1 objects not found 2026/07/18 02:13:50 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/07/18 02:13:50 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2026/07/18 02:13:50 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:13:50 DEBUG : file1: >Open: fd=file1 (w), err= 2026/07/18 02:13:50 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2026/07/18 02:13:50 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:13:50 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: File to upload is small (0 bytes), uploading instead of streaming 2026/07/18 02:13:50 DEBUG : file1: size = 0 OK 2026/07/18 02:13:50 DEBUG : file1: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/07/18 02:13:50 DEBUG : file1: Size and md5 of src and dst objects identical 2026/07/18 02:13:50 DEBUG : Added virtual directory entry vAddFile: "file1" dir_test.go:250: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:250 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:164 Error: Not equal: expected: []string{"file1,5,false"} actual : []string{"file1,0,false"} Diff: --- Expected +++ Actual @@ -1,3 +1,3 @@ ([]string) (len=1) { - (string) (len=13) "file1,5,false" + (string) (len=13) "file1,0,false" } Test: TestWriteFileHandleMethods 2026/07/18 02:13:50 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/07/18 02:13:50 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2026/07/18 02:13:50 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:13:50 DEBUG : file1: >Open: fd=file1 (w), err= 2026/07/18 02:13:50 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2026/07/18 02:13:50 ERROR : file1: WriteFileHandle: Can't open for write without O_TRUNC on existing file without --vfs-cache-mode >= writes dir_test.go:250: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:250 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:173 Error: Not equal: expected: []string{"file1,5,false"} actual : []string{"file1,0,false"} Diff: --- Expected +++ Actual @@ -1,3 +1,3 @@ ([]string) (len=1) { - (string) (len=13) "file1,5,false" + (string) (len=13) "file1,0,false" } Test: TestWriteFileHandleMethods 2026/07/18 02:13:50 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx 2026/07/18 02:13:50 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE|O_TRUNC 2026/07/18 02:13:50 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:13:50 DEBUG : file1: >Open: fd=file1 (w), err= 2026/07/18 02:13:50 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2026/07/18 02:13:50 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:13:50 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: File to upload is small (0 bytes), uploading instead of streaming 2026/07/18 02:13:50 DEBUG : file1: size = 0 OK 2026/07/18 02:13:50 DEBUG : file1: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/07/18 02:13:50 DEBUG : file1: Size and md5 of src and dst objects identical 2026/07/18 02:13:50 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:13:50 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx 2026/07/18 02:13:50 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE|O_TRUNC 2026/07/18 02:13:50 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:13:50 DEBUG : file1: >Open: fd=file1 (w), err= 2026/07/18 02:13:50 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2026/07/18 02:13:50 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:13:50 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: File to upload is small (7 bytes), uploading instead of streaming 2026/07/18 02:13:50 ERROR : file1: WriteFileHandle.New Rcat failed: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:50 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[85c2a1ca-062d-495e-b253-cd37af0cdab6] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=85c2a1ca-062d-495e-b253-cd37af0cdab6) write_test.go:190: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:190 Error: Received unexpected error: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:50 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[85c2a1ca-062d-495e-b253-cd37af0cdab6] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=85c2a1ca-062d-495e-b253-cd37af0cdab6) Test: TestWriteFileHandleMethods dir_test.go:250: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:250 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:191 Error: Not equal: expected: []string{"file1,7,false"} actual : []string{"file1,0,false"} Diff: --- Expected +++ Actual @@ -1,3 +1,3 @@ ([]string) (len=1) { - (string) (len=13) "file1,7,false" + (string) (len=13) "file1,0,false" } Test: TestWriteFileHandleMethods 2026/07/18 02:13:50 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:13:50 DEBUG : Looking for writers 2026/07/18 02:13:50 DEBUG : file1: reading active writers 2026/07/18 02:13:50 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleMethods (7.90s) === RUN TestWriteFileHandleWriteAt run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:13:50 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:13:50 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/07/18 02:13:50 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2026/07/18 02:13:50 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:13:50 DEBUG : file1: >Open: fd=file1 (w), err= 2026/07/18 02:13:50 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2026/07/18 02:13:50 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:13:50 DEBUG : file1: waiting for in-sequence write to 100 for 1s 2026/07/18 02:13:51 DEBUG : file1: aborting in-sequence write wait, off=100 2026/07/18 02:13:51 DEBUG : file1: failed to wait for in-sequence write to 100 2026/07/18 02:13:51 ERROR : file1: WriteFileHandle.Write: can't seek in file without --vfs-cache-mode >= writes 2026/07/18 02:13:51 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: File to upload is small (11 bytes), uploading instead of streaming 2026/07/18 02:13:51 ERROR : file1: WriteFileHandle.New Rcat failed: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:51 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[efcc7c80-6b5d-49f9-b68c-a72bd40244a0] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=efcc7c80-6b5d-49f9-b68c-a72bd40244a0) 2026/07/18 02:13:51 DEBUG : file1: Remove: 2026/07/18 02:13:51 DEBUG : Added virtual directory entry vDel: "file1" 2026/07/18 02:13:51 DEBUG : file1: >Remove: err= write_test.go:221: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:221 Error: Received unexpected error: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:51 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[efcc7c80-6b5d-49f9-b68c-a72bd40244a0] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=efcc7c80-6b5d-49f9-b68c-a72bd40244a0) Test: TestWriteFileHandleWriteAt 2026/07/18 02:13:51 ERROR : file1: WriteFileHandle.Write: error: Bad file descriptor dir_test.go:250: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:250 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:231 Error: Not equal: expected: []string{"file1,11,false"} actual : []string(nil) Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=1) { - (string) (len=14) "file1,11,false" -} +([]string) Test: TestWriteFileHandleWriteAt 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/vfs/write_test.go:235 Error: Should be true Test: TestWriteFileHandleWriteAt Messages: listing wrong, want file1 (11) got fstest.go:203: Not found "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/vfs/write_test.go:235 Error: Not equal: expected: 0 actual : 1 Test: TestWriteFileHandleWriteAt Messages: 1 objects not found 2026/07/18 02:13:58 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:13:58 DEBUG : Looking for writers 2026/07/18 02:13:58 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleWriteAt (8.35s) === RUN TestWriteFileHandleFlush run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:13:59 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:13:59 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/07/18 02:13:59 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2026/07/18 02:13:59 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:13:59 DEBUG : file1: >Open: fd=file1 (w), err= 2026/07/18 02:13:59 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2026/07/18 02:13:59 DEBUG : file1: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions 2026/07/18 02:13:59 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:13:59 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: File to upload is small (5 bytes), uploading instead of streaming 2026/07/18 02:13:59 ERROR : file1: WriteFileHandle.New Rcat failed: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:59 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[d8d07c35-a896-4969-ab89-133c670b10a1] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=d8d07c35-a896-4969-ab89-133c670b10a1) 2026/07/18 02:13:59 DEBUG : file1: Remove: 2026/07/18 02:13:59 DEBUG : Added virtual directory entry vDel: "file1" 2026/07/18 02:13:59 DEBUG : file1: >Remove: err= 2026/07/18 02:13:59 ERROR : file1: WriteFileHandle.Flush error: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:59 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[d8d07c35-a896-4969-ab89-133c670b10a1] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=d8d07c35-a896-4969-ab89-133c670b10a1) write_test.go:256: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:256 Error: Received unexpected error: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:59 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[d8d07c35-a896-4969-ab89-133c670b10a1] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=d8d07c35-a896-4969-ab89-133c670b10a1) Test: TestWriteFileHandleFlush 2026/07/18 02:13:59 DEBUG : file1: WriteFileHandle.Flush nothing to do dir_test.go:250: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:250 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:267 Error: Not equal: expected: []string{"file1,5,false"} actual : []string(nil) Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=1) { - (string) (len=13) "file1,5,false" -} +([]string) Test: TestWriteFileHandleFlush 2026/07/18 02:13:59 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:13:59 DEBUG : Looking for writers 2026/07/18 02:13:59 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleFlush (0.29s) === RUN TestWriteFileModTimeWithOpenWriters run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:13:59 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:13:59 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/07/18 02:13:59 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2026/07/18 02:13:59 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:13:59 DEBUG : file1: >Open: fd=file1 (w), err= 2026/07/18 02:13:59 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2026/07/18 02:13:59 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:13:59 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: File to upload is small (2 bytes), uploading instead of streaming 2026/07/18 02:13:59 ERROR : file1: WriteFileHandle.New Rcat failed: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:59 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[c3969921-4599-48b1-b3ce-c0488aa36522] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=c3969921-4599-48b1-b3ce-c0488aa36522) 2026/07/18 02:13:59 DEBUG : file1: Remove: 2026/07/18 02:13:59 DEBUG : Added virtual directory entry vDel: "file1" 2026/07/18 02:13:59 DEBUG : file1: >Remove: err= write_test.go:333: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:333 Error: Received unexpected error: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:59 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[c3969921-4599-48b1-b3ce-c0488aa36522] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=c3969921-4599-48b1-b3ce-c0488aa36522) Test: TestWriteFileModTimeWithOpenWriters 2026/07/18 02:13:59 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:13:59 DEBUG : Looking for writers 2026/07/18 02:13:59 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileModTimeWithOpenWriters (0.22s) === RUN TestFileReadAtNonZeroLength run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:13:59 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote 2026/07/18 02:13:59 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2026/07/18 02:13:59 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2026/07/18 02:13:59 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:13:59 DEBUG : file1: >Open: fd=file1 (w), err= 2026/07/18 02:13:59 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2026/07/18 02:13:59 DEBUG : Added virtual directory entry vAddFile: "file1" 2026/07/18 02:13:59 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: File to upload is small (100 bytes), uploading instead of streaming 2026/07/18 02:13:59 ERROR : file1: WriteFileHandle.New Rcat failed: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:59 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[c429c796-231e-4257-8b1b-038f4f562414] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=c429c796-231e-4257-8b1b-038f4f562414) 2026/07/18 02:13:59 DEBUG : file1: Remove: 2026/07/18 02:13:59 DEBUG : Added virtual directory entry vDel: "file1" 2026/07/18 02:13:59 DEBUG : file1: >Remove: err= write_test.go:360: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:360 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:384 Error: Received unexpected error: Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:59 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[c429c796-231e-4257-8b1b-038f4f562414] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=c429c796-231e-4257-8b1b-038f4f562414) Test: TestFileReadAtNonZeroLength 2026/07/18 02:13:59 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2026/07/18 02:13:59 DEBUG : file1: >OpenFile: fd=, err=file does not exist write_test.go:365: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:365 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:384 Error: Received unexpected error: file does not exist Test: TestFileReadAtNonZeroLength 2026/07/18 02:13:59 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:13:59 DEBUG : Looking for writers 2026/07/18 02:13:59 DEBUG : >WaitForWriters: --- FAIL: TestFileReadAtNonZeroLength (0.22s) === RUN TestZipManyFiles run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:13:59 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "flat/f000.txt" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:13:59 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[8fc65b34-6c3b-423d-aebf-ff2cbe11257e] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=8fc65b34-6c3b-423d-aebf-ff2cbe11257e) 2026/07/18 02:13:59 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:13:59 DEBUG : Looking for writers 2026/07/18 02:13:59 DEBUG : >WaitForWriters: --- FAIL: TestZipManyFiles (0.50s) === RUN TestZipManySubDirs run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:14:00 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "a/top.txt" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:14:00 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[a0a9708a-cd55-42d3-9267-05b9d8b84606] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=a0a9708a-cd55-42d3-9267-05b9d8b84606) 2026/07/18 02:14:00 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:14:00 DEBUG : Looking for writers 2026/07/18 02:14:00 DEBUG : >WaitForWriters: --- FAIL: TestZipManySubDirs (0.46s) === RUN TestZipLargeFiles run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:14:00 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "bigdir/big.bin" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:14:00 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[8f407655-2d36-4b22-b35d-33a113904747] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=8f407655-2d36-4b22-b35d-33a113904747) 2026/07/18 02:14:01 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:14:01 DEBUG : Looking for writers 2026/07/18 02:14:01 DEBUG : >WaitForWriters: --- FAIL: TestZipLargeFiles (0.62s) === RUN TestZipDirsInRoot run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo", Local "Local file system at /tmp/rclone1798279652", Modify Window "1ms" 2026/07/18 02:14:01 INFO : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: poll-interval is not supported by this remote run.go:303: Failed to put "dir1/a.txt" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo": Invalid response status! Got 500, expected [200]; headers: map[Cache-Control:[no-cache, no-store, must-revalidate] Content-Length:[71] Content-Type:[text/plain] Date:[Sat, 18 Jul 2026 04:14:01 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[23ef4b0c-f04b-4ccf-9686-dfaef73d0f6f] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=23ef4b0c-f04b-4ccf-9686-dfaef73d0f6f) 2026/07/18 02:14:01 DEBUG : WaitForWriters: timeout=30s 2026/07/18 02:14:01 DEBUG : Looking for writers 2026/07/18 02:14:01 DEBUG : >WaitForWriters: --- FAIL: TestZipDirsInRoot (0.53s) FAIL 2026/07/18 02:14:01 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-puzexax4kelo: Purge dir "" "./vfs.test -test.v -test.timeout 1h0m0s -remote TestKoofr: -verbose -test.run '^(TestDirCreate|TestDirFileOpen|TestDirForgetAll|TestDirForgetPath|TestDirHandleMethods|TestDirHandleReaddir|TestDirHandleReaddirnames|TestDirMetadataExtension|TestDirMethods|TestDirMkdir|TestDirMkdirSub|TestDirOpen|TestDirReadDirAll|TestDirRemove|TestDirRemoveAll|TestDirRemoveName|TestDirRename|TestDirSetModTime|TestDirStat|TestDirWalk|TestFileMethods|TestFileOpen|TestFileOpenRead|TestFileOpenWrite|TestFileReadAtNonZeroLength|TestFileRemove|TestFileRemoveAll|TestRWCacheUpdate|TestRWFileHandleFlushRead|TestRWFileHandleMethodsRead|TestRWFileHandleMethodsWrite|TestRWFileHandleReadAt|TestRWFileHandleReleaseRead|TestRWFileHandleSeek|TestRWFileHandleSizeCreateExisting|TestRWFileHandleSizeTruncateExisting|TestRWFileHandleWriteAt|TestRWFileModTimeWithOpenWriters|TestReadFileHandleFlush|TestReadFileHandleMethods|TestReadFileHandleReadAt|TestReadFileHandleRelease|TestReadFileHandleSeek|TestUnicodeNormalization|TestVFSOpenFile|TestVFSRename|TestVFSStat|TestVFSStatParent|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileHandleWriteAt|TestWriteFileModTimeWithOpenWriters|TestZipDirsInRoot|TestZipLargeFiles|TestZipManyFiles|TestZipManySubDirs)$|^TestFileRename$/^(full,forceCache=false|minimal,forceCache=false|minimal,forceCache=true|off,forceCache=false|writes,forceCache=false|writes,forceCache=true)$|^TestFileSetModTime$/^(cache=full,open=false,write=false|cache=full,open=true,write=false|cache=full,open=true,write=true|cache=off,open=false,write=false|cache=off,open=true,write=false|cache=off,open=true,write=true)$'" - Finished ERROR in 3m30.088031283s (try 2/5): exit status 1: Failed [TestDirHandleMethods TestDirHandleReaddir TestDirHandleReaddirnames TestDirMethods TestDirForgetAll TestDirForgetPath TestDirWalk TestDirSetModTime TestDirStat TestDirReadDirAll TestDirOpen TestDirCreate TestDirMkdir TestDirMkdirSub TestDirRemove TestDirRemoveAll TestDirRemoveName TestDirRename TestDirFileOpen TestDirMetadataExtension TestFileMethods TestFileSetModTime/cache=off,open=false,write=false TestFileSetModTime/cache=off,open=true,write=false TestFileSetModTime/cache=off,open=true,write=true TestFileSetModTime/cache=full,open=false,write=false TestFileSetModTime/cache=full,open=true,write=false TestFileSetModTime/cache=full,open=true,write=true TestFileOpenRead TestFileOpenWrite TestFileRemove TestFileRemoveAll TestFileOpen TestFileRename/off,forceCache=false TestFileRename/minimal,forceCache=false TestFileRename/minimal,forceCache=true TestFileRename/writes,forceCache=false TestFileRename/writes,forceCache=true TestFileRename/full,forceCache=false TestReadFileHandleMethods TestReadFileHandleSeek TestReadFileHandleReadAt TestReadFileHandleFlush TestReadFileHandleRelease TestRWFileHandleMethodsRead TestRWFileHandleSeek TestRWFileHandleReadAt TestRWFileHandleFlushRead TestRWFileHandleReleaseRead TestRWFileHandleMethodsWrite TestRWFileHandleWriteAt TestRWFileHandleSizeTruncateExisting TestRWFileHandleSizeCreateExisting TestRWFileModTimeWithOpenWriters TestRWCacheUpdate TestUnicodeNormalization TestVFSStat TestVFSStatParent TestVFSOpenFile TestVFSRename TestWriteFileHandleMethods TestWriteFileHandleWriteAt TestWriteFileHandleFlush TestWriteFileModTimeWithOpenWriters TestFileReadAtNonZeroLength TestZipManyFiles TestZipManySubDirs TestZipLargeFiles TestZipDirsInRoot]