"./sync.test -test.v -test.timeout 2h0m0s -remote TestPutio: -verbose" - Starting (try 1/5)
2022/01/13 05:57:54 DEBUG : Creating backend with remote "TestPutio:rclone-test-vegocuq9liqayol6xigirew3"
2022/01/13 05:57:54 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2022/01/13 05:57:54 DEBUG : Creating backend with remote "/tmp/rclone857832132"
=== RUN   TestPipe
--- PASS: TestPipe (0.00s)
=== RUN   TestPipeConcurrent
--- PASS: TestPipeConcurrent (0.02s)
=== RUN   TestPipeOrderBy
=== RUN   TestPipeOrderBy/#00
=== RUN   TestPipeOrderBy/size
=== RUN   TestPipeOrderBy/name
=== RUN   TestPipeOrderBy/modtime
=== RUN   TestPipeOrderBy/size,ascending
=== RUN   TestPipeOrderBy/name,asc
=== RUN   TestPipeOrderBy/modtime,ascending
=== RUN   TestPipeOrderBy/size,descending
=== RUN   TestPipeOrderBy/name,desc
=== RUN   TestPipeOrderBy/modtime,descending
=== RUN   TestPipeOrderBy/size,mixed,50
=== RUN   TestPipeOrderBy/size,mixed,51
--- PASS: TestPipeOrderBy (0.00s)
    --- PASS: TestPipeOrderBy/#00 (0.00s)
    --- PASS: TestPipeOrderBy/size (0.00s)
    --- PASS: TestPipeOrderBy/name (0.00s)
    --- PASS: TestPipeOrderBy/modtime (0.00s)
    --- PASS: TestPipeOrderBy/size,ascending (0.00s)
    --- PASS: TestPipeOrderBy/name,asc (0.00s)
    --- PASS: TestPipeOrderBy/modtime,ascending (0.00s)
    --- PASS: TestPipeOrderBy/size,descending (0.00s)
    --- PASS: TestPipeOrderBy/name,desc (0.00s)
    --- PASS: TestPipeOrderBy/modtime,descending (0.00s)
    --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s)
    --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s)
=== RUN   TestNewLess
=== RUN   TestNewLess/blankOK
=== RUN   TestNewLess/tooManyParts
=== RUN   TestNewLess/tooManyParts2
=== RUN   TestNewLess/badMixed
=== RUN   TestNewLess/unknownComparison
=== RUN   TestNewLess/unknownSortDirection
=== RUN   TestNewLess/size
=== RUN   TestNewLess/name
=== RUN   TestNewLess/modtime
=== RUN   TestNewLess/size,ascending
=== RUN   TestNewLess/name,asc
=== RUN   TestNewLess/modtime,ascending
=== RUN   TestNewLess/size,descending
=== RUN   TestNewLess/name,desc
=== RUN   TestNewLess/modtime,descending
=== RUN   TestNewLess/modtime,mixed
=== RUN   TestNewLess/modtime,mixed,30
--- PASS: TestNewLess (0.00s)
    --- PASS: TestNewLess/blankOK (0.00s)
    --- PASS: TestNewLess/tooManyParts (0.00s)
    --- PASS: TestNewLess/tooManyParts2 (0.00s)
    --- PASS: TestNewLess/badMixed (0.00s)
    --- PASS: TestNewLess/unknownComparison (0.00s)
    --- PASS: TestNewLess/unknownSortDirection (0.00s)
    --- PASS: TestNewLess/size (0.00s)
    --- PASS: TestNewLess/name (0.00s)
    --- PASS: TestNewLess/modtime (0.00s)
    --- PASS: TestNewLess/size,ascending (0.00s)
    --- PASS: TestNewLess/name,asc (0.00s)
    --- PASS: TestNewLess/modtime,ascending (0.00s)
    --- PASS: TestNewLess/size,descending (0.00s)
    --- PASS: TestNewLess/name,desc (0.00s)
    --- PASS: TestNewLess/modtime,descending (0.00s)
    --- PASS: TestNewLess/modtime,mixed (0.00s)
    --- PASS: TestNewLess/modtime,mixed,30 (0.00s)
=== RUN   TestRcCopy
    rc_test.go:16: Skipping test on non local remote
--- SKIP: TestRcCopy (0.00s)
=== RUN   TestRcMove
    rc_test.go:16: Skipping test on non local remote
--- SKIP: TestRcMove (0.00s)
=== RUN   TestRcSync
    rc_test.go:16: Skipping test on non local remote
