"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5)
2025/03/26 06:12:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova"
2025/03/26 06:12:16 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/03/26 06:12:16 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610"
2025/03/26 06:12:17 DEBUG : Creating backend with remote "/tmp/rclone929948549"
=== RUN   TestPipe
--- PASS: TestPipe (0.00s)
=== RUN   TestPipeConcurrent
--- PASS: TestPipeConcurrent (0.02s)
=== RUN   TestPipeOrderBy
=== RUN   TestPipeOrderBy/#00
=== RUN   TestPipeOrderBy/size
=== RUN   TestPipeOrderBy/name
=== RUN   TestPipeOrderBy/modtime
=== RUN   TestPipeOrderBy/size,ascending
=== RUN   TestPipeOrderBy/name,asc
=== RUN   TestPipeOrderBy/modtime,ascending
=== RUN   TestPipeOrderBy/size,descending
=== RUN   TestPipeOrderBy/name,desc
=== RUN   TestPipeOrderBy/modtime,descending
=== RUN   TestPipeOrderBy/size,mixed,50
=== RUN   TestPipeOrderBy/size,mixed,51
--- PASS: TestPipeOrderBy (0.00s)
    --- PASS: TestPipeOrderBy/#00 (0.00s)
    --- PASS: TestPipeOrderBy/size (0.00s)
    --- PASS: TestPipeOrderBy/name (0.00s)
    --- PASS: TestPipeOrderBy/modtime (0.00s)
    --- PASS: TestPipeOrderBy/size,ascending (0.00s)
    --- PASS: TestPipeOrderBy/name,asc (0.00s)
    --- PASS: TestPipeOrderBy/modtime,ascending (0.00s)
    --- PASS: TestPipeOrderBy/size,descending (0.00s)
    --- PASS: TestPipeOrderBy/name,desc (0.00s)
    --- PASS: TestPipeOrderBy/modtime,descending (0.00s)
    --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s)
    --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s)
=== RUN   TestNewLess
=== RUN   TestNewLess/blankOK
=== RUN   TestNewLess/tooManyParts
=== RUN   TestNewLess/tooManyParts2
=== RUN   TestNewLess/badMixed
=== RUN   TestNewLess/unknownComparison
=== RUN   TestNewLess/unknownSortDirection
=== RUN   TestNewLess/size
=== RUN   TestNewLess/name
=== RUN   TestNewLess/modtime
=== RUN   TestNewLess/size,ascending
=== RUN   TestNewLess/name,asc
=== RUN   TestNewLess/modtime,ascending
=== RUN   TestNewLess/size,descending
=== RUN   TestNewLess/name,desc
=== RUN   TestNewLess/modtime,descending
=== RUN   TestNewLess/modtime,mixed
=== RUN   TestNewLess/modtime,mixed,30
--- PASS: TestNewLess (0.00s)
    --- PASS: TestNewLess/blankOK (0.00s)
    --- PASS: TestNewLess/tooManyParts (0.00s)
    --- PASS: TestNewLess/tooManyParts2 (0.00s)
    --- PASS: TestNewLess/badMixed (0.00s)
    --- PASS: TestNewLess/unknownComparison (0.00s)
    --- PASS: TestNewLess/unknownSortDirection (0.00s)
    --- PASS: TestNewLess/size (0.00s)
    --- PASS: TestNewLess/name (0.00s)
    --- PASS: TestNewLess/modtime (0.00s)
    --- PASS: TestNewLess/size,ascending (0.00s)
    --- PASS: TestNewLess/name,asc (0.00s)
    --- PASS: TestNewLess/modtime,ascending (0.00s)
    --- PASS: TestNewLess/size,descending (0.00s)
    --- PASS: TestNewLess/name,desc (0.00s)
    --- PASS: TestNewLess/modtime,descending (0.00s)
    --- PASS: TestNewLess/modtime,mixed (0.00s)
    --- PASS: TestNewLess/modtime,mixed,30 (0.00s)
=== RUN   TestRcCopy
    rc_test.go:16: Skipping test on non local remote
--- SKIP: TestRcCopy (0.00s)
=== RUN   TestRcMove
    rc_test.go:16: Skipping test on non local remote
--- SKIP: TestRcMove (0.00s)
=== RUN   TestRcSync
    rc_test.go:16: Skipping test on non local remote
