"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5)
2022/06/12 06:55:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2"
2022/06/12 06:55:36 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2022/06/12 06:55:37 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e"
2022/06/12 06:55:38 DEBUG : Creating backend with remote "/tmp/rclone1762447505"
=== 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-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:55:39 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2022/06/12 06:55:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:55:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
--- PASS: TestCopyWithDryRun (2.18s)
=== RUN   TestCopy
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:55:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:55:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:55:43 DEBUG : sub dir/hello world: md5 = ccf3764503c9ae5fc7e395a793a6cf6d OK
2022/06/12 06:55:43 INFO  : sub dir/hello world: Copied (new)
2022/06/12 06:55:45 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (5.86s)
=== RUN   TestCopyMissingDirectory
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:55:46 DEBUG : Creating backend with remote "/non-existing"
2022/06/12 06:55:46 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2022/06/12 06:55:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:55:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
--- PASS: TestCopyMissingDirectory (0.80s)
=== RUN   TestCopyNoTraverse
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:55:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:55:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:55:49 DEBUG : sub dir/hello world: md5 = 2c488b72927c1ccb069de05d5493ce7c OK
2022/06/12 06:55:49 INFO  : sub dir/hello world: Copied (new)
2022/06/12 06:55:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (5.82s)
=== RUN   TestCopyCheckFirst
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:55:52 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Running all checks before starting transfers
2022/06/12 06:55:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:55:53 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Checks finished, now starting transfers
2022/06/12 06:55:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:55:55 DEBUG : sub dir/hello world: md5 = 4f5c586be29810d1722e3f3607cc59f9 OK
2022/06/12 06:55:55 INFO  : sub dir/hello world: Copied (new)
2022/06/12 06:55:57 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (5.83s)
=== RUN   TestSyncNoTraverse
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:55:58 ERROR : Ignoring --no-traverse with sync
2022/06/12 06:55:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:55:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:56:01 DEBUG : sub dir/hello world: md5 = 2ea03d38833b1ce46f5ed93775d87aad OK
2022/06/12 06:56:01 INFO  : sub dir/hello world: Copied (new)
2022/06/12 06:56:01 DEBUG : Waiting for deletions to finish
2022/06/12 06:56:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (5.90s)
=== RUN   TestCopyWithDepth
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:56:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:56:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:56:06 DEBUG : hello world2: md5 = 5639c03d28ca79ad28ef93be0e35c0ce OK
2022/06/12 06:56:06 INFO  : hello world2: Copied (new)
--- PASS: TestCopyWithDepth (3.43s)
=== RUN   TestCopyWithFilesFrom
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:56:08 DEBUG : hello world2: Excluded
2022/06/12 06:56:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:56:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:56:09 DEBUG : potato2: md5 = 3228f6b19d55566dbb693e8502f84065 OK
2022/06/12 06:56:09 INFO  : potato2: Copied (new)
--- PASS: TestCopyWithFilesFrom (3.32s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:56:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:56:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:56:13 DEBUG : potato2: md5 = a6f5b773cf8377a952ebcf469e22206a OK
2022/06/12 06:56:13 INFO  : potato2: Copied (new)
--- PASS: TestCopyWithFilesFromAndNoTraverse (3.50s)
=== RUN   TestCopyEmptyDirectories
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:56:14 DEBUG : sub dir2: Making directory
2022/06/12 06:56:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:56:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:56:17 DEBUG : sub dir/hello world: md5 = 6cd4a5302a352a43a4cbea8aefd85d35 OK
2022/06/12 06:56:17 INFO  : sub dir/hello world: Copied (new)
2022/06/12 06:56:17 DEBUG : sub dir2: Making directory
2022/06/12 06:56:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': copied 1 directories
2022/06/12 06:56:21 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (7.80s)
=== RUN   TestMoveEmptyDirectories
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:56:22 DEBUG : sub dir2: Making directory
2022/06/12 06:56:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:56:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:56:25 DEBUG : sub dir/hello world: md5 = 3ce9c76fdee749e72c4720b52cfd0b34 OK
2022/06/12 06:56:25 INFO  : sub dir/hello world: Copied (new)
2022/06/12 06:56:25 INFO  : sub dir/hello world: Deleted
2022/06/12 06:56:25 DEBUG : sub dir: Making directory
2022/06/12 06:56:25 DEBUG : sub dir2: Making directory
2022/06/12 06:56:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': copied 2 directories
2022/06/12 06:56:29 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (7.42s)
=== RUN   TestSyncEmptyDirectories
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:56:30 DEBUG : sub dir2: Making directory
2022/06/12 06:56:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:56:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:56:32 DEBUG : sub dir/hello world: md5 = e32b38edaefbdc6bfe6f75d000e952ac OK
2022/06/12 06:56:32 INFO  : sub dir/hello world: Copied (new)
2022/06/12 06:56:32 DEBUG : sub dir2: Making directory
2022/06/12 06:56:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': copied 1 directories
2022/06/12 06:56:33 DEBUG : Waiting for deletions to finish
2022/06/12 06:56:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (7.46s)
=== RUN   TestServerSideCopy
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:56:40 DEBUG : sub dir/hello world: md5 = 4f2eda5e759d83ce048d8bdbfddcf211 OK
2022/06/12 06:56:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dotopam9nabutub8lohahoq0"
2022/06/12 06:56:41 DEBUG : Creating backend with remote "TestDrive:crypt/gaoi8cb8u0humchv402o4q0faki11c8vapfc9qtvtnucms45i4v75afenekmurpamvjmhjeu22r6c"
    sync_test.go:275: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2' -> Encrypted drive 'TestCryptDrive:rclone-test-dotopam9nabutub8lohahoq0'
2022/06/12 06:56:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dotopam9nabutub8lohahoq0': Waiting for checks to finish
2022/06/12 06:56:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dotopam9nabutub8lohahoq0': Waiting for transfers to finish
2022/06/12 06:56:46 INFO  : sub dir/hello world: Copied (server-side copy)
2022/06/12 06:56:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dotopam9nabutub8lohahoq0': Purge remote
2022/06/12 06:56:48 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (12.25s)
=== RUN   TestCopyAfterDelete
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:56:52 DEBUG : sub dir/hello world: md5 = 58ef274fd4539b120b5369a8b50a9774 OK
2022/06/12 06:56:52 ERROR : : error listing: directory not found
2022/06/12 06:56:53 DEBUG : Local file system at /tmp/rclone1762447505: Making directory
2022/06/12 06:56:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:56:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:56:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (6.53s)
=== RUN   TestCopyRedownload
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:56:58 DEBUG : sub dir/hello world: md5 = 8f7f475b189cddd98f807d739e607806 OK
2022/06/12 06:57:00 DEBUG : Local file system at /tmp/rclone1762447505: Waiting for checks to finish
2022/06/12 06:57:00 DEBUG : Local file system at /tmp/rclone1762447505: Waiting for transfers to finish
2022/06/12 06:57:01 INFO  : sub dir/hello world: Copied (new)
2022/06/12 06:57:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (6.98s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:57:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:57:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:57:05 DEBUG : check sum: md5 = 7b1675b7c67481d49175e1495833bb29 OK
2022/06/12 06:57:05 INFO  : check sum: Copied (new)
2022/06/12 06:57:05 DEBUG : Waiting for deletions to finish
2022/06/12 06:57:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:57:05 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2022/06/12 06:57:05 DEBUG : check sum: Size of src and dst objects identical
2022/06/12 06:57:05 DEBUG : check sum: Unchanged skipping
2022/06/12 06:57:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:57:05 DEBUG : Waiting for deletions to finish
2022/06/12 06:57:05 INFO  : There was nothing to transfer
--- PASS: TestSyncBasedOnCheckSum (4.02s)
=== RUN   TestSyncSizeOnly
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:57:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:57:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:57:09 DEBUG : sizeonly: md5 = f5e4054e995d383815af4aa8dd7097b1 OK
2022/06/12 06:57:09 INFO  : sizeonly: Copied (new)
2022/06/12 06:57:09 DEBUG : Waiting for deletions to finish
2022/06/12 06:57:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:57:09 DEBUG : sizeonly: Sizes identical
2022/06/12 06:57:09 DEBUG : sizeonly: Unchanged skipping
2022/06/12 06:57:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:57:09 DEBUG : Waiting for deletions to finish
2022/06/12 06:57:09 INFO  : There was nothing to transfer
--- PASS: TestSyncSizeOnly (4.03s)
=== RUN   TestSyncIgnoreSize
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:57:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:57:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:57:13 DEBUG : ignore-size: md5 = 8eef92f4250b420623d2ad0ae9bfdb42 OK
2022/06/12 06:57:13 INFO  : ignore-size: Copied (new)
2022/06/12 06:57:13 DEBUG : Waiting for deletions to finish
2022/06/12 06:57:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:57:14 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 06:57:14 DEBUG : ignore-size: Unchanged skipping
2022/06/12 06:57:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:57:14 DEBUG : Waiting for deletions to finish
2022/06/12 06:57:14 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreSize (4.04s)
=== RUN   TestSyncIgnoreTimes
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:57:16 DEBUG : existing: md5 = 9134493e5a9b551ecdab2de217f3a072 OK
2022/06/12 06:57:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:57:17 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 06:57:17 DEBUG : existing: Unchanged skipping
2022/06/12 06:57:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:57:17 DEBUG : Waiting for deletions to finish
2022/06/12 06:57:17 INFO  : There was nothing to transfer
2022/06/12 06:57:17 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2022/06/12 06:57:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:57:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:57:19 DEBUG : existing: md5 = 2bdd3d7b03c68dcdb204491ef143da72 OK
2022/06/12 06:57:19 INFO  : existing: Copied (replaced existing)
2022/06/12 06:57:19 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncIgnoreTimes (4.98s)
=== RUN   TestSyncIgnoreExisting
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:57:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:57:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:57:22 DEBUG : existing: md5 = d82519ed81b923c30fd7e80f2f3be2fb OK
2022/06/12 06:57:22 INFO  : existing: Copied (new)
2022/06/12 06:57:22 DEBUG : Waiting for deletions to finish
2022/06/12 06:57:22 DEBUG : existing: Destination exists, skipping
2022/06/12 06:57:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:57:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:57:22 DEBUG : Waiting for deletions to finish
2022/06/12 06:57:22 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreExisting (3.89s)
=== RUN   TestSyncIgnoreErrors
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:57:27 DEBUG : b/potato: md5 = e745c5bc0e858709458975a38f292d2d OK
2022/06/12 06:57:29 DEBUG : c/non empty space: md5 = 16d899c688164b8bb445e2d37ba8e03b OK
2022/06/12 06:57:29 DEBUG : d: Making directory
2022/06/12 06:57:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:57:31 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 06:57:31 DEBUG : c/non empty space: Unchanged skipping
2022/06/12 06:57:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:57:34 DEBUG : a/potato2: md5 = c16b69497c3657bc29d2007d68216e6e OK
2022/06/12 06:57:34 INFO  : a/potato2: Copied (new)
2022/06/12 06:57:34 DEBUG : Waiting for deletions to finish
2022/06/12 06:57:34 INFO  : b/potato: Deleted
2022/06/12 06:57:34 INFO  : d: Removing directory
2022/06/12 06:57:35 INFO  : b: Removing directory
2022/06/12 06:57:35 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2022/06/12 06:57:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': deleted 2 directories
2022/06/12 06:57:39 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2022/06/12 06:57:40 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (16.73s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:57:42 DEBUG : empty space: md5 = 089dc50ded5328be4b9ce0a4ccc941aa OK
2022/06/12 06:57:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:57:43 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/06/12 06:57:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:57:43 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2022/06/12 06:57:43 DEBUG : Waiting for deletions to finish
2022/06/12 06:57:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:57:43 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/06/12 06:57:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:57:45 DEBUG : empty space: md5 = 6641b0b20eee9dd618281e5eee1c6380 OK
2022/06/12 06:57:45 INFO  : empty space: Copied (replaced existing)
2022/06/12 06:57:45 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncAfterChangingModtimeOnly (5.38s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
    sync_test.go:577: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.56s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:57:48 DEBUG : foo: md5 = 1aedc82de403529a41fbeac2e696479e OK
2022/06/12 06:57:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:57:49 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/06/12 06:57:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:57:50 DEBUG : foo: md5 = 1c343e20a6f018061e402fb851495a3c OK
2022/06/12 06:57:50 INFO  : foo: Copied (replaced existing)
2022/06/12 06:57:50 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncDoesntUpdateModtime (4.85s)
=== RUN   TestSyncAfterAddingAFile
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:57:53 DEBUG : empty space: md5 = db5e6e3f538653b837ae07cfea2b125d OK
2022/06/12 06:57:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:57:53 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 06:57:53 DEBUG : empty space: Unchanged skipping
2022/06/12 06:57:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:57:55 DEBUG : potato: md5 = d587a94a2229d06866792702033bbce3 OK
2022/06/12 06:57:55 INFO  : potato: Copied (new)
2022/06/12 06:57:55 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncAfterAddingAFile (5.70s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:57:59 DEBUG : potato: md5 = a700eaeeb6408cfd58cafb5ea0f1c5a2 OK
2022/06/12 06:58:00 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2022/06/12 06:58:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:58:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:58:01 DEBUG : potato: md5 = dcbb71ee1228c20279c2db20fd84f89a OK
2022/06/12 06:58:01 INFO  : potato: Copied (replaced existing)
2022/06/12 06:58:01 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncAfterChangingFilesSizeOnly (5.52s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:58:04 DEBUG : potato: md5 = d732c5f660e78824b8bbc9a65c6f6464 OK
2022/06/12 06:58:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:58:05 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/06/12 06:58:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:58:06 DEBUG : potato: md5 = ed6e252e89808f6f2acef2561a21c4b0 OK
2022/06/12 06:58:06 INFO  : potato: Copied (replaced existing)
2022/06/12 06:58:06 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncAfterChangingContentsOnly (4.97s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:58:09 DEBUG : potato: md5 = 4e476063222a604fb39b1fe6f9410b28 OK
2022/06/12 06:58:11 DEBUG : empty space: md5 = e0d39d48fc49108d12ccd4b1230f9483 OK
2022/06/12 06:58:11 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2022/06/12 06:58:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:58:11 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 06:58:11 DEBUG : empty space: Unchanged skipping
2022/06/12 06:58:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:58:11 DEBUG : Waiting for deletions to finish
2022/06/12 06:58:11 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.55s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:58:15 DEBUG : potato: md5 = e1a0ff331df11306f79d394908a62b8b OK
2022/06/12 06:58:16 DEBUG : empty space: md5 = 68a9b3a531ea41010d760d668158ada9 OK
2022/06/12 06:58:17 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 06:58:17 DEBUG : empty space: Unchanged skipping
2022/06/12 06:58:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:58:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:58:18 DEBUG : potato2: md5 = fbfed5146e994be09c86b0c455371998 OK
2022/06/12 06:58:18 INFO  : potato2: Copied (new)
2022/06/12 06:58:18 DEBUG : Waiting for deletions to finish
2022/06/12 06:58:19 INFO  : potato: Deleted
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.30s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:58:24 DEBUG : b/potato: md5 = d1e751432209c89e0f1b9d49cc667325 OK
2022/06/12 06:58:26 DEBUG : c/non empty space: md5 = 568196724769e3e89195c99c6e7254d2 OK
2022/06/12 06:58:26 DEBUG : d: Making directory
2022/06/12 06:58:27 DEBUG : d/e: Making directory
2022/06/12 06:58:30 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 06:58:30 DEBUG : c/non empty space: Unchanged skipping
2022/06/12 06:58:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:58:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:58:32 DEBUG : a/potato2: md5 = 9a456b404b22335c415dbef5e98843b7 OK
2022/06/12 06:58:32 INFO  : a/potato2: Copied (new)
2022/06/12 06:58:32 DEBUG : Waiting for deletions to finish
2022/06/12 06:58:33 INFO  : b/potato: Deleted
2022/06/12 06:58:33 INFO  : d/e: Removing directory
2022/06/12 06:58:34 INFO  : d: Removing directory
2022/06/12 06:58:34 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2022/06/12 06:58:35 INFO  : b: Removing directory
2022/06/12 06:58:35 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2022/06/12 06:58:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': deleted 3 directories
2022/06/12 06:58:38 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2022/06/12 06:58:39 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (18.53s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:58:43 DEBUG : b/potato: md5 = eab1242dbe2db85943d1e68c1dc6ba0b OK
2022/06/12 06:58:45 DEBUG : c/non empty space: md5 = cbf37070bf922a0c46d2be9b8bcb5a4d OK
2022/06/12 06:58:45 DEBUG : d: Making directory
2022/06/12 06:58:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:58:48 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 06:58:48 DEBUG : c/non empty space: Unchanged skipping
2022/06/12 06:58:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:58:50 DEBUG : a/potato2: md5 = a270d580385bb25f4cec617ff75e51bb OK
2022/06/12 06:58:50 INFO  : a/potato2: Copied (new)
2022/06/12 06:58:50 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': not deleting files as there were IO errors
2022/06/12 06:58:50 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': not deleting directories as there were IO errors
2022/06/12 06:58:54 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2022/06/12 06:58:55 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2022/06/12 06:58:56 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (17.26s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:58:59 DEBUG : potato: md5 = 42637ead3eefeac8f5a7bef92b182d17 OK
2022/06/12 06:59:00 DEBUG : empty space: md5 = a6d23e935fe4518909bf9e127be119f8 OK
2022/06/12 06:59:01 DEBUG : Waiting for deletions to finish
2022/06/12 06:59:01 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 06:59:01 DEBUG : empty space: Unchanged skipping
2022/06/12 06:59:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:59:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:59:02 INFO  : potato: Deleted
2022/06/12 06:59:03 DEBUG : potato2: md5 = bfab785f3044ab6410aea844779888ba OK
2022/06/12 06:59:03 INFO  : potato2: Copied (new)
--- PASS: TestSyncDeleteDuring (7.55s)
=== RUN   TestSyncDeleteBefore
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:59:06 DEBUG : potato: md5 = bcc8ae684b3f70c64064c80c825db86b OK
2022/06/12 06:59:08 DEBUG : empty space: md5 = b5b369cc119eb7537c3bc81b36675403 OK
2022/06/12 06:59:08 DEBUG : Waiting for deletions to finish
2022/06/12 06:59:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:59:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:59:09 INFO  : potato: Deleted
2022/06/12 06:59:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:59:09 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 06:59:09 DEBUG : empty space: Unchanged skipping
2022/06/12 06:59:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:59:11 DEBUG : potato2: md5 = 9ae3b62d1946dd88ba9b3ed8b18a578e OK
2022/06/12 06:59:11 INFO  : potato2: Copied (new)
--- PASS: TestSyncDeleteBefore (8.52s)
=== RUN   TestCopyDeleteBefore
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:59:15 DEBUG : potato: md5 = 081fd36c397c4da15c86998adc58f8bf OK
2022/06/12 06:59:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:59:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:59:17 DEBUG : potato2: md5 = 13dc407a17bd18e4d7feee773bce3dea OK
2022/06/12 06:59:17 INFO  : potato2: Copied (new)
--- PASS: TestCopyDeleteBefore (6.16s)
=== RUN   TestSyncWithExclude
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:59:21 DEBUG : potato2: md5 = 2e28a7bd60c2fe5ec51d14c0c1fff990 OK
2022/06/12 06:59:23 DEBUG : empty space: md5 = 8f7ab33aee21d94afafd2e1cfa3f69b0 OK
2022/06/12 06:59:23 DEBUG : enormous: Excluded
2022/06/12 06:59:23 DEBUG : potato2: Excluded
2022/06/12 06:59:23 DEBUG : potato2: Excluded
2022/06/12 06:59:23 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 06:59:23 DEBUG : empty space: Unchanged skipping
2022/06/12 06:59:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:59:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:59:23 DEBUG : Waiting for deletions to finish
2022/06/12 06:59:23 INFO  : There was nothing to transfer
2022/06/12 06:59:24 DEBUG : enormous: Excluded
2022/06/12 06:59:24 DEBUG : potato2: Excluded
2022/06/12 06:59:24 DEBUG : potato2: Excluded
2022/06/12 06:59:24 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2022/06/12 06:59:24 DEBUG : empty space: Unchanged skipping
2022/06/12 06:59:24 DEBUG : Local file system at /tmp/rclone1762447505: Waiting for checks to finish
2022/06/12 06:59:24 DEBUG : Local file system at /tmp/rclone1762447505: Waiting for transfers to finish
2022/06/12 06:59:24 DEBUG : Waiting for deletions to finish
2022/06/12 06:59:24 INFO  : There was nothing to transfer
--- PASS: TestSyncWithExclude (6.35s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:59:27 DEBUG : potato2: md5 = 1e81dec372d224b32d0c44a3b29df006 OK
2022/06/12 06:59:29 DEBUG : empty space: md5 = d2ab9ba3d2e27ce3fcba06c243232199 OK
2022/06/12 06:59:30 DEBUG : enormous: md5 = bf42e3842b8b6fe9f7d784a5dd81b714 OK
2022/06/12 06:59:31 DEBUG : enormous: Excluded
2022/06/12 06:59:31 DEBUG : potato2: Excluded
2022/06/12 06:59:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:59:31 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 06:59:31 DEBUG : empty space: Unchanged skipping
2022/06/12 06:59:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:59:31 DEBUG : Waiting for deletions to finish
2022/06/12 06:59:32 INFO  : potato2: Deleted
2022/06/12 06:59:32 INFO  : enormous: Deleted
2022/06/12 06:59:32 INFO  : There was nothing to transfer
2022/06/12 06:59:32 DEBUG : Local file system at /tmp/rclone1762447505: Waiting for checks to finish
2022/06/12 06:59:32 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2022/06/12 06:59:32 DEBUG : empty space: Unchanged skipping
2022/06/12 06:59:32 DEBUG : Local file system at /tmp/rclone1762447505: Waiting for transfers to finish
2022/06/12 06:59:32 DEBUG : Waiting for deletions to finish
2022/06/12 06:59:32 INFO  : potato2: Deleted
2022/06/12 06:59:32 INFO  : enormous: Deleted
2022/06/12 06:59:32 INFO  : There was nothing to transfer
--- PASS: TestSyncWithExcludeAndDeleteExcluded (7.69s)
=== RUN   TestSyncWithUpdateOlder
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 06:59:35 DEBUG : one: md5 = 4f3a84a30097a3404bd6ab142f2e6759 OK
2022/06/12 06:59:37 DEBUG : two: md5 = ceff2a251226337f1713e30515f8b3b0 OK
2022/06/12 06:59:38 DEBUG : three: md5 = b4973908896f4f5ec38bcd532ebdcdcc OK
2022/06/12 06:59:40 DEBUG : four: md5 = 179564d58a718c1b6d1c136bcdd2cdc3 OK
2022/06/12 06:59:41 DEBUG : four: Sizes differ (src 4 vs dst 8)
2022/06/12 06:59:41 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2022/06/12 06:59:41 DEBUG : one: Destination is newer than source, skipping
2022/06/12 06:59:41 DEBUG : three: Sizes identical
2022/06/12 06:59:41 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2022/06/12 06:59:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:59:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:59:42 DEBUG : four: md5 = 1fd9874528b551d2a19fe68a5b87b8c8 OK
2022/06/12 06:59:42 INFO  : four: Copied (replaced existing)
2022/06/12 06:59:42 DEBUG : two: md5 = cee450cc470cf08b0bd6e29e229e2776 OK
2022/06/12 06:59:42 INFO  : two: Copied (replaced existing)
2022/06/12 06:59:42 DEBUG : five: md5 = 0bd5846c6f9c89ba0d3992fbf17c5e74 OK
2022/06/12 06:59:42 INFO  : five: Copied (new)
2022/06/12 06:59:42 DEBUG : Waiting for deletions to finish
    sync_test.go:992: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (12.63s)
=== 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-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
    sync_test.go:1058: Can track renames: false
2022/06/12 06:59:46 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Ignoring --track-renames as the source and destination do not have a common hash
2022/06/12 06:59:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:59:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:59:48 DEBUG : potato: md5 = 3442c56a0c3a0ac45616aa092a9998b1 OK
2022/06/12 06:59:48 INFO  : potato: Copied (new)
2022/06/12 06:59:48 DEBUG : yam: md5 = 8738036899179b87a54316972e33cf14 OK
2022/06/12 06:59:48 INFO  : yam: Copied (new)
2022/06/12 06:59:48 DEBUG : Waiting for deletions to finish
2022/06/12 06:59:49 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Ignoring --track-renames as the source and destination do not have a common hash
2022/06/12 06:59:49 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 06:59:49 DEBUG : potato: Unchanged skipping
2022/06/12 06:59:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:59:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:59:50 DEBUG : yaml: md5 = bb9c673750aee205d5eef7f14d4a0a07 OK
2022/06/12 06:59:50 INFO  : yaml: Copied (new)
2022/06/12 06:59:50 DEBUG : Waiting for deletions to finish
2022/06/12 06:59:51 INFO  : yam: Deleted
--- PASS: TestSyncWithTrackRenames (6.99s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
    sync_test.go:1127: Can track renames: true
2022/06/12 06:59:53 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Making map for --track-renames
2022/06/12 06:59:53 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Finished making map for --track-renames
2022/06/12 06:59:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:59:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for renames to finish
2022/06/12 06:59:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:59:55 DEBUG : yam: md5 = 9b25928df2eddd5559f5813a65abca04 OK
2022/06/12 06:59:55 INFO  : yam: Copied (new)
2022/06/12 06:59:55 DEBUG : potato: md5 = ae28368800a16ee1af9d21a115391a9a OK
2022/06/12 06:59:55 INFO  : potato: Copied (new)
2022/06/12 06:59:55 DEBUG : Waiting for deletions to finish
2022/06/12 06:59:56 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 06:59:56 DEBUG : potato: Unchanged skipping
2022/06/12 06:59:56 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Making map for --track-renames
2022/06/12 06:59:56 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Finished making map for --track-renames
2022/06/12 06:59:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:59:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for renames to finish
2022/06/12 06:59:57 INFO  : yam: Moved (server-side) to: yaml
2022/06/12 06:59:57 INFO  : yaml: Renamed from "yam"
2022/06/12 06:59:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 06:59:57 DEBUG : Waiting for deletions to finish
2022/06/12 06:59:57 INFO  : There was nothing to transfer
--- PASS: TestSyncWithTrackRenamesStrategyModtime (5.62s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
    sync_test.go:1163: Can track renames: true
2022/06/12 06:59:59 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Making map for --track-renames
2022/06/12 06:59:59 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Finished making map for --track-renames
2022/06/12 06:59:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 06:59:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for renames to finish
2022/06/12 06:59:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 07:00:01 DEBUG : sub/yam: md5 = 50dbbd064c825c8e3c78f6c8372f3a9f OK
2022/06/12 07:00:01 INFO  : sub/yam: Copied (new)
2022/06/12 07:00:01 DEBUG : potato: md5 = 427e0ccc5fd09ff264def98a79103358 OK
2022/06/12 07:00:01 INFO  : potato: Copied (new)
2022/06/12 07:00:01 DEBUG : Waiting for deletions to finish
2022/06/12 07:00:02 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:00:02 DEBUG : potato: Unchanged skipping
2022/06/12 07:00:03 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Making map for --track-renames
2022/06/12 07:00:03 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Finished making map for --track-renames
2022/06/12 07:00:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 07:00:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for renames to finish
2022/06/12 07:00:04 INFO  : sub/yam: Moved (server-side) to: yam
2022/06/12 07:00:04 INFO  : yam: Renamed from "sub/yam"
2022/06/12 07:00:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 07:00:04 DEBUG : Waiting for deletions to finish
2022/06/12 07:00:04 INFO  : There was nothing to transfer
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (8.82s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:00:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 07:00:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 07:00:11 DEBUG : sub dir/hello world: md5 = db0ac555cf607abddf7890ae285f3127 OK
2022/06/12 07:00:11 INFO  : sub dir/hello world: Copied (new)
2022/06/12 07:00:11 INFO  : sub dir/hello world: Deleted
2022/06/12 07:00:13 DEBUG : nested/sub dir/file: md5 = 278cb56bac40db0a479e139bd0d20d59 OK
2022/06/12 07:00:13 INFO  : nested/sub dir/file: Copied (new)
2022/06/12 07:00:13 INFO  : nested/sub dir/file: Deleted
2022/06/12 07:00:13 INFO  : sub dir: Removing directory
2022/06/12 07:00:13 INFO  : nested/sub dir: Removing directory
2022/06/12 07:00:13 INFO  : nested: Removing directory
2022/06/12 07:00:13 DEBUG : Local file system at /tmp/rclone1762447505: deleted 3 directories
2022/06/12 07:00:16 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2022/06/12 07:00:17 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2022/06/12 07:00:18 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (10.80s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:00:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 07:00:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 07:00:21 DEBUG : sub dir/hello world: md5 = 56ecea6f56d5e536179d09a6fd0bd1cf OK
2022/06/12 07:00:21 INFO  : sub dir/hello world: Copied (new)
2022/06/12 07:00:21 INFO  : sub dir/hello world: Deleted
2022/06/12 07:00:23 DEBUG : nested/sub dir/file: md5 = 10a52e865ec14afb1b663ca2bf838bd4 OK
2022/06/12 07:00:23 INFO  : nested/sub dir/file: Copied (new)
2022/06/12 07:00:23 INFO  : nested/sub dir/file: Deleted
2022/06/12 07:00:27 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2022/06/12 07:00:28 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2022/06/12 07:00:29 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (11.13s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:00:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 07:00:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 07:00:31 DEBUG : existing: md5 = 2796cb754d48e2c5e42632a98110f4ab OK
2022/06/12 07:00:31 INFO  : existing: Copied (new)
2022/06/12 07:00:31 INFO  : existing: Deleted
2022/06/12 07:00:31 DEBUG : existing-b: md5 = 88b15b9403ead727fc5277a9e0c0152b OK
2022/06/12 07:00:31 INFO  : existing-b: Copied (new)
2022/06/12 07:00:31 INFO  : existing-b: Deleted
2022/06/12 07:00:32 DEBUG : existing: Destination exists, skipping
2022/06/12 07:00:32 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2022/06/12 07:00:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 07:00:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 07:00:32 INFO  : There was nothing to transfer
--- PASS: TestMoveWithIgnoreExisting (4.46s)
=== RUN   TestServerSideMove
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:00:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tinemex1xuviyux0kugunid4"
2022/06/12 07:00:34 DEBUG : Config file has changed externaly - reloading
2022/06/12 07:00:34 DEBUG : Creating backend with remote "TestDrive:crypt/fiq69q0qsm296qvubl5rdosvrm4pjiengeiicvh7o5satpn4adraf00a0tkghiuku4fo032nfaore"
2022/06/12 07:00:37 DEBUG : potato2: md5 = fd0f321a002760421787d82ac25f5d50 OK
2022/06/12 07:00:39 DEBUG : empty space: md5 = 41803a4e137d200d7beb47cb178598b7 OK
2022/06/12 07:00:40 DEBUG : potato3: md5 = 1607fc41fc1a8f33b31169fb720158ac OK
    sync_test.go:1215: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2' -> Encrypted drive 'TestCryptDrive:rclone-test-tinemex1xuviyux0kugunid4'
2022/06/12 07:00:43 DEBUG : empty space: md5 = 37577c4f35a70abc0d688a98bafc105c OK
2022/06/12 07:00:45 DEBUG : potato3: md5 = 159f1d12f876c3d83e65d53293398a80 OK
2022/06/12 07:00:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tinemex1xuviyux0kugunid4': Using server-side directory move
2022/06/12 07:00:45 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tinemex1xuviyux0kugunid4': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2022/06/12 07:00:45 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2022/06/12 07:00:45 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2022/06/12 07:00:45 DEBUG : empty space: Unchanged skipping
2022/06/12 07:00:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tinemex1xuviyux0kugunid4': Waiting for checks to finish
2022/06/12 07:00:46 INFO  : empty space: Deleted
2022/06/12 07:00:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tinemex1xuviyux0kugunid4': Waiting for transfers to finish
2022/06/12 07:00:46 INFO  : potato3: Deleted
2022/06/12 07:00:46 INFO  : potato2: Moved (server-side)
2022/06/12 07:00:47 INFO  : potato3: Moved (server-side)
2022/06/12 07:00:47 INFO  : There was nothing to transfer
2022/06/12 07:00:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sufevij2vomagaf5misuzek0"
2022/06/12 07:00:47 DEBUG : Creating backend with remote "TestDrive:crypt/irdikpkbdg5ca6edooovlbbc7t1qghrbdc05ji57qe8ponv38bppbou52rrfho6d0ppr3k26t9gac"
2022/06/12 07:00:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sufevij2vomagaf5misuzek0': Using server-side directory move
2022/06/12 07:00:49 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-sufevij2vomagaf5misuzek0': Server side directory move succeeded
2022/06/12 07:00:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sufevij2vomagaf5misuzek0': Purge remote
2022/06/12 07:00:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tinemex1xuviyux0kugunid4': Purge remote
2022/06/12 07:00:52 purge failed: directory not found
--- PASS: TestServerSideMove (18.31s)
=== RUN   TestServerSideMoveWithFilter
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:00:52 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cejelih5vacimib0nunitad2"
2022/06/12 07:00:52 DEBUG : Creating backend with remote "TestDrive:crypt/gh7lv76aspc44f6nc1du5ranva151r3v7aqks4fk61oemcoandk21vfngii9a602klclj7hqik31e"
2022/06/12 07:00:53 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/06/12 07:00:53 DEBUG : pacer: Rate limited, increasing sleep to 1.459064466s
2022/06/12 07:00:53 DEBUG : pacer: Reducing sleep to 0s
2022/06/12 07:00:56 DEBUG : potato2: md5 = 3bf184a2897ecbeaf725822ea99713ea OK
2022/06/12 07:00:58 DEBUG : empty space: md5 = 809ebe6ec80ec34b3a89cd5f8dd1d78f OK
2022/06/12 07:01:00 DEBUG : potato3: md5 = cf75820d54c260abda5c9532add7e604 OK
    sync_test.go:1215: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2' -> Encrypted drive 'TestCryptDrive:rclone-test-cejelih5vacimib0nunitad2'
2022/06/12 07:01:03 DEBUG : empty space: md5 = 59561719e021b614f7cacd80d199cf4f OK
2022/06/12 07:01:04 DEBUG : potato3: md5 = fca8bdc4a37f89faa1814cb6de838484 OK
2022/06/12 07:01:05 DEBUG : empty space: Excluded
2022/06/12 07:01:05 DEBUG : empty space: Excluded
2022/06/12 07:01:05 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2022/06/12 07:01:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cejelih5vacimib0nunitad2': Waiting for checks to finish
2022/06/12 07:01:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cejelih5vacimib0nunitad2': Waiting for transfers to finish
2022/06/12 07:01:06 INFO  : potato3: Deleted
2022/06/12 07:01:06 INFO  : potato2: Moved (server-side)
2022/06/12 07:01:07 INFO  : potato3: Moved (server-side)
2022/06/12 07:01:07 INFO  : There was nothing to transfer
2022/06/12 07:01:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qaqeqoy7dofakiw0fatuluf3"
2022/06/12 07:01:07 DEBUG : Creating backend with remote "TestDrive:crypt/fck21tjfl4c20jf2bd0ji3sin8e1d0erbrcapbse97il4nbkprm2tf4qpm4hgeeas80j7r5fntpfk"
2022/06/12 07:01:09 DEBUG : empty space: Excluded
2022/06/12 07:01:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qaqeqoy7dofakiw0fatuluf3': Waiting for checks to finish
2022/06/12 07:01:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qaqeqoy7dofakiw0fatuluf3': Waiting for transfers to finish
2022/06/12 07:01:11 INFO  : potato2: Moved (server-side)
2022/06/12 07:01:11 INFO  : potato3: Moved (server-side)
2022/06/12 07:01:11 INFO  : There was nothing to transfer
2022/06/12 07:01:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qaqeqoy7dofakiw0fatuluf3': Purge remote
2022/06/12 07:01:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cejelih5vacimib0nunitad2': Purge remote
--- PASS: TestServerSideMoveWithFilter (22.28s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:01:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-batazov5mipelel8zejidux0"
2022/06/12 07:01:15 DEBUG : Creating backend with remote "TestDrive:crypt/q2lh2d4vbbuhgvt4vo4p85hp692ahubemqioha02vc822eqmgblgt7e11vrua782agv176vf4d3b4"
2022/06/12 07:01:17 DEBUG : potato2: md5 = afff4f69f66b42ee60804ca5fe09bfb8 OK
2022/06/12 07:01:19 DEBUG : empty space: md5 = 48d9489fc6583d26bf7a68be35ff62f5 OK
2022/06/12 07:01:21 DEBUG : potato3: md5 = 95ed19fb05886cdd8422c6029af8b27c OK
2022/06/12 07:01:21 DEBUG : tomatoDir: Making directory
    sync_test.go:1215: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2' -> Encrypted drive 'TestCryptDrive:rclone-test-batazov5mipelel8zejidux0'
2022/06/12 07:01:25 DEBUG : empty space: md5 = 02c0366bd5d0d24e7aa0699c1eb7de07 OK
2022/06/12 07:01:27 DEBUG : potato3: md5 = c4bc9743d2ae389764764a34b60c3f9f OK
2022/06/12 07:01:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-batazov5mipelel8zejidux0': Using server-side directory move
2022/06/12 07:01:27 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-batazov5mipelel8zejidux0': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2022/06/12 07:01:27 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2022/06/12 07:01:27 DEBUG : empty space: Unchanged skipping
2022/06/12 07:01:27 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2022/06/12 07:01:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-batazov5mipelel8zejidux0': Waiting for checks to finish
2022/06/12 07:01:28 INFO  : empty space: Deleted
2022/06/12 07:01:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-batazov5mipelel8zejidux0': Waiting for transfers to finish
2022/06/12 07:01:28 INFO  : potato2: Moved (server-side)
2022/06/12 07:01:29 INFO  : potato3: Deleted
2022/06/12 07:01:29 INFO  : potato3: Moved (server-side)
2022/06/12 07:01:29 INFO  : tomatoDir: Removing directory
2022/06/12 07:01:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': deleted 1 directories
2022/06/12 07:01:30 INFO  : There was nothing to transfer
2022/06/12 07:01:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qubitox8detoduq8zujuyel5"
2022/06/12 07:01:31 DEBUG : Config file has changed externaly - reloading
2022/06/12 07:01:31 DEBUG : Creating backend with remote "TestDrive:crypt/3ftniq5bhog88bkgc0e5hs6mdf5q1ptkrpj0av98rh3guuocu33epv78pmd690jk7drge9839j9b6"
2022/06/12 07:01:33 DEBUG : tomatoDir: Making directory
2022/06/12 07:01:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qubitox8detoduq8zujuyel5': Using server-side directory move
2022/06/12 07:01:35 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-qubitox8detoduq8zujuyel5': Server side directory move succeeded
2022/06/12 07:01:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qubitox8detoduq8zujuyel5': Purge remote
2022/06/12 07:01:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-batazov5mipelel8zejidux0': Purge remote
2022/06/12 07:01:37 purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (23.54s)
=== RUN   TestServerSideMoveOverlap
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
    sync_test.go:1399: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.53s)
=== RUN   TestSyncOverlap
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:01:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/rclone-sync-test"
2022/06/12 07:01:39 DEBUG : Config file has changed externaly - reloading
2022/06/12 07:01:39 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
--- PASS: TestSyncOverlap (2.39s)
=== RUN   TestSyncOverlapWithFilter
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:01:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/rclone-sync-test"
2022/06/12 07:01:41 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2022/06/12 07:01:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/rclone-sync-test-include/layer2"
2022/06/12 07:01:44 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2022/06/12 07:01:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/rclone-sync-test-ignore-file"
2022/06/12 07:01:48 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2022/06/12 07:01:52 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 5406c7918097be3464bcefeccfd1642c OK
2022/06/12 07:01:53 DEBUG : rclone-sync-test-ignore-file: Excluded
2022/06/12 07:01:54 DEBUG : rclone-sync-test: Excluded
2022/06/12 07:01:54 DEBUG : rclone-sync-test-include/layer2: Excluded
2022/06/12 07:01:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/rclone-sync-test': Waiting for checks to finish
2022/06/12 07:01:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/rclone-sync-test': Waiting for transfers to finish
2022/06/12 07:01:54 DEBUG : Waiting for deletions to finish
2022/06/12 07:01:54 INFO  : There was nothing to transfer
2022/06/12 07:01:56 DEBUG : rclone-sync-test-ignore-file: Excluded
2022/06/12 07:01:56 DEBUG : rclone-sync-test: Excluded
2022/06/12 07:01:57 DEBUG : rclone-sync-test-include/layer2: Excluded
2022/06/12 07:01:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/rclone-sync-test-include/layer2': Waiting for checks to finish
2022/06/12 07:01:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/rclone-sync-test-include/layer2': Waiting for transfers to finish
2022/06/12 07:01:57 DEBUG : Waiting for deletions to finish
2022/06/12 07:01:57 INFO  : There was nothing to transfer
2022/06/12 07:01:57 DEBUG : : Excluded
2022/06/12 07:01:58 DEBUG : rclone-sync-test-ignore-file: Excluded
2022/06/12 07:01:58 DEBUG : rclone-sync-test: Excluded
2022/06/12 07:01:59 DEBUG : rclone-sync-test-include/layer2: Excluded
2022/06/12 07:01:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/rclone-sync-test-ignore-file': Waiting for checks to finish
2022/06/12 07:01:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/rclone-sync-test-ignore-file': Waiting for transfers to finish
2022/06/12 07:01:59 DEBUG : Waiting for deletions to finish
2022/06/12 07:01:59 INFO  : There was nothing to transfer
2022/06/12 07:02:01 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2022/06/12 07:02:02 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (23.42s)
=== RUN   TestSyncCompareDest
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:02:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst"
2022/06/12 07:02:04 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/31u3jie661vd5p8j7rtc3hgbh0"
2022/06/12 07:02:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/CompareDest"
2022/06/12 07:02:06 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/gveqi14airsml4bgu7krj116o8"
2022/06/12 07:02:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for checks to finish
2022/06/12 07:02:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for transfers to finish
2022/06/12 07:02:12 DEBUG : one: md5 = b09db665e53fba565a103cb08e054841 OK
2022/06/12 07:02:12 INFO  : one: Copied (new)
2022/06/12 07:02:12 DEBUG : Waiting for deletions to finish
2022/06/12 07:02:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for checks to finish
2022/06/12 07:02:14 DEBUG : one: Sizes differ (src 5 vs dst 3)
2022/06/12 07:02:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for transfers to finish
2022/06/12 07:02:15 DEBUG : one: md5 = a1cd0f55349a80c33383d496c6af08ff OK
2022/06/12 07:02:15 INFO  : one: Copied (replaced existing)
2022/06/12 07:02:15 DEBUG : Waiting for deletions to finish
2022/06/12 07:02:17 DEBUG : dst/one: md5 = 580d55868eaebaf5ab0616087a597134 OK
2022/06/12 07:02:20 DEBUG : CompareDest/one: md5 = 95f058fa78e2cafa78e970f60c100e2e OK
2022/06/12 07:02:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for checks to finish
2022/06/12 07:02:22 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 07:02:22 DEBUG : one: Destination found in --compare-dest, skipping
2022/06/12 07:02:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for transfers to finish
2022/06/12 07:02:22 DEBUG : Waiting for deletions to finish
2022/06/12 07:02:22 INFO  : There was nothing to transfer
2022/06/12 07:02:24 DEBUG : CompareDest/two: md5 = 446d45366d6d19f8f8b5e6fc5e261ea4 OK
2022/06/12 07:02:25 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 07:02:25 DEBUG : two: Destination found in --compare-dest, skipping
2022/06/12 07:02:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for checks to finish
2022/06/12 07:02:26 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 07:02:26 DEBUG : one: Destination found in --compare-dest, skipping
2022/06/12 07:02:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for transfers to finish
2022/06/12 07:02:26 DEBUG : Waiting for deletions to finish
2022/06/12 07:02:26 INFO  : There was nothing to transfer
2022/06/12 07:02:27 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 07:02:27 DEBUG : two: Destination found in --compare-dest, skipping
2022/06/12 07:02:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for checks to finish
2022/06/12 07:02:27 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 07:02:27 DEBUG : one: Destination found in --compare-dest, skipping
2022/06/12 07:02:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for transfers to finish
2022/06/12 07:02:27 DEBUG : Waiting for deletions to finish
2022/06/12 07:02:27 INFO  : There was nothing to transfer
    sync_test.go:1600: No hash on uploaded file so skipping compare timestamp test
2022/06/12 07:02:29 DEBUG : two: Sizes differ (src 5 vs dst 3)
2022/06/12 07:02:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for checks to finish
2022/06/12 07:02:30 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 07:02:30 DEBUG : one: Destination found in --compare-dest, skipping
2022/06/12 07:02:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for transfers to finish
2022/06/12 07:02:31 DEBUG : two: md5 = d0d795a92fa907dfae4f73440d5f7a4d OK
2022/06/12 07:02:31 INFO  : two: Copied (new)
2022/06/12 07:02:31 DEBUG : Waiting for deletions to finish
2022/06/12 07:02:32 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/06/12 07:02:32 DEBUG : pacer: Rate limited, increasing sleep to 1.137356422s
2022/06/12 07:02:32 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/06/12 07:02:32 DEBUG : pacer: Rate limited, increasing sleep to 2.609535518s
2022/06/12 07:02:32 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/06/12 07:02:32 DEBUG : pacer: Rate limited, increasing sleep to 4.623587856s
2022/06/12 07:02:34 DEBUG : pacer: Reducing sleep to 0s
2022/06/12 07:02:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2022/06/12 07:02:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/06/12 07:02:42 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2022/06/12 07:02:42 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCompareDest (38.32s)
=== RUN   TestSyncMultipleCompareDest
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:02:45 DEBUG : pre-dest1/1: md5 = e6c6de201388376f362013d04be139d5 OK
2022/06/12 07:02:48 DEBUG : pre-dest2/2: md5 = 65beae6bbbb431701df3606298cb6816 OK
2022/06/12 07:02:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dest"
2022/06/12 07:02:49 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/rg03c1jvnehrrc617i0lnqjddc"
2022/06/12 07:02:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/pre-dest1"
2022/06/12 07:02:51 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/bbnblvh6k061ssopqrp18kd7gc"
2022/06/12 07:02:52 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/pre-dest2"
2022/06/12 07:02:52 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/dgicm1h6b5ejvlltm8eeif0bnk"
2022/06/12 07:02:54 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:02:54 DEBUG : 1: Destination found in --compare-dest, skipping
2022/06/12 07:02:54 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:02:54 DEBUG : 2: Destination found in --compare-dest, skipping
2022/06/12 07:02:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dest': Waiting for checks to finish
2022/06/12 07:02:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dest': Waiting for transfers to finish
2022/06/12 07:02:57 DEBUG : 3: md5 = 6829f8687a350534f55a972145d3fc4e OK
2022/06/12 07:02:57 INFO  : 3: Copied (new)
2022/06/12 07:02:57 DEBUG : Waiting for deletions to finish
2022/06/12 07:03:01 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2022/06/12 07:03:02 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2022/06/12 07:03:03 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (21.24s)
=== RUN   TestSyncCopyDest
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:03:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst"
2022/06/12 07:03:04 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/31u3jie661vd5p8j7rtc3hgbh0"
2022/06/12 07:03:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/CopyDest"
2022/06/12 07:03:06 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/d09o6po3f7bm6ce32vdgs8h9ls"
2022/06/12 07:03:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for checks to finish
2022/06/12 07:03:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for transfers to finish
2022/06/12 07:03:11 DEBUG : one: md5 = d85be0406a1a9493bc7275ae86156f48 OK
2022/06/12 07:03:11 INFO  : one: Copied (new)
2022/06/12 07:03:11 DEBUG : Waiting for deletions to finish
2022/06/12 07:03:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for checks to finish
2022/06/12 07:03:13 DEBUG : one: Sizes differ (src 5 vs dst 3)
2022/06/12 07:03:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for transfers to finish
2022/06/12 07:03:14 DEBUG : one: md5 = e2d63627da4cd8ad17567523ae9a1886 OK
2022/06/12 07:03:14 INFO  : one: Copied (replaced existing)
2022/06/12 07:03:14 DEBUG : Waiting for deletions to finish
2022/06/12 07:03:16 DEBUG : dst/one: md5 = 5e9011d560cc76af57cb57cc16c740e1 OK
2022/06/12 07:03:19 DEBUG : CopyDest/one: md5 = da96a91ca79a41bdf377b5f6f032607c OK
2022/06/12 07:03:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/BackupDir"
2022/06/12 07:03:20 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/s6dbk3lfi7c9kfvo6j7bla9m0g"
2022/06/12 07:03:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for checks to finish
2022/06/12 07:03:23 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 07:03:23 DEBUG : one: Sizes differ (src 5 vs dst 3)
2022/06/12 07:03:25 INFO  : one: Moved (server-side)
2022/06/12 07:03:27 INFO  : one: Copied (server-side copy)
2022/06/12 07:03:27 DEBUG : one: Destination found in --copy-dest, using server-side copy
2022/06/12 07:03:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for transfers to finish
2022/06/12 07:03:27 DEBUG : Waiting for deletions to finish
2022/06/12 07:03:29 DEBUG : CopyDest/two: md5 = 8c6d4c89166cdc5c0e7a344e2fe2af37 OK
2022/06/12 07:03:30 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 07:03:32 INFO  : two: Copied (server-side copy)
2022/06/12 07:03:32 DEBUG : two: Destination found in --copy-dest, using server-side copy
2022/06/12 07:03:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for checks to finish
2022/06/12 07:03:32 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 07:03:32 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 07:03:32 DEBUG : one: Unchanged skipping
2022/06/12 07:03:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for transfers to finish
2022/06/12 07:03:32 DEBUG : Waiting for deletions to finish
2022/06/12 07:03:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for checks to finish
2022/06/12 07:03:33 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 07:03:33 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 07:03:33 DEBUG : one: Unchanged skipping
2022/06/12 07:03:33 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 07:03:33 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 07:03:33 DEBUG : two: Unchanged skipping
2022/06/12 07:03:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for transfers to finish
2022/06/12 07:03:33 DEBUG : Waiting for deletions to finish
2022/06/12 07:03:33 INFO  : There was nothing to transfer
2022/06/12 07:03:36 DEBUG : CopyDest/three: md5 = 3c6d421c7871c7721e79749ddde1c3f5 OK
2022/06/12 07:03:37 DEBUG : three: Sizes differ (src 7 vs dst 5)
2022/06/12 07:03:37 DEBUG : three: Destination not found in --copy-dest
2022/06/12 07:03:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for checks to finish
2022/06/12 07:03:37 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 07:03:37 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 07:03:37 DEBUG : one: Unchanged skipping
2022/06/12 07:03:37 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 07:03:37 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2022/06/12 07:03:37 DEBUG : two: Unchanged skipping
2022/06/12 07:03:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for transfers to finish
2022/06/12 07:03:39 DEBUG : three: md5 = b55c36913a4750808c8e2e1e744e5943 OK
2022/06/12 07:03:39 INFO  : three: Copied (new)
2022/06/12 07:03:39 DEBUG : Waiting for deletions to finish
2022/06/12 07:03:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2022/06/12 07:03:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2022/06/12 07:03:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/06/12 07:03:47 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2022/06/12 07:03:47 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/06/12 07:03:47 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2022/06/12 07:03:48 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (45.13s)
=== RUN   TestSyncBackupDir
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:03:52 DEBUG : dst/one: md5 = 259c5d1b64f0ed73bb0f7cf8cad1c243 OK
2022/06/12 07:03:54 DEBUG : dst/two: md5 = 4dc5c065bcf1ea7eab179f58cd441cd4 OK
2022/06/12 07:03:56 DEBUG : dst/three.txt: md5 = 93f8334f19bd10a0850cd9c16d754419 OK
2022/06/12 07:03:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst"
2022/06/12 07:03:57 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/31u3jie661vd5p8j7rtc3hgbh0"
2022/06/12 07:03:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/backup"
2022/06/12 07:03:57 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/1nrff024r7pq65ecp72fc28jb0"
2022/06/12 07:04:00 DEBUG : one: Sizes differ (src 4 vs dst 3)
2022/06/12 07:04:00 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:04:00 DEBUG : two: Unchanged skipping
2022/06/12 07:04:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for checks to finish
2022/06/12 07:04:02 INFO  : one: Moved (server-side)
2022/06/12 07:04:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for transfers to finish
2022/06/12 07:04:04 DEBUG : one: md5 = 45adf98b13506cfee3afa4b9850f7582 OK
2022/06/12 07:04:04 INFO  : one: Copied (new)
2022/06/12 07:04:04 DEBUG : Waiting for deletions to finish
2022/06/12 07:04:05 INFO  : three.txt: Moved (server-side)
2022/06/12 07:04:05 INFO  : three.txt: Moved into backup dir
2022/06/12 07:04:08 DEBUG : dst/three.txt: md5 = 6382638af9c813d0877a5b85c6314418 OK
2022/06/12 07:04:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for checks to finish
2022/06/12 07:04:09 DEBUG : one: Sizes differ (src 5 vs dst 4)
2022/06/12 07:04:09 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:04:09 DEBUG : two: Unchanged skipping
2022/06/12 07:04:10 INFO  : one: Deleted
2022/06/12 07:04:10 INFO  : one: Moved (server-side)
2022/06/12 07:04:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for transfers to finish
2022/06/12 07:04:12 DEBUG : one: md5 = 08fdbc2a5a4c5f009f4eb278ba13e7b6 OK
2022/06/12 07:04:12 INFO  : one: Copied (new)
2022/06/12 07:04:12 DEBUG : Waiting for deletions to finish
2022/06/12 07:04:13 INFO  : three.txt: Deleted
2022/06/12 07:04:14 INFO  : three.txt: Moved (server-side)
2022/06/12 07:04:14 INFO  : three.txt: Moved into backup dir
2022/06/12 07:04:18 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/06/12 07:04:18 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2022/06/12 07:04:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2022/06/12 07:04:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/06/12 07:04:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2022/06/12 07:04:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncBackupDir (30.58s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:04:22 DEBUG : dst/one: md5 = a489e99880224f9e74ab2085b51eea42 OK
2022/06/12 07:04:24 DEBUG : dst/two: md5 = dcd1137cdd357cc8c6ef8b7d2f22058c OK
2022/06/12 07:04:26 DEBUG : dst/three.txt: md5 = 3550cff17f37d4e6c71c966d08f46f2f OK
2022/06/12 07:04:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst"
2022/06/12 07:04:27 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/31u3jie661vd5p8j7rtc3hgbh0"
2022/06/12 07:04:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/backup"
2022/06/12 07:04:28 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/1nrff024r7pq65ecp72fc28jb0"
2022/06/12 07:04:30 DEBUG : one: Sizes differ (src 4 vs dst 3)
2022/06/12 07:04:30 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:04:30 DEBUG : two: Unchanged skipping
2022/06/12 07:04:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for checks to finish
2022/06/12 07:04:32 INFO  : one: Moved (server-side) to: one.bak
2022/06/12 07:04:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for transfers to finish
2022/06/12 07:04:34 DEBUG : one: md5 = 62bac2927efcd8c138f3b40f043d2c16 OK
2022/06/12 07:04:34 INFO  : one: Copied (new)
2022/06/12 07:04:34 DEBUG : Waiting for deletions to finish
2022/06/12 07:04:35 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2022/06/12 07:04:35 INFO  : three.txt: Moved into backup dir
2022/06/12 07:04:37 DEBUG : dst/three.txt: md5 = 63374c9cbbbc017e3ecc2335fbd97289 OK
2022/06/12 07:04:38 DEBUG : one: Sizes differ (src 5 vs dst 4)
2022/06/12 07:04:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for checks to finish
2022/06/12 07:04:38 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:04:38 DEBUG : two: Unchanged skipping
2022/06/12 07:04:39 INFO  : one.bak: Deleted
2022/06/12 07:04:40 INFO  : one: Moved (server-side) to: one.bak
2022/06/12 07:04:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for transfers to finish
2022/06/12 07:04:41 DEBUG : one: md5 = 8f03334010d99a5f4dc98ff897187610 OK
2022/06/12 07:04:41 INFO  : one: Copied (new)
2022/06/12 07:04:41 DEBUG : Waiting for deletions to finish
2022/06/12 07:04:42 INFO  : three.txt.bak: Deleted
2022/06/12 07:04:43 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2022/06/12 07:04:43 INFO  : three.txt: Moved into backup dir
2022/06/12 07:04:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/06/12 07:04:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2022/06/12 07:04:48 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2022/06/12 07:04:48 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2022/06/12 07:04:48 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2022/06/12 07:04:48 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncBackupDirWithSuffix (29.13s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:04:52 DEBUG : dst/one: md5 = 649dc45811f706a5f275c3a8825e3c93 OK
2022/06/12 07:04:53 DEBUG : dst/two: md5 = d56590604087459ca8b0a48890fc7f5a OK
2022/06/12 07:04:57 DEBUG : dst/three.txt: md5 = 5a3d19e7a3ac02ad6f7f1ecf65156732 OK
2022/06/12 07:04:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst"
2022/06/12 07:04:57 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/31u3jie661vd5p8j7rtc3hgbh0"
2022/06/12 07:04:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/backup"
2022/06/12 07:04:58 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/1nrff024r7pq65ecp72fc28jb0"
2022/06/12 07:05:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for checks to finish
2022/06/12 07:05:01 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:05:01 DEBUG : two: Unchanged skipping
2022/06/12 07:05:01 DEBUG : one: Sizes differ (src 4 vs dst 3)
2022/06/12 07:05:03 INFO  : one: Moved (server-side) to: one-2019-01-01
2022/06/12 07:05:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for transfers to finish
2022/06/12 07:05:04 DEBUG : one: md5 = c954bdf8292379f6a6522a2e72612819 OK
2022/06/12 07:05:04 INFO  : one: Copied (new)
2022/06/12 07:05:04 DEBUG : Waiting for deletions to finish
2022/06/12 07:05:05 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2022/06/12 07:05:05 INFO  : three.txt: Moved into backup dir
2022/06/12 07:05:08 DEBUG : dst/three.txt: md5 = 8fae2f3801f5074560f3bbdca424f378 OK
2022/06/12 07:05:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for checks to finish
2022/06/12 07:05:09 DEBUG : one: Sizes differ (src 5 vs dst 4)
2022/06/12 07:05:09 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:05:09 DEBUG : two: Unchanged skipping
2022/06/12 07:05:10 INFO  : one-2019-01-01: Deleted
2022/06/12 07:05:11 INFO  : one: Moved (server-side) to: one-2019-01-01
2022/06/12 07:05:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for transfers to finish
2022/06/12 07:05:12 DEBUG : one: md5 = a0061a1b148460a11e3497a4ac1eb5fe OK
2022/06/12 07:05:12 INFO  : one: Copied (new)
2022/06/12 07:05:12 DEBUG : Waiting for deletions to finish
2022/06/12 07:05:13 INFO  : three-2019-01-01.txt: Deleted
2022/06/12 07:05:14 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2022/06/12 07:05:14 INFO  : three.txt: Moved into backup dir
2022/06/12 07:05:18 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/06/12 07:05:18 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2022/06/12 07:05:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2022/06/12 07:05:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2022/06/12 07:05:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2022/06/12 07:05:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (30.68s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:05:22 DEBUG : dst/one: md5 = cb8f79be89aed12212df65c6c5503d26 OK
2022/06/12 07:05:24 DEBUG : dst/two: md5 = b2483cfd43e49af29587a22c5b4d7a76 OK
2022/06/12 07:05:25 DEBUG : dst/three.txt: md5 = 9748df5e67e06e338fbe143dd9d1f8a5 OK
2022/06/12 07:05:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst"
2022/06/12 07:05:26 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/31u3jie661vd5p8j7rtc3hgbh0"
2022/06/12 07:05:27 DEBUG : one: Sizes differ (src 4 vs dst 3)
2022/06/12 07:05:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for checks to finish
2022/06/12 07:05:27 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:05:27 DEBUG : two: Unchanged skipping
2022/06/12 07:05:28 INFO  : one: Moved (server-side) to: one.bak
2022/06/12 07:05:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for transfers to finish
2022/06/12 07:05:30 DEBUG : one: md5 = 3c31ba94e9592570deeb3c89c143a511 OK
2022/06/12 07:05:30 INFO  : one: Copied (new)
2022/06/12 07:05:30 DEBUG : Waiting for deletions to finish
2022/06/12 07:05:31 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2022/06/12 07:05:31 INFO  : three.txt: Moved into backup dir
2022/06/12 07:05:33 DEBUG : dst/three.txt: md5 = cf8ab88e5e1def701bcf59fbc7cb61b7 OK
2022/06/12 07:05:34 DEBUG : one.bak: Excluded
2022/06/12 07:05:34 DEBUG : three.txt.bak: Excluded
2022/06/12 07:05:34 DEBUG : one: Sizes differ (src 5 vs dst 4)
2022/06/12 07:05:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for checks to finish
2022/06/12 07:05:34 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:05:34 DEBUG : two: Unchanged skipping
2022/06/12 07:05:35 INFO  : one.bak: Deleted
2022/06/12 07:05:35 INFO  : one: Moved (server-side) to: one.bak
2022/06/12 07:05:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst': Waiting for transfers to finish
2022/06/12 07:05:37 DEBUG : one: md5 = ef201165fa0fd0bcb8ca7f7aeac6338c OK
2022/06/12 07:05:37 INFO  : one: Copied (new)
2022/06/12 07:05:37 DEBUG : Waiting for deletions to finish
2022/06/12 07:05:38 INFO  : three.txt.bak: Deleted
2022/06/12 07:05:39 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2022/06/12 07:05:39 INFO  : three.txt: Moved into backup dir
2022/06/12 07:05:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/06/12 07:05:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2022/06/12 07:05:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2022/06/12 07:05:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2022/06/12 07:05:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2022/06/12 07:05:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncBackupDirSuffixOnly (23.90s)
=== RUN   TestSyncSuffix
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:05:46 DEBUG : dst/one: md5 = 04fb3196c68135563d108d589248b94b OK
2022/06/12 07:05:47 DEBUG : dst/two: md5 = b8e7b7c68d0f5752ee739b2ea5ac1b40 OK
2022/06/12 07:05:49 DEBUG : dst/three.txt: md5 = b02ea62b82497f1407c4b2ded094416f OK
2022/06/12 07:05:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst"
2022/06/12 07:05:50 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/31u3jie661vd5p8j7rtc3hgbh0"
2022/06/12 07:05:51 DEBUG : one: Sizes differ (src 4 vs dst 3)
2022/06/12 07:05:52 INFO  : one: Moved (server-side) to: one.bak
2022/06/12 07:05:54 DEBUG : one: md5 = 306176a0f09c5566a3b0ccfcdeb018f2 OK
2022/06/12 07:05:54 INFO  : one: Copied (new)
2022/06/12 07:05:54 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:05:54 DEBUG : two: Unchanged skipping
2022/06/12 07:05:55 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2022/06/12 07:05:56 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2022/06/12 07:05:57 DEBUG : three.txt: md5 = c968f5023adfa59d534aea450832962e OK
2022/06/12 07:05:57 INFO  : three.txt: Copied (new)
2022/06/12 07:05:59 DEBUG : one: Sizes differ (src 5 vs dst 4)
2022/06/12 07:06:00 INFO  : one.bak: Deleted
2022/06/12 07:06:00 INFO  : one: Moved (server-side) to: one.bak
2022/06/12 07:06:02 DEBUG : one: md5 = 49a022771cfb937806a157a92d8d5ec0 OK
2022/06/12 07:06:02 INFO  : one: Copied (new)
2022/06/12 07:06:02 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:06:02 DEBUG : two: Unchanged skipping
2022/06/12 07:06:02 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2022/06/12 07:06:03 INFO  : three.txt.bak: Deleted
2022/06/12 07:06:04 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2022/06/12 07:06:06 DEBUG : three.txt: md5 = c6076fb181d206db8046a99212871abf OK
2022/06/12 07:06:06 INFO  : three.txt: Copied (new)
2022/06/12 07:06:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/06/12 07:06:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2022/06/12 07:06:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2022/06/12 07:06:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2022/06/12 07:06:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2022/06/12 07:06:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2022/06/12 07:06:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncSuffix (27.79s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:06:14 DEBUG : dst/one: md5 = 3e0d2d282cf02479b98f8aacc04d6a31 OK
2022/06/12 07:06:15 DEBUG : dst/two: md5 = 36a14755b4d7126c27ded038e761c7d0 OK
2022/06/12 07:06:17 DEBUG : dst/three.txt: md5 = 741364bdcb8af994a679f933739d077f OK
2022/06/12 07:06:18 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2/dst"
2022/06/12 07:06:18 DEBUG : Creating backend with remote "TestDrive:crypt/pcp4fb84bduafpctng7bo0tpbk9o7q80a9d10g5c3h9clkrip6p0lt52oqmu6sq1buvd5r1o3vb9e/31u3jie661vd5p8j7rtc3hgbh0"
2022/06/12 07:06:19 DEBUG : one: Sizes differ (src 4 vs dst 3)
2022/06/12 07:06:20 INFO  : one: Moved (server-side) to: one-2019-01-01
2022/06/12 07:06:21 DEBUG : one: md5 = abe8eacd49a14be026f707809e5463c4 OK
2022/06/12 07:06:21 INFO  : one: Copied (new)
2022/06/12 07:06:22 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:06:22 DEBUG : two: Unchanged skipping
2022/06/12 07:06:22 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2022/06/12 07:06:23 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2022/06/12 07:06:25 DEBUG : three.txt: md5 = 03d32181039aac6e34cfb3848d48b833 OK
2022/06/12 07:06:25 INFO  : three.txt: Copied (new)
2022/06/12 07:06:26 DEBUG : one: Sizes differ (src 5 vs dst 4)
2022/06/12 07:06:27 INFO  : one-2019-01-01: Deleted
2022/06/12 07:06:28 INFO  : one: Moved (server-side) to: one-2019-01-01
2022/06/12 07:06:29 DEBUG : one: md5 = b8380534c5201c1c2494f5bcda672b5e OK
2022/06/12 07:06:29 INFO  : one: Copied (new)
2022/06/12 07:06:30 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:06:30 DEBUG : two: Unchanged skipping
2022/06/12 07:06:30 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2022/06/12 07:06:31 INFO  : three-2019-01-01.txt: Deleted
2022/06/12 07:06:31 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2022/06/12 07:06:33 DEBUG : three.txt: md5 = d2fc6579b1fd8ff37e018fd714d173fc OK
2022/06/12 07:06:33 INFO  : three.txt: Copied (new)
2022/06/12 07:06:38 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2022/06/12 07:06:38 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2022/06/12 07:06:38 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2022/06/12 07:06:38 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2022/06/12 07:06:38 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2022/06/12 07:06:38 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2022/06/12 07:06:38 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncSuffixKeepExtension (27.49s)
=== RUN   TestSyncUTFNorm
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:06:40 DEBUG : Testêé: md5 = aa759e490341873a87120ee5f5abbb42 OK
2022/06/12 07:06:41 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2022/06/12 07:06:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 07:06:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 07:06:42 DEBUG : Testêé: md5 = 5a087ce949306713f890b8526577810f OK
2022/06/12 07:06:42 INFO  : Testêé: Copied (replaced existing)
2022/06/12 07:06:42 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (5.13s)
=== RUN   TestSyncImmutable
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:06:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 07:06:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 07:06:46 DEBUG : existing: md5 = af849dcdc0644f46b76761ae4a0ea5ca OK
2022/06/12 07:06:46 INFO  : existing: Copied (new)
2022/06/12 07:06:46 DEBUG : Waiting for deletions to finish
2022/06/12 07:06:47 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2022/06/12 07:06:47 ERROR : existing: Source and destination exist but do not match: immutable file modified
2022/06/12 07:06:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 07:06:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 07:06:47 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': not deleting files as there were IO errors
2022/06/12 07:06:47 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': not deleting directories as there were IO errors
--- PASS: TestSyncImmutable (4.71s)
=== RUN   TestSyncIgnoreCase
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:06:50 DEBUG : EXISTING: md5 = d79f34e55dd893e49c84d11473524141 OK
2022/06/12 07:06:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 07:06:51 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:06:51 DEBUG : existing: Unchanged skipping
2022/06/12 07:06:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 07:06:51 DEBUG : Waiting for deletions to finish
2022/06/12 07:06:51 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (3.85s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
    sync_test.go:2046: This test only runs on local
=== RUN   TestMaxTransfer/Soft
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
    sync_test.go:2046: This test only runs on local
=== RUN   TestMaxTransfer/Cautious
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
    sync_test.go:2046: This test only runs on local
--- PASS: TestMaxTransfer (1.84s)
    --- SKIP: TestMaxTransfer/Hard (0.53s)
    --- SKIP: TestMaxTransfer/Soft (0.72s)
    --- SKIP: TestMaxTransfer/Cautious (0.60s)
=== RUN   TestSyncConcurrentDelete
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:06:56 DEBUG : both0: md5 = 7fabff0d303d3eb8e193ba9ae0e646ed OK
2022/06/12 07:06:57 DEBUG : only0: md5 = 6dbae76d6d17e805408a56cdbfe9b8d0 OK
2022/06/12 07:06:59 DEBUG : both1: md5 = f432294027ff115f475e0788ac51bc4e OK
2022/06/12 07:07:01 DEBUG : only1: md5 = f3db2abc553cfecbaf73c37a2e6b952b OK
2022/06/12 07:07:02 DEBUG : both2: md5 = 85286db0d78f7939f13d8a0d79e03617 OK
2022/06/12 07:07:04 DEBUG : only2: md5 = 9e7c31de821d2373d166ea0fdd8d3707 OK
2022/06/12 07:07:06 DEBUG : both3: md5 = 6df6db23a85f893ed352a037b77701c5 OK
2022/06/12 07:07:07 DEBUG : only3: md5 = 2ea3d6fc26ea0a077e4910dfc88f036d OK
2022/06/12 07:07:09 DEBUG : both4: md5 = 80a19ed58eb43147bdb860fb3e7f67de OK
2022/06/12 07:07:10 DEBUG : only4: md5 = 9db1e5963af195f63ce4ef6d54ef80e3 OK
2022/06/12 07:07:12 DEBUG : both5: md5 = 4ac72b842d9df843df09fb803d2c6250 OK
2022/06/12 07:07:13 DEBUG : only5: md5 = 481cea4af6fc8680bfaca29cbd246170 OK
2022/06/12 07:07:15 DEBUG : both6: md5 = 1020c4d701742df56c075b49f4e11241 OK
2022/06/12 07:07:16 DEBUG : only6: md5 = 12e531685381f980577bfc51ca3449ad OK
2022/06/12 07:07:18 DEBUG : both7: md5 = 9363d32c1b5c90189db214bc094fa46c OK
2022/06/12 07:07:19 DEBUG : only7: md5 = e23fcca7d3fcd0650a472ab93ab12dc1 OK
2022/06/12 07:07:21 DEBUG : both8: md5 = ee613fb5174c797628b27746c466d354 OK
2022/06/12 07:07:23 DEBUG : only8: md5 = 68cb339cbe6a7f2f3dc0c20f7e5c348f OK
2022/06/12 07:07:24 DEBUG : both9: md5 = 1745a6fdf6a55d1619abe60242fefd50 OK
2022/06/12 07:07:26 DEBUG : only9: md5 = 0a5114905ddf91a8c82411c22498aee1 OK
2022/06/12 07:07:28 DEBUG : both10: md5 = 3d60ac271f4352fe176485584ad9e160 OK
2022/06/12 07:07:29 DEBUG : only10: md5 = bd73c44c37f55682ad34443b28ed3733 OK
2022/06/12 07:07:31 DEBUG : both11: md5 = 5737681c20aaab047f002d6c70efa242 OK
2022/06/12 07:07:32 DEBUG : only11: md5 = 2e85dd940bb1c67daf481632b95e823c OK
2022/06/12 07:07:34 DEBUG : both12: md5 = 8bca03e872b704b7433dc66bfc4316fb OK
2022/06/12 07:07:36 DEBUG : only12: md5 = bf5d883d575d1c46a460fc4f9715c5b6 OK
2022/06/12 07:07:37 DEBUG : both13: md5 = df9f8d13361d3b73a17ccdaf1e9171c5 OK
2022/06/12 07:07:39 DEBUG : only13: md5 = 9c9c677440c9cfba9777e1da569c3a08 OK
2022/06/12 07:07:40 DEBUG : both14: md5 = 51faca21a1ea03f71b22f4d28b64829c OK
2022/06/12 07:07:42 DEBUG : only14: md5 = 41f8a6e4f860f9ef018efa1de12982b7 OK
2022/06/12 07:07:43 DEBUG : both15: md5 = fcf347172bf95d8e511fb4e897e8a77c OK
2022/06/12 07:07:45 DEBUG : only15: md5 = a1607a4ede870f721cdd0715a1c08168 OK
2022/06/12 07:07:47 DEBUG : both16: md5 = 90c605b8dc4dfb0f04004505957ed58e OK
2022/06/12 07:07:48 DEBUG : only16: md5 = d2ceceee3bb4f88419cf31f899b1866b OK
2022/06/12 07:07:50 DEBUG : both17: md5 = 0669c786964eda76537be86d6401aa50 OK
2022/06/12 07:07:51 DEBUG : only17: md5 = 9d82c9cb47f10b0c5cf8b2efe9f28bd2 OK
2022/06/12 07:07:51 DEBUG : Config file has changed externaly - reloading
2022/06/12 07:07:51 DEBUG : TestDrive: Loaded fresh token from config file
2022/06/12 07:07:53 DEBUG : both18: md5 = a3a4b5bf34a20f404aaa900a1ab611ad OK
2022/06/12 07:07:54 DEBUG : only18: md5 = fe21e92fd92f9daadc6815dbfa32e46c OK
2022/06/12 07:07:56 DEBUG : both19: md5 = a2af977333c753f547bf2ece9d754599 OK
2022/06/12 07:07:58 DEBUG : only19: md5 = f96a599264b11f99573350190feed536 OK
2022/06/12 07:07:59 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:07:59 DEBUG : both0: Unchanged skipping
2022/06/12 07:07:59 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:07:59 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:07:59 DEBUG : both10: Unchanged skipping
2022/06/12 07:07:59 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:07:59 DEBUG : both13: Unchanged skipping
2022/06/12 07:07:59 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:07:59 DEBUG : both12: Unchanged skipping
2022/06/12 07:07:59 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:07:59 DEBUG : both14: Unchanged skipping
2022/06/12 07:07:59 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:07:59 DEBUG : both16: Unchanged skipping
2022/06/12 07:07:59 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:07:59 DEBUG : both15: Unchanged skipping
2022/06/12 07:07:59 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:07:59 DEBUG : both18: Unchanged skipping
2022/06/12 07:07:59 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:07:59 DEBUG : both19: Unchanged skipping
2022/06/12 07:07:59 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:07:59 DEBUG : both2: Unchanged skipping
2022/06/12 07:07:59 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:07:59 DEBUG : both3: Unchanged skipping
2022/06/12 07:07:59 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:07:59 DEBUG : both4: Unchanged skipping
2022/06/12 07:07:59 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:07:59 DEBUG : both5: Unchanged skipping
2022/06/12 07:07:59 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:07:59 DEBUG : both6: Unchanged skipping
2022/06/12 07:07:59 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:07:59 DEBUG : both7: Unchanged skipping
2022/06/12 07:07:59 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:07:59 DEBUG : both11: Unchanged skipping
2022/06/12 07:07:59 DEBUG : both8: Unchanged skipping
2022/06/12 07:07:59 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:07:59 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:07:59 DEBUG : both9: Unchanged skipping
2022/06/12 07:07:59 DEBUG : both17: Unchanged skipping
2022/06/12 07:07:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 07:07:59 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:07:59 DEBUG : both1: Unchanged skipping
2022/06/12 07:07:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 07:07:59 DEBUG : Waiting for deletions to finish
2022/06/12 07:07:59 INFO  : only17: Deleted
2022/06/12 07:07:59 INFO  : only6: Deleted
2022/06/12 07:07:59 INFO  : only3: Deleted
2022/06/12 07:07:59 INFO  : only0: Deleted
2022/06/12 07:08:00 INFO  : only10: Deleted
2022/06/12 07:08:00 INFO  : only11: Deleted
2022/06/12 07:08:00 INFO  : only9: Deleted
2022/06/12 07:08:00 INFO  : only19: Deleted
2022/06/12 07:08:00 INFO  : only2: Deleted
2022/06/12 07:08:00 INFO  : only4: Deleted
2022/06/12 07:08:00 INFO  : only5: Deleted
2022/06/12 07:08:01 INFO  : only7: Deleted
2022/06/12 07:08:01 INFO  : only14: Deleted
2022/06/12 07:08:01 INFO  : only16: Deleted
2022/06/12 07:08:01 INFO  : only18: Deleted
2022/06/12 07:08:01 INFO  : only15: Deleted
2022/06/12 07:08:01 INFO  : only8: Deleted
2022/06/12 07:08:02 INFO  : only1: Deleted
2022/06/12 07:08:02 INFO  : only12: Deleted
2022/06/12 07:08:02 INFO  : only13: Deleted
2022/06/12 07:08:02 INFO  : There was nothing to transfer
--- PASS: TestSyncConcurrentDelete (79.35s)
=== RUN   TestSyncConcurrentTruncate
    run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2'", Local "Local file system at /tmp/rclone1762447505", Modify Window "1ms"
2022/06/12 07:08:15 DEBUG : both0: md5 = 51e7c0f810c1e57a305b346a540cf045 OK
2022/06/12 07:08:17 DEBUG : only0: md5 = 488b648c2fc4a983a799f0d68c89d602 OK
2022/06/12 07:08:18 DEBUG : both1: md5 = d78eb94563c7ba69ac1ce25d1163f478 OK
2022/06/12 07:08:20 DEBUG : only1: md5 = bf42f7bfcd48b019b5ac629ee7a79252 OK
2022/06/12 07:08:21 DEBUG : both2: md5 = 72c6348b208bf4ed0c229a9efa4fceb3 OK
2022/06/12 07:08:23 DEBUG : only2: md5 = f72ab1ef844cbef15c4a9d09b5d5a5ce OK
2022/06/12 07:08:25 DEBUG : both3: md5 = b3eddcfbde62b6b0a3ab8ae4b06ec886 OK
2022/06/12 07:08:26 DEBUG : only3: md5 = 07e4b81c1076c567eb40ac66e9461076 OK
2022/06/12 07:08:28 DEBUG : both4: md5 = 9ab15ab223c6483aeff538feb6122eea OK
2022/06/12 07:08:30 DEBUG : only4: md5 = 639b413cce183f4a1c7501b0d66f4667 OK
2022/06/12 07:08:31 DEBUG : both5: md5 = 0a48ccf3c5a6add151ed2c28d54b7d1f OK
2022/06/12 07:08:33 DEBUG : only5: md5 = acaac42d28b2f1532877f4ae97b5940b OK
2022/06/12 07:08:34 DEBUG : both6: md5 = 9626121c7a71dcdcba30d113360e922b OK
2022/06/12 07:08:36 DEBUG : only6: md5 = b8c41000e956c1d009a595ddad6e153d OK
2022/06/12 07:08:38 DEBUG : both7: md5 = c0e67e7739e85ef8ac16c7794167fa2a OK
2022/06/12 07:08:39 DEBUG : only7: md5 = b3c3cab00be05a4580d4ad5e15e36da8 OK
2022/06/12 07:08:43 DEBUG : both8: md5 = f63f769858b88404070a2ceee72276fa OK
2022/06/12 07:08:44 DEBUG : only8: md5 = c639a51fc59a6774d9f108e6e097cfa8 OK
2022/06/12 07:08:45 DEBUG : both9: md5 = 835dad643cb000948a6e72fd741a0aae OK
2022/06/12 07:08:47 DEBUG : only9: md5 = c42482cda8fe06115019dbd2c34395a3 OK
2022/06/12 07:08:48 DEBUG : both10: md5 = 642a494580216a3b34551512cf40beff OK
2022/06/12 07:08:50 DEBUG : only10: md5 = 2dcf3230d8a8167dcde0950e5f7106ec OK
2022/06/12 07:08:52 DEBUG : both11: md5 = 28a774120d3fd5e4bd741059bcfd00ad OK
2022/06/12 07:08:53 DEBUG : only11: md5 = b88a051f545f9ecf8ba5bf31529c97e9 OK
2022/06/12 07:08:55 DEBUG : both12: md5 = 056faa54818e769f7762aeb6e8c7b02e OK
2022/06/12 07:08:56 DEBUG : only12: md5 = 2c10c95c4efe7d76e10226705b64c472 OK
2022/06/12 07:08:59 DEBUG : both13: md5 = cb9f68ef0f60629d063a87fdd8baa9b2 OK
2022/06/12 07:09:00 DEBUG : only13: md5 = d88b79f03ee25480aa2600ea671486d3 OK
2022/06/12 07:09:02 DEBUG : both14: md5 = 15e5478445b32f6ef2516537a80b7f21 OK
2022/06/12 07:09:03 DEBUG : only14: md5 = ee72d3e89a47287e4d82088f6c37c379 OK
2022/06/12 07:09:05 DEBUG : both15: md5 = 28ed5499563732c44f3932f3269bfde9 OK
2022/06/12 07:09:06 DEBUG : only15: md5 = 7d7172df5b4bb3d4da813b62fc46b82d OK
2022/06/12 07:09:08 DEBUG : both16: md5 = 3b413cee3e84f70a2fc1bd23f8400a66 OK
2022/06/12 07:09:09 DEBUG : only16: md5 = 222593c9c3f383c9136ebd345a734ef8 OK
2022/06/12 07:09:11 DEBUG : both17: md5 = 48762cef420057ac585d432702175d55 OK
2022/06/12 07:09:13 DEBUG : only17: md5 = 4e69df8b3453a7c67e2d3bada7d6bf96 OK
2022/06/12 07:09:14 DEBUG : both18: md5 = 045f72b84ef86337f9991de0e7819a80 OK
2022/06/12 07:09:16 DEBUG : only18: md5 = e31f1581ba0237d47bff4ce992677b0e OK
2022/06/12 07:09:17 DEBUG : both19: md5 = 31072f465bb53f01e117db2ba70bcedb OK
2022/06/12 07:09:19 DEBUG : only19: md5 = 15bcf0da7b5cb0e4efd1393b7bdfbdc4 OK
2022/06/12 07:09:20 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:09:20 DEBUG : both10: Unchanged skipping
2022/06/12 07:09:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for checks to finish
2022/06/12 07:09:20 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:09:20 DEBUG : both11: Unchanged skipping
2022/06/12 07:09:20 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:09:20 DEBUG : both13: Unchanged skipping
2022/06/12 07:09:20 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:09:20 DEBUG : both14: Unchanged skipping
2022/06/12 07:09:20 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:09:20 DEBUG : both15: Unchanged skipping
2022/06/12 07:09:20 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:09:20 DEBUG : both16: Unchanged skipping
2022/06/12 07:09:20 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:09:20 DEBUG : both17: Unchanged skipping
2022/06/12 07:09:20 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:09:20 DEBUG : both18: Unchanged skipping
2022/06/12 07:09:20 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:09:20 DEBUG : both19: Unchanged skipping
2022/06/12 07:09:20 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:09:20 DEBUG : both2: Unchanged skipping
2022/06/12 07:09:20 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:09:20 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:09:20 DEBUG : both3: Unchanged skipping
2022/06/12 07:09:20 DEBUG : both0: Unchanged skipping
2022/06/12 07:09:20 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:09:20 DEBUG : both4: Unchanged skipping
2022/06/12 07:09:20 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:09:20 DEBUG : both5: Unchanged skipping
2022/06/12 07:09:20 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:09:20 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:09:20 DEBUG : both6: Unchanged skipping
2022/06/12 07:09:20 DEBUG : both7: Unchanged skipping
2022/06/12 07:09:20 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:09:20 DEBUG : both9: Unchanged skipping
2022/06/12 07:09:20 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:09:20 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2022/06/12 07:09:20 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:09:20 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2022/06/12 07:09:20 DEBUG : both8: Unchanged skipping
2022/06/12 07:09:20 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2022/06/12 07:09:20 DEBUG : both12: Unchanged skipping
2022/06/12 07:09:20 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2022/06/12 07:09:20 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2022/06/12 07:09:20 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2022/06/12 07:09:20 DEBUG : both1: Unchanged skipping
2022/06/12 07:09:20 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2022/06/12 07:09:20 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2022/06/12 07:09:20 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2022/06/12 07:09:20 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2022/06/12 07:09:20 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2022/06/12 07:09:20 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2022/06/12 07:09:20 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2022/06/12 07:09:20 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2022/06/12 07:09:20 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2022/06/12 07:09:20 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2022/06/12 07:09:20 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2022/06/12 07:09:20 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2022/06/12 07:09:20 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2022/06/12 07:09:20 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2022/06/12 07:09:20 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2022/06/12 07:09:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Waiting for transfers to finish
2022/06/12 07:09:21 DEBUG : only1: md5 = 302f045b654d358369cad4ecc21dcffa OK
2022/06/12 07:09:21 INFO  : only1: Copied (replaced existing)
2022/06/12 07:09:21 DEBUG : only0: md5 = 4ca0620213dcadae45b7f59af81f7525 OK
2022/06/12 07:09:21 INFO  : only0: Copied (replaced existing)
2022/06/12 07:09:21 DEBUG : only10: md5 = 7a7507362c9447ea2cc77e7df40549d5 OK
2022/06/12 07:09:21 INFO  : only10: Copied (replaced existing)
2022/06/12 07:09:21 DEBUG : only14: md5 = a1320ab3ddc7a0543d524b41172327e6 OK
2022/06/12 07:09:21 INFO  : only14: Copied (replaced existing)
2022/06/12 07:09:22 DEBUG : only15: md5 = 88515ad2a781ce9d304da81b96e00ace OK
2022/06/12 07:09:22 INFO  : only15: Copied (replaced existing)
2022/06/12 07:09:22 DEBUG : only16: md5 = aa564b5527a8d8478c81cdd706fdcf1c OK
2022/06/12 07:09:22 INFO  : only16: Copied (replaced existing)
2022/06/12 07:09:22 DEBUG : only17: md5 = df865c1387065750b4aec7bc37038b7f OK
2022/06/12 07:09:22 INFO  : only17: Copied (replaced existing)
2022/06/12 07:09:23 DEBUG : only18: md5 = 7ab3931436a2f525b949d99c54e46275 OK
2022/06/12 07:09:23 INFO  : only18: Copied (replaced existing)
2022/06/12 07:09:24 DEBUG : only19: md5 = 66b76b4a58b6691ed5c50b8786911e95 OK
2022/06/12 07:09:24 INFO  : only19: Copied (replaced existing)
2022/06/12 07:09:24 DEBUG : only2: md5 = 08033d7cfae8149df40b280573970dab OK
2022/06/12 07:09:24 INFO  : only2: Copied (replaced existing)
2022/06/12 07:09:24 DEBUG : only3: md5 = 355b964b61fe570974b2e4cac25e9f68 OK
2022/06/12 07:09:24 INFO  : only3: Copied (replaced existing)
2022/06/12 07:09:24 DEBUG : only4: md5 = d00d726a5724596e1389ad208e2b0c3d OK
2022/06/12 07:09:24 INFO  : only4: Copied (replaced existing)
2022/06/12 07:09:25 DEBUG : only5: md5 = ef65813077f53a24e61608bc48ceda7a OK
2022/06/12 07:09:25 INFO  : only5: Copied (replaced existing)
2022/06/12 07:09:25 DEBUG : only6: md5 = 8812793f0bc6f910683fdbe7b7ba6be3 OK
2022/06/12 07:09:25 INFO  : only6: Copied (replaced existing)
2022/06/12 07:09:25 DEBUG : only7: md5 = b77ad40650af11b4bfee53b6c02175e8 OK
2022/06/12 07:09:25 INFO  : only7: Copied (replaced existing)
2022/06/12 07:09:25 DEBUG : only8: md5 = ea1b0a89c7bf691f8fefb0c04b03424a OK
2022/06/12 07:09:25 INFO  : only8: Copied (replaced existing)
2022/06/12 07:09:26 DEBUG : only9: md5 = 4e87bdec3818f929fc87defa40fe4638 OK
2022/06/12 07:09:26 INFO  : only9: Copied (replaced existing)
2022/06/12 07:09:26 DEBUG : only13: md5 = e6b55de304b4b0380b48a81b8238b857 OK
2022/06/12 07:09:26 INFO  : only13: Copied (replaced existing)
2022/06/12 07:09:26 DEBUG : only12: md5 = eaaa508a0226784d4be08c216b4c45d4 OK
2022/06/12 07:09:26 INFO  : only12: Copied (replaced existing)
2022/06/12 07:09:26 DEBUG : only11: md5 = 86d6d8d65557362b24852e0a7f19e2a5 OK
2022/06/12 07:09:26 INFO  : only11: Copied (replaced existing)
2022/06/12 07:09:26 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncConcurrentTruncate (95.92s)
PASS
2022/06/12 07:09:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuyotob5wuzuvet2goqadop2': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 14m13.775699957s (try 1/5)