--- SKIP: TestRcSync (0.00s)
=== RUN   TestCopyWithDryRun
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:57:55 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:57:55 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:57:55 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
--- PASS: TestCopyWithDryRun (1.07s)
=== RUN   TestCopy
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:57:56 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:57:56 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:57:56 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 11
2022/01/13 05:57:56 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 11
2022/01/13 05:57:58 DEBUG : sub dir/hello world: crc32 = 0d4a1185 OK
2022/01/13 05:57:58 INFO  : sub dir/hello world: Copied (new)
--- PASS: TestCopy (3.56s)
=== RUN   TestCopyMissingDirectory
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:57:59 DEBUG : Creating backend with remote "/non-existing"
2022/01/13 05:57:59 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2022/01/13 05:57:59 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:57:59 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
--- PASS: TestCopyMissingDirectory (0.21s)
=== RUN   TestCopyNoTraverse
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:57:59 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:57:59 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:00 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 11
2022/01/13 05:58:00 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 11
2022/01/13 05:58:01 DEBUG : sub dir/hello world: crc32 = 0d4a1185 OK
2022/01/13 05:58:01 INFO  : sub dir/hello world: Copied (new)
--- PASS: TestCopyNoTraverse (2.28s)
=== RUN   TestCopyCheckFirst
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:01 INFO  : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Running all checks before starting transfers
2022/01/13 05:58:02 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:02 INFO  : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Checks finished, now starting transfers
2022/01/13 05:58:02 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:02 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 11
2022/01/13 05:58:02 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 11
2022/01/13 05:58:03 DEBUG : sub dir/hello world: crc32 = 0d4a1185 OK
2022/01/13 05:58:03 INFO  : sub dir/hello world: Copied (new)
--- PASS: TestCopyCheckFirst (2.30s)
=== RUN   TestSyncNoTraverse
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:04 ERROR : Ignoring --no-traverse with sync
2022/01/13 05:58:04 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:04 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:04 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 11
2022/01/13 05:58:04 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 11
2022/01/13 05:58:05 DEBUG : sub dir/hello world: crc32 = 0d4a1185 OK
2022/01/13 05:58:05 INFO  : sub dir/hello world: Copied (new)
2022/01/13 05:58:05 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncNoTraverse (2.12s)
=== RUN   TestCopyWithDepth
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:06 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:06 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:07 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 12
2022/01/13 05:58:07 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 12
2022/01/13 05:58:07 DEBUG : hello world2: crc32 = 870a83b3 OK
2022/01/13 05:58:07 INFO  : hello world2: Copied (new)
--- PASS: TestCopyWithDepth (1.86s)
=== RUN   TestCopyWithFilesFrom
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:08 DEBUG : hello world2: Excluded
2022/01/13 05:58:08 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:08 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:08 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 11
2022/01/13 05:58:08 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 11
2022/01/13 05:58:09 DEBUG : potato2: crc32 = 0d4a1185 OK
2022/01/13 05:58:09 INFO  : potato2: Copied (new)
--- PASS: TestCopyWithFilesFrom (1.65s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:09 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:09 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:10 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 11
2022/01/13 05:58:10 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 11
2022/01/13 05:58:11 DEBUG : potato2: crc32 = 0d4a1185 OK
2022/01/13 05:58:11 INFO  : potato2: Copied (new)
--- PASS: TestCopyWithFilesFromAndNoTraverse (1.50s)
=== RUN   TestCopyEmptyDirectories
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:11 DEBUG : sub dir2: Making directory
2022/01/13 05:58:11 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:11 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:12 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 11
2022/01/13 05:58:12 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 11
2022/01/13 05:58:14 DEBUG : sub dir/hello world: crc32 = 0d4a1185 OK
2022/01/13 05:58:14 INFO  : sub dir/hello world: Copied (new)
2022/01/13 05:58:14 DEBUG : sub dir2: Making directory
2022/01/13 05:58:14 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': copied 1 directories
--- PASS: TestCopyEmptyDirectories (3.71s)
=== RUN   TestMoveEmptyDirectories
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:15 DEBUG : sub dir2: Making directory
2022/01/13 05:58:15 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:15 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:15 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 11
2022/01/13 05:58:15 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 11
2022/01/13 05:58:16 DEBUG : sub dir/hello world: crc32 = 0d4a1185 OK
2022/01/13 05:58:16 INFO  : sub dir/hello world: Copied (new)
2022/01/13 05:58:16 INFO  : sub dir/hello world: Deleted
2022/01/13 05:58:16 DEBUG : sub dir: Making directory
2022/01/13 05:58:16 DEBUG : sub dir2: Making directory
2022/01/13 05:58:16 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': copied 2 directories
--- PASS: TestMoveEmptyDirectories (2.60s)
=== RUN   TestSyncEmptyDirectories
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:17 DEBUG : sub dir2: Making directory
2022/01/13 05:58:17 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:17 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:18 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 11
2022/01/13 05:58:18 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 11
2022/01/13 05:58:18 DEBUG : sub dir/hello world: crc32 = 0d4a1185 OK
2022/01/13 05:58:18 INFO  : sub dir/hello world: Copied (new)
2022/01/13 05:58:18 DEBUG : sub dir2: Making directory
2022/01/13 05:58:19 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': copied 1 directories
2022/01/13 05:58:19 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncEmptyDirectories (2.70s)
=== RUN   TestServerSideCopy
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:21 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 11
2022/01/13 05:58:21 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 11
2022/01/13 05:58:22 DEBUG : Creating backend with remote "TestPutio:rclone-test-bataqiz3daquqim6wovufaz9"
    sync_test.go:275: Server side copy (if possible) Putio root 'rclone-test-vegocuq9liqayol6xigirew3' -> Putio root 'rclone-test-bataqiz3daquqim6wovufaz9'
2022/01/13 05:58:22 DEBUG : Putio root 'rclone-test-bataqiz3daquqim6wovufaz9': Waiting for checks to finish
2022/01/13 05:58:22 DEBUG : Putio root 'rclone-test-bataqiz3daquqim6wovufaz9': Waiting for transfers to finish
2022/01/13 05:58: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/01/13 05:58:22 DEBUG : Putio root 'rclone-test-bataqiz3daquqim6wovufaz9': Purge remote
--- FAIL: TestServerSideCopy (3.23s)
=== RUN   TestCopyAfterDelete
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:24 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 11
2022/01/13 05:58:24 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 11
2022/01/13 05:58:25 ERROR : : error listing: directory not found
2022/01/13 05:58:25 DEBUG : Local file system at /tmp/rclone857832132: Making directory
2022/01/13 05:58:25 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:25 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
--- PASS: TestCopyAfterDelete (2.40s)
=== RUN   TestCopyRedownload
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:26 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 11
2022/01/13 05:58:26 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 11
2022/01/13 05:58:27 DEBUG : Local file system at /tmp/rclone857832132: Waiting for checks to finish
2022/01/13 05:58:27 DEBUG : Local file system at /tmp/rclone857832132: Waiting for transfers to finish
2022/01/13 05:58:27 DEBUG : sub dir/hello world: crc32 = 0d4a1185 OK
2022/01/13 05:58:27 INFO  : sub dir/hello world: Copied (new)
--- PASS: TestCopyRedownload (2.48s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:28 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:28 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:29 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 1
2022/01/13 05:58:29 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 1
2022/01/13 05:58:29 DEBUG : check sum: crc32 = 97ddb3f8 OK
2022/01/13 05:58:29 INFO  : check sum: Copied (new)
2022/01/13 05:58:29 DEBUG : Waiting for deletions to finish
2022/01/13 05:58:29 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:29 DEBUG : check sum: crc32 = 97ddb3f8 OK
2022/01/13 05:58:29 DEBUG : check sum: Size and crc32 of src and dst objects identical
2022/01/13 05:58:29 DEBUG : check sum: Unchanged skipping
2022/01/13 05:58:29 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:29 DEBUG : Waiting for deletions to finish
2022/01/13 05:58:29 INFO  : There was nothing to transfer
--- PASS: TestSyncBasedOnCheckSum (1.75s)
=== RUN   TestSyncSizeOnly
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:30 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:30 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:30 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 05:58:30 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 05:58:33 DEBUG : sizeonly: crc32 = 9a941a19 OK
2022/01/13 05:58:33 INFO  : sizeonly: Copied (new)
2022/01/13 05:58:33 DEBUG : Waiting for deletions to finish
2022/01/13 05:58:33 DEBUG : sizeonly: Sizes identical
2022/01/13 05:58:33 DEBUG : sizeonly: Unchanged skipping
2022/01/13 05:58:33 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:33 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:33 DEBUG : Waiting for deletions to finish
2022/01/13 05:58:33 INFO  : There was nothing to transfer
--- PASS: TestSyncSizeOnly (3.55s)
=== RUN   TestSyncIgnoreSize
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:33 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:33 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:34 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 8
2022/01/13 05:58:34 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 8
2022/01/13 05:58:34 DEBUG : ignore-size: crc32 = b4fa1177 OK
2022/01/13 05:58:34 INFO  : ignore-size: Copied (new)
2022/01/13 05:58:34 DEBUG : Waiting for deletions to finish
2022/01/13 05:58:35 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:35 DEBUG : ignore-size: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 05:58:35 DEBUG : ignore-size: Unchanged skipping
2022/01/13 05:58:35 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:35 DEBUG : Waiting for deletions to finish
2022/01/13 05:58:35 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreSize (1.53s)
=== RUN   TestSyncIgnoreTimes
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:35 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 05:58:35 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 05:58:36 DEBUG : existing: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 05:58:36 DEBUG : existing: Unchanged skipping
2022/01/13 05:58:36 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:36 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:36 DEBUG : Waiting for deletions to finish
2022/01/13 05:58:36 INFO  : There was nothing to transfer
2022/01/13 05:58:36 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2022/01/13 05:58:36 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:36 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:37 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 05:58:37 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 05:58:38 DEBUG : existing: crc32 = 9a941a19 OK
2022/01/13 05:58:38 INFO  : existing: Copied (replaced existing)
2022/01/13 05:58:38 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncIgnoreTimes (3.28s)
=== RUN   TestSyncIgnoreExisting
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:38 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:38 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:39 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 05:58:39 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 05:58:39 DEBUG : existing: crc32 = 9a941a19 OK
2022/01/13 05:58:39 INFO  : existing: Copied (new)
2022/01/13 05:58:39 DEBUG : Waiting for deletions to finish
2022/01/13 05:58:40 DEBUG : existing: Destination exists, skipping
2022/01/13 05:58:40 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:40 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:40 DEBUG : Waiting for deletions to finish
2022/01/13 05:58:40 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreExisting (1.82s)
=== RUN   TestSyncIgnoreErrors
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:41 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 21
2022/01/13 05:58:41 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 21
2022/01/13 05:58:42 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 5
2022/01/13 05:58:42 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 5
2022/01/13 05:58:43 DEBUG : d: Making directory
2022/01/13 05:58:43 DEBUG : c/non empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2022/01/13 05:58:43 DEBUG : c/non empty space: Unchanged skipping
2022/01/13 05:58:44 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:44 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:44 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 60
2022/01/13 05:58:44 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 60
2022/01/13 05:58:44 DEBUG : a/potato2: crc32 = d423bfba OK
2022/01/13 05:58:44 INFO  : a/potato2: Copied (new)
2022/01/13 05:58:44 DEBUG : Waiting for deletions to finish
2022/01/13 05:58:44 INFO  : b/potato: Deleted
2022/01/13 05:58:44 INFO  : d: Removing directory
2022/01/13 05:58:45 INFO  : b: Removing directory
2022/01/13 05:58:45 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': deleted 2 directories
--- PASS: TestSyncIgnoreErrors (5.92s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:47 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 1
2022/01/13 05:58:47 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 1
2022/01/13 05:58:47 DEBUG : empty space: Modification times differ by -95456h54m53.123456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06 +0000 UTC
2022/01/13 05:58:47 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:47 DEBUG : empty space: crc32 = 97ddb3f8 OK
2022/01/13 05:58:47 NOTICE: empty space: Skipped update modification time as --dry-run is set (size 1)
2022/01/13 05:58:47 DEBUG : empty space: Unchanged skipping
2022/01/13 05:58:47 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:47 DEBUG : Waiting for deletions to finish
2022/01/13 05:58:47 INFO  : There was nothing to transfer
2022/01/13 05:58:48 DEBUG : empty space: Modification times differ by -95456h54m53.123456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06 +0000 UTC
2022/01/13 05:58:48 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:48 DEBUG : empty space: crc32 = 97ddb3f8 OK
2022/01/13 05:58:48 INFO  : empty space: Updated modification time in destination
2022/01/13 05:58:48 DEBUG : empty space: Unchanged skipping
2022/01/13 05:58:48 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:48 DEBUG : Waiting for deletions to finish
2022/01/13 05:58:48 INFO  : There was nothing to transfer
--- PASS: TestSyncAfterChangingModtimeOnly (2.02s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:48 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 1
2022/01/13 05:58:48 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 1
2022/01/13 05:58:49 DEBUG : empty space: Modification times differ by -95456h54m53.123456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06 +0000 UTC
2022/01/13 05:58:49 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:49 DEBUG : empty space: crc32 = 97ddb3f8 OK
2022/01/13 05:58:49 DEBUG : empty space: Unchanged skipping
2022/01/13 05:58:49 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:49 DEBUG : Waiting for deletions to finish
2022/01/13 05:58:49 INFO  : There was nothing to transfer
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (1.57s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:50 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 3
2022/01/13 05:58:50 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 3
2022/01/13 05:58:51 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:51 DEBUG : foo: Modification times differ by -95456h54m53.123456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06 +0000 UTC
2022/01/13 05:58:51 DEBUG : foo: crc32 = 8c736521 (Local file system at /tmp/rclone857832132)
2022/01/13 05:58:51 DEBUG : foo: crc32 = 76ff8caa (Putio root 'rclone-test-vegocuq9liqayol6xigirew3')
2022/01/13 05:58:51 DEBUG : foo: crc32 differ
2022/01/13 05:58:51 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:51 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 3
2022/01/13 05:58:51 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 3
2022/01/13 05:58:52 DEBUG : foo: crc32 = 8c736521 OK
2022/01/13 05:58:52 INFO  : foo: Copied (replaced existing)
2022/01/13 05:58:52 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncDoesntUpdateModtime (2.76s)
=== RUN   TestSyncAfterAddingAFile
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:53 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 1
2022/01/13 05:58:53 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 1
2022/01/13 05:58:53 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:53 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2022/01/13 05:58:53 DEBUG : empty space: Unchanged skipping
2022/01/13 05:58:53 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:54 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 60
2022/01/13 05:58:54 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 60
2022/01/13 05:58:54 DEBUG : potato: crc32 = d423bfba OK
2022/01/13 05:58:54 INFO  : potato: Copied (new)
2022/01/13 05:58:54 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncAfterAddingAFile (2.67s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:55 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 60
2022/01/13 05:58:55 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 60
2022/01/13 05:58:56 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2022/01/13 05:58:56 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:56 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:58:57 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 21
2022/01/13 05:58:57 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 21
2022/01/13 05:58:58 DEBUG : potato: crc32 = f4498cc3 OK
2022/01/13 05:58:58 INFO  : potato: Copied (replaced existing)
2022/01/13 05:58:58 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncAfterChangingFilesSizeOnly (3.22s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:58:58 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 21
2022/01/13 05:58:58 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 21
2022/01/13 05:58:59 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC
2022/01/13 05:58:59 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:58:59 DEBUG : potato: crc32 = 1b366e1c (Local file system at /tmp/rclone857832132)
2022/01/13 05:58:59 DEBUG : potato: crc32 = f4498cc3 (Putio root 'rclone-test-vegocuq9liqayol6xigirew3')
2022/01/13 05:58:59 DEBUG : potato: crc32 differ
2022/01/13 05:58:59 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:59:00 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 21
2022/01/13 05:59:00 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 21
2022/01/13 05:59:01 DEBUG : potato: crc32 = 1b366e1c OK
2022/01/13 05:59:01 INFO  : potato: Copied (replaced existing)
2022/01/13 05:59:01 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncAfterChangingContentsOnly (2.76s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:59:01 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 21
2022/01/13 05:59:01 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 21
2022/01/13 05:59:02 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 1
2022/01/13 05:59:02 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 1
2022/01/13 05:59:03 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2022/01/13 05:59:03 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2022/01/13 05:59:03 DEBUG : empty space: Unchanged skipping
2022/01/13 05:59:03 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:59:03 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:59:03 DEBUG : Waiting for deletions to finish
2022/01/13 05:59:03 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (2.81s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:59:04 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 21
2022/01/13 05:59:04 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 21
2022/01/13 05:59:05 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 1
2022/01/13 05:59:05 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 1
2022/01/13 05:59:06 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2022/01/13 05:59:06 DEBUG : empty space: Unchanged skipping
2022/01/13 05:59:06 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:59:06 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:59:06 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 60
2022/01/13 05:59:06 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 60
2022/01/13 05:59:09 DEBUG : potato2: crc32 = d423bfba OK
2022/01/13 05:59:09 INFO  : potato2: Copied (new)
2022/01/13 05:59:09 DEBUG : Waiting for deletions to finish
2022/01/13 05:59:09 INFO  : potato: Deleted
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (5.66s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:59:10 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 21
2022/01/13 05:59:10 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 21
2022/01/13 05:59:11 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 5
2022/01/13 05:59:11 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 5
2022/01/13 05:59:12 DEBUG : d: Making directory
2022/01/13 05:59:12 DEBUG : d/e: Making directory
2022/01/13 05:59:13 DEBUG : c/non empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2022/01/13 05:59:13 DEBUG : c/non empty space: Unchanged skipping
2022/01/13 05:59:13 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:59:13 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:59:13 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 60
2022/01/13 05:59:13 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 60
2022/01/13 05:59:14 DEBUG : a/potato2: crc32 = d423bfba OK
2022/01/13 05:59:14 INFO  : a/potato2: Copied (new)
2022/01/13 05:59:14 DEBUG : Waiting for deletions to finish
2022/01/13 05:59:14 INFO  : b/potato: Deleted
2022/01/13 05:59:14 INFO  : d/e: Removing directory
2022/01/13 05:59:14 INFO  : d: Removing directory
2022/01/13 05:59:14 INFO  : b: Removing directory
2022/01/13 05:59:15 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': deleted 3 directories
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (6.32s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:59:16 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 21
2022/01/13 05:59:16 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 21
2022/01/13 05:59:18 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 5
2022/01/13 05:59:18 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 5
2022/01/13 05:59:18 DEBUG : d: Making directory
2022/01/13 05:59:19 DEBUG : c/non empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2022/01/13 05:59:19 DEBUG : c/non empty space: Unchanged skipping
2022/01/13 05:59:19 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:59:19 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:59:19 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 60
2022/01/13 05:59:19 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 60
2022/01/13 05:59:20 DEBUG : a/potato2: crc32 = d423bfba OK
2022/01/13 05:59:20 INFO  : a/potato2: Copied (new)
2022/01/13 05:59:20 ERROR : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': not deleting files as there were IO errors
2022/01/13 05:59:20 ERROR : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': not deleting directories as there were IO errors
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (5.86s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:59:22 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 21
2022/01/13 05:59:22 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 21
2022/01/13 05:59:23 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 1
2022/01/13 05:59:23 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 1
2022/01/13 05:59:24 DEBUG : Waiting for deletions to finish
2022/01/13 05:59:24 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2022/01/13 05:59:24 DEBUG : empty space: Unchanged skipping
2022/01/13 05:59:24 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:59:24 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:59:24 INFO  : potato: Deleted
2022/01/13 05:59:24 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 60
2022/01/13 05:59:24 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 60
2022/01/13 05:59:25 DEBUG : potato2: crc32 = d423bfba OK
2022/01/13 05:59:25 INFO  : potato2: Copied (new)
--- PASS: TestSyncDeleteDuring (4.03s)
=== RUN   TestSyncDeleteBefore
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:59:26 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 21
2022/01/13 05:59:26 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 21
2022/01/13 05:59:27 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 1
2022/01/13 05:59:27 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 1
2022/01/13 05:59:28 DEBUG : Waiting for deletions to finish
2022/01/13 05:59:28 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:59:28 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:59:28 INFO  : potato: Deleted
2022/01/13 05:59:28 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2022/01/13 05:59:28 DEBUG : empty space: Unchanged skipping
2022/01/13 05:59:28 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:59:28 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:59:29 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 60
2022/01/13 05:59:29 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 60
2022/01/13 05:59:29 DEBUG : potato2: crc32 = d423bfba OK
2022/01/13 05:59:29 INFO  : potato2: Copied (new)
--- PASS: TestSyncDeleteBefore (4.06s)
=== RUN   TestCopyDeleteBefore
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:59:30 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 21
2022/01/13 05:59:30 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 21
2022/01/13 05:59:31 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:59:31 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:59:31 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 19
2022/01/13 05:59:31 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 19
2022/01/13 05:59:32 DEBUG : potato2: crc32 = 9f4e1e48 OK
2022/01/13 05:59:32 INFO  : potato2: Copied (new)
--- PASS: TestCopyDeleteBefore (2.71s)
=== RUN   TestSyncWithExclude
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:59:33 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 60
2022/01/13 05:59:33 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 60
2022/01/13 05:59:34 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 1
2022/01/13 05:59:34 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 1
2022/01/13 05:59:34 DEBUG : enormous: Excluded
2022/01/13 05:59:34 DEBUG : potato2: Excluded
2022/01/13 05:59:34 DEBUG : potato2: Excluded
2022/01/13 05:59:34 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2022/01/13 05:59:34 DEBUG : empty space: Unchanged skipping
2022/01/13 05:59:34 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:59:34 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:59:34 DEBUG : Waiting for deletions to finish
2022/01/13 05:59:34 INFO  : There was nothing to transfer
2022/01/13 05:59:34 DEBUG : enormous: Excluded
2022/01/13 05:59:34 DEBUG : potato2: Excluded
2022/01/13 05:59:35 DEBUG : potato2: Excluded
2022/01/13 05:59:35 DEBUG : empty space: Size and modification time the same (differ by 123.456789ms, within tolerance 1s)
2022/01/13 05:59:35 DEBUG : empty space: Unchanged skipping
2022/01/13 05:59:35 DEBUG : Local file system at /tmp/rclone857832132: Waiting for checks to finish
2022/01/13 05:59:35 DEBUG : Local file system at /tmp/rclone857832132: Waiting for transfers to finish
2022/01/13 05:59:35 DEBUG : Waiting for deletions to finish
2022/01/13 05:59:35 INFO  : There was nothing to transfer
--- PASS: TestSyncWithExclude (2.61s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:59:36 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 60
2022/01/13 05:59:36 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 60
2022/01/13 05:59:37 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 1
2022/01/13 05:59:37 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 1
2022/01/13 05:59:38 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 100
2022/01/13 05:59:38 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 100
2022/01/13 05:59:38 DEBUG : enormous: Excluded
2022/01/13 05:59:38 DEBUG : potato2: Excluded
2022/01/13 05:59:38 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:59:38 DEBUG : empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2022/01/13 05:59:38 DEBUG : empty space: Unchanged skipping
2022/01/13 05:59:38 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:59:38 DEBUG : Waiting for deletions to finish
2022/01/13 05:59:38 INFO  : enormous: Deleted
2022/01/13 05:59:40 INFO  : potato2: Deleted
2022/01/13 05:59:40 INFO  : There was nothing to transfer
2022/01/13 05:59:40 DEBUG : Local file system at /tmp/rclone857832132: Waiting for checks to finish
2022/01/13 05:59:40 DEBUG : empty space: Size and modification time the same (differ by 123.456789ms, within tolerance 1s)
2022/01/13 05:59:40 DEBUG : empty space: Unchanged skipping
2022/01/13 05:59:40 DEBUG : Local file system at /tmp/rclone857832132: Waiting for transfers to finish
2022/01/13 05:59:40 DEBUG : Waiting for deletions to finish
2022/01/13 05:59:40 INFO  : enormous: Deleted
2022/01/13 05:59:40 INFO  : potato2: Deleted
2022/01/13 05:59:40 INFO  : There was nothing to transfer
--- PASS: TestSyncWithExcludeAndDeleteExcluded (4.96s)
=== RUN   TestSyncWithUpdateOlder
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:59:40 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 3
2022/01/13 05:59:40 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 3
2022/01/13 05:59:41 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 3
2022/01/13 05:59:41 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 3
2022/01/13 05:59:42 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 5
2022/01/13 05:59:42 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 5
2022/01/13 05:59:43 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 8
2022/01/13 05:59:43 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 8
2022/01/13 05:59:44 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:59:44 DEBUG : four: Sizes differ (src 4 vs dst 8)
2022/01/13 05:59:44 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2022/01/13 05:59:44 DEBUG : one: Destination is newer than source, skipping
2022/01/13 05:59:44 DEBUG : three: Sizes identical
2022/01/13 05:59:44 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2022/01/13 05:59:44 DEBUG : two: crc32 = 11ca8a66 (Local file system at /tmp/rclone857832132)
2022/01/13 05:59:44 DEBUG : two: crc32 = 876dc8ec (Putio root 'rclone-test-vegocuq9liqayol6xigirew3')
2022/01/13 05:59:44 DEBUG : two: crc32 differ
2022/01/13 05:59:44 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:59:44 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 4
2022/01/13 05:59:44 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 4
2022/01/13 05:59:44 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 4
2022/01/13 05:59:44 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 4
2022/01/13 05:59:45 DEBUG : five: crc32 = 3cb2cccb OK
2022/01/13 05:59:45 INFO  : five: Copied (new)
2022/01/13 05:59:45 DEBUG : four: crc32 = 90c1667d OK
2022/01/13 05:59:45 INFO  : four: Copied (replaced existing)
2022/01/13 05:59:45 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 3
2022/01/13 05:59:45 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 3
2022/01/13 05:59:48 DEBUG : two: crc32 = 11ca8a66 OK
2022/01/13 05:59:48 INFO  : two: Copied (replaced existing)
2022/01/13 05:59:48 DEBUG : Waiting for deletions to finish
2022/01/13 05:59:48 DEBUG : one: Destination is newer than source, skipping
2022/01/13 05:59:48 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:59:48 DEBUG : five: crc32 = 3cb2cccb OK
2022/01/13 05:59:48 DEBUG : five: Size and crc32 of src and dst objects identical
2022/01/13 05:59:48 DEBUG : five: Destination mod time is within 1s of source and files identical, skipping
2022/01/13 05:59:48 DEBUG : two: crc32 = 11ca8a66 OK
2022/01/13 05:59:48 DEBUG : two: Size and crc32 of src and dst objects identical
2022/01/13 05:59:48 DEBUG : two: Destination mod time is within 1s of source and files identical, skipping
2022/01/13 05:59:48 DEBUG : three: crc32 = 46c5d8f5 (Local file system at /tmp/rclone857832132)
2022/01/13 05:59:48 DEBUG : three: crc32 = b1911a45 (Putio root 'rclone-test-vegocuq9liqayol6xigirew3')
2022/01/13 05:59:48 DEBUG : three: crc32 differ
2022/01/13 05:59:48 DEBUG : three: Destination mod time is within 1s of source but files differ, transferring
2022/01/13 05:59:48 DEBUG : four: crc32 = 90c1667d OK
2022/01/13 05:59:48 DEBUG : four: Size and crc32 of src and dst objects identical
2022/01/13 05:59:48 DEBUG : four: Destination mod time is within 1s of source and files identical, skipping
2022/01/13 05:59:48 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:59:49 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 5
2022/01/13 05:59:49 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 5
2022/01/13 05:59:49 DEBUG : three: crc32 = 46c5d8f5 OK
2022/01/13 05:59:49 INFO  : three: Copied (replaced existing)
2022/01/13 05:59:49 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncWithUpdateOlder (10.26s)
=== RUN   TestSyncWithMaxDuration
    sync_test.go:1009: Skipping test on non local remote
--- SKIP: TestSyncWithMaxDuration (0.00s)
=== RUN   TestSyncWithTrackRenames
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
    sync_test.go:1058: Can track renames: true
2022/01/13 05:59:50 INFO  : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Making map for --track-renames
2022/01/13 05:59:50 INFO  : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Finished making map for --track-renames
2022/01/13 05:59:50 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:59:50 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for renames to finish
2022/01/13 05:59:50 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:59:51 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 14
2022/01/13 05:59:51 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 14
2022/01/13 05:59:51 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 11
2022/01/13 05:59:51 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 11
2022/01/13 05:59:51 DEBUG : potato: crc32 = 403f91c8 OK
2022/01/13 05:59:51 INFO  : potato: Copied (new)
2022/01/13 05:59:51 DEBUG : yam: crc32 = ae1fefed OK
2022/01/13 05:59:51 INFO  : yam: Copied (new)
2022/01/13 05:59:51 DEBUG : Waiting for deletions to finish
2022/01/13 05:59:51 DEBUG : potato: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 05:59:51 DEBUG : potato: Unchanged skipping
2022/01/13 05:59:51 INFO  : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Making map for --track-renames
2022/01/13 05:59:51 INFO  : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Finished making map for --track-renames
2022/01/13 05:59:51 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:59:51 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for renames to finish
2022/01/13 05:59:52 INFO  : yam: Moved (server-side) to: yaml
2022/01/13 05:59:52 INFO  : yaml: Renamed from "yam"
2022/01/13 05:59:52 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:59:52 DEBUG : Waiting for deletions to finish
2022/01/13 05:59:52 INFO  : There was nothing to transfer
--- PASS: TestSyncWithTrackRenames (2.01s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
    sync_test.go:1127: Can track renames: true
2022/01/13 05:59:52 INFO  : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Making map for --track-renames
2022/01/13 05:59:52 INFO  : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Finished making map for --track-renames
2022/01/13 05:59:52 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:59:52 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for renames to finish
2022/01/13 05:59:52 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:59:53 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 14
2022/01/13 05:59:53 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 14
2022/01/13 05:59:53 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 11
2022/01/13 05:59:53 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 11
2022/01/13 05:59:53 DEBUG : potato: crc32 = 403f91c8 OK
2022/01/13 05:59:53 INFO  : potato: Copied (new)
2022/01/13 05:59:53 DEBUG : yam: crc32 = ae1fefed OK
2022/01/13 05:59:53 INFO  : yam: Copied (new)
2022/01/13 05:59:53 DEBUG : Waiting for deletions to finish
2022/01/13 05:59:54 DEBUG : potato: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 05:59:54 DEBUG : potato: Unchanged skipping
2022/01/13 05:59:54 INFO  : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Making map for --track-renames
2022/01/13 05:59:54 INFO  : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Finished making map for --track-renames
2022/01/13 05:59:54 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:59:54 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for renames to finish
2022/01/13 05:59:54 INFO  : yam: Moved (server-side) to: yaml
2022/01/13 05:59:54 INFO  : yaml: Renamed from "yam"
2022/01/13 05:59:54 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:59:54 DEBUG : Waiting for deletions to finish
2022/01/13 05:59:54 INFO  : There was nothing to transfer
--- PASS: TestSyncWithTrackRenamesStrategyModtime (2.21s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
    sync_test.go:1163: Can track renames: true
2022/01/13 05:59:54 INFO  : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Making map for --track-renames
2022/01/13 05:59:54 INFO  : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Finished making map for --track-renames
2022/01/13 05:59:54 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:59:54 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for renames to finish
2022/01/13 05:59:54 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:59:55 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 11
2022/01/13 05:59:55 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 11
2022/01/13 05:59:55 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 14
2022/01/13 05:59:55 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 14
2022/01/13 05:59:56 DEBUG : sub/yam: crc32 = ae1fefed OK
2022/01/13 05:59:56 INFO  : sub/yam: Copied (new)
2022/01/13 05:59:56 DEBUG : potato: crc32 = 403f91c8 OK
2022/01/13 05:59:56 INFO  : potato: Copied (new)
2022/01/13 05:59:56 DEBUG : Waiting for deletions to finish
2022/01/13 05:59:56 DEBUG : potato: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 05:59:56 DEBUG : potato: Unchanged skipping
2022/01/13 05:59:56 INFO  : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Making map for --track-renames
2022/01/13 05:59:56 INFO  : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Finished making map for --track-renames
2022/01/13 05:59:56 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:59:56 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for renames to finish
2022/01/13 05:59:56 INFO  : sub/yam: Moved (server-side) to: yam
2022/01/13 05:59:56 INFO  : yam: Renamed from "sub/yam"
2022/01/13 05:59:56 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:59:56 DEBUG : Waiting for deletions to finish
2022/01/13 05:59:56 INFO  : There was nothing to transfer
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (2.65s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 05:59:57 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 05:59:57 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 05:59:58 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 11
2022/01/13 05:59:58 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 11
2022/01/13 05:59:58 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 05:59:58 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 05:59:58 DEBUG : sub dir/hello world: crc32 = 0d4a1185 OK
2022/01/13 05:59:58 INFO  : sub dir/hello world: Copied (new)
2022/01/13 05:59:58 INFO  : sub dir/hello world: Deleted
2022/01/13 06:00:00 DEBUG : nested/sub dir/file: crc32 = aac9c2e9 OK
2022/01/13 06:00:00 INFO  : nested/sub dir/file: Copied (new)
2022/01/13 06:00:00 INFO  : nested/sub dir/file: Deleted
2022/01/13 06:00:00 INFO  : sub dir: Removing directory
2022/01/13 06:00:00 INFO  : nested/sub dir: Removing directory
2022/01/13 06:00:00 INFO  : nested: Removing directory
2022/01/13 06:00:00 DEBUG : Local file system at /tmp/rclone857832132: deleted 3 directories
--- PASS: TestMoveWithDeleteEmptySrcDirs (4.61s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 06:00:02 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 06:00:02 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 06:00:02 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 11
2022/01/13 06:00:02 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 11
2022/01/13 06:00:03 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:00:03 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:00:04 DEBUG : sub dir/hello world: crc32 = 0d4a1185 OK
2022/01/13 06:00:04 INFO  : sub dir/hello world: Copied (new)
2022/01/13 06:00:04 INFO  : sub dir/hello world: Deleted
2022/01/13 06:00:04 DEBUG : nested/sub dir/file: crc32 = aac9c2e9 OK
2022/01/13 06:00:04 INFO  : nested/sub dir/file: Copied (new)
2022/01/13 06:00:04 INFO  : nested/sub dir/file: Deleted
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (4.16s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 06:00:06 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 06:00:06 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 06:00:06 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:00:06 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:00:06 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:00:06 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:00:07 DEBUG : existing-b: crc32 = 2c14401a OK
2022/01/13 06:00:07 INFO  : existing-b: Copied (new)
2022/01/13 06:00:07 INFO  : existing-b: Deleted
2022/01/13 06:00:07 DEBUG : existing: crc32 = 9a941a19 OK
2022/01/13 06:00:07 INFO  : existing: Copied (new)
2022/01/13 06:00:07 INFO  : existing: Deleted
2022/01/13 06:00:08 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 06:00:08 DEBUG : existing: Destination exists, skipping
2022/01/13 06:00:08 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2022/01/13 06:00:08 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 06:00:08 INFO  : There was nothing to transfer
--- PASS: TestMoveWithIgnoreExisting (2.21s)
=== RUN   TestServerSideMove
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 06:00:08 DEBUG : Creating backend with remote "TestPutio:rclone-test-loyojol1juhonas8lulidod2"
2022/01/13 06:00:09 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 60
2022/01/13 06:00:09 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 60
2022/01/13 06:00:10 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 1
2022/01/13 06:00:10 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 1
2022/01/13 06:00:11 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 68
2022/01/13 06:00:11 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 68
    sync_test.go:1215: Server side move (if possible) Putio root 'rclone-test-vegocuq9liqayol6xigirew3' -> Putio root 'rclone-test-loyojol1juhonas8lulidod2'
2022/01/13 06:00:12 DEBUG : Putio root 'rclone-test-loyojol1juhonas8lulidod2': chunkStart: 0, reqSize: 1
2022/01/13 06:00:12 DEBUG : Putio root 'rclone-test-loyojol1juhonas8lulidod2': Sending chunk. transferOffset: 0 length: 1
2022/01/13 06:00:13 DEBUG : Putio root 'rclone-test-loyojol1juhonas8lulidod2': chunkStart: 0, reqSize: 60
2022/01/13 06:00:13 DEBUG : Putio root 'rclone-test-loyojol1juhonas8lulidod2': Sending chunk. transferOffset: 0 length: 60
2022/01/13 06:00:14 DEBUG : Putio root 'rclone-test-loyojol1juhonas8lulidod2': Using server-side directory move
2022/01/13 06:00:14 INFO  : Putio root 'rclone-test-loyojol1juhonas8lulidod2': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2022/01/13 06:00:14 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1s)
2022/01/13 06:00:14 DEBUG : empty space: Unchanged skipping
2022/01/13 06:00:14 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2022/01/13 06:00:14 DEBUG : Putio root 'rclone-test-loyojol1juhonas8lulidod2': Waiting for checks to finish
2022/01/13 06:00:14 INFO  : potato3: Deleted
2022/01/13 06:00:15 INFO  : potato2: Moved (server-side)
2022/01/13 06:00:15 INFO  : potato3: Moved (server-side)
2022/01/13 06:00:15 INFO  : empty space: Deleted
2022/01/13 06:00:15 DEBUG : Putio root 'rclone-test-loyojol1juhonas8lulidod2': Waiting for transfers to finish
2022/01/13 06:00:15 INFO  : There was nothing to transfer
2022/01/13 06:00:16 DEBUG : Creating backend with remote "TestPutio:rclone-test-yenayeb5vuwegas1zefejot7"
2022/01/13 06:00:16 DEBUG : Putio root 'rclone-test-yenayeb5vuwegas1zefejot7': Using server-side directory move
2022/01/13 06:00:16 INFO  : Putio root 'rclone-test-yenayeb5vuwegas1zefejot7': Server side directory move succeeded
2022/01/13 06:00:16 ERROR : : error listing: directory not found
2022/01/13 06:00:16 DEBUG : Putio root 'rclone-test-yenayeb5vuwegas1zefejot7': Purge remote
2022/01/13 06:00:16 DEBUG : Putio root 'rclone-test-loyojol1juhonas8lulidod2': Purge remote
2022/01/13 06:00:16 purge failed: Rmdir: directory not found
--- PASS: TestServerSideMove (8.48s)
=== RUN   TestServerSideMoveWithFilter
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 06:00:17 DEBUG : Creating backend with remote "TestPutio:rclone-test-qaqinez1pogenim9rakeleg2"
2022/01/13 06:00:17 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 60
2022/01/13 06:00:17 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 60
2022/01/13 06:00:19 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 1
2022/01/13 06:00:19 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 1
2022/01/13 06:00:20 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 68
2022/01/13 06:00:20 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 68
    sync_test.go:1215: Server side move (if possible) Putio root 'rclone-test-vegocuq9liqayol6xigirew3' -> Putio root 'rclone-test-qaqinez1pogenim9rakeleg2'
2022/01/13 06:00:21 DEBUG : Putio root 'rclone-test-qaqinez1pogenim9rakeleg2': chunkStart: 0, reqSize: 1
2022/01/13 06:00:21 DEBUG : Putio root 'rclone-test-qaqinez1pogenim9rakeleg2': Sending chunk. transferOffset: 0 length: 1
2022/01/13 06:00:22 DEBUG : Putio root 'rclone-test-qaqinez1pogenim9rakeleg2': chunkStart: 0, reqSize: 60
2022/01/13 06:00:22 DEBUG : Putio root 'rclone-test-qaqinez1pogenim9rakeleg2': Sending chunk. transferOffset: 0 length: 60
2022/01/13 06:00:25 DEBUG : empty space: Excluded
2022/01/13 06:00:25 DEBUG : empty space: Excluded
2022/01/13 06:00:25 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2022/01/13 06:00:25 DEBUG : Putio root 'rclone-test-qaqinez1pogenim9rakeleg2': Waiting for checks to finish
2022/01/13 06:00:25 DEBUG : Putio root 'rclone-test-qaqinez1pogenim9rakeleg2': Waiting for transfers to finish
2022/01/13 06:00:25 INFO  : potato2: Moved (server-side)
2022/01/13 06:00:25 INFO  : potato3: Deleted
2022/01/13 06:00:26 INFO  : potato3: Moved (server-side)
2022/01/13 06:00:26 INFO  : There was nothing to transfer
2022/01/13 06:00:26 DEBUG : Creating backend with remote "TestPutio:rclone-test-baduwuw7doxegej0culemaj9"
2022/01/13 06:00:26 DEBUG : empty space: Excluded
2022/01/13 06:00:26 DEBUG : Putio root 'rclone-test-baduwuw7doxegej0culemaj9': Waiting for checks to finish
2022/01/13 06:00:26 DEBUG : Putio root 'rclone-test-baduwuw7doxegej0culemaj9': Waiting for transfers to finish
2022/01/13 06:00:26 INFO  : potato3: Moved (server-side)
2022/01/13 06:00:27 INFO  : potato2: Moved (server-side)
2022/01/13 06:00:27 INFO  : There was nothing to transfer
2022/01/13 06:00:27 DEBUG : Putio root 'rclone-test-baduwuw7doxegej0culemaj9': Purge remote
2022/01/13 06:00:27 DEBUG : Putio root 'rclone-test-qaqinez1pogenim9rakeleg2': Purge remote
--- PASS: TestServerSideMoveWithFilter (10.75s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 06:00:27 DEBUG : Creating backend with remote "TestPutio:rclone-test-cekizaz6mosorag9colokeb8"
2022/01/13 06:00:28 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 60
2022/01/13 06:00:28 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 60
2022/01/13 06:00:29 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 1
2022/01/13 06:00:29 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 1
2022/01/13 06:00:33 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 68
2022/01/13 06:00:33 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 68
2022/01/13 06:00:34 DEBUG : tomatoDir: Making directory
    sync_test.go:1215: Server side move (if possible) Putio root 'rclone-test-vegocuq9liqayol6xigirew3' -> Putio root 'rclone-test-cekizaz6mosorag9colokeb8'
2022/01/13 06:00:35 DEBUG : Putio root 'rclone-test-cekizaz6mosorag9colokeb8': chunkStart: 0, reqSize: 1
2022/01/13 06:00:35 DEBUG : Putio root 'rclone-test-cekizaz6mosorag9colokeb8': Sending chunk. transferOffset: 0 length: 1
2022/01/13 06:00:36 DEBUG : Putio root 'rclone-test-cekizaz6mosorag9colokeb8': chunkStart: 0, reqSize: 60
2022/01/13 06:00:36 DEBUG : Putio root 'rclone-test-cekizaz6mosorag9colokeb8': Sending chunk. transferOffset: 0 length: 60
2022/01/13 06:00:37 DEBUG : Putio root 'rclone-test-cekizaz6mosorag9colokeb8': Using server-side directory move
2022/01/13 06:00:37 INFO  : Putio root 'rclone-test-cekizaz6mosorag9colokeb8': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2022/01/13 06:00:37 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1s)
2022/01/13 06:00:37 DEBUG : empty space: Unchanged skipping
2022/01/13 06:00:37 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2022/01/13 06:00:37 DEBUG : Putio root 'rclone-test-cekizaz6mosorag9colokeb8': Waiting for checks to finish
2022/01/13 06:00:37 INFO  : potato3: Deleted
2022/01/13 06:00:37 INFO  : potato2: Moved (server-side)
2022/01/13 06:00:37 INFO  : potato3: Moved (server-side)
2022/01/13 06:00:38 INFO  : empty space: Deleted
2022/01/13 06:00:38 DEBUG : Putio root 'rclone-test-cekizaz6mosorag9colokeb8': Waiting for transfers to finish
2022/01/13 06:00:38 INFO  : tomatoDir: Removing directory
2022/01/13 06:00:38 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': deleted 1 directories
2022/01/13 06:00:38 INFO  : There was nothing to transfer
2022/01/13 06:00:38 DEBUG : Creating backend with remote "TestPutio:rclone-test-lipotaj0makucak3vahukab5"
2022/01/13 06:00:39 DEBUG : tomatoDir: Making directory
2022/01/13 06:00:39 DEBUG : Putio root 'rclone-test-lipotaj0makucak3vahukab5': Using server-side directory move
2022/01/13 06:00:39 INFO  : Putio root 'rclone-test-lipotaj0makucak3vahukab5': Server side directory move succeeded
2022/01/13 06:00:39 ERROR : : error listing: directory not found
2022/01/13 06:00:39 ERROR : : error listing: directory not found
2022/01/13 06:00:39 DEBUG : Putio root 'rclone-test-lipotaj0makucak3vahukab5': Purge remote
2022/01/13 06:00:39 DEBUG : Putio root 'rclone-test-cekizaz6mosorag9colokeb8': Purge remote
2022/01/13 06:00:39 purge failed: Rmdir: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (12.27s)
=== RUN   TestServerSideMoveOverlap
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
    sync_test.go:1399: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.15s)
=== RUN   TestSyncOverlap
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 06:00:40 DEBUG : Creating backend with remote "TestPutio:rclone-test-vegocuq9liqayol6xigirew3/rclone-sync-test"
--- PASS: TestSyncOverlap (0.42s)
=== RUN   TestSyncCompareDest
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 06:00:40 DEBUG : Creating backend with remote "TestPutio:rclone-test-vegocuq9liqayol6xigirew3/dst"
2022/01/13 06:00:40 DEBUG : Creating backend with remote "TestPutio:rclone-test-vegocuq9liqayol6xigirew3/CompareDest"
2022/01/13 06:00:41 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for checks to finish
2022/01/13 06:00:41 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for transfers to finish
2022/01/13 06:00:41 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 3
2022/01/13 06:00:41 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 3
2022/01/13 06:00:43 DEBUG : one: crc32 = 7a6c86f1 OK
2022/01/13 06:00:43 INFO  : one: Copied (new)
2022/01/13 06:00:43 DEBUG : Waiting for deletions to finish
2022/01/13 06:00:43 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for checks to finish
2022/01/13 06:00:43 DEBUG : one: Sizes differ (src 5 vs dst 3)
2022/01/13 06:00:43 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for transfers to finish
2022/01/13 06:00:44 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 5
2022/01/13 06:00:44 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 5
2022/01/13 06:00:44 DEBUG : one: crc32 = cb217308 OK
2022/01/13 06:00:44 INFO  : one: Copied (replaced existing)
2022/01/13 06:00:44 DEBUG : Waiting for deletions to finish
2022/01/13 06:00:45 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 3
2022/01/13 06:00:45 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 3
2022/01/13 06:00:46 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 5
2022/01/13 06:00:46 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 5
2022/01/13 06:00:47 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for checks to finish
2022/01/13 06:00:47 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2022/01/13 06:00:47 DEBUG : one: Destination found in --compare-dest, skipping
2022/01/13 06:00:47 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for transfers to finish
2022/01/13 06:00:47 DEBUG : Waiting for deletions to finish
2022/01/13 06:00:47 INFO  : There was nothing to transfer
2022/01/13 06:00:48 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 3
2022/01/13 06:00:48 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 3
2022/01/13 06:00:49 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2022/01/13 06:00:49 DEBUG : two: Destination found in --compare-dest, skipping
2022/01/13 06:00:49 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for checks to finish
2022/01/13 06:00:49 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2022/01/13 06:00:49 DEBUG : one: Destination found in --compare-dest, skipping
2022/01/13 06:00:49 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for transfers to finish
2022/01/13 06:00:49 DEBUG : Waiting for deletions to finish
2022/01/13 06:00:49 INFO  : There was nothing to transfer
2022/01/13 06:00:49 DEBUG : two: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2022/01/13 06:00:49 DEBUG : two: Destination found in --compare-dest, skipping
2022/01/13 06:00:49 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for checks to finish
2022/01/13 06:00:49 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2022/01/13 06:00:49 DEBUG : one: Destination found in --compare-dest, skipping
2022/01/13 06:00:49 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for transfers to finish
2022/01/13 06:00:49 DEBUG : Waiting for deletions to finish
2022/01/13 06:00:49 INFO  : There was nothing to transfer
2022/01/13 06:00:50 DEBUG : two: Modification times differ by -120h0m0s: 2011-12-30 12:59:59 +0000 UTC, 2011-12-25 12:59:59 +0000 UTC
2022/01/13 06:00:50 DEBUG : two: crc32 = 11ca8a66 OK
2022/01/13 06:00:50 DEBUG : two: Destination found in --compare-dest, skipping
2022/01/13 06:00:50 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for checks to finish
2022/01/13 06:00:50 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2022/01/13 06:00:50 DEBUG : one: Destination found in --compare-dest, skipping
2022/01/13 06:00:50 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for transfers to finish
2022/01/13 06:00:50 DEBUG : Waiting for deletions to finish
2022/01/13 06:00:50 INFO  : There was nothing to transfer
2022/01/13 06:00:50 DEBUG : two: Sizes differ (src 5 vs dst 3)
2022/01/13 06:00:50 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for checks to finish
2022/01/13 06:00:50 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2022/01/13 06:00:50 DEBUG : one: Destination found in --compare-dest, skipping
2022/01/13 06:00:50 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for transfers to finish
2022/01/13 06:00:51 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 5
2022/01/13 06:00:51 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 5
2022/01/13 06:00:51 DEBUG : two: crc32 = 8b9078ce OK
2022/01/13 06:00:51 INFO  : two: Copied (new)
2022/01/13 06:00:51 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncCompareDest (12.79s)
=== RUN   TestSyncMultipleCompareDest
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 06:00:53 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 1
2022/01/13 06:00:53 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 1
2022/01/13 06:00:55 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 1
2022/01/13 06:00:55 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 1
2022/01/13 06:00:56 DEBUG : Creating backend with remote "TestPutio:rclone-test-vegocuq9liqayol6xigirew3/dest"
2022/01/13 06:00:56 DEBUG : Config file has changed externaly - reloading
2022/01/13 06:00:56 DEBUG : Creating backend with remote "TestPutio:rclone-test-vegocuq9liqayol6xigirew3/pre-dest1"
2022/01/13 06:00:56 DEBUG : Creating backend with remote "TestPutio:rclone-test-vegocuq9liqayol6xigirew3/pre-dest2"
2022/01/13 06:00:56 DEBUG : 1: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:00:56 DEBUG : 1: Destination found in --compare-dest, skipping
2022/01/13 06:00:57 DEBUG : 2: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:00:57 DEBUG : 2: Destination found in --compare-dest, skipping
2022/01/13 06:00:57 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dest': Waiting for checks to finish
2022/01/13 06:00:57 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dest': Waiting for transfers to finish
2022/01/13 06:00:57 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dest': chunkStart: 0, reqSize: 1
2022/01/13 06:00:57 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dest': Sending chunk. transferOffset: 0 length: 1
2022/01/13 06:00:58 DEBUG : 3: crc32 = 6dd28e9b OK
2022/01/13 06:00:58 INFO  : 3: Copied (new)
2022/01/13 06:00:58 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncMultipleCompareDest (6.66s)
=== RUN   TestSyncCopyDest
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 06:01:00 DEBUG : Creating backend with remote "TestPutio:rclone-test-vegocuq9liqayol6xigirew3/dst"
2022/01/13 06:01:00 DEBUG : Creating backend with remote "TestPutio:rclone-test-vegocuq9liqayol6xigirew3/CopyDest"
2022/01/13 06:01:00 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for checks to finish
2022/01/13 06:01:00 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for transfers to finish
2022/01/13 06:01:01 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 3
2022/01/13 06:01:01 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 3
2022/01/13 06:01:02 DEBUG : one: crc32 = 7a6c86f1 OK
2022/01/13 06:01:02 INFO  : one: Copied (new)
2022/01/13 06:01:02 DEBUG : Waiting for deletions to finish
2022/01/13 06:01:02 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for checks to finish
2022/01/13 06:01:02 DEBUG : one: Sizes differ (src 5 vs dst 3)
2022/01/13 06:01:02 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for transfers to finish
2022/01/13 06:01:03 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 5
2022/01/13 06:01:03 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 5
2022/01/13 06:01:04 DEBUG : one: crc32 = cb217308 OK
2022/01/13 06:01:04 INFO  : one: Copied (replaced existing)
2022/01/13 06:01:04 DEBUG : Waiting for deletions to finish
2022/01/13 06:01:04 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 3
2022/01/13 06:01:04 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 3
2022/01/13 06:01:06 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 5
2022/01/13 06:01:06 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 5
2022/01/13 06:01:07 DEBUG : Creating backend with remote "TestPutio:rclone-test-vegocuq9liqayol6xigirew3/BackupDir"
2022/01/13 06:01:08 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for checks to finish
2022/01/13 06:01:08 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2022/01/13 06:01:08 DEBUG : one: Sizes differ (src 5 vs dst 3)
2022/01/13 06:01:09 INFO  : one: Moved (server-side)
2022/01/13 06:01:09 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:01:09 ERROR : one: Destination found in --copy-dest, error copying
2022/01/13 06:01:09 DEBUG : one: Sizes differ (src 5 vs dst 3)
2022/01/13 06:01:09 INFO  : one: Deleted
2022/01/13 06:01:09 ERROR : one: Couldn't move: object not found
2022/01/13 06:01:09 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for transfers to finish
2022/01/13 06:01:09 ERROR : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': not deleting files as there were IO errors
2022/01/13 06:01:09 ERROR : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/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 (10.32s)
=== RUN   TestSyncBackupDir
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 06:01:11 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 3
2022/01/13 06:01:11 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 3
2022/01/13 06:01:12 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 3
2022/01/13 06:01:12 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 3
2022/01/13 06:01:13 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 5
2022/01/13 06:01:13 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 5
2022/01/13 06:01:14 DEBUG : Creating backend with remote "TestPutio:rclone-test-vegocuq9liqayol6xigirew3/dst"
2022/01/13 06:01:14 DEBUG : Creating backend with remote "TestPutio:rclone-test-vegocuq9liqayol6xigirew3/backup"
2022/01/13 06:01:14 DEBUG : one: Sizes differ (src 4 vs dst 3)
2022/01/13 06:01:14 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:01:14 DEBUG : two: Unchanged skipping
2022/01/13 06:01:14 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for checks to finish
2022/01/13 06:01:15 INFO  : one: Moved (server-side)
2022/01/13 06:01:15 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for transfers to finish
2022/01/13 06:01:15 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 4
2022/01/13 06:01:15 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 4
2022/01/13 06:01:16 DEBUG : one: crc32 = 19193087 OK
2022/01/13 06:01:16 INFO  : one: Copied (new)
2022/01/13 06:01:16 DEBUG : Waiting for deletions to finish
2022/01/13 06:01:16 INFO  : three.txt: Moved (server-side)
2022/01/13 06:01:16 INFO  : three.txt: Moved into backup dir
2022/01/13 06:01:17 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:01:17 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:01:18 DEBUG : one: Sizes differ (src 5 vs dst 4)
2022/01/13 06:01:18 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for checks to finish
2022/01/13 06:01:18 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:01:18 DEBUG : two: Unchanged skipping
2022/01/13 06:01:18 INFO  : one: Deleted
2022/01/13 06:01:18 INFO  : one: Moved (server-side)
2022/01/13 06:01:18 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for transfers to finish
2022/01/13 06:01:19 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 5
2022/01/13 06:01:19 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 5
2022/01/13 06:01:22 DEBUG : one: crc32 = 12389341 OK
2022/01/13 06:01:22 INFO  : one: Copied (new)
2022/01/13 06:01:22 DEBUG : Waiting for deletions to finish
2022/01/13 06:01:22 INFO  : three.txt: Deleted
2022/01/13 06:01:23 INFO  : three.txt: Moved (server-side)
2022/01/13 06:01:23 INFO  : three.txt: Moved into backup dir
--- PASS: TestSyncBackupDir (14.03s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 06:01:24 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 3
2022/01/13 06:01:24 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 3
2022/01/13 06:01:25 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 3
2022/01/13 06:01:25 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 3
2022/01/13 06:01:26 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 5
2022/01/13 06:01:26 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 5
2022/01/13 06:01:27 DEBUG : Creating backend with remote "TestPutio:rclone-test-vegocuq9liqayol6xigirew3/dst"
2022/01/13 06:01:27 DEBUG : Creating backend with remote "TestPutio:rclone-test-vegocuq9liqayol6xigirew3/backup"
2022/01/13 06:01:28 DEBUG : one: Sizes differ (src 4 vs dst 3)
2022/01/13 06:01:28 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for checks to finish
2022/01/13 06:01:28 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:01:28 DEBUG : two: Unchanged skipping
2022/01/13 06:01:28 INFO  : one: Moved (server-side) to: one.bak
2022/01/13 06:01:28 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for transfers to finish
2022/01/13 06:01:29 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 4
2022/01/13 06:01:29 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 4
2022/01/13 06:01:31 DEBUG : one: crc32 = 19193087 OK
2022/01/13 06:01:31 INFO  : one: Copied (new)
2022/01/13 06:01:31 DEBUG : Waiting for deletions to finish
2022/01/13 06:01:31 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2022/01/13 06:01:31 INFO  : three.txt: Moved into backup dir
2022/01/13 06:01:32 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:01:32 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:01:32 DEBUG : one: Sizes differ (src 5 vs dst 4)
2022/01/13 06:01:32 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:01:32 DEBUG : two: Unchanged skipping
2022/01/13 06:01:32 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for checks to finish
2022/01/13 06:01:32 INFO  : one.bak: Deleted
2022/01/13 06:01:33 INFO  : one: Moved (server-side) to: one.bak
2022/01/13 06:01:33 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for transfers to finish
2022/01/13 06:01:33 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 5
2022/01/13 06:01:33 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 5
2022/01/13 06:01:34 DEBUG : one: crc32 = 12389341 OK
2022/01/13 06:01:34 INFO  : one: Copied (new)
2022/01/13 06:01:34 DEBUG : Waiting for deletions to finish
2022/01/13 06:01:34 INFO  : three.txt.bak: Deleted
2022/01/13 06:01:34 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2022/01/13 06:01:34 INFO  : three.txt: Moved into backup dir
--- PASS: TestSyncBackupDirWithSuffix (11.50s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 06:01:36 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 3
2022/01/13 06:01:36 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 3
2022/01/13 06:01:37 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 3
2022/01/13 06:01:37 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 3
2022/01/13 06:01:38 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 5
2022/01/13 06:01:38 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 5
2022/01/13 06:01:39 DEBUG : Creating backend with remote "TestPutio:rclone-test-vegocuq9liqayol6xigirew3/dst"
2022/01/13 06:01:39 DEBUG : Creating backend with remote "TestPutio:rclone-test-vegocuq9liqayol6xigirew3/backup"
2022/01/13 06:01:40 DEBUG : one: Sizes differ (src 4 vs dst 3)
2022/01/13 06:01:40 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:01:40 DEBUG : two: Unchanged skipping
2022/01/13 06:01:40 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for checks to finish
2022/01/13 06:01:40 INFO  : one: Moved (server-side) to: one-2019-01-01
2022/01/13 06:01:40 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for transfers to finish
2022/01/13 06:01:41 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 4
2022/01/13 06:01:41 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 4
2022/01/13 06:01:41 DEBUG : one: crc32 = 19193087 OK
2022/01/13 06:01:41 INFO  : one: Copied (new)
2022/01/13 06:01:41 DEBUG : Waiting for deletions to finish
2022/01/13 06:01:42 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2022/01/13 06:01:42 INFO  : three.txt: Moved into backup dir
2022/01/13 06:01:42 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:01:42 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:01:49 DEBUG : one: Sizes differ (src 5 vs dst 4)
2022/01/13 06:01:49 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:01:49 DEBUG : two: Unchanged skipping
2022/01/13 06:01:49 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for checks to finish
2022/01/13 06:01:49 INFO  : one-2019-01-01: Deleted
2022/01/13 06:01:50 INFO  : one: Moved (server-side) to: one-2019-01-01
2022/01/13 06:01:50 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for transfers to finish
2022/01/13 06:01:50 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 5
2022/01/13 06:01:50 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 5
2022/01/13 06:01:53 DEBUG : one: crc32 = 12389341 OK
2022/01/13 06:01:53 INFO  : one: Copied (new)
2022/01/13 06:01:53 DEBUG : Waiting for deletions to finish
2022/01/13 06:01:53 INFO  : three-2019-01-01.txt: Deleted
2022/01/13 06:01:53 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2022/01/13 06:01:53 INFO  : three.txt: Moved into backup dir
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (19.28s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 06:01:55 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 3
2022/01/13 06:01:55 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 3
2022/01/13 06:01:56 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 3
2022/01/13 06:01:56 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 3
2022/01/13 06:01:57 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 5
2022/01/13 06:01:57 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 5
2022/01/13 06:01:58 DEBUG : Creating backend with remote "TestPutio:rclone-test-vegocuq9liqayol6xigirew3/dst"
2022/01/13 06:01:58 DEBUG : one: Sizes differ (src 4 vs dst 3)
2022/01/13 06:01:58 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:01:58 DEBUG : two: Unchanged skipping
2022/01/13 06:01:58 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for checks to finish
2022/01/13 06:01:59 INFO  : one: Moved (server-side) to: one.bak
2022/01/13 06:01:59 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for transfers to finish
2022/01/13 06:01:59 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 4
2022/01/13 06:01:59 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 4
2022/01/13 06:02:00 DEBUG : one: crc32 = 19193087 OK
2022/01/13 06:02:00 INFO  : one: Copied (new)
2022/01/13 06:02:00 DEBUG : Waiting for deletions to finish
2022/01/13 06:02:00 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2022/01/13 06:02:00 INFO  : three.txt: Moved into backup dir
2022/01/13 06:02:01 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:02:01 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:02:01 DEBUG : one.bak: Excluded
2022/01/13 06:02:01 DEBUG : three.txt.bak: Excluded
2022/01/13 06:02:01 DEBUG : one: Sizes differ (src 5 vs dst 4)
2022/01/13 06:02:01 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:02:01 DEBUG : two: Unchanged skipping
2022/01/13 06:02:01 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for checks to finish
2022/01/13 06:02:02 INFO  : one.bak: Deleted
2022/01/13 06:02:02 INFO  : one: Moved (server-side) to: one.bak
2022/01/13 06:02:02 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Waiting for transfers to finish
2022/01/13 06:02:03 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 5
2022/01/13 06:02:03 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 5
2022/01/13 06:02:03 DEBUG : one: crc32 = 12389341 OK
2022/01/13 06:02:03 INFO  : one: Copied (new)
2022/01/13 06:02:03 DEBUG : Waiting for deletions to finish
2022/01/13 06:02:04 INFO  : three.txt.bak: Deleted
2022/01/13 06:02:04 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2022/01/13 06:02:04 INFO  : three.txt: Moved into backup dir
--- PASS: TestSyncBackupDirSuffixOnly (10.38s)
=== RUN   TestSyncSuffix
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 06:02:06 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 3
2022/01/13 06:02:06 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 3
2022/01/13 06:02:07 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 3
2022/01/13 06:02:07 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 3
2022/01/13 06:02:08 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 5
2022/01/13 06:02:08 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 5
2022/01/13 06:02:09 DEBUG : Creating backend with remote "TestPutio:rclone-test-vegocuq9liqayol6xigirew3/dst"
2022/01/13 06:02:09 DEBUG : one: Sizes differ (src 4 vs dst 3)
2022/01/13 06:02:10 INFO  : one: Moved (server-side) to: one.bak
2022/01/13 06:02:10 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 4
2022/01/13 06:02:10 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 4
2022/01/13 06:02:11 DEBUG : one: crc32 = 19193087 OK
2022/01/13 06:02:11 INFO  : one: Copied (new)
2022/01/13 06:02:11 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:02:11 DEBUG : two: Unchanged skipping
2022/01/13 06:02:11 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2022/01/13 06:02:11 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2022/01/13 06:02:11 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 6
2022/01/13 06:02:11 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:02:12 DEBUG : three.txt: crc32 = 1e485dc0 OK
2022/01/13 06:02:12 INFO  : three.txt: Copied (new)
2022/01/13 06:02:12 DEBUG : one: Sizes differ (src 5 vs dst 4)
2022/01/13 06:02:13 INFO  : one.bak: Deleted
2022/01/13 06:02:13 INFO  : one: Moved (server-side) to: one.bak
2022/01/13 06:02:13 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 5
2022/01/13 06:02:13 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 5
2022/01/13 06:02:14 DEBUG : one: crc32 = 12389341 OK
2022/01/13 06:02:14 INFO  : one: Copied (new)
2022/01/13 06:02:14 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:02:14 DEBUG : two: Unchanged skipping
2022/01/13 06:02:14 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2022/01/13 06:02:14 INFO  : three.txt.bak: Deleted
2022/01/13 06:02:15 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2022/01/13 06:02:15 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 19
2022/01/13 06:02:15 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 19
2022/01/13 06:02:15 DEBUG : three.txt: crc32 = 5c880d37 OK
2022/01/13 06:02:15 INFO  : three.txt: Copied (new)
--- PASS: TestSyncSuffix (11.45s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 06:02:17 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 3
2022/01/13 06:02:17 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 3
2022/01/13 06:02:20 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 3
2022/01/13 06:02:20 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 3
2022/01/13 06:02:22 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 5
2022/01/13 06:02:22 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 5
2022/01/13 06:02:25 DEBUG : Creating backend with remote "TestPutio:rclone-test-vegocuq9liqayol6xigirew3/dst"
2022/01/13 06:02:25 DEBUG : one: Sizes differ (src 4 vs dst 3)
2022/01/13 06:02:25 INFO  : one: Moved (server-side) to: one-2019-01-01
2022/01/13 06:02:26 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 4
2022/01/13 06:02:26 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 4
2022/01/13 06:02:26 DEBUG : one: crc32 = 19193087 OK
2022/01/13 06:02:26 INFO  : one: Copied (new)
2022/01/13 06:02:26 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:02:26 DEBUG : two: Unchanged skipping
2022/01/13 06:02:26 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2022/01/13 06:02:27 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2022/01/13 06:02:27 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 6
2022/01/13 06:02:27 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:02:27 DEBUG : three.txt: crc32 = 1e485dc0 OK
2022/01/13 06:02:27 INFO  : three.txt: Copied (new)
2022/01/13 06:02:28 DEBUG : one: Sizes differ (src 5 vs dst 4)
2022/01/13 06:02:28 INFO  : one-2019-01-01: Deleted
2022/01/13 06:02:28 INFO  : one: Moved (server-side) to: one-2019-01-01
2022/01/13 06:02:29 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 5
2022/01/13 06:02:29 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 5
2022/01/13 06:02:29 DEBUG : one: crc32 = 12389341 OK
2022/01/13 06:02:29 INFO  : one: Copied (new)
2022/01/13 06:02:29 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:02:29 DEBUG : two: Unchanged skipping
2022/01/13 06:02:30 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2022/01/13 06:02:30 INFO  : three-2019-01-01.txt: Deleted
2022/01/13 06:02:30 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2022/01/13 06:02:30 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': chunkStart: 0, reqSize: 19
2022/01/13 06:02:30 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3/dst': Sending chunk. transferOffset: 0 length: 19
2022/01/13 06:02:33 DEBUG : three.txt: crc32 = 5c880d37 OK
2022/01/13 06:02:33 INFO  : three.txt: Copied (new)
--- PASS: TestSyncSuffixKeepExtension (17.52s)
=== RUN   TestSyncUTFNorm
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 06:02:34 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 18
2022/01/13 06:02:34 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 18
2022/01/13 06:02:35 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2022/01/13 06:02:35 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 06:02:35 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 06:02:36 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 14
2022/01/13 06:02:36 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 14
2022/01/13 06:02:36 DEBUG : Testêé: crc32 = c07a9f32 OK
2022/01/13 06:02:36 INFO  : Testêé: Copied (replaced existing)
2022/01/13 06:02:36 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (2.54s)
=== RUN   TestSyncImmutable
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 06:02:37 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 06:02:37 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 06:02:37 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:02:37 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:02:38 DEBUG : existing: crc32 = 9a941a19 OK
2022/01/13 06:02:38 INFO  : existing: Copied (new)
2022/01/13 06:02:38 DEBUG : Waiting for deletions to finish
2022/01/13 06:02:38 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 06:02:38 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2022/01/13 06:02:38 ERROR : existing: Source and destination exist but do not match: immutable file modified
2022/01/13 06:02:38 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 06:02:38 ERROR : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': not deleting files as there were IO errors
2022/01/13 06:02:38 ERROR : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': not deleting directories as there were IO errors
--- PASS: TestSyncImmutable (1.77s)
=== RUN   TestSyncIgnoreCase
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 06:02:39 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:02:39 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:02:39 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 06:02:39 DEBUG : existing: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:02:39 DEBUG : existing: Unchanged skipping
2022/01/13 06:02:39 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 06:02:39 DEBUG : Waiting for deletions to finish
2022/01/13 06:02:39 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (1.43s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
    sync_test.go:1989: This test only runs on local
=== RUN   TestMaxTransfer/Soft
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
    sync_test.go:1989: This test only runs on local
=== RUN   TestMaxTransfer/Cautious
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
    sync_test.go:1989: This test only runs on local
--- PASS: TestMaxTransfer (0.43s)
    --- SKIP: TestMaxTransfer/Hard (0.14s)
    --- SKIP: TestMaxTransfer/Soft (0.14s)
    --- SKIP: TestMaxTransfer/Cautious (0.14s)
=== RUN   TestSyncConcurrentDelete
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 06:02:41 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:02:41 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:02:42 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:02:42 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:02:46 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:02:46 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:02:47 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:02:47 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:02:48 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:02:48 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:02:49 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:02:49 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:02:50 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:02:50 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:02:51 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:02:51 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:02:53 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:02:53 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:02:54 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:02:54 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:02:57 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:02:57 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:02:58 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:02:58 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:01 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:01 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:03 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:03 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:04 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:04 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:05 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:05 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:07 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:07 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:10 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:10 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:11 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:11 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:14 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:14 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:15 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:15 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:16 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:16 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:17 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:17 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:18 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:18 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:19 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:19 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:21 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:21 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:23 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:23 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:24 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:24 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:27 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:27 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:28 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:28 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:29 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:29 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:30 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:30 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:31 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:31 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:32 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:32 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:37 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:37 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:37 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:37 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:39 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:39 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:40 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:40 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:41 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:41 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:42 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:42 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:42 DEBUG : both1: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:03:42 DEBUG : both1: Unchanged skipping
2022/01/13 06:03:42 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 06:03:42 DEBUG : both12: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:03:42 DEBUG : both12: Unchanged skipping
2022/01/13 06:03:42 DEBUG : both13: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:03:42 DEBUG : both13: Unchanged skipping
2022/01/13 06:03:42 DEBUG : both14: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:03:42 DEBUG : both14: Unchanged skipping
2022/01/13 06:03:42 DEBUG : both15: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:03:42 DEBUG : both15: Unchanged skipping
2022/01/13 06:03:42 DEBUG : both16: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:03:42 DEBUG : both16: Unchanged skipping
2022/01/13 06:03:42 DEBUG : both17: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:03:42 DEBUG : both17: Unchanged skipping
2022/01/13 06:03:42 DEBUG : both11: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:03:42 DEBUG : both18: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:03:42 DEBUG : both11: Unchanged skipping
2022/01/13 06:03:42 DEBUG : both18: Unchanged skipping
2022/01/13 06:03:42 DEBUG : both19: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:03:42 DEBUG : both2: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:03:42 DEBUG : both19: Unchanged skipping
2022/01/13 06:03:42 DEBUG : both2: Unchanged skipping
2022/01/13 06:03:42 DEBUG : both3: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:03:42 DEBUG : both3: Unchanged skipping
2022/01/13 06:03:42 DEBUG : both4: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:03:42 DEBUG : both5: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:03:42 DEBUG : both4: Unchanged skipping
2022/01/13 06:03:42 DEBUG : both5: Unchanged skipping
2022/01/13 06:03:42 DEBUG : both7: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:03:42 DEBUG : both10: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:03:42 DEBUG : both7: Unchanged skipping
2022/01/13 06:03:42 DEBUG : both10: Unchanged skipping
2022/01/13 06:03:42 DEBUG : both8: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:03:42 DEBUG : both8: Unchanged skipping
2022/01/13 06:03:42 DEBUG : both6: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:03:42 DEBUG : both0: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:03:42 DEBUG : both0: Unchanged skipping
2022/01/13 06:03:42 DEBUG : both6: Unchanged skipping
2022/01/13 06:03:42 DEBUG : both9: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:03:42 DEBUG : both9: Unchanged skipping
2022/01/13 06:03:42 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 06:03:42 DEBUG : Waiting for deletions to finish
2022/01/13 06:03:42 INFO  : only1: Deleted
2022/01/13 06:03:42 INFO  : only8: Deleted
2022/01/13 06:03:43 INFO  : only6: Deleted
2022/01/13 06:03:43 INFO  : only15: Deleted
2022/01/13 06:03:43 INFO  : only16: Deleted
2022/01/13 06:03:43 INFO  : only17: Deleted
2022/01/13 06:03:43 INFO  : only18: Deleted
2022/01/13 06:03:43 INFO  : only2: Deleted
2022/01/13 06:03:43 INFO  : only10: Deleted
2022/01/13 06:03:43 INFO  : only13: Deleted
2022/01/13 06:03:44 INFO  : only5: Deleted
2022/01/13 06:03:44 INFO  : only3: Deleted
2022/01/13 06:03:44 INFO  : only4: Deleted
2022/01/13 06:03:44 INFO  : only9: Deleted
2022/01/13 06:03:44 INFO  : only11: Deleted
2022/01/13 06:03:44 INFO  : only19: Deleted
2022/01/13 06:03:44 INFO  : only7: Deleted
2022/01/13 06:03:44 INFO  : only0: Deleted
2022/01/13 06:03:45 INFO  : only14: Deleted
2022/01/13 06:03:45 INFO  : only12: Deleted
2022/01/13 06:03:45 INFO  : There was nothing to transfer
--- PASS: TestSyncConcurrentDelete (68.22s)
=== RUN   TestSyncConcurrentTruncate
    run.go:181: Remote "Putio root 'rclone-test-vegocuq9liqayol6xigirew3'", Local "Local file system at /tmp/rclone857832132", Modify Window "1s"
2022/01/13 06:03:49 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:49 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:52 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:52 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:53 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:53 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:54 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:54 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:55 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:55 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:03:59 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:03:59 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:00 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:00 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:01 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:01 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:02 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:02 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:03 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:03 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:04 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:04 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:08 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:08 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:09 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:09 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:10 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:10 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:11 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:11 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:12 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:12 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:14 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:14 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:15 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:15 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:16 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:16 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:18 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:18 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:19 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:19 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:20 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:20 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:21 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:21 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:24 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:24 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:25 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:25 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:27 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:27 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:28 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:28 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:29 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:29 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:30 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:30 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:31 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:31 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:32 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:32 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:33 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:33 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:34 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:34 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:35 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:35 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:36 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:36 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:42 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:42 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:43 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:43 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:44 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:44 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:45 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:45 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:46 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': chunkStart: 0, reqSize: 6
2022/01/13 06:04:46 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending chunk. transferOffset: 0 length: 6
2022/01/13 06:04:47 DEBUG : both0: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:04:47 DEBUG : both0: Unchanged skipping
2022/01/13 06:04:47 DEBUG : both1: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:04:47 DEBUG : both1: Unchanged skipping
2022/01/13 06:04:47 DEBUG : both10: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:04:47 DEBUG : both10: Unchanged skipping
2022/01/13 06:04:47 DEBUG : both11: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:04:47 DEBUG : both11: Unchanged skipping
2022/01/13 06:04:47 DEBUG : both12: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:04:47 DEBUG : both12: Unchanged skipping
2022/01/13 06:04:47 DEBUG : both13: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:04:47 DEBUG : both13: Unchanged skipping
2022/01/13 06:04:47 DEBUG : both14: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:04:47 DEBUG : both14: Unchanged skipping
2022/01/13 06:04:47 DEBUG : both15: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:04:47 DEBUG : both15: Unchanged skipping
2022/01/13 06:04:47 DEBUG : both16: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:04:47 DEBUG : both16: Unchanged skipping
2022/01/13 06:04:47 DEBUG : both17: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:04:47 DEBUG : both17: Unchanged skipping
2022/01/13 06:04:47 DEBUG : both18: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:04:47 DEBUG : both18: Unchanged skipping
2022/01/13 06:04:47 DEBUG : both19: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:04:47 DEBUG : both19: Unchanged skipping
2022/01/13 06:04:47 DEBUG : both2: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:04:47 DEBUG : both2: Unchanged skipping
2022/01/13 06:04:47 DEBUG : both3: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:04:47 DEBUG : both3: Unchanged skipping
2022/01/13 06:04:47 DEBUG : both4: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:04:47 DEBUG : both4: Unchanged skipping
2022/01/13 06:04:47 DEBUG : both5: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:04:47 DEBUG : both5: Unchanged skipping
2022/01/13 06:04:47 DEBUG : both6: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:04:47 DEBUG : both6: Unchanged skipping
2022/01/13 06:04:47 DEBUG : both7: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:04:47 DEBUG : both7: Unchanged skipping
2022/01/13 06:04:47 DEBUG : both8: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:04:47 DEBUG : both8: Unchanged skipping
2022/01/13 06:04:47 DEBUG : both9: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/01/13 06:04:47 DEBUG : both9: Unchanged skipping
2022/01/13 06:04:47 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2022/01/13 06:04:47 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2022/01/13 06:04:47 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2022/01/13 06:04:47 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2022/01/13 06:04:47 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2022/01/13 06:04:47 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2022/01/13 06:04:47 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2022/01/13 06:04:47 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2022/01/13 06:04:47 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2022/01/13 06:04:47 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2022/01/13 06:04:47 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2022/01/13 06:04:47 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2022/01/13 06:04:47 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2022/01/13 06:04:47 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2022/01/13 06:04:47 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2022/01/13 06:04:47 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2022/01/13 06:04:47 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2022/01/13 06:04:47 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2022/01/13 06:04:47 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2022/01/13 06:04:47 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2022/01/13 06:04:47 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for checks to finish
2022/01/13 06:04:47 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Waiting for transfers to finish
2022/01/13 06:04:47 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:48 DEBUG : only0: crc32 = 00000000 OK
2022/01/13 06:04:48 INFO  : only0: Copied (replaced existing)
2022/01/13 06:04:48 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:49 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:49 DEBUG : only10: crc32 = 00000000 OK
2022/01/13 06:04:49 INFO  : only10: Copied (replaced existing)
2022/01/13 06:04:49 DEBUG : only12: crc32 = 00000000 OK
2022/01/13 06:04:49 INFO  : only12: Copied (replaced existing)
2022/01/13 06:04:49 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:49 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:50 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:50 DEBUG : only14: crc32 = 00000000 OK
2022/01/13 06:04:50 INFO  : only14: Copied (replaced existing)
2022/01/13 06:04:50 DEBUG : only11: crc32 = 00000000 OK
2022/01/13 06:04:50 INFO  : only11: Copied (replaced existing)
2022/01/13 06:04:50 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:51 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:51 DEBUG : pacer: low level retry 1/10 (error unexpected status code (500) response while doing PATCH to https://s99.put.io/files/57cb5d50af6f1f17434c2ba783af92ed67b72402)
2022/01/13 06:04:51 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2022/01/13 06:04:51 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:51 DEBUG : pacer: Reducing sleep to 15ms
2022/01/13 06:04:51 DEBUG : pacer: Reducing sleep to 11.25ms
2022/01/13 06:04:51 ERROR : only1: Failed to copy: unexpected status code (404) response while doing PATCH to https://s99.put.io/files/57cb5d50af6f1f17434c2ba783af92ed67b72402
2022/01/13 06:04:51 DEBUG : pacer: Reducing sleep to 10ms
2022/01/13 06:04:51 DEBUG : only16: crc32 = 00000000 OK
2022/01/13 06:04:51 INFO  : only16: Copied (replaced existing)
2022/01/13 06:04:51 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:51 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:52 DEBUG : only13: crc32 = 00000000 OK
2022/01/13 06:04:52 INFO  : only13: Copied (replaced existing)
2022/01/13 06:04:52 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:52 DEBUG : only15: crc32 = 00000000 OK
2022/01/13 06:04:52 INFO  : only15: Copied (replaced existing)
2022/01/13 06:04:52 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:52 DEBUG : only17: crc32 = 00000000 OK
2022/01/13 06:04:52 INFO  : only17: Copied (replaced existing)
2022/01/13 06:04:52 DEBUG : pacer: low level retry 1/10 (error unexpected status code (500) response while doing PATCH to https://s92.put.io/files/4b59378e0ae51bc42e8421c062fe8ab96c464c12)
2022/01/13 06:04:52 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2022/01/13 06:04:52 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:52 DEBUG : pacer: Reducing sleep to 15ms
2022/01/13 06:04:52 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:52 DEBUG : pacer: Reducing sleep to 11.25ms
2022/01/13 06:04:53 DEBUG : pacer: Reducing sleep to 10ms
2022/01/13 06:04:53 DEBUG : only19: crc32 = 00000000 OK
2022/01/13 06:04:53 INFO  : only19: Copied (replaced existing)
2022/01/13 06:04:53 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:53 ERROR : only18: Failed to copy: unexpected status code (404) response while doing PATCH to https://s92.put.io/files/4b59378e0ae51bc42e8421c062fe8ab96c464c12
2022/01/13 06:04:53 DEBUG : only2: crc32 = 00000000 OK
2022/01/13 06:04:53 INFO  : only2: Copied (replaced existing)
2022/01/13 06:04:53 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:53 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:53 DEBUG : only3: crc32 = 00000000 OK
2022/01/13 06:04:53 INFO  : only3: Copied (replaced existing)
2022/01/13 06:04:53 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:54 DEBUG : only4: crc32 = 00000000 OK
2022/01/13 06:04:54 INFO  : only4: Copied (replaced existing)
2022/01/13 06:04:54 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:54 DEBUG : only5: crc32 = 00000000 OK
2022/01/13 06:04:54 INFO  : only5: Copied (replaced existing)
2022/01/13 06:04:54 DEBUG : only6: crc32 = 00000000 OK
2022/01/13 06:04:54 INFO  : only6: Copied (replaced existing)
2022/01/13 06:04:54 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:54 DEBUG : only7: crc32 = 00000000 OK
2022/01/13 06:04:54 INFO  : only7: Copied (replaced existing)
2022/01/13 06:04:55 DEBUG : only8: crc32 = 00000000 OK
2022/01/13 06:04:55 INFO  : only8: Copied (replaced existing)
2022/01/13 06:04:55 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Sending zero length chunk
2022/01/13 06:04:58 DEBUG : only9: crc32 = 00000000 OK
2022/01/13 06:04:58 INFO  : only9: Copied (replaced existing)
2022/01/13 06:04:58 ERROR : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': not deleting files as there were IO errors
2022/01/13 06:04:58 ERROR : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': 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://s92.put.io/files/4b59378e0ae51bc42e8421c062fe8ab96c464c12
        	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), only10 (0), only11 (0), only12 (0), only13 (0), only14 (0), only15 (0), only16 (0), only17 (0), only19 (0), only2 (0), only3 (0), only4 (0), only5 (0), only6 (0), only7 (0), only8 (0), only9 (0)
    fstest.go:204: Not found "only18"
    fstest.go:204: Not found "only1"
    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  : 2
        	Test:       	TestSyncConcurrentTruncate
        	Messages:   	2 objects not found
--- FAIL: TestSyncConcurrentTruncate (82.46s)
FAIL
2022/01/13 06:05:11 DEBUG : Putio root 'rclone-test-vegocuq9liqayol6xigirew3': Purge remote
"./sync.test -test.v -test.timeout 2h0m0s -remote TestPutio: -verbose" - Finished ERROR in 7m17.065338756s (try 1/5): exit status 1: Failed [TestServerSideCopy TestSyncCopyDest TestSyncConcurrentTruncate]