"./operations.test -test.v -test.timeout 2h0m0s -remote TestPutio: -verbose -test.run '^(TestCat|TestCopyFile|TestCopyFileBackupDir|TestCopyFileCopyDest|TestCopyURL|TestCount|TestDeduplicateNewestByHash|TestDelete|TestHashSums|TestListDirSorted|TestListJSON|TestLs|TestLsLong|TestLsWithFilesFrom|TestLsd|TestMoveFile|TestMoveFileBackupDir|TestMoveFileWithIgnoreExisting|TestPurge|TestRmdirsNoLeaveRoot|TestStatJSON)$'" - Starting (try 4/5)
2022/03/23 06:14:41 DEBUG : Creating backend with remote "TestPutio:rclone-test-duvadek2paqerev2girajiz6"
2022/03/23 06:14:41 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2022/03/23 06:14:41 DEBUG : Creating backend with remote "/tmp/rclone4060446431"
=== RUN   TestDeduplicateNewestByHash
    run.go:181: Remote "Putio root 'rclone-test-duvadek2paqerev2girajiz6'", Local "Local file system at /tmp/rclone4060446431", Modify Window "1s"
2022/03/23 06:14:42 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 100
2022/03/23 06:14:42 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 100
2022/03/23 06:14:43 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 100
2022/03/23 06:14:43 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 100
2022/03/23 06:14:44 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 100
2022/03/23 06:14:44 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 100
2022/03/23 06:14:46 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 5
2022/03/23 06:14:46 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 5
2022/03/23 06:14:46 INFO  : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Looking for duplicate crc32 hashes using newest mode.
2022/03/23 06:14:47 NOTICE: c1fb359d: Found 3 files with duplicate crc32 hashes
2022/03/23 06:14:47 INFO  : one: Deleted
2022/03/23 06:14:47 INFO  : also/one: Deleted
2022/03/23 06:14:47 NOTICE: c1fb359d: Deleted 2 extra copies
--- PASS: TestDeduplicateNewestByHash (6.70s)
=== RUN   TestListDirSorted
    run.go:181: Remote "Putio root 'rclone-test-duvadek2paqerev2girajiz6'", Local "Local file system at /tmp/rclone4060446431", Modify Window "1s"
2022/03/23 06:14:48 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 11
2022/03/23 06:14:48 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 11
2022/03/23 06:14:49 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 5
2022/03/23 06:14:49 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 5
2022/03/23 06:14:51 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 11
2022/03/23 06:14:51 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 11
2022/03/23 06:14:52 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 11
2022/03/23 06:14:52 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 11
2022/03/23 06:14:53 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 1
2022/03/23 06:14:53 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 1
2022/03/23 06:14:54 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 9
2022/03/23 06:14:54 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 9
2022/03/23 06:14:58 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 11
2022/03/23 06:14:58 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 11
2022/03/23 06:14:59 DEBUG : a.txt: Excluded
2022/03/23 06:14:59 DEBUG : sub dir/hello world: Excluded
2022/03/23 06:14:59 DEBUG : sub dir/hello world2: Excluded
2022/03/23 06:15:00 DEBUG : sub dir/hello world: Excluded
2022/03/23 06:15:00 DEBUG : sub dir/hello world2: Excluded
2022/03/23 06:15:00 DEBUG : sub dir/ignore dir: Excluded
2022/03/23 06:15:00 DEBUG : sub dir/ignore dir: Excluded
--- PASS: TestListDirSorted (14.01s)
=== RUN   TestListJSON
    run.go:181: Remote "Putio root 'rclone-test-duvadek2paqerev2girajiz6'", Local "Local file system at /tmp/rclone4060446431", Modify Window "1s"
