"./sync.test -test.v -test.timeout 2h0m0s -remote TestPutio: -verbose -test.run '^(TestServerSideCopy|TestSyncConcurrentTruncate|TestSyncCopyDest)$'" - Starting (try 4/5) 2022/01/13 06:08:25 DEBUG : Creating backend with remote "TestPutio:rclone-test-cesehas6dimayom2pezoqan4" 2022/01/13 06:08:25 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2022/01/13 06:08:25 DEBUG : Creating backend with remote "/tmp/rclone2195548531" === RUN TestServerSideCopy run.go:181: Remote "Putio root 'rclone-test-cesehas6dimayom2pezoqan4'", Local "Local file system at /tmp/rclone2195548531", Modify Window "1s" 2022/01/13 06:08:26 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 11 2022/01/13 06:08:26 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 11 2022/01/13 06:08:27 DEBUG : Creating backend with remote "TestPutio:rclone-test-nicomad3yayoxop9ciqaxew9" sync_test.go:275: Server side copy (if possible) Putio root 'rclone-test-cesehas6dimayom2pezoqan4' -> Putio root 'rclone-test-nicomad3yayoxop9ciqaxew9' 2022/01/13 06:08:27 DEBUG : Putio root 'rclone-test-nicomad3yayoxop9ciqaxew9': Waiting for checks to finish 2022/01/13 06:08:27 DEBUG : Putio root 'rclone-test-nicomad3yayoxop9ciqaxew9': Waiting for transfers to finish 2022/01/13 06:08:28 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 2022/01/13 06:08:28 DEBUG : Putio root 'rclone-test-nicomad3yayoxop9ciqaxew9': Purge remote --- FAIL: TestServerSideCopy (3.37s) === RUN TestSyncCopyDest run.go:181: Remote "Putio root 'rclone-test-cesehas6dimayom2pezoqan4'", Local "Local file system at /tmp/rclone2195548531", Modify Window "1s" 2022/01/13 06:08:28 DEBUG : Creating backend with remote "TestPutio:rclone-test-cesehas6dimayom2pezoqan4/dst" 2022/01/13 06:08:29 DEBUG : Creating backend with remote "TestPutio:rclone-test-cesehas6dimayom2pezoqan4/CopyDest" 2022/01/13 06:08:29 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4/dst': Waiting for checks to finish 2022/01/13 06:08:29 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4/dst': Waiting for transfers to finish 2022/01/13 06:08:30 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4/dst': chunkStart: 0, reqSize: 3 2022/01/13 06:08:30 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4/dst': Sending chunk. transferOffset: 0 length: 3 2022/01/13 06:08:30 DEBUG : one: crc32 = 7a6c86f1 OK 2022/01/13 06:08:30 INFO : one: Copied (new) 2022/01/13 06:08:30 DEBUG : Waiting for deletions to finish 2022/01/13 06:08:31 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4/dst': Waiting for checks to finish 2022/01/13 06:08:31 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/01/13 06:08:31 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4/dst': Waiting for transfers to finish 2022/01/13 06:08:31 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4/dst': chunkStart: 0, reqSize: 5 2022/01/13 06:08:31 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4/dst': Sending chunk. transferOffset: 0 length: 5 2022/01/13 06:08:32 DEBUG : one: crc32 = cb217308 OK 2022/01/13 06:08:32 INFO : one: Copied (replaced existing) 2022/01/13 06:08:32 DEBUG : Waiting for deletions to finish 2022/01/13 06:08:33 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 3 2022/01/13 06:08:33 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 3 2022/01/13 06:08:34 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 5 2022/01/13 06:08:34 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 5 2022/01/13 06:08:35 DEBUG : Creating backend with remote "TestPutio:rclone-test-cesehas6dimayom2pezoqan4/BackupDir" 2022/01/13 06:08:35 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4/dst': Waiting for checks to finish 2022/01/13 06:08:36 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/01/13 06:08:36 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/01/13 06:08:36 INFO : one: Moved (server-side) 2022/01/13 06:08:36 ERROR : one: Failed to copy: unexpected status code (400) response while doing POST to https://api.put.io/v2/files/copy 2022/01/13 06:08:36 ERROR : one: Destination found in --copy-dest, error copying 2022/01/13 06:08:36 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/01/13 06:08:37 INFO : one: Deleted 2022/01/13 06:08:37 ERROR : one: Couldn't move: object not found 2022/01/13 06:08:37 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4/dst': Waiting for transfers to finish 2022/01/13 06:08:37 ERROR : Putio root 'rclone-test-cesehas6dimayom2pezoqan4/dst': not deleting files as there were IO errors 2022/01/13 06:08:37 ERROR : Putio root 'rclone-test-cesehas6dimayom2pezoqan4/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 (9.74s) === RUN TestSyncConcurrentTruncate run.go:181: Remote "Putio root 'rclone-test-cesehas6dimayom2pezoqan4'", Local "Local file system at /tmp/rclone2195548531", Modify Window "1s" 2022/01/13 06:08:38 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:08:38 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:08:40 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:08:40 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:08:41 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:08:41 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:08:42 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:08:42 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:08:43 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:08:43 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:08:47 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:08:47 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:08:48 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:08:48 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:08:49 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:08:49 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:08:50 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:08:50 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:08:51 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:08:51 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:08:52 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:08:52 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:08:53 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:08:53 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:08:54 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:08:54 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:08:55 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:08:55 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:08:58 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:08:58 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:08:59 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:08:59 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:00 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:00 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:01 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:01 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:02 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:02 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:04 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:04 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:05 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:05 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:06 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:06 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:07 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:07 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:08 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:08 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:09 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:09 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:10 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:10 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:11 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:11 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:12 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:12 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:13 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:13 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:14 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:14 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:15 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:15 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:16 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:16 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:17 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:17 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:18 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:18 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:19 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:19 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:20 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:20 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:21 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:21 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:22 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:22 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:23 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:23 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:24 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': chunkStart: 0, reqSize: 6 2022/01/13 06:09:24 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending chunk. transferOffset: 0 length: 6 2022/01/13 06:09:26 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Waiting for checks to finish 2022/01/13 06:09:26 DEBUG : both0: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/13 06:09:26 DEBUG : both1: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/13 06:09:26 DEBUG : both10: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/13 06:09:26 DEBUG : both11: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/13 06:09:26 DEBUG : both11: Unchanged skipping 2022/01/13 06:09:26 DEBUG : both1: Unchanged skipping 2022/01/13 06:09:26 DEBUG : both12: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/13 06:09:26 DEBUG : both12: Unchanged skipping 2022/01/13 06:09:26 DEBUG : both13: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/13 06:09:26 DEBUG : both13: Unchanged skipping 2022/01/13 06:09:26 DEBUG : both15: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/13 06:09:26 DEBUG : both15: Unchanged skipping 2022/01/13 06:09:26 DEBUG : both16: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/13 06:09:26 DEBUG : both16: Unchanged skipping 2022/01/13 06:09:26 DEBUG : both17: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/13 06:09:26 DEBUG : both17: Unchanged skipping 2022/01/13 06:09:26 DEBUG : both18: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/13 06:09:26 DEBUG : both18: Unchanged skipping 2022/01/13 06:09:26 DEBUG : both19: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/13 06:09:26 DEBUG : both19: Unchanged skipping 2022/01/13 06:09:26 DEBUG : both2: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/13 06:09:26 DEBUG : both2: Unchanged skipping 2022/01/13 06:09:26 DEBUG : both10: Unchanged skipping 2022/01/13 06:09:26 DEBUG : both4: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/13 06:09:26 DEBUG : both4: Unchanged skipping 2022/01/13 06:09:26 DEBUG : both5: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/13 06:09:26 DEBUG : both5: Unchanged skipping 2022/01/13 06:09:26 DEBUG : both6: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/13 06:09:26 DEBUG : both6: Unchanged skipping 2022/01/13 06:09:26 DEBUG : both7: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/13 06:09:26 DEBUG : both7: Unchanged skipping 2022/01/13 06:09:26 DEBUG : both8: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/13 06:09:26 DEBUG : both8: Unchanged skipping 2022/01/13 06:09:26 DEBUG : both9: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/13 06:09:26 DEBUG : both9: Unchanged skipping 2022/01/13 06:09:26 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2022/01/13 06:09:26 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2022/01/13 06:09:26 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2022/01/13 06:09:26 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2022/01/13 06:09:26 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2022/01/13 06:09:26 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2022/01/13 06:09:26 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2022/01/13 06:09:26 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2022/01/13 06:09:26 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2022/01/13 06:09:26 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2022/01/13 06:09:26 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2022/01/13 06:09:26 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2022/01/13 06:09:26 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2022/01/13 06:09:26 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2022/01/13 06:09:26 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2022/01/13 06:09:26 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2022/01/13 06:09:26 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2022/01/13 06:09:26 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2022/01/13 06:09:26 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2022/01/13 06:09:26 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2022/01/13 06:09:26 DEBUG : both14: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/13 06:09:26 DEBUG : both14: Unchanged skipping 2022/01/13 06:09:26 DEBUG : both0: Unchanged skipping 2022/01/13 06:09:26 DEBUG : both3: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/13 06:09:26 DEBUG : both3: Unchanged skipping 2022/01/13 06:09:26 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Waiting for transfers to finish 2022/01/13 06:09:26 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:27 DEBUG : only0: crc32 = 00000000 OK 2022/01/13 06:09:27 INFO : only0: Copied (replaced existing) 2022/01/13 06:09:27 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:27 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:27 DEBUG : only12: crc32 = 00000000 OK 2022/01/13 06:09:27 INFO : only12: Copied (replaced existing) 2022/01/13 06:09:28 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:28 DEBUG : only1: crc32 = 00000000 OK 2022/01/13 06:09:28 INFO : only1: Copied (replaced existing) 2022/01/13 06:09:28 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:28 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:28 DEBUG : pacer: low level retry 1/10 (error unexpected status code (500) response while doing PATCH to https://s69.put.io/files/f7b58cc959dfa5754326aceeda87502312fd9785) 2022/01/13 06:09:28 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2022/01/13 06:09:28 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:29 DEBUG : pacer: Reducing sleep to 15ms 2022/01/13 06:09:29 DEBUG : pacer: Reducing sleep to 11.25ms 2022/01/13 06:09:29 ERROR : only10: Failed to copy: unexpected status code (404) response while doing PATCH to https://s69.put.io/files/f7b58cc959dfa5754326aceeda87502312fd9785 2022/01/13 06:09:29 DEBUG : pacer: Reducing sleep to 10ms 2022/01/13 06:09:29 DEBUG : only14: crc32 = 00000000 OK 2022/01/13 06:09:29 INFO : only14: Copied (replaced existing) 2022/01/13 06:09:29 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:29 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:30 DEBUG : only11: crc32 = 00000000 OK 2022/01/13 06:09:30 INFO : only11: Copied (replaced existing) 2022/01/13 06:09:30 DEBUG : only16: crc32 = 00000000 OK 2022/01/13 06:09:30 INFO : only16: Copied (replaced existing) 2022/01/13 06:09:30 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:30 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:30 DEBUG : only13: crc32 = 00000000 OK 2022/01/13 06:09:30 INFO : only13: Copied (replaced existing) 2022/01/13 06:09:31 DEBUG : only18: crc32 = 00000000 OK 2022/01/13 06:09:31 INFO : only18: Copied (replaced existing) 2022/01/13 06:09:31 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:31 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:32 DEBUG : only2: crc32 = 00000000 OK 2022/01/13 06:09:32 INFO : only2: Copied (replaced existing) 2022/01/13 06:09:32 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:32 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:33 DEBUG : pacer: low level retry 1/10 (error unexpected status code (500) response while doing PATCH to https://s81.put.io/files/2ca777f3fff640e575b90a5bf66cb25883e2dfdc) 2022/01/13 06:09:33 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2022/01/13 06:09:33 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:33 DEBUG : pacer: Reducing sleep to 15ms 2022/01/13 06:09:33 DEBUG : only3: crc32 = 00000000 OK 2022/01/13 06:09:33 INFO : only3: Copied (replaced existing) 2022/01/13 06:09:33 DEBUG : pacer: Reducing sleep to 11.25ms 2022/01/13 06:09:33 DEBUG : only17: crc32 = 00000000 OK 2022/01/13 06:09:33 INFO : only17: Copied (replaced existing) 2022/01/13 06:09:33 DEBUG : pacer: Reducing sleep to 10ms 2022/01/13 06:09:33 DEBUG : only19: crc32 = 00000000 OK 2022/01/13 06:09:33 INFO : only19: Copied (replaced existing) 2022/01/13 06:09:33 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:33 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:34 DEBUG : only15: crc32 = 00000000 OK 2022/01/13 06:09:34 INFO : only15: Copied (replaced existing) 2022/01/13 06:09:34 DEBUG : only4: crc32 = 00000000 OK 2022/01/13 06:09:34 INFO : only4: Copied (replaced existing) 2022/01/13 06:09:34 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:34 DEBUG : only6: crc32 = 00000000 OK 2022/01/13 06:09:34 INFO : only6: Copied (replaced existing) 2022/01/13 06:09:34 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:34 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:35 DEBUG : only8: crc32 = 00000000 OK 2022/01/13 06:09:35 INFO : only8: Copied (replaced existing) 2022/01/13 06:09:35 DEBUG : only9: crc32 = 00000000 OK 2022/01/13 06:09:35 INFO : only9: Copied (replaced existing) 2022/01/13 06:09:35 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Sending zero length chunk 2022/01/13 06:09:36 DEBUG : only5: crc32 = 00000000 OK 2022/01/13 06:09:36 INFO : only5: Copied (replaced existing) 2022/01/13 06:09:38 DEBUG : only7: crc32 = 00000000 OK 2022/01/13 06:09:38 INFO : only7: Copied (replaced existing) 2022/01/13 06:09:38 ERROR : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': not deleting files as there were IO errors 2022/01/13 06:09:38 ERROR : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': not deleting directories as there were IO errors sync_test.go:2056: Error Trace: sync_test.go:2056 sync_test.go:2066 Error: Received unexpected error: unexpected status code (404) response while doing PATCH to https://s69.put.io/files/f7b58cc959dfa5754326aceeda87502312fd9785 Test: TestSyncConcurrentTruncate Messages: Sync must not return a error sync_test.go:2057: Error Trace: sync_test.go:2057 sync_test.go:2066 Error: Should be false Test: TestSyncConcurrentTruncate Messages: Low level errors must not have happened fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:2058 sync_test.go:2066 Error: Should be true Test: TestSyncConcurrentTruncate Messages: listing wrong, want both0 (6), both1 (6), both10 (6), both11 (6), both12 (6), both13 (6), both14 (6), both15 (6), both16 (6), both17 (6), both18 (6), both19 (6), both2 (6), both3 (6), both4 (6), both5 (6), both6 (6), both7 (6), both8 (6), both9 (6), only0 (0), only1 (0), only10 (0), only11 (0), only12 (0), only13 (0), only14 (0), only15 (0), only16 (0), only17 (0), only18 (0), only19 (0), only2 (0), only3 (0), only4 (0), only5 (0), only6 (0), only7 (0), only8 (0), only9 (0) got both0 (6), both1 (6), both10 (6), both11 (6), both12 (6), both13 (6), both14 (6), both15 (6), both16 (6), both17 (6), both18 (6), both19 (6), both2 (6), both3 (6), both4 (6), both5 (6), both6 (6), both7 (6), both8 (6), both9 (6), only0 (0), only1 (0), only11 (0), only12 (0), only13 (0), only14 (0), only15 (0), only16 (0), only17 (0), only18 (0), only19 (0), only2 (0), only3 (0), only4 (0), only5 (0), only6 (0), only7 (0), only8 (0), only9 (0) fstest.go:204: Not found "only10" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:2058 sync_test.go:2066 Error: Not equal: expected: 0 actual : 1 Test: TestSyncConcurrentTruncate Messages: 1 objects not found --- FAIL: TestSyncConcurrentTruncate (71.98s) FAIL 2022/01/13 06:09:50 DEBUG : Putio root 'rclone-test-cesehas6dimayom2pezoqan4': Purge remote "./sync.test -test.v -test.timeout 2h0m0s -remote TestPutio: -verbose -test.run '^(TestServerSideCopy|TestSyncConcurrentTruncate|TestSyncCopyDest)$'" - Finished ERROR in 1m25.560630209s (try 4/5): exit status 1: Failed [TestServerSideCopy TestSyncCopyDest TestSyncConcurrentTruncate]