"./sync.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bSHA1QuickS3: -verbose -size-limit 1024 -test.run '^TestServerSideMove$'" - Starting (try 4/5)
2020/12/12 05:31:57 DEBUG : Creating backend with remote "TestChunkerChunk50bSHA1QuickS3:rclone-test-gepicoz0baroquw3lafazuh7"
2020/12/12 05:31:57 DEBUG : Creating backend with remote "TestS3:rclone-test-gepicoz0baroquw3lafazuh7"
2020/12/12 05:31:57 DEBUG : Reset feature "ListR"
2020/12/12 05:31:57 DEBUG : Creating backend with remote "/tmp/rclone405051099"
=== RUN   TestServerSideMove
    run.go:176: Remote "Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-gepicoz0baroquw3lafazuh7'", Local "Local file system at /tmp/rclone405051099", Modify Window "1ns"
2020/12/12 05:31:57 DEBUG : Creating backend with remote "TestChunkerChunk50bSHA1QuickS3:rclone-test-wosikah7gujecir1rabogul2"
2020/12/12 05:31:57 DEBUG : Creating backend with remote "TestS3:rclone-test-wosikah7gujecir1rabogul2"
2020/12/12 05:31:57 DEBUG : Reset feature "ListR"
2020/12/12 05:31:57 INFO  : S3 bucket rclone-test-gepicoz0baroquw3lafazuh7: Bucket "rclone-test-gepicoz0baroquw3lafazuh7" created with ACL "private"
2020/12/12 05:31:57 DEBUG : potato2.rclone_chunk.001_7tvcls: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 05:31:57 INFO  : potato2.rclone_chunk.001_7tvcls: Copied (server-side copy) to: potato2.rclone_chunk.001
2020/12/12 05:31:57 INFO  : potato2.rclone_chunk.001_7tvcls: Deleted
2020/12/12 05:31:58 DEBUG : potato2.rclone_chunk.002_7tvcls: MD5 = 01a6651a94ab602dbfc47587d234b52c OK
2020/12/12 05:31:58 INFO  : potato2.rclone_chunk.002_7tvcls: Copied (server-side copy) to: potato2.rclone_chunk.002
2020/12/12 05:31:58 INFO  : potato2.rclone_chunk.002_7tvcls: Deleted
2020/12/12 05:31:58 DEBUG : empty space.rclone_chunk.001_7tvd7t: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK
2020/12/12 05:31:58 INFO  : empty space.rclone_chunk.001_7tvd7t: Copied (server-side copy) to: empty space
2020/12/12 05:31:58 INFO  : empty space.rclone_chunk.001_7tvd7t: Deleted
2020/12/12 05:31:58 DEBUG : potato3.rclone_chunk.001_7tvd0t: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 05:31:58 INFO  : potato3.rclone_chunk.001_7tvd0t: Copied (server-side copy) to: potato3.rclone_chunk.001
2020/12/12 05:31:58 INFO  : potato3.rclone_chunk.001_7tvd0t: Deleted
2020/12/12 05:31:58 DEBUG : potato3.rclone_chunk.002_7tvd0t: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK
2020/12/12 05:31:58 INFO  : potato3.rclone_chunk.002_7tvd0t: Copied (server-side copy) to: potato3.rclone_chunk.002
2020/12/12 05:31:58 INFO  : potato3.rclone_chunk.002_7tvd0t: Deleted
    sync_test.go:1294: Server side move (if possible) Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-gepicoz0baroquw3lafazuh7' -> Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-wosikah7gujecir1rabogul2'