2022/03/23 06:15:02 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 5
2022/03/23 06:15:02 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 5
2022/03/23 06:15:04 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 9
2022/03/23 06:15:04 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 9
=== RUN   TestListJSON/Default
=== RUN   TestListJSON/FilesOnly
=== RUN   TestListJSON/DirsOnly
=== RUN   TestListJSON/Recurse
=== RUN   TestListJSON/SubDir
=== RUN   TestListJSON/NoModTime
=== RUN   TestListJSON/NoMimeType
=== RUN   TestListJSON/ShowHash
=== RUN   TestListJSON/HashTypes
2022/03/23 06:15:06 ERROR : file1: Failed to read hash: hash type not supported
--- PASS: TestListJSON (4.35s)
    --- PASS: TestListJSON/Default (0.09s)
    --- PASS: TestListJSON/FilesOnly (0.08s)
    --- PASS: TestListJSON/DirsOnly (0.08s)
    --- PASS: TestListJSON/Recurse (0.19s)
    --- PASS: TestListJSON/SubDir (0.11s)
    --- PASS: TestListJSON/NoModTime (0.09s)
    --- PASS: TestListJSON/NoMimeType (0.09s)
    --- PASS: TestListJSON/ShowHash (0.09s)
    --- PASS: TestListJSON/HashTypes (0.08s)
=== RUN   TestStatJSON
    run.go:181: Remote "Putio root 'rclone-test-duvadek2paqerev2girajiz6'", Local "Local file system at /tmp/rclone4060446431", Modify Window "1s"
2022/03/23 06:15:07 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 5
2022/03/23 06:15:07 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 5
2022/03/23 06:15:08 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 9
2022/03/23 06:15:08 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 9
=== RUN   TestStatJSON/Root
=== RUN   TestStatJSON/RootFilesOnly
=== RUN   TestStatJSON/RootDirsOnly
=== RUN   TestStatJSON/Dir
=== RUN   TestStatJSON/File
=== RUN   TestStatJSON/NotFound
=== RUN   TestStatJSON/DirFilesOnly
=== RUN   TestStatJSON/FileFilesOnly
=== RUN   TestStatJSON/NotFoundFilesOnly
=== RUN   TestStatJSON/DirDirsOnly
=== RUN   TestStatJSON/FileDirsOnly
=== RUN   TestStatJSON/NotFoundDirsOnly
=== RUN   TestStatJSON/RootNotFound
2022/03/23 06:15:13 DEBUG : Creating backend with remote "TestPutio:rclone-test-duvadek2paqerev2girajiz6/notfound"
--- PASS: TestStatJSON (7.85s)
    --- PASS: TestStatJSON/Root (0.08s)
    --- PASS: TestStatJSON/RootFilesOnly (0.00s)
    --- PASS: TestStatJSON/RootDirsOnly (0.09s)
    --- PASS: TestStatJSON/Dir (0.15s)
    --- PASS: TestStatJSON/File (0.07s)
    --- PASS: TestStatJSON/NotFound (0.15s)
    --- PASS: TestStatJSON/DirFilesOnly (0.07s)
    --- PASS: TestStatJSON/FileFilesOnly (0.07s)
    --- PASS: TestStatJSON/NotFoundFilesOnly (0.07s)
    --- PASS: TestStatJSON/DirDirsOnly (0.09s)
    --- PASS: TestStatJSON/FileDirsOnly (0.09s)
    --- PASS: TestStatJSON/NotFoundDirsOnly (0.09s)
    --- PASS: TestStatJSON/RootNotFound (0.43s)
=== RUN   TestLsd
    run.go:181: Remote "Putio root 'rclone-test-duvadek2paqerev2girajiz6'", Local "Local file system at /tmp/rclone4060446431", Modify Window "1s"
2022/03/23 06:15:15 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 11
2022/03/23 06:15:15 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 11
--- PASS: TestLsd (4.77s)
=== RUN   TestLs
    run.go:181: Remote "Putio root 'rclone-test-duvadek2paqerev2girajiz6'", Local "Local file system at /tmp/rclone4060446431", Modify Window "1s"
