"./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 4/5)
2026/07/18 02:17:41 DEBUG : Creating backend with remote "TestKoofr:rclone-test-gujodil9kifo"
2026/07/18 02:17:41 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/07/18 02:17:42 DEBUG : Creating backend with remote "/tmp/rclone185572851"
=== RUN   TestDirHandleMethods
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:17:42 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:17:42 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[80fadf43-541c-4ab7-a2c9-a23f587080c6] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=80fadf43-541c-4ab7-a2c9-a23f587080c6)
2026/07/18 02:17:43 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:17:43 DEBUG : Looking for writers
2026/07/18 02:17:43 DEBUG : >WaitForWriters: 
--- FAIL: TestDirHandleMethods (1.69s)
=== RUN   TestDirHandleReaddir
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:17:43 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:17:44 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[ddbae140-101d-4d83-be84-88e6ef015523] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=ddbae140-101d-4d83-be84-88e6ef015523)
2026/07/18 02:17:44 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:17:44 DEBUG : Looking for writers
2026/07/18 02:17:44 DEBUG : >WaitForWriters: 
--- FAIL: TestDirHandleReaddir (1.15s)
=== RUN   TestDirHandleReaddirnames
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:17:44 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:17:45 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[8c63a463-deb4-4f63-b27d-0caacf8cfc27] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=8c63a463-deb4-4f63-b27d-0caacf8cfc27)
2026/07/18 02:17:45 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:17:45 DEBUG : Looking for writers
2026/07/18 02:17:45 DEBUG : >WaitForWriters: 
--- FAIL: TestDirHandleReaddirnames (0.82s)
=== RUN   TestDirMethods
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:17:45 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:17:46 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[ebf6fd70-e051-40f8-b6a5-06ffe4dc9c58] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=ebf6fd70-e051-40f8-b6a5-06ffe4dc9c58)
2026/07/18 02:17:46 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:17:46 DEBUG : Looking for writers
2026/07/18 02:17:46 DEBUG : >WaitForWriters: 
--- FAIL: TestDirMethods (0.74s)
=== RUN   TestDirForgetAll
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:17:46 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:17:46 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[e9541d69-c1c7-4044-8b3b-0c12ffefa06b] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=e9541d69-c1c7-4044-8b3b-0c12ffefa06b)
2026/07/18 02:17:46 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:17:46 DEBUG : Looking for writers
2026/07/18 02:17:46 DEBUG : >WaitForWriters: 
--- FAIL: TestDirForgetAll (0.65s)
=== RUN   TestDirForgetPath
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:17:47 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:17:47 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[861a05f6-43b5-4f4a-8000-0c11f301b6ff] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=861a05f6-43b5-4f4a-8000-0c11f301b6ff)
2026/07/18 02:17:47 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:17:47 DEBUG : Looking for writers
2026/07/18 02:17:47 DEBUG : >WaitForWriters: 
--- FAIL: TestDirForgetPath (0.58s)
=== RUN   TestDirWalk
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:17:47 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:17:47 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[1816d63c-2131-45ae-b751-b5caccd2d8d7] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=1816d63c-2131-45ae-b751-b5caccd2d8d7)
2026/07/18 02:17:48 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:17:48 DEBUG : Looking for writers
2026/07/18 02:17:48 DEBUG : >WaitForWriters: 
--- FAIL: TestDirWalk (0.65s)
=== RUN   TestDirSetModTime
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:17:48 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:17:48 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[b1bb6f5d-15f6-4fbb-954c-0d4588aa2457] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=b1bb6f5d-15f6-4fbb-954c-0d4588aa2457)
2026/07/18 02:17:48 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:17:48 DEBUG : Looking for writers
2026/07/18 02:17:48 DEBUG : >WaitForWriters: 
--- FAIL: TestDirSetModTime (0.58s)
=== RUN   TestDirStat
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:17:48 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:17:49 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[3af44018-4574-4b85-870e-e87efa53d7c0] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=3af44018-4574-4b85-870e-e87efa53d7c0)
2026/07/18 02:17:49 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:17:49 DEBUG : Looking for writers
2026/07/18 02:17:49 DEBUG : >WaitForWriters: 
--- FAIL: TestDirStat (0.57s)
=== RUN   TestDirReadDirAll
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:17:49 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:17:49 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[5530e745-cde1-4ca1-b7e0-0f3c1d3430b8] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=5530e745-cde1-4ca1-b7e0-0f3c1d3430b8)
2026/07/18 02:17:49 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:17:49 DEBUG : Looking for writers
2026/07/18 02:17:49 DEBUG : >WaitForWriters: 
--- FAIL: TestDirReadDirAll (0.59s)
=== RUN   TestDirOpen
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:17:50 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:17:50 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[341064c1-9970-41d4-82a6-dc07453df8dc] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=341064c1-9970-41d4-82a6-dc07453df8dc)
2026/07/18 02:17:50 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:17:50 DEBUG : Looking for writers
2026/07/18 02:17:50 DEBUG : >WaitForWriters: 
--- FAIL: TestDirOpen (0.64s)
=== RUN   TestDirCreate
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:17:50 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:17:51 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[71bb11eb-accd-4adc-aa57-6fd5c703aa4f] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=71bb11eb-accd-4adc-aa57-6fd5c703aa4f)
2026/07/18 02:17:51 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:17:51 DEBUG : Looking for writers
2026/07/18 02:17:51 DEBUG : >WaitForWriters: 
--- FAIL: TestDirCreate (0.60s)
=== RUN   TestDirMkdir
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:17:51 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:17:51 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[0b9cc26c-fb25-4a14-b96c-61967bd5bd8c] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=0b9cc26c-fb25-4a14-b96c-61967bd5bd8c)
2026/07/18 02:17:51 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:17:51 DEBUG : Looking for writers
2026/07/18 02:17:51 DEBUG : >WaitForWriters: 
--- FAIL: TestDirMkdir (0.61s)
=== RUN   TestDirMkdirSub
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:17:51 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:17:52 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[5a21b94d-d655-4628-beb5-26de6bd25609] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=5a21b94d-d655-4628-beb5-26de6bd25609)
2026/07/18 02:17:52 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:17:52 DEBUG : Looking for writers
2026/07/18 02:17:52 DEBUG : >WaitForWriters: 
--- FAIL: TestDirMkdirSub (0.64s)
=== RUN   TestDirRemove
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:17:52 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:17:53 ERROR : dir/: Dir.Remove not empty
2026/07/18 02:17:53 DEBUG : dir/file1: Remove: 
2026/07/18 02:17:53 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/07/18 02:17:53 DEBUG : dir/file1: >Remove: err=<nil>
2026/07/18 02:17:53 DEBUG : Added virtual directory entry vDel: "dir"
2026/07/18 02:17:53 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:17:53 DEBUG : Looking for writers
2026/07/18 02:17:53 DEBUG : >WaitForWriters: 
--- PASS: TestDirRemove (1.14s)
=== RUN   TestDirRemoveAll
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:17:53 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:17:54 DEBUG : dir/file1: Remove: 
2026/07/18 02:17:54 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/07/18 02:17:54 DEBUG : dir/file1: >Remove: err=<nil>
2026/07/18 02:17:54 DEBUG : Added virtual directory entry vDel: "dir"
2026/07/18 02:17:54 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:17:54 DEBUG : Looking for writers
2026/07/18 02:17:54 DEBUG : >WaitForWriters: 
--- PASS: TestDirRemoveAll (1.32s)
=== RUN   TestDirRemoveName
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:17:55 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:17:55 DEBUG : dir/file1: Remove: 
2026/07/18 02:17:56 DEBUG : dir: Added virtual directory entry vDel: "file1"
2026/07/18 02:17:56 DEBUG : dir/file1: >Remove: err=<nil>
2026/07/18 02:17:56 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:17:56 DEBUG : dir: Looking for writers
2026/07/18 02:17:56 DEBUG : Looking for writers
2026/07/18 02:17:56 DEBUG : dir: reading active writers
2026/07/18 02:17:56 DEBUG : >WaitForWriters: 
--- PASS: TestDirRemoveName (1.39s)
=== RUN   TestDirRename
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:17:56 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:17:58 ERROR : dir/not found: Dir.Rename error: file does not exist
2026/07/18 02:17:58 DEBUG : dir: Updating dir with dir2 0x351defa428f0
2026/07/18 02:17:58 DEBUG : dir: forgetting directory cache
2026/07/18 02:17:58 DEBUG : Added virtual directory entry vDel: "dir"
2026/07/18 02:17:58 DEBUG : Added virtual directory entry vAddDir: "dir2"
2026/07/18 02:17:59 INFO  : dir2/file1: Moved (server-side) to: file2
2026/07/18 02:17:59 DEBUG : file2: Updating file with file2 0x351defa432b0
2026/07/18 02:17:59 DEBUG : dir2: Added virtual directory entry vDel: "file1"
2026/07/18 02:17:59 DEBUG : Added virtual directory entry vAddFile: "file2"
2026/07/18 02:17:59 INFO  : dir2/file3: Deleted
2026/07/18 02:17:59 INFO  : file2: Moved (server-side) to: dir2/file3
2026/07/18 02:17:59 DEBUG : dir2/file3: Updating file with dir2/file3 0x351defa432b0
2026/07/18 02:17:59 DEBUG : Added virtual directory entry vDel: "file2"
2026/07/18 02:17:59 DEBUG : dir2: Added virtual directory entry vAddFile: "file3"
2026/07/18 02:18:00 DEBUG : Added virtual directory entry vAddDir: "empty directory"
2026/07/18 02:18:00 DEBUG : empty directory: Updating dir with renamed empty directory 0x351def944680
2026/07/18 02:18:00 DEBUG : empty directory: forgetting directory cache
2026/07/18 02:18:00 DEBUG : Added virtual directory entry vDel: "empty directory"
2026/07/18 02:18:00 DEBUG : Added virtual directory entry vAddDir: "renamed empty directory"
2026/07/18 02:18:00 DEBUG : dir2: Renaming to "dir3"
2026/07/18 02:18:00 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:18:00 DEBUG : dir3: Looking for writers
2026/07/18 02:18:00 DEBUG : file3: reading active writers
2026/07/18 02:18:00 DEBUG : renamed empty directory: Looking for writers
2026/07/18 02:18:00 DEBUG : Looking for writers
2026/07/18 02:18:00 DEBUG : dir3: reading active writers
2026/07/18 02:18:00 DEBUG : renamed empty directory: reading active writers
2026/07/18 02:18:00 DEBUG : >WaitForWriters: 
--- PASS: TestDirRename (4.48s)
=== RUN   TestDirFileOpen
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:18:00 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:18:01 DEBUG : dir: Added virtual directory entry vAddDir: "sub"
2026/07/18 02:18:01 DEBUG : dir/sub/file0: OpenFile: flags=O_RDWR|O_CREATE|O_TRUNC, perm=-rw-rw-rw-
2026/07/18 02:18:02 DEBUG : dir/sub/file0: Open: flags=O_RDWR|O_CREATE|O_TRUNC
2026/07/18 02:18:02 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file0"
2026/07/18 02:18:02 DEBUG : dir/sub/file0: >Open: fd=dir/sub/file0 (w), err=<nil>
2026/07/18 02:18:02 DEBUG : dir/sub/file0: >OpenFile: fd=dir/sub/file0 (w), err=<nil>
2026/07/18 02:18:02 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file0"
2026/07/18 02:18:02 DEBUG : dir/sub/file2: OpenFile: flags=O_RDWR|O_CREATE|O_TRUNC, perm=-rw-rw-rw-
2026/07/18 02:18:02 DEBUG : dir/sub/file2: Open: flags=O_RDWR|O_CREATE|O_TRUNC
2026/07/18 02:18:02 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file2"
2026/07/18 02:18:02 DEBUG : dir/sub/file2: >Open: fd=dir/sub/file2 (w), err=<nil>
2026/07/18 02:18:02 DEBUG : dir/sub/file2: >OpenFile: fd=dir/sub/file2 (w), err=<nil>
2026/07/18 02:18:02 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file2"
2026/07/18 02:18:02 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: File to upload is small (12 bytes), uploading instead of streaming
2026/07/18 02:18:02 DEBUG : dir/sub/file2: size = 12 OK
2026/07/18 02:18:02 DEBUG : dir/sub/file2: md5 = fc3ff98e8c6a0d3087d515c0473f8677 OK
2026/07/18 02:18:02 DEBUG : dir/sub/file2: Size and md5 of src and dst objects identical
2026/07/18 02:18:02 DEBUG : dir/sub: Added virtual directory entry vAddFile: "file2"
2026/07/18 02:18:02 DEBUG : forgetting directory cache
2026/07/18 02:18:02 DEBUG : dir: forgetting directory cache
2026/07/18 02:18:02 DEBUG : dir/sub: forgetting directory cache
2026/07/18 02:18:02 DEBUG : dir/sub: Removed virtual directory entry vAddFile: "file2"
2026/07/18 02:18:02 DEBUG : dir: Removed virtual directory entry vAddDir: "sub"
2026/07/18 02:18:02 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: File to upload is small (5 bytes), uploading instead of streaming
2026/07/18 02:23:02 DEBUG : dir/sub/file0: Received error: Post "https:/content/api/v2/mounts/4266cdc3-3d29-4a88-ac94-738914c162b4/files/put?autorename=false&filename=file0&info=true&modified=1784341082002&overwrite=true&overwriteIgnoreNonexisting=&path=%2Frclone-test-gujodil9kifo%2Fdir%2Fsub": http2: timeout awaiting response headers - low level retry 1/10
2026/07/18 02:23:02 ERROR : dir/sub/file0: 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 02:23:02 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[5bb057a8-0a87-4a09-95ea-6117cf9e4b2c] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=5bb057a8-0a87-4a09-95ea-6117cf9e4b2c)
2026/07/18 02:23:02 DEBUG : dir/sub/file0: Remove: 
2026/07/18 02:23:02 DEBUG : dir/sub: Added virtual directory entry vDel: "file0"
2026/07/18 02:23:02 DEBUG : dir/sub/file0: >Remove: err=<nil>
    dir_test.go:632: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:632
        	            				/home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:660
        	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 02:23:02 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[5bb057a8-0a87-4a09-95ea-6117cf9e4b2c] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=5bb057a8-0a87-4a09-95ea-6117cf9e4b2c)
        	Test:       	TestDirFileOpen