--- SKIP: TestRcSync (0.00s)
=== RUN   TestCopyWithDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:12:18 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/03/26 06:12:18 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/03/26 06:12:18 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2025/03/26 06:12:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:12:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:12:18 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (2.24s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:12:19 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/03/26 06:12:19 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/03/26 06:12:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/03/26 06:12:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:12:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:12:22 DEBUG : sub dir/hello world: md5 = d92abe067a0d8218326ff7b9a0e37fa5 OK
2025/03/26 06:12:22 INFO  : sub dir/hello world: Copied (new)
2025/03/26 06:12:22 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:12:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (6.52s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:12:26 DEBUG : metadata sub dir: Making directory with metadata
2025/03/26 06:12:26 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/03/26 06:12:26 DEBUG : empty metadata sub dir: Making directory with metadata
2025/03/26 06:12:26 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/03/26 06:12:26 DEBUG : Local file system at /tmp/rclone929948549: File to upload is small (21 bytes), uploading instead of streaming
2025/03/26 06:12:26 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2025/03/26 06:12:26 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2025/03/26 06:12:26 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2025/03/26 06:12:26 DEBUG : Google drive root 'crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610': Skipping btime metadata as can't update it on an existing file: 2025-03-26T06:12:26.129315899Z
2025/03/26 06:12:27 INFO  : empty metadata sub dir: Updated directory metadata
2025/03/26 06:12:27 DEBUG : Google drive root 'crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610': Skipping btime metadata as can't update it on an existing file: 2025-03-26T06:12:26.129315899Z
2025/03/26 06:12:28 INFO  : metadata sub dir: Updated directory metadata
2025/03/26 06:12:28 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2025/03/26 06:12:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:12:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:12:29 DEBUG : metadata sub dir/hello metadata world: md5 = ab98d7d09c81c0d09bbf15a9e65e274b OK
2025/03/26 06:12:29 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:12:32 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (8.38s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:12:34 DEBUG : metadata sub dir: Making directory with metadata
2025/03/26 06:12:34 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/03/26 06:12:34 DEBUG : empty metadata sub dir: Making directory with metadata
2025/03/26 06:12:34 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/03/26 06:12:34 DEBUG : Local file system at /tmp/rclone929948549: File to upload is small (21 bytes), uploading instead of streaming
2025/03/26 06:12:34 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2025/03/26 06:12:34 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2025/03/26 06:12:34 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2025/03/26 06:12:34 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2025/03/26 06:12:34 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2025/03/26 06:12:34 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2025/03/26 06:12:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:12:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:12:36 DEBUG : metadata sub dir/hello metadata world: md5 = 0f3c5ca65a4643b9637deaf183e0ab09 OK
2025/03/26 06:12:36 INFO  : metadata sub dir/hello metadata world: Copied (new)
2025/03/26 06:12:36 DEBUG : Google drive root 'crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610': Skipping btime metadata as can't update it on an existing file: 2025-03-26T06:12:34.505331149Z
2025/03/26 06:12:37 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:12:40 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (6.91s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:12:41 DEBUG : Creating backend with remote "/non-existing"
2025/03/26 06:12:41 DEBUG : Config file has changed externally - reloading
2025/03/26 06:12:41 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2025/03/26 06:12:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:12:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.14s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:12:42 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/03/26 06:12:42 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/03/26 06:12:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:12:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:12:45 DEBUG : sub dir/hello world: md5 = 66674812e7ec4404a330806607fe12ed OK
2025/03/26 06:12:45 INFO  : sub dir/hello world: Copied (new)
2025/03/26 06:12:45 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:12:47 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (6.35s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:12:48 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Running all checks before starting transfers
2025/03/26 06:12:49 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/03/26 06:12:49 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/03/26 06:12:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:12:49 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Checks finished, now starting transfers
2025/03/26 06:12:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:12:51 DEBUG : sub dir/hello world: md5 = c771ff77877f5002c60233da2579faed OK
2025/03/26 06:12:51 INFO  : sub dir/hello world: Copied (new)
2025/03/26 06:12:51 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:12:53 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (6.00s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:12:54 ERROR : Ignoring --no-traverse with sync
2025/03/26 06:12:55 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/03/26 06:12:55 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/03/26 06:12:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:12:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:12:57 DEBUG : sub dir/hello world: md5 = bd29ae31e1695bb8a1ff70833e71f3a8 OK
2025/03/26 06:12:57 INFO  : sub dir/hello world: Copied (new)
2025/03/26 06:12:57 DEBUG : Waiting for deletions to finish
2025/03/26 06:12:57 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:12:59 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (5.77s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:13:00 DEBUG : hello world2: Need to transfer - File not found at Destination
2025/03/26 06:13:00 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/03/26 06:13:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:13:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:13:02 DEBUG : hello world2: md5 = 01dfa001f906a1b20c40f032e679804c OK
2025/03/26 06:13:02 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestCopyWithDepth (3.38s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:13:04 DEBUG : potato2: Need to transfer - File not found at Destination
2025/03/26 06:13:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:13:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:13:05 DEBUG : potato2: md5 = 320b32262dee1a160c026d4f5b652710 OK
2025/03/26 06:13:05 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (3.30s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:13:07 DEBUG : potato2: Need to transfer - File not found at Destination
2025/03/26 06:13:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:13:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:13:08 DEBUG : potato2: md5 = 9c2ab497ecc47409978a9a4f0a130f59 OK
2025/03/26 06:13:08 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (3.23s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:13:10 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/03/26 06:13:10 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/03/26 06:13:10 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/03/26 06:13:10 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/03/26 06:13:10 DEBUG : sub dir: Making directory with metadata
2025/03/26 06:13:11 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/03/26 06:13:11 DEBUG : sub dir2: Making directory with metadata
2025/03/26 06:13:12 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/03/26 06:13:12 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/03/26 06:13:12 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/03/26 06:13:13 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/03/26 06:13:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:13:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:13:14 DEBUG : sub dir/hello world: md5 = 1d13e46b2c6898d054bab2242fccbee7 OK
2025/03/26 06:13:14 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:13:17 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2025/03/26 06:13:18 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (9.06s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:13:19 INFO  : sub dir2: Making directory
2025/03/26 06:13:19 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/03/26 06:13:19 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/03/26 06:13:19 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/03/26 06:13:19 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/03/26 06:13:19 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2025/03/26 06:13:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/03/26 06:13:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:13:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:13:21 DEBUG : sub dir/hello world: md5 = 66779fd3f5772f1530b6f8e1b983f3df OK
2025/03/26 06:13:21 INFO  : sub dir/hello world: Copied (new)
2025/03/26 06:13:22 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/03/26 06:13:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (5.49s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:13:25 DEBUG : sub dir2: Making directory with metadata
2025/03/26 06:13:25 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/03/26 06:13:25 DEBUG : sub dir: Making directory with metadata
2025/03/26 06:13:26 INFO  : sub dir: Made directory with metadata (mtime=2025-03-26T06:13:25.117422898Z)
2025/03/26 06:13:26 DEBUG : sub dir2: Making directory with metadata
2025/03/26 06:13:26 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/03/26 06:13:26 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/03/26 06:13:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:13:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:13:28 DEBUG : sub dir/hello world: md5 = ab4d44249c79e40fe92b7d5bb1a0a86f OK
2025/03/26 06:13:28 INFO  : sub dir/hello world: Copied (new)
2025/03/26 06:13:28 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:13:31 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (7.57s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:13:32 DEBUG : sub dir no update dir modtime: Making directory with metadata
2025/03/26 06:13:32 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/03/26 06:13:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:13:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:13:34 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (4.06s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:13:36 INFO  : sub dir2: Making directory
2025/03/26 06:13:36 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/03/26 06:13:36 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/03/26 06:13:36 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/03/26 06:13:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:13:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:13:39 DEBUG : sub dir/hello world: md5 = ef7633bb59091ddfb7ac7da5ecd2ad6b OK
2025/03/26 06:13:39 INFO  : sub dir/hello world: Copied (new)
2025/03/26 06:13:39 INFO  : sub dir/hello world: Deleted
2025/03/26 06:13:39 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/03/26 06:13:41 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (5.58s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:13:42 DEBUG : sub dir2: Making directory with metadata
2025/03/26 06:13:42 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/03/26 06:13:42 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/03/26 06:13:42 DEBUG : sub dir: Making directory with metadata
2025/03/26 06:13:43 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/03/26 06:13:43 DEBUG : sub dir2: Making directory with metadata
2025/03/26 06:13:44 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/03/26 06:13:44 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/03/26 06:13:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:13:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:13:45 DEBUG : sub dir/hello world: md5 = 2b695369b2f43617801d693fb238ae38 OK
2025/03/26 06:13:45 INFO  : sub dir/hello world: Copied (new)
2025/03/26 06:13:45 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:13:48 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (7.57s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.47s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:13:50 INFO  : sub dir2: Making directory
2025/03/26 06:13:50 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/03/26 06:13:50 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/03/26 06:13:50 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/03/26 06:13:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:13:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:13:52 DEBUG : sub dir/hello world: md5 = 5f794053c934ea35d2e10c3edd2650cb OK
2025/03/26 06:13:52 INFO  : sub dir/hello world: Copied (new)
2025/03/26 06:13:52 DEBUG : Waiting for deletions to finish
2025/03/26 06:13:53 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/03/26 06:13:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (5.26s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:13:57 DEBUG : sub dir/hello world: md5 = 0b3959ba378f7a01ea6f398c48dbe6e5 OK
2025/03/26 06:13:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yucovep0desi"
2025/03/26 06:13:58 DEBUG : Config file has changed externally - reloading
2025/03/26 06:13:58 DEBUG : Creating backend with remote "TestDrive:crypt/41f2ll7m7mjulj7ho8pjkpj7cvi6bue05jsfv3r5vj0erd5t6gd0"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova' -> Encrypted drive 'TestCryptDrive:rclone-test-yucovep0desi'
2025/03/26 06:13:59 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/03/26 06:13:59 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/03/26 06:13:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yucovep0desi': Waiting for checks to finish
2025/03/26 06:13:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yucovep0desi': Waiting for transfers to finish
2025/03/26 06:14:02 INFO  : sub dir/hello world: Copied (server-side copy)
2025/03/26 06:14:02 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:14:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yucovep0desi': Purge remote
2025/03/26 06:14:04 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (10.45s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:14:08 DEBUG : sub dir/hello world: md5 = 0575506b86a643fbefe76e2d82440301 OK
2025/03/26 06:14:09 INFO  : sub dir: Set directory modification time (using SetModTime)
2025/03/26 06:14:09 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/03/26 06:14:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:14:09 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/03/26 06:14:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:14:10 DEBUG : sub dir/hello world: md5 = 65815492dc0e5927ea94baac16fe2954 OK
2025/03/26 06:14:10 INFO  : sub dir/hello world: Copied (replaced existing)
2025/03/26 06:14:11 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:14:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (8.17s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:14:16 DEBUG : sub dir/hello world: md5 = 9f34488c05c0ce91ae9710096030fad6 OK
2025/03/26 06:14:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-jiximif0wada"
2025/03/26 06:14:17 DEBUG : Creating backend with remote "TestDrive:crypt/0s6mli855intkcuc6runm1rk3dq27m8h2lgshm1altqmp15oqjng"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova' -> Encrypted drive 'TestCryptDrive:rclone-test-jiximif0wada'
2025/03/26 06:14:18 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/03/26 06:14:18 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/03/26 06:14:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jiximif0wada': Waiting for checks to finish
2025/03/26 06:14:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jiximif0wada': Waiting for transfers to finish
2025/03/26 06:14:21 INFO  : sub dir/hello world: Copied (server-side copy)
2025/03/26 06:14:21 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:14:23 DEBUG : sub dir/hello world: md5 = 77416e1d970844f135e2f4230e778525 OK
2025/03/26 06:14:24 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/03/26 06:14:24 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/03/26 06:14:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jiximif0wada': Waiting for checks to finish
2025/03/26 06:14:24 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/03/26 06:14:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jiximif0wada': Waiting for transfers to finish
2025/03/26 06:14:26 INFO  : sub dir/hello world: Copied (server-side copy)
2025/03/26 06:14:26 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:14:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jiximif0wada': Purge remote
2025/03/26 06:14:28 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (16.10s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:14:32 DEBUG : sub dir/hello world: md5 = 19cdbd77ab54ce71c36860797a5f423b OK
2025/03/26 06:14:34 INFO  : sub dir: Set directory modification time (using SetModTime)
2025/03/26 06:14:34 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/03/26 06:14:34 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/03/26 06:14:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:14:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:14:35 DEBUG : sub dir/hello world: md5 = 8f546e074d0f86ac2fa9c6a620555cd9 OK
2025/03/26 06:14:35 INFO  : sub dir/hello world: Copied (replaced existing)
2025/03/26 06:14:35 INFO  : sub dir/hello world: Deleted
2025/03/26 06:14:35 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:14:37 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (8.28s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:14:40 DEBUG : sub dir/hello world: md5 = 2fd1207709c1e21c2a3ab32511785452 OK
2025/03/26 06:14:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-poteced8xobe"
2025/03/26 06:14:41 DEBUG : Creating backend with remote "TestDrive:crypt/ooqu3g3l1g0p6n52rauce2jiclr5vibhh2ljcj1csjoslcs0i410"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova' -> Encrypted drive 'TestCryptDrive:rclone-test-poteced8xobe'
2025/03/26 06:14:42 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/03/26 06:14:42 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/03/26 06:14:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-poteced8xobe': Waiting for checks to finish
2025/03/26 06:14:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-poteced8xobe': Waiting for transfers to finish
2025/03/26 06:14:45 INFO  : sub dir/hello world: Copied (server-side copy)
2025/03/26 06:14:45 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:14:47 DEBUG : sub dir/hello world: md5 = 45750a444e7e52c21e915182192fc1db OK
2025/03/26 06:14:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-poteced8xobe': Using server-side directory move
2025/03/26 06:14:47 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-poteced8xobe': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/03/26 06:14:48 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/03/26 06:14:48 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/03/26 06:14:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-poteced8xobe': Waiting for checks to finish
2025/03/26 06:14:48 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/03/26 06:14:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-poteced8xobe': Waiting for transfers to finish
2025/03/26 06:14:48 INFO  : sub dir/hello world: Deleted
2025/03/26 06:14:49 INFO  : sub dir/hello world: Moved (server-side)
2025/03/26 06:14:49 INFO  : sub dir: Set directory modification time (using SetModTime)
2025/03/26 06:14:52 DEBUG : sub dir/hello world: md5 = f2338d6dd28432f3ad6aa59d4fe56f76 OK
2025/03/26 06:14:52 DEBUG : testing file moves
2025/03/26 06:14:53 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/03/26 06:14:53 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/03/26 06:14:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-poteced8xobe': Waiting for checks to finish
2025/03/26 06:14:53 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2025/03/26 06:14:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-poteced8xobe': Waiting for transfers to finish
2025/03/26 06:14:53 INFO  : sub dir/hello world: Deleted
2025/03/26 06:14:54 INFO  : sub dir/hello world: Moved (server-side)
2025/03/26 06:14:54 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:14:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-poteced8xobe': Purge remote
--- PASS: TestServerSideMoveOverSelf (19.80s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:15:00 DEBUG : sub dir/hello world: md5 = a38caf330efed381a208847d37ad079e OK
2025/03/26 06:15:00 ERROR : : error listing: directory not found
2025/03/26 06:15:01 INFO  : Local file system at /tmp/rclone929948549: Making directory
2025/03/26 06:15:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:15:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:15:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (5.97s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:15:06 DEBUG : sub dir/hello world: md5 = da88216c98f759a9864cffda67796674 OK
2025/03/26 06:15:07 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/03/26 06:15:07 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/03/26 06:15:07 DEBUG : Local file system at /tmp/rclone929948549: Waiting for checks to finish
2025/03/26 06:15:07 DEBUG : Local file system at /tmp/rclone929948549: Waiting for transfers to finish
2025/03/26 06:15:08 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2025/03/26 06:15:08 INFO  : sub dir/hello world: Copied (new)
2025/03/26 06:15:08 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:15:09 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (6.19s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:15:10 DEBUG : check sum: Need to transfer - File not found at Destination
2025/03/26 06:15:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:15:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:15:12 DEBUG : check sum: md5 = 696ffa1691bb4264ee6171a5a3ad5b5e OK
2025/03/26 06:15:12 INFO  : check sum: Copied (new)
2025/03/26 06:15:12 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:15:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:15:12 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2025/03/26 06:15:12 DEBUG : check sum: Size of src and dst objects identical
2025/03/26 06:15:12 DEBUG : check sum: Unchanged skipping
2025/03/26 06:15:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:15:12 DEBUG : Waiting for deletions to finish
2025/03/26 06:15:12 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (4.14s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:15:14 DEBUG : sizeonly: Need to transfer - File not found at Destination
2025/03/26 06:15:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:15:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:15:16 DEBUG : sizeonly: md5 = 6c20c6ef9e62ee14c75214c662b6401e OK
2025/03/26 06:15:16 INFO  : sizeonly: Copied (new)
2025/03/26 06:15:16 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:15:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:15:16 DEBUG : sizeonly: Sizes identical
2025/03/26 06:15:16 DEBUG : sizeonly: Unchanged skipping
2025/03/26 06:15:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:15:16 DEBUG : Waiting for deletions to finish
2025/03/26 06:15:16 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (4.23s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:15:19 DEBUG : ignore-size: Need to transfer - File not found at Destination
2025/03/26 06:15:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:15:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:15:20 DEBUG : ignore-size: md5 = cc4b742f906b8120ca172dade5fcfa81 OK
2025/03/26 06:15:20 INFO  : ignore-size: Copied (new)
2025/03/26 06:15:20 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:15:21 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:15:21 DEBUG : ignore-size: Unchanged skipping
2025/03/26 06:15:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:15:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:15:21 DEBUG : Waiting for deletions to finish
2025/03/26 06:15:21 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (4.51s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:15:24 DEBUG : existing: md5 = 8d29a8e0650abaf523c2acbdb596b39a OK
2025/03/26 06:15:25 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:15:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:15:25 DEBUG : existing: Unchanged skipping
2025/03/26 06:15:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:15:25 DEBUG : Waiting for deletions to finish
2025/03/26 06:15:25 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:15:25 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2025/03/26 06:15:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:15:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:15:26 DEBUG : existing: md5 = 55960cdfaf4a88d25b5f99e77958171a OK
2025/03/26 06:15:26 INFO  : existing: Copied (replaced existing)
2025/03/26 06:15:26 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (5.46s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:15:29 DEBUG : existing: Need to transfer - File not found at Destination
2025/03/26 06:15:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:15:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:15:30 DEBUG : existing: md5 = e971c8dba93a675acfcc8491b7d1c2a6 OK
2025/03/26 06:15:30 INFO  : existing: Copied (new)
2025/03/26 06:15:30 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:15:31 DEBUG : existing: Destination exists, skipping
2025/03/26 06:15:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:15:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:15:31 DEBUG : Waiting for deletions to finish
2025/03/26 06:15:31 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (4.15s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:15:35 DEBUG : b/potato: md5 = 41dca1090a52ba779154f267447bb9da OK
2025/03/26 06:15:37 DEBUG : c/non empty space: md5 = a4b08976dc28a16bafe433b1b79a4c11 OK
2025/03/26 06:15:37 INFO  : d: Making directory
2025/03/26 06:15:39 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/03/26 06:15:40 INFO  : c: Set directory modification time (using SetModTime)
2025/03/26 06:15:40 DEBUG : Added delayed dir = "c", newDst=c
2025/03/26 06:15:40 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:15:40 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/03/26 06:15:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:15:40 DEBUG : c/non empty space: Unchanged skipping
2025/03/26 06:15:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:15:42 DEBUG : a/potato2: md5 = 6db5548d15cc78d1e22331621cf7c2a9 OK
2025/03/26 06:15:42 INFO  : a/potato2: Copied (new)
2025/03/26 06:15:42 DEBUG : Waiting for deletions to finish
2025/03/26 06:15:42 INFO  : b/potato: Deleted
2025/03/26 06:15:43 INFO  : a: Set directory modification time (using DirSetModTime)
2025/03/26 06:15:43 INFO  : d: Removing directory
2025/03/26 06:15:44 INFO  : b: Removing directory
2025/03/26 06:15:44 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/03/26 06:15:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:15:47 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/03/26 06:15:47 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (16.06s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:15:50 DEBUG : empty space: md5 = 9ea0a1eba74de11e9b8e97b930baf090 OK
2025/03/26 06:15:51 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/03/26 06:15:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:15:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:15:51 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2025/03/26 06:15:51 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:15:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:15:51 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/03/26 06:15:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:15:52 DEBUG : empty space: md5 = 11cd29ca13c08458677a1570626208b3 OK
2025/03/26 06:15:52 INFO  : empty space: Copied (replaced existing)
2025/03/26 06:15:52 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (5.67s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.47s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:15:56 DEBUG : foo: md5 = b49bdd66067779a71b56d462fb81907c OK
2025/03/26 06:15:57 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/03/26 06:15:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:15:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:15:58 DEBUG : foo: md5 = ad6b036045eeab49aeb0c058b379f3e2 OK
2025/03/26 06:15:58 INFO  : foo: Copied (replaced existing)
2025/03/26 06:15:58 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (4.88s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:16:01 DEBUG : empty space: md5 = a7a372b5c5a74eb7f246b00ced6d8641 OK
2025/03/26 06:16:02 DEBUG : potato: Need to transfer - File not found at Destination
2025/03/26 06:16:02 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:16:02 DEBUG : empty space: Unchanged skipping
2025/03/26 06:16:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:16:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:16:03 DEBUG : potato: md5 = e53ec15b35ab7b9ef8a9095340dcfbf7 OK
2025/03/26 06:16:03 INFO  : potato: Copied (new)
2025/03/26 06:16:03 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (5.30s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:16:07 DEBUG : potato: md5 = f423031fd82832d10863769e5327596b OK
2025/03/26 06:16:08 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2025/03/26 06:16:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:16:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:16:09 DEBUG : potato: md5 = ebc4b1265ccad31389890355932d2b67 OK
2025/03/26 06:16:09 INFO  : potato: Copied (replaced existing)
2025/03/26 06:16:09 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (6.31s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:16:13 DEBUG : potato: md5 = 8ac43d199af6906e010e2929f4923c77 OK
2025/03/26 06:16:13 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/03/26 06:16:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:16:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:16:14 DEBUG : potato: md5 = 5c3e992a098f4e017f744df4acb548d6 OK
2025/03/26 06:16:14 INFO  : potato: Copied (replaced existing)
2025/03/26 06:16:14 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (4.64s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:16:17 DEBUG : potato: md5 = ed869b86562e03425331fb88e98b6773 OK
2025/03/26 06:16:19 DEBUG : empty space: md5 = 39c2f8146e810bf2dc62754240bc47e1 OK
2025/03/26 06:16:19 DEBUG : potato2: Need to transfer - File not found at Destination
2025/03/26 06:16:19 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2025/03/26 06:16:19 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:16:19 DEBUG : empty space: Unchanged skipping
2025/03/26 06:16:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:16:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:16:19 DEBUG : Waiting for deletions to finish
2025/03/26 06:16:19 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.21s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:16:22 DEBUG : potato: md5 = 3a3b84a465bbbabb248a4569b017520c OK
2025/03/26 06:16:24 DEBUG : empty space: md5 = 9650670b4294568590bdba0694c474f3 OK
2025/03/26 06:16:24 DEBUG : potato2: Need to transfer - File not found at Destination
2025/03/26 06:16:24 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:16:24 DEBUG : empty space: Unchanged skipping
2025/03/26 06:16:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:16:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:16:26 DEBUG : potato2: md5 = f4cb8dbad3b78d0d438eb7690d070a9c OK
2025/03/26 06:16:26 INFO  : potato2: Copied (new)
2025/03/26 06:16:26 DEBUG : Waiting for deletions to finish
2025/03/26 06:16:26 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (7.87s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:16:31 DEBUG : b/potato: md5 = 9aad73a65c30b2f8c04af59a2226a2ba OK
2025/03/26 06:16:34 DEBUG : c/non empty space: md5 = 4bc8469b1de37b99ae5841213852e61a OK
2025/03/26 06:16:34 INFO  : d: Making directory
2025/03/26 06:16:34 INFO  : d/e: Making directory
2025/03/26 06:16:37 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/03/26 06:16:38 INFO  : c: Set directory modification time (using SetModTime)
2025/03/26 06:16:38 DEBUG : Added delayed dir = "c", newDst=c
2025/03/26 06:16:38 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/03/26 06:16:38 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:16:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:16:38 DEBUG : c/non empty space: Unchanged skipping
2025/03/26 06:16:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:16:40 DEBUG : a/potato2: md5 = d42303b5dcb0a97ab21753ec00cce894 OK
2025/03/26 06:16:40 INFO  : a/potato2: Copied (new)
2025/03/26 06:16:40 DEBUG : Waiting for deletions to finish
2025/03/26 06:16:40 INFO  : b/potato: Deleted
2025/03/26 06:16:41 INFO  : a: Set directory modification time (using DirSetModTime)
2025/03/26 06:16:41 INFO  : d/e: Removing directory
2025/03/26 06:16:41 INFO  : d: Removing directory
2025/03/26 06:16:42 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2025/03/26 06:16:42 INFO  : b: Removing directory
2025/03/26 06:16:42 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/03/26 06:16:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:16:45 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/03/26 06:16:46 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (17.89s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:16:49 DEBUG : b/potato: md5 = 508b0700e0021f3309afff81cd5d51e0 OK
2025/03/26 06:16:52 DEBUG : c/non empty space: md5 = 9f8d873f90c345f2bc632d7306f14682 OK
2025/03/26 06:16:52 INFO  : d: Making directory
2025/03/26 06:16:53 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/03/26 06:16:54 INFO  : c: Set directory modification time (using SetModTime)
2025/03/26 06:16:54 DEBUG : Added delayed dir = "c", newDst=c
2025/03/26 06:16:54 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:16:54 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/03/26 06:16:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:16:54 DEBUG : c/non empty space: Unchanged skipping
2025/03/26 06:16:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:16:56 DEBUG : a/potato2: md5 = f0be4c77e38d7da4ef938a784a829ae6 OK
2025/03/26 06:16:56 INFO  : a/potato2: Copied (new)
2025/03/26 06:16:56 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': not deleting files as there were IO errors
2025/03/26 06:16:57 INFO  : a: Set directory modification time (using DirSetModTime)
2025/03/26 06:16:57 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:17:00 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/03/26 06:17:01 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/03/26 06:17:02 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (16.17s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:17:04 DEBUG : potato: md5 = cc872d65afbcbf250f3a7252aff0c530 OK
2025/03/26 06:17:06 DEBUG : empty space: md5 = b73d40a49b58ffab6993660a1e116c16 OK
2025/03/26 06:17:06 DEBUG : Waiting for deletions to finish
2025/03/26 06:17:06 DEBUG : potato2: Need to transfer - File not found at Destination
2025/03/26 06:17:06 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:17:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:17:06 DEBUG : empty space: Unchanged skipping
2025/03/26 06:17:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:17:07 INFO  : potato: Deleted
2025/03/26 06:17:08 DEBUG : potato2: md5 = 8d7acaffafce82cc4fe4b0ff18a2f788 OK
2025/03/26 06:17:08 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (6.73s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:17:11 DEBUG : potato: md5 = a1c83b98ca33f8d64ab98042c79a824d OK
2025/03/26 06:17:12 DEBUG : empty space: md5 = 7b2a509d86e379bf15a2963abdf9f535 OK
2025/03/26 06:17:13 DEBUG : Waiting for deletions to finish
2025/03/26 06:17:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:17:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:17:13 INFO  : potato: Deleted
2025/03/26 06:17:14 DEBUG : potato2: Need to transfer - File not found at Destination
2025/03/26 06:17:14 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:17:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:17:14 DEBUG : empty space: Unchanged skipping
2025/03/26 06:17:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:17:15 DEBUG : potato2: md5 = 99c7b5b777d138231c8035b028f54e04 OK
2025/03/26 06:17:15 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (7.42s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:17:19 DEBUG : potato: md5 = db57bb9862e744c9226e847e71cb554f OK
2025/03/26 06:17:19 DEBUG : potato2: Need to transfer - File not found at Destination
2025/03/26 06:17:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:17:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:17:21 DEBUG : potato2: md5 = b3271f109154801c642ae0130c966f73 OK
2025/03/26 06:17:21 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (5.73s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:17:24 DEBUG : potato2: md5 = fbfb702e9d4989806d15073923995c65 OK
2025/03/26 06:17:26 DEBUG : empty space: md5 = a681a4cbeb27cfc9b7e048da08a7fe0b OK
2025/03/26 06:17:26 DEBUG : enormous: Excluded (Size Filter)
2025/03/26 06:17:26 DEBUG : enormous: Excluded
2025/03/26 06:17:26 DEBUG : potato2: Excluded (Size Filter)
2025/03/26 06:17:26 DEBUG : potato2: Excluded
2025/03/26 06:17:26 DEBUG : potato2: Excluded (Size Filter)
2025/03/26 06:17:26 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:17:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:17:26 DEBUG : empty space: Unchanged skipping
2025/03/26 06:17:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:17:26 DEBUG : Waiting for deletions to finish
2025/03/26 06:17:26 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:17:27 DEBUG : enormous: Excluded (Size Filter)
2025/03/26 06:17:27 DEBUG : enormous: Excluded
2025/03/26 06:17:27 DEBUG : potato2: Excluded (Size Filter)
2025/03/26 06:17:27 DEBUG : potato2: Excluded
2025/03/26 06:17:27 DEBUG : potato2: Excluded (Size Filter)
2025/03/26 06:17:27 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2025/03/26 06:17:27 DEBUG : empty space: Unchanged skipping
2025/03/26 06:17:27 DEBUG : Local file system at /tmp/rclone929948549: Waiting for checks to finish
2025/03/26 06:17:27 DEBUG : Local file system at /tmp/rclone929948549: Waiting for transfers to finish
2025/03/26 06:17:27 DEBUG : Waiting for deletions to finish
2025/03/26 06:17:27 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncWithExclude (6.18s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:17:31 DEBUG : potato2: md5 = f5610c5e27ba9f5f39e50ae7c51ada9c OK
2025/03/26 06:17:32 DEBUG : empty space: md5 = 0408ba14db8aa2b27312b699d94c2136 OK
2025/03/26 06:17:33 DEBUG : enormous: md5 = dd6e6b9e4c0e71a1ee1a45b2d2fcd2e1 OK
2025/03/26 06:17:34 DEBUG : enormous: Excluded (Size Filter)
2025/03/26 06:17:34 DEBUG : enormous: Excluded
2025/03/26 06:17:34 DEBUG : potato2: Excluded (Size Filter)
2025/03/26 06:17:34 DEBUG : potato2: Excluded
2025/03/26 06:17:34 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:17:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:17:34 DEBUG : empty space: Unchanged skipping
2025/03/26 06:17:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:17:34 DEBUG : Waiting for deletions to finish
2025/03/26 06:17:34 INFO  : potato2: Deleted
2025/03/26 06:17:34 INFO  : enormous: Deleted
2025/03/26 06:17:34 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:17:35 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2025/03/26 06:17:35 DEBUG : empty space: Unchanged skipping
2025/03/26 06:17:35 DEBUG : Local file system at /tmp/rclone929948549: Waiting for checks to finish
2025/03/26 06:17:35 DEBUG : Local file system at /tmp/rclone929948549: Waiting for transfers to finish
2025/03/26 06:17:35 DEBUG : Waiting for deletions to finish
2025/03/26 06:17:35 INFO  : enormous: Deleted
2025/03/26 06:17:35 INFO  : potato2: Deleted
2025/03/26 06:17:35 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (7.64s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:17:38 DEBUG : one: md5 = 5499607c066088fb051371081a5a85b5 OK
2025/03/26 06:17:40 DEBUG : two: md5 = 925ca5d9b3a1b61e5586971e87b94a41 OK
2025/03/26 06:17:41 DEBUG : three: md5 = 07010244fc99e1a5ff1975ce2942225d OK
2025/03/26 06:17:42 DEBUG : four: md5 = b5fb82e2da57581e9439237a1c04738a OK
2025/03/26 06:17:43 DEBUG : five: Need to transfer - File not found at Destination
2025/03/26 06:17:43 DEBUG : four: Sizes differ (src 4 vs dst 8)
2025/03/26 06:17:43 DEBUG : one: Destination is newer than source, skipping
2025/03/26 06:17:43 DEBUG : three: Sizes identical
2025/03/26 06:17:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:17:43 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2025/03/26 06:17:43 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2025/03/26 06:17:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:17:44 DEBUG : four: md5 = a57255625e48ede96bcfdf11df776999 OK
2025/03/26 06:17:44 INFO  : four: Copied (replaced existing)
2025/03/26 06:17:44 DEBUG : two: md5 = 6fd57476b8c2dcac8102537a7859da8a OK
2025/03/26 06:17:44 INFO  : two: Copied (replaced existing)
2025/03/26 06:17:44 DEBUG : five: md5 = 7649ba18bc9e422d90488603cfbd56b2 OK
2025/03/26 06:17:44 INFO  : five: Copied (new)
2025/03/26 06:17:44 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (10.45s)
=== 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-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2025/03/26 06:17:47 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Ignoring --track-renames as the source and destination do not have a common hash
2025/03/26 06:17:48 DEBUG : potato: Need to transfer - File not found at Destination
2025/03/26 06:17:48 DEBUG : yam: Need to transfer - File not found at Destination
2025/03/26 06:17:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:17:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:17:49 DEBUG : potato: md5 = c9a9dd83d334517e47fac25dd4021778 OK
2025/03/26 06:17:49 INFO  : potato: Copied (new)
2025/03/26 06:17:49 DEBUG : yam: md5 = f8f6369e942881eca7499d532b43d0d1 OK
2025/03/26 06:17:49 INFO  : yam: Copied (new)
2025/03/26 06:17:49 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:17:49 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Ignoring --track-renames as the source and destination do not have a common hash
2025/03/26 06:17:50 DEBUG : yaml: Need to transfer - File not found at Destination
2025/03/26 06:17:50 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:17:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:17:50 DEBUG : potato: Unchanged skipping
2025/03/26 06:17:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:17:51 DEBUG : yaml: md5 = c7565c67d85f1575dc0c544eeb0a563b OK
2025/03/26 06:17:51 INFO  : yaml: Copied (new)
2025/03/26 06:17:51 DEBUG : Waiting for deletions to finish
2025/03/26 06:17:51 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (6.85s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2025/03/26 06:17:54 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Making map for --track-renames
2025/03/26 06:17:54 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Finished making map for --track-renames
2025/03/26 06:17:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:17:54 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/03/26 06:17:54 DEBUG : yam: Need to transfer - No matching file found at Destination
2025/03/26 06:17:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for renames to finish
2025/03/26 06:17:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:17:56 DEBUG : potato: md5 = de20403e3abee1232c21543bcdb9021b OK
2025/03/26 06:17:56 INFO  : potato: Copied (new)
2025/03/26 06:17:56 DEBUG : yam: md5 = 3a88e99398eab47a2d93c02550c2da4b OK
2025/03/26 06:17:56 INFO  : yam: Copied (new)
2025/03/26 06:17:56 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:17:56 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:17:56 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Making map for --track-renames
2025/03/26 06:17:56 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Finished making map for --track-renames
2025/03/26 06:17:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:17:56 DEBUG : potato: Unchanged skipping
2025/03/26 06:17:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for renames to finish
2025/03/26 06:17:57 INFO  : yam: Moved (server-side) to: yaml
2025/03/26 06:17:57 INFO  : yaml: Renamed from "yam"
2025/03/26 06:17:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:17:57 DEBUG : Waiting for deletions to finish
2025/03/26 06:17:57 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (5.54s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2025/03/26 06:18:00 DEBUG : Added delayed dir = "sub", newDst=<nil>
2025/03/26 06:18:00 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Making map for --track-renames
2025/03/26 06:18:00 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Finished making map for --track-renames
2025/03/26 06:18:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:18:00 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/03/26 06:18:00 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2025/03/26 06:18:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for renames to finish
2025/03/26 06:18:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:18:02 DEBUG : potato: md5 = c772b9db3d1952673c8c8cd918f1b4ed OK
2025/03/26 06:18:02 INFO  : potato: Copied (new)
2025/03/26 06:18:02 DEBUG : sub/yam: md5 = 027e69dc396a055dcc4e6dfc67a03aca OK
2025/03/26 06:18:02 INFO  : sub/yam: Copied (new)
2025/03/26 06:18:02 DEBUG : Waiting for deletions to finish
2025/03/26 06:18:03 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:18:04 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:18:04 DEBUG : potato: Unchanged skipping
2025/03/26 06:18:04 INFO  : sub: Set directory modification time (using SetModTime)
2025/03/26 06:18:04 DEBUG : Added delayed dir = "sub", newDst=sub
2025/03/26 06:18:04 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Making map for --track-renames
2025/03/26 06:18:04 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Finished making map for --track-renames
2025/03/26 06:18:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:18:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for renames to finish
2025/03/26 06:18:05 INFO  : sub/yam: Moved (server-side) to: yam
2025/03/26 06:18:05 INFO  : yam: Renamed from "sub/yam"
2025/03/26 06:18:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:18:05 DEBUG : Waiting for deletions to finish
2025/03/26 06:18:05 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.12s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:18:09 DEBUG : Creating backend with remote "/tmp/rclone929948549/dir1"
2025/03/26 06:18:09 DEBUG : Creating backend with remote "/tmp/rclone929948549/dir2"
2025/03/26 06:18:09 DEBUG : Local file system at /tmp/rclone929948549/dir2: Using server-side directory move
2025/03/26 06:18:09 INFO  : Local file system at /tmp/rclone929948549/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/03/26 06:18:09 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/03/26 06:18:09 INFO  : file1.txt: Moved (server-side)
2025/03/26 06:18:09 DEBUG : Local file system at /tmp/rclone929948549/dir2: Waiting for checks to finish
2025/03/26 06:18:09 DEBUG : Local file system at /tmp/rclone929948549/dir2: Waiting for transfers to finish
--- PASS: TestServerSideMoveLocal (0.45s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:18:09 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/03/26 06:18:09 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/03/26 06:18:09 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/03/26 06:18:09 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/03/26 06:18:09 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/03/26 06:18:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:18:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:18:12 DEBUG : sub dir/hello world: md5 = 154b72f5f5d52833b2a1574c00fd023e OK
2025/03/26 06:18:12 INFO  : sub dir/hello world: Copied (new)
2025/03/26 06:18:12 INFO  : sub dir/hello world: Deleted
2025/03/26 06:18:13 DEBUG : nested/sub dir/file: md5 = 155bef1a09a4cb9fd2a40cabf37a5cc5 OK
2025/03/26 06:18:13 INFO  : nested/sub dir/file: Copied (new)
2025/03/26 06:18:13 INFO  : nested/sub dir/file: Deleted
2025/03/26 06:18:14 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/03/26 06:18:14 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/03/26 06:18:14 INFO  : nested: Set directory modification time (using DirSetModTime)
2025/03/26 06:18:14 INFO  : sub dir: Removing directory
2025/03/26 06:18:14 INFO  : nested/sub dir: Removing directory
2025/03/26 06:18:14 INFO  : nested: Removing directory
2025/03/26 06:18:14 DEBUG : Local file system at /tmp/rclone929948549: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:18:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/03/26 06:18:18 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2025/03/26 06:18:18 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (10.47s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:18:20 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/03/26 06:18:20 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/03/26 06:18:20 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/03/26 06:18:20 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/03/26 06:18:20 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/03/26 06:18:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:18:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:18:22 DEBUG : sub dir/hello world: md5 = 9011751d3fa893e0c427762eb3f56746 OK
2025/03/26 06:18:22 INFO  : sub dir/hello world: Copied (new)
2025/03/26 06:18:22 INFO  : sub dir/hello world: Deleted
2025/03/26 06:18:24 DEBUG : nested/sub dir/file: md5 = 2f89b8b735c87144d10d026b73ef8db2 OK
2025/03/26 06:18:24 INFO  : nested/sub dir/file: Copied (new)
2025/03/26 06:18:24 INFO  : nested/sub dir/file: Deleted
2025/03/26 06:18:25 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/03/26 06:18:25 INFO  : nested: Set directory modification time (using DirSetModTime)
2025/03/26 06:18:25 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:18:28 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/03/26 06:18:28 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2025/03/26 06:18:29 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.55s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:18:30 DEBUG : existing: Need to transfer - File not found at Destination
2025/03/26 06:18:30 DEBUG : existing-b: Need to transfer - File not found at Destination
2025/03/26 06:18:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:18:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:18:32 DEBUG : existing-b: md5 = 8253d1cb3ba555a4cae0d47baff5bab8 OK
2025/03/26 06:18:32 INFO  : existing-b: Copied (new)
2025/03/26 06:18:32 INFO  : existing-b: Deleted
2025/03/26 06:18:32 DEBUG : existing: md5 = dc2e99acf5603a3bcbf484ff02a97f88 OK
2025/03/26 06:18:32 INFO  : existing: Copied (new)
2025/03/26 06:18:32 INFO  : existing: Deleted
2025/03/26 06:18:32 DEBUG : existing: Destination exists, skipping
2025/03/26 06:18:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:18:32 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2025/03/26 06:18:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:18:32 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (4.27s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:18:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zuvoray1dero"
2025/03/26 06:18:35 DEBUG : Creating backend with remote "TestDrive:crypt/am158f3dvpptqd1cp4je7rjsnec9g0irk8htlf3cp91rqnt3ej8g"
2025/03/26 06:18:37 DEBUG : potato2: md5 = 755184e1d082685076b000285d0f0081 OK
2025/03/26 06:18:38 DEBUG : empty space: md5 = d91cdd1a17e5d50af649c8f9ea412856 OK
2025/03/26 06:18:40 DEBUG : potato3: md5 = 3cab3eeb4517ea2731b278be816e8728 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova' -> Encrypted drive 'TestCryptDrive:rclone-test-zuvoray1dero'
2025/03/26 06:18:42 DEBUG : empty space: md5 = 9dcd4540fc4b023d1173de5305bb2d8c OK
2025/03/26 06:18:43 DEBUG : potato3: md5 = 7efe8901f19074318e8fd618999349c8 OK
2025/03/26 06:18:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zuvoray1dero': Using server-side directory move
2025/03/26 06:18:44 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-zuvoray1dero': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/03/26 06:18:44 DEBUG : potato2: Need to transfer - File not found at Destination
2025/03/26 06:18:44 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/03/26 06:18:44 DEBUG : empty space: Unchanged skipping
2025/03/26 06:18:44 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/03/26 06:18:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zuvoray1dero': Waiting for checks to finish
2025/03/26 06:18:44 INFO  : empty space: Deleted
2025/03/26 06:18:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zuvoray1dero': Waiting for transfers to finish
2025/03/26 06:18:44 INFO  : potato3: Deleted
2025/03/26 06:18:44 INFO  : potato2: Moved (server-side)
2025/03/26 06:18:45 INFO  : potato3: Moved (server-side)
2025/03/26 06:18:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-ropikig3topo"
2025/03/26 06:18:46 DEBUG : Creating backend with remote "TestDrive:crypt/4ghg74n3301t78ibv3hnl7ssfolrqhg0c4o5orp88nml3l9so41g"
2025/03/26 06:18:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ropikig3topo': Using server-side directory move
2025/03/26 06:18:47 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-ropikig3topo': Server side directory move succeeded
2025/03/26 06:18:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ropikig3topo': Purge remote
2025/03/26 06:18:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zuvoray1dero': Purge remote
2025/03/26 06:18:49 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (14.96s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:18:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tibaduk3dobi"
2025/03/26 06:18:50 DEBUG : Creating backend with remote "TestDrive:crypt/mga2kjp0ve2bcbg21aap85p7gud5d0sqs3d0nmoqdj7v9m05skd0"
2025/03/26 06:18:52 DEBUG : potato2: md5 = 5efb65a642b53e38d86797eef1d1010c OK
2025/03/26 06:18:54 DEBUG : empty space: md5 = 77c1c568006901981f33a87c9e42519d OK
2025/03/26 06:18:55 DEBUG : potato3: md5 = 3c4a86eaa1cba34d216c90c9fd84862f OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova' -> Encrypted drive 'TestCryptDrive:rclone-test-tibaduk3dobi'
2025/03/26 06:18:58 DEBUG : empty space: md5 = c4ec4bbf713ef34b3464da7287e04e31 OK
2025/03/26 06:18:59 DEBUG : potato3: md5 = 1a9f1224f79097ca9095e28c911ca143 OK
2025/03/26 06:18:59 DEBUG : empty space: Excluded (Size Filter)
2025/03/26 06:18:59 DEBUG : empty space: Excluded (Size Filter)
2025/03/26 06:18:59 DEBUG : potato2: Need to transfer - File not found at Destination
2025/03/26 06:18:59 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/03/26 06:18:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tibaduk3dobi': Waiting for checks to finish
2025/03/26 06:18:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tibaduk3dobi': Waiting for transfers to finish
2025/03/26 06:19:00 INFO  : potato3: Deleted
2025/03/26 06:19:00 INFO  : potato2: Moved (server-side)
2025/03/26 06:19:00 INFO  : potato3: Moved (server-side)
2025/03/26 06:19:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yabubat3fefa"
2025/03/26 06:19:01 DEBUG : Creating backend with remote "TestDrive:crypt/kck83mdcst28a5ovhq81pdnh1ghpjnr3st3otk4fphqparjeml20"
2025/03/26 06:19:02 DEBUG : empty space: Excluded (Size Filter)
2025/03/26 06:19:02 DEBUG : potato2: Need to transfer - File not found at Destination
2025/03/26 06:19:02 DEBUG : potato3: Need to transfer - File not found at Destination
2025/03/26 06:19:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yabubat3fefa': Waiting for checks to finish
2025/03/26 06:19:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yabubat3fefa': Waiting for transfers to finish
2025/03/26 06:19:04 INFO  : potato2: Moved (server-side)
2025/03/26 06:19:05 INFO  : potato3: Moved (server-side)
2025/03/26 06:19:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yabubat3fefa': Purge remote
2025/03/26 06:19:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tibaduk3dobi': Purge remote
--- PASS: TestServerSideMoveWithFilter (17.89s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:19:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yukilig7joda"
2025/03/26 06:19:07 DEBUG : Creating backend with remote "TestDrive:crypt/rclpodsu4m7m7ooh2kd63c2ji3ijs0pb5ug11sld2rolalug8gpg"
2025/03/26 06:19:10 DEBUG : potato2: md5 = 4192a6438c9c65de5ee62b529720c577 OK
2025/03/26 06:19:11 DEBUG : empty space: md5 = ec7add782b15bf839e28e672a60fb6a9 OK
2025/03/26 06:19:13 DEBUG : potato3: md5 = 90e469f4a13c39efd53e80ad1358e4ed OK
2025/03/26 06:19:13 INFO  : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova' -> Encrypted drive 'TestCryptDrive:rclone-test-yukilig7joda'
2025/03/26 06:19:16 DEBUG : empty space: md5 = accd369aa87c5ca2c08b18f0d11fc559 OK
2025/03/26 06:19:17 DEBUG : potato3: md5 = 58a12fe87ab289a264354767edb4ab3a OK
2025/03/26 06:19:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yukilig7joda': Using server-side directory move
2025/03/26 06:19:18 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-yukilig7joda': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/03/26 06:19:18 DEBUG : potato2: Need to transfer - File not found at Destination
2025/03/26 06:19:18 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2025/03/26 06:19:18 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/03/26 06:19:18 DEBUG : empty space: Unchanged skipping
2025/03/26 06:19:18 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/03/26 06:19:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yukilig7joda': Waiting for checks to finish
2025/03/26 06:19:19 INFO  : potato3: Deleted
2025/03/26 06:19:19 INFO  : empty space: Deleted
2025/03/26 06:19:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yukilig7joda': Waiting for transfers to finish
2025/03/26 06:19:19 INFO  : potato2: Moved (server-side)
2025/03/26 06:19:19 INFO  : potato3: Moved (server-side)
2025/03/26 06:19:19 INFO  : tomatoDir: Removing directory
2025/03/26 06:19:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': deleted 1 directories
2025/03/26 06:19:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beduxut1yini"
2025/03/26 06:19:21 DEBUG : Config file has changed externally - reloading
2025/03/26 06:19:21 DEBUG : Creating backend with remote "TestDrive:crypt/3gtom75fd5tm7130oro9lr0i8b9cbee172u1l6brs8e2d6v57650"
2025/03/26 06:19:22 INFO  : tomatoDir: Making directory
2025/03/26 06:19:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beduxut1yini': Using server-side directory move
2025/03/26 06:19:23 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-beduxut1yini': Server side directory move succeeded
2025/03/26 06:19:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beduxut1yini': Purge remote
2025/03/26 06:19:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yukilig7joda': Purge remote
2025/03/26 06:19:25 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (18.46s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.45s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:19:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/rclone-sync-test"
2025/03/26 06:19:26 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncOverlap (3.89s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:19:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/rclone-sync-test"
2025/03/26 06:19:30 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2025/03/26 06:19:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/rclone-sync-test-include/layer2"
2025/03/26 06:19:32 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2025/03/26 06:19:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/rclone-sync-test-ignore-file"
2025/03/26 06:19:35 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2025/03/26 06:19:39 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = adde49803a5eb6f7369dd90a868498ab OK
2025/03/26 06:19:41 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/03/26 06:19:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/rclone-sync-test': Waiting for checks to finish
2025/03/26 06:19:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/rclone-sync-test': Waiting for transfers to finish
2025/03/26 06:19:41 DEBUG : Waiting for deletions to finish
2025/03/26 06:19:41 INFO  : There was nothing to transfer
2025/03/26 06:19:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:19:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:19:43 DEBUG : Waiting for deletions to finish
2025/03/26 06:19:43 INFO  : rclone-sync-test-include: Removing directory
2025/03/26 06:19:43 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/03/26 06:19:43 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2025/03/26 06:19:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': failed to delete 1 directories
2025/03/26 06:19:43 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:19:45 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/03/26 06:19:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/rclone-sync-test-include/layer2': Waiting for checks to finish
2025/03/26 06:19:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/rclone-sync-test-include/layer2': Waiting for transfers to finish
2025/03/26 06:19:45 DEBUG : Waiting for deletions to finish
2025/03/26 06:19:45 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:19:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:19:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:19:47 DEBUG : Waiting for deletions to finish
2025/03/26 06:19:47 INFO  : rclone-sync-test-include: Removing directory
2025/03/26 06:19:48 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/03/26 06:19:48 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2025/03/26 06:19:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': failed to delete 1 directories
2025/03/26 06:19:48 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:19:49 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/03/26 06:19:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/rclone-sync-test-ignore-file': Waiting for checks to finish
2025/03/26 06:19:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/rclone-sync-test-ignore-file': Waiting for transfers to finish
2025/03/26 06:19:49 DEBUG : Waiting for deletions to finish
2025/03/26 06:19:49 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:19:51 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/03/26 06:19:52 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (30.95s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:20:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/dst"
2025/03/26 06:20:01 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/31u3jie661vd5p8j7rtc3hgbh0"
2025/03/26 06:20:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/CompareDest"
2025/03/26 06:20:03 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/gveqi14airsml4bgu7krj116o8"
2025/03/26 06:20:05 DEBUG : one: Need to transfer - File not found at Destination
2025/03/26 06:20:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for checks to finish
2025/03/26 06:20:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for transfers to finish
2025/03/26 06:20:07 DEBUG : one: md5 = 65abeabb5049e6d152b5597a853937ab OK
2025/03/26 06:20:07 INFO  : one: Copied (new)
2025/03/26 06:20:07 DEBUG : Waiting for deletions to finish
2025/03/26 06:20:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for checks to finish
2025/03/26 06:20:08 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/03/26 06:20:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for transfers to finish
2025/03/26 06:20:10 DEBUG : one: md5 = a55d877fd2a4836b60175adac43cd5a2 OK
2025/03/26 06:20:10 INFO  : one: Copied (replaced existing)
2025/03/26 06:20:10 DEBUG : Waiting for deletions to finish
2025/03/26 06:20:12 DEBUG : dst/one: md5 = 68e1fb78095782558ad073de468a6175 OK
2025/03/26 06:20:14 DEBUG : CompareDest/one: md5 = d6d650b50100103b7f4654b23d4cd291 OK
2025/03/26 06:20:15 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/03/26 06:20:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for checks to finish
2025/03/26 06:20:15 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:20:15 DEBUG : one: Destination found in --compare-dest, skipping
2025/03/26 06:20:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for transfers to finish
2025/03/26 06:20:15 DEBUG : Waiting for deletions to finish
2025/03/26 06:20:15 INFO  : There was nothing to transfer
2025/03/26 06:20:17 DEBUG : CompareDest/two: md5 = 9c2eee1f6d0b960e310b8ce6c2c416d0 OK
2025/03/26 06:20:18 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:20:18 DEBUG : two: Destination found in --compare-dest, skipping
2025/03/26 06:20:18 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/03/26 06:20:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for checks to finish
2025/03/26 06:20:18 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:20:18 DEBUG : one: Destination found in --compare-dest, skipping
2025/03/26 06:20:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for transfers to finish
2025/03/26 06:20:18 DEBUG : Waiting for deletions to finish
2025/03/26 06:20:18 INFO  : There was nothing to transfer
2025/03/26 06:20:19 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:20:19 DEBUG : two: Destination found in --compare-dest, skipping
2025/03/26 06:20:19 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/03/26 06:20:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for checks to finish
2025/03/26 06:20:20 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:20:20 DEBUG : one: Destination found in --compare-dest, skipping
2025/03/26 06:20:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for transfers to finish
2025/03/26 06:20:20 DEBUG : Waiting for deletions to finish
2025/03/26 06:20:20 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2025/03/26 06:20:21 DEBUG : two: Sizes differ (src 5 vs dst 3)
2025/03/26 06:20:21 DEBUG : two: Need to transfer - File not found at Destination
2025/03/26 06:20:21 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/03/26 06:20:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for checks to finish
2025/03/26 06:20:21 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:20:21 DEBUG : one: Destination found in --compare-dest, skipping
2025/03/26 06:20:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for transfers to finish
2025/03/26 06:20:23 DEBUG : two: md5 = 9db79c17681c696388ce8f7d95f2ab6d OK
2025/03/26 06:20:23 INFO  : two: Copied (new)
2025/03/26 06:20:23 DEBUG : Waiting for deletions to finish
2025/03/26 06:20:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/03/26 06:20:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/03/26 06:20:27 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/03/26 06:20:27 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncCompareDest (26.14s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:20:29 DEBUG : pre-dest1/1: md5 = faaa5e0520a29b6e9f495fb2e798a086 OK
2025/03/26 06:20:32 DEBUG : pre-dest2/2: md5 = b2b7cc7752568255c628930ffbc342b6 OK
2025/03/26 06:20:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/dest"
2025/03/26 06:20:32 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/rg03c1jvnehrrc617i0lnqjddc"
2025/03/26 06:20:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/pre-dest1"
2025/03/26 06:20:34 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/bbnblvh6k061ssopqrp18kd7gc"
2025/03/26 06:20:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/pre-dest2"
2025/03/26 06:20:35 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/dgicm1h6b5ejvlltm8eeif0bnk"
2025/03/26 06:20:36 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:20:36 DEBUG : 1: Destination found in --compare-dest, skipping
2025/03/26 06:20:36 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:20:36 DEBUG : 2: Destination found in --compare-dest, skipping
2025/03/26 06:20:37 DEBUG : 3: Need to transfer - File not found at Destination
2025/03/26 06:20:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dest': Waiting for checks to finish
2025/03/26 06:20:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dest': Waiting for transfers to finish
2025/03/26 06:20:39 DEBUG : 3: md5 = 2bf8664dddf7506b91dc60166c67906d OK
2025/03/26 06:20:39 INFO  : 3: Copied (new)
2025/03/26 06:20:39 DEBUG : Waiting for deletions to finish
2025/03/26 06:20:42 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2025/03/26 06:20:43 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2025/03/26 06:20:43 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (16.77s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:20:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/dst"
2025/03/26 06:20:44 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/31u3jie661vd5p8j7rtc3hgbh0"
2025/03/26 06:20:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/CopyDest"
2025/03/26 06:20:46 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/d09o6po3f7bm6ce32vdgs8h9ls"
2025/03/26 06:20:48 DEBUG : one: Need to transfer - File not found at Destination
2025/03/26 06:20:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for checks to finish
2025/03/26 06:20:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for transfers to finish
2025/03/26 06:20:50 DEBUG : one: md5 = 4aeede3f4ca74704e4c0d7419c26ed18 OK
2025/03/26 06:20:50 INFO  : one: Copied (new)
2025/03/26 06:20:50 DEBUG : Waiting for deletions to finish
2025/03/26 06:20:51 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/03/26 06:20:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for checks to finish
2025/03/26 06:20:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for transfers to finish
2025/03/26 06:20:53 DEBUG : one: md5 = 2b5b2db057c6d8de61fdaa225e951270 OK
2025/03/26 06:20:53 INFO  : one: Copied (replaced existing)
2025/03/26 06:20:53 DEBUG : Waiting for deletions to finish
2025/03/26 06:20:54 DEBUG : dst/one: md5 = 27d60168c980c524fa3ee633735e821a OK
2025/03/26 06:20:56 DEBUG : CopyDest/one: md5 = 6461b345bddbac49e99fd69a62681314 OK
2025/03/26 06:20:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/BackupDir"
2025/03/26 06:20:57 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/s6dbk3lfi7c9kfvo6j7bla9m0g"
2025/03/26 06:20:59 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/03/26 06:20:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for checks to finish
2025/03/26 06:20:59 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:20:59 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/03/26 06:21:01 INFO  : one: Moved (server-side)
2025/03/26 06:21:02 INFO  : one: Copied (server-side copy)
2025/03/26 06:21:02 DEBUG : one: Destination found in --copy-dest, using server-side copy
2025/03/26 06:21:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for transfers to finish
2025/03/26 06:21:02 DEBUG : Waiting for deletions to finish
2025/03/26 06:21:04 DEBUG : CopyDest/two: md5 = c3e5786159916aff4f98360bcefd3014 OK
2025/03/26 06:21:05 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:21:06 INFO  : two: Copied (server-side copy)
2025/03/26 06:21:06 DEBUG : two: Destination found in --copy-dest, using server-side copy
2025/03/26 06:21:06 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:21:06 DEBUG : one: Unchanged skipping
2025/03/26 06:21:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for checks to finish
2025/03/26 06:21:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for transfers to finish
2025/03/26 06:21:06 DEBUG : Waiting for deletions to finish
2025/03/26 06:21:07 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:21:07 DEBUG : one: Unchanged skipping
2025/03/26 06:21:07 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:21:07 DEBUG : two: Unchanged skipping
2025/03/26 06:21:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for checks to finish
2025/03/26 06:21:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for transfers to finish
2025/03/26 06:21:07 DEBUG : Waiting for deletions to finish
2025/03/26 06:21:07 INFO  : There was nothing to transfer
2025/03/26 06:21:08 DEBUG : CopyDest/three: md5 = 9508e8ca5cdc1c6948faf6ba816248b5 OK
2025/03/26 06:21:09 DEBUG : three: Sizes differ (src 7 vs dst 5)
2025/03/26 06:21:09 DEBUG : three: Destination not found in --copy-dest
2025/03/26 06:21:09 DEBUG : three: Need to transfer - File not found at Destination
2025/03/26 06:21:09 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:21:09 DEBUG : one: Unchanged skipping
2025/03/26 06:21:09 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/03/26 06:21:09 DEBUG : two: Unchanged skipping
2025/03/26 06:21:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for checks to finish
2025/03/26 06:21:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for transfers to finish
2025/03/26 06:21:11 DEBUG : three: md5 = 05cd53d68919a91c9b5d172ec65dfa6e OK
2025/03/26 06:21:11 INFO  : three: Copied (new)
2025/03/26 06:21:11 DEBUG : Waiting for deletions to finish
2025/03/26 06:21:16 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2025/03/26 06:21:16 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/03/26 06:21:16 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/03/26 06:21:16 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2025/03/26 06:21:16 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/03/26 06:21:16 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/03/26 06:21:17 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (33.78s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:21:20 DEBUG : dst/one: md5 = 5d0fe167de50b650987b7008ebee982b OK
2025/03/26 06:21:21 DEBUG : dst/two: md5 = 2520df3cfdb1288b9c6746cc9f816b31 OK
2025/03/26 06:21:23 DEBUG : dst/three.txt: md5 = e488486179d57111166a28b52642312d OK
2025/03/26 06:21:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/dst"
2025/03/26 06:21:23 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/31u3jie661vd5p8j7rtc3hgbh0"
2025/03/26 06:21:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/backup"
2025/03/26 06:21:24 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/1nrff024r7pq65ecp72fc28jb0"
2025/03/26 06:21:26 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/03/26 06:21:26 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:21:26 DEBUG : two: Unchanged skipping
2025/03/26 06:21:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for checks to finish
2025/03/26 06:21:28 INFO  : one: Moved (server-side)
2025/03/26 06:21:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for transfers to finish
2025/03/26 06:21:29 DEBUG : one: md5 = df87745fcdc6689d26b724cf6c40c27a OK
2025/03/26 06:21:29 INFO  : one: Copied (new)
2025/03/26 06:21:29 DEBUG : Waiting for deletions to finish
2025/03/26 06:21:30 INFO  : three.txt: Moved (server-side)
2025/03/26 06:21:30 INFO  : three.txt: Moved into backup dir
2025/03/26 06:21:31 DEBUG : dst/three.txt: md5 = 2616d903d5279c915d54b16f25e4bdd3 OK
2025/03/26 06:21:32 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/03/26 06:21:32 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:21:32 DEBUG : two: Unchanged skipping
2025/03/26 06:21:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for checks to finish
2025/03/26 06:21:33 INFO  : one: Deleted
2025/03/26 06:21:34 INFO  : one: Moved (server-side)
2025/03/26 06:21:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for transfers to finish
2025/03/26 06:21:35 DEBUG : one: md5 = 2f66998c31523ee492db4725e84fc92a OK
2025/03/26 06:21:35 INFO  : one: Copied (new)
2025/03/26 06:21:35 DEBUG : Waiting for deletions to finish
2025/03/26 06:21:36 INFO  : three.txt: Deleted
2025/03/26 06:21:36 INFO  : three.txt: Moved (server-side)
2025/03/26 06:21:36 INFO  : three.txt: Moved into backup dir
2025/03/26 06:21:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/03/26 06:21:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/03/26 06:21:40 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/03/26 06:21:40 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/03/26 06:21:40 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/03/26 06:21:40 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncBackupDir (23.39s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:21:43 DEBUG : dst/one: md5 = a82084e49d96536a17812a06b1d7b337 OK
2025/03/26 06:21:45 DEBUG : dst/two: md5 = 4577d6fc367dddad1c64bfe06f04fca1 OK
2025/03/26 06:21:46 DEBUG : dst/three.txt: md5 = 207fc15bd0a13f38529decaa3fb2946c OK
2025/03/26 06:21:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/dst"
2025/03/26 06:21:47 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/31u3jie661vd5p8j7rtc3hgbh0"
2025/03/26 06:21:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/backup"
2025/03/26 06:21:47 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/1nrff024r7pq65ecp72fc28jb0"
2025/03/26 06:21:49 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/03/26 06:21:49 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:21:49 DEBUG : two: Unchanged skipping
2025/03/26 06:21:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for checks to finish
2025/03/26 06:21:51 INFO  : one: Moved (server-side) to: one.bak
2025/03/26 06:21:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for transfers to finish
2025/03/26 06:21:52 DEBUG : one: md5 = d042c468398b387ac7db6aeef1d4b664 OK
2025/03/26 06:21:52 INFO  : one: Copied (new)
2025/03/26 06:21:52 DEBUG : Waiting for deletions to finish
2025/03/26 06:21:53 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/03/26 06:21:53 INFO  : three.txt: Moved into backup dir
2025/03/26 06:21:55 DEBUG : dst/three.txt: md5 = 34fc271b30a89289857b7d8d0368860b OK
2025/03/26 06:21:56 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/03/26 06:21:56 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:21:56 DEBUG : two: Unchanged skipping
2025/03/26 06:21:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for checks to finish
2025/03/26 06:21:56 INFO  : one.bak: Deleted
2025/03/26 06:21:57 INFO  : one: Moved (server-side) to: one.bak
2025/03/26 06:21:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for transfers to finish
2025/03/26 06:21:58 DEBUG : one: md5 = a0cc71db8627f0490d44d0bb4a505809 OK
2025/03/26 06:21:58 INFO  : one: Copied (new)
2025/03/26 06:21:58 DEBUG : Waiting for deletions to finish
2025/03/26 06:21:59 INFO  : three.txt.bak: Deleted
2025/03/26 06:21:59 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/03/26 06:21:59 INFO  : three.txt: Moved into backup dir
2025/03/26 06:22:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/03/26 06:22:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/03/26 06:22:03 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/03/26 06:22:03 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/03/26 06:22:03 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/03/26 06:22:03 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncBackupDirWithSuffix (22.79s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:22:06 DEBUG : dst/one: md5 = 5f720f5e58dcfe3e640cf12d4132b99f OK
2025/03/26 06:22:07 DEBUG : dst/two: md5 = 55057c49beac75e3b8c761a04344fb18 OK
2025/03/26 06:22:09 DEBUG : dst/three.txt: md5 = a452b7f1e00075d68c4a10f439654223 OK
2025/03/26 06:22:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/dst"
2025/03/26 06:22:09 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/31u3jie661vd5p8j7rtc3hgbh0"
2025/03/26 06:22:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/backup"
2025/03/26 06:22:10 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/1nrff024r7pq65ecp72fc28jb0"
2025/03/26 06:22:12 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/03/26 06:22:12 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:22:12 DEBUG : two: Unchanged skipping
2025/03/26 06:22:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for checks to finish
2025/03/26 06:22:13 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/03/26 06:22:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for transfers to finish
2025/03/26 06:22:15 DEBUG : one: md5 = 94e7187dddf6a0da622b22c3c5a7e34f OK
2025/03/26 06:22:15 INFO  : one: Copied (new)
2025/03/26 06:22:15 DEBUG : Waiting for deletions to finish
2025/03/26 06:22:16 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/03/26 06:22:16 INFO  : three.txt: Moved into backup dir
2025/03/26 06:22:17 DEBUG : dst/three.txt: md5 = 1ee422e9fd8ef57f1ee8299037c37732 OK
2025/03/26 06:22:18 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/03/26 06:22:18 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:22:18 DEBUG : two: Unchanged skipping
2025/03/26 06:22:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for checks to finish
2025/03/26 06:22:19 INFO  : one-2019-01-01: Deleted
2025/03/26 06:22:19 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/03/26 06:22:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for transfers to finish
2025/03/26 06:22:21 DEBUG : one: md5 = aed6f1c9360eaa153b9974967f55383c OK
2025/03/26 06:22:21 INFO  : one: Copied (new)
2025/03/26 06:22:21 DEBUG : Waiting for deletions to finish
2025/03/26 06:22:22 INFO  : three-2019-01-01.txt: Deleted
2025/03/26 06:22:22 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/03/26 06:22:22 INFO  : three.txt: Moved into backup dir
2025/03/26 06:22:25 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/03/26 06:22:25 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/03/26 06:22:26 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/03/26 06:22:26 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/03/26 06:22:26 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/03/26 06:22:26 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (22.83s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:22:29 DEBUG : dst/one: md5 = 494dfa7bc78ffd0da8f9601ca8e784a6 OK
2025/03/26 06:22:30 DEBUG : dst/two: md5 = f10a5d71a079557719e45bafd3482b00 OK
2025/03/26 06:22:31 DEBUG : dst/three.txt: md5 = 6f30c2f41c7550bf38493343c8e85b21 OK
2025/03/26 06:22:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/dst"
2025/03/26 06:22:32 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/31u3jie661vd5p8j7rtc3hgbh0"
2025/03/26 06:22:33 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/03/26 06:22:33 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:22:33 DEBUG : two: Unchanged skipping
2025/03/26 06:22:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for checks to finish
2025/03/26 06:22:34 INFO  : one: Moved (server-side) to: one.bak
2025/03/26 06:22:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for transfers to finish
2025/03/26 06:22:35 DEBUG : one: md5 = e444fc7f56c4f401f09a90f30d7e0981 OK
2025/03/26 06:22:35 INFO  : one: Copied (new)
2025/03/26 06:22:35 DEBUG : Waiting for deletions to finish
2025/03/26 06:22:36 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/03/26 06:22:36 INFO  : three.txt: Moved into backup dir
2025/03/26 06:22:38 DEBUG : dst/three.txt: md5 = 72878baeac5352cdc2400dbd10fc4090 OK
2025/03/26 06:22:39 DEBUG : one.bak: Excluded (Path Filter)
2025/03/26 06:22:39 DEBUG : three.txt.bak: Excluded (Path Filter)
2025/03/26 06:22:39 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/03/26 06:22:39 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:22:39 DEBUG : two: Unchanged skipping
2025/03/26 06:22:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for checks to finish
2025/03/26 06:22:39 INFO  : one.bak: Deleted
2025/03/26 06:22:40 INFO  : one: Moved (server-side) to: one.bak
2025/03/26 06:22:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova/dst': Waiting for transfers to finish
2025/03/26 06:22:41 DEBUG : one: md5 = 4fde5be441c055908a158b9f770655b9 OK
2025/03/26 06:22:41 INFO  : one: Copied (new)
2025/03/26 06:22:41 DEBUG : Waiting for deletions to finish
2025/03/26 06:22:42 INFO  : three.txt.bak: Deleted
2025/03/26 06:22:43 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/03/26 06:22:43 INFO  : three.txt: Moved into backup dir
2025/03/26 06:22:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/03/26 06:22:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/03/26 06:22:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/03/26 06:22:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/03/26 06:22:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/03/26 06:22:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncBackupDirSuffixOnly (19.57s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:22:48 DEBUG : dst/one: md5 = c0b9e6d0dac6c68c5eae7591fe4bcfe9 OK
2025/03/26 06:22:50 DEBUG : dst/two: md5 = 82015bed0b5e683ce792b37eaeacefb4 OK
2025/03/26 06:22:51 DEBUG : dst/three.txt: md5 = 21bd7c081068773ad3d2a97e989e54d8 OK
2025/03/26 06:22:52 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/dst"
2025/03/26 06:22:52 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/31u3jie661vd5p8j7rtc3hgbh0"
2025/03/26 06:22:53 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/03/26 06:22:54 INFO  : one: Moved (server-side) to: one.bak
2025/03/26 06:22:55 DEBUG : one: md5 = 2d18631a1b9730b7da4b41315519283b OK
2025/03/26 06:22:55 INFO  : one: Copied (new)
2025/03/26 06:22:55 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:22:55 DEBUG : two: Unchanged skipping
2025/03/26 06:22:56 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/03/26 06:22:56 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/03/26 06:22:58 DEBUG : three.txt: md5 = 9ec7f6bc3f1ef88d9be0007345ea20e6 OK
2025/03/26 06:22:58 INFO  : three.txt: Copied (new)
2025/03/26 06:22:59 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/03/26 06:23:00 INFO  : one.bak: Deleted
2025/03/26 06:23:00 INFO  : one: Moved (server-side) to: one.bak
2025/03/26 06:23:02 DEBUG : one: md5 = 3c134bf2ac05a91deb068690c1e09c30 OK
2025/03/26 06:23:02 INFO  : one: Copied (new)
2025/03/26 06:23:02 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:23:02 DEBUG : two: Unchanged skipping
2025/03/26 06:23:02 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/03/26 06:23:03 INFO  : three.txt.bak: Deleted
2025/03/26 06:23:03 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/03/26 06:23:05 DEBUG : three.txt: md5 = d8941852dd003f10fc17ba1631410d32 OK
2025/03/26 06:23:05 INFO  : three.txt: Copied (new)
2025/03/26 06:23:08 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/03/26 06:23:08 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/03/26 06:23:08 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/03/26 06:23:08 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/03/26 06:23:08 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/03/26 06:23:08 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/03/26 06:23:08 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncSuffix (22.58s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:23:11 DEBUG : dst/one: md5 = e15f1a1b1267815d3ef93722075e8183 OK
2025/03/26 06:23:13 DEBUG : dst/two: md5 = 413360a43b58b01e3bed54dd267713a4 OK
2025/03/26 06:23:14 DEBUG : dst/three.txt: md5 = 493686eb46d5792eae806648a47b614c OK
2025/03/26 06:23:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-parohux9hova/dst"
2025/03/26 06:23:15 DEBUG : Creating backend with remote "TestDrive:crypt/uj4iu7kmio0fibme6e6qq80unosbrvhc0cvdom6n1buefdqg9610/31u3jie661vd5p8j7rtc3hgbh0"
2025/03/26 06:23:16 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/03/26 06:23:16 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/03/26 06:23:18 DEBUG : one: md5 = 150a3d2d15d7a4ee2a03a35f6eb621f6 OK
2025/03/26 06:23:18 INFO  : one: Copied (new)
2025/03/26 06:23:18 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:23:18 DEBUG : two: Unchanged skipping
2025/03/26 06:23:19 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/03/26 06:23:19 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/03/26 06:23:21 DEBUG : three.txt: md5 = 3ffc3a33b732e42b71fb70bc95214d3f OK
2025/03/26 06:23:21 INFO  : three.txt: Copied (new)
2025/03/26 06:23:22 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/03/26 06:23:23 INFO  : one-2019-01-01: Deleted
2025/03/26 06:23:23 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/03/26 06:23:24 DEBUG : one: md5 = 570beeaaf2d6f734e641ca2fee7d010b OK
2025/03/26 06:23:24 INFO  : one: Copied (new)
2025/03/26 06:23:25 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:23:25 DEBUG : two: Unchanged skipping
2025/03/26 06:23:25 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/03/26 06:23:26 INFO  : three-2019-01-01.txt: Deleted
2025/03/26 06:23:26 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/03/26 06:23:27 DEBUG : three.txt: md5 = 204400501fb93666279b9abe154614d2 OK
2025/03/26 06:23:27 INFO  : three.txt: Copied (new)
2025/03/26 06:23:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/03/26 06:23:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/03/26 06:23:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/03/26 06:23:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/03/26 06:23:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/03/26 06:23:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/03/26 06:23:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncSuffixKeepExtension (22.66s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:23:33 DEBUG : Testêé: md5 = 766bdbb7fc807d1883da888146ff0d74 OK
2025/03/26 06:23:34 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2025/03/26 06:23:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:23:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:23:35 DEBUG : Testêé: md5 = c320fa9d88bbba71f0837e26fdf2fa3b OK
2025/03/26 06:23:35 INFO  : Testêé: Copied (replaced existing) to: Testêé
2025/03/26 06:23:35 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (4.76s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:23:37 DEBUG : existing: Need to transfer - File not found at Destination
2025/03/26 06:23:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:23:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:23:38 DEBUG : existing: md5 = 345ef6dabdcd68b26147c51aba61ef2d OK
2025/03/26 06:23:38 INFO  : existing: Copied (new)
2025/03/26 06:23:38 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:23:39 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2025/03/26 06:23:39 ERROR : existing: Source and destination exist but do not match: immutable file modified
2025/03/26 06:23:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:23:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:23:39 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': not deleting files as there were IO errors
2025/03/26 06:23:39 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncImmutable (4.43s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:23:42 DEBUG : EXISTING: md5 = 0044bc83f4af221a4b5ecc10a0addb35 OK
2025/03/26 06:23:43 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:23:43 DEBUG : existing: Unchanged skipping
2025/03/26 06:23:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:23:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:23:43 DEBUG : Waiting for deletions to finish
2025/03/26 06:23:43 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (3.04s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    sync_test.go:2635: Skipping test as local or remote are case-sensitive
--- SKIP: TestFixCase (0.46s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", 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-parohux9hova'", Local "Local file system at /tmp/rclone929948549", 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-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.31s)
    --- SKIP: TestMaxTransfer/Hard (0.39s)
    --- SKIP: TestMaxTransfer/Soft (0.45s)
    --- SKIP: TestMaxTransfer/Cautious (0.47s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:23:47 DEBUG : both0: md5 = ac3de6648d294a32033bf678b2f7291f OK
2025/03/26 06:23:48 DEBUG : only0: md5 = 65585f83f5d4e1ebe22a5fcf7c494a56 OK
2025/03/26 06:23:50 DEBUG : both1: md5 = f8a8249b57a4961e4fa8126963b0e8d1 OK
2025/03/26 06:23:51 DEBUG : only1: md5 = b8dc7809c74ab8685641f8b88ce284c0 OK
2025/03/26 06:23:53 DEBUG : both2: md5 = 1372bf9317746b1f13bfde7e01a6682e OK
2025/03/26 06:23:54 DEBUG : only2: md5 = bc061fb9985b0948440cf06ea980d68f OK
2025/03/26 06:23:55 DEBUG : both3: md5 = b6f6d4acc2ee23a13fcaf8f4de921d92 OK
2025/03/26 06:23:57 DEBUG : only3: md5 = da711339e4b2f7d099768a58c70ec73d OK
2025/03/26 06:23:58 DEBUG : both4: md5 = 429acf5ff704c81497ff6bebd6ae18f7 OK
2025/03/26 06:24:00 DEBUG : only4: md5 = 316a308d0bb0a1b73ae82951e3803d2f OK
2025/03/26 06:24:01 DEBUG : both5: md5 = d2d906d5232b6b807c7b231eaa628a53 OK
2025/03/26 06:24:02 DEBUG : only5: md5 = a00c30daf74735aeb25a407e3005edd5 OK
2025/03/26 06:24:04 DEBUG : both6: md5 = 88dddbe072f755c55b8444cb63240827 OK
2025/03/26 06:24:05 DEBUG : only6: md5 = 385256307f5d6d5749faf37b206935fc OK
2025/03/26 06:24:06 DEBUG : both7: md5 = a49cee4e0e5384d0377e60b37de383f0 OK
2025/03/26 06:24:08 DEBUG : only7: md5 = 59b0f03d55c85d0ff72904f24a6ddc68 OK
2025/03/26 06:24:09 DEBUG : both8: md5 = 5d6c6ce769314c82af4251f4ce9c972b OK
2025/03/26 06:24:11 DEBUG : only8: md5 = a67e8d4255a62c92419c5ad550ab6f55 OK
2025/03/26 06:24:12 DEBUG : both9: md5 = a4fbcbd147b0449b8e1c613463b2b1cc OK
2025/03/26 06:24:13 DEBUG : only9: md5 = 162aebe50286ce1f2b237e8fd2a49838 OK
2025/03/26 06:24:15 DEBUG : both10: md5 = 5609b96a35b466df7bc3382f0c4881d1 OK
2025/03/26 06:24:16 DEBUG : only10: md5 = 0e7696c71b508493856905ebe9e5e5b0 OK
2025/03/26 06:24:18 DEBUG : both11: md5 = 7025e1c5e8f25d5c6aa0dcd6a475d293 OK
2025/03/26 06:24:19 DEBUG : only11: md5 = c632e68768bdff31d91f1212451faaa3 OK
2025/03/26 06:24:20 DEBUG : both12: md5 = 2f55cb2f32ecac69bd6df028efab8f34 OK
2025/03/26 06:24:22 DEBUG : only12: md5 = 197dfd51e953388d3dde0b4fe77aeb63 OK
2025/03/26 06:24:23 DEBUG : both13: md5 = bc881e04df798c862c5368b608a16444 OK
2025/03/26 06:24:25 DEBUG : only13: md5 = c99a6447bd0f4c0517e5737aaf03d427 OK
2025/03/26 06:24:26 DEBUG : both14: md5 = c198f05fb0b185ee79f81afd2370dcae OK
2025/03/26 06:24:27 DEBUG : only14: md5 = 13f79540d31e8f2e39840c0349b1a86e OK
2025/03/26 06:24:29 DEBUG : both15: md5 = a0ef70cb1da2f3984f4c0735c639e087 OK
2025/03/26 06:24:30 DEBUG : only15: md5 = 3f3d7a9fb4d14d9593de235f0e525b87 OK
2025/03/26 06:24:31 DEBUG : both16: md5 = a06cc9017259fd05d085e169dc71dda6 OK
2025/03/26 06:24:33 DEBUG : only16: md5 = fbeb6b36182e3812219b307c1e4868fe OK
2025/03/26 06:24:34 DEBUG : both17: md5 = 4a9448a02c65cc45108b04bc05a88e5f OK
2025/03/26 06:24:35 DEBUG : only17: md5 = d655c775902044d15a06168603c49a4e OK
2025/03/26 06:24:37 DEBUG : both18: md5 = 70ed1b1e617f72b360cd1dba52879a7e OK
2025/03/26 06:24:39 DEBUG : only18: md5 = b7359860ac43c626d847b205db9f5dcf OK
2025/03/26 06:24:40 DEBUG : both19: md5 = b8dc7ddfbfe0cf7cffbc5e164423e26e OK
2025/03/26 06:24:42 DEBUG : only19: md5 = bfbd66096daeee495a843a28b6e1cf12 OK
2025/03/26 06:24:42 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:24:42 DEBUG : both0: Unchanged skipping
2025/03/26 06:24:42 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:24:42 DEBUG : both1: Unchanged skipping
2025/03/26 06:24:42 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:24:42 DEBUG : both10: Unchanged skipping
2025/03/26 06:24:42 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:24:42 DEBUG : both11: Unchanged skipping
2025/03/26 06:24:42 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:24:42 DEBUG : both12: Unchanged skipping
2025/03/26 06:24:42 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:24:42 DEBUG : both13: Unchanged skipping
2025/03/26 06:24:42 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:24:42 DEBUG : both14: Unchanged skipping
2025/03/26 06:24:42 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:24:42 DEBUG : both15: Unchanged skipping
2025/03/26 06:24:42 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:24:42 DEBUG : both16: Unchanged skipping
2025/03/26 06:24:42 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:24:42 DEBUG : both17: Unchanged skipping
2025/03/26 06:24:42 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:24:42 DEBUG : both18: Unchanged skipping
2025/03/26 06:24:42 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:24:42 DEBUG : both19: Unchanged skipping
2025/03/26 06:24:42 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:24:42 DEBUG : both2: Unchanged skipping
2025/03/26 06:24:42 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:24:42 DEBUG : both3: Unchanged skipping
2025/03/26 06:24:42 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:24:42 DEBUG : both4: Unchanged skipping
2025/03/26 06:24:42 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:24:42 DEBUG : both5: Unchanged skipping
2025/03/26 06:24:42 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:24:42 DEBUG : both6: Unchanged skipping
2025/03/26 06:24:42 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:24:42 DEBUG : both7: Unchanged skipping
2025/03/26 06:24:42 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:24:42 DEBUG : both8: Unchanged skipping
2025/03/26 06:24:42 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:24:42 DEBUG : both9: Unchanged skipping
2025/03/26 06:24:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:24:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:24:42 DEBUG : Waiting for deletions to finish
2025/03/26 06:24:43 INFO  : only17: Deleted
2025/03/26 06:24:43 INFO  : only12: Deleted
2025/03/26 06:24:43 INFO  : only11: Deleted
2025/03/26 06:24:43 INFO  : only15: Deleted
2025/03/26 06:24:43 INFO  : only19: Deleted
2025/03/26 06:24:43 INFO  : only4: Deleted
2025/03/26 06:24:43 INFO  : only14: Deleted
2025/03/26 06:24:43 INFO  : only0: Deleted
2025/03/26 06:24:44 INFO  : only2: Deleted
2025/03/26 06:24:44 INFO  : only7: Deleted
2025/03/26 06:24:44 INFO  : only9: Deleted
2025/03/26 06:24:44 INFO  : only6: Deleted
2025/03/26 06:24:44 INFO  : only1: Deleted
2025/03/26 06:24:44 INFO  : only13: Deleted
2025/03/26 06:24:44 INFO  : only10: Deleted
2025/03/26 06:24:44 INFO  : only16: Deleted
2025/03/26 06:24:45 INFO  : only18: Deleted
2025/03/26 06:24:45 INFO  : only3: Deleted
2025/03/26 06:24:45 INFO  : only5: Deleted
2025/03/26 06:24:45 INFO  : only8: Deleted
2025/03/26 06:24:45 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (69.22s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:24:56 DEBUG : both0: md5 = 1ee03d5c489571ce386d91d4f7386af6 OK
2025/03/26 06:24:57 DEBUG : only0: md5 = ccf74191934dba35144b76964b621f9c OK
2025/03/26 06:24:59 DEBUG : both1: md5 = 57adcf0ceca70b06ca4960abcfe76e92 OK
2025/03/26 06:25:00 DEBUG : only1: md5 = abe021771371482818b7ecb03a8f974d OK
2025/03/26 06:25:01 DEBUG : both2: md5 = d78b8eabb4d6bcc6d573d90602987908 OK
2025/03/26 06:25:03 DEBUG : only2: md5 = e4a2a0c1b95384a628cebc427514afa3 OK
2025/03/26 06:25:04 DEBUG : both3: md5 = 4a0837d887c26d16104ed6bd0031d69b OK
2025/03/26 06:25:05 DEBUG : only3: md5 = 320a7e5f0adba703ae78a4f43ee4dc51 OK
2025/03/26 06:25:07 DEBUG : both4: md5 = 3b41d67c332c35c30a27d8b7d8681ad1 OK
2025/03/26 06:25:08 DEBUG : only4: md5 = 58014b1c2be4e05db27cfb51ed9ccd97 OK
2025/03/26 06:25:10 DEBUG : both5: md5 = 19292eedc32497a5916c0a5e83132a97 OK
2025/03/26 06:25:11 DEBUG : only5: md5 = 7d77c56428e1024e4f3b17dbcbea9704 OK
2025/03/26 06:25:12 DEBUG : both6: md5 = 0a1fde09e117e1cd4a1923836a7d54c2 OK
2025/03/26 06:25:14 DEBUG : only6: md5 = 71a5530ab43360d8e83537f626cb89b6 OK
2025/03/26 06:25:15 DEBUG : both7: md5 = 878e0a3bdd562bcb4a3a303fba9001b5 OK
2025/03/26 06:25:16 DEBUG : only7: md5 = 980bb144c006bae7f6e4040927817a17 OK
2025/03/26 06:25:18 DEBUG : both8: md5 = 65fd22293d35b610e8d5bd21596939a5 OK
2025/03/26 06:25:19 DEBUG : only8: md5 = ca222e768e71e96db28bc014ac02b5ee OK
2025/03/26 06:25:20 DEBUG : both9: md5 = 3b796e08d390b7ee84ab8530e1b39580 OK
2025/03/26 06:25:22 DEBUG : only9: md5 = 13726ef3fd0ca303be84c8e2abb60071 OK
2025/03/26 06:25:23 DEBUG : both10: md5 = 54e85f036a3838c482c491dc5cb9e49b OK
2025/03/26 06:25:24 DEBUG : only10: md5 = 5b0e35f7eafb3c1a4714fd7f95ccf38f OK
2025/03/26 06:25:25 DEBUG : both11: md5 = f3927d8204a19e5d7b41e7080f1e231b OK
2025/03/26 06:25:27 DEBUG : only11: md5 = 9b174298db6367c23eb3a74b19ba4881 OK
2025/03/26 06:25:28 DEBUG : both12: md5 = b5239d793dba474183f8e9610399a26b OK
2025/03/26 06:25:29 DEBUG : only12: md5 = 5a5ea4390db55170d4089f110d2cd344 OK
2025/03/26 06:25:31 DEBUG : both13: md5 = 773a8b6a7924b7b1858ea5679d2f6807 OK
2025/03/26 06:25:32 DEBUG : only13: md5 = 56b7e2d45841a7d34b8bfd628ec8edb3 OK
2025/03/26 06:25:33 DEBUG : both14: md5 = 70ee4ad8f69545277d3b0e3f2ce8689d OK
2025/03/26 06:25:34 DEBUG : only14: md5 = 1a1b64f46d33828804ca2dfe6f0b9db9 OK
2025/03/26 06:25:36 DEBUG : both15: md5 = 4d0dd518dd42a05017df89c36daaf67f OK
2025/03/26 06:25:37 DEBUG : only15: md5 = faf9c45b5ff685767df35315d97c0d35 OK
2025/03/26 06:25:38 DEBUG : both16: md5 = 473088afe6a6c6797aaa24a1a0f48791 OK
2025/03/26 06:25:40 DEBUG : only16: md5 = 229758720b61732d2317c140a21f6242 OK
2025/03/26 06:25:41 DEBUG : both17: md5 = 77fdc70312fc03f372df9afc65a63c83 OK
2025/03/26 06:25:43 DEBUG : only17: md5 = b496f0bc028d2f115ac5f3338f966a0f OK
2025/03/26 06:25:44 DEBUG : both18: md5 = d623b7e197583bf639d02adc75eab4c6 OK
2025/03/26 06:25:45 DEBUG : only18: md5 = ab3d184218ae89363090e455e92347f1 OK
2025/03/26 06:25:47 DEBUG : both19: md5 = 0c77b376e0c202e0aeaa42da4615ee1f OK
2025/03/26 06:25:48 DEBUG : only19: md5 = d8c7075d48ab331c2587d31b5ebe129a OK
2025/03/26 06:25:49 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:25:49 DEBUG : both0: Unchanged skipping
2025/03/26 06:25:49 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:25:49 DEBUG : both1: Unchanged skipping
2025/03/26 06:25:49 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:25:49 DEBUG : both10: Unchanged skipping
2025/03/26 06:25:49 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:25:49 DEBUG : both11: Unchanged skipping
2025/03/26 06:25:49 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:25:49 DEBUG : both12: Unchanged skipping
2025/03/26 06:25:49 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:25:49 DEBUG : both13: Unchanged skipping
2025/03/26 06:25:49 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:25:49 DEBUG : both14: Unchanged skipping
2025/03/26 06:25:49 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:25:49 DEBUG : both15: Unchanged skipping
2025/03/26 06:25:49 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:25:49 DEBUG : both16: Unchanged skipping
2025/03/26 06:25:49 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:25:49 DEBUG : both17: Unchanged skipping
2025/03/26 06:25:49 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:25:49 DEBUG : both18: Unchanged skipping
2025/03/26 06:25:49 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:25:49 DEBUG : both19: Unchanged skipping
2025/03/26 06:25:49 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:25:49 DEBUG : both2: Unchanged skipping
2025/03/26 06:25:49 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:25:49 DEBUG : both3: Unchanged skipping
2025/03/26 06:25:49 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:25:49 DEBUG : both4: Unchanged skipping
2025/03/26 06:25:49 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:25:49 DEBUG : both5: Unchanged skipping
2025/03/26 06:25:49 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:25:49 DEBUG : both6: Unchanged skipping
2025/03/26 06:25:49 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:25:49 DEBUG : both7: Unchanged skipping
2025/03/26 06:25:49 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:25:49 DEBUG : both8: Unchanged skipping
2025/03/26 06:25:49 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/03/26 06:25:49 DEBUG : both9: Unchanged skipping
2025/03/26 06:25:49 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2025/03/26 06:25:49 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2025/03/26 06:25:49 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2025/03/26 06:25:49 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2025/03/26 06:25:49 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2025/03/26 06:25:49 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2025/03/26 06:25:49 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2025/03/26 06:25:49 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2025/03/26 06:25:49 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2025/03/26 06:25:49 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2025/03/26 06:25:49 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2025/03/26 06:25:49 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2025/03/26 06:25:49 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2025/03/26 06:25:49 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2025/03/26 06:25:49 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2025/03/26 06:25:49 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2025/03/26 06:25:49 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2025/03/26 06:25:49 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2025/03/26 06:25:49 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2025/03/26 06:25:49 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2025/03/26 06:25:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for checks to finish
2025/03/26 06:25:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Waiting for transfers to finish
2025/03/26 06:25:50 DEBUG : only1: md5 = 5c57c98455748188f7cf24b87e13c0ee OK
2025/03/26 06:25:50 INFO  : only1: Copied (replaced existing)
2025/03/26 06:25:50 DEBUG : only11: md5 = 605812014bf30465478179f80c60cbce OK
2025/03/26 06:25:50 INFO  : only11: Copied (replaced existing)
2025/03/26 06:25:50 DEBUG : only10: md5 = 14a9f5dcb4ff0cf69ea4253be878856d OK
2025/03/26 06:25:50 INFO  : only10: Copied (replaced existing)
2025/03/26 06:25:50 DEBUG : only0: md5 = 0810d65b674e34906b1be638f2f74712 OK
2025/03/26 06:25:50 INFO  : only0: Copied (replaced existing)
2025/03/26 06:25:51 DEBUG : only12: md5 = 91328b85ad621ca3c5010d12a050b1da OK
2025/03/26 06:25:51 INFO  : only12: Copied (replaced existing)
2025/03/26 06:25:51 DEBUG : only13: md5 = 08878636e52630b4d0bdd959e143efc8 OK
2025/03/26 06:25:51 INFO  : only13: Copied (replaced existing)
2025/03/26 06:25:51 DEBUG : only15: md5 = 798741473d8e0d84ca4c20f3bf2a0de3 OK
2025/03/26 06:25:51 INFO  : only15: Copied (replaced existing)
2025/03/26 06:25:51 DEBUG : only14: md5 = c709269ae2b57970b32bcbca3c992c52 OK
2025/03/26 06:25:51 INFO  : only14: Copied (replaced existing)
2025/03/26 06:25:52 DEBUG : only18: md5 = 658c017eb7bebe76ad11c1defbe369b6 OK
2025/03/26 06:25:52 INFO  : only18: Copied (replaced existing)
2025/03/26 06:25:52 DEBUG : only16: md5 = 4043bae170a7f259b8dba55fd9172dac OK
2025/03/26 06:25:52 INFO  : only16: Copied (replaced existing)
2025/03/26 06:25:52 DEBUG : only19: md5 = e98a6effa051b295016fa0c90acfe5f3 OK
2025/03/26 06:25:52 INFO  : only19: Copied (replaced existing)
2025/03/26 06:25:52 DEBUG : only17: md5 = 68777e1534d84605b2098c2397735a14 OK
2025/03/26 06:25:52 INFO  : only17: Copied (replaced existing)
2025/03/26 06:25:53 DEBUG : only3: md5 = b560b65f87ab2ab1ec0a6e958a461a87 OK
2025/03/26 06:25:53 INFO  : only3: Copied (replaced existing)
2025/03/26 06:25:53 DEBUG : only2: md5 = 50ef9b1c18cdb5a29992de5b533d429d OK
2025/03/26 06:25:53 INFO  : only2: Copied (replaced existing)
2025/03/26 06:25:53 DEBUG : only4: md5 = 6a0098bec54f81beeb8340c8633bceec OK
2025/03/26 06:25:53 INFO  : only4: Copied (replaced existing)
2025/03/26 06:25:53 DEBUG : only5: md5 = a287e96b8e328fe050effb08ee7af8cd OK
2025/03/26 06:25:53 INFO  : only5: Copied (replaced existing)
2025/03/26 06:25:54 DEBUG : only8: md5 = c864820551ce8899f303cb1781688f65 OK
2025/03/26 06:25:54 INFO  : only8: Copied (replaced existing)
2025/03/26 06:25:54 DEBUG : only6: md5 = 9b224179dbf115825c0a9dc4ebbac421 OK
2025/03/26 06:25:54 INFO  : only6: Copied (replaced existing)
2025/03/26 06:25:54 DEBUG : only7: md5 = 823feba3c75823680d26f4e94c2439a7 OK
2025/03/26 06:25:54 INFO  : only7: Copied (replaced existing)
2025/03/26 06:25:54 DEBUG : only9: md5 = 84f0eda046cc44f636812e58f0ec1228 OK
2025/03/26 06:25:54 INFO  : only9: Copied (replaced existing)
2025/03/26 06:25:54 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (79.07s)
=== RUN   TestSyncReplaceDirModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:26:14 DEBUG : empty_dir: Making directory with metadata
2025/03/26 06:26:14 INFO  : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/03/26 06:26:14 DEBUG : empty_on_remote: Making directory with metadata
2025/03/26 06:26:14 INFO  : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/03/26 06:26:14 DEBUG : empty_on_remote: Making directory with metadata
2025/03/26 06:26:15 INFO  : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:26:20 INFO  : test_dir1: Set directory modification time (using DirSetModTime)
2025/03/26 06:26:20 INFO  : test_dir2: Set directory modification time (using DirSetModTime)
2025/03/26 06:26:20 INFO  : test_dir2/sub_dir: Set directory modification time (using DirSetModTime)
2025/03/26 06:26:20 INFO  : empty_on_remote: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:26:27 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto"
2025/03/26 06:26:28 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8"
2025/03/26 06:26:28 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00"
--- PASS: TestSyncReplaceDirModTime (16.88s)
=== RUN   TestSyncReplaceDirModTimeWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:26:31 DEBUG : empty_dir: Making directory with metadata
2025/03/26 06:26:31 INFO  : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/03/26 06:26:31 DEBUG : empty_on_remote: Making directory with metadata
2025/03/26 06:26:31 INFO  : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/03/26 06:26:31 DEBUG : empty_on_remote: Making directory with metadata
2025/03/26 06:26: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-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:26:36 INFO  : test_dir1: Set directory modification time (using DirSetModTime)
2025/03/26 06:26:36 INFO  : test_dir2: Set directory modification time (using DirSetModTime)
2025/03/26 06:26:36 INFO  : test_dir2/sub_dir: Set directory modification time (using DirSetModTime)
2025/03/26 06:26:36 INFO  : empty_on_remote: Set directory modification time (using DirSetModTime)
2025/03/26 06:26:36 INFO  : empty_dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:26:44 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto"
2025/03/26 06:26:45 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8"
2025/03/26 06:26:45 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00"
--- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (17.51s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:26:48 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/03/26 06:26:48 DEBUG : sub dir: Making directory with metadata
2025/03/26 06:26:49 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:27:07 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/03/26 06:27:07 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/03/26 06:27:07 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/03/26 06:27:07 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:27:21 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2025/03/26 06:27:22 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/03/26 06:27:23 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2025/03/26 06:27:24 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2025/03/26 06:27:24 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/03/26 06:27:25 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/03/26 06:27:26 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/03/26 06:27:26 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/03/26 06:27:27 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/03/26 06:27:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2025/03/26 06:27:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/03/26 06:27:28 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (42.11s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:27:30 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/03/26 06:27:30 DEBUG : sub dir: Making directory with metadata
2025/03/26 06:27:31 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:27:53 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/03/26 06:27:53 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/03/26 06:27:53 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/03/26 06:27:53 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova'", Local "Local file system at /tmp/rclone929948549", Modify Window "1ms"
2025/03/26 06:28:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/03/26 06:28:07 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2025/03/26 06:28:07 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2025/03/26 06:28:08 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/03/26 06:28:09 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/03/26 06:28:09 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/03/26 06:28:10 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/03/26 06:28:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/03/26 06:28:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2025/03/26 06:28:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/03/26 06:28:12 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (43.75s)
PASS
2025/03/26 06:28:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-parohux9hova': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 15m58.952640256s (try 1/5)