2022/03/23 06:15:19 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 60
2022/03/23 06:15:19 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 60
2022/03/23 06:15:21 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 1
2022/03/23 06:15:21 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 1
--- PASS: TestLs (2.84s)
=== RUN   TestLsWithFilesFrom
    run.go:181: Remote "Putio root 'rclone-test-duvadek2paqerev2girajiz6'", Local "Local file system at /tmp/rclone4060446431", Modify Window "1s"
2022/03/23 06:15:23 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 60
2022/03/23 06:15:23 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 60
2022/03/23 06:15:24 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 1
2022/03/23 06:15:24 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 1
2022/03/23 06:15:25 DEBUG : empty space: Excluded
--- PASS: TestLsWithFilesFrom (3.82s)
=== RUN   TestLsLong
    run.go:181: Remote "Putio root 'rclone-test-duvadek2paqerev2girajiz6'", Local "Local file system at /tmp/rclone4060446431", Modify Window "1s"
2022/03/23 06:15:26 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 60
2022/03/23 06:15:26 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 60
2022/03/23 06:15:28 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 1
2022/03/23 06:15:28 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 1
--- PASS: TestLsLong (4.76s)
=== RUN   TestHashSums
    run.go:181: Remote "Putio root 'rclone-test-duvadek2paqerev2girajiz6'", Local "Local file system at /tmp/rclone4060446431", Modify Window "1s"
2022/03/23 06:15:31 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 60
2022/03/23 06:15:31 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 60
2022/03/23 06:15:32 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 1
2022/03/23 06:15:32 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 1
--- PASS: TestHashSums (2.83s)
=== RUN   TestCount
    run.go:181: Remote "Putio root 'rclone-test-duvadek2paqerev2girajiz6'", Local "Local file system at /tmp/rclone4060446431", Modify Window "1s"
2022/03/23 06:15:33 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 60
2022/03/23 06:15:33 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 60
2022/03/23 06:15:35 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 1
2022/03/23 06:15:35 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 1
2022/03/23 06:15:36 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 5
2022/03/23 06:15:36 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 5
--- PASS: TestCount (4.16s)
=== RUN   TestDelete
    run.go:181: Remote "Putio root 'rclone-test-duvadek2paqerev2girajiz6'", Local "Local file system at /tmp/rclone4060446431", Modify Window "1s"
2022/03/23 06:15:38 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 10
2022/03/23 06:15:38 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 10
2022/03/23 06:15:38 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 60
2022/03/23 06:15:38 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 60
2022/03/23 06:15:48 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 100
2022/03/23 06:15:48 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 100
2022/03/23 06:15:49 DEBUG : Waiting for deletions to finish
2022/03/23 06:15:49 DEBUG : large: Excluded
2022/03/23 06:15:49 INFO  : medium: Deleted
2022/03/23 06:15:49 INFO  : small: Deleted
--- PASS: TestDelete (12.30s)
=== RUN   TestCat
    run.go:181: Remote "Putio root 'rclone-test-duvadek2paqerev2girajiz6'", Local "Local file system at /tmp/rclone4060446431", Modify Window "1s"
2022/03/23 06:15:50 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 10
2022/03/23 06:15:50 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 10
2022/03/23 06:15:51 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 9
2022/03/23 06:15:51 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 9
--- PASS: TestCat (8.50s)
=== RUN   TestPurge
2022/03/23 06:15:58 DEBUG : Creating backend with remote "TestPutio:rclone-test-taqoxuh8bikezog7kacicex9"
2022/03/23 06:15:58 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2022/03/23 06:15:58 DEBUG : Creating backend with remote "/tmp/rclone2083146934"
    run.go:181: Remote "Putio root 'rclone-test-taqoxuh8bikezog7kacicex9'", Local "Local file system at /tmp/rclone2083146934", Modify Window "1s"
