"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5)
2025/01/28 01:28:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude"
2025/01/28 01:28:12 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/01/28 01:28:12 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0"
2025/01/28 01:28:13 DEBUG : Creating backend with remote "/tmp/rclone2548372772"
=== RUN   TestPipe
--- PASS: TestPipe (0.00s)
=== RUN   TestPipeConcurrent
--- PASS: TestPipeConcurrent (0.03s)
=== 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:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:28:14 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/28 01:28:14 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/28 01:28:14 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2025/01/28 01:28:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:28:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:28:14 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (2.52s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:28:15 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/28 01:28:16 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/28 01:28:16 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/28 01:28:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:28:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:28:19 DEBUG : sub dir/hello world: md5 = e808aee931530240fea8894cc26b3f23 OK
2025/01/28 01:28:19 INFO  : sub dir/hello world: Copied (new)
2025/01/28 01:28:20 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:28:22 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (8.20s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:28:24 DEBUG : metadata sub dir: Making directory with metadata
2025/01/28 01:28:24 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/28 01:28:24 DEBUG : empty metadata sub dir: Making directory with metadata
2025/01/28 01:28:24 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/28 01:28:24 DEBUG : Local file system at /tmp/rclone2548372772: File to upload is small (21 bytes), uploading instead of streaming
2025/01/28 01:28:24 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2025/01/28 01:28:24 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2025/01/28 01:28:24 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2025/01/28 01:28:24 DEBUG : Google drive root 'crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0': Skipping btime metadata as can't update it on an existing file: 2025-01-28T01:28:24.143032805Z
2025/01/28 01:28:25 INFO  : empty metadata sub dir: Updated directory metadata
2025/01/28 01:28:25 DEBUG : Google drive root 'crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0': Skipping btime metadata as can't update it on an existing file: 2025-01-28T01:28:24.143032805Z
2025/01/28 01:28:26 INFO  : metadata sub dir: Updated directory metadata
2025/01/28 01:28:26 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2025/01/28 01:28:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:28:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:28:28 DEBUG : metadata sub dir/hello metadata world: md5 = a71e7d6c81591537a184875e62a3b281 OK
2025/01/28 01:28:28 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:28:31 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (9.66s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:28:33 DEBUG : metadata sub dir: Making directory with metadata
2025/01/28 01:28:33 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/28 01:28:33 DEBUG : empty metadata sub dir: Making directory with metadata
2025/01/28 01:28:33 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/28 01:28:33 DEBUG : Local file system at /tmp/rclone2548372772: File to upload is small (21 bytes), uploading instead of streaming
2025/01/28 01:28:33 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2025/01/28 01:28:33 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2025/01/28 01:28:33 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2025/01/28 01:28:34 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2025/01/28 01:28:34 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2025/01/28 01:28:34 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2025/01/28 01:28:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:28:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:28:36 DEBUG : metadata sub dir/hello metadata world: md5 = 771d928fdd365c615072288eaaf8d8ad OK
2025/01/28 01:28:36 INFO  : metadata sub dir/hello metadata world: Copied (new)
2025/01/28 01:28:36 DEBUG : Google drive root 'crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0': Skipping btime metadata as can't update it on an existing file: 2025-01-28T01:28:33.798990987Z
2025/01/28 01:28:37 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:28:40 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (7.55s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:28:41 DEBUG : Creating backend with remote "/non-existing"
2025/01/28 01:28:41 DEBUG : Config file has changed externally - reloading
2025/01/28 01:28:41 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2025/01/28 01:28:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:28:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.13s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:28:42 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/28 01:28:42 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/28 01:28:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:28:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:28:45 DEBUG : sub dir/hello world: md5 = 71838b5c56e7d45124c481267ae88cd7 OK
2025/01/28 01:28:45 INFO  : sub dir/hello world: Copied (new)
2025/01/28 01:28:46 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:28:48 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (7.28s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:28:49 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Running all checks before starting transfers
2025/01/28 01:28:49 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/28 01:28:49 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/28 01:28:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:28:49 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Checks finished, now starting transfers
2025/01/28 01:28:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:28:52 DEBUG : sub dir/hello world: md5 = f7ed704453f750d0dd068a4b6fd78bfc OK
2025/01/28 01:28:52 INFO  : sub dir/hello world: Copied (new)
2025/01/28 01:28:53 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:28:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (6.96s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:28:56 ERROR : Ignoring --no-traverse with sync
2025/01/28 01:28:56 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/28 01:28:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/28 01:28:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:28:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:29:00 DEBUG : sub dir/hello world: md5 = e164714ed2b72424cf9091f115b20b8f OK
2025/01/28 01:29:00 INFO  : sub dir/hello world: Copied (new)
2025/01/28 01:29:00 DEBUG : Waiting for deletions to finish
2025/01/28 01:29:00 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:29:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (7.17s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:29:04 DEBUG : hello world2: Need to transfer - File not found at Destination
2025/01/28 01:29:04 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/28 01:29:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:29:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:29:06 DEBUG : hello world2: md5 = 6bdfe88d17c773fb3f7b9bd246e243bd OK
2025/01/28 01:29:06 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestCopyWithDepth (3.98s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:29:08 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/28 01:29:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:29:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:29:10 DEBUG : potato2: md5 = 7071e02d2a42b0181fa3d34e15c50b75 OK
2025/01/28 01:29:10 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (3.92s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:29:12 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/28 01:29:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:29:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:29:13 DEBUG : potato2: md5 = 8cf441385fe9e5c15b0ee9fb9453bd1f OK
2025/01/28 01:29:13 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (3.96s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:29:15 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/01/28 01:29:15 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/28 01:29:15 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/28 01:29:15 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/28 01:29:15 DEBUG : sub dir: Making directory with metadata
2025/01/28 01:29:17 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/01/28 01:29:17 DEBUG : sub dir2: Making directory with metadata
2025/01/28 01:29:18 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/28 01:29:18 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/01/28 01:29:18 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/28 01:29:19 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/28 01:29:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:29:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:29:20 DEBUG : sub dir/hello world: md5 = cbd8fd79c541b43d245a64f6389f01a0 OK
2025/01/28 01:29:20 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:29:24 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2025/01/28 01:29:25 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (10.98s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:29:26 INFO  : sub dir2: Making directory
2025/01/28 01:29:26 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/01/28 01:29:26 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/28 01:29:26 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/28 01:29:26 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/01/28 01:29:26 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2025/01/28 01:29:26 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/28 01:29:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:29:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:29:29 DEBUG : sub dir/hello world: md5 = db5aa534b60a215d7d97c6560d2f8648 OK
2025/01/28 01:29:29 INFO  : sub dir/hello world: Copied (new)
2025/01/28 01:29:30 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/28 01:29:32 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (6.48s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:29:33 DEBUG : sub dir2: Making directory with metadata
2025/01/28 01:29:33 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/28 01:29:33 DEBUG : sub dir: Making directory with metadata
2025/01/28 01:29:34 INFO  : sub dir: Made directory with metadata (mtime=2025-01-28T01:29:33.186723782Z)
2025/01/28 01:29:34 DEBUG : sub dir2: Making directory with metadata
2025/01/28 01:29:35 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/28 01:29:35 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/28 01:29:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:29:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:29:37 DEBUG : sub dir/hello world: md5 = 16bbd703b432317a680e6b9c7e587add OK
2025/01/28 01:29:37 INFO  : sub dir/hello world: Copied (new)
2025/01/28 01:29:37 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:29:40 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (8.79s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:29:41 DEBUG : sub dir no update dir modtime: Making directory with metadata
2025/01/28 01:29:41 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/01/28 01:29:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:29:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:29:43 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (4.64s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:29:46 INFO  : sub dir2: Making directory
2025/01/28 01:29:46 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/28 01:29:46 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/01/28 01:29:46 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/28 01:29:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:29:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:29:49 DEBUG : sub dir/hello world: md5 = f01b65766f34cb0c3242aae4d39b7dfc OK
2025/01/28 01:29:49 INFO  : sub dir/hello world: Copied (new)
2025/01/28 01:29:49 INFO  : sub dir/hello world: Deleted
2025/01/28 01:29:50 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/28 01:29:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (6.68s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:29:53 DEBUG : sub dir2: Making directory with metadata
2025/01/28 01:29:53 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/28 01:29:53 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/28 01:29:53 DEBUG : sub dir: Making directory with metadata
2025/01/28 01:29:54 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/01/28 01:29:54 DEBUG : sub dir2: Making directory with metadata
2025/01/28 01:29:55 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/28 01:29:55 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/28 01:29:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:29:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:29:57 DEBUG : sub dir/hello world: md5 = f24241eec359889e66f0d9669687a084 OK
2025/01/28 01:29:57 INFO  : sub dir/hello world: Copied (new)
2025/01/28 01:29:57 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:30:00 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (8.89s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.48s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:30:02 INFO  : sub dir2: Making directory
2025/01/28 01:30:02 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/28 01:30:02 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/01/28 01:30:02 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/28 01:30:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:30:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:30:05 DEBUG : sub dir/hello world: md5 = 6f827c48ee1976a676914ee3ccc2b142 OK
2025/01/28 01:30:05 INFO  : sub dir/hello world: Copied (new)
2025/01/28 01:30:05 DEBUG : Waiting for deletions to finish
2025/01/28 01:30:06 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/28 01:30:08 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (6.65s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:30:12 DEBUG : sub dir/hello world: md5 = 2bc6ca259aa5fe60305b1723dc501f64 OK
2025/01/28 01:30:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wadibeq1vapi"
2025/01/28 01:30:12 DEBUG : Creating backend with remote "TestDrive:crypt/agj0kqpib1u9t7c198lmhvneljmmivmd60lc24b0f5lllcq81jc0"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude' -> Encrypted drive 'TestCryptDrive:rclone-test-wadibeq1vapi'
2025/01/28 01:30:13 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/28 01:30:14 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/28 01:30:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wadibeq1vapi': Waiting for checks to finish
2025/01/28 01:30:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wadibeq1vapi': Waiting for transfers to finish
2025/01/28 01:30:17 INFO  : sub dir/hello world: Copied (server-side copy)
2025/01/28 01:30:18 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:30:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wadibeq1vapi': Purge remote
2025/01/28 01:30:21 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (13.28s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:30:25 DEBUG : sub dir/hello world: md5 = 5afa0d0c84d64e78802253590665dd7e OK
2025/01/28 01:30:26 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/28 01:30:26 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/01/28 01:30:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:30:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:30:28 DEBUG : sub dir/hello world: md5 = 21b0fba6ddb61a3526dfceacf572c87a OK
2025/01/28 01:30:28 INFO  : sub dir/hello world: Copied (replaced existing)
2025/01/28 01:30:28 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:30:30 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (9.28s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:30:34 DEBUG : sub dir/hello world: md5 = eaa9f7ba11b1ea3e849ebb5c38340c8a OK
2025/01/28 01:30:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zulopiq2nede"
2025/01/28 01:30:35 DEBUG : Creating backend with remote "TestDrive:crypt/mrr6m44m3tgovs17v15qrol2uaf8cni0rhm0sh67a3gofaj2t01g"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude' -> Encrypted drive 'TestCryptDrive:rclone-test-zulopiq2nede'
2025/01/28 01:30:36 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/28 01:30:36 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/28 01:30:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zulopiq2nede': Waiting for checks to finish
2025/01/28 01:30:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zulopiq2nede': Waiting for transfers to finish
2025/01/28 01:30:40 INFO  : sub dir/hello world: Copied (server-side copy)
2025/01/28 01:30:41 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:30:43 DEBUG : sub dir/hello world: md5 = 748396aaf0545c9f505f0e64df848fb5 OK
2025/01/28 01:30:44 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/01/28 01:30:44 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/28 01:30:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zulopiq2nede': Waiting for checks to finish
2025/01/28 01:30:44 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/01/28 01:30:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zulopiq2nede': Waiting for transfers to finish
2025/01/28 01:30:46 INFO  : sub dir/hello world: Copied (server-side copy)
2025/01/28 01:30:47 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:30:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zulopiq2nede': Purge remote
2025/01/28 01:30:49 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (20.07s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:30:54 DEBUG : sub dir/hello world: md5 = 12ed53fc2d9e2eea9b6b2cd1560c7603 OK
2025/01/28 01:30:55 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/28 01:30:56 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/01/28 01:30:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:30:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:30:57 DEBUG : sub dir/hello world: md5 = c10c9154f8e7924aa4fc852c87589658 OK
2025/01/28 01:30:57 INFO  : sub dir/hello world: Copied (replaced existing)
2025/01/28 01:30:57 INFO  : sub dir/hello world: Deleted
2025/01/28 01:30:58 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:31:00 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (9.50s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:31:04 DEBUG : sub dir/hello world: md5 = 105dc25313a138ee11a3a39b7e988238 OK
2025/01/28 01:31:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qicufig2duko"
2025/01/28 01:31:04 DEBUG : Config file has changed externally - reloading
2025/01/28 01:31:04 DEBUG : Creating backend with remote "TestDrive:crypt/gbpiah9ivv61ubbr649jhlu4t991cddbtv3r854bf2ovor7pgk2g"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude' -> Encrypted drive 'TestCryptDrive:rclone-test-qicufig2duko'
2025/01/28 01:31:06 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/28 01:31:06 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/28 01:31:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qicufig2duko': Waiting for checks to finish
2025/01/28 01:31:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qicufig2duko': Waiting for transfers to finish
2025/01/28 01:31:09 INFO  : sub dir/hello world: Copied (server-side copy)
2025/01/28 01:31:10 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:31:12 DEBUG : sub dir/hello world: md5 = 21a958316fa959ed8096b401c732a8f2 OK
2025/01/28 01:31:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qicufig2duko': Using server-side directory move
2025/01/28 01:31:13 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-qicufig2duko': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/01/28 01:31:13 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/01/28 01:31:13 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/28 01:31:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qicufig2duko': Waiting for checks to finish
2025/01/28 01:31:13 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/01/28 01:31:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qicufig2duko': Waiting for transfers to finish
2025/01/28 01:31:14 INFO  : sub dir/hello world: Deleted
2025/01/28 01:31:15 INFO  : sub dir/hello world: Moved (server-side)
2025/01/28 01:31:15 INFO  : sub dir: Set directory modification time (using SetModTime)
2025/01/28 01:31:18 DEBUG : sub dir/hello world: md5 = f2410537ccf595494020e1ea904f9c9a OK
2025/01/28 01:31:18 DEBUG : testing file moves
2025/01/28 01:31:19 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/01/28 01:31:19 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/28 01:31:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qicufig2duko': Waiting for checks to finish
2025/01/28 01:31:19 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2025/01/28 01:31:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qicufig2duko': Waiting for transfers to finish
2025/01/28 01:31:19 INFO  : sub dir/hello world: Deleted
2025/01/28 01:31:21 INFO  : sub dir/hello world: Moved (server-side)
2025/01/28 01:31:21 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:31:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qicufig2duko': Purge remote
--- PASS: TestServerSideMoveOverSelf (24.27s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:31:28 DEBUG : sub dir/hello world: md5 = 8ed01a3e7357db3c756b9dab2fd8a678 OK
2025/01/28 01:31:28 ERROR : : error listing: directory not found
2025/01/28 01:31:29 INFO  : Local file system at /tmp/rclone2548372772: Making directory
2025/01/28 01:31:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:31:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:31:31 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (7.23s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:31:35 DEBUG : sub dir/hello world: md5 = fea14a48e11f0b51fab90a82176a99dd OK
2025/01/28 01:31:36 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/28 01:31:36 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/28 01:31:36 DEBUG : Local file system at /tmp/rclone2548372772: Waiting for checks to finish
2025/01/28 01:31:36 DEBUG : Local file system at /tmp/rclone2548372772: Waiting for transfers to finish
2025/01/28 01:31:37 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2025/01/28 01:31:37 INFO  : sub dir/hello world: Copied (new)
2025/01/28 01:31:37 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:31:39 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (7.50s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:31:40 DEBUG : check sum: Need to transfer - File not found at Destination
2025/01/28 01:31:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:31:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:31:42 DEBUG : check sum: md5 = eeefe97eb104dd256ddbfa06892c1af7 OK
2025/01/28 01:31:42 INFO  : check sum: Copied (new)
2025/01/28 01:31:42 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:31:42 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2025/01/28 01:31:42 DEBUG : check sum: Size of src and dst objects identical
2025/01/28 01:31:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:31:42 DEBUG : check sum: Unchanged skipping
2025/01/28 01:31:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:31:42 DEBUG : Waiting for deletions to finish
2025/01/28 01:31:42 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (4.70s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:31:45 DEBUG : sizeonly: Need to transfer - File not found at Destination
2025/01/28 01:31:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:31:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:31:46 DEBUG : sizeonly: md5 = 56bccf45912a6300e0e256a9bb8e4c52 OK
2025/01/28 01:31:46 INFO  : sizeonly: Copied (new)
2025/01/28 01:31:46 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:31:47 DEBUG : sizeonly: Sizes identical
2025/01/28 01:31:47 DEBUG : sizeonly: Unchanged skipping
2025/01/28 01:31:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:31:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:31:47 DEBUG : Waiting for deletions to finish
2025/01/28 01:31:47 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (4.54s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:31:49 DEBUG : ignore-size: Need to transfer - File not found at Destination
2025/01/28 01:31:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:31:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:31:51 DEBUG : ignore-size: md5 = ee6ce22891e56ff219dae72c4b7c59cb OK
2025/01/28 01:31:51 INFO  : ignore-size: Copied (new)
2025/01/28 01:31:51 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:31:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:31:52 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:31:52 DEBUG : ignore-size: Unchanged skipping
2025/01/28 01:31:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:31:52 DEBUG : Waiting for deletions to finish
2025/01/28 01:31:52 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (4.60s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:31:56 DEBUG : existing: md5 = 47cdc5c7290f67b37bd65f19940127cb OK
2025/01/28 01:31:56 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:31:56 DEBUG : existing: Unchanged skipping
2025/01/28 01:31:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:31:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:31:56 DEBUG : Waiting for deletions to finish
2025/01/28 01:31:56 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:31:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:31:56 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2025/01/28 01:31:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:31:58 DEBUG : existing: md5 = 34a505ce8314098096e83469739860ea OK
2025/01/28 01:31:58 INFO  : existing: Copied (replaced existing)
2025/01/28 01:31:58 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (6.22s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:32:00 DEBUG : existing: Need to transfer - File not found at Destination
2025/01/28 01:32:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:32:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:32:02 DEBUG : existing: md5 = 4d123c9a2400c42f0b5d318a160448cb OK
2025/01/28 01:32:02 INFO  : existing: Copied (new)
2025/01/28 01:32:02 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:32:02 DEBUG : existing: Destination exists, skipping
2025/01/28 01:32:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:32:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:32:02 DEBUG : Waiting for deletions to finish
2025/01/28 01:32:02 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (4.61s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:32:07 DEBUG : b/potato: md5 = 10912002170da011f6a9b2bfd25e54bf OK
2025/01/28 01:32:10 DEBUG : c/non empty space: md5 = 00d8794e593baacf4861c9aa2562f030 OK
2025/01/28 01:32:10 INFO  : d: Making directory
2025/01/28 01:32:12 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/01/28 01:32:12 DEBUG : Added delayed dir = "c", newDst=c
2025/01/28 01:32:12 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/01/28 01:32:13 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:32:13 DEBUG : c/non empty space: Unchanged skipping
2025/01/28 01:32:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:32:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:32:15 DEBUG : a/potato2: md5 = 0d00fdb9eb3ca75bbd6b17d18268f87a OK
2025/01/28 01:32:15 INFO  : a/potato2: Copied (new)
2025/01/28 01:32:15 DEBUG : Waiting for deletions to finish
2025/01/28 01:32:16 INFO  : b/potato: Deleted
2025/01/28 01:32:16 INFO  : a: Set directory modification time (using DirSetModTime)
2025/01/28 01:32:16 INFO  : d: Removing directory
2025/01/28 01:32:17 INFO  : b: Removing directory
2025/01/28 01:32:18 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/01/28 01:32:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:32:21 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/01/28 01:32:22 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (18.75s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:32:25 DEBUG : empty space: md5 = f8aeb8f1c80305dfff67dfa382269a88 OK
2025/01/28 01:32:26 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
2025/01/28 01:32:26 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2025/01/28 01:32:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:32:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:32:26 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:32:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:32:26 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
2025/01/28 01:32:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:32:28 DEBUG : empty space: md5 = 56569942e07c57be586b9375d35f43ef OK
2025/01/28 01:32:28 INFO  : empty space: Copied (replaced existing)
2025/01/28 01:32:28 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (6.69s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.47s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:32:32 DEBUG : foo: md5 = 8d6e0b0f68523b4bc2591057e98d6312 OK
2025/01/28 01:32:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:32:33 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
2025/01/28 01:32:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:32:34 DEBUG : foo: md5 = 5bf8070ff783c3643eb69593f532ff10 OK
2025/01/28 01:32:34 INFO  : foo: Copied (replaced existing)
2025/01/28 01:32:34 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (5.44s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:32:38 DEBUG : empty space: md5 = 0cca05c7cde6b0961a69d55436abb40b OK
2025/01/28 01:32:38 DEBUG : potato: Need to transfer - File not found at Destination
2025/01/28 01:32:38 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:32:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:32:38 DEBUG : empty space: Unchanged skipping
2025/01/28 01:32:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:32:40 DEBUG : potato: md5 = 69882df1b06ea8c315e10124e77bb960 OK
2025/01/28 01:32:40 INFO  : potato: Copied (new)
2025/01/28 01:32:40 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (6.44s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:32:44 DEBUG : potato: md5 = 6625aa75fad7d50cbdb74e5ce8e35994 OK
2025/01/28 01:32:45 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2025/01/28 01:32:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:32:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:32:46 DEBUG : potato: md5 = fc89775313a1076e1363e71285335505 OK
2025/01/28 01:32:46 INFO  : potato: Copied (replaced existing)
2025/01/28 01:32:46 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (5.52s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:32:50 DEBUG : potato: md5 = c095b36424efbbbc1320827f7aeb7935 OK
2025/01/28 01:32:50 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
2025/01/28 01:32:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:32:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:32:52 DEBUG : potato: md5 = 4c6cc162c6933ef7ed309d97556862c4 OK
2025/01/28 01:32:52 INFO  : potato: Copied (replaced existing)
2025/01/28 01:32:52 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (5.43s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:32:55 DEBUG : potato: md5 = 59b0854017a47d1791ac7882d9844b94 OK
2025/01/28 01:32:57 DEBUG : empty space: md5 = 70e1711af993e3203fbbac60d6002edd OK
2025/01/28 01:32:57 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/28 01:32:57 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2025/01/28 01:32:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:32:57 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:32:57 DEBUG : empty space: Unchanged skipping
2025/01/28 01:32:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:32:57 DEBUG : Waiting for deletions to finish
2025/01/28 01:32:57 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (6.34s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:33:01 DEBUG : potato: md5 = c8dfc6ea568db703b5bfeb14a9744936 OK
2025/01/28 01:33:03 DEBUG : empty space: md5 = 6c8b52b3106d4e5d4a1d2dfe07452d96 OK
2025/01/28 01:33:04 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/28 01:33:04 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:33:04 DEBUG : empty space: Unchanged skipping
2025/01/28 01:33:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:33:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:33:05 DEBUG : potato2: md5 = 103eb85a55ae1360ce1d7c1c40c1f9cc OK
2025/01/28 01:33:05 INFO  : potato2: Copied (new)
2025/01/28 01:33:05 DEBUG : Waiting for deletions to finish
2025/01/28 01:33:06 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.85s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:33:12 DEBUG : b/potato: md5 = 605cd26dc6a7f704397f928eb9432a48 OK
2025/01/28 01:33:14 DEBUG : c/non empty space: md5 = 0d479ec3db96cbb970c120eb4f4e64f0 OK
2025/01/28 01:33:14 INFO  : d: Making directory
2025/01/28 01:33:15 INFO  : d/e: Making directory
2025/01/28 01:33:18 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/01/28 01:33:18 DEBUG : Added delayed dir = "c", newDst=c
2025/01/28 01:33:18 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/01/28 01:33:18 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:33:18 DEBUG : c/non empty space: Unchanged skipping
2025/01/28 01:33:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:33:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:33:21 DEBUG : a/potato2: md5 = 48bf6ea8f9ca196953dcf794923aca43 OK
2025/01/28 01:33:21 INFO  : a/potato2: Copied (new)
2025/01/28 01:33:21 DEBUG : Waiting for deletions to finish
2025/01/28 01:33:21 INFO  : b/potato: Deleted
2025/01/28 01:33:22 INFO  : a: Set directory modification time (using DirSetModTime)
2025/01/28 01:33:22 INFO  : d/e: Removing directory
2025/01/28 01:33:23 INFO  : d: Removing directory
2025/01/28 01:33:23 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2025/01/28 01:33:24 INFO  : b: Removing directory
2025/01/28 01:33:24 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/01/28 01:33:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:33:27 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/01/28 01:33:28 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (20.91s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:33:32 DEBUG : b/potato: md5 = b1b5d378082b155968e917e7d2cb45bd OK
2025/01/28 01:33:35 DEBUG : c/non empty space: md5 = 09d9178adc66526278ead44b83e9bf88 OK
2025/01/28 01:33:35 INFO  : d: Making directory
2025/01/28 01:33:37 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/01/28 01:33:37 DEBUG : Added delayed dir = "c", newDst=c
2025/01/28 01:33:37 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/01/28 01:33:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:33:37 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:33:37 DEBUG : c/non empty space: Unchanged skipping
2025/01/28 01:33:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:33:40 DEBUG : a/potato2: md5 = 25d5196cb14ff56beb09f67c9c64988d OK
2025/01/28 01:33:40 INFO  : a/potato2: Copied (new)
2025/01/28 01:33:40 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': not deleting files as there were IO errors
2025/01/28 01:33:41 INFO  : a: Set directory modification time (using DirSetModTime)
2025/01/28 01:33:41 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:33:45 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/01/28 01:33:46 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/01/28 01:33:47 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (18.61s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:33:50 DEBUG : potato: md5 = 322c96f7ce1f6b4aea6a514fc4187fd3 OK
2025/01/28 01:33:52 DEBUG : empty space: md5 = 0b3e1f819f631aa0aa1918c7d55d63cd OK
2025/01/28 01:33:52 DEBUG : Waiting for deletions to finish
2025/01/28 01:33:52 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/28 01:33:52 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:33:52 DEBUG : empty space: Unchanged skipping
2025/01/28 01:33:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:33:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:33:53 INFO  : potato: Deleted
2025/01/28 01:33:54 DEBUG : potato2: md5 = f68e52102ead7741030ce19745211524 OK
2025/01/28 01:33:54 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (8.61s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:33:59 DEBUG : potato: md5 = fdcd7ffac59ed7746739fbcdcad69fa7 OK
2025/01/28 01:34:01 DEBUG : empty space: md5 = 2645797b4f0471d74d880ac8cb9c424d OK
2025/01/28 01:34:01 DEBUG : Waiting for deletions to finish
2025/01/28 01:34:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:34:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:34:02 INFO  : potato: Deleted
2025/01/28 01:34:02 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/28 01:34:02 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:34:02 DEBUG : empty space: Unchanged skipping
2025/01/28 01:34:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:34:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:34:04 DEBUG : potato2: md5 = 144309f9217dfe16ddca10ecd8c96067 OK
2025/01/28 01:34:04 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (10.07s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:34:09 DEBUG : potato: md5 = 7285fbebac75768028fbcee1f129214e OK
2025/01/28 01:34:09 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/28 01:34:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:34:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:34:11 DEBUG : potato2: md5 = 710c4d5fefeee212c7008745ee9dca67 OK
2025/01/28 01:34:11 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (6.37s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:34:15 DEBUG : potato2: md5 = c5a7fb73876af7dccf195273b401335a OK
2025/01/28 01:34:17 DEBUG : empty space: md5 = 14391fb991c08296adb114b676bf73e5 OK
2025/01/28 01:34:17 DEBUG : enormous: Excluded (Size Filter)
2025/01/28 01:34:17 DEBUG : enormous: Excluded
2025/01/28 01:34:17 DEBUG : potato2: Excluded (Size Filter)
2025/01/28 01:34:17 DEBUG : potato2: Excluded
2025/01/28 01:34:17 DEBUG : potato2: Excluded (Size Filter)
2025/01/28 01:34:17 DEBUG : potato2: Excluded
2025/01/28 01:34:17 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:34:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:34:17 DEBUG : empty space: Unchanged skipping
2025/01/28 01:34:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:34:17 DEBUG : Waiting for deletions to finish
2025/01/28 01:34:17 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:34:18 DEBUG : enormous: Excluded (Size Filter)
2025/01/28 01:34:18 DEBUG : enormous: Excluded
2025/01/28 01:34:18 DEBUG : potato2: Excluded (Size Filter)
2025/01/28 01:34:18 DEBUG : potato2: Excluded
2025/01/28 01:34:18 DEBUG : potato2: Excluded (Size Filter)
2025/01/28 01:34:18 DEBUG : potato2: Excluded
2025/01/28 01:34:18 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2025/01/28 01:34:18 DEBUG : empty space: Unchanged skipping
2025/01/28 01:34:18 DEBUG : Local file system at /tmp/rclone2548372772: Waiting for checks to finish
2025/01/28 01:34:18 DEBUG : Local file system at /tmp/rclone2548372772: Waiting for transfers to finish
2025/01/28 01:34:18 DEBUG : Waiting for deletions to finish
2025/01/28 01:34:18 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncWithExclude (7.63s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:34:23 DEBUG : potato2: md5 = a16d76a19ff18e0e072e38cabb443393 OK
2025/01/28 01:34:24 DEBUG : empty space: md5 = f7c1de09999331e076176a4f55bfa404 OK
2025/01/28 01:34:26 DEBUG : enormous: md5 = 9d224922c94f00a48379066e553e4931 OK
2025/01/28 01:34:26 DEBUG : enormous: Excluded (Size Filter)
2025/01/28 01:34:26 DEBUG : enormous: Excluded
2025/01/28 01:34:26 DEBUG : potato2: Excluded (Size Filter)
2025/01/28 01:34:26 DEBUG : potato2: Excluded
2025/01/28 01:34:26 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:34:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:34:26 DEBUG : empty space: Unchanged skipping
2025/01/28 01:34:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:34:26 DEBUG : Waiting for deletions to finish
2025/01/28 01:34:27 INFO  : potato2: Deleted
2025/01/28 01:34:27 INFO  : enormous: Deleted
2025/01/28 01:34:27 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:34:28 DEBUG : Local file system at /tmp/rclone2548372772: Waiting for checks to finish
2025/01/28 01:34:28 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2025/01/28 01:34:28 DEBUG : empty space: Unchanged skipping
2025/01/28 01:34:28 DEBUG : Local file system at /tmp/rclone2548372772: Waiting for transfers to finish
2025/01/28 01:34:28 DEBUG : Waiting for deletions to finish
2025/01/28 01:34:28 INFO  : potato2: Deleted
2025/01/28 01:34:28 INFO  : enormous: Deleted
2025/01/28 01:34:28 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (8.89s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:34:31 DEBUG : one: md5 = f7dca01d4eeed38861018f9adfce4a84 OK
2025/01/28 01:34:33 DEBUG : two: md5 = fa1192b383567615f5b157509405e05b OK
2025/01/28 01:34:35 DEBUG : three: md5 = 2460c5fe12684dfcc20ff2ab015dac0b OK
2025/01/28 01:34:37 DEBUG : four: md5 = 692f24b825589818ce845f6507b5283b OK
2025/01/28 01:34:37 DEBUG : five: Need to transfer - File not found at Destination
2025/01/28 01:34:37 DEBUG : four: Sizes differ (src 4 vs dst 8)
2025/01/28 01:34:37 DEBUG : one: Destination is newer than source, skipping
2025/01/28 01:34:37 DEBUG : three: Sizes identical
2025/01/28 01:34:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:34:37 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2025/01/28 01:34:37 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2025/01/28 01:34:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:34:39 DEBUG : four: md5 = f67fc9f51dbf627f27d4ad00c2b4d890 OK
2025/01/28 01:34:39 INFO  : four: Copied (replaced existing)
2025/01/28 01:34:39 DEBUG : two: md5 = 9b2321451e504935a90f3b6841c2b966 OK
2025/01/28 01:34:39 INFO  : two: Copied (replaced existing)
2025/01/28 01:34:39 DEBUG : five: md5 = 94c44cbb6dfc52a6658f36c9c76b4814 OK
2025/01/28 01:34:39 INFO  : five: Copied (new)
2025/01/28 01:34:39 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (13.34s)
=== RUN   TestSyncWithMaxDuration
=== RUN   TestSyncWithMaxDuration/Hard
    sync_test.go:1466: Skipping test on non local remote
=== RUN   TestSyncWithMaxDuration/Soft
    sync_test.go:1466: Skipping test on non local remote
--- PASS: TestSyncWithMaxDuration (0.00s)
    --- SKIP: TestSyncWithMaxDuration/Hard (0.00s)
    --- SKIP: TestSyncWithMaxDuration/Soft (0.00s)
=== RUN   TestSyncWithTrackRenames
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2025/01/28 01:34:43 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Ignoring --track-renames as the source and destination do not have a common hash
2025/01/28 01:34:43 DEBUG : potato: Need to transfer - File not found at Destination
2025/01/28 01:34:43 DEBUG : yam: Need to transfer - File not found at Destination
2025/01/28 01:34:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:34:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:34:45 DEBUG : potato: md5 = cd1335379be22fb4d5fa1016ab067a2e OK
2025/01/28 01:34:45 INFO  : potato: Copied (new)
2025/01/28 01:34:45 DEBUG : yam: md5 = 111fcfc0864f15812744f3e12cb65f9d OK
2025/01/28 01:34:45 INFO  : yam: Copied (new)
2025/01/28 01:34:45 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:34:45 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Ignoring --track-renames as the source and destination do not have a common hash
2025/01/28 01:34:46 DEBUG : yaml: Need to transfer - File not found at Destination
2025/01/28 01:34:46 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:34:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:34:46 DEBUG : potato: Unchanged skipping
2025/01/28 01:34:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:34:47 DEBUG : yaml: md5 = 67238dae609edc539c7199cb825cf8cd OK
2025/01/28 01:34:47 INFO  : yaml: Copied (new)
2025/01/28 01:34:47 DEBUG : Waiting for deletions to finish
2025/01/28 01:34:48 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (7.56s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2025/01/28 01:34:51 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Making map for --track-renames
2025/01/28 01:34:51 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Finished making map for --track-renames
2025/01/28 01:34:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:34:51 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/01/28 01:34:51 DEBUG : yam: Need to transfer - No matching file found at Destination
2025/01/28 01:34:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for renames to finish
2025/01/28 01:34:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:34:52 DEBUG : yam: md5 = 586f0b629f0e5773c724e085289c8144 OK
2025/01/28 01:34:52 INFO  : yam: Copied (new)
2025/01/28 01:34:53 DEBUG : potato: md5 = 39d6f4c086e9558a1714bff7450a0f1d OK
2025/01/28 01:34:53 INFO  : potato: Copied (new)
2025/01/28 01:34:53 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:34:53 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:34:53 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Making map for --track-renames
2025/01/28 01:34:53 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Finished making map for --track-renames
2025/01/28 01:34:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:34:53 DEBUG : potato: Unchanged skipping
2025/01/28 01:34:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for renames to finish
2025/01/28 01:34:54 INFO  : yam: Moved (server-side) to: yaml
2025/01/28 01:34:54 INFO  : yaml: Renamed from "yam"
2025/01/28 01:34:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:34:54 DEBUG : Waiting for deletions to finish
2025/01/28 01:34:54 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (6.58s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2025/01/28 01:34:57 DEBUG : Added delayed dir = "sub", newDst=<nil>
2025/01/28 01:34:57 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Making map for --track-renames
2025/01/28 01:34:57 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Finished making map for --track-renames
2025/01/28 01:34:57 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/01/28 01:34:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:34:57 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2025/01/28 01:34:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for renames to finish
2025/01/28 01:34:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:35:00 DEBUG : potato: md5 = 4a6bf700e504af13775d56277a3a19ae OK
2025/01/28 01:35:00 INFO  : potato: Copied (new)
2025/01/28 01:35:00 DEBUG : sub/yam: md5 = 8fb570aaa7558c5300b12f4a689a4f62 OK
2025/01/28 01:35:00 INFO  : sub/yam: Copied (new)
2025/01/28 01:35:00 DEBUG : Waiting for deletions to finish
2025/01/28 01:35:01 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:35:01 DEBUG : Added delayed dir = "sub", newDst=sub
2025/01/28 01:35:01 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:35:01 DEBUG : potato: Unchanged skipping
2025/01/28 01:35:02 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Making map for --track-renames
2025/01/28 01:35:02 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Finished making map for --track-renames
2025/01/28 01:35:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:35:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for renames to finish
2025/01/28 01:35:03 INFO  : sub/yam: Moved (server-side) to: yam
2025/01/28 01:35:03 INFO  : yam: Renamed from "sub/yam"
2025/01/28 01:35:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:35:03 DEBUG : Waiting for deletions to finish
2025/01/28 01:35:03 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.94s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:35:07 DEBUG : Creating backend with remote "/tmp/rclone2548372772/dir1"
2025/01/28 01:35:07 DEBUG : Creating backend with remote "/tmp/rclone2548372772/dir2"
2025/01/28 01:35:07 DEBUG : Local file system at /tmp/rclone2548372772/dir2: Using server-side directory move
2025/01/28 01:35:07 INFO  : Local file system at /tmp/rclone2548372772/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/01/28 01:35:07 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/01/28 01:35:07 DEBUG : Local file system at /tmp/rclone2548372772/dir2: Waiting for checks to finish
2025/01/28 01:35:07 DEBUG : Local file system at /tmp/rclone2548372772/dir2: Waiting for transfers to finish
2025/01/28 01:35:07 INFO  : file1.txt: Moved (server-side)
--- PASS: TestServerSideMoveLocal (0.44s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:35:08 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/01/28 01:35:08 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/28 01:35:08 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/28 01:35:08 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/01/28 01:35:08 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/01/28 01:35:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:35:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:35:11 DEBUG : sub dir/hello world: md5 = 816e9b27e73375c7f136a8d5cf7ea6e0 OK
2025/01/28 01:35:11 INFO  : sub dir/hello world: Copied (new)
2025/01/28 01:35:11 INFO  : sub dir/hello world: Deleted
2025/01/28 01:35:13 DEBUG : nested/sub dir/file: md5 = 9eca471926cdd72f5cf156b884cba909 OK
2025/01/28 01:35:13 INFO  : nested/sub dir/file: Copied (new)
2025/01/28 01:35:13 INFO  : nested/sub dir/file: Deleted
2025/01/28 01:35:14 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/01/28 01:35:14 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/28 01:35:14 INFO  : nested: Set directory modification time (using DirSetModTime)
2025/01/28 01:35:14 INFO  : sub dir: Removing directory
2025/01/28 01:35:14 INFO  : nested/sub dir: Removing directory
2025/01/28 01:35:14 INFO  : nested: Removing directory
2025/01/28 01:35:14 DEBUG : Local file system at /tmp/rclone2548372772: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:35:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/28 01:35:18 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2025/01/28 01:35:19 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (12.90s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:35:21 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/01/28 01:35:21 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/28 01:35:21 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/28 01:35:21 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/01/28 01:35:21 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/01/28 01:35:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:35:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:35:24 DEBUG : sub dir/hello world: md5 = d7734f72b8fa1cbf20a935e17fb9d5f8 OK
2025/01/28 01:35:24 INFO  : sub dir/hello world: Copied (new)
2025/01/28 01:35:24 INFO  : sub dir/hello world: Deleted
2025/01/28 01:35:26 DEBUG : nested/sub dir/file: md5 = 5fefc6a706cb6692bcfadaca1d5706f0 OK
2025/01/28 01:35:26 INFO  : nested/sub dir/file: Copied (new)
2025/01/28 01:35:26 INFO  : nested/sub dir/file: Deleted
2025/01/28 01:35:27 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/01/28 01:35:27 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/28 01:35:27 INFO  : nested: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:35:30 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/28 01:35:31 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2025/01/28 01:35:32 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (13.20s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:35:34 DEBUG : existing: Need to transfer - File not found at Destination
2025/01/28 01:35:34 DEBUG : existing-b: Need to transfer - File not found at Destination
2025/01/28 01:35:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:35:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:35:36 DEBUG : existing: md5 = e02fb0fddf3f228f34b1f537ccb05b9f OK
2025/01/28 01:35:36 INFO  : existing: Copied (new)
2025/01/28 01:35:36 INFO  : existing: Deleted
2025/01/28 01:35:36 DEBUG : existing-b: md5 = df11c6d8bc094fd314ee344cd1b8287b OK
2025/01/28 01:35:36 INFO  : existing-b: Copied (new)
2025/01/28 01:35:36 INFO  : existing-b: Deleted
2025/01/28 01:35:36 DEBUG : existing: Destination exists, skipping
2025/01/28 01:35:36 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2025/01/28 01:35:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:35:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:35:36 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (5.25s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:35:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-befagod9jega"
2025/01/28 01:35:39 DEBUG : Creating backend with remote "TestDrive:crypt/q00lf9gp57o6nsdcqob74a3c0tlicohi41jescc7qghfs0g8ol90"
2025/01/28 01:35:42 DEBUG : potato2: md5 = eaa880315a38c4a86dc9eb204716a019 OK
2025/01/28 01:35:44 DEBUG : empty space: md5 = 437d321cddd6e1b43791d3e1bda76330 OK
2025/01/28 01:35:45 DEBUG : potato3: md5 = b88718b76dd742148df2833c85969025 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude' -> Encrypted drive 'TestCryptDrive:rclone-test-befagod9jega'
2025/01/28 01:35:49 DEBUG : empty space: md5 = 19decdd4b7e83cb0d5eda9ac6280eded OK
2025/01/28 01:35:50 DEBUG : potato3: md5 = a334a99043fd7855627902b69f3b87f5 OK
2025/01/28 01:35:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-befagod9jega': Using server-side directory move
2025/01/28 01:35:51 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-befagod9jega': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/01/28 01:35:51 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/28 01:35:51 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/01/28 01:35:51 DEBUG : empty space: Unchanged skipping
2025/01/28 01:35:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-befagod9jega': Waiting for checks to finish
2025/01/28 01:35:51 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/01/28 01:35:51 INFO  : potato3: Deleted
2025/01/28 01:35:51 INFO  : empty space: Deleted
2025/01/28 01:35:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-befagod9jega': Waiting for transfers to finish
2025/01/28 01:35:52 INFO  : potato2: Moved (server-side)
2025/01/28 01:35:53 INFO  : potato3: Moved (server-side)
2025/01/28 01:35:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tivocus6xihe"
2025/01/28 01:35:53 DEBUG : Creating backend with remote "TestDrive:crypt/2frs9imf7uijrasn3vaun8plav4u634kpj8dj4bqu24lkigkim00"
2025/01/28 01:35:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tivocus6xihe': Using server-side directory move
2025/01/28 01:35:55 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tivocus6xihe': Server side directory move succeeded
2025/01/28 01:35:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tivocus6xihe': Purge remote
2025/01/28 01:35:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-befagod9jega': Purge remote
2025/01/28 01:35:57 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (18.62s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:35:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xiziyuj0lagi"
2025/01/28 01:35:58 DEBUG : Creating backend with remote "TestDrive:crypt/qru1nohiedalgsmv1h2i3jb5rdk9el6afqnem04fbrca4dsrffi0"
2025/01/28 01:36:00 DEBUG : potato2: md5 = 9618c625e5363c07a724d5481ffa1a98 OK
2025/01/28 01:36:02 DEBUG : empty space: md5 = e83c9fd4559ba2e76970123e0bcfe377 OK
2025/01/28 01:36:04 DEBUG : potato3: md5 = 18b3a54ef1337109e4fe32da0db84b83 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude' -> Encrypted drive 'TestCryptDrive:rclone-test-xiziyuj0lagi'
2025/01/28 01:36:07 DEBUG : empty space: md5 = d762c8287d174f000865a76c192526bd OK
2025/01/28 01:36:09 DEBUG : potato3: md5 = 5ce1db1e911d433860c25ea7b0b26be8 OK
2025/01/28 01:36:09 DEBUG : empty space: Excluded (Size Filter)
2025/01/28 01:36:09 DEBUG : empty space: Excluded
2025/01/28 01:36:09 DEBUG : empty space: Excluded (Size Filter)
2025/01/28 01:36:09 DEBUG : empty space: Excluded
2025/01/28 01:36:09 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/28 01:36:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xiziyuj0lagi': Waiting for checks to finish
2025/01/28 01:36:09 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/01/28 01:36:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xiziyuj0lagi': Waiting for transfers to finish
2025/01/28 01:36:10 INFO  : potato3: Deleted
2025/01/28 01:36:10 INFO  : potato2: Moved (server-side)
2025/01/28 01:36:11 INFO  : potato3: Moved (server-side)
2025/01/28 01:36:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nowupoh3roya"
2025/01/28 01:36:11 DEBUG : Creating backend with remote "TestDrive:crypt/tkhee8o8tvei4snlt86hufm83qr6d3a739kckthbkpsj2tper200"
2025/01/28 01:36:13 DEBUG : empty space: Excluded (Size Filter)
2025/01/28 01:36:13 DEBUG : empty space: Excluded
2025/01/28 01:36:13 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/28 01:36:13 DEBUG : potato3: Need to transfer - File not found at Destination
2025/01/28 01:36:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nowupoh3roya': Waiting for checks to finish
2025/01/28 01:36:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nowupoh3roya': Waiting for transfers to finish
2025/01/28 01:36:15 INFO  : potato3: Moved (server-side)
2025/01/28 01:36:16 INFO  : potato2: Moved (server-side)
2025/01/28 01:36:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nowupoh3roya': Purge remote
2025/01/28 01:36:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xiziyuj0lagi': Purge remote
--- PASS: TestServerSideMoveWithFilter (21.28s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:36:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yofinad4fuli"
2025/01/28 01:36:19 DEBUG : Creating backend with remote "TestDrive:crypt/hmciehjnduojsd7v081vrb8sp59slkqsp3i1phim3uc58me6mu00"
2025/01/28 01:36:21 DEBUG : potato2: md5 = 0a01c65af31902ce558e30e87021adc0 OK
2025/01/28 01:36:23 DEBUG : empty space: md5 = 11d5dcbb7478d8266c6daad89211fa35 OK
2025/01/28 01:36:25 DEBUG : potato3: md5 = 5f2d60813e3dec63050edc012aa19767 OK
2025/01/28 01:36:25 INFO  : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude' -> Encrypted drive 'TestCryptDrive:rclone-test-yofinad4fuli'
2025/01/28 01:36:29 DEBUG : empty space: md5 = 69a19d6fa6b5c396f154c6bba9134dd1 OK
2025/01/28 01:36:31 DEBUG : potato3: md5 = a2a0f82c91ac6c91034cc1bd54a8cb88 OK
2025/01/28 01:36:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yofinad4fuli': Using server-side directory move
2025/01/28 01:36:31 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-yofinad4fuli': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/01/28 01:36:32 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/28 01:36:32 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2025/01/28 01:36:32 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/01/28 01:36:32 DEBUG : empty space: Unchanged skipping
2025/01/28 01:36:32 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/01/28 01:36:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yofinad4fuli': Waiting for checks to finish
2025/01/28 01:36:32 INFO  : empty space: Deleted
2025/01/28 01:36:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yofinad4fuli': Waiting for transfers to finish
2025/01/28 01:36:32 INFO  : potato3: Deleted
2025/01/28 01:36:33 INFO  : potato2: Moved (server-side)
2025/01/28 01:36:33 INFO  : potato3: Moved (server-side)
2025/01/28 01:36:33 INFO  : tomatoDir: Removing directory
2025/01/28 01:36:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': deleted 1 directories
2025/01/28 01:36:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-benedox8xagu"
2025/01/28 01:36:35 DEBUG : Creating backend with remote "TestDrive:crypt/vivkj365j6epioqb9ospk9n01564b9k0lfbgep5pvalvs8rkpm70"
2025/01/28 01:36:36 INFO  : tomatoDir: Making directory
2025/01/28 01:36:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-benedox8xagu': Using server-side directory move
2025/01/28 01:36:38 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-benedox8xagu': Server side directory move succeeded
2025/01/28 01:36:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-benedox8xagu': Purge remote
2025/01/28 01:36:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yofinad4fuli': Purge remote
2025/01/28 01:36:40 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (21.78s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.44s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:36:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/rclone-sync-test"
2025/01/28 01:36:41 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncOverlap (3.84s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:36:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/rclone-sync-test"
2025/01/28 01:36:45 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2025/01/28 01:36:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/rclone-sync-test-include/layer2"
2025/01/28 01:36:48 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2025/01/28 01:36:52 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/rclone-sync-test-ignore-file"
2025/01/28 01:36:52 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2025/01/28 01:36:56 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 8813eb3998ca63eceb2ba4e8a40a34d9 OK
2025/01/28 01:36:57 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/01/28 01:36:58 DEBUG : rclone-sync-test: Excluded
2025/01/28 01:36:58 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/01/28 01:36:58 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/01/28 01:36:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/rclone-sync-test': Waiting for checks to finish
2025/01/28 01:36:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/rclone-sync-test': Waiting for transfers to finish
2025/01/28 01:36:58 DEBUG : Waiting for deletions to finish
2025/01/28 01:36:58 INFO  : There was nothing to transfer
2025/01/28 01:36:59 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/01/28 01:36:59 DEBUG : rclone-sync-test: Excluded
2025/01/28 01:37:00 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/01/28 01:37:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:37:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:37:00 DEBUG : Waiting for deletions to finish
2025/01/28 01:37:00 INFO  : rclone-sync-test-include: Removing directory
2025/01/28 01:37:00 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/01/28 01:37:00 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2025/01/28 01:37:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': failed to delete 1 directories
2025/01/28 01:37:00 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:37:01 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/01/28 01:37:01 DEBUG : rclone-sync-test: Excluded
2025/01/28 01:37:01 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/01/28 01:37:02 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/01/28 01:37:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/rclone-sync-test-include/layer2': Waiting for checks to finish
2025/01/28 01:37:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/rclone-sync-test-include/layer2': Waiting for transfers to finish
2025/01/28 01:37:02 DEBUG : Waiting for deletions to finish
2025/01/28 01:37:02 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:37:03 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/01/28 01:37:03 DEBUG : rclone-sync-test: Excluded
2025/01/28 01:37:04 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/01/28 01:37:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:37:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:37:04 DEBUG : Waiting for deletions to finish
2025/01/28 01:37:04 INFO  : rclone-sync-test-include: Removing directory
2025/01/28 01:37:04 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/01/28 01:37:04 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2025/01/28 01:37:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': failed to delete 1 directories
2025/01/28 01:37:04 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:37:04 DEBUG : : Excluded
2025/01/28 01:37:05 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/01/28 01:37:05 DEBUG : rclone-sync-test: Excluded
2025/01/28 01:37:05 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/01/28 01:37:06 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/01/28 01:37:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/rclone-sync-test-ignore-file': Waiting for checks to finish
2025/01/28 01:37:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/rclone-sync-test-ignore-file': Waiting for transfers to finish
2025/01/28 01:37:06 DEBUG : Waiting for deletions to finish
2025/01/28 01:37:06 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:37:08 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/01/28 01:37:09 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (34.25s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:37:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/dst"
2025/01/28 01:37:19 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/28 01:37:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/CompareDest"
2025/01/28 01:37:21 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/gveqi14airsml4bgu7krj116o8"
2025/01/28 01:37:23 DEBUG : one: Need to transfer - File not found at Destination
2025/01/28 01:37:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for checks to finish
2025/01/28 01:37:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for transfers to finish
2025/01/28 01:37:26 DEBUG : one: md5 = 71f191c5a730772e1bf5580b479292fe OK
2025/01/28 01:37:26 INFO  : one: Copied (new)
2025/01/28 01:37:26 DEBUG : Waiting for deletions to finish
2025/01/28 01:37:27 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/28 01:37:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for checks to finish
2025/01/28 01:37:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for transfers to finish
2025/01/28 01:37:29 DEBUG : one: md5 = a91889c06e0cf104b1b672e05dd278e9 OK
2025/01/28 01:37:29 INFO  : one: Copied (replaced existing)
2025/01/28 01:37:29 DEBUG : Waiting for deletions to finish
2025/01/28 01:37:31 DEBUG : dst/one: md5 = 58dda4a6d5e33562b19d127a115a4d13 OK
2025/01/28 01:37:34 DEBUG : CompareDest/one: md5 = 865669c4fad19ac1baf958105d7fe24f OK
2025/01/28 01:37:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for checks to finish
2025/01/28 01:37:35 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/28 01:37:35 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:37:35 DEBUG : one: Destination found in --compare-dest, skipping
2025/01/28 01:37:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for transfers to finish
2025/01/28 01:37:35 DEBUG : Waiting for deletions to finish
2025/01/28 01:37:35 INFO  : There was nothing to transfer
2025/01/28 01:37:38 DEBUG : CompareDest/two: md5 = f282494b943ea0f11bce2c87e187eb60 OK
2025/01/28 01:37:39 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:37:39 DEBUG : two: Destination found in --compare-dest, skipping
2025/01/28 01:37:39 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/28 01:37:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for checks to finish
2025/01/28 01:37:39 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:37:39 DEBUG : one: Destination found in --compare-dest, skipping
2025/01/28 01:37:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for transfers to finish
2025/01/28 01:37:39 DEBUG : Waiting for deletions to finish
2025/01/28 01:37:39 INFO  : There was nothing to transfer
2025/01/28 01:37:40 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:37:40 DEBUG : two: Destination found in --compare-dest, skipping
2025/01/28 01:37:40 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/28 01:37:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for checks to finish
2025/01/28 01:37:41 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:37:41 DEBUG : one: Destination found in --compare-dest, skipping
2025/01/28 01:37:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for transfers to finish
2025/01/28 01:37:41 DEBUG : Waiting for deletions to finish
2025/01/28 01:37:41 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2025/01/28 01:37:42 DEBUG : two: Sizes differ (src 5 vs dst 3)
2025/01/28 01:37:42 DEBUG : two: Need to transfer - File not found at Destination
2025/01/28 01:37:42 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/28 01:37:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for checks to finish
2025/01/28 01:37:42 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:37:42 DEBUG : one: Destination found in --compare-dest, skipping
2025/01/28 01:37:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for transfers to finish
2025/01/28 01:37:44 DEBUG : two: md5 = 9c3aa0d38058f096bbe3a37e32103d26 OK
2025/01/28 01:37:44 INFO  : two: Copied (new)
2025/01/28 01:37:44 DEBUG : Waiting for deletions to finish
2025/01/28 01:37:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/28 01:37:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/28 01:37:48 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/28 01:37:48 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCompareDest (30.40s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:37:52 DEBUG : pre-dest1/1: md5 = 6aa35f146947bf5066502d056434984a OK
2025/01/28 01:37:56 DEBUG : pre-dest2/2: md5 = 67666f4f77652235bc2a0b3b9c613105 OK
2025/01/28 01:37:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/dest"
2025/01/28 01:37:56 DEBUG : Config file has changed externally - reloading
2025/01/28 01:37:56 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/rg03c1jvnehrrc617i0lnqjddc"
2025/01/28 01:37:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/pre-dest1"
2025/01/28 01:37:58 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/bbnblvh6k061ssopqrp18kd7gc"
2025/01/28 01:37:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/pre-dest2"
2025/01/28 01:37:58 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/dgicm1h6b5ejvlltm8eeif0bnk"
2025/01/28 01:38:00 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:38:00 DEBUG : 1: Destination found in --compare-dest, skipping
2025/01/28 01:38:00 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:38:00 DEBUG : 2: Destination found in --compare-dest, skipping
2025/01/28 01:38:01 DEBUG : 3: Need to transfer - File not found at Destination
2025/01/28 01:38:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dest': Waiting for checks to finish
2025/01/28 01:38:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dest': Waiting for transfers to finish
2025/01/28 01:38:04 DEBUG : 3: md5 = 0b9c69fbac530fd2d0ff5d98d21e9861 OK
2025/01/28 01:38:04 INFO  : 3: Copied (new)
2025/01/28 01:38:04 DEBUG : Waiting for deletions to finish
2025/01/28 01:38:07 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2025/01/28 01:38:08 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2025/01/28 01:38:09 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (20.05s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:38:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/dst"
2025/01/28 01:38:10 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/28 01:38:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/CopyDest"
2025/01/28 01:38:11 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/d09o6po3f7bm6ce32vdgs8h9ls"
2025/01/28 01:38:13 DEBUG : one: Need to transfer - File not found at Destination
2025/01/28 01:38:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for checks to finish
2025/01/28 01:38:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for transfers to finish
2025/01/28 01:38:16 DEBUG : one: md5 = c6ae09f874939ee150125285c666bec8 OK
2025/01/28 01:38:16 INFO  : one: Copied (new)
2025/01/28 01:38:16 DEBUG : Waiting for deletions to finish
2025/01/28 01:38:17 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/28 01:38:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for checks to finish
2025/01/28 01:38:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for transfers to finish
2025/01/28 01:38:19 DEBUG : one: md5 = 8121c71fa8cd10265c6633b130f6c909 OK
2025/01/28 01:38:19 INFO  : one: Copied (replaced existing)
2025/01/28 01:38:19 DEBUG : Waiting for deletions to finish
2025/01/28 01:38:22 DEBUG : dst/one: md5 = 62133233470e95e62002ae6d3c64b71c OK
2025/01/28 01:38:24 DEBUG : CopyDest/one: md5 = 19741a0004d459b8208982dfacebc629 OK
2025/01/28 01:38:25 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/BackupDir"
2025/01/28 01:38:25 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/s6dbk3lfi7c9kfvo6j7bla9m0g"
2025/01/28 01:38:27 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/28 01:38:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for checks to finish
2025/01/28 01:38:27 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:38:27 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/28 01:38:30 INFO  : one: Moved (server-side)
2025/01/28 01:38:31 INFO  : one: Copied (server-side copy)
2025/01/28 01:38:31 DEBUG : one: Destination found in --copy-dest, using server-side copy
2025/01/28 01:38:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for transfers to finish
2025/01/28 01:38:31 DEBUG : Waiting for deletions to finish
2025/01/28 01:38:33 DEBUG : CopyDest/two: md5 = 2d7212b19695918815af42e3646fccae OK
2025/01/28 01:38:34 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:38:36 INFO  : two: Copied (server-side copy)
2025/01/28 01:38:36 DEBUG : two: Destination found in --copy-dest, using server-side copy
2025/01/28 01:38:36 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:38:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for checks to finish
2025/01/28 01:38:36 DEBUG : one: Unchanged skipping
2025/01/28 01:38:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for transfers to finish
2025/01/28 01:38:36 DEBUG : Waiting for deletions to finish
2025/01/28 01:38:37 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:38:37 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:38:37 DEBUG : two: Unchanged skipping
2025/01/28 01:38:37 DEBUG : one: Unchanged skipping
2025/01/28 01:38:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for checks to finish
2025/01/28 01:38:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for transfers to finish
2025/01/28 01:38:37 DEBUG : Waiting for deletions to finish
2025/01/28 01:38:37 INFO  : There was nothing to transfer
2025/01/28 01:38:39 DEBUG : CopyDest/three: md5 = 93995bd266d7d27d45ef03ac37681be3 OK
2025/01/28 01:38:40 DEBUG : three: Sizes differ (src 7 vs dst 5)
2025/01/28 01:38:40 DEBUG : three: Destination not found in --copy-dest
2025/01/28 01:38:40 DEBUG : three: Need to transfer - File not found at Destination
2025/01/28 01:38:40 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:38:40 DEBUG : one: Unchanged skipping
2025/01/28 01:38:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for checks to finish
2025/01/28 01:38:40 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/28 01:38:40 DEBUG : two: Unchanged skipping
2025/01/28 01:38:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for transfers to finish
2025/01/28 01:38:42 DEBUG : three: md5 = 6d9f1e7ebf75687f2c019a1ca6c50b6e OK
2025/01/28 01:38:42 INFO  : three: Copied (new)
2025/01/28 01:38:42 DEBUG : Waiting for deletions to finish
2025/01/28 01:38:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2025/01/28 01:38:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/28 01:38:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/28 01:38:48 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2025/01/28 01:38:48 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/28 01:38:48 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/28 01:38:49 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (40.49s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:38:53 DEBUG : dst/one: md5 = e23bbe38a27dd48dd9c699fc59698f63 OK
2025/01/28 01:38:55 DEBUG : dst/two: md5 = 95d6d43878d634bea3be50040b8737ec OK
2025/01/28 01:38:56 DEBUG : dst/three.txt: md5 = 0762ce3f64caa7acdb062d2fc3aabcb9 OK
2025/01/28 01:38:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/dst"
2025/01/28 01:38:57 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/28 01:38:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/backup"
2025/01/28 01:38:58 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/1nrff024r7pq65ecp72fc28jb0"
2025/01/28 01:38:59 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/28 01:38:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for checks to finish
2025/01/28 01:38:59 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:38:59 DEBUG : two: Unchanged skipping
2025/01/28 01:39:02 INFO  : one: Moved (server-side)
2025/01/28 01:39:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for transfers to finish
2025/01/28 01:39:03 DEBUG : one: md5 = 1cf3eae54b4609262f73ea276aa11d51 OK
2025/01/28 01:39:03 INFO  : one: Copied (new)
2025/01/28 01:39:03 DEBUG : Waiting for deletions to finish
2025/01/28 01:39:05 INFO  : three.txt: Moved (server-side)
2025/01/28 01:39:05 INFO  : three.txt: Moved into backup dir
2025/01/28 01:39:07 DEBUG : dst/three.txt: md5 = eff189c067a4046ea847056517525d5b OK
2025/01/28 01:39:08 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/28 01:39:08 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:39:08 DEBUG : two: Unchanged skipping
2025/01/28 01:39:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for checks to finish
2025/01/28 01:39:09 INFO  : one: Deleted
2025/01/28 01:39:10 INFO  : one: Moved (server-side)
2025/01/28 01:39:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for transfers to finish
2025/01/28 01:39:12 DEBUG : one: md5 = 27bd7258069f416b2623d77b68d7222f OK
2025/01/28 01:39:12 INFO  : one: Copied (new)
2025/01/28 01:39:12 DEBUG : Waiting for deletions to finish
2025/01/28 01:39:12 INFO  : three.txt: Deleted
2025/01/28 01:39:13 INFO  : three.txt: Moved (server-side)
2025/01/28 01:39:13 INFO  : three.txt: Moved into backup dir
2025/01/28 01:39:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/28 01:39:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/28 01:39:18 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/28 01:39:18 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/01/28 01:39:18 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/28 01:39:18 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
--- PASS: TestSyncBackupDir (28.67s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:39:21 DEBUG : dst/one: md5 = 0f29e67d19307be66ce35ae7a4e6d1c9 OK
2025/01/28 01:39:23 DEBUG : dst/two: md5 = 80d1b41e0721f0f38d03b42fb4bb71dc OK
2025/01/28 01:39:25 DEBUG : dst/three.txt: md5 = a84a08bece353bb28462b32ac74a06ce OK
2025/01/28 01:39:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/dst"
2025/01/28 01:39:26 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/28 01:39:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/backup"
2025/01/28 01:39:26 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/1nrff024r7pq65ecp72fc28jb0"
2025/01/28 01:39:28 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/28 01:39:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for checks to finish
2025/01/28 01:39:28 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:39:28 DEBUG : two: Unchanged skipping
2025/01/28 01:39:31 INFO  : one: Moved (server-side) to: one.bak
2025/01/28 01:39:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for transfers to finish
2025/01/28 01:39:32 DEBUG : one: md5 = d58ac3f506b4ba83897cfb1ceb384332 OK
2025/01/28 01:39:32 INFO  : one: Copied (new)
2025/01/28 01:39:32 DEBUG : Waiting for deletions to finish
2025/01/28 01:39:33 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/28 01:39:33 INFO  : three.txt: Moved into backup dir
2025/01/28 01:39:36 DEBUG : dst/three.txt: md5 = e03a81e83f3fc45c29ea7af85b0c5d02 OK
2025/01/28 01:39:36 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/28 01:39:36 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:39:36 DEBUG : two: Unchanged skipping
2025/01/28 01:39:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for checks to finish
2025/01/28 01:39:37 INFO  : one.bak: Deleted
2025/01/28 01:39:38 INFO  : one: Moved (server-side) to: one.bak
2025/01/28 01:39:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for transfers to finish
2025/01/28 01:39:40 DEBUG : one: md5 = a84581a7fa8d0de2f6f82aa3348b8074 OK
2025/01/28 01:39:40 INFO  : one: Copied (new)
2025/01/28 01:39:40 DEBUG : Waiting for deletions to finish
2025/01/28 01:39:41 INFO  : three.txt.bak: Deleted
2025/01/28 01:39:42 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/28 01:39:42 INFO  : three.txt: Moved into backup dir
2025/01/28 01:39:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/28 01:39:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/28 01:39:47 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/28 01:39:47 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/28 01:39:47 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/28 01:39:47 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncBackupDirWithSuffix (28.80s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:39:50 DEBUG : dst/one: md5 = 364448151ac970dc4a42ecbdf3977e97 OK
2025/01/28 01:39:52 DEBUG : dst/two: md5 = 9fbf8f2a097a99599bd67932882f9335 OK
2025/01/28 01:39:54 DEBUG : dst/three.txt: md5 = cb178efbab298170f4a223ba3efd0578 OK
2025/01/28 01:39:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/dst"
2025/01/28 01:39:54 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/28 01:39:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/backup"
2025/01/28 01:39:55 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/1nrff024r7pq65ecp72fc28jb0"
2025/01/28 01:39:57 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/28 01:39:57 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:39:57 DEBUG : two: Unchanged skipping
2025/01/28 01:39:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for checks to finish
2025/01/28 01:39:59 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/01/28 01:39:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for transfers to finish
2025/01/28 01:40:01 DEBUG : one: md5 = 4fd33e40e9dfdde2001283cac3301d5b OK
2025/01/28 01:40:01 INFO  : one: Copied (new)
2025/01/28 01:40:01 DEBUG : Waiting for deletions to finish
2025/01/28 01:40:02 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/01/28 01:40:02 INFO  : three.txt: Moved into backup dir
2025/01/28 01:40:04 DEBUG : dst/three.txt: md5 = e442062fb0fa4ff54240713c2203dbd2 OK
2025/01/28 01:40:05 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/28 01:40:05 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:40:05 DEBUG : two: Unchanged skipping
2025/01/28 01:40:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for checks to finish
2025/01/28 01:40:06 INFO  : one-2019-01-01: Deleted
2025/01/28 01:40:06 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/01/28 01:40:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for transfers to finish
2025/01/28 01:40:08 DEBUG : one: md5 = 847e8a70209b1b0d0cb2a6ce34d60e26 OK
2025/01/28 01:40:08 INFO  : one: Copied (new)
2025/01/28 01:40:08 DEBUG : Waiting for deletions to finish
2025/01/28 01:40:09 INFO  : three-2019-01-01.txt: Deleted
2025/01/28 01:40:10 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/01/28 01:40:10 INFO  : three.txt: Moved into backup dir
2025/01/28 01:40:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/28 01:40:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/28 01:40:15 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/01/28 01:40:15 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/01/28 01:40:15 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/01/28 01:40:15 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (28.88s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:40:19 DEBUG : dst/one: md5 = 48df6fbb763419e0af8d527c7e8c0671 OK
2025/01/28 01:40:21 DEBUG : dst/two: md5 = e563bf3f59d1de4dbbac0584282bb8be OK
2025/01/28 01:40:22 DEBUG : dst/three.txt: md5 = ce6b3425212e1ef1a5b0572870fdf5e6 OK
2025/01/28 01:40:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/dst"
2025/01/28 01:40:23 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/28 01:40:24 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/28 01:40:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for checks to finish
2025/01/28 01:40:24 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:40:24 DEBUG : two: Unchanged skipping
2025/01/28 01:40:25 INFO  : one: Moved (server-side) to: one.bak
2025/01/28 01:40:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for transfers to finish
2025/01/28 01:40:27 DEBUG : one: md5 = 251e8761d59ee906f8b4d6fd3fde1f57 OK
2025/01/28 01:40:27 INFO  : one: Copied (new)
2025/01/28 01:40:27 DEBUG : Waiting for deletions to finish
2025/01/28 01:40:28 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/28 01:40:28 INFO  : three.txt: Moved into backup dir
2025/01/28 01:40:30 DEBUG : dst/three.txt: md5 = 0f8cca63bcc5ecc456a9434e6fad983e OK
2025/01/28 01:40:31 DEBUG : three.txt.bak: Excluded (Path Filter)
2025/01/28 01:40:31 DEBUG : three.txt.bak: Excluded
2025/01/28 01:40:31 DEBUG : one.bak: Excluded (Path Filter)
2025/01/28 01:40:31 DEBUG : one.bak: Excluded
2025/01/28 01:40:31 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/28 01:40:31 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:40:31 DEBUG : two: Unchanged skipping
2025/01/28 01:40:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for checks to finish
2025/01/28 01:40:32 INFO  : one.bak: Deleted
2025/01/28 01:40:32 INFO  : one: Moved (server-side) to: one.bak
2025/01/28 01:40:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude/dst': Waiting for transfers to finish
2025/01/28 01:40:34 DEBUG : one: md5 = 68d26f96ef2cfb1abf6cb289f515bbbb OK
2025/01/28 01:40:34 INFO  : one: Copied (new)
2025/01/28 01:40:34 DEBUG : Waiting for deletions to finish
2025/01/28 01:40:35 INFO  : three.txt.bak: Deleted
2025/01/28 01:40:36 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/28 01:40:36 INFO  : three.txt: Moved into backup dir
2025/01/28 01:40:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/28 01:40:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/28 01:40:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/28 01:40:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/28 01:40:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/28 01:40:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncBackupDirSuffixOnly (23.91s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:40:43 DEBUG : dst/one: md5 = f669400e3f49a2dfa69b512a006b8d4d OK
2025/01/28 01:40:45 DEBUG : dst/two: md5 = c0a4bd1802f46caf232c014b56988022 OK
2025/01/28 01:40:47 DEBUG : dst/three.txt: md5 = 2f2e236f43d4ca2b475e866c34127f12 OK
2025/01/28 01:40:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/dst"
2025/01/28 01:40:47 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/28 01:40:48 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/28 01:40:49 INFO  : one: Moved (server-side) to: one.bak
2025/01/28 01:40:51 DEBUG : one: md5 = 8bcfe1f9041ca5d3c222ffb754798f36 OK
2025/01/28 01:40:51 INFO  : one: Copied (new)
2025/01/28 01:40:51 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:40:51 DEBUG : two: Unchanged skipping
2025/01/28 01:40:51 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/01/28 01:40:52 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/28 01:40:54 DEBUG : three.txt: md5 = 01aed8b2aae253ecabf7520cfb66afdc OK
2025/01/28 01:40:54 INFO  : three.txt: Copied (new)
2025/01/28 01:40:55 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/28 01:40:56 INFO  : one.bak: Deleted
2025/01/28 01:40:57 INFO  : one: Moved (server-side) to: one.bak
2025/01/28 01:40:59 DEBUG : one: md5 = 77ac3107af11079dddf09453714789d3 OK
2025/01/28 01:40:59 INFO  : one: Copied (new)
2025/01/28 01:40:59 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:40:59 DEBUG : two: Unchanged skipping
2025/01/28 01:40:59 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/01/28 01:41:00 INFO  : three.txt.bak: Deleted
2025/01/28 01:41:01 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/28 01:41:03 DEBUG : three.txt: md5 = ebc3cfad9d8d5276c1b5cb967876e5a3 OK
2025/01/28 01:41:03 INFO  : three.txt: Copied (new)
2025/01/28 01:41:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/01/28 01:41:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/28 01:41:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/28 01:41:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/28 01:41:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/28 01:41:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/28 01:41:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncSuffix (27.69s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:41:11 DEBUG : dst/one: md5 = beeddd6c0a5187261c685a222d624f11 OK
2025/01/28 01:41:13 DEBUG : dst/two: md5 = 3775faf6cc1371f482994b7c24e9600c OK
2025/01/28 01:41:15 DEBUG : dst/three.txt: md5 = b3496f8dc0696de10d9cdcf01c16e7b5 OK
2025/01/28 01:41:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vosijug8nude/dst"
2025/01/28 01:41:15 DEBUG : Creating backend with remote "TestDrive:crypt/6le0n0j0d5ac7e28c4800jl65dhvfbk4dhajprqnfl8pnfr0qvl0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/28 01:41:16 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/28 01:41:17 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/01/28 01:41:19 DEBUG : one: md5 = 6345391f814ab86ce710a6b85cf5d2bc OK
2025/01/28 01:41:19 INFO  : one: Copied (new)
2025/01/28 01:41:19 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:41:19 DEBUG : two: Unchanged skipping
2025/01/28 01:41:19 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/01/28 01:41:20 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/01/28 01:41:22 DEBUG : three.txt: md5 = 0498c97ec23e8ea4fcc6c9757d1f80a2 OK
2025/01/28 01:41:22 INFO  : three.txt: Copied (new)
2025/01/28 01:41:23 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/28 01:41:24 INFO  : one-2019-01-01: Deleted
2025/01/28 01:41:25 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/01/28 01:41:26 DEBUG : one: md5 = 3fb2ccb68e1de2e5a539bb6b1014df54 OK
2025/01/28 01:41:26 INFO  : one: Copied (new)
2025/01/28 01:41:27 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:41:27 DEBUG : two: Unchanged skipping
2025/01/28 01:41:27 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/01/28 01:41:28 INFO  : three-2019-01-01.txt: Deleted
2025/01/28 01:41:28 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/01/28 01:41:31 DEBUG : three.txt: md5 = 912f55d45cab4c52a1f0216f61667a3c OK
2025/01/28 01:41:31 INFO  : three.txt: Copied (new)
2025/01/28 01:41:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/28 01:41:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/01/28 01:41:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/01/28 01:41:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/01/28 01:41:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/28 01:41:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/01/28 01:41:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncSuffixKeepExtension (27.89s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:41:38 DEBUG : Testêé: md5 = ebf07a59c9b5b4ac7d501d6537b75dc0 OK
2025/01/28 01:41:38 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2025/01/28 01:41:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:41:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:41:40 DEBUG : Testêé: md5 = 04e28ce5d71db68bd2c8d7ad29a60416 OK
2025/01/28 01:41:40 INFO  : Testêé: Copied (replaced existing) to: Testêé
2025/01/28 01:41:40 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (5.51s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:41:42 DEBUG : existing: Need to transfer - File not found at Destination
2025/01/28 01:41:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:41:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:41:43 DEBUG : existing: md5 = d9c01fd73c46200309bde8a7a73db3c0 OK
2025/01/28 01:41:43 INFO  : existing: Copied (new)
2025/01/28 01:41:43 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:41:44 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2025/01/28 01:41:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:41:44 ERROR : existing: Source and destination exist but do not match: immutable file modified
2025/01/28 01:41:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:41:44 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': not deleting files as there were IO errors
2025/01/28 01:41:44 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncImmutable (6.17s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:41:50 DEBUG : EXISTING: md5 = 6f099450d908a5aaad073730ff63887f OK
2025/01/28 01:41:50 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:41:50 DEBUG : existing: Unchanged skipping
2025/01/28 01:41:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:41:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:41:50 DEBUG : Waiting for deletions to finish
2025/01/28 01:41:50 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (3.82s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    sync_test.go:2635: Skipping test as local or remote are case-sensitive
--- SKIP: TestFixCase (0.44s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
=== RUN   TestMaxTransfer/Soft
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
=== RUN   TestMaxTransfer/Cautious
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.36s)
    --- SKIP: TestMaxTransfer/Hard (0.42s)
    --- SKIP: TestMaxTransfer/Soft (0.48s)
    --- SKIP: TestMaxTransfer/Cautious (0.46s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:41:55 DEBUG : both0: md5 = 6b2d96df249f987d5ca693c13360ac94 OK
2025/01/28 01:41:57 DEBUG : only0: md5 = d8096c56b400390adaf7efefa5a3562a OK
2025/01/28 01:41:59 DEBUG : both1: md5 = 5941b022bafcdbdbab3cf4b4667a7b7a OK
2025/01/28 01:42:01 DEBUG : only1: md5 = 30077f8963eb226ca2f19933f6055488 OK
2025/01/28 01:42:02 DEBUG : both2: md5 = 717be0e90192932a89de79e8d3d13096 OK
2025/01/28 01:42:04 DEBUG : only2: md5 = e6386ffb089d7a78cd963619657da7d9 OK
2025/01/28 01:42:06 DEBUG : both3: md5 = 0d2417ae8251f15850037deee0e5c2b2 OK
2025/01/28 01:42:08 DEBUG : only3: md5 = d3463c25e0f03397c3ea31401bd2bdf1 OK
2025/01/28 01:42:10 DEBUG : both4: md5 = 55b55a57c659da978a4a0ff2bb9435f4 OK
2025/01/28 01:42:12 DEBUG : only4: md5 = 9734b083bbef7f2eef83d7e6950f41f4 OK
2025/01/28 01:42:14 DEBUG : both5: md5 = 10fc3fcbf940c47744bef0cdf26b6ee5 OK
2025/01/28 01:42:16 DEBUG : only5: md5 = 728fce7729a0cd6df9b0985930fa8b11 OK
2025/01/28 01:42:18 DEBUG : both6: md5 = 166a7d07845690cddbb13720cc89938e OK
2025/01/28 01:42:20 DEBUG : only6: md5 = 2f22a861b8c8cc72ad280ffde952c2eb OK
2025/01/28 01:42:21 DEBUG : both7: md5 = 0dadba192c5ff107a5a4c3e2df520c63 OK
2025/01/28 01:42:23 DEBUG : only7: md5 = 7e5e2e7d508471e03dc4f3ce9588863f OK
2025/01/28 01:42:25 DEBUG : both8: md5 = 671e0f02e86ccc24bcef3a307903de4c OK
2025/01/28 01:42:27 DEBUG : only8: md5 = 7a327312ebc967ec5b0ca700e41a16a1 OK
2025/01/28 01:42:29 DEBUG : both9: md5 = 743fb2e94ed5d4bf0f4db7a27832c76e OK
2025/01/28 01:42:31 DEBUG : only9: md5 = 082eed32012e65544510f9ebf0b09cd5 OK
2025/01/28 01:42:33 DEBUG : both10: md5 = b7879ae70573067f664ce533e371408e OK
2025/01/28 01:42:35 DEBUG : only10: md5 = f6ef10baa9dd41089e6507dddda851a8 OK
2025/01/28 01:42:37 DEBUG : both11: md5 = 7d5e7c78e9730ccc4f0dd39ab74af63f OK
2025/01/28 01:42:38 DEBUG : only11: md5 = 359d19a4bfd72477d6a1e27f17bfe13c OK
2025/01/28 01:42:40 DEBUG : both12: md5 = 689ab6f506c817682044fe796d0b77d0 OK
2025/01/28 01:42:42 DEBUG : only12: md5 = 334e37f5e88da7075234b055096ae414 OK
2025/01/28 01:42:43 DEBUG : both13: md5 = 5a40fbdb176de68d83674203fa84e97f OK
2025/01/28 01:42:45 DEBUG : only13: md5 = 1dc8a589c79e74c274889f2470344007 OK
2025/01/28 01:42:47 DEBUG : both14: md5 = 5746e13673628ea219eff8b9d7407265 OK
2025/01/28 01:42:49 DEBUG : only14: md5 = 46d13e4234b90e9a1c4e73a20d55cf98 OK
2025/01/28 01:42:50 DEBUG : both15: md5 = 32837e726fec8023de36715c0b1d4469 OK
2025/01/28 01:42:52 DEBUG : only15: md5 = c0bdc28dd301ccc0e861cc203b337da0 OK
2025/01/28 01:42:54 DEBUG : both16: md5 = 5e80d89ddd51acc357e0d95153c2e99d OK
2025/01/28 01:42:56 DEBUG : only16: md5 = a5b5711b39607f1d9e65a3d6eaa17b73 OK
2025/01/28 01:42:57 DEBUG : both17: md5 = 8d92e281e385487542c0c6c78f7e3f5a OK
2025/01/28 01:42:59 DEBUG : only17: md5 = e2f4dac0e74ff90bae010e919499c44f OK
2025/01/28 01:43:01 DEBUG : both18: md5 = 35b671114bdc0611c288bb4006d851f1 OK
2025/01/28 01:43:03 DEBUG : only18: md5 = cbaf7c9f972cb7963a7198f06d59cfa6 OK
2025/01/28 01:43:04 DEBUG : both19: md5 = 05153ff83b8fc2c38d815873eec300e5 OK
2025/01/28 01:43:06 DEBUG : only19: md5 = 71b83db277837e1ad467be2d41f29035 OK
2025/01/28 01:43:07 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:43:07 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:43:07 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:43:07 DEBUG : both0: Unchanged skipping
2025/01/28 01:43:07 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:43:07 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:43:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:43:07 DEBUG : both10: Unchanged skipping
2025/01/28 01:43:07 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:43:07 DEBUG : both13: Unchanged skipping
2025/01/28 01:43:07 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:43:07 DEBUG : both14: Unchanged skipping
2025/01/28 01:43:07 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:43:07 DEBUG : both15: Unchanged skipping
2025/01/28 01:43:07 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:43:07 DEBUG : both16: Unchanged skipping
2025/01/28 01:43:07 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:43:07 DEBUG : both1: Unchanged skipping
2025/01/28 01:43:07 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:43:07 DEBUG : both18: Unchanged skipping
2025/01/28 01:43:07 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:43:07 DEBUG : both11: Unchanged skipping
2025/01/28 01:43:07 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:43:07 DEBUG : both17: Unchanged skipping
2025/01/28 01:43:07 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:43:07 DEBUG : both12: Unchanged skipping
2025/01/28 01:43:07 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:43:07 DEBUG : both19: Unchanged skipping
2025/01/28 01:43:07 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:43:07 DEBUG : both5: Unchanged skipping
2025/01/28 01:43:07 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:43:07 DEBUG : both6: Unchanged skipping
2025/01/28 01:43:07 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:43:07 DEBUG : both7: Unchanged skipping
2025/01/28 01:43:07 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:43:07 DEBUG : both8: Unchanged skipping
2025/01/28 01:43:07 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:43:07 DEBUG : both9: Unchanged skipping
2025/01/28 01:43:07 DEBUG : both2: Unchanged skipping
2025/01/28 01:43:07 DEBUG : both3: Unchanged skipping
2025/01/28 01:43:07 DEBUG : both4: Unchanged skipping
2025/01/28 01:43:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:43:07 DEBUG : Waiting for deletions to finish
2025/01/28 01:43:07 INFO  : only19: Deleted
2025/01/28 01:43:07 INFO  : only13: Deleted
2025/01/28 01:43:07 INFO  : only10: Deleted
2025/01/28 01:43:07 INFO  : only15: Deleted
2025/01/28 01:43:08 INFO  : only3: Deleted
2025/01/28 01:43:08 INFO  : only5: Deleted
2025/01/28 01:43:08 INFO  : only14: Deleted
2025/01/28 01:43:08 INFO  : only0: Deleted
2025/01/28 01:43:08 INFO  : only4: Deleted
2025/01/28 01:43:09 INFO  : only2: Deleted
2025/01/28 01:43:09 INFO  : only7: Deleted
2025/01/28 01:43:09 INFO  : only1: Deleted
2025/01/28 01:43:09 INFO  : only12: Deleted
2025/01/28 01:43:09 INFO  : only8: Deleted
2025/01/28 01:43:09 INFO  : only18: Deleted
2025/01/28 01:43:10 INFO  : only9: Deleted
2025/01/28 01:43:10 INFO  : only11: Deleted
2025/01/28 01:43:10 INFO  : only17: Deleted
2025/01/28 01:43:10 INFO  : only6: Deleted
2025/01/28 01:43:10 INFO  : only16: Deleted
2025/01/28 01:43:10 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (90.20s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:43:25 DEBUG : both0: md5 = b08152037703cc2b7dc707dee97226ce OK
2025/01/28 01:43:27 DEBUG : only0: md5 = fd6e695e41bcf3794e5ba08d72506259 OK
2025/01/28 01:43:29 DEBUG : both1: md5 = 39334806b29e4e69be170b520a94466f OK
2025/01/28 01:43:30 DEBUG : only1: md5 = f8105c0908a09499412a96c88ad8f58d OK
2025/01/28 01:43:32 DEBUG : both2: md5 = bb65e7f365d398455fe3538bdf54c941 OK
2025/01/28 01:43:34 DEBUG : only2: md5 = 7a5db510e1d2277f42fc9c009a8c3548 OK
2025/01/28 01:43:36 DEBUG : both3: md5 = 80fa3eb065c9857e91bbb728db330507 OK
2025/01/28 01:43:37 DEBUG : only3: md5 = 6ffddc63a9df0bad2e5e70f80a3e6422 OK
2025/01/28 01:43:39 DEBUG : both4: md5 = 589bea0ef82fa9d7183c8a017693df27 OK
2025/01/28 01:43:41 DEBUG : only4: md5 = 9a00851bc555ea65a8da19f462fcbc45 OK
2025/01/28 01:43:43 DEBUG : both5: md5 = 3bf3758ed22b1102a03bda98ef86c4c9 OK
2025/01/28 01:43:44 DEBUG : only5: md5 = 95bf82201f610784515610267d371691 OK
2025/01/28 01:43:46 DEBUG : both6: md5 = 5f4f44f128a5c6ae166202036c6b2cb3 OK
2025/01/28 01:43:48 DEBUG : only6: md5 = d297575a6e6c28d903102297fae57315 OK
2025/01/28 01:43:50 DEBUG : both7: md5 = 879b75d5e970f5752c9ce5fd00104a5d OK
2025/01/28 01:43:52 DEBUG : only7: md5 = 7778daa23ba87e48f915fb7af4940cfb OK
2025/01/28 01:43:53 DEBUG : both8: md5 = 1cad6edfe50d7e624bf497bf59fa61df OK
2025/01/28 01:43:55 DEBUG : only8: md5 = 979c7d1106eaed6bf3a1e9a44462c1a0 OK
2025/01/28 01:43:56 DEBUG : both9: md5 = 4e7e35427d8b93e761729411cc6831fb OK
2025/01/28 01:43:58 DEBUG : only9: md5 = ea0c8e63ba1d5d0a0cf3aacde9cd8967 OK
2025/01/28 01:44:00 DEBUG : both10: md5 = 648ebfe3c41813a82e6807c3f4415005 OK
2025/01/28 01:44:02 DEBUG : only10: md5 = f3054101f1f7487a44e5601a6d1773c5 OK
2025/01/28 01:44:03 DEBUG : both11: md5 = c84bdba1640f002e3b91f54377386473 OK
2025/01/28 01:44:05 DEBUG : only11: md5 = d55190623a9477c68548c4536154038f OK
2025/01/28 01:44:07 DEBUG : both12: md5 = 79433d74ab48f014f4313d42c48cd415 OK
2025/01/28 01:44:08 DEBUG : only12: md5 = 52eb45948608be5f534c671986eee156 OK
2025/01/28 01:44:10 DEBUG : both13: md5 = 7d90349867e63bcacad7e5c3be563dd9 OK
2025/01/28 01:44:12 DEBUG : only13: md5 = 7b702615071a52c8bb40a93da0c2f5c7 OK
2025/01/28 01:44:13 DEBUG : both14: md5 = 33ba517a9932c87f314bfc5d835a3115 OK
2025/01/28 01:44:15 DEBUG : only14: md5 = 860d9dbe53d92784892ffc06c778b727 OK
2025/01/28 01:44:17 DEBUG : both15: md5 = b43becb2db5e8bb98ade5bdb5e9b6e27 OK
2025/01/28 01:44:18 DEBUG : only15: md5 = 19fd3908e29b671cb87ef56d4909ce18 OK
2025/01/28 01:44:20 DEBUG : both16: md5 = e752e29f2fe1848659e8ad1782a36911 OK
2025/01/28 01:44:21 DEBUG : only16: md5 = 99978bee383766fe4bb0d0e8e0964594 OK
2025/01/28 01:44:23 DEBUG : both17: md5 = 4281362ca4590829db21d996a8a4b4a1 OK
2025/01/28 01:44:25 DEBUG : only17: md5 = db9a9b03bcfdb44120e84b0b49ca0940 OK
2025/01/28 01:44:27 DEBUG : both18: md5 = 5431ca07830fdbfb514f0c0c27c08d17 OK
2025/01/28 01:44:28 DEBUG : only18: md5 = c55084a6d50081284fbb68c31ff5eb21 OK
2025/01/28 01:44:30 DEBUG : both19: md5 = 842ea1867580caed28790b2e1556b6eb OK
2025/01/28 01:44:32 DEBUG : only19: md5 = 47be39ecd2dc1394d54b0f74b614ba59 OK
2025/01/28 01:44:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for checks to finish
2025/01/28 01:44:32 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:44:32 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:44:32 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:44:32 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:44:32 DEBUG : both1: Unchanged skipping
2025/01/28 01:44:32 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:44:32 DEBUG : both12: Unchanged skipping
2025/01/28 01:44:32 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:44:32 DEBUG : both13: Unchanged skipping
2025/01/28 01:44:32 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:44:32 DEBUG : both0: Unchanged skipping
2025/01/28 01:44:32 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:44:32 DEBUG : both15: Unchanged skipping
2025/01/28 01:44:32 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:44:32 DEBUG : both16: Unchanged skipping
2025/01/28 01:44:32 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:44:32 DEBUG : both17: Unchanged skipping
2025/01/28 01:44:32 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:44:32 DEBUG : both18: Unchanged skipping
2025/01/28 01:44:32 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:44:32 DEBUG : both19: Unchanged skipping
2025/01/28 01:44:32 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:44:32 DEBUG : both2: Unchanged skipping
2025/01/28 01:44:32 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:44:32 DEBUG : both3: Unchanged skipping
2025/01/28 01:44:32 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:44:32 DEBUG : both4: Unchanged skipping
2025/01/28 01:44:32 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:44:32 DEBUG : both5: Unchanged skipping
2025/01/28 01:44:32 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:44:32 DEBUG : both6: Unchanged skipping
2025/01/28 01:44:32 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:44:32 DEBUG : both7: Unchanged skipping
2025/01/28 01:44:32 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:44:32 DEBUG : both8: Unchanged skipping
2025/01/28 01:44:32 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/28 01:44:32 DEBUG : both9: Unchanged skipping
2025/01/28 01:44:32 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2025/01/28 01:44:32 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2025/01/28 01:44:32 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2025/01/28 01:44:32 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2025/01/28 01:44:32 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2025/01/28 01:44:32 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2025/01/28 01:44:32 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2025/01/28 01:44:32 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2025/01/28 01:44:32 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2025/01/28 01:44:32 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2025/01/28 01:44:32 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2025/01/28 01:44:32 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2025/01/28 01:44:32 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2025/01/28 01:44:32 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2025/01/28 01:44:32 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2025/01/28 01:44:32 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2025/01/28 01:44:32 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2025/01/28 01:44:32 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2025/01/28 01:44:32 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2025/01/28 01:44:32 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2025/01/28 01:44:32 DEBUG : both10: Unchanged skipping
2025/01/28 01:44:32 DEBUG : both11: Unchanged skipping
2025/01/28 01:44:32 DEBUG : both14: Unchanged skipping
2025/01/28 01:44:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Waiting for transfers to finish
2025/01/28 01:44:34 DEBUG : only0: md5 = 9719747e64953607027a0b97f51fe09c OK
2025/01/28 01:44:34 INFO  : only0: Copied (replaced existing)
2025/01/28 01:44:34 DEBUG : only11: md5 = 66aaa06e1cfbb707d7dd095ae08739f1 OK
2025/01/28 01:44:34 INFO  : only11: Copied (replaced existing)
2025/01/28 01:44:34 DEBUG : only1: md5 = 8e9b9cbd673daf6c076d905597a14df2 OK
2025/01/28 01:44:34 INFO  : only1: Copied (replaced existing)
2025/01/28 01:44:34 DEBUG : only10: md5 = c0cefa02921ed8ccb21e3fddafcbaebc OK
2025/01/28 01:44:34 INFO  : only10: Copied (replaced existing)
2025/01/28 01:44:35 DEBUG : only13: md5 = ecf2381a65527a11c2954e8e37028fea OK
2025/01/28 01:44:35 INFO  : only13: Copied (replaced existing)
2025/01/28 01:44:35 DEBUG : only14: md5 = 84a8c03e5b4c995529607f4d07e3458c OK
2025/01/28 01:44:35 INFO  : only14: Copied (replaced existing)
2025/01/28 01:44:35 DEBUG : only15: md5 = 4c390d87badd82645b49b1a0cbce8ef1 OK
2025/01/28 01:44:35 INFO  : only15: Copied (replaced existing)
2025/01/28 01:44:35 DEBUG : only12: md5 = c3824e8d27d0ac0d9738f900d019c8dd OK
2025/01/28 01:44:35 INFO  : only12: Copied (replaced existing)
2025/01/28 01:44:36 DEBUG : only17: md5 = c8a5d33b5a04b3d996b3debb6dde2701 OK
2025/01/28 01:44:36 INFO  : only17: Copied (replaced existing)
2025/01/28 01:44:36 DEBUG : only18: md5 = cc121120f6eb9425950a77ec3676da06 OK
2025/01/28 01:44:36 INFO  : only18: Copied (replaced existing)
2025/01/28 01:44:36 DEBUG : only16: md5 = ecd0d70c98cff0429b4a396f353dcfd9 OK
2025/01/28 01:44:36 INFO  : only16: Copied (replaced existing)
2025/01/28 01:44:37 DEBUG : only19: md5 = b4886ad977f953523a4ecc86f7e25ef2 OK
2025/01/28 01:44:37 INFO  : only19: Copied (replaced existing)
2025/01/28 01:44:38 DEBUG : only2: md5 = efdf7574897d114550799934f49fb3b4 OK
2025/01/28 01:44:38 INFO  : only2: Copied (replaced existing)
2025/01/28 01:44:38 DEBUG : only4: md5 = 644f8b5f54af850a0ff2c92ab59103a0 OK
2025/01/28 01:44:38 INFO  : only4: Copied (replaced existing)
2025/01/28 01:44:38 DEBUG : only3: md5 = 8e2e513bb3fc65ecb1ce7c4f90603904 OK
2025/01/28 01:44:38 INFO  : only3: Copied (replaced existing)
2025/01/28 01:44:38 DEBUG : only5: md5 = b511424121270236b7f687a5620ad1ea OK
2025/01/28 01:44:38 INFO  : only5: Copied (replaced existing)
2025/01/28 01:44:39 DEBUG : only6: md5 = 89d600bc25c3543079c4ddb5443509a7 OK
2025/01/28 01:44:39 INFO  : only6: Copied (replaced existing)
2025/01/28 01:44:39 DEBUG : only7: md5 = ba0a42363bc758d26be9d6dd6ff04dae OK
2025/01/28 01:44:39 INFO  : only7: Copied (replaced existing)
2025/01/28 01:44:39 DEBUG : only9: md5 = 3958eba23711d13b765b0b8ec58f9f80 OK
2025/01/28 01:44:39 INFO  : only9: Copied (replaced existing)
2025/01/28 01:44:39 DEBUG : only8: md5 = 45672c0e28865e270ad92e1fcfe7ffd1 OK
2025/01/28 01:44:39 INFO  : only8: Copied (replaced existing)
2025/01/28 01:44:39 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (101.83s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:45:05 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/28 01:45:05 DEBUG : sub dir: Making directory with metadata
2025/01/28 01:45:06 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:45:27 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/28 01:45:28 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/28 01:45:28 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/28 01:45:28 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:45:42 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2025/01/28 01:45:43 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/28 01:45:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2025/01/28 01:45:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2025/01/28 01:45:45 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/28 01:45:46 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/28 01:45:47 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/28 01:45:48 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/28 01:45:49 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/28 01:45:50 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2025/01/28 01:45:50 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/28 01:45:51 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (47.83s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:45:53 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/28 01:45:53 DEBUG : sub dir: Making directory with metadata
2025/01/28 01:45:54 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:46:19 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/28 01:46:20 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/28 01:46:20 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/28 01:46:20 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude'", Local "Local file system at /tmp/rclone2548372772", Modify Window "1ms"
2025/01/28 01:46:32 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/28 01:46:33 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2025/01/28 01:46:35 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2025/01/28 01:46:35 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/28 01:46:36 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/28 01:46:37 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/28 01:46:38 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/28 01:46:39 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/28 01:46:40 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2025/01/28 01:46:40 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/28 01:46:41 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (49.87s)
PASS
2025/01/28 01:46:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vosijug8nude': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 18m31.70061796s (try 1/5)