2026/07/18 02:23:02 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:02 DEBUG : dir/sub: Looking for writers
2026/07/18 02:23:02 DEBUG : file2: reading active writers
2026/07/18 02:23:02 DEBUG : dir: Looking for writers
2026/07/18 02:23:02 DEBUG : file1: reading active writers
2026/07/18 02:23:02 DEBUG : sub: reading active writers
2026/07/18 02:23:02 DEBUG : Looking for writers
2026/07/18 02:23:02 DEBUG : dir: reading active writers
2026/07/18 02:23:02 DEBUG : >WaitForWriters: 
--- FAIL: TestDirFileOpen (302.48s)
=== RUN   TestDirMetadataExtension
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:03 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:03 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[3223cd8e-1e68-48ff-bdb1-e0c8fc675701] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=3223cd8e-1e68-48ff-bdb1-e0c8fc675701)
2026/07/18 02:23:03 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:03 DEBUG : Looking for writers
2026/07/18 02:23:03 DEBUG : >WaitForWriters: 
--- FAIL: TestDirMetadataExtension (0.61s)
=== RUN   TestFileMethods
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:04 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:04 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[831592e6-4df2-44aa-99a3-ba763373c7ae] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=831592e6-4df2-44aa-99a3-ba763373c7ae)
2026/07/18 02:23:04 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:04 DEBUG : Looking for writers
2026/07/18 02:23:04 DEBUG : >WaitForWriters: 
--- FAIL: TestFileMethods (0.58s)
=== RUN   TestFileSetModTime
=== RUN   TestFileSetModTime/cache=off,open=false,write=false
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:04 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:04 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[129a67e6-3f34-4d9d-b3df-966797ea90cf] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=129a67e6-3f34-4d9d-b3df-966797ea90cf)
2026/07/18 02:23:04 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:04 DEBUG : Looking for writers
2026/07/18 02:23:04 DEBUG : >WaitForWriters: 
=== RUN   TestFileSetModTime/cache=off,open=true,write=false
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:05 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:05 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[a2472896-f571-4ae0-beb5-b2f340712110] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=a2472896-f571-4ae0-beb5-b2f340712110)
2026/07/18 02:23:05 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:05 DEBUG : Looking for writers
2026/07/18 02:23:05 DEBUG : >WaitForWriters: 
=== RUN   TestFileSetModTime/cache=off,open=true,write=true
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:05 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:05 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[057ef294-dadd-42ae-8876-50b40d66ca7b] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=057ef294-dadd-42ae-8876-50b40d66ca7b)
2026/07/18 02:23:06 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:06 DEBUG : Looking for writers
2026/07/18 02:23:06 DEBUG : >WaitForWriters: 
=== RUN   TestFileSetModTime/cache=full,open=false,write=false
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:06 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:23:06 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: root is "/home/rclone/.cache/rclone"
2026/07/18 02:23:06 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:06 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:06 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:06 DEBUG : Config file has changed externally - reloading
2026/07/18 02:23:06 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:06 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:06 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:06 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:06 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:06 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:06 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[7daeb585-15c5-41ea-a1e1-220001fc6efb] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=7daeb585-15c5-41ea-a1e1-220001fc6efb)
2026/07/18 02:23:06 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:06 DEBUG : Looking for writers
2026/07/18 02:23:06 DEBUG : >WaitForWriters: 
2026/07/18 02:23:06 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaner exiting
=== RUN   TestFileSetModTime/cache=full,open=true,write=false
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:06 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:23:06 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: root is "/home/rclone/.cache/rclone"
2026/07/18 02:23:06 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:06 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:06 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:06 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:06 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:06 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:06 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:06 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:06 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:07 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[ca8cb657-3fc1-4530-a9e6-ebf2f353aa27] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=ca8cb657-3fc1-4530-a9e6-ebf2f353aa27)
2026/07/18 02:23:07 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:07 DEBUG : Looking for writers
2026/07/18 02:23:07 DEBUG : >WaitForWriters: 
2026/07/18 02:23:07 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaner exiting
=== RUN   TestFileSetModTime/cache=full,open=true,write=true
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:07 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:23:07 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: root is "/home/rclone/.cache/rclone"
2026/07/18 02:23:07 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:07 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:07 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:07 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:07 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:07 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:07 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:07 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:07 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:07 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[68d8118a-a0b1-42cd-a70f-75507f31a059] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=68d8118a-a0b1-42cd-a70f-75507f31a059)
2026/07/18 02:23:07 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:07 DEBUG : Looking for writers
2026/07/18 02:23:07 DEBUG : >WaitForWriters: 
2026/07/18 02:23:07 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaner exiting
--- FAIL: TestFileSetModTime (3.38s)
    --- FAIL: TestFileSetModTime/cache=off,open=false,write=false (0.55s)
    --- FAIL: TestFileSetModTime/cache=off,open=true,write=false (0.55s)
    --- FAIL: TestFileSetModTime/cache=off,open=true,write=true (0.56s)
    --- FAIL: TestFileSetModTime/cache=full,open=false,write=false (0.58s)
    --- FAIL: TestFileSetModTime/cache=full,open=true,write=false (0.59s)
    --- FAIL: TestFileSetModTime/cache=full,open=true,write=true (0.55s)
=== RUN   TestFileOpenRead
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:08 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:08 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[03382fea-e810-4157-b206-eff0672009ee] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=03382fea-e810-4157-b206-eff0672009ee)
2026/07/18 02:23:08 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:08 DEBUG : Looking for writers
2026/07/18 02:23:08 DEBUG : >WaitForWriters: 
--- FAIL: TestFileOpenRead (0.58s)
=== RUN   TestFileOpenWrite
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:08 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:08 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[30cdf956-f355-4aaf-af18-9d06617963d7] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=30cdf956-f355-4aaf-af18-9d06617963d7)
2026/07/18 02:23:08 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:08 DEBUG : Looking for writers
2026/07/18 02:23:08 DEBUG : >WaitForWriters: 
--- FAIL: TestFileOpenWrite (0.54s)
=== RUN   TestFileRemove
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:09 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:09 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[d9d5206e-529c-448a-80c2-a0026eaa74fe] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=d9d5206e-529c-448a-80c2-a0026eaa74fe)
2026/07/18 02:23:09 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:09 DEBUG : Looking for writers
2026/07/18 02:23:09 DEBUG : >WaitForWriters: 
--- FAIL: TestFileRemove (0.56s)
=== RUN   TestFileRemoveAll
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:09 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:09 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[1c680988-ca41-4191-ab20-c63db2c99be8] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=1c680988-ca41-4191-ab20-c63db2c99be8)
2026/07/18 02:23:09 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:09 DEBUG : Looking for writers
2026/07/18 02:23:09 DEBUG : >WaitForWriters: 
--- FAIL: TestFileRemoveAll (0.59s)
=== RUN   TestFileOpen
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:10 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:10 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[6cf7a302-e1af-4f32-a5bc-f436d30c960b] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=6cf7a302-e1af-4f32-a5bc-f436d30c960b)
2026/07/18 02:23:10 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:10 DEBUG : Looking for writers
2026/07/18 02:23:10 DEBUG : >WaitForWriters: 
--- FAIL: TestFileOpen (0.66s)
=== RUN   TestFileRename
=== RUN   TestFileRename/off,forceCache=false
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:10 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:11 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[339c9c1b-c5f1-4526-bb0e-36f8dda58d33] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=339c9c1b-c5f1-4526-bb0e-36f8dda58d33)
2026/07/18 02:23:11 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:11 DEBUG : Looking for writers
2026/07/18 02:23:11 DEBUG : >WaitForWriters: 
=== RUN   TestFileRename/minimal,forceCache=false
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:11 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:23:11 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: root is "/home/rclone/.cache/rclone"
2026/07/18 02:23:11 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:11 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:11 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:11 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:11 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:11 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:11 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:11 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:11 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:11 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[b533bbd3-8192-4c0d-ab5a-ff3ee471ed57] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=b533bbd3-8192-4c0d-ab5a-ff3ee471ed57)
2026/07/18 02:23:11 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:11 DEBUG : Looking for writers
2026/07/18 02:23:11 DEBUG : >WaitForWriters: 
2026/07/18 02:23:11 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaner exiting
=== RUN   TestFileRename/minimal,forceCache=true
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:12 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:23:12 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: root is "/home/rclone/.cache/rclone"
2026/07/18 02:23:12 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:12 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:12 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:12 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:12 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:12 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:12 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:12 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:12 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:12 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[31dbe377-2bfa-4ade-8130-400d68336832] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=31dbe377-2bfa-4ade-8130-400d68336832)
2026/07/18 02:23:12 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:12 DEBUG : Looking for writers
2026/07/18 02:23:12 DEBUG : >WaitForWriters: 
2026/07/18 02:23:12 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaner exiting
=== RUN   TestFileRename/writes,forceCache=false
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:12 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:23:12 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: root is "/home/rclone/.cache/rclone"
2026/07/18 02:23:12 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:12 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:12 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:12 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:12 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:12 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:12 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:12 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:12 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:12 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[7d03c72b-1018-49fc-b082-eeda05b20a6e] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=7d03c72b-1018-49fc-b082-eeda05b20a6e)
2026/07/18 02:23:12 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:12 DEBUG : Looking for writers
2026/07/18 02:23:12 DEBUG : >WaitForWriters: 
2026/07/18 02:23:12 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaner exiting
=== RUN   TestFileRename/writes,forceCache=true
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:13 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:23:13 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: root is "/home/rclone/.cache/rclone"
2026/07/18 02:23:13 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:13 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:13 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:13 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:13 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:13 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:13 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:13 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:13 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:13 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[f7a578e1-e89f-4a11-91f9-f8ba5f6331d3] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=f7a578e1-e89f-4a11-91f9-f8ba5f6331d3)
2026/07/18 02:23:13 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:13 DEBUG : Looking for writers
2026/07/18 02:23:13 DEBUG : >WaitForWriters: 
2026/07/18 02:23:13 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaner exiting
=== RUN   TestFileRename/full,forceCache=false
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:13 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:23:13 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: root is "/home/rclone/.cache/rclone"
2026/07/18 02:23:13 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:13 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:13 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:13 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:13 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:13 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:13 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:13 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:13 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:14 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[1f2c6129-69be-4295-89ea-42761f93bd0b] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=1f2c6129-69be-4295-89ea-42761f93bd0b)
2026/07/18 02:23:14 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:14 DEBUG : Looking for writers
2026/07/18 02:23:14 DEBUG : >WaitForWriters: 
2026/07/18 02:23:14 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaner exiting
--- FAIL: TestFileRename (3.56s)
    --- FAIL: TestFileRename/off,forceCache=false (0.60s)
    --- FAIL: TestFileRename/minimal,forceCache=false (0.57s)
    --- FAIL: TestFileRename/minimal,forceCache=true (0.58s)
    --- FAIL: TestFileRename/writes,forceCache=false (0.56s)
    --- FAIL: TestFileRename/writes,forceCache=true (0.55s)
    --- FAIL: TestFileRename/full,forceCache=false (0.70s)