2022/03/23 06:16:01 DEBUG : Putio root 'rclone-test-taqoxuh8bikezog7kacicex9': chunkStart: 0, reqSize: 3
2022/03/23 06:16:01 DEBUG : Putio root 'rclone-test-taqoxuh8bikezog7kacicex9': Sending chunk. transferOffset: 0 length: 3
2022/03/23 06:16:12 DEBUG : A2: Making directory
2022/03/23 06:16:12 DEBUG : A1/B2: Making directory
2022/03/23 06:16:13 DEBUG : A1/B2/C2: Making directory
2022/03/23 06:16:13 DEBUG : A1/B1/C3: Making directory
2022/03/23 06:16:13 DEBUG : A3: Making directory
2022/03/23 06:16:14 DEBUG : A3/B3: Making directory
2022/03/23 06:16:14 DEBUG : A3/B3/C4: Making directory
2022/03/23 06:16:14 DEBUG : Putio root 'rclone-test-taqoxuh8bikezog7kacicex9': chunkStart: 0, reqSize: 3
2022/03/23 06:16:14 DEBUG : Putio root 'rclone-test-taqoxuh8bikezog7kacicex9': Sending chunk. transferOffset: 0 length: 3
2022/03/23 06:16:20 ERROR : : error listing: directory not found
2022/03/23 06:16:20 DEBUG : Putio root 'rclone-test-taqoxuh8bikezog7kacicex9': Purge remote
2022/03/23 06:16:20 purge failed: Rmdir: directory not found
--- PASS: TestPurge (21.59s)
=== RUN   TestRmdirsNoLeaveRoot
    run.go:181: Remote "Putio root 'rclone-test-duvadek2paqerev2girajiz6'", Local "Local file system at /tmp/rclone4060446431", Modify Window "1s"
2022/03/23 06:16:21 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 3
2022/03/23 06:16:21 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 3
2022/03/23 06:16:21 DEBUG : A2: Making directory
2022/03/23 06:16:21 DEBUG : A1/B2: Making directory
2022/03/23 06:16:22 DEBUG : A1/B2/C2: Making directory
2022/03/23 06:16:22 DEBUG : A1/B1/C3: Making directory
2022/03/23 06:16:22 DEBUG : A3: Making directory
2022/03/23 06:16:22 DEBUG : A3/B3: Making directory
2022/03/23 06:16:23 DEBUG : A3/B3/C4: Making directory
2022/03/23 06:16:23 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 3
2022/03/23 06:16:23 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 3
2022/03/23 06:16:25 INFO  : A3/B3/C4: Removing directory
2022/03/23 06:16:26 INFO  : A3/B3: Removing directory
2022/03/23 06:16:26 INFO  : A3: Removing directory
2022/03/23 06:16:26 INFO  : A2: Removing directory
2022/03/23 06:16:27 INFO  : A1/B2/C2: Removing directory
2022/03/23 06:16:27 INFO  : A1/B2: Removing directory
2022/03/23 06:16:27 INFO  : A1/B1/C3: Removing directory
--- PASS: TestRmdirsNoLeaveRoot (9.06s)
=== RUN   TestCopyURL
    run.go:181: Remote "Putio root 'rclone-test-duvadek2paqerev2girajiz6'", Local "Local file system at /tmp/rclone4060446431", Modify Window "1s"
2022/03/23 06:16:29 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 14
2022/03/23 06:16:29 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 14
2022/03/23 06:16:33 DEBUG : filename.txt: File name found in url
2022/03/23 06:16:34 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 14
2022/03/23 06:16:34 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 14
2022/03/23 06:16:35 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 14
2022/03/23 06:16:35 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 14
--- PASS: TestCopyURL (7.58s)
=== RUN   TestMoveFile
    run.go:181: Remote "Putio root 'rclone-test-duvadek2paqerev2girajiz6'", Local "Local file system at /tmp/rclone4060446431", Modify Window "1s"
