"./sync.test -test.v -test.timeout 2h0m0s -remote TestPutio: -verbose -test.run '^(TestMoveWithDeleteEmptySrcDirs|TestMoveWithIgnoreExisting|TestMoveWithoutDeleteEmptySrcDirs|TestServerSideCopy|TestServerSideMove|TestServerSideMoveDeleteEmptySourceDirs|TestServerSideMoveWithFilter|TestSyncBackupDirSuffixOnly|TestSyncConcurrentTruncate|TestSyncCopyDest|TestSyncWithTrackRenames|TestSyncWithTrackRenamesStrategyLeaf|TestSyncWithTrackRenamesStrategyModtime|TestSyncWithUpdateOlder)$'" - Starting (try 5/5)
2022/03/03 06:51:19 DEBUG : Creating backend with remote "TestPutio:rclone-test-weziril0gixiked6lekobad7"
2022/03/03 06:51:19 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2022/03/03 06:51:19 DEBUG : Creating backend with remote "/tmp/rclone1166303137"
=== RUN   TestServerSideCopy
    run.go:181: Remote "Putio root 'rclone-test-weziril0gixiked6lekobad7'", Local "Local file system at /tmp/rclone1166303137", Modify Window "1s"
2022/03/03 06:51:20 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 11
2022/03/03 06:51:20 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 11
2022/03/03 06:51:21 DEBUG : Creating backend with remote "TestPutio:rclone-test-furaniq8buqaqax5zojequy7"
    sync_test.go:275: Server side copy (if possible) Putio root 'rclone-test-weziril0gixiked6lekobad7' -> Putio root 'rclone-test-furaniq8buqaqax5zojequy7'
2022/03/03 06:51:21 DEBUG : Putio root 'rclone-test-furaniq8buqaqax5zojequy7': Waiting for checks to finish
2022/03/03 06:51:21 DEBUG : Putio root 'rclone-test-furaniq8buqaqax5zojequy7': Waiting for transfers to finish
2022/03/03 06:51:22 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/03/03 06:51:22 DEBUG : Putio root 'rclone-test-furaniq8buqaqax5zojequy7': Purge remote
--- FAIL: TestServerSideCopy (3.28s)
=== RUN   TestSyncWithUpdateOlder
    run.go:181: Remote "Putio root 'rclone-test-weziril0gixiked6lekobad7'", Local "Local file system at /tmp/rclone1166303137", Modify Window "1s"
2022/03/03 06:51:23 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 3
2022/03/03 06:51:23 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 3
2022/03/03 06:51:24 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 3
2022/03/03 06:51:24 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 3
2022/03/03 06:51:25 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 5
2022/03/03 06:51:25 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 5
2022/03/03 06:51:27 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 8
2022/03/03 06:51:27 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 8
2022/03/03 06:51:30 DEBUG : four: Sizes differ (src 4 vs dst 8)
2022/03/03 06:51:30 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2022/03/03 06:51:30 DEBUG : one: Destination is newer than source, skipping
2022/03/03 06:51:30 DEBUG : three: Sizes identical
2022/03/03 06:51:30 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2022/03/03 06:51:30 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for checks to finish
2022/03/03 06:51:30 DEBUG : two: crc32 = 11ca8a66 (Local file system at /tmp/rclone1166303137)
2022/03/03 06:51:30 DEBUG : two: crc32 = 876dc8ec (Putio root 'rclone-test-weziril0gixiked6lekobad7')
2022/03/03 06:51:30 DEBUG : two: crc32 differ
2022/03/03 06:51:30 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for transfers to finish
2022/03/03 06:51:31 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 4
2022/03/03 06:51:31 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 4
2022/03/03 06:51:31 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 4
2022/03/03 06:51:31 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 4
2022/03/03 06:51:31 DEBUG : five: crc32 = 3cb2cccb OK
2022/03/03 06:51:31 INFO  : five: Copied (new)
2022/03/03 06:51:32 DEBUG : four: crc32 = 90c1667d OK
2022/03/03 06:51:32 INFO  : four: Copied (replaced existing)
2022/03/03 06:51:32 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 3
2022/03/03 06:51:32 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 3
2022/03/03 06:51:32 DEBUG : two: crc32 = 11ca8a66 OK
2022/03/03 06:51:32 INFO  : two: Copied (replaced existing)
2022/03/03 06:51:32 ERROR : Putio root 'rclone-test-weziril0gixiked6lekobad7': not deleting files as there were IO errors
2022/03/03 06:51:32 ERROR : Putio root 'rclone-test-weziril0gixiked6lekobad7': not deleting directories as there were IO errors
    sync_test.go:988: 
        	Error Trace:	sync_test.go:988
        	Error:      	Received unexpected error:
        	            	not deleting files as there were IO errors
        	Test:       	TestSyncWithUpdateOlder
