"./sync.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bMD5QuickS3: -verbose -size-limit 1024 -test.run '^(TestServerSideMove|TestServerSideMoveDeleteEmptySourceDirs)$'" - Starting (try 5/5)
2020/12/12 05:48:02 DEBUG : Creating backend with remote "TestChunkerChunk50bMD5QuickS3:rclone-test-wasevog4sababug4konuyec3"
2020/12/12 05:48:02 DEBUG : Creating backend with remote "TestS3:rclone-test-wasevog4sababug4konuyec3"
2020/12/12 05:48:02 DEBUG : Reset feature "ListR"
2020/12/12 05:48:02 DEBUG : Creating backend with remote "/tmp/rclone014357102"
=== RUN   TestServerSideMove
    run.go:176: Remote "Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-wasevog4sababug4konuyec3'", Local "Local file system at /tmp/rclone014357102", Modify Window "1ns"
2020/12/12 05:48:02 DEBUG : Creating backend with remote "TestChunkerChunk50bMD5QuickS3:rclone-test-deyesof9sebeciq7raduduj2"
2020/12/12 05:48:02 DEBUG : Creating backend with remote "TestS3:rclone-test-deyesof9sebeciq7raduduj2"
2020/12/12 05:48:02 DEBUG : Reset feature "ListR"
2020/12/12 05:48:03 INFO  : S3 bucket rclone-test-wasevog4sababug4konuyec3: Bucket "rclone-test-wasevog4sababug4konuyec3" created with ACL "private"
2020/12/12 05:48:03 DEBUG : potato2.rclone_chunk.001_7um6ae: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 05:48:03 INFO  : potato2.rclone_chunk.001_7um6ae: Copied (server-side copy) to: potato2.rclone_chunk.001
2020/12/12 05:48:03 INFO  : potato2.rclone_chunk.001_7um6ae: Deleted
2020/12/12 05:48:03 DEBUG : potato2.rclone_chunk.002_7um6ae: MD5 = 01a6651a94ab602dbfc47587d234b52c OK
2020/12/12 05:48:03 INFO  : potato2.rclone_chunk.002_7um6ae: Copied (server-side copy) to: potato2.rclone_chunk.002
2020/12/12 05:48:03 INFO  : potato2.rclone_chunk.002_7um6ae: Deleted
2020/12/12 05:48:03 DEBUG : empty space.rclone_chunk.001_7um6pz: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK
2020/12/12 05:48:03 INFO  : empty space.rclone_chunk.001_7um6pz: Copied (server-side copy) to: empty space
2020/12/12 05:48:03 INFO  : empty space.rclone_chunk.001_7um6pz: Deleted
2020/12/12 05:48:04 DEBUG : potato3.rclone_chunk.001_7um6uc: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 05:48:04 INFO  : potato3.rclone_chunk.001_7um6uc: Copied (server-side copy) to: potato3.rclone_chunk.001
2020/12/12 05:48:04 INFO  : potato3.rclone_chunk.001_7um6uc: Deleted
2020/12/12 05:48:04 DEBUG : potato3.rclone_chunk.002_7um6uc: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK
2020/12/12 05:48:04 INFO  : potato3.rclone_chunk.002_7um6uc: Copied (server-side copy) to: potato3.rclone_chunk.002
2020/12/12 05:48:04 INFO  : potato3.rclone_chunk.002_7um6uc: Deleted
    sync_test.go:1294: Server side move (if possible) Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-wasevog4sababug4konuyec3' -> Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-deyesof9sebeciq7raduduj2'