2022/03/23 06:16:36 DEBUG : file1: Need to transfer - File not found at Destination
2022/03/23 06:16:37 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 14
2022/03/23 06:16:37 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 14
2022/03/23 06:16:38 DEBUG : file1: crc32 = f401d3a6 OK
2022/03/23 06:16:38 INFO  : file1: Copied (new) to: sub/file2
2022/03/23 06:16:38 INFO  : file1: Deleted
2022/03/23 06:16:39 DEBUG : file1: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/03/23 06:16:39 DEBUG : file1: Unchanged skipping
2022/03/23 06:16:39 INFO  : file1: Deleted
2022/03/23 06:16:39 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': don't need to copy/move sub/file2, it is already at target location
--- PASS: TestMoveFile (3.23s)
=== RUN   TestMoveFileWithIgnoreExisting
    run.go:181: Remote "Putio root 'rclone-test-duvadek2paqerev2girajiz6'", Local "Local file system at /tmp/rclone4060446431", Modify Window "1s"
2022/03/23 06:16:40 DEBUG : file1: Need to transfer - File not found at Destination
2022/03/23 06:16:40 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 14
2022/03/23 06:16:40 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 14
2022/03/23 06:16:41 DEBUG : file1: crc32 = f401d3a6 OK
2022/03/23 06:16:41 INFO  : file1: Copied (new)
2022/03/23 06:16:41 INFO  : file1: Deleted
2022/03/23 06:16:41 DEBUG : file1: Destination exists, skipping
2022/03/23 06:16:41 DEBUG : file1: Not removing source file as destination file exists and --ignore-existing is set
--- PASS: TestMoveFileWithIgnoreExisting (1.77s)
=== RUN   TestMoveFileBackupDir
    run.go:181: Remote "Putio root 'rclone-test-duvadek2paqerev2girajiz6'", Local "Local file system at /tmp/rclone4060446431", Modify Window "1s"
2022/03/23 06:16:42 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 18
2022/03/23 06:16:42 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 18
2022/03/23 06:16:43 DEBUG : Creating backend with remote "TestPutio:rclone-test-duvadek2paqerev2girajiz6/backup"
2022/03/23 06:16:43 DEBUG : dst/file1: Sizes differ (src 14 vs dst 18)
2022/03/23 06:16:44 INFO  : dst/file1: Moved (server-side)
2022/03/23 06:16:45 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 14
2022/03/23 06:16:45 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 14
2022/03/23 06:16:45 DEBUG : dst/file1: crc32 = f401d3a6 OK
2022/03/23 06:16:45 INFO  : dst/file1: Copied (new)
2022/03/23 06:16:45 INFO  : dst/file1: Deleted
--- PASS: TestMoveFileBackupDir (5.44s)
=== RUN   TestCopyFile
    run.go:181: Remote "Putio root 'rclone-test-duvadek2paqerev2girajiz6'", Local "Local file system at /tmp/rclone4060446431", Modify Window "1s"
2022/03/23 06:16:47 DEBUG : file1: Need to transfer - File not found at Destination
2022/03/23 06:16:48 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 14
2022/03/23 06:16:48 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 14
2022/03/23 06:16:51 DEBUG : file1: crc32 = f401d3a6 OK
2022/03/23 06:16:51 INFO  : file1: Copied (new) to: sub/file2
2022/03/23 06:16:51 DEBUG : file1: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2022/03/23 06:16:51 DEBUG : file1: Unchanged skipping
2022/03/23 06:16:51 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': don't need to copy/move sub/file2, it is already at target location
--- PASS: TestCopyFile (5.34s)
=== RUN   TestCopyFileBackupDir
    run.go:181: Remote "Putio root 'rclone-test-duvadek2paqerev2girajiz6'", Local "Local file system at /tmp/rclone4060446431", Modify Window "1s"
2022/03/23 06:16:53 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 18
2022/03/23 06:16:53 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 18
2022/03/23 06:16:53 DEBUG : Creating backend with remote "TestPutio:rclone-test-duvadek2paqerev2girajiz6/backup"
2022/03/23 06:16:54 DEBUG : dst/file1: Sizes differ (src 14 vs dst 18)
2022/03/23 06:16:54 INFO  : dst/file1: Moved (server-side)
2022/03/23 06:16:55 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 14
2022/03/23 06:16:55 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 14
2022/03/23 06:16:55 DEBUG : dst/file1: crc32 = f401d3a6 OK
2022/03/23 06:16:55 INFO  : dst/file1: Copied (new)
--- PASS: TestCopyFileBackupDir (4.75s)
=== RUN   TestCopyFileCopyDest
    run.go:181: Remote "Putio root 'rclone-test-duvadek2paqerev2girajiz6'", Local "Local file system at /tmp/rclone4060446431", Modify Window "1s"
