"./sync.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bSHA1QuickS3: -verbose -size-limit 1024 -test.run '^(TestServerSideMove|TestServerSideMoveDeleteEmptySourceDirs)$'" - Starting (try 2/5) 2021/02/08 05:49:53 DEBUG : Creating backend with remote "TestChunkerChunk50bSHA1QuickS3:rclone-test-quqorom5pikutuh1muvefas1" 2021/02/08 05:49:53 DEBUG : Creating backend with remote "TestS3:rclone-test-quqorom5pikutuh1muvefas1" 2021/02/08 05:49:53 DEBUG : Reset feature "ListR" 2021/02/08 05:49:53 DEBUG : Creating backend with remote "/tmp/rclone556148213" === RUN TestServerSideMove run.go:176: Remote "Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-quqorom5pikutuh1muvefas1'", Local "Local file system at /tmp/rclone556148213", Modify Window "1ns" 2021/02/08 05:49:53 DEBUG : Creating backend with remote "TestChunkerChunk50bSHA1QuickS3:rclone-test-jucohib9dafudiz0kowelej0" 2021/02/08 05:49:53 DEBUG : Creating backend with remote "TestS3:rclone-test-jucohib9dafudiz0kowelej0" 2021/02/08 05:49:53 DEBUG : Reset feature "ListR" 2021/02/08 05:49:53 INFO : S3 bucket rclone-test-quqorom5pikutuh1muvefas1: Bucket "rclone-test-quqorom5pikutuh1muvefas1" created with ACL "private" 2021/02/08 05:49:54 DEBUG : potato2.rclone_chunk.001_79dto6: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:49:54 INFO : potato2.rclone_chunk.001_79dto6: Copied (server-side copy) to: potato2.rclone_chunk.001 2021/02/08 05:49:54 INFO : potato2.rclone_chunk.001_79dto6: Deleted 2021/02/08 05:49:54 DEBUG : potato2.rclone_chunk.002_79dto6: MD5 = 01a6651a94ab602dbfc47587d234b52c OK 2021/02/08 05:49:54 INFO : potato2.rclone_chunk.002_79dto6: Copied (server-side copy) to: potato2.rclone_chunk.002 2021/02/08 05:49:54 INFO : potato2.rclone_chunk.002_79dto6: Deleted 2021/02/08 05:49:54 DEBUG : empty space.rclone_chunk.001_79dupr: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK 2021/02/08 05:49:54 INFO : empty space.rclone_chunk.001_79dupr: Copied (server-side copy) to: empty space 2021/02/08 05:49:54 INFO : empty space.rclone_chunk.001_79dupr: Deleted 2021/02/08 05:49:54 DEBUG : potato3.rclone_chunk.001_79duvf: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:49:54 INFO : potato3.rclone_chunk.001_79duvf: Copied (server-side copy) to: potato3.rclone_chunk.001 2021/02/08 05:49:54 INFO : potato3.rclone_chunk.001_79duvf: Deleted 2021/02/08 05:49:54 DEBUG : potato3.rclone_chunk.002_79duvf: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK 2021/02/08 05:49:54 INFO : potato3.rclone_chunk.002_79duvf: Copied (server-side copy) to: potato3.rclone_chunk.002 2021/02/08 05:49:54 INFO : potato3.rclone_chunk.002_79duvf: Deleted sync_test.go:1294: Server side move (if possible) Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-quqorom5pikutuh1muvefas1' -> Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-jucohib9dafudiz0kowelej0' 2021/02/08 05:49:55 INFO : S3 bucket rclone-test-jucohib9dafudiz0kowelej0: Bucket "rclone-test-jucohib9dafudiz0kowelej0" created with ACL "private" 2021/02/08 05:49:55 DEBUG : empty space.rclone_chunk.001_79dvvq: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK 2021/02/08 05:49:55 INFO : empty space.rclone_chunk.001_79dvvq: Copied (server-side copy) to: empty space 2021/02/08 05:49:55 INFO : empty space.rclone_chunk.001_79dvvq: Deleted 2021/02/08 05:49:55 DEBUG : potato3.rclone_chunk.001_79dvo7: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:49:55 INFO : potato3.rclone_chunk.001_79dvo7: Copied (server-side copy) to: potato3.rclone_chunk.001 2021/02/08 05:49:55 INFO : potato3.rclone_chunk.001_79dvo7: Deleted 2021/02/08 05:49:56 DEBUG : potato3.rclone_chunk.002_79dvo7: MD5 = 01a6651a94ab602dbfc47587d234b52c OK 2021/02/08 05:49:56 INFO : potato3.rclone_chunk.002_79dvo7: Copied (server-side copy) to: potato3.rclone_chunk.002 2021/02/08 05:49:56 INFO : potato3.rclone_chunk.002_79dvo7: Deleted 2021/02/08 05:49:56 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-jucohib9dafudiz0kowelej0': Waiting for checks to finish 2021/02/08 05:49:56 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2021/02/08 05:49:56 DEBUG : potato2: Can't copy - required hash not found 2021/02/08 05:49:56 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns) 2021/02/08 05:49:56 DEBUG : empty space: Unchanged skipping 2021/02/08 05:49:56 DEBUG : potato3: Can't copy - required hash not found 2021/02/08 05:49:56 INFO : empty space: Deleted 2021/02/08 05:49:56 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-jucohib9dafudiz0kowelej0': Waiting for transfers to finish 2021/02/08 05:49:56 DEBUG : potato2.rclone_chunk.001_79dwtp: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:49:56 INFO : potato2.rclone_chunk.001_79dwtp: Copied (server-side copy) to: potato2.rclone_chunk.001 2021/02/08 05:49:56 INFO : potato2.rclone_chunk.001_79dwtp: Deleted 2021/02/08 05:49:56 DEBUG : potato3.rclone_chunk.001_79dwu6: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:49:56 INFO : potato3.rclone_chunk.001_79dwu6: Copied (server-side copy) to: potato3.rclone_chunk.001 2021/02/08 05:49:56 DEBUG : potato2.rclone_chunk.002_79dwtp: MD5 = 01a6651a94ab602dbfc47587d234b52c OK 2021/02/08 05:49:56 INFO : potato2.rclone_chunk.002_79dwtp: Copied (server-side copy) to: potato2.rclone_chunk.002 2021/02/08 05:49:56 INFO : potato3.rclone_chunk.001_79dwu6: Deleted 2021/02/08 05:49:56 INFO : potato2.rclone_chunk.002_79dwtp: Deleted 2021/02/08 05:49:56 DEBUG : potato3.rclone_chunk.002_79dwu6: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK 2021/02/08 05:49:56 INFO : potato3.rclone_chunk.002_79dwu6: Copied (server-side copy) to: potato3.rclone_chunk.002 2021/02/08 05:49:56 INFO : potato2: Copied (new) 2021/02/08 05:49:56 INFO : potato3.rclone_chunk.002_79dwu6: Deleted 2021/02/08 05:49:56 INFO : potato3: Copied (replaced existing) 2021/02/08 05:49:56 INFO : potato2: Deleted 2021/02/08 05:49:56 INFO : potato3: Deleted 2021/02/08 05:49:56 DEBUG : Creating backend with remote "TestChunkerChunk50bSHA1QuickS3:rclone-test-situfeh6lekixuq7heqatig2" 2021/02/08 05:49:56 DEBUG : Creating backend with remote "TestS3:rclone-test-situfeh6lekixuq7heqatig2" 2021/02/08 05:49:56 DEBUG : Reset feature "ListR" 2021/02/08 05:49:56 DEBUG : empty space: copy non-chunked object... 2021/02/08 05:49:56 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-situfeh6lekixuq7heqatig2': Waiting for checks to finish 2021/02/08 05:49:56 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-situfeh6lekixuq7heqatig2': Waiting for transfers to finish 2021/02/08 05:49:56 DEBUG : potato3: Can't copy - required hash not found 2021/02/08 05:49:56 DEBUG : potato2: Can't copy - required hash not found 2021/02/08 05:49:57 INFO : S3 bucket rclone-test-situfeh6lekixuq7heqatig2: Bucket "rclone-test-situfeh6lekixuq7heqatig2" created with ACL "private" 2021/02/08 05:49:57 INFO : empty space: Copied (server-side copy) 2021/02/08 05:49:57 INFO : empty space: Deleted 2021/02/08 05:49:57 ERROR : potato2: Failed to copy: object not found 2021/02/08 05:49:57 ERROR : potato2: Not deleting source as copy failed: object not found 2021/02/08 05:49:57 ERROR : potato3: Failed to copy: object not found 2021/02/08 05:49:57 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 2021/02/08 05:49:57 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-situfeh6lekixuq7heqatig2': Purge object "empty space" 2021/02/08 05:49:57 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-situfeh6lekixuq7heqatig2': Purge dir "" 2021/02/08 05:49:57 purge failed to rmdir "": BucketNotEmpty: The bucket you tried to delete is not empty status code: 409, request id: 1D37487AF2C3210F, host id: nIyurPzTcY6UO/6BlZergWvzUm3sgGc4StJ5FqQCdfHPuQLyxo5BnoyW5WfGcRjTTBSMudOscBc= 2021/02/08 05:49:57 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-jucohib9dafudiz0kowelej0': Purge object "potato2" 2021/02/08 05:49:57 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-jucohib9dafudiz0kowelej0': Purge object "potato3" 2021/02/08 05:49:58 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-jucohib9dafudiz0kowelej0': Purge dir "" 2021/02/08 05:49:58 INFO : S3 bucket rclone-test-jucohib9dafudiz0kowelej0: Bucket "rclone-test-jucohib9dafudiz0kowelej0" deleted --- FAIL: TestServerSideMove (5.26s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:176: Remote "Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-quqorom5pikutuh1muvefas1'", Local "Local file system at /tmp/rclone556148213", Modify Window "1ns" 2021/02/08 05:49:58 DEBUG : Creating backend with remote "TestChunkerChunk50bSHA1QuickS3:rclone-test-dohoyis9yayikup1buzohot9" 2021/02/08 05:49:58 DEBUG : Creating backend with remote "TestS3:rclone-test-dohoyis9yayikup1buzohot9" 2021/02/08 05:49:58 DEBUG : Reset feature "ListR" 2021/02/08 05:49:58 DEBUG : potato2.rclone_chunk.001_79dyus: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:49:58 INFO : potato2.rclone_chunk.001_79dyus: Copied (server-side copy) to: potato2.rclone_chunk.001 2021/02/08 05:49:58 INFO : potato2.rclone_chunk.001_79dyus: Deleted 2021/02/08 05:49:58 DEBUG : potato2.rclone_chunk.002_79dyus: MD5 = 01a6651a94ab602dbfc47587d234b52c OK 2021/02/08 05:49:58 INFO : potato2.rclone_chunk.002_79dyus: Copied (server-side copy) to: potato2.rclone_chunk.002 2021/02/08 05:49:58 INFO : potato2.rclone_chunk.002_79dyus: Deleted 2021/02/08 05:49:58 DEBUG : empty space.rclone_chunk.001_79dyyt: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK 2021/02/08 05:49:58 INFO : empty space.rclone_chunk.001_79dyyt: Copied (server-side copy) to: empty space 2021/02/08 05:49:58 INFO : empty space.rclone_chunk.001_79dyyt: Deleted 2021/02/08 05:49:59 DEBUG : potato3.rclone_chunk.001_79dy05: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:49:59 INFO : potato3.rclone_chunk.001_79dy05: Copied (server-side copy) to: potato3.rclone_chunk.001 2021/02/08 05:49:59 INFO : potato3.rclone_chunk.001_79dy05: Deleted 2021/02/08 05:49:59 DEBUG : potato3.rclone_chunk.002_79dy05: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK 2021/02/08 05:49:59 INFO : potato3.rclone_chunk.002_79dy05: Copied (server-side copy) to: potato3.rclone_chunk.002 2021/02/08 05:49:59 INFO : potato3.rclone_chunk.002_79dy05: Deleted 2021/02/08 05:49:59 DEBUG : tomatoDir: Making directory sync_test.go:1294: Server side move (if possible) Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-quqorom5pikutuh1muvefas1' -> Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-dohoyis9yayikup1buzohot9' 2021/02/08 05:49:59 INFO : S3 bucket rclone-test-dohoyis9yayikup1buzohot9: Bucket "rclone-test-dohoyis9yayikup1buzohot9" created with ACL "private" 2021/02/08 05:50:00 DEBUG : empty space.rclone_chunk.001_79e06t: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK 2021/02/08 05:50:00 INFO : empty space.rclone_chunk.001_79e06t: Copied (server-side copy) to: empty space 2021/02/08 05:50:00 INFO : empty space.rclone_chunk.001_79e06t: Deleted 2021/02/08 05:50:00 DEBUG : potato3.rclone_chunk.001_79e0r9: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:50:00 INFO : potato3.rclone_chunk.001_79e0r9: Copied (server-side copy) to: potato3.rclone_chunk.001 2021/02/08 05:50:00 INFO : potato3.rclone_chunk.001_79e0r9: Deleted 2021/02/08 05:50:00 DEBUG : potato3.rclone_chunk.002_79e0r9: MD5 = 01a6651a94ab602dbfc47587d234b52c OK 2021/02/08 05:50:00 INFO : potato3.rclone_chunk.002_79e0r9: Copied (server-side copy) to: potato3.rclone_chunk.002 2021/02/08 05:50:00 INFO : potato3.rclone_chunk.002_79e0r9: Deleted 2021/02/08 05:50:00 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2021/02/08 05:50:00 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-dohoyis9yayikup1buzohot9': Waiting for checks to finish 2021/02/08 05:50:00 DEBUG : potato2: Can't copy - required hash not found 2021/02/08 05:50:00 DEBUG : potato3: Can't copy - required hash not found 2021/02/08 05:50:00 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns) 2021/02/08 05:50:00 DEBUG : empty space: Unchanged skipping 2021/02/08 05:50:00 INFO : empty space: Deleted 2021/02/08 05:50:00 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-dohoyis9yayikup1buzohot9': Waiting for transfers to finish 2021/02/08 05:50:01 DEBUG : potato2.rclone_chunk.001_79e0xj: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:50:01 INFO : potato2.rclone_chunk.001_79e0xj: Copied (server-side copy) to: potato2.rclone_chunk.001 2021/02/08 05:50:01 INFO : potato2.rclone_chunk.001_79e0xj: Deleted 2021/02/08 05:50:01 DEBUG : potato2.rclone_chunk.002_79e0xj: MD5 = 01a6651a94ab602dbfc47587d234b52c OK 2021/02/08 05:50:01 INFO : potato2.rclone_chunk.002_79e0xj: Copied (server-side copy) to: potato2.rclone_chunk.002 2021/02/08 05:50:01 DEBUG : potato3.rclone_chunk.001_79e035: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:50:01 INFO : potato3.rclone_chunk.001_79e035: Copied (server-side copy) to: potato3.rclone_chunk.001 2021/02/08 05:50:01 INFO : potato2.rclone_chunk.002_79e0xj: Deleted 2021/02/08 05:50:01 INFO : potato3.rclone_chunk.001_79e035: Deleted 2021/02/08 05:50:01 INFO : potato2: Copied (new) 2021/02/08 05:50:01 DEBUG : potato3.rclone_chunk.002_79e035: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK 2021/02/08 05:50:01 INFO : potato3.rclone_chunk.002_79e035: Copied (server-side copy) to: potato3.rclone_chunk.002 2021/02/08 05:50:01 INFO : potato3.rclone_chunk.002_79e035: Deleted 2021/02/08 05:50:01 INFO : potato2: Deleted 2021/02/08 05:50:01 INFO : potato3: Copied (replaced existing) 2021/02/08 05:50:01 INFO : potato3: Deleted 2021/02/08 05:50:01 DEBUG : Creating backend with remote "TestChunkerChunk50bSHA1QuickS3:rclone-test-ciwifut5lujuxiy0yegaqut4" 2021/02/08 05:50:01 DEBUG : Creating backend with remote "TestS3:rclone-test-ciwifut5lujuxiy0yegaqut4" 2021/02/08 05:50:01 DEBUG : Reset feature "ListR" 2021/02/08 05:50:01 DEBUG : tomatoDir: Making directory 2021/02/08 05:50:01 DEBUG : empty space: copy non-chunked object... 2021/02/08 05:50:01 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-ciwifut5lujuxiy0yegaqut4': Waiting for checks to finish 2021/02/08 05:50:01 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-ciwifut5lujuxiy0yegaqut4': Waiting for transfers to finish 2021/02/08 05:50:01 DEBUG : potato3: Can't copy - required hash not found 2021/02/08 05:50:01 DEBUG : potato2: Can't copy - required hash not found 2021/02/08 05:50:02 INFO : S3 bucket rclone-test-ciwifut5lujuxiy0yegaqut4: Bucket "rclone-test-ciwifut5lujuxiy0yegaqut4" created with ACL "private" 2021/02/08 05:50:02 ERROR : potato2: Failed to copy: object not found 2021/02/08 05:50:02 ERROR : potato2: Not deleting source as copy failed: object not found 2021/02/08 05:50:02 INFO : empty space: Copied (server-side copy) 2021/02/08 05:50:02 INFO : empty space: Deleted 2021/02/08 05:50:02 DEBUG : potato3.rclone_chunk.001_79e1mf: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2021/02/08 05:50:02 INFO : potato3.rclone_chunk.001_79e1mf: Copied (server-side copy) to: potato3.rclone_chunk.001 2021/02/08 05:50:02 INFO : potato3.rclone_chunk.001_79e1mf: Deleted 2021/02/08 05:50:02 DEBUG : potato3.rclone_chunk.002_79e1mf: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK 2021/02/08 05:50:02 INFO : potato3.rclone_chunk.002_79e1mf: Copied (server-side copy) to: potato3.rclone_chunk.002 2021/02/08 05:50:02 INFO : potato3.rclone_chunk.002_79e1mf: Deleted 2021/02/08 05:50:02 INFO : potato3: Copied (new) 2021/02/08 05:50:03 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 2021/02/08 05:50:03 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-ciwifut5lujuxiy0yegaqut4': Purge object "empty space" 2021/02/08 05:50:03 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-ciwifut5lujuxiy0yegaqut4': Purge object "potato3" 2021/02/08 05:50:03 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-ciwifut5lujuxiy0yegaqut4': Purge dir "" 2021/02/08 05:50:03 purge failed to rmdir "": BucketNotEmpty: The bucket you tried to delete is not empty status code: 409, request id: EFA235C2EF7049CB, host id: KEoebDpx5kyxN3dKp6dysjiuvmIVbPb2pRzDkDHQQ7eSiDsSz0+2g5YhEUgqte6woKtd9zhXWzo= 2021/02/08 05:50:03 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-dohoyis9yayikup1buzohot9': Purge object "potato2" 2021/02/08 05:50:03 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-dohoyis9yayikup1buzohot9': Purge dir "" 2021/02/08 05:50:03 INFO : S3 bucket rclone-test-dohoyis9yayikup1buzohot9: Bucket "rclone-test-dohoyis9yayikup1buzohot9" deleted --- FAIL: TestServerSideMoveDeleteEmptySourceDirs (5.24s) FAIL 2021/02/08 05:50:03 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-quqorom5pikutuh1muvefas1': Purge dir "" 2021/02/08 05:50:03 INFO : S3 bucket rclone-test-quqorom5pikutuh1muvefas1: Bucket "rclone-test-quqorom5pikutuh1muvefas1" deleted "./sync.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bSHA1QuickS3: -verbose -size-limit 1024 -test.run '^(TestServerSideMove|TestServerSideMoveDeleteEmptySourceDirs)$'" - Finished ERROR in 10.820430757s (try 2/5): exit status 1: Failed [TestServerSideMove TestServerSideMoveDeleteEmptySourceDirs]