2020/12/12 05:31:59 INFO  : S3 bucket rclone-test-wosikah7gujecir1rabogul2: Bucket "rclone-test-wosikah7gujecir1rabogul2" created with ACL "private"
2020/12/12 05:31:59 DEBUG : empty space.rclone_chunk.001_7tveob: MD5 = 336d5ebc5436534e61d16e63ddfca327 OK
2020/12/12 05:31:59 INFO  : empty space.rclone_chunk.001_7tveob: Copied (server-side copy) to: empty space
2020/12/12 05:31:59 INFO  : empty space.rclone_chunk.001_7tveob: Deleted
2020/12/12 05:31:59 DEBUG : potato3.rclone_chunk.001_7tvesi: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 05:31:59 INFO  : potato3.rclone_chunk.001_7tvesi: Copied (server-side copy) to: potato3.rclone_chunk.001
2020/12/12 05:31:59 INFO  : potato3.rclone_chunk.001_7tvesi: Deleted
2020/12/12 05:31:59 DEBUG : potato3.rclone_chunk.002_7tvesi: MD5 = 01a6651a94ab602dbfc47587d234b52c OK
2020/12/12 05:31:59 INFO  : potato3.rclone_chunk.002_7tvesi: Copied (server-side copy) to: potato3.rclone_chunk.002
2020/12/12 05:31:59 INFO  : potato3.rclone_chunk.002_7tvesi: Deleted
2020/12/12 05:31:59 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2020/12/12 05:31:59 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-wosikah7gujecir1rabogul2': Waiting for checks to finish
2020/12/12 05:31:59 DEBUG : potato2: Can't copy - required hash not found
2020/12/12 05:31:59 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ns)
2020/12/12 05:31:59 DEBUG : empty space: Unchanged skipping
2020/12/12 05:31:59 DEBUG : potato3: Can't copy - required hash not found
2020/12/12 05:31:59 INFO  : empty space: Deleted
2020/12/12 05:31:59 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-wosikah7gujecir1rabogul2': Waiting for transfers to finish
2020/12/12 05:32:00 DEBUG : potato2.rclone_chunk.001_7tveey: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 05:32:00 INFO  : potato2.rclone_chunk.001_7tveey: Copied (server-side copy) to: potato2.rclone_chunk.001
2020/12/12 05:32:00 INFO  : potato2.rclone_chunk.001_7tveey: Deleted
2020/12/12 05:32:00 DEBUG : potato2.rclone_chunk.002_7tveey: MD5 = 01a6651a94ab602dbfc47587d234b52c OK
2020/12/12 05:32:00 INFO  : potato2.rclone_chunk.002_7tveey: Copied (server-side copy) to: potato2.rclone_chunk.002
2020/12/12 05:32:00 INFO  : potato2.rclone_chunk.002_7tveey: Deleted
2020/12/12 05:32:00 DEBUG : potato3.rclone_chunk.001_7tvfiz: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 05:32:00 INFO  : potato3.rclone_chunk.001_7tvfiz: Copied (server-side copy) to: potato3.rclone_chunk.001
2020/12/12 05:32:00 INFO  : potato2: Copied (new)
2020/12/12 05:32:00 INFO  : potato3.rclone_chunk.001_7tvfiz: Deleted
2020/12/12 05:32:00 DEBUG : potato3.rclone_chunk.002_7tvfiz: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK
2020/12/12 05:32:00 INFO  : potato3.rclone_chunk.002_7tvfiz: Copied (server-side copy) to: potato3.rclone_chunk.002
2020/12/12 05:32:00 INFO  : potato2: Deleted
2020/12/12 05:32:00 INFO  : potato3.rclone_chunk.002_7tvfiz: Deleted
2020/12/12 05:32:00 INFO  : potato3: Copied (replaced existing)
2020/12/12 05:32:00 INFO  : potato3: Deleted
2020/12/12 05:32:00 DEBUG : Creating backend with remote "TestChunkerChunk50bSHA1QuickS3:rclone-test-yexucut4quxacep4fisucaw4"
2020/12/12 05:32:00 DEBUG : Creating backend with remote "TestS3:rclone-test-yexucut4quxacep4fisucaw4"
2020/12/12 05:32:00 DEBUG : Reset feature "ListR"
2020/12/12 05:32:00 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-yexucut4quxacep4fisucaw4': Waiting for checks to finish
2020/12/12 05:32:00 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-yexucut4quxacep4fisucaw4': Waiting for transfers to finish
2020/12/12 05:32:00 DEBUG : empty space: copy non-chunked object...
2020/12/12 05:32:00 DEBUG : potato3: Can't copy - required hash not found
2020/12/12 05:32:00 DEBUG : potato2: Can't copy - required hash not found
2020/12/12 05:32:01 INFO  : S3 bucket rclone-test-yexucut4quxacep4fisucaw4: Bucket "rclone-test-yexucut4quxacep4fisucaw4" created with ACL "private"
2020/12/12 05:32:01 INFO  : empty space: Copied (server-side copy)
2020/12/12 05:32:01 INFO  : empty space: Deleted
2020/12/12 05:32:01 DEBUG : potato3.rclone_chunk.001_7tvfn5: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 05:32:01 INFO  : potato3.rclone_chunk.001_7tvfn5: Copied (server-side copy) to: potato3.rclone_chunk.001
2020/12/12 05:32:01 DEBUG : potato2.rclone_chunk.001_7tvf3e: MD5 = dbbc040ac83a6f6c6816767a36d34c7b OK
2020/12/12 05:32:01 INFO  : potato2.rclone_chunk.001_7tvf3e: Copied (server-side copy) to: potato2.rclone_chunk.001
2020/12/12 05:32:01 INFO  : potato3.rclone_chunk.001_7tvfn5: Deleted
2020/12/12 05:32:01 INFO  : potato2.rclone_chunk.001_7tvf3e: Deleted
2020/12/12 05:32:01 DEBUG : potato3.rclone_chunk.002_7tvfn5: MD5 = 111c387f2584838efb7e0ec6f2fa2e10 OK
2020/12/12 05:32:01 INFO  : potato3.rclone_chunk.002_7tvfn5: Copied (server-side copy) to: potato3.rclone_chunk.002
2020/12/12 05:32:01 DEBUG : potato2.rclone_chunk.002_7tvf3e: MD5 = 01a6651a94ab602dbfc47587d234b52c OK
2020/12/12 05:32:01 INFO  : potato2.rclone_chunk.002_7tvf3e: Copied (server-side copy) to: potato2.rclone_chunk.002
2020/12/12 05:32:01 INFO  : potato3.rclone_chunk.002_7tvfn5: Deleted
2020/12/12 05:32:01 INFO  : potato2.rclone_chunk.002_7tvf3e: Deleted
2020/12/12 05:32:01 INFO  : potato3: Copied (new)
2020/12/12 05:32:01 INFO  : potato2: Copied (new)
2020/12/12 05:32:01 INFO  : potato3: Deleted
2020/12/12 05:32:01 INFO  : potato2: Deleted
2020/12/12 05:32:01 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-yexucut4quxacep4fisucaw4': Purge object "empty space"
2020/12/12 05:32:01 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-yexucut4quxacep4fisucaw4': Purge object "potato2"
2020/12/12 05:32:01 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-yexucut4quxacep4fisucaw4': Purge object "potato3"
2020/12/12 05:32:01 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-yexucut4quxacep4fisucaw4': Purge dir ""
2020/12/12 05:32:02 INFO  : S3 bucket rclone-test-yexucut4quxacep4fisucaw4: Bucket "rclone-test-yexucut4quxacep4fisucaw4" deleted
2020/12/12 05:32:02 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-wosikah7gujecir1rabogul2': Purge dir ""
2020/12/12 05:32:02 INFO  : S3 bucket rclone-test-wosikah7gujecir1rabogul2: Bucket "rclone-test-wosikah7gujecir1rabogul2" deleted
--- PASS: TestServerSideMove (5.48s)
PASS
2020/12/12 05:32:02 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-gepicoz0baroquw3lafazuh7': Purge dir ""
2020/12/12 05:32:02 INFO  : S3 bucket rclone-test-gepicoz0baroquw3lafazuh7: Bucket "rclone-test-gepicoz0baroquw3lafazuh7" deleted
"./sync.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bSHA1QuickS3: -verbose -size-limit 1024 -test.run '^TestServerSideMove$'" - Finished OK in 5.794617594s (try 4/5)