"./sync.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bSHA1QuickS3: -verbose -size-limit 1024 -test.run '^(TestServerSideMove|TestServerSideMoveDeleteEmptySourceDirs)$'" - Starting (try 3/5) 2021/02/08 05:50:04 DEBUG : Creating backend with remote "TestChunkerChunk50bSHA1QuickS3:rclone-test-fafodog2sedebox7xofucib3" 2021/02/08 05:50:04 DEBUG : Creating backend with remote "TestS3:rclone-test-fafodog2sedebox7xofucib3" 2021/02/08 05:50:04 DEBUG : Reset feature "ListR" 2021/02/08 05:50:04 DEBUG : Creating backend with remote "/tmp/rclone879141811" === RUN TestServerSideMove run.go:176: Remote "Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-fafodog2sedebox7xofucib3'", Local "Local file system at /tmp/rclone879141811", Modify Window "1ns" 2021/02/08 05:50:04 DEBUG : Creating backend with remote "TestChunkerChunk50bSHA1QuickS3:rclone-test-hujepag4ribesog9xegegav1" 2021/02/08 05:50:04 DEBUG : Creating backend with remote "TestS3:rclone-test-hujepag4ribesog9xegegav1" 2021/02/08 05:50:04 DEBUG : Reset feature "ListR" 2021/02/08 05:50:04 INFO : S3 bucket rclone-test-fafodog2sedebox7xofucib3: Bucket "rclone-test-fafodog2sedebox7xofucib3" created with ACL "private" 2021/02/08 05:50:05 DEBUG : potato2.rclone_chunk.001_79e441: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:50:05 INFO : potato2.rclone_chunk.001_79e441: Copied (server-side copy) to: potato2.rclone_chunk.001 2021/02/08 05:50:05 INFO : potato2.rclone_chunk.001_79e441: Deleted 2021/02/08 05:50:05 DEBUG : potato2.rclone_chunk.002_79e441: MD5 = 01a6651a94ab602dbfc47587d234b52c OK 2021/02/08 05:50:05 INFO : potato2.rclone_chunk.002_79e441: Copied (server-side copy) to: potato2.rclone_chunk.002 2021/02/08 05:50:05 INFO : potato2.rclone_chunk.002_79e441: Deleted 2021/02/08 05:50:05 DEBUG : empty space.rclone_chunk.001_79e5z6: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK 2021/02/08 05:50:05 INFO : empty space.rclone_chunk.001_79e5z6: Copied (server-side copy) to: empty space 2021/02/08 05:50:05 INFO : empty space.rclone_chunk.001_79e5z6: Deleted 2021/02/08 05:50:05 DEBUG : potato3.rclone_chunk.001_79e5im: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:50:05 INFO : potato3.rclone_chunk.001_79e5im: Copied (server-side copy) to: potato3.rclone_chunk.001 2021/02/08 05:50:05 INFO : potato3.rclone_chunk.001_79e5im: Deleted 2021/02/08 05:50:05 DEBUG : potato3.rclone_chunk.002_79e5im: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK 2021/02/08 05:50:05 INFO : potato3.rclone_chunk.002_79e5im: Copied (server-side copy) to: potato3.rclone_chunk.002 2021/02/08 05:50:05 INFO : potato3.rclone_chunk.002_79e5im: Deleted sync_test.go:1294: Server side move (if possible) Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-fafodog2sedebox7xofucib3' -> Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-hujepag4ribesog9xegegav1' 2021/02/08 05:50:07 INFO : S3 bucket rclone-test-hujepag4ribesog9xegegav1: Bucket "rclone-test-hujepag4ribesog9xegegav1" created with ACL "private" 2021/02/08 05:50:07 DEBUG : empty space.rclone_chunk.001_79e72l: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK 2021/02/08 05:50:07 INFO : empty space.rclone_chunk.001_79e72l: Copied (server-side copy) to: empty space 2021/02/08 05:50:07 INFO : empty space.rclone_chunk.001_79e72l: Deleted 2021/02/08 05:50:07 DEBUG : potato3.rclone_chunk.001_79e74c: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:50:07 INFO : potato3.rclone_chunk.001_79e74c: Copied (server-side copy) to: potato3.rclone_chunk.001 2021/02/08 05:50:07 INFO : potato3.rclone_chunk.001_79e74c: Deleted 2021/02/08 05:50:07 DEBUG : potato3.rclone_chunk.002_79e74c: MD5 = 01a6651a94ab602dbfc47587d234b52c OK 2021/02/08 05:50:07 INFO : potato3.rclone_chunk.002_79e74c: Copied (server-side copy) to: potato3.rclone_chunk.002 2021/02/08 05:50:07 INFO : potato3.rclone_chunk.002_79e74c: Deleted 2021/02/08 05:50:07 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2021/02/08 05:50:07 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-hujepag4ribesog9xegegav1': Waiting for checks to finish 2021/02/08 05:50:07 DEBUG : potato2: Can't copy - required hash not found 2021/02/08 05:50:07 DEBUG : potato3: Can't copy - required hash not found 2021/02/08 05:50:07 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns) 2021/02/08 05:50:07 DEBUG : empty space: Unchanged skipping 2021/02/08 05:50:07 INFO : empty space: Deleted 2021/02/08 05:50:07 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-hujepag4ribesog9xegegav1': Waiting for transfers to finish 2021/02/08 05:50:08 DEBUG : potato2.rclone_chunk.001_79e7gc: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:50:08 INFO : potato2.rclone_chunk.001_79e7gc: Copied (server-side copy) to: potato2.rclone_chunk.001 2021/02/08 05:50:08 INFO : potato2.rclone_chunk.001_79e7gc: Deleted 2021/02/08 05:50:08 DEBUG : potato3.rclone_chunk.001_79e79v: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:50:08 INFO : potato3.rclone_chunk.001_79e79v: Copied (server-side copy) to: potato3.rclone_chunk.001 2021/02/08 05:50:08 DEBUG : potato2.rclone_chunk.002_79e7gc: MD5 = 01a6651a94ab602dbfc47587d234b52c OK 2021/02/08 05:50:08 INFO : potato2.rclone_chunk.002_79e7gc: Copied (server-side copy) to: potato2.rclone_chunk.002 2021/02/08 05:50:08 INFO : potato3.rclone_chunk.001_79e79v: Deleted 2021/02/08 05:50:08 INFO : potato2.rclone_chunk.002_79e7gc: Deleted 2021/02/08 05:50:08 INFO : potato2: Copied (new) 2021/02/08 05:50:08 DEBUG : potato3.rclone_chunk.002_79e79v: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK 2021/02/08 05:50:08 INFO : potato3.rclone_chunk.002_79e79v: Copied (server-side copy) to: potato3.rclone_chunk.002 2021/02/08 05:50:08 INFO : potato3.rclone_chunk.002_79e79v: Deleted 2021/02/08 05:50:08 INFO : potato2: Deleted 2021/02/08 05:50:08 INFO : potato3: Copied (replaced existing) 2021/02/08 05:50:08 INFO : potato3: Deleted 2021/02/08 05:50:08 DEBUG : Creating backend with remote "TestChunkerChunk50bSHA1QuickS3:rclone-test-muqamor4foqiked9ximiyax4" 2021/02/08 05:50:08 DEBUG : Creating backend with remote "TestS3:rclone-test-muqamor4foqiked9ximiyax4" 2021/02/08 05:50:08 DEBUG : Reset feature "ListR" 2021/02/08 05:50:08 DEBUG : empty space: copy non-chunked object... 2021/02/08 05:50:08 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-muqamor4foqiked9ximiyax4': Waiting for checks to finish 2021/02/08 05:50:08 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-muqamor4foqiked9ximiyax4': Waiting for transfers to finish 2021/02/08 05:50:08 DEBUG : potato3: Can't copy - required hash not found 2021/02/08 05:50:08 DEBUG : potato2: Can't copy - required hash not found 2021/02/08 05:50:09 INFO : S3 bucket rclone-test-muqamor4foqiked9ximiyax4: Bucket "rclone-test-muqamor4foqiked9ximiyax4" created with ACL "private" 2021/02/08 05:50:09 INFO : empty space: Copied (server-side copy) 2021/02/08 05:50:09 INFO : empty space: Deleted 2021/02/08 05:50:09 ERROR : potato3: Failed to copy: object not found 2021/02/08 05:50:09 ERROR : potato3: Not deleting source as copy failed: object not found 2021/02/08 05:50:09 ERROR : potato2: Failed to copy: object not found 2021/02/08 05:50:09 ERROR : potato2: Not deleting source as copy failed: object not found sync_test.go:1331: Error Trace: sync_test.go:1331 sync_test.go:1398 Error: Received unexpected error: object not found Test: TestServerSideMove 2021/02/08 05:50:09 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-muqamor4foqiked9ximiyax4': Purge object "empty space" 2021/02/08 05:50:09 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-muqamor4foqiked9ximiyax4': Purge dir "" 2021/02/08 05:50:09 purge failed to rmdir "": BucketNotEmpty: The bucket you tried to delete is not empty status code: 409, request id: DE96F4B71A9AF918, host id: JCj+SAHdm6Ckvb+pkyYnrdIBzeHCQdyV7/yaPgG9si0reppWeBDc9INJ7/XYfpFVs2oZSLQCXxg= 2021/02/08 05:50:09 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-hujepag4ribesog9xegegav1': Purge object "potato2" 2021/02/08 05:50:09 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-hujepag4ribesog9xegegav1': Purge object "potato3" 2021/02/08 05:50:10 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-hujepag4ribesog9xegegav1': Purge dir "" 2021/02/08 05:50:10 INFO : S3 bucket rclone-test-hujepag4ribesog9xegegav1: Bucket "rclone-test-hujepag4ribesog9xegegav1" deleted --- FAIL: TestServerSideMove (6.35s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:176: Remote "Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-fafodog2sedebox7xofucib3'", Local "Local file system at /tmp/rclone879141811", Modify Window "1ns" 2021/02/08 05:50:10 DEBUG : Creating backend with remote "TestChunkerChunk50bSHA1QuickS3:rclone-test-zuqinad5sejewim9zafanaw0" 2021/02/08 05:50:10 DEBUG : Creating backend with remote "TestS3:rclone-test-zuqinad5sejewim9zafanaw0" 2021/02/08 05:50:10 DEBUG : Reset feature "ListR" 2021/02/08 05:50:10 DEBUG : potato2.rclone_chunk.001_79eard: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:50:10 INFO : potato2.rclone_chunk.001_79eard: Copied (server-side copy) to: potato2.rclone_chunk.001 2021/02/08 05:50:10 INFO : potato2.rclone_chunk.001_79eard: Deleted 2021/02/08 05:50:10 DEBUG : potato2.rclone_chunk.002_79eard: MD5 = 01a6651a94ab602dbfc47587d234b52c OK 2021/02/08 05:50:10 INFO : potato2.rclone_chunk.002_79eard: Copied (server-side copy) to: potato2.rclone_chunk.002 2021/02/08 05:50:10 INFO : potato2.rclone_chunk.002_79eard: Deleted 2021/02/08 05:50:11 DEBUG : empty space.rclone_chunk.001_79eagj: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK 2021/02/08 05:50:11 INFO : empty space.rclone_chunk.001_79eagj: Copied (server-side copy) to: empty space 2021/02/08 05:50:11 INFO : empty space.rclone_chunk.001_79eagj: Deleted 2021/02/08 05:50:11 DEBUG : potato3.rclone_chunk.001_79eb2n: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:50:11 INFO : potato3.rclone_chunk.001_79eb2n: Copied (server-side copy) to: potato3.rclone_chunk.001 2021/02/08 05:50:11 INFO : potato3.rclone_chunk.001_79eb2n: Deleted 2021/02/08 05:50:11 DEBUG : potato3.rclone_chunk.002_79eb2n: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK 2021/02/08 05:50:11 INFO : potato3.rclone_chunk.002_79eb2n: Copied (server-side copy) to: potato3.rclone_chunk.002 2021/02/08 05:50:11 INFO : potato3.rclone_chunk.002_79eb2n: Deleted 2021/02/08 05:50:11 DEBUG : tomatoDir: Making directory sync_test.go:1294: Server side move (if possible) Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-fafodog2sedebox7xofucib3' -> Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-zuqinad5sejewim9zafanaw0' 2021/02/08 05:50:12 INFO : S3 bucket rclone-test-zuqinad5sejewim9zafanaw0: Bucket "rclone-test-zuqinad5sejewim9zafanaw0" created with ACL "private" 2021/02/08 05:50:12 DEBUG : empty space.rclone_chunk.001_79eca7: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK 2021/02/08 05:50:12 INFO : empty space.rclone_chunk.001_79eca7: Copied (server-side copy) to: empty space 2021/02/08 05:50:12 INFO : empty space.rclone_chunk.001_79eca7: Deleted 2021/02/08 05:50:12 DEBUG : potato3.rclone_chunk.001_79ecjh: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:50:12 INFO : potato3.rclone_chunk.001_79ecjh: Copied (server-side copy) to: potato3.rclone_chunk.001 2021/02/08 05:50:12 INFO : potato3.rclone_chunk.001_79ecjh: Deleted 2021/02/08 05:50:12 DEBUG : potato3.rclone_chunk.002_79ecjh: MD5 = 01a6651a94ab602dbfc47587d234b52c OK 2021/02/08 05:50:12 INFO : potato3.rclone_chunk.002_79ecjh: Copied (server-side copy) to: potato3.rclone_chunk.002 2021/02/08 05:50:13 INFO : potato3.rclone_chunk.002_79ecjh: Deleted 2021/02/08 05:50:13 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2021/02/08 05:50:13 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-zuqinad5sejewim9zafanaw0': Waiting for checks to finish 2021/02/08 05:50:13 DEBUG : potato3: Can't copy - required hash not found 2021/02/08 05:50:13 DEBUG : potato2: Can't copy - required hash not found 2021/02/08 05:50:13 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns) 2021/02/08 05:50:13 DEBUG : empty space: Unchanged skipping 2021/02/08 05:50:13 INFO : empty space: Deleted 2021/02/08 05:50:13 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-zuqinad5sejewim9zafanaw0': Waiting for transfers to finish 2021/02/08 05:50:13 DEBUG : potato2.rclone_chunk.001_79edsu: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:50:13 INFO : potato2.rclone_chunk.001_79edsu: Copied (server-side copy) to: potato2.rclone_chunk.001 2021/02/08 05:50:13 INFO : potato2.rclone_chunk.001_79edsu: Deleted 2021/02/08 05:50:13 DEBUG : potato3.rclone_chunk.001_79edei: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:50:13 INFO : potato3.rclone_chunk.001_79edei: Copied (server-side copy) to: potato3.rclone_chunk.001 2021/02/08 05:50:13 INFO : potato3.rclone_chunk.001_79edei: Deleted 2021/02/08 05:50:13 DEBUG : potato2.rclone_chunk.002_79edsu: MD5 = 01a6651a94ab602dbfc47587d234b52c OK 2021/02/08 05:50:13 INFO : potato2.rclone_chunk.002_79edsu: Copied (server-side copy) to: potato2.rclone_chunk.002 2021/02/08 05:50:13 INFO : potato2.rclone_chunk.002_79edsu: Deleted 2021/02/08 05:50:13 DEBUG : potato3.rclone_chunk.002_79edei: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK 2021/02/08 05:50:13 INFO : potato3.rclone_chunk.002_79edei: Copied (server-side copy) to: potato3.rclone_chunk.002 2021/02/08 05:50:13 INFO : potato2: Copied (new) 2021/02/08 05:50:13 INFO : potato3.rclone_chunk.002_79edei: Deleted 2021/02/08 05:50:13 INFO : potato3: Copied (replaced existing) 2021/02/08 05:50:13 INFO : potato2: Deleted 2021/02/08 05:50:13 INFO : potato3: Deleted 2021/02/08 05:50:13 DEBUG : Creating backend with remote "TestChunkerChunk50bSHA1QuickS3:rclone-test-viyogos1xiseqic6qedawik5" 2021/02/08 05:50:13 DEBUG : Creating backend with remote "TestS3:rclone-test-viyogos1xiseqic6qedawik5" 2021/02/08 05:50:13 DEBUG : Reset feature "ListR" 2021/02/08 05:50:13 DEBUG : tomatoDir: Making directory 2021/02/08 05:50:13 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-viyogos1xiseqic6qedawik5': Waiting for checks to finish 2021/02/08 05:50:13 DEBUG : empty space: copy non-chunked object... 2021/02/08 05:50:13 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-viyogos1xiseqic6qedawik5': Waiting for transfers to finish 2021/02/08 05:50:13 DEBUG : potato2: Can't copy - required hash not found 2021/02/08 05:50:13 DEBUG : potato3: Can't copy - required hash not found 2021/02/08 05:50:14 INFO : S3 bucket rclone-test-viyogos1xiseqic6qedawik5: Bucket "rclone-test-viyogos1xiseqic6qedawik5" created with ACL "private" 2021/02/08 05:50:14 INFO : empty space: Copied (server-side copy) 2021/02/08 05:50:14 INFO : empty space: Deleted 2021/02/08 05:50:14 DEBUG : potato3.rclone_chunk.001_79eeku: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:50:14 INFO : potato3.rclone_chunk.001_79eeku: Copied (server-side copy) to: potato3.rclone_chunk.001 2021/02/08 05:50:14 DEBUG : potato2.rclone_chunk.001_79ee3w: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:50:14 INFO : potato2.rclone_chunk.001_79ee3w: Copied (server-side copy) to: potato2.rclone_chunk.001 2021/02/08 05:50:14 INFO : potato3.rclone_chunk.001_79eeku: Deleted 2021/02/08 05:50:14 INFO : potato2.rclone_chunk.001_79ee3w: Deleted 2021/02/08 05:50:14 DEBUG : potato3.rclone_chunk.002_79eeku: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK 2021/02/08 05:50:14 INFO : potato3.rclone_chunk.002_79eeku: Copied (server-side copy) to: potato3.rclone_chunk.002 2021/02/08 05:50:14 INFO : potato3.rclone_chunk.002_79eeku: Deleted 2021/02/08 05:50:14 DEBUG : potato2.rclone_chunk.002_79ee3w: MD5 = 01a6651a94ab602dbfc47587d234b52c OK 2021/02/08 05:50:14 INFO : potato2.rclone_chunk.002_79ee3w: Copied (server-side copy) to: potato2.rclone_chunk.002 2021/02/08 05:50:14 INFO : potato2.rclone_chunk.002_79ee3w: Deleted 2021/02/08 05:50:14 INFO : potato3: Copied (new) 2021/02/08 05:50:15 INFO : potato2: Copied (new) 2021/02/08 05:50:15 INFO : potato3: Deleted 2021/02/08 05:50:15 INFO : potato2: Deleted 2021/02/08 05:50:15 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-viyogos1xiseqic6qedawik5': Purge object "empty space" 2021/02/08 05:50:15 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-viyogos1xiseqic6qedawik5': Purge object "potato2" 2021/02/08 05:50:15 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-viyogos1xiseqic6qedawik5': Purge object "potato3" 2021/02/08 05:50:15 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-viyogos1xiseqic6qedawik5': Purge dir "" 2021/02/08 05:50:15 INFO : S3 bucket rclone-test-viyogos1xiseqic6qedawik5: Bucket "rclone-test-viyogos1xiseqic6qedawik5" deleted 2021/02/08 05:50:15 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-zuqinad5sejewim9zafanaw0': Purge dir "" 2021/02/08 05:50:15 INFO : S3 bucket rclone-test-zuqinad5sejewim9zafanaw0: Bucket "rclone-test-zuqinad5sejewim9zafanaw0" deleted --- PASS: TestServerSideMoveDeleteEmptySourceDirs (5.63s) FAIL 2021/02/08 05:50:16 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-fafodog2sedebox7xofucib3': Purge dir "" 2021/02/08 05:50:16 INFO : S3 bucket rclone-test-fafodog2sedebox7xofucib3: Bucket "rclone-test-fafodog2sedebox7xofucib3" deleted "./sync.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bSHA1QuickS3: -verbose -size-limit 1024 -test.run '^(TestServerSideMove|TestServerSideMoveDeleteEmptySourceDirs)$'" - Finished ERROR in 12.278525187s (try 3/5): exit status 1: Failed [TestServerSideMove]