2020/12/12 05:48:05 INFO  : S3 bucket rclone-test-deyesof9sebeciq7raduduj2: Bucket "rclone-test-deyesof9sebeciq7raduduj2" created with ACL "private"
2020/12/12 05:48:05 DEBUG : empty space.rclone_chunk.001_7um82v: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK
2020/12/12 05:48:05 INFO  : empty space.rclone_chunk.001_7um82v: Copied (server-side copy) to: empty space
2020/12/12 05:48:05 INFO  : empty space.rclone_chunk.001_7um82v: Deleted
2020/12/12 05:48:05 DEBUG : potato3.rclone_chunk.001_7um8zh: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 05:48:05 INFO  : potato3.rclone_chunk.001_7um8zh: Copied (server-side copy) to: potato3.rclone_chunk.001
2020/12/12 05:48:05 INFO  : potato3.rclone_chunk.001_7um8zh: Deleted
2020/12/12 05:48:05 DEBUG : potato3.rclone_chunk.002_7um8zh: MD5 = 01a6651a94ab602dbfc47587d234b52c OK
2020/12/12 05:48:05 INFO  : potato3.rclone_chunk.002_7um8zh: Copied (server-side copy) to: potato3.rclone_chunk.002
2020/12/12 05:48:05 INFO  : potato3.rclone_chunk.002_7um8zh: Deleted
2020/12/12 05:48:05 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2020/12/12 05:48:05 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-deyesof9sebeciq7raduduj2': Waiting for checks to finish
2020/12/12 05:48:05 DEBUG : potato2: Can't copy - required hash not found
2020/12/12 05:48:05 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/12/12 05:48:05 DEBUG : empty space: Unchanged skipping
2020/12/12 05:48:05 DEBUG : potato3: Can't copy - required hash not found
2020/12/12 05:48:05 INFO  : empty space: Deleted
2020/12/12 05:48:05 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-deyesof9sebeciq7raduduj2': Waiting for transfers to finish
2020/12/12 05:48:05 DEBUG : potato2.rclone_chunk.001_7um8ei: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 05:48:05 INFO  : potato2.rclone_chunk.001_7um8ei: Copied (server-side copy) to: potato2.rclone_chunk.001
2020/12/12 05:48:05 INFO  : potato2.rclone_chunk.001_7um8ei: Deleted
2020/12/12 05:48:06 DEBUG : potato2.rclone_chunk.002_7um8ei: MD5 = 01a6651a94ab602dbfc47587d234b52c OK
2020/12/12 05:48:06 INFO  : potato2.rclone_chunk.002_7um8ei: Copied (server-side copy) to: potato2.rclone_chunk.002
2020/12/12 05:48:06 INFO  : potato2.rclone_chunk.002_7um8ei: Deleted
2020/12/12 05:48:06 INFO  : potato2: Copied (new)
2020/12/12 05:48:06 INFO  : potato2: Deleted
2020/12/12 05:48:06 DEBUG : potato3.rclone_chunk.001_7um8jh: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 05:48:06 INFO  : potato3.rclone_chunk.001_7um8jh: Copied (server-side copy) to: potato3.rclone_chunk.001
2020/12/12 05:48:06 INFO  : potato3.rclone_chunk.001_7um8jh: Deleted
2020/12/12 05:48:06 DEBUG : potato3.rclone_chunk.002_7um8jh: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK
2020/12/12 05:48:06 INFO  : potato3.rclone_chunk.002_7um8jh: Copied (server-side copy) to: potato3.rclone_chunk.002
2020/12/12 05:48:06 INFO  : potato3.rclone_chunk.002_7um8jh: Deleted
2020/12/12 05:48:06 INFO  : potato3: Copied (replaced existing)
2020/12/12 05:48:06 INFO  : potato3: Deleted
2020/12/12 05:48:06 DEBUG : Creating backend with remote "TestChunkerChunk50bMD5QuickS3:rclone-test-vomojot5mitofef5viciduy9"
2020/12/12 05:48:06 DEBUG : Creating backend with remote "TestS3:rclone-test-vomojot5mitofef5viciduy9"
2020/12/12 05:48:06 DEBUG : Reset feature "ListR"
2020/12/12 05:48:06 DEBUG : empty space: copy non-chunked object...
2020/12/12 05:48:06 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-vomojot5mitofef5viciduy9': Waiting for checks to finish
2020/12/12 05:48:06 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-vomojot5mitofef5viciduy9': Waiting for transfers to finish
2020/12/12 05:48:06 DEBUG : potato2: Can't copy - required hash not found
2020/12/12 05:48:06 DEBUG : potato3: Can't copy - required hash not found
2020/12/12 05:48:07 INFO  : S3 bucket rclone-test-vomojot5mitofef5viciduy9: Bucket "rclone-test-vomojot5mitofef5viciduy9" created with ACL "private"
2020/12/12 05:48:07 INFO  : empty space: Copied (server-side copy)
2020/12/12 05:48:07 INFO  : empty space: Deleted
2020/12/12 05:48:07 ERROR : potato3: Failed to copy: object not found
2020/12/12 05:48:07 ERROR : potato3: Not deleting source as copy failed: object not found
2020/12/12 05:48:07 ERROR : potato2: Failed to copy: object not found
2020/12/12 05:48:07 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
2020/12/12 05:48:07 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-vomojot5mitofef5viciduy9': Purge object "empty space"
2020/12/12 05:48:07 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-vomojot5mitofef5viciduy9': Purge dir ""
2020/12/12 05:48:07 purge failed to rmdir "": BucketNotEmpty: The bucket you tried to delete is not empty
	status code: 409, request id: 0FBD8901837A771D, host id: bLp8hcaMfr5isjYIzsY089GE5jh6p4WoFpV7eeBXJn7mG+L70oA60IhUVptyfqu9TjUBQRJPwM8=
