"./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)$/^(cache=full,open=false,write=false|cache=full,open=true,write=false|cache=full,open=true,write=true|cache=off,open=false,write=false|cache=off,open=true,write=false|cache=off,open=true,write=true|full,forceCache=false|minimal,forceCache=false|minimal,forceCache=true|off,forceCache=false|writes,forceCache=false|writes,forceCache=true)$'" - Starting (try 3/5) 2021/06/01 06:12:20 DEBUG : Creating backend with remote "TestQingStor:rclone-test-deyohud0panixok0zotagev4" 2021/06/01 06:12:20 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2021/06/01 06:12:20 DEBUG : Creating backend with remote "/tmp/rclone442657724" === RUN TestDirHandleMethods run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:12:20 INFO : QingStor bucket rclone-test-deyohud0panixok0zotagev4: poll-interval is not supported by this remote 2021/06/01 06:12:20 NOTICE: QingStor bucket rclone-test-deyohud0panixok0zotagev4: --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-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "90e112e1a1a77778", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirHandleMethods (7.36s) === RUN TestDirHandleReaddir run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:12:27 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "777c9854dab1b2f2", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:12:34 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:12:34 DEBUG : : Looking for writers 2021/06/01 06:12:34 DEBUG : >WaitForWriters: --- FAIL: TestDirHandleReaddir (6.41s) === RUN TestDirHandleReaddirnames run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:12:34 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "b936a5b60b509d49", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirHandleReaddirnames (6.05s) === RUN TestDirMethods run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:12:40 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "a38705b45c1c1248", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirMethods (6.07s) === RUN TestDirForgetAll run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:12:46 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "b134fcc2a18bd3cb", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirForgetAll (6.11s) === RUN TestDirForgetPath run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:12:52 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "75e3570cac41210c", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirForgetPath (6.01s) === RUN TestDirWalk run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:12:58 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "83536165a87c339a", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirWalk (6.01s) === RUN TestDirSetModTime run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:13:04 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "8dba3bd0bbac47e9", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirSetModTime (6.07s) === RUN TestDirStat run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:13:10 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "e214c656685a6e99", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirStat (6.14s) === RUN TestDirReadDirAll run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:13:16 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "a9392dc434acf3b0", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:13:22 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:13:22 DEBUG : : Looking for writers 2021/06/01 06:13:22 DEBUG : >WaitForWriters: --- FAIL: TestDirReadDirAll (6.38s) === RUN TestDirOpen run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:13:23 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "61b1c14829ef5cfc", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirOpen (6.11s) === RUN TestDirCreate run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:13:29 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "598165f8f8e3996c", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirCreate (6.17s) === RUN TestDirMkdir run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:13:35 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "bffdb420f5ff643b", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirMkdir (6.07s) === RUN TestDirMkdirSub run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:13:41 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "026f892e762b691c", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirMkdirSub (6.13s) === RUN TestDirRemove run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:13:47 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "28567311952ab8c7", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirRemove (6.12s) === RUN TestDirRemoveAll run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:13:53 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "255e565523210f56", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirRemoveAll (6.10s) === RUN TestDirRemoveName run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:13:59 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "5fae49f741904d58", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirRemoveName (6.01s) === RUN TestDirRename run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:14:05 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "551051de3580ba99", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestDirRename (6.13s) === RUN TestFileMethods run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:14:11 INFO : QingStor bucket rclone-test-deyohud0panixok0zotagev4: poll-interval is not supported by this remote 2021/06/01 06:14:11 NOTICE: QingStor bucket rclone-test-deyohud0panixok0zotagev4: --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-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "3da86734efb5c6fd", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestFileMethods (6.16s) === RUN TestFileSetModTime === RUN TestFileSetModTime/cache=off,open=false,write=false run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:14:18 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "d9a94209726342ab", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" === RUN TestFileSetModTime/cache=off,open=true,write=false run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:14:24 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "af8713c9d71f7826", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" === RUN TestFileSetModTime/cache=off,open=true,write=true run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:14:30 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "b2d300f7de228209", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" === RUN TestFileSetModTime/cache=full,open=false,write=false run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:14:36 INFO : QingStor bucket rclone-test-deyohud0panixok0zotagev4: poll-interval is not supported by this remote 2021/06/01 06:14:36 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestQingStor/rclone-test-deyohud0panixok0zotagev4" 2021/06/01 06:14:36 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestQingStor/rclone-test-deyohud0panixok0zotagev4" 2021/06/01 06:14:36 DEBUG : Creating backend with remote "/home/rclone/.cache/rclone/vfs/TestQingStor/rclone-test-deyohud0panixok0zotagev4" 2021/06/01 06:14:36 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-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "f08d668c52981f8b", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" === RUN TestFileSetModTime/cache=full,open=true,write=false run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:14:42 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "979858b3f77e4cff", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" === RUN TestFileSetModTime/cache=full,open=true,write=true run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:14:48 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "a25bcc80b9975226", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestFileSetModTime (36.59s) --- FAIL: TestFileSetModTime/cache=off,open=false,write=false (6.14s) --- FAIL: TestFileSetModTime/cache=off,open=true,write=false (6.12s) --- FAIL: TestFileSetModTime/cache=off,open=true,write=true (6.11s) --- FAIL: TestFileSetModTime/cache=full,open=false,write=false (6.08s) --- FAIL: TestFileSetModTime/cache=full,open=true,write=false (6.14s) --- FAIL: TestFileSetModTime/cache=full,open=true,write=true (6.00s) === RUN TestFileOpenRead run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:14:54 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "c2af0c370a4f5340", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestFileOpenRead (6.02s) === RUN TestFileOpenWrite run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:15:00 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "e7b1f4ef6beb24d4", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestFileOpenWrite (6.05s) === RUN TestFileRemove run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:15:06 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "d3b8a42a6e038da1", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestFileRemove (6.06s) === RUN TestFileRemoveAll run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:15:12 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "c977af53c7289ced", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestFileRemoveAll (6.13s) === RUN TestFileOpen run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:15:18 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "f59743c3a5ac6798", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestFileOpen (6.04s) === RUN TestFileRename === RUN TestFileRename/off,forceCache=false run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:15:25 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "228775f1b53e752e", 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-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:15:31 INFO : QingStor bucket rclone-test-deyohud0panixok0zotagev4: poll-interval is not supported by this remote 2021/06/01 06:15:31 NOTICE: QingStor bucket rclone-test-deyohud0panixok0zotagev4: --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2021/06/01 06:15:31 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestQingStor/rclone-test-deyohud0panixok0zotagev4" 2021/06/01 06:15:31 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestQingStor/rclone-test-deyohud0panixok0zotagev4" 2021/06/01 06:15:31 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2021/06/01 06:15:36 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-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "7c8797222f3c5b00", 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-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:15:37 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "9e4244dc46ae30a0", 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-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:15:43 INFO : QingStor bucket rclone-test-deyohud0panixok0zotagev4: poll-interval is not supported by this remote 2021/06/01 06:15:43 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestQingStor/rclone-test-deyohud0panixok0zotagev4" 2021/06/01 06:15:43 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestQingStor/rclone-test-deyohud0panixok0zotagev4" 2021/06/01 06:15:43 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-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "ee93a90932b7153c", 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-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:15:49 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "0db84db1bc244297", 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-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:15:55 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "8909e56a4c6695c8", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestFileRename (36.29s) --- FAIL: TestFileRename/off,forceCache=false (6.02s) --- FAIL: TestFileRename/minimal,forceCache=false (6.01s) --- FAIL: TestFileRename/minimal,forceCache=true (6.04s) --- FAIL: TestFileRename/writes,forceCache=false (6.06s) --- FAIL: TestFileRename/writes,forceCache=true (6.05s) --- FAIL: TestFileRename/full,forceCache=false (6.11s) === 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-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:16:01 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: 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 2021/06/01 06:16:01 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:16:01 DEBUG : : Looking for writers 2021/06/01 06:16:01 DEBUG : >WaitForWriters: --- FAIL: TestRcGetVFS (0.27s) === RUN TestReadFileHandleMethods run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:16:01 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "36ddbe6b3be90700", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestReadFileHandleMethods (6.10s) === RUN TestReadFileHandleSeek run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:16:07 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "846bf40d708d351a", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestReadFileHandleSeek (6.17s) === RUN TestReadFileHandleReadAt run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:16:13 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "6c54d76a11b9cab4", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestReadFileHandleReadAt (6.03s) === RUN TestReadFileHandleFlush run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:16:19 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "62fab70d91ba4eff", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestReadFileHandleFlush (6.14s) === RUN TestReadFileHandleRelease run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:16:26 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache 2021/06/01 06:16:31 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-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "4a1b31aac46bc653", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestReadFileHandleRelease (6.10s) === RUN TestRWFileHandleMethodsRead run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:16:32 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache 2021/06/01 06:16:36 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-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "1cca916fe4327522", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestRWFileHandleMethodsRead (6.22s) === RUN TestRWFileHandleSeek run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:16:38 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache 2021/06/01 06:16:43 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-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "a10bd3a0f97fd333", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestRWFileHandleSeek (6.12s) === RUN TestRWFileHandleReadAt run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:16:44 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "9ea5a835e377a2b4", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestRWFileHandleReadAt (6.04s) === RUN TestRWFileHandleFlushRead run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:16:50 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "362c47e8d14f9ecf", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestRWFileHandleFlushRead (6.04s) === RUN TestRWFileHandleReleaseRead run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:16:56 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:234: Failed to mkdir "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "403", Code "too_many_buckets", Message "You created too many buckets, please open ticket to apply more quota.", Request ID "b49dae33204eb527", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestRWFileHandleReleaseRead (6.04s) === RUN TestRWFileHandleMethodsWrite run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:17:02 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache 2021/06/01 06:17:02 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2021/06/01 06:17:02 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2021/06/01 06:17:02 DEBUG : file1: newRWFileHandle: 2021/06/01 06:17:02 DEBUG : file1(0xc0008ca800): openPending: 2021/06/01 06:17:02 DEBUG : file1: vfs cache: truncate to size=0 2021/06/01 06:17:02 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:17:02 DEBUG : file1(0xc0008ca800): >openPending: err= 2021/06/01 06:17:02 DEBUG : file1: >newRWFileHandle: err= 2021/06/01 06:17:02 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:17:02 DEBUG : file1: >Open: fd=file1 (rw), err= 2021/06/01 06:17:02 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2021/06/01 06:17:02 DEBUG : file1(0xc0008ca800): _writeAt: size=5, off=0 2021/06/01 06:17:02 DEBUG : file1(0xc0008ca800): >_writeAt: n=5, err= 2021/06/01 06:17:02 DEBUG : file1(0xc0008ca800): _writeAt: size=7, off=5 2021/06/01 06:17:02 DEBUG : file1(0xc0008ca800): >_writeAt: n=7, err= 2021/06/01 06:17:02 DEBUG : file1: vfs cache: truncate to size=11 2021/06/01 06:17:02 DEBUG : file1(0xc0008ca800): close: 2021/06/01 06:17:02 DEBUG : file1: vfs cache: setting modification time to 2021-06-01 06:17:02.852581594 +0000 UTC m=+282.373318649 2021/06/01 06:17:02 INFO : file1: vfs cache: queuing for upload in 100ms 2021/06/01 06:17:02 DEBUG : file1(0xc0008ca800): >close: err= 2021/06/01 06:17:02 DEBUG : file1(0xc0008ca800): close: 2021/06/01 06:17:02 DEBUG : file1(0xc0008ca800): >close: err=file already closed 2021/06/01 06:17:02 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:17:02 DEBUG : : Looking for writers 2021/06/01 06:17:02 DEBUG : file1: reading active writers 2021/06/01 06:17:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2021/06/01 06:17:02 DEBUG : : Looking for writers 2021/06/01 06:17:02 DEBUG : file1: reading active writers 2021/06/01 06:17:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2021/06/01 06:17:02 DEBUG : : Looking for writers 2021/06/01 06:17:02 DEBUG : file1: reading active writers 2021/06/01 06:17:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2021/06/01 06:17:02 DEBUG : : Looking for writers 2021/06/01 06:17:02 DEBUG : file1: reading active writers 2021/06/01 06:17:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2021/06/01 06:17:02 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:17:03 DEBUG : : Looking for writers 2021/06/01 06:17:03 DEBUG : file1: reading active writers 2021/06/01 06:17:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2021/06/01 06:17:03 DEBUG : : Looking for writers 2021/06/01 06:17:03 DEBUG : file1: reading active writers 2021/06/01 06:17:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2021/06/01 06:17:03 DEBUG : : Looking for writers 2021/06/01 06:17:03 DEBUG : file1: reading active writers 2021/06/01 06:17:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2021/06/01 06:17:04 DEBUG : : Looking for writers 2021/06/01 06:17:04 DEBUG : file1: reading active writers 2021/06/01 06:17:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:05 DEBUG : : Looking for writers 2021/06/01 06:17:05 DEBUG : file1: reading active writers 2021/06/01 06:17:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:06 DEBUG : : Looking for writers 2021/06/01 06:17:06 DEBUG : file1: reading active writers 2021/06/01 06:17:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:07 DEBUG : : Looking for writers 2021/06/01 06:17:07 DEBUG : file1: reading active writers 2021/06/01 06:17:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:08 DEBUG : : Looking for writers 2021/06/01 06:17:08 DEBUG : file1: reading active writers 2021/06/01 06:17:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:09 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 "d9bf9aad3e4c4c48", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:09 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 "d9bf9aad3e4c4c48", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:09 DEBUG : : Looking for writers 2021/06/01 06:17:09 DEBUG : file1: reading active writers 2021/06/01 06:17:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:09 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:17:10 DEBUG : : Looking for writers 2021/06/01 06:17:10 DEBUG : file1: reading active writers 2021/06/01 06:17:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:11 DEBUG : : Looking for writers 2021/06/01 06:17:11 DEBUG : file1: reading active writers 2021/06/01 06:17:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:12 DEBUG : : Looking for writers 2021/06/01 06:17:12 DEBUG : file1: reading active writers 2021/06/01 06:17:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:12 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s Cache{ "file1": &{c:0xc0001a1800 mu:{state:0 sema:0} cond:0xc0008ca7c0 name:file1 opens:0 downloaders: o: fd: modified:false info:{ModTime:{wall:13845633259902426330 ext:282373318649 loc:0x2b58f40} ATime:{wall:13845633259902450396 ext:282373342704 loc:0x2b58f40} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, } 2021/06/01 06:17:12 DEBUG : >WaitForWriters: fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 2021/06/01 06:17:15 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 "720c6e407364a6a9", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:15 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 "720c6e407364a6a9", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:15 DEBUG : file1: vfs cache: starting upload 2021/06/01 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 "9274a9f0bac6c03a", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:15 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 "9274a9f0bac6c03a", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:16 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:17: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 "014491ac8f2dae23", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:17 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 "014491ac8f2dae23", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 2021/06/01 06:17:18 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:17:18 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "644c8a228d55aa1e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:18 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "644c8a228d55aa1e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 read_write_test.go:344 Error: Should be true Test: TestRWFileHandleMethodsWrite Messages: listing wrong, want file1 (11) got fstest.go:204: Not found "file1" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 read_write_test.go:344 Error: Not equal: expected: 0 actual : 1 Test: TestRWFileHandleMethodsWrite Messages: 1 objects not found 2021/06/01 06:17:21 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:17:21 DEBUG : : Looking for writers 2021/06/01 06:17:21 DEBUG : file1: reading active writers 2021/06/01 06:17:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2021/06/01 06:17:21 DEBUG : : Looking for writers 2021/06/01 06:17:21 DEBUG : file1: reading active writers 2021/06/01 06:17:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2021/06/01 06:17:21 DEBUG : : Looking for writers 2021/06/01 06:17:21 DEBUG : file1: reading active writers 2021/06/01 06:17:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2021/06/01 06:17:21 DEBUG : : Looking for writers 2021/06/01 06:17:21 DEBUG : file1: reading active writers 2021/06/01 06:17:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2021/06/01 06:17:21 DEBUG : : Looking for writers 2021/06/01 06:17:21 DEBUG : file1: reading active writers 2021/06/01 06:17:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2021/06/01 06:17:21 DEBUG : : Looking for writers 2021/06/01 06:17:21 DEBUG : file1: reading active writers 2021/06/01 06:17:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2021/06/01 06:17:22 DEBUG : : Looking for writers 2021/06/01 06:17:22 DEBUG : file1: reading active writers 2021/06/01 06:17:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2021/06/01 06:17:22 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:17: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 "78815eb2840ca9ca", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:22 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 "78815eb2840ca9ca", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:22 DEBUG : : Looking for writers 2021/06/01 06:17:22 DEBUG : file1: reading active writers 2021/06/01 06:17:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:23 DEBUG : : Looking for writers 2021/06/01 06:17:23 DEBUG : file1: reading active writers 2021/06/01 06:17:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:24 DEBUG : : Looking for writers 2021/06/01 06:17:24 DEBUG : file1: reading active writers 2021/06/01 06:17:24 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:25 DEBUG : : Looking for writers 2021/06/01 06:17:25 DEBUG : file1: reading active writers 2021/06/01 06:17:25 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:26 DEBUG : : Looking for writers 2021/06/01 06:17:26 DEBUG : file1: reading active writers 2021/06/01 06:17:26 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:27 DEBUG : : Looking for writers 2021/06/01 06:17:27 DEBUG : file1: reading active writers 2021/06/01 06:17:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:28 DEBUG : : Looking for writers 2021/06/01 06:17:28 DEBUG : file1: reading active writers 2021/06/01 06:17:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:28 DEBUG : file1: vfs cache: starting upload 2021/06/01 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 "4fc840ce1b4628e7", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:29 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 "4fc840ce1b4628e7", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:29 DEBUG : : Looking for writers 2021/06/01 06:17:29 DEBUG : file1: reading active writers 2021/06/01 06:17:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:30 DEBUG : : Looking for writers 2021/06/01 06:17:30 DEBUG : file1: reading active writers 2021/06/01 06:17:30 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:31 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2021/06/01 06:17:31 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s Cache{ "file1": &{c:0xc0001a1800 mu:{state:0 sema:0} cond:0xc0008ca7c0 name:file1 opens:0 downloaders: o: fd: modified:false info:{ModTime:{wall:13845633259902426330 ext:282373318649 loc:0x2b58f40} ATime:{wall:13845633259902450396 ext:282373342704 loc:0x2b58f40} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, } 2021/06/01 06:17:31 DEBUG : >WaitForWriters: --- FAIL: TestRWFileHandleMethodsWrite (29.13s) === RUN TestRWFileHandleWriteAt run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:17:31 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache 2021/06/01 06:17:31 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2021/06/01 06:17:31 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2021/06/01 06:17:31 DEBUG : file1: newRWFileHandle: 2021/06/01 06:17:31 DEBUG : file1(0xc00007e1c0): openPending: 2021/06/01 06:17:31 ERROR : file1: vfs cache: detected external removal of cache file 2021/06/01 06:17:31 DEBUG : file1: vfs cache: truncate to size=0 2021/06/01 06:17:31 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:17:31 DEBUG : file1(0xc00007e1c0): >openPending: err= 2021/06/01 06:17:31 DEBUG : file1: vfs cache: cancelling writeback (uploading false) 0xc0008c6af0 item 1 2021/06/01 06:17:31 DEBUG : file1: >newRWFileHandle: err= 2021/06/01 06:17:31 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:17:31 DEBUG : file1: >Open: fd=file1 (rw), err= 2021/06/01 06:17:31 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2021/06/01 06:17:31 DEBUG : file1(0xc00007e1c0): _writeAt: size=7, off=0 2021/06/01 06:17:31 DEBUG : file1(0xc00007e1c0): >_writeAt: n=7, err= 2021/06/01 06:17:31 DEBUG : file1(0xc00007e1c0): _writeAt: size=6, off=5 2021/06/01 06:17:31 DEBUG : file1(0xc00007e1c0): >_writeAt: n=6, err= 2021/06/01 06:17:31 DEBUG : file1(0xc00007e1c0): close: 2021/06/01 06:17:31 DEBUG : file1: vfs cache: setting modification time to 2021-06-01 06:17:31.704518682 +0000 UTC m=+311.225255715 2021/06/01 06:17:31 INFO : file1: vfs cache: queuing for upload in 100ms 2021/06/01 06:17:31 DEBUG : file1(0xc00007e1c0): >close: err= 2021/06/01 06:17:31 DEBUG : file1(0xc00007e1c0): _writeAt: size=5, off=0 2021/06/01 06:17:31 DEBUG : file1(0xc00007e1c0): >_writeAt: n=0, err=file already closed 2021/06/01 06:17:31 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:17:31 DEBUG : : Looking for writers 2021/06/01 06:17:31 DEBUG : file1: reading active writers 2021/06/01 06:17:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2021/06/01 06:17:31 DEBUG : : Looking for writers 2021/06/01 06:17:31 DEBUG : file1: reading active writers 2021/06/01 06:17:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2021/06/01 06:17:31 DEBUG : : Looking for writers 2021/06/01 06:17:31 DEBUG : file1: reading active writers 2021/06/01 06:17:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2021/06/01 06:17:31 DEBUG : : Looking for writers 2021/06/01 06:17:31 DEBUG : file1: reading active writers 2021/06/01 06:17:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2021/06/01 06:17:31 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:17:31 DEBUG : : Looking for writers 2021/06/01 06:17:31 DEBUG : file1: reading active writers 2021/06/01 06:17:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2021/06/01 06:17:32 DEBUG : : Looking for writers 2021/06/01 06:17:32 DEBUG : file1: reading active writers 2021/06/01 06:17:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2021/06/01 06:17:32 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "c41f9936440022a8", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:32 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 "c41f9936440022a8", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:32 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:17:32 DEBUG : : Looking for writers 2021/06/01 06:17:32 DEBUG : file1: reading active writers 2021/06/01 06:17:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2021/06/01 06:17:32 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "f79feb239abda802", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:32 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 "f79feb239abda802", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:32 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:17:32 DEBUG : : Looking for writers 2021/06/01 06:17:32 DEBUG : file1: reading active writers 2021/06/01 06:17:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:33 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "4a06c7cbbad8bedc", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:33 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 "4a06c7cbbad8bedc", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:33 DEBUG : : Looking for writers 2021/06/01 06:17:33 DEBUG : file1: reading active writers 2021/06/01 06:17:33 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:33 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:17: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 "290b62d41a000cba", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:34 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 "290b62d41a000cba", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:34 DEBUG : : Looking for writers 2021/06/01 06:17:34 DEBUG : file1: reading active writers 2021/06/01 06:17:34 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:35 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:17:35 DEBUG : : Looking for writers 2021/06/01 06:17:35 DEBUG : file1: reading active writers 2021/06/01 06:17:35 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:36 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "07849cb946d6f974", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:36 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 "07849cb946d6f974", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:36 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2021/06/01 06:17:36 INFO : vfs cache: cleaned: objects 1 (was 1) in use 1, to upload 1, uploading 0, total size 11 (was 11) 2021/06/01 06:17:36 DEBUG : : Looking for writers 2021/06/01 06:17:36 DEBUG : file1: reading active writers 2021/06/01 06:17:36 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:37 DEBUG : : Looking for writers 2021/06/01 06:17:37 DEBUG : file1: reading active writers 2021/06/01 06:17:37 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:38 DEBUG : : Looking for writers 2021/06/01 06:17:38 DEBUG : file1: reading active writers 2021/06/01 06:17:38 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:39 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:17:39 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "a49e5eeb7134d8fd", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:39 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 "a49e5eeb7134d8fd", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:39 DEBUG : : Looking for writers 2021/06/01 06:17:39 DEBUG : file1: reading active writers 2021/06/01 06:17:39 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:40 DEBUG : : Looking for writers 2021/06/01 06:17:40 DEBUG : file1: reading active writers 2021/06/01 06:17:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:41 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s Cache{ "file1": &{c:0xc0001a1800 mu:{state:0 sema:0} cond:0xc0008ca7c0 name:file1 opens:0 downloaders: o: fd: modified:false info:{ModTime:{wall:13845633290892876314 ext:311225255715 loc:0x2b58f40} ATime:{wall:13845633290892900700 ext:311225280096 loc:0x2b58f40} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, } 2021/06/01 06:17:41 DEBUG : >WaitForWriters: fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 2021/06/01 06:17:43 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 2021/06/01 06:17:45 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:17:46 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "2fd28869cc18b74f", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:46 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 "2fd28869cc18b74f", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 read_write_test.go:392 Error: Should be true Test: TestRWFileHandleWriteAt Messages: listing wrong, want file1 (11) got fstest.go:204: Not found "file1" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 read_write_test.go:392 Error: Not equal: expected: 0 actual : 1 Test: TestRWFileHandleWriteAt Messages: 1 objects not found 2021/06/01 06:17:49 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:17:49 DEBUG : : Looking for writers 2021/06/01 06:17:49 DEBUG : file1: reading active writers 2021/06/01 06:17:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms 2021/06/01 06:17:49 DEBUG : : Looking for writers 2021/06/01 06:17:49 DEBUG : file1: reading active writers 2021/06/01 06:17:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms 2021/06/01 06:17:49 DEBUG : : Looking for writers 2021/06/01 06:17:49 DEBUG : file1: reading active writers 2021/06/01 06:17:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms 2021/06/01 06:17:49 DEBUG : : Looking for writers 2021/06/01 06:17:49 DEBUG : file1: reading active writers 2021/06/01 06:17:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms 2021/06/01 06:17:49 DEBUG : : Looking for writers 2021/06/01 06:17:49 DEBUG : file1: reading active writers 2021/06/01 06:17:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms 2021/06/01 06:17:49 DEBUG : : Looking for writers 2021/06/01 06:17:49 DEBUG : file1: reading active writers 2021/06/01 06:17:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms 2021/06/01 06:17:50 DEBUG : : Looking for writers 2021/06/01 06:17:50 DEBUG : file1: reading active writers 2021/06/01 06:17:50 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms 2021/06/01 06:17:50 DEBUG : : Looking for writers 2021/06/01 06:17:50 DEBUG : file1: reading active writers 2021/06/01 06:17:50 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:51 DEBUG : : Looking for writers 2021/06/01 06:17:51 DEBUG : file1: reading active writers 2021/06/01 06:17:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:52 DEBUG : : Looking for writers 2021/06/01 06:17:52 DEBUG : file1: reading active writers 2021/06/01 06:17:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:53 DEBUG : : Looking for writers 2021/06/01 06:17:53 DEBUG : file1: reading active writers 2021/06/01 06:17:53 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:54 DEBUG : : Looking for writers 2021/06/01 06:17:54 DEBUG : file1: reading active writers 2021/06/01 06:17:54 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:55 DEBUG : : Looking for writers 2021/06/01 06:17:55 DEBUG : file1: reading active writers 2021/06/01 06:17:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:56 DEBUG : : Looking for writers 2021/06/01 06:17:56 DEBUG : file1: reading active writers 2021/06/01 06:17:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:57 DEBUG : : Looking for writers 2021/06/01 06:17:57 DEBUG : file1: reading active writers 2021/06/01 06:17:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:58 DEBUG : : Looking for writers 2021/06/01 06:17:58 DEBUG : file1: reading active writers 2021/06/01 06:17:58 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s 2021/06/01 06:17:59 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:17:59 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "5d488e82aee498df", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:59 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 "5d488e82aee498df", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:17:59 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s Cache{ "file1": &{c:0xc0001a1800 mu:{state:0 sema:0} cond:0xc0008ca7c0 name:file1 opens:0 downloaders: o: fd: modified:false info:{ModTime:{wall:13845633290892876314 ext:311225255715 loc:0x2b58f40} ATime:{wall:13845633290892900700 ext:311225280096 loc:0x2b58f40} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, } 2021/06/01 06:17:59 DEBUG : >WaitForWriters: --- FAIL: TestRWFileHandleWriteAt (28.05s) === RUN TestRWFileHandleWriteNoWrite run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:17:59 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache 2021/06/01 06:17:59 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2021/06/01 06:17:59 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2021/06/01 06:17:59 DEBUG : file1: newRWFileHandle: 2021/06/01 06:17:59 DEBUG : file1(0xc00007f140): openPending: 2021/06/01 06:17:59 ERROR : file1: vfs cache: detected external removal of cache file 2021/06/01 06:17:59 DEBUG : file1: vfs cache: truncate to size=0 2021/06/01 06:17:59 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:17:59 DEBUG : file1(0xc00007f140): >openPending: err= 2021/06/01 06:17:59 DEBUG : file1: vfs cache: cancelling writeback (uploading false) 0xc000219a40 item 1 2021/06/01 06:17:59 DEBUG : file1: >newRWFileHandle: err= 2021/06/01 06:17:59 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:17:59 DEBUG : file1: >Open: fd=file1 (rw), err= 2021/06/01 06:17:59 DEBUG : file1: >OpenFile: fd=file1 (rw), err= 2021/06/01 06:17:59 DEBUG : file1(0xc00007f140): close: 2021/06/01 06:17:59 DEBUG : file1: vfs cache: setting modification time to 2021-06-01 06:17:59.757291661 +0000 UTC m=+339.278028708 2021/06/01 06:17:59 INFO : file1: vfs cache: queuing for upload in 100ms 2021/06/01 06:17:59 DEBUG : file1(0xc00007f140): >close: err= 2021/06/01 06:17:59 DEBUG : file2: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx 2021/06/01 06:17:59 DEBUG : file2: Open: flags=O_WRONLY|O_CREATE|O_TRUNC 2021/06/01 06:17:59 DEBUG : file2: newRWFileHandle: 2021/06/01 06:17:59 DEBUG : file2(0xc00007f240): openPending: 2021/06/01 06:17:59 DEBUG : file2: vfs cache: truncate to size=0 2021/06/01 06:17:59 DEBUG : : Added virtual directory entry vAddFile: "file2" 2021/06/01 06:17:59 DEBUG : file2(0xc00007f240): >openPending: err= 2021/06/01 06:17:59 DEBUG : file2: >newRWFileHandle: err= 2021/06/01 06:17:59 DEBUG : : Added virtual directory entry vAddFile: "file2" 2021/06/01 06:17:59 DEBUG : file2: >Open: fd=file2 (rw), err= 2021/06/01 06:17:59 DEBUG : file2: >OpenFile: fd=file2 (rw), err= 2021/06/01 06:17:59 DEBUG : file2(0xc00007f240): RWFileHandle.Flush 2021/06/01 06:17:59 DEBUG : file2(0xc00007f240): RWFileHandle.Release 2021/06/01 06:17:59 DEBUG : file2(0xc00007f240): close: 2021/06/01 06:17:59 DEBUG : file2: vfs cache: setting modification time to 2021-06-01 06:17:59.758112789 +0000 UTC m=+339.278849804 2021/06/01 06:17:59 INFO : file2: vfs cache: queuing for upload in 100ms 2021/06/01 06:17:59 DEBUG : file2(0xc00007f240): >close: err= 2021/06/01 06:17:59 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:17:59 DEBUG : : Looking for writers 2021/06/01 06:17:59 DEBUG : file1: reading active writers 2021/06/01 06:17:59 DEBUG : file2: reading active writers 2021/06/01 06:17:59 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms 2021/06/01 06:17:59 DEBUG : : Looking for writers 2021/06/01 06:17:59 DEBUG : file1: reading active writers 2021/06/01 06:17:59 DEBUG : file2: reading active writers 2021/06/01 06:17:59 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms 2021/06/01 06:17:59 DEBUG : : Looking for writers 2021/06/01 06:17:59 DEBUG : file1: reading active writers 2021/06/01 06:17:59 DEBUG : file2: reading active writers 2021/06/01 06:17:59 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms 2021/06/01 06:17:59 DEBUG : : Looking for writers 2021/06/01 06:17:59 DEBUG : file1: reading active writers 2021/06/01 06:17:59 DEBUG : file2: reading active writers 2021/06/01 06:17:59 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms 2021/06/01 06:17:59 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:17:59 DEBUG : file2: vfs cache: starting upload 2021/06/01 06:17:59 DEBUG : : Looking for writers 2021/06/01 06:17:59 DEBUG : file1: reading active writers 2021/06/01 06:17:59 DEBUG : file2: reading active writers 2021/06/01 06:17:59 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms 2021/06/01 06:18:00 DEBUG : : Looking for writers 2021/06/01 06:18:00 DEBUG : file1: reading active writers 2021/06/01 06:18:00 DEBUG : file2: reading active writers 2021/06/01 06:18:00 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms 2021/06/01 06:18:00 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "f49c8e30165d438e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:00 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 "f49c8e30165d438e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:00 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:18:00 ERROR : file2: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "59c5af02e4bf53ea", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:00 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 "59c5af02e4bf53ea", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:00 DEBUG : : Looking for writers 2021/06/01 06:18:00 DEBUG : file1: reading active writers 2021/06/01 06:18:00 DEBUG : file2: reading active writers 2021/06/01 06:18:00 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms 2021/06/01 06:18:00 DEBUG : file2: vfs cache: starting upload 2021/06/01 06:18:00 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "32b4d13b3d776245", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:00 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 "32b4d13b3d776245", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:00 ERROR : file2: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "4a58f11757915edd", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:00 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 "4a58f11757915edd", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:01 DEBUG : : Looking for writers 2021/06/01 06:18:01 DEBUG : file1: reading active writers 2021/06/01 06:18:01 DEBUG : file2: reading active writers 2021/06/01 06:18:01 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:01 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:18:01 DEBUG : file2: vfs cache: starting upload 2021/06/01 06:18:01 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "12ab674c2b36ef29", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:01 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 "12ab674c2b36ef29", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:01 ERROR : file2: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "9746ff3d5991b5d8", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:01 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 "9746ff3d5991b5d8", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:02 DEBUG : : Looking for writers 2021/06/01 06:18:02 DEBUG : file1: reading active writers 2021/06/01 06:18:02 DEBUG : file2: reading active writers 2021/06/01 06:18:02 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:02 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:18:02 DEBUG : file2: vfs cache: starting upload 2021/06/01 06:18: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 "7091ca9053130f0a", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:02 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 "7091ca9053130f0a", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18: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 "f67da5f00e2aeee1", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:02 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 "f67da5f00e2aeee1", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:03 DEBUG : : Looking for writers 2021/06/01 06:18:03 DEBUG : file1: reading active writers 2021/06/01 06:18:03 DEBUG : file2: reading active writers 2021/06/01 06:18:03 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:03 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:18:04 DEBUG : : Looking for writers 2021/06/01 06:18:04 DEBUG : file1: reading active writers 2021/06/01 06:18:04 DEBUG : file2: reading active writers 2021/06/01 06:18:04 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:04 DEBUG : file2: vfs cache: starting upload 2021/06/01 06:18: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 "9cffb22c109d459e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:04 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 "9cffb22c109d459e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:04 ERROR : file2: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "a566521f07787d77", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:04 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 "a566521f07787d77", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:05 DEBUG : : Looking for writers 2021/06/01 06:18:05 DEBUG : file1: reading active writers 2021/06/01 06:18:05 DEBUG : file2: reading active writers 2021/06/01 06:18:05 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:06 DEBUG : : Looking for writers 2021/06/01 06:18:06 DEBUG : file2: reading active writers 2021/06/01 06:18:06 DEBUG : file1: reading active writers 2021/06/01 06:18:06 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:07 DEBUG : : Looking for writers 2021/06/01 06:18:07 DEBUG : file1: reading active writers 2021/06/01 06:18:07 DEBUG : file2: reading active writers 2021/06/01 06:18:07 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:07 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:18:07 DEBUG : file2: vfs cache: starting upload 2021/06/01 06:18:07 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "edfd9462ef163836", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:07 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 "edfd9462ef163836", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:07 ERROR : file2: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "37ffaf26b35c582e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:07 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 "37ffaf26b35c582e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:08 DEBUG : : Looking for writers 2021/06/01 06:18:08 DEBUG : file2: reading active writers 2021/06/01 06:18:08 DEBUG : file1: reading active writers 2021/06/01 06:18:08 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:09 DEBUG : : Looking for writers 2021/06/01 06:18:09 DEBUG : file2: reading active writers 2021/06/01 06:18:09 DEBUG : file1: reading active writers 2021/06/01 06:18:09 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:09 ERROR : Exiting even though 0 writers active and 2 cache items in use after 10s Cache{ "file1": &{c:0xc0001a1800 mu:{state:0 sema:0} cond:0xc0008ca7c0 name:file1 opens:0 downloaders: o: fd: modified:false info:{ModTime:{wall:13845633321010420365 ext:339278028708 loc:0x2b58f40} ATime:{wall:13845633321010607555 ext:339278215866 loc:0x2b58f40} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, "file2": &{c:0xc0001a1800 mu:{state:0 sema:0} cond:0xc00007f200 name:file2 opens:0 downloaders: o: fd: modified:false info:{ModTime:{wall:13845633321011241493 ext:339278849804 loc:0x2b58f40} ATime:{wall:13845633321011362942 ext:339278971260 loc:0x2b58f40} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2 pendingAccesses:0 beingReset:false}, } 2021/06/01 06:18:09 DEBUG : >WaitForWriters: fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 2021/06/01 06:18:14 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:18:14 DEBUG : file2: vfs cache: starting upload 2021/06/01 06:18:14 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "7075c4615cac2a21", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:14 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 "7075c4615cac2a21", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:14 ERROR : file2: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "55458be058d54697", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:14 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 "55458be058d54697", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 read_write_test.go:426 Error: Should be true Test: TestRWFileHandleWriteNoWrite Messages: listing wrong, want file1 (0), file2 (0) got fstest.go:204: Not found "file1" fstest.go:204: Not found "file2" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 read_write_test.go:426 Error: Not equal: expected: 0 actual : 2 Test: TestRWFileHandleWriteNoWrite Messages: 2 objects not found 2021/06/01 06:18:17 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:18:17 DEBUG : : Looking for writers 2021/06/01 06:18:17 DEBUG : file2: reading active writers 2021/06/01 06:18:17 DEBUG : file1: reading active writers 2021/06/01 06:18:17 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms 2021/06/01 06:18:17 DEBUG : : Looking for writers 2021/06/01 06:18:17 DEBUG : file2: reading active writers 2021/06/01 06:18:17 DEBUG : file1: reading active writers 2021/06/01 06:18:17 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms 2021/06/01 06:18:17 DEBUG : : Looking for writers 2021/06/01 06:18:17 DEBUG : file1: reading active writers 2021/06/01 06:18:17 DEBUG : file2: reading active writers 2021/06/01 06:18:17 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms 2021/06/01 06:18:17 DEBUG : : Looking for writers 2021/06/01 06:18:17 DEBUG : file1: reading active writers 2021/06/01 06:18:17 DEBUG : file2: reading active writers 2021/06/01 06:18:17 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms 2021/06/01 06:18:17 DEBUG : : Looking for writers 2021/06/01 06:18:17 DEBUG : file1: reading active writers 2021/06/01 06:18:17 DEBUG : file2: reading active writers 2021/06/01 06:18:17 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms 2021/06/01 06:18:17 DEBUG : : Looking for writers 2021/06/01 06:18:17 DEBUG : file1: reading active writers 2021/06/01 06:18:17 DEBUG : file2: reading active writers 2021/06/01 06:18:17 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms 2021/06/01 06:18:18 DEBUG : : Looking for writers 2021/06/01 06:18:18 DEBUG : file1: reading active writers 2021/06/01 06:18:18 DEBUG : file2: reading active writers 2021/06/01 06:18:18 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms 2021/06/01 06:18:18 DEBUG : : Looking for writers 2021/06/01 06:18:18 DEBUG : file1: reading active writers 2021/06/01 06:18:18 DEBUG : file2: reading active writers 2021/06/01 06:18:18 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:19 DEBUG : : Looking for writers 2021/06/01 06:18:19 DEBUG : file1: reading active writers 2021/06/01 06:18:19 DEBUG : file2: reading active writers 2021/06/01 06:18:19 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:20 DEBUG : : Looking for writers 2021/06/01 06:18:20 DEBUG : file1: reading active writers 2021/06/01 06:18:20 DEBUG : file2: reading active writers 2021/06/01 06:18:20 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:21 DEBUG : : Looking for writers 2021/06/01 06:18:21 DEBUG : file1: reading active writers 2021/06/01 06:18:21 DEBUG : file2: reading active writers 2021/06/01 06:18:21 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:22 DEBUG : : Looking for writers 2021/06/01 06:18:22 DEBUG : file1: reading active writers 2021/06/01 06:18:22 DEBUG : file2: reading active writers 2021/06/01 06:18:22 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:23 DEBUG : : Looking for writers 2021/06/01 06:18:23 DEBUG : file1: reading active writers 2021/06/01 06:18:23 DEBUG : file2: reading active writers 2021/06/01 06:18:23 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:24 DEBUG : : Looking for writers 2021/06/01 06:18:24 DEBUG : file1: reading active writers 2021/06/01 06:18:24 DEBUG : file2: reading active writers 2021/06/01 06:18:24 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:25 DEBUG : : Looking for writers 2021/06/01 06:18:25 DEBUG : file2: reading active writers 2021/06/01 06:18:25 DEBUG : file1: reading active writers 2021/06/01 06:18:25 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:26 DEBUG : : Looking for writers 2021/06/01 06:18:26 DEBUG : file1: reading active writers 2021/06/01 06:18:26 DEBUG : file2: reading active writers 2021/06/01 06:18:26 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:27 DEBUG : file1: vfs cache: starting upload 2021/06/01 06:18:27 DEBUG : file2: vfs cache: starting upload 2021/06/01 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 "824de25a08972330", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:27 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 "824de25a08972330", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:27 ERROR : Exiting even though 0 writers active and 2 cache items in use after 10s Cache{ "file1": &{c:0xc0001a1800 mu:{state:0 sema:0} cond:0xc0008ca7c0 name:file1 opens:0 downloaders: o: fd: modified:false info:{ModTime:{wall:13845633321010420365 ext:339278028708 loc:0x2b58f40} ATime:{wall:13845633321010607555 ext:339278215866 loc:0x2b58f40} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, "file2": &{c:0xc0001a1800 mu:{state:0 sema:0} cond:0xc00007f200 name:file2 opens:0 downloaders: o: fd: modified:false info:{ModTime:{wall:13845633321011241493 ext:339278849804 loc:0x2b58f40} ATime:{wall:13845633321011362942 ext:339278971260 loc:0x2b58f40} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2 pendingAccesses:0 beingReset:false}, } 2021/06/01 06:18:27 DEBUG : >WaitForWriters: 2021/06/01 06:18:27 ERROR : file2: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "4c2e5e20a92bf86e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:27 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 "4c2e5e20a92bf86e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestRWFileHandleWriteNoWrite (28.06s) === RUN TestRWFileHandleSizeTruncateExisting run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:18:27 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "78de889ca54a3b00", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestRWFileHandleSizeTruncateExisting (0.26s) === RUN TestRWFileHandleSizeCreateExisting run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:18:28 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:282: Failed to put "dir/file1" to "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "5fc10f16332981df", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestRWFileHandleSizeCreateExisting (0.26s) === RUN TestRWFileModTimeWithOpenWriters run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:18:28 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache 2021/06/01 06:18:28 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2021/06/01 06:18:28 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2021/06/01 06:18:28 DEBUG : file1: newRWFileHandle: 2021/06/01 06:18:28 DEBUG : file1(0xc0005c23c0): openPending: 2021/06/01 06:18:28 DEBUG : file1: vfs cache: truncate to size=0 2021/06/01 06:18:28 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:18:28 DEBUG : file1(0xc0005c23c0): >openPending: err= 2021/06/01 06:18:28 DEBUG : file1: vfs cache: cancelling writeback (uploading false) 0xc00019ad20 item 1 2021/06/01 06:18:28 DEBUG : file1: >newRWFileHandle: err= 2021/06/01 06:18:28 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:18:28 DEBUG : file1: >Open: fd=file1 (rw), err= 2021/06/01 06:18:28 DEBUG : file1: >OpenFile: fd=file1 (rw), err= run.go:282: Failed to put "time_test" to "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "01a7d5b2f2159f9b", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:28 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:18:28 DEBUG : : Looking for writers 2021/06/01 06:18:28 DEBUG : file1: reading active writers 2021/06/01 06:18:28 DEBUG : file1: active writers 1 2021/06/01 06:18:28 DEBUG : file2: reading active writers 2021/06/01 06:18:28 DEBUG : Still 1 writers active and 2 cache items in use, waiting 10ms 2021/06/01 06:18:28 DEBUG : : Looking for writers 2021/06/01 06:18:28 DEBUG : file1: reading active writers 2021/06/01 06:18:28 DEBUG : file1: active writers 1 2021/06/01 06:18:28 DEBUG : file2: reading active writers 2021/06/01 06:18:28 DEBUG : Still 1 writers active and 2 cache items in use, waiting 20ms 2021/06/01 06:18:28 DEBUG : : Looking for writers 2021/06/01 06:18:28 DEBUG : file1: reading active writers 2021/06/01 06:18:28 DEBUG : file1: active writers 1 2021/06/01 06:18:28 DEBUG : file2: reading active writers 2021/06/01 06:18:28 DEBUG : Still 1 writers active and 2 cache items in use, waiting 40ms 2021/06/01 06:18:28 DEBUG : : Looking for writers 2021/06/01 06:18:28 DEBUG : file1: reading active writers 2021/06/01 06:18:28 DEBUG : file1: active writers 1 2021/06/01 06:18:28 DEBUG : file2: reading active writers 2021/06/01 06:18:28 DEBUG : Still 1 writers active and 2 cache items in use, waiting 80ms 2021/06/01 06:18:28 DEBUG : : Looking for writers 2021/06/01 06:18:28 DEBUG : file2: reading active writers 2021/06/01 06:18:28 DEBUG : file1: reading active writers 2021/06/01 06:18:28 DEBUG : file1: active writers 1 2021/06/01 06:18:28 DEBUG : Still 1 writers active and 2 cache items in use, waiting 160ms 2021/06/01 06:18:28 DEBUG : : Looking for writers 2021/06/01 06:18:28 DEBUG : file1: reading active writers 2021/06/01 06:18:28 DEBUG : file1: active writers 1 2021/06/01 06:18:28 DEBUG : file2: reading active writers 2021/06/01 06:18:28 DEBUG : Still 1 writers active and 2 cache items in use, waiting 320ms 2021/06/01 06:18:29 DEBUG : : Looking for writers 2021/06/01 06:18:29 DEBUG : file2: reading active writers 2021/06/01 06:18:29 DEBUG : file1: reading active writers 2021/06/01 06:18:29 DEBUG : file1: active writers 1 2021/06/01 06:18:29 DEBUG : Still 1 writers active and 2 cache items in use, waiting 640ms 2021/06/01 06:18:29 DEBUG : : Looking for writers 2021/06/01 06:18:29 DEBUG : file1: reading active writers 2021/06/01 06:18:29 DEBUG : file1: active writers 1 2021/06/01 06:18:29 DEBUG : file2: reading active writers 2021/06/01 06:18:29 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:30 DEBUG : : Looking for writers 2021/06/01 06:18:30 DEBUG : file1: reading active writers 2021/06/01 06:18:30 DEBUG : file1: active writers 1 2021/06/01 06:18:30 DEBUG : file2: reading active writers 2021/06/01 06:18:30 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:31 INFO : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0) 2021/06/01 06:18:31 DEBUG : : Looking for writers 2021/06/01 06:18:31 DEBUG : file1: reading active writers 2021/06/01 06:18:31 DEBUG : file1: active writers 1 2021/06/01 06:18:31 DEBUG : file2: reading active writers 2021/06/01 06:18:31 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:32 DEBUG : : Looking for writers 2021/06/01 06:18:32 DEBUG : file1: reading active writers 2021/06/01 06:18:32 DEBUG : file1: active writers 1 2021/06/01 06:18:32 DEBUG : file2: reading active writers 2021/06/01 06:18:32 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:33 DEBUG : : Looking for writers 2021/06/01 06:18:33 DEBUG : file1: reading active writers 2021/06/01 06:18:33 DEBUG : file1: active writers 1 2021/06/01 06:18:33 DEBUG : file2: reading active writers 2021/06/01 06:18:33 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:34 DEBUG : : Looking for writers 2021/06/01 06:18:34 DEBUG : file1: reading active writers 2021/06/01 06:18:34 DEBUG : file1: active writers 1 2021/06/01 06:18:34 DEBUG : file2: reading active writers 2021/06/01 06:18:34 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:35 DEBUG : : Looking for writers 2021/06/01 06:18:35 DEBUG : file2: reading active writers 2021/06/01 06:18:35 DEBUG : file1: reading active writers 2021/06/01 06:18:35 DEBUG : file1: active writers 1 2021/06/01 06:18:35 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:36 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file2 not removed, freed 0 bytes 2021/06/01 06:18:36 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item file1 not removed, freed 0 bytes 2021/06/01 06:18:36 INFO : vfs cache: cleaned: objects 2 (was 2) in use 2, to upload 1, uploading 0, total size 0 (was 0) 2021/06/01 06:18:36 DEBUG : : Looking for writers 2021/06/01 06:18:36 DEBUG : file1: reading active writers 2021/06/01 06:18:36 DEBUG : file1: active writers 1 2021/06/01 06:18:36 DEBUG : file2: reading active writers 2021/06/01 06:18:36 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:37 DEBUG : : Looking for writers 2021/06/01 06:18:37 DEBUG : file1: reading active writers 2021/06/01 06:18:37 DEBUG : file1: active writers 1 2021/06/01 06:18:37 DEBUG : file2: reading active writers 2021/06/01 06:18:37 DEBUG : Still 1 writers active and 2 cache items in use, waiting 1s 2021/06/01 06:18:38 ERROR : Exiting even though 1 writers active and 2 cache items in use after 10s Cache{ "file1": &{c:0xc0001a1800 mu:{state:0 sema:0} cond:0xc0008ca7c0 name:file1 opens:1 downloaders: o: fd:0xc00056a630 modified:true info:{ModTime:{wall:13845633351738787423 ext:367867882838 loc:0x2b58f40} ATime:{wall:13845633351738787423 ext:367867882838 loc:0x2b58f40} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1 pendingAccesses:0 beingReset:false}, "file2": &{c:0xc0001a1800 mu:{state:0 sema:0} cond:0xc00007f200 name:file2 opens:0 downloaders: o: fd: modified:false info:{ModTime:{wall:13845633321011241493 ext:339278849804 loc:0x2b58f40} ATime:{wall:13845633321011362942 ext:339278971260 loc:0x2b58f40} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2 pendingAccesses:0 beingReset:false}, } 2021/06/01 06:18:38 DEBUG : >WaitForWriters: --- FAIL: TestRWFileModTimeWithOpenWriters (10.53s) === RUN TestCaseSensitivity run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" run.go:282: Failed to put "FiLeA" to "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "0ded9ba642162267", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" --- FAIL: TestCaseSensitivity (0.53s) === 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-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:18:39 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: 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 2021/06/01 06:18:39 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: 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 2021/06/01 06:18:39 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:18:39 DEBUG : : Looking for writers 2021/06/01 06:18:39 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.26s) === RUN TestVFSStat run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:18:39 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:282: Failed to put "file1" to "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "4065b33fdfbd978c", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:39 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:18:39 DEBUG : : Looking for writers 2021/06/01 06:18:39 DEBUG : >WaitForWriters: --- FAIL: TestVFSStat (0.52s) === RUN TestVFSStatParent run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:18:40 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:282: Failed to put "file1" to "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "9adea4aff5643cbf", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:40 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:18:40 DEBUG : : Looking for writers 2021/06/01 06:18:40 DEBUG : >WaitForWriters: --- FAIL: TestVFSStatParent (0.53s) === RUN TestVFSOpenFile run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:18:40 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:282: Failed to put "file1" to "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "1149bcf5c1f5bb02", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:40 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:18:40 DEBUG : : Looking for writers 2021/06/01 06:18:40 DEBUG : >WaitForWriters: --- FAIL: TestVFSOpenFile (0.53s) === RUN TestVFSRename run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:18:41 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache run.go:282: Failed to put "dir/file2" to "QingStor bucket rclone-test-deyohud0panixok0zotagev4": QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "bca03bc8f26d1ef9", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:41 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:18:41 DEBUG : : Looking for writers 2021/06/01 06:18:41 DEBUG : >WaitForWriters: --- FAIL: TestVFSRename (0.53s) === RUN TestWriteFileHandleMethods run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:18:41 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache 2021/06/01 06:18:41 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2021/06/01 06:18:42 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2021/06/01 06:18:42 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:18:42 DEBUG : file1: >Open: fd=file1 (w), err= 2021/06/01 06:18:42 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2021/06/01 06:18:42 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:18:42 ERROR : file1: WriteFileHandle: Read: Can't read and write to file without --vfs-cache-mode >= minimal 2021/06/01 06:18:42 ERROR : file1: WriteFileHandle: ReadAt: Can't read and write to file without --vfs-cache-mode >= minimal 2021/06/01 06:18:42 ERROR : file1: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes 2021/06/01 06:18:42 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: File to upload is small (5 bytes), uploading instead of streaming 2021/06/01 06:18:42 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "f7e40315b1495d9e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:42 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 "f7e40315b1495d9e", 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 "f7e40315b1495d9e", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" Test: TestWriteFileHandleMethods fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 write_test.go:97 Error: Should be true Test: TestWriteFileHandleMethods Messages: listing wrong, want file1 (5) got fstest.go:204: Not found "file1" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 write_test.go:97 Error: Not equal: expected: 0 actual : 1 Test: TestWriteFileHandleMethods Messages: 1 objects not found 2021/06/01 06:18:50 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2021/06/01 06:18:50 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2021/06/01 06:18:50 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:18:50 DEBUG : file1: >Open: fd=file1 (w), err= 2021/06/01 06:18:50 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2021/06/01 06:18:50 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:18:50 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: File to upload is small (0 bytes), uploading instead of streaming 2021/06/01 06:18: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 "fa7728a0e6a9c226", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:18:50 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 "fa7728a0e6a9c226", 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 "fa7728a0e6a9c226", 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 2021/06/01 06:18:50 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2021/06/01 06:18:50 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2021/06/01 06:18:50 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:18:50 DEBUG : file1: >Open: fd=file1 (w), err= 2021/06/01 06:18:50 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2021/06/01 06:18:50 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 2021/06/01 06:18:50 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:18:50 DEBUG : : Looking for writers 2021/06/01 06:18:50 DEBUG : file1: reading active writers 2021/06/01 06:18:50 DEBUG : file1: active writers 1 2021/06/01 06:18:50 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2021/06/01 06:18:50 DEBUG : : Looking for writers 2021/06/01 06:18:50 DEBUG : file1: reading active writers 2021/06/01 06:18:50 DEBUG : file1: active writers 1 2021/06/01 06:18:50 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2021/06/01 06:18:50 DEBUG : : Looking for writers 2021/06/01 06:18:50 DEBUG : file1: reading active writers 2021/06/01 06:18:50 DEBUG : file1: active writers 1 2021/06/01 06:18:50 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2021/06/01 06:18:50 DEBUG : : Looking for writers 2021/06/01 06:18:50 DEBUG : file1: reading active writers 2021/06/01 06:18:50 DEBUG : file1: active writers 1 2021/06/01 06:18:50 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2021/06/01 06:18:50 DEBUG : : Looking for writers 2021/06/01 06:18:50 DEBUG : file1: reading active writers 2021/06/01 06:18:50 DEBUG : file1: active writers 1 2021/06/01 06:18:50 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2021/06/01 06:18:50 DEBUG : : Looking for writers 2021/06/01 06:18:50 DEBUG : file1: reading active writers 2021/06/01 06:18:50 DEBUG : file1: active writers 1 2021/06/01 06:18:50 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2021/06/01 06:18:50 DEBUG : : Looking for writers 2021/06/01 06:18:50 DEBUG : file1: reading active writers 2021/06/01 06:18:50 DEBUG : file1: active writers 1 2021/06/01 06:18:50 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2021/06/01 06:18:51 DEBUG : : Looking for writers 2021/06/01 06:18:51 DEBUG : file1: reading active writers 2021/06/01 06:18:51 DEBUG : file1: active writers 1 2021/06/01 06:18:51 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:18:52 DEBUG : : Looking for writers 2021/06/01 06:18:52 DEBUG : file1: reading active writers 2021/06/01 06:18:52 DEBUG : file1: active writers 1 2021/06/01 06:18:52 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:18:53 DEBUG : file2: vfs cache: starting upload 2021/06/01 06:18:53 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-deyohud0panixok0zotagev4/file2: no such file or directory 2021/06/01 06:18:53 INFO : file2: vfs cache: upload succeeded try #9 2021/06/01 06:18:53 DEBUG : : Looking for writers 2021/06/01 06:18:53 DEBUG : file1: reading active writers 2021/06/01 06:18:53 DEBUG : file1: active writers 1 2021/06/01 06:18:53 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:18:54 DEBUG : : Looking for writers 2021/06/01 06:18:54 DEBUG : file1: reading active writers 2021/06/01 06:18:54 DEBUG : file1: active writers 1 2021/06/01 06:18:54 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:18:55 DEBUG : : Looking for writers 2021/06/01 06:18:55 DEBUG : file1: reading active writers 2021/06/01 06:18:55 DEBUG : file1: active writers 1 2021/06/01 06:18:55 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:18:56 DEBUG : : Looking for writers 2021/06/01 06:18:56 DEBUG : file1: reading active writers 2021/06/01 06:18:56 DEBUG : file1: active writers 1 2021/06/01 06:18:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:18:57 DEBUG : : Looking for writers 2021/06/01 06:18:57 DEBUG : file1: reading active writers 2021/06/01 06:18:57 DEBUG : file1: active writers 1 2021/06/01 06:18:57 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:18:58 DEBUG : : Looking for writers 2021/06/01 06:18:58 DEBUG : file1: reading active writers 2021/06/01 06:18:58 DEBUG : file1: active writers 1 2021/06/01 06:18:58 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:18:59 DEBUG : : Looking for writers 2021/06/01 06:18:59 DEBUG : file1: reading active writers 2021/06/01 06:18:59 DEBUG : file1: active writers 1 2021/06/01 06:18:59 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:00 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2021/06/01 06:19:00 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleMethods (18.85s) === RUN TestWriteFileHandleWriteAt run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:19:00 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache 2021/06/01 06:19:00 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2021/06/01 06:19:00 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2021/06/01 06:19:00 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:19:00 DEBUG : file1: >Open: fd=file1 (w), err= 2021/06/01 06:19:00 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2021/06/01 06:19:00 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:19:00 DEBUG : file1: waiting for in-sequence write to 100 for 1s 2021/06/01 06:19:01 DEBUG : file1: aborting in-sequence write wait, off=100 2021/06/01 06:19:01 DEBUG : file1: failed to wait for in-sequence write to 100 2021/06/01 06:19:01 ERROR : file1: WriteFileHandle.Write: can't seek in file without --vfs-cache-mode >= writes 2021/06/01 06:19:01 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: File to upload is small (11 bytes), uploading instead of streaming 2021/06/01 06:19:01 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "40eecda336d81191", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:19:01 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 "40eecda336d81191", 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 "40eecda336d81191", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" Test: TestWriteFileHandleWriteAt 2021/06/01 06:19:01 ERROR : file1: WriteFileHandle.Write: error: Bad file descriptor fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 write_test.go:176 Error: Should be true Test: TestWriteFileHandleWriteAt Messages: listing wrong, want file1 (11) got fstest.go:204: Not found "file1" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 write_test.go:176 Error: Not equal: expected: 0 actual : 1 Test: TestWriteFileHandleWriteAt Messages: 1 objects not found 2021/06/01 06:19:09 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:19:09 DEBUG : : Looking for writers 2021/06/01 06:19:09 DEBUG : file1: reading active writers 2021/06/01 06:19:09 DEBUG : file1: active writers 1 2021/06/01 06:19:09 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2021/06/01 06:19:09 DEBUG : : Looking for writers 2021/06/01 06:19:09 DEBUG : file1: reading active writers 2021/06/01 06:19:09 DEBUG : file1: active writers 1 2021/06/01 06:19:09 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2021/06/01 06:19:09 DEBUG : : Looking for writers 2021/06/01 06:19:09 DEBUG : file1: reading active writers 2021/06/01 06:19:09 DEBUG : file1: active writers 1 2021/06/01 06:19:09 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2021/06/01 06:19:09 DEBUG : : Looking for writers 2021/06/01 06:19:09 DEBUG : file1: reading active writers 2021/06/01 06:19:09 DEBUG : file1: active writers 1 2021/06/01 06:19:09 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2021/06/01 06:19:09 DEBUG : : Looking for writers 2021/06/01 06:19:09 DEBUG : file1: reading active writers 2021/06/01 06:19:09 DEBUG : file1: active writers 1 2021/06/01 06:19:09 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2021/06/01 06:19:09 DEBUG : : Looking for writers 2021/06/01 06:19:09 DEBUG : file1: reading active writers 2021/06/01 06:19:09 DEBUG : file1: active writers 1 2021/06/01 06:19:09 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2021/06/01 06:19:10 DEBUG : : Looking for writers 2021/06/01 06:19:10 DEBUG : file1: reading active writers 2021/06/01 06:19:10 DEBUG : file1: active writers 1 2021/06/01 06:19:10 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2021/06/01 06:19:10 DEBUG : : Looking for writers 2021/06/01 06:19:10 DEBUG : file1: reading active writers 2021/06/01 06:19:10 DEBUG : file1: active writers 1 2021/06/01 06:19:10 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:11 DEBUG : : Looking for writers 2021/06/01 06:19:11 DEBUG : file1: reading active writers 2021/06/01 06:19:11 DEBUG : file1: active writers 1 2021/06/01 06:19:11 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:12 DEBUG : : Looking for writers 2021/06/01 06:19:12 DEBUG : file1: reading active writers 2021/06/01 06:19:12 DEBUG : file1: active writers 1 2021/06/01 06:19:12 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:13 DEBUG : : Looking for writers 2021/06/01 06:19:13 DEBUG : file1: reading active writers 2021/06/01 06:19:13 DEBUG : file1: active writers 1 2021/06/01 06:19:13 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:14 DEBUG : : Looking for writers 2021/06/01 06:19:14 DEBUG : file1: reading active writers 2021/06/01 06:19:14 DEBUG : file1: active writers 1 2021/06/01 06:19:14 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:15 DEBUG : : Looking for writers 2021/06/01 06:19:15 DEBUG : file1: reading active writers 2021/06/01 06:19:15 DEBUG : file1: active writers 1 2021/06/01 06:19:15 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:16 DEBUG : : Looking for writers 2021/06/01 06:19:16 DEBUG : file1: reading active writers 2021/06/01 06:19:16 DEBUG : file1: active writers 1 2021/06/01 06:19:16 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:17 DEBUG : : Looking for writers 2021/06/01 06:19:17 DEBUG : file1: reading active writers 2021/06/01 06:19:17 DEBUG : file1: active writers 1 2021/06/01 06:19:17 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:18 DEBUG : : Looking for writers 2021/06/01 06:19:18 DEBUG : file1: reading active writers 2021/06/01 06:19:18 DEBUG : file1: active writers 1 2021/06/01 06:19:18 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:19 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2021/06/01 06:19:19 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleWriteAt (19.32s) === RUN TestWriteFileHandleFlush run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:19:19 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache 2021/06/01 06:19:19 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2021/06/01 06:19:19 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2021/06/01 06:19:19 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:19:19 DEBUG : file1: >Open: fd=file1 (w), err= 2021/06/01 06:19:19 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2021/06/01 06:19:19 DEBUG : file1: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions 2021/06/01 06:19:19 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:19:19 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: File to upload is small (5 bytes), uploading instead of streaming 2021/06/01 06:19: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 "b7ae8e10f788cb8a", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:19:20 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 "b7ae8e10f788cb8a", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:19:20 ERROR : file1: WriteFileHandle.Flush error: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "b7ae8e10f788cb8a", 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 "b7ae8e10f788cb8a", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" Test: TestWriteFileHandleFlush 2021/06/01 06:19:20 DEBUG : file1: WriteFileHandle.Flush nothing to do 2021/06/01 06:19:20 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:19:20 DEBUG : : Looking for writers 2021/06/01 06:19:20 DEBUG : file1: reading active writers 2021/06/01 06:19:20 DEBUG : file1: active writers 1 2021/06/01 06:19:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2021/06/01 06:19:20 DEBUG : : Looking for writers 2021/06/01 06:19:20 DEBUG : file1: reading active writers 2021/06/01 06:19:20 DEBUG : file1: active writers 1 2021/06/01 06:19:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2021/06/01 06:19:20 DEBUG : : Looking for writers 2021/06/01 06:19:20 DEBUG : file1: reading active writers 2021/06/01 06:19:20 DEBUG : file1: active writers 1 2021/06/01 06:19:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2021/06/01 06:19:20 DEBUG : : Looking for writers 2021/06/01 06:19:20 DEBUG : file1: reading active writers 2021/06/01 06:19:20 DEBUG : file1: active writers 1 2021/06/01 06:19:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2021/06/01 06:19:20 DEBUG : : Looking for writers 2021/06/01 06:19:20 DEBUG : file1: reading active writers 2021/06/01 06:19:20 DEBUG : file1: active writers 1 2021/06/01 06:19:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2021/06/01 06:19:20 DEBUG : : Looking for writers 2021/06/01 06:19:20 DEBUG : file1: reading active writers 2021/06/01 06:19:20 DEBUG : file1: active writers 1 2021/06/01 06:19:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2021/06/01 06:19:20 DEBUG : : Looking for writers 2021/06/01 06:19:20 DEBUG : file1: reading active writers 2021/06/01 06:19:20 DEBUG : file1: active writers 1 2021/06/01 06:19:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2021/06/01 06:19:21 DEBUG : : Looking for writers 2021/06/01 06:19:21 DEBUG : file1: reading active writers 2021/06/01 06:19:21 DEBUG : file1: active writers 1 2021/06/01 06:19:21 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:22 DEBUG : : Looking for writers 2021/06/01 06:19:22 DEBUG : file1: reading active writers 2021/06/01 06:19:22 DEBUG : file1: active writers 1 2021/06/01 06:19:22 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:23 DEBUG : : Looking for writers 2021/06/01 06:19:23 DEBUG : file1: reading active writers 2021/06/01 06:19:23 DEBUG : file1: active writers 1 2021/06/01 06:19:23 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:24 DEBUG : : Looking for writers 2021/06/01 06:19:24 DEBUG : file1: reading active writers 2021/06/01 06:19:24 DEBUG : file1: active writers 1 2021/06/01 06:19:24 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:25 DEBUG : : Looking for writers 2021/06/01 06:19:25 DEBUG : file1: reading active writers 2021/06/01 06:19:25 DEBUG : file1: active writers 1 2021/06/01 06:19:25 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:26 DEBUG : : Looking for writers 2021/06/01 06:19:26 DEBUG : file1: reading active writers 2021/06/01 06:19:26 DEBUG : file1: active writers 1 2021/06/01 06:19:26 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:27 DEBUG : : Looking for writers 2021/06/01 06:19:27 DEBUG : file1: reading active writers 2021/06/01 06:19:27 DEBUG : file1: active writers 1 2021/06/01 06:19:27 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:28 DEBUG : : Looking for writers 2021/06/01 06:19:28 DEBUG : file1: reading active writers 2021/06/01 06:19:28 DEBUG : file1: active writers 1 2021/06/01 06:19:28 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:29 DEBUG : : Looking for writers 2021/06/01 06:19:29 DEBUG : file1: reading active writers 2021/06/01 06:19:29 DEBUG : file1: active writers 1 2021/06/01 06:19:29 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:30 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2021/06/01 06:19:30 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleFlush (10.53s) === RUN TestWriteFileHandleRelease run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:19:30 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache 2021/06/01 06:19:30 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2021/06/01 06:19:30 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2021/06/01 06:19:30 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:19:30 DEBUG : file1: >Open: fd=file1 (w), err= 2021/06/01 06:19:30 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2021/06/01 06:19:30 DEBUG : file1: WriteFileHandle.Release closing 2021/06/01 06:19:30 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:19:30 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: File to upload is small (0 bytes), uploading instead of streaming 2021/06/01 06:19:30 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "947244ed0e0a77e0", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:19:30 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 "947244ed0e0a77e0", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:19:30 ERROR : file1: WriteFileHandle.Release error: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "947244ed0e0a77e0", 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 "947244ed0e0a77e0", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" Test: TestWriteFileHandleRelease 2021/06/01 06:19:30 DEBUG : file1: WriteFileHandle.Release nothing to do 2021/06/01 06:19:30 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:19:30 DEBUG : : Looking for writers 2021/06/01 06:19:30 DEBUG : file1: reading active writers 2021/06/01 06:19:30 DEBUG : file1: active writers 1 2021/06/01 06:19:30 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2021/06/01 06:19:30 DEBUG : : Looking for writers 2021/06/01 06:19:30 DEBUG : file1: reading active writers 2021/06/01 06:19:30 DEBUG : file1: active writers 1 2021/06/01 06:19:30 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2021/06/01 06:19:30 DEBUG : : Looking for writers 2021/06/01 06:19:30 DEBUG : file1: reading active writers 2021/06/01 06:19:30 DEBUG : file1: active writers 1 2021/06/01 06:19:30 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2021/06/01 06:19:30 DEBUG : : Looking for writers 2021/06/01 06:19:30 DEBUG : file1: reading active writers 2021/06/01 06:19:30 DEBUG : file1: active writers 1 2021/06/01 06:19:30 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2021/06/01 06:19:30 DEBUG : : Looking for writers 2021/06/01 06:19:30 DEBUG : file1: reading active writers 2021/06/01 06:19:30 DEBUG : file1: active writers 1 2021/06/01 06:19:30 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2021/06/01 06:19:31 DEBUG : : Looking for writers 2021/06/01 06:19:31 DEBUG : file1: reading active writers 2021/06/01 06:19:31 DEBUG : file1: active writers 1 2021/06/01 06:19:31 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2021/06/01 06:19:31 DEBUG : : Looking for writers 2021/06/01 06:19:31 DEBUG : file1: reading active writers 2021/06/01 06:19:31 DEBUG : file1: active writers 1 2021/06/01 06:19:31 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2021/06/01 06:19:31 DEBUG : : Looking for writers 2021/06/01 06:19:31 DEBUG : file1: reading active writers 2021/06/01 06:19:31 DEBUG : file1: active writers 1 2021/06/01 06:19:31 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:32 DEBUG : : Looking for writers 2021/06/01 06:19:32 DEBUG : file1: reading active writers 2021/06/01 06:19:32 DEBUG : file1: active writers 1 2021/06/01 06:19:32 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:33 DEBUG : : Looking for writers 2021/06/01 06:19:33 DEBUG : file1: reading active writers 2021/06/01 06:19:33 DEBUG : file1: active writers 1 2021/06/01 06:19:33 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:34 DEBUG : : Looking for writers 2021/06/01 06:19:34 DEBUG : file1: reading active writers 2021/06/01 06:19:34 DEBUG : file1: active writers 1 2021/06/01 06:19:34 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:35 DEBUG : : Looking for writers 2021/06/01 06:19:35 DEBUG : file1: reading active writers 2021/06/01 06:19:35 DEBUG : file1: active writers 1 2021/06/01 06:19:35 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:36 DEBUG : : Looking for writers 2021/06/01 06:19:37 DEBUG : file1: reading active writers 2021/06/01 06:19:37 DEBUG : file1: active writers 1 2021/06/01 06:19:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:38 DEBUG : : Looking for writers 2021/06/01 06:19:38 DEBUG : file1: reading active writers 2021/06/01 06:19:38 DEBUG : file1: active writers 1 2021/06/01 06:19:38 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:39 DEBUG : : Looking for writers 2021/06/01 06:19:39 DEBUG : file1: reading active writers 2021/06/01 06:19:39 DEBUG : file1: active writers 1 2021/06/01 06:19:39 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:40 DEBUG : : Looking for writers 2021/06/01 06:19:40 DEBUG : file1: reading active writers 2021/06/01 06:19:40 DEBUG : file1: active writers 1 2021/06/01 06:19:40 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:40 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2021/06/01 06:19:40 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileHandleRelease (10.53s) === RUN TestWriteFileModTimeWithOpenWriters run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:19:40 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache 2021/06/01 06:19:40 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2021/06/01 06:19:40 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2021/06/01 06:19:40 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:19:40 DEBUG : file1: >Open: fd=file1 (w), err= 2021/06/01 06:19:40 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2021/06/01 06:19:40 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:19:40 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: File to upload is small (2 bytes), uploading instead of streaming 2021/06/01 06:19:41 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "e797df282a56758d", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:19:41 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 "e797df282a56758d", 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 "e797df282a56758d", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" Test: TestWriteFileModTimeWithOpenWriters 2021/06/01 06:19:41 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:19:41 DEBUG : : Looking for writers 2021/06/01 06:19:41 DEBUG : file1: reading active writers 2021/06/01 06:19:41 DEBUG : file1: active writers 1 2021/06/01 06:19:41 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2021/06/01 06:19:41 DEBUG : : Looking for writers 2021/06/01 06:19:41 DEBUG : file1: reading active writers 2021/06/01 06:19:41 DEBUG : file1: active writers 1 2021/06/01 06:19:41 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2021/06/01 06:19:41 DEBUG : : Looking for writers 2021/06/01 06:19:41 DEBUG : file1: reading active writers 2021/06/01 06:19:41 DEBUG : file1: active writers 1 2021/06/01 06:19:41 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2021/06/01 06:19:41 DEBUG : : Looking for writers 2021/06/01 06:19:41 DEBUG : file1: reading active writers 2021/06/01 06:19:41 DEBUG : file1: active writers 1 2021/06/01 06:19:41 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2021/06/01 06:19:41 DEBUG : : Looking for writers 2021/06/01 06:19:41 DEBUG : file1: reading active writers 2021/06/01 06:19:41 DEBUG : file1: active writers 1 2021/06/01 06:19:41 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2021/06/01 06:19:41 DEBUG : : Looking for writers 2021/06/01 06:19:41 DEBUG : file1: reading active writers 2021/06/01 06:19:41 DEBUG : file1: active writers 1 2021/06/01 06:19:41 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2021/06/01 06:19:41 DEBUG : : Looking for writers 2021/06/01 06:19:41 DEBUG : file1: reading active writers 2021/06/01 06:19:41 DEBUG : file1: active writers 1 2021/06/01 06:19:41 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2021/06/01 06:19:42 DEBUG : : Looking for writers 2021/06/01 06:19:42 DEBUG : file1: reading active writers 2021/06/01 06:19:42 DEBUG : file1: active writers 1 2021/06/01 06:19:42 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:43 DEBUG : : Looking for writers 2021/06/01 06:19:43 DEBUG : file1: reading active writers 2021/06/01 06:19:43 DEBUG : file1: active writers 1 2021/06/01 06:19:43 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:44 DEBUG : : Looking for writers 2021/06/01 06:19:44 DEBUG : file1: reading active writers 2021/06/01 06:19:44 DEBUG : file1: active writers 1 2021/06/01 06:19:44 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:45 DEBUG : : Looking for writers 2021/06/01 06:19:45 DEBUG : file1: reading active writers 2021/06/01 06:19:45 DEBUG : file1: active writers 1 2021/06/01 06:19:45 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:46 DEBUG : : Looking for writers 2021/06/01 06:19:46 DEBUG : file1: reading active writers 2021/06/01 06:19:46 DEBUG : file1: active writers 1 2021/06/01 06:19:46 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:47 DEBUG : : Looking for writers 2021/06/01 06:19:47 DEBUG : file1: reading active writers 2021/06/01 06:19:47 DEBUG : file1: active writers 1 2021/06/01 06:19:47 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:48 DEBUG : : Looking for writers 2021/06/01 06:19:48 DEBUG : file1: reading active writers 2021/06/01 06:19:48 DEBUG : file1: active writers 1 2021/06/01 06:19:48 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:49 DEBUG : : Looking for writers 2021/06/01 06:19:49 DEBUG : file1: reading active writers 2021/06/01 06:19:49 DEBUG : file1: active writers 1 2021/06/01 06:19:49 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:50 DEBUG : : Looking for writers 2021/06/01 06:19:50 DEBUG : file1: reading active writers 2021/06/01 06:19:50 DEBUG : file1: active writers 1 2021/06/01 06:19:50 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:51 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2021/06/01 06:19:51 DEBUG : >WaitForWriters: --- FAIL: TestWriteFileModTimeWithOpenWriters (10.53s) === RUN TestFileReadAtZeroLength run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:19:51 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache 2021/06/01 06:19:51 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2021/06/01 06:19:51 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2021/06/01 06:19:51 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:19:51 DEBUG : file1: >Open: fd=file1 (w), err= 2021/06/01 06:19:51 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2021/06/01 06:19:51 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:19:51 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: File to upload is small (0 bytes), uploading instead of streaming 2021/06/01 06:19:51 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "296303dd5a08d396", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:19:51 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 "296303dd5a08d396", 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 "296303dd5a08d396", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" Test: TestFileReadAtZeroLength 2021/06/01 06:19:51 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2021/06/01 06:19:51 DEBUG : file1: Open: flags=O_RDONLY 2021/06/01 06:19:56 DEBUG : file1: >Open: fd=, err=file does not exist 2021/06/01 06:19:56 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 2021/06/01 06:19:56 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:19:56 DEBUG : : Looking for writers 2021/06/01 06:19:56 DEBUG : file1: reading active writers 2021/06/01 06:19:56 DEBUG : file1: active writers 1 2021/06/01 06:19:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2021/06/01 06:19:56 DEBUG : : Looking for writers 2021/06/01 06:19:56 DEBUG : file1: reading active writers 2021/06/01 06:19:56 DEBUG : file1: active writers 1 2021/06/01 06:19:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2021/06/01 06:19:56 DEBUG : : Looking for writers 2021/06/01 06:19:56 DEBUG : file1: reading active writers 2021/06/01 06:19:56 DEBUG : file1: active writers 1 2021/06/01 06:19:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2021/06/01 06:19:56 DEBUG : : Looking for writers 2021/06/01 06:19:56 DEBUG : file1: reading active writers 2021/06/01 06:19:56 DEBUG : file1: active writers 1 2021/06/01 06:19:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2021/06/01 06:19:56 DEBUG : : Looking for writers 2021/06/01 06:19:56 DEBUG : file1: reading active writers 2021/06/01 06:19:56 DEBUG : file1: active writers 1 2021/06/01 06:19:56 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2021/06/01 06:19:57 DEBUG : : Looking for writers 2021/06/01 06:19:57 DEBUG : file1: reading active writers 2021/06/01 06:19:57 DEBUG : file1: active writers 1 2021/06/01 06:19:57 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2021/06/01 06:19:57 DEBUG : : Looking for writers 2021/06/01 06:19:57 DEBUG : file1: reading active writers 2021/06/01 06:19:57 DEBUG : file1: active writers 1 2021/06/01 06:19:57 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2021/06/01 06:19:58 DEBUG : : Looking for writers 2021/06/01 06:19:58 DEBUG : file1: reading active writers 2021/06/01 06:19:58 DEBUG : file1: active writers 1 2021/06/01 06:19:58 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:19:59 DEBUG : : Looking for writers 2021/06/01 06:19:59 DEBUG : file1: reading active writers 2021/06/01 06:19:59 DEBUG : file1: active writers 1 2021/06/01 06:19:59 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:20:00 DEBUG : : Looking for writers 2021/06/01 06:20:00 DEBUG : file1: reading active writers 2021/06/01 06:20:00 DEBUG : file1: active writers 1 2021/06/01 06:20:00 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:20:01 DEBUG : : Looking for writers 2021/06/01 06:20:01 DEBUG : file1: reading active writers 2021/06/01 06:20:01 DEBUG : file1: active writers 1 2021/06/01 06:20:01 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:20:02 DEBUG : : Looking for writers 2021/06/01 06:20:02 DEBUG : file1: reading active writers 2021/06/01 06:20:02 DEBUG : file1: active writers 1 2021/06/01 06:20:02 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:20:03 DEBUG : : Looking for writers 2021/06/01 06:20:03 DEBUG : file1: reading active writers 2021/06/01 06:20:03 DEBUG : file1: active writers 1 2021/06/01 06:20:03 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:20:04 DEBUG : : Looking for writers 2021/06/01 06:20:04 DEBUG : file1: reading active writers 2021/06/01 06:20:04 DEBUG : file1: active writers 1 2021/06/01 06:20:04 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:20:05 DEBUG : : Looking for writers 2021/06/01 06:20:05 DEBUG : file1: reading active writers 2021/06/01 06:20:05 DEBUG : file1: active writers 1 2021/06/01 06:20:05 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:20:06 DEBUG : : Looking for writers 2021/06/01 06:20:06 DEBUG : file1: reading active writers 2021/06/01 06:20:06 DEBUG : file1: active writers 1 2021/06/01 06:20:06 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:20:06 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2021/06/01 06:20:06 DEBUG : >WaitForWriters: --- FAIL: TestFileReadAtZeroLength (15.54s) === RUN TestFileReadAtNonZeroLength run.go:176: Remote "QingStor bucket rclone-test-deyohud0panixok0zotagev4", Local "Local file system at /tmp/rclone442657724", Modify Window "876000h0m0s" 2021/06/01 06:20:07 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Re-using VFS from active cache 2021/06/01 06:20:07 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2021/06/01 06:20:07 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2021/06/01 06:20:07 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:20:07 DEBUG : file1: >Open: fd=file1 (w), err= 2021/06/01 06:20:07 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2021/06/01 06:20:07 DEBUG : : Added virtual directory entry vAddFile: "file1" 2021/06/01 06:20:07 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: File to upload is small (100 bytes), uploading instead of streaming 2021/06/01 06:20:07 ERROR : file1: Failed to copy: QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "66ba923803135646", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:20:07 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 "66ba923803135646", 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 "66ba923803135646", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" Test: TestFileReadAtNonZeroLength 2021/06/01 06:20:07 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2021/06/01 06:20:07 DEBUG : file1: Open: flags=O_RDONLY 2021/06/01 06:20:12 DEBUG : file1: >Open: fd=, err=file does not exist 2021/06/01 06:20:12 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 2021/06/01 06:20:12 DEBUG : WaitForWriters: timeout=10s 2021/06/01 06:20:12 DEBUG : : Looking for writers 2021/06/01 06:20:12 DEBUG : file1: reading active writers 2021/06/01 06:20:12 DEBUG : file1: active writers 1 2021/06/01 06:20:12 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms 2021/06/01 06:20:12 DEBUG : : Looking for writers 2021/06/01 06:20:12 DEBUG : file1: reading active writers 2021/06/01 06:20:12 DEBUG : file1: active writers 1 2021/06/01 06:20:12 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms 2021/06/01 06:20:12 DEBUG : : Looking for writers 2021/06/01 06:20:12 DEBUG : file1: reading active writers 2021/06/01 06:20:12 DEBUG : file1: active writers 1 2021/06/01 06:20:12 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms 2021/06/01 06:20:12 DEBUG : : Looking for writers 2021/06/01 06:20:12 DEBUG : file1: reading active writers 2021/06/01 06:20:12 DEBUG : file1: active writers 1 2021/06/01 06:20:12 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms 2021/06/01 06:20:12 DEBUG : : Looking for writers 2021/06/01 06:20:12 DEBUG : file1: reading active writers 2021/06/01 06:20:12 DEBUG : file1: active writers 1 2021/06/01 06:20:12 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms 2021/06/01 06:20:12 DEBUG : : Looking for writers 2021/06/01 06:20:12 DEBUG : file1: reading active writers 2021/06/01 06:20:12 DEBUG : file1: active writers 1 2021/06/01 06:20:12 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms 2021/06/01 06:20:12 DEBUG : : Looking for writers 2021/06/01 06:20:12 DEBUG : file1: reading active writers 2021/06/01 06:20:12 DEBUG : file1: active writers 1 2021/06/01 06:20:12 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms 2021/06/01 06:20:13 DEBUG : : Looking for writers 2021/06/01 06:20:13 DEBUG : file1: reading active writers 2021/06/01 06:20:13 DEBUG : file1: active writers 1 2021/06/01 06:20:13 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:20:14 DEBUG : : Looking for writers 2021/06/01 06:20:14 DEBUG : file1: reading active writers 2021/06/01 06:20:14 DEBUG : file1: active writers 1 2021/06/01 06:20:14 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:20:15 DEBUG : : Looking for writers 2021/06/01 06:20:15 DEBUG : file1: reading active writers 2021/06/01 06:20:15 DEBUG : file1: active writers 1 2021/06/01 06:20:15 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:20:16 DEBUG : : Looking for writers 2021/06/01 06:20:16 DEBUG : file1: reading active writers 2021/06/01 06:20:16 DEBUG : file1: active writers 1 2021/06/01 06:20:16 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:20:17 DEBUG : : Looking for writers 2021/06/01 06:20:17 DEBUG : file1: reading active writers 2021/06/01 06:20:17 DEBUG : file1: active writers 1 2021/06/01 06:20:17 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:20:18 DEBUG : : Looking for writers 2021/06/01 06:20:18 DEBUG : file1: reading active writers 2021/06/01 06:20:18 DEBUG : file1: active writers 1 2021/06/01 06:20:18 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:20:19 DEBUG : : Looking for writers 2021/06/01 06:20:19 DEBUG : file1: reading active writers 2021/06/01 06:20:19 DEBUG : file1: active writers 1 2021/06/01 06:20:19 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:20:20 DEBUG : : Looking for writers 2021/06/01 06:20:20 DEBUG : file1: reading active writers 2021/06/01 06:20:20 DEBUG : file1: active writers 1 2021/06/01 06:20:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:20:21 DEBUG : : Looking for writers 2021/06/01 06:20:21 DEBUG : file1: reading active writers 2021/06/01 06:20:21 DEBUG : file1: active writers 1 2021/06/01 06:20:21 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s 2021/06/01 06:20:22 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s Cache: 2021/06/01 06:20:22 DEBUG : >WaitForWriters: --- FAIL: TestFileReadAtNonZeroLength (15.54s) FAIL 2021/06/01 06:20:22 DEBUG : QingStor bucket rclone-test-deyohud0panixok0zotagev4: Purge dir "" 2021/06/01 06:20:23 purge failed to rmdir "": QingStor Error: StatusCode "404", Code "bucket_not_exists", Message "The bucket you are accessing does not exist.", Request ID "a83dd59f14d59574", Reference URL "http://docs.qingcloud.com/qingstor/api/common/error_code.html" 2021/06/01 06:20:23 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)$/^(cache=full,open=false,write=false|cache=full,open=true,write=false|cache=full,open=true,write=true|cache=off,open=false,write=false|cache=off,open=true,write=false|cache=off,open=true,write=true|full,forceCache=false|minimal,forceCache=false|minimal,forceCache=true|off,forceCache=false|writes,forceCache=false|writes,forceCache=true)$'" - Finished ERROR in 8m2.642825893s (try 3/5): exit status 1: Failed [TestDirHandleMethods TestDirHandleReaddir TestDirHandleReaddirnames TestDirMethods TestDirForgetAll TestDirForgetPath TestDirWalk TestDirSetModTime TestDirStat TestDirReadDirAll TestDirOpen TestDirCreate TestDirMkdir TestDirMkdirSub TestDirRemove TestDirRemoveAll TestDirRemoveName TestDirRename TestFileMethods TestFileSetModTime/cache=off,open=false,write=false TestFileSetModTime/cache=off,open=true,write=false TestFileSetModTime/cache=off,open=true,write=true TestFileSetModTime/cache=full,open=false,write=false TestFileSetModTime/cache=full,open=true,write=false TestFileSetModTime/cache=full,open=true,write=true TestFileOpenRead TestFileOpenWrite TestFileRemove TestFileRemoveAll TestFileOpen TestFileRename/off,forceCache=false TestFileRename/minimal,forceCache=false TestFileRename/minimal,forceCache=true TestFileRename/writes,forceCache=false TestFileRename/writes,forceCache=true TestFileRename/full,forceCache=false 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]