=== RUN   TestReadFileHandleMethods
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:14 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:14 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[87ac6af7-89aa-4886-a52f-963bba09ae6c] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=87ac6af7-89aa-4886-a52f-963bba09ae6c)
2026/07/18 02:23:14 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:14 DEBUG : Looking for writers
2026/07/18 02:23:14 DEBUG : >WaitForWriters: 
--- FAIL: TestReadFileHandleMethods (0.63s)
=== RUN   TestReadFileHandleSeek
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:15 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:15 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[9d978286-719d-4581-8965-7aa276ffd7c6] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=9d978286-719d-4581-8965-7aa276ffd7c6)
2026/07/18 02:23:15 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:15 DEBUG : Looking for writers
2026/07/18 02:23:15 DEBUG : >WaitForWriters: 
--- FAIL: TestReadFileHandleSeek (0.59s)
=== RUN   TestReadFileHandleReadAt
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:15 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:15 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[a73f7099-167a-4fba-9d6f-5136b4ffb13e] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=a73f7099-167a-4fba-9d6f-5136b4ffb13e)
2026/07/18 02:23:16 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:16 DEBUG : Looking for writers
2026/07/18 02:23:16 DEBUG : >WaitForWriters: 
--- FAIL: TestReadFileHandleReadAt (0.58s)
=== RUN   TestReadFileHandleFlush
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:16 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:16 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[423ee4f0-368b-46c0-8372-bf804111b63d] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=423ee4f0-368b-46c0-8372-bf804111b63d)
2026/07/18 02:23:16 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:16 DEBUG : Looking for writers
2026/07/18 02:23:16 DEBUG : >WaitForWriters: 
--- FAIL: TestReadFileHandleFlush (0.57s)
=== RUN   TestReadFileHandleRelease
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:16 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:17 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[5ee8585f-99cf-416c-91f0-193f9d96b61b] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=5ee8585f-99cf-416c-91f0-193f9d96b61b)
2026/07/18 02:23:17 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:17 DEBUG : Looking for writers
2026/07/18 02:23:17 DEBUG : >WaitForWriters: 
--- FAIL: TestReadFileHandleRelease (0.59s)
=== RUN   TestRWFileHandleMethodsRead
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:17 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:23:17 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: root is "/home/rclone/.cache/rclone"
2026/07/18 02:23:17 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:17 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:17 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:17 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:17 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:17 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:17 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:17 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:17 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:17 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[fc9a35ce-1317-424a-8db9-34f9918f3490] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=fc9a35ce-1317-424a-8db9-34f9918f3490)
2026/07/18 02:23:17 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:17 DEBUG : Looking for writers
2026/07/18 02:23:17 DEBUG : >WaitForWriters: 
2026/07/18 02:23:17 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaner exiting
--- FAIL: TestRWFileHandleMethodsRead (0.65s)
=== RUN   TestRWFileHandleSeek
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:18 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:23:18 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: root is "/home/rclone/.cache/rclone"
2026/07/18 02:23:18 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:18 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:18 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:18 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:18 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:18 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:18 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:18 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:18 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:18 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[57b3ee87-dbbf-4807-9d63-a19827ca51a4] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=57b3ee87-dbbf-4807-9d63-a19827ca51a4)
2026/07/18 02:23:18 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:18 DEBUG : Looking for writers
2026/07/18 02:23:18 DEBUG : >WaitForWriters: 
2026/07/18 02:23:18 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaner exiting
--- FAIL: TestRWFileHandleSeek (0.56s)
=== RUN   TestRWFileHandleReadAt
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:18 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:23:18 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: root is "/home/rclone/.cache/rclone"
2026/07/18 02:23:18 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:18 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:18 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:18 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:18 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:18 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:18 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:18 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:18 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:18 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[1678783b-0fd4-4bc9-9ef8-29efe4bcb75b] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=1678783b-0fd4-4bc9-9ef8-29efe4bcb75b)
2026/07/18 02:23:18 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:18 DEBUG : Looking for writers
2026/07/18 02:23:18 DEBUG : >WaitForWriters: 
2026/07/18 02:23:18 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaner exiting
--- FAIL: TestRWFileHandleReadAt (0.56s)
=== RUN   TestRWFileHandleFlushRead
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:19 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:23:19 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: root is "/home/rclone/.cache/rclone"
2026/07/18 02:23:19 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:19 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:19 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:19 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:19 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:19 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:19 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:19 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:19 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:19 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[55a2e9d1-2fc0-4af1-8fbe-290c59f5be7e] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=55a2e9d1-2fc0-4af1-8fbe-290c59f5be7e)
2026/07/18 02:23:19 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:19 DEBUG : Looking for writers
2026/07/18 02:23:19 DEBUG : >WaitForWriters: 
2026/07/18 02:23:19 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaner exiting
--- FAIL: TestRWFileHandleFlushRead (0.57s)
=== RUN   TestRWFileHandleReleaseRead
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:19 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:23:19 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: root is "/home/rclone/.cache/rclone"
2026/07/18 02:23:19 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:19 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:19 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:19 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:19 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:19 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:19 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:19 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:19 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:23:20 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[042ee5a1-49cb-45a0-a5cd-e98e63290f4e] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=042ee5a1-49cb-45a0-a5cd-e98e63290f4e)
2026/07/18 02:23:20 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:20 DEBUG : Looking for writers
2026/07/18 02:23:20 DEBUG : >WaitForWriters: 
2026/07/18 02:23:20 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaner exiting
--- FAIL: TestRWFileHandleReleaseRead (0.59s)
=== RUN   TestRWFileHandleMethodsWrite
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:23:20 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:23:20 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: root is "/home/rclone/.cache/rclone"
2026/07/18 02:23:20 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:20 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:20 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:20 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:20 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:20 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:20 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:23:20 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:23:20 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2026/07/18 02:23:20 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2026/07/18 02:23:20 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2026/07/18 02:23:20 DEBUG : file1: newRWFileHandle: 
2026/07/18 02:23:20 DEBUG : file1(0x351defaf7580): openPending: 
2026/07/18 02:23:20 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct)
2026/07/18 02:23:20 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:23:20 DEBUG : file1(0x351defaf7580): >openPending: err=<nil>
2026/07/18 02:23:20 DEBUG : file1: >newRWFileHandle: err=<nil>
2026/07/18 02:23:20 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:23:20 DEBUG : file1: >Open: fd=file1 (rw), err=<nil>
2026/07/18 02:23:20 DEBUG : file1: >OpenFile: fd=file1 (rw), err=<nil>
2026/07/18 02:23:20 DEBUG : file1(0x351defaf7580): _writeAt: size=5, off=0
2026/07/18 02:23:20 DEBUG : file1(0x351defaf7580): >_writeAt: n=5, err=<nil>
2026/07/18 02:23:20 DEBUG : file1(0x351defaf7580): _writeAt: size=7, off=5
2026/07/18 02:23:20 DEBUG : file1(0x351defaf7580): >_writeAt: n=7, err=<nil>
2026/07/18 02:23:20 DEBUG : file1: vfs cache: truncate to size=11
2026/07/18 02:23:20 DEBUG : file1(0x351defaf7580): close: 
2026/07/18 02:23:20 DEBUG : file1: vfs cache: setting modification time to 2026-07-18 02:23:20.456196292 +0000 UTC m=+338.954712244
2026/07/18 02:23:20 INFO  : file1: vfs cache: queuing for upload in 100ms
2026/07/18 02:23:20 DEBUG : file1(0x351defaf7580): >close: err=<nil>
2026/07/18 02:23:20 DEBUG : file1(0x351defaf7580): close: 
2026/07/18 02:23:20 DEBUG : file1(0x351defaf7580): >close: err=file already closed
2026/07/18 02:23:20 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:20 DEBUG : Looking for writers
2026/07/18 02:23:20 DEBUG : file1: reading active writers
2026/07/18 02:23:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms
2026/07/18 02:23:20 DEBUG : Looking for writers
2026/07/18 02:23:20 DEBUG : file1: reading active writers
2026/07/18 02:23:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms
2026/07/18 02:23:20 DEBUG : Looking for writers
2026/07/18 02:23:20 DEBUG : file1: reading active writers
2026/07/18 02:23:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms
2026/07/18 02:23:20 DEBUG : Looking for writers
2026/07/18 02:23:20 DEBUG : file1: reading active writers
2026/07/18 02:23:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms
2026/07/18 02:23:20 DEBUG : file1: vfs cache: starting upload
2026/07/18 02:23:20 DEBUG : Looking for writers
2026/07/18 02:23:20 DEBUG : file1: reading active writers
2026/07/18 02:23:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms
2026/07/18 02:23:20 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 02:23:20 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[4b9fd8c5-5630-4cef-9ae5-e557c150f9a9] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=4b9fd8c5-5630-4cef-9ae5-e557c150f9a9)
2026/07/18 02:23:20 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 02:23:20 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[4b9fd8c5-5630-4cef-9ae5-e557c150f9a9] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=4b9fd8c5-5630-4cef-9ae5-e557c150f9a9)
2026/07/18 02:23:20 DEBUG : Looking for writers
2026/07/18 02:23:20 DEBUG : file1: reading active writers
2026/07/18 02:23:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms
2026/07/18 02:23:20 DEBUG : file1: vfs cache: starting upload
2026/07/18 02:23:20 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 02:23:20 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[1eb93a30-ec1f-4e84-8dda-c45440ff7953] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=1eb93a30-ec1f-4e84-8dda-c45440ff7953)
2026/07/18 02:23:20 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 02:23:20 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[1eb93a30-ec1f-4e84-8dda-c45440ff7953] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=1eb93a30-ec1f-4e84-8dda-c45440ff7953)
2026/07/18 02:23:21 DEBUG : Looking for writers
2026/07/18 02:23:21 DEBUG : file1: reading active writers
2026/07/18 02:23:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms
2026/07/18 02:23:21 DEBUG : file1: vfs cache: starting upload
2026/07/18 02:23:21 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 02:23:21 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[83c9e4d9-1996-4d7c-912f-3b0310fe2fd1] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=83c9e4d9-1996-4d7c-912f-3b0310fe2fd1)
2026/07/18 02:23:21 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 02:23:21 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[83c9e4d9-1996-4d7c-912f-3b0310fe2fd1] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=83c9e4d9-1996-4d7c-912f-3b0310fe2fd1)
2026/07/18 02:23:21 DEBUG : Looking for writers
2026/07/18 02:23:21 DEBUG : file1: reading active writers
2026/07/18 02:23:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:22 DEBUG : file1: vfs cache: starting upload
2026/07/18 02:23: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 02:23:22 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[f3ff074d-6ef0-4247-90a5-8829c9807332] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=f3ff074d-6ef0-4247-90a5-8829c9807332)
2026/07/18 02:23:22 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 02:23:22 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[f3ff074d-6ef0-4247-90a5-8829c9807332] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=f3ff074d-6ef0-4247-90a5-8829c9807332)
2026/07/18 02:23:22 DEBUG : Looking for writers
2026/07/18 02:23:22 DEBUG : file1: reading active writers
2026/07/18 02:23:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:23 DEBUG : Looking for writers
2026/07/18 02:23:23 DEBUG : file1: reading active writers
2026/07/18 02:23:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:24 DEBUG : file1: vfs cache: starting upload
2026/07/18 02:23:24 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 02:23:24 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[ca97eb4a-4201-4279-ab8a-33a0d14eded7] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=ca97eb4a-4201-4279-ab8a-33a0d14eded7)
2026/07/18 02:23:24 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 02:23:24 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[ca97eb4a-4201-4279-ab8a-33a0d14eded7] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=ca97eb4a-4201-4279-ab8a-33a0d14eded7)
2026/07/18 02:23:24 DEBUG : Looking for writers
2026/07/18 02:23:24 DEBUG : file1: reading active writers
2026/07/18 02:23:24 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:25 DEBUG : Looking for writers
2026/07/18 02:23:25 DEBUG : file1: reading active writers
2026/07/18 02:23:25 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:26 DEBUG : Looking for writers
2026/07/18 02:23:26 DEBUG : file1: reading active writers
2026/07/18 02:23:26 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:27 DEBUG : file1: vfs cache: starting upload
2026/07/18 02:23:27 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 02:23:27 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[8a7ce4d3-b6c3-4aa1-8e58-4022b4b58af3] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=8a7ce4d3-b6c3-4aa1-8e58-4022b4b58af3)
2026/07/18 02:23:27 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 02:23:27 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[8a7ce4d3-b6c3-4aa1-8e58-4022b4b58af3] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=8a7ce4d3-b6c3-4aa1-8e58-4022b4b58af3)
2026/07/18 02:23:27 DEBUG : Looking for writers
2026/07/18 02:23:27 DEBUG : file1: reading active writers
2026/07/18 02:23:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:28 DEBUG : Looking for writers
2026/07/18 02:23:28 DEBUG : file1: reading active writers
2026/07/18 02:23:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:29 DEBUG : Looking for writers
2026/07/18 02:23:29 DEBUG : file1: reading active writers
2026/07/18 02:23:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:30 DEBUG : Looking for writers
2026/07/18 02:23:30 DEBUG : file1: reading active writers
2026/07/18 02:23:30 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:31 DEBUG : Looking for writers
2026/07/18 02:23:31 DEBUG : file1: reading active writers
2026/07/18 02:23:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:32 DEBUG : Looking for writers
2026/07/18 02:23:32 DEBUG : file1: reading active writers
2026/07/18 02:23:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:33 DEBUG : Looking for writers
2026/07/18 02:23:33 DEBUG : file1: reading active writers
2026/07/18 02:23:33 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:33 DEBUG : file1: vfs cache: starting upload
2026/07/18 02:23:34 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 02:23:33 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[21e54dc7-0c6e-4f67-81f0-87c5e81c6e7e] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=21e54dc7-0c6e-4f67-81f0-87c5e81c6e7e)
2026/07/18 02:23:34 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 02:23:33 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[21e54dc7-0c6e-4f67-81f0-87c5e81c6e7e] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=21e54dc7-0c6e-4f67-81f0-87c5e81c6e7e)
2026/07/18 02:23:34 DEBUG : Looking for writers
2026/07/18 02:23:34 DEBUG : file1: reading active writers
2026/07/18 02:23:34 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:35 DEBUG : Looking for writers
2026/07/18 02:23:35 DEBUG : file1: reading active writers
2026/07/18 02:23:35 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:36 DEBUG : Looking for writers
2026/07/18 02:23:36 DEBUG : file1: reading active writers
2026/07/18 02:23:36 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:37 DEBUG : Looking for writers
2026/07/18 02:23:37 DEBUG : file1: reading active writers
2026/07/18 02:23:37 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:38 DEBUG : Looking for writers
2026/07/18 02:23:38 DEBUG : file1: reading active writers
2026/07/18 02:23:38 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:39 DEBUG : Looking for writers
2026/07/18 02:23:39 DEBUG : file1: reading active writers
2026/07/18 02:23:39 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:40 DEBUG : Looking for writers
2026/07/18 02:23:40 DEBUG : file1: reading active writers
2026/07/18 02:23:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:41 DEBUG : Looking for writers
2026/07/18 02:23:41 DEBUG : file1: reading active writers
2026/07/18 02:23:41 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:42 DEBUG : Looking for writers
2026/07/18 02:23:42 DEBUG : file1: reading active writers
2026/07/18 02:23:42 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:43 DEBUG : Looking for writers
2026/07/18 02:23:43 DEBUG : file1: reading active writers
2026/07/18 02:23:43 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:44 DEBUG : Looking for writers
2026/07/18 02:23:44 DEBUG : file1: reading active writers
2026/07/18 02:23:44 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:45 DEBUG : Looking for writers
2026/07/18 02:23:45 DEBUG : file1: reading active writers
2026/07/18 02:23:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:46 DEBUG : Looking for writers
2026/07/18 02:23:46 DEBUG : file1: reading active writers
2026/07/18 02:23:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:46 DEBUG : file1: vfs cache: starting upload
2026/07/18 02:23:46 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 02:23:46 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[c393e50b-0420-451c-9b21-38e202eaf836] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=c393e50b-0420-451c-9b21-38e202eaf836)
2026/07/18 02:23:46 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 02:23:46 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[c393e50b-0420-451c-9b21-38e202eaf836] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=c393e50b-0420-451c-9b21-38e202eaf836)
2026/07/18 02:23:47 DEBUG : Looking for writers
2026/07/18 02:23:47 DEBUG : file1: reading active writers
2026/07/18 02:23:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:48 DEBUG : Looking for writers
2026/07/18 02:23:48 DEBUG : file1: reading active writers
2026/07/18 02:23:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:49 DEBUG : Looking for writers
2026/07/18 02:23:49 DEBUG : file1: reading active writers
2026/07/18 02:23:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:50 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s
Cache{
	"file1": &{c:0x351def7f6900 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0x351defbdf7a8 notify:{wait:0 notify:0 lock:0 head:<nil> tail:<nil>} checker:58402692528096} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> info:{ModTime:{wall:14019378836398997700 ext:338954712244 loc:0x47a3720} ATime:{wall:14019378836399017648 ext:338954732182 loc:0x47a3720} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false graceTimer:<nil> closing:<nil>},
}
2026/07/18 02:23:50 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:23:57 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:23:57 DEBUG : Looking for writers
2026/07/18 02:23:57 DEBUG : file1: reading active writers
2026/07/18 02:23:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms
2026/07/18 02:23:57 DEBUG : Looking for writers
2026/07/18 02:23:57 DEBUG : file1: reading active writers
2026/07/18 02:23:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms
2026/07/18 02:23:57 DEBUG : Looking for writers
2026/07/18 02:23:57 DEBUG : file1: reading active writers
2026/07/18 02:23:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms
2026/07/18 02:23:57 DEBUG : Looking for writers
2026/07/18 02:23:57 DEBUG : file1: reading active writers
2026/07/18 02:23:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms
2026/07/18 02:23:57 DEBUG : Looking for writers
2026/07/18 02:23:57 DEBUG : file1: reading active writers
2026/07/18 02:23:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms
2026/07/18 02:23:57 DEBUG : Looking for writers
2026/07/18 02:23:57 DEBUG : file1: reading active writers
2026/07/18 02:23:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms
2026/07/18 02:23:58 DEBUG : Looking for writers
2026/07/18 02:23:58 DEBUG : file1: reading active writers
2026/07/18 02:23:58 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms
2026/07/18 02:23:58 DEBUG : Looking for writers
2026/07/18 02:23:58 DEBUG : file1: reading active writers
2026/07/18 02:23:58 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:23:59 DEBUG : Looking for writers
2026/07/18 02:23:59 DEBUG : file1: reading active writers
2026/07/18 02:23:59 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:00 DEBUG : Looking for writers
2026/07/18 02:24:00 DEBUG : file1: reading active writers
2026/07/18 02:24:00 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:01 DEBUG : Looking for writers
2026/07/18 02:24:01 DEBUG : file1: reading active writers
2026/07/18 02:24:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:02 DEBUG : Looking for writers
2026/07/18 02:24:02 DEBUG : file1: reading active writers
2026/07/18 02:24:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:03 DEBUG : Looking for writers
2026/07/18 02:24:03 DEBUG : file1: reading active writers
2026/07/18 02:24:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:04 DEBUG : Looking for writers
2026/07/18 02:24:04 DEBUG : file1: reading active writers
2026/07/18 02:24:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:05 DEBUG : Looking for writers
2026/07/18 02:24:05 DEBUG : file1: reading active writers
2026/07/18 02:24:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:06 DEBUG : Looking for writers
2026/07/18 02:24:06 DEBUG : file1: reading active writers
2026/07/18 02:24:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:07 DEBUG : Looking for writers
2026/07/18 02:24:07 DEBUG : file1: reading active writers
2026/07/18 02:24:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:08 DEBUG : Looking for writers
2026/07/18 02:24:08 DEBUG : file1: reading active writers
2026/07/18 02:24:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:09 DEBUG : Looking for writers
2026/07/18 02:24:09 DEBUG : file1: reading active writers
2026/07/18 02:24:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:10 DEBUG : Looking for writers
2026/07/18 02:24:10 DEBUG : file1: reading active writers
2026/07/18 02:24:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:11 DEBUG : Looking for writers
2026/07/18 02:24:11 DEBUG : file1: reading active writers
2026/07/18 02:24:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:12 DEBUG : file1: vfs cache: starting upload
2026/07/18 02:24:12 DEBUG : Looking for writers
2026/07/18 02:24:12 DEBUG : file1: reading active writers
2026/07/18 02:24:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:13 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 02:24:12 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[fabe6d4a-4368-4ce4-960a-89dcdc8b2c54] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=fabe6d4a-4368-4ce4-960a-89dcdc8b2c54)
2026/07/18 02:24:13 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 02:24:12 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[fabe6d4a-4368-4ce4-960a-89dcdc8b2c54] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=fabe6d4a-4368-4ce4-960a-89dcdc8b2c54)
2026/07/18 02:24:13 DEBUG : Looking for writers
2026/07/18 02:24:13 DEBUG : file1: reading active writers
2026/07/18 02:24:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:14 DEBUG : Looking for writers
2026/07/18 02:24:14 DEBUG : file1: reading active writers
2026/07/18 02:24:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:15 DEBUG : Looking for writers
2026/07/18 02:24:15 DEBUG : file1: reading active writers
2026/07/18 02:24:15 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:16 DEBUG : Looking for writers
2026/07/18 02:24:16 DEBUG : file1: reading active writers
2026/07/18 02:24:16 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:17 DEBUG : Looking for writers
2026/07/18 02:24:17 DEBUG : file1: reading active writers
2026/07/18 02:24:17 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:18 DEBUG : Looking for writers
2026/07/18 02:24:18 DEBUG : file1: reading active writers
2026/07/18 02:24:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:19 DEBUG : Looking for writers
2026/07/18 02:24:19 DEBUG : file1: reading active writers
2026/07/18 02:24:19 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:20 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes
2026/07/18 02:24:20 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaned: objects 1 (was 1) in use 1, to upload 1, uploading 0, total size 11 (was 11)
2026/07/18 02:24:20 DEBUG : Looking for writers
2026/07/18 02:24:20 DEBUG : file1: reading active writers
2026/07/18 02:24:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:21 DEBUG : Looking for writers
2026/07/18 02:24:21 DEBUG : file1: reading active writers
2026/07/18 02:24:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:22 DEBUG : Looking for writers
2026/07/18 02:24:22 DEBUG : file1: reading active writers
2026/07/18 02:24:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:23 DEBUG : Looking for writers
2026/07/18 02:24:23 DEBUG : file1: reading active writers
2026/07/18 02:24:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:24 DEBUG : Looking for writers
2026/07/18 02:24:24 DEBUG : file1: reading active writers
2026/07/18 02:24:24 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:25 DEBUG : Looking for writers
2026/07/18 02:24:25 DEBUG : file1: reading active writers
2026/07/18 02:24:25 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:26 DEBUG : Looking for writers
2026/07/18 02:24:26 DEBUG : file1: reading active writers
2026/07/18 02:24:26 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:27 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s
Cache{
	"file1": &{c:0x351def7f6900 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0x351defbdf7a8 notify:{wait:0 notify:0 lock:0 head:<nil> tail:<nil>} checker:58402692528096} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> info:{ModTime:{wall:14019378836398997700 ext:338954712244 loc:0x47a3720} ATime:{wall:14019378836399017648 ext:338954732182 loc:0x47a3720} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false graceTimer:<nil> closing:<nil>},
}
2026/07/18 02:24:27 DEBUG : >WaitForWriters: 
2026/07/18 02:24:27 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaner exiting
--- FAIL: TestRWFileHandleMethodsWrite (67.29s)
=== RUN   TestRWFileHandleWriteAt
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:24:27 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:24:27 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: root is "/home/rclone/.cache/rclone"
2026/07/18 02:24:27 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:24:27 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:24:27 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:24:27 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:24:27 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:24:27 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:24:27 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:24:27 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:24:27 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2026/07/18 02:24:27 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2026/07/18 02:24:27 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2026/07/18 02:24:27 DEBUG : file1: newRWFileHandle: 
2026/07/18 02:24:27 DEBUG : file1(0x351def52cac0): openPending: 
2026/07/18 02:24:27 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct)
2026/07/18 02:24:27 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:24:27 DEBUG : file1(0x351def52cac0): >openPending: err=<nil>
2026/07/18 02:24:27 DEBUG : file1: >newRWFileHandle: err=<nil>
2026/07/18 02:24:27 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:24:27 DEBUG : file1: >Open: fd=file1 (rw), err=<nil>
2026/07/18 02:24:27 DEBUG : file1: >OpenFile: fd=file1 (rw), err=<nil>
2026/07/18 02:24:27 DEBUG : file1(0x351def52cac0): _writeAt: size=7, off=0
2026/07/18 02:24:27 DEBUG : file1(0x351def52cac0): >_writeAt: n=7, err=<nil>
2026/07/18 02:24:27 DEBUG : file1(0x351def52cac0): _writeAt: size=6, off=5
2026/07/18 02:24:27 DEBUG : file1(0x351def52cac0): >_writeAt: n=6, err=<nil>
2026/07/18 02:24:27 DEBUG : file1(0x351def52cac0): close: 
2026/07/18 02:24:27 DEBUG : file1: vfs cache: setting modification time to 2026-07-18 02:24:27.741061701 +0000 UTC m=+406.239577643
2026/07/18 02:24:27 INFO  : file1: vfs cache: queuing for upload in 100ms
2026/07/18 02:24:27 DEBUG : file1(0x351def52cac0): >close: err=<nil>
2026/07/18 02:24:27 DEBUG : file1(0x351def52cac0): _writeAt: size=5, off=0
2026/07/18 02:24:27 DEBUG : file1(0x351def52cac0): >_writeAt: n=0, err=file already closed
2026/07/18 02:24:27 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:24:27 DEBUG : Looking for writers
2026/07/18 02:24:27 DEBUG : file1: reading active writers
2026/07/18 02:24:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms
2026/07/18 02:24:27 DEBUG : Looking for writers
2026/07/18 02:24:27 DEBUG : file1: reading active writers
2026/07/18 02:24:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms
2026/07/18 02:24:27 DEBUG : Looking for writers
2026/07/18 02:24:27 DEBUG : file1: reading active writers
2026/07/18 02:24:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms
2026/07/18 02:24:27 DEBUG : Looking for writers
2026/07/18 02:24:27 DEBUG : file1: reading active writers
2026/07/18 02:24:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms
2026/07/18 02:24:27 DEBUG : file1: vfs cache: starting upload
2026/07/18 02:24:27 DEBUG : Looking for writers
2026/07/18 02:24:27 DEBUG : file1: reading active writers
2026/07/18 02:24:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms
2026/07/18 02:24:27 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 02:24:27 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[c53f0139-f167-4cfd-b1d3-1d793e840210] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=c53f0139-f167-4cfd-b1d3-1d793e840210)
2026/07/18 02:24:27 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 02:24:27 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[c53f0139-f167-4cfd-b1d3-1d793e840210] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=c53f0139-f167-4cfd-b1d3-1d793e840210)
2026/07/18 02:24:28 DEBUG : Looking for writers
2026/07/18 02:24:28 DEBUG : file1: reading active writers
2026/07/18 02:24:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms
2026/07/18 02:24:28 DEBUG : file1: vfs cache: starting upload
2026/07/18 02:24:28 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 02:24:28 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[76c082a3-fdc9-4406-bf3b-4f069d6c25c2] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=76c082a3-fdc9-4406-bf3b-4f069d6c25c2)
2026/07/18 02:24:28 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 02:24:28 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[76c082a3-fdc9-4406-bf3b-4f069d6c25c2] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=76c082a3-fdc9-4406-bf3b-4f069d6c25c2)
2026/07/18 02:24:28 DEBUG : Looking for writers
2026/07/18 02:24:28 DEBUG : file1: reading active writers
2026/07/18 02:24:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms
2026/07/18 02:24:28 DEBUG : file1: vfs cache: starting upload
2026/07/18 02:24:28 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 02:24:28 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[bb88fbd7-f1b9-4102-82d0-8335112854a6] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=bb88fbd7-f1b9-4102-82d0-8335112854a6)
2026/07/18 02:24:28 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 02:24:28 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[bb88fbd7-f1b9-4102-82d0-8335112854a6] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=bb88fbd7-f1b9-4102-82d0-8335112854a6)
2026/07/18 02:24:29 DEBUG : Looking for writers
2026/07/18 02:24:29 DEBUG : file1: reading active writers
2026/07/18 02:24:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:29 DEBUG : file1: vfs cache: starting upload
2026/07/18 02:24: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 02:24:29 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[4a5f1380-bb95-4397-ad04-0a316748b64f] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=4a5f1380-bb95-4397-ad04-0a316748b64f)
2026/07/18 02:24:29 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 02:24:29 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[4a5f1380-bb95-4397-ad04-0a316748b64f] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=4a5f1380-bb95-4397-ad04-0a316748b64f)
2026/07/18 02:24:30 DEBUG : Looking for writers
2026/07/18 02:24:30 DEBUG : file1: reading active writers
2026/07/18 02:24:30 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:31 DEBUG : Looking for writers
2026/07/18 02:24:31 DEBUG : file1: reading active writers
2026/07/18 02:24:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:31 DEBUG : file1: vfs cache: starting upload
2026/07/18 02:24:31 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 02:24:31 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[092e4a9a-9845-44af-8eca-c9defea6e34f] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=092e4a9a-9845-44af-8eca-c9defea6e34f)
2026/07/18 02:24:31 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 02:24:31 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[092e4a9a-9845-44af-8eca-c9defea6e34f] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=092e4a9a-9845-44af-8eca-c9defea6e34f)
2026/07/18 02:24:32 DEBUG : Looking for writers
2026/07/18 02:24:32 DEBUG : file1: reading active writers
2026/07/18 02:24:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:33 DEBUG : Looking for writers
2026/07/18 02:24:33 DEBUG : file1: reading active writers
2026/07/18 02:24:33 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:34 DEBUG : Looking for writers
2026/07/18 02:24:34 DEBUG : file1: reading active writers
2026/07/18 02:24:34 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:34 DEBUG : file1: vfs cache: starting upload
2026/07/18 02:24:34 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 02:24:34 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[1de60d77-550d-4227-a0dd-7f604c8599f0] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=1de60d77-550d-4227-a0dd-7f604c8599f0)
2026/07/18 02:24:34 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 02:24:34 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[1de60d77-550d-4227-a0dd-7f604c8599f0] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=1de60d77-550d-4227-a0dd-7f604c8599f0)
2026/07/18 02:24:35 DEBUG : Looking for writers
2026/07/18 02:24:35 DEBUG : file1: reading active writers
2026/07/18 02:24:35 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:36 DEBUG : Looking for writers
2026/07/18 02:24:36 DEBUG : file1: reading active writers
2026/07/18 02:24:36 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:37 DEBUG : Looking for writers
2026/07/18 02:24:37 DEBUG : file1: reading active writers
2026/07/18 02:24:37 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:38 DEBUG : Looking for writers
2026/07/18 02:24:38 DEBUG : file1: reading active writers
2026/07/18 02:24:38 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:39 DEBUG : Looking for writers
2026/07/18 02:24:39 DEBUG : file1: reading active writers
2026/07/18 02:24:39 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:40 DEBUG : Looking for writers
2026/07/18 02:24:40 DEBUG : file1: reading active writers
2026/07/18 02:24:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:41 DEBUG : Looking for writers
2026/07/18 02:24:41 DEBUG : file1: reading active writers
2026/07/18 02:24:41 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:41 DEBUG : file1: vfs cache: starting upload
2026/07/18 02:24:41 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 02:24:41 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[e8b62bda-4a08-43f1-bf57-d10dd5d1ad52] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=e8b62bda-4a08-43f1-bf57-d10dd5d1ad52)
2026/07/18 02:24:41 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 02:24:41 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[e8b62bda-4a08-43f1-bf57-d10dd5d1ad52] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=e8b62bda-4a08-43f1-bf57-d10dd5d1ad52)
2026/07/18 02:24:42 DEBUG : Looking for writers
2026/07/18 02:24:42 DEBUG : file1: reading active writers
2026/07/18 02:24:42 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:43 DEBUG : Looking for writers
2026/07/18 02:24:43 DEBUG : file1: reading active writers
2026/07/18 02:24:43 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:44 DEBUG : Looking for writers
2026/07/18 02:24:44 DEBUG : file1: reading active writers
2026/07/18 02:24:44 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:45 DEBUG : Looking for writers
2026/07/18 02:24:45 DEBUG : file1: reading active writers
2026/07/18 02:24:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:46 DEBUG : Looking for writers
2026/07/18 02:24:46 DEBUG : file1: reading active writers
2026/07/18 02:24:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:47 DEBUG : Looking for writers
2026/07/18 02:24:47 DEBUG : file1: reading active writers
2026/07/18 02:24:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:48 DEBUG : Looking for writers
2026/07/18 02:24:48 DEBUG : file1: reading active writers
2026/07/18 02:24:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:49 DEBUG : Looking for writers
2026/07/18 02:24:49 DEBUG : file1: reading active writers
2026/07/18 02:24:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:50 DEBUG : Looking for writers
2026/07/18 02:24:50 DEBUG : file1: reading active writers
2026/07/18 02:24:50 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:51 DEBUG : Looking for writers
2026/07/18 02:24:51 DEBUG : file1: reading active writers
2026/07/18 02:24:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:52 DEBUG : Looking for writers
2026/07/18 02:24:52 DEBUG : file1: reading active writers
2026/07/18 02:24:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:53 DEBUG : Looking for writers
2026/07/18 02:24:53 DEBUG : file1: reading active writers
2026/07/18 02:24:53 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:54 DEBUG : Looking for writers
2026/07/18 02:24:54 DEBUG : file1: reading active writers
2026/07/18 02:24:54 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:54 DEBUG : file1: vfs cache: starting upload
2026/07/18 02:24:54 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 02:24:54 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[102f9345-d952-42b6-ab50-3b124d032b10] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=102f9345-d952-42b6-ab50-3b124d032b10)
2026/07/18 02:24:54 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 02:24:54 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[102f9345-d952-42b6-ab50-3b124d032b10] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=102f9345-d952-42b6-ab50-3b124d032b10)
2026/07/18 02:24:55 DEBUG : Looking for writers
2026/07/18 02:24:55 DEBUG : file1: reading active writers
2026/07/18 02:24:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:56 DEBUG : Looking for writers
2026/07/18 02:24:56 DEBUG : file1: reading active writers
2026/07/18 02:24:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:57 DEBUG : Looking for writers
2026/07/18 02:24:57 DEBUG : file1: reading active writers
2026/07/18 02:24:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:24:57 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s
Cache{
	"file1": &{c:0x351deffc4400 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0x351defbdfb08 notify:{wait:0 notify:0 lock:0 head:<nil> tail:<nil>} checker:58402692528960} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> info:{ModTime:{wall:14019378908624565317 ext:406239577643 loc:0x47a3720} ATime:{wall:14019378908624623056 ext:406239635383 loc:0x47a3720} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false graceTimer:<nil> closing:<nil>},
}
2026/07/18 02:24:57 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:25:04 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:25:04 DEBUG : Looking for writers
2026/07/18 02:25:04 DEBUG : file1: reading active writers
2026/07/18 02:25:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms
2026/07/18 02:25:04 DEBUG : Looking for writers
2026/07/18 02:25:04 DEBUG : file1: reading active writers
2026/07/18 02:25:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms
2026/07/18 02:25:04 DEBUG : Looking for writers
2026/07/18 02:25:04 DEBUG : file1: reading active writers
2026/07/18 02:25:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms
2026/07/18 02:25:04 DEBUG : Looking for writers
2026/07/18 02:25:04 DEBUG : file1: reading active writers
2026/07/18 02:25:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms
2026/07/18 02:25:05 DEBUG : Looking for writers
2026/07/18 02:25:05 DEBUG : file1: reading active writers
2026/07/18 02:25:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms
2026/07/18 02:25:05 DEBUG : Looking for writers
2026/07/18 02:25:05 DEBUG : file1: reading active writers
2026/07/18 02:25:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms
2026/07/18 02:25:05 DEBUG : Looking for writers
2026/07/18 02:25:05 DEBUG : file1: reading active writers
2026/07/18 02:25:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms
2026/07/18 02:25:06 DEBUG : Looking for writers
2026/07/18 02:25:06 DEBUG : file1: reading active writers
2026/07/18 02:25:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:07 DEBUG : Looking for writers
2026/07/18 02:25:07 DEBUG : file1: reading active writers
2026/07/18 02:25:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:08 DEBUG : Looking for writers
2026/07/18 02:25:08 DEBUG : file1: reading active writers
2026/07/18 02:25:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:09 DEBUG : Looking for writers
2026/07/18 02:25:09 DEBUG : file1: reading active writers
2026/07/18 02:25:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:10 DEBUG : Looking for writers
2026/07/18 02:25:10 DEBUG : file1: reading active writers
2026/07/18 02:25:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:11 DEBUG : Looking for writers
2026/07/18 02:25:11 DEBUG : file1: reading active writers
2026/07/18 02:25:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:12 DEBUG : Looking for writers
2026/07/18 02:25:12 DEBUG : file1: reading active writers
2026/07/18 02:25:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:13 DEBUG : Looking for writers
2026/07/18 02:25:13 DEBUG : file1: reading active writers
2026/07/18 02:25:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:14 DEBUG : Looking for writers
2026/07/18 02:25:14 DEBUG : file1: reading active writers
2026/07/18 02:25:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:15 DEBUG : Looking for writers
2026/07/18 02:25:15 DEBUG : file1: reading active writers
2026/07/18 02:25:15 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:16 DEBUG : Looking for writers
2026/07/18 02:25:16 DEBUG : file1: reading active writers
2026/07/18 02:25:16 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:17 DEBUG : Looking for writers
2026/07/18 02:25:17 DEBUG : file1: reading active writers
2026/07/18 02:25:17 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:18 DEBUG : Looking for writers
2026/07/18 02:25:18 DEBUG : file1: reading active writers
2026/07/18 02:25:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:19 DEBUG : Looking for writers
2026/07/18 02:25:19 DEBUG : file1: reading active writers
2026/07/18 02:25:19 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:19 DEBUG : file1: vfs cache: starting upload
2026/07/18 02:25:19 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 02:25:19 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[0d2d4e4f-635f-40ea-bc89-3ca8d75cb18b] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=0d2d4e4f-635f-40ea-bc89-3ca8d75cb18b)
2026/07/18 02:25:19 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 02:25:19 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[0d2d4e4f-635f-40ea-bc89-3ca8d75cb18b] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=0d2d4e4f-635f-40ea-bc89-3ca8d75cb18b)
2026/07/18 02:25:20 DEBUG : Looking for writers
2026/07/18 02:25:20 DEBUG : file1: reading active writers
2026/07/18 02:25:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:21 DEBUG : Looking for writers
2026/07/18 02:25:21 DEBUG : file1: reading active writers
2026/07/18 02:25:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:22 DEBUG : Looking for writers
2026/07/18 02:25:22 DEBUG : file1: reading active writers
2026/07/18 02:25:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:23 DEBUG : Looking for writers
2026/07/18 02:25:23 DEBUG : file1: reading active writers
2026/07/18 02:25:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:24 DEBUG : Looking for writers
2026/07/18 02:25:24 DEBUG : file1: reading active writers
2026/07/18 02:25:24 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:25 DEBUG : Looking for writers
2026/07/18 02:25:25 DEBUG : file1: reading active writers
2026/07/18 02:25:25 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:26 DEBUG : Looking for writers
2026/07/18 02:25:26 DEBUG : file1: reading active writers
2026/07/18 02:25:26 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:27 DEBUG : Looking for writers
2026/07/18 02:25:27 DEBUG : file1: reading active writers
2026/07/18 02:25:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:27 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes
2026/07/18 02:25:27 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaned: objects 1 (was 1) in use 1, to upload 1, uploading 0, total size 11 (was 11)
2026/07/18 02:25:28 DEBUG : Looking for writers
2026/07/18 02:25:28 DEBUG : file1: reading active writers
2026/07/18 02:25:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:29 DEBUG : Looking for writers
2026/07/18 02:25:29 DEBUG : file1: reading active writers
2026/07/18 02:25:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:30 DEBUG : Looking for writers
2026/07/18 02:25:30 DEBUG : file1: reading active writers
2026/07/18 02:25:30 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:31 DEBUG : Looking for writers
2026/07/18 02:25:31 DEBUG : file1: reading active writers
2026/07/18 02:25:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:32 DEBUG : Looking for writers
2026/07/18 02:25:32 DEBUG : file1: reading active writers
2026/07/18 02:25:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:33 DEBUG : Looking for writers
2026/07/18 02:25:33 DEBUG : file1: reading active writers
2026/07/18 02:25:33 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:34 DEBUG : Looking for writers
2026/07/18 02:25:34 DEBUG : file1: reading active writers
2026/07/18 02:25:34 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:34 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s
Cache{
	"file1": &{c:0x351deffc4400 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0x351defbdfb08 notify:{wait:0 notify:0 lock:0 head:<nil> tail:<nil>} checker:58402692528960} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> info:{ModTime:{wall:14019378908624565317 ext:406239577643 loc:0x47a3720} ATime:{wall:14019378908624623056 ext:406239635383 loc:0x47a3720} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false graceTimer:<nil> closing:<nil>},
}
2026/07/18 02:25:34 DEBUG : >WaitForWriters: 
2026/07/18 02:25:34 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaner exiting
--- FAIL: TestRWFileHandleWriteAt (67.30s)
=== RUN   TestRWFileHandleSizeTruncateExisting
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:25:34 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:25:34 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: root is "/home/rclone/.cache/rclone"
2026/07/18 02:25:34 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:25:34 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:25:34 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:25:34 DEBUG : Config file has changed externally - reloading
2026/07/18 02:25:34 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:25:34 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:25:34 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:25:34 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:25:34 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:25:34 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:25:35 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[ce96e274-e407-43f1-900b-3ac06dfdbb0c] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=ce96e274-e407-43f1-900b-3ac06dfdbb0c)
2026/07/18 02:25:35 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:25:35 DEBUG : Looking for writers
2026/07/18 02:25:35 DEBUG : >WaitForWriters: 
2026/07/18 02:25:35 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaner exiting
--- FAIL: TestRWFileHandleSizeTruncateExisting (0.65s)
=== RUN   TestRWFileHandleSizeCreateExisting
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:25:35 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:25:35 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: root is "/home/rclone/.cache/rclone"
2026/07/18 02:25:35 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:25:35 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:25:35 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:25:35 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:25:35 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:25:35 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:25:35 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:25:35 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:25:35 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:25:35 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[96eecb8f-926c-490b-ad9f-408f52bfc29b] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=96eecb8f-926c-490b-ad9f-408f52bfc29b)
2026/07/18 02:25:35 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:25:35 DEBUG : Looking for writers
2026/07/18 02:25:35 DEBUG : >WaitForWriters: 
2026/07/18 02:25:35 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaner exiting
--- FAIL: TestRWFileHandleSizeCreateExisting (0.63s)
=== RUN   TestRWFileModTimeWithOpenWriters
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:25:36 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:25:36 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: root is "/home/rclone/.cache/rclone"
2026/07/18 02:25:36 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:25:36 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:25:36 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:25:36 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:25:36 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:25:36 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:25:36 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:25:36 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:25:36 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2026/07/18 02:25:36 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2026/07/18 02:25:36 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2026/07/18 02:25:36 DEBUG : file1: newRWFileHandle: 
2026/07/18 02:25:36 DEBUG : file1(0x351def1a3d80): openPending: 
2026/07/18 02:25:36 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct)
2026/07/18 02:25:36 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:25:36 DEBUG : file1(0x351def1a3d80): >openPending: err=<nil>
2026/07/18 02:25:36 DEBUG : file1: >newRWFileHandle: err=<nil>
2026/07/18 02:25:36 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:25:36 DEBUG : file1: >Open: fd=file1 (rw), err=<nil>
2026/07/18 02:25:36 DEBUG : file1: >OpenFile: fd=file1 (rw), err=<nil>
    run.go:303: Failed to put "time_test" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo": 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 02:25:36 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[b1a9d241-9868-4ccc-b106-cbdd03fa1e03] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=b1a9d241-9868-4ccc-b106-cbdd03fa1e03)
