"./sync.test -test.v -test.timeout 2h0m0s -remote TestPutio: -verbose -test.run '^(TestServerSideCopy|TestSyncConcurrentTruncate|TestSyncCopyDest)$'" - Starting (try 2/5)
2021/12/13 06:17:50 DEBUG : Creating backend with remote "TestPutio:rclone-test-badupiz4nutolof4tirohax8"
2021/12/13 06:17:50 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2021/12/13 06:17:50 DEBUG : Creating backend with remote "/tmp/rclone3948400392"
=== RUN   TestServerSideCopy
    run.go:181: Remote "Putio root 'rclone-test-badupiz4nutolof4tirohax8'", Local "Local file system at /tmp/rclone3948400392", Modify Window "1s"
2021/12/13 06:17:51 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': chunkStart: 0, reqSize: 11
2021/12/13 06:17:51 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': Sending chunk. transferOffset: 0 length: 11
2021/12/13 06:17:53 DEBUG : Creating backend with remote "TestPutio:rclone-test-neviyom4bipovez8vifoxil7"
    sync_test.go:275: Server side copy (if possible) Putio root 'rclone-test-badupiz4nutolof4tirohax8' -> Putio root 'rclone-test-neviyom4bipovez8vifoxil7'
2021/12/13 06:17:53 DEBUG : Putio root 'rclone-test-neviyom4bipovez8vifoxil7': Waiting for checks to finish
2021/12/13 06:17:53 DEBUG : Putio root 'rclone-test-neviyom4bipovez8vifoxil7': Waiting for transfers to finish
2021/12/13 06:17:54 ERROR : sub dir/hello world: Failed to copy: unexpected status code (400) response while doing POST to https://api.put.io/v2/files/copy
    sync_test.go:278: 
        	Error Trace:	sync_test.go:278
        	Error:      	Received unexpected error:
        	            	unexpected status code (400) response while doing POST to https://api.put.io/v2/files/copy
        	Test:       	TestServerSideCopy
2021/12/13 06:17:54 DEBUG : Putio root 'rclone-test-neviyom4bipovez8vifoxil7': Purge remote
--- FAIL: TestServerSideCopy (4.58s)
=== RUN   TestSyncCopyDest
    run.go:181: Remote "Putio root 'rclone-test-badupiz4nutolof4tirohax8'", Local "Local file system at /tmp/rclone3948400392", Modify Window "1s"
2021/12/13 06:17:55 DEBUG : Creating backend with remote "TestPutio:rclone-test-badupiz4nutolof4tirohax8/dst"
2021/12/13 06:17:55 DEBUG : Creating backend with remote "TestPutio:rclone-test-badupiz4nutolof4tirohax8/CopyDest"
2021/12/13 06:17:57 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8/dst': Waiting for checks to finish
2021/12/13 06:17:57 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8/dst': Waiting for transfers to finish
2021/12/13 06:17:58 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8/dst': chunkStart: 0, reqSize: 3
2021/12/13 06:17:58 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8/dst': Sending chunk. transferOffset: 0 length: 3
2021/12/13 06:17:59 DEBUG : one: crc32 = 7a6c86f1 OK
2021/12/13 06:17:59 INFO  : one: Copied (new)
2021/12/13 06:17:59 DEBUG : Waiting for deletions to finish
2021/12/13 06:18:00 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8/dst': Waiting for checks to finish
2021/12/13 06:18:00 DEBUG : one: Sizes differ (src 5 vs dst 3)
2021/12/13 06:18:00 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8/dst': Waiting for transfers to finish
2021/12/13 06:18:01 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8/dst': chunkStart: 0, reqSize: 5
2021/12/13 06:18:01 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8/dst': Sending chunk. transferOffset: 0 length: 5
2021/12/13 06:18:02 DEBUG : one: crc32 = cb217308 OK
2021/12/13 06:18:02 INFO  : one: Copied (replaced existing)
2021/12/13 06:18:02 DEBUG : Waiting for deletions to finish
2021/12/13 06:18:04 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': chunkStart: 0, reqSize: 3
2021/12/13 06:18:04 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': Sending chunk. transferOffset: 0 length: 3
2021/12/13 06:18:07 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': chunkStart: 0, reqSize: 5
2021/12/13 06:18:07 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': Sending chunk. transferOffset: 0 length: 5
2021/12/13 06:18:10 DEBUG : Creating backend with remote "TestPutio:rclone-test-badupiz4nutolof4tirohax8/BackupDir"
2021/12/13 06:18:11 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8/dst': Waiting for checks to finish
2021/12/13 06:18:11 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2021/12/13 06:18:11 DEBUG : one: Sizes differ (src 5 vs dst 3)
2021/12/13 06:18:12 INFO  : one: Moved (server-side)
2021/12/13 06:18:12 ERROR : one: Failed to copy: unexpected status code (400) response while doing POST to https://api.put.io/v2/files/copy
2021/12/13 06:18:12 ERROR : one: Destination found in --copy-dest, error copying
2021/12/13 06:18:12 DEBUG : one: Sizes differ (src 5 vs dst 3)
2021/12/13 06:18:12 INFO  : one: Deleted
2021/12/13 06:18:12 ERROR : one: Couldn't move: object not found
2021/12/13 06:18:12 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8/dst': Waiting for transfers to finish
2021/12/13 06:18:12 ERROR : Putio root 'rclone-test-badupiz4nutolof4tirohax8/dst': not deleting files as there were IO errors
2021/12/13 06:18:12 ERROR : Putio root 'rclone-test-badupiz4nutolof4tirohax8/dst': not deleting directories as there were IO errors
    sync_test.go:1648: 
        	Error Trace:	sync_test.go:1648
        	Error:      	Received unexpected error:
        	            	object not found
        	Test:       	TestSyncCopyDest
