"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5)
2022/01/17 06:34:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8"
2022/01/17 06:34:15 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2022/01/17 06:34:15 DEBUG : Creating backend with remote "TestDrive:crypt/hgot3mhm2tb9i7d08h8it2orgd0nttf9cb2111rlgbtpd3i5n5mgmqkjm12q9r8474a6p32dhucam"
2022/01/17 06:34:17 DEBUG : Creating backend with remote "/tmp/rclone2614245315"
=== 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 "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:34:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:34:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:34:18 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
--- PASS: TestCopyWithDryRun (1.89s)
=== RUN   TestCopy
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:34:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:34:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:34:21 DEBUG : sub dir/hello world: md5 = db00814eaaabe7deddf6719ebcd810a7 OK
2022/01/17 06:34:21 INFO  : sub dir/hello world: Copied (new)
2022/01/17 06:34:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (5.51s)
=== RUN   TestCopyMissingDirectory
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:34:24 DEBUG : Creating backend with remote "/non-existing"
2022/01/17 06:34:24 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2022/01/17 06:34:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:34:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
--- PASS: TestCopyMissingDirectory (0.70s)
=== RUN   TestCopyNoTraverse
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:34:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:34:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:34:27 DEBUG : sub dir/hello world: md5 = 7b2725f61c5c349b1939d0339f61a490 OK
2022/01/17 06:34:27 INFO  : sub dir/hello world: Copied (new)
2022/01/17 06:34:29 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (5.47s)
=== RUN   TestCopyCheckFirst
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:34:30 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Running all checks before starting transfers
2022/01/17 06:34:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:34:30 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Checks finished, now starting transfers
2022/01/17 06:34:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:34:33 DEBUG : sub dir/hello world: md5 = 858836dea621d2d33453659e16b1e391 OK
2022/01/17 06:34:33 INFO  : sub dir/hello world: Copied (new)
2022/01/17 06:34:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (5.40s)
=== RUN   TestSyncNoTraverse
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:34:36 ERROR : Ignoring --no-traverse with sync
2022/01/17 06:34:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:34:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:34:38 DEBUG : sub dir/hello world: md5 = 194c5fde5c19ef8897bd30f3952f10a7 OK
2022/01/17 06:34:38 INFO  : sub dir/hello world: Copied (new)
2022/01/17 06:34:38 DEBUG : Waiting for deletions to finish
2022/01/17 06:34:40 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (5.56s)
=== RUN   TestCopyWithDepth
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:34:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:34:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:34:43 DEBUG : hello world2: md5 = ff6212f46109c72dc21f59f07c63a8bd OK
2022/01/17 06:34:43 INFO  : hello world2: Copied (new)
--- PASS: TestCopyWithDepth (2.85s)
=== RUN   TestCopyWithFilesFrom
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:34:44 DEBUG : hello world2: Excluded
2022/01/17 06:34:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:34:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:34:46 DEBUG : potato2: md5 = 73b145f7958f892d55cded1cb55411ea OK
2022/01/17 06:34:46 INFO  : potato2: Copied (new)
--- PASS: TestCopyWithFilesFrom (2.98s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:34:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:34:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:34:49 DEBUG : potato2: md5 = 5f3365f0cca10ca41ad158c5024c6c93 OK
2022/01/17 06:34:49 INFO  : potato2: Copied (new)
--- PASS: TestCopyWithFilesFromAndNoTraverse (3.06s)
=== RUN   TestCopyEmptyDirectories
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:34:50 DEBUG : sub dir2: Making directory
2022/01/17 06:34:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:34:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:34:53 DEBUG : sub dir/hello world: md5 = 91cc803e306116f2ffe2e26817612e42 OK
2022/01/17 06:34:53 INFO  : sub dir/hello world: Copied (new)
2022/01/17 06:34:53 DEBUG : sub dir2: Making directory
2022/01/17 06:34:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': copied 1 directories
2022/01/17 06:34:56 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (7.30s)
=== RUN   TestMoveEmptyDirectories
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:34:57 DEBUG : sub dir2: Making directory
2022/01/17 06:34:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:34:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:35:00 DEBUG : sub dir/hello world: md5 = eae85d4025ef64617b95702f99d13076 OK
2022/01/17 06:35:00 INFO  : sub dir/hello world: Copied (new)
2022/01/17 06:35:00 INFO  : sub dir/hello world: Deleted
2022/01/17 06:35:00 DEBUG : sub dir: Making directory
2022/01/17 06:35:00 DEBUG : sub dir2: Making directory
2022/01/17 06:35:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': copied 2 directories
2022/01/17 06:35:04 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (7.73s)
=== RUN   TestSyncEmptyDirectories
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:35:05 DEBUG : sub dir2: Making directory
2022/01/17 06:35:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:35:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:35:08 DEBUG : sub dir/hello world: md5 = 2e72d6d564928bccc42f83c5e1ebea31 OK
2022/01/17 06:35:08 INFO  : sub dir/hello world: Copied (new)
2022/01/17 06:35:08 DEBUG : sub dir2: Making directory
2022/01/17 06:35:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': copied 1 directories
2022/01/17 06:35:09 DEBUG : Waiting for deletions to finish
2022/01/17 06:35:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (7.19s)
=== RUN   TestServerSideCopy
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:35:15 DEBUG : sub dir/hello world: md5 = cca66ab62a0ef52af0ba189950a985b1 OK
2022/01/17 06:35:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qupifos2tabavip2xirapax2"
2022/01/17 06:35:15 DEBUG : Creating backend with remote "TestDrive:crypt/qo1fn4gq0rm3pu7hqon9ti6q4k55893ftm9uid5t9bcf00lg1ensnj9pa9t5tksrtv09bbfv259du"
    sync_test.go:275: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8' -> Encrypted drive 'TestCryptDrive:rclone-test-qupifos2tabavip2xirapax2'
2022/01/17 06:35:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qupifos2tabavip2xirapax2': Waiting for checks to finish
2022/01/17 06:35:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qupifos2tabavip2xirapax2': Waiting for transfers to finish
2022/01/17 06:35:20 INFO  : sub dir/hello world: Copied (server-side copy)
2022/01/17 06:35:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qupifos2tabavip2xirapax2': Purge remote
2022/01/17 06:35:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (11.40s)
=== RUN   TestCopyAfterDelete
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:35:26 DEBUG : sub dir/hello world: md5 = d77841e74cb3b3f26c36ae8a239cf44e OK
2022/01/17 06:35:26 ERROR : : error listing: directory not found
2022/01/17 06:35:27 DEBUG : Local file system at /tmp/rclone2614245315: Making directory
2022/01/17 06:35:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:35:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:35:29 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (5.98s)
=== RUN   TestCopyRedownload
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:35:32 DEBUG : sub dir/hello world: md5 = 3aa12c457d30ed6534b9c6c46747d2f5 OK
2022/01/17 06:35:33 DEBUG : Local file system at /tmp/rclone2614245315: Waiting for checks to finish
2022/01/17 06:35:33 DEBUG : Local file system at /tmp/rclone2614245315: Waiting for transfers to finish
2022/01/17 06:35:34 INFO  : sub dir/hello world: Copied (new)
2022/01/17 06:35:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (6.55s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:35:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:35:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:35:38 DEBUG : check sum: md5 = 40c750da591afff7d007588a8d4f4383 OK
2022/01/17 06:35:38 INFO  : check sum: Copied (new)
2022/01/17 06:35:38 DEBUG : Waiting for deletions to finish
2022/01/17 06:35:39 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2022/01/17 06:35:39 DEBUG : check sum: Size of src and dst objects identical
2022/01/17 06:35:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:35:39 DEBUG : check sum: Unchanged skipping
2022/01/17 06:35:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:35:39 DEBUG : Waiting for deletions to finish
2022/01/17 06:35:39 INFO  : There was nothing to transfer
--- PASS: TestSyncBasedOnCheckSum (3.71s)
=== RUN   TestSyncSizeOnly
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:35:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:35:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:35:42 DEBUG : sizeonly: md5 = efd980b063398570840299628c3376cc OK
2022/01/17 06:35:42 INFO  : sizeonly: Copied (new)
2022/01/17 06:35:42 DEBUG : Waiting for deletions to finish
2022/01/17 06:35:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:35:42 DEBUG : sizeonly: Sizes identical
2022/01/17 06:35:42 DEBUG : sizeonly: Unchanged skipping
2022/01/17 06:35:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:35:42 DEBUG : Waiting for deletions to finish
2022/01/17 06:35:42 INFO  : There was nothing to transfer
--- PASS: TestSyncSizeOnly (3.72s)
=== RUN   TestSyncIgnoreSize
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:35:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:35:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:35:45 DEBUG : ignore-size: md5 = 4298919663ab7ff5115ded1b1ac4d8db OK
2022/01/17 06:35:45 INFO  : ignore-size: Copied (new)
2022/01/17 06:35:45 DEBUG : Waiting for deletions to finish
2022/01/17 06:35:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:35:46 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:35:46 DEBUG : ignore-size: Unchanged skipping
2022/01/17 06:35:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:35:46 DEBUG : Waiting for deletions to finish
2022/01/17 06:35:46 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreSize (3.72s)
=== RUN   TestSyncIgnoreTimes
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:35:49 DEBUG : existing: md5 = a32d695876deaf3a5442bd4017a8920d OK
2022/01/17 06:35:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:35:49 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:35:49 DEBUG : existing: Unchanged skipping
2022/01/17 06:35:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:35:49 DEBUG : Waiting for deletions to finish
2022/01/17 06:35:49 INFO  : There was nothing to transfer
2022/01/17 06:35:50 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2022/01/17 06:35:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:35:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:35:51 DEBUG : existing: md5 = f10a51b22c457d1588b8f53df4c51778 OK
2022/01/17 06:35:51 INFO  : existing: Copied (replaced existing)
2022/01/17 06:35:51 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncIgnoreTimes (4.80s)
=== RUN   TestSyncIgnoreExisting
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:35:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:35:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:35:54 DEBUG : existing: md5 = a276e6300b9ac499fe24ee744fe47001 OK
2022/01/17 06:35:54 INFO  : existing: Copied (new)
2022/01/17 06:35:54 DEBUG : Waiting for deletions to finish
2022/01/17 06:35:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:35:54 DEBUG : existing: Destination exists, skipping
2022/01/17 06:35:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:35:54 DEBUG : Waiting for deletions to finish
2022/01/17 06:35:54 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreExisting (3.74s)
=== RUN   TestSyncIgnoreErrors
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:35:58 DEBUG : b/potato: md5 = 2f7f14d88c361a995f35da83a75bec1c OK
2022/01/17 06:36:01 DEBUG : c/non empty space: md5 = a102c59aa4a5aee11826669da066b1e3 OK
2022/01/17 06:36:01 DEBUG : d: Making directory
2022/01/17 06:36:03 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:36:03 DEBUG : c/non empty space: Unchanged skipping
2022/01/17 06:36:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:36:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:36:05 DEBUG : a/potato2: md5 = 184b63b2b4f39a3ead58c18ca55ed5a3 OK
2022/01/17 06:36:05 INFO  : a/potato2: Copied (new)
2022/01/17 06:36:05 DEBUG : Waiting for deletions to finish
2022/01/17 06:36:06 INFO  : b/potato: Deleted
2022/01/17 06:36:06 INFO  : d: Removing directory
2022/01/17 06:36:06 INFO  : b: Removing directory
2022/01/17 06:36:07 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2022/01/17 06:36:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': deleted 2 directories
2022/01/17 06:36:10 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2022/01/17 06:36:11 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (16.29s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:36:14 DEBUG : empty space: md5 = 7d688a71f594f750f802e9c7939228dd OK
2022/01/17 06:36:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:36:14 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2022/01/17 06:36:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:36:14 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2022/01/17 06:36:14 DEBUG : Waiting for deletions to finish
2022/01/17 06:36:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:36:15 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2022/01/17 06:36:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:36:16 DEBUG : empty space: md5 = 2a00f811c95ead9eb5ee6dbee924b679 OK
2022/01/17 06:36:16 INFO  : empty space: Copied (replaced existing)
2022/01/17 06:36:16 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncAfterChangingModtimeOnly (5.27s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
    sync_test.go:577: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.51s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:36:19 DEBUG : foo: md5 = 03c5cabccc5b6326ac360e1df997a68a OK
2022/01/17 06:36:20 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2022/01/17 06:36:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:36:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:36:21 DEBUG : foo: md5 = e955eec08ef200923efe893a3c07cc82 OK
2022/01/17 06:36:21 INFO  : foo: Copied (replaced existing)
2022/01/17 06:36:21 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncDoesntUpdateModtime (4.84s)
=== RUN   TestSyncAfterAddingAFile
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:36:24 DEBUG : empty space: md5 = 606300ed2571cec7fd346bc02abbf75f OK
2022/01/17 06:36:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:36:25 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:36:25 DEBUG : empty space: Unchanged skipping
2022/01/17 06:36:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:36:26 DEBUG : potato: md5 = 06f5cddb71d15dc91b794d71ab38f266 OK
2022/01/17 06:36:26 INFO  : potato: Copied (new)
2022/01/17 06:36:26 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncAfterAddingAFile (5.89s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:36:30 DEBUG : potato: md5 = d1e62540d63ea05a3e23880aff283047 OK
2022/01/17 06:36:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:36:31 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2022/01/17 06:36:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:36:32 DEBUG : potato: md5 = 137dab376aacfb5de52e7c0ae991ea87 OK
2022/01/17 06:36:32 INFO  : potato: Copied (replaced existing)
2022/01/17 06:36:32 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncAfterChangingFilesSizeOnly (4.97s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:36:35 DEBUG : potato: md5 = 91f3d0b12a7320ef97b4223f6aa29dd9 OK
2022/01/17 06:36:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:36:36 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/17 06:36:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:36:37 DEBUG : potato: md5 = 6a65e0b2533720bc7f6563aaedd40f4f OK
2022/01/17 06:36:37 INFO  : potato: Copied (replaced existing)
2022/01/17 06:36:37 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncAfterChangingContentsOnly (4.85s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:36:40 DEBUG : potato: md5 = f90805fc05aad70c7c650f68ae187de9 OK
2022/01/17 06:36:42 DEBUG : empty space: md5 = 1c89c1b678fbaf122151a9164f67b707 OK
2022/01/17 06:36:42 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:36:42 DEBUG : empty space: Unchanged skipping
2022/01/17 06:36:42 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2022/01/17 06:36:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:36:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:36:42 DEBUG : Waiting for deletions to finish
2022/01/17 06:36:42 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.47s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:36:46 DEBUG : potato: md5 = 9c27af7a2f9083484be32f28f56f126f OK
2022/01/17 06:36:47 DEBUG : empty space: md5 = 1549c9d73959026f2309f481e0757a42 OK
2022/01/17 06:36:48 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:36:48 DEBUG : empty space: Unchanged skipping
2022/01/17 06:36:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:36:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:36:49 DEBUG : potato2: md5 = b2894459896000b4e85e997b0df9edff OK
2022/01/17 06:36:49 INFO  : potato2: Copied (new)
2022/01/17 06:36:49 DEBUG : Waiting for deletions to finish
2022/01/17 06:36:50 INFO  : potato: Deleted
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.13s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:36:55 DEBUG : b/potato: md5 = 18b4521574a4bdf21013f94e9b36c015 OK
2022/01/17 06:36:57 DEBUG : c/non empty space: md5 = 36af23b078359fe1fba205dc0412e363 OK
2022/01/17 06:36:57 DEBUG : d: Making directory
2022/01/17 06:36:58 DEBUG : d/e: Making directory
2022/01/17 06:37:00 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:37:00 DEBUG : c/non empty space: Unchanged skipping
2022/01/17 06:37:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:37:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:37:03 DEBUG : a/potato2: md5 = 8e52ecc889357020898076b518b27184 OK
2022/01/17 06:37:03 INFO  : a/potato2: Copied (new)
2022/01/17 06:37:03 DEBUG : Waiting for deletions to finish
2022/01/17 06:37:03 INFO  : b/potato: Deleted
2022/01/17 06:37:03 INFO  : d/e: Removing directory
2022/01/17 06:37:04 INFO  : d: Removing directory
2022/01/17 06:37:04 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2022/01/17 06:37:05 INFO  : b: Removing directory
2022/01/17 06:37:05 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2022/01/17 06:37:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': deleted 3 directories
2022/01/17 06:37:09 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2022/01/17 06:37:09 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (18.33s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:37:13 DEBUG : b/potato: md5 = b67b28e6d4980ab81a140c3d4576831c OK
2022/01/17 06:37:15 DEBUG : c/non empty space: md5 = fa0d95a083c4a580acf7847ba524a1c1 OK
2022/01/17 06:37:15 DEBUG : d: Making directory
2022/01/17 06:37:18 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:37:18 DEBUG : c/non empty space: Unchanged skipping
2022/01/17 06:37:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:37:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:37:20 DEBUG : a/potato2: md5 = d1670cef22f2e9db76d3e2cd902336d3 OK
2022/01/17 06:37:20 INFO  : a/potato2: Copied (new)
2022/01/17 06:37:20 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': not deleting files as there were IO errors
2022/01/17 06:37:20 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': not deleting directories as there were IO errors
2022/01/17 06:37:24 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2022/01/17 06:37:25 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2022/01/17 06:37:26 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (16.10s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:37:28 DEBUG : potato: md5 = 7572ea2ac2fc599819ef4fcb7e84a94a OK
2022/01/17 06:37:30 DEBUG : empty space: md5 = aa99cbb770f12daaad29bae5195435d6 OK
2022/01/17 06:37:30 DEBUG : Waiting for deletions to finish
2022/01/17 06:37:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:37:30 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:37:30 DEBUG : empty space: Unchanged skipping
2022/01/17 06:37:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:37:31 INFO  : potato: Deleted
2022/01/17 06:37:32 DEBUG : potato2: md5 = 92c621518ea0b517ef43dc3d81cd7c89 OK
2022/01/17 06:37:32 INFO  : potato2: Copied (new)
--- PASS: TestSyncDeleteDuring (7.03s)
=== RUN   TestSyncDeleteBefore
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:37:35 DEBUG : potato: md5 = 248063ca95a4eb4bd4425482060f9989 OK
2022/01/17 06:37:36 DEBUG : empty space: md5 = 80027c2fae0bc99730fc291c06f89010 OK
2022/01/17 06:37:37 DEBUG : Waiting for deletions to finish
2022/01/17 06:37:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:37:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:37:38 INFO  : potato: Deleted
2022/01/17 06:37:38 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:37:38 DEBUG : empty space: Unchanged skipping
2022/01/17 06:37:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:37:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:37:39 DEBUG : potato2: md5 = 92ed6cc30c39318eecbcb282c5d4016f OK
2022/01/17 06:37:39 INFO  : potato2: Copied (new)
--- PASS: TestSyncDeleteBefore (7.54s)
=== RUN   TestCopyDeleteBefore
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:37:43 DEBUG : potato: md5 = e61ed98cfb9e7f873db971041517dba7 OK
2022/01/17 06:37:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:37:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:37:44 DEBUG : potato2: md5 = a9fcaaae860c675c546dbf5ba4c68d52 OK
2022/01/17 06:37:44 INFO  : potato2: Copied (new)
--- PASS: TestCopyDeleteBefore (5.45s)
=== RUN   TestSyncWithExclude
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:37:48 DEBUG : potato2: md5 = 262e2ead54a63422a4e5a55491ea1b7f OK
2022/01/17 06:37:49 DEBUG : empty space: md5 = 59f3ff3f43e4f06468d652d2eac5deb2 OK
2022/01/17 06:37:50 DEBUG : enormous: Excluded
2022/01/17 06:37:50 DEBUG : potato2: Excluded
2022/01/17 06:37:50 DEBUG : potato2: Excluded
2022/01/17 06:37:50 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:37:50 DEBUG : empty space: Unchanged skipping
2022/01/17 06:37:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:37:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:37:50 DEBUG : Waiting for deletions to finish
2022/01/17 06:37:50 INFO  : There was nothing to transfer
2022/01/17 06:37:50 DEBUG : enormous: Excluded
2022/01/17 06:37:50 DEBUG : potato2: Excluded
2022/01/17 06:37:50 DEBUG : potato2: Excluded
2022/01/17 06:37:50 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2022/01/17 06:37:50 DEBUG : empty space: Unchanged skipping
2022/01/17 06:37:50 DEBUG : Local file system at /tmp/rclone2614245315: Waiting for checks to finish
2022/01/17 06:37:50 DEBUG : Local file system at /tmp/rclone2614245315: Waiting for transfers to finish
2022/01/17 06:37:50 DEBUG : Waiting for deletions to finish
2022/01/17 06:37:50 INFO  : There was nothing to transfer
--- PASS: TestSyncWithExclude (5.55s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:37:54 DEBUG : potato2: md5 = ec98b838695677ecd8247ac206e405e6 OK
2022/01/17 06:37:55 DEBUG : empty space: md5 = d678cbeeec4f66a3208cd6b229e921cf OK
2022/01/17 06:37:57 DEBUG : enormous: md5 = 18d0a79451ff3df46c2ca25b86d89707 OK
2022/01/17 06:37:57 DEBUG : enormous: Excluded
2022/01/17 06:37:57 DEBUG : potato2: Excluded
2022/01/17 06:37:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:37:57 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:37:57 DEBUG : empty space: Unchanged skipping
2022/01/17 06:37:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:37:57 DEBUG : Waiting for deletions to finish
2022/01/17 06:37:58 INFO  : enormous: Deleted
2022/01/17 06:37:58 INFO  : potato2: Deleted
2022/01/17 06:37:58 INFO  : There was nothing to transfer
2022/01/17 06:37:59 DEBUG : Local file system at /tmp/rclone2614245315: Waiting for checks to finish
2022/01/17 06:37:59 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2022/01/17 06:37:59 DEBUG : empty space: Unchanged skipping
2022/01/17 06:37:59 DEBUG : Local file system at /tmp/rclone2614245315: Waiting for transfers to finish
2022/01/17 06:37:59 DEBUG : Waiting for deletions to finish
2022/01/17 06:37:59 INFO  : enormous: Deleted
2022/01/17 06:37:59 INFO  : potato2: Deleted
2022/01/17 06:37:59 INFO  : There was nothing to transfer
--- PASS: TestSyncWithExcludeAndDeleteExcluded (7.59s)
=== RUN   TestSyncWithUpdateOlder
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:38:01 DEBUG : one: md5 = 7be7c019e6bd9e42438f6616aa544f20 OK
2022/01/17 06:38:03 DEBUG : two: md5 = af6175a75a5be7236f18f6a0016a0d09 OK
2022/01/17 06:38:04 DEBUG : three: md5 = 62a9a119699832f6046c36977a18d2bc OK
2022/01/17 06:38:06 DEBUG : four: md5 = 481cd4e8525ffc7e608310bb2a9bd653 OK
2022/01/17 06:38:07 DEBUG : four: Sizes differ (src 4 vs dst 8)
2022/01/17 06:38:07 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2022/01/17 06:38:07 DEBUG : one: Destination is newer than source, skipping
2022/01/17 06:38:07 DEBUG : three: Sizes identical
2022/01/17 06:38:07 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2022/01/17 06:38:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:38:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:38:08 DEBUG : four: md5 = fc7fc9cfdd459d5898ff1def656c8437 OK
2022/01/17 06:38:08 INFO  : four: Copied (replaced existing)
2022/01/17 06:38:08 DEBUG : two: md5 = 0a45eeadc483c332fcb25fa8d087c116 OK
2022/01/17 06:38:08 INFO  : two: Copied (replaced existing)
2022/01/17 06:38:08 DEBUG : five: md5 = ca34dd9da2e404d56f21af632a52b659 OK
2022/01/17 06:38:08 INFO  : five: Copied (new)
2022/01/17 06:38:08 DEBUG : Waiting for deletions to finish
    sync_test.go:992: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (12.59s)
=== RUN   TestSyncWithMaxDuration
    sync_test.go:1009: Skipping test on non local remote
--- SKIP: TestSyncWithMaxDuration (0.00s)
=== RUN   TestSyncWithTrackRenames
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
    sync_test.go:1058: Can track renames: false
2022/01/17 06:38:12 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Ignoring --track-renames as the source and destination do not have a common hash
2022/01/17 06:38:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:38:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:38:14 DEBUG : potato: md5 = a49bd7b1f6a255ecfc096787e955803d OK
2022/01/17 06:38:14 INFO  : potato: Copied (new)
2022/01/17 06:38:15 DEBUG : yam: md5 = ea413537557b6f401b37270d8a3bf70b OK
2022/01/17 06:38:15 INFO  : yam: Copied (new)
2022/01/17 06:38:15 DEBUG : Waiting for deletions to finish
2022/01/17 06:38:15 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Ignoring --track-renames as the source and destination do not have a common hash
2022/01/17 06:38:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:38:15 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:38:15 DEBUG : potato: Unchanged skipping
2022/01/17 06:38:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:38:17 DEBUG : yaml: md5 = f5eaa4113ea88d3d84e16bbb3fbe8bbc OK
2022/01/17 06:38:17 INFO  : yaml: Copied (new)
2022/01/17 06:38:17 DEBUG : Waiting for deletions to finish
2022/01/17 06:38:17 INFO  : yam: Deleted
--- PASS: TestSyncWithTrackRenames (7.03s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
    sync_test.go:1127: Can track renames: true
2022/01/17 06:38:20 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Making map for --track-renames
2022/01/17 06:38:20 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Finished making map for --track-renames
2022/01/17 06:38:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:38:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for renames to finish
2022/01/17 06:38:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:38:21 DEBUG : yam: md5 = 10cb3f5be58dad5e015dcbdc4956333f OK
2022/01/17 06:38:21 INFO  : yam: Copied (new)
2022/01/17 06:38:21 DEBUG : potato: md5 = 575268076c95c23c86391b11fce29304 OK
2022/01/17 06:38:21 INFO  : potato: Copied (new)
2022/01/17 06:38:21 DEBUG : Waiting for deletions to finish
2022/01/17 06:38:22 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:38:22 DEBUG : potato: Unchanged skipping
2022/01/17 06:38:22 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Making map for --track-renames
2022/01/17 06:38:22 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Finished making map for --track-renames
2022/01/17 06:38:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:38:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for renames to finish
2022/01/17 06:38:23 INFO  : yam: Moved (server-side) to: yaml
2022/01/17 06:38:23 INFO  : yaml: Renamed from "yam"
2022/01/17 06:38:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:38:23 DEBUG : Waiting for deletions to finish
2022/01/17 06:38:23 INFO  : There was nothing to transfer
--- PASS: TestSyncWithTrackRenamesStrategyModtime (5.60s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
    sync_test.go:1163: Can track renames: true
2022/01/17 06:38:25 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Making map for --track-renames
2022/01/17 06:38:25 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Finished making map for --track-renames
2022/01/17 06:38:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:38:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for renames to finish
2022/01/17 06:38:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:38:27 DEBUG : sub/yam: md5 = eeb91d7efb17de31182a112e6cf8841f OK
2022/01/17 06:38:27 INFO  : sub/yam: Copied (new)
2022/01/17 06:38:28 DEBUG : potato: md5 = 379f92d8b2260f5cebd57aa54dbd30f4 OK
2022/01/17 06:38:28 INFO  : potato: Copied (new)
2022/01/17 06:38:28 DEBUG : Waiting for deletions to finish
2022/01/17 06:38:28 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:38:28 DEBUG : potato: Unchanged skipping
2022/01/17 06:38:29 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Making map for --track-renames
2022/01/17 06:38:29 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Finished making map for --track-renames
2022/01/17 06:38:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:38:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for renames to finish
2022/01/17 06:38:30 INFO  : sub/yam: Moved (server-side) to: yam
2022/01/17 06:38:30 INFO  : yam: Renamed from "sub/yam"
2022/01/17 06:38:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:38:30 DEBUG : Waiting for deletions to finish
2022/01/17 06:38:30 INFO  : There was nothing to transfer
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (8.56s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:38:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:38:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:38:36 DEBUG : sub dir/hello world: md5 = 7837243ee2a3e8386c070e26da4b4578 OK
2022/01/17 06:38:36 INFO  : sub dir/hello world: Copied (new)
2022/01/17 06:38:36 INFO  : sub dir/hello world: Deleted
2022/01/17 06:38:38 DEBUG : nested/sub dir/file: md5 = 9afea055c02f305650d2ef2cc3c05029 OK
2022/01/17 06:38:38 INFO  : nested/sub dir/file: Copied (new)
2022/01/17 06:38:38 INFO  : nested/sub dir/file: Deleted
2022/01/17 06:38:38 INFO  : sub dir: Removing directory
2022/01/17 06:38:38 INFO  : nested/sub dir: Removing directory
2022/01/17 06:38:38 INFO  : nested: Removing directory
2022/01/17 06:38:38 DEBUG : Local file system at /tmp/rclone2614245315: deleted 3 directories
2022/01/17 06:38:42 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2022/01/17 06:38:43 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2022/01/17 06:38:44 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (11.17s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:38:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:38:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:38:48 DEBUG : sub dir/hello world: md5 = 91a0edc1e70a338d98f9c065aad5297b OK
2022/01/17 06:38:48 INFO  : sub dir/hello world: Copied (new)
2022/01/17 06:38:48 INFO  : sub dir/hello world: Deleted
2022/01/17 06:38:50 DEBUG : nested/sub dir/file: md5 = a9ccee55d7d9c48980c1abe86ac35931 OK
2022/01/17 06:38:50 INFO  : nested/sub dir/file: Copied (new)
2022/01/17 06:38:50 INFO  : nested/sub dir/file: Deleted
2022/01/17 06:38:53 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2022/01/17 06:38:54 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2022/01/17 06:38:55 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.77s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:38:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:38:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:38:57 DEBUG : existing: md5 = 6c65d6617c1317123b6c254e70fe9953 OK
2022/01/17 06:38:57 INFO  : existing: Copied (new)
2022/01/17 06:38:57 INFO  : existing: Deleted
2022/01/17 06:38:58 DEBUG : existing-b: md5 = 6fe66e7d657fad445acc7ecf77e41eee OK
2022/01/17 06:38:58 INFO  : existing-b: Copied (new)
2022/01/17 06:38:58 INFO  : existing-b: Deleted
2022/01/17 06:38:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:38:58 DEBUG : existing: Destination exists, skipping
2022/01/17 06:38:58 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2022/01/17 06:38:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:38:58 INFO  : There was nothing to transfer
--- PASS: TestMoveWithIgnoreExisting (4.79s)
=== RUN   TestServerSideMove
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:39:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-libilin9fedigag9dequmif4"
2022/01/17 06:39:00 DEBUG : Creating backend with remote "TestDrive:crypt/hicppla3rm6rd6etlsjl7gao7aqbif0sadrabkmre2lfbpp2178dsqcu5icuo0nkm6ulnu81khvs0"
2022/01/17 06:39:03 DEBUG : potato2: md5 = 26cda96f0940972ed1ff9c16f66b8fab OK
2022/01/17 06:39:05 DEBUG : empty space: md5 = 663bf62b06aea7bf8411aed02e7d5975 OK
2022/01/17 06:39:06 DEBUG : potato3: md5 = 2d683e97348b9dbe44bfeaa8a33ad8f4 OK
    sync_test.go:1215: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8' -> Encrypted drive 'TestCryptDrive:rclone-test-libilin9fedigag9dequmif4'
2022/01/17 06:39:09 DEBUG : empty space: md5 = 871e3c50696a70846fc31dd05d6e4848 OK
2022/01/17 06:39:11 DEBUG : potato3: md5 = 96518d17e12d7b8daf28d8be32ef3bae OK
2022/01/17 06:39:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-libilin9fedigag9dequmif4': Using server-side directory move
2022/01/17 06:39:11 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-libilin9fedigag9dequmif4': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2022/01/17 06:39:11 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2022/01/17 06:39:11 DEBUG : empty space: Unchanged skipping
2022/01/17 06:39:11 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2022/01/17 06:39:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-libilin9fedigag9dequmif4': Waiting for checks to finish
2022/01/17 06:39:12 INFO  : empty space: Deleted
2022/01/17 06:39:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-libilin9fedigag9dequmif4': Waiting for transfers to finish
2022/01/17 06:39:12 INFO  : potato3: Deleted
2022/01/17 06:39:12 INFO  : potato2: Moved (server-side)
2022/01/17 06:39:13 INFO  : potato3: Moved (server-side)
2022/01/17 06:39:13 INFO  : There was nothing to transfer
2022/01/17 06:39:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-behesir5hotitoc7todupeg5"
2022/01/17 06:39:14 DEBUG : Creating backend with remote "TestDrive:crypt/138nig69urampa0i6k7n6go3vj6f8bmtbh5e0svf7vuh63vbdnqd7vl47sellv4p260hkrrmm4nf8"
2022/01/17 06:39:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-behesir5hotitoc7todupeg5': Using server-side directory move
2022/01/17 06:39:16 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-behesir5hotitoc7todupeg5': Server side directory move succeeded
2022/01/17 06:39:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-behesir5hotitoc7todupeg5': Purge remote
2022/01/17 06:39:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-libilin9fedigag9dequmif4': Purge remote
2022/01/17 06:39:18 purge failed: directory not found
--- PASS: TestServerSideMove (18.16s)
=== RUN   TestServerSideMoveWithFilter
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:39:18 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tutuhan0jafidox7zicihoy2"
2022/01/17 06:39:18 DEBUG : Creating backend with remote "TestDrive:crypt/nimro947peoio0tgjuq3o1pc89i7cc9gjnrrs0378cg20frhr4r8hj983kddb9s970dd9i9kin0gq"
2022/01/17 06:39:21 DEBUG : potato2: md5 = 0b05f816ccc4798b316c50741e026e8a OK
2022/01/17 06:39:23 DEBUG : empty space: md5 = e426f9e2de78abda15995aba8ab377a8 OK
2022/01/17 06:39:24 DEBUG : potato3: md5 = a5b673c9fc6c3616c42f88c8d445d0f1 OK
    sync_test.go:1215: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8' -> Encrypted drive 'TestCryptDrive:rclone-test-tutuhan0jafidox7zicihoy2'
2022/01/17 06:39:27 DEBUG : empty space: md5 = 47e9da5f783a50b0d9fbfca9faf8a100 OK
2022/01/17 06:39:29 DEBUG : potato3: md5 = 111c67b0c2b3a07fe199b98781f4c1e1 OK
2022/01/17 06:39:29 DEBUG : empty space: Excluded
2022/01/17 06:39:29 DEBUG : empty space: Excluded
2022/01/17 06:39:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tutuhan0jafidox7zicihoy2': Waiting for checks to finish
2022/01/17 06:39:29 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2022/01/17 06:39:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tutuhan0jafidox7zicihoy2': Waiting for transfers to finish
2022/01/17 06:39:30 INFO  : potato3: Deleted
2022/01/17 06:39:30 INFO  : potato2: Moved (server-side)
2022/01/17 06:39:31 INFO  : potato3: Moved (server-side)
2022/01/17 06:39:31 INFO  : There was nothing to transfer
2022/01/17 06:39:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tonakaj4tiwapev1sakitij6"
2022/01/17 06:39:31 DEBUG : Creating backend with remote "TestDrive:crypt/mn4fgi60ndi5mei18qt7v1487cnbblnhuvfot1vn8uj2j0astjs86ksdvmr961riig4agge4o6dli"
2022/01/17 06:39:33 DEBUG : empty space: Excluded
2022/01/17 06:39:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tonakaj4tiwapev1sakitij6': Waiting for checks to finish
2022/01/17 06:39:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tonakaj4tiwapev1sakitij6': Waiting for transfers to finish
2022/01/17 06:39:35 INFO  : potato3: Moved (server-side)
2022/01/17 06:39:35 INFO  : potato2: Moved (server-side)
2022/01/17 06:39:35 INFO  : There was nothing to transfer
2022/01/17 06:39:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tonakaj4tiwapev1sakitij6': Purge remote
2022/01/17 06:39:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tutuhan0jafidox7zicihoy2': Purge remote
--- PASS: TestServerSideMoveWithFilter (20.13s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:39:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-ralufix6zehuwun2wojopoc2"
2022/01/17 06:39:39 DEBUG : Creating backend with remote "TestDrive:crypt/adp89j1cj1vg498cfc300c281fsb7q7a3ckkulmcpl3oi717kgf910rndms6r51lqoa5s7v60imm2"
2022/01/17 06:39:42 DEBUG : potato2: md5 = 8c4ec177c653df15a2d71fce1e07c4ff OK
2022/01/17 06:39:43 DEBUG : empty space: md5 = 63de385d4ad924f141f589a2face9fec OK
2022/01/17 06:39:45 DEBUG : potato3: md5 = a7739f9b6b72174f9de9cc7a8439801e OK
2022/01/17 06:39:45 DEBUG : tomatoDir: Making directory
    sync_test.go:1215: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8' -> Encrypted drive 'TestCryptDrive:rclone-test-ralufix6zehuwun2wojopoc2'
2022/01/17 06:39:49 DEBUG : empty space: md5 = b76e1e2879420be54b67b3ccb331c449 OK
2022/01/17 06:39:50 DEBUG : potato3: md5 = 433b3440975fa0a9114a4798f7782562 OK
2022/01/17 06:39:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ralufix6zehuwun2wojopoc2': Using server-side directory move
2022/01/17 06:39:50 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-ralufix6zehuwun2wojopoc2': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2022/01/17 06:39:51 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2022/01/17 06:39:51 DEBUG : empty space: Unchanged skipping
2022/01/17 06:39:51 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2022/01/17 06:39:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ralufix6zehuwun2wojopoc2': Waiting for checks to finish
2022/01/17 06:39:51 INFO  : potato3: Deleted
2022/01/17 06:39:51 INFO  : empty space: Deleted
2022/01/17 06:39:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ralufix6zehuwun2wojopoc2': Waiting for transfers to finish
2022/01/17 06:39:52 INFO  : potato2: Moved (server-side)
2022/01/17 06:39:52 INFO  : potato3: Moved (server-side)
2022/01/17 06:39:52 INFO  : tomatoDir: Removing directory
2022/01/17 06:39:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': deleted 1 directories
2022/01/17 06:39:53 INFO  : There was nothing to transfer
2022/01/17 06:39:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-basopij7hejuxec7bavezah0"
2022/01/17 06:39:54 DEBUG : Creating backend with remote "TestDrive:crypt/lq1m1cpokm8mi2e1a1gu5v721qkfkqr1jvipvllqhia5e8kodcvksj8nbf6s4me1trcreaeqqh10i"
2022/01/17 06:39:55 DEBUG : tomatoDir: Making directory
2022/01/17 06:39:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-basopij7hejuxec7bavezah0': Using server-side directory move
2022/01/17 06:39:57 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-basopij7hejuxec7bavezah0': Server side directory move succeeded
2022/01/17 06:39:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-basopij7hejuxec7bavezah0': Purge remote
2022/01/17 06:39:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ralufix6zehuwun2wojopoc2': Purge remote
2022/01/17 06:39:59 purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (21.31s)
=== RUN   TestServerSideMoveOverlap
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
    sync_test.go:1399: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.58s)
=== RUN   TestSyncOverlap
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:40:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/rclone-sync-test"
2022/01/17 06:40:00 DEBUG : Creating backend with remote "TestDrive:crypt/hgot3mhm2tb9i7d08h8it2orgd0nttf9cb2111rlgbtpd3i5n5mgmqkjm12q9r8474a6p32dhucam/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
--- PASS: TestSyncOverlap (2.45s)
=== RUN   TestSyncCompareDest
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:40:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst"
2022/01/17 06:40:03 DEBUG : Creating backend with remote "TestDrive:crypt/hgot3mhm2tb9i7d08h8it2orgd0nttf9cb2111rlgbtpd3i5n5mgmqkjm12q9r8474a6p32dhucam/31u3jie661vd5p8j7rtc3hgbh0"
2022/01/17 06:40:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/CompareDest"
2022/01/17 06:40:05 DEBUG : Creating backend with remote "TestDrive:crypt/hgot3mhm2tb9i7d08h8it2orgd0nttf9cb2111rlgbtpd3i5n5mgmqkjm12q9r8474a6p32dhucam/gveqi14airsml4bgu7krj116o8"
2022/01/17 06:40:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for checks to finish
2022/01/17 06:40:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for transfers to finish
2022/01/17 06:40:10 DEBUG : one: md5 = 0fee0829eccd2197506bd51b83283d33 OK
2022/01/17 06:40:10 INFO  : one: Copied (new)
2022/01/17 06:40:10 DEBUG : Waiting for deletions to finish
2022/01/17 06:40:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for checks to finish
2022/01/17 06:40:11 DEBUG : one: Sizes differ (src 5 vs dst 3)
2022/01/17 06:40:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for transfers to finish
2022/01/17 06:40:13 DEBUG : one: md5 = c13f8638efc5622fc51ac06516c59c1e OK
2022/01/17 06:40:13 INFO  : one: Copied (replaced existing)
2022/01/17 06:40:13 DEBUG : Waiting for deletions to finish
2022/01/17 06:40:15 DEBUG : dst/one: md5 = b7b76315942e51bef0a74404469462b7 OK
2022/01/17 06:40:17 DEBUG : CompareDest/one: md5 = d904ffad7818d419a350383b3bb0fd83 OK
2022/01/17 06:40:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for checks to finish
2022/01/17 06:40:19 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:40:19 DEBUG : one: Destination found in --compare-dest, skipping
2022/01/17 06:40:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for transfers to finish
2022/01/17 06:40:19 DEBUG : Waiting for deletions to finish
2022/01/17 06:40:19 INFO  : There was nothing to transfer
2022/01/17 06:40:21 DEBUG : CompareDest/two: md5 = 41def1c77bc185aac31618c16e555cfd OK
2022/01/17 06:40:22 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:40:22 DEBUG : two: Destination found in --compare-dest, skipping
2022/01/17 06:40:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for checks to finish
2022/01/17 06:40:23 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:40:23 DEBUG : one: Destination found in --compare-dest, skipping
2022/01/17 06:40:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for transfers to finish
2022/01/17 06:40:23 DEBUG : Waiting for deletions to finish
2022/01/17 06:40:23 INFO  : There was nothing to transfer
2022/01/17 06:40:24 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:40:24 DEBUG : two: Destination found in --compare-dest, skipping
2022/01/17 06:40:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for checks to finish
2022/01/17 06:40:24 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:40:24 DEBUG : one: Destination found in --compare-dest, skipping
2022/01/17 06:40:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for transfers to finish
2022/01/17 06:40:24 DEBUG : Waiting for deletions to finish
2022/01/17 06:40:24 INFO  : There was nothing to transfer
    sync_test.go:1543: No hash on uploaded file so skipping compare timestamp test
2022/01/17 06:40:26 DEBUG : two: Sizes differ (src 5 vs dst 3)
2022/01/17 06:40:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for checks to finish
2022/01/17 06:40:26 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:40:26 DEBUG : one: Destination found in --compare-dest, skipping
2022/01/17 06:40:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for transfers to finish
2022/01/17 06:40:27 DEBUG : two: md5 = 239fb2aa84292ce62ebec2364aa83ada OK
2022/01/17 06:40:27 INFO  : two: Copied (new)
2022/01/17 06:40:27 DEBUG : Waiting for deletions to finish
2022/01/17 06:40:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2022/01/17 06:40:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/01/17 06:40:32 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2022/01/17 06:40:32 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCompareDest (30.46s)
=== RUN   TestSyncMultipleCompareDest
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:40:36 DEBUG : pre-dest1/1: md5 = 9661beaa3060e35caa90a076726fafe2 OK
2022/01/17 06:40:39 DEBUG : pre-dest2/2: md5 = 8c6c75757e280cd9c07d2e5ff071e52d OK
2022/01/17 06:40:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dest"
2022/01/17 06:40:39 DEBUG : Creating backend with remote "TestDrive:crypt/hgot3mhm2tb9i7d08h8it2orgd0nttf9cb2111rlgbtpd3i5n5mgmqkjm12q9r8474a6p32dhucam/rg03c1jvnehrrc617i0lnqjddc"
2022/01/17 06:40:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/pre-dest1"
2022/01/17 06:40:41 DEBUG : Creating backend with remote "TestDrive:crypt/hgot3mhm2tb9i7d08h8it2orgd0nttf9cb2111rlgbtpd3i5n5mgmqkjm12q9r8474a6p32dhucam/bbnblvh6k061ssopqrp18kd7gc"
2022/01/17 06:40:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/pre-dest2"
2022/01/17 06:40:42 DEBUG : Creating backend with remote "TestDrive:crypt/hgot3mhm2tb9i7d08h8it2orgd0nttf9cb2111rlgbtpd3i5n5mgmqkjm12q9r8474a6p32dhucam/dgicm1h6b5ejvlltm8eeif0bnk"
2022/01/17 06:40:44 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:40:44 DEBUG : 1: Destination found in --compare-dest, skipping
2022/01/17 06:40:44 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:40:44 DEBUG : 2: Destination found in --compare-dest, skipping
2022/01/17 06:40:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dest': Waiting for checks to finish
2022/01/17 06:40:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dest': Waiting for transfers to finish
2022/01/17 06:40:47 DEBUG : 3: md5 = e0c870aba596d29d43358c70c69dfaea OK
2022/01/17 06:40:47 INFO  : 3: Copied (new)
2022/01/17 06:40:47 DEBUG : Waiting for deletions to finish
2022/01/17 06:40:51 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2022/01/17 06:40:52 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2022/01/17 06:40:53 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (21.06s)
=== RUN   TestSyncCopyDest
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:40:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst"
2022/01/17 06:40:54 DEBUG : Creating backend with remote "TestDrive:crypt/hgot3mhm2tb9i7d08h8it2orgd0nttf9cb2111rlgbtpd3i5n5mgmqkjm12q9r8474a6p32dhucam/31u3jie661vd5p8j7rtc3hgbh0"
2022/01/17 06:40:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/CopyDest"
2022/01/17 06:40:56 DEBUG : Creating backend with remote "TestDrive:crypt/hgot3mhm2tb9i7d08h8it2orgd0nttf9cb2111rlgbtpd3i5n5mgmqkjm12q9r8474a6p32dhucam/d09o6po3f7bm6ce32vdgs8h9ls"
2022/01/17 06:40:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for checks to finish
2022/01/17 06:40:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for transfers to finish
2022/01/17 06:41:01 DEBUG : one: md5 = 05153ffbdb37e952ee8a7252f668af72 OK
2022/01/17 06:41:01 INFO  : one: Copied (new)
2022/01/17 06:41:01 DEBUG : Waiting for deletions to finish
2022/01/17 06:41:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for checks to finish
2022/01/17 06:41:03 DEBUG : one: Sizes differ (src 5 vs dst 3)
2022/01/17 06:41:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for transfers to finish
2022/01/17 06:41:04 DEBUG : one: md5 = 30311c06c7abd8cfd41b7a665916811d OK
2022/01/17 06:41:04 INFO  : one: Copied (replaced existing)
2022/01/17 06:41:04 DEBUG : Waiting for deletions to finish
2022/01/17 06:41:07 DEBUG : dst/one: md5 = 99c70d097bd4fcb139c0de093481a4c3 OK
2022/01/17 06:41:09 DEBUG : CopyDest/one: md5 = d75c6c7b1615fe1a3389ba904963356d OK
2022/01/17 06:41:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/BackupDir"
2022/01/17 06:41:10 DEBUG : Creating backend with remote "TestDrive:crypt/hgot3mhm2tb9i7d08h8it2orgd0nttf9cb2111rlgbtpd3i5n5mgmqkjm12q9r8474a6p32dhucam/s6dbk3lfi7c9kfvo6j7bla9m0g"
2022/01/17 06:41:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for checks to finish
2022/01/17 06:41:12 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:41:12 DEBUG : one: Sizes differ (src 5 vs dst 3)
2022/01/17 06:41:15 INFO  : one: Moved (server-side)
2022/01/17 06:41:16 INFO  : one: Copied (server-side copy)
2022/01/17 06:41:16 DEBUG : one: Destination found in --copy-dest, using server-side copy
2022/01/17 06:41:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for transfers to finish
2022/01/17 06:41:16 DEBUG : Waiting for deletions to finish
2022/01/17 06:41:18 DEBUG : CopyDest/two: md5 = cc67fdc4136dc103d9bb8acf022d6642 OK
2022/01/17 06:41:19 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:41:21 INFO  : two: Copied (server-side copy)
2022/01/17 06:41:21 DEBUG : two: Destination found in --copy-dest, using server-side copy
2022/01/17 06:41:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for checks to finish
2022/01/17 06:41:21 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:41:21 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:41:21 DEBUG : one: Unchanged skipping
2022/01/17 06:41:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for transfers to finish
2022/01/17 06:41:21 DEBUG : Waiting for deletions to finish
2022/01/17 06:41:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for checks to finish
2022/01/17 06:41:23 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:41:23 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:41:23 DEBUG : one: Unchanged skipping
2022/01/17 06:41:23 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:41:23 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:41:23 DEBUG : two: Unchanged skipping
2022/01/17 06:41:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for transfers to finish
2022/01/17 06:41:23 DEBUG : Waiting for deletions to finish
2022/01/17 06:41:23 INFO  : There was nothing to transfer
2022/01/17 06:41:25 DEBUG : CopyDest/three: md5 = a4a8b6c45f22ac2d2f0af76282dca138 OK
2022/01/17 06:41:26 DEBUG : three: Sizes differ (src 7 vs dst 5)
2022/01/17 06:41:26 DEBUG : three: Destination not found in --copy-dest
2022/01/17 06:41:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for checks to finish
2022/01/17 06:41:26 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:41:26 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:41:26 DEBUG : two: Unchanged skipping
2022/01/17 06:41:26 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:41:26 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/01/17 06:41:26 DEBUG : one: Unchanged skipping
2022/01/17 06:41:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for transfers to finish
2022/01/17 06:41:28 DEBUG : three: md5 = fd34f6fc5ee198530e18c9ca5385cc0f OK
2022/01/17 06:41:28 INFO  : three: Copied (new)
2022/01/17 06:41:28 DEBUG : Waiting for deletions to finish
2022/01/17 06:41:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2022/01/17 06:41:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2022/01/17 06:41:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/01/17 06:41:35 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2022/01/17 06:41:35 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2022/01/17 06:41:35 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/01/17 06:41:36 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (42.28s)
=== RUN   TestSyncBackupDir
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:41:39 DEBUG : dst/one: md5 = 2c2ee211a19612e6a2056e426b4633b2 OK
2022/01/17 06:41:41 DEBUG : dst/two: md5 = b7f0a2125f2edb9a9998ef108b1c8ac4 OK
2022/01/17 06:41:43 DEBUG : dst/three.txt: md5 = e3da15c500847de16bfd5fd9447291f3 OK
2022/01/17 06:41:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst"
2022/01/17 06:41:43 DEBUG : Creating backend with remote "TestDrive:crypt/hgot3mhm2tb9i7d08h8it2orgd0nttf9cb2111rlgbtpd3i5n5mgmqkjm12q9r8474a6p32dhucam/31u3jie661vd5p8j7rtc3hgbh0"
2022/01/17 06:41:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/backup"
2022/01/17 06:41:44 DEBUG : Creating backend with remote "TestDrive:crypt/hgot3mhm2tb9i7d08h8it2orgd0nttf9cb2111rlgbtpd3i5n5mgmqkjm12q9r8474a6p32dhucam/1nrff024r7pq65ecp72fc28jb0"
2022/01/17 06:41:46 DEBUG : one: Sizes differ (src 4 vs dst 3)
2022/01/17 06:41:46 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:41:46 DEBUG : two: Unchanged skipping
2022/01/17 06:41:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for checks to finish
2022/01/17 06:41:49 INFO  : one: Moved (server-side)
2022/01/17 06:41:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for transfers to finish
2022/01/17 06:41:50 DEBUG : one: md5 = abec629bf8544920cd3ecde31d8917e4 OK
2022/01/17 06:41:50 INFO  : one: Copied (new)
2022/01/17 06:41:50 DEBUG : Waiting for deletions to finish
2022/01/17 06:41:51 INFO  : three.txt: Moved (server-side)
2022/01/17 06:41:51 INFO  : three.txt: Moved into backup dir
2022/01/17 06:41:53 DEBUG : dst/three.txt: md5 = 5835dfff13a20405a9b26bc251a71315 OK
2022/01/17 06:41:54 DEBUG : one: Sizes differ (src 5 vs dst 4)
2022/01/17 06:41:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for checks to finish
2022/01/17 06:41:54 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:41:54 DEBUG : two: Unchanged skipping
2022/01/17 06:41:54 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2022/01/17 06:41:54 DEBUG : pacer: Rate limited, increasing sleep to 1.878334782s
2022/01/17 06:41:55 DEBUG : pacer: Reducing sleep to 0s
2022/01/17 06:41:57 INFO  : one: Deleted
2022/01/17 06:41:58 INFO  : one: Moved (server-side)
2022/01/17 06:41:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for transfers to finish
2022/01/17 06:42:00 DEBUG : one: md5 = da0d34c10ba4e736523d9a0f3790bb6e OK
2022/01/17 06:42:00 INFO  : one: Copied (new)
2022/01/17 06:42:00 DEBUG : Waiting for deletions to finish
2022/01/17 06:42:00 INFO  : three.txt: Deleted
2022/01/17 06:42:01 INFO  : three.txt: Moved (server-side)
2022/01/17 06:42:01 INFO  : three.txt: Moved into backup dir
2022/01/17 06:42:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/01/17 06:42:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2022/01/17 06:42:07 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2022/01/17 06:42:07 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/01/17 06:42:07 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/01/17 06:42:07 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
--- PASS: TestSyncBackupDir (31.01s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:42:10 DEBUG : dst/one: md5 = d149d7ed67aecfbd1d82959062c287b6 OK
2022/01/17 06:42:12 DEBUG : dst/two: md5 = 4492c95b87ce86164da509c5df6d9da8 OK
2022/01/17 06:42:14 DEBUG : dst/three.txt: md5 = 4486ed0c4708f3010cfd1d9f37366bfb OK
2022/01/17 06:42:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst"
2022/01/17 06:42:14 DEBUG : Creating backend with remote "TestDrive:crypt/hgot3mhm2tb9i7d08h8it2orgd0nttf9cb2111rlgbtpd3i5n5mgmqkjm12q9r8474a6p32dhucam/31u3jie661vd5p8j7rtc3hgbh0"
2022/01/17 06:42:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/backup"
2022/01/17 06:42:15 DEBUG : Creating backend with remote "TestDrive:crypt/hgot3mhm2tb9i7d08h8it2orgd0nttf9cb2111rlgbtpd3i5n5mgmqkjm12q9r8474a6p32dhucam/1nrff024r7pq65ecp72fc28jb0"
2022/01/17 06:42:17 DEBUG : one: Sizes differ (src 4 vs dst 3)
2022/01/17 06:42:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for checks to finish
2022/01/17 06:42:17 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:42:17 DEBUG : two: Unchanged skipping
2022/01/17 06:42:20 INFO  : one: Moved (server-side) to: one.bak
2022/01/17 06:42:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for transfers to finish
2022/01/17 06:42:21 DEBUG : one: md5 = e33eea112eae69a5f5dd117671f39ca8 OK
2022/01/17 06:42:21 INFO  : one: Copied (new)
2022/01/17 06:42:21 DEBUG : Waiting for deletions to finish
2022/01/17 06:42:23 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2022/01/17 06:42:23 INFO  : three.txt: Moved into backup dir
2022/01/17 06:42:25 DEBUG : dst/three.txt: md5 = a63ed8ab6786f48fed1f079df2514d82 OK
2022/01/17 06:42:26 DEBUG : one: Sizes differ (src 5 vs dst 4)
2022/01/17 06:42:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for checks to finish
2022/01/17 06:42:26 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:42:26 DEBUG : two: Unchanged skipping
2022/01/17 06:42:27 INFO  : one.bak: Deleted
2022/01/17 06:42:27 INFO  : one: Moved (server-side) to: one.bak
2022/01/17 06:42:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for transfers to finish
2022/01/17 06:42:29 DEBUG : one: md5 = a5bf3e8c27088ecf614415a70dfe0e5a OK
2022/01/17 06:42:29 INFO  : one: Copied (new)
2022/01/17 06:42:29 DEBUG : Waiting for deletions to finish
2022/01/17 06:42:30 INFO  : three.txt.bak: Deleted
2022/01/17 06:42:31 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2022/01/17 06:42:31 INFO  : three.txt: Moved into backup dir
2022/01/17 06:42:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/01/17 06:42:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2022/01/17 06:42:36 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2022/01/17 06:42:36 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2022/01/17 06:42:36 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2022/01/17 06:42:36 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncBackupDirWithSuffix (29.73s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:42:40 DEBUG : dst/one: md5 = 22f9cb42088bde13abce2aa77be7b6a0 OK
2022/01/17 06:42:41 DEBUG : dst/two: md5 = 03e04059f0af5182a79bac547a4920a1 OK
2022/01/17 06:42:43 DEBUG : dst/three.txt: md5 = 693dec60635316065d2b823c0bbeb5c8 OK
2022/01/17 06:42:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst"
2022/01/17 06:42:44 DEBUG : Creating backend with remote "TestDrive:crypt/hgot3mhm2tb9i7d08h8it2orgd0nttf9cb2111rlgbtpd3i5n5mgmqkjm12q9r8474a6p32dhucam/31u3jie661vd5p8j7rtc3hgbh0"
2022/01/17 06:42:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/backup"
2022/01/17 06:42:45 DEBUG : Creating backend with remote "TestDrive:crypt/hgot3mhm2tb9i7d08h8it2orgd0nttf9cb2111rlgbtpd3i5n5mgmqkjm12q9r8474a6p32dhucam/1nrff024r7pq65ecp72fc28jb0"
2022/01/17 06:42:47 DEBUG : one: Sizes differ (src 4 vs dst 3)
2022/01/17 06:42:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for checks to finish
2022/01/17 06:42:47 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:42:47 DEBUG : two: Unchanged skipping
2022/01/17 06:42:49 INFO  : one: Moved (server-side) to: one-2019-01-01
2022/01/17 06:42:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for transfers to finish
2022/01/17 06:42:51 DEBUG : one: md5 = 83ce3674e354d8b0543753b2ee0626e7 OK
2022/01/17 06:42:51 INFO  : one: Copied (new)
2022/01/17 06:42:51 DEBUG : Waiting for deletions to finish
2022/01/17 06:42:52 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2022/01/17 06:42:52 INFO  : three.txt: Moved into backup dir
2022/01/17 06:42:54 DEBUG : dst/three.txt: md5 = f60178c22c9f83f80a645da5c6bcf74e OK
2022/01/17 06:42:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for checks to finish
2022/01/17 06:42:55 DEBUG : one: Sizes differ (src 5 vs dst 4)
2022/01/17 06:42:55 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:42:55 DEBUG : two: Unchanged skipping
2022/01/17 06:42:56 INFO  : one-2019-01-01: Deleted
2022/01/17 06:42:57 INFO  : one: Moved (server-side) to: one-2019-01-01
2022/01/17 06:42:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for transfers to finish
2022/01/17 06:42:58 DEBUG : one: md5 = b9614ae0fba0e761fd002ae710ec63f4 OK
2022/01/17 06:42:58 INFO  : one: Copied (new)
2022/01/17 06:42:58 DEBUG : Waiting for deletions to finish
2022/01/17 06:42:59 INFO  : three-2019-01-01.txt: Deleted
2022/01/17 06:43:00 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2022/01/17 06:43:00 INFO  : three.txt: Moved into backup dir
2022/01/17 06:43:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/01/17 06:43:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2022/01/17 06:43:05 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2022/01/17 06:43:05 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2022/01/17 06:43:05 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2022/01/17 06:43:05 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (28.72s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:43:09 DEBUG : dst/one: md5 = b5955387522f325652f820081501bed6 OK
2022/01/17 06:43:10 DEBUG : dst/two: md5 = aa5eb38c3de54111838176a83a868dec OK
2022/01/17 06:43:12 DEBUG : dst/three.txt: md5 = 0e124c4c81fc83ae5aafc6582be9ac79 OK
2022/01/17 06:43:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst"
2022/01/17 06:43:12 DEBUG : Creating backend with remote "TestDrive:crypt/hgot3mhm2tb9i7d08h8it2orgd0nttf9cb2111rlgbtpd3i5n5mgmqkjm12q9r8474a6p32dhucam/31u3jie661vd5p8j7rtc3hgbh0"
2022/01/17 06:43:14 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2022/01/17 06:43:14 DEBUG : pacer: Rate limited, increasing sleep to 1.153467021s
2022/01/17 06:43:14 DEBUG : pacer: Reducing sleep to 0s
2022/01/17 06:43:14 DEBUG : one: Sizes differ (src 4 vs dst 3)
2022/01/17 06:43:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for checks to finish
2022/01/17 06:43:14 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:43:14 DEBUG : two: Unchanged skipping
2022/01/17 06:43:16 INFO  : one: Moved (server-side) to: one.bak
2022/01/17 06:43:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for transfers to finish
2022/01/17 06:43:17 DEBUG : one: md5 = 3b99dcc5de6d7a921feba6e882e99f2d OK
2022/01/17 06:43:17 INFO  : one: Copied (new)
2022/01/17 06:43:17 DEBUG : Waiting for deletions to finish
2022/01/17 06:43:18 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2022/01/17 06:43:18 INFO  : three.txt: Moved into backup dir
2022/01/17 06:43:20 DEBUG : dst/three.txt: md5 = 958171335bfc4a5a2cfb1516a4477164 OK
2022/01/17 06:43:21 DEBUG : three.txt.bak: Excluded
2022/01/17 06:43:21 DEBUG : one.bak: Excluded
2022/01/17 06:43:21 DEBUG : one: Sizes differ (src 5 vs dst 4)
2022/01/17 06:43:21 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:43:21 DEBUG : two: Unchanged skipping
2022/01/17 06:43:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for checks to finish
2022/01/17 06:43:22 INFO  : one.bak: Deleted
2022/01/17 06:43:23 INFO  : one: Moved (server-side) to: one.bak
2022/01/17 06:43:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst': Waiting for transfers to finish
2022/01/17 06:43:24 DEBUG : one: md5 = bf8520dd75d3f2c7de33f8b655d1c711 OK
2022/01/17 06:43:24 INFO  : one: Copied (new)
2022/01/17 06:43:24 DEBUG : Waiting for deletions to finish
2022/01/17 06:43:25 INFO  : three.txt.bak: Deleted
2022/01/17 06:43:26 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2022/01/17 06:43:26 INFO  : three.txt: Moved into backup dir
2022/01/17 06:43:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/01/17 06:43:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2022/01/17 06:43:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2022/01/17 06:43:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2022/01/17 06:43:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2022/01/17 06:43:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncBackupDirSuffixOnly (24.99s)
=== RUN   TestSyncSuffix
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:43:31 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2022/01/17 06:43:31 DEBUG : pacer: Rate limited, increasing sleep to 1.360217706s
2022/01/17 06:43:32 DEBUG : pacer: Reducing sleep to 0s
2022/01/17 06:43:35 DEBUG : dst/one: md5 = 4c03cef71ac4cad3fe82f5cfdb2486f8 OK
2022/01/17 06:43:37 DEBUG : dst/two: md5 = e848046c3b05b1bf5a5797f27802aa74 OK
2022/01/17 06:43:38 DEBUG : dst/three.txt: md5 = 56bf3f92351b7d819a11c3d42dd2db15 OK
2022/01/17 06:43:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst"
2022/01/17 06:43:39 DEBUG : Creating backend with remote "TestDrive:crypt/hgot3mhm2tb9i7d08h8it2orgd0nttf9cb2111rlgbtpd3i5n5mgmqkjm12q9r8474a6p32dhucam/31u3jie661vd5p8j7rtc3hgbh0"
2022/01/17 06:43:40 DEBUG : one: Sizes differ (src 4 vs dst 3)
2022/01/17 06:43:41 INFO  : one: Moved (server-side) to: one.bak
2022/01/17 06:43:42 DEBUG : one: md5 = 77660943fe495f03063b4ecd08aa4d0c OK
2022/01/17 06:43:42 INFO  : one: Copied (new)
2022/01/17 06:43:43 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:43:43 DEBUG : two: Unchanged skipping
2022/01/17 06:43:43 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2022/01/17 06:43:44 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2022/01/17 06:43:45 DEBUG : three.txt: md5 = c566e19fac1a2e75e86462773c9bf46d OK
2022/01/17 06:43:45 INFO  : three.txt: Copied (new)
2022/01/17 06:43:47 DEBUG : one: Sizes differ (src 5 vs dst 4)
2022/01/17 06:43:48 INFO  : one.bak: Deleted
2022/01/17 06:43:48 INFO  : one: Moved (server-side) to: one.bak
2022/01/17 06:43:50 DEBUG : one: md5 = f4b0add0b697e92bcd5a415933b02a5f OK
2022/01/17 06:43:50 INFO  : one: Copied (new)
2022/01/17 06:43:50 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:43:50 DEBUG : two: Unchanged skipping
2022/01/17 06:43:50 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2022/01/17 06:43:51 INFO  : three.txt.bak: Deleted
2022/01/17 06:43:52 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2022/01/17 06:43:53 DEBUG : three.txt: md5 = dc6482468938768aa594b9ba0c3bb281 OK
2022/01/17 06:43:53 INFO  : three.txt: Copied (new)
2022/01/17 06:43:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2022/01/17 06:43:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/01/17 06:43:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2022/01/17 06:43:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2022/01/17 06:43:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2022/01/17 06:43:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2022/01/17 06:43:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncSuffix (28.25s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:43:59 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2022/01/17 06:43:59 DEBUG : pacer: Rate limited, increasing sleep to 1.998586444s
2022/01/17 06:44:00 DEBUG : pacer: Reducing sleep to 0s
2022/01/17 06:44:04 DEBUG : dst/one: md5 = e4e288ab9edeb790140d8a0ec88fe095 OK
2022/01/17 06:44:05 DEBUG : dst/two: md5 = 5c4e9455d51aca55a4a023592f1c9fe3 OK
2022/01/17 06:44:05 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2022/01/17 06:44:05 DEBUG : pacer: Rate limited, increasing sleep to 1.998579358s
2022/01/17 06:44:06 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2022/01/17 06:44:06 DEBUG : pacer: Rate limited, increasing sleep to 2.772284273s
2022/01/17 06:44:08 DEBUG : pacer: Reducing sleep to 0s
2022/01/17 06:44:11 DEBUG : dst/three.txt: md5 = 979613c82c55632abb1aed45bf606e4f OK
2022/01/17 06:44:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8/dst"
2022/01/17 06:44:12 DEBUG : Creating backend with remote "TestDrive:crypt/hgot3mhm2tb9i7d08h8it2orgd0nttf9cb2111rlgbtpd3i5n5mgmqkjm12q9r8474a6p32dhucam/31u3jie661vd5p8j7rtc3hgbh0"
2022/01/17 06:44:13 DEBUG : one: Sizes differ (src 4 vs dst 3)
2022/01/17 06:44:13 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2022/01/17 06:44:13 DEBUG : pacer: Rate limited, increasing sleep to 1.774129036s
2022/01/17 06:44:14 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded)
2022/01/17 06:44:14 DEBUG : pacer: Rate limited, increasing sleep to 2.976728771s
2022/01/17 06:44:15 DEBUG : pacer: Reducing sleep to 0s
2022/01/17 06:44:19 INFO  : one: Moved (server-side) to: one-2019-01-01
2022/01/17 06:44:20 DEBUG : one: md5 = b917be7c48840e8b3132098c1c3e1c8b OK
2022/01/17 06:44:20 INFO  : one: Copied (new)
2022/01/17 06:44:20 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:44:20 DEBUG : two: Unchanged skipping
2022/01/17 06:44:21 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2022/01/17 06:44:22 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2022/01/17 06:44:23 DEBUG : three.txt: md5 = c83512fa4370c19fb19049805b3e3b1b OK
2022/01/17 06:44:23 INFO  : three.txt: Copied (new)
2022/01/17 06:44:24 DEBUG : one: Sizes differ (src 5 vs dst 4)
2022/01/17 06:44:25 INFO  : one-2019-01-01: Deleted
2022/01/17 06:44:26 INFO  : one: Moved (server-side) to: one-2019-01-01
2022/01/17 06:44:27 DEBUG : one: md5 = 010661d5074088271f3282e22e655a9e OK
2022/01/17 06:44:27 INFO  : one: Copied (new)
2022/01/17 06:44:28 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:44:28 DEBUG : two: Unchanged skipping
2022/01/17 06:44:28 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2022/01/17 06:44:29 INFO  : three-2019-01-01.txt: Deleted
2022/01/17 06:44:29 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2022/01/17 06:44:31 DEBUG : three.txt: md5 = 75d85592794b922790a3ba76a255f89a OK
2022/01/17 06:44:31 INFO  : three.txt: Copied (new)
2022/01/17 06:44:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2022/01/17 06:44:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/01/17 06:44:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2022/01/17 06:44:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2022/01/17 06:44:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2022/01/17 06:44:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2022/01/17 06:44:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncSuffixKeepExtension (36.51s)
=== RUN   TestSyncUTFNorm
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:44:37 DEBUG : Testêé: md5 = 7add357f9e8b0224f8254e6d528b70c4 OK
2022/01/17 06:44:38 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2022/01/17 06:44:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:44:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:44:39 DEBUG : Testêé: md5 = 7987062c60b345864b57db5e375f5fb2 OK
2022/01/17 06:44:39 INFO  : Testêé: Copied (replaced existing)
2022/01/17 06:44:39 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (4.56s)
=== RUN   TestSyncImmutable
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:44:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:44:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:44:42 DEBUG : existing: md5 = b21a78a9202dfd3470984e2c6341f773 OK
2022/01/17 06:44:42 INFO  : existing: Copied (new)
2022/01/17 06:44:42 DEBUG : Waiting for deletions to finish
2022/01/17 06:44:43 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2022/01/17 06:44:43 ERROR : existing: Source and destination exist but do not match: immutable file modified
2022/01/17 06:44:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:44:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:44:43 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': not deleting files as there were IO errors
2022/01/17 06:44:43 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': not deleting directories as there were IO errors
--- PASS: TestSyncImmutable (4.23s)
=== RUN   TestSyncIgnoreCase
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:44:46 DEBUG : EXISTING: md5 = 96a8f2772935c467b06f77834fb462b8 OK
2022/01/17 06:44:47 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:44:47 DEBUG : existing: Unchanged skipping
2022/01/17 06:44:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:44:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:44:47 DEBUG : Waiting for deletions to finish
2022/01/17 06:44:47 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (3.43s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
    sync_test.go:1989: This test only runs on local
=== RUN   TestMaxTransfer/Soft
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
    sync_test.go:1989: This test only runs on local
=== RUN   TestMaxTransfer/Cautious
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
    sync_test.go:1989: This test only runs on local
--- PASS: TestMaxTransfer (1.65s)
    --- SKIP: TestMaxTransfer/Hard (0.59s)
    --- SKIP: TestMaxTransfer/Soft (0.53s)
    --- SKIP: TestMaxTransfer/Cautious (0.53s)
=== RUN   TestSyncConcurrentDelete
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:44:51 DEBUG : both0: md5 = 173b0a235439a33353bd26c895e0403f OK
2022/01/17 06:44:53 DEBUG : only0: md5 = 009d198a8ec85640b13a2b26dc3902bd OK
2022/01/17 06:44:55 DEBUG : both1: md5 = 22b45a9f42c49a2c2a4966cd195e0fcb OK
2022/01/17 06:44:56 DEBUG : only1: md5 = ebd6d32b42c96b49debc40c1ba179e78 OK
2022/01/17 06:44:57 DEBUG : both2: md5 = 3a7d4334381dbd64bb0e9486acbe06f9 OK
2022/01/17 06:44:59 DEBUG : only2: md5 = 32d36b411da2def4a00ddae6520c5c75 OK
2022/01/17 06:45:00 DEBUG : both3: md5 = 5327549fd7ac564e7e48087775e3584f OK
2022/01/17 06:45:02 DEBUG : only3: md5 = 9d86b53ce5d3071b8a3a3667f9f98a03 OK
2022/01/17 06:45:03 DEBUG : both4: md5 = d95c9c7bdf6f617e82f094da17b31204 OK
2022/01/17 06:45:05 DEBUG : only4: md5 = 3a9e125590866cba7cc08f14c6b21ecd OK
2022/01/17 06:45:06 DEBUG : both5: md5 = 295f60437c479ae5f36301442d301d3f OK
2022/01/17 06:45:08 DEBUG : only5: md5 = 3adac0dad578b7612768f5cc70ba68da OK
2022/01/17 06:45:09 DEBUG : both6: md5 = 138b1b01d7422d7ed7863b73912ec8d6 OK
2022/01/17 06:45:11 DEBUG : only6: md5 = 058bd015bb6fcc106c9d59ce0d9695e7 OK
2022/01/17 06:45:12 DEBUG : both7: md5 = 97b467b7c16b7a0258352ae5e717fea4 OK
2022/01/17 06:45:14 DEBUG : only7: md5 = b7d055d47862a58fc3288c83918043ef OK
2022/01/17 06:45:16 DEBUG : both8: md5 = 26ea4dfb52afcc8af64811c990772235 OK
2022/01/17 06:45:17 DEBUG : only8: md5 = 22215cbac887b0d19337ed01f99b9f71 OK
2022/01/17 06:45:19 DEBUG : both9: md5 = 32106793dbddbeb249cb8927e8511a01 OK
2022/01/17 06:45:20 DEBUG : only9: md5 = f0dfb49572ce7bf60c4fdd2fc32e638b OK
2022/01/17 06:45:21 DEBUG : both10: md5 = dfc23cc3cb0f3f4b68832966baa88536 OK
2022/01/17 06:45:23 DEBUG : only10: md5 = 7a9fa069ab169f7f4ca34ad6bdd18991 OK
2022/01/17 06:45:24 DEBUG : both11: md5 = 98d0fe5d3bb173217a07cc850568d20e OK
2022/01/17 06:45:26 DEBUG : only11: md5 = edde514cbbb525b1eb62101ae10188d8 OK
2022/01/17 06:45:27 DEBUG : both12: md5 = 863bb44850ade044b95ee4a2a62a186d OK
2022/01/17 06:45:28 DEBUG : only12: md5 = c7bc743cf8d606cfd36f9d96a3a999c6 OK
2022/01/17 06:45:30 DEBUG : both13: md5 = f05c7bd3df67e2c04ffda622268afc39 OK
2022/01/17 06:45:31 DEBUG : only13: md5 = 29764ec57f6e2fb0725873f5fdc6b15e OK
2022/01/17 06:45:33 DEBUG : both14: md5 = 635be0c70a8095b20053a530ff9fed28 OK
2022/01/17 06:45:34 DEBUG : only14: md5 = 78bde1dbef65b1636cb3d1e2bac317b1 OK
2022/01/17 06:45:36 DEBUG : both15: md5 = 9284d0450a0f0407bd036f71f941c42b OK
2022/01/17 06:45:37 DEBUG : only15: md5 = 06a723dad7bd6cbeb61e94992449b3a0 OK
2022/01/17 06:45:39 DEBUG : both16: md5 = 13480acf89aab4ee5e55a5544235f046 OK
2022/01/17 06:45:40 DEBUG : only16: md5 = 2df1d9fef68f3db436283cfcaed97243 OK
2022/01/17 06:45:42 DEBUG : both17: md5 = 23203581ae838d665cdf80fb0d1eef91 OK
2022/01/17 06:45:43 DEBUG : only17: md5 = c54ab797a323560d55d6265cb3914d8a OK
2022/01/17 06:45:45 DEBUG : both18: md5 = 046ea3ec3895f682b2892246a44075b2 OK
2022/01/17 06:45:46 DEBUG : only18: md5 = 84e0ba65de9766d633df1cb0c452e9fa OK
2022/01/17 06:45:48 DEBUG : both19: md5 = 6054f0680080ea0a2395285b13d28979 OK
2022/01/17 06:45:49 DEBUG : only19: md5 = 48f23ee3ae33c24d2348e31dcab2fe09 OK
2022/01/17 06:45:50 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:45:50 DEBUG : both0: Unchanged skipping
2022/01/17 06:45:50 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:45:50 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:45:50 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:45:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:45:50 DEBUG : both1: Unchanged skipping
2022/01/17 06:45:50 DEBUG : both10: Unchanged skipping
2022/01/17 06:45:50 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:45:50 DEBUG : both13: Unchanged skipping
2022/01/17 06:45:50 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:45:50 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:45:50 DEBUG : both14: Unchanged skipping
2022/01/17 06:45:50 DEBUG : both15: Unchanged skipping
2022/01/17 06:45:50 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:45:50 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:45:50 DEBUG : both12: Unchanged skipping
2022/01/17 06:45:50 DEBUG : both17: Unchanged skipping
2022/01/17 06:45:50 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:45:50 DEBUG : both18: Unchanged skipping
2022/01/17 06:45:50 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:45:50 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:45:50 DEBUG : both19: Unchanged skipping
2022/01/17 06:45:50 DEBUG : both16: Unchanged skipping
2022/01/17 06:45:50 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:45:50 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:45:50 DEBUG : both2: Unchanged skipping
2022/01/17 06:45:50 DEBUG : both11: Unchanged skipping
2022/01/17 06:45:50 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:45:50 DEBUG : both4: Unchanged skipping
2022/01/17 06:45:50 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:45:50 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:45:50 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:45:50 DEBUG : both3: Unchanged skipping
2022/01/17 06:45:50 DEBUG : both7: Unchanged skipping
2022/01/17 06:45:50 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:45:50 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:45:50 DEBUG : both6: Unchanged skipping
2022/01/17 06:45:50 DEBUG : both9: Unchanged skipping
2022/01/17 06:45:50 DEBUG : both5: Unchanged skipping
2022/01/17 06:45:50 DEBUG : both8: Unchanged skipping
2022/01/17 06:45:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:45:50 DEBUG : Waiting for deletions to finish
2022/01/17 06:45:50 INFO  : only1: Deleted
2022/01/17 06:45:50 INFO  : only18: Deleted
2022/01/17 06:45:50 INFO  : only7: Deleted
2022/01/17 06:45:50 INFO  : only14: Deleted
2022/01/17 06:45:51 INFO  : only17: Deleted
2022/01/17 06:45:51 INFO  : only8: Deleted
2022/01/17 06:45:51 INFO  : only4: Deleted
2022/01/17 06:45:51 INFO  : only6: Deleted
2022/01/17 06:45:51 INFO  : only11: Deleted
2022/01/17 06:45:52 INFO  : only12: Deleted
2022/01/17 06:45:52 INFO  : only13: Deleted
2022/01/17 06:45:52 INFO  : only15: Deleted
2022/01/17 06:45:52 INFO  : only9: Deleted
2022/01/17 06:45:52 INFO  : only10: Deleted
2022/01/17 06:45:52 INFO  : only0: Deleted
2022/01/17 06:45:52 INFO  : only16: Deleted
2022/01/17 06:45:52 INFO  : only2: Deleted
2022/01/17 06:45:53 INFO  : only19: Deleted
2022/01/17 06:45:53 INFO  : only5: Deleted
2022/01/17 06:45:53 INFO  : only3: Deleted
2022/01/17 06:45:53 INFO  : There was nothing to transfer
--- PASS: TestSyncConcurrentDelete (74.54s)
=== RUN   TestSyncConcurrentTruncate
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8'", Local "Local file system at /tmp/rclone2614245315", Modify Window "1ms"
2022/01/17 06:46:06 DEBUG : both0: md5 = 5d81cbe4d203de8c3348dc2adefb3d65 OK
2022/01/17 06:46:07 DEBUG : only0: md5 = 3ac0777d98e02c6201feda0cfea749a8 OK
2022/01/17 06:46:08 DEBUG : both1: md5 = 32efe88f1721afb7fffb1302b2cc0384 OK
2022/01/17 06:46:10 DEBUG : only1: md5 = 9514a16d1573d9a65909ccc338c1dd6a OK
2022/01/17 06:46:11 DEBUG : both2: md5 = 1d603e7ceea20e9a1caf6896fcb04c61 OK
2022/01/17 06:46:13 DEBUG : only2: md5 = c757809417d99ded09a76374fd109522 OK
2022/01/17 06:46:14 DEBUG : both3: md5 = 7ae46e553e2319c163ed8489628400d3 OK
2022/01/17 06:46:16 DEBUG : only3: md5 = de15f9ce98d2dccc02f2749a2d59190c OK
2022/01/17 06:46:17 DEBUG : both4: md5 = 106c39282771c97e0d6b4742618f7eae OK
2022/01/17 06:46:18 DEBUG : only4: md5 = e7180641c27a1d281eeacff9b383985a OK
2022/01/17 06:46:20 DEBUG : both5: md5 = f1b7097e54065f2aabe342096b276f47 OK
2022/01/17 06:46:21 DEBUG : only5: md5 = 334034870677a38dabde8f6fb52c5c36 OK
2022/01/17 06:46:23 DEBUG : both6: md5 = 896004512a5542ea98c6b1fdd5646dd4 OK
2022/01/17 06:46:24 DEBUG : only6: md5 = 2d81f5b669693ba163e7d66889f92d4f OK
2022/01/17 06:46:26 DEBUG : both7: md5 = b57bec1733814af873453413f52f6ef8 OK
2022/01/17 06:46:27 DEBUG : only7: md5 = 75de8b2c205e97b1f8d765e0a78b11b5 OK
2022/01/17 06:46:28 DEBUG : both8: md5 = d6e47b8d1e30f87741587e6ac7790a6b OK
2022/01/17 06:46:30 DEBUG : only8: md5 = 4d3c087d0300df4e9a8972d70de3980f OK
2022/01/17 06:46:31 DEBUG : both9: md5 = 899aa1dc0adc4ce3247c51a24c11758d OK
2022/01/17 06:46:33 DEBUG : only9: md5 = 508c8afb74aca3d350b37e68c842e660 OK
2022/01/17 06:46:34 DEBUG : both10: md5 = 5770e5b200a34c1d4e69d21471608b53 OK
2022/01/17 06:46:35 DEBUG : only10: md5 = 3a62a3d8ae7194259ec4435c07dd23df OK
2022/01/17 06:46:37 DEBUG : both11: md5 = 354ca1371d9133ef2c561c76d161fd80 OK
2022/01/17 06:46:38 DEBUG : only11: md5 = c7899631b910d46712b94774d30448a5 OK
2022/01/17 06:46:40 DEBUG : both12: md5 = c0f2c2faad2e17fc63636aad42e6bf6d OK
2022/01/17 06:46:41 DEBUG : only12: md5 = 4ee0ca414312770efcd0da055b336321 OK
2022/01/17 06:46:43 DEBUG : both13: md5 = 3d8acd7ae959cf83e709c87037d6f0a8 OK
2022/01/17 06:46:44 DEBUG : only13: md5 = f25c9c9c932b07bd44053934cd7fa72c OK
2022/01/17 06:46:46 DEBUG : both14: md5 = 5fd0dc35a5f36bc14f36cd84f9277eb9 OK
2022/01/17 06:46:47 DEBUG : only14: md5 = f61a77f4926b3954d6d02ac87aa887fd OK
2022/01/17 06:46:48 DEBUG : both15: md5 = 514952f65b16541f7b75d395ac00fbc5 OK
2022/01/17 06:46:50 DEBUG : only15: md5 = 3b22b5e195331fd9907abb6e9a7d1d34 OK
2022/01/17 06:46:51 DEBUG : both16: md5 = b82292565e646b25d401472a5eb20031 OK
2022/01/17 06:46:53 DEBUG : only16: md5 = 52cf275454996c4f2e65dd39b0152fbf OK
2022/01/17 06:46:54 DEBUG : both17: md5 = ef8e606c200c83797a95a4d268c21b1e OK
2022/01/17 06:46:55 DEBUG : only17: md5 = 07a0327d155b166a2af9e22b4aa65459 OK
2022/01/17 06:46:57 DEBUG : both18: md5 = 4468468dae70d6cd9b24c76bc585bf97 OK
2022/01/17 06:46:58 DEBUG : only18: md5 = c526d2474f7104e9064806e56013d2e2 OK
2022/01/17 06:47:00 DEBUG : both19: md5 = bd29a2a472a81b9bfe6bb5342980c9b7 OK
2022/01/17 06:47:01 DEBUG : only19: md5 = c5a03796010346b6e27f9a36f8584576 OK
2022/01/17 06:47:02 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:47:02 DEBUG : both0: Unchanged skipping
2022/01/17 06:47:02 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:47:02 DEBUG : both1: Unchanged skipping
2022/01/17 06:47:02 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:47:02 DEBUG : both10: Unchanged skipping
2022/01/17 06:47:02 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:47:02 DEBUG : both11: Unchanged skipping
2022/01/17 06:47:02 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:47:02 DEBUG : both12: Unchanged skipping
2022/01/17 06:47:02 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:47:02 DEBUG : both13: Unchanged skipping
2022/01/17 06:47:02 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:47:02 DEBUG : both14: Unchanged skipping
2022/01/17 06:47:02 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:47:02 DEBUG : both15: Unchanged skipping
2022/01/17 06:47:02 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:47:02 DEBUG : both16: Unchanged skipping
2022/01/17 06:47:02 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:47:02 DEBUG : both17: Unchanged skipping
2022/01/17 06:47:02 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:47:02 DEBUG : both18: Unchanged skipping
2022/01/17 06:47:02 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:47:02 DEBUG : both19: Unchanged skipping
2022/01/17 06:47:02 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:47:02 DEBUG : both2: Unchanged skipping
2022/01/17 06:47:02 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:47:02 DEBUG : both3: Unchanged skipping
2022/01/17 06:47:02 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:47:02 DEBUG : both4: Unchanged skipping
2022/01/17 06:47:02 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:47:02 DEBUG : both5: Unchanged skipping
2022/01/17 06:47:02 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:47:02 DEBUG : both6: Unchanged skipping
2022/01/17 06:47:02 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:47:02 DEBUG : both7: Unchanged skipping
2022/01/17 06:47:02 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:47:02 DEBUG : both8: Unchanged skipping
2022/01/17 06:47:02 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/01/17 06:47:02 DEBUG : both9: Unchanged skipping
2022/01/17 06:47:02 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2022/01/17 06:47:02 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2022/01/17 06:47:02 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2022/01/17 06:47:02 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2022/01/17 06:47:02 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2022/01/17 06:47:02 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2022/01/17 06:47:02 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2022/01/17 06:47:02 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2022/01/17 06:47:02 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2022/01/17 06:47:02 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2022/01/17 06:47:02 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2022/01/17 06:47:02 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2022/01/17 06:47:02 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2022/01/17 06:47:02 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2022/01/17 06:47:02 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2022/01/17 06:47:02 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2022/01/17 06:47:02 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2022/01/17 06:47:02 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2022/01/17 06:47:02 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2022/01/17 06:47:02 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2022/01/17 06:47:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for checks to finish
2022/01/17 06:47:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Waiting for transfers to finish
2022/01/17 06:47:03 DEBUG : only11: md5 = 71294ef6964bc8cac4f3ffbb46be857c OK
2022/01/17 06:47:03 INFO  : only11: Copied (replaced existing)
2022/01/17 06:47:03 DEBUG : only0: md5 = 39114ce23a0f2ada5dc442b17e99debe OK
2022/01/17 06:47:03 INFO  : only0: Copied (replaced existing)
2022/01/17 06:47:03 DEBUG : only1: md5 = 6dc7103e717e64307b38edd691bbe1c1 OK
2022/01/17 06:47:03 INFO  : only1: Copied (replaced existing)
2022/01/17 06:47:03 DEBUG : only10: md5 = 0915afbe99bb59d219f19d03d803a090 OK
2022/01/17 06:47:03 INFO  : only10: Copied (replaced existing)
2022/01/17 06:47:04 DEBUG : only12: md5 = aa1e954e0ffb44e9cf606b0a7489651a OK
2022/01/17 06:47:04 INFO  : only12: Copied (replaced existing)
2022/01/17 06:47:04 DEBUG : only13: md5 = 2067274251a7c48eb1b4481463629020 OK
2022/01/17 06:47:04 INFO  : only13: Copied (replaced existing)
2022/01/17 06:47:04 DEBUG : only14: md5 = 07010a24701e3e3b1cf4aa9a7af56cda OK
2022/01/17 06:47:04 INFO  : only14: Copied (replaced existing)
2022/01/17 06:47:04 DEBUG : only15: md5 = 872c5275427ffb05ce6ffcb09582ac71 OK
2022/01/17 06:47:04 INFO  : only15: Copied (replaced existing)
2022/01/17 06:47:05 DEBUG : only16: md5 = d0aecf6b3161628775d8d72202401825 OK
2022/01/17 06:47:05 INFO  : only16: Copied (replaced existing)
2022/01/17 06:47:05 DEBUG : only17: md5 = c4044e2fbe1913bb918ebe7e83e83eae OK
2022/01/17 06:47:05 INFO  : only17: Copied (replaced existing)
2022/01/17 06:47:05 DEBUG : only19: md5 = daa4a568eb7fe02c9b322cd7457f3101 OK
2022/01/17 06:47:05 INFO  : only19: Copied (replaced existing)
2022/01/17 06:47:05 DEBUG : only18: md5 = a30b89537eaca9c15f7fc1fe8b323167 OK
2022/01/17 06:47:05 INFO  : only18: Copied (replaced existing)
2022/01/17 06:47:06 DEBUG : only2: md5 = 5fb01068c8a32259d38984f6c2b611f1 OK
2022/01/17 06:47:06 INFO  : only2: Copied (replaced existing)
2022/01/17 06:47:06 DEBUG : only3: md5 = a3c796d85d8566754673ce004f0f4ca1 OK
2022/01/17 06:47:06 INFO  : only3: Copied (replaced existing)
2022/01/17 06:47:07 DEBUG : only5: md5 = 962d428d59ccae77e224967767a30186 OK
2022/01/17 06:47:07 INFO  : only5: Copied (replaced existing)
2022/01/17 06:47:07 DEBUG : only4: md5 = dbc9f39de30c33cf9561b2077cf3a7d5 OK
2022/01/17 06:47:07 INFO  : only4: Copied (replaced existing)
2022/01/17 06:47:07 DEBUG : only6: md5 = 62306ea146e8920e3b8b89afac7796af OK
2022/01/17 06:47:07 INFO  : only6: Copied (replaced existing)
2022/01/17 06:47:08 DEBUG : only7: md5 = 8600845716c262849417a780b4228ded OK
2022/01/17 06:47:08 INFO  : only7: Copied (replaced existing)
2022/01/17 06:47:08 DEBUG : only9: md5 = aaab80faea3b9bb69a84a25cc2f5c546 OK
2022/01/17 06:47:08 INFO  : only9: Copied (replaced existing)
2022/01/17 06:47:08 DEBUG : only8: md5 = 8c41d5c26d5fe3561a7b1c8302376815 OK
2022/01/17 06:47:08 INFO  : only8: Copied (replaced existing)
2022/01/17 06:47:08 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncConcurrentTruncate (85.66s)
PASS
2022/01/17 06:47:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-letediz0tojuxuh9miwohuy8': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 13m15.298840698s (try 1/5)