2026/07/18 02:25:36 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:25:36 DEBUG : Looking for writers
2026/07/18 02:25:36 DEBUG : file1: reading active writers
2026/07/18 02:25:36 DEBUG : file1: active writers 1
2026/07/18 02:25:36 DEBUG : Still 1 writers active and 1 cache items in use, waiting 10ms
2026/07/18 02:25:36 DEBUG : Looking for writers
2026/07/18 02:25:36 DEBUG : file1: reading active writers
2026/07/18 02:25:36 DEBUG : file1: active writers 1
2026/07/18 02:25:36 DEBUG : Still 1 writers active and 1 cache items in use, waiting 20ms
2026/07/18 02:25:36 DEBUG : Looking for writers
2026/07/18 02:25:36 DEBUG : file1: reading active writers
2026/07/18 02:25:36 DEBUG : file1: active writers 1
2026/07/18 02:25:36 DEBUG : Still 1 writers active and 1 cache items in use, waiting 40ms
2026/07/18 02:25:36 DEBUG : Looking for writers
2026/07/18 02:25:36 DEBUG : file1: reading active writers
2026/07/18 02:25:36 DEBUG : file1: active writers 1
2026/07/18 02:25:36 DEBUG : Still 1 writers active and 1 cache items in use, waiting 80ms
2026/07/18 02:25:36 DEBUG : Looking for writers
2026/07/18 02:25:36 DEBUG : file1: reading active writers
2026/07/18 02:25:36 DEBUG : file1: active writers 1
2026/07/18 02:25:36 DEBUG : Still 1 writers active and 1 cache items in use, waiting 160ms
2026/07/18 02:25:36 DEBUG : Looking for writers
2026/07/18 02:25:36 DEBUG : file1: reading active writers
2026/07/18 02:25:36 DEBUG : file1: active writers 1
2026/07/18 02:25:36 DEBUG : Still 1 writers active and 1 cache items in use, waiting 320ms
2026/07/18 02:25:37 DEBUG : Looking for writers
2026/07/18 02:25:37 DEBUG : file1: reading active writers
2026/07/18 02:25:37 DEBUG : file1: active writers 1
2026/07/18 02:25:37 DEBUG : Still 1 writers active and 1 cache items in use, waiting 640ms
2026/07/18 02:25:37 DEBUG : Looking for writers
2026/07/18 02:25:37 DEBUG : file1: reading active writers
2026/07/18 02:25:37 DEBUG : file1: active writers 1
2026/07/18 02:25:37 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:38 DEBUG : Looking for writers
2026/07/18 02:25:38 DEBUG : file1: reading active writers
2026/07/18 02:25:38 DEBUG : file1: active writers 1
2026/07/18 02:25:38 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:39 DEBUG : Looking for writers
2026/07/18 02:25:39 DEBUG : file1: reading active writers
2026/07/18 02:25:39 DEBUG : file1: active writers 1
2026/07/18 02:25:39 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:40 DEBUG : Looking for writers
2026/07/18 02:25:40 DEBUG : file1: reading active writers
2026/07/18 02:25:40 DEBUG : file1: active writers 1
2026/07/18 02:25:40 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:41 DEBUG : Looking for writers
2026/07/18 02:25:41 DEBUG : file1: reading active writers
2026/07/18 02:25:41 DEBUG : file1: active writers 1
2026/07/18 02:25:41 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:42 DEBUG : Looking for writers
2026/07/18 02:25:42 DEBUG : file1: reading active writers
2026/07/18 02:25:42 DEBUG : file1: active writers 1
2026/07/18 02:25:42 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:43 DEBUG : Looking for writers
2026/07/18 02:25:43 DEBUG : file1: reading active writers
2026/07/18 02:25:43 DEBUG : file1: active writers 1
2026/07/18 02:25:43 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:44 DEBUG : Looking for writers
2026/07/18 02:25:44 DEBUG : file1: reading active writers
2026/07/18 02:25:44 DEBUG : file1: active writers 1
2026/07/18 02:25:44 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:45 DEBUG : Looking for writers
2026/07/18 02:25:45 DEBUG : file1: reading active writers
2026/07/18 02:25:45 DEBUG : file1: active writers 1
2026/07/18 02:25:45 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:46 DEBUG : Looking for writers
2026/07/18 02:25:46 DEBUG : file1: reading active writers
2026/07/18 02:25:46 DEBUG : file1: active writers 1
2026/07/18 02:25:46 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:47 DEBUG : Looking for writers
2026/07/18 02:25:47 DEBUG : file1: reading active writers
2026/07/18 02:25:47 DEBUG : file1: active writers 1
2026/07/18 02:25:47 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:48 DEBUG : Looking for writers
2026/07/18 02:25:48 DEBUG : file1: reading active writers
2026/07/18 02:25:48 DEBUG : file1: active writers 1
2026/07/18 02:25:48 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:49 DEBUG : Looking for writers
2026/07/18 02:25:49 DEBUG : file1: reading active writers
2026/07/18 02:25:49 DEBUG : file1: active writers 1
2026/07/18 02:25:49 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:50 DEBUG : Looking for writers
2026/07/18 02:25:50 DEBUG : file1: reading active writers
2026/07/18 02:25:50 DEBUG : file1: active writers 1
2026/07/18 02:25:50 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:51 DEBUG : Looking for writers
2026/07/18 02:25:51 DEBUG : file1: reading active writers
2026/07/18 02:25:51 DEBUG : file1: active writers 1
2026/07/18 02:25:51 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:52 DEBUG : Looking for writers
2026/07/18 02:25:52 DEBUG : file1: reading active writers
2026/07/18 02:25:52 DEBUG : file1: active writers 1
2026/07/18 02:25:52 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:53 DEBUG : Looking for writers
2026/07/18 02:25:53 DEBUG : file1: reading active writers
2026/07/18 02:25:53 DEBUG : file1: active writers 1
2026/07/18 02:25:53 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:54 DEBUG : Looking for writers
2026/07/18 02:25:54 DEBUG : file1: reading active writers
2026/07/18 02:25:54 DEBUG : file1: active writers 1
2026/07/18 02:25:54 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:55 DEBUG : Looking for writers
2026/07/18 02:25:55 DEBUG : file1: reading active writers
2026/07/18 02:25:55 DEBUG : file1: active writers 1
2026/07/18 02:25:55 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:56 DEBUG : Looking for writers
2026/07/18 02:25:56 DEBUG : file1: reading active writers
2026/07/18 02:25:56 DEBUG : file1: active writers 1
2026/07/18 02:25:56 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:57 DEBUG : Looking for writers
2026/07/18 02:25:57 DEBUG : file1: reading active writers
2026/07/18 02:25:57 DEBUG : file1: active writers 1
2026/07/18 02:25:57 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:58 DEBUG : Looking for writers
2026/07/18 02:25:58 DEBUG : file1: reading active writers
2026/07/18 02:25:58 DEBUG : file1: active writers 1
2026/07/18 02:25:58 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:25:59 DEBUG : Looking for writers
2026/07/18 02:25:59 DEBUG : file1: reading active writers
2026/07/18 02:25:59 DEBUG : file1: active writers 1
2026/07/18 02:25:59 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:26:00 DEBUG : Looking for writers
2026/07/18 02:26:00 DEBUG : file1: reading active writers
2026/07/18 02:26:00 DEBUG : file1: active writers 1
2026/07/18 02:26:00 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:26:01 DEBUG : Looking for writers
2026/07/18 02:26:01 DEBUG : file1: reading active writers
2026/07/18 02:26:01 DEBUG : file1: active writers 1
2026/07/18 02:26:01 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:26:02 DEBUG : Looking for writers
2026/07/18 02:26:02 DEBUG : file1: reading active writers
2026/07/18 02:26:02 DEBUG : file1: active writers 1
2026/07/18 02:26:02 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:26:03 DEBUG : Looking for writers
2026/07/18 02:26:03 DEBUG : file1: reading active writers
2026/07/18 02:26:03 DEBUG : file1: active writers 1
2026/07/18 02:26:03 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:26:04 DEBUG : Looking for writers
2026/07/18 02:26:04 DEBUG : file1: reading active writers
2026/07/18 02:26:04 DEBUG : file1: active writers 1
2026/07/18 02:26:04 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:26:05 DEBUG : Looking for writers
2026/07/18 02:26:05 DEBUG : file1: reading active writers
2026/07/18 02:26:05 DEBUG : file1: active writers 1
2026/07/18 02:26:05 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s
2026/07/18 02:26:06 ERROR : Exiting even though 1 writers active and 1 cache items in use after 30s
Cache{
	"file1": &{c:0x351def7f7c00 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0x351def84e5a8 notify:{wait:0 notify:0 lock:0 head:<nil> tail:<nil>} checker:58402688787936} name:file1 opens:1 downloaders:<nil> o:<nil> fd:0x351def286370 info:{ModTime:{wall:14019378982299522711 ext:474826349180 loc:0x47a3720} ATime:{wall:14019378982299522711 ext:474826349180 loc:0x47a3720} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:0 pendingAccesses:0 modified:true beingReset:false graceTimer:<nil> closing:<nil>},
}
2026/07/18 02:26:06 DEBUG : >WaitForWriters: 
2026/07/18 02:26:06 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaner exiting
--- FAIL: TestRWFileModTimeWithOpenWriters (30.31s)
=== RUN   TestRWCacheUpdate
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:26:06 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:26:06 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: root is "/home/rclone/.cache/rclone"
2026/07/18 02:26:06 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:26:06 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:26:06 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:26:06 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:26:06 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:26:06 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:26:06 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name
2026/07/18 02:26:06 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestKoofr/rclone-test-gujodil9kifo"
2026/07/18 02:26:06 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:26:06 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[5162937b-b84d-4c70-9c36-004582ea5730] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=5162937b-b84d-4c70-9c36-004582ea5730)
2026/07/18 02:26:06 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:26:06 DEBUG : Looking for writers
2026/07/18 02:26:06 DEBUG : >WaitForWriters: 
2026/07/18 02:26:06 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: vfs cache: cleaner exiting
2026/07/18 02:26:06 DEBUG : forgetting directory cache
--- FAIL: TestRWCacheUpdate (0.23s)
=== RUN   TestUnicodeNormalization
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
    run.go:303: Failed to put "normal name with no special characters.txt" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo": 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 02:26:06 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[037e8d93-43e9-42dc-845b-0ed24f9fec01] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=037e8d93-43e9-42dc-845b-0ed24f9fec01)