--- FAIL: TestSyncCopyDest (19.90s)
=== RUN   TestSyncConcurrentTruncate
    run.go:181: Remote "Putio root 'rclone-test-badupiz4nutolof4tirohax8'", Local "Local file system at /tmp/rclone3948400392", Modify Window "1s"
2021/12/13 06:18:16 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': chunkStart: 0, reqSize: 6
2021/12/13 06:18:16 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': Sending chunk. transferOffset: 0 length: 6
2021/12/13 06:18:17 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': chunkStart: 0, reqSize: 6
2021/12/13 06:18:17 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': Sending chunk. transferOffset: 0 length: 6
2021/12/13 06:18:26 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': chunkStart: 0, reqSize: 6
2021/12/13 06:18:26 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': Sending chunk. transferOffset: 0 length: 6
2021/12/13 06:18:27 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': chunkStart: 0, reqSize: 6
2021/12/13 06:18:27 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': Sending chunk. transferOffset: 0 length: 6
2021/12/13 06:18:29 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': chunkStart: 0, reqSize: 6
2021/12/13 06:18:29 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': Sending chunk. transferOffset: 0 length: 6
2021/12/13 06:18:30 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': chunkStart: 0, reqSize: 6
2021/12/13 06:18:30 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': Sending chunk. transferOffset: 0 length: 6
2021/12/13 06:19:30 DEBUG : pacer: low level retry 1/10 (error connection broken)
2021/12/13 06:19:30 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2021/12/13 06:19:35 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': sentBytes: 0
2021/12/13 06:19:35 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': Sending chunk. transferOffset: 0 length: 6
2021/12/13 06:19:35 DEBUG : pacer: low level retry 2/10 (error unexpected status code (409) response while doing PATCH to https://s94.put.io/files/4c2a1d0e00dd0f8b68b593595a8c061a13c41b54)
2021/12/13 06:19:35 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2021/12/13 06:19:35 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': sentBytes: 0
2021/12/13 06:19:35 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': Sending chunk. transferOffset: 0 length: 6
2021/12/13 06:19:35 DEBUG : pacer: low level retry 3/10 (error connection broken)
2021/12/13 06:19:35 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2021/12/13 06:19:36 DEBUG : pacer: Reducing sleep to 60ms
    run.go:287: Failed to put "only2" to "Putio root 'rclone-test-badupiz4nutolof4tirohax8'": unexpected status code (404) response while doing HEAD to https://s94.put.io/files/4c2a1d0e00dd0f8b68b593595a8c061a13c41b54
2021/12/13 06:19:36 DEBUG : pacer: Reducing sleep to 45ms
2021/12/13 06:19:37 DEBUG : pacer: Reducing sleep to 33.75ms
2021/12/13 06:19:38 DEBUG : pacer: Reducing sleep to 25.3125ms
2021/12/13 06:19:38 DEBUG : pacer: Reducing sleep to 18.984375ms
2021/12/13 06:19:38 DEBUG : pacer: Reducing sleep to 14.238281ms
2021/12/13 06:19:39 DEBUG : pacer: Reducing sleep to 10.67871ms
2021/12/13 06:19:39 DEBUG : pacer: Reducing sleep to 10ms
--- FAIL: TestSyncConcurrentTruncate (84.19s)
FAIL
2021/12/13 06:19:39 DEBUG : Putio root 'rclone-test-badupiz4nutolof4tirohax8': Purge remote
"./sync.test -test.v -test.timeout 2h0m0s -remote TestPutio: -verbose -test.run '^(TestServerSideCopy|TestSyncConcurrentTruncate|TestSyncCopyDest)$'" - Finished ERROR in 1m49.258374818s (try 2/5): exit status 1: Failed [TestServerSideCopy TestSyncCopyDest TestSyncConcurrentTruncate]