"./sync.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bMD5QuickS3: -verbose -fast-list -size-limit 1024 -test.run '^(TestServerSideMove|TestServerSideMoveDeleteEmptySourceDirs)$'" - Starting (try 3/5)
2020/12/12 06:01:02 DEBUG : Creating backend with remote "TestChunkerChunk50bMD5QuickS3:rclone-test-valukiy5zifetaz1capazul4"
2020/12/12 06:01:02 DEBUG : Creating backend with remote "TestS3:rclone-test-valukiy5zifetaz1capazul4"
2020/12/12 06:01:02 DEBUG : Reset feature "ListR"
2020/12/12 06:01:02 DEBUG : Creating backend with remote "/tmp/rclone793038819"
=== RUN   TestServerSideMove
    run.go:176: Remote "Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-valukiy5zifetaz1capazul4'", Local "Local file system at /tmp/rclone793038819", Modify Window "1ns"
2020/12/12 06:01:02 DEBUG : Creating backend with remote "TestChunkerChunk50bMD5QuickS3:rclone-test-migamek0soxezuk1fekewes2"
2020/12/12 06:01:02 DEBUG : Creating backend with remote "TestS3:rclone-test-migamek0soxezuk1fekewes2"
2020/12/12 06:01:02 DEBUG : Reset feature "ListR"
2020/12/12 06:01:03 INFO  : S3 bucket rclone-test-valukiy5zifetaz1capazul4: Bucket "rclone-test-valukiy5zifetaz1capazul4" created with ACL "private"
2020/12/12 06:01:03 DEBUG : potato2.rclone_chunk.001_7v7ui7: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 06:01:03 INFO  : potato2.rclone_chunk.001_7v7ui7: Copied (server-side copy) to: potato2.rclone_chunk.001
2020/12/12 06:01:03 INFO  : potato2.rclone_chunk.001_7v7ui7: Deleted
2020/12/12 06:01:03 DEBUG : potato2.rclone_chunk.002_7v7ui7: MD5 = 01a6651a94ab602dbfc47587d234b52c OK
2020/12/12 06:01:03 INFO  : potato2.rclone_chunk.002_7v7ui7: Copied (server-side copy) to: potato2.rclone_chunk.002
2020/12/12 06:01:03 INFO  : potato2.rclone_chunk.002_7v7ui7: Deleted
2020/12/12 06:01:03 DEBUG : empty space.rclone_chunk.001_7v7uui: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK
2020/12/12 06:01:03 INFO  : empty space.rclone_chunk.001_7v7uui: Copied (server-side copy) to: empty space
2020/12/12 06:01:03 INFO  : empty space.rclone_chunk.001_7v7uui: Deleted
2020/12/12 06:01:03 DEBUG : potato3.rclone_chunk.001_7v7ul3: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 06:01:03 INFO  : potato3.rclone_chunk.001_7v7ul3: Copied (server-side copy) to: potato3.rclone_chunk.001
2020/12/12 06:01:03 INFO  : potato3.rclone_chunk.001_7v7ul3: Deleted
2020/12/12 06:01:03 DEBUG : potato3.rclone_chunk.002_7v7ul3: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK
2020/12/12 06:01:03 INFO  : potato3.rclone_chunk.002_7v7ul3: Copied (server-side copy) to: potato3.rclone_chunk.002
2020/12/12 06:01:03 INFO  : potato3.rclone_chunk.002_7v7ul3: Deleted
    sync_test.go:1294: Server side move (if possible) Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-valukiy5zifetaz1capazul4' -> Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-migamek0soxezuk1fekewes2'
