"./vfs.test -test.v -test.timeout 1h0m0s -remote TestB2: -list-retries 5 -verbose -test.run '^(TestCaseSensitivity|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|TestFileReadAtZeroLength|TestFileRemove|TestFileRemoveAll|TestRWCacheUpdate|TestRWFileHandleFlushRead|TestRWFileHandleMethodsRead|TestRWFileHandleMethodsWrite|TestRWFileHandleReadAt|TestRWFileHandleReleaseRead|TestRWFileHandleSeek|TestRWFileHandleSizeCreateExisting|TestRWFileHandleSizeTruncateExisting|TestRWFileHandleWriteAt|TestRWFileHandleWriteNoWrite|TestRWFileModTimeWithOpenWriters|TestReadFileHandleFlush|TestReadFileHandleMethods|TestReadFileHandleReadAt|TestReadFileHandleRelease|TestReadFileHandleSeek|TestUnicodeNormalization|TestVFSOpenFile|TestVFSRename|TestVFSStat|TestVFSStatParent|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileHandleRelease|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 3/5) 2025/11/28 02:43:31 DEBUG : Creating backend with remote "TestB2:rclone-test-bogayoz7sina" 2025/11/28 02:43:31 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/11/28 02:43:32 DEBUG : Creating backend with remote "/tmp/rclone260528418" === RUN TestDirHandleMethods run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:32 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:33 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:33 DEBUG : Looking for writers 2025/11/28 02:43:33 DEBUG : >WaitForWriters: --- FAIL: TestDirHandleMethods (0.56s) === RUN TestDirHandleReaddir run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:33 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:33 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:33 DEBUG : Looking for writers 2025/11/28 02:43:33 DEBUG : >WaitForWriters: --- FAIL: TestDirHandleReaddir (0.24s) === RUN TestDirHandleReaddirnames run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:33 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:33 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:33 DEBUG : Looking for writers 2025/11/28 02:43:33 DEBUG : >WaitForWriters: --- FAIL: TestDirHandleReaddirnames (0.20s) === RUN TestDirMethods run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:33 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:33 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:33 DEBUG : Looking for writers 2025/11/28 02:43:33 DEBUG : >WaitForWriters: --- FAIL: TestDirMethods (0.19s) === RUN TestDirForgetAll run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:33 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:33 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:33 DEBUG : Looking for writers 2025/11/28 02:43:33 DEBUG : >WaitForWriters: --- FAIL: TestDirForgetAll (0.19s) === RUN TestDirForgetPath run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:33 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:34 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:34 DEBUG : Looking for writers 2025/11/28 02:43:34 DEBUG : >WaitForWriters: --- FAIL: TestDirForgetPath (0.20s) === RUN TestDirWalk run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:34 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:34 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:34 DEBUG : Looking for writers 2025/11/28 02:43:34 DEBUG : >WaitForWriters: --- FAIL: TestDirWalk (0.20s) === RUN TestDirSetModTime run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:34 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:34 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:34 DEBUG : Looking for writers 2025/11/28 02:43:34 DEBUG : >WaitForWriters: --- FAIL: TestDirSetModTime (0.19s) === RUN TestDirStat run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:34 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:34 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:34 DEBUG : Looking for writers 2025/11/28 02:43:34 DEBUG : >WaitForWriters: --- FAIL: TestDirStat (0.19s) === RUN TestDirReadDirAll run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:34 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:34 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:34 DEBUG : Looking for writers 2025/11/28 02:43:34 DEBUG : >WaitForWriters: --- FAIL: TestDirReadDirAll (0.20s) === RUN TestDirOpen run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:34 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:35 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:35 DEBUG : Looking for writers 2025/11/28 02:43:35 DEBUG : >WaitForWriters: --- FAIL: TestDirOpen (0.20s) === RUN TestDirCreate run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:35 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:35 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:35 DEBUG : Looking for writers 2025/11/28 02:43:35 DEBUG : >WaitForWriters: --- FAIL: TestDirCreate (0.22s) === RUN TestDirMkdir run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:35 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:35 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:35 DEBUG : Looking for writers 2025/11/28 02:43:35 DEBUG : >WaitForWriters: --- FAIL: TestDirMkdir (0.19s) === RUN TestDirMkdirSub run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:35 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:35 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:35 DEBUG : Looking for writers 2025/11/28 02:43:35 DEBUG : >WaitForWriters: --- FAIL: TestDirMkdirSub (0.19s) === RUN TestDirRemove run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:35 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:35 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:35 DEBUG : Looking for writers 2025/11/28 02:43:35 DEBUG : >WaitForWriters: --- FAIL: TestDirRemove (0.19s) === RUN TestDirRemoveAll run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:35 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:36 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:36 DEBUG : Looking for writers 2025/11/28 02:43:36 DEBUG : >WaitForWriters: --- FAIL: TestDirRemoveAll (0.20s) === RUN TestDirRemoveName run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:36 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:36 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:36 DEBUG : Looking for writers 2025/11/28 02:43:36 DEBUG : >WaitForWriters: --- FAIL: TestDirRemoveName (0.20s) === RUN TestDirRename run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:36 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:36 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:36 DEBUG : Looking for writers 2025/11/28 02:43:36 DEBUG : >WaitForWriters: --- FAIL: TestDirRename (0.20s) === RUN TestDirFileOpen run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:36 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:36 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:36 DEBUG : Looking for writers 2025/11/28 02:43:36 DEBUG : >WaitForWriters: --- FAIL: TestDirFileOpen (0.20s) === RUN TestDirMetadataExtension run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:36 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:36 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:36 DEBUG : Looking for writers 2025/11/28 02:43:36 DEBUG : >WaitForWriters: --- FAIL: TestDirMetadataExtension (0.20s) === RUN TestFileMethods run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:36 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:37 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:37 DEBUG : Looking for writers 2025/11/28 02:43:37 DEBUG : >WaitForWriters: --- FAIL: TestFileMethods (0.19s) === RUN TestFileSetModTime === RUN TestFileSetModTime/cache=off,open=false,write=false run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:37 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:37 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:37 DEBUG : Looking for writers 2025/11/28 02:43:37 DEBUG : >WaitForWriters: === RUN TestFileSetModTime/cache=off,open=true,write=false run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:37 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:37 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:37 DEBUG : Looking for writers 2025/11/28 02:43:37 DEBUG : >WaitForWriters: === RUN TestFileSetModTime/cache=off,open=true,write=true run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:37 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:37 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:37 DEBUG : Looking for writers 2025/11/28 02:43:37 DEBUG : >WaitForWriters: === RUN TestFileSetModTime/cache=full,open=false,write=false run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:37 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:43:37 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: root is "/home/rclone/.cache/rclone" 2025/11/28 02:43:37 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:37 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:37 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:37 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:37 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:37 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:37 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:37 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:37 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:37 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:37 DEBUG : Looking for writers 2025/11/28 02:43:37 DEBUG : >WaitForWriters: 2025/11/28 02:43:37 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaner exiting === RUN TestFileSetModTime/cache=full,open=true,write=false run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:37 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:43:37 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: root is "/home/rclone/.cache/rclone" 2025/11/28 02:43:37 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:37 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:37 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:37 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:37 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:37 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:37 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:37 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:37 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:38 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:38 DEBUG : Looking for writers 2025/11/28 02:43:38 DEBUG : >WaitForWriters: 2025/11/28 02:43:38 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaner exiting === RUN TestFileSetModTime/cache=full,open=true,write=true run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:38 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:43:38 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: root is "/home/rclone/.cache/rclone" 2025/11/28 02:43:38 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:38 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:38 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:38 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:38 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:38 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:38 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:38 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:38 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:38 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:38 DEBUG : Looking for writers 2025/11/28 02:43:38 DEBUG : >WaitForWriters: --- FAIL: TestFileSetModTime (1.21s) --- FAIL: TestFileSetModTime/cache=off,open=false,write=false (0.20s) --- FAIL: TestFileSetModTime/cache=off,open=true,write=false (0.20s) --- FAIL: TestFileSetModTime/cache=off,open=true,write=true (0.19s) --- FAIL: TestFileSetModTime/cache=full,open=false,write=false (0.21s) --- FAIL: TestFileSetModTime/cache=full,open=true,write=false (0.20s) --- FAIL: TestFileSetModTime/cache=full,open=true,write=true (0.20s) 2025/11/28 02:43:38 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaner exiting === RUN TestFileOpenRead run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:38 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:38 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:38 DEBUG : Looking for writers 2025/11/28 02:43:38 DEBUG : >WaitForWriters: --- FAIL: TestFileOpenRead (0.20s) === RUN TestFileOpenWrite run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:38 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:38 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:38 DEBUG : Looking for writers 2025/11/28 02:43:38 DEBUG : >WaitForWriters: --- FAIL: TestFileOpenWrite (0.20s) === RUN TestFileRemove run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:38 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:38 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:38 DEBUG : Looking for writers 2025/11/28 02:43:38 DEBUG : >WaitForWriters: --- FAIL: TestFileRemove (0.20s) === RUN TestFileRemoveAll run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:38 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:39 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:39 DEBUG : Looking for writers 2025/11/28 02:43:39 DEBUG : >WaitForWriters: --- FAIL: TestFileRemoveAll (0.23s) === RUN TestFileOpen run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:39 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:39 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:39 DEBUG : Looking for writers 2025/11/28 02:43:39 DEBUG : >WaitForWriters: --- FAIL: TestFileOpen (0.19s) === RUN TestFileRename === RUN TestFileRename/off,forceCache=false run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:39 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:39 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:39 DEBUG : Looking for writers 2025/11/28 02:43:39 DEBUG : >WaitForWriters: === RUN TestFileRename/minimal,forceCache=false run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:39 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:43:39 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: root is "/home/rclone/.cache/rclone" 2025/11/28 02:43:39 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:39 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:39 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:39 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:39 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:39 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:39 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:39 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:39 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:39 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:39 DEBUG : Looking for writers 2025/11/28 02:43:39 DEBUG : >WaitForWriters: 2025/11/28 02:43:39 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaner exiting === RUN TestFileRename/minimal,forceCache=true run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:39 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:43:39 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: root is "/home/rclone/.cache/rclone" 2025/11/28 02:43:39 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:39 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:39 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:39 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:39 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:39 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:39 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:39 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:39 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:39 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:39 DEBUG : Looking for writers 2025/11/28 02:43:39 DEBUG : >WaitForWriters: 2025/11/28 02:43:39 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaner exiting === RUN TestFileRename/writes,forceCache=false run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:39 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:43:39 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: root is "/home/rclone/.cache/rclone" 2025/11/28 02:43:39 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:39 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:39 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:39 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:39 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:39 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:39 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:39 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:39 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:40 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:40 DEBUG : Looking for writers 2025/11/28 02:43:40 DEBUG : >WaitForWriters: 2025/11/28 02:43:40 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaner exiting === RUN TestFileRename/writes,forceCache=true run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:40 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:43:40 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: root is "/home/rclone/.cache/rclone" 2025/11/28 02:43:40 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:40 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:40 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:40 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:40 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:40 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:40 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:40 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:40 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:40 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:40 DEBUG : Looking for writers 2025/11/28 02:43:40 DEBUG : >WaitForWriters: 2025/11/28 02:43:40 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaner exiting === RUN TestFileRename/full,forceCache=false run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:40 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:43:40 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: root is "/home/rclone/.cache/rclone" 2025/11/28 02:43:40 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:40 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:40 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:40 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:40 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:40 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:40 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:40 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:40 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:40 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:40 DEBUG : Looking for writers 2025/11/28 02:43:40 DEBUG : >WaitForWriters: --- FAIL: TestFileRename (1.29s) --- FAIL: TestFileRename/off,forceCache=false (0.19s) --- FAIL: TestFileRename/minimal,forceCache=false (0.20s) --- FAIL: TestFileRename/minimal,forceCache=true (0.20s) --- FAIL: TestFileRename/writes,forceCache=false (0.28s) --- FAIL: TestFileRename/writes,forceCache=true (0.21s) --- FAIL: TestFileRename/full,forceCache=false (0.20s) 2025/11/28 02:43:40 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaner exiting === RUN TestReadFileHandleMethods run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:40 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:40 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:40 DEBUG : Looking for writers 2025/11/28 02:43:40 DEBUG : >WaitForWriters: --- FAIL: TestReadFileHandleMethods (0.20s) === RUN TestReadFileHandleSeek run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:40 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:40 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:40 DEBUG : Looking for writers 2025/11/28 02:43:40 DEBUG : >WaitForWriters: --- FAIL: TestReadFileHandleSeek (0.20s) === RUN TestReadFileHandleReadAt run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:40 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:41 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:41 DEBUG : Looking for writers 2025/11/28 02:43:41 DEBUG : >WaitForWriters: --- FAIL: TestReadFileHandleReadAt (0.19s) === RUN TestReadFileHandleFlush run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:41 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:41 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:41 DEBUG : Looking for writers 2025/11/28 02:43:41 DEBUG : >WaitForWriters: --- FAIL: TestReadFileHandleFlush (0.20s) === RUN TestReadFileHandleRelease run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:41 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:41 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:41 DEBUG : Looking for writers 2025/11/28 02:43:41 DEBUG : >WaitForWriters: --- FAIL: TestReadFileHandleRelease (0.20s) === RUN TestRWFileHandleMethodsRead run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:41 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:43:41 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: root is "/home/rclone/.cache/rclone" 2025/11/28 02:43:41 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:41 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:41 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:41 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:41 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:41 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:41 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:41 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:41 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:41 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:41 DEBUG : Looking for writers 2025/11/28 02:43:41 DEBUG : >WaitForWriters: --- FAIL: TestRWFileHandleMethodsRead (0.20s) 2025/11/28 02:43:41 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaner exiting === RUN TestRWFileHandleSeek run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:41 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:43:41 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: root is "/home/rclone/.cache/rclone" 2025/11/28 02:43:41 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:41 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:41 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:41 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:41 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:41 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:41 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:41 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:41 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:41 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:41 DEBUG : Looking for writers 2025/11/28 02:43:41 DEBUG : >WaitForWriters: --- FAIL: TestRWFileHandleSeek (0.20s) === RUN TestRWFileHandleReadAt 2025/11/28 02:43:41 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaner exiting run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:41 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:43:41 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: root is "/home/rclone/.cache/rclone" 2025/11/28 02:43:41 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:41 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:41 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:41 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:41 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:41 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:41 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:41 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:41 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:42 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:42 DEBUG : Looking for writers 2025/11/28 02:43:42 DEBUG : >WaitForWriters: --- FAIL: TestRWFileHandleReadAt (0.20s) 2025/11/28 02:43:42 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaner exiting === RUN TestRWFileHandleFlushRead run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:42 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:43:42 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: root is "/home/rclone/.cache/rclone" 2025/11/28 02:43:42 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:42 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:42 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:42 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:42 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:42 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:42 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:42 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:42 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:42 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:42 DEBUG : Looking for writers 2025/11/28 02:43:42 DEBUG : >WaitForWriters: --- FAIL: TestRWFileHandleFlushRead (0.20s) === RUN TestRWFileHandleReleaseRead 2025/11/28 02:43:42 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaner exiting run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:42 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:43:42 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: root is "/home/rclone/.cache/rclone" 2025/11/28 02:43:42 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:42 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:42 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:42 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:42 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:42 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:42 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:42 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:42 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:42 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:42 DEBUG : Looking for writers 2025/11/28 02:43:42 DEBUG : >WaitForWriters: --- FAIL: TestRWFileHandleReleaseRead (0.20s) === RUN TestRWFileHandleMethodsWrite run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:43:42 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaner exiting 2025/11/28 02:43:42 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:43:42 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: root is "/home/rclone/.cache/rclone" 2025/11/28 02:43:42 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:42 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:42 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:42 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:42 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:42 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:42 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:43:42 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:43:42 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/11/28 02:43:42 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/11/28 02:43:42 DEBUG : file1: newRWFileHandle: 2025/11/28 02:43:42 DEBUG : file1(0xc000694a80): openPending: 2025/11/28 02:43:42 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct) 2025/11/28 02:43:42 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2025/11/28 02:43:42 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 1 (was 1) in use 1, to upload 0, uploading 0, total size 0 (was 0) 2025/11/28 02:43:42 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:43:42 DEBUG : file1(0xc000694a80): >openPending: err= 2025/11/28 02:43:42 DEBUG : file1: >newRWFileHandle: err= 2025/11/28 02:43:42 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:43:42 DEBUG : file1: >Open: fd=file1 (rw), err= 2025/11/28 02:43:42 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2025/11/28 02:43:42 DEBUG : file1(0xc000694a80): _writeAt: size=5, off=0 2025/11/28 02:43:42 DEBUG : file1(0xc000694a80): >_writeAt: n=5, err= 2025/11/28 02:43:42 DEBUG : file1(0xc000694a80): _writeAt: size=7, off=5 2025/11/28 02:43:42 DEBUG : file1(0xc000694a80): >_writeAt: n=7, err= 2025/11/28 02:43:42 DEBUG : file1: vfs cache: truncate to size=11 2025/11/28 02:43:42 DEBUG : file1(0xc000694a80): close: 2025/11/28 02:43:42 DEBUG : file1: vfs cache: setting modification time to 2025-11-28 02:43:42.583457823 +0000 UTC m=+10.630211619 2025/11/28 02:43:42 INFO : file1: vfs cache: queuing for upload in 100ms 2025/11/28 02:43:42 DEBUG : file1(0xc000694a80): >close: err= 2025/11/28 02:43:42 DEBUG : file1(0xc000694a80): close: 2025/11/28 02:43:42 DEBUG : file1(0xc000694a80): >close: err=file already closed 2025/11/28 02:43:42 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:43:42 DEBUG : Looking for writers 2025/11/28 02:43:42 DEBUG : file1: reading active writers 2025/11/28 02:43:42 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2025/11/28 02:43:42 DEBUG : Looking for writers 2025/11/28 02:43:42 DEBUG : file1: reading active writers 2025/11/28 02:43:42 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2025/11/28 02:43:42 DEBUG : Looking for writers 2025/11/28 02:43:42 DEBUG : file1: reading active writers 2025/11/28 02:43:42 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2025/11/28 02:43:42 DEBUG : Looking for writers 2025/11/28 02:43:42 DEBUG : file1: reading active writers 2025/11/28 02:43:42 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2025/11/28 02:43:42 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:43:42 DEBUG : Looking for writers 2025/11/28 02:43:42 DEBUG : file1: reading active writers 2025/11/28 02:43:42 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2025/11/28 02:43:42 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:42 ERROR : file1: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:42 DEBUG : Looking for writers 2025/11/28 02:43:42 DEBUG : file1: reading active writers 2025/11/28 02:43:42 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2025/11/28 02:43:43 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:43:43 DEBUG : Looking for writers 2025/11/28 02:43:43 DEBUG : file1: reading active writers 2025/11/28 02:43:43 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2025/11/28 02:43:43 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:43 ERROR : file1: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:43 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:43:43 DEBUG : Looking for writers 2025/11/28 02:43:43 DEBUG : file1: reading active writers 2025/11/28 02:43:43 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:43:43 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:43 ERROR : file1: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:44 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:43:44 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:44 ERROR : file1: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:44 DEBUG : Looking for writers 2025/11/28 02:43:44 DEBUG : file1: reading active writers 2025/11/28 02:43:44 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:43:45 DEBUG : Looking for writers 2025/11/28 02:43:45 DEBUG : file1: reading active writers 2025/11/28 02:43:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:43:46 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:43:46 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:46 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:46 DEBUG : Looking for writers 2025/11/28 02:43:46 DEBUG : file1: reading active writers 2025/11/28 02:43:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:43:47 DEBUG : Looking for writers 2025/11/28 02:43:47 DEBUG : file1: reading active writers 2025/11/28 02:43:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:43:48 DEBUG : Looking for writers 2025/11/28 02:43:48 DEBUG : file1: reading active writers 2025/11/28 02:43:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:43:49 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:43:49 DEBUG : Looking for writers 2025/11/28 02:43:49 DEBUG : file1: reading active writers 2025/11/28 02:43:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:43:50 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:50 ERROR : file1: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:50 DEBUG : Looking for writers 2025/11/28 02:43:50 DEBUG : file1: reading active writers 2025/11/28 02:43:50 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:43:51 DEBUG : Looking for writers 2025/11/28 02:43:51 DEBUG : file1: reading active writers 2025/11/28 02:43:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:43:52 DEBUG : Looking for writers 2025/11/28 02:43:52 DEBUG : file1: reading active writers 2025/11/28 02:43:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:43:53 DEBUG : Looking for writers 2025/11/28 02:43:53 DEBUG : file1: reading active writers 2025/11/28 02:43:53 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:43:54 DEBUG : Looking for writers 2025/11/28 02:43:54 DEBUG : file1: reading active writers 2025/11/28 02:43:54 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:43:55 DEBUG : Looking for writers 2025/11/28 02:43:55 DEBUG : file1: reading active writers 2025/11/28 02:43:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:43:56 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:43:56 DEBUG : Looking for writers 2025/11/28 02:43:56 DEBUG : file1: reading active writers 2025/11/28 02:43:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:43:57 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:57 ERROR : file1: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:43:57 DEBUG : Looking for writers 2025/11/28 02:43:57 DEBUG : file1: reading active writers 2025/11/28 02:43:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:43:58 DEBUG : Looking for writers 2025/11/28 02:43:58 DEBUG : file1: reading active writers 2025/11/28 02:43:58 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:43:59 DEBUG : Looking for writers 2025/11/28 02:43:59 DEBUG : file1: reading active writers 2025/11/28 02:43:59 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:00 DEBUG : Looking for writers 2025/11/28 02:44:00 DEBUG : file1: reading active writers 2025/11/28 02:44:00 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:01 DEBUG : Looking for writers 2025/11/28 02:44:01 DEBUG : file1: reading active writers 2025/11/28 02:44:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:02 DEBUG : Looking for writers 2025/11/28 02:44:02 DEBUG : file1: reading active writers 2025/11/28 02:44:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:03 DEBUG : Looking for writers 2025/11/28 02:44:03 DEBUG : file1: reading active writers 2025/11/28 02:44:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:04 DEBUG : Looking for writers 2025/11/28 02:44:04 DEBUG : file1: reading active writers 2025/11/28 02:44:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:05 DEBUG : Looking for writers 2025/11/28 02:44:05 DEBUG : file1: reading active writers 2025/11/28 02:44:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:06 DEBUG : Looking for writers 2025/11/28 02:44:06 DEBUG : file1: reading active writers 2025/11/28 02:44:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:07 DEBUG : Looking for writers 2025/11/28 02:44:07 DEBUG : file1: reading active writers 2025/11/28 02:44:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:08 DEBUG : Looking for writers 2025/11/28 02:44:08 DEBUG : file1: reading active writers 2025/11/28 02:44:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:09 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:44:09 DEBUG : Looking for writers 2025/11/28 02:44:09 DEBUG : file1: reading active writers 2025/11/28 02:44:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:10 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:44:10 ERROR : file1: vfs cache: failed to upload try #8, will retry in 25.6s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:44:10 DEBUG : Looking for writers 2025/11/28 02:44:10 DEBUG : file1: reading active writers 2025/11/28 02:44:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:11 DEBUG : Looking for writers 2025/11/28 02:44:11 DEBUG : file1: reading active writers 2025/11/28 02:44:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:12 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc000454b40 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc0006e0108 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824640930112} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13997857208525052959 ext:10630211619 loc:0x42a0c60} ATime:{wall:13997857208525071193 ext:10630229843 loc:0x42a0c60} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2025/11/28 02:44:12 DEBUG : >WaitForWriters: fstest.go:298: Sleeping for 1s for list eventual consistency: 1/5 fstest.go:298: Sleeping for 2s for list eventual consistency: 2/5 fstest.go:298: Sleeping for 4s for list eventual consistency: 3/5 fstest.go:298: Sleeping for 8s for list eventual consistency: 4/5 fstest.go:298: Sleeping for 16s for list eventual consistency: 5/5 2025/11/28 02:44:35 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:44:36 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:44:36 ERROR : file1: vfs cache: failed to upload try #9, will retry in 51.2s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:44:42 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2025/11/28 02:44:42 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 1 (was 1) in use 1, to upload 1, uploading 0, total size 11 (was 11) 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 2025/11/28 02:44:43 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:44:43 DEBUG : Looking for writers 2025/11/28 02:44:43 DEBUG : file1: reading active writers 2025/11/28 02:44:43 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2025/11/28 02:44:43 DEBUG : Looking for writers 2025/11/28 02:44:43 DEBUG : file1: reading active writers 2025/11/28 02:44:43 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2025/11/28 02:44:43 DEBUG : Looking for writers 2025/11/28 02:44:43 DEBUG : file1: reading active writers 2025/11/28 02:44:43 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2025/11/28 02:44:43 DEBUG : Looking for writers 2025/11/28 02:44:43 DEBUG : file1: reading active writers 2025/11/28 02:44:43 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2025/11/28 02:44:43 DEBUG : Looking for writers 2025/11/28 02:44:43 DEBUG : file1: reading active writers 2025/11/28 02:44:43 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2025/11/28 02:44:43 DEBUG : Looking for writers 2025/11/28 02:44:43 DEBUG : file1: reading active writers 2025/11/28 02:44:43 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2025/11/28 02:44:44 DEBUG : Looking for writers 2025/11/28 02:44:44 DEBUG : file1: reading active writers 2025/11/28 02:44:44 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2025/11/28 02:44:44 DEBUG : Looking for writers 2025/11/28 02:44:44 DEBUG : file1: reading active writers 2025/11/28 02:44:44 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:45 DEBUG : Looking for writers 2025/11/28 02:44:45 DEBUG : file1: reading active writers 2025/11/28 02:44:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:46 DEBUG : Looking for writers 2025/11/28 02:44:46 DEBUG : file1: reading active writers 2025/11/28 02:44:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:47 DEBUG : Looking for writers 2025/11/28 02:44:47 DEBUG : file1: reading active writers 2025/11/28 02:44:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:48 DEBUG : Looking for writers 2025/11/28 02:44:48 DEBUG : file1: reading active writers 2025/11/28 02:44:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:49 DEBUG : Looking for writers 2025/11/28 02:44:49 DEBUG : file1: reading active writers 2025/11/28 02:44:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:50 DEBUG : Looking for writers 2025/11/28 02:44:50 DEBUG : file1: reading active writers 2025/11/28 02:44:50 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:51 DEBUG : Looking for writers 2025/11/28 02:44:51 DEBUG : file1: reading active writers 2025/11/28 02:44:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:52 DEBUG : Looking for writers 2025/11/28 02:44:52 DEBUG : file1: reading active writers 2025/11/28 02:44:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:53 DEBUG : Looking for writers 2025/11/28 02:44:53 DEBUG : file1: reading active writers 2025/11/28 02:44:53 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:54 DEBUG : Looking for writers 2025/11/28 02:44:54 DEBUG : file1: reading active writers 2025/11/28 02:44:54 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:55 DEBUG : Looking for writers 2025/11/28 02:44:55 DEBUG : file1: reading active writers 2025/11/28 02:44:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:56 DEBUG : Looking for writers 2025/11/28 02:44:56 DEBUG : file1: reading active writers 2025/11/28 02:44:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:57 DEBUG : Looking for writers 2025/11/28 02:44:57 DEBUG : file1: reading active writers 2025/11/28 02:44:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:58 DEBUG : Looking for writers 2025/11/28 02:44:58 DEBUG : file1: reading active writers 2025/11/28 02:44:58 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:44:59 DEBUG : Looking for writers 2025/11/28 02:44:59 DEBUG : file1: reading active writers 2025/11/28 02:44:59 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:00 DEBUG : Looking for writers 2025/11/28 02:45:00 DEBUG : file1: reading active writers 2025/11/28 02:45:00 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:01 DEBUG : Looking for writers 2025/11/28 02:45:01 DEBUG : file1: reading active writers 2025/11/28 02:45:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:02 DEBUG : Looking for writers 2025/11/28 02:45:02 DEBUG : file1: reading active writers 2025/11/28 02:45:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:03 DEBUG : Looking for writers 2025/11/28 02:45:03 DEBUG : file1: reading active writers 2025/11/28 02:45:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:04 DEBUG : Looking for writers 2025/11/28 02:45:04 DEBUG : file1: reading active writers 2025/11/28 02:45:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:05 DEBUG : Looking for writers 2025/11/28 02:45:05 DEBUG : file1: reading active writers 2025/11/28 02:45:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:06 DEBUG : Looking for writers 2025/11/28 02:45:06 DEBUG : file1: reading active writers 2025/11/28 02:45:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:07 DEBUG : Looking for writers 2025/11/28 02:45:07 DEBUG : file1: reading active writers 2025/11/28 02:45:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:08 DEBUG : Looking for writers 2025/11/28 02:45:08 DEBUG : file1: reading active writers 2025/11/28 02:45:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:09 DEBUG : Looking for writers 2025/11/28 02:45:09 DEBUG : file1: reading active writers 2025/11/28 02:45:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:10 DEBUG : Looking for writers 2025/11/28 02:45:10 DEBUG : file1: reading active writers 2025/11/28 02:45:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:11 DEBUG : Looking for writers 2025/11/28 02:45:11 DEBUG : file1: reading active writers 2025/11/28 02:45:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:12 DEBUG : Looking for writers 2025/11/28 02:45:12 DEBUG : file1: reading active writers 2025/11/28 02:45:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:13 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc000454b40 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc0006e0108 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824640930112} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13997857208525052959 ext:10630211619 loc:0x42a0c60} ATime:{wall:13997857208525071193 ext:10630229843 loc:0x42a0c60} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2025/11/28 02:45:13 DEBUG : >WaitForWriters: 2025/11/28 02:45:13 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaner exiting --- FAIL: TestRWFileHandleMethodsWrite (91.02s) === RUN TestRWFileHandleWriteAt run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:45:13 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:45:13 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: root is "/home/rclone/.cache/rclone" 2025/11/28 02:45:13 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:45:13 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:45:13 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:45:13 DEBUG : Config file has changed externally - reloading 2025/11/28 02:45:13 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:45:13 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:45:13 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:45:13 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:45:13 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:45:13 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/11/28 02:45:13 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/11/28 02:45:13 DEBUG : file1: newRWFileHandle: 2025/11/28 02:45:13 DEBUG : file1(0xc0004bbf40): openPending: 2025/11/28 02:45:13 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct) 2025/11/28 02:45:13 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2025/11/28 02:45:13 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 1 (was 1) in use 1, to upload 0, uploading 0, total size 0 (was 0) 2025/11/28 02:45:13 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:45:13 DEBUG : file1(0xc0004bbf40): >openPending: err= 2025/11/28 02:45:13 DEBUG : file1: >newRWFileHandle: err= 2025/11/28 02:45:13 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:45:13 DEBUG : file1: >Open: fd=file1 (rw), err= 2025/11/28 02:45:13 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2025/11/28 02:45:13 DEBUG : file1(0xc0004bbf40): _writeAt: size=7, off=0 2025/11/28 02:45:13 DEBUG : file1(0xc0004bbf40): >_writeAt: n=7, err= 2025/11/28 02:45:13 DEBUG : file1(0xc0004bbf40): _writeAt: size=6, off=5 2025/11/28 02:45:13 DEBUG : file1(0xc0004bbf40): >_writeAt: n=6, err= 2025/11/28 02:45:13 DEBUG : file1(0xc0004bbf40): close: 2025/11/28 02:45:13 DEBUG : file1: vfs cache: setting modification time to 2025-11-28 02:45:13.60291759 +0000 UTC m=+101.649671366 2025/11/28 02:45:13 INFO : file1: vfs cache: queuing for upload in 100ms 2025/11/28 02:45:13 DEBUG : file1(0xc0004bbf40): >close: err= 2025/11/28 02:45:13 DEBUG : file1(0xc0004bbf40): _writeAt: size=5, off=0 2025/11/28 02:45:13 DEBUG : file1(0xc0004bbf40): >_writeAt: n=0, err=file already closed 2025/11/28 02:45:13 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:45:13 DEBUG : Looking for writers 2025/11/28 02:45:13 DEBUG : file1: reading active writers 2025/11/28 02:45:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2025/11/28 02:45:13 DEBUG : Looking for writers 2025/11/28 02:45:13 DEBUG : file1: reading active writers 2025/11/28 02:45:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2025/11/28 02:45:13 DEBUG : Looking for writers 2025/11/28 02:45:13 DEBUG : file1: reading active writers 2025/11/28 02:45:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2025/11/28 02:45:13 DEBUG : Looking for writers 2025/11/28 02:45:13 DEBUG : file1: reading active writers 2025/11/28 02:45:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2025/11/28 02:45:13 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:45:13 DEBUG : Looking for writers 2025/11/28 02:45:13 DEBUG : file1: reading active writers 2025/11/28 02:45:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2025/11/28 02:45:13 DEBUG : Looking for writers 2025/11/28 02:45:13 DEBUG : file1: reading active writers 2025/11/28 02:45:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2025/11/28 02:45:14 DEBUG : Looking for writers 2025/11/28 02:45:14 DEBUG : file1: reading active writers 2025/11/28 02:45:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2025/11/28 02:45:14 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:45:14 ERROR : file1: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:45:14 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:45:14 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:45:14 ERROR : file1: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:45:14 DEBUG : Looking for writers 2025/11/28 02:45:14 DEBUG : file1: reading active writers 2025/11/28 02:45:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:15 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:45:15 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:45:15 ERROR : file1: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:45:15 DEBUG : Looking for writers 2025/11/28 02:45:15 DEBUG : file1: reading active writers 2025/11/28 02:45:15 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:16 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:45:16 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:45:16 ERROR : file1: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:45:16 DEBUG : Looking for writers 2025/11/28 02:45:16 DEBUG : file1: reading active writers 2025/11/28 02:45:16 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:17 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:45:17 DEBUG : Looking for writers 2025/11/28 02:45:17 DEBUG : file1: reading active writers 2025/11/28 02:45:17 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:18 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:45:18 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:45:18 DEBUG : Looking for writers 2025/11/28 02:45:18 DEBUG : file1: reading active writers 2025/11/28 02:45:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:19 DEBUG : Looking for writers 2025/11/28 02:45:19 DEBUG : file1: reading active writers 2025/11/28 02:45:19 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:20 DEBUG : Looking for writers 2025/11/28 02:45:20 DEBUG : file1: reading active writers 2025/11/28 02:45:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:21 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:45:21 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:45:21 ERROR : file1: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:45:21 DEBUG : Looking for writers 2025/11/28 02:45:21 DEBUG : file1: reading active writers 2025/11/28 02:45:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:22 DEBUG : Looking for writers 2025/11/28 02:45:22 DEBUG : file1: reading active writers 2025/11/28 02:45:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:23 DEBUG : Looking for writers 2025/11/28 02:45:23 DEBUG : file1: reading active writers 2025/11/28 02:45:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:24 DEBUG : Looking for writers 2025/11/28 02:45:24 DEBUG : file1: reading active writers 2025/11/28 02:45:24 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:25 DEBUG : Looking for writers 2025/11/28 02:45:25 DEBUG : file1: reading active writers 2025/11/28 02:45:25 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:26 DEBUG : Looking for writers 2025/11/28 02:45:26 DEBUG : file1: reading active writers 2025/11/28 02:45:26 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:27 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:45:27 DEBUG : Looking for writers 2025/11/28 02:45:27 DEBUG : file1: reading active writers 2025/11/28 02:45:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:28 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:45:28 ERROR : file1: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:45:28 DEBUG : Looking for writers 2025/11/28 02:45:28 DEBUG : file1: reading active writers 2025/11/28 02:45:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:29 DEBUG : Looking for writers 2025/11/28 02:45:29 DEBUG : file1: reading active writers 2025/11/28 02:45:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:30 DEBUG : Looking for writers 2025/11/28 02:45:30 DEBUG : file1: reading active writers 2025/11/28 02:45:30 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:31 DEBUG : Looking for writers 2025/11/28 02:45:31 DEBUG : file1: reading active writers 2025/11/28 02:45:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:32 DEBUG : Looking for writers 2025/11/28 02:45:32 DEBUG : file1: reading active writers 2025/11/28 02:45:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:33 DEBUG : Looking for writers 2025/11/28 02:45:33 DEBUG : file1: reading active writers 2025/11/28 02:45:33 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:34 DEBUG : Looking for writers 2025/11/28 02:45:34 DEBUG : file1: reading active writers 2025/11/28 02:45:34 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:35 DEBUG : Looking for writers 2025/11/28 02:45:35 DEBUG : file1: reading active writers 2025/11/28 02:45:35 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:36 DEBUG : Looking for writers 2025/11/28 02:45:36 DEBUG : file1: reading active writers 2025/11/28 02:45:36 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:37 DEBUG : Looking for writers 2025/11/28 02:45:37 DEBUG : file1: reading active writers 2025/11/28 02:45:37 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:38 DEBUG : Looking for writers 2025/11/28 02:45:38 DEBUG : file1: reading active writers 2025/11/28 02:45:38 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:39 DEBUG : Looking for writers 2025/11/28 02:45:39 DEBUG : file1: reading active writers 2025/11/28 02:45:39 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:40 DEBUG : Looking for writers 2025/11/28 02:45:40 DEBUG : file1: reading active writers 2025/11/28 02:45:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:41 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:45:41 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:45:41 ERROR : file1: vfs cache: failed to upload try #8, will retry in 25.6s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:45:41 DEBUG : Looking for writers 2025/11/28 02:45:41 DEBUG : file1: reading active writers 2025/11/28 02:45:41 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:42 DEBUG : Looking for writers 2025/11/28 02:45:42 DEBUG : file1: reading active writers 2025/11/28 02:45:42 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:45:43 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc0007cc1e0 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc000604508 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824640030016} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13997857306255018710 ext:101649671366 loc:0x42a0c60} ATime:{wall:13997857306255049037 ext:101649701703 loc:0x42a0c60} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2025/11/28 02:45:43 DEBUG : >WaitForWriters: fstest.go:298: Sleeping for 1s for list eventual consistency: 1/5 fstest.go:298: Sleeping for 2s for list eventual consistency: 2/5 fstest.go:298: Sleeping for 4s for list eventual consistency: 3/5 fstest.go:298: Sleeping for 8s for list eventual consistency: 4/5 fstest.go:298: Sleeping for 16s for list eventual consistency: 5/5 2025/11/28 02:46:07 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:46:07 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:07 ERROR : file1: vfs cache: failed to upload try #9, will retry in 51.2s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:13 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2025/11/28 02:46:13 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 1 (was 1) in use 1, to upload 1, uploading 0, total size 11 (was 11) 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 2025/11/28 02:46:14 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:46:14 DEBUG : Looking for writers 2025/11/28 02:46:14 DEBUG : file1: reading active writers 2025/11/28 02:46:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2025/11/28 02:46:14 DEBUG : Looking for writers 2025/11/28 02:46:14 DEBUG : file1: reading active writers 2025/11/28 02:46:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2025/11/28 02:46:14 DEBUG : Looking for writers 2025/11/28 02:46:14 DEBUG : file1: reading active writers 2025/11/28 02:46:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2025/11/28 02:46:14 DEBUG : Looking for writers 2025/11/28 02:46:14 DEBUG : file1: reading active writers 2025/11/28 02:46:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2025/11/28 02:46:14 DEBUG : Looking for writers 2025/11/28 02:46:14 DEBUG : file1: reading active writers 2025/11/28 02:46:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2025/11/28 02:46:14 DEBUG : Looking for writers 2025/11/28 02:46:14 DEBUG : file1: reading active writers 2025/11/28 02:46:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2025/11/28 02:46:15 DEBUG : Looking for writers 2025/11/28 02:46:15 DEBUG : file1: reading active writers 2025/11/28 02:46:15 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2025/11/28 02:46:15 DEBUG : Looking for writers 2025/11/28 02:46:15 DEBUG : file1: reading active writers 2025/11/28 02:46:15 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:16 DEBUG : Looking for writers 2025/11/28 02:46:16 DEBUG : file1: reading active writers 2025/11/28 02:46:16 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:17 DEBUG : Looking for writers 2025/11/28 02:46:17 DEBUG : file1: reading active writers 2025/11/28 02:46:17 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:18 DEBUG : Looking for writers 2025/11/28 02:46:18 DEBUG : file1: reading active writers 2025/11/28 02:46:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:19 DEBUG : Looking for writers 2025/11/28 02:46:19 DEBUG : file1: reading active writers 2025/11/28 02:46:19 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:20 DEBUG : Looking for writers 2025/11/28 02:46:20 DEBUG : file1: reading active writers 2025/11/28 02:46:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:21 DEBUG : Looking for writers 2025/11/28 02:46:21 DEBUG : file1: reading active writers 2025/11/28 02:46:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:22 DEBUG : Looking for writers 2025/11/28 02:46:22 DEBUG : file1: reading active writers 2025/11/28 02:46:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:23 DEBUG : Looking for writers 2025/11/28 02:46:23 DEBUG : file1: reading active writers 2025/11/28 02:46:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:24 DEBUG : Looking for writers 2025/11/28 02:46:24 DEBUG : file1: reading active writers 2025/11/28 02:46:24 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:25 DEBUG : Looking for writers 2025/11/28 02:46:25 DEBUG : file1: reading active writers 2025/11/28 02:46:25 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:26 DEBUG : Looking for writers 2025/11/28 02:46:26 DEBUG : file1: reading active writers 2025/11/28 02:46:26 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:27 DEBUG : Looking for writers 2025/11/28 02:46:27 DEBUG : file1: reading active writers 2025/11/28 02:46:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:28 DEBUG : Looking for writers 2025/11/28 02:46:28 DEBUG : file1: reading active writers 2025/11/28 02:46:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:29 DEBUG : Looking for writers 2025/11/28 02:46:29 DEBUG : file1: reading active writers 2025/11/28 02:46:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:30 DEBUG : Looking for writers 2025/11/28 02:46:30 DEBUG : file1: reading active writers 2025/11/28 02:46:30 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:31 DEBUG : Looking for writers 2025/11/28 02:46:31 DEBUG : file1: reading active writers 2025/11/28 02:46:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:32 DEBUG : Looking for writers 2025/11/28 02:46:32 DEBUG : file1: reading active writers 2025/11/28 02:46:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:33 DEBUG : Looking for writers 2025/11/28 02:46:33 DEBUG : file1: reading active writers 2025/11/28 02:46:33 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:34 DEBUG : Looking for writers 2025/11/28 02:46:34 DEBUG : file1: reading active writers 2025/11/28 02:46:34 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:35 DEBUG : Looking for writers 2025/11/28 02:46:35 DEBUG : file1: reading active writers 2025/11/28 02:46:35 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:36 DEBUG : Looking for writers 2025/11/28 02:46:36 DEBUG : file1: reading active writers 2025/11/28 02:46:36 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:37 DEBUG : Looking for writers 2025/11/28 02:46:37 DEBUG : file1: reading active writers 2025/11/28 02:46:37 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:38 DEBUG : Looking for writers 2025/11/28 02:46:38 DEBUG : file1: reading active writers 2025/11/28 02:46:38 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:39 DEBUG : Looking for writers 2025/11/28 02:46:39 DEBUG : file1: reading active writers 2025/11/28 02:46:39 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:40 DEBUG : Looking for writers 2025/11/28 02:46:40 DEBUG : file1: reading active writers 2025/11/28 02:46:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:41 DEBUG : Looking for writers 2025/11/28 02:46:41 DEBUG : file1: reading active writers 2025/11/28 02:46:41 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:42 DEBUG : Looking for writers 2025/11/28 02:46:42 DEBUG : file1: reading active writers 2025/11/28 02:46:42 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:43 DEBUG : Looking for writers 2025/11/28 02:46:43 DEBUG : file1: reading active writers 2025/11/28 02:46:43 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:46:44 ERROR : Exiting even though 0 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc0007cc1e0 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc000604508 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824640030016} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13997857306255018710 ext:101649671366 loc:0x42a0c60} ATime:{wall:13997857306255049037 ext:101649701703 loc:0x42a0c60} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2025/11/28 02:46:44 DEBUG : >WaitForWriters: --- FAIL: TestRWFileHandleWriteAt (91.02s) 2025/11/28 02:46:44 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaner exiting === RUN TestRWFileHandleWriteNoWrite run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:46:44 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:46:44 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: root is "/home/rclone/.cache/rclone" 2025/11/28 02:46:44 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:46:44 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:46:44 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:46:44 DEBUG : Config file has changed externally - reloading 2025/11/28 02:46:44 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:46:44 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:46:44 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:46:44 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:46:44 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:46:44 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/11/28 02:46:44 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/11/28 02:46:44 DEBUG : file1: newRWFileHandle: 2025/11/28 02:46:44 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2025/11/28 02:46:44 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 1 (was 1) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2025/11/28 02:46:44 DEBUG : file1(0xc000882140): openPending: 2025/11/28 02:46:44 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct) 2025/11/28 02:46:44 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:46:44 DEBUG : file1(0xc000882140): >openPending: err= 2025/11/28 02:46:44 DEBUG : file1: >newRWFileHandle: err= 2025/11/28 02:46:44 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:46:44 DEBUG : file1: >Open: fd=file1 (rw), err= 2025/11/28 02:46:44 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2025/11/28 02:46:44 DEBUG : file1(0xc000882140): close: 2025/11/28 02:46:44 DEBUG : file1: vfs cache: setting modification time to 2025-11-28 02:46:44.622520634 +0000 UTC m=+192.669274440 2025/11/28 02:46:44 INFO : file1: vfs cache: queuing for upload in 100ms 2025/11/28 02:46:44 DEBUG : file1(0xc000882140): >close: err= 2025/11/28 02:46:44 DEBUG : file2: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx 2025/11/28 02:46:44 DEBUG : file2: Open: flags=O_WRONLY|O_CREATE|O_TRUNC 2025/11/28 02:46:44 DEBUG : file2: newRWFileHandle: 2025/11/28 02:46:44 DEBUG : file2(0xc000882680): openPending: 2025/11/28 02:46:44 DEBUG : file2: vfs cache: truncate to size=0 (not needed as size correct) 2025/11/28 02:46:44 DEBUG : Added virtual directory entry vAddFile: "file2" 2025/11/28 02:46:44 DEBUG : file2(0xc000882680): >openPending: err= 2025/11/28 02:46:44 DEBUG : file2: >newRWFileHandle: err= 2025/11/28 02:46:44 DEBUG : Added virtual directory entry vAddFile: "file2" 2025/11/28 02:46:44 DEBUG : file2: >Open: fd=file2 (rw), err= 2025/11/28 02:46:44 DEBUG : file2: >OpenFile: fd=file2 (rw), err= 2025/11/28 02:46:44 DEBUG : file2(0xc000882680): RWFileHandle.Flush 2025/11/28 02:46:44 DEBUG : file2(0xc000882680): RWFileHandle.Release 2025/11/28 02:46:44 DEBUG : file2(0xc000882680): close: 2025/11/28 02:46:44 DEBUG : file2: vfs cache: setting modification time to 2025-11-28 02:46:44.623732448 +0000 UTC m=+192.670486254 2025/11/28 02:46:44 INFO : file2: vfs cache: queuing for upload in 100ms 2025/11/28 02:46:44 DEBUG : file2(0xc000882680): >close: err= 2025/11/28 02:46:44 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:46:44 DEBUG : Looking for writers 2025/11/28 02:46:44 DEBUG : file1: reading active writers 2025/11/28 02:46:44 DEBUG : file2: reading active writers 2025/11/28 02:46:44 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms 2025/11/28 02:46:44 DEBUG : Looking for writers 2025/11/28 02:46:44 DEBUG : file1: reading active writers 2025/11/28 02:46:44 DEBUG : file2: reading active writers 2025/11/28 02:46:44 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms 2025/11/28 02:46:44 DEBUG : Looking for writers 2025/11/28 02:46:44 DEBUG : file1: reading active writers 2025/11/28 02:46:44 DEBUG : file2: reading active writers 2025/11/28 02:46:44 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms 2025/11/28 02:46:44 DEBUG : Looking for writers 2025/11/28 02:46:44 DEBUG : file1: reading active writers 2025/11/28 02:46:44 DEBUG : file2: reading active writers 2025/11/28 02:46:44 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms 2025/11/28 02:46:44 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:46:44 DEBUG : file2: vfs cache: starting upload 2025/11/28 02:46:44 DEBUG : Looking for writers 2025/11/28 02:46:44 DEBUG : file1: reading active writers 2025/11/28 02:46:44 DEBUG : file2: reading active writers 2025/11/28 02:46:44 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms 2025/11/28 02:46:44 DEBUG : Looking for writers 2025/11/28 02:46:44 DEBUG : file1: reading active writers 2025/11/28 02:46:44 DEBUG : file2: reading active writers 2025/11/28 02:46:44 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms 2025/11/28 02:46:45 DEBUG : Looking for writers 2025/11/28 02:46:45 DEBUG : file2: reading active writers 2025/11/28 02:46:45 DEBUG : file1: reading active writers 2025/11/28 02:46:45 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms 2025/11/28 02:46:45 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:45 ERROR : file1: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:45 ERROR : file2: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:45 ERROR : file2: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:45 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:46:45 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:45 ERROR : file1: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:45 DEBUG : file2: vfs cache: starting upload 2025/11/28 02:46:45 ERROR : file2: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:45 ERROR : file2: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:45 DEBUG : Looking for writers 2025/11/28 02:46:45 DEBUG : file1: reading active writers 2025/11/28 02:46:45 DEBUG : file2: reading active writers 2025/11/28 02:46:45 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:46:46 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:46:46 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:46 ERROR : file1: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:46 DEBUG : file2: vfs cache: starting upload 2025/11/28 02:46:46 ERROR : file2: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:46 ERROR : file2: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:46 DEBUG : Looking for writers 2025/11/28 02:46:46 DEBUG : file1: reading active writers 2025/11/28 02:46:46 DEBUG : file2: reading active writers 2025/11/28 02:46:46 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:46:47 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:46:47 DEBUG : file2: vfs cache: starting upload 2025/11/28 02:46:47 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:47 ERROR : file1: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:47 ERROR : file2: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:47 ERROR : file2: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:47 DEBUG : Looking for writers 2025/11/28 02:46:47 DEBUG : file2: reading active writers 2025/11/28 02:46:47 DEBUG : file1: reading active writers 2025/11/28 02:46:47 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:46:48 DEBUG : Looking for writers 2025/11/28 02:46:48 DEBUG : file1: reading active writers 2025/11/28 02:46:48 DEBUG : file2: reading active writers 2025/11/28 02:46:48 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:46:48 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:46:49 DEBUG : file2: vfs cache: starting upload 2025/11/28 02:46:49 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:49 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:49 ERROR : file2: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:49 ERROR : file2: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:49 DEBUG : Looking for writers 2025/11/28 02:46:49 DEBUG : file1: reading active writers 2025/11/28 02:46:49 DEBUG : file2: reading active writers 2025/11/28 02:46:49 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:46:50 DEBUG : Looking for writers 2025/11/28 02:46:50 DEBUG : file1: reading active writers 2025/11/28 02:46:50 DEBUG : file2: reading active writers 2025/11/28 02:46:50 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:46:51 DEBUG : Looking for writers 2025/11/28 02:46:51 DEBUG : file1: reading active writers 2025/11/28 02:46:51 DEBUG : file2: reading active writers 2025/11/28 02:46:51 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:46:52 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:46:52 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:52 ERROR : file1: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:52 DEBUG : file2: vfs cache: starting upload 2025/11/28 02:46:52 ERROR : file2: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:52 ERROR : file2: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:52 DEBUG : Looking for writers 2025/11/28 02:46:52 DEBUG : file1: reading active writers 2025/11/28 02:46:52 DEBUG : file2: reading active writers 2025/11/28 02:46:52 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:46:53 DEBUG : Looking for writers 2025/11/28 02:46:53 DEBUG : file2: reading active writers 2025/11/28 02:46:53 DEBUG : file1: reading active writers 2025/11/28 02:46:53 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:46:54 DEBUG : Looking for writers 2025/11/28 02:46:54 DEBUG : file1: reading active writers 2025/11/28 02:46:54 DEBUG : file2: reading active writers 2025/11/28 02:46:54 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:46:55 DEBUG : Looking for writers 2025/11/28 02:46:55 DEBUG : file1: reading active writers 2025/11/28 02:46:55 DEBUG : file2: reading active writers 2025/11/28 02:46:55 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:46:56 DEBUG : Looking for writers 2025/11/28 02:46:56 DEBUG : file1: reading active writers 2025/11/28 02:46:56 DEBUG : file2: reading active writers 2025/11/28 02:46:56 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:46:57 DEBUG : Looking for writers 2025/11/28 02:46:57 DEBUG : file1: reading active writers 2025/11/28 02:46:57 DEBUG : file2: reading active writers 2025/11/28 02:46:57 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:46:58 DEBUG : Looking for writers 2025/11/28 02:46:58 DEBUG : file1: reading active writers 2025/11/28 02:46:58 DEBUG : file2: reading active writers 2025/11/28 02:46:58 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:46:58 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:46:59 DEBUG : file2: vfs cache: starting upload 2025/11/28 02:46:59 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:59 ERROR : file1: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:59 ERROR : file2: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:59 ERROR : file2: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:46:59 DEBUG : Looking for writers 2025/11/28 02:46:59 DEBUG : file1: reading active writers 2025/11/28 02:46:59 DEBUG : file2: reading active writers 2025/11/28 02:46:59 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:00 DEBUG : Looking for writers 2025/11/28 02:47:00 DEBUG : file2: reading active writers 2025/11/28 02:47:00 DEBUG : file1: reading active writers 2025/11/28 02:47:00 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:01 DEBUG : Looking for writers 2025/11/28 02:47:01 DEBUG : file2: reading active writers 2025/11/28 02:47:01 DEBUG : file1: reading active writers 2025/11/28 02:47:01 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:02 DEBUG : Looking for writers 2025/11/28 02:47:02 DEBUG : file1: reading active writers 2025/11/28 02:47:02 DEBUG : file2: reading active writers 2025/11/28 02:47:02 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:03 DEBUG : Looking for writers 2025/11/28 02:47:03 DEBUG : file1: reading active writers 2025/11/28 02:47:03 DEBUG : file2: reading active writers 2025/11/28 02:47:03 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:04 DEBUG : Looking for writers 2025/11/28 02:47:04 DEBUG : file1: reading active writers 2025/11/28 02:47:04 DEBUG : file2: reading active writers 2025/11/28 02:47:04 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:05 DEBUG : Looking for writers 2025/11/28 02:47:05 DEBUG : file1: reading active writers 2025/11/28 02:47:05 DEBUG : file2: reading active writers 2025/11/28 02:47:05 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:06 DEBUG : Looking for writers 2025/11/28 02:47:06 DEBUG : file1: reading active writers 2025/11/28 02:47:06 DEBUG : file2: reading active writers 2025/11/28 02:47:06 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:07 DEBUG : Looking for writers 2025/11/28 02:47:07 DEBUG : file1: reading active writers 2025/11/28 02:47:07 DEBUG : file2: reading active writers 2025/11/28 02:47:07 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:08 DEBUG : Looking for writers 2025/11/28 02:47:08 DEBUG : file1: reading active writers 2025/11/28 02:47:08 DEBUG : file2: reading active writers 2025/11/28 02:47:08 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:09 DEBUG : Looking for writers 2025/11/28 02:47:09 DEBUG : file1: reading active writers 2025/11/28 02:47:09 DEBUG : file2: reading active writers 2025/11/28 02:47:09 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:10 DEBUG : Looking for writers 2025/11/28 02:47:10 DEBUG : file1: reading active writers 2025/11/28 02:47:10 DEBUG : file2: reading active writers 2025/11/28 02:47:10 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:11 DEBUG : Looking for writers 2025/11/28 02:47:11 DEBUG : file1: reading active writers 2025/11/28 02:47:11 DEBUG : file2: reading active writers 2025/11/28 02:47:11 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:12 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:47:12 DEBUG : file2: vfs cache: starting upload 2025/11/28 02:47:12 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:47:12 ERROR : file1: vfs cache: failed to upload try #8, will retry in 25.6s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:47:12 DEBUG : Looking for writers 2025/11/28 02:47:12 DEBUG : file1: reading active writers 2025/11/28 02:47:12 DEBUG : file2: reading active writers 2025/11/28 02:47:12 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:13 ERROR : file2: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:47:13 ERROR : file2: vfs cache: failed to upload try #8, will retry in 25.6s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:47:13 DEBUG : Looking for writers 2025/11/28 02:47:13 DEBUG : file1: reading active writers 2025/11/28 02:47:13 DEBUG : file2: reading active writers 2025/11/28 02:47:13 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:14 ERROR : Exiting even though 0 writers active and 2 cache items in use after 30s Cache{ "file2": &{c:0xc0007cd950 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc0001e7b08 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824635718464} name:file2 opens:0 downloaders: o: fd: info:{ModTime:{wall:13997857403986339552 ext:192670486254 loc:0x42a0c60} ATime:{wall:13997857403986558153 ext:192670704856 loc:0x42a0c60} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2 pendingAccesses:0 modified:false beingReset:false}, "file1": &{c:0xc0007cd950 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc000604808 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824640030784} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13997857403985127738 ext:192669274440 loc:0x42a0c60} ATime:{wall:13997857403985392035 ext:192669538738 loc:0x42a0c60} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2025/11/28 02:47:14 DEBUG : >WaitForWriters: fstest.go:298: Sleeping for 1s for list eventual consistency: 1/5 fstest.go:298: Sleeping for 2s for list eventual consistency: 2/5 fstest.go:298: Sleeping for 4s for list eventual consistency: 3/5 fstest.go:298: Sleeping for 8s for list eventual consistency: 4/5 fstest.go:298: Sleeping for 16s for list eventual consistency: 5/5 2025/11/28 02:47:38 DEBUG : file1: vfs cache: starting upload 2025/11/28 02:47:38 DEBUG : file2: vfs cache: starting upload 2025/11/28 02:47:38 ERROR : file1: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:47:38 ERROR : file1: vfs cache: failed to upload try #9, will retry in 51.2s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:47:39 ERROR : file2: Failed to copy: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:47:39 ERROR : file2: vfs cache: failed to upload try #9, will retry in 51.2s: vfs cache: failed to transfer file from cache to remote: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:47:44 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file2 not removed, freed 0 bytes 2025/11/28 02:47:44 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2025/11/28 02:47:44 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 2 (was 2) in use 2, to upload 2, uploading 0, total size 0 (was 0) 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:420 Error: Should be true Test: TestRWFileHandleWriteNoWrite Messages: listing wrong, want file1 (0), file2 (0) got fstest.go:203: Not found "file1" fstest.go:203: Not found "file2" 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:420 Error: Not equal: expected: 0 actual : 2 Test: TestRWFileHandleWriteNoWrite Messages: 2 objects not found 2025/11/28 02:47:45 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:47:45 DEBUG : Looking for writers 2025/11/28 02:47:45 DEBUG : file1: reading active writers 2025/11/28 02:47:45 DEBUG : file2: reading active writers 2025/11/28 02:47:45 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms 2025/11/28 02:47:45 DEBUG : Looking for writers 2025/11/28 02:47:45 DEBUG : file1: reading active writers 2025/11/28 02:47:45 DEBUG : file2: reading active writers 2025/11/28 02:47:45 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms 2025/11/28 02:47:45 DEBUG : Looking for writers 2025/11/28 02:47:45 DEBUG : file1: reading active writers 2025/11/28 02:47:45 DEBUG : file2: reading active writers 2025/11/28 02:47:45 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms 2025/11/28 02:47:45 DEBUG : Looking for writers 2025/11/28 02:47:45 DEBUG : file2: reading active writers 2025/11/28 02:47:45 DEBUG : file1: reading active writers 2025/11/28 02:47:45 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms 2025/11/28 02:47:45 DEBUG : Looking for writers 2025/11/28 02:47:45 DEBUG : file1: reading active writers 2025/11/28 02:47:45 DEBUG : file2: reading active writers 2025/11/28 02:47:45 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms 2025/11/28 02:47:45 DEBUG : Looking for writers 2025/11/28 02:47:45 DEBUG : file1: reading active writers 2025/11/28 02:47:45 DEBUG : file2: reading active writers 2025/11/28 02:47:45 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms 2025/11/28 02:47:46 DEBUG : Looking for writers 2025/11/28 02:47:46 DEBUG : file2: reading active writers 2025/11/28 02:47:46 DEBUG : file1: reading active writers 2025/11/28 02:47:46 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms 2025/11/28 02:47:46 DEBUG : Looking for writers 2025/11/28 02:47:46 DEBUG : file1: reading active writers 2025/11/28 02:47:46 DEBUG : file2: reading active writers 2025/11/28 02:47:46 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:47 DEBUG : Looking for writers 2025/11/28 02:47:47 DEBUG : file1: reading active writers 2025/11/28 02:47:47 DEBUG : file2: reading active writers 2025/11/28 02:47:47 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:48 DEBUG : Looking for writers 2025/11/28 02:47:48 DEBUG : file1: reading active writers 2025/11/28 02:47:48 DEBUG : file2: reading active writers 2025/11/28 02:47:48 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:49 DEBUG : Looking for writers 2025/11/28 02:47:49 DEBUG : file1: reading active writers 2025/11/28 02:47:49 DEBUG : file2: reading active writers 2025/11/28 02:47:49 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:50 DEBUG : Looking for writers 2025/11/28 02:47:50 DEBUG : file1: reading active writers 2025/11/28 02:47:50 DEBUG : file2: reading active writers 2025/11/28 02:47:50 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:51 DEBUG : Looking for writers 2025/11/28 02:47:51 DEBUG : file1: reading active writers 2025/11/28 02:47:51 DEBUG : file2: reading active writers 2025/11/28 02:47:51 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:52 DEBUG : Looking for writers 2025/11/28 02:47:52 DEBUG : file1: reading active writers 2025/11/28 02:47:52 DEBUG : file2: reading active writers 2025/11/28 02:47:52 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:53 DEBUG : Looking for writers 2025/11/28 02:47:53 DEBUG : file1: reading active writers 2025/11/28 02:47:53 DEBUG : file2: reading active writers 2025/11/28 02:47:53 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:54 DEBUG : Looking for writers 2025/11/28 02:47:54 DEBUG : file1: reading active writers 2025/11/28 02:47:54 DEBUG : file2: reading active writers 2025/11/28 02:47:54 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:55 DEBUG : Looking for writers 2025/11/28 02:47:55 DEBUG : file1: reading active writers 2025/11/28 02:47:55 DEBUG : file2: reading active writers 2025/11/28 02:47:55 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:56 DEBUG : Looking for writers 2025/11/28 02:47:56 DEBUG : file1: reading active writers 2025/11/28 02:47:56 DEBUG : file2: reading active writers 2025/11/28 02:47:56 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:57 DEBUG : Looking for writers 2025/11/28 02:47:57 DEBUG : file1: reading active writers 2025/11/28 02:47:57 DEBUG : file2: reading active writers 2025/11/28 02:47:57 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:58 DEBUG : Looking for writers 2025/11/28 02:47:58 DEBUG : file1: reading active writers 2025/11/28 02:47:58 DEBUG : file2: reading active writers 2025/11/28 02:47:58 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:47:59 DEBUG : Looking for writers 2025/11/28 02:47:59 DEBUG : file1: reading active writers 2025/11/28 02:47:59 DEBUG : file2: reading active writers 2025/11/28 02:47:59 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:48:00 DEBUG : Looking for writers 2025/11/28 02:48:00 DEBUG : file1: reading active writers 2025/11/28 02:48:00 DEBUG : file2: reading active writers 2025/11/28 02:48:00 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:48:01 DEBUG : Looking for writers 2025/11/28 02:48:01 DEBUG : file1: reading active writers 2025/11/28 02:48:01 DEBUG : file2: reading active writers 2025/11/28 02:48:01 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:48:02 DEBUG : Looking for writers 2025/11/28 02:48:02 DEBUG : file1: reading active writers 2025/11/28 02:48:02 DEBUG : file2: reading active writers 2025/11/28 02:48:02 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:48:03 DEBUG : Looking for writers 2025/11/28 02:48:03 DEBUG : file1: reading active writers 2025/11/28 02:48:03 DEBUG : file2: reading active writers 2025/11/28 02:48:03 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:48:04 DEBUG : Looking for writers 2025/11/28 02:48:04 DEBUG : file1: reading active writers 2025/11/28 02:48:04 DEBUG : file2: reading active writers 2025/11/28 02:48:04 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:48:05 DEBUG : Looking for writers 2025/11/28 02:48:05 DEBUG : file1: reading active writers 2025/11/28 02:48:05 DEBUG : file2: reading active writers 2025/11/28 02:48:05 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:48:06 DEBUG : Looking for writers 2025/11/28 02:48:06 DEBUG : file2: reading active writers 2025/11/28 02:48:06 DEBUG : file1: reading active writers 2025/11/28 02:48:06 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:48:07 DEBUG : Looking for writers 2025/11/28 02:48:07 DEBUG : file1: reading active writers 2025/11/28 02:48:07 DEBUG : file2: reading active writers 2025/11/28 02:48:07 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:48:08 DEBUG : Looking for writers 2025/11/28 02:48:08 DEBUG : file1: reading active writers 2025/11/28 02:48:08 DEBUG : file2: reading active writers 2025/11/28 02:48:08 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:48:09 DEBUG : Looking for writers 2025/11/28 02:48:09 DEBUG : file1: reading active writers 2025/11/28 02:48:09 DEBUG : file2: reading active writers 2025/11/28 02:48:09 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:48:10 DEBUG : Looking for writers 2025/11/28 02:48:10 DEBUG : file2: reading active writers 2025/11/28 02:48:10 DEBUG : file1: reading active writers 2025/11/28 02:48:10 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:48:11 DEBUG : Looking for writers 2025/11/28 02:48:11 DEBUG : file1: reading active writers 2025/11/28 02:48:11 DEBUG : file2: reading active writers 2025/11/28 02:48:11 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:48:12 DEBUG : Looking for writers 2025/11/28 02:48:12 DEBUG : file1: reading active writers 2025/11/28 02:48:12 DEBUG : file2: reading active writers 2025/11/28 02:48:12 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:48:13 DEBUG : Looking for writers 2025/11/28 02:48:13 DEBUG : file1: reading active writers 2025/11/28 02:48:13 DEBUG : file2: reading active writers 2025/11/28 02:48:13 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:48:14 DEBUG : Looking for writers 2025/11/28 02:48:14 DEBUG : file1: reading active writers 2025/11/28 02:48:14 DEBUG : file2: reading active writers 2025/11/28 02:48:14 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2025/11/28 02:48:15 ERROR : Exiting even though 0 writers active and 2 cache items in use after 30s Cache{ "file2": &{c:0xc0007cd950 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc0001e7b08 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824635718464} name:file2 opens:0 downloaders: o: fd: info:{ModTime:{wall:13997857403986339552 ext:192670486254 loc:0x42a0c60} ATime:{wall:13997857403986558153 ext:192670704856 loc:0x42a0c60} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2 pendingAccesses:0 modified:false beingReset:false}, "file1": &{c:0xc0007cd950 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc000604808 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824640030784} name:file1 opens:0 downloaders: o: fd: info:{ModTime:{wall:13997857403985127738 ext:192669274440 loc:0x42a0c60} ATime:{wall:13997857403985392035 ext:192669538738 loc:0x42a0c60} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 modified:false beingReset:false}, } 2025/11/28 02:48:15 DEBUG : >WaitForWriters: --- FAIL: TestRWFileHandleWriteNoWrite (91.02s) 2025/11/28 02:48:15 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaner exiting === RUN TestRWFileHandleSizeTruncateExisting run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:48:15 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:48:15 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: root is "/home/rclone/.cache/rclone" 2025/11/28 02:48:15 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:15 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:15 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:15 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:48:15 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:15 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:15 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:48:15 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:15 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:48:16 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:48:16 DEBUG : Looking for writers 2025/11/28 02:48:16 DEBUG : >WaitForWriters: --- FAIL: TestRWFileHandleSizeTruncateExisting (0.56s) 2025/11/28 02:48:16 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaner exiting === RUN TestRWFileHandleSizeCreateExisting run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:48:16 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:48:16 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: root is "/home/rclone/.cache/rclone" 2025/11/28 02:48:16 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:16 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:16 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:16 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:48:16 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:16 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:16 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:48:16 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:16 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:48:16 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:48:16 DEBUG : Looking for writers 2025/11/28 02:48:16 DEBUG : >WaitForWriters: --- FAIL: TestRWFileHandleSizeCreateExisting (0.19s) 2025/11/28 02:48:16 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaner exiting === RUN TestRWFileModTimeWithOpenWriters run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:48:16 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:48:16 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: root is "/home/rclone/.cache/rclone" 2025/11/28 02:48:16 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:16 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:16 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:16 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:48:16 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:16 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:16 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:48:16 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:16 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/11/28 02:48:16 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/11/28 02:48:16 DEBUG : file1: newRWFileHandle: 2025/11/28 02:48:16 DEBUG : file1(0xc000883200): openPending: 2025/11/28 02:48:16 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2025/11/28 02:48:16 DEBUG : file1: vfs cache: truncate to size=0 (not needed as size correct) 2025/11/28 02:48:16 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 1 (was 1) in use 1, to upload 0, uploading 0, total size 0 (was 0) 2025/11/28 02:48:16 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:48:16 DEBUG : file1(0xc000883200): >openPending: err= 2025/11/28 02:48:16 DEBUG : file1: >newRWFileHandle: err= 2025/11/28 02:48:16 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:48:16 DEBUG : file1: >Open: fd=file1 (rw), err= 2025/11/28 02:48:16 DEBUG : file1: >OpenFile: fd=file1 (rw), err= run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:48:16 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:48:16 DEBUG : Looking for writers 2025/11/28 02:48:16 DEBUG : file1: reading active writers 2025/11/28 02:48:16 DEBUG : file1: active writers 1 2025/11/28 02:48:16 DEBUG : Still 1 writers active and 1 cache items in use, waiting 10ms 2025/11/28 02:48:16 DEBUG : Looking for writers 2025/11/28 02:48:16 DEBUG : file1: reading active writers 2025/11/28 02:48:16 DEBUG : file1: active writers 1 2025/11/28 02:48:16 DEBUG : Still 1 writers active and 1 cache items in use, waiting 20ms 2025/11/28 02:48:16 DEBUG : Looking for writers 2025/11/28 02:48:16 DEBUG : file1: reading active writers 2025/11/28 02:48:16 DEBUG : file1: active writers 1 2025/11/28 02:48:16 DEBUG : Still 1 writers active and 1 cache items in use, waiting 40ms 2025/11/28 02:48:16 DEBUG : Looking for writers 2025/11/28 02:48:16 DEBUG : file1: reading active writers 2025/11/28 02:48:16 DEBUG : file1: active writers 1 2025/11/28 02:48:16 DEBUG : Still 1 writers active and 1 cache items in use, waiting 80ms 2025/11/28 02:48:16 DEBUG : Looking for writers 2025/11/28 02:48:16 DEBUG : file1: reading active writers 2025/11/28 02:48:16 DEBUG : file1: active writers 1 2025/11/28 02:48:16 DEBUG : Still 1 writers active and 1 cache items in use, waiting 160ms 2025/11/28 02:48:16 DEBUG : Looking for writers 2025/11/28 02:48:16 DEBUG : file1: reading active writers 2025/11/28 02:48:16 DEBUG : file1: active writers 1 2025/11/28 02:48:16 DEBUG : Still 1 writers active and 1 cache items in use, waiting 320ms 2025/11/28 02:48:17 DEBUG : Looking for writers 2025/11/28 02:48:17 DEBUG : file1: reading active writers 2025/11/28 02:48:17 DEBUG : file1: active writers 1 2025/11/28 02:48:17 DEBUG : Still 1 writers active and 1 cache items in use, waiting 640ms 2025/11/28 02:48:17 DEBUG : Looking for writers 2025/11/28 02:48:17 DEBUG : file1: reading active writers 2025/11/28 02:48:17 DEBUG : file1: active writers 1 2025/11/28 02:48:17 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:18 DEBUG : Looking for writers 2025/11/28 02:48:18 DEBUG : file1: reading active writers 2025/11/28 02:48:18 DEBUG : file1: active writers 1 2025/11/28 02:48:18 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:19 DEBUG : Looking for writers 2025/11/28 02:48:19 DEBUG : file1: reading active writers 2025/11/28 02:48:19 DEBUG : file1: active writers 1 2025/11/28 02:48:19 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:20 DEBUG : Looking for writers 2025/11/28 02:48:20 DEBUG : file1: reading active writers 2025/11/28 02:48:20 DEBUG : file1: active writers 1 2025/11/28 02:48:20 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:21 DEBUG : Looking for writers 2025/11/28 02:48:21 DEBUG : file1: reading active writers 2025/11/28 02:48:21 DEBUG : file1: active writers 1 2025/11/28 02:48:21 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:22 DEBUG : Looking for writers 2025/11/28 02:48:22 DEBUG : file1: reading active writers 2025/11/28 02:48:22 DEBUG : file1: active writers 1 2025/11/28 02:48:22 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:23 DEBUG : Looking for writers 2025/11/28 02:48:23 DEBUG : file1: reading active writers 2025/11/28 02:48:23 DEBUG : file1: active writers 1 2025/11/28 02:48:23 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:24 DEBUG : Looking for writers 2025/11/28 02:48:24 DEBUG : file1: reading active writers 2025/11/28 02:48:24 DEBUG : file1: active writers 1 2025/11/28 02:48:24 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:25 DEBUG : Looking for writers 2025/11/28 02:48:25 DEBUG : file1: reading active writers 2025/11/28 02:48:25 DEBUG : file1: active writers 1 2025/11/28 02:48:25 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:26 DEBUG : Looking for writers 2025/11/28 02:48:26 DEBUG : file1: reading active writers 2025/11/28 02:48:26 DEBUG : file1: active writers 1 2025/11/28 02:48:26 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:27 DEBUG : Looking for writers 2025/11/28 02:48:27 DEBUG : file1: reading active writers 2025/11/28 02:48:27 DEBUG : file1: active writers 1 2025/11/28 02:48:27 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:28 DEBUG : Looking for writers 2025/11/28 02:48:28 DEBUG : file1: reading active writers 2025/11/28 02:48:28 DEBUG : file1: active writers 1 2025/11/28 02:48:28 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:29 DEBUG : Looking for writers 2025/11/28 02:48:29 DEBUG : file1: reading active writers 2025/11/28 02:48:29 DEBUG : file1: active writers 1 2025/11/28 02:48:29 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:30 DEBUG : Looking for writers 2025/11/28 02:48:30 DEBUG : file1: reading active writers 2025/11/28 02:48:30 DEBUG : file1: active writers 1 2025/11/28 02:48:30 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:31 DEBUG : Looking for writers 2025/11/28 02:48:31 DEBUG : file1: reading active writers 2025/11/28 02:48:31 DEBUG : file1: active writers 1 2025/11/28 02:48:31 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:32 DEBUG : Looking for writers 2025/11/28 02:48:32 DEBUG : file1: reading active writers 2025/11/28 02:48:32 DEBUG : file1: active writers 1 2025/11/28 02:48:32 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:33 DEBUG : Looking for writers 2025/11/28 02:48:33 DEBUG : file1: reading active writers 2025/11/28 02:48:33 DEBUG : file1: active writers 1 2025/11/28 02:48:33 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:34 DEBUG : Looking for writers 2025/11/28 02:48:34 DEBUG : file1: reading active writers 2025/11/28 02:48:34 DEBUG : file1: active writers 1 2025/11/28 02:48:34 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:35 DEBUG : Looking for writers 2025/11/28 02:48:35 DEBUG : file1: reading active writers 2025/11/28 02:48:35 DEBUG : file1: active writers 1 2025/11/28 02:48:35 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:36 DEBUG : Looking for writers 2025/11/28 02:48:36 DEBUG : file1: reading active writers 2025/11/28 02:48:36 DEBUG : file1: active writers 1 2025/11/28 02:48:36 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:37 DEBUG : Looking for writers 2025/11/28 02:48:37 DEBUG : file1: reading active writers 2025/11/28 02:48:37 DEBUG : file1: active writers 1 2025/11/28 02:48:37 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:38 DEBUG : Looking for writers 2025/11/28 02:48:38 DEBUG : file1: reading active writers 2025/11/28 02:48:38 DEBUG : file1: active writers 1 2025/11/28 02:48:38 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:39 DEBUG : Looking for writers 2025/11/28 02:48:39 DEBUG : file1: reading active writers 2025/11/28 02:48:39 DEBUG : file1: active writers 1 2025/11/28 02:48:39 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:40 DEBUG : Looking for writers 2025/11/28 02:48:40 DEBUG : file1: reading active writers 2025/11/28 02:48:40 DEBUG : file1: active writers 1 2025/11/28 02:48:40 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:41 DEBUG : Looking for writers 2025/11/28 02:48:41 DEBUG : file1: reading active writers 2025/11/28 02:48:41 DEBUG : file1: active writers 1 2025/11/28 02:48:41 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:42 DEBUG : Looking for writers 2025/11/28 02:48:42 DEBUG : file1: reading active writers 2025/11/28 02:48:42 DEBUG : file1: active writers 1 2025/11/28 02:48:42 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:43 DEBUG : Looking for writers 2025/11/28 02:48:43 DEBUG : file1: reading active writers 2025/11/28 02:48:43 DEBUG : file1: active writers 1 2025/11/28 02:48:43 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:44 DEBUG : Looking for writers 2025/11/28 02:48:44 DEBUG : file1: reading active writers 2025/11/28 02:48:44 DEBUG : file1: active writers 1 2025/11/28 02:48:44 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:45 DEBUG : Looking for writers 2025/11/28 02:48:45 DEBUG : file1: reading active writers 2025/11/28 02:48:45 DEBUG : file1: active writers 1 2025/11/28 02:48:45 DEBUG : Still 1 writers active and 1 cache items in use, waiting 1s 2025/11/28 02:48:46 ERROR : Exiting even though 1 writers active and 1 cache items in use after 30s Cache{ "file1": &{c:0xc000455590 mu:{_:{} mu:{state:0 sema:0}} cond:{noCopy:{} L:0xc00080f708 notify:{wait:0 notify:0 lock:0 head: tail:} checker:824642172736} name:file1 opens:1 downloaders: o: fd:0xc000682140 info:{ModTime:{wall:13997857502542494811 ext:284442393675 loc:0x42a0c60} ATime:{wall:13997857502542494811 ext:284442393675 loc:0x42a0c60} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:0 pendingAccesses:0 modified:true beingReset:false}, } 2025/11/28 02:48:46 DEBUG : >WaitForWriters: --- FAIL: TestRWFileModTimeWithOpenWriters (30.20s) 2025/11/28 02:48:46 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaner exiting === RUN TestRWCacheUpdate run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:48:46 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:48:46 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: root is "/home/rclone/.cache/rclone" 2025/11/28 02:48:46 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: data root is "/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:46 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: metadata root is "/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:46 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:46 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:48:46 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfs/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:46 DEBUG : Creating backend with remote ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:46 DEBUG : :local: detected overridden config - adding "{8un-i}" suffix to name 2025/11/28 02:48:46 DEBUG : fs cache: renaming cache item ":local,encoding='Slash,Dot',links=false:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" to be canonical ":local{8un-i}:/home/rclone/.cache/rclone/vfsMeta/TestB2/rclone-test-bogayoz7sina" 2025/11/28 02:48:46 INFO : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2025/11/28 02:48:46 DEBUG : forgetting directory cache run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:48:47 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:48:47 DEBUG : Looking for writers 2025/11/28 02:48:47 DEBUG : >WaitForWriters: --- FAIL: TestRWCacheUpdate (0.56s) 2025/11/28 02:48:47 DEBUG : B2 bucket rclone-test-bogayoz7sina: vfs cache: cleaner exiting === RUN TestCaseSensitivity run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) --- FAIL: TestCaseSensitivity (0.19s) === RUN TestUnicodeNormalization run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) --- FAIL: TestUnicodeNormalization (0.20s) === RUN TestVFSStat run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:48:47 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:48:47 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:48:47 DEBUG : Looking for writers 2025/11/28 02:48:47 DEBUG : >WaitForWriters: --- FAIL: TestVFSStat (0.20s) === RUN TestVFSStatParent run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:48:47 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:48:47 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:48:47 DEBUG : Looking for writers 2025/11/28 02:48:47 DEBUG : >WaitForWriters: --- FAIL: TestVFSStatParent (0.20s) === RUN TestVFSOpenFile run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:48:47 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:48:48 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:48:48 DEBUG : Looking for writers 2025/11/28 02:48:48 DEBUG : >WaitForWriters: --- FAIL: TestVFSOpenFile (0.27s) === RUN TestVFSRename run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:48:48 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:48:48 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:48:48 DEBUG : Looking for writers 2025/11/28 02:48:48 DEBUG : >WaitForWriters: --- FAIL: TestVFSRename (0.20s) === RUN TestWriteFileHandleMethods run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:48:48 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:48:48 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/11/28 02:48:48 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/11/28 02:48:48 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:48:48 DEBUG : file1: >Open: fd=file1 (w), err= 2025/11/28 02:48:48 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/11/28 02:48:48 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:48:48 ERROR : file1: WriteFileHandle: Read: Can't read and write to file without --vfs-cache-mode >= minimal 2025/11/28 02:48:48 ERROR : file1: WriteFileHandle: ReadAt: Can't read and write to file without --vfs-cache-mode >= minimal 2025/11/28 02:48:48 ERROR : file1: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes 2025/11/28 02:48:48 DEBUG : B2 bucket rclone-test-bogayoz7sina: File to upload is small (5 bytes), uploading instead of streaming 2025/11/28 02:48:48 ERROR : file1: WriteFileHandle.New Rcat failed: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:48:48 DEBUG : file1: Remove: 2025/11/28 02:48:48 DEBUG : Added virtual directory entry vDel: "file1" 2025/11/28 02:48:48 DEBUG : file1: >Remove: err= write_test.go:144: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:144 Error: Received unexpected error: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) Test: TestWriteFileHandleMethods dir_test.go:250: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:250 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:153 Error: Not equal: expected: []string{"file1,5,false"} actual : []string(nil) Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=1) { - (string) (len=13) "file1,5,false" -} +([]string) Test: TestWriteFileHandleMethods fstest.go:298: Sleeping for 1s for list eventual consistency: 1/5 fstest.go:298: Sleeping for 2s for list eventual consistency: 2/5 fstest.go:298: Sleeping for 4s for list eventual consistency: 3/5 fstest.go:298: Sleeping for 8s for list eventual consistency: 4/5 fstest.go:298: Sleeping for 16s for list eventual consistency: 5/5 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 2025/11/28 02:49:19 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/11/28 02:49:19 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/11/28 02:49:19 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:49:19 DEBUG : file1: >Open: fd=file1 (w), err= 2025/11/28 02:49:19 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/11/28 02:49:19 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:49:19 DEBUG : B2 bucket rclone-test-bogayoz7sina: File to upload is small (0 bytes), uploading instead of streaming 2025/11/28 02:49:20 ERROR : file1: WriteFileHandle.New Rcat failed: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:49:20 DEBUG : file1: Remove: 2025/11/28 02:49:20 DEBUG : Added virtual directory entry vDel: "file1" 2025/11/28 02:49:20 DEBUG : file1: >Remove: err= write_test.go:163: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:163 Error: Received unexpected error: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 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:164 Error: Not equal: expected: []string{"file1,5,false"} actual : []string(nil) Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=1) { - (string) (len=13) "file1,5,false" -} +([]string) Test: TestWriteFileHandleMethods 2025/11/28 02:49:20 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/11/28 02:49:20 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/11/28 02:49:20 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:49:20 DEBUG : file1: >Open: fd=file1 (w), err= 2025/11/28 02:49:20 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/11/28 02:49:20 DEBUG : Added virtual directory entry vAddFile: "file1" write_test.go:171: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:171 Error: Not equal: expected: *errors.errorString(&errors.errorString{s:"permission denied"}) actual : () Test: TestWriteFileHandleMethods 2025/11/28 02:49:20 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:49:20 DEBUG : Looking for writers 2025/11/28 02:49:20 DEBUG : file1: reading active writers 2025/11/28 02:49:20 DEBUG : file1: active writers 1 2025/11/28 02:49:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2025/11/28 02:49:20 DEBUG : Looking for writers 2025/11/28 02:49:20 DEBUG : file1: reading active writers 2025/11/28 02:49:20 DEBUG : file1: active writers 1 2025/11/28 02:49:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2025/11/28 02:49:20 DEBUG : Looking for writers 2025/11/28 02:49:20 DEBUG : file1: reading active writers 2025/11/28 02:49:20 DEBUG : file1: active writers 1 2025/11/28 02:49:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2025/11/28 02:49:20 DEBUG : Looking for writers 2025/11/28 02:49:20 DEBUG : file1: reading active writers 2025/11/28 02:49:20 DEBUG : file1: active writers 1 2025/11/28 02:49:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2025/11/28 02:49:20 DEBUG : Looking for writers 2025/11/28 02:49:20 DEBUG : file1: reading active writers 2025/11/28 02:49:20 DEBUG : file1: active writers 1 2025/11/28 02:49:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2025/11/28 02:49:20 DEBUG : Looking for writers 2025/11/28 02:49:20 DEBUG : file1: reading active writers 2025/11/28 02:49:20 DEBUG : file1: active writers 1 2025/11/28 02:49:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2025/11/28 02:49:20 DEBUG : Looking for writers 2025/11/28 02:49:20 DEBUG : file1: reading active writers 2025/11/28 02:49:20 DEBUG : file1: active writers 1 2025/11/28 02:49:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2025/11/28 02:49:21 DEBUG : Looking for writers 2025/11/28 02:49:21 DEBUG : file1: reading active writers 2025/11/28 02:49:21 DEBUG : file1: active writers 1 2025/11/28 02:49:21 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:22 DEBUG : Looking for writers 2025/11/28 02:49:22 DEBUG : file1: reading active writers 2025/11/28 02:49:22 DEBUG : file1: active writers 1 2025/11/28 02:49:22 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:23 DEBUG : Looking for writers 2025/11/28 02:49:23 DEBUG : file1: reading active writers 2025/11/28 02:49:23 DEBUG : file1: active writers 1 2025/11/28 02:49:23 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:24 DEBUG : Looking for writers 2025/11/28 02:49:24 DEBUG : file1: reading active writers 2025/11/28 02:49:24 DEBUG : file1: active writers 1 2025/11/28 02:49:24 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:25 DEBUG : Looking for writers 2025/11/28 02:49:25 DEBUG : file1: reading active writers 2025/11/28 02:49:25 DEBUG : file1: active writers 1 2025/11/28 02:49:25 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:26 DEBUG : Looking for writers 2025/11/28 02:49:26 DEBUG : file1: reading active writers 2025/11/28 02:49:26 DEBUG : file1: active writers 1 2025/11/28 02:49:26 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:27 DEBUG : Looking for writers 2025/11/28 02:49:27 DEBUG : file1: reading active writers 2025/11/28 02:49:27 DEBUG : file1: active writers 1 2025/11/28 02:49:27 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:28 DEBUG : Looking for writers 2025/11/28 02:49:28 DEBUG : file1: reading active writers 2025/11/28 02:49:28 DEBUG : file1: active writers 1 2025/11/28 02:49:28 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:29 DEBUG : Looking for writers 2025/11/28 02:49:29 DEBUG : file1: reading active writers 2025/11/28 02:49:29 DEBUG : file1: active writers 1 2025/11/28 02:49:29 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:30 DEBUG : Looking for writers 2025/11/28 02:49:30 DEBUG : file1: reading active writers 2025/11/28 02:49:30 DEBUG : file1: active writers 1 2025/11/28 02:49:30 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:31 DEBUG : Looking for writers 2025/11/28 02:49:31 DEBUG : file1: reading active writers 2025/11/28 02:49:31 DEBUG : file1: active writers 1 2025/11/28 02:49:31 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:32 DEBUG : Looking for writers 2025/11/28 02:49:32 DEBUG : file1: reading active writers 2025/11/28 02:49:32 DEBUG : file1: active writers 1 2025/11/28 02:49:32 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:33 DEBUG : Looking for writers 2025/11/28 02:49:33 DEBUG : file1: reading active writers 2025/11/28 02:49:33 DEBUG : file1: active writers 1 2025/11/28 02:49:33 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:34 DEBUG : Looking for writers 2025/11/28 02:49:34 DEBUG : file1: reading active writers 2025/11/28 02:49:34 DEBUG : file1: active writers 1 2025/11/28 02:49:34 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:35 DEBUG : Looking for writers 2025/11/28 02:49:35 DEBUG : file1: reading active writers 2025/11/28 02:49:35 DEBUG : file1: active writers 1 2025/11/28 02:49:35 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:36 DEBUG : Looking for writers 2025/11/28 02:49:36 DEBUG : file1: reading active writers 2025/11/28 02:49:36 DEBUG : file1: active writers 1 2025/11/28 02:49:36 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:37 DEBUG : Looking for writers 2025/11/28 02:49:37 DEBUG : file1: reading active writers 2025/11/28 02:49:37 DEBUG : file1: active writers 1 2025/11/28 02:49:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:38 DEBUG : Looking for writers 2025/11/28 02:49:38 DEBUG : file1: reading active writers 2025/11/28 02:49:38 DEBUG : file1: active writers 1 2025/11/28 02:49:38 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:39 DEBUG : Looking for writers 2025/11/28 02:49:39 DEBUG : file1: reading active writers 2025/11/28 02:49:39 DEBUG : file1: active writers 1 2025/11/28 02:49:39 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:40 DEBUG : Looking for writers 2025/11/28 02:49:40 DEBUG : file1: reading active writers 2025/11/28 02:49:40 DEBUG : file1: active writers 1 2025/11/28 02:49:40 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:41 DEBUG : Looking for writers 2025/11/28 02:49:41 DEBUG : file1: reading active writers 2025/11/28 02:49:41 DEBUG : file1: active writers 1 2025/11/28 02:49:41 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:42 DEBUG : Looking for writers 2025/11/28 02:49:42 DEBUG : file1: reading active writers 2025/11/28 02:49:42 DEBUG : file1: active writers 1 2025/11/28 02:49:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:43 DEBUG : Looking for writers 2025/11/28 02:49:43 DEBUG : file1: reading active writers 2025/11/28 02:49:43 DEBUG : file1: active writers 1 2025/11/28 02:49:43 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:44 DEBUG : Looking for writers 2025/11/28 02:49:44 DEBUG : file1: reading active writers 2025/11/28 02:49:44 DEBUG : file1: active writers 1 2025/11/28 02:49:44 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:45 DEBUG : Looking for writers 2025/11/28 02:49:45 DEBUG : file1: reading active writers 2025/11/28 02:49:45 DEBUG : file1: active writers 1 2025/11/28 02:49:45 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:46 DEBUG : Looking for writers 2025/11/28 02:49:46 DEBUG : file1: reading active writers 2025/11/28 02:49:46 DEBUG : file1: active writers 1 2025/11/28 02:49:46 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:47 DEBUG : Looking for writers 2025/11/28 02:49:47 DEBUG : file1: reading active writers 2025/11/28 02:49:47 DEBUG : file1: active writers 1 2025/11/28 02:49:47 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:48 DEBUG : Looking for writers 2025/11/28 02:49:48 DEBUG : file1: reading active writers 2025/11/28 02:49:48 DEBUG : file1: active writers 1 2025/11/28 02:49:48 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:49 DEBUG : Looking for writers 2025/11/28 02:49:49 DEBUG : file1: reading active writers 2025/11/28 02:49:49 DEBUG : file1: active writers 1 2025/11/28 02:49:49 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2025/11/28 02:49:50 ERROR : Exiting even though 1 writers active and 0 cache items in use after 30s Cache: 2025/11/28 02:49:50 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleMethods (61.80s) === RUN TestWriteFileHandleWriteAt run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:49:50 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:49:50 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/11/28 02:49:50 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/11/28 02:49:50 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:49:50 DEBUG : file1: >Open: fd=file1 (w), err= 2025/11/28 02:49:50 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/11/28 02:49:50 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:49:50 DEBUG : file1: waiting for in-sequence write to 100 for 1s 2025/11/28 02:49:51 DEBUG : file1: aborting in-sequence write wait, off=100 2025/11/28 02:49:51 DEBUG : file1: failed to wait for in-sequence write to 100 2025/11/28 02:49:51 ERROR : file1: WriteFileHandle.Write: can't seek in file without --vfs-cache-mode >= writes 2025/11/28 02:49:51 DEBUG : B2 bucket rclone-test-bogayoz7sina: File to upload is small (11 bytes), uploading instead of streaming 2025/11/28 02:49:51 ERROR : file1: WriteFileHandle.New Rcat failed: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:49:51 DEBUG : file1: Remove: 2025/11/28 02:49:51 DEBUG : Added virtual directory entry vDel: "file1" 2025/11/28 02:49:51 DEBUG : file1: >Remove: err= write_test.go:221: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:221 Error: Received unexpected error: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) Test: TestWriteFileHandleWriteAt 2025/11/28 02:49:51 ERROR : file1: WriteFileHandle.Write: error: Bad file descriptor dir_test.go:250: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:250 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:231 Error: Not equal: expected: []string{"file1,11,false"} actual : []string(nil) Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=1) { - (string) (len=14) "file1,11,false" -} +([]string) Test: TestWriteFileHandleWriteAt fstest.go:298: Sleeping for 1s for list eventual consistency: 1/5 fstest.go:298: Sleeping for 2s for list eventual consistency: 2/5 fstest.go:298: Sleeping for 4s for list eventual consistency: 3/5 fstest.go:298: Sleeping for 8s for list eventual consistency: 4/5 fstest.go:298: Sleeping for 16s for list eventual consistency: 5/5 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 2025/11/28 02:50:22 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:50:22 DEBUG : Looking for writers 2025/11/28 02:50:22 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleWriteAt (32.61s) === RUN TestWriteFileHandleFlush run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:50:22 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:50:22 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/11/28 02:50:22 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/11/28 02:50:22 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:50:22 DEBUG : file1: >Open: fd=file1 (w), err= 2025/11/28 02:50:22 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/11/28 02:50:22 DEBUG : file1: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions 2025/11/28 02:50:22 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:50:22 DEBUG : B2 bucket rclone-test-bogayoz7sina: File to upload is small (5 bytes), uploading instead of streaming 2025/11/28 02:50:23 ERROR : file1: WriteFileHandle.New Rcat failed: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:50:23 DEBUG : file1: Remove: 2025/11/28 02:50:23 DEBUG : Added virtual directory entry vDel: "file1" 2025/11/28 02:50:23 DEBUG : file1: >Remove: err= 2025/11/28 02:50:23 ERROR : file1: WriteFileHandle.Flush error: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) write_test.go:256: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:256 Error: Received unexpected error: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) Test: TestWriteFileHandleFlush 2025/11/28 02:50:23 DEBUG : file1: WriteFileHandle.Flush nothing to do dir_test.go:250: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/dir_test.go:250 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:267 Error: Not equal: expected: []string{"file1,5,false"} actual : []string(nil) Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=1) { - (string) (len=13) "file1,5,false" -} +([]string) Test: TestWriteFileHandleFlush 2025/11/28 02:50:23 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:50:23 DEBUG : Looking for writers 2025/11/28 02:50:23 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleFlush (0.56s) === RUN TestWriteFileHandleRelease run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:50:23 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:50:23 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/11/28 02:50:23 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/11/28 02:50:23 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:50:23 DEBUG : file1: >Open: fd=file1 (w), err= 2025/11/28 02:50:23 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/11/28 02:50:23 DEBUG : file1: WriteFileHandle.Release closing 2025/11/28 02:50:23 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:50:23 DEBUG : B2 bucket rclone-test-bogayoz7sina: File to upload is small (0 bytes), uploading instead of streaming 2025/11/28 02:50:23 ERROR : file1: WriteFileHandle.New Rcat failed: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:50:23 DEBUG : file1: Remove: 2025/11/28 02:50:23 DEBUG : Added virtual directory entry vDel: "file1" 2025/11/28 02:50:23 DEBUG : file1: >Remove: err= 2025/11/28 02:50:23 ERROR : file1: WriteFileHandle.Release error: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) write_test.go:279: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:279 Error: Received unexpected error: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) Test: TestWriteFileHandleRelease 2025/11/28 02:50:23 DEBUG : file1: WriteFileHandle.Release nothing to do 2025/11/28 02:50:23 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:50:23 DEBUG : Looking for writers 2025/11/28 02:50:23 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleRelease (0.21s) === RUN TestWriteFileModTimeWithOpenWriters run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:50:23 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:50:23 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/11/28 02:50:23 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/11/28 02:50:23 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:50:23 DEBUG : file1: >Open: fd=file1 (w), err= 2025/11/28 02:50:23 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/11/28 02:50:23 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:50:23 DEBUG : B2 bucket rclone-test-bogayoz7sina: File to upload is small (2 bytes), uploading instead of streaming 2025/11/28 02:50:23 ERROR : file1: WriteFileHandle.New Rcat failed: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:50:23 DEBUG : file1: Remove: 2025/11/28 02:50:23 DEBUG : Added virtual directory entry vDel: "file1" 2025/11/28 02:50:23 DEBUG : file1: >Remove: err= write_test.go:333: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:333 Error: Received unexpected error: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) Test: TestWriteFileModTimeWithOpenWriters 2025/11/28 02:50:23 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:50:23 DEBUG : Looking for writers 2025/11/28 02:50:23 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileModTimeWithOpenWriters (0.20s) === RUN TestFileReadAtZeroLength run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:50:23 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:50:23 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/11/28 02:50:23 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/11/28 02:50:23 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:50:23 DEBUG : file1: >Open: fd=file1 (w), err= 2025/11/28 02:50:23 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/11/28 02:50:23 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:50:23 DEBUG : B2 bucket rclone-test-bogayoz7sina: File to upload is small (0 bytes), uploading instead of streaming 2025/11/28 02:50:24 ERROR : file1: WriteFileHandle.New Rcat failed: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:50:24 DEBUG : file1: Remove: 2025/11/28 02:50:24 DEBUG : Added virtual directory entry vDel: "file1" 2025/11/28 02:50:24 DEBUG : file1: >Remove: err= write_test.go:360: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:360 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:380 Error: Received unexpected error: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) Test: TestFileReadAtZeroLength 2025/11/28 02:50:24 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2025/11/28 02:50:24 DEBUG : file1: >OpenFile: fd=, err=file does not exist write_test.go:365: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:365 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:380 Error: Received unexpected error: file does not exist Test: TestFileReadAtZeroLength 2025/11/28 02:50:24 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:50:24 DEBUG : Looking for writers 2025/11/28 02:50:24 DEBUG : >WaitForWriters: --- FAIL: TestFileReadAtZeroLength (0.25s) === RUN TestFileReadAtNonZeroLength run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:50:24 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote 2025/11/28 02:50:24 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/11/28 02:50:24 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/11/28 02:50:24 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:50:24 DEBUG : file1: >Open: fd=file1 (w), err= 2025/11/28 02:50:24 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/11/28 02:50:24 DEBUG : Added virtual directory entry vAddFile: "file1" 2025/11/28 02:50:24 DEBUG : B2 bucket rclone-test-bogayoz7sina: File to upload is small (100 bytes), uploading instead of streaming 2025/11/28 02:50:24 ERROR : file1: WriteFileHandle.New Rcat failed: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:50:24 DEBUG : file1: Remove: 2025/11/28 02:50:24 DEBUG : Added virtual directory entry vDel: "file1" 2025/11/28 02:50:24 DEBUG : file1: >Remove: err= write_test.go:360: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:360 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:384 Error: Received unexpected error: failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) Test: TestFileReadAtNonZeroLength 2025/11/28 02:50:24 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2025/11/28 02:50:24 DEBUG : file1: >OpenFile: fd=, err=file does not exist write_test.go:365: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:365 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:384 Error: Received unexpected error: file does not exist Test: TestFileReadAtNonZeroLength 2025/11/28 02:50:24 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:50:24 DEBUG : Looking for writers 2025/11/28 02:50:24 DEBUG : >WaitForWriters: --- FAIL: TestFileReadAtNonZeroLength (0.20s) === RUN TestZipManyFiles run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:50:24 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:50:24 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:50:24 DEBUG : Looking for writers 2025/11/28 02:50:24 DEBUG : >WaitForWriters: --- FAIL: TestZipManyFiles (0.20s) === RUN TestZipManySubDirs run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:50:24 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:50:24 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:50:24 DEBUG : Looking for writers 2025/11/28 02:50:24 DEBUG : >WaitForWriters: --- FAIL: TestZipManySubDirs (0.20s) === RUN TestZipLargeFiles run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:50:24 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:50:24 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:50:24 DEBUG : Looking for writers 2025/11/28 02:50:24 DEBUG : >WaitForWriters: --- FAIL: TestZipLargeFiles (0.27s) === RUN TestZipDirsInRoot run.go:185: Remote "B2 bucket rclone-test-bogayoz7sina", Local "Local file system at /tmp/rclone260528418", Modify Window "1ms" 2025/11/28 02:50:24 INFO : B2 bucket rclone-test-bogayoz7sina: poll-interval is not supported by this remote run.go:242: Failed to mkdir "B2 bucket rclone-test-bogayoz7sina": failed to create bucket: The account is already at the maximum bucket count (400 too_many_buckets) 2025/11/28 02:50:25 DEBUG : WaitForWriters: timeout=30s 2025/11/28 02:50:25 DEBUG : Looking for writers 2025/11/28 02:50:25 DEBUG : >WaitForWriters: --- FAIL: TestZipDirsInRoot (0.19s) FAIL 2025/11/28 02:50:25 DEBUG : B2 bucket rclone-test-bogayoz7sina: Purge remote 2025/11/28 02:50:25 INFO : B2 bucket rclone-test-bogayoz7sina: cleaning bucket "rclone-test-bogayoz7sina" of all files 2025/11/28 02:50:25 NOTICE: purge failed: directory not found "./vfs.test -test.v -test.timeout 1h0m0s -remote TestB2: -list-retries 5 -verbose -test.run '^(TestCaseSensitivity|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|TestFileReadAtZeroLength|TestFileRemove|TestFileRemoveAll|TestRWCacheUpdate|TestRWFileHandleFlushRead|TestRWFileHandleMethodsRead|TestRWFileHandleMethodsWrite|TestRWFileHandleReadAt|TestRWFileHandleReleaseRead|TestRWFileHandleSeek|TestRWFileHandleSizeCreateExisting|TestRWFileHandleSizeTruncateExisting|TestRWFileHandleWriteAt|TestRWFileHandleWriteNoWrite|TestRWFileModTimeWithOpenWriters|TestReadFileHandleFlush|TestReadFileHandleMethods|TestReadFileHandleReadAt|TestReadFileHandleRelease|TestReadFileHandleSeek|TestUnicodeNormalization|TestVFSOpenFile|TestVFSRename|TestVFSStat|TestVFSStatParent|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileHandleRelease|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 6m53.146785139s (try 3/5): exit status 1: Failed [TestDirHandleMethods TestDirHandleReaddir TestDirHandleReaddirnames TestDirMethods TestDirForgetAll TestDirForgetPath TestDirWalk TestDirSetModTime TestDirStat TestDirReadDirAll TestDirOpen TestDirCreate TestDirMkdir TestDirMkdirSub TestDirRemove TestDirRemoveAll TestDirRemoveName TestDirRename TestDirFileOpen TestDirMetadataExtension TestFileMethods TestFileSetModTime/cache=off,open=false,write=false TestFileSetModTime/cache=off,open=true,write=false TestFileSetModTime/cache=off,open=true,write=true TestFileSetModTime/cache=full,open=false,write=false TestFileSetModTime/cache=full,open=true,write=false TestFileSetModTime/cache=full,open=true,write=true TestFileOpenRead TestFileOpenWrite TestFileRemove TestFileRemoveAll TestFileOpen TestFileRename/off,forceCache=false TestFileRename/minimal,forceCache=false TestFileRename/minimal,forceCache=true TestFileRename/writes,forceCache=false TestFileRename/writes,forceCache=true TestFileRename/full,forceCache=false TestReadFileHandleMethods TestReadFileHandleSeek TestReadFileHandleReadAt TestReadFileHandleFlush TestReadFileHandleRelease TestRWFileHandleMethodsRead TestRWFileHandleSeek TestRWFileHandleReadAt TestRWFileHandleFlushRead TestRWFileHandleReleaseRead TestRWFileHandleMethodsWrite TestRWFileHandleWriteAt TestRWFileHandleWriteNoWrite TestRWFileHandleSizeTruncateExisting TestRWFileHandleSizeCreateExisting TestRWFileModTimeWithOpenWriters TestRWCacheUpdate TestCaseSensitivity TestUnicodeNormalization TestVFSStat TestVFSStatParent TestVFSOpenFile TestVFSRename TestWriteFileHandleMethods TestWriteFileHandleWriteAt TestWriteFileHandleFlush TestWriteFileHandleRelease TestWriteFileModTimeWithOpenWriters TestFileReadAtZeroLength TestFileReadAtNonZeroLength TestZipManyFiles TestZipManySubDirs TestZipLargeFiles TestZipDirsInRoot]