"./vfs.test -test.v -test.timeout 1h0m0s -remote TestQingStor: -verbose -test.run '^(TestCaseSensitivity|TestDirCreate|TestDirForgetAll|TestDirForgetPath|TestDirHandleMethods|TestDirHandleReaddir|TestDirHandleReaddirnames|TestDirMethods|TestDirMkdir|TestDirMkdirSub|TestDirOpen|TestDirReadDirAll|TestDirRemove|TestDirRemoveAll|TestDirRemoveName|TestDirRename|TestDirSetModTime|TestDirStat|TestDirWalk|TestFileMethods|TestFileOpen|TestFileOpenRead|TestFileOpenWrite|TestFileReadAtNonZeroLength|TestFileReadAtZeroLength|TestFileRemove|TestFileRemoveAll|TestFileRename|TestFileSetModTime|TestRWFileHandleFlushRead|TestRWFileHandleMethodsRead|TestRWFileHandleMethodsWrite|TestRWFileHandleReadAt|TestRWFileHandleReleaseRead|TestRWFileHandleSeek|TestRWFileHandleSizeCreateExisting|TestRWFileHandleSizeTruncateExisting|TestRWFileHandleWriteAt|TestRWFileHandleWriteNoWrite|TestRWFileModTimeWithOpenWriters|TestRcGetVFS|TestReadFileHandleFlush|TestReadFileHandleMethods|TestReadFileHandleReadAt|TestReadFileHandleRelease|TestReadFileHandleSeek|TestVFSNew|TestVFSOpenFile|TestVFSRename|TestVFSStat|TestVFSStatParent|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileHandleRelease|TestWriteFileHandleWriteAt|TestWriteFileModTimeWithOpenWriters)$/^(full,forceCache=false|minimal,forceCache=false|minimal,forceCache=true|off,forceCache=false|writes,forceCache=false|writes,forceCache=true)$'" - Starting (try 4/5) 2020/12/27 06:12:02 DEBUG : Creating backend with remote "TestQingStor:rclone-test-kodotij6tedopev1vuleyoq2" 2020/12/27 06:12:02 DEBUG : Creating backend with remote "/tmp/rclone588092388" === RUN TestDirHandleMethods run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:12:02 INFO : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: poll-interval is not supported by this remote 2020/12/27 06:12:02 NOTICE: QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "b97b4cc478fcee0e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirHandleMethods (6.15s) === RUN TestDirHandleReaddir run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:12:08 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "9e94ec08e33a97a0", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:12:13 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:12:13 DEBUG : : Looking for writers 2020/12/27 06:12:13 DEBUG : >WaitForWriters: --- FAIL: TestDirHandleReaddir (5.69s) === RUN TestDirHandleReaddirnames run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:12:13 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "1e5ed41637efc92f", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirHandleReaddirnames (5.50s) === RUN TestDirMethods run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:12:19 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "9472332cd4e91547", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirMethods (5.48s) === RUN TestDirForgetAll run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:12:24 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "350c43019790a3b0", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirForgetAll (5.49s) === RUN TestDirForgetPath run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:12:30 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "2570b67e71e4624f", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirForgetPath (5.49s) === RUN TestDirWalk run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:12:35 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "774a8d89a3ea63b1", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirWalk (5.49s) === RUN TestDirSetModTime run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:12:41 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "d4c73f02ec279ccc", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirSetModTime (5.48s) === RUN TestDirStat run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:12:46 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "599fe1499a0942c5", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirStat (5.89s) === RUN TestDirReadDirAll run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:12:52 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "6f20d3378f54662c", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:12:58 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:12:58 DEBUG : : Looking for writers 2020/12/27 06:12:58 DEBUG : >WaitForWriters: --- FAIL: TestDirReadDirAll (5.68s) === RUN TestDirOpen run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:12:58 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "2d3b4f80b6c9e18b", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirOpen (5.48s) === RUN TestDirCreate run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:13:03 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "c4cd23d84d4290d2", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirCreate (5.47s) === RUN TestDirMkdir run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:13:09 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "8dc9974c76f9160c", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirMkdir (5.47s) === RUN TestDirMkdirSub run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:13:14 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "7d88ef93de0a65e7", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirMkdirSub (5.49s) === RUN TestDirRemove run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:13:20 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "bf80f236ddec9873", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirRemove (5.49s) === RUN TestDirRemoveAll run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:13:25 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "b1c34e6e2f3b1810", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirRemoveAll (5.48s) === RUN TestDirRemoveName run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:13:31 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "431f82ef637c66eb", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirRemoveName (5.49s) === RUN TestDirRename run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:13:36 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "b524f2cee896345e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirRename (5.48s) === RUN TestFileMethods run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:13:42 INFO : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: poll-interval is not supported by this remote 2020/12/27 06:13:42 NOTICE: QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: --vfs-cache-mode writes or full is recommended for this remote as it can't stream run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "526c843499869a91", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestFileMethods (6.68s) === RUN TestFileSetModTime run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:13:48 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "7c7636c02c58a673", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestFileSetModTime (5.88s) === RUN TestFileOpenRead run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:13:54 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "767056025b41a0ac", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestFileOpenRead (6.28s) === RUN TestFileOpenWrite run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:14:01 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "23db792442e53db8", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestFileOpenWrite (5.48s) === RUN TestFileRemove run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:14:06 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "dff6d4135394c8c4", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestFileRemove (5.48s) === RUN TestFileRemoveAll run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:14:12 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "6fa2e2a70e1c5ee6", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestFileRemoveAll (5.47s) === RUN TestFileOpen run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:14:17 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "e61bf772ce71cee7", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestFileOpen (5.48s) === RUN TestFileRename === RUN TestFileRename/off,forceCache=false run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:14:23 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "ceea2278bae8f3b0", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" === RUN TestFileRename/minimal,forceCache=false run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:14:28 INFO : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: poll-interval is not supported by this remote 2020/12/27 06:14:28 NOTICE: QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2020/12/27 06:14:28 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestQingStor/rclone-test-kodotij6tedopev1vuleyoq2" 2020/12/27 06:14:28 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestQingStor/rclone-test-kodotij6tedopev1vuleyoq2" 2020/12/27 06:14:28 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestQingStor/rclone-test-kodotij6tedopev1vuleyoq2" 2020/12/27 06:14:28 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "c3bed581a9d9c881", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" === RUN TestFileRename/minimal,forceCache=true run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:14:34 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "4fa4430c7fcbe729", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" === RUN TestFileRename/writes,forceCache=false run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:14:39 INFO : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: poll-interval is not supported by this remote 2020/12/27 06:14:39 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestQingStor/rclone-test-kodotij6tedopev1vuleyoq2" 2020/12/27 06:14:39 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestQingStor/rclone-test-kodotij6tedopev1vuleyoq2" 2020/12/27 06:14:39 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "4b940ba6f3e3b81b", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" === RUN TestFileRename/writes,forceCache=true run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:14:45 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "2394470947310c1e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" === RUN TestFileRename/full,forceCache=false run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:14:50 INFO : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: poll-interval is not supported by this remote 2020/12/27 06:14:50 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestQingStor/rclone-test-kodotij6tedopev1vuleyoq2" 2020/12/27 06:14:50 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestQingStor/rclone-test-kodotij6tedopev1vuleyoq2" 2020/12/27 06:14:50 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "496b876b86d40605", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestFileRename (33.35s) --- FAIL: TestFileRename/off,forceCache=false (5.92s) --- FAIL: TestFileRename/minimal,forceCache=false (5.49s) --- FAIL: TestFileRename/minimal,forceCache=true (5.48s) --- FAIL: TestFileRename/writes,forceCache=false (5.49s) --- FAIL: TestFileRename/writes,forceCache=true (5.48s) --- FAIL: TestFileRename/full,forceCache=false (5.49s) === RUN TestRcGetVFS rc_test.go:29: Error Trace: rc_test.go:29 Error: "more than one VFS active - need \"fs\" parameter" does not contain "no VFS active" Test: TestRcGetVFS run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:14:56 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache rc_test.go:36: Error Trace: rc_test.go:36 Error: Received unexpected error: more than one VFS active - need "fs" parameter github.com/rclone/rclone/vfs.getVFS /home/rclone/go/src/github.com/rclone/rclone/vfs/rc.go:38 github.com/rclone/rclone/vfs.TestRcGetVFS /home/rclone/go/src/github.com/rclone/rclone/vfs/rc_test.go:35 testing.tRunner /usr/local/go/src/testing/testing.go:1123 runtime.goexit /usr/local/go/src/runtime/asm_amd64.s:1374 Test: TestRcGetVFS 2020/12/27 06:14:56 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:14:56 DEBUG : : Looking for writers 2020/12/27 06:14:56 DEBUG : >WaitForWriters: --- FAIL: TestRcGetVFS (0.20s) === RUN TestReadFileHandleMethods run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:14:56 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "0180d3465b5bd5e9", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestReadFileHandleMethods (5.48s) === RUN TestReadFileHandleSeek run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:15:02 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "5b05302223b3357d", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestReadFileHandleSeek (5.48s) === RUN TestReadFileHandleReadAt run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:15:07 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "1a39300ea0961e5b", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestReadFileHandleReadAt (5.48s) === RUN TestReadFileHandleFlush run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:15:12 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "d96b0d6aa76946a6", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestReadFileHandleFlush (5.49s) === RUN TestReadFileHandleRelease run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:15:18 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "ac0bc62d7b8daf97", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestReadFileHandleRelease (5.48s) === RUN TestRWFileHandleMethodsRead run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:15:23 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache 2020/12/27 06:15:28 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "91de305101f2e5ec", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestRWFileHandleMethodsRead (5.48s) === RUN TestRWFileHandleSeek run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:15:29 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "286066ba011af8f1", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestRWFileHandleSeek (5.48s) === RUN TestRWFileHandleReadAt run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:15:34 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache 2020/12/27 06:15:39 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "8464eda9d3429b3f", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestRWFileHandleReadAt (5.48s) === RUN TestRWFileHandleFlushRead run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:15:40 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "4703caf137668b19", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestRWFileHandleFlushRead (5.48s) === RUN TestRWFileHandleReleaseRead run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:15:45 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache 2020/12/27 06:15:50 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) run.go:234: Failed to mkdir "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "a02bef24be2f6d15", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestRWFileHandleReleaseRead (5.49s) === RUN TestRWFileHandleMethodsWrite run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:15:51 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache 2020/12/27 06:15:51 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/12/27 06:15:51 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/12/27 06:15:51 DEBUG : file1: newRWFileHandle: 2020/12/27 06:15:51 DEBUG : file1(0xc000624ac0): openPending: 2020/12/27 06:15:51 DEBUG : file1: vfs cache: truncate to size=0 2020/12/27 06:15:51 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:15:51 DEBUG : file1(0xc000624ac0): >openPending: err= 2020/12/27 06:15:51 DEBUG : file1: >newRWFileHandle: err= 2020/12/27 06:15:51 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:15:51 DEBUG : file1: >Open: fd=file1 (rw), err= 2020/12/27 06:15:51 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2020/12/27 06:15:51 DEBUG : file1(0xc000624ac0): _writeAt: size=5, off=0 2020/12/27 06:15:51 DEBUG : file1(0xc000624ac0): >_writeAt: n=5, err= 2020/12/27 06:15:51 DEBUG : file1(0xc000624ac0): _writeAt: size=7, off=5 2020/12/27 06:15:51 DEBUG : file1(0xc000624ac0): >_writeAt: n=7, err= 2020/12/27 06:15:51 DEBUG : file1: vfs cache: truncate to size=11 2020/12/27 06:15:51 DEBUG : file1(0xc000624ac0): close: 2020/12/27 06:15:51 DEBUG : file1: vfs cache: setting modification time to 2020-12-27 06:15:51.571344986 +0000 UTC m=+229.550621721 2020/12/27 06:15:51 INFO : file1: vfs cache: queuing for upload in 100ms 2020/12/27 06:15:51 DEBUG : file1(0xc000624ac0): >close: err= 2020/12/27 06:15:51 DEBUG : file1(0xc000624ac0): close: 2020/12/27 06:15:51 DEBUG : file1(0xc000624ac0): >close: err=file already closed 2020/12/27 06:15:51 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:15:51 DEBUG : : Looking for writers 2020/12/27 06:15:51 DEBUG : file1: reading active writers 2020/12/27 06:15:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2020/12/27 06:15:51 DEBUG : : Looking for writers 2020/12/27 06:15:51 DEBUG : file1: reading active writers 2020/12/27 06:15:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2020/12/27 06:15:51 DEBUG : : Looking for writers 2020/12/27 06:15:51 DEBUG : file1: reading active writers 2020/12/27 06:15:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2020/12/27 06:15:51 DEBUG : : Looking for writers 2020/12/27 06:15:51 DEBUG : file1: reading active writers 2020/12/27 06:15:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2020/12/27 06:15:51 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:15:51 DEBUG : : Looking for writers 2020/12/27 06:15:51 DEBUG : file1: reading active writers 2020/12/27 06:15:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2020/12/27 06:15:51 DEBUG : : Looking for writers 2020/12/27 06:15:51 DEBUG : file1: reading active writers 2020/12/27 06:15:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2020/12/27 06:15:52 DEBUG : : Looking for writers 2020/12/27 06:15:52 DEBUG : file1: reading active writers 2020/12/27 06:15:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2020/12/27 06:15:52 DEBUG : : Looking for writers 2020/12/27 06:15:52 DEBUG : file1: reading active writers 2020/12/27 06:15:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:15:53 DEBUG : : Looking for writers 2020/12/27 06:15:53 DEBUG : file1: reading active writers 2020/12/27 06:15:53 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:15:54 DEBUG : : Looking for writers 2020/12/27 06:15:54 DEBUG : file1: reading active writers 2020/12/27 06:15:54 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:15:55 DEBUG : : Looking for writers 2020/12/27 06:15:55 DEBUG : file1: reading active writers 2020/12/27 06:15:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:15:56 DEBUG : : Looking for writers 2020/12/27 06:15:56 DEBUG : file1: reading active writers 2020/12/27 06:15:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:15:57 ERROR : file1: Failed to copy: QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "a05490b162c854be", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:15:57 ERROR : file1: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "a05490b162c854be", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:15:57 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:15:57 DEBUG : : Looking for writers 2020/12/27 06:15:57 DEBUG : file1: reading active writers 2020/12/27 06:15:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:15:58 DEBUG : : Looking for writers 2020/12/27 06:15:58 DEBUG : file1: reading active writers 2020/12/27 06:15:58 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:15:59 DEBUG : : Looking for writers 2020/12/27 06:15:59 DEBUG : file1: reading active writers 2020/12/27 06:15:59 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:00 DEBUG : : Looking for writers 2020/12/27 06:16:00 DEBUG : file1: reading active writers 2020/12/27 06:16:00 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:01 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s Cache{ "file1": &{c:0xc0001ce300 mu:{state:0 sema:0} cond:0xc000624a80 name:file1 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13831160861584918618 ext:229550621721 loc:0x26d8980} ATime:{wall:13831160861584938522 ext:229550641591 loc:0x26d8980} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, } 2020/12/27 06:16:01 DEBUG : >WaitForWriters: fstest.go:297: Sleeping for 1s for list eventual consistency: 1/3 2020/12/27 06:16:02 ERROR : file1: Failed to copy: QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "f737a2ebc5885d64", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:02 ERROR : file1: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "f737a2ebc5885d64", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:03 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:16:03 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "4f5164a29cffaf98", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:03 ERROR : file1: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "4f5164a29cffaf98", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" fstest.go:297: Sleeping for 2s for list eventual consistency: 2/3 2020/12/27 06:16:04 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:16:04 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "cfaa32d1568c500f", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:04 ERROR : file1: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "cfaa32d1568c500f", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:06 DEBUG : file1: vfs cache: starting upload fstest.go:297: Sleeping for 4s for list eventual consistency: 3/3 2020/12/27 06:16:06 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "216f90cbc4287c4e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:06 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "216f90cbc4287c4e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:09 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:16:09 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "bdf8910848d4a88c", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:09 ERROR : file1: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "bdf8910848d4a88c", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" fstest.go:304: Error Trace: fstest.go:304 fstest.go:337 read_write_test.go:344 Error: Should be true Test: TestRWFileHandleMethodsWrite Messages: listing wrong, want file1 (11) got fstest.go:202: Not found "file1" fstest.go:205: Error Trace: fstest.go:205 fstest.go:309 fstest.go:337 read_write_test.go:344 Error: Not equal: expected: 0 actual : 1 Test: TestRWFileHandleMethodsWrite Messages: 1 objects not found 2020/12/27 06:16:10 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:16:10 DEBUG : : Looking for writers 2020/12/27 06:16:10 DEBUG : file1: reading active writers 2020/12/27 06:16:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2020/12/27 06:16:10 DEBUG : : Looking for writers 2020/12/27 06:16:10 DEBUG : file1: reading active writers 2020/12/27 06:16:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2020/12/27 06:16:10 DEBUG : : Looking for writers 2020/12/27 06:16:10 DEBUG : file1: reading active writers 2020/12/27 06:16:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2020/12/27 06:16:10 DEBUG : : Looking for writers 2020/12/27 06:16:10 DEBUG : file1: reading active writers 2020/12/27 06:16:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2020/12/27 06:16:10 DEBUG : : Looking for writers 2020/12/27 06:16:10 DEBUG : file1: reading active writers 2020/12/27 06:16:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2020/12/27 06:16:10 DEBUG : : Looking for writers 2020/12/27 06:16:10 DEBUG : file1: reading active writers 2020/12/27 06:16:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2020/12/27 06:16:10 DEBUG : : Looking for writers 2020/12/27 06:16:10 DEBUG : file1: reading active writers 2020/12/27 06:16:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2020/12/27 06:16:11 DEBUG : : Looking for writers 2020/12/27 06:16:11 DEBUG : file1: reading active writers 2020/12/27 06:16:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:12 DEBUG : : Looking for writers 2020/12/27 06:16:12 DEBUG : file1: reading active writers 2020/12/27 06:16:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:13 DEBUG : : Looking for writers 2020/12/27 06:16:13 DEBUG : file1: reading active writers 2020/12/27 06:16:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:14 DEBUG : : Looking for writers 2020/12/27 06:16:14 DEBUG : file1: reading active writers 2020/12/27 06:16:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:15 DEBUG : : Looking for writers 2020/12/27 06:16:15 DEBUG : file1: reading active writers 2020/12/27 06:16:15 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:16 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:16:16 DEBUG : : Looking for writers 2020/12/27 06:16:16 DEBUG : file1: reading active writers 2020/12/27 06:16:16 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:16 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "1bb8cfdf9f0010a7", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:16 ERROR : file1: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "1bb8cfdf9f0010a7", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:17 DEBUG : : Looking for writers 2020/12/27 06:16:17 DEBUG : file1: reading active writers 2020/12/27 06:16:17 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:18 DEBUG : : Looking for writers 2020/12/27 06:16:18 DEBUG : file1: reading active writers 2020/12/27 06:16:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:19 DEBUG : : Looking for writers 2020/12/27 06:16:19 DEBUG : file1: reading active writers 2020/12/27 06:16:19 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:20 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s Cache{ "file1": &{c:0xc0001ce300 mu:{state:0 sema:0} cond:0xc000624a80 name:file1 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13831160861584918618 ext:229550621721 loc:0x26d8980} ATime:{wall:13831160861584938522 ext:229550641591 loc:0x26d8980} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, } 2020/12/27 06:16:20 DEBUG : >WaitForWriters: --- FAIL: TestRWFileHandleMethodsWrite (28.93s) === RUN TestRWFileHandleWriteAt run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:16:20 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache 2020/12/27 06:16:20 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/12/27 06:16:20 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/12/27 06:16:20 DEBUG : file1: newRWFileHandle: 2020/12/27 06:16:20 DEBUG : file1(0xc000910440): openPending: 2020/12/27 06:16:20 ERROR : file1: vfs cache: detected external removal of cache file 2020/12/27 06:16:20 DEBUG : file1: vfs cache: truncate to size=0 2020/12/27 06:16:20 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:16:20 DEBUG : file1(0xc000910440): >openPending: err= 2020/12/27 06:16:20 DEBUG : file1: vfs cache: cancelling writeback (uploading false) 0xc000342b60 item 1 2020/12/27 06:16:20 DEBUG : file1: >newRWFileHandle: err= 2020/12/27 06:16:20 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:16:20 DEBUG : file1: >Open: fd=file1 (rw), err= 2020/12/27 06:16:20 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2020/12/27 06:16:20 DEBUG : file1(0xc000910440): _writeAt: size=7, off=0 2020/12/27 06:16:20 DEBUG : file1(0xc000910440): >_writeAt: n=7, err= 2020/12/27 06:16:20 DEBUG : file1(0xc000910440): _writeAt: size=6, off=5 2020/12/27 06:16:20 DEBUG : file1(0xc000910440): >_writeAt: n=6, err= 2020/12/27 06:16:20 DEBUG : file1(0xc000910440): close: 2020/12/27 06:16:20 DEBUG : file1: vfs cache: setting modification time to 2020-12-27 06:16:20.302669784 +0000 UTC m=+258.281946480 2020/12/27 06:16:20 INFO : file1: vfs cache: queuing for upload in 100ms 2020/12/27 06:16:20 DEBUG : file1(0xc000910440): >close: err= 2020/12/27 06:16:20 DEBUG : file1(0xc000910440): _writeAt: size=5, off=0 2020/12/27 06:16:20 DEBUG : file1(0xc000910440): >_writeAt: n=0, err=file already closed 2020/12/27 06:16:20 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:16:20 DEBUG : : Looking for writers 2020/12/27 06:16:20 DEBUG : file1: reading active writers 2020/12/27 06:16:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2020/12/27 06:16:20 DEBUG : : Looking for writers 2020/12/27 06:16:20 DEBUG : file1: reading active writers 2020/12/27 06:16:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2020/12/27 06:16:20 DEBUG : : Looking for writers 2020/12/27 06:16:20 DEBUG : file1: reading active writers 2020/12/27 06:16:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2020/12/27 06:16:20 DEBUG : : Looking for writers 2020/12/27 06:16:20 DEBUG : file1: reading active writers 2020/12/27 06:16:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2020/12/27 06:16:20 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:16:20 DEBUG : : Looking for writers 2020/12/27 06:16:20 DEBUG : file1: reading active writers 2020/12/27 06:16:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2020/12/27 06:16:20 DEBUG : : Looking for writers 2020/12/27 06:16:20 DEBUG : file1: reading active writers 2020/12/27 06:16:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2020/12/27 06:16:20 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "9659debe081adcb6", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:20 ERROR : file1: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "9659debe081adcb6", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:20 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:16:20 DEBUG : : Looking for writers 2020/12/27 06:16:20 DEBUG : file1: reading active writers 2020/12/27 06:16:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2020/12/27 06:16:21 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "76b0eb4edd4317ac", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:21 ERROR : file1: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "76b0eb4edd4317ac", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:21 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:16:21 DEBUG : : Looking for writers 2020/12/27 06:16:21 DEBUG : file1: reading active writers 2020/12/27 06:16:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:21 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "13cef4e3581b1372", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:21 ERROR : file1: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "13cef4e3581b1372", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:22 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:16:22 DEBUG : : Looking for writers 2020/12/27 06:16:22 DEBUG : file1: reading active writers 2020/12/27 06:16:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:22 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "e7e7f12f3484d9dc", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:22 ERROR : file1: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "e7e7f12f3484d9dc", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:23 DEBUG : : Looking for writers 2020/12/27 06:16:23 DEBUG : file1: reading active writers 2020/12/27 06:16:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:24 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:16:24 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "d24a754122c03563", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:24 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "d24a754122c03563", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:24 DEBUG : : Looking for writers 2020/12/27 06:16:24 DEBUG : file1: reading active writers 2020/12/27 06:16:24 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:25 DEBUG : : Looking for writers 2020/12/27 06:16:25 DEBUG : file1: reading active writers 2020/12/27 06:16:25 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:26 DEBUG : : Looking for writers 2020/12/27 06:16:26 DEBUG : file1: reading active writers 2020/12/27 06:16:26 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:27 DEBUG : : Looking for writers 2020/12/27 06:16:27 DEBUG : file1: reading active writers 2020/12/27 06:16:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:27 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:16:27 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "323663db805e5f18", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:27 ERROR : file1: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "323663db805e5f18", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:28 DEBUG : : Looking for writers 2020/12/27 06:16:28 DEBUG : file1: reading active writers 2020/12/27 06:16:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:28 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2020/12/27 06:16:29 DEBUG : : Looking for writers 2020/12/27 06:16:29 DEBUG : file1: reading active writers 2020/12/27 06:16:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:30 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s Cache{ "file1": &{c:0xc0001ce300 mu:{state:0 sema:0} cond:0xc000624a80 name:file1 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13831160892454756312 ext:258281946480 loc:0x26d8980} ATime:{wall:13831160892454772790 ext:258281962960 loc:0x26d8980} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, } 2020/12/27 06:16:30 DEBUG : >WaitForWriters: fstest.go:297: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:297: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:297: Sleeping for 4s for list eventual consistency: 3/3 2020/12/27 06:16:34 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:16:34 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "7f737d8c06d3fb88", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:34 ERROR : file1: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "7f737d8c06d3fb88", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" fstest.go:304: Error Trace: fstest.go:304 fstest.go:337 read_write_test.go:392 Error: Should be true Test: TestRWFileHandleWriteAt Messages: listing wrong, want file1 (11) got fstest.go:202: Not found "file1" fstest.go:205: Error Trace: fstest.go:205 fstest.go:309 fstest.go:337 read_write_test.go:392 Error: Not equal: expected: 0 actual : 1 Test: TestRWFileHandleWriteAt Messages: 1 objects not found 2020/12/27 06:16:37 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:16:37 DEBUG : : Looking for writers 2020/12/27 06:16:37 DEBUG : file1: reading active writers 2020/12/27 06:16:37 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2020/12/27 06:16:37 DEBUG : : Looking for writers 2020/12/27 06:16:37 DEBUG : file1: reading active writers 2020/12/27 06:16:37 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2020/12/27 06:16:38 DEBUG : : Looking for writers 2020/12/27 06:16:38 DEBUG : file1: reading active writers 2020/12/27 06:16:38 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2020/12/27 06:16:38 DEBUG : : Looking for writers 2020/12/27 06:16:38 DEBUG : file1: reading active writers 2020/12/27 06:16:38 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2020/12/27 06:16:38 DEBUG : : Looking for writers 2020/12/27 06:16:38 DEBUG : file1: reading active writers 2020/12/27 06:16:38 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2020/12/27 06:16:38 DEBUG : : Looking for writers 2020/12/27 06:16:38 DEBUG : file1: reading active writers 2020/12/27 06:16:38 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2020/12/27 06:16:38 DEBUG : : Looking for writers 2020/12/27 06:16:38 DEBUG : file1: reading active writers 2020/12/27 06:16:38 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2020/12/27 06:16:39 DEBUG : : Looking for writers 2020/12/27 06:16:39 DEBUG : file1: reading active writers 2020/12/27 06:16:39 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:39 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2020/12/27 06:16:40 DEBUG : : Looking for writers 2020/12/27 06:16:40 DEBUG : file1: reading active writers 2020/12/27 06:16:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:41 DEBUG : : Looking for writers 2020/12/27 06:16:41 DEBUG : file1: reading active writers 2020/12/27 06:16:41 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:42 DEBUG : : Looking for writers 2020/12/27 06:16:42 DEBUG : file1: reading active writers 2020/12/27 06:16:42 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:43 DEBUG : : Looking for writers 2020/12/27 06:16:43 DEBUG : file1: reading active writers 2020/12/27 06:16:43 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:44 DEBUG : : Looking for writers 2020/12/27 06:16:44 DEBUG : file1: reading active writers 2020/12/27 06:16:44 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:45 DEBUG : : Looking for writers 2020/12/27 06:16:45 DEBUG : file1: reading active writers 2020/12/27 06:16:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:46 DEBUG : : Looking for writers 2020/12/27 06:16:46 DEBUG : file1: reading active writers 2020/12/27 06:16:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:47 DEBUG : : Looking for writers 2020/12/27 06:16:47 DEBUG : file1: reading active writers 2020/12/27 06:16:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2020/12/27 06:16:47 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:16:47 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "a899fb2edcbc3272", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:47 ERROR : file1: vfs cache: failed to upload try #8, will retry in 25.6s: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "a899fb2edcbc3272", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:47 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s Cache{ "file1": &{c:0xc0001ce300 mu:{state:0 sema:0} cond:0xc000624a80 name:file1 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13831160892454756312 ext:258281946480 loc:0x26d8980} ATime:{wall:13831160892454772790 ext:258281962960 loc:0x26d8980} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, } 2020/12/27 06:16:47 DEBUG : >WaitForWriters: --- FAIL: TestRWFileHandleWriteAt (27.91s) === RUN TestRWFileHandleWriteNoWrite run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:16:48 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache 2020/12/27 06:16:48 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/12/27 06:16:48 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/12/27 06:16:48 DEBUG : file1: newRWFileHandle: 2020/12/27 06:16:48 DEBUG : file1(0xc000625740): openPending: 2020/12/27 06:16:48 ERROR : file1: vfs cache: detected external removal of cache file 2020/12/27 06:16:48 DEBUG : file1: vfs cache: truncate to size=0 2020/12/27 06:16:48 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:16:48 DEBUG : file1(0xc000625740): >openPending: err= 2020/12/27 06:16:48 DEBUG : file1: vfs cache: cancelling writeback (uploading false) 0xc000456620 item 1 2020/12/27 06:16:48 DEBUG : file1: >newRWFileHandle: err= 2020/12/27 06:16:48 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:16:48 DEBUG : file1: >Open: fd=file1 (rw), err= 2020/12/27 06:16:48 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2020/12/27 06:16:48 DEBUG : file1(0xc000625740): close: 2020/12/27 06:16:48 DEBUG : file1: vfs cache: setting modification time to 2020-12-27 06:16:48.211094614 +0000 UTC m=+286.190371356 2020/12/27 06:16:48 INFO : file1: vfs cache: queuing for upload in 100ms 2020/12/27 06:16:48 DEBUG : file1(0xc000625740): >close: err= 2020/12/27 06:16:48 DEBUG : file2: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx 2020/12/27 06:16:48 DEBUG : file2: Open: flags=O_WRONLY|O_CREATE|O_TRUNC 2020/12/27 06:16:48 DEBUG : file2: newRWFileHandle: 2020/12/27 06:16:48 DEBUG : file2(0xc000625900): openPending: 2020/12/27 06:16:48 DEBUG : file2: vfs cache: truncate to size=0 2020/12/27 06:16:48 DEBUG : : Added virtual directory entry vAddFile: "file2" 2020/12/27 06:16:48 DEBUG : file2(0xc000625900): >openPending: err= 2020/12/27 06:16:48 DEBUG : file2: >newRWFileHandle: err= 2020/12/27 06:16:48 DEBUG : : Added virtual directory entry vAddFile: "file2" 2020/12/27 06:16:48 DEBUG : file2: >Open: fd=file2 (rw), err= 2020/12/27 06:16:48 DEBUG : file2: >OpenFile: fd=file2 (rw), err= 2020/12/27 06:16:48 DEBUG : file2(0xc000625900): RWFileHandle.Flush 2020/12/27 06:16:48 DEBUG : file2(0xc000625900): RWFileHandle.Release 2020/12/27 06:16:48 DEBUG : file2(0xc000625900): close: 2020/12/27 06:16:48 DEBUG : file2: vfs cache: setting modification time to 2020-12-27 06:16:48.21231255 +0000 UTC m=+286.191589256 2020/12/27 06:16:48 INFO : file2: vfs cache: queuing for upload in 100ms 2020/12/27 06:16:48 DEBUG : file2(0xc000625900): >close: err= 2020/12/27 06:16:48 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:16:48 DEBUG : : Looking for writers 2020/12/27 06:16:48 DEBUG : file1: reading active writers 2020/12/27 06:16:48 DEBUG : file2: reading active writers 2020/12/27 06:16:48 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms 2020/12/27 06:16:48 DEBUG : : Looking for writers 2020/12/27 06:16:48 DEBUG : file2: reading active writers 2020/12/27 06:16:48 DEBUG : file1: reading active writers 2020/12/27 06:16:48 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms 2020/12/27 06:16:48 DEBUG : : Looking for writers 2020/12/27 06:16:48 DEBUG : file1: reading active writers 2020/12/27 06:16:48 DEBUG : file2: reading active writers 2020/12/27 06:16:48 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms 2020/12/27 06:16:48 DEBUG : : Looking for writers 2020/12/27 06:16:48 DEBUG : file1: reading active writers 2020/12/27 06:16:48 DEBUG : file2: reading active writers 2020/12/27 06:16:48 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms 2020/12/27 06:16:48 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:16:48 DEBUG : file2: vfs cache: starting upload 2020/12/27 06:16:48 DEBUG : : Looking for writers 2020/12/27 06:16:48 DEBUG : file1: reading active writers 2020/12/27 06:16:48 DEBUG : file2: reading active writers 2020/12/27 06:16:48 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms 2020/12/27 06:16:48 ERROR : file2: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "c68cf8ee56648fa4", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:48 ERROR : file2: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "c68cf8ee56648fa4", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:48 DEBUG : : Looking for writers 2020/12/27 06:16:48 DEBUG : file1: reading active writers 2020/12/27 06:16:48 DEBUG : file2: reading active writers 2020/12/27 06:16:48 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms 2020/12/27 06:16:48 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "29fa3dbb5fe97a98", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:48 ERROR : file1: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "29fa3dbb5fe97a98", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:48 DEBUG : file2: vfs cache: starting upload 2020/12/27 06:16:48 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:16:48 DEBUG : : Looking for writers 2020/12/27 06:16:48 DEBUG : file1: reading active writers 2020/12/27 06:16:48 DEBUG : file2: reading active writers 2020/12/27 06:16:48 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms 2020/12/27 06:16:48 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "09df81777f9be925", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:48 ERROR : file1: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "09df81777f9be925", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:48 ERROR : file2: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "d021b860bf967bef", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:48 ERROR : file2: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "d021b860bf967bef", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:49 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:16:49 DEBUG : file2: vfs cache: starting upload 2020/12/27 06:16:49 DEBUG : : Looking for writers 2020/12/27 06:16:49 DEBUG : file1: reading active writers 2020/12/27 06:16:49 DEBUG : file2: reading active writers 2020/12/27 06:16:49 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:16:49 ERROR : file2: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "0e01735ed1b6b44e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:49 ERROR : file2: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "0e01735ed1b6b44e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:49 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "b1b0edb2f542c71e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:49 ERROR : file1: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "b1b0edb2f542c71e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:50 DEBUG : file2: vfs cache: starting upload 2020/12/27 06:16:50 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:16:50 DEBUG : : Looking for writers 2020/12/27 06:16:50 DEBUG : file1: reading active writers 2020/12/27 06:16:50 DEBUG : file2: reading active writers 2020/12/27 06:16:50 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:16:50 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "60b082617cb5edb0", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:50 ERROR : file1: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "60b082617cb5edb0", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:50 ERROR : file2: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "c6104f61e48cc2da", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:50 ERROR : file2: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "c6104f61e48cc2da", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:50 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file2 not removed, freed 0 bytes 2020/12/27 06:16:50 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2020/12/27 06:16:50 INFO : vfs cache: cleaned: objects 2 (was 2) in use 2, to upload 2, uploading 0, total size 0 (was 0) 2020/12/27 06:16:51 DEBUG : : Looking for writers 2020/12/27 06:16:51 DEBUG : file1: reading active writers 2020/12/27 06:16:51 DEBUG : file2: reading active writers 2020/12/27 06:16:51 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:16:52 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:16:52 DEBUG : file2: vfs cache: starting upload 2020/12/27 06:16:52 ERROR : file2: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "1c7f8ee56c5ef7d5", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:52 ERROR : file2: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "1c7f8ee56c5ef7d5", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:52 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "e702cc7d8f768768", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:52 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "e702cc7d8f768768", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:52 DEBUG : : Looking for writers 2020/12/27 06:16:52 DEBUG : file1: reading active writers 2020/12/27 06:16:52 DEBUG : file2: reading active writers 2020/12/27 06:16:52 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:16:53 DEBUG : : Looking for writers 2020/12/27 06:16:53 DEBUG : file1: reading active writers 2020/12/27 06:16:53 DEBUG : file2: reading active writers 2020/12/27 06:16:53 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:16:54 DEBUG : : Looking for writers 2020/12/27 06:16:54 DEBUG : file1: reading active writers 2020/12/27 06:16:54 DEBUG : file2: reading active writers 2020/12/27 06:16:54 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:16:55 DEBUG : : Looking for writers 2020/12/27 06:16:55 DEBUG : file1: reading active writers 2020/12/27 06:16:55 DEBUG : file2: reading active writers 2020/12/27 06:16:55 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:16:55 DEBUG : file2: vfs cache: starting upload 2020/12/27 06:16:55 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:16:55 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "5d510aa457026df0", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:55 ERROR : file1: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "5d510aa457026df0", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:55 ERROR : file2: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "9f805256486b05d8", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:55 ERROR : file2: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "9f805256486b05d8", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:16:56 DEBUG : : Looking for writers 2020/12/27 06:16:56 DEBUG : file1: reading active writers 2020/12/27 06:16:56 DEBUG : file2: reading active writers 2020/12/27 06:16:56 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:16:57 DEBUG : : Looking for writers 2020/12/27 06:16:57 DEBUG : file1: reading active writers 2020/12/27 06:16:57 DEBUG : file2: reading active writers 2020/12/27 06:16:57 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:16:58 ERROR : Exiting even though 0 writers active and 2 cache items in use after 10s Cache{ "file1": &{c:0xc0001ce300 mu:{state:0 sema:0} cond:0xc000624a80 name:file1 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13831160922427952214 ext:286190371356 loc:0x26d8980} ATime:{wall:13831160922428239607 ext:286190658715 loc:0x26d8980} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, "file2": &{c:0xc0001ce300 mu:{state:0 sema:0} cond:0xc0006258c0 name:file2 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13831160922429170150 ext:286191589256 loc:0x26d8980} ATime:{wall:13831160922429342558 ext:286191761670 loc:0x26d8980} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2 pendingAccesses:0 beingReset:false}, } 2020/12/27 06:16:58 DEBUG : >WaitForWriters: fstest.go:297: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:297: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:297: Sleeping for 4s for list eventual consistency: 3/3 2020/12/27 06:17:02 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:17:02 DEBUG : file2: vfs cache: starting upload 2020/12/27 06:17:02 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "0da6d403da0f6683", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:17:02 ERROR : file1: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "0da6d403da0f6683", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:17:02 ERROR : file2: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "8c2c28fd825dc7d2", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:17:02 ERROR : file2: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "8c2c28fd825dc7d2", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" fstest.go:304: Error Trace: fstest.go:304 fstest.go:337 read_write_test.go:426 Error: Should be true Test: TestRWFileHandleWriteNoWrite Messages: listing wrong, want file1 (0), file2 (0) got fstest.go:202: Not found "file1" fstest.go:202: Not found "file2" fstest.go:205: Error Trace: fstest.go:205 fstest.go:309 fstest.go:337 read_write_test.go:426 Error: Not equal: expected: 0 actual : 2 Test: TestRWFileHandleWriteNoWrite Messages: 2 objects not found 2020/12/27 06:17:05 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:17:05 DEBUG : : Looking for writers 2020/12/27 06:17:05 DEBUG : file1: reading active writers 2020/12/27 06:17:05 DEBUG : file2: reading active writers 2020/12/27 06:17:05 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms 2020/12/27 06:17:05 DEBUG : : Looking for writers 2020/12/27 06:17:05 DEBUG : file1: reading active writers 2020/12/27 06:17:05 DEBUG : file2: reading active writers 2020/12/27 06:17:05 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms 2020/12/27 06:17:05 DEBUG : : Looking for writers 2020/12/27 06:17:05 DEBUG : file1: reading active writers 2020/12/27 06:17:05 DEBUG : file2: reading active writers 2020/12/27 06:17:05 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms 2020/12/27 06:17:05 DEBUG : : Looking for writers 2020/12/27 06:17:05 DEBUG : file1: reading active writers 2020/12/27 06:17:05 DEBUG : file2: reading active writers 2020/12/27 06:17:05 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms 2020/12/27 06:17:06 DEBUG : : Looking for writers 2020/12/27 06:17:06 DEBUG : file1: reading active writers 2020/12/27 06:17:06 DEBUG : file2: reading active writers 2020/12/27 06:17:06 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms 2020/12/27 06:17:06 DEBUG : : Looking for writers 2020/12/27 06:17:06 DEBUG : file1: reading active writers 2020/12/27 06:17:06 DEBUG : file2: reading active writers 2020/12/27 06:17:06 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms 2020/12/27 06:17:06 DEBUG : : Looking for writers 2020/12/27 06:17:06 DEBUG : file1: reading active writers 2020/12/27 06:17:06 DEBUG : file2: reading active writers 2020/12/27 06:17:06 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms 2020/12/27 06:17:07 DEBUG : : Looking for writers 2020/12/27 06:17:07 DEBUG : file1: reading active writers 2020/12/27 06:17:07 DEBUG : file2: reading active writers 2020/12/27 06:17:07 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:17:08 DEBUG : : Looking for writers 2020/12/27 06:17:08 DEBUG : file1: reading active writers 2020/12/27 06:17:08 DEBUG : file2: reading active writers 2020/12/27 06:17:08 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:17:09 DEBUG : : Looking for writers 2020/12/27 06:17:09 DEBUG : file1: reading active writers 2020/12/27 06:17:09 DEBUG : file2: reading active writers 2020/12/27 06:17:09 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:17:10 DEBUG : : Looking for writers 2020/12/27 06:17:10 DEBUG : file1: reading active writers 2020/12/27 06:17:10 DEBUG : file2: reading active writers 2020/12/27 06:17:10 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:17:11 DEBUG : : Looking for writers 2020/12/27 06:17:11 DEBUG : file1: reading active writers 2020/12/27 06:17:11 DEBUG : file2: reading active writers 2020/12/27 06:17:11 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:17:12 DEBUG : : Looking for writers 2020/12/27 06:17:12 DEBUG : file1: reading active writers 2020/12/27 06:17:12 DEBUG : file2: reading active writers 2020/12/27 06:17:12 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:17:13 DEBUG : : Looking for writers 2020/12/27 06:17:13 DEBUG : file1: reading active writers 2020/12/27 06:17:13 DEBUG : file2: reading active writers 2020/12/27 06:17:13 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:17:14 DEBUG : : Looking for writers 2020/12/27 06:17:14 DEBUG : file1: reading active writers 2020/12/27 06:17:14 DEBUG : file2: reading active writers 2020/12/27 06:17:14 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:17:15 DEBUG : : Looking for writers 2020/12/27 06:17:15 DEBUG : file1: reading active writers 2020/12/27 06:17:15 DEBUG : file2: reading active writers 2020/12/27 06:17:15 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:17:15 DEBUG : file1: vfs cache: starting upload 2020/12/27 06:17:15 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "0260b95d5d1684dc", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:17:15 ERROR : file1: vfs cache: failed to upload try #8, will retry in 25.6s: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "0260b95d5d1684dc", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:17:15 DEBUG : file2: vfs cache: starting upload 2020/12/27 06:17:15 ERROR : file2: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "1dc81a22590aac7e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:17:15 ERROR : file2: vfs cache: failed to upload try #8, will retry in 25.6s: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "1dc81a22590aac7e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:17:15 ERROR : Exiting even though 0 writers active and 2 cache items in use after 10s Cache{ "file1": &{c:0xc0001ce300 mu:{state:0 sema:0} cond:0xc000624a80 name:file1 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13831160922427952214 ext:286190371356 loc:0x26d8980} ATime:{wall:13831160922428239607 ext:286190658715 loc:0x26d8980} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, "file2": &{c:0xc0001ce300 mu:{state:0 sema:0} cond:0xc0006258c0 name:file2 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13831160922429170150 ext:286191589256 loc:0x26d8980} ATime:{wall:13831160922429342558 ext:286191761670 loc:0x26d8980} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2 pendingAccesses:0 beingReset:false}, } 2020/12/27 06:17:15 DEBUG : >WaitForWriters: --- FAIL: TestRWFileHandleWriteNoWrite (27.88s) === RUN TestRWFileHandleSizeTruncateExisting run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:17:16 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "bfeb971e7438b844", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestRWFileHandleSizeTruncateExisting (0.20s) === RUN TestRWFileHandleSizeCreateExisting run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:17:16 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "b03fe3c4a650369d", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestRWFileHandleSizeCreateExisting (0.20s) === RUN TestRWFileModTimeWithOpenWriters run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:17:16 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache 2020/12/27 06:17:16 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/12/27 06:17:16 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/12/27 06:17:16 DEBUG : file1: newRWFileHandle: 2020/12/27 06:17:16 DEBUG : file1(0xc0000165c0): openPending: 2020/12/27 06:17:16 DEBUG : file1: vfs cache: truncate to size=0 2020/12/27 06:17:16 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:17:16 DEBUG : file1(0xc0000165c0): >openPending: err= 2020/12/27 06:17:16 DEBUG : file1: vfs cache: cancelling writeback (uploading false) 0xc000342c40 item 1 2020/12/27 06:17:16 DEBUG : file1: >newRWFileHandle: err= 2020/12/27 06:17:16 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:17:16 DEBUG : file1: >Open: fd=file1 (rw), err= 2020/12/27 06:17:16 DEBUG : file1: >OpenFile: fd=file1 (rw), err= run.go:282: Failed to put "time_test" to "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "af4ce7bb3d453175", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:17:16 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:17:16 DEBUG : : Looking for writers 2020/12/27 06:17:16 DEBUG : file1: reading active writers 2020/12/27 06:17:16 DEBUG : file1: active writers 1 2020/12/27 06:17:16 DEBUG : file2: reading active writers 2020/12/27 06:17:16 DEBUG : Still 1 writers active and 2 cache items in use, waiting 10ms 2020/12/27 06:17:16 DEBUG : : Looking for writers 2020/12/27 06:17:16 DEBUG : file1: reading active writers 2020/12/27 06:17:16 DEBUG : file1: active writers 1 2020/12/27 06:17:16 DEBUG : file2: reading active writers 2020/12/27 06:17:16 DEBUG : Still 1 writers active and 2 cache items in use, waiting 20ms 2020/12/27 06:17:16 DEBUG : : Looking for writers 2020/12/27 06:17:16 DEBUG : file1: reading active writers 2020/12/27 06:17:16 DEBUG : file1: active writers 1 2020/12/27 06:17:16 DEBUG : file2: reading active writers 2020/12/27 06:17:16 DEBUG : Still 1 writers active and 2 cache items in use, waiting 40ms 2020/12/27 06:17:16 DEBUG : : Looking for writers 2020/12/27 06:17:16 DEBUG : file1: reading active writers 2020/12/27 06:17:16 DEBUG : file1: active writers 1 2020/12/27 06:17:16 DEBUG : file2: reading active writers 2020/12/27 06:17:16 DEBUG : Still 1 writers active and 2 cache items in use, waiting 80ms 2020/12/27 06:17:16 DEBUG : : Looking for writers 2020/12/27 06:17:16 DEBUG : file1: reading active writers 2020/12/27 06:17:16 DEBUG : file1: active writers 1 2020/12/27 06:17:16 DEBUG : file2: reading active writers 2020/12/27 06:17:16 DEBUG : Still 1 writers active and 2 cache items in use, waiting 160ms 2020/12/27 06:17:16 DEBUG : : Looking for writers 2020/12/27 06:17:16 DEBUG : file1: reading active writers 2020/12/27 06:17:16 DEBUG : file1: active writers 1 2020/12/27 06:17:16 DEBUG : file2: reading active writers 2020/12/27 06:17:16 DEBUG : Still 1 writers active and 2 cache items in use, waiting 320ms 2020/12/27 06:17:17 DEBUG : : Looking for writers 2020/12/27 06:17:17 DEBUG : file2: reading active writers 2020/12/27 06:17:17 DEBUG : file1: reading active writers 2020/12/27 06:17:17 DEBUG : file1: active writers 1 2020/12/27 06:17:17 DEBUG : Still 1 writers active and 2 cache items in use, waiting 640ms 2020/12/27 06:17:17 DEBUG : : Looking for writers 2020/12/27 06:17:17 DEBUG : file2: reading active writers 2020/12/27 06:17:17 DEBUG : file1: reading active writers 2020/12/27 06:17:17 DEBUG : file1: active writers 1 2020/12/27 06:17:17 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:17:18 DEBUG : : Looking for writers 2020/12/27 06:17:18 DEBUG : file1: reading active writers 2020/12/27 06:17:18 DEBUG : file1: active writers 1 2020/12/27 06:17:18 DEBUG : file2: reading active writers 2020/12/27 06:17:18 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:17:19 DEBUG : : Looking for writers 2020/12/27 06:17:19 DEBUG : file1: reading active writers 2020/12/27 06:17:19 DEBUG : file1: active writers 1 2020/12/27 06:17:19 DEBUG : file2: reading active writers 2020/12/27 06:17:19 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:17:20 DEBUG : : Looking for writers 2020/12/27 06:17:20 DEBUG : file1: reading active writers 2020/12/27 06:17:20 DEBUG : file1: active writers 1 2020/12/27 06:17:20 DEBUG : file2: reading active writers 2020/12/27 06:17:20 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:17:21 DEBUG : : Looking for writers 2020/12/27 06:17:21 DEBUG : file1: reading active writers 2020/12/27 06:17:21 DEBUG : file1: active writers 1 2020/12/27 06:17:21 DEBUG : file2: reading active writers 2020/12/27 06:17:21 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:17:22 DEBUG : : Looking for writers 2020/12/27 06:17:22 DEBUG : file1: reading active writers 2020/12/27 06:17:22 DEBUG : file1: active writers 1 2020/12/27 06:17:22 DEBUG : file2: reading active writers 2020/12/27 06:17:22 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:17:23 DEBUG : : Looking for writers 2020/12/27 06:17:23 DEBUG : file1: reading active writers 2020/12/27 06:17:23 DEBUG : file1: active writers 1 2020/12/27 06:17:23 DEBUG : file2: reading active writers 2020/12/27 06:17:23 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:17:24 DEBUG : : Looking for writers 2020/12/27 06:17:24 DEBUG : file1: reading active writers 2020/12/27 06:17:24 DEBUG : file1: active writers 1 2020/12/27 06:17:24 DEBUG : file2: reading active writers 2020/12/27 06:17:24 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:17:25 DEBUG : : Looking for writers 2020/12/27 06:17:25 DEBUG : file1: reading active writers 2020/12/27 06:17:25 DEBUG : file1: active writers 1 2020/12/27 06:17:25 DEBUG : file2: reading active writers 2020/12/27 06:17:25 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2020/12/27 06:17:26 ERROR : Exiting even though 1 writers active and 2 cache items in use after 10s Cache{ "file1": &{c:0xc0001ce300 mu:{state:0 sema:0} cond:0xc000624a80 name:file1 opens:1 downloaders: o: fd:0xc000010620 metaDirty:true modified:true info:{ModTime:{wall:13831160952769659742 ext:314467307759 loc:0x26d8980} ATime:{wall:13831160952769659742 ext:314467307759 loc:0x26d8980} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, "file2": &{c:0xc0001ce300 mu:{state:0 sema:0} cond:0xc0006258c0 name:file2 opens:0 downloaders: o: fd: metaDirty:false modified:false info:{ModTime:{wall:13831160922429170150 ext:286191589256 loc:0x26d8980} ATime:{wall:13831160922429342558 ext:286191761670 loc:0x26d8980} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2 pendingAccesses:0 beingReset:false}, } 2020/12/27 06:17:26 DEBUG : >WaitForWriters: --- FAIL: TestRWFileModTimeWithOpenWriters (10.40s) === RUN TestCaseSensitivity run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" run.go:282: Failed to put "FiLeA" to "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "120ea2151246ed47", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestCaseSensitivity (0.40s) === RUN TestVFSNew vfs_test.go:134: Error Trace: vfs_test.go:134 vfs_test.go:137 Error: Not equal: expected: 0 actual : 5 Test: TestVFSNew run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:17:27 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache vfs_test.go:134: Error Trace: vfs_test.go:134 vfs_test.go:147 Error: Not equal: expected: 1 actual : 5 Test: TestVFSNew 2020/12/27 06:17:27 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache vfs_test.go:134: Error Trace: vfs_test.go:134 vfs_test.go:154 Error: Not equal: expected: 1 actual : 5 Test: TestVFSNew vfs_test.go:134: Error Trace: vfs_test.go:134 vfs_test.go:159 Error: Not equal: expected: 1 actual : 5 Test: TestVFSNew 2020/12/27 06:17:27 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:17:27 DEBUG : : Looking for writers 2020/12/27 06:17:27 DEBUG : >WaitForWriters: vfs_test.go:134: Error Trace: vfs_test.go:134 vfs_test.go:163 Error: Not equal: expected: 0 actual : 5 Test: TestVFSNew --- FAIL: TestVFSNew (0.20s) === RUN TestVFSStat run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:17:27 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:282: Failed to put "file1" to "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "450615afcdc0292b", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:17:27 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:17:27 DEBUG : : Looking for writers 2020/12/27 06:17:27 DEBUG : >WaitForWriters: --- FAIL: TestVFSStat (0.40s) === RUN TestVFSStatParent run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:17:27 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:282: Failed to put "file1" to "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "4a54e73e500b615f", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:17:28 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:17:28 DEBUG : : Looking for writers 2020/12/27 06:17:28 DEBUG : >WaitForWriters: --- FAIL: TestVFSStatParent (0.40s) === RUN TestVFSOpenFile run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:17:28 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:282: Failed to put "file1" to "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "ba637c64799ce870", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:17:28 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:17:28 DEBUG : : Looking for writers 2020/12/27 06:17:28 DEBUG : >WaitForWriters: --- FAIL: TestVFSOpenFile (0.40s) === RUN TestVFSRename run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:17:28 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache run.go:282: Failed to put "dir/file2" to "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2": QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "bf16f97ee5735751", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:17:28 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:17:28 DEBUG : : Looking for writers 2020/12/27 06:17:28 DEBUG : >WaitForWriters: --- FAIL: TestVFSRename (0.40s) === RUN TestWriteFileHandleMethods run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:17:29 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache 2020/12/27 06:17:29 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/12/27 06:17:29 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/12/27 06:17:29 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:17:29 DEBUG : file1: >Open: fd=file1 (w), err= 2020/12/27 06:17:29 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/12/27 06:17:29 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:17:29 ERROR : file1: WriteFileHandle: Read: Can't read and write to file without --vfs-cache-mode >= minimal 2020/12/27 06:17:29 ERROR : file1: WriteFileHandle: ReadAt: Can't read and write to file without --vfs-cache-mode >= minimal 2020/12/27 06:17:29 ERROR : file1: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes 2020/12/27 06:17:29 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: File to upload is small (5 bytes), uploading instead of streaming 2020/12/27 06:17:29 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "3126f928ed1cdb9d", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:17:29 ERROR : file1: WriteFileHandle.New Rcat failed: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "3126f928ed1cdb9d", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" write_test.go:84: Error Trace: write_test.go:84 Error: Received unexpected error: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "3126f928ed1cdb9d", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" Test: TestWriteFileHandleMethods fstest.go:297: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:297: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:297: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:304: Error Trace: fstest.go:304 fstest.go:337 write_test.go:97 Error: Should be true Test: TestWriteFileHandleMethods Messages: listing wrong, want file1 (5) got fstest.go:202: Not found "file1" fstest.go:205: Error Trace: fstest.go:205 fstest.go:309 fstest.go:337 write_test.go:97 Error: Not equal: expected: 0 actual : 1 Test: TestWriteFileHandleMethods Messages: 1 objects not found 2020/12/27 06:17:37 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/12/27 06:17:37 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/12/27 06:17:37 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:17:37 DEBUG : file1: >Open: fd=file1 (w), err= 2020/12/27 06:17:37 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/12/27 06:17:37 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:17:37 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: File to upload is small (0 bytes), uploading instead of streaming 2020/12/27 06:17:37 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "a7f81ed97231affb", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:17:37 ERROR : file1: WriteFileHandle.New Rcat failed: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "a7f81ed97231affb", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" write_test.go:103: Error Trace: write_test.go:103 Error: Received unexpected error: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "a7f81ed97231affb", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" Test: TestWriteFileHandleMethods dir_test.go:252: Error Trace: dir_test.go:252 write_test.go:104 Error: Not equal: expected: []string{"file1,5,false"} actual : []string{"file1,0,false"} Diff: --- Expected +++ Actual @@ -1,3 +1,3 @@ ([]string) (len=1) { - (string) (len=13) "file1,5,false" + (string) (len=13) "file1,0,false" } Test: TestWriteFileHandleMethods 2020/12/27 06:17:37 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/12/27 06:17:37 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/12/27 06:17:37 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:17:37 DEBUG : file1: >Open: fd=file1 (w), err= 2020/12/27 06:17:37 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/12/27 06:17:37 DEBUG : : Added virtual directory entry vAddFile: "file1" write_test.go:111: Error Trace: write_test.go:111 Error: Not equal: expected: *errors.errorString(&errors.errorString{s:"permission denied"}) actual : () Test: TestWriteFileHandleMethods 2020/12/27 06:17:37 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:17:37 DEBUG : : Looking for writers 2020/12/27 06:17:37 DEBUG : file1: reading active writers 2020/12/27 06:17:37 DEBUG : file1: active writers 1 2020/12/27 06:17:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/12/27 06:17:37 DEBUG : : Looking for writers 2020/12/27 06:17:37 DEBUG : file1: reading active writers 2020/12/27 06:17:37 DEBUG : file1: active writers 1 2020/12/27 06:17:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/12/27 06:17:37 DEBUG : : Looking for writers 2020/12/27 06:17:37 DEBUG : file1: reading active writers 2020/12/27 06:17:37 DEBUG : file1: active writers 1 2020/12/27 06:17:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/12/27 06:17:37 DEBUG : : Looking for writers 2020/12/27 06:17:37 DEBUG : file1: reading active writers 2020/12/27 06:17:37 DEBUG : file1: active writers 1 2020/12/27 06:17:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/12/27 06:17:37 DEBUG : : Looking for writers 2020/12/27 06:17:37 DEBUG : file1: reading active writers 2020/12/27 06:17:37 DEBUG : file1: active writers 1 2020/12/27 06:17:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/12/27 06:17:37 DEBUG : : Looking for writers 2020/12/27 06:17:37 DEBUG : file1: reading active writers 2020/12/27 06:17:37 DEBUG : file1: active writers 1 2020/12/27 06:17:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/12/27 06:17:37 DEBUG : : Looking for writers 2020/12/27 06:17:37 DEBUG : file1: reading active writers 2020/12/27 06:17:37 DEBUG : file1: active writers 1 2020/12/27 06:17:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/12/27 06:17:38 DEBUG : : Looking for writers 2020/12/27 06:17:38 DEBUG : file1: reading active writers 2020/12/27 06:17:38 DEBUG : file1: active writers 1 2020/12/27 06:17:38 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:17:39 DEBUG : : Looking for writers 2020/12/27 06:17:39 DEBUG : file1: reading active writers 2020/12/27 06:17:39 DEBUG : file1: active writers 1 2020/12/27 06:17:39 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:17:40 DEBUG : : Looking for writers 2020/12/27 06:17:40 DEBUG : file1: reading active writers 2020/12/27 06:17:40 DEBUG : file1: active writers 1 2020/12/27 06:17:40 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:17:41 DEBUG : file2: vfs cache: starting upload 2020/12/27 06:17:41 ERROR : file2: vfs cache: failed to write metadata file: vfs cache item: failed to write metadata: open /home/rclone/.cache/rclone/vfsMeta/TestQingStor/rclone-test-kodotij6tedopev1vuleyoq2/file2: no such file or directory 2020/12/27 06:17:41 INFO : file2: vfs cache: upload succeeded try #9 2020/12/27 06:17:41 DEBUG : : Looking for writers 2020/12/27 06:17:41 DEBUG : file1: reading active writers 2020/12/27 06:17:41 DEBUG : file1: active writers 1 2020/12/27 06:17:41 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:17:42 DEBUG : : Looking for writers 2020/12/27 06:17:42 DEBUG : file1: reading active writers 2020/12/27 06:17:42 DEBUG : file1: active writers 1 2020/12/27 06:17:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:17:43 DEBUG : : Looking for writers 2020/12/27 06:17:43 DEBUG : file1: reading active writers 2020/12/27 06:17:43 DEBUG : file1: active writers 1 2020/12/27 06:17:43 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:17:44 DEBUG : : Looking for writers 2020/12/27 06:17:44 DEBUG : file1: reading active writers 2020/12/27 06:17:44 DEBUG : file1: active writers 1 2020/12/27 06:17:44 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:17:45 DEBUG : : Looking for writers 2020/12/27 06:17:45 DEBUG : file1: reading active writers 2020/12/27 06:17:45 DEBUG : file1: active writers 1 2020/12/27 06:17:45 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:17:46 DEBUG : : Looking for writers 2020/12/27 06:17:46 DEBUG : file1: reading active writers 2020/12/27 06:17:46 DEBUG : file1: active writers 1 2020/12/27 06:17:46 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:17:47 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/12/27 06:17:47 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleMethods (18.40s) === RUN TestWriteFileHandleWriteAt run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:17:47 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache 2020/12/27 06:17:47 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/12/27 06:17:47 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/12/27 06:17:47 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:17:47 DEBUG : file1: >Open: fd=file1 (w), err= 2020/12/27 06:17:47 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/12/27 06:17:47 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:17:47 DEBUG : file1: waiting for in-sequence write to 100 for 1s 2020/12/27 06:17:48 DEBUG : file1: aborting in-sequence write wait, off=100 2020/12/27 06:17:48 DEBUG : file1: failed to wait for in-sequence write to 100 2020/12/27 06:17:48 ERROR : file1: WriteFileHandle.Write: can't seek in file without --vfs-cache-mode >= writes 2020/12/27 06:17:48 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: File to upload is small (11 bytes), uploading instead of streaming 2020/12/27 06:17:48 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "88e0d6685624f8d4", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:17:48 ERROR : file1: WriteFileHandle.New Rcat failed: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "88e0d6685624f8d4", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" write_test.go:162: Error Trace: write_test.go:162 Error: Received unexpected error: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "88e0d6685624f8d4", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" Test: TestWriteFileHandleWriteAt 2020/12/27 06:17:48 ERROR : file1: WriteFileHandle.Write: error: Bad file descriptor fstest.go:297: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:297: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:297: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:304: Error Trace: fstest.go:304 fstest.go:337 write_test.go:176 Error: Should be true Test: TestWriteFileHandleWriteAt Messages: listing wrong, want file1 (11) got fstest.go:202: Not found "file1" fstest.go:205: Error Trace: fstest.go:205 fstest.go:309 fstest.go:337 write_test.go:176 Error: Not equal: expected: 0 actual : 1 Test: TestWriteFileHandleWriteAt Messages: 1 objects not found 2020/12/27 06:17:56 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:17:56 DEBUG : : Looking for writers 2020/12/27 06:17:56 DEBUG : file1: reading active writers 2020/12/27 06:17:56 DEBUG : file1: active writers 1 2020/12/27 06:17:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/12/27 06:17:56 DEBUG : : Looking for writers 2020/12/27 06:17:56 DEBUG : file1: reading active writers 2020/12/27 06:17:56 DEBUG : file1: active writers 1 2020/12/27 06:17:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/12/27 06:17:56 DEBUG : : Looking for writers 2020/12/27 06:17:56 DEBUG : file1: reading active writers 2020/12/27 06:17:56 DEBUG : file1: active writers 1 2020/12/27 06:17:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/12/27 06:17:56 DEBUG : : Looking for writers 2020/12/27 06:17:56 DEBUG : file1: reading active writers 2020/12/27 06:17:56 DEBUG : file1: active writers 1 2020/12/27 06:17:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/12/27 06:17:56 DEBUG : : Looking for writers 2020/12/27 06:17:56 DEBUG : file1: reading active writers 2020/12/27 06:17:56 DEBUG : file1: active writers 1 2020/12/27 06:17:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/12/27 06:17:56 DEBUG : : Looking for writers 2020/12/27 06:17:56 DEBUG : file1: reading active writers 2020/12/27 06:17:56 DEBUG : file1: active writers 1 2020/12/27 06:17:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/12/27 06:17:56 DEBUG : : Looking for writers 2020/12/27 06:17:56 DEBUG : file1: reading active writers 2020/12/27 06:17:56 DEBUG : file1: active writers 1 2020/12/27 06:17:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/12/27 06:17:57 DEBUG : : Looking for writers 2020/12/27 06:17:57 DEBUG : file1: reading active writers 2020/12/27 06:17:57 DEBUG : file1: active writers 1 2020/12/27 06:17:57 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:17:58 DEBUG : : Looking for writers 2020/12/27 06:17:58 DEBUG : file1: reading active writers 2020/12/27 06:17:58 DEBUG : file1: active writers 1 2020/12/27 06:17:58 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:17:59 DEBUG : : Looking for writers 2020/12/27 06:17:59 DEBUG : file1: reading active writers 2020/12/27 06:17:59 DEBUG : file1: active writers 1 2020/12/27 06:17:59 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:00 DEBUG : : Looking for writers 2020/12/27 06:18:00 DEBUG : file1: reading active writers 2020/12/27 06:18:00 DEBUG : file1: active writers 1 2020/12/27 06:18:00 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:01 DEBUG : : Looking for writers 2020/12/27 06:18:01 DEBUG : file1: reading active writers 2020/12/27 06:18:01 DEBUG : file1: active writers 1 2020/12/27 06:18:01 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:02 DEBUG : : Looking for writers 2020/12/27 06:18:02 DEBUG : file1: reading active writers 2020/12/27 06:18:02 DEBUG : file1: active writers 1 2020/12/27 06:18:02 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:03 DEBUG : : Looking for writers 2020/12/27 06:18:03 DEBUG : file1: reading active writers 2020/12/27 06:18:03 DEBUG : file1: active writers 1 2020/12/27 06:18:03 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:04 DEBUG : : Looking for writers 2020/12/27 06:18:04 DEBUG : file1: reading active writers 2020/12/27 06:18:04 DEBUG : file1: active writers 1 2020/12/27 06:18:04 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:05 DEBUG : : Looking for writers 2020/12/27 06:18:05 DEBUG : file1: reading active writers 2020/12/27 06:18:05 DEBUG : file1: active writers 1 2020/12/27 06:18:05 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:06 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/12/27 06:18:06 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleWriteAt (18.99s) === RUN TestWriteFileHandleFlush run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:18:06 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache 2020/12/27 06:18:06 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/12/27 06:18:06 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/12/27 06:18:06 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:18:06 DEBUG : file1: >Open: fd=file1 (w), err= 2020/12/27 06:18:06 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/12/27 06:18:06 DEBUG : file1: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions 2020/12/27 06:18:06 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:18:06 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: File to upload is small (5 bytes), uploading instead of streaming 2020/12/27 06:18:06 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "e3b93111e1d568b7", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:18:06 ERROR : file1: WriteFileHandle.New Rcat failed: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "e3b93111e1d568b7", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:18:06 ERROR : file1: WriteFileHandle.Flush error: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "e3b93111e1d568b7", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" write_test.go:198: Error Trace: write_test.go:198 Error: Received unexpected error: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "e3b93111e1d568b7", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" Test: TestWriteFileHandleFlush 2020/12/27 06:18:06 DEBUG : file1: WriteFileHandle.Flush nothing to do 2020/12/27 06:18:06 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:18:06 DEBUG : : Looking for writers 2020/12/27 06:18:06 DEBUG : file1: reading active writers 2020/12/27 06:18:06 DEBUG : file1: active writers 1 2020/12/27 06:18:06 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/12/27 06:18:06 DEBUG : : Looking for writers 2020/12/27 06:18:06 DEBUG : file1: reading active writers 2020/12/27 06:18:06 DEBUG : file1: active writers 1 2020/12/27 06:18:06 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/12/27 06:18:06 DEBUG : : Looking for writers 2020/12/27 06:18:06 DEBUG : file1: reading active writers 2020/12/27 06:18:06 DEBUG : file1: active writers 1 2020/12/27 06:18:06 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/12/27 06:18:06 DEBUG : : Looking for writers 2020/12/27 06:18:06 DEBUG : file1: reading active writers 2020/12/27 06:18:06 DEBUG : file1: active writers 1 2020/12/27 06:18:06 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/12/27 06:18:06 DEBUG : : Looking for writers 2020/12/27 06:18:06 DEBUG : file1: reading active writers 2020/12/27 06:18:06 DEBUG : file1: active writers 1 2020/12/27 06:18:06 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/12/27 06:18:06 DEBUG : : Looking for writers 2020/12/27 06:18:06 DEBUG : file1: reading active writers 2020/12/27 06:18:06 DEBUG : file1: active writers 1 2020/12/27 06:18:06 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/12/27 06:18:07 DEBUG : : Looking for writers 2020/12/27 06:18:07 DEBUG : file1: reading active writers 2020/12/27 06:18:07 DEBUG : file1: active writers 1 2020/12/27 06:18:07 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/12/27 06:18:07 DEBUG : : Looking for writers 2020/12/27 06:18:07 DEBUG : file1: reading active writers 2020/12/27 06:18:07 DEBUG : file1: active writers 1 2020/12/27 06:18:07 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:08 DEBUG : : Looking for writers 2020/12/27 06:18:08 DEBUG : file1: reading active writers 2020/12/27 06:18:08 DEBUG : file1: active writers 1 2020/12/27 06:18:08 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:09 DEBUG : : Looking for writers 2020/12/27 06:18:09 DEBUG : file1: reading active writers 2020/12/27 06:18:09 DEBUG : file1: active writers 1 2020/12/27 06:18:09 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:10 DEBUG : : Looking for writers 2020/12/27 06:18:10 DEBUG : file1: reading active writers 2020/12/27 06:18:10 DEBUG : file1: active writers 1 2020/12/27 06:18:10 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:11 DEBUG : : Looking for writers 2020/12/27 06:18:11 DEBUG : file1: reading active writers 2020/12/27 06:18:11 DEBUG : file1: active writers 1 2020/12/27 06:18:11 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:12 DEBUG : : Looking for writers 2020/12/27 06:18:12 DEBUG : file1: reading active writers 2020/12/27 06:18:12 DEBUG : file1: active writers 1 2020/12/27 06:18:12 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:13 DEBUG : : Looking for writers 2020/12/27 06:18:13 DEBUG : file1: reading active writers 2020/12/27 06:18:13 DEBUG : file1: active writers 1 2020/12/27 06:18:13 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:14 DEBUG : : Looking for writers 2020/12/27 06:18:14 DEBUG : file1: reading active writers 2020/12/27 06:18:14 DEBUG : file1: active writers 1 2020/12/27 06:18:14 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:15 DEBUG : : Looking for writers 2020/12/27 06:18:15 DEBUG : file1: reading active writers 2020/12/27 06:18:15 DEBUG : file1: active writers 1 2020/12/27 06:18:15 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:16 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/12/27 06:18:16 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleFlush (10.40s) === RUN TestWriteFileHandleRelease run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:18:16 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache 2020/12/27 06:18:16 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/12/27 06:18:16 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/12/27 06:18:16 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:18:16 DEBUG : file1: >Open: fd=file1 (w), err= 2020/12/27 06:18:16 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/12/27 06:18:16 DEBUG : file1: WriteFileHandle.Release closing 2020/12/27 06:18:16 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:18:16 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: File to upload is small (0 bytes), uploading instead of streaming 2020/12/27 06:18:17 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "78f721b5e22375c9", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:18:17 ERROR : file1: WriteFileHandle.New Rcat failed: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "78f721b5e22375c9", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:18:17 ERROR : file1: WriteFileHandle.Release error: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "78f721b5e22375c9", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" write_test.go:222: Error Trace: write_test.go:222 Error: Received unexpected error: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "78f721b5e22375c9", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" Test: TestWriteFileHandleRelease 2020/12/27 06:18:17 DEBUG : file1: WriteFileHandle.Release nothing to do 2020/12/27 06:18:17 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:18:17 DEBUG : : Looking for writers 2020/12/27 06:18:17 DEBUG : file1: reading active writers 2020/12/27 06:18:17 DEBUG : file1: active writers 1 2020/12/27 06:18:17 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/12/27 06:18:17 DEBUG : : Looking for writers 2020/12/27 06:18:17 DEBUG : file1: reading active writers 2020/12/27 06:18:17 DEBUG : file1: active writers 1 2020/12/27 06:18:17 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/12/27 06:18:17 DEBUG : : Looking for writers 2020/12/27 06:18:17 DEBUG : file1: reading active writers 2020/12/27 06:18:17 DEBUG : file1: active writers 1 2020/12/27 06:18:17 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/12/27 06:18:17 DEBUG : : Looking for writers 2020/12/27 06:18:17 DEBUG : file1: reading active writers 2020/12/27 06:18:17 DEBUG : file1: active writers 1 2020/12/27 06:18:17 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/12/27 06:18:17 DEBUG : : Looking for writers 2020/12/27 06:18:17 DEBUG : file1: reading active writers 2020/12/27 06:18:17 DEBUG : file1: active writers 1 2020/12/27 06:18:17 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/12/27 06:18:17 DEBUG : : Looking for writers 2020/12/27 06:18:17 DEBUG : file1: reading active writers 2020/12/27 06:18:17 DEBUG : file1: active writers 1 2020/12/27 06:18:17 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/12/27 06:18:17 DEBUG : : Looking for writers 2020/12/27 06:18:17 DEBUG : file1: reading active writers 2020/12/27 06:18:17 DEBUG : file1: active writers 1 2020/12/27 06:18:17 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/12/27 06:18:18 DEBUG : : Looking for writers 2020/12/27 06:18:18 DEBUG : file1: reading active writers 2020/12/27 06:18:18 DEBUG : file1: active writers 1 2020/12/27 06:18:18 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:19 DEBUG : : Looking for writers 2020/12/27 06:18:19 DEBUG : file1: reading active writers 2020/12/27 06:18:19 DEBUG : file1: active writers 1 2020/12/27 06:18:19 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:20 DEBUG : : Looking for writers 2020/12/27 06:18:20 DEBUG : file1: reading active writers 2020/12/27 06:18:20 DEBUG : file1: active writers 1 2020/12/27 06:18:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:21 DEBUG : : Looking for writers 2020/12/27 06:18:21 DEBUG : file1: reading active writers 2020/12/27 06:18:21 DEBUG : file1: active writers 1 2020/12/27 06:18:21 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:22 DEBUG : : Looking for writers 2020/12/27 06:18:22 DEBUG : file1: reading active writers 2020/12/27 06:18:22 DEBUG : file1: active writers 1 2020/12/27 06:18:22 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:23 DEBUG : : Looking for writers 2020/12/27 06:18:23 DEBUG : file1: reading active writers 2020/12/27 06:18:23 DEBUG : file1: active writers 1 2020/12/27 06:18:23 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:24 DEBUG : : Looking for writers 2020/12/27 06:18:24 DEBUG : file1: reading active writers 2020/12/27 06:18:24 DEBUG : file1: active writers 1 2020/12/27 06:18:24 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:25 DEBUG : : Looking for writers 2020/12/27 06:18:25 DEBUG : file1: reading active writers 2020/12/27 06:18:25 DEBUG : file1: active writers 1 2020/12/27 06:18:25 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:26 DEBUG : : Looking for writers 2020/12/27 06:18:26 DEBUG : file1: reading active writers 2020/12/27 06:18:26 DEBUG : file1: active writers 1 2020/12/27 06:18:26 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:27 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/12/27 06:18:27 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleRelease (10.40s) === RUN TestWriteFileModTimeWithOpenWriters run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:18:27 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache 2020/12/27 06:18:27 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/12/27 06:18:27 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/12/27 06:18:27 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:18:27 DEBUG : file1: >Open: fd=file1 (w), err= 2020/12/27 06:18:27 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/12/27 06:18:27 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:18:27 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: File to upload is small (2 bytes), uploading instead of streaming 2020/12/27 06:18:27 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "06fb7c17f5e811ec", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:18:27 ERROR : file1: WriteFileHandle.New Rcat failed: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "06fb7c17f5e811ec", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" write_test.go:277: Error Trace: write_test.go:277 Error: Received unexpected error: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "06fb7c17f5e811ec", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" Test: TestWriteFileModTimeWithOpenWriters 2020/12/27 06:18:27 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:18:27 DEBUG : : Looking for writers 2020/12/27 06:18:27 DEBUG : file1: reading active writers 2020/12/27 06:18:27 DEBUG : file1: active writers 1 2020/12/27 06:18:27 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/12/27 06:18:27 DEBUG : : Looking for writers 2020/12/27 06:18:27 DEBUG : file1: reading active writers 2020/12/27 06:18:27 DEBUG : file1: active writers 1 2020/12/27 06:18:27 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/12/27 06:18:27 DEBUG : : Looking for writers 2020/12/27 06:18:27 DEBUG : file1: reading active writers 2020/12/27 06:18:27 DEBUG : file1: active writers 1 2020/12/27 06:18:27 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/12/27 06:18:27 DEBUG : : Looking for writers 2020/12/27 06:18:27 DEBUG : file1: reading active writers 2020/12/27 06:18:27 DEBUG : file1: active writers 1 2020/12/27 06:18:27 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/12/27 06:18:27 DEBUG : : Looking for writers 2020/12/27 06:18:27 DEBUG : file1: reading active writers 2020/12/27 06:18:27 DEBUG : file1: active writers 1 2020/12/27 06:18:27 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/12/27 06:18:27 DEBUG : : Looking for writers 2020/12/27 06:18:27 DEBUG : file1: reading active writers 2020/12/27 06:18:27 DEBUG : file1: active writers 1 2020/12/27 06:18:27 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/12/27 06:18:28 DEBUG : : Looking for writers 2020/12/27 06:18:28 DEBUG : file1: reading active writers 2020/12/27 06:18:28 DEBUG : file1: active writers 1 2020/12/27 06:18:28 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/12/27 06:18:28 DEBUG : : Looking for writers 2020/12/27 06:18:28 DEBUG : file1: reading active writers 2020/12/27 06:18:28 DEBUG : file1: active writers 1 2020/12/27 06:18:28 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:29 DEBUG : : Looking for writers 2020/12/27 06:18:29 DEBUG : file1: reading active writers 2020/12/27 06:18:29 DEBUG : file1: active writers 1 2020/12/27 06:18:29 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:30 DEBUG : : Looking for writers 2020/12/27 06:18:30 DEBUG : file1: reading active writers 2020/12/27 06:18:30 DEBUG : file1: active writers 1 2020/12/27 06:18:30 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:31 DEBUG : : Looking for writers 2020/12/27 06:18:31 DEBUG : file1: reading active writers 2020/12/27 06:18:31 DEBUG : file1: active writers 1 2020/12/27 06:18:31 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:32 DEBUG : : Looking for writers 2020/12/27 06:18:32 DEBUG : file1: reading active writers 2020/12/27 06:18:32 DEBUG : file1: active writers 1 2020/12/27 06:18:32 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:33 DEBUG : : Looking for writers 2020/12/27 06:18:33 DEBUG : file1: reading active writers 2020/12/27 06:18:33 DEBUG : file1: active writers 1 2020/12/27 06:18:33 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:34 DEBUG : : Looking for writers 2020/12/27 06:18:34 DEBUG : file1: reading active writers 2020/12/27 06:18:34 DEBUG : file1: active writers 1 2020/12/27 06:18:34 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:35 DEBUG : : Looking for writers 2020/12/27 06:18:35 DEBUG : file1: reading active writers 2020/12/27 06:18:35 DEBUG : file1: active writers 1 2020/12/27 06:18:35 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:36 DEBUG : : Looking for writers 2020/12/27 06:18:36 DEBUG : file1: reading active writers 2020/12/27 06:18:36 DEBUG : file1: active writers 1 2020/12/27 06:18:36 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:37 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/12/27 06:18:37 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileModTimeWithOpenWriters (10.40s) === RUN TestFileReadAtZeroLength run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:18:37 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache 2020/12/27 06:18:37 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/12/27 06:18:37 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/12/27 06:18:37 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:18:37 DEBUG : file1: >Open: fd=file1 (w), err= 2020/12/27 06:18:37 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/12/27 06:18:37 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:18:37 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: File to upload is small (0 bytes), uploading instead of streaming 2020/12/27 06:18:37 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "7af139dff1953b3c", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:18:37 ERROR : file1: WriteFileHandle.New Rcat failed: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "7af139dff1953b3c", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" write_test.go:305: Error Trace: write_test.go:305 write_test.go:325 Error: Received unexpected error: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "7af139dff1953b3c", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" Test: TestFileReadAtZeroLength 2020/12/27 06:18:37 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2020/12/27 06:18:37 DEBUG : file1: Open: flags=O_RDONLY 2020/12/27 06:18:42 DEBUG : file1: >Open: fd=, err=file does not exist 2020/12/27 06:18:42 DEBUG : file1: >OpenFile: fd=, err=file does not exist write_test.go:310: Error Trace: write_test.go:310 write_test.go:325 Error: Received unexpected error: file does not exist Test: TestFileReadAtZeroLength 2020/12/27 06:18:42 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:18:42 DEBUG : : Looking for writers 2020/12/27 06:18:42 DEBUG : file1: reading active writers 2020/12/27 06:18:42 DEBUG : file1: active writers 1 2020/12/27 06:18:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/12/27 06:18:42 DEBUG : : Looking for writers 2020/12/27 06:18:42 DEBUG : file1: reading active writers 2020/12/27 06:18:42 DEBUG : file1: active writers 1 2020/12/27 06:18:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/12/27 06:18:42 DEBUG : : Looking for writers 2020/12/27 06:18:42 DEBUG : file1: reading active writers 2020/12/27 06:18:42 DEBUG : file1: active writers 1 2020/12/27 06:18:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/12/27 06:18:42 DEBUG : : Looking for writers 2020/12/27 06:18:42 DEBUG : file1: reading active writers 2020/12/27 06:18:42 DEBUG : file1: active writers 1 2020/12/27 06:18:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/12/27 06:18:43 DEBUG : : Looking for writers 2020/12/27 06:18:43 DEBUG : file1: reading active writers 2020/12/27 06:18:43 DEBUG : file1: active writers 1 2020/12/27 06:18:43 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/12/27 06:18:43 DEBUG : : Looking for writers 2020/12/27 06:18:43 DEBUG : file1: reading active writers 2020/12/27 06:18:43 DEBUG : file1: active writers 1 2020/12/27 06:18:43 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/12/27 06:18:43 DEBUG : : Looking for writers 2020/12/27 06:18:43 DEBUG : file1: reading active writers 2020/12/27 06:18:43 DEBUG : file1: active writers 1 2020/12/27 06:18:43 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/12/27 06:18:44 DEBUG : : Looking for writers 2020/12/27 06:18:44 DEBUG : file1: reading active writers 2020/12/27 06:18:44 DEBUG : file1: active writers 1 2020/12/27 06:18:44 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:45 DEBUG : : Looking for writers 2020/12/27 06:18:45 DEBUG : file1: reading active writers 2020/12/27 06:18:45 DEBUG : file1: active writers 1 2020/12/27 06:18:45 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:46 DEBUG : : Looking for writers 2020/12/27 06:18:46 DEBUG : file1: reading active writers 2020/12/27 06:18:46 DEBUG : file1: active writers 1 2020/12/27 06:18:46 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:47 DEBUG : : Looking for writers 2020/12/27 06:18:47 DEBUG : file1: reading active writers 2020/12/27 06:18:47 DEBUG : file1: active writers 1 2020/12/27 06:18:47 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:48 DEBUG : : Looking for writers 2020/12/27 06:18:48 DEBUG : file1: reading active writers 2020/12/27 06:18:48 DEBUG : file1: active writers 1 2020/12/27 06:18:48 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:49 DEBUG : : Looking for writers 2020/12/27 06:18:49 DEBUG : file1: reading active writers 2020/12/27 06:18:49 DEBUG : file1: active writers 1 2020/12/27 06:18:49 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:50 DEBUG : : Looking for writers 2020/12/27 06:18:50 DEBUG : file1: reading active writers 2020/12/27 06:18:50 DEBUG : file1: active writers 1 2020/12/27 06:18:50 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:51 DEBUG : : Looking for writers 2020/12/27 06:18:51 DEBUG : file1: reading active writers 2020/12/27 06:18:51 DEBUG : file1: active writers 1 2020/12/27 06:18:51 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:52 DEBUG : : Looking for writers 2020/12/27 06:18:52 DEBUG : file1: reading active writers 2020/12/27 06:18:52 DEBUG : file1: active writers 1 2020/12/27 06:18:52 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:18:52 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/12/27 06:18:52 DEBUG : >WaitForWriters: --- FAIL: TestFileReadAtZeroLength (16.61s) === RUN TestFileReadAtNonZeroLength run.go:176: Remote "QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2", Local "Local file system at /tmp/rclone588092388", Modify Window "876000h0m0s" 2020/12/27 06:18:54 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Re-using VFS from active cache 2020/12/27 06:18:54 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2020/12/27 06:18:54 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2020/12/27 06:18:54 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:18:54 DEBUG : file1: >Open: fd=file1 (w), err= 2020/12/27 06:18:54 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2020/12/27 06:18:54 DEBUG : : Added virtual directory entry vAddFile: "file1" 2020/12/27 06:18:54 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: File to upload is small (100 bytes), uploading instead of streaming 2020/12/27 06:18:54 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "c8136edb4e0ef0ba", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:18:54 ERROR : file1: WriteFileHandle.New Rcat failed: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "c8136edb4e0ef0ba", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" write_test.go:305: Error Trace: write_test.go:305 write_test.go:329 Error: Received unexpected error: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "c8136edb4e0ef0ba", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" Test: TestFileReadAtNonZeroLength 2020/12/27 06:18:54 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2020/12/27 06:18:54 DEBUG : file1: Open: flags=O_RDONLY 2020/12/27 06:18:59 DEBUG : file1: >Open: fd=, err=file does not exist 2020/12/27 06:18:59 DEBUG : file1: >OpenFile: fd=, err=file does not exist write_test.go:310: Error Trace: write_test.go:310 write_test.go:329 Error: Received unexpected error: file does not exist Test: TestFileReadAtNonZeroLength 2020/12/27 06:18:59 DEBUG : WaitForWriters: timeout=10s 2020/12/27 06:18:59 DEBUG : : Looking for writers 2020/12/27 06:18:59 DEBUG : file1: reading active writers 2020/12/27 06:18:59 DEBUG : file1: active writers 1 2020/12/27 06:18:59 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2020/12/27 06:18:59 DEBUG : : Looking for writers 2020/12/27 06:18:59 DEBUG : file1: reading active writers 2020/12/27 06:18:59 DEBUG : file1: active writers 1 2020/12/27 06:18:59 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2020/12/27 06:18:59 DEBUG : : Looking for writers 2020/12/27 06:18:59 DEBUG : file1: reading active writers 2020/12/27 06:18:59 DEBUG : file1: active writers 1 2020/12/27 06:18:59 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2020/12/27 06:18:59 DEBUG : : Looking for writers 2020/12/27 06:18:59 DEBUG : file1: reading active writers 2020/12/27 06:18:59 DEBUG : file1: active writers 1 2020/12/27 06:18:59 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2020/12/27 06:18:59 DEBUG : : Looking for writers 2020/12/27 06:18:59 DEBUG : file1: reading active writers 2020/12/27 06:18:59 DEBUG : file1: active writers 1 2020/12/27 06:18:59 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2020/12/27 06:18:59 DEBUG : : Looking for writers 2020/12/27 06:18:59 DEBUG : file1: reading active writers 2020/12/27 06:18:59 DEBUG : file1: active writers 1 2020/12/27 06:18:59 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2020/12/27 06:19:00 DEBUG : : Looking for writers 2020/12/27 06:19:00 DEBUG : file1: reading active writers 2020/12/27 06:19:00 DEBUG : file1: active writers 1 2020/12/27 06:19:00 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2020/12/27 06:19:00 DEBUG : : Looking for writers 2020/12/27 06:19:00 DEBUG : file1: reading active writers 2020/12/27 06:19:00 DEBUG : file1: active writers 1 2020/12/27 06:19:00 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:19:01 DEBUG : : Looking for writers 2020/12/27 06:19:01 DEBUG : file1: reading active writers 2020/12/27 06:19:01 DEBUG : file1: active writers 1 2020/12/27 06:19:01 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:19:02 DEBUG : : Looking for writers 2020/12/27 06:19:02 DEBUG : file1: reading active writers 2020/12/27 06:19:02 DEBUG : file1: active writers 1 2020/12/27 06:19:02 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:19:03 DEBUG : : Looking for writers 2020/12/27 06:19:03 DEBUG : file1: reading active writers 2020/12/27 06:19:03 DEBUG : file1: active writers 1 2020/12/27 06:19:03 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:19:04 DEBUG : : Looking for writers 2020/12/27 06:19:04 DEBUG : file1: reading active writers 2020/12/27 06:19:04 DEBUG : file1: active writers 1 2020/12/27 06:19:04 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:19:05 DEBUG : : Looking for writers 2020/12/27 06:19:05 DEBUG : file1: reading active writers 2020/12/27 06:19:05 DEBUG : file1: active writers 1 2020/12/27 06:19:05 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:19:06 DEBUG : : Looking for writers 2020/12/27 06:19:06 DEBUG : file1: reading active writers 2020/12/27 06:19:06 DEBUG : file1: active writers 1 2020/12/27 06:19:06 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:19:07 DEBUG : : Looking for writers 2020/12/27 06:19:07 DEBUG : file1: reading active writers 2020/12/27 06:19:07 DEBUG : file1: active writers 1 2020/12/27 06:19:07 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:19:08 DEBUG : : Looking for writers 2020/12/27 06:19:08 DEBUG : file1: reading active writers 2020/12/27 06:19:08 DEBUG : file1: active writers 1 2020/12/27 06:19:08 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2020/12/27 06:19:09 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2020/12/27 06:19:09 DEBUG : >WaitForWriters: --- FAIL: TestFileReadAtNonZeroLength (15.41s) FAIL 2020/12/27 06:19:09 DEBUG : QingStor bucket rclone-test-kodotij6tedopev1vuleyoq2: Purge dir "" 2020/12/27 06:19:10 purge failed to rmdir "": QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "1eadd828fe824a29", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2020/12/27 06:19:10 purge failed: directory not found "./vfs.test -test.v -test.timeout 1h0m0s -remote TestQingStor: -verbose -test.run '^(TestCaseSensitivity|TestDirCreate|TestDirForgetAll|TestDirForgetPath|TestDirHandleMethods|TestDirHandleReaddir|TestDirHandleReaddirnames|TestDirMethods|TestDirMkdir|TestDirMkdirSub|TestDirOpen|TestDirReadDirAll|TestDirRemove|TestDirRemoveAll|TestDirRemoveName|TestDirRename|TestDirSetModTime|TestDirStat|TestDirWalk|TestFileMethods|TestFileOpen|TestFileOpenRead|TestFileOpenWrite|TestFileReadAtNonZeroLength|TestFileReadAtZeroLength|TestFileRemove|TestFileRemoveAll|TestFileRename|TestFileSetModTime|TestRWFileHandleFlushRead|TestRWFileHandleMethodsRead|TestRWFileHandleMethodsWrite|TestRWFileHandleReadAt|TestRWFileHandleReleaseRead|TestRWFileHandleSeek|TestRWFileHandleSizeCreateExisting|TestRWFileHandleSizeTruncateExisting|TestRWFileHandleWriteAt|TestRWFileHandleWriteNoWrite|TestRWFileModTimeWithOpenWriters|TestRcGetVFS|TestReadFileHandleFlush|TestReadFileHandleMethods|TestReadFileHandleReadAt|TestReadFileHandleRelease|TestReadFileHandleSeek|TestVFSNew|TestVFSOpenFile|TestVFSRename|TestVFSStat|TestVFSStatParent|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileHandleRelease|TestWriteFileHandleWriteAt|TestWriteFileModTimeWithOpenWriters)$/^(full,forceCache=false|minimal,forceCache=false|minimal,forceCache=true|off,forceCache=false|writes,forceCache=false|writes,forceCache=true)$'" - Finished ERROR in 7m8.052815179s (try 4/5): exit status 1: Failed [TestDirHandleMethods TestDirHandleReaddir TestDirHandleReaddirnames TestDirMethods TestDirForgetAll TestDirForgetPath TestDirWalk TestDirSetModTime TestDirStat TestDirReadDirAll TestDirOpen TestDirCreate TestDirMkdir TestDirMkdirSub TestDirRemove TestDirRemoveAll TestDirRemoveName TestDirRename TestFileMethods TestFileSetModTime 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 TestRcGetVFS TestReadFileHandleMethods TestReadFileHandleSeek TestReadFileHandleReadAt TestReadFileHandleFlush TestReadFileHandleRelease TestRWFileHandleMethodsRead TestRWFileHandleSeek TestRWFileHandleReadAt TestRWFileHandleFlushRead TestRWFileHandleReleaseRead TestRWFileHandleMethodsWrite TestRWFileHandleWriteAt TestRWFileHandleWriteNoWrite TestRWFileHandleSizeTruncateExisting TestRWFileHandleSizeCreateExisting TestRWFileModTimeWithOpenWriters TestCaseSensitivity TestVFSNew TestVFSStat TestVFSStatParent TestVFSOpenFile TestVFSRename TestWriteFileHandleMethods TestWriteFileHandleWriteAt TestWriteFileHandleFlush TestWriteFileHandleRelease TestWriteFileModTimeWithOpenWriters TestFileReadAtZeroLength TestFileReadAtNonZeroLength]