2020/12/12 06:01:04 INFO  : S3 bucket rclone-test-migamek0soxezuk1fekewes2: Bucket "rclone-test-migamek0soxezuk1fekewes2" created with ACL "private"
2020/12/12 06:01:04 DEBUG : empty space.rclone_chunk.001_7v7v8b: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK
2020/12/12 06:01:04 INFO  : empty space.rclone_chunk.001_7v7v8b: Copied (server-side copy) to: empty space
2020/12/12 06:01:04 INFO  : empty space.rclone_chunk.001_7v7v8b: Deleted
2020/12/12 06:01:04 DEBUG : potato3.rclone_chunk.001_7v7vdr: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 06:01:04 INFO  : potato3.rclone_chunk.001_7v7vdr: Copied (server-side copy) to: potato3.rclone_chunk.001
2020/12/12 06:01:05 INFO  : potato3.rclone_chunk.001_7v7vdr: Deleted
2020/12/12 06:01:05 DEBUG : potato3.rclone_chunk.002_7v7vdr: MD5 = 01a6651a94ab602dbfc47587d234b52c OK
2020/12/12 06:01:05 INFO  : potato3.rclone_chunk.002_7v7vdr: Copied (server-side copy) to: potato3.rclone_chunk.002
2020/12/12 06:01:05 INFO  : potato3.rclone_chunk.002_7v7vdr: Deleted
2020/12/12 06:01:05 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2020/12/12 06:01:05 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-migamek0soxezuk1fekewes2': Waiting for checks to finish
2020/12/12 06:01:05 DEBUG : potato2: Can't copy - required hash not found
2020/12/12 06:01:05 DEBUG : potato3: Can't copy - required hash not found
2020/12/12 06:01:05 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/12/12 06:01:05 DEBUG : empty space: Unchanged skipping
2020/12/12 06:01:05 INFO  : empty space: Deleted
2020/12/12 06:01:05 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-migamek0soxezuk1fekewes2': Waiting for transfers to finish
2020/12/12 06:01:05 DEBUG : potato2.rclone_chunk.001_7v7wws: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 06:01:05 INFO  : potato2.rclone_chunk.001_7v7wws: Copied (server-side copy) to: potato2.rclone_chunk.001
2020/12/12 06:01:05 INFO  : potato2.rclone_chunk.001_7v7wws: Deleted
2020/12/12 06:01:05 DEBUG : potato2.rclone_chunk.002_7v7wws: MD5 = 01a6651a94ab602dbfc47587d234b52c OK
2020/12/12 06:01:05 INFO  : potato2.rclone_chunk.002_7v7wws: Copied (server-side copy) to: potato2.rclone_chunk.002
2020/12/12 06:01:05 DEBUG : potato3.rclone_chunk.001_7v7wjf: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 06:01:05 INFO  : potato3.rclone_chunk.001_7v7wjf: Copied (server-side copy) to: potato3.rclone_chunk.001
2020/12/12 06:01:05 INFO  : potato2.rclone_chunk.002_7v7wws: Deleted
2020/12/12 06:01:05 INFO  : potato3.rclone_chunk.001_7v7wjf: Deleted
2020/12/12 06:01:05 DEBUG : potato3.rclone_chunk.002_7v7wjf: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK
2020/12/12 06:01:05 INFO  : potato3.rclone_chunk.002_7v7wjf: Copied (server-side copy) to: potato3.rclone_chunk.002
2020/12/12 06:01:05 INFO  : potato2: Copied (new)
2020/12/12 06:01:05 INFO  : potato3.rclone_chunk.002_7v7wjf: Deleted
2020/12/12 06:01:05 INFO  : potato3: Copied (replaced existing)
2020/12/12 06:01:05 INFO  : potato2: Deleted
2020/12/12 06:01:05 INFO  : potato3: Deleted
2020/12/12 06:01:05 DEBUG : Creating backend with remote "TestChunkerChunk50bMD5QuickS3:rclone-test-hokodof4kebazag6vixuvox8"
2020/12/12 06:01:05 DEBUG : Creating backend with remote "TestS3:rclone-test-hokodof4kebazag6vixuvox8"
2020/12/12 06:01:05 DEBUG : Reset feature "ListR"
2020/12/12 06:01:05 DEBUG : empty space: copy non-chunked object...
2020/12/12 06:01:05 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-hokodof4kebazag6vixuvox8': Waiting for checks to finish
2020/12/12 06:01:05 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-hokodof4kebazag6vixuvox8': Waiting for transfers to finish
2020/12/12 06:01:05 DEBUG : potato2: Can't copy - required hash not found
2020/12/12 06:01:05 DEBUG : potato3: Can't copy - required hash not found
2020/12/12 06:01:06 INFO  : S3 bucket rclone-test-hokodof4kebazag6vixuvox8: Bucket "rclone-test-hokodof4kebazag6vixuvox8" created with ACL "private"
2020/12/12 06:01:06 INFO  : empty space: Copied (server-side copy)
2020/12/12 06:01:06 INFO  : empty space: Deleted
2020/12/12 06:01:06 ERROR : potato2: Failed to copy: object not found
2020/12/12 06:01:06 ERROR : potato2: Not deleting source as copy failed: object not found
2020/12/12 06:01:06 ERROR : potato3: Failed to copy: object not found
2020/12/12 06:01:06 ERROR : potato3: 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 06:01:06 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-hokodof4kebazag6vixuvox8': Purge object "empty space"
2020/12/12 06:01:06 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-hokodof4kebazag6vixuvox8': Purge dir ""
2020/12/12 06:01:06 purge failed to rmdir "": BucketNotEmpty: The bucket you tried to delete is not empty
	status code: 409, request id: 80CAB6755FA98526, host id: jSZ2DSvYZWt53eVxrXklHlNuy4sPp9SbC8Ei+us+YEWR8bdxnrBpr6umuXIri/hdJmLUKB9N3NI=
