"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5)
2025/04/19 04:34:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa"
2025/04/19 04:34:48 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/19 04:34:48 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10"
2025/04/19 04:34:49 DEBUG : Creating backend with remote "/tmp/rclone1578056088"
=== RUN   TestPipe
--- PASS: TestPipe (0.00s)
=== RUN   TestPipeConcurrent
--- PASS: TestPipeConcurrent (0.05s)
=== 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-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:34:50 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/19 04:34:50 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/19 04:34:50 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2025/04/19 04:34:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:34:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:34:50 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (2.18s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:34:52 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/19 04:34:52 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/19 04:34:52 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/19 04:34:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:34:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:34:54 DEBUG : sub dir/hello world: md5 = 3716ad81b68d0f4384788c717573c4c0 OK
2025/04/19 04:34:54 INFO  : sub dir/hello world: Copied (new)
2025/04/19 04:34:54 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:34:56 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (6.08s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:34:58 DEBUG : metadata sub dir: Making directory with metadata
2025/04/19 04:34:58 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/19 04:34:58 DEBUG : empty metadata sub dir: Making directory with metadata
2025/04/19 04:34:58 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/19 04:34:58 DEBUG : Local file system at /tmp/rclone1578056088: File to upload is small (21 bytes), uploading instead of streaming
2025/04/19 04:34:58 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2025/04/19 04:34:58 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2025/04/19 04:34:58 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2025/04/19 04:34:58 DEBUG : Google drive root 'crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10': Skipping btime metadata as can't update it on an existing file: 2025-04-19T04:34:58.073942181Z
2025/04/19 04:34:59 INFO  : empty metadata sub dir: Updated directory metadata
2025/04/19 04:34:59 DEBUG : Google drive root 'crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10': Skipping btime metadata as can't update it on an existing file: 2025-04-19T04:34:58.073942181Z
2025/04/19 04:34:59 INFO  : metadata sub dir: Updated directory metadata
2025/04/19 04:34:59 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2025/04/19 04:34:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:34:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:35:01 DEBUG : metadata sub dir/hello metadata world: md5 = ebdd6abc181b168e61e33e6cd3bfab16 OK
2025/04/19 04:35:01 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:35:03 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (7.54s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:35:05 DEBUG : metadata sub dir: Making directory with metadata
2025/04/19 04:35:05 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/19 04:35:05 DEBUG : empty metadata sub dir: Making directory with metadata
2025/04/19 04:35:05 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/19 04:35:05 DEBUG : Local file system at /tmp/rclone1578056088: File to upload is small (21 bytes), uploading instead of streaming
2025/04/19 04:35:05 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2025/04/19 04:35:05 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2025/04/19 04:35:05 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2025/04/19 04:35:05 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2025/04/19 04:35:05 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2025/04/19 04:35:05 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2025/04/19 04:35:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:35:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:35:08 DEBUG : metadata sub dir/hello metadata world: md5 = 2415500b164107207642bdc7bb1da61d OK
2025/04/19 04:35:08 INFO  : metadata sub dir/hello metadata world: Copied (new)
2025/04/19 04:35:08 DEBUG : Google drive root 'crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10': Skipping btime metadata as can't update it on an existing file: 2025-04-19T04:35:05.61395913Z
2025/04/19 04:35:08 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:35:11 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (6.63s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:35:12 DEBUG : Creating backend with remote "/non-existing"
2025/04/19 04:35:12 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2025/04/19 04:35:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:35:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.13s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:35:13 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/19 04:35:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/19 04:35:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:35:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:35:15 DEBUG : sub dir/hello world: md5 = 6d106453e33daf882c6ebee8d6420f91 OK
2025/04/19 04:35:15 INFO  : sub dir/hello world: Copied (new)
2025/04/19 04:35:16 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:35:18 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (6.01s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:35:19 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Running all checks before starting transfers
2025/04/19 04:35:19 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/19 04:35:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/19 04:35:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:35:19 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Checks finished, now starting transfers
2025/04/19 04:35:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:35:21 DEBUG : sub dir/hello world: md5 = faa067c1ccb7cf151494de9753c428d3 OK
2025/04/19 04:35:21 INFO  : sub dir/hello world: Copied (new)
2025/04/19 04:35:22 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:35:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (5.69s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:35:25 ERROR : Ignoring --no-traverse with sync
2025/04/19 04:35:25 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/19 04:35:25 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/19 04:35:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:35:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:35:27 DEBUG : sub dir/hello world: md5 = fbbaff7d5efaba29efc863ed47843d08 OK
2025/04/19 04:35:27 INFO  : sub dir/hello world: Copied (new)
2025/04/19 04:35:27 DEBUG : Waiting for deletions to finish
2025/04/19 04:35:28 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:35:29 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (5.90s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:35:31 DEBUG : hello world2: Need to transfer - File not found at Destination
2025/04/19 04:35:31 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/19 04:35:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:35:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:35:32 DEBUG : hello world2: md5 = 5ee28bbe3f75cfbbf70e406feb88bb9b OK
2025/04/19 04:35:32 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestCopyWithDepth (3.12s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:35:34 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/19 04:35:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:35:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:35:35 DEBUG : potato2: md5 = 435088b9d386ad73c6c584aad0aca885 OK
2025/04/19 04:35:35 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (3.13s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:35:37 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/19 04:35:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:35:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:35:38 DEBUG : potato2: md5 = fb57d75e8e65c0f5b90bcd5bd24e962a OK
2025/04/19 04:35:38 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (3.20s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:35:40 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/04/19 04:35:40 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/19 04:35:40 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/04/19 04:35:40 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/19 04:35:40 DEBUG : sub dir: Making directory with metadata
2025/04/19 04:35:41 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/04/19 04:35:41 DEBUG : sub dir2: Making directory with metadata
2025/04/19 04:35:42 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/19 04:35:42 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/04/19 04:35:42 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/19 04:35:42 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/19 04:35:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:35:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:35:43 DEBUG : sub dir/hello world: md5 = d8c1e09c04cf52e91f8e253c13e93ffa OK
2025/04/19 04:35:43 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:35:47 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2025/04/19 04:35:47 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (8.60s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:35:49 INFO  : sub dir2: Making directory
2025/04/19 04:35:49 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/04/19 04:35:49 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/19 04:35:49 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/19 04:35:49 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/04/19 04:35:49 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2025/04/19 04:35:49 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/19 04:35:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:35:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:35:51 DEBUG : sub dir/hello world: md5 = e85671ad9b6163d9a0c158324fe76621 OK
2025/04/19 04:35:51 INFO  : sub dir/hello world: Copied (new)
2025/04/19 04:35:51 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/19 04:35:53 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (5.10s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:35:54 DEBUG : sub dir2: Making directory with metadata
2025/04/19 04:35:54 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/19 04:35:54 DEBUG : sub dir: Making directory with metadata
2025/04/19 04:35:55 INFO  : sub dir: Made directory with metadata (mtime=2025-04-19T04:35:54.118067Z)
2025/04/19 04:35:55 DEBUG : sub dir2: Making directory with metadata
2025/04/19 04:35:55 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/19 04:35:55 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/19 04:35:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:35:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:35:57 DEBUG : sub dir/hello world: md5 = a6e7b81603ac453fb6900bee1a2ca0c0 OK
2025/04/19 04:35:57 INFO  : sub dir/hello world: Copied (new)
2025/04/19 04:35:57 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:36:00 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (7.08s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:36:01 DEBUG : sub dir no update dir modtime: Making directory with metadata
2025/04/19 04:36:01 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/04/19 04:36:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:36:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:36:02 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (3.77s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:36:04 INFO  : sub dir2: Making directory
2025/04/19 04:36:05 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/19 04:36:05 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/04/19 04:36:05 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/19 04:36:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:36:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:36:07 DEBUG : sub dir/hello world: md5 = fe841396528eb28791f722bf3e3000ab OK
2025/04/19 04:36:07 INFO  : sub dir/hello world: Copied (new)
2025/04/19 04:36:07 INFO  : sub dir/hello world: Deleted
2025/04/19 04:36:07 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/19 04:36:09 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (5.29s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:36:10 DEBUG : sub dir2: Making directory with metadata
2025/04/19 04:36:10 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/19 04:36:10 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/19 04:36:10 DEBUG : sub dir: Making directory with metadata
2025/04/19 04:36:11 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/04/19 04:36:11 DEBUG : sub dir2: Making directory with metadata
2025/04/19 04:36:12 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/19 04:36:12 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/19 04:36:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:36:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:36:13 DEBUG : sub dir/hello world: md5 = ce37b9a15d8a58fa326c5b3bf2b976c2 OK
2025/04/19 04:36:13 INFO  : sub dir/hello world: Copied (new)
2025/04/19 04:36:13 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:36:16 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (7.06s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.46s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:36:17 INFO  : sub dir2: Making directory
2025/04/19 04:36:18 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/19 04:36:18 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/04/19 04:36:18 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/19 04:36:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:36:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:36:20 DEBUG : sub dir/hello world: md5 = edf4fe4cac0a8887b7258656a7dc386f OK
2025/04/19 04:36:20 INFO  : sub dir/hello world: Copied (new)
2025/04/19 04:36:20 DEBUG : Waiting for deletions to finish
2025/04/19 04:36:20 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/19 04:36:22 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (5.50s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:36:25 DEBUG : sub dir/hello world: md5 = a560785f09649289f4d6bc7523bd45f1 OK
2025/04/19 04:36:25 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cosamar0fuce"
2025/04/19 04:36:25 DEBUG : Creating backend with remote "TestDrive:crypt/j4ft3nmtq88hnlf79a4otbbnvd49mkroa7j7qg19mk2ulnipg80g"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa' -> Encrypted drive 'TestCryptDrive:rclone-test-cosamar0fuce'
2025/04/19 04:36:27 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/19 04:36:27 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/19 04:36:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cosamar0fuce': Waiting for checks to finish
2025/04/19 04:36:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cosamar0fuce': Waiting for transfers to finish
2025/04/19 04:36:29 INFO  : sub dir/hello world: Copied (server-side copy)
2025/04/19 04:36:30 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:36:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cosamar0fuce': Purge remote
2025/04/19 04:36:32 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (10.24s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:36:35 DEBUG : sub dir/hello world: md5 = 328986a67db6321b754fb88f61cd1164 OK
2025/04/19 04:36:36 INFO  : sub dir: Set directory modification time (using SetModTime)
2025/04/19 04:36:36 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/04/19 04:36:36 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/04/19 04:36:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:36:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:36:38 DEBUG : sub dir/hello world: md5 = 044a6806d0d4a842aaf04aae5f1a170e OK
2025/04/19 04:36:38 INFO  : sub dir/hello world: Copied (replaced existing)
2025/04/19 04:36:38 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:36:40 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (7.97s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:36:43 DEBUG : sub dir/hello world: md5 = 54f188df9f8aff3b1737634b5f357c4b OK
2025/04/19 04:36:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vezumiw1jube"
2025/04/19 04:36:43 DEBUG : Config file has changed externally - reloading
2025/04/19 04:36:44 DEBUG : Creating backend with remote "TestDrive:crypt/3m6pukntabf2iqtj3t0k6me7gjq6daah95qk951v0k8kdlmtg3u0"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa' -> Encrypted drive 'TestCryptDrive:rclone-test-vezumiw1jube'
2025/04/19 04:36:45 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/19 04:36:45 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/19 04:36:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vezumiw1jube': Waiting for checks to finish
2025/04/19 04:36:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vezumiw1jube': Waiting for transfers to finish
2025/04/19 04:36:47 INFO  : sub dir/hello world: Copied (server-side copy)
2025/04/19 04:36:48 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:36:50 DEBUG : sub dir/hello world: md5 = 311cd92b06ebc1cb861c822b326bc64b OK
2025/04/19 04:36:50 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/04/19 04:36:50 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/04/19 04:36:51 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/04/19 04:36:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vezumiw1jube': Waiting for checks to finish
2025/04/19 04:36:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vezumiw1jube': Waiting for transfers to finish
2025/04/19 04:36:52 INFO  : sub dir/hello world: Copied (server-side copy)
2025/04/19 04:36:53 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:36:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vezumiw1jube': Purge remote
2025/04/19 04:36:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (15.35s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:36:58 DEBUG : sub dir/hello world: md5 = 58577d886a23452ff62a8ef5cabbc8ba OK
2025/04/19 04:37:00 INFO  : sub dir: Set directory modification time (using SetModTime)
2025/04/19 04:37:00 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/04/19 04:37:00 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/04/19 04:37:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:37:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:37:01 DEBUG : sub dir/hello world: md5 = e6271d2947c4e328278166c046db046e OK
2025/04/19 04:37:01 INFO  : sub dir/hello world: Copied (replaced existing)
2025/04/19 04:37:01 INFO  : sub dir/hello world: Deleted
2025/04/19 04:37:01 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:37:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (7.73s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:37:07 DEBUG : sub dir/hello world: md5 = 2dac8842de87502ad425e0d8d153dd2e OK
2025/04/19 04:37:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-reyelop0soha"
2025/04/19 04:37:07 DEBUG : Creating backend with remote "TestDrive:crypt/5fgnpd0jc9a9htoljsg5a3o7nafnih53enugk92qorc0sgndp4q0"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa' -> Encrypted drive 'TestCryptDrive:rclone-test-reyelop0soha'
2025/04/19 04:37:08 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/19 04:37:09 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/19 04:37:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-reyelop0soha': Waiting for checks to finish
2025/04/19 04:37:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-reyelop0soha': Waiting for transfers to finish
2025/04/19 04:37:11 INFO  : sub dir/hello world: Copied (server-side copy)
2025/04/19 04:37:11 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:37:13 DEBUG : sub dir/hello world: md5 = 906fae946523a9da3c330b2d99773753 OK
2025/04/19 04:37:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-reyelop0soha': Using server-side directory move
2025/04/19 04:37:14 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-reyelop0soha': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/04/19 04:37:14 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/04/19 04:37:14 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/04/19 04:37:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-reyelop0soha': Waiting for checks to finish
2025/04/19 04:37:14 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/04/19 04:37:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-reyelop0soha': Waiting for transfers to finish
2025/04/19 04:37:15 INFO  : sub dir/hello world: Deleted
2025/04/19 04:37:15 INFO  : sub dir/hello world: Moved (server-side)
2025/04/19 04:37:16 INFO  : sub dir: Set directory modification time (using SetModTime)
2025/04/19 04:37:18 DEBUG : sub dir/hello world: md5 = 02045d917a2dd3e2ee448c6947a33d41 OK
2025/04/19 04:37:18 DEBUG : testing file moves
2025/04/19 04:37:19 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/04/19 04:37:19 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/04/19 04:37:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-reyelop0soha': Waiting for checks to finish
2025/04/19 04:37:19 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2025/04/19 04:37:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-reyelop0soha': Waiting for transfers to finish
2025/04/19 04:37:19 INFO  : sub dir/hello world: Deleted
2025/04/19 04:37:20 INFO  : sub dir/hello world: Moved (server-side)
2025/04/19 04:37:20 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:37:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-reyelop0soha': Purge remote
--- PASS: TestServerSideMoveOverSelf (19.68s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:37:26 DEBUG : sub dir/hello world: md5 = 9dcf1599555d54ad8cd4eca66059fe1c OK
2025/04/19 04:37:26 ERROR : : error listing: directory not found
2025/04/19 04:37:26 INFO  : Local file system at /tmp/rclone1578056088: Making directory
2025/04/19 04:37:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:37:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:37:28 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (5.79s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:37:32 DEBUG : sub dir/hello world: md5 = 95d446b631a852baf4b80d07822e7753 OK
2025/04/19 04:37:32 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/19 04:37:33 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/19 04:37:33 DEBUG : Local file system at /tmp/rclone1578056088: Waiting for checks to finish
2025/04/19 04:37:33 DEBUG : Local file system at /tmp/rclone1578056088: Waiting for transfers to finish
2025/04/19 04:37:34 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2025/04/19 04:37:34 INFO  : sub dir/hello world: Copied (new)
2025/04/19 04:37:34 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:37:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (6.26s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:37:36 DEBUG : check sum: Need to transfer - File not found at Destination
2025/04/19 04:37:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:37:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:37:37 DEBUG : check sum: md5 = bb7b18654702b149b8defaba6e8fc180 OK
2025/04/19 04:37:37 INFO  : check sum: Copied (new)
2025/04/19 04:37:37 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:37:38 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2025/04/19 04:37:38 DEBUG : check sum: Size of src and dst objects identical
2025/04/19 04:37:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:37:38 DEBUG : check sum: Unchanged skipping
2025/04/19 04:37:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:37:38 DEBUG : Waiting for deletions to finish
2025/04/19 04:37:38 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (3.94s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:37:40 DEBUG : sizeonly: Need to transfer - File not found at Destination
2025/04/19 04:37:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:37:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:37:41 DEBUG : sizeonly: md5 = 85172033bb8e1a8bf36f89b511fa433e OK
2025/04/19 04:37:41 INFO  : sizeonly: Copied (new)
2025/04/19 04:37:41 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:37:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:37:42 DEBUG : sizeonly: Sizes identical
2025/04/19 04:37:42 DEBUG : sizeonly: Unchanged skipping
2025/04/19 04:37:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:37:42 DEBUG : Waiting for deletions to finish
2025/04/19 04:37:42 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (4.06s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:37:44 DEBUG : ignore-size: Need to transfer - File not found at Destination
2025/04/19 04:37:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:37:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:37:45 DEBUG : ignore-size: md5 = 9b1b610c77121a70794cd8131c68c0e3 OK
2025/04/19 04:37:45 INFO  : ignore-size: Copied (new)
2025/04/19 04:37:45 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:37:46 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:37:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:37:46 DEBUG : ignore-size: Unchanged skipping
2025/04/19 04:37:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:37:46 DEBUG : Waiting for deletions to finish
2025/04/19 04:37:46 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (4.05s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:37:49 DEBUG : existing: md5 = 87b14070b36c034b3a4d40981c6dca1d OK
2025/04/19 04:37:50 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:37:50 DEBUG : existing: Unchanged skipping
2025/04/19 04:37:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:37:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:37:50 DEBUG : Waiting for deletions to finish
2025/04/19 04:37:50 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:37:50 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2025/04/19 04:37:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:37:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:37:51 DEBUG : existing: md5 = 438a80a81f9d5e35b1a79c0de25559cf OK
2025/04/19 04:37:51 INFO  : existing: Copied (replaced existing)
2025/04/19 04:37:51 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (5.26s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:37:53 DEBUG : existing: Need to transfer - File not found at Destination
2025/04/19 04:37:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:37:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:37:55 DEBUG : existing: md5 = 6856a5aa56a8b6693676945d1fb620f2 OK
2025/04/19 04:37:55 INFO  : existing: Copied (new)
2025/04/19 04:37:55 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:37:55 DEBUG : existing: Destination exists, skipping
2025/04/19 04:37:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:37:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:37:55 DEBUG : Waiting for deletions to finish
2025/04/19 04:37:55 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (3.99s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:37:59 DEBUG : b/potato: md5 = df32c5be601da5c7699b8014da78ee4d OK
2025/04/19 04:38:01 DEBUG : c/non empty space: md5 = 3b02b8c978e04668fa852a7d18952ba4 OK
2025/04/19 04:38:01 INFO  : d: Making directory
2025/04/19 04:38:03 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/04/19 04:38:03 INFO  : c: Set directory modification time (using SetModTime)
2025/04/19 04:38:03 DEBUG : Added delayed dir = "c", newDst=c
2025/04/19 04:38:03 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/04/19 04:38:03 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:38:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:38:03 DEBUG : c/non empty space: Unchanged skipping
2025/04/19 04:38:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:38:05 DEBUG : a/potato2: md5 = e1015992667322b89b84de7f23c34efd OK
2025/04/19 04:38:05 INFO  : a/potato2: Copied (new)
2025/04/19 04:38:05 DEBUG : Waiting for deletions to finish
2025/04/19 04:38:06 INFO  : b/potato: Deleted
2025/04/19 04:38:06 INFO  : a: Set directory modification time (using DirSetModTime)
2025/04/19 04:38:06 INFO  : d: Removing directory
2025/04/19 04:38:07 INFO  : b: Removing directory
2025/04/19 04:38:07 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/04/19 04:38:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:38:10 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/04/19 04:38:10 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (14.43s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:38:13 DEBUG : empty space: md5 = 11e21ebcb618f1f1dc9114209eb8db0f OK
2025/04/19 04:38:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:38:13 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/04/19 04:38:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:38:13 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2025/04/19 04:38:13 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:38:14 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2025/04/19 04:38:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:38:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:38:15 DEBUG : empty space: md5 = 070b6336b6b60e56b635f9517c0548c4 OK
2025/04/19 04:38:15 INFO  : empty space: Copied (replaced existing)
2025/04/19 04:38:15 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (5.38s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.50s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:38:19 DEBUG : foo: md5 = 53079debc5b25ce7ab8bf30d19135c9b OK
2025/04/19 04:38:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:38:19 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/04/19 04:38:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:38:20 DEBUG : foo: md5 = f0af3cc4632833ed1749a0a9c894ffc6 OK
2025/04/19 04:38:20 INFO  : foo: Copied (replaced existing)
2025/04/19 04:38:20 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (4.56s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:38:23 DEBUG : empty space: md5 = 0d759ff0bd0eff7630fa36914f7a8764 OK
2025/04/19 04:38:24 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:38:24 DEBUG : potato: Need to transfer - File not found at Destination
2025/04/19 04:38:24 DEBUG : empty space: Unchanged skipping
2025/04/19 04:38:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:38:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:38:25 DEBUG : potato: md5 = d674d5aba0610c96d78a79b3a7fd6d97 OK
2025/04/19 04:38:25 INFO  : potato: Copied (new)
2025/04/19 04:38:25 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (5.22s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:38:29 DEBUG : potato: md5 = 4e8fe451d53711a0a6d1ff0ca38c34d5 OK
2025/04/19 04:38:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:38:29 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2025/04/19 04:38:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:38:30 DEBUG : potato: md5 = ff80bb317df6f9c1fda83cc654a53241 OK
2025/04/19 04:38:30 INFO  : potato: Copied (replaced existing)
2025/04/19 04:38:30 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (4.47s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:38:33 DEBUG : potato: md5 = 315a14a3c66adfca45a26a2795e330de OK
2025/04/19 04:38:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:38:33 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/04/19 04:38:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:38:35 DEBUG : potato: md5 = 5768dbe410d589afeea8a01de687a01e OK
2025/04/19 04:38:35 INFO  : potato: Copied (replaced existing)
2025/04/19 04:38:35 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (4.53s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:38:38 DEBUG : potato: md5 = de703c1c84799188a6da984241bc938e OK
2025/04/19 04:38:39 DEBUG : empty space: md5 = 842858f4bedbb67a3265366cb4c8cb30 OK
2025/04/19 04:38:39 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/19 04:38:39 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:38:39 DEBUG : empty space: Unchanged skipping
2025/04/19 04:38:39 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2025/04/19 04:38:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:38:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:38:39 DEBUG : Waiting for deletions to finish
2025/04/19 04:38:39 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.35s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:38:43 DEBUG : potato: md5 = fd5be83e0e66b79728ff515aa274b9de OK
2025/04/19 04:38:44 DEBUG : empty space: md5 = e29392e958606d0b14a489213428b552 OK
2025/04/19 04:38:45 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:38:45 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/19 04:38:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:38:45 DEBUG : empty space: Unchanged skipping
2025/04/19 04:38:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:38:46 DEBUG : potato2: md5 = 26d4d2f54084b44ce79107fe032cd0e2 OK
2025/04/19 04:38:46 INFO  : potato2: Copied (new)
2025/04/19 04:38:46 DEBUG : Waiting for deletions to finish
2025/04/19 04:38:46 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (6.90s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:38:50 DEBUG : b/potato: md5 = 08693b2cd66749f906d9c9c169d74fa1 OK
2025/04/19 04:38:52 DEBUG : c/non empty space: md5 = c6d7800a8fb10dc649e10bda05c8d7e4 OK
2025/04/19 04:38:52 INFO  : d: Making directory
2025/04/19 04:38:53 INFO  : d/e: Making directory
2025/04/19 04:38:55 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/04/19 04:38:55 INFO  : c: Set directory modification time (using SetModTime)
2025/04/19 04:38:55 DEBUG : Added delayed dir = "c", newDst=c
2025/04/19 04:38:55 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/04/19 04:38:56 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:38:56 DEBUG : c/non empty space: Unchanged skipping
2025/04/19 04:38:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:38:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:38:57 DEBUG : a/potato2: md5 = c33163485106d5de08acc2edc8dfa280 OK
2025/04/19 04:38:57 INFO  : a/potato2: Copied (new)
2025/04/19 04:38:57 DEBUG : Waiting for deletions to finish
2025/04/19 04:38:58 INFO  : b/potato: Deleted
2025/04/19 04:38:58 INFO  : a: Set directory modification time (using DirSetModTime)
2025/04/19 04:38:58 INFO  : d/e: Removing directory
2025/04/19 04:38:59 INFO  : d: Removing directory
2025/04/19 04:38:59 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2025/04/19 04:39:00 INFO  : b: Removing directory
2025/04/19 04:39:00 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/04/19 04:39:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:39:02 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/04/19 04:39:03 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (15.80s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:39:06 DEBUG : b/potato: md5 = 7224b7547a7c214c1996f2915641430e OK
2025/04/19 04:39:08 DEBUG : c/non empty space: md5 = 3e6483d76fd1530986081f0764814de0 OK
2025/04/19 04:39:08 INFO  : d: Making directory
2025/04/19 04:39:10 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/04/19 04:39:10 INFO  : c: Set directory modification time (using SetModTime)
2025/04/19 04:39:10 DEBUG : Added delayed dir = "c", newDst=c
2025/04/19 04:39:10 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/04/19 04:39:11 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:39:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:39:11 DEBUG : c/non empty space: Unchanged skipping
2025/04/19 04:39:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:39:12 DEBUG : a/potato2: md5 = eafa015cf920c77ba7d2cb608e0aa2fe OK
2025/04/19 04:39:12 INFO  : a/potato2: Copied (new)
2025/04/19 04:39:12 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': not deleting files as there were IO errors
2025/04/19 04:39:13 INFO  : a: Set directory modification time (using DirSetModTime)
2025/04/19 04:39:13 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:39:16 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/04/19 04:39:17 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/04/19 04:39:17 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (14.25s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:39:20 DEBUG : potato: md5 = 833b0fe89424e5dce99c149c32a498c9 OK
2025/04/19 04:39:21 DEBUG : empty space: md5 = 44f6c84ef6daf1a1e8d6ad72e64d2072 OK
2025/04/19 04:39:21 DEBUG : Waiting for deletions to finish
2025/04/19 04:39:22 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:39:22 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/19 04:39:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:39:22 DEBUG : empty space: Unchanged skipping
2025/04/19 04:39:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:39:22 INFO  : potato: Deleted
2025/04/19 04:39:23 DEBUG : potato2: md5 = a7a52038018488c3e4480cf2bd05e416 OK
2025/04/19 04:39:23 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (6.46s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:39:26 DEBUG : potato: md5 = 6b8d9bec8be5c491df14fb653d1bbdf9 OK
2025/04/19 04:39:28 DEBUG : empty space: md5 = 3c2c78825acc2293fc986b8a1f284d51 OK
2025/04/19 04:39:28 DEBUG : Waiting for deletions to finish
2025/04/19 04:39:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:39:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:39:29 INFO  : potato: Deleted
2025/04/19 04:39:29 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:39:29 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/19 04:39:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:39:29 DEBUG : empty space: Unchanged skipping
2025/04/19 04:39:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:39:30 DEBUG : potato2: md5 = 22bd20d20655cc5e262d0235631cb758 OK
2025/04/19 04:39:30 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (7.10s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:39:34 DEBUG : potato: md5 = 26c506adc46a5fbbdaa16ea1cdd4c60f OK
2025/04/19 04:39:34 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/19 04:39:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:39:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:39:35 DEBUG : potato2: md5 = 565cd1b85e934525a9793cf68f540f6e OK
2025/04/19 04:39:35 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (5.37s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:39:39 DEBUG : potato2: md5 = 28d6b1e81c3ef5f7e6768a5d5b06be12 OK
2025/04/19 04:39:40 DEBUG : empty space: md5 = 6a44a327c806585ea414ad7162aebb01 OK
2025/04/19 04:39:40 DEBUG : enormous: Excluded (Size Filter)
2025/04/19 04:39:40 DEBUG : enormous: Excluded
2025/04/19 04:39:40 DEBUG : potato2: Excluded (Size Filter)
2025/04/19 04:39:40 DEBUG : potato2: Excluded
2025/04/19 04:39:41 DEBUG : potato2: Excluded (Size Filter)
2025/04/19 04:39:41 DEBUG : potato2: Excluded
2025/04/19 04:39:41 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:39:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:39:41 DEBUG : empty space: Unchanged skipping
2025/04/19 04:39:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:39:41 DEBUG : Waiting for deletions to finish
2025/04/19 04:39:41 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:39:41 DEBUG : enormous: Excluded (Size Filter)
2025/04/19 04:39:41 DEBUG : enormous: Excluded
2025/04/19 04:39:41 DEBUG : potato2: Excluded (Size Filter)
2025/04/19 04:39:41 DEBUG : potato2: Excluded
2025/04/19 04:39:41 DEBUG : potato2: Excluded (Size Filter)
2025/04/19 04:39:41 DEBUG : potato2: Excluded
2025/04/19 04:39:41 DEBUG : Local file system at /tmp/rclone1578056088: Waiting for checks to finish
2025/04/19 04:39:41 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2025/04/19 04:39:41 DEBUG : empty space: Unchanged skipping
2025/04/19 04:39:41 DEBUG : Local file system at /tmp/rclone1578056088: Waiting for transfers to finish
2025/04/19 04:39:41 DEBUG : Waiting for deletions to finish
2025/04/19 04:39:41 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncWithExclude (5.91s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:39:45 DEBUG : potato2: md5 = 3204262adffd04f4a09645ac069e60e5 OK
2025/04/19 04:39:46 DEBUG : empty space: md5 = ba918a9f1a80f601f2395d5ed0328787 OK
2025/04/19 04:39:47 DEBUG : enormous: md5 = 3c1dd04131e0902a5c38fa832f91d210 OK
2025/04/19 04:39:48 DEBUG : enormous: Excluded (Size Filter)
2025/04/19 04:39:48 DEBUG : enormous: Excluded
2025/04/19 04:39:48 DEBUG : potato2: Excluded (Size Filter)
2025/04/19 04:39:48 DEBUG : potato2: Excluded
2025/04/19 04:39:48 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:39:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:39:48 DEBUG : empty space: Unchanged skipping
2025/04/19 04:39:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:39:48 DEBUG : Waiting for deletions to finish
2025/04/19 04:39:48 INFO  : enormous: Deleted
2025/04/19 04:39:48 INFO  : potato2: Deleted
2025/04/19 04:39:48 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:39:49 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2025/04/19 04:39:49 DEBUG : Local file system at /tmp/rclone1578056088: Waiting for checks to finish
2025/04/19 04:39:49 DEBUG : empty space: Unchanged skipping
2025/04/19 04:39:49 DEBUG : Local file system at /tmp/rclone1578056088: Waiting for transfers to finish
2025/04/19 04:39:49 DEBUG : Waiting for deletions to finish
2025/04/19 04:39:49 INFO  : enormous: Deleted
2025/04/19 04:39:49 INFO  : potato2: Deleted
2025/04/19 04:39:49 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (7.24s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:39:52 DEBUG : one: md5 = 5d399b30fabbc6db9628daf9b8c807fe OK
2025/04/19 04:39:53 DEBUG : two: md5 = 321aeaa3afa5b205b43713cc5c54c263 OK
2025/04/19 04:39:55 DEBUG : three: md5 = 5e3098299b47bf6e11cc61022823f97e OK
2025/04/19 04:39:56 DEBUG : four: md5 = 8d79099498bb339b0fa5daa866a43278 OK
2025/04/19 04:39:56 DEBUG : five: Need to transfer - File not found at Destination
2025/04/19 04:39:56 DEBUG : four: Sizes differ (src 4 vs dst 8)
2025/04/19 04:39:56 DEBUG : one: Destination is newer than source, skipping
2025/04/19 04:39:56 DEBUG : three: Sizes identical
2025/04/19 04:39:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:39:56 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2025/04/19 04:39:56 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2025/04/19 04:39:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:39:57 DEBUG : two: md5 = 8b62b04cb469b2c8a5b08f5d282adcff OK
2025/04/19 04:39:57 INFO  : two: Copied (replaced existing)
2025/04/19 04:39:57 DEBUG : four: md5 = c0f56ca98eca86c2ab50f7de3c266103 OK
2025/04/19 04:39:57 INFO  : four: Copied (replaced existing)
2025/04/19 04:39:58 DEBUG : five: md5 = abc8279660b77a44191ee0b0155000f4 OK
2025/04/19 04:39:58 INFO  : five: Copied (new)
2025/04/19 04:39:58 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (10.27s)
=== 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-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2025/04/19 04:40:01 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Ignoring --track-renames as the source and destination do not have a common hash
2025/04/19 04:40:01 DEBUG : potato: Need to transfer - File not found at Destination
2025/04/19 04:40:01 DEBUG : yam: Need to transfer - File not found at Destination
2025/04/19 04:40:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:40:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:40:03 DEBUG : yam: md5 = 161948160a95b4d0d93eb2d2aaf96e73 OK
2025/04/19 04:40:03 INFO  : yam: Copied (new)
2025/04/19 04:40:03 DEBUG : potato: md5 = fff2a7296b4e312a8ed933c3ddfca50d OK
2025/04/19 04:40:03 INFO  : potato: Copied (new)
2025/04/19 04:40:03 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:40:03 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Ignoring --track-renames as the source and destination do not have a common hash
2025/04/19 04:40:03 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:40:03 DEBUG : yaml: Need to transfer - File not found at Destination
2025/04/19 04:40:03 DEBUG : potato: Unchanged skipping
2025/04/19 04:40:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:40:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:40:04 DEBUG : yaml: md5 = 3e0695812c58c0491504b2661e1d057d OK
2025/04/19 04:40:04 INFO  : yaml: Copied (new)
2025/04/19 04:40:04 DEBUG : Waiting for deletions to finish
2025/04/19 04:40:05 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (6.62s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2025/04/19 04:40:08 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Making map for --track-renames
2025/04/19 04:40:08 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Finished making map for --track-renames
2025/04/19 04:40:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:40:08 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/04/19 04:40:08 DEBUG : yam: Need to transfer - No matching file found at Destination
2025/04/19 04:40:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for renames to finish
2025/04/19 04:40:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:40:09 DEBUG : potato: md5 = 3a584a3a59bd1143dee535aafea74e11 OK
2025/04/19 04:40:09 INFO  : potato: Copied (new)
2025/04/19 04:40:09 DEBUG : yam: md5 = 9aa335c899d6f6f8638ed11edc718275 OK
2025/04/19 04:40:09 INFO  : yam: Copied (new)
2025/04/19 04:40:09 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:40:10 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:40:10 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Making map for --track-renames
2025/04/19 04:40:10 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Finished making map for --track-renames
2025/04/19 04:40:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:40:10 DEBUG : potato: Unchanged skipping
2025/04/19 04:40:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for renames to finish
2025/04/19 04:40:10 INFO  : yam: Moved (server-side) to: yaml
2025/04/19 04:40:10 INFO  : yaml: Renamed from "yam"
2025/04/19 04:40:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:40:10 DEBUG : Waiting for deletions to finish
2025/04/19 04:40:10 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (5.38s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2025/04/19 04:40:13 DEBUG : Added delayed dir = "sub", newDst=<nil>
2025/04/19 04:40:13 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Making map for --track-renames
2025/04/19 04:40:13 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Finished making map for --track-renames
2025/04/19 04:40:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:40:13 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2025/04/19 04:40:13 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/04/19 04:40:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for renames to finish
2025/04/19 04:40:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:40:15 DEBUG : sub/yam: md5 = 51d76bbe621755161568bf2347d30eb4 OK
2025/04/19 04:40:15 INFO  : sub/yam: Copied (new)
2025/04/19 04:40:15 DEBUG : potato: md5 = 7f64231df79e91995d77d1e3eb9f71f5 OK
2025/04/19 04:40:15 INFO  : potato: Copied (new)
2025/04/19 04:40:15 DEBUG : Waiting for deletions to finish
2025/04/19 04:40:16 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:40:17 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:40:17 DEBUG : potato: Unchanged skipping
2025/04/19 04:40:17 INFO  : sub: Set directory modification time (using SetModTime)
2025/04/19 04:40:17 DEBUG : Added delayed dir = "sub", newDst=sub
2025/04/19 04:40:17 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Making map for --track-renames
2025/04/19 04:40:17 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Finished making map for --track-renames
2025/04/19 04:40:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:40:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for renames to finish
2025/04/19 04:40:18 INFO  : sub/yam: Moved (server-side) to: yam
2025/04/19 04:40:18 INFO  : yam: Renamed from "sub/yam"
2025/04/19 04:40:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:40:18 DEBUG : Waiting for deletions to finish
2025/04/19 04:40:18 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.12s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:40:22 DEBUG : Creating backend with remote "/tmp/rclone1578056088/dir1"
2025/04/19 04:40:22 DEBUG : Config file has changed externally - reloading
2025/04/19 04:40:22 DEBUG : Creating backend with remote "/tmp/rclone1578056088/dir2"
2025/04/19 04:40:22 DEBUG : Local file system at /tmp/rclone1578056088/dir2: Using server-side directory move
2025/04/19 04:40:22 INFO  : Local file system at /tmp/rclone1578056088/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/04/19 04:40:22 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/04/19 04:40:22 INFO  : file1.txt: Moved (server-side)
2025/04/19 04:40:22 DEBUG : Local file system at /tmp/rclone1578056088/dir2: Waiting for checks to finish
2025/04/19 04:40:22 DEBUG : Local file system at /tmp/rclone1578056088/dir2: Waiting for transfers to finish
--- PASS: TestServerSideMoveLocal (0.42s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:40:23 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/04/19 04:40:23 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/19 04:40:23 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/19 04:40:23 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/04/19 04:40:23 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/04/19 04:40:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:40:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:40:25 DEBUG : sub dir/hello world: md5 = bfd4d28520e025c9a73cca02a314fc07 OK
2025/04/19 04:40:25 INFO  : sub dir/hello world: Copied (new)
2025/04/19 04:40:25 INFO  : sub dir/hello world: Deleted
2025/04/19 04:40:26 DEBUG : nested/sub dir/file: md5 = 67fd99490b8f7ad19392a12db9277e8c OK
2025/04/19 04:40:26 INFO  : nested/sub dir/file: Copied (new)
2025/04/19 04:40:26 INFO  : nested/sub dir/file: Deleted
2025/04/19 04:40:27 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/04/19 04:40:27 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/19 04:40:27 INFO  : nested: Set directory modification time (using DirSetModTime)
2025/04/19 04:40:27 INFO  : sub dir: Removing directory
2025/04/19 04:40:27 INFO  : nested/sub dir: Removing directory
2025/04/19 04:40:27 INFO  : nested: Removing directory
2025/04/19 04:40:27 DEBUG : Local file system at /tmp/rclone1578056088: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:40:30 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/04/19 04:40:30 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2025/04/19 04:40:31 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (9.92s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:40:33 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/04/19 04:40:33 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/04/19 04:40:33 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/04/19 04:40:33 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/04/19 04:40:33 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/04/19 04:40:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:40:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:40:35 DEBUG : sub dir/hello world: md5 = 4c0d9d7f082a667e0b186b4dadd73b95 OK
2025/04/19 04:40:35 INFO  : sub dir/hello world: Copied (new)
2025/04/19 04:40:35 INFO  : sub dir/hello world: Deleted
2025/04/19 04:40:36 DEBUG : nested/sub dir/file: md5 = e06b91610ccbfc189d3ef8015fb3a22e OK
2025/04/19 04:40:36 INFO  : nested/sub dir/file: Copied (new)
2025/04/19 04:40:36 INFO  : nested/sub dir/file: Deleted
2025/04/19 04:40:37 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/04/19 04:40:37 INFO  : nested: Set directory modification time (using DirSetModTime)
2025/04/19 04:40:38 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:40:40 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/04/19 04:40:41 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2025/04/19 04:40:41 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.27s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:40:43 DEBUG : existing: Need to transfer - File not found at Destination
2025/04/19 04:40:43 DEBUG : existing-b: Need to transfer - File not found at Destination
2025/04/19 04:40:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:40:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:40:44 DEBUG : existing: md5 = 0e140466a460f2a06c9ba90daa65eec8 OK
2025/04/19 04:40:44 INFO  : existing: Copied (new)
2025/04/19 04:40:44 INFO  : existing: Deleted
2025/04/19 04:40:44 DEBUG : existing-b: md5 = 28e9e947dc0ea5fa1c99541cf4289e87 OK
2025/04/19 04:40:44 INFO  : existing-b: Copied (new)
2025/04/19 04:40:44 INFO  : existing-b: Deleted
2025/04/19 04:40:45 DEBUG : existing: Destination exists, skipping
2025/04/19 04:40:45 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2025/04/19 04:40:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:40:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:40:45 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (4.15s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:40:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wonedoc1yuru"
2025/04/19 04:40:47 DEBUG : Creating backend with remote "TestDrive:crypt/3o8r1oafm6uqvgbhkr024vurl6ar1skl4s2vfhvd20t30ek5sf30"
2025/04/19 04:40:49 DEBUG : potato2: md5 = dedd31471247e33440163989d6025b3e OK
2025/04/19 04:40:50 DEBUG : empty space: md5 = 6cdff44a1715e7843b2f2f12f5e61f71 OK
2025/04/19 04:40:52 DEBUG : potato3: md5 = 3121882aa0e89a8c5e6489b91318b71b OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa' -> Encrypted drive 'TestCryptDrive:rclone-test-wonedoc1yuru'
2025/04/19 04:40:54 DEBUG : empty space: md5 = 3a5caaeff02c37888b77a46680a24420 OK
2025/04/19 04:40:56 DEBUG : potato3: md5 = 7b22756554c7df2ac86a2b32c4d869e4 OK
2025/04/19 04:40:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wonedoc1yuru': Using server-side directory move
2025/04/19 04:40:56 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-wonedoc1yuru': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/04/19 04:40:56 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/19 04:40:56 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/04/19 04:40:56 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/04/19 04:40:56 DEBUG : empty space: Unchanged skipping
2025/04/19 04:40:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wonedoc1yuru': Waiting for checks to finish
2025/04/19 04:40:57 INFO  : potato3: Deleted
2025/04/19 04:40:57 INFO  : empty space: Deleted
2025/04/19 04:40:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wonedoc1yuru': Waiting for transfers to finish
2025/04/19 04:40:57 INFO  : potato2: Moved (server-side)
2025/04/19 04:40:57 INFO  : potato3: Moved (server-side)
2025/04/19 04:40:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cujihis9vuci"
2025/04/19 04:40:58 DEBUG : Creating backend with remote "TestDrive:crypt/2br1sou04divbvo10drhf5t4m15s2jm2i7unu0pan6mecv68qg8g"
2025/04/19 04:40:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cujihis9vuci': Using server-side directory move
2025/04/19 04:40:59 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-cujihis9vuci': Server side directory move succeeded
2025/04/19 04:41:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cujihis9vuci': Purge remote
2025/04/19 04:41:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wonedoc1yuru': Purge remote
2025/04/19 04:41:01 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (14.61s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:41:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lonipih3ruro"
2025/04/19 04:41:01 DEBUG : Creating backend with remote "TestDrive:crypt/nim9tn2dhl699da6n3u63i083ci9879425gruapkhomevv0ciss0"
2025/04/19 04:41:03 DEBUG : Config file has changed externally - reloading
2025/04/19 04:41:03 DEBUG : TestDrive: Loaded fresh token from config file
2025/04/19 04:41:04 DEBUG : potato2: md5 = 88b846fd89a6f376e01e2b2696d9a0cb OK
2025/04/19 04:41:05 DEBUG : empty space: md5 = f428f6114e14fe006d613853d84b0683 OK
2025/04/19 04:41:07 DEBUG : potato3: md5 = 31821ded8c776981e6fa0153e0eba0ce OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa' -> Encrypted drive 'TestCryptDrive:rclone-test-lonipih3ruro'
2025/04/19 04:41:07 DEBUG : TestDrive: Loaded fresh token from config file
2025/04/19 04:41:09 DEBUG : empty space: md5 = 9f576520f4edc0210da56be185c0264c OK
2025/04/19 04:41:11 DEBUG : potato3: md5 = 12c3bf40807d46b664c8669232d62b86 OK
2025/04/19 04:41:11 DEBUG : empty space: Excluded (Size Filter)
2025/04/19 04:41:11 DEBUG : empty space: Excluded
2025/04/19 04:41:11 DEBUG : empty space: Excluded (Size Filter)
2025/04/19 04:41:11 DEBUG : empty space: Excluded
2025/04/19 04:41:11 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/19 04:41:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lonipih3ruro': Waiting for checks to finish
2025/04/19 04:41:11 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/04/19 04:41:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lonipih3ruro': Waiting for transfers to finish
2025/04/19 04:41:12 INFO  : potato3: Deleted
2025/04/19 04:41:12 INFO  : potato2: Moved (server-side)
2025/04/19 04:41:12 INFO  : potato3: Moved (server-side)
2025/04/19 04:41:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-satocen6gosu"
2025/04/19 04:41:13 DEBUG : Creating backend with remote "TestDrive:crypt/6nbo674mvfms2qm94s5ibobelcfqeps1t58r74ahrvo39m2873o0"
2025/04/19 04:41:14 DEBUG : empty space: Excluded (Size Filter)
2025/04/19 04:41:14 DEBUG : empty space: Excluded
2025/04/19 04:41:14 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/19 04:41:14 DEBUG : potato3: Need to transfer - File not found at Destination
2025/04/19 04:41:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-satocen6gosu': Waiting for checks to finish
2025/04/19 04:41:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-satocen6gosu': Waiting for transfers to finish
2025/04/19 04:41:15 INFO  : potato2: Moved (server-side)
2025/04/19 04:41:16 INFO  : potato3: Moved (server-side)
2025/04/19 04:41:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-satocen6gosu': Purge remote
2025/04/19 04:41:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lonipih3ruro': Purge remote
--- PASS: TestServerSideMoveWithFilter (16.56s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:41:18 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fefadip8pato"
2025/04/19 04:41:18 DEBUG : Creating backend with remote "TestDrive:crypt/meqbd56a4ek7vvu5ks8qhk76sfftbh6aao2ngds6h59ofbik76p0"
2025/04/19 04:41:20 DEBUG : potato2: md5 = 90d9e68be7f542994ede1e0653ecab14 OK
2025/04/19 04:41:21 DEBUG : empty space: md5 = 22df12a90cda4ac9c55039a121e2da78 OK
2025/04/19 04:41:23 DEBUG : potato3: md5 = ec9673595db6e3d6bb3b816d42e37a89 OK
2025/04/19 04:41:23 INFO  : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa' -> Encrypted drive 'TestCryptDrive:rclone-test-fefadip8pato'
2025/04/19 04:41:26 DEBUG : empty space: md5 = c7368882437f27618a5911785635740f OK
2025/04/19 04:41:27 DEBUG : potato3: md5 = a3e284369b975286a6bb80a5bb76c87f OK
2025/04/19 04:41:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fefadip8pato': Using server-side directory move
2025/04/19 04:41:28 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-fefadip8pato': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/04/19 04:41:28 DEBUG : potato2: Need to transfer - File not found at Destination
2025/04/19 04:41:28 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2025/04/19 04:41:28 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/04/19 04:41:28 DEBUG : empty space: Unchanged skipping
2025/04/19 04:41:28 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/04/19 04:41:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fefadip8pato': Waiting for checks to finish
2025/04/19 04:41:28 INFO  : empty space: Deleted
2025/04/19 04:41:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fefadip8pato': Waiting for transfers to finish
2025/04/19 04:41:28 INFO  : potato3: Deleted
2025/04/19 04:41:28 INFO  : potato2: Moved (server-side)
2025/04/19 04:41:29 INFO  : potato3: Moved (server-side)
2025/04/19 04:41:29 INFO  : tomatoDir: Removing directory
2025/04/19 04:41:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': deleted 1 directories
2025/04/19 04:41:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nocezuq4qoqe"
2025/04/19 04:41:30 DEBUG : Creating backend with remote "TestDrive:crypt/fm626skntglhl25fvbtkpb8jtjn8anbc8k7vrk9mpmbofh2sk8sg"
2025/04/19 04:41:31 INFO  : tomatoDir: Making directory
2025/04/19 04:41:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nocezuq4qoqe': Using server-side directory move
2025/04/19 04:41:33 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-nocezuq4qoqe': Server side directory move succeeded
2025/04/19 04:41:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nocezuq4qoqe': Purge remote
2025/04/19 04:41:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fefadip8pato': Purge remote
2025/04/19 04:41:35 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (17.33s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.43s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:41:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/rclone-sync-test"
2025/04/19 04:41:36 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncOverlap (3.60s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:41:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/rclone-sync-test"
2025/04/19 04:41:39 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2025/04/19 04:41:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/rclone-sync-test-include/layer2"
2025/04/19 04:41:42 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2025/04/19 04:41:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/rclone-sync-test-ignore-file"
2025/04/19 04:41:44 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2025/04/19 04:41:48 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = b0b45921ba86afe4e07fb8aabe0045fd OK
2025/04/19 04:41:49 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/04/19 04:41:49 DEBUG : rclone-sync-test: Excluded
2025/04/19 04:41:49 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/04/19 04:41:50 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/04/19 04:41:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/rclone-sync-test': Waiting for checks to finish
2025/04/19 04:41:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/rclone-sync-test': Waiting for transfers to finish
2025/04/19 04:41:50 DEBUG : Waiting for deletions to finish
2025/04/19 04:41:50 INFO  : There was nothing to transfer
2025/04/19 04:41:50 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/04/19 04:41:51 DEBUG : rclone-sync-test: Excluded
2025/04/19 04:41:51 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/04/19 04:41:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:41:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:41:51 DEBUG : Waiting for deletions to finish
2025/04/19 04:41:51 INFO  : rclone-sync-test-include: Removing directory
2025/04/19 04:41:51 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/04/19 04:41:51 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2025/04/19 04:41:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': failed to delete 1 directories
2025/04/19 04:41:51 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:41:52 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/04/19 04:41:53 DEBUG : rclone-sync-test: Excluded
2025/04/19 04:41:53 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/04/19 04:41:53 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/04/19 04:41:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/rclone-sync-test-include/layer2': Waiting for checks to finish
2025/04/19 04:41:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/rclone-sync-test-include/layer2': Waiting for transfers to finish
2025/04/19 04:41:53 DEBUG : Waiting for deletions to finish
2025/04/19 04:41:53 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:41:54 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/04/19 04:41:54 DEBUG : rclone-sync-test: Excluded
2025/04/19 04:41:55 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/04/19 04:41:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:41:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:41:55 DEBUG : Waiting for deletions to finish
2025/04/19 04:41:55 INFO  : rclone-sync-test-include: Removing directory
2025/04/19 04:41:55 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/04/19 04:41:55 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2025/04/19 04:41:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': failed to delete 1 directories
2025/04/19 04:41:55 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:41:55 DEBUG : : Excluded
2025/04/19 04:41:55 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/04/19 04:41:56 DEBUG : rclone-sync-test: Excluded
2025/04/19 04:41:56 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/04/19 04:41:56 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/04/19 04:41:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/rclone-sync-test-ignore-file': Waiting for checks to finish
2025/04/19 04:41:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/rclone-sync-test-ignore-file': Waiting for transfers to finish
2025/04/19 04:41:56 DEBUG : Waiting for deletions to finish
2025/04/19 04:41:56 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:41:58 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/04/19 04:41:59 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (28.17s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:42:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/dst"
2025/04/19 04:42:08 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/31u3jie661vd5p8j7rtc3hgbh0"
2025/04/19 04:42:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/CompareDest"
2025/04/19 04:42:09 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/gveqi14airsml4bgu7krj116o8"
2025/04/19 04:42:11 DEBUG : one: Need to transfer - File not found at Destination
2025/04/19 04:42:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for checks to finish
2025/04/19 04:42:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for transfers to finish
2025/04/19 04:42:13 DEBUG : one: md5 = 5430dc9070d63c7c2583cef0d0a35bc1 OK
2025/04/19 04:42:13 INFO  : one: Copied (new)
2025/04/19 04:42:13 DEBUG : Waiting for deletions to finish
2025/04/19 04:42:14 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/19 04:42:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for checks to finish
2025/04/19 04:42:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for transfers to finish
2025/04/19 04:42:15 DEBUG : one: md5 = a8a243778fe7f9e69eb309ad9fcb4569 OK
2025/04/19 04:42:15 INFO  : one: Copied (replaced existing)
2025/04/19 04:42:15 DEBUG : Waiting for deletions to finish
2025/04/19 04:42:17 DEBUG : dst/one: md5 = 0921f5926f1e0fcce3db972d12ebdf24 OK
2025/04/19 04:42:19 DEBUG : CompareDest/one: md5 = 110fad322ed9f0c88404274c83ac85be OK
2025/04/19 04:42:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for checks to finish
2025/04/19 04:42:20 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/19 04:42:20 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:42:20 DEBUG : one: Destination found in --compare-dest, skipping
2025/04/19 04:42:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for transfers to finish
2025/04/19 04:42:20 DEBUG : Waiting for deletions to finish
2025/04/19 04:42:20 INFO  : There was nothing to transfer
2025/04/19 04:42:22 DEBUG : CompareDest/two: md5 = f9d578297dbb1506f8813b26c107b614 OK
2025/04/19 04:42:23 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/19 04:42:23 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:42:23 DEBUG : two: Destination found in --compare-dest, skipping
2025/04/19 04:42:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for checks to finish
2025/04/19 04:42:23 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:42:23 DEBUG : one: Destination found in --compare-dest, skipping
2025/04/19 04:42:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for transfers to finish
2025/04/19 04:42:23 DEBUG : Waiting for deletions to finish
2025/04/19 04:42:23 INFO  : There was nothing to transfer
2025/04/19 04:42:24 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/19 04:42:24 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:42:24 DEBUG : two: Destination found in --compare-dest, skipping
2025/04/19 04:42:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for checks to finish
2025/04/19 04:42:24 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:42:24 DEBUG : one: Destination found in --compare-dest, skipping
2025/04/19 04:42:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for transfers to finish
2025/04/19 04:42:24 DEBUG : Waiting for deletions to finish
2025/04/19 04:42:24 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2025/04/19 04:42:25 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/19 04:42:25 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:42:25 DEBUG : one: Destination found in --compare-dest, skipping
2025/04/19 04:42:25 DEBUG : two: Sizes differ (src 5 vs dst 3)
2025/04/19 04:42:25 DEBUG : two: Need to transfer - File not found at Destination
2025/04/19 04:42:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for checks to finish
2025/04/19 04:42:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for transfers to finish
2025/04/19 04:42:27 DEBUG : two: md5 = 0d057d38311054ef203b6926151d276f OK
2025/04/19 04:42:27 INFO  : two: Copied (new)
2025/04/19 04:42:27 DEBUG : Waiting for deletions to finish
2025/04/19 04:42:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/04/19 04:42:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/04/19 04:42:30 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/04/19 04:42:30 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCompareDest (23.29s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:42:33 DEBUG : pre-dest1/1: md5 = a4c759e99b3acff66d19fc03da8ac34c OK
2025/04/19 04:42:35 DEBUG : pre-dest2/2: md5 = 2f65099e81d726c6ab989da785bdebee OK
2025/04/19 04:42:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/dest"
2025/04/19 04:42:35 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/rg03c1jvnehrrc617i0lnqjddc"
2025/04/19 04:42:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/pre-dest1"
2025/04/19 04:42:37 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/bbnblvh6k061ssopqrp18kd7gc"
2025/04/19 04:42:38 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/pre-dest2"
2025/04/19 04:42:38 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/dgicm1h6b5ejvlltm8eeif0bnk"
2025/04/19 04:42:39 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:42:39 DEBUG : 1: Destination found in --compare-dest, skipping
2025/04/19 04:42:39 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:42:39 DEBUG : 2: Destination found in --compare-dest, skipping
2025/04/19 04:42:40 DEBUG : 3: Need to transfer - File not found at Destination
2025/04/19 04:42:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dest': Waiting for checks to finish
2025/04/19 04:42:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dest': Waiting for transfers to finish
2025/04/19 04:42:42 DEBUG : 3: md5 = db389d9a79e1c20ee94c125e2d04c85c OK
2025/04/19 04:42:42 INFO  : 3: Copied (new)
2025/04/19 04:42:42 DEBUG : Waiting for deletions to finish
2025/04/19 04:42:44 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2025/04/19 04:42:45 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2025/04/19 04:42:46 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (15.75s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:42:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/dst"
2025/04/19 04:42:47 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/31u3jie661vd5p8j7rtc3hgbh0"
2025/04/19 04:42:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/CopyDest"
2025/04/19 04:42:48 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/d09o6po3f7bm6ce32vdgs8h9ls"
2025/04/19 04:42:50 DEBUG : one: Need to transfer - File not found at Destination
2025/04/19 04:42:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for checks to finish
2025/04/19 04:42:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for transfers to finish
2025/04/19 04:42:52 DEBUG : one: md5 = 3fd24f45d44621281571952df332cd68 OK
2025/04/19 04:42:52 INFO  : one: Copied (new)
2025/04/19 04:42:52 DEBUG : Waiting for deletions to finish
2025/04/19 04:42:53 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/19 04:42:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for checks to finish
2025/04/19 04:42:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for transfers to finish
2025/04/19 04:42:54 DEBUG : one: md5 = 4fa1cdb7332938a4b95fbddd203aceb1 OK
2025/04/19 04:42:54 INFO  : one: Copied (replaced existing)
2025/04/19 04:42:54 DEBUG : Waiting for deletions to finish
2025/04/19 04:42:56 DEBUG : dst/one: md5 = f5ee06306e96d7db580259928660b92c OK
2025/04/19 04:42:58 DEBUG : CopyDest/one: md5 = bd9d9720da950011ebca6aae593fcdfd OK
2025/04/19 04:42:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/BackupDir"
2025/04/19 04:42:59 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/s6dbk3lfi7c9kfvo6j7bla9m0g"
2025/04/19 04:43:01 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/19 04:43:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for checks to finish
2025/04/19 04:43:01 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:43:01 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/04/19 04:43:02 INFO  : one: Moved (server-side)
2025/04/19 04:43:03 INFO  : one: Copied (server-side copy)
2025/04/19 04:43:03 DEBUG : one: Destination found in --copy-dest, using server-side copy
2025/04/19 04:43:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for transfers to finish
2025/04/19 04:43:03 DEBUG : Waiting for deletions to finish
2025/04/19 04:43:05 DEBUG : CopyDest/two: md5 = 9b11af15ce8fd8b54f395a2d7383518a OK
2025/04/19 04:43:06 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:43:06 DEBUG : one: Unchanged skipping
2025/04/19 04:43:06 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:43:07 INFO  : two: Copied (server-side copy)
2025/04/19 04:43:07 DEBUG : two: Destination found in --copy-dest, using server-side copy
2025/04/19 04:43:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for checks to finish
2025/04/19 04:43:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for transfers to finish
2025/04/19 04:43:07 DEBUG : Waiting for deletions to finish
2025/04/19 04:43:08 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:43:08 DEBUG : one: Unchanged skipping
2025/04/19 04:43:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for checks to finish
2025/04/19 04:43:08 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:43:08 DEBUG : two: Unchanged skipping
2025/04/19 04:43:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for transfers to finish
2025/04/19 04:43:08 DEBUG : Waiting for deletions to finish
2025/04/19 04:43:08 INFO  : There was nothing to transfer
2025/04/19 04:43:09 DEBUG : CopyDest/three: md5 = f407f69f801d09603467a9c22de18167 OK
2025/04/19 04:43:10 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:43:10 DEBUG : one: Unchanged skipping
2025/04/19 04:43:10 DEBUG : three: Sizes differ (src 7 vs dst 5)
2025/04/19 04:43:10 DEBUG : three: Destination not found in --copy-dest
2025/04/19 04:43:10 DEBUG : three: Need to transfer - File not found at Destination
2025/04/19 04:43:10 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/04/19 04:43:10 DEBUG : two: Unchanged skipping
2025/04/19 04:43:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for checks to finish
2025/04/19 04:43:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for transfers to finish
2025/04/19 04:43:12 DEBUG : three: md5 = b52e9d3caa87d722247a458c47bfe98e OK
2025/04/19 04:43:12 INFO  : three: Copied (new)
2025/04/19 04:43:12 DEBUG : Waiting for deletions to finish
2025/04/19 04:43:16 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2025/04/19 04:43:16 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/04/19 04:43:16 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/04/19 04:43:17 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/04/19 04:43:17 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2025/04/19 04:43:17 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/04/19 04:43:17 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (31.31s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:43:20 DEBUG : dst/one: md5 = 616aecd45abdba66b7dfbdc224dd2c31 OK
2025/04/19 04:43:21 DEBUG : dst/two: md5 = 26705b6e7b686155bb3978dd3886e7df OK
2025/04/19 04:43:22 DEBUG : dst/three.txt: md5 = a86ea059902cc38c0f2ba691b005459e OK
2025/04/19 04:43:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/dst"
2025/04/19 04:43:23 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/31u3jie661vd5p8j7rtc3hgbh0"
2025/04/19 04:43:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/backup"
2025/04/19 04:43:24 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/1nrff024r7pq65ecp72fc28jb0"
2025/04/19 04:43:25 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/04/19 04:43:25 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:43:25 DEBUG : two: Unchanged skipping
2025/04/19 04:43:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for checks to finish
2025/04/19 04:43:27 INFO  : one: Moved (server-side)
2025/04/19 04:43:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for transfers to finish
2025/04/19 04:43:28 DEBUG : one: md5 = 696a416ce4596638960495f902ca9dc5 OK
2025/04/19 04:43:28 INFO  : one: Copied (new)
2025/04/19 04:43:28 DEBUG : Waiting for deletions to finish
2025/04/19 04:43:29 INFO  : three.txt: Moved (server-side)
2025/04/19 04:43:29 INFO  : three.txt: Moved into backup dir
2025/04/19 04:43:31 DEBUG : dst/three.txt: md5 = d36f34b252cf8d1e7db7f4a15e2ea55d OK
2025/04/19 04:43:31 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/04/19 04:43:31 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:43:31 DEBUG : two: Unchanged skipping
2025/04/19 04:43:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for checks to finish
2025/04/19 04:43:32 INFO  : one: Deleted
2025/04/19 04:43:33 INFO  : one: Moved (server-side)
2025/04/19 04:43:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for transfers to finish
2025/04/19 04:43:34 DEBUG : one: md5 = 7399781763c643ebee5ea4859e1c7135 OK
2025/04/19 04:43:34 INFO  : one: Copied (new)
2025/04/19 04:43:34 DEBUG : Waiting for deletions to finish
2025/04/19 04:43:35 INFO  : three.txt: Deleted
2025/04/19 04:43:35 INFO  : three.txt: Moved (server-side)
2025/04/19 04:43:35 INFO  : three.txt: Moved into backup dir
2025/04/19 04:43:38 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/04/19 04:43:38 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/04/19 04:43:39 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/04/19 04:43:39 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/04/19 04:43:39 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/04/19 04:43:39 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncBackupDir (21.50s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:43:41 DEBUG : dst/one: md5 = 8438dd3efcc6f3e745cccb57f6765b7b OK
2025/04/19 04:43:43 DEBUG : dst/two: md5 = 1dc509e34347af371a390034b1f1cc59 OK
2025/04/19 04:43:44 DEBUG : dst/three.txt: md5 = 92a96532d54521ba43d67575aa04afd6 OK
2025/04/19 04:43:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/dst"
2025/04/19 04:43:45 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/31u3jie661vd5p8j7rtc3hgbh0"
2025/04/19 04:43:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/backup"
2025/04/19 04:43:45 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/1nrff024r7pq65ecp72fc28jb0"
2025/04/19 04:43:47 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/04/19 04:43:47 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:43:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for checks to finish
2025/04/19 04:43:47 DEBUG : two: Unchanged skipping
2025/04/19 04:43:49 INFO  : one: Moved (server-side) to: one.bak
2025/04/19 04:43:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for transfers to finish
2025/04/19 04:43:50 DEBUG : one: md5 = 3c250e2d921393c40cc347f87f8c4ea9 OK
2025/04/19 04:43:50 INFO  : one: Copied (new)
2025/04/19 04:43:50 DEBUG : Waiting for deletions to finish
2025/04/19 04:43:51 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/04/19 04:43:51 INFO  : three.txt: Moved into backup dir
2025/04/19 04:43:53 DEBUG : dst/three.txt: md5 = b5beb7dfc353576c31e58be12363b867 OK
2025/04/19 04:43:54 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/04/19 04:43:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for checks to finish
2025/04/19 04:43:54 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:43:54 DEBUG : two: Unchanged skipping
2025/04/19 04:43:54 INFO  : one.bak: Deleted
2025/04/19 04:43:55 INFO  : one: Moved (server-side) to: one.bak
2025/04/19 04:43:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for transfers to finish
2025/04/19 04:43:56 DEBUG : one: md5 = a25d2d2097f014a9cc70b00b16a692dd OK
2025/04/19 04:43:56 INFO  : one: Copied (new)
2025/04/19 04:43:56 DEBUG : Waiting for deletions to finish
2025/04/19 04:43:57 INFO  : three.txt.bak: Deleted
2025/04/19 04:43:57 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/04/19 04:43:57 INFO  : three.txt: Moved into backup dir
2025/04/19 04:44:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/04/19 04:44:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/04/19 04:44:01 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/04/19 04:44:01 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/04/19 04:44:01 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/04/19 04:44:01 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncBackupDirWithSuffix (22.13s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:44:03 DEBUG : dst/one: md5 = 819ea5c106501eb8e716ec5c5527d0ab OK
2025/04/19 04:44:05 DEBUG : dst/two: md5 = afb63e2ecddd985f6b875371fba2cb68 OK
2025/04/19 04:44:06 DEBUG : dst/three.txt: md5 = def06afcca2e5b4baeb04869ceb09cb4 OK
2025/04/19 04:44:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/dst"
2025/04/19 04:44:07 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/31u3jie661vd5p8j7rtc3hgbh0"
2025/04/19 04:44:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/backup"
2025/04/19 04:44:07 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/1nrff024r7pq65ecp72fc28jb0"
2025/04/19 04:44:09 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/04/19 04:44:09 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:44:09 DEBUG : two: Unchanged skipping
2025/04/19 04:44:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for checks to finish
2025/04/19 04:44:11 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/04/19 04:44:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for transfers to finish
2025/04/19 04:44:12 DEBUG : one: md5 = 8f60d52f3a34e212e51c448b20690814 OK
2025/04/19 04:44:12 INFO  : one: Copied (new)
2025/04/19 04:44:12 DEBUG : Waiting for deletions to finish
2025/04/19 04:44:13 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/04/19 04:44:13 INFO  : three.txt: Moved into backup dir
2025/04/19 04:44:14 DEBUG : dst/three.txt: md5 = 0ee02faf3aa1719a8e1bcdeca2ea1b9d OK
2025/04/19 04:44:15 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/04/19 04:44:15 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:44:15 DEBUG : two: Unchanged skipping
2025/04/19 04:44:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for checks to finish
2025/04/19 04:44:16 INFO  : one-2019-01-01: Deleted
2025/04/19 04:44:16 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/04/19 04:44:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for transfers to finish
2025/04/19 04:44:17 DEBUG : one: md5 = 043b1b555416f05d7f77ae2994d69bb2 OK
2025/04/19 04:44:17 INFO  : one: Copied (new)
2025/04/19 04:44:17 DEBUG : Waiting for deletions to finish
2025/04/19 04:44:18 INFO  : three-2019-01-01.txt: Deleted
2025/04/19 04:44:19 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/04/19 04:44:19 INFO  : three.txt: Moved into backup dir
2025/04/19 04:44:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/04/19 04:44:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/04/19 04:44:22 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/04/19 04:44:22 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/04/19 04:44:22 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/04/19 04:44:22 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (21.52s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:44:25 DEBUG : dst/one: md5 = aabeda7419fb8a7a94c12d3de228b024 OK
2025/04/19 04:44:26 DEBUG : dst/two: md5 = 7d55b3653e47ce49f8f36d655e8f72c7 OK
2025/04/19 04:44:28 DEBUG : dst/three.txt: md5 = b8eef7d9abf903daa2b940a8440df916 OK
2025/04/19 04:44:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/dst"
2025/04/19 04:44:28 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/31u3jie661vd5p8j7rtc3hgbh0"
2025/04/19 04:44:29 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/04/19 04:44:29 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:44:29 DEBUG : two: Unchanged skipping
2025/04/19 04:44:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for checks to finish
2025/04/19 04:44:30 INFO  : one: Moved (server-side) to: one.bak
2025/04/19 04:44:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for transfers to finish
2025/04/19 04:44:31 DEBUG : one: md5 = a293f4698f2d60b1cb0eaa19ae318733 OK
2025/04/19 04:44:31 INFO  : one: Copied (new)
2025/04/19 04:44:31 DEBUG : Waiting for deletions to finish
2025/04/19 04:44:32 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/04/19 04:44:32 INFO  : three.txt: Moved into backup dir
2025/04/19 04:44:34 DEBUG : dst/three.txt: md5 = f3d073f330041a86eb3001e464a93324 OK
2025/04/19 04:44:34 DEBUG : one.bak: Excluded (Path Filter)
2025/04/19 04:44:34 DEBUG : one.bak: Excluded
2025/04/19 04:44:34 DEBUG : three.txt.bak: Excluded (Path Filter)
2025/04/19 04:44:34 DEBUG : three.txt.bak: Excluded
2025/04/19 04:44:34 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/04/19 04:44:34 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:44:34 DEBUG : two: Unchanged skipping
2025/04/19 04:44:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for checks to finish
2025/04/19 04:44:35 INFO  : one.bak: Deleted
2025/04/19 04:44:35 INFO  : one: Moved (server-side) to: one.bak
2025/04/19 04:44:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa/dst': Waiting for transfers to finish
2025/04/19 04:44:37 DEBUG : one: md5 = 8f9b4687be43557aea5cab20a3d960dd OK
2025/04/19 04:44:37 INFO  : one: Copied (new)
2025/04/19 04:44:37 DEBUG : Waiting for deletions to finish
2025/04/19 04:44:37 INFO  : three.txt.bak: Deleted
2025/04/19 04:44:38 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/04/19 04:44:38 INFO  : three.txt: Moved into backup dir
2025/04/19 04:44:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/04/19 04:44:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/04/19 04:44:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/04/19 04:44:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/04/19 04:44:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/04/19 04:44:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncBackupDirSuffixOnly (18.49s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:44:44 DEBUG : dst/one: md5 = f69c608162a257c174bc73339afc279b OK
2025/04/19 04:44:45 DEBUG : dst/two: md5 = f3d30563595c9bab1b85f096d819a85e OK
2025/04/19 04:44:46 DEBUG : dst/three.txt: md5 = 383965618485c6a69d4086c9551a2ae0 OK
2025/04/19 04:44:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/dst"
2025/04/19 04:44:47 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/31u3jie661vd5p8j7rtc3hgbh0"
2025/04/19 04:44:48 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/04/19 04:44:48 INFO  : one: Moved (server-side) to: one.bak
2025/04/19 04:44:50 DEBUG : one: md5 = f7cb5b24a6a627e96d153cedf0c2bdc4 OK
2025/04/19 04:44:50 INFO  : one: Copied (new)
2025/04/19 04:44:50 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:44:50 DEBUG : two: Unchanged skipping
2025/04/19 04:44:50 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/04/19 04:44:51 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/04/19 04:44:52 DEBUG : three.txt: md5 = dcc41afd1f5dca98478389def971fc0b OK
2025/04/19 04:44:52 INFO  : three.txt: Copied (new)
2025/04/19 04:44:53 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/04/19 04:44:54 INFO  : one.bak: Deleted
2025/04/19 04:44:54 INFO  : one: Moved (server-side) to: one.bak
2025/04/19 04:44:56 DEBUG : one: md5 = 03cb6f2cd56aeb821afb60b4b33004fc OK
2025/04/19 04:44:56 INFO  : one: Copied (new)
2025/04/19 04:44:56 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:44:56 DEBUG : two: Unchanged skipping
2025/04/19 04:44:56 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/04/19 04:44:57 INFO  : three.txt.bak: Deleted
2025/04/19 04:44:57 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/04/19 04:44:59 DEBUG : three.txt: md5 = 68f3e1666c11fe34f415c8740973e80e OK
2025/04/19 04:44:59 INFO  : three.txt: Copied (new)
2025/04/19 04:45:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/04/19 04:45:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/04/19 04:45:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/04/19 04:45:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/04/19 04:45:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/04/19 04:45:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/04/19 04:45:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncSuffix (21.01s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:45:05 DEBUG : dst/one: md5 = ad849f77e4921010664f8508af7eefae OK
2025/04/19 04:45:06 DEBUG : dst/two: md5 = c901a30145fde445f3e753dcd869f9a9 OK
2025/04/19 04:45:07 DEBUG : dst/three.txt: md5 = da3d422909833da1c61c79bad1efcea4 OK
2025/04/19 04:45:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuseboj5jaqa/dst"
2025/04/19 04:45:08 DEBUG : Creating backend with remote "TestDrive:crypt/o3uu76n31r6p8d476nd6r0mhhcmkbms8ik1o8mnlgiqrk458oi10/31u3jie661vd5p8j7rtc3hgbh0"
2025/04/19 04:45:09 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/04/19 04:45:09 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/04/19 04:45:11 DEBUG : one: md5 = 803e3747a061d4eae53706f51d8b176f OK
2025/04/19 04:45:11 INFO  : one: Copied (new)
2025/04/19 04:45:11 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:45:11 DEBUG : two: Unchanged skipping
2025/04/19 04:45:11 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/04/19 04:45:12 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/04/19 04:45:13 DEBUG : three.txt: md5 = ce0f57e16d42c3a57a0327e11b82fde1 OK
2025/04/19 04:45:13 INFO  : three.txt: Copied (new)
2025/04/19 04:45:14 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/04/19 04:45:15 INFO  : one-2019-01-01: Deleted
2025/04/19 04:45:15 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/04/19 04:45:17 DEBUG : one: md5 = 947e903ea7fd095b3b39066a3f0e1a3a OK
2025/04/19 04:45:17 INFO  : one: Copied (new)
2025/04/19 04:45:17 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:45:17 DEBUG : two: Unchanged skipping
2025/04/19 04:45:17 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/04/19 04:45:18 INFO  : three-2019-01-01.txt: Deleted
2025/04/19 04:45:18 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/04/19 04:45:19 DEBUG : three.txt: md5 = 6941e37482fb3497d214f50a98ccbca4 OK
2025/04/19 04:45:19 INFO  : three.txt: Copied (new)
2025/04/19 04:45:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/04/19 04:45:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/04/19 04:45:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/04/19 04:45:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/04/19 04:45:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/04/19 04:45:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/04/19 04:45:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncSuffixKeepExtension (21.10s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:45:25 DEBUG : Testêé: md5 = 8c6675cd2fe5a39b9eabdb0febcab3fd OK
2025/04/19 04:45:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:45:25 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2025/04/19 04:45:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:45:26 DEBUG : Testêé: md5 = e97ee59baf90c154d68a0bc1cafbac1a OK
2025/04/19 04:45:26 INFO  : Testêé: Copied (replaced existing) to: Testêé
2025/04/19 04:45:26 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (3.85s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:45:28 DEBUG : existing: Need to transfer - File not found at Destination
2025/04/19 04:45:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:45:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:45:29 DEBUG : existing: md5 = 2b09a56f225b907a7d221c4a7c18eec7 OK
2025/04/19 04:45:29 INFO  : existing: Copied (new)
2025/04/19 04:45:29 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:45:30 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2025/04/19 04:45:30 ERROR : existing: Source and destination exist but do not match: immutable file modified
2025/04/19 04:45:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:45:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:45:30 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': not deleting files as there were IO errors
2025/04/19 04:45:30 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncImmutable (4.29s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:45:33 DEBUG : EXISTING: md5 = 6eb69307edae8e18b73f2ffa29bd3d93 OK
2025/04/19 04:45:33 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:45:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:45:33 DEBUG : existing: Unchanged skipping
2025/04/19 04:45:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:45:33 DEBUG : Waiting for deletions to finish
2025/04/19 04:45:33 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (2.90s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    sync_test.go:2635: Skipping test as local or remote are case-sensitive
--- SKIP: TestFixCase (0.46s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", 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-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", 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-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.26s)
    --- SKIP: TestMaxTransfer/Hard (0.41s)
    --- SKIP: TestMaxTransfer/Soft (0.43s)
    --- SKIP: TestMaxTransfer/Cautious (0.42s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:45:38 DEBUG : both0: md5 = 2e93d2e1d89e968b3d8d41991b0851df OK
2025/04/19 04:45:39 DEBUG : only0: md5 = 0ea4f6f6865cf1ebed56875ae202e968 OK
2025/04/19 04:45:40 DEBUG : both1: md5 = 7bfb4fedd082c888e63b860f6b8a9919 OK
2025/04/19 04:45:41 DEBUG : only1: md5 = 89a1b2a932258124205d336bf046c16a OK
2025/04/19 04:45:43 DEBUG : both2: md5 = 925e3c45d4aaf3afe1382a7b9b94ee2f OK
2025/04/19 04:45:44 DEBUG : only2: md5 = 21c48ca8b6abd67e405689faa28aa82e OK
2025/04/19 04:45:45 DEBUG : both3: md5 = 3d75bb5a992ee93e3e71c60b27b0b551 OK
2025/04/19 04:45:47 DEBUG : only3: md5 = 2d5c33dd9b33af63eed0fce35dc85061 OK
2025/04/19 04:45:48 DEBUG : both4: md5 = 4d26c133330a54060d5936bb9f69c8c3 OK
2025/04/19 04:45:49 DEBUG : only4: md5 = 2ca6fb1e0445d6ec02711e62d1671db0 OK
2025/04/19 04:45:50 DEBUG : both5: md5 = 00399d57d5e23ea64e605a5118d2007e OK
2025/04/19 04:45:52 DEBUG : only5: md5 = 89843f9b4aec72d2779ca6e8abfa2929 OK
2025/04/19 04:45:53 DEBUG : both6: md5 = d6e6ec8ba4fc8d2611177e1bea1a96d5 OK
2025/04/19 04:45:54 DEBUG : only6: md5 = 14523820290099fa2fb97b302590cbc6 OK
2025/04/19 04:45:55 DEBUG : both7: md5 = fa4f3417a7ffbb99cb5cf6071f545974 OK
2025/04/19 04:45:57 DEBUG : only7: md5 = 85a0fa3df61fe89ad46a8157d02b586d OK
2025/04/19 04:45:58 DEBUG : both8: md5 = 234568ff77acf3f4570af4a005a25a74 OK
2025/04/19 04:46:00 DEBUG : only8: md5 = 78a2638b638bbfffc7d326df65b141d8 OK
2025/04/19 04:46:01 DEBUG : both9: md5 = abc61f11dca7b992603e5e93a7de9960 OK
2025/04/19 04:46:02 DEBUG : only9: md5 = aeaa22359b1d66bdbec0ad9d2e8799a0 OK
2025/04/19 04:46:03 DEBUG : both10: md5 = 3d9c5c777961ce21cc78d71b9d619aca OK
2025/04/19 04:46:05 DEBUG : only10: md5 = bfa1ce4452d025b6b9b3a6cafafd48c5 OK
2025/04/19 04:46:06 DEBUG : both11: md5 = 3539a6042d318d8a3225b4624ade05dc OK
2025/04/19 04:46:07 DEBUG : only11: md5 = 7dc4ba55bf395e1c1f891f3cca8955f2 OK
2025/04/19 04:46:09 DEBUG : both12: md5 = 3183b1710c44ca0be4b139a8ad56a0f4 OK
2025/04/19 04:46:10 DEBUG : only12: md5 = 0fcb00a0e9708e29bfc0fcdd5d6221a3 OK
2025/04/19 04:46:12 DEBUG : both13: md5 = 37994af516714eb41841739f1b729552 OK
2025/04/19 04:46:13 DEBUG : only13: md5 = 8a658612f7529234d345f71a4a2585b1 OK
2025/04/19 04:46:14 DEBUG : both14: md5 = 816e479e4c5404630f786c5f877c930e OK
2025/04/19 04:46:15 DEBUG : only14: md5 = 3a77d5b36644bd34248504fb28a9efa2 OK
2025/04/19 04:46:17 DEBUG : both15: md5 = 1070ae650bb9de5791bffd51b420095f OK
2025/04/19 04:46:18 DEBUG : only15: md5 = 71a4f42a3caf0d11ff78f6ad950416b5 OK
2025/04/19 04:46:19 DEBUG : both16: md5 = 9499d1797f4cbc8573ded07ed6bcf7b4 OK
2025/04/19 04:46:21 DEBUG : only16: md5 = efeafe2b586eb53daa93dea72a61f758 OK
2025/04/19 04:46:22 DEBUG : both17: md5 = e8b8c603b8c48f887eacc30c5612d4cd OK
2025/04/19 04:46:23 DEBUG : only17: md5 = 3bb20bde8e6154a867aafb95a37db0cc OK
2025/04/19 04:46:25 DEBUG : both18: md5 = 748fa716a4010f1e4aa51bdf3630d123 OK
2025/04/19 04:46:26 DEBUG : only18: md5 = 83772f05401bad88670af81eed60a304 OK
2025/04/19 04:46:27 DEBUG : both19: md5 = efb4e4462d621fbe8e0c15d27c3ecb09 OK
2025/04/19 04:46:29 DEBUG : only19: md5 = 94888e7e837d60b66861f4ecc6c078bd OK
2025/04/19 04:46:29 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:46:29 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:46:29 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:46:29 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:46:29 DEBUG : both1: Unchanged skipping
2025/04/19 04:46:29 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:46:29 DEBUG : both12: Unchanged skipping
2025/04/19 04:46:29 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:46:29 DEBUG : both13: Unchanged skipping
2025/04/19 04:46:29 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:46:29 DEBUG : both14: Unchanged skipping
2025/04/19 04:46:29 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:46:29 DEBUG : both15: Unchanged skipping
2025/04/19 04:46:29 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:46:29 DEBUG : both16: Unchanged skipping
2025/04/19 04:46:29 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:46:29 DEBUG : both17: Unchanged skipping
2025/04/19 04:46:29 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:46:29 DEBUG : both18: Unchanged skipping
2025/04/19 04:46:29 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:46:29 DEBUG : both19: Unchanged skipping
2025/04/19 04:46:29 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:46:29 DEBUG : both2: Unchanged skipping
2025/04/19 04:46:29 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:46:29 DEBUG : both3: Unchanged skipping
2025/04/19 04:46:29 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:46:29 DEBUG : both4: Unchanged skipping
2025/04/19 04:46:29 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:46:29 DEBUG : both5: Unchanged skipping
2025/04/19 04:46:29 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:46:29 DEBUG : both6: Unchanged skipping
2025/04/19 04:46:29 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:46:29 DEBUG : both7: Unchanged skipping
2025/04/19 04:46:29 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:46:29 DEBUG : both8: Unchanged skipping
2025/04/19 04:46:29 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:46:29 DEBUG : both9: Unchanged skipping
2025/04/19 04:46:29 DEBUG : both0: Unchanged skipping
2025/04/19 04:46:29 DEBUG : both10: Unchanged skipping
2025/04/19 04:46:29 DEBUG : both11: Unchanged skipping
2025/04/19 04:46:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:46:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:46:29 DEBUG : Waiting for deletions to finish
2025/04/19 04:46:30 INFO  : only14: Deleted
2025/04/19 04:46:30 INFO  : only17: Deleted
2025/04/19 04:46:30 INFO  : only12: Deleted
2025/04/19 04:46:30 INFO  : only16: Deleted
2025/04/19 04:46:30 INFO  : only10: Deleted
2025/04/19 04:46:30 INFO  : only8: Deleted
2025/04/19 04:46:30 INFO  : only2: Deleted
2025/04/19 04:46:30 INFO  : only19: Deleted
2025/04/19 04:46:31 INFO  : only13: Deleted
2025/04/19 04:46:31 INFO  : only15: Deleted
2025/04/19 04:46:31 INFO  : only0: Deleted
2025/04/19 04:46:31 INFO  : only1: Deleted
2025/04/19 04:46:31 INFO  : only18: Deleted
2025/04/19 04:46:31 INFO  : only3: Deleted
2025/04/19 04:46:31 INFO  : only9: Deleted
2025/04/19 04:46:31 INFO  : only6: Deleted
2025/04/19 04:46:31 INFO  : only11: Deleted
2025/04/19 04:46:31 INFO  : only5: Deleted
2025/04/19 04:46:31 INFO  : only7: Deleted
2025/04/19 04:46:31 INFO  : only4: Deleted
2025/04/19 04:46:31 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (64.57s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:46:42 DEBUG : both0: md5 = 421ed1b2d2579c531cd62e07648272cb OK
2025/04/19 04:46:44 DEBUG : only0: md5 = 2c8f64701d9ea984bb7169daf6285570 OK
2025/04/19 04:46:45 DEBUG : both1: md5 = c9ae25424f9725fed9a1af96708591a1 OK
2025/04/19 04:46:46 DEBUG : only1: md5 = c9d2a2907d189f048f43e0eb7558c185 OK
2025/04/19 04:46:47 DEBUG : both2: md5 = abc4462f3aaaa77f092a05b2e0aab6b9 OK
2025/04/19 04:46:49 DEBUG : only2: md5 = a8847e4b25c666c943f7a0627b8fdbf8 OK
2025/04/19 04:46:50 DEBUG : both3: md5 = e3bcfb71273bfc879cdc8d4a27853f49 OK
2025/04/19 04:46:52 DEBUG : only3: md5 = fc2f6e20d6807df00fc86f8c2423dfec OK
2025/04/19 04:46:53 DEBUG : both4: md5 = 36c188203154907190d3b8aef49114ff OK
2025/04/19 04:46:54 DEBUG : only4: md5 = f1c9eca4d731b038877ff330748d9de9 OK
2025/04/19 04:46:56 DEBUG : both5: md5 = 2215b0174a0e13fa66dbc4569d954681 OK
2025/04/19 04:46:57 DEBUG : only5: md5 = 877129343a6a0f660d1427055d1693d6 OK
2025/04/19 04:46:58 DEBUG : both6: md5 = 0496d254b5178577856931082c924308 OK
2025/04/19 04:47:00 DEBUG : only6: md5 = 9b8e6bb212248d0745d0abb0368785e7 OK
2025/04/19 04:47:01 DEBUG : both7: md5 = 7983a0bae08b68c4be7d6789d99def83 OK
2025/04/19 04:47:03 DEBUG : only7: md5 = 5bf0caba076eed99f046787de94f5312 OK
2025/04/19 04:47:04 DEBUG : both8: md5 = 2d425b33470d29273a631ebebfc0ff64 OK
2025/04/19 04:47:05 DEBUG : only8: md5 = edbe2c9fafa9269ff0cece1a2746f35f OK
2025/04/19 04:47:06 DEBUG : both9: md5 = bcbb0d5903da5612d7f0c61181b4592d OK
2025/04/19 04:47:08 DEBUG : only9: md5 = 6561569fbc4f7d83d5ecc2a6256ce122 OK
2025/04/19 04:47:09 DEBUG : both10: md5 = 3b53854cd87fca8668b244d02aae32ce OK
2025/04/19 04:47:10 DEBUG : only10: md5 = 072530cad18a693452ebdb387eafbfd8 OK
2025/04/19 04:47:12 DEBUG : both11: md5 = 3df842ad4b20e9baff05023753c34bea OK
2025/04/19 04:47:13 DEBUG : only11: md5 = 104f03946e9c46224ffffdb86b70a140 OK
2025/04/19 04:47:14 DEBUG : both12: md5 = f054591dec7b00424c397b6009f5acfa OK
2025/04/19 04:47:16 DEBUG : only12: md5 = 618acf151a83736ea90c10003bdfe7d0 OK
2025/04/19 04:47:17 DEBUG : both13: md5 = 8f169622b178897df5bed4789aa48afd OK
2025/04/19 04:47:18 DEBUG : only13: md5 = 813ed3765b3b131ccd7f394c41e7b100 OK
2025/04/19 04:47:20 DEBUG : both14: md5 = b189b465108113ab49a34cbecb1a17d3 OK
2025/04/19 04:47:21 DEBUG : only14: md5 = e5789d44138584d8018ce2c4cf3fd31c OK
2025/04/19 04:47:22 DEBUG : both15: md5 = 4e77a3864723b67ce0329cca16adeb52 OK
2025/04/19 04:47:23 DEBUG : only15: md5 = 4d0619f9177fa1242031c0d72d9ab4eb OK
2025/04/19 04:47:25 DEBUG : both16: md5 = 76f0f5f9ada73c77812d9e2136eb385b OK
2025/04/19 04:47:26 DEBUG : only16: md5 = 09b1de0ad9e0281fd05b500fd20bc1b8 OK
2025/04/19 04:47:27 DEBUG : both17: md5 = 7182c513ace6db1bc957408f8890d06a OK
2025/04/19 04:47:29 DEBUG : only17: md5 = 1d328bf3190728c05e530834ed492c92 OK
2025/04/19 04:47:30 DEBUG : both18: md5 = fad831a5eb74dc23f87185a6ef0b9314 OK
2025/04/19 04:47:31 DEBUG : only18: md5 = 55eb457e1e748dc77440bcf8675c5bb8 OK
2025/04/19 04:47:32 DEBUG : both19: md5 = a8a958d18edf4d5685de8de7a7093454 OK
2025/04/19 04:47:34 DEBUG : only19: md5 = cc54f4a08e4f4df3bdb8f7624b562446 OK
2025/04/19 04:47:34 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:47:34 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:47:34 DEBUG : both0: Unchanged skipping
2025/04/19 04:47:34 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:47:34 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:47:34 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:47:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for checks to finish
2025/04/19 04:47:34 DEBUG : both10: Unchanged skipping
2025/04/19 04:47:34 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:47:34 DEBUG : both13: Unchanged skipping
2025/04/19 04:47:34 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:47:34 DEBUG : both14: Unchanged skipping
2025/04/19 04:47:34 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:47:34 DEBUG : both11: Unchanged skipping
2025/04/19 04:47:34 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:47:34 DEBUG : both16: Unchanged skipping
2025/04/19 04:47:34 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:47:34 DEBUG : both17: Unchanged skipping
2025/04/19 04:47:34 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:47:34 DEBUG : both18: Unchanged skipping
2025/04/19 04:47:34 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:47:34 DEBUG : both1: Unchanged skipping
2025/04/19 04:47:34 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:47:34 DEBUG : both12: Unchanged skipping
2025/04/19 04:47:34 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:47:34 DEBUG : both15: Unchanged skipping
2025/04/19 04:47:34 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:47:34 DEBUG : both4: Unchanged skipping
2025/04/19 04:47:34 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:47:34 DEBUG : both19: Unchanged skipping
2025/04/19 04:47:34 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:47:34 DEBUG : both6: Unchanged skipping
2025/04/19 04:47:34 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:47:34 DEBUG : both7: Unchanged skipping
2025/04/19 04:47:34 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:47:34 DEBUG : both8: Unchanged skipping
2025/04/19 04:47:34 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/04/19 04:47:34 DEBUG : both9: Unchanged skipping
2025/04/19 04:47:34 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2025/04/19 04:47:34 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2025/04/19 04:47:34 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2025/04/19 04:47:34 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2025/04/19 04:47:34 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2025/04/19 04:47:34 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2025/04/19 04:47:34 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2025/04/19 04:47:34 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2025/04/19 04:47:34 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2025/04/19 04:47:34 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2025/04/19 04:47:34 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2025/04/19 04:47:34 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2025/04/19 04:47:34 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2025/04/19 04:47:34 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2025/04/19 04:47:34 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2025/04/19 04:47:34 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2025/04/19 04:47:34 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2025/04/19 04:47:34 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2025/04/19 04:47:34 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2025/04/19 04:47:34 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2025/04/19 04:47:34 DEBUG : both2: Unchanged skipping
2025/04/19 04:47:34 DEBUG : both3: Unchanged skipping
2025/04/19 04:47:34 DEBUG : both5: Unchanged skipping
2025/04/19 04:47:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Waiting for transfers to finish
2025/04/19 04:47:35 DEBUG : only10: md5 = 8262784ab882abe7f514961441b14ea9 OK
2025/04/19 04:47:35 INFO  : only10: Copied (replaced existing)
2025/04/19 04:47:35 DEBUG : only1: md5 = 2d385e138b13ae0f4d8fe5d8fee9a230 OK
2025/04/19 04:47:35 INFO  : only1: Copied (replaced existing)
2025/04/19 04:47:35 DEBUG : only0: md5 = eb781b140bcb4f9fbf61f9ea31b8dbb8 OK
2025/04/19 04:47:35 INFO  : only0: Copied (replaced existing)
2025/04/19 04:47:36 DEBUG : only11: md5 = 82092ba685986d04544a2ca67795ab08 OK
2025/04/19 04:47:36 INFO  : only11: Copied (replaced existing)
2025/04/19 04:47:36 DEBUG : only14: md5 = ade31f093662047c4368c9026b9ffe38 OK
2025/04/19 04:47:36 INFO  : only14: Copied (replaced existing)
2025/04/19 04:47:36 DEBUG : only13: md5 = bf5e859475c522f3fde00f35a74886c1 OK
2025/04/19 04:47:36 INFO  : only13: Copied (replaced existing)
2025/04/19 04:47:37 DEBUG : only12: md5 = 57a5bb17a4bc61b4f0eec4c81bbe068b OK
2025/04/19 04:47:37 INFO  : only12: Copied (replaced existing)
2025/04/19 04:47:37 DEBUG : only15: md5 = bb5ed66893f241fb4cb57599f82a03f5 OK
2025/04/19 04:47:37 INFO  : only15: Copied (replaced existing)
2025/04/19 04:47:37 DEBUG : only16: md5 = 2aa344cc95cc8f43f36f6abd55a08d5c OK
2025/04/19 04:47:37 INFO  : only16: Copied (replaced existing)
2025/04/19 04:47:37 DEBUG : only17: md5 = 2ed22e558ca120dddca269c29dd629ef OK
2025/04/19 04:47:37 INFO  : only17: Copied (replaced existing)
2025/04/19 04:47:38 DEBUG : only18: md5 = 8125531f1fe8075de6c573947e58a8be OK
2025/04/19 04:47:38 INFO  : only18: Copied (replaced existing)
2025/04/19 04:47:38 DEBUG : only19: md5 = ba3e75a95d776126c341a8e057ff20fa OK
2025/04/19 04:47:38 INFO  : only19: Copied (replaced existing)
2025/04/19 04:47:38 DEBUG : only2: md5 = 5139c946fbd7d61bb9ce980c90709038 OK
2025/04/19 04:47:38 INFO  : only2: Copied (replaced existing)
2025/04/19 04:47:39 DEBUG : only3: md5 = c358512e822d44fec928cc12e11d8787 OK
2025/04/19 04:47:39 INFO  : only3: Copied (replaced existing)
2025/04/19 04:47:39 DEBUG : only4: md5 = 2ec959b8bdb501b3a88cf23adac52a2b OK
2025/04/19 04:47:39 INFO  : only4: Copied (replaced existing)
2025/04/19 04:47:39 DEBUG : only5: md5 = 8a3e809014fb1649d1ceb697effc08db OK
2025/04/19 04:47:39 INFO  : only5: Copied (replaced existing)
2025/04/19 04:47:40 DEBUG : only6: md5 = e2e9224862aa01e3fad20bdcee9035ad OK
2025/04/19 04:47:40 INFO  : only6: Copied (replaced existing)
2025/04/19 04:47:40 DEBUG : only7: md5 = 6d73af56fa66157d353b06135161ae9a OK
2025/04/19 04:47:40 INFO  : only7: Copied (replaced existing)
2025/04/19 04:47:40 DEBUG : only8: md5 = 68183c6eead7c19ccc60d241064f7994 OK
2025/04/19 04:47:40 INFO  : only8: Copied (replaced existing)
2025/04/19 04:47:40 DEBUG : only9: md5 = 3d7b071a6f3527104977a1cdcb33b008 OK
2025/04/19 04:47:40 INFO  : only9: Copied (replaced existing)
2025/04/19 04:47:40 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (77.10s)
=== RUN   TestSyncReplaceDirModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:47:58 DEBUG : empty_dir: Making directory with metadata
2025/04/19 04:47:58 INFO  : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/19 04:47:58 DEBUG : empty_on_remote: Making directory with metadata
2025/04/19 04:47:58 INFO  : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/19 04:47:58 DEBUG : empty_on_remote: Making directory with metadata
2025/04/19 04:47:59 INFO  : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:48:03 INFO  : test_dir1: Set directory modification time (using DirSetModTime)
2025/04/19 04:48:03 INFO  : test_dir2: Set directory modification time (using DirSetModTime)
2025/04/19 04:48:03 INFO  : test_dir2/sub_dir: Set directory modification time (using DirSetModTime)
2025/04/19 04:48:03 INFO  : empty_on_remote: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:48:10 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto"
2025/04/19 04:48:11 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8"
2025/04/19 04:48:11 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00"
--- PASS: TestSyncReplaceDirModTime (15.22s)
=== RUN   TestSyncReplaceDirModTimeWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:48:13 DEBUG : empty_dir: Making directory with metadata
2025/04/19 04:48:13 INFO  : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/19 04:48:13 DEBUG : empty_on_remote: Making directory with metadata
2025/04/19 04:48:13 INFO  : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/19 04:48:13 DEBUG : empty_on_remote: Making directory with metadata
2025/04/19 04:48:14 INFO  : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:48:18 INFO  : test_dir1: Set directory modification time (using DirSetModTime)
2025/04/19 04:48:18 INFO  : test_dir2: Set directory modification time (using DirSetModTime)
2025/04/19 04:48:18 INFO  : test_dir2/sub_dir: Set directory modification time (using DirSetModTime)
2025/04/19 04:48:18 INFO  : empty_on_remote: Set directory modification time (using DirSetModTime)
2025/04/19 04:48:18 INFO  : empty_dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:48:25 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto"
2025/04/19 04:48:26 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8"
2025/04/19 04:48:27 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00"
--- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (16.50s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:48:30 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/19 04:48:30 DEBUG : sub dir: Making directory with metadata
2025/04/19 04:48:30 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:48:47 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/04/19 04:48:47 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/04/19 04:48:47 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/19 04:48:47 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:48:59 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2025/04/19 04:49:00 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/04/19 04:49:00 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2025/04/19 04:49:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2025/04/19 04:49:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/04/19 04:49:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/04/19 04:49:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/04/19 04:49:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/04/19 04:49:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/04/19 04:49:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2025/04/19 04:49:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/04/19 04:49:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (37.68s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:49:07 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/04/19 04:49:07 DEBUG : sub dir: Making directory with metadata
2025/04/19 04:49:08 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:49:28 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/04/19 04:49:28 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/04/19 04:49:28 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/04/19 04:49:28 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa'", Local "Local file system at /tmp/rclone1578056088", Modify Window "1ms"
2025/04/19 04:49:39 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/04/19 04:49:40 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2025/04/19 04:49:40 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2025/04/19 04:49:41 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/04/19 04:49:42 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/04/19 04:49:42 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/04/19 04:49:43 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/04/19 04:49:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/04/19 04:49:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2025/04/19 04:49:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/04/19 04:49:45 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (39.74s)
PASS
2025/04/19 04:49:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuseboj5jaqa': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 14m59.436826121s (try 1/5)