--- FAIL: TestUnicodeNormalization (0.23s)
=== RUN   TestVFSStat
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:26:07 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
    run.go:303: Failed to put "file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo": 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 02:26:07 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[16b54fd1-b592-49c7-83a0-59a402990796] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=16b54fd1-b592-49c7-83a0-59a402990796)
2026/07/18 02:26:07 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:26:07 DEBUG : Looking for writers
2026/07/18 02:26:07 DEBUG : >WaitForWriters: 
--- FAIL: TestVFSStat (0.28s)
=== RUN   TestVFSStatParent
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:26:07 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
    run.go:303: Failed to put "file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo": 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 02:26:07 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[1d79cb80-b42b-4b2e-9587-49b12932d64f] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=1d79cb80-b42b-4b2e-9587-49b12932d64f)
2026/07/18 02:26:07 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:26:07 DEBUG : Looking for writers
2026/07/18 02:26:07 DEBUG : >WaitForWriters: 
--- FAIL: TestVFSStatParent (0.22s)
=== RUN   TestVFSOpenFile
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:26:07 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
    run.go:303: Failed to put "file1" to "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo": 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 02:26:07 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[2f59394f-b248-4856-942b-b1718954510e] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=2f59394f-b248-4856-942b-b1718954510e)
2026/07/18 02:26:07 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:26:07 DEBUG : Looking for writers
2026/07/18 02:26:07 DEBUG : >WaitForWriters: 
--- FAIL: TestVFSOpenFile (0.30s)
=== RUN   TestVFSRename
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:26:07 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:26:08 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[a96b37e9-a8a7-4d8f-b1f1-bb7b99d4e9f2] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=a96b37e9-a8a7-4d8f-b1f1-bb7b99d4e9f2)
2026/07/18 02:26:08 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:26:08 DEBUG : Looking for writers
2026/07/18 02:26:08 DEBUG : >WaitForWriters: 
--- FAIL: TestVFSRename (0.69s)
=== RUN   TestWriteFileHandleMethods
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:26:08 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:26:08 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2026/07/18 02:26:08 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2026/07/18 02:26:08 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:26:08 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2026/07/18 02:26:08 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2026/07/18 02:26:08 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:26:08 ERROR : file1: WriteFileHandle: Read: Can't read and write to file without --vfs-cache-mode >= minimal
2026/07/18 02:26:08 ERROR : file1: WriteFileHandle: ReadAt: Can't read and write to file without --vfs-cache-mode >= minimal
2026/07/18 02:26:08 ERROR : file1: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes
2026/07/18 02:26:08 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: File to upload is small (5 bytes), uploading instead of streaming
2026/07/18 02:26:08 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 02:26:08 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[006d24e9-17f1-46b0-808d-907c93a5c8fc] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=006d24e9-17f1-46b0-808d-907c93a5c8fc)
2026/07/18 02:26:08 DEBUG : file1: Remove: 
2026/07/18 02:26:08 DEBUG : Added virtual directory entry vDel: "file1"
2026/07/18 02:26:08 DEBUG : file1: >Remove: err=<nil>
    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 02:26:08 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[006d24e9-17f1-46b0-808d-907c93a5c8fc] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=006d24e9-17f1-46b0-808d-907c93a5c8fc)
        	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) <nil>
        	            	 
        	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:26:15 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2026/07/18 02:26:15 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2026/07/18 02:26:15 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:26:15 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2026/07/18 02:26:15 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2026/07/18 02:26:15 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:26:15 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: File to upload is small (0 bytes), uploading instead of streaming