2020/12/12 06:01:06 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-migamek0soxezuk1fekewes2': Purge object "potato2"
2020/12/12 06:01:07 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-migamek0soxezuk1fekewes2': Purge object "potato3"
2020/12/12 06:01:07 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-migamek0soxezuk1fekewes2': Purge dir ""
2020/12/12 06:01:07 INFO  : S3 bucket rclone-test-migamek0soxezuk1fekewes2: Bucket "rclone-test-migamek0soxezuk1fekewes2" deleted
--- FAIL: TestServerSideMove (5.03s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:176: Remote "Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-valukiy5zifetaz1capazul4'", Local "Local file system at /tmp/rclone793038819", Modify Window "1ns"
2020/12/12 06:01:07 DEBUG : Creating backend with remote "TestChunkerChunk50bMD5QuickS3:rclone-test-guyoger8lojevos8posivoq0"
2020/12/12 06:01:07 DEBUG : Creating backend with remote "TestS3:rclone-test-guyoger8lojevos8posivoq0"
2020/12/12 06:01:07 DEBUG : Reset feature "ListR"
2020/12/12 06:01:07 DEBUG : potato2.rclone_chunk.001_7v7ywp: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 06:01:07 INFO  : potato2.rclone_chunk.001_7v7ywp: Copied (server-side copy) to: potato2.rclone_chunk.001
2020/12/12 06:01:07 INFO  : potato2.rclone_chunk.001_7v7ywp: Deleted
2020/12/12 06:01:07 DEBUG : potato2.rclone_chunk.002_7v7ywp: MD5 = 01a6651a94ab602dbfc47587d234b52c OK
2020/12/12 06:01:07 INFO  : potato2.rclone_chunk.002_7v7ywp: Copied (server-side copy) to: potato2.rclone_chunk.002
2020/12/12 06:01:07 INFO  : potato2.rclone_chunk.002_7v7ywp: Deleted
2020/12/12 06:01:07 DEBUG : empty space.rclone_chunk.001_7v7y1w: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK
2020/12/12 06:01:07 INFO  : empty space.rclone_chunk.001_7v7y1w: Copied (server-side copy) to: empty space
2020/12/12 06:01:07 INFO  : empty space.rclone_chunk.001_7v7y1w: Deleted
2020/12/12 06:01:08 DEBUG : potato3.rclone_chunk.001_7v7yrz: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 06:01:08 INFO  : potato3.rclone_chunk.001_7v7yrz: Copied (server-side copy) to: potato3.rclone_chunk.001
2020/12/12 06:01:08 INFO  : potato3.rclone_chunk.001_7v7yrz: Deleted
2020/12/12 06:01:08 DEBUG : potato3.rclone_chunk.002_7v7yrz: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK
2020/12/12 06:01:08 INFO  : potato3.rclone_chunk.002_7v7yrz: Copied (server-side copy) to: potato3.rclone_chunk.002
2020/12/12 06:01:08 INFO  : potato3.rclone_chunk.002_7v7yrz: Deleted
2020/12/12 06:01:08 DEBUG : tomatoDir: Making directory
    sync_test.go:1294: Server side move (if possible) Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-valukiy5zifetaz1capazul4' -> Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-guyoger8lojevos8posivoq0'
2020/12/12 06:01:08 INFO  : S3 bucket rclone-test-guyoger8lojevos8posivoq0: Bucket "rclone-test-guyoger8lojevos8posivoq0" created with ACL "private"
2020/12/12 06:01:09 DEBUG : empty space.rclone_chunk.001_7v7zs1: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK
2020/12/12 06:01:09 INFO  : empty space.rclone_chunk.001_7v7zs1: Copied (server-side copy) to: empty space
2020/12/12 06:01:09 INFO  : empty space.rclone_chunk.001_7v7zs1: Deleted
2020/12/12 06:01:09 DEBUG : potato3.rclone_chunk.001_7v80jn: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 06:01:09 INFO  : potato3.rclone_chunk.001_7v80jn: Copied (server-side copy) to: potato3.rclone_chunk.001
2020/12/12 06:01:09 INFO  : potato3.rclone_chunk.001_7v80jn: Deleted
2020/12/12 06:01:09 DEBUG : potato3.rclone_chunk.002_7v80jn: MD5 = 01a6651a94ab602dbfc47587d234b52c OK
2020/12/12 06:01:09 INFO  : potato3.rclone_chunk.002_7v80jn: Copied (server-side copy) to: potato3.rclone_chunk.002
2020/12/12 06:01:09 INFO  : potato3.rclone_chunk.002_7v80jn: Deleted
2020/12/12 06:01:09 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2020/12/12 06:01:09 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-guyoger8lojevos8posivoq0': Waiting for checks to finish
2020/12/12 06:01:09 DEBUG : potato3: Can't copy - required hash not found
2020/12/12 06:01:09 DEBUG : potato2: Can't copy - required hash not found
2020/12/12 06:01:09 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/12/12 06:01:09 DEBUG : empty space: Unchanged skipping
2020/12/12 06:01:09 INFO  : empty space: Deleted
2020/12/12 06:01:09 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-guyoger8lojevos8posivoq0': Waiting for transfers to finish
2020/12/12 06:01:09 DEBUG : potato2.rclone_chunk.001_7v80nf: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 06:01:09 INFO  : potato2.rclone_chunk.001_7v80nf: Copied (server-side copy) to: potato2.rclone_chunk.001
2020/12/12 06:01:09 INFO  : potato2.rclone_chunk.001_7v80nf: Deleted
2020/12/12 06:01:10 DEBUG : potato2.rclone_chunk.002_7v80nf: MD5 = 01a6651a94ab602dbfc47587d234b52c OK
2020/12/12 06:01:10 INFO  : potato2.rclone_chunk.002_7v80nf: Copied (server-side copy) to: potato2.rclone_chunk.002
2020/12/12 06:01:10 INFO  : potato2.rclone_chunk.002_7v80nf: Deleted
2020/12/12 06:01:10 DEBUG : potato3.rclone_chunk.001_7v804q: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 06:01:10 INFO  : potato3.rclone_chunk.001_7v804q: Copied (server-side copy) to: potato3.rclone_chunk.001
2020/12/12 06:01:10 INFO  : potato3.rclone_chunk.001_7v804q: Deleted
2020/12/12 06:01:10 INFO  : potato2: Copied (new)
2020/12/12 06:01:10 INFO  : potato2: Deleted
2020/12/12 06:01:10 DEBUG : potato3.rclone_chunk.002_7v804q: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK
2020/12/12 06:01:10 INFO  : potato3.rclone_chunk.002_7v804q: Copied (server-side copy) to: potato3.rclone_chunk.002
2020/12/12 06:01:10 INFO  : potato3.rclone_chunk.002_7v804q: Deleted
2020/12/12 06:01:10 INFO  : potato3: Copied (replaced existing)
2020/12/12 06:01:10 INFO  : potato3: Deleted
2020/12/12 06:01:10 DEBUG : Creating backend with remote "TestChunkerChunk50bMD5QuickS3:rclone-test-totiyed9zexijap8mebuqiy8"
2020/12/12 06:01:10 DEBUG : Creating backend with remote "TestS3:rclone-test-totiyed9zexijap8mebuqiy8"
2020/12/12 06:01:10 DEBUG : Reset feature "ListR"
2020/12/12 06:01:10 DEBUG : tomatoDir: Making directory
2020/12/12 06:01:10 DEBUG : empty space: copy non-chunked object...
2020/12/12 06:01:10 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-totiyed9zexijap8mebuqiy8': Waiting for checks to finish
2020/12/12 06:01:10 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-totiyed9zexijap8mebuqiy8': Waiting for transfers to finish
2020/12/12 06:01:10 DEBUG : potato2: Can't copy - required hash not found
2020/12/12 06:01:10 DEBUG : potato3: Can't copy - required hash not found
2020/12/12 06:01:11 INFO  : S3 bucket rclone-test-totiyed9zexijap8mebuqiy8: Bucket "rclone-test-totiyed9zexijap8mebuqiy8" created with ACL "private"
2020/12/12 06:01:11 INFO  : empty space: Copied (server-side copy)
2020/12/12 06:01:11 ERROR : potato2: Failed to copy: object not found
2020/12/12 06:01:11 ERROR : potato2: Not deleting source as copy failed: object not found
2020/12/12 06:01:11 INFO  : empty space: Deleted
2020/12/12 06:01:11 ERROR : potato3: Failed to copy: object not found
2020/12/12 06:01:11 ERROR : potato3: Not deleting source as copy failed: object not found
    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 06:01:11 ERROR : : error listing: directory not found
2020/12/12 06:01:11 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-totiyed9zexijap8mebuqiy8': Purge dir ""
2020/12/12 06:01:11 purge failed to rmdir "": BucketNotEmpty: The bucket you tried to delete is not empty
	status code: 409, request id: D798AB29D04F69C1, host id: Hc8Nj0jxnftXJfETDH0s1kcweb9OSTlFBdzUFasgTC5SCu7j0iLGRTIx+xCabWjObthq6wh0OX0=
2020/12/12 06:01:11 purge failed: directory not found
2020/12/12 06:01:11 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-guyoger8lojevos8posivoq0': Purge object "potato2"
2020/12/12 06:01:11 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-guyoger8lojevos8posivoq0': Purge object "potato3"
2020/12/12 06:01:11 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-guyoger8lojevos8posivoq0': Purge dir ""
2020/12/12 06:01:11 INFO  : S3 bucket rclone-test-guyoger8lojevos8posivoq0: Bucket "rclone-test-guyoger8lojevos8posivoq0" deleted
--- FAIL: TestServerSideMoveDeleteEmptySourceDirs (4.28s)
FAIL
2020/12/12 06:01:11 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-valukiy5zifetaz1capazul4': Purge dir ""
2020/12/12 06:01:11 INFO  : S3 bucket rclone-test-valukiy5zifetaz1capazul4: Bucket "rclone-test-valukiy5zifetaz1capazul4" deleted
"./sync.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bMD5QuickS3: -verbose -fast-list -size-limit 1024 -test.run '^(TestServerSideMove|TestServerSideMoveDeleteEmptySourceDirs)$'" - Finished ERROR in 9.587752256s (try 3/5): exit status 1: Failed [TestServerSideMove TestServerSideMoveDeleteEmptySourceDirs]