"./sync.test -test.v -test.timeout 2h0m0s -remote TestPutio: -verbose -test.run '^(TestServerSideCopy|TestSyncConcurrentTruncate|TestSyncCopyDest)$'" - Starting (try 2/5) 2022/01/12 06:28:07 DEBUG : Creating backend with remote "TestPutio:rclone-test-yubiyey7tuwocut5mujimuy3" 2022/01/12 06:28:07 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2022/01/12 06:28:08 DEBUG : Creating backend with remote "/tmp/rclone3457637875" === RUN TestServerSideCopy run.go:181: Remote "Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3'", Local "Local file system at /tmp/rclone3457637875", Modify Window "1s" 2022/01/12 06:28:09 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 11 2022/01/12 06:28:09 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 11 2022/01/12 06:28:09 DEBUG : Creating backend with remote "TestPutio:rclone-test-nurijep8rahutiw2jehipoh2" sync_test.go:275: Server side copy (if possible) Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3' -> Putio root 'rclone-test-nurijep8rahutiw2jehipoh2' 2022/01/12 06:28:10 DEBUG : Putio root 'rclone-test-nurijep8rahutiw2jehipoh2': Waiting for checks to finish 2022/01/12 06:28:10 DEBUG : Putio root 'rclone-test-nurijep8rahutiw2jehipoh2': Waiting for transfers to finish 2022/01/12 06:28:10 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/12 06:28:10 DEBUG : Putio root 'rclone-test-nurijep8rahutiw2jehipoh2': Purge remote --- FAIL: TestServerSideCopy (3.20s) === RUN TestSyncCopyDest run.go:181: Remote "Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3'", Local "Local file system at /tmp/rclone3457637875", Modify Window "1s" 2022/01/12 06:28:11 DEBUG : Creating backend with remote "TestPutio:rclone-test-yubiyey7tuwocut5mujimuy3/dst" 2022/01/12 06:28:11 DEBUG : Creating backend with remote "TestPutio:rclone-test-yubiyey7tuwocut5mujimuy3/CopyDest" 2022/01/12 06:28:12 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3/dst': Waiting for checks to finish 2022/01/12 06:28:12 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3/dst': Waiting for transfers to finish 2022/01/12 06:28:12 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3/dst': chunkStart: 0, reqSize: 3 2022/01/12 06:28:12 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3/dst': Sending chunk. transferOffset: 0 length: 3 2022/01/12 06:28:13 DEBUG : one: crc32 = 7a6c86f1 OK 2022/01/12 06:28:13 INFO : one: Copied (new) 2022/01/12 06:28:13 DEBUG : Waiting for deletions to finish 2022/01/12 06:28:13 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3/dst': Waiting for checks to finish 2022/01/12 06:28:13 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/01/12 06:28:13 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3/dst': Waiting for transfers to finish 2022/01/12 06:28:14 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3/dst': chunkStart: 0, reqSize: 5 2022/01/12 06:28:14 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3/dst': Sending chunk. transferOffset: 0 length: 5 2022/01/12 06:28:15 DEBUG : one: crc32 = cb217308 OK 2022/01/12 06:28:15 INFO : one: Copied (replaced existing) 2022/01/12 06:28:15 DEBUG : Waiting for deletions to finish 2022/01/12 06:28:16 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 3 2022/01/12 06:28:16 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 3 2022/01/12 06:28:17 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 5 2022/01/12 06:28:17 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 5 2022/01/12 06:28:18 DEBUG : Creating backend with remote "TestPutio:rclone-test-yubiyey7tuwocut5mujimuy3/BackupDir" 2022/01/12 06:28:18 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3/dst': Waiting for checks to finish 2022/01/12 06:28:19 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2022/01/12 06:28:19 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/01/12 06:28:19 INFO : one: Moved (server-side) 2022/01/12 06:28:19 ERROR : one: Failed to copy: unexpected status code (400) response while doing POST to https://api.put.io/v2/files/copy 2022/01/12 06:28:19 ERROR : one: Destination found in --copy-dest, error copying 2022/01/12 06:28:19 DEBUG : one: Sizes differ (src 5 vs dst 3) 2022/01/12 06:28:19 INFO : one: Deleted 2022/01/12 06:28:20 ERROR : one: Couldn't move: object not found 2022/01/12 06:28:20 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3/dst': Waiting for transfers to finish 2022/01/12 06:28:20 ERROR : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3/dst': not deleting files as there were IO errors 2022/01/12 06:28:20 ERROR : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3/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.69s) === RUN TestSyncConcurrentTruncate run.go:181: Remote "Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3'", Local "Local file system at /tmp/rclone3457637875", Modify Window "1s" 2022/01/12 06:28:21 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:21 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:22 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:22 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:23 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:23 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:24 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:24 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:25 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:25 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:27 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:27 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:28 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:28 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:29 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:29 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:30 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:30 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:32 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:32 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:33 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:33 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:34 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:34 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:35 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:35 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:37 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:37 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:38 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:38 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:39 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:39 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:41 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:41 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:42 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:42 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:42 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:42 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:44 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:44 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:47 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:47 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:50 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:50 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:51 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:51 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:52 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:52 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:53 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:53 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:54 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:54 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:55 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:55 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:58 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:58 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:28:59 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:28:59 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:29:00 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:29:00 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:29:07 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:29:07 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:29:08 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:29:08 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:29:08 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:29:08 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:29:10 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:29:10 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:29:13 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:29:13 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:29:14 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:29:14 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:29:15 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:29:15 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:29:16 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:29:16 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:29:17 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:29:17 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:29:18 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': chunkStart: 0, reqSize: 6 2022/01/12 06:29:18 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending chunk. transferOffset: 0 length: 6 2022/01/12 06:29:21 DEBUG : both0: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/12 06:29:21 DEBUG : both0: Unchanged skipping 2022/01/12 06:29:21 DEBUG : both12: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/12 06:29:21 DEBUG : both12: Unchanged skipping 2022/01/12 06:29:21 DEBUG : both1: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/12 06:29:21 DEBUG : both1: Unchanged skipping 2022/01/12 06:29:21 DEBUG : both14: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/12 06:29:21 DEBUG : both14: Unchanged skipping 2022/01/12 06:29:21 DEBUG : both15: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/12 06:29:21 DEBUG : both15: Unchanged skipping 2022/01/12 06:29:21 DEBUG : both16: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/12 06:29:21 DEBUG : both16: Unchanged skipping 2022/01/12 06:29:21 DEBUG : both17: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/12 06:29:21 DEBUG : both17: Unchanged skipping 2022/01/12 06:29:21 DEBUG : both18: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/12 06:29:21 DEBUG : both18: Unchanged skipping 2022/01/12 06:29:21 DEBUG : both19: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/12 06:29:21 DEBUG : both19: Unchanged skipping 2022/01/12 06:29:21 DEBUG : both2: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/12 06:29:21 DEBUG : both2: Unchanged skipping 2022/01/12 06:29:21 DEBUG : both3: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/12 06:29:21 DEBUG : both3: Unchanged skipping 2022/01/12 06:29:21 DEBUG : both4: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/12 06:29:21 DEBUG : both4: Unchanged skipping 2022/01/12 06:29:21 DEBUG : both5: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/12 06:29:21 DEBUG : both5: Unchanged skipping 2022/01/12 06:29:21 DEBUG : both6: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/12 06:29:21 DEBUG : both6: Unchanged skipping 2022/01/12 06:29:21 DEBUG : both7: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/12 06:29:21 DEBUG : both7: Unchanged skipping 2022/01/12 06:29:21 DEBUG : both8: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/12 06:29:21 DEBUG : both8: Unchanged skipping 2022/01/12 06:29:21 DEBUG : both9: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/12 06:29:21 DEBUG : both9: Unchanged skipping 2022/01/12 06:29:21 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2022/01/12 06:29:21 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2022/01/12 06:29:21 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2022/01/12 06:29:21 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2022/01/12 06:29:21 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2022/01/12 06:29:21 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2022/01/12 06:29:21 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2022/01/12 06:29:21 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2022/01/12 06:29:21 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2022/01/12 06:29:21 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2022/01/12 06:29:21 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2022/01/12 06:29:21 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2022/01/12 06:29:21 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2022/01/12 06:29:21 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2022/01/12 06:29:21 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2022/01/12 06:29:21 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2022/01/12 06:29:21 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2022/01/12 06:29:21 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2022/01/12 06:29:21 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2022/01/12 06:29:21 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2022/01/12 06:29:21 DEBUG : both10: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/12 06:29:21 DEBUG : both10: Unchanged skipping 2022/01/12 06:29:21 DEBUG : both11: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/12 06:29:21 DEBUG : both11: Unchanged skipping 2022/01/12 06:29:21 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Waiting for checks to finish 2022/01/12 06:29:21 DEBUG : both13: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2022/01/12 06:29:21 DEBUG : both13: Unchanged skipping 2022/01/12 06:29:21 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Waiting for transfers to finish 2022/01/12 06:29:22 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:23 DEBUG : only0: crc32 = 00000000 OK 2022/01/12 06:29:23 INFO : only0: Copied (replaced existing) 2022/01/12 06:29:23 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:23 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:23 DEBUG : only1: crc32 = 00000000 OK 2022/01/12 06:29:23 INFO : only1: Copied (replaced existing) 2022/01/12 06:29:24 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:24 DEBUG : pacer: low level retry 1/10 (error unexpected status code (500) response while doing PATCH to https://s66.put.io/files/a0101bc9b038c45bb35112d0abdc73a408b0e4fb) 2022/01/12 06:29:24 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2022/01/12 06:29:24 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:24 DEBUG : pacer: Reducing sleep to 15ms 2022/01/12 06:29:24 ERROR : only12: Failed to copy: unexpected status code (404) response while doing PATCH to https://s66.put.io/files/a0101bc9b038c45bb35112d0abdc73a408b0e4fb 2022/01/12 06:29:25 DEBUG : pacer: Reducing sleep to 11.25ms 2022/01/12 06:29:25 DEBUG : pacer: Reducing sleep to 10ms 2022/01/12 06:29:25 DEBUG : only10: crc32 = 00000000 OK 2022/01/12 06:29:25 INFO : only10: Copied (replaced existing) 2022/01/12 06:29:25 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:25 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:25 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:25 DEBUG : only11: crc32 = 00000000 OK 2022/01/12 06:29:25 INFO : only11: Copied (replaced existing) 2022/01/12 06:29:26 DEBUG : only15: crc32 = 00000000 OK 2022/01/12 06:29:26 INFO : only15: Copied (replaced existing) 2022/01/12 06:29:26 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:26 DEBUG : only14: crc32 = 00000000 OK 2022/01/12 06:29:26 INFO : only14: Copied (replaced existing) 2022/01/12 06:29:26 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:26 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:26 DEBUG : pacer: low level retry 1/10 (error unexpected status code (500) response while doing PATCH to https://s76.put.io/files/3983bc25c63dc4afeb11f0ceb0a26b5c475d2602) 2022/01/12 06:29:26 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2022/01/12 06:29:26 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:26 DEBUG : pacer: Reducing sleep to 15ms 2022/01/12 06:29:26 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:26 DEBUG : pacer: Reducing sleep to 11.25ms 2022/01/12 06:29:26 ERROR : only16: Failed to copy: unexpected status code (404) response while doing PATCH to https://s76.put.io/files/3983bc25c63dc4afeb11f0ceb0a26b5c475d2602 2022/01/12 06:29:26 DEBUG : pacer: Reducing sleep to 10ms 2022/01/12 06:29:26 DEBUG : only13: crc32 = 00000000 OK 2022/01/12 06:29:26 INFO : only13: Copied (replaced existing) 2022/01/12 06:29:26 DEBUG : only17: crc32 = 00000000 OK 2022/01/12 06:29:26 INFO : only17: Copied (replaced existing) 2022/01/12 06:29:27 DEBUG : only18: crc32 = 00000000 OK 2022/01/12 06:29:27 INFO : only18: Copied (replaced existing) 2022/01/12 06:29:27 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:27 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:27 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:27 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:27 DEBUG : pacer: low level retry 1/10 (error unexpected status code (500) response while doing PATCH to https://s79.put.io/files/f0b425338e161a56383f871b0a810e15029b5a5a) 2022/01/12 06:29:27 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2022/01/12 06:29:27 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:27 DEBUG : pacer: Reducing sleep to 15ms 2022/01/12 06:29:27 DEBUG : pacer: Reducing sleep to 11.25ms 2022/01/12 06:29:27 ERROR : only3: Failed to copy: unexpected status code (404) response while doing PATCH to https://s79.put.io/files/f0b425338e161a56383f871b0a810e15029b5a5a 2022/01/12 06:29:27 DEBUG : pacer: Reducing sleep to 10ms 2022/01/12 06:29:27 DEBUG : only4: crc32 = 00000000 OK 2022/01/12 06:29:27 INFO : only4: Copied (replaced existing) 2022/01/12 06:29:28 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:28 DEBUG : only5: crc32 = 00000000 OK 2022/01/12 06:29:28 INFO : only5: Copied (replaced existing) 2022/01/12 06:29:29 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:29 DEBUG : only2: crc32 = 00000000 OK 2022/01/12 06:29:29 INFO : only2: Copied (replaced existing) 2022/01/12 06:29:29 DEBUG : only6: crc32 = 00000000 OK 2022/01/12 06:29:29 INFO : only6: Copied (replaced existing) 2022/01/12 06:29:29 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:30 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:30 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Sending zero length chunk 2022/01/12 06:29:30 DEBUG : only9: crc32 = 00000000 OK 2022/01/12 06:29:30 INFO : only9: Copied (replaced existing) 2022/01/12 06:29:31 DEBUG : only19: crc32 = 00000000 OK 2022/01/12 06:29:31 INFO : only19: Copied (replaced existing) 2022/01/12 06:29:31 DEBUG : only7: crc32 = 00000000 OK 2022/01/12 06:29:31 INFO : only7: Copied (replaced existing) 2022/01/12 06:29:32 DEBUG : only8: crc32 = 00000000 OK 2022/01/12 06:29:32 INFO : only8: Copied (replaced existing) 2022/01/12 06:29:32 ERROR : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': not deleting files as there were IO errors 2022/01/12 06:29:32 ERROR : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': 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://s79.put.io/files/f0b425338e161a56383f871b0a810e15029b5a5a 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), only10 (0), only11 (0), only13 (0), only14 (0), only15 (0), only17 (0), only18 (0), only19 (0), only2 (0), only4 (0), only5 (0), only6 (0), only7 (0), only8 (0), only9 (0) fstest.go:204: Not found "only12" fstest.go:204: Not found "only3" fstest.go:204: Not found "only16" 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 : 3 Test: TestSyncConcurrentTruncate Messages: 3 objects not found --- FAIL: TestSyncConcurrentTruncate (84.20s) FAIL 2022/01/12 06:29:45 DEBUG : Putio root 'rclone-test-yubiyey7tuwocut5mujimuy3': Purge remote "./sync.test -test.v -test.timeout 2h0m0s -remote TestPutio: -verbose -test.run '^(TestServerSideCopy|TestSyncConcurrentTruncate|TestSyncCopyDest)$'" - Finished ERROR in 1m37.633759532s (try 2/5): exit status 1: Failed [TestServerSideCopy TestSyncCopyDest TestSyncConcurrentTruncate]