2026/07/18 02:26:16 DEBUG : file1: size = 0 OK
2026/07/18 02:26:16 DEBUG : file1: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/07/18 02:26:16 DEBUG : file1: Size and md5 of src and dst objects identical
2026/07/18 02:26:16 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:26:16 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2026/07/18 02:26:16 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2026/07/18 02:26:16 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:26:16 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2026/07/18 02:26:16 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2026/07/18 02:26:16 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:26:16 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx
2026/07/18 02:26:16 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE|O_TRUNC
2026/07/18 02:26:16 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:26:16 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2026/07/18 02:26:16 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2026/07/18 02:26:16 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:26:16 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: File to upload is small (0 bytes), uploading instead of streaming
2026/07/18 02:26:16 DEBUG : file1: size = 0 OK
2026/07/18 02:26:16 DEBUG : file1: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/07/18 02:26:16 DEBUG : file1: Size and md5 of src and dst objects identical
2026/07/18 02:26:16 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:26:16 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx
2026/07/18 02:26:16 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE|O_TRUNC
2026/07/18 02:26:16 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:26:16 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2026/07/18 02:26:16 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2026/07/18 02:26:16 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:26:16 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: File to upload is small (7 bytes), uploading instead of streaming
2026/07/18 02:26:16 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 02:26:16 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[bcb8a5ff-c650-40a6-b996-bf5b1e7d6e83] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=bcb8a5ff-c650-40a6-b996-bf5b1e7d6e83)
    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 02:26:16 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[bcb8a5ff-c650-40a6-b996-bf5b1e7d6e83] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=bcb8a5ff-c650-40a6-b996-bf5b1e7d6e83)
        	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:26:16 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:26:16 DEBUG : Looking for writers