2022/03/23 06:16:57 DEBUG : Creating backend with remote "TestPutio:rclone-test-duvadek2paqerev2girajiz6/dst"
2022/03/23 06:16:57 DEBUG : Creating backend with remote "TestPutio:rclone-test-duvadek2paqerev2girajiz6/CopyDest"
2022/03/23 06:16:58 DEBUG : one: Need to transfer - File not found at Destination
2022/03/23 06:16:58 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6/dst': chunkStart: 0, reqSize: 3
2022/03/23 06:16:58 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6/dst': Sending chunk. transferOffset: 0 length: 3
2022/03/23 06:16:59 DEBUG : one: crc32 = 7a6c86f1 OK
2022/03/23 06:16:59 INFO  : one: Copied (new)
2022/03/23 06:17:00 DEBUG : one: Sizes differ (src 5 vs dst 3)
2022/03/23 06:17:00 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6/dst': chunkStart: 0, reqSize: 5
2022/03/23 06:17:00 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6/dst': Sending chunk. transferOffset: 0 length: 5
2022/03/23 06:17:01 DEBUG : one: crc32 = cb217308 OK
2022/03/23 06:17:01 INFO  : one: Copied (replaced existing)
2022/03/23 06:17:01 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 3
2022/03/23 06:17:01 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 3
2022/03/23 06:17:03 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': chunkStart: 0, reqSize: 5
2022/03/23 06:17:03 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Sending chunk. transferOffset: 0 length: 5
2022/03/23 06:17:04 DEBUG : Creating backend with remote "TestPutio:rclone-test-duvadek2paqerev2girajiz6/BackupDir"
2022/03/23 06:17:04 DEBUG : one: Size and modification time the same (differ by -123.456789ms, within tolerance 1s)
2022/03/23 06:17:04 DEBUG : one: Sizes differ (src 5 vs dst 3)
2022/03/23 06:17:05 INFO  : one: Moved (server-side)
2022/03/23 06:17:05 ERROR : one: Failed to copy: unexpected status code (400) response while doing POST to https://api.put.io/v2/files/copy
2022/03/23 06:17:05 ERROR : one: Destination found in --copy-dest, error copying
2022/03/23 06:17:05 DEBUG : one: Sizes differ (src 5 vs dst 3)
2022/03/23 06:17:05 INFO  : one: Deleted
2022/03/23 06:17:05 ERROR : one: Couldn't move: object not found
    operations_test.go:1114: 
        	Error Trace:	operations_test.go:1114
        	Error:      	Received unexpected error:
        	            	moving to --backup-dir failed: object not found
        	Test:       	TestCopyFileCopyDest
--- FAIL: TestCopyFileCopyDest (9.43s)
FAIL
2022/03/23 06:17:06 DEBUG : Putio root 'rclone-test-duvadek2paqerev2girajiz6': Purge remote
"./operations.test -test.v -test.timeout 2h0m0s -remote TestPutio: -verbose -test.run '^(TestCat|TestCopyFile|TestCopyFileBackupDir|TestCopyFileCopyDest|TestCopyURL|TestCount|TestDeduplicateNewestByHash|TestDelete|TestHashSums|TestListDirSorted|TestListJSON|TestLs|TestLsLong|TestLsWithFilesFrom|TestLsd|TestMoveFile|TestMoveFileBackupDir|TestMoveFileWithIgnoreExisting|TestPurge|TestRmdirsNoLeaveRoot|TestStatJSON)$'" - Finished ERROR in 2m25.608501903s (try 4/5): exit status 1: Failed [TestCopyFileCopyDest]