"./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/27 05:18:05 DEBUG : Creating backend with remote "TestChunkerChunk50bMD5QuickS3:rclone-test-lotuvip3zaxoxep7mebudec9" 2020/12/27 05:18:05 DEBUG : Creating backend with remote "TestS3:rclone-test-lotuvip3zaxoxep7mebudec9" 2020/12/27 05:18:05 DEBUG : Reset feature "ListR" 2020/12/27 05:18:05 DEBUG : Creating backend with remote "/tmp/rclone394657764" === RUN TestServerSideMove run.go:176: Remote "Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-lotuvip3zaxoxep7mebudec9'", Local "Local file system at /tmp/rclone394657764", Modify Window "1ns" 2020/12/27 05:18:05 DEBUG : Creating backend with remote "TestChunkerChunk50bMD5QuickS3:rclone-test-xovefox2filevus6goliyuh6" 2020/12/27 05:18:05 DEBUG : Creating backend with remote "TestS3:rclone-test-xovefox2filevus6goliyuh6" 2020/12/27 05:18:05 DEBUG : Reset feature "ListR" 2020/12/27 05:18:05 INFO : S3 bucket rclone-test-lotuvip3zaxoxep7mebudec9: Bucket "rclone-test-lotuvip3zaxoxep7mebudec9" created with ACL "private" 2020/12/27 05:18:06 DEBUG : potato2.rclone_chunk.001_zl88ig: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2020/12/27 05:18:06 INFO : potato2.rclone_chunk.001_zl88ig: Copied (server-side copy) to: potato2.rclone_chunk.001 2020/12/27 05:18:06 INFO : potato2.rclone_chunk.001_zl88ig: Deleted 2020/12/27 05:18:06 DEBUG : potato2.rclone_chunk.002_zl88ig: MD5 = 01a6651a94ab602dbfc47587d234b52c OK 2020/12/27 05:18:06 INFO : potato2.rclone_chunk.002_zl88ig: Copied (server-side copy) to: potato2.rclone_chunk.002 2020/12/27 05:18:06 INFO : potato2.rclone_chunk.002_zl88ig: Deleted 2020/12/27 05:18:06 DEBUG : empty space.rclone_chunk.001_zl89vn: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK 2020/12/27 05:18:06 INFO : empty space.rclone_chunk.001_zl89vn: Copied (server-side copy) to: empty space 2020/12/27 05:18:06 INFO : empty space.rclone_chunk.001_zl89vn: Deleted 2020/12/27 05:18:06 DEBUG : potato3.rclone_chunk.001_zl896p: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2020/12/27 05:18:06 INFO : potato3.rclone_chunk.001_zl896p: Copied (server-side copy) to: potato3.rclone_chunk.001 2020/12/27 05:18:06 INFO : potato3.rclone_chunk.001_zl896p: Deleted 2020/12/27 05:18:06 DEBUG : potato3.rclone_chunk.002_zl896p: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK 2020/12/27 05:18:06 INFO : potato3.rclone_chunk.002_zl896p: Copied (server-side copy) to: potato3.rclone_chunk.002 2020/12/27 05:18:06 INFO : potato3.rclone_chunk.002_zl896p: Deleted sync_test.go:1294: Server side move (if possible) Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-lotuvip3zaxoxep7mebudec9' -> Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-xovefox2filevus6goliyuh6' 2020/12/27 05:18:07 INFO : S3 bucket rclone-test-xovefox2filevus6goliyuh6: Bucket "rclone-test-xovefox2filevus6goliyuh6" created with ACL "private" 2020/12/27 05:18:07 DEBUG : empty space.rclone_chunk.001_zl8aac: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK 2020/12/27 05:18:07 INFO : empty space.rclone_chunk.001_zl8aac: Copied (server-side copy) to: empty space 2020/12/27 05:18:07 INFO : empty space.rclone_chunk.001_zl8aac: Deleted 2020/12/27 05:18:07 DEBUG : potato3.rclone_chunk.001_zl8anj: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2020/12/27 05:18:07 INFO : potato3.rclone_chunk.001_zl8anj: Copied (server-side copy) to: potato3.rclone_chunk.001 2020/12/27 05:18:07 INFO : potato3.rclone_chunk.001_zl8anj: Deleted 2020/12/27 05:18:08 DEBUG : potato3.rclone_chunk.002_zl8anj: MD5 = 01a6651a94ab602dbfc47587d234b52c OK 2020/12/27 05:18:08 INFO : potato3.rclone_chunk.002_zl8anj: Copied (server-side copy) to: potato3.rclone_chunk.002 2020/12/27 05:18:08 INFO : potato3.rclone_chunk.002_zl8anj: Deleted 2020/12/27 05:18:08 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2020/12/27 05:18:08 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-xovefox2filevus6goliyuh6': Waiting for checks to finish 2020/12/27 05:18:08 DEBUG : potato2: Can't copy - required hash not found 2020/12/27 05:18:08 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns) 2020/12/27 05:18:08 DEBUG : empty space: Unchanged skipping 2020/12/27 05:18:08 DEBUG : potato3: Can't copy - required hash not found 2020/12/27 05:18:08 INFO : empty space: Deleted 2020/12/27 05:18:08 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-xovefox2filevus6goliyuh6': Waiting for transfers to finish 2020/12/27 05:18:08 DEBUG : potato2.rclone_chunk.001_zl8b3i: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2020/12/27 05:18:08 INFO : potato2.rclone_chunk.001_zl8b3i: Copied (server-side copy) to: potato2.rclone_chunk.001 2020/12/27 05:18:08 INFO : potato2.rclone_chunk.001_zl8b3i: Deleted 2020/12/27 05:18:08 DEBUG : potato3.rclone_chunk.001_zl8bp3: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2020/12/27 05:18:08 INFO : potato3.rclone_chunk.001_zl8bp3: Copied (server-side copy) to: potato3.rclone_chunk.001 2020/12/27 05:18:08 DEBUG : potato2.rclone_chunk.002_zl8b3i: MD5 = 01a6651a94ab602dbfc47587d234b52c OK 2020/12/27 05:18:08 INFO : potato2.rclone_chunk.002_zl8b3i: Copied (server-side copy) to: potato2.rclone_chunk.002 2020/12/27 05:18:08 INFO : potato3.rclone_chunk.001_zl8bp3: Deleted 2020/12/27 05:18:08 INFO : potato2.rclone_chunk.002_zl8b3i: Deleted 2020/12/27 05:18:08 INFO : potato2: Copied (new) 2020/12/27 05:18:08 DEBUG : potato3.rclone_chunk.002_zl8bp3: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK 2020/12/27 05:18:08 INFO : potato3.rclone_chunk.002_zl8bp3: Copied (server-side copy) to: potato3.rclone_chunk.002 2020/12/27 05:18:08 INFO : potato3.rclone_chunk.002_zl8bp3: Deleted 2020/12/27 05:18:08 INFO : potato3: Copied (replaced existing) 2020/12/27 05:18:08 INFO : potato2: Deleted 2020/12/27 05:18:08 INFO : potato3: Deleted 2020/12/27 05:18:08 DEBUG : Creating backend with remote "TestChunkerChunk50bMD5QuickS3:rclone-test-quqifih4bopoher9gocufit5" 2020/12/27 05:18:08 DEBUG : Creating backend with remote "TestS3:rclone-test-quqifih4bopoher9gocufit5" 2020/12/27 05:18:08 DEBUG : Reset feature "ListR" 2020/12/27 05:18:08 DEBUG : empty space: copy non-chunked object... 2020/12/27 05:18:08 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-quqifih4bopoher9gocufit5': Waiting for checks to finish 2020/12/27 05:18:08 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-quqifih4bopoher9gocufit5': Waiting for transfers to finish 2020/12/27 05:18:08 DEBUG : potato2: Can't copy - required hash not found 2020/12/27 05:18:08 DEBUG : potato3: Can't copy - required hash not found 2020/12/27 05:18:09 INFO : S3 bucket rclone-test-quqifih4bopoher9gocufit5: Bucket "rclone-test-quqifih4bopoher9gocufit5" created with ACL "private" 2020/12/27 05:18:09 INFO : empty space: Copied (server-side copy) 2020/12/27 05:18:09 INFO : empty space: Deleted 2020/12/27 05:18:09 ERROR : potato2: Failed to copy: object not found 2020/12/27 05:18:09 ERROR : potato2: Not deleting source as copy failed: object not found 2020/12/27 05:18:09 ERROR : potato3: Failed to copy: object not found 2020/12/27 05:18:09 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/27 05:18:09 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-quqifih4bopoher9gocufit5': Purge object "empty space" 2020/12/27 05:18:09 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-quqifih4bopoher9gocufit5': Purge dir "" 2020/12/27 05:18:09 purge failed to rmdir "": BucketNotEmpty: The bucket you tried to delete is not empty status code: 409, request id: 17697E1F04BEBEC8, host id: I+pz28sl9FMQi6Xt2B7M9SQDrgGGHpqkQBWL0MwAE5E9WTWii0FG3oQEpvGly1UPl2PaXq9uYro= 2020/12/27 05:18:09 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-xovefox2filevus6goliyuh6': Purge object "potato2" 2020/12/27 05:18:09 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-xovefox2filevus6goliyuh6': Purge object "potato3" 2020/12/27 05:18:09 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-xovefox2filevus6goliyuh6': Purge dir "" 2020/12/27 05:18:10 INFO : S3 bucket rclone-test-xovefox2filevus6goliyuh6: Bucket "rclone-test-xovefox2filevus6goliyuh6" deleted --- FAIL: TestServerSideMove (4.96s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:176: Remote "Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-lotuvip3zaxoxep7mebudec9'", Local "Local file system at /tmp/rclone394657764", Modify Window "1ns" 2020/12/27 05:18:10 DEBUG : Creating backend with remote "TestChunkerChunk50bMD5QuickS3:rclone-test-wesatax2magimog2lususih1" 2020/12/27 05:18:10 DEBUG : Creating backend with remote "TestS3:rclone-test-wesatax2magimog2lususih1" 2020/12/27 05:18:10 DEBUG : Reset feature "ListR" 2020/12/27 05:18:10 DEBUG : potato2.rclone_chunk.001_zl8dye: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2020/12/27 05:18:10 INFO : potato2.rclone_chunk.001_zl8dye: Copied (server-side copy) to: potato2.rclone_chunk.001 2020/12/27 05:18:10 INFO : potato2.rclone_chunk.001_zl8dye: Deleted 2020/12/27 05:18:10 DEBUG : potato2.rclone_chunk.002_zl8dye: MD5 = 01a6651a94ab602dbfc47587d234b52c OK 2020/12/27 05:18:10 INFO : potato2.rclone_chunk.002_zl8dye: Copied (server-side copy) to: potato2.rclone_chunk.002 2020/12/27 05:18:10 INFO : potato2.rclone_chunk.002_zl8dye: Deleted 2020/12/27 05:18:10 DEBUG : empty space.rclone_chunk.001_zl8d7m: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK 2020/12/27 05:18:10 INFO : empty space.rclone_chunk.001_zl8d7m: Copied (server-side copy) to: empty space 2020/12/27 05:18:10 INFO : empty space.rclone_chunk.001_zl8d7m: Deleted 2020/12/27 05:18:10 DEBUG : potato3.rclone_chunk.001_zl8d60: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2020/12/27 05:18:10 INFO : potato3.rclone_chunk.001_zl8d60: Copied (server-side copy) to: potato3.rclone_chunk.001 2020/12/27 05:18:10 INFO : potato3.rclone_chunk.001_zl8d60: Deleted 2020/12/27 05:18:10 DEBUG : potato3.rclone_chunk.002_zl8d60: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK 2020/12/27 05:18:10 INFO : potato3.rclone_chunk.002_zl8d60: Copied (server-side copy) to: potato3.rclone_chunk.002 2020/12/27 05:18:10 INFO : potato3.rclone_chunk.002_zl8d60: Deleted 2020/12/27 05:18:11 DEBUG : tomatoDir: Making directory sync_test.go:1294: Server side move (if possible) Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-lotuvip3zaxoxep7mebudec9' -> Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-wesatax2magimog2lususih1' 2020/12/27 05:18:11 INFO : S3 bucket rclone-test-wesatax2magimog2lususih1: Bucket "rclone-test-wesatax2magimog2lususih1" created with ACL "private" 2020/12/27 05:18:11 DEBUG : empty space.rclone_chunk.001_zl8ezo: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK 2020/12/27 05:18:11 INFO : empty space.rclone_chunk.001_zl8ezo: Copied (server-side copy) to: empty space 2020/12/27 05:18:11 INFO : empty space.rclone_chunk.001_zl8ezo: Deleted 2020/12/27 05:18:12 DEBUG : potato3.rclone_chunk.001_zl8eqo: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2020/12/27 05:18:12 INFO : potato3.rclone_chunk.001_zl8eqo: Copied (server-side copy) to: potato3.rclone_chunk.001 2020/12/27 05:18:12 INFO : potato3.rclone_chunk.001_zl8eqo: Deleted 2020/12/27 05:18:12 DEBUG : potato3.rclone_chunk.002_zl8eqo: MD5 = 01a6651a94ab602dbfc47587d234b52c OK 2020/12/27 05:18:12 INFO : potato3.rclone_chunk.002_zl8eqo: Copied (server-side copy) to: potato3.rclone_chunk.002 2020/12/27 05:18:12 INFO : potato3.rclone_chunk.002_zl8eqo: Deleted 2020/12/27 05:18:12 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2020/12/27 05:18:12 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-wesatax2magimog2lususih1': Waiting for checks to finish 2020/12/27 05:18:12 DEBUG : potato2: Can't copy - required hash not found 2020/12/27 05:18:12 DEBUG : potato3: Can't copy - required hash not found 2020/12/27 05:18:12 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns) 2020/12/27 05:18:12 DEBUG : empty space: Unchanged skipping 2020/12/27 05:18:12 INFO : empty space: Deleted 2020/12/27 05:18:12 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-wesatax2magimog2lususih1': Waiting for transfers to finish 2020/12/27 05:18:12 DEBUG : potato2.rclone_chunk.001_zl8f6y: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2020/12/27 05:18:12 INFO : potato2.rclone_chunk.001_zl8f6y: Copied (server-side copy) to: potato2.rclone_chunk.001 2020/12/27 05:18:12 INFO : potato2.rclone_chunk.001_zl8f6y: Deleted 2020/12/27 05:18:12 DEBUG : potato3.rclone_chunk.001_zl8fa6: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2020/12/27 05:18:12 INFO : potato3.rclone_chunk.001_zl8fa6: Copied (server-side copy) to: potato3.rclone_chunk.001 2020/12/27 05:18:12 DEBUG : potato2.rclone_chunk.002_zl8f6y: MD5 = 01a6651a94ab602dbfc47587d234b52c OK 2020/12/27 05:18:12 INFO : potato2.rclone_chunk.002_zl8f6y: Copied (server-side copy) to: potato2.rclone_chunk.002 2020/12/27 05:18:12 INFO : potato3.rclone_chunk.001_zl8fa6: Deleted 2020/12/27 05:18:12 INFO : potato2.rclone_chunk.002_zl8f6y: Deleted 2020/12/27 05:18:12 DEBUG : potato3.rclone_chunk.002_zl8fa6: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK 2020/12/27 05:18:12 INFO : potato3.rclone_chunk.002_zl8fa6: Copied (server-side copy) to: potato3.rclone_chunk.002 2020/12/27 05:18:12 INFO : potato2: Copied (new) 2020/12/27 05:18:12 INFO : potato3.rclone_chunk.002_zl8fa6: Deleted 2020/12/27 05:18:12 INFO : potato3: Copied (replaced existing) 2020/12/27 05:18:12 INFO : potato2: Deleted 2020/12/27 05:18:12 INFO : potato3: Deleted 2020/12/27 05:18:13 DEBUG : Creating backend with remote "TestChunkerChunk50bMD5QuickS3:rclone-test-qoreteb4polokag0wihosoq9" 2020/12/27 05:18:13 DEBUG : Creating backend with remote "TestS3:rclone-test-qoreteb4polokag0wihosoq9" 2020/12/27 05:18:13 DEBUG : Reset feature "ListR" 2020/12/27 05:18:13 DEBUG : tomatoDir: Making directory 2020/12/27 05:18:13 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-qoreteb4polokag0wihosoq9': Waiting for checks to finish 2020/12/27 05:18:13 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-qoreteb4polokag0wihosoq9': Waiting for transfers to finish 2020/12/27 05:18:13 DEBUG : empty space: copy non-chunked object... 2020/12/27 05:18:13 DEBUG : potato2: Can't copy - required hash not found 2020/12/27 05:18:13 DEBUG : potato3: Can't copy - required hash not found 2020/12/27 05:18:13 INFO : S3 bucket rclone-test-qoreteb4polokag0wihosoq9: Bucket "rclone-test-qoreteb4polokag0wihosoq9" created with ACL "private" 2020/12/27 05:18:13 INFO : empty space: Copied (server-side copy) 2020/12/27 05:18:13 INFO : empty space: Deleted 2020/12/27 05:18:13 DEBUG : potato3.rclone_chunk.001_zl8gxb: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2020/12/27 05:18:13 INFO : potato3.rclone_chunk.001_zl8gxb: Copied (server-side copy) to: potato3.rclone_chunk.001 2020/12/27 05:18:13 DEBUG : potato2.rclone_chunk.001_zl8g52: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK 2020/12/27 05:18:13 INFO : potato2.rclone_chunk.001_zl8g52: Copied (server-side copy) to: potato2.rclone_chunk.001 2020/12/27 05:18:13 INFO : potato3.rclone_chunk.001_zl8gxb: Deleted 2020/12/27 05:18:13 INFO : potato2.rclone_chunk.001_zl8g52: Deleted 2020/12/27 05:18:13 DEBUG : potato3.rclone_chunk.002_zl8gxb: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK 2020/12/27 05:18:13 INFO : potato3.rclone_chunk.002_zl8gxb: Copied (server-side copy) to: potato3.rclone_chunk.002 2020/12/27 05:18:13 DEBUG : potato2.rclone_chunk.002_zl8g52: MD5 = 01a6651a94ab602dbfc47587d234b52c OK 2020/12/27 05:18:13 INFO : potato2.rclone_chunk.002_zl8g52: Copied (server-side copy) to: potato2.rclone_chunk.002 2020/12/27 05:18:13 INFO : potato3.rclone_chunk.002_zl8gxb: Deleted 2020/12/27 05:18:13 INFO : potato2.rclone_chunk.002_zl8g52: Deleted 2020/12/27 05:18:14 INFO : potato3: Copied (new) 2020/12/27 05:18:14 INFO : potato2: Copied (new) 2020/12/27 05:18:14 INFO : potato3: Deleted 2020/12/27 05:18:14 INFO : potato2: Deleted 2020/12/27 05:18:14 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-qoreteb4polokag0wihosoq9': Purge object "empty space" 2020/12/27 05:18:14 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-qoreteb4polokag0wihosoq9': Purge object "potato2" 2020/12/27 05:18:14 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-qoreteb4polokag0wihosoq9': Purge object "potato3" 2020/12/27 05:18:14 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-qoreteb4polokag0wihosoq9': Purge dir "" 2020/12/27 05:18:14 INFO : S3 bucket rclone-test-qoreteb4polokag0wihosoq9: Bucket "rclone-test-qoreteb4polokag0wihosoq9" deleted 2020/12/27 05:18:14 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-wesatax2magimog2lususih1': Purge dir "" 2020/12/27 05:18:14 INFO : S3 bucket rclone-test-wesatax2magimog2lususih1: Bucket "rclone-test-wesatax2magimog2lususih1" deleted --- PASS: TestServerSideMoveDeleteEmptySourceDirs (4.79s) FAIL 2020/12/27 05:18:15 DEBUG : Chunked 'TestChunkerChunk50bMD5QuickS3:rclone-test-lotuvip3zaxoxep7mebudec9': Purge dir "" 2020/12/27 05:18:15 INFO : S3 bucket rclone-test-lotuvip3zaxoxep7mebudec9: Bucket "rclone-test-lotuvip3zaxoxep7mebudec9" deleted "./sync.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bMD5QuickS3: -verbose -fast-list -size-limit 1024 -test.run '^(TestServerSideMove|TestServerSideMoveDeleteEmptySourceDirs)$'" - Finished ERROR in 10.0289013s (try 3/5): exit status 1: Failed [TestServerSideMove]