2026/07/18 02:26:16 DEBUG : file1: reading active writers
2026/07/18 02:26:16 DEBUG : >WaitForWriters: 
--- FAIL: TestWriteFileHandleMethods (8.30s)
=== RUN   TestWriteFileHandleWriteAt
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:26:16 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:26:16 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2026/07/18 02:26:16 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2026/07/18 02:26:16 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:26:16 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2026/07/18 02:26:16 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2026/07/18 02:26:16 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:26:16 DEBUG : file1: waiting for in-sequence write to 100 for 1s
2026/07/18 02:26:17 DEBUG : file1: aborting in-sequence write wait, off=100
2026/07/18 02:26:17 DEBUG : file1: failed to wait for in-sequence write to 100
2026/07/18 02:26:17 ERROR : file1: WriteFileHandle.Write: can't seek in file without --vfs-cache-mode >= writes
2026/07/18 02:26:17 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: File to upload is small (11 bytes), uploading instead of streaming
2026/07/18 02:26:18 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 02:26:17 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[34f70dd4-99bf-4e56-8bca-db7dd0740525] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=34f70dd4-99bf-4e56-8bca-db7dd0740525)
2026/07/18 02:26:18 DEBUG : file1: Remove: 
2026/07/18 02:26:18 DEBUG : Added virtual directory entry vDel: "file1"
2026/07/18 02:26:18 DEBUG : file1: >Remove: err=<nil>
    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 02:26:17 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[34f70dd4-99bf-4e56-8bca-db7dd0740525] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=34f70dd4-99bf-4e56-8bca-db7dd0740525)
        	Test:       	TestWriteFileHandleWriteAt