2020/12/12 05:48:07 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-deyesof9sebeciq7raduduj2': Purge object "potato2"
2020/12/12 05:48:07 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-deyesof9sebeciq7raduduj2': Purge object "potato3"
2020/12/12 05:48:07 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-deyesof9sebeciq7raduduj2': Purge dir ""
2020/12/12 05:48:08 INFO  : S3 bucket rclone-test-deyesof9sebeciq7raduduj2: Bucket "rclone-test-deyesof9sebeciq7raduduj2" deleted
--- FAIL: TestServerSideMove (6.09s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:176: Remote "Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-wasevog4sababug4konuyec3'", Local "Local file system at /tmp/rclone014357102", Modify Window "1ns"
2020/12/12 05:48:08 DEBUG : Creating backend with remote "TestChunkerChunk50bMD5QuickS3:rclone-test-huduliy2povelem7ruyufom9"
2020/12/12 05:48:08 DEBUG : Creating backend with remote "TestS3:rclone-test-huduliy2povelem7ruyufom9"
2020/12/12 05:48:08 DEBUG : Reset feature "ListR"
2020/12/12 05:48:08 DEBUG : potato2.rclone_chunk.001_7umbuo: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 05:48:08 INFO  : potato2.rclone_chunk.001_7umbuo: Copied (server-side copy) to: potato2.rclone_chunk.001
2020/12/12 05:48:08 INFO  : potato2.rclone_chunk.001_7umbuo: Deleted
2020/12/12 05:48:08 DEBUG : potato2.rclone_chunk.002_7umbuo: MD5 = 01a6651a94ab602dbfc47587d234b52c OK
2020/12/12 05:48:08 INFO  : potato2.rclone_chunk.002_7umbuo: Copied (server-side copy) to: potato2.rclone_chunk.002
2020/12/12 05:48:08 INFO  : potato2.rclone_chunk.002_7umbuo: Deleted
2020/12/12 05:48:09 DEBUG : empty space.rclone_chunk.001_7umbtn: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK
2020/12/12 05:48:09 INFO  : empty space.rclone_chunk.001_7umbtn: Copied (server-side copy) to: empty space
2020/12/12 05:48:09 INFO  : empty space.rclone_chunk.001_7umbtn: Deleted
2020/12/12 05:48:09 DEBUG : potato3.rclone_chunk.001_7umcrj: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 05:48:09 INFO  : potato3.rclone_chunk.001_7umcrj: Copied (server-side copy) to: potato3.rclone_chunk.001
2020/12/12 05:48:09 INFO  : potato3.rclone_chunk.001_7umcrj: Deleted
2020/12/12 05:48:09 DEBUG : potato3.rclone_chunk.002_7umcrj: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK
2020/12/12 05:48:09 INFO  : potato3.rclone_chunk.002_7umcrj: Copied (server-side copy) to: potato3.rclone_chunk.002
2020/12/12 05:48:09 INFO  : potato3.rclone_chunk.002_7umcrj: Deleted
2020/12/12 05:48:09 DEBUG : tomatoDir: Making directory
    sync_test.go:1294: Server side move (if possible) Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-wasevog4sababug4konuyec3' -> Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-huduliy2povelem7ruyufom9'
2020/12/12 05:48:10 INFO  : S3 bucket rclone-test-huduliy2povelem7ruyufom9: Bucket "rclone-test-huduliy2povelem7ruyufom9" created with ACL "private"
2020/12/12 05:48:10 DEBUG : empty space.rclone_chunk.001_7umddm: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK
2020/12/12 05:48:10 INFO  : empty space.rclone_chunk.001_7umddm: Copied (server-side copy) to: empty space
2020/12/12 05:48:10 INFO  : empty space.rclone_chunk.001_7umddm: Deleted
2020/12/12 05:48:10 DEBUG : potato3.rclone_chunk.001_7umd4s: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 05:48:10 INFO  : potato3.rclone_chunk.001_7umd4s: Copied (server-side copy) to: potato3.rclone_chunk.001
2020/12/12 05:48:10 INFO  : potato3.rclone_chunk.001_7umd4s: Deleted
2020/12/12 05:48:10 DEBUG : potato3.rclone_chunk.002_7umd4s: MD5 = 01a6651a94ab602dbfc47587d234b52c OK
2020/12/12 05:48:10 INFO  : potato3.rclone_chunk.002_7umd4s: Copied (server-side copy) to: potato3.rclone_chunk.002
2020/12/12 05:48:10 INFO  : potato3.rclone_chunk.002_7umd4s: Deleted
2020/12/12 05:48:10 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2020/12/12 05:48:10 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-huduliy2povelem7ruyufom9': Waiting for checks to finish
2020/12/12 05:48:10 DEBUG : potato2: Can't copy - required hash not found
2020/12/12 05:48:10 DEBUG : potato3: Can't copy - required hash not found
2020/12/12 05:48:10 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/12/12 05:48:10 DEBUG : empty space: Unchanged skipping
2020/12/12 05:48:10 INFO  : empty space: Deleted
2020/12/12 05:48:10 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-huduliy2povelem7ruyufom9': Waiting for transfers to finish
2020/12/12 05:48:11 DEBUG : potato2.rclone_chunk.001_7umddh: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 05:48:11 INFO  : potato2.rclone_chunk.001_7umddh: Copied (server-side copy) to: potato2.rclone_chunk.001
2020/12/12 05:48:11 INFO  : potato2.rclone_chunk.001_7umddh: Deleted
2020/12/12 05:48:11 DEBUG : potato3.rclone_chunk.001_7umd4a: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 05:48:11 INFO  : potato3.rclone_chunk.001_7umd4a: Copied (server-side copy) to: potato3.rclone_chunk.001
2020/12/12 05:48:11 INFO  : potato3.rclone_chunk.001_7umd4a: Deleted
2020/12/12 05:48:11 DEBUG : potato2.rclone_chunk.002_7umddh: MD5 = 01a6651a94ab602dbfc47587d234b52c OK
2020/12/12 05:48:11 INFO  : potato2.rclone_chunk.002_7umddh: Copied (server-side copy) to: potato2.rclone_chunk.002
2020/12/12 05:48:11 INFO  : potato2.rclone_chunk.002_7umddh: Deleted
2020/12/12 05:48:11 DEBUG : potato3.rclone_chunk.002_7umd4a: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK
2020/12/12 05:48:11 INFO  : potato3.rclone_chunk.002_7umd4a: Copied (server-side copy) to: potato3.rclone_chunk.002
2020/12/12 05:48:11 INFO  : potato3.rclone_chunk.002_7umd4a: Deleted
2020/12/12 05:48:11 INFO  : potato2: Copied (new)
2020/12/12 05:48:11 INFO  : potato3: Copied (replaced existing)
2020/12/12 05:48:11 INFO  : potato2: Deleted
2020/12/12 05:48:11 INFO  : potato3: Deleted
2020/12/12 05:48:11 DEBUG : Creating backend with remote "TestChunkerChunk50bMD5QuickS3:rclone-test-gakutox5cuboqag4pulilip5"
2020/12/12 05:48:11 DEBUG : Creating backend with remote "TestS3:rclone-test-gakutox5cuboqag4pulilip5"
2020/12/12 05:48:11 DEBUG : Reset feature "ListR"
2020/12/12 05:48:11 DEBUG : tomatoDir: Making directory
2020/12/12 05:48:11 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-gakutox5cuboqag4pulilip5': Waiting for checks to finish
2020/12/12 05:48:11 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-gakutox5cuboqag4pulilip5': Waiting for transfers to finish
2020/12/12 05:48:11 DEBUG : empty space: copy non-chunked object...
2020/12/12 05:48:11 DEBUG : potato3: Can't copy - required hash not found
2020/12/12 05:48:11 DEBUG : potato2: Can't copy - required hash not found
2020/12/12 05:48:12 INFO  : S3 bucket rclone-test-gakutox5cuboqag4pulilip5: Bucket "rclone-test-gakutox5cuboqag4pulilip5" created with ACL "private"
2020/12/12 05:48:12 INFO  : empty space: Copied (server-side copy)
2020/12/12 05:48:12 INFO  : empty space: Deleted
2020/12/12 05:48:12 ERROR : potato2: Failed to copy: object not found
2020/12/12 05:48:12 ERROR : potato2: Not deleting source as copy failed: object not found
2020/12/12 05:48:12 DEBUG : potato3.rclone_chunk.001_7umect: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 05:48:12 INFO  : potato3.rclone_chunk.001_7umect: Copied (server-side copy) to: potato3.rclone_chunk.001
2020/12/12 05:48:12 INFO  : potato3.rclone_chunk.001_7umect: Deleted
2020/12/12 05:48:12 DEBUG : potato3.rclone_chunk.002_7umect: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK
2020/12/12 05:48:12 INFO  : potato3.rclone_chunk.002_7umect: Copied (server-side copy) to: potato3.rclone_chunk.002
2020/12/12 05:48:12 INFO  : potato3.rclone_chunk.002_7umect: Deleted
2020/12/12 05:48:12 INFO  : potato3: Copied (new)
2020/12/12 05:48:12 INFO  : potato3: Deleted
    sync_test.go:1331: 
        	Error Trace:	sync_test.go:1331
        	            				sync_test.go:1420
        	Error:      	Received unexpected error:
        	            	object not found
        	Test:       	TestServerSideMoveDeleteEmptySourceDirs
2020/12/12 05:48:12 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-gakutox5cuboqag4pulilip5': Purge object "empty space"
2020/12/12 05:48:12 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-gakutox5cuboqag4pulilip5': Purge object "potato3"
2020/12/12 05:48:12 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-gakutox5cuboqag4pulilip5': Purge dir ""
2020/12/12 05:48:12 purge failed to rmdir "": BucketNotEmpty: The bucket you tried to delete is not empty
	status code: 409, request id: 9CCFC41DC3054BD7, host id: i7ic4xypuc9Cb98fa/HPmw/r2RBFfePR/FA/VJUOwuNDjfQZiVvJ9fTkb765Jj9gsqfv0FCHSNA=
2020/12/12 05:48:12 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-huduliy2povelem7ruyufom9': Purge object "potato2"
2020/12/12 05:48:12 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-huduliy2povelem7ruyufom9': Purge dir ""
2020/12/12 05:48:13 INFO  : S3 bucket rclone-test-huduliy2povelem7ruyufom9: Bucket "rclone-test-huduliy2povelem7ruyufom9" deleted
--- FAIL: TestServerSideMoveDeleteEmptySourceDirs (5.10s)
FAIL
2020/12/12 05:48:13 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-wasevog4sababug4konuyec3': Purge dir ""
2020/12/12 05:48:13 INFO  : S3 bucket rclone-test-wasevog4sababug4konuyec3: Bucket "rclone-test-wasevog4sababug4konuyec3" deleted
"./sync.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bMD5QuickS3: -verbose -size-limit 1024 -test.run '^(TestServerSideMove|TestServerSideMoveDeleteEmptySourceDirs)$'" - Finished ERROR in 11.536955385s (try 5/5): exit status 1: Failed [TestServerSideMove TestServerSideMoveDeleteEmptySourceDirs]