--- FAIL: TestSyncWithUpdateOlder (10.46s)
=== RUN   TestSyncWithTrackRenames
    run.go:181: Remote "Putio root 'rclone-test-weziril0gixiked6lekobad7'", Local "Local file system at /tmp/rclone1166303137", Modify Window "1s"
    sync_test.go:1058: Can track renames: true
2022/03/03 06:51:33 INFO  : Putio root 'rclone-test-weziril0gixiked6lekobad7': Making map for --track-renames
2022/03/03 06:51:33 INFO  : Putio root 'rclone-test-weziril0gixiked6lekobad7': Finished making map for --track-renames
2022/03/03 06:51:33 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for checks to finish
2022/03/03 06:51:33 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for renames to finish
2022/03/03 06:51:33 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for transfers to finish
2022/03/03 06:51:33 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 14
2022/03/03 06:51:33 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 14
2022/03/03 06:51:34 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 11
2022/03/03 06:51:34 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 11
2022/03/03 06:51:34 DEBUG : potato: crc32 = 403f91c8 OK
2022/03/03 06:51:34 INFO  : potato: Copied (new)
2022/03/03 06:51:34 DEBUG : yam: crc32 = ae1fefed OK
2022/03/03 06:51:34 INFO  : yam: Copied (new)
2022/03/03 06:51:34 DEBUG : Waiting for deletions to finish
2022/03/03 06:51:34 DEBUG : potato: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/03/03 06:51:34 DEBUG : potato: Unchanged skipping
2022/03/03 06:51:34 INFO  : Putio root 'rclone-test-weziril0gixiked6lekobad7': Making map for --track-renames
2022/03/03 06:51:34 INFO  : Putio root 'rclone-test-weziril0gixiked6lekobad7': Finished making map for --track-renames
2022/03/03 06:51:34 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for checks to finish
2022/03/03 06:51:34 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for renames to finish
2022/03/03 06:51:35 INFO  : yam: Moved (server-side) to: yaml
2022/03/03 06:51:35 INFO  : yaml: Renamed from "yam"
2022/03/03 06:51:35 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for transfers to finish
2022/03/03 06:51:35 DEBUG : Waiting for deletions to finish
2022/03/03 06:51:35 INFO  : There was nothing to transfer
--- PASS: TestSyncWithTrackRenames (2.36s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:181: Remote "Putio root 'rclone-test-weziril0gixiked6lekobad7'", Local "Local file system at /tmp/rclone1166303137", Modify Window "1s"
    sync_test.go:1127: Can track renames: true
2022/03/03 06:51:35 INFO  : Putio root 'rclone-test-weziril0gixiked6lekobad7': Making map for --track-renames
2022/03/03 06:51:35 INFO  : Putio root 'rclone-test-weziril0gixiked6lekobad7': Finished making map for --track-renames
2022/03/03 06:51:35 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for checks to finish
2022/03/03 06:51:35 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for renames to finish
2022/03/03 06:51:35 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for transfers to finish
2022/03/03 06:51:36 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 14
2022/03/03 06:51:36 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 14
2022/03/03 06:51:36 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 11
2022/03/03 06:51:36 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 11
2022/03/03 06:51:36 DEBUG : potato: crc32 = 403f91c8 OK
2022/03/03 06:51:36 INFO  : potato: Copied (new)
2022/03/03 06:51:36 DEBUG : yam: crc32 = ae1fefed OK
2022/03/03 06:51:36 INFO  : yam: Copied (new)
2022/03/03 06:51:36 DEBUG : Waiting for deletions to finish
2022/03/03 06:51:37 DEBUG : potato: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/03/03 06:51:37 DEBUG : potato: Unchanged skipping
2022/03/03 06:51:37 INFO  : Putio root 'rclone-test-weziril0gixiked6lekobad7': Making map for --track-renames
2022/03/03 06:51:37 INFO  : Putio root 'rclone-test-weziril0gixiked6lekobad7': Finished making map for --track-renames
2022/03/03 06:51:37 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for checks to finish
2022/03/03 06:51:37 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for renames to finish
2022/03/03 06:51:37 INFO  : yam: Moved (server-side) to: yaml
2022/03/03 06:51:37 INFO  : yaml: Renamed from "yam"
2022/03/03 06:51:37 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for transfers to finish
2022/03/03 06:51:37 DEBUG : Waiting for deletions to finish
2022/03/03 06:51:37 INFO  : There was nothing to transfer
--- PASS: TestSyncWithTrackRenamesStrategyModtime (2.43s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:181: Remote "Putio root 'rclone-test-weziril0gixiked6lekobad7'", Local "Local file system at /tmp/rclone1166303137", Modify Window "1s"
    sync_test.go:1163: Can track renames: true
2022/03/03 06:51:38 INFO  : Putio root 'rclone-test-weziril0gixiked6lekobad7': Making map for --track-renames
2022/03/03 06:51:38 INFO  : Putio root 'rclone-test-weziril0gixiked6lekobad7': Finished making map for --track-renames
2022/03/03 06:51:38 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for checks to finish
2022/03/03 06:51:38 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for renames to finish
2022/03/03 06:51:38 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for transfers to finish
2022/03/03 06:51:39 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 14
2022/03/03 06:51:39 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 14
2022/03/03 06:51:39 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 11
2022/03/03 06:51:39 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 11
2022/03/03 06:51:39 DEBUG : potato: crc32 = 403f91c8 OK
2022/03/03 06:51:39 INFO  : potato: Copied (new)
2022/03/03 06:51:39 DEBUG : sub/yam: crc32 = ae1fefed OK
2022/03/03 06:51:39 INFO  : sub/yam: Copied (new)
2022/03/03 06:51:39 DEBUG : Waiting for deletions to finish
2022/03/03 06:51:39 DEBUG : potato: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/03/03 06:51:39 DEBUG : potato: Unchanged skipping
2022/03/03 06:51:40 INFO  : Putio root 'rclone-test-weziril0gixiked6lekobad7': Making map for --track-renames
2022/03/03 06:51:40 INFO  : Putio root 'rclone-test-weziril0gixiked6lekobad7': Finished making map for --track-renames
2022/03/03 06:51:40 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for checks to finish
2022/03/03 06:51:40 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for renames to finish
2022/03/03 06:51:40 INFO  : sub/yam: Moved (server-side) to: yam
2022/03/03 06:51:40 INFO  : yam: Renamed from "sub/yam"
2022/03/03 06:51:40 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for transfers to finish
2022/03/03 06:51:40 DEBUG : Waiting for deletions to finish
2022/03/03 06:51:40 INFO  : There was nothing to transfer
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (2.94s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:181: Remote "Putio root 'rclone-test-weziril0gixiked6lekobad7'", Local "Local file system at /tmp/rclone1166303137", Modify Window "1s"
2022/03/03 06:51:41 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for checks to finish
2022/03/03 06:51:41 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for transfers to finish
2022/03/03 06:51:41 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 11
2022/03/03 06:51:41 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 11
2022/03/03 06:51:42 DEBUG : sub dir/hello world: crc32 = 0d4a1185 OK
2022/03/03 06:51:42 INFO  : sub dir/hello world: Copied (new)
2022/03/03 06:51:42 INFO  : sub dir/hello world: Deleted
2022/03/03 06:51:42 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 6
2022/03/03 06:51:42 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 6
2022/03/03 06:51:42 DEBUG : nested/sub dir/file: crc32 = aac9c2e9 OK
2022/03/03 06:51:42 INFO  : nested/sub dir/file: Copied (new)
2022/03/03 06:51:42 INFO  : nested/sub dir/file: Deleted
2022/03/03 06:51:42 INFO  : sub dir: Removing directory
2022/03/03 06:51:42 INFO  : nested/sub dir: Removing directory
2022/03/03 06:51:42 INFO  : nested: Removing directory
2022/03/03 06:51:42 DEBUG : Local file system at /tmp/rclone1166303137: deleted 3 directories
--- PASS: TestMoveWithDeleteEmptySrcDirs (3.38s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:181: Remote "Putio root 'rclone-test-weziril0gixiked6lekobad7'", Local "Local file system at /tmp/rclone1166303137", Modify Window "1s"
2022/03/03 06:51:44 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for checks to finish
2022/03/03 06:51:44 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for transfers to finish
2022/03/03 06:51:45 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 11
2022/03/03 06:51:45 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 11
2022/03/03 06:51:45 DEBUG : sub dir/hello world: crc32 = 0d4a1185 OK
2022/03/03 06:51:45 INFO  : sub dir/hello world: Copied (new)
2022/03/03 06:51:45 INFO  : sub dir/hello world: Deleted
2022/03/03 06:51:45 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 6
2022/03/03 06:51:45 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 6
2022/03/03 06:51:46 DEBUG : nested/sub dir/file: crc32 = aac9c2e9 OK
2022/03/03 06:51:46 INFO  : nested/sub dir/file: Copied (new)
2022/03/03 06:51:46 INFO  : nested/sub dir/file: Deleted
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (4.09s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:181: Remote "Putio root 'rclone-test-weziril0gixiked6lekobad7'", Local "Local file system at /tmp/rclone1166303137", Modify Window "1s"
2022/03/03 06:51:48 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for checks to finish
2022/03/03 06:51:48 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for transfers to finish
2022/03/03 06:51:49 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 6
2022/03/03 06:51:49 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 6
2022/03/03 06:51:49 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 6
2022/03/03 06:51:49 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 6
2022/03/03 06:51:49 DEBUG : existing: crc32 = 9a941a19 OK
2022/03/03 06:51:49 INFO  : existing: Copied (new)
2022/03/03 06:51:49 INFO  : existing: Deleted
2022/03/03 06:51:49 DEBUG : existing-b: crc32 = 2c14401a OK
2022/03/03 06:51:49 INFO  : existing-b: Copied (new)
2022/03/03 06:51:49 INFO  : existing-b: Deleted
2022/03/03 06:51:49 DEBUG : existing: Destination exists, skipping
2022/03/03 06:51:49 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2022/03/03 06:51:49 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for checks to finish
2022/03/03 06:51:49 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Waiting for transfers to finish
2022/03/03 06:51:49 INFO  : There was nothing to transfer
--- PASS: TestMoveWithIgnoreExisting (1.75s)
=== RUN   TestServerSideMove
    run.go:181: Remote "Putio root 'rclone-test-weziril0gixiked6lekobad7'", Local "Local file system at /tmp/rclone1166303137", Modify Window "1s"
2022/03/03 06:51:50 DEBUG : Creating backend with remote "TestPutio:rclone-test-lonakoz9fuhujol4fumetug7"
2022/03/03 06:51:50 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 60
2022/03/03 06:51:50 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 60
2022/03/03 06:51:54 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 1
2022/03/03 06:51:54 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 1
2022/03/03 06:51:54 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 68
2022/03/03 06:51:54 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 68
    sync_test.go:1215: Server side move (if possible) Putio root 'rclone-test-weziril0gixiked6lekobad7' -> Putio root 'rclone-test-lonakoz9fuhujol4fumetug7'
2022/03/03 06:51:56 DEBUG : Putio root 'rclone-test-lonakoz9fuhujol4fumetug7': chunkStart: 0, reqSize: 1
2022/03/03 06:51:56 DEBUG : Putio root 'rclone-test-lonakoz9fuhujol4fumetug7': Sending chunk. transferOffset: 0 length: 1
2022/03/03 06:51:57 DEBUG : Putio root 'rclone-test-lonakoz9fuhujol4fumetug7': chunkStart: 0, reqSize: 60
2022/03/03 06:51:57 DEBUG : Putio root 'rclone-test-lonakoz9fuhujol4fumetug7': Sending chunk. transferOffset: 0 length: 60
2022/03/03 06:51:57 DEBUG : Putio root 'rclone-test-lonakoz9fuhujol4fumetug7': Using server-side directory move
2022/03/03 06:51:57 INFO  : Putio root 'rclone-test-lonakoz9fuhujol4fumetug7': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2022/03/03 06:51:57 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1s)
2022/03/03 06:51:57 DEBUG : empty space: Unchanged skipping
2022/03/03 06:51:57 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2022/03/03 06:51:57 DEBUG : Putio root 'rclone-test-lonakoz9fuhujol4fumetug7': Waiting for checks to finish
2022/03/03 06:51:57 INFO  : empty space: Deleted
2022/03/03 06:51:57 DEBUG : Putio root 'rclone-test-lonakoz9fuhujol4fumetug7': Waiting for transfers to finish
2022/03/03 06:51:57 INFO  : potato2: Moved (server-side)
2022/03/03 06:51:58 INFO  : potato3: Deleted
2022/03/03 06:51:58 INFO  : potato3: Moved (server-side)
2022/03/03 06:51:58 INFO  : There was nothing to transfer
2022/03/03 06:51:59 DEBUG : Creating backend with remote "TestPutio:rclone-test-febinuc6susuvuv5dumawas0"
2022/03/03 06:51:59 DEBUG : Putio root 'rclone-test-febinuc6susuvuv5dumawas0': Using server-side directory move
2022/03/03 06:51:59 INFO  : Putio root 'rclone-test-febinuc6susuvuv5dumawas0': Server side directory move succeeded
2022/03/03 06:51:59 ERROR : : error listing: directory not found
2022/03/03 06:51:59 DEBUG : Putio root 'rclone-test-febinuc6susuvuv5dumawas0': Purge remote
2022/03/03 06:51:59 DEBUG : Putio root 'rclone-test-lonakoz9fuhujol4fumetug7': Purge remote
2022/03/03 06:51:59 purge failed: Rmdir: directory not found
--- PASS: TestServerSideMove (9.69s)
=== RUN   TestServerSideMoveWithFilter
    run.go:181: Remote "Putio root 'rclone-test-weziril0gixiked6lekobad7'", Local "Local file system at /tmp/rclone1166303137", Modify Window "1s"
2022/03/03 06:52:00 DEBUG : Creating backend with remote "TestPutio:rclone-test-nagejet7wulocok1rumijox3"
2022/03/03 06:52:00 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 60
2022/03/03 06:52:00 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 60
2022/03/03 06:52:01 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 1
2022/03/03 06:52:01 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 1
2022/03/03 06:52:02 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 68
2022/03/03 06:52:02 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 68
    sync_test.go:1215: Server side move (if possible) Putio root 'rclone-test-weziril0gixiked6lekobad7' -> Putio root 'rclone-test-nagejet7wulocok1rumijox3'
2022/03/03 06:52:04 DEBUG : Putio root 'rclone-test-nagejet7wulocok1rumijox3': chunkStart: 0, reqSize: 1
2022/03/03 06:52:04 DEBUG : Putio root 'rclone-test-nagejet7wulocok1rumijox3': Sending chunk. transferOffset: 0 length: 1
2022/03/03 06:52:04 DEBUG : Putio root 'rclone-test-nagejet7wulocok1rumijox3': chunkStart: 0, reqSize: 60
2022/03/03 06:52:04 DEBUG : Putio root 'rclone-test-nagejet7wulocok1rumijox3': Sending chunk. transferOffset: 0 length: 60
2022/03/03 06:52:05 DEBUG : empty space: Excluded
2022/03/03 06:52:05 DEBUG : empty space: Excluded
2022/03/03 06:52:05 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2022/03/03 06:52:05 DEBUG : Putio root 'rclone-test-nagejet7wulocok1rumijox3': Waiting for checks to finish
2022/03/03 06:52:05 DEBUG : Putio root 'rclone-test-nagejet7wulocok1rumijox3': Waiting for transfers to finish
2022/03/03 06:52:05 INFO  : potato3: Deleted
2022/03/03 06:52:05 INFO  : potato2: Moved (server-side)
2022/03/03 06:52:05 INFO  : potato3: Moved (server-side)
2022/03/03 06:52:05 INFO  : There was nothing to transfer
2022/03/03 06:52:05 DEBUG : Creating backend with remote "TestPutio:rclone-test-soduliz1negaqub6nuhuray5"
2022/03/03 06:52:06 DEBUG : empty space: Excluded
2022/03/03 06:52:06 DEBUG : Putio root 'rclone-test-soduliz1negaqub6nuhuray5': Waiting for checks to finish
2022/03/03 06:52:06 DEBUG : Putio root 'rclone-test-soduliz1negaqub6nuhuray5': Waiting for transfers to finish
2022/03/03 06:52:06 INFO  : potato2: Moved (server-side)
2022/03/03 06:52:06 INFO  : potato3: Moved (server-side)
2022/03/03 06:52:06 INFO  : There was nothing to transfer
2022/03/03 06:52:06 DEBUG : Putio root 'rclone-test-soduliz1negaqub6nuhuray5': Purge remote
2022/03/03 06:52:06 DEBUG : Putio root 'rclone-test-nagejet7wulocok1rumijox3': Purge remote
--- PASS: TestServerSideMoveWithFilter (7.21s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:181: Remote "Putio root 'rclone-test-weziril0gixiked6lekobad7'", Local "Local file system at /tmp/rclone1166303137", Modify Window "1s"
2022/03/03 06:52:07 DEBUG : Creating backend with remote "TestPutio:rclone-test-walaniv6deredoy0yatazij2"
2022/03/03 06:52:07 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 60
2022/03/03 06:52:07 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 60
2022/03/03 06:52:10 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 1
2022/03/03 06:52:10 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 1
2022/03/03 06:52:11 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': chunkStart: 0, reqSize: 68
2022/03/03 06:52:11 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Sending chunk. transferOffset: 0 length: 68
2022/03/03 06:52:12 DEBUG : tomatoDir: Making directory
    sync_test.go:1215: Server side move (if possible) Putio root 'rclone-test-weziril0gixiked6lekobad7' -> Putio root 'rclone-test-walaniv6deredoy0yatazij2'
    run.go:287: Failed to put "empty space" to "Putio root 'rclone-test-walaniv6deredoy0yatazij2'": unexpected status code from upload create: 429
2022/03/03 06:52:12 DEBUG : Putio root 'rclone-test-walaniv6deredoy0yatazij2': Purge remote
--- FAIL: TestServerSideMoveDeleteEmptySourceDirs (6.62s)
=== RUN   TestSyncCopyDest
    run.go:181: Remote "Putio root 'rclone-test-weziril0gixiked6lekobad7'", Local "Local file system at /tmp/rclone1166303137", Modify Window "1s"
2022/03/03 06:52:13 DEBUG : Creating backend with remote "TestPutio:rclone-test-weziril0gixiked6lekobad7/dst"
2022/03/03 06:52:14 DEBUG : Creating backend with remote "TestPutio:rclone-test-weziril0gixiked6lekobad7/CopyDest"
2022/03/03 06:52:14 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7/dst': Waiting for checks to finish
2022/03/03 06:52:14 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7/dst': Waiting for transfers to finish
2022/03/03 06:52:14 ERROR : one: Failed to copy: unexpected status code from upload create: 429
2022/03/03 06:52:14 ERROR : Putio root 'rclone-test-weziril0gixiked6lekobad7/dst': not deleting files as there were IO errors
2022/03/03 06:52:14 ERROR : Putio root 'rclone-test-weziril0gixiked6lekobad7/dst': not deleting directories as there were IO errors
    sync_test.go:1615: 
        	Error Trace:	sync_test.go:1615
        	Error:      	Received unexpected error:
        	            	unexpected status code from upload create: 429
        	Test:       	TestSyncCopyDest
--- FAIL: TestSyncCopyDest (1.45s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:181: Remote "Putio root 'rclone-test-weziril0gixiked6lekobad7'", Local "Local file system at /tmp/rclone1166303137", Modify Window "1s"
    run.go:287: Failed to put "dst/one" to "Putio root 'rclone-test-weziril0gixiked6lekobad7'": unexpected status code from upload create: 429
--- FAIL: TestSyncBackupDirSuffixOnly (0.83s)
=== RUN   TestSyncConcurrentTruncate
    run.go:181: Remote "Putio root 'rclone-test-weziril0gixiked6lekobad7'", Local "Local file system at /tmp/rclone1166303137", Modify Window "1s"
    run.go:287: Failed to put "both0" to "Putio root 'rclone-test-weziril0gixiked6lekobad7'": unexpected status code from upload create: 429
--- FAIL: TestSyncConcurrentTruncate (0.50s)
FAIL
2022/03/03 06:52:16 DEBUG : Putio root 'rclone-test-weziril0gixiked6lekobad7': Purge remote
"./sync.test -test.v -test.timeout 2h0m0s -remote TestPutio: -verbose -test.run '^(TestMoveWithDeleteEmptySrcDirs|TestMoveWithIgnoreExisting|TestMoveWithoutDeleteEmptySrcDirs|TestServerSideCopy|TestServerSideMove|TestServerSideMoveDeleteEmptySourceDirs|TestServerSideMoveWithFilter|TestSyncBackupDirSuffixOnly|TestSyncConcurrentTruncate|TestSyncCopyDest|TestSyncWithTrackRenames|TestSyncWithTrackRenamesStrategyLeaf|TestSyncWithTrackRenamesStrategyModtime|TestSyncWithUpdateOlder)$'" - Finished ERROR in 57.622100674s (try 5/5): exit status 1: Failed [TestServerSideCopy TestSyncWithUpdateOlder TestServerSideMoveDeleteEmptySourceDirs TestSyncCopyDest TestSyncBackupDirSuffixOnly TestSyncConcurrentTruncate]