2026/07/18 02:26:18 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) <nil>
        	            	 
        	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:26:25 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:26:25 DEBUG : Looking for writers
2026/07/18 02:26:25 DEBUG : >WaitForWriters: 
--- FAIL: TestWriteFileHandleWriteAt (8.43s)
=== RUN   TestWriteFileHandleFlush
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:26:25 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:26:25 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2026/07/18 02:26:25 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2026/07/18 02:26:25 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:26:25 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2026/07/18 02:26:25 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2026/07/18 02:26:25 DEBUG : file1: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions
2026/07/18 02:26:25 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:26:25 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: File to upload is small (5 bytes), uploading instead of streaming
2026/07/18 02:26:25 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 02:26:25 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[aea0cc24-30bc-4b46-a7c5-6696ee5b215c] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=aea0cc24-30bc-4b46-a7c5-6696ee5b215c)
2026/07/18 02:26:25 DEBUG : file1: Remove: 
2026/07/18 02:26:25 DEBUG : Added virtual directory entry vDel: "file1"
2026/07/18 02:26:25 DEBUG : file1: >Remove: err=<nil>
2026/07/18 02:26:25 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 02:26:25 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[aea0cc24-30bc-4b46-a7c5-6696ee5b215c] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=aea0cc24-30bc-4b46-a7c5-6696ee5b215c)
    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 02:26:25 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[aea0cc24-30bc-4b46-a7c5-6696ee5b215c] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=aea0cc24-30bc-4b46-a7c5-6696ee5b215c)
        	Test:       	TestWriteFileHandleFlush
2026/07/18 02:26:25 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) <nil>
        	            	 
        	Test:       	TestWriteFileHandleFlush
2026/07/18 02:26:25 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:26:25 DEBUG : Looking for writers
2026/07/18 02:26:25 DEBUG : >WaitForWriters: 
--- FAIL: TestWriteFileHandleFlush (0.25s)
=== RUN   TestWriteFileModTimeWithOpenWriters
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:26:25 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:26:25 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2026/07/18 02:26:25 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2026/07/18 02:26:25 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:26:25 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2026/07/18 02:26:25 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2026/07/18 02:26:25 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:26:25 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: File to upload is small (2 bytes), uploading instead of streaming
2026/07/18 02:26:25 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 02:26:25 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[b19af7ae-ee0f-457a-9077-95408973e621] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=b19af7ae-ee0f-457a-9077-95408973e621)
2026/07/18 02:26:25 DEBUG : file1: Remove: 
2026/07/18 02:26:25 DEBUG : Added virtual directory entry vDel: "file1"
2026/07/18 02:26:25 DEBUG : file1: >Remove: err=<nil>
    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 02:26:25 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[b19af7ae-ee0f-457a-9077-95408973e621] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=b19af7ae-ee0f-457a-9077-95408973e621)
        	Test:       	TestWriteFileModTimeWithOpenWriters
2026/07/18 02:26:25 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:26:25 DEBUG : Looking for writers
2026/07/18 02:26:25 DEBUG : >WaitForWriters: 
--- FAIL: TestWriteFileModTimeWithOpenWriters (0.26s)
=== RUN   TestFileReadAtNonZeroLength
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:26:25 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: poll-interval is not supported by this remote
2026/07/18 02:26:25 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2026/07/18 02:26:25 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2026/07/18 02:26:25 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:26:25 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2026/07/18 02:26:25 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2026/07/18 02:26:25 DEBUG : Added virtual directory entry vAddFile: "file1"
2026/07/18 02:26:25 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: File to upload is small (100 bytes), uploading instead of streaming
2026/07/18 02:26:25 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 02:26:25 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[85a5fb46-af02-40a5-975c-af1bfd5cba73] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=85a5fb46-af02-40a5-975c-af1bfd5cba73)
2026/07/18 02:26:25 DEBUG : file1: Remove: 
2026/07/18 02:26:25 DEBUG : Added virtual directory entry vDel: "file1"
2026/07/18 02:26:25 DEBUG : file1: >Remove: err=<nil>
    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 02:26:25 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[85a5fb46-af02-40a5-975c-af1bfd5cba73] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=85a5fb46-af02-40a5-975c-af1bfd5cba73)
        	Test:       	TestFileReadAtNonZeroLength
2026/07/18 02:26:25 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=----------
2026/07/18 02:26:25 DEBUG : file1: >OpenFile: fd=<nil>, 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:26:25 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:26:25 DEBUG : Looking for writers
2026/07/18 02:26:25 DEBUG : >WaitForWriters: 
--- FAIL: TestFileReadAtNonZeroLength (0.27s)
=== RUN   TestZipManyFiles
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:26:26 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:26:26 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[7be64d7a-15c4-4ef1-b670-681ed2789460] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=7be64d7a-15c4-4ef1-b670-681ed2789460)
2026/07/18 02:26:26 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:26:26 DEBUG : Looking for writers
2026/07/18 02:26:26 DEBUG : >WaitForWriters: 
--- FAIL: TestZipManyFiles (0.65s)
=== RUN   TestZipManySubDirs
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:26:26 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:26:26 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[613e783a-ec69-42db-a76f-95196c142515] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=613e783a-ec69-42db-a76f-95196c142515)
2026/07/18 02:26:27 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:26:27 DEBUG : Looking for writers
2026/07/18 02:26:27 DEBUG : >WaitForWriters: 
--- FAIL: TestZipManySubDirs (0.60s)
=== RUN   TestZipLargeFiles
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:26:27 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:26:27 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[8bc5ede6-8785-48ee-b475-578981b5f1bc] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=8bc5ede6-8785-48ee-b475-578981b5f1bc)
2026/07/18 02:26:27 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:26:27 DEBUG : Looking for writers
2026/07/18 02:26:27 DEBUG : >WaitForWriters: 
--- FAIL: TestZipLargeFiles (0.71s)
=== RUN   TestZipDirsInRoot
    run.go:198: Remote "koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo", Local "Local file system at /tmp/rclone185572851", Modify Window "1ms"
2026/07/18 02:26:28 INFO  : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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-gujodil9kifo": 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 02:26:28 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=31536000; includeSubDomains] X-Request-Id:[f32cd183-5947-4bb3-bfe5-cbdee422b5fc] X-User-Id:[64ee1c28-c9ac-4f50-97d0-b24cfe05482f]], content: Internal server error (requestId=f32cd183-5947-4bb3-bfe5-cbdee422b5fc)
2026/07/18 02:26:28 DEBUG : WaitForWriters: timeout=30s
2026/07/18 02:26:28 DEBUG : Looking for writers
2026/07/18 02:26:28 DEBUG : >WaitForWriters: 
--- FAIL: TestZipDirsInRoot (0.56s)
FAIL
2026/07/18 02:26:28 DEBUG : koofr:4266cdc3-3d29-4a88-ac94-738914c162b4:rclone-test-gujodil9kifo: 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 8m47.257152052s (try 4/5): exit status 1: Failed [TestDirHandleMethods TestDirHandleReaddir TestDirHandleReaddirnames TestDirMethods TestDirForgetAll TestDirForgetPath TestDirWalk TestDirSetModTime TestDirStat TestDirReadDirAll TestDirOpen TestDirCreate TestDirMkdir TestDirMkdirSub 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]