"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5)
2025/05/11 01:28:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi"
2025/05/11 01:28:22 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/05/11 01:28:22 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg"
2025/05/11 01:28:23 DEBUG : Creating backend with remote "/tmp/rclone3547058176"
=== RUN   TestPipe
--- PASS: TestPipe (0.00s)
=== RUN   TestPipeConcurrent
--- PASS: TestPipeConcurrent (0.04s)
=== 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-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:28:24 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/11 01:28:24 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/11 01:28:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:28:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:28:24 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2025/05/11 01:28:24 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (1.99s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:28:25 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/05/11 01:28:26 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/11 01:28:26 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/11 01:28:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:28:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:28:28 DEBUG : sub dir/hello world: md5 = f45efb4a55a8064736b2d652a12af836 OK
2025/05/11 01:28:28 INFO  : sub dir/hello world: Copied (new)
2025/05/11 01:28:28 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:28:30 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (5.94s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:28:31 DEBUG : metadata sub dir: Making directory with metadata
2025/05/11 01:28:31 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/11 01:28:31 DEBUG : empty metadata sub dir: Making directory with metadata
2025/05/11 01:28:31 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/11 01:28:31 DEBUG : Local file system at /tmp/rclone3547058176: File to upload is small (21 bytes), uploading instead of streaming
2025/05/11 01:28:31 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2025/05/11 01:28:31 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2025/05/11 01:28:31 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2025/05/11 01:28:32 DEBUG : Google drive root 'crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg': Skipping btime metadata as can't update it on an existing file: 2025-05-11T01:28:31.740610762Z
2025/05/11 01:28:32 INFO  : empty metadata sub dir: Updated directory metadata
2025/05/11 01:28:32 DEBUG : Google drive root 'crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg': Skipping btime metadata as can't update it on an existing file: 2025-05-11T01:28:31.740610762Z
2025/05/11 01:28:33 INFO  : metadata sub dir: Updated directory metadata
2025/05/11 01:28:33 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2025/05/11 01:28:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:28:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:28:34 DEBUG : metadata sub dir/hello metadata world: md5 = 2555fb60119baee9794504b69401bb33 OK
2025/05/11 01:28:34 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:28:37 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (7.30s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:28:39 DEBUG : metadata sub dir: Making directory with metadata
2025/05/11 01:28:39 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/11 01:28:39 DEBUG : empty metadata sub dir: Making directory with metadata
2025/05/11 01:28:39 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/11 01:28:39 DEBUG : Local file system at /tmp/rclone3547058176: File to upload is small (21 bytes), uploading instead of streaming
2025/05/11 01:28:39 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2025/05/11 01:28:39 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2025/05/11 01:28:39 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2025/05/11 01:28:39 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2025/05/11 01:28:39 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2025/05/11 01:28:39 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2025/05/11 01:28:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:28:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:28:41 DEBUG : metadata sub dir/hello metadata world: md5 = cd4647bf6c1e4751b2c902486c89598b OK
2025/05/11 01:28:41 INFO  : metadata sub dir/hello metadata world: Copied (new)
2025/05/11 01:28:41 DEBUG : Google drive root 'crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg': Skipping btime metadata as can't update it on an existing file: 2025-05-11T01:28:39.044616921Z
2025/05/11 01:28:41 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:28:44 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (6.38s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:28:45 DEBUG : Creating backend with remote "/non-existing"
2025/05/11 01:28:45 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2025/05/11 01:28:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:28:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.04s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:28:46 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/11 01:28:46 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/11 01:28:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:28:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:28:48 DEBUG : sub dir/hello world: md5 = 568e41783951069636bdad87decff350 OK
2025/05/11 01:28:48 INFO  : sub dir/hello world: Copied (new)
2025/05/11 01:28:49 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:28:50 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (5.46s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:28:51 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Running all checks before starting transfers
2025/05/11 01:28:52 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/11 01:28:52 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/11 01:28:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:28:52 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Checks finished, now starting transfers
2025/05/11 01:28:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:28:54 DEBUG : sub dir/hello world: md5 = dc24eddc0491961c1184a04536410156 OK
2025/05/11 01:28:54 INFO  : sub dir/hello world: Copied (new)
2025/05/11 01:28:54 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:28:56 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (5.31s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:28:57 ERROR : Ignoring --no-traverse with sync
2025/05/11 01:28:57 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/11 01:28:57 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/11 01:28:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:28:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:28:59 DEBUG : sub dir/hello world: md5 = 42979788ce27fdb56d9f413afa6021d8 OK
2025/05/11 01:28:59 INFO  : sub dir/hello world: Copied (new)
2025/05/11 01:28:59 DEBUG : Waiting for deletions to finish
2025/05/11 01:28:59 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:29:01 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (5.24s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:29:02 DEBUG : hello world2: Need to transfer - File not found at Destination
2025/05/11 01:29:02 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/11 01:29:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:29:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:29:03 DEBUG : hello world2: md5 = fb66f2c3d18f029b107136766049c774 OK
2025/05/11 01:29:03 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestCopyWithDepth (3.06s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:29:05 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/11 01:29:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:29:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:29:07 DEBUG : potato2: md5 = 0c3f7cdedaf7bc04cad82e951c880182 OK
2025/05/11 01:29:07 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (3.07s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:29:08 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/11 01:29:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:29:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:29:10 DEBUG : potato2: md5 = 2a6c507bf91ead860cbfd4a43ce0a36c OK
2025/05/11 01:29:10 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (2.87s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:29:11 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/05/11 01:29:11 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/11 01:29:11 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/05/11 01:29:11 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/05/11 01:29:11 DEBUG : sub dir: Making directory with metadata
2025/05/11 01:29:12 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/05/11 01:29:12 DEBUG : sub dir2: Making directory with metadata
2025/05/11 01:29:13 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/11 01:29:13 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/05/11 01:29:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/11 01:29:13 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/11 01:29:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:29:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:29:14 DEBUG : sub dir/hello world: md5 = 9699ee62d17117b5914fa92b4aa3d9a5 OK
2025/05/11 01:29:14 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:29:17 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2025/05/11 01:29:18 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (8.16s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:29:19 INFO  : sub dir2: Making directory
2025/05/11 01:29:19 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/05/11 01:29:19 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/11 01:29:19 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/11 01:29:19 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/05/11 01:29:19 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2025/05/11 01:29:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/11 01:29:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:29:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:29:21 DEBUG : sub dir/hello world: md5 = 9906f696b69ff0bafd0082e5788fe7fc OK
2025/05/11 01:29:21 INFO  : sub dir/hello world: Copied (new)
2025/05/11 01:29:22 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/05/11 01:29:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (5.16s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:29:24 DEBUG : sub dir2: Making directory with metadata
2025/05/11 01:29:24 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/11 01:29:25 DEBUG : sub dir: Making directory with metadata
2025/05/11 01:29:25 INFO  : sub dir: Made directory with metadata (mtime=2025-05-11T01:29:24.792655618Z)
2025/05/11 01:29:25 DEBUG : sub dir2: Making directory with metadata
2025/05/11 01:29:26 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/11 01:29:26 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/11 01:29:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:29:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:29:27 DEBUG : sub dir/hello world: md5 = d728a14c4213e1c759fd1c903e8f707d OK
2025/05/11 01:29:27 INFO  : sub dir/hello world: Copied (new)
2025/05/11 01:29:27 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:29:30 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (6.65s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:29:31 DEBUG : sub dir no update dir modtime: Making directory with metadata
2025/05/11 01:29:31 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/05/11 01:29:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:29:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:29:32 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (3.69s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:29:35 INFO  : sub dir2: Making directory
2025/05/11 01:29:35 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/11 01:29:35 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/05/11 01:29:35 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/11 01:29:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:29:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:29:37 DEBUG : sub dir/hello world: md5 = aedec19867b34f291e71335f4893b7b3 OK
2025/05/11 01:29:37 INFO  : sub dir/hello world: Copied (new)
2025/05/11 01:29:37 INFO  : sub dir/hello world: Deleted
2025/05/11 01:29:37 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/05/11 01:29:39 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (5.04s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:29:40 DEBUG : sub dir2: Making directory with metadata
2025/05/11 01:29:40 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/11 01:29:40 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/05/11 01:29:40 DEBUG : sub dir: Making directory with metadata
2025/05/11 01:29:41 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/05/11 01:29:41 DEBUG : sub dir2: Making directory with metadata
2025/05/11 01:29:41 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/11 01:29:41 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/11 01:29:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:29:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:29:43 DEBUG : sub dir/hello world: md5 = 66040f41e916d58982e96544f1b2bda0 OK
2025/05/11 01:29:43 INFO  : sub dir/hello world: Copied (new)
2025/05/11 01:29:43 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:29:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (6.90s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.43s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:29:47 INFO  : sub dir2: Making directory
2025/05/11 01:29:47 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/11 01:29:47 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/05/11 01:29:47 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/11 01:29:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:29:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:29:49 DEBUG : sub dir/hello world: md5 = 5f844ca1590791391607e562b2914e6d OK
2025/05/11 01:29:49 INFO  : sub dir/hello world: Copied (new)
2025/05/11 01:29:49 DEBUG : Waiting for deletions to finish
2025/05/11 01:29:50 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/05/11 01:29:51 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (5.05s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:29:54 DEBUG : sub dir/hello world: md5 = 350378a0ef5a190ab69057e997e05379 OK
2025/05/11 01:29:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-satoyun8zesu"
2025/05/11 01:29:54 DEBUG : Config file has changed externally - reloading
2025/05/11 01:29:55 DEBUG : Creating backend with remote "TestDrive:crypt/1d12aqnr9u9b0mlds0fc19n4a85ct5rihhmh61lk3489t6o8jjmg"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi' -> Encrypted drive 'TestCryptDrive:rclone-test-satoyun8zesu'
2025/05/11 01:29:56 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/11 01:29:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/11 01:29:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-satoyun8zesu': Waiting for checks to finish
2025/05/11 01:29:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-satoyun8zesu': Waiting for transfers to finish
2025/05/11 01:29:59 INFO  : sub dir/hello world: Copied (server-side copy)
2025/05/11 01:30:00 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:30:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-satoyun8zesu': Purge remote
2025/05/11 01:30:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (10.62s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:30:05 DEBUG : sub dir/hello world: md5 = 4456d9dbc287dd97600f8191952cbdb7 OK
2025/05/11 01:30:06 INFO  : sub dir: Set directory modification time (using SetModTime)
2025/05/11 01:30:06 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/05/11 01:30:06 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/05/11 01:30:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:30:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:30:07 DEBUG : sub dir/hello world: md5 = f5f57462dfd1003acbe50072a40c8194 OK
2025/05/11 01:30:07 INFO  : sub dir/hello world: Copied (replaced existing)
2025/05/11 01:30:08 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:30:09 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (7.53s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:30:12 DEBUG : sub dir/hello world: md5 = 53da013e79fb85a65ddcfe49a0211836 OK
2025/05/11 01:30:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mejumul1doni"
2025/05/11 01:30:13 DEBUG : Creating backend with remote "TestDrive:crypt/v4fh8aevrojciopidcmg3i78gunkmehh554nrvrd9oqgfor1i1i0"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi' -> Encrypted drive 'TestCryptDrive:rclone-test-mejumul1doni'
2025/05/11 01:30:14 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/11 01:30:14 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/11 01:30:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mejumul1doni': Waiting for checks to finish
2025/05/11 01:30:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mejumul1doni': Waiting for transfers to finish
2025/05/11 01:30:17 INFO  : sub dir/hello world: Copied (server-side copy)
2025/05/11 01:30:17 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:30:19 DEBUG : sub dir/hello world: md5 = 864a0357b696c116acb1442610a8dbec OK
2025/05/11 01:30:19 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/05/11 01:30:19 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/05/11 01:30:20 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/05/11 01:30:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mejumul1doni': Waiting for checks to finish
2025/05/11 01:30:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mejumul1doni': Waiting for transfers to finish
2025/05/11 01:30:21 INFO  : sub dir/hello world: Copied (server-side copy)
2025/05/11 01:30:22 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:30:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mejumul1doni': Purge remote
2025/05/11 01:30:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (14.88s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:30:27 DEBUG : sub dir/hello world: md5 = ee46347e8ee79b204f378d295c11ceb4 OK
2025/05/11 01:30:28 INFO  : sub dir: Set directory modification time (using SetModTime)
2025/05/11 01:30:28 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/05/11 01:30:29 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/05/11 01:30:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:30:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:30:30 DEBUG : sub dir/hello world: md5 = bb1e82179d9eb22d96b17e99beba3b4f OK
2025/05/11 01:30:30 INFO  : sub dir/hello world: Copied (replaced existing)
2025/05/11 01:30:30 INFO  : sub dir/hello world: Deleted
2025/05/11 01:30:30 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:30:32 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (7.89s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:30:35 DEBUG : sub dir/hello world: md5 = 347c66b27296aa789c812f08fc7bdb0e OK
2025/05/11 01:30:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wutepar6haco"
2025/05/11 01:30:36 DEBUG : Creating backend with remote "TestDrive:crypt/prvrll74lbs76jmhc4ganag1n76i0uspspupb2sm99hegf88d810"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi' -> Encrypted drive 'TestCryptDrive:rclone-test-wutepar6haco'
2025/05/11 01:30:37 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/11 01:30:37 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/11 01:30:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wutepar6haco': Waiting for checks to finish
2025/05/11 01:30:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wutepar6haco': Waiting for transfers to finish
2025/05/11 01:30:39 INFO  : sub dir/hello world: Copied (server-side copy)
2025/05/11 01:30:40 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:30:42 DEBUG : sub dir/hello world: md5 = 6ef1cc10f08dd236a998e3379c65321b OK
2025/05/11 01:30:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wutepar6haco': Using server-side directory move
2025/05/11 01:30:42 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-wutepar6haco': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/05/11 01:30:42 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/05/11 01:30:42 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/05/11 01:30:43 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/05/11 01:30:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wutepar6haco': Waiting for checks to finish
2025/05/11 01:30:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wutepar6haco': Waiting for transfers to finish
2025/05/11 01:30:43 INFO  : sub dir/hello world: Deleted
2025/05/11 01:30:44 INFO  : sub dir/hello world: Moved (server-side)
2025/05/11 01:30:44 INFO  : sub dir: Set directory modification time (using SetModTime)
2025/05/11 01:30:46 DEBUG : sub dir/hello world: md5 = 6c84e054b1e78e13e81f8458e8836b8f OK
2025/05/11 01:30:47 DEBUG : testing file moves
2025/05/11 01:30:47 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/05/11 01:30:47 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/05/11 01:30:47 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2025/05/11 01:30:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wutepar6haco': Waiting for checks to finish
2025/05/11 01:30:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wutepar6haco': Waiting for transfers to finish
2025/05/11 01:30:48 INFO  : sub dir/hello world: Deleted
2025/05/11 01:30:48 INFO  : sub dir/hello world: Moved (server-side)
2025/05/11 01:30:49 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:30:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wutepar6haco': Purge remote
--- PASS: TestServerSideMoveOverSelf (19.03s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:30:54 DEBUG : sub dir/hello world: md5 = e3bed9ecaae4a8d3fae5fde3f9afff9d OK
2025/05/11 01:30:54 ERROR : : error listing: directory not found
2025/05/11 01:30:55 INFO  : Local file system at /tmp/rclone3547058176: Making directory
2025/05/11 01:30:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:30:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:30:57 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (5.84s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:31:00 DEBUG : sub dir/hello world: md5 = 82bc45c0b64d8a1ed989461b69ce5b41 OK
2025/05/11 01:31:01 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/11 01:31:01 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/11 01:31:01 DEBUG : Local file system at /tmp/rclone3547058176: Waiting for checks to finish
2025/05/11 01:31:01 DEBUG : Local file system at /tmp/rclone3547058176: Waiting for transfers to finish
2025/05/11 01:31:02 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2025/05/11 01:31:02 INFO  : sub dir/hello world: Copied (new)
2025/05/11 01:31:02 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:31:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (6.05s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:31:04 DEBUG : check sum: Need to transfer - File not found at Destination
2025/05/11 01:31:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:31:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:31:05 DEBUG : check sum: md5 = fd11f408750fb4d8375548d0f5741e54 OK
2025/05/11 01:31:05 INFO  : check sum: Copied (new)
2025/05/11 01:31:05 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:31:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:31:06 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2025/05/11 01:31:06 DEBUG : check sum: Size of src and dst objects identical
2025/05/11 01:31:06 DEBUG : check sum: Unchanged skipping
2025/05/11 01:31:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:31:06 DEBUG : Waiting for deletions to finish
2025/05/11 01:31:06 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (4.14s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:31:08 DEBUG : sizeonly: Need to transfer - File not found at Destination
2025/05/11 01:31:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:31:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:31:09 DEBUG : sizeonly: md5 = 8876e479ab882dd2dc2e0361a7d3c5a6 OK
2025/05/11 01:31:09 INFO  : sizeonly: Copied (new)
2025/05/11 01:31:09 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:31:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:31:10 DEBUG : sizeonly: Sizes identical
2025/05/11 01:31:10 DEBUG : sizeonly: Unchanged skipping
2025/05/11 01:31:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:31:10 DEBUG : Waiting for deletions to finish
2025/05/11 01:31:10 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (3.73s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:31:12 DEBUG : ignore-size: Need to transfer - File not found at Destination
2025/05/11 01:31:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:31:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:31:13 DEBUG : ignore-size: md5 = a7a84daaa1fec078671529422a26432b OK
2025/05/11 01:31:13 INFO  : ignore-size: Copied (new)
2025/05/11 01:31:13 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:31:14 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:31:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:31:14 DEBUG : ignore-size: Unchanged skipping
2025/05/11 01:31:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:31:14 DEBUG : Waiting for deletions to finish
2025/05/11 01:31:14 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (3.87s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:31:17 DEBUG : existing: md5 = dd41958dc8071baaea850c05c2f742d4 OK
2025/05/11 01:31:17 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:31:17 DEBUG : existing: Unchanged skipping
2025/05/11 01:31:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:31:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:31:17 DEBUG : Waiting for deletions to finish
2025/05/11 01:31:17 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:31:17 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2025/05/11 01:31:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:31:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:31:18 DEBUG : existing: md5 = 55274ba808a563c9e9ef828f86d7d0c6 OK
2025/05/11 01:31:18 INFO  : existing: Copied (replaced existing)
2025/05/11 01:31:18 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (4.74s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:31:21 DEBUG : existing: Need to transfer - File not found at Destination
2025/05/11 01:31:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:31:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:31:22 DEBUG : existing: md5 = 5dfc13a3ba2e0d8164fbc26e134e9e66 OK
2025/05/11 01:31:22 INFO  : existing: Copied (new)
2025/05/11 01:31:22 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:31:22 DEBUG : existing: Destination exists, skipping
2025/05/11 01:31:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:31:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:31:22 DEBUG : Waiting for deletions to finish
2025/05/11 01:31:22 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (3.88s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:31:26 DEBUG : b/potato: md5 = 008137b9d55d49c718c16d265430fe29 OK
2025/05/11 01:31:28 DEBUG : c/non empty space: md5 = 8e138a3f6933a4181eee8a6a39e878b8 OK
2025/05/11 01:31:28 INFO  : d: Making directory
2025/05/11 01:31:30 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/05/11 01:31:30 INFO  : c: Set directory modification time (using SetModTime)
2025/05/11 01:31:30 DEBUG : Added delayed dir = "c", newDst=c
2025/05/11 01:31:30 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/05/11 01:31:30 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:31:30 DEBUG : c/non empty space: Unchanged skipping
2025/05/11 01:31:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:31:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:31:32 DEBUG : a/potato2: md5 = 4f03e28f0b695051cfabffcd7cc4025d OK
2025/05/11 01:31:32 INFO  : a/potato2: Copied (new)
2025/05/11 01:31:32 DEBUG : Waiting for deletions to finish
2025/05/11 01:31:33 INFO  : b/potato: Deleted
2025/05/11 01:31:33 INFO  : a: Set directory modification time (using DirSetModTime)
2025/05/11 01:31:33 INFO  : d: Removing directory
2025/05/11 01:31:34 INFO  : b: Removing directory
2025/05/11 01:31:34 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/05/11 01:31:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:31:36 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/05/11 01:31:37 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (13.62s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:31:39 DEBUG : empty space: md5 = fbba1eba351f3c750f87cb42aba2c04c OK
2025/05/11 01:31:40 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/05/11 01:31:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:31:40 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2025/05/11 01:31:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:31:40 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:31:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:31:40 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/05/11 01:31:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:31:42 DEBUG : empty space: md5 = f39dba8614ab87144ff18b4208f839ae OK
2025/05/11 01:31:42 INFO  : empty space: Copied (replaced existing)
2025/05/11 01:31:42 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (5.59s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.42s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:31:45 DEBUG : foo: md5 = 8865fc1f5c9a16aac34d72e22e6326cd OK
2025/05/11 01:31:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:31:46 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/05/11 01:31:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:31:47 DEBUG : foo: md5 = 813f24b724f997547e7d38f9f03261fb OK
2025/05/11 01:31:47 INFO  : foo: Copied (replaced existing)
2025/05/11 01:31:47 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (4.42s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:31:50 DEBUG : empty space: md5 = 342746077098e6fc45e9ac08d36fa279 OK
2025/05/11 01:31:50 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:31:50 DEBUG : potato: Need to transfer - File not found at Destination
2025/05/11 01:31:50 DEBUG : empty space: Unchanged skipping
2025/05/11 01:31:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:31:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:31:51 DEBUG : potato: md5 = 488763a8e66bdee71a71f6648f0e96a7 OK
2025/05/11 01:31:51 INFO  : potato: Copied (new)
2025/05/11 01:31:51 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (5.09s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:31:55 DEBUG : potato: md5 = b39384febd571f16df9b50b3a88d45ae OK
2025/05/11 01:31:55 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2025/05/11 01:31:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:31:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:31:57 DEBUG : potato: md5 = a7bf09e04c1e7b7111c533c6a4b8d60e OK
2025/05/11 01:31:57 INFO  : potato: Copied (replaced existing)
2025/05/11 01:31:57 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (4.73s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:31:59 DEBUG : potato: md5 = 3c5075ba2c651b820063117b52d21348 OK
2025/05/11 01:32:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:32:00 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/05/11 01:32:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:32:01 DEBUG : potato: md5 = 396e84b3525b682671d124898df06c4b OK
2025/05/11 01:32:01 INFO  : potato: Copied (replaced existing)
2025/05/11 01:32:01 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (4.45s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:32:04 DEBUG : potato: md5 = cc038269b6c4b13d63c0e7bf799052f7 OK
2025/05/11 01:32:05 DEBUG : empty space: md5 = 80de531275e70c95bda08e334711ddac OK
2025/05/11 01:32:05 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/11 01:32:05 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:32:05 DEBUG : empty space: Unchanged skipping
2025/05/11 01:32:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:32:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:32:05 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2025/05/11 01:32:05 DEBUG : Waiting for deletions to finish
2025/05/11 01:32:05 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (4.86s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:32:09 DEBUG : potato: md5 = 49a3bff1cd7b349cb13dfa105c1b7f2d OK
2025/05/11 01:32:10 DEBUG : empty space: md5 = 19d0df3d693b9eec41287f0df9012e50 OK
2025/05/11 01:32:10 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:32:10 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/11 01:32:10 DEBUG : empty space: Unchanged skipping
2025/05/11 01:32:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:32:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:32:12 DEBUG : potato2: md5 = ce4d21a14ae432d127e20730b4b7f22c OK
2025/05/11 01:32:12 INFO  : potato2: Copied (new)
2025/05/11 01:32:12 DEBUG : Waiting for deletions to finish
2025/05/11 01:32:12 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (6.76s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:32:16 DEBUG : b/potato: md5 = 3920cf165b2b2160bf6ba48bd9a7fc7d OK
2025/05/11 01:32:18 DEBUG : c/non empty space: md5 = 691cdfd1cb2d9da4c5b5b0ba7341f83e OK
2025/05/11 01:32:18 INFO  : d: Making directory
2025/05/11 01:32:19 INFO  : d/e: Making directory
2025/05/11 01:32:21 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/05/11 01:32:21 INFO  : c: Set directory modification time (using SetModTime)
2025/05/11 01:32:21 DEBUG : Added delayed dir = "c", newDst=c
2025/05/11 01:32:21 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/05/11 01:32:21 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:32:21 DEBUG : c/non empty space: Unchanged skipping
2025/05/11 01:32:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:32:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:32:23 DEBUG : a/potato2: md5 = 764217d537a67fb7c8d18452d0b55934 OK
2025/05/11 01:32:23 INFO  : a/potato2: Copied (new)
2025/05/11 01:32:23 DEBUG : Waiting for deletions to finish
2025/05/11 01:32:24 INFO  : b/potato: Deleted
2025/05/11 01:32:24 INFO  : a: Set directory modification time (using DirSetModTime)
2025/05/11 01:32:24 INFO  : d/e: Removing directory
2025/05/11 01:32:25 INFO  : d: Removing directory
2025/05/11 01:32:25 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2025/05/11 01:32:25 INFO  : b: Removing directory
2025/05/11 01:32:25 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/05/11 01:32:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:32:28 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/05/11 01:32:28 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (15.31s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:32:32 DEBUG : b/potato: md5 = 0e35c46576fede062ff69e496df3290d OK
2025/05/11 01:32:34 DEBUG : c/non empty space: md5 = c01ebea6046304d954ebf5328456d992 OK
2025/05/11 01:32:34 INFO  : d: Making directory
2025/05/11 01:32:35 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/05/11 01:32:35 INFO  : c: Set directory modification time (using SetModTime)
2025/05/11 01:32:35 DEBUG : Added delayed dir = "c", newDst=c
2025/05/11 01:32:35 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/05/11 01:32:36 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:32:36 DEBUG : c/non empty space: Unchanged skipping
2025/05/11 01:32:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:32:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:32:37 DEBUG : a/potato2: md5 = c6f25625171279259d4e032832432844 OK
2025/05/11 01:32:37 INFO  : a/potato2: Copied (new)
2025/05/11 01:32:37 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': not deleting files as there were IO errors
2025/05/11 01:32:38 INFO  : a: Set directory modification time (using DirSetModTime)
2025/05/11 01:32:38 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:32:41 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/05/11 01:32:42 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/05/11 01:32:42 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (13.80s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:32:45 DEBUG : potato: md5 = 7c6fcccb901e0c29fc5d5cef857671a8 OK
2025/05/11 01:32:46 DEBUG : empty space: md5 = 53ae2694ef6664d28474db0fbf04cdff OK
2025/05/11 01:32:46 DEBUG : Waiting for deletions to finish
2025/05/11 01:32:46 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:32:46 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/11 01:32:46 DEBUG : empty space: Unchanged skipping
2025/05/11 01:32:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:32:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:32:47 INFO  : potato: Deleted
2025/05/11 01:32:48 DEBUG : potato2: md5 = 70338ce9332d6b765e799d1cba398fad OK
2025/05/11 01:32:48 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (6.33s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:32:51 DEBUG : potato: md5 = 4b13f97bf57df39663fd0428952bfb08 OK
2025/05/11 01:32:52 DEBUG : empty space: md5 = b65d6d679b354132e01d3dbf1922dc1f OK
2025/05/11 01:32:53 DEBUG : Waiting for deletions to finish
2025/05/11 01:32:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:32:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:32:53 INFO  : potato: Deleted
2025/05/11 01:32:53 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:32:53 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/11 01:32:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:32:53 DEBUG : empty space: Unchanged skipping
2025/05/11 01:32:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:32:55 DEBUG : potato2: md5 = 023855bb645cffd4530b26d51cf3ded0 OK
2025/05/11 01:32:55 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (7.05s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:32:58 DEBUG : potato: md5 = 8f35321834d8c8f442f8af56448daf89 OK
2025/05/11 01:32:58 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/11 01:32:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:32:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:33:00 DEBUG : potato2: md5 = 88e64f80c3cc1b95b03716a8f02832fc OK
2025/05/11 01:33:00 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (4.90s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:33:03 DEBUG : potato2: md5 = a9b8b8a36eaa3860284822161a338882 OK
2025/05/11 01:33:04 DEBUG : empty space: md5 = 844abe4344ade3a5ba2812098f5bc6e9 OK
2025/05/11 01:33:05 DEBUG : enormous: Excluded (Size Filter)
2025/05/11 01:33:05 DEBUG : enormous: Excluded
2025/05/11 01:33:05 DEBUG : potato2: Excluded (Size Filter)
2025/05/11 01:33:05 DEBUG : potato2: Excluded
2025/05/11 01:33:05 DEBUG : potato2: Excluded (Size Filter)
2025/05/11 01:33:05 DEBUG : potato2: Excluded
2025/05/11 01:33:05 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:33:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:33:05 DEBUG : empty space: Unchanged skipping
2025/05/11 01:33:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:33:05 DEBUG : Waiting for deletions to finish
2025/05/11 01:33:05 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:33:05 DEBUG : enormous: Excluded (Size Filter)
2025/05/11 01:33:05 DEBUG : enormous: Excluded
2025/05/11 01:33:05 DEBUG : potato2: Excluded (Size Filter)
2025/05/11 01:33:05 DEBUG : potato2: Excluded
2025/05/11 01:33:05 DEBUG : potato2: Excluded (Size Filter)
2025/05/11 01:33:05 DEBUG : potato2: Excluded
2025/05/11 01:33:05 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2025/05/11 01:33:05 DEBUG : empty space: Unchanged skipping
2025/05/11 01:33:05 DEBUG : Local file system at /tmp/rclone3547058176: Waiting for checks to finish
2025/05/11 01:33:05 DEBUG : Local file system at /tmp/rclone3547058176: Waiting for transfers to finish
2025/05/11 01:33:05 DEBUG : Waiting for deletions to finish
2025/05/11 01:33:05 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncWithExclude (5.74s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:33:09 DEBUG : potato2: md5 = 919936f8b8bd04338467b5851a4e3722 OK
2025/05/11 01:33:10 DEBUG : empty space: md5 = a99701447ac0527ae396f1cfd72748ba OK
2025/05/11 01:33:11 DEBUG : enormous: md5 = 893fa600e94f9b692d3d3eeff90def2f OK
2025/05/11 01:33:11 DEBUG : enormous: Excluded (Size Filter)
2025/05/11 01:33:11 DEBUG : enormous: Excluded
2025/05/11 01:33:11 DEBUG : potato2: Excluded (Size Filter)
2025/05/11 01:33:11 DEBUG : potato2: Excluded
2025/05/11 01:33:12 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:33:12 DEBUG : empty space: Unchanged skipping
2025/05/11 01:33:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:33:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:33:12 DEBUG : Waiting for deletions to finish
2025/05/11 01:33:12 INFO  : enormous: Deleted
2025/05/11 01:33:12 INFO  : potato2: Deleted
2025/05/11 01:33:12 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:33:13 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2025/05/11 01:33:13 DEBUG : empty space: Unchanged skipping
2025/05/11 01:33:13 DEBUG : Local file system at /tmp/rclone3547058176: Waiting for checks to finish
2025/05/11 01:33:13 DEBUG : Local file system at /tmp/rclone3547058176: Waiting for transfers to finish
2025/05/11 01:33:13 DEBUG : Waiting for deletions to finish
2025/05/11 01:33:13 INFO  : enormous: Deleted
2025/05/11 01:33:13 INFO  : potato2: Deleted
2025/05/11 01:33:13 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (6.88s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:33:16 DEBUG : one: md5 = 090c228c2df96da4abecf222084e6934 OK
2025/05/11 01:33:17 DEBUG : two: md5 = df26d476ac7717337de9c3ecbcd9b947 OK
2025/05/11 01:33:18 DEBUG : three: md5 = c9d3caa873baedaa876ed0dbb3c3360b OK
2025/05/11 01:33:19 DEBUG : four: md5 = a3e0bd488830152b95ecbfc1752ebf87 OK
2025/05/11 01:33:20 DEBUG : five: Need to transfer - File not found at Destination
2025/05/11 01:33:20 DEBUG : four: Sizes differ (src 4 vs dst 8)
2025/05/11 01:33:20 DEBUG : one: Destination is newer than source, skipping
2025/05/11 01:33:20 DEBUG : three: Sizes identical
2025/05/11 01:33:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:33:20 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2025/05/11 01:33:20 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2025/05/11 01:33:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:33:21 DEBUG : two: md5 = 52f48e26d2817ba3fcf2a3340cb3f838 OK
2025/05/11 01:33:21 INFO  : two: Copied (replaced existing)
2025/05/11 01:33:21 DEBUG : four: md5 = 0d7ea366f83e4c779791b64053ecd073 OK
2025/05/11 01:33:21 INFO  : four: Copied (replaced existing)
2025/05/11 01:33:21 DEBUG : five: md5 = 65a2b6621ae8af7ff289b74dbed213dd OK
2025/05/11 01:33:21 INFO  : five: Copied (new)
2025/05/11 01:33:21 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (9.82s)
=== 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-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2025/05/11 01:33:24 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Ignoring --track-renames as the source and destination do not have a common hash
2025/05/11 01:33:24 DEBUG : potato: Need to transfer - File not found at Destination
2025/05/11 01:33:24 DEBUG : yam: Need to transfer - File not found at Destination
2025/05/11 01:33:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:33:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:33:25 DEBUG : yam: md5 = ea2103446c2c9c1181075bd0a3067908 OK
2025/05/11 01:33:25 INFO  : yam: Copied (new)
2025/05/11 01:33:26 DEBUG : potato: md5 = eb34b200eb0ed6a594eba5ada3c034f5 OK
2025/05/11 01:33:26 INFO  : potato: Copied (new)
2025/05/11 01:33:26 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:33:26 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Ignoring --track-renames as the source and destination do not have a common hash
2025/05/11 01:33:26 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:33:26 DEBUG : yaml: Need to transfer - File not found at Destination
2025/05/11 01:33:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:33:26 DEBUG : potato: Unchanged skipping
2025/05/11 01:33:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:33:27 DEBUG : yaml: md5 = abf013ebc1ddcbae0b630d9273f95038 OK
2025/05/11 01:33:27 INFO  : yaml: Copied (new)
2025/05/11 01:33:27 DEBUG : Waiting for deletions to finish
2025/05/11 01:33:28 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (6.46s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2025/05/11 01:33:31 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Making map for --track-renames
2025/05/11 01:33:31 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Finished making map for --track-renames
2025/05/11 01:33:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:33:31 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/05/11 01:33:31 DEBUG : yam: Need to transfer - No matching file found at Destination
2025/05/11 01:33:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for renames to finish
2025/05/11 01:33:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:33:32 DEBUG : yam: md5 = 29ebaf61e472a03cfb1ead230f17922c OK
2025/05/11 01:33:32 INFO  : yam: Copied (new)
2025/05/11 01:33:32 DEBUG : potato: md5 = afe1e6799c3cdceff4eb5ebad8711e93 OK
2025/05/11 01:33:32 INFO  : potato: Copied (new)
2025/05/11 01:33:32 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:33:33 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:33:33 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Making map for --track-renames
2025/05/11 01:33:33 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Finished making map for --track-renames
2025/05/11 01:33:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:33:33 DEBUG : potato: Unchanged skipping
2025/05/11 01:33:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for renames to finish
2025/05/11 01:33:33 INFO  : yam: Moved (server-side) to: yaml
2025/05/11 01:33:33 INFO  : yaml: Renamed from "yam"
2025/05/11 01:33:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:33:33 DEBUG : Waiting for deletions to finish
2025/05/11 01:33:33 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (5.10s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2025/05/11 01:33:36 DEBUG : Added delayed dir = "sub", newDst=<nil>
2025/05/11 01:33:36 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Making map for --track-renames
2025/05/11 01:33:36 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Finished making map for --track-renames
2025/05/11 01:33:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:33:36 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/05/11 01:33:36 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2025/05/11 01:33:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for renames to finish
2025/05/11 01:33:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:33:38 DEBUG : potato: md5 = b734329bbdbd885bab92e612de538e9b OK
2025/05/11 01:33:38 INFO  : potato: Copied (new)
2025/05/11 01:33:38 DEBUG : sub/yam: md5 = d6b610651c0c967f94aea44fc3efb28e OK
2025/05/11 01:33:38 INFO  : sub/yam: Copied (new)
2025/05/11 01:33:38 DEBUG : Waiting for deletions to finish
2025/05/11 01:33:38 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:33:39 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:33:39 DEBUG : potato: Unchanged skipping
2025/05/11 01:33:40 INFO  : sub: Set directory modification time (using SetModTime)
2025/05/11 01:33:40 DEBUG : Added delayed dir = "sub", newDst=sub
2025/05/11 01:33:40 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Making map for --track-renames
2025/05/11 01:33:40 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Finished making map for --track-renames
2025/05/11 01:33:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:33:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for renames to finish
2025/05/11 01:33:41 INFO  : sub/yam: Moved (server-side) to: yam
2025/05/11 01:33:41 INFO  : yam: Renamed from "sub/yam"
2025/05/11 01:33:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:33:41 DEBUG : Waiting for deletions to finish
2025/05/11 01:33:41 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (8.30s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:33:44 DEBUG : Creating backend with remote "/tmp/rclone3547058176/dir1"
2025/05/11 01:33:44 DEBUG : Creating backend with remote "/tmp/rclone3547058176/dir2"
2025/05/11 01:33:44 DEBUG : Local file system at /tmp/rclone3547058176/dir2: Using server-side directory move
2025/05/11 01:33:44 INFO  : Local file system at /tmp/rclone3547058176/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/05/11 01:33:44 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/05/11 01:33:44 INFO  : file1.txt: Moved (server-side)
2025/05/11 01:33:44 DEBUG : Local file system at /tmp/rclone3547058176/dir2: Waiting for checks to finish
2025/05/11 01:33:44 DEBUG : Local file system at /tmp/rclone3547058176/dir2: Waiting for transfers to finish
--- PASS: TestServerSideMoveLocal (0.44s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:33:45 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/05/11 01:33:45 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/11 01:33:45 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/11 01:33:45 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/05/11 01:33:45 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/05/11 01:33:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:33:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:33:47 DEBUG : sub dir/hello world: md5 = 51584f3f0754a27bfa44f3079a7094ca OK
2025/05/11 01:33:47 INFO  : sub dir/hello world: Copied (new)
2025/05/11 01:33:47 INFO  : sub dir/hello world: Deleted
2025/05/11 01:33:48 DEBUG : nested/sub dir/file: md5 = 041393ebc881262093c38e9d6a2131ba OK
2025/05/11 01:33:48 INFO  : nested/sub dir/file: Copied (new)
2025/05/11 01:33:48 INFO  : nested/sub dir/file: Deleted
2025/05/11 01:33:49 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/05/11 01:33:49 INFO  : nested: Set directory modification time (using DirSetModTime)
2025/05/11 01:33:49 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/05/11 01:33:49 INFO  : sub dir: Removing directory
2025/05/11 01:33:49 INFO  : nested/sub dir: Removing directory
2025/05/11 01:33:49 INFO  : nested: Removing directory
2025/05/11 01:33:49 DEBUG : Local file system at /tmp/rclone3547058176: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:33:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/05/11 01:33:52 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2025/05/11 01:33:53 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (9.45s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:33:54 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/05/11 01:33:54 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/11 01:33:54 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/11 01:33:54 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/05/11 01:33:54 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/05/11 01:33:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:33:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:33:56 DEBUG : sub dir/hello world: md5 = ae4ab3144e2ec967ca020a4de38c2be4 OK
2025/05/11 01:33:56 INFO  : sub dir/hello world: Copied (new)
2025/05/11 01:33:56 INFO  : sub dir/hello world: Deleted
2025/05/11 01:33:58 DEBUG : nested/sub dir/file: md5 = 3e1c431ccff0fd31731a41b8525d404e OK
2025/05/11 01:33:58 INFO  : nested/sub dir/file: Copied (new)
2025/05/11 01:33:58 INFO  : nested/sub dir/file: Deleted
2025/05/11 01:33:58 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/05/11 01:33:59 INFO  : nested: Set directory modification time (using DirSetModTime)
2025/05/11 01:33:59 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:34:01 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/05/11 01:34:02 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2025/05/11 01:34:02 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (9.76s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:34:04 DEBUG : existing: Need to transfer - File not found at Destination
2025/05/11 01:34:04 DEBUG : existing-b: Need to transfer - File not found at Destination
2025/05/11 01:34:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:34:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:34:05 DEBUG : existing: md5 = 8e7172f76160faea6a62723693285a7b OK
2025/05/11 01:34:05 INFO  : existing: Copied (new)
2025/05/11 01:34:05 INFO  : existing: Deleted
2025/05/11 01:34:05 DEBUG : existing-b: md5 = b35add1e019332e8aa417ebdff8de269 OK
2025/05/11 01:34:05 INFO  : existing-b: Copied (new)
2025/05/11 01:34:05 INFO  : existing-b: Deleted
2025/05/11 01:34:06 DEBUG : existing: Destination exists, skipping
2025/05/11 01:34:06 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2025/05/11 01:34:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:34:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:34:06 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (3.85s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:34:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dugiqen4moti"
2025/05/11 01:34:07 DEBUG : Creating backend with remote "TestDrive:crypt/vjqkqc58kj6qtic4scr1ote1lfpt1l9et7035akdvtp8gf2ei140"
2025/05/11 01:34:10 DEBUG : potato2: md5 = b2f0320509b55521c6c3ea90b63120b7 OK
2025/05/11 01:34:11 DEBUG : empty space: md5 = 756bd04087759d6717534f212acf588d OK
2025/05/11 01:34:12 DEBUG : potato3: md5 = 7a5c9590552ec37b2cf8dc58b18055af OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi' -> Encrypted drive 'TestCryptDrive:rclone-test-dugiqen4moti'
2025/05/11 01:34:15 DEBUG : empty space: md5 = 650897f637b38cc57b86e91996eb780e OK
2025/05/11 01:34:16 DEBUG : potato3: md5 = c3ac7c5a00b29e1fd88741fa75a796db OK
2025/05/11 01:34:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dugiqen4moti': Using server-side directory move
2025/05/11 01:34:16 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-dugiqen4moti': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/05/11 01:34:16 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/11 01:34:16 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/05/11 01:34:16 DEBUG : empty space: Unchanged skipping
2025/05/11 01:34:16 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/05/11 01:34:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dugiqen4moti': Waiting for checks to finish
2025/05/11 01:34:17 INFO  : empty space: Deleted
2025/05/11 01:34:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dugiqen4moti': Waiting for transfers to finish
2025/05/11 01:34:17 INFO  : potato3: Deleted
2025/05/11 01:34:17 INFO  : potato2: Moved (server-side)
2025/05/11 01:34:17 INFO  : potato3: Moved (server-side)
2025/05/11 01:34:18 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feweqic3raga"
2025/05/11 01:34:18 DEBUG : Creating backend with remote "TestDrive:crypt/gkbkuhs3vk13fscj08cb5fuin7bf56b8t4o2ejcocvldb37n5hkg"
2025/05/11 01:34:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feweqic3raga': Using server-side directory move
2025/05/11 01:34:20 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-feweqic3raga': Server side directory move succeeded
2025/05/11 01:34:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feweqic3raga': Purge remote
2025/05/11 01:34:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dugiqen4moti': Purge remote
2025/05/11 01:34:21 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (14.06s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:34:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mucikid2have"
2025/05/11 01:34:22 DEBUG : Creating backend with remote "TestDrive:crypt/m1erj2jrgg7rp3h1jhrp63thbc8vu8c62f1mmade008d01pqfst0"
2025/05/11 01:34:24 DEBUG : potato2: md5 = a7c54b9b776a035834b58bef5670a729 OK
2025/05/11 01:34:25 DEBUG : empty space: md5 = 74fe852ad03c14aed44de48d31b0d035 OK
2025/05/11 01:34:26 DEBUG : potato3: md5 = d2e9ef808ee3bd197e3f0aded81807af OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi' -> Encrypted drive 'TestCryptDrive:rclone-test-mucikid2have'
2025/05/11 01:34:29 DEBUG : empty space: md5 = 04c3308c693ab8e9a1191048e0681003 OK
2025/05/11 01:34:30 DEBUG : potato3: md5 = dcc9f2b9bab6507fa15f439b31e79ddf OK
2025/05/11 01:34:30 DEBUG : empty space: Excluded (Size Filter)
2025/05/11 01:34:30 DEBUG : empty space: Excluded
2025/05/11 01:34:30 DEBUG : empty space: Excluded (Size Filter)
2025/05/11 01:34:30 DEBUG : empty space: Excluded
2025/05/11 01:34:30 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/11 01:34:30 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/05/11 01:34:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mucikid2have': Waiting for checks to finish
2025/05/11 01:34:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mucikid2have': Waiting for transfers to finish
2025/05/11 01:34:31 INFO  : potato3: Deleted
2025/05/11 01:34:31 INFO  : potato2: Moved (server-side)
2025/05/11 01:34:31 INFO  : potato3: Moved (server-side)
2025/05/11 01:34:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bokicay5buqa"
2025/05/11 01:34:32 DEBUG : Creating backend with remote "TestDrive:crypt/feuo1cg9fmudd04keas6l61gnf914anuiv3v8pblj2grqg3tqr3g"
2025/05/11 01:34:33 DEBUG : empty space: Excluded (Size Filter)
2025/05/11 01:34:33 DEBUG : empty space: Excluded
2025/05/11 01:34:33 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/11 01:34:33 DEBUG : potato3: Need to transfer - File not found at Destination
2025/05/11 01:34:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bokicay5buqa': Waiting for checks to finish
2025/05/11 01:34:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bokicay5buqa': Waiting for transfers to finish
2025/05/11 01:34:34 INFO  : potato2: Moved (server-side)
2025/05/11 01:34:34 INFO  : potato3: Moved (server-side)
2025/05/11 01:34:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bokicay5buqa': Purge remote
2025/05/11 01:34:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mucikid2have': Purge remote
--- PASS: TestServerSideMoveWithFilter (15.14s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:34:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gidobug3ziqo"
2025/05/11 01:34:37 DEBUG : Creating backend with remote "TestDrive:crypt/5qm4rkldo3s9v4moetrho8i7ql36khau622boqtjrb519am0l040"
2025/05/11 01:34:39 DEBUG : potato2: md5 = 3c892ce9a8b96c43b85c84d2fe14ea3f OK
2025/05/11 01:34:40 DEBUG : empty space: md5 = a3a88aeafeb67e0ee315da420970e527 OK
2025/05/11 01:34:41 DEBUG : potato3: md5 = edb5df8bcab96ff57eb09c5c38aba591 OK
2025/05/11 01:34:41 INFO  : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi' -> Encrypted drive 'TestCryptDrive:rclone-test-gidobug3ziqo'
2025/05/11 01:34:45 DEBUG : empty space: md5 = 0db2376d63abae49a1fc90e7a4948abc OK
2025/05/11 01:34:46 DEBUG : potato3: md5 = 5075924f8348bd82589f2295dc0bfd5d OK
2025/05/11 01:34:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gidobug3ziqo': Using server-side directory move
2025/05/11 01:34:46 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gidobug3ziqo': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/05/11 01:34:46 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/11 01:34:46 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2025/05/11 01:34:46 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/05/11 01:34:46 DEBUG : empty space: Unchanged skipping
2025/05/11 01:34:46 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/05/11 01:34:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gidobug3ziqo': Waiting for checks to finish
2025/05/11 01:34:47 INFO  : empty space: Deleted
2025/05/11 01:34:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gidobug3ziqo': Waiting for transfers to finish
2025/05/11 01:34:47 INFO  : potato3: Deleted
2025/05/11 01:34:47 INFO  : potato2: Moved (server-side)
2025/05/11 01:34:47 INFO  : potato3: Moved (server-side)
2025/05/11 01:34:47 INFO  : tomatoDir: Removing directory
2025/05/11 01:34:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': deleted 1 directories
2025/05/11 01:34:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-ruputuy8piju"
2025/05/11 01:34:49 DEBUG : Creating backend with remote "TestDrive:crypt/lc9uq1nibam53jg0lsgq66b26oqh0a1ber5rpd4g1sansouqheag"
2025/05/11 01:34:50 INFO  : tomatoDir: Making directory
2025/05/11 01:34:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ruputuy8piju': Using server-side directory move
2025/05/11 01:34:51 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-ruputuy8piju': Server side directory move succeeded
2025/05/11 01:34:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ruputuy8piju': Purge remote
2025/05/11 01:34:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gidobug3ziqo': Purge remote
2025/05/11 01:34:53 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (16.96s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.44s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:34:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/rclone-sync-test"
2025/05/11 01:34:54 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncOverlap (3.57s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:34:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/rclone-sync-test"
2025/05/11 01:34:58 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2025/05/11 01:35:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/rclone-sync-test-include/layer2"
2025/05/11 01:35:00 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2025/05/11 01:35:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/rclone-sync-test-ignore-file"
2025/05/11 01:35:03 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2025/05/11 01:35:06 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 3b0cc6b680ced36fc8cb8e86f2a4dc83 OK
2025/05/11 01:35:07 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/05/11 01:35:08 DEBUG : rclone-sync-test: Excluded
2025/05/11 01:35:08 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/05/11 01:35:08 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/05/11 01:35:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/rclone-sync-test': Waiting for checks to finish
2025/05/11 01:35:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/rclone-sync-test': Waiting for transfers to finish
2025/05/11 01:35:08 DEBUG : Waiting for deletions to finish
2025/05/11 01:35:08 INFO  : There was nothing to transfer
2025/05/11 01:35:09 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/05/11 01:35:09 DEBUG : rclone-sync-test: Excluded
2025/05/11 01:35:10 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/05/11 01:35:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:35:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:35:10 DEBUG : Waiting for deletions to finish
2025/05/11 01:35:10 INFO  : rclone-sync-test-include: Removing directory
2025/05/11 01:35:10 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/05/11 01:35:10 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2025/05/11 01:35:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': failed to delete 1 directories
2025/05/11 01:35:10 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:35:10 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/05/11 01:35:11 DEBUG : rclone-sync-test: Excluded
2025/05/11 01:35:11 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/05/11 01:35:11 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/05/11 01:35:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/rclone-sync-test-include/layer2': Waiting for checks to finish
2025/05/11 01:35:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/rclone-sync-test-include/layer2': Waiting for transfers to finish
2025/05/11 01:35:11 DEBUG : Waiting for deletions to finish
2025/05/11 01:35:11 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:35:12 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/05/11 01:35:12 DEBUG : rclone-sync-test: Excluded
2025/05/11 01:35:13 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/05/11 01:35:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:35:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:35:13 DEBUG : Waiting for deletions to finish
2025/05/11 01:35:13 INFO  : rclone-sync-test-include: Removing directory
2025/05/11 01:35:13 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/05/11 01:35:13 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2025/05/11 01:35:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': failed to delete 1 directories
2025/05/11 01:35:13 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:35:14 DEBUG : : Excluded
2025/05/11 01:35:14 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/05/11 01:35:14 DEBUG : rclone-sync-test: Excluded
2025/05/11 01:35:14 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/05/11 01:35:15 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/05/11 01:35:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/rclone-sync-test-ignore-file': Waiting for checks to finish
2025/05/11 01:35:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/rclone-sync-test-ignore-file': Waiting for transfers to finish
2025/05/11 01:35:15 DEBUG : Waiting for deletions to finish
2025/05/11 01:35:15 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:35:17 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/05/11 01:35:17 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (28.09s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:35:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/dst"
2025/05/11 01:35:26 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/31u3jie661vd5p8j7rtc3hgbh0"
2025/05/11 01:35:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/CompareDest"
2025/05/11 01:35:27 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/gveqi14airsml4bgu7krj116o8"
2025/05/11 01:35:29 DEBUG : one: Need to transfer - File not found at Destination
2025/05/11 01:35:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for checks to finish
2025/05/11 01:35:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for transfers to finish
2025/05/11 01:35:31 DEBUG : one: md5 = 73ed2443c150eed4d4c952c0f0669479 OK
2025/05/11 01:35:31 INFO  : one: Copied (new)
2025/05/11 01:35:31 DEBUG : Waiting for deletions to finish
2025/05/11 01:35:32 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/05/11 01:35:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for checks to finish
2025/05/11 01:35:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for transfers to finish
2025/05/11 01:35:34 DEBUG : one: md5 = bad00be7b685c7f490ce034ce867d33c OK
2025/05/11 01:35:34 INFO  : one: Copied (replaced existing)
2025/05/11 01:35:34 DEBUG : Waiting for deletions to finish
2025/05/11 01:35:35 DEBUG : dst/one: md5 = 8e27fecf6de18c64b7e2f795b35da50b OK
2025/05/11 01:35:37 DEBUG : CompareDest/one: md5 = 3328c9565a32f99ff3f713321d97e5ba OK
2025/05/11 01:35:38 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/05/11 01:35:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for checks to finish
2025/05/11 01:35:39 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:35:39 DEBUG : one: Destination found in --compare-dest, skipping
2025/05/11 01:35:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for transfers to finish
2025/05/11 01:35:39 DEBUG : Waiting for deletions to finish
2025/05/11 01:35:39 INFO  : There was nothing to transfer
2025/05/11 01:35:40 DEBUG : CompareDest/two: md5 = ab535574bafb44292b21df41cb9e76c0 OK
2025/05/11 01:35:41 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/05/11 01:35:41 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:35:41 DEBUG : two: Destination found in --compare-dest, skipping
2025/05/11 01:35:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for checks to finish
2025/05/11 01:35:41 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:35:41 DEBUG : one: Destination found in --compare-dest, skipping
2025/05/11 01:35:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for transfers to finish
2025/05/11 01:35:41 DEBUG : Waiting for deletions to finish
2025/05/11 01:35:41 INFO  : There was nothing to transfer
2025/05/11 01:35:42 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/05/11 01:35:42 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:35:42 DEBUG : two: Destination found in --compare-dest, skipping
2025/05/11 01:35:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for checks to finish
2025/05/11 01:35:42 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:35:42 DEBUG : one: Destination found in --compare-dest, skipping
2025/05/11 01:35:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for transfers to finish
2025/05/11 01:35:42 DEBUG : Waiting for deletions to finish
2025/05/11 01:35:42 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2025/05/11 01:35:43 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/05/11 01:35:44 DEBUG : two: Sizes differ (src 5 vs dst 3)
2025/05/11 01:35:44 DEBUG : two: Need to transfer - File not found at Destination
2025/05/11 01:35:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for checks to finish
2025/05/11 01:35:44 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:35:44 DEBUG : one: Destination found in --compare-dest, skipping
2025/05/11 01:35:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for transfers to finish
2025/05/11 01:35:45 DEBUG : two: md5 = b6f5c1bfbd998bc059ad7bf23ae014e2 OK
2025/05/11 01:35:45 INFO  : two: Copied (new)
2025/05/11 01:35:45 DEBUG : Waiting for deletions to finish
2025/05/11 01:35:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/05/11 01:35:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/11 01:35:48 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/11 01:35:48 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncCompareDest (23.21s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:35:51 DEBUG : pre-dest1/1: md5 = 11016ed61eeeec30af062a8fa828db0e OK
2025/05/11 01:35:53 DEBUG : pre-dest2/2: md5 = 73a489c7d86621c6eecd288cf3691ed8 OK
2025/05/11 01:35:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/dest"
2025/05/11 01:35:53 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/rg03c1jvnehrrc617i0lnqjddc"
2025/05/11 01:35:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/pre-dest1"
2025/05/11 01:35:55 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/bbnblvh6k061ssopqrp18kd7gc"
2025/05/11 01:35:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/pre-dest2"
2025/05/11 01:35:56 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/dgicm1h6b5ejvlltm8eeif0bnk"
2025/05/11 01:35:57 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:35:57 DEBUG : 1: Destination found in --compare-dest, skipping
2025/05/11 01:35:57 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:35:57 DEBUG : 2: Destination found in --compare-dest, skipping
2025/05/11 01:35:58 DEBUG : 3: Need to transfer - File not found at Destination
2025/05/11 01:35:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dest': Waiting for checks to finish
2025/05/11 01:35:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dest': Waiting for transfers to finish
2025/05/11 01:36:00 DEBUG : 3: md5 = 72e2bfdd9ead155ea8b0571fb7ba6272 OK
2025/05/11 01:36:00 INFO  : 3: Copied (new)
2025/05/11 01:36:00 DEBUG : Waiting for deletions to finish
2025/05/11 01:36:02 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2025/05/11 01:36:03 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2025/05/11 01:36:04 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (15.27s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:36:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/dst"
2025/05/11 01:36:04 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/31u3jie661vd5p8j7rtc3hgbh0"
2025/05/11 01:36:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/CopyDest"
2025/05/11 01:36:06 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/d09o6po3f7bm6ce32vdgs8h9ls"
2025/05/11 01:36:07 DEBUG : one: Need to transfer - File not found at Destination
2025/05/11 01:36:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for checks to finish
2025/05/11 01:36:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for transfers to finish
2025/05/11 01:36:09 DEBUG : one: md5 = 697e8fdb4a9823e23c73506e0c7d692f OK
2025/05/11 01:36:09 INFO  : one: Copied (new)
2025/05/11 01:36:09 DEBUG : Waiting for deletions to finish
2025/05/11 01:36:11 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/05/11 01:36:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for checks to finish
2025/05/11 01:36:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for transfers to finish
2025/05/11 01:36:12 DEBUG : one: md5 = d44f7868ae410de67843c824d3535104 OK
2025/05/11 01:36:12 INFO  : one: Copied (replaced existing)
2025/05/11 01:36:12 DEBUG : Waiting for deletions to finish
2025/05/11 01:36:14 DEBUG : dst/one: md5 = 7a79310951baa7e47f79ee7b576d8920 OK
2025/05/11 01:36:16 DEBUG : CopyDest/one: md5 = 9f1a69bca7597064ed622f0ea47ab0aa OK
2025/05/11 01:36:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/BackupDir"
2025/05/11 01:36:16 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/s6dbk3lfi7c9kfvo6j7bla9m0g"
2025/05/11 01:36:18 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/05/11 01:36:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for checks to finish
2025/05/11 01:36:18 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:36:18 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/05/11 01:36:20 INFO  : one: Moved (server-side)
2025/05/11 01:36:21 INFO  : one: Copied (server-side copy)
2025/05/11 01:36:21 DEBUG : one: Destination found in --copy-dest, using server-side copy
2025/05/11 01:36:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for transfers to finish
2025/05/11 01:36:21 DEBUG : Waiting for deletions to finish
2025/05/11 01:36:23 DEBUG : CopyDest/two: md5 = 5b8b68852b98bfc602793ea5c2ecc438 OK
2025/05/11 01:36:23 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:36:23 DEBUG : one: Unchanged skipping
2025/05/11 01:36:24 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:36:25 INFO  : two: Copied (server-side copy)
2025/05/11 01:36:25 DEBUG : two: Destination found in --copy-dest, using server-side copy
2025/05/11 01:36:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for checks to finish
2025/05/11 01:36:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for transfers to finish
2025/05/11 01:36:25 DEBUG : Waiting for deletions to finish
2025/05/11 01:36:25 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:36:25 DEBUG : one: Unchanged skipping
2025/05/11 01:36:25 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:36:25 DEBUG : two: Unchanged skipping
2025/05/11 01:36:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for checks to finish
2025/05/11 01:36:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for transfers to finish
2025/05/11 01:36:25 DEBUG : Waiting for deletions to finish
2025/05/11 01:36:25 INFO  : There was nothing to transfer
2025/05/11 01:36:27 DEBUG : CopyDest/three: md5 = 1649ee31b3da3f243316d5a188660ae3 OK
2025/05/11 01:36:28 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:36:28 DEBUG : one: Unchanged skipping
2025/05/11 01:36:28 DEBUG : three: Sizes differ (src 7 vs dst 5)
2025/05/11 01:36:28 DEBUG : three: Destination not found in --copy-dest
2025/05/11 01:36:28 DEBUG : three: Need to transfer - File not found at Destination
2025/05/11 01:36:28 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/11 01:36:28 DEBUG : two: Unchanged skipping
2025/05/11 01:36:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for checks to finish
2025/05/11 01:36:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for transfers to finish
2025/05/11 01:36:29 DEBUG : three: md5 = ba848d7dd28064a1f8825f16cca38cf3 OK
2025/05/11 01:36:29 INFO  : three: Copied (new)
2025/05/11 01:36:29 DEBUG : Waiting for deletions to finish
2025/05/11 01:36:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2025/05/11 01:36:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/05/11 01:36:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/11 01:36:34 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/05/11 01:36:34 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/11 01:36:34 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2025/05/11 01:36:35 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (31.77s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:36:38 DEBUG : dst/one: md5 = edf5ccb33f5bd7b393da894af18241f3 OK
2025/05/11 01:36:39 DEBUG : dst/two: md5 = b4dd1f2ed1152d4d040bf2c3cdf34607 OK
2025/05/11 01:36:41 DEBUG : dst/three.txt: md5 = f41a11457cda12cdc6f40eb883c058a1 OK
2025/05/11 01:36:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/dst"
2025/05/11 01:36:41 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/31u3jie661vd5p8j7rtc3hgbh0"
2025/05/11 01:36:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/backup"
2025/05/11 01:36:42 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/1nrff024r7pq65ecp72fc28jb0"
2025/05/11 01:36:44 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/05/11 01:36:44 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:36:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for checks to finish
2025/05/11 01:36:44 DEBUG : two: Unchanged skipping
2025/05/11 01:36:45 INFO  : one: Moved (server-side)
2025/05/11 01:36:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for transfers to finish
2025/05/11 01:36:47 DEBUG : one: md5 = eaff31b029800fc381ba1cfafb525de6 OK
2025/05/11 01:36:47 INFO  : one: Copied (new)
2025/05/11 01:36:47 DEBUG : Waiting for deletions to finish
2025/05/11 01:36:47 INFO  : three.txt: Moved (server-side)
2025/05/11 01:36:47 INFO  : three.txt: Moved into backup dir
2025/05/11 01:36:50 DEBUG : dst/three.txt: md5 = 1ad72101e4d9b28ea7259cf6e86188ba OK
2025/05/11 01:36:51 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/05/11 01:36:51 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:36:51 DEBUG : two: Unchanged skipping
2025/05/11 01:36:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for checks to finish
2025/05/11 01:36:51 INFO  : one: Deleted
2025/05/11 01:36:52 INFO  : one: Moved (server-side)
2025/05/11 01:36:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for transfers to finish
2025/05/11 01:36:53 DEBUG : one: md5 = c0bf0ba9fb0450f15ff46788a412c022 OK
2025/05/11 01:36:53 INFO  : one: Copied (new)
2025/05/11 01:36:53 DEBUG : Waiting for deletions to finish
2025/05/11 01:36:54 INFO  : three.txt: Deleted
2025/05/11 01:36:54 INFO  : three.txt: Moved (server-side)
2025/05/11 01:36:54 INFO  : three.txt: Moved into backup dir
2025/05/11 01:36:57 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/11 01:36:57 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/05/11 01:36:58 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/05/11 01:36:58 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/11 01:36:58 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/11 01:36:58 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
--- PASS: TestSyncBackupDir (22.96s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:37:01 DEBUG : dst/one: md5 = b489af7a3b9786e85b3e0f579ed53adf OK
2025/05/11 01:37:02 DEBUG : dst/two: md5 = f1638955b3e601994b5956311ca84ce7 OK
2025/05/11 01:37:04 DEBUG : dst/three.txt: md5 = 4dc7d2721098b25fb37ec22dacfe120e OK
2025/05/11 01:37:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/dst"
2025/05/11 01:37:04 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/31u3jie661vd5p8j7rtc3hgbh0"
2025/05/11 01:37:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/backup"
2025/05/11 01:37:05 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/1nrff024r7pq65ecp72fc28jb0"
2025/05/11 01:37:07 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/05/11 01:37:07 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:37:07 DEBUG : two: Unchanged skipping
2025/05/11 01:37:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for checks to finish
2025/05/11 01:37:08 INFO  : one: Moved (server-side) to: one.bak
2025/05/11 01:37:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for transfers to finish
2025/05/11 01:37:10 DEBUG : one: md5 = 62e0fb2914cc91fd155fc6879078e2aa OK
2025/05/11 01:37:10 INFO  : one: Copied (new)
2025/05/11 01:37:10 DEBUG : Waiting for deletions to finish
2025/05/11 01:37:11 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/05/11 01:37:11 INFO  : three.txt: Moved into backup dir
2025/05/11 01:37:12 DEBUG : dst/three.txt: md5 = 546ee6aad8d12af72c3d34a87efe17f1 OK
2025/05/11 01:37:13 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/05/11 01:37:13 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:37:13 DEBUG : two: Unchanged skipping
2025/05/11 01:37:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for checks to finish
2025/05/11 01:37:14 INFO  : one.bak: Deleted
2025/05/11 01:37:14 INFO  : one: Moved (server-side) to: one.bak
2025/05/11 01:37:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for transfers to finish
2025/05/11 01:37:16 DEBUG : one: md5 = 7834647529ae12055b535a13e2c1c8ba OK
2025/05/11 01:37:16 INFO  : one: Copied (new)
2025/05/11 01:37:16 DEBUG : Waiting for deletions to finish
2025/05/11 01:37:16 INFO  : three.txt.bak: Deleted
2025/05/11 01:37:17 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/05/11 01:37:17 INFO  : three.txt: Moved into backup dir
2025/05/11 01:37:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/11 01:37:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/05/11 01:37:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/05/11 01:37:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/05/11 01:37:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/05/11 01:37:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncBackupDirWithSuffix (22.54s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:37:24 DEBUG : dst/one: md5 = 655edf75c6ab3ba3a4a92b5e780d4fef OK
2025/05/11 01:37:25 DEBUG : dst/two: md5 = baed254716a20aa7f66f79726c0d9ec1 OK
2025/05/11 01:37:26 DEBUG : dst/three.txt: md5 = 9210c95f3403cfbeef77a5c9f99cc853 OK
2025/05/11 01:37:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/dst"
2025/05/11 01:37:27 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/31u3jie661vd5p8j7rtc3hgbh0"
2025/05/11 01:37:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/backup"
2025/05/11 01:37:28 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/1nrff024r7pq65ecp72fc28jb0"
2025/05/11 01:37:30 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/05/11 01:37:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for checks to finish
2025/05/11 01:37:30 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:37:30 DEBUG : two: Unchanged skipping
2025/05/11 01:37:31 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/05/11 01:37:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for transfers to finish
2025/05/11 01:37:32 DEBUG : one: md5 = 4d1cb97c4b5c83ac27b456c1f6c6cc42 OK
2025/05/11 01:37:32 INFO  : one: Copied (new)
2025/05/11 01:37:32 DEBUG : Waiting for deletions to finish
2025/05/11 01:37:33 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/05/11 01:37:33 INFO  : three.txt: Moved into backup dir
2025/05/11 01:37:35 DEBUG : dst/three.txt: md5 = ca9ff98949ca168a64cf638f9026c943 OK
2025/05/11 01:37:36 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/05/11 01:37:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for checks to finish
2025/05/11 01:37:36 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:37:36 DEBUG : two: Unchanged skipping
2025/05/11 01:37:36 INFO  : one-2019-01-01: Deleted
2025/05/11 01:37:37 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/05/11 01:37:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for transfers to finish
2025/05/11 01:37:38 DEBUG : one: md5 = e399a4e2f135a1325f6e13428747b489 OK
2025/05/11 01:37:38 INFO  : one: Copied (new)
2025/05/11 01:37:38 DEBUG : Waiting for deletions to finish
2025/05/11 01:37:39 INFO  : three-2019-01-01.txt: Deleted
2025/05/11 01:37:39 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/05/11 01:37:39 INFO  : three.txt: Moved into backup dir
2025/05/11 01:37:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/11 01:37:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/05/11 01:37:43 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/05/11 01:37:43 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/05/11 01:37:43 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/05/11 01:37:43 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (22.14s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:37:46 DEBUG : dst/one: md5 = 52a5028c4de9dfb49257e5ca22fcccce OK
2025/05/11 01:37:47 DEBUG : dst/two: md5 = a82ca1c126635f2c69f5ce0fc594062a OK
2025/05/11 01:37:48 DEBUG : dst/three.txt: md5 = fb0337ff8526f00b784d69806bd6c849 OK
2025/05/11 01:37:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/dst"
2025/05/11 01:37:49 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/31u3jie661vd5p8j7rtc3hgbh0"
2025/05/11 01:37:50 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/05/11 01:37:50 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:37:50 DEBUG : two: Unchanged skipping
2025/05/11 01:37:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for checks to finish
2025/05/11 01:37:50 INFO  : one: Moved (server-side) to: one.bak
2025/05/11 01:37:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for transfers to finish
2025/05/11 01:37:52 DEBUG : one: md5 = 28d3e6ff5352445a003a0ce698fd5ca0 OK
2025/05/11 01:37:52 INFO  : one: Copied (new)
2025/05/11 01:37:52 DEBUG : Waiting for deletions to finish
2025/05/11 01:37:52 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/05/11 01:37:52 INFO  : three.txt: Moved into backup dir
2025/05/11 01:37:54 DEBUG : dst/three.txt: md5 = de83835070548d6f45f4cee25439ed4b OK
2025/05/11 01:37:55 DEBUG : one.bak: Excluded (Path Filter)
2025/05/11 01:37:55 DEBUG : one.bak: Excluded
2025/05/11 01:37:55 DEBUG : three.txt.bak: Excluded (Path Filter)
2025/05/11 01:37:55 DEBUG : three.txt.bak: Excluded
2025/05/11 01:37:55 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/05/11 01:37:55 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:37:55 DEBUG : two: Unchanged skipping
2025/05/11 01:37:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for checks to finish
2025/05/11 01:37:55 INFO  : one.bak: Deleted
2025/05/11 01:37:56 INFO  : one: Moved (server-side) to: one.bak
2025/05/11 01:37:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi/dst': Waiting for transfers to finish
2025/05/11 01:37:57 DEBUG : one: md5 = d9a8543b28f5204a6b38be75a4e5393d OK
2025/05/11 01:37:57 INFO  : one: Copied (new)
2025/05/11 01:37:57 DEBUG : Waiting for deletions to finish
2025/05/11 01:37:58 INFO  : three.txt.bak: Deleted
2025/05/11 01:37:58 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/05/11 01:37:58 INFO  : three.txt: Moved into backup dir
2025/05/11 01:38:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/11 01:38:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/05/11 01:38:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/05/11 01:38:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/05/11 01:38:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/05/11 01:38:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncBackupDirSuffixOnly (18.01s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:38:03 DEBUG : dst/one: md5 = 76a143cfefc7cb260e3df5b84278bb9b OK
2025/05/11 01:38:05 DEBUG : dst/two: md5 = 47d3c669e8a829f5732b2cb7f1ff4ff2 OK
2025/05/11 01:38:06 DEBUG : dst/three.txt: md5 = 6a8f6ed6659561f7894556a81a4f3c6c OK
2025/05/11 01:38:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/dst"
2025/05/11 01:38:07 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/31u3jie661vd5p8j7rtc3hgbh0"
2025/05/11 01:38:08 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/05/11 01:38:08 INFO  : one: Moved (server-side) to: one.bak
2025/05/11 01:38:10 DEBUG : one: md5 = a344b26ad2753f75e7e71b15e2d64ff3 OK
2025/05/11 01:38:10 INFO  : one: Copied (new)
2025/05/11 01:38:10 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:38:10 DEBUG : two: Unchanged skipping
2025/05/11 01:38:10 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/05/11 01:38:11 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/05/11 01:38:12 DEBUG : three.txt: md5 = 2fb8d3da755ce7a81e4c3f9fd19f6cc6 OK
2025/05/11 01:38:12 INFO  : three.txt: Copied (new)
2025/05/11 01:38:13 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/05/11 01:38:14 INFO  : one.bak: Deleted
2025/05/11 01:38:14 INFO  : one: Moved (server-side) to: one.bak
2025/05/11 01:38:15 DEBUG : one: md5 = 4fb1b59724dbbdd1b8a0edff4a19f0eb OK
2025/05/11 01:38:15 INFO  : one: Copied (new)
2025/05/11 01:38:16 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:38:16 DEBUG : two: Unchanged skipping
2025/05/11 01:38:16 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/05/11 01:38:17 INFO  : three.txt.bak: Deleted
2025/05/11 01:38:17 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/05/11 01:38:18 DEBUG : three.txt: md5 = 5722d1ed77366f139ffb85ec4384f0ab OK
2025/05/11 01:38:18 INFO  : three.txt: Copied (new)
2025/05/11 01:38:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/05/11 01:38:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/11 01:38:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/05/11 01:38:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/05/11 01:38:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/05/11 01:38:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/05/11 01:38:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncSuffix (20.61s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:38:24 DEBUG : dst/one: md5 = 805642abb70baa71a128d6e004d428a4 OK
2025/05/11 01:38:25 DEBUG : dst/two: md5 = a3cd32fafad361a91ac81fd69cfa502f OK
2025/05/11 01:38:27 DEBUG : dst/three.txt: md5 = dceb803c67f05e0a3df06368fb3c17d0 OK
2025/05/11 01:38:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuvowuq0xomi/dst"
2025/05/11 01:38:27 DEBUG : Creating backend with remote "TestDrive:crypt/icbsvlu07r159h84kg2j5kum4d8b3an7veu3udf0seg0fji82bpg/31u3jie661vd5p8j7rtc3hgbh0"
2025/05/11 01:38:28 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/05/11 01:38:29 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/05/11 01:38:30 DEBUG : one: md5 = 0a490bd1bd580e3a1e8b0ab8c79bf02b OK
2025/05/11 01:38:30 INFO  : one: Copied (new)
2025/05/11 01:38:30 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:38:30 DEBUG : two: Unchanged skipping
2025/05/11 01:38:30 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/05/11 01:38:31 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/05/11 01:38:32 DEBUG : three.txt: md5 = 6307c1134141fc66a59af1939ee73c23 OK
2025/05/11 01:38:32 INFO  : three.txt: Copied (new)
2025/05/11 01:38:34 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/05/11 01:38:34 INFO  : one-2019-01-01: Deleted
2025/05/11 01:38:35 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/05/11 01:38:36 DEBUG : one: md5 = ddbe6753c7fc9e7ad21ae722d28d2ab6 OK
2025/05/11 01:38:36 INFO  : one: Copied (new)
2025/05/11 01:38:36 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:38:36 DEBUG : two: Unchanged skipping
2025/05/11 01:38:37 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/05/11 01:38:37 INFO  : three-2019-01-01.txt: Deleted
2025/05/11 01:38:38 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/05/11 01:38:39 DEBUG : three.txt: md5 = 4861c3251f8b91a89a0e0852bd2ece7f OK
2025/05/11 01:38:39 INFO  : three.txt: Copied (new)
2025/05/11 01:38:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/11 01:38:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/05/11 01:38:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/05/11 01:38:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/05/11 01:38:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/05/11 01:38:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/05/11 01:38:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncSuffixKeepExtension (20.65s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:38:44 DEBUG : Testêé: md5 = dc9091c849b46d02bbebea0d36cdf3d4 OK
2025/05/11 01:38:45 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2025/05/11 01:38:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:38:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:38:46 DEBUG : Testêé: md5 = bf6d225c2354cdd9d8fd50ab9e9b50da OK
2025/05/11 01:38:46 INFO  : Testêé: Copied (replaced existing) to: Testêé
2025/05/11 01:38:46 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (4.03s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:38:47 DEBUG : existing: Need to transfer - File not found at Destination
2025/05/11 01:38:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:38:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:38:49 DEBUG : existing: md5 = 91eabd356ae10c7832061be9edff3db8 OK
2025/05/11 01:38:49 INFO  : existing: Copied (new)
2025/05/11 01:38:49 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:38:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:38:49 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2025/05/11 01:38:49 ERROR : existing: Source and destination exist but do not match: immutable file modified
2025/05/11 01:38:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:38:49 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': not deleting files as there were IO errors
2025/05/11 01:38:49 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncImmutable (4.61s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:38:53 DEBUG : EXISTING: md5 = cd18a1659db9d221d7807349dddd6474 OK
2025/05/11 01:38:53 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:38:53 DEBUG : existing: Unchanged skipping
2025/05/11 01:38:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:38:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:38:53 DEBUG : Waiting for deletions to finish
2025/05/11 01:38:53 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (2.87s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    sync_test.go:2635: Skipping test as local or remote are case-sensitive
--- SKIP: TestFixCase (0.45s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", 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-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", 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-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.27s)
    --- SKIP: TestMaxTransfer/Hard (0.42s)
    --- SKIP: TestMaxTransfer/Soft (0.42s)
    --- SKIP: TestMaxTransfer/Cautious (0.43s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:38:57 DEBUG : both0: md5 = e9029147e3af4201d58618e17a28d84f OK
2025/05/11 01:38:59 DEBUG : only0: md5 = f7524023ad48a81c9bd07b00bc55c6a2 OK
2025/05/11 01:39:00 DEBUG : both1: md5 = 03fdb95a280681e5b0bf1b76d399939b OK
2025/05/11 01:39:01 DEBUG : only1: md5 = f8f4336379b0510c102cd50bfc185f1b OK
2025/05/11 01:39:02 DEBUG : both2: md5 = 81d393e19de3f6cff28449218f736c86 OK
2025/05/11 01:39:04 DEBUG : only2: md5 = 8382c2a4deb52dbbeb8fcc1749f98ece OK
2025/05/11 01:39:05 DEBUG : both3: md5 = c54b85a5af3b46513c05c8a9b39347e5 OK
2025/05/11 01:39:06 DEBUG : only3: md5 = ecb9613ebb169972650acacc3644b757 OK
2025/05/11 01:39:08 DEBUG : both4: md5 = c87073401e12f31c3acfdeb3cafdf657 OK
2025/05/11 01:39:09 DEBUG : only4: md5 = 9fcf9dfd10eb418dbe646f9aa6085f9d OK
2025/05/11 01:39:10 DEBUG : both5: md5 = 2db7d6e37787ea7ab487dfffbcc32ffa OK
2025/05/11 01:39:12 DEBUG : only5: md5 = 0cee9bc0dab7572764a33ad87dad0444 OK
2025/05/11 01:39:13 DEBUG : both6: md5 = b8d2f578587fa41d1139030edbf6b02f OK
2025/05/11 01:39:14 DEBUG : only6: md5 = b17533c06a9f33337c8d856e42721b70 OK
2025/05/11 01:39:16 DEBUG : both7: md5 = 0a8db3603e9b288bb0f348fa62891cab OK
2025/05/11 01:39:17 DEBUG : only7: md5 = 20b5adc086c2a1ceccb0bbda3c41b744 OK
2025/05/11 01:39:18 DEBUG : both8: md5 = 226bef5c29fce8418dba456a1043133a OK
2025/05/11 01:39:19 DEBUG : only8: md5 = 023a12055171ed6545109f7a180d81db OK
2025/05/11 01:39:21 DEBUG : both9: md5 = 3a91d1cf35d0ccc82232bce4f75c5735 OK
2025/05/11 01:39:22 DEBUG : only9: md5 = 69591ba38dd335c3f34e933b69fe12b9 OK
2025/05/11 01:39:23 DEBUG : both10: md5 = 10126138f2138cc085bce73947d6fd70 OK
2025/05/11 01:39:25 DEBUG : only10: md5 = 5fcbe9679516e7dee68856eaa353915f OK
2025/05/11 01:39:26 DEBUG : both11: md5 = 1162d2e5df50b4fcc1bb18962df3cbb5 OK
2025/05/11 01:39:27 DEBUG : only11: md5 = 1c20bfa20335c63de3174b00e7ba075e OK
2025/05/11 01:39:29 DEBUG : both12: md5 = d821b834f15f58532daec55b99a93a42 OK
2025/05/11 01:39:30 DEBUG : only12: md5 = 9ceb15ca3dbe0fd52f429441941f16d6 OK
2025/05/11 01:39:31 DEBUG : both13: md5 = a0a3755ed613eb2a387133bc5710de97 OK
2025/05/11 01:39:32 DEBUG : only13: md5 = 4d1a45298e573979fc0bff21ed78401f OK
2025/05/11 01:39:33 DEBUG : both14: md5 = 4465c062531291217a5a0b81679089b2 OK
2025/05/11 01:39:35 DEBUG : only14: md5 = ae3b9aa692adfa6d18fc24e18fb29df8 OK
2025/05/11 01:39:36 DEBUG : both15: md5 = 2f3b2adecdee93a41cdd07caf7dd0244 OK
2025/05/11 01:39:37 DEBUG : only15: md5 = a38c397d81b61d14b9fc6bc7be4d39a3 OK
2025/05/11 01:39:39 DEBUG : both16: md5 = 57bcfb5a7d08ce13a9f1efa67f37777e OK
2025/05/11 01:39:40 DEBUG : only16: md5 = c8ca02742e6f8ef6b28bc73ab6edb016 OK
2025/05/11 01:39:41 DEBUG : both17: md5 = 4ca802094d5f90ae2e02799c05c2cfa4 OK
2025/05/11 01:39:42 DEBUG : only17: md5 = 486455a8ffb835e019d9b84bc62fe701 OK
2025/05/11 01:39:44 DEBUG : both18: md5 = e7939184e874a9255625225253aa9953 OK
2025/05/11 01:39:45 DEBUG : only18: md5 = a9cb5ed3d56d1b696b315b25cb47cae3 OK
2025/05/11 01:39:46 DEBUG : both19: md5 = 40af530a6a57aa17ad78d7e307abb9d1 OK
2025/05/11 01:39:47 DEBUG : only19: md5 = 28f259610030f01605a17f8ed07cbb15 OK
2025/05/11 01:39:48 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:39:48 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:39:48 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:39:48 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:39:48 DEBUG : both1: Unchanged skipping
2025/05/11 01:39:48 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:39:48 DEBUG : both12: Unchanged skipping
2025/05/11 01:39:48 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:39:48 DEBUG : both13: Unchanged skipping
2025/05/11 01:39:48 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:39:48 DEBUG : both14: Unchanged skipping
2025/05/11 01:39:48 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:39:48 DEBUG : both15: Unchanged skipping
2025/05/11 01:39:48 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:39:48 DEBUG : both16: Unchanged skipping
2025/05/11 01:39:48 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:39:48 DEBUG : both17: Unchanged skipping
2025/05/11 01:39:48 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:39:48 DEBUG : both18: Unchanged skipping
2025/05/11 01:39:48 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:39:48 DEBUG : both19: Unchanged skipping
2025/05/11 01:39:48 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:39:48 DEBUG : both2: Unchanged skipping
2025/05/11 01:39:48 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:39:48 DEBUG : both3: Unchanged skipping
2025/05/11 01:39:48 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:39:48 DEBUG : both4: Unchanged skipping
2025/05/11 01:39:48 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:39:48 DEBUG : both5: Unchanged skipping
2025/05/11 01:39:48 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:39:48 DEBUG : both6: Unchanged skipping
2025/05/11 01:39:48 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:39:48 DEBUG : both7: Unchanged skipping
2025/05/11 01:39:48 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:39:48 DEBUG : both8: Unchanged skipping
2025/05/11 01:39:48 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:39:48 DEBUG : both9: Unchanged skipping
2025/05/11 01:39:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:39:48 DEBUG : both10: Unchanged skipping
2025/05/11 01:39:48 DEBUG : both0: Unchanged skipping
2025/05/11 01:39:48 DEBUG : both11: Unchanged skipping
2025/05/11 01:39:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:39:48 DEBUG : Waiting for deletions to finish
2025/05/11 01:39:48 INFO  : only4: Deleted
2025/05/11 01:39:48 INFO  : only2: Deleted
2025/05/11 01:39:48 INFO  : only18: Deleted
2025/05/11 01:39:48 INFO  : only7: Deleted
2025/05/11 01:39:49 INFO  : only13: Deleted
2025/05/11 01:39:49 INFO  : only6: Deleted
2025/05/11 01:39:49 INFO  : only11: Deleted
2025/05/11 01:39:49 INFO  : only16: Deleted
2025/05/11 01:39:49 INFO  : only9: Deleted
2025/05/11 01:39:49 INFO  : only1: Deleted
2025/05/11 01:39:49 INFO  : only3: Deleted
2025/05/11 01:39:49 INFO  : only10: Deleted
2025/05/11 01:39:50 INFO  : only12: Deleted
2025/05/11 01:39:50 INFO  : only19: Deleted
2025/05/11 01:39:50 INFO  : only17: Deleted
2025/05/11 01:39:50 INFO  : only5: Deleted
2025/05/11 01:39:50 INFO  : only8: Deleted
2025/05/11 01:39:50 INFO  : only14: Deleted
2025/05/11 01:39:50 INFO  : only0: Deleted
2025/05/11 01:39:50 INFO  : only15: Deleted
2025/05/11 01:39:50 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (63.69s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:40:01 DEBUG : both0: md5 = 154b0bfe396935d27126aa2e78033e7c OK
2025/05/11 01:40:02 DEBUG : only0: md5 = 19314ebed1a2d4c4a63469fa636d4b54 OK
2025/05/11 01:40:04 DEBUG : both1: md5 = b9234b79bc1b81ebc62e0834f27d9d19 OK
2025/05/11 01:40:05 DEBUG : only1: md5 = b784c828a2866f821faa5f08b6fd3865 OK
2025/05/11 01:40:06 DEBUG : both2: md5 = 34cc5059d5f448f469cca58b1d17d48e OK
2025/05/11 01:40:07 DEBUG : only2: md5 = 3f0f95087e25e957b2f980d67edde9d3 OK
2025/05/11 01:40:09 DEBUG : both3: md5 = b7d97b0e089440219ebaddfe2346cde9 OK
2025/05/11 01:40:10 DEBUG : only3: md5 = 8fd2c6eef5e155c57f73a3d9e99a9b2f OK
2025/05/11 01:40:11 DEBUG : both4: md5 = d6e0863861b696081e96d0112904a1bb OK
2025/05/11 01:40:12 DEBUG : only4: md5 = 414a1ae6069650325f1417809aa30922 OK
2025/05/11 01:40:14 DEBUG : both5: md5 = a7da843b4efb225528d3d8656b3c6cf5 OK
2025/05/11 01:40:15 DEBUG : only5: md5 = 6b3569725e70b9024cc9b5003e6b0a23 OK
2025/05/11 01:40:16 DEBUG : both6: md5 = bb973d46c1df0a20c7159f6b276781a5 OK
2025/05/11 01:40:17 DEBUG : only6: md5 = 3318684d0e1c4d561ed54d7502183b76 OK
2025/05/11 01:40:19 DEBUG : both7: md5 = 3cef534f9be867b4048b4d72a99fe4cd OK
2025/05/11 01:40:20 DEBUG : only7: md5 = d336b6b696a247633d064eafda3111a9 OK
2025/05/11 01:40:21 DEBUG : both8: md5 = 3dc89416b052205c0f8e4e26993da707 OK
2025/05/11 01:40:22 DEBUG : only8: md5 = ccb129bf0dc098f3207b3b3661d08ea1 OK
2025/05/11 01:40:24 DEBUG : both9: md5 = da899fe5325868d7805bdb383c412bfb OK
2025/05/11 01:40:25 DEBUG : only9: md5 = c349bdf4d846ee200cb2b567075738e3 OK
2025/05/11 01:40:26 DEBUG : both10: md5 = f12e33347a52c35c5ecb79da3dfca0c7 OK
2025/05/11 01:40:28 DEBUG : only10: md5 = 06d9eeb803998a2afb3cdc55e7f5d828 OK
2025/05/11 01:40:29 DEBUG : both11: md5 = 6a443ccc6ee36d4a3209c108f9cd1273 OK
2025/05/11 01:40:30 DEBUG : only11: md5 = 87ed28e4d70532744c3af17a08ba9fec OK
2025/05/11 01:40:31 DEBUG : both12: md5 = 9d44df76d3a9da743d44eeac566caa51 OK
2025/05/11 01:40:33 DEBUG : only12: md5 = 3371ade469ccc25599a04c1b7935c984 OK
2025/05/11 01:40:34 DEBUG : both13: md5 = 0e544858794c8123be5edec78e30b30b OK
2025/05/11 01:40:35 DEBUG : only13: md5 = 5ddfb727f9987871d5d2796eb7057b7c OK
2025/05/11 01:40:37 DEBUG : both14: md5 = eabe6aaa21f1bed13220c4ef97be2f25 OK
2025/05/11 01:40:38 DEBUG : only14: md5 = 5cd3a4ce0e680c022987524b48e57560 OK
2025/05/11 01:40:39 DEBUG : both15: md5 = 81fe0aacbaa885c6ca8a3ce836167ecd OK
2025/05/11 01:40:41 DEBUG : only15: md5 = 88fca646b12e1799bbe04f79bec6c303 OK
2025/05/11 01:40:42 DEBUG : both16: md5 = 0a038a0a467fab2c40eedde310af26e4 OK
2025/05/11 01:40:43 DEBUG : only16: md5 = e85e84a749c218c68254497b9a762f4f OK
2025/05/11 01:40:45 DEBUG : both17: md5 = f3d920a28f4f2e8d01b26280a17cf4df OK
2025/05/11 01:40:46 DEBUG : only17: md5 = 2525022879df908b5e4937c6510f9758 OK
2025/05/11 01:40:47 DEBUG : both18: md5 = 4660861ca993d75b1a5c1563cc1794d6 OK
2025/05/11 01:40:49 DEBUG : only18: md5 = 24acc495aae494a4c5ab3fbc2481898e OK
2025/05/11 01:40:50 DEBUG : both19: md5 = 243379d564de5bec9d6bd27d9917335a OK
2025/05/11 01:40:51 DEBUG : only19: md5 = fc185a646db57d69006d8905fbcb3786 OK
2025/05/11 01:40:52 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:40:52 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:40:52 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:40:52 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:40:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for checks to finish
2025/05/11 01:40:52 DEBUG : both1: Unchanged skipping
2025/05/11 01:40:52 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:40:52 DEBUG : both12: Unchanged skipping
2025/05/11 01:40:52 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:40:52 DEBUG : both13: Unchanged skipping
2025/05/11 01:40:52 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:40:52 DEBUG : both14: Unchanged skipping
2025/05/11 01:40:52 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:40:52 DEBUG : both15: Unchanged skipping
2025/05/11 01:40:52 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:40:52 DEBUG : both16: Unchanged skipping
2025/05/11 01:40:52 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:40:52 DEBUG : both0: Unchanged skipping
2025/05/11 01:40:52 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:40:52 DEBUG : both10: Unchanged skipping
2025/05/11 01:40:52 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:40:52 DEBUG : both19: Unchanged skipping
2025/05/11 01:40:52 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:40:52 DEBUG : both2: Unchanged skipping
2025/05/11 01:40:52 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:40:52 DEBUG : both3: Unchanged skipping
2025/05/11 01:40:52 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:40:52 DEBUG : both4: Unchanged skipping
2025/05/11 01:40:52 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:40:52 DEBUG : both5: Unchanged skipping
2025/05/11 01:40:52 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:40:52 DEBUG : both6: Unchanged skipping
2025/05/11 01:40:52 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:40:52 DEBUG : both7: Unchanged skipping
2025/05/11 01:40:52 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:40:52 DEBUG : both8: Unchanged skipping
2025/05/11 01:40:52 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/11 01:40:52 DEBUG : both9: Unchanged skipping
2025/05/11 01:40:52 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2025/05/11 01:40:52 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2025/05/11 01:40:52 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2025/05/11 01:40:52 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2025/05/11 01:40:52 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2025/05/11 01:40:52 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2025/05/11 01:40:52 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2025/05/11 01:40:52 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2025/05/11 01:40:52 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2025/05/11 01:40:52 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2025/05/11 01:40:52 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2025/05/11 01:40:52 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2025/05/11 01:40:52 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2025/05/11 01:40:52 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2025/05/11 01:40:52 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2025/05/11 01:40:52 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2025/05/11 01:40:52 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2025/05/11 01:40:52 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2025/05/11 01:40:52 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2025/05/11 01:40:52 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2025/05/11 01:40:52 DEBUG : both11: Unchanged skipping
2025/05/11 01:40:52 DEBUG : both17: Unchanged skipping
2025/05/11 01:40:52 DEBUG : both18: Unchanged skipping
2025/05/11 01:40:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Waiting for transfers to finish
2025/05/11 01:40:53 DEBUG : only10: md5 = dc5933efc021a5da6b9bf9717de3d0e8 OK
2025/05/11 01:40:53 INFO  : only10: Copied (replaced existing)
2025/05/11 01:40:53 DEBUG : only11: md5 = 4d485066a5fcc8dd729fa4eb4ebea02d OK
2025/05/11 01:40:53 INFO  : only11: Copied (replaced existing)
2025/05/11 01:40:53 DEBUG : only1: md5 = 9ac1f34212a9c97489eac4831f600c18 OK
2025/05/11 01:40:53 INFO  : only1: Copied (replaced existing)
2025/05/11 01:40:53 DEBUG : only0: md5 = 83d11ad3ee2ddfc42d0b4d38cab52ce6 OK
2025/05/11 01:40:53 INFO  : only0: Copied (replaced existing)
2025/05/11 01:40:54 DEBUG : only12: md5 = 5451fd804e7157f7873449884eadc2c7 OK
2025/05/11 01:40:54 INFO  : only12: Copied (replaced existing)
2025/05/11 01:40:54 DEBUG : only14: md5 = 525eae8f7101323560d4d21d362eadf8 OK
2025/05/11 01:40:54 INFO  : only14: Copied (replaced existing)
2025/05/11 01:40:54 DEBUG : only13: md5 = 4d1d907c5b216db64f014ba985a496a1 OK
2025/05/11 01:40:54 INFO  : only13: Copied (replaced existing)
2025/05/11 01:40:54 DEBUG : only15: md5 = 156b9aeaa946eb9c4e87142b5a630f92 OK
2025/05/11 01:40:54 INFO  : only15: Copied (replaced existing)
2025/05/11 01:40:55 DEBUG : only16: md5 = 968b5e680cdfa55d3a25fce0572c0f4f OK
2025/05/11 01:40:55 INFO  : only16: Copied (replaced existing)
2025/05/11 01:40:55 DEBUG : only17: md5 = a49aa27e41d733dc757b8fcbd7fa7812 OK
2025/05/11 01:40:55 INFO  : only17: Copied (replaced existing)
2025/05/11 01:40:55 DEBUG : only18: md5 = a98cc5177105d39504ca43ffcea7f8b0 OK
2025/05/11 01:40:55 INFO  : only18: Copied (replaced existing)
2025/05/11 01:40:55 DEBUG : only19: md5 = 74a633083e1a2155857d5a024da307f5 OK
2025/05/11 01:40:55 INFO  : only19: Copied (replaced existing)
2025/05/11 01:40:56 DEBUG : only2: md5 = 6a2cd9efa1650b5f262d545ce9b0dea8 OK
2025/05/11 01:40:56 INFO  : only2: Copied (replaced existing)
2025/05/11 01:40:56 DEBUG : only4: md5 = 2e05646976491d65d03ffc3e1a16c5d5 OK
2025/05/11 01:40:56 INFO  : only4: Copied (replaced existing)
2025/05/11 01:40:56 DEBUG : only5: md5 = 4e0d79a09e8c6597e3957503d4e8415c OK
2025/05/11 01:40:56 INFO  : only5: Copied (replaced existing)
2025/05/11 01:40:56 DEBUG : only3: md5 = 9544fc1f4c3a0143f5e1a23588f54524 OK
2025/05/11 01:40:56 INFO  : only3: Copied (replaced existing)
2025/05/11 01:40:57 DEBUG : only6: md5 = 406bb8ee8b62f3116faff38ce25e2f37 OK
2025/05/11 01:40:57 INFO  : only6: Copied (replaced existing)
2025/05/11 01:40:57 DEBUG : only9: md5 = 674263360e1d2b10f9834b777e35334c OK
2025/05/11 01:40:57 INFO  : only9: Copied (replaced existing)
2025/05/11 01:40:57 DEBUG : only7: md5 = ac5bc21460704124886b9b3b452918b2 OK
2025/05/11 01:40:57 INFO  : only7: Copied (replaced existing)
2025/05/11 01:40:57 DEBUG : only8: md5 = 1092c8f87c3ea0d25317d195d9cc9c1c OK
2025/05/11 01:40:57 INFO  : only8: Copied (replaced existing)
2025/05/11 01:40:57 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (75.87s)
=== RUN   TestSyncReplaceDirModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:41:16 DEBUG : empty_dir: Making directory with metadata
2025/05/11 01:41:16 INFO  : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/11 01:41:16 DEBUG : empty_on_remote: Making directory with metadata
2025/05/11 01:41:16 INFO  : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/11 01:41:16 DEBUG : empty_on_remote: Making directory with metadata
2025/05/11 01:41:16 INFO  : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:41:21 INFO  : test_dir1: Set directory modification time (using DirSetModTime)
2025/05/11 01:41:21 INFO  : test_dir2: Set directory modification time (using DirSetModTime)
2025/05/11 01:41:21 INFO  : test_dir2/sub_dir: Set directory modification time (using DirSetModTime)
2025/05/11 01:41:21 INFO  : empty_on_remote: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:41:27 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto"
2025/05/11 01:41:28 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8"
2025/05/11 01:41:29 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00"
--- PASS: TestSyncReplaceDirModTime (15.23s)
=== RUN   TestSyncReplaceDirModTimeWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:41:31 DEBUG : empty_dir: Making directory with metadata
2025/05/11 01:41:31 INFO  : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/11 01:41:31 DEBUG : empty_on_remote: Making directory with metadata
2025/05/11 01:41:31 INFO  : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/11 01:41:31 DEBUG : empty_on_remote: Making directory with metadata
2025/05/11 01:41:32 INFO  : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:41:36 INFO  : test_dir1: Set directory modification time (using DirSetModTime)
2025/05/11 01:41:36 INFO  : test_dir2: Set directory modification time (using DirSetModTime)
2025/05/11 01:41:36 INFO  : test_dir2/sub_dir: Set directory modification time (using DirSetModTime)
2025/05/11 01:41:36 INFO  : empty_on_remote: Set directory modification time (using DirSetModTime)
2025/05/11 01:41:36 INFO  : empty_dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:41:43 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto"
2025/05/11 01:41:44 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8"
2025/05/11 01:41:44 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00"
--- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (16.32s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:41:47 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/05/11 01:41:47 DEBUG : sub dir: Making directory with metadata
2025/05/11 01:41:48 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:42:04 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/05/11 01:42:05 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/05/11 01:42:05 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/11 01:42:05 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:42:16 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2025/05/11 01:42:17 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/05/11 01:42:18 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2025/05/11 01:42:19 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2025/05/11 01:42:20 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/05/11 01:42:20 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/05/11 01:42:21 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/05/11 01:42:22 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/05/11 01:42:22 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/05/11 01:42:23 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2025/05/11 01:42:23 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/05/11 01:42:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (38.32s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:42:25 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/05/11 01:42:25 DEBUG : sub dir: Making directory with metadata
2025/05/11 01:42:26 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:42:46 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/05/11 01:42:46 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/05/11 01:42:46 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/11 01:42:46 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi'", Local "Local file system at /tmp/rclone3547058176", Modify Window "1ms"
2025/05/11 01:42:57 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/05/11 01:42:58 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2025/05/11 01:42:59 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2025/05/11 01:42:59 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/05/11 01:43:00 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/05/11 01:43:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/05/11 01:43:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/05/11 01:43:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/05/11 01:43:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2025/05/11 01:43:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/05/11 01:43:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (39.82s)
PASS
2025/05/11 01:43:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuvowuq0xomi': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 14m43.462429706s (try 1/5)