"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5)
2025/05/09 01:04:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu"
2025/05/09 01:04:54 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/05/09 01:04:54 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0"
2025/05/09 01:04:55 DEBUG : Creating backend with remote "/tmp/rclone2669512264"
=== RUN   TestPipe
--- PASS: TestPipe (0.00s)
=== RUN   TestPipeConcurrent
--- PASS: TestPipeConcurrent (0.05s)
=== RUN   TestPipeOrderBy
=== RUN   TestPipeOrderBy/#00
=== RUN   TestPipeOrderBy/size
=== RUN   TestPipeOrderBy/name
=== RUN   TestPipeOrderBy/modtime
=== RUN   TestPipeOrderBy/size,ascending
=== RUN   TestPipeOrderBy/name,asc
=== RUN   TestPipeOrderBy/modtime,ascending
=== RUN   TestPipeOrderBy/size,descending
=== RUN   TestPipeOrderBy/name,desc
=== RUN   TestPipeOrderBy/modtime,descending
=== RUN   TestPipeOrderBy/size,mixed,50
=== RUN   TestPipeOrderBy/size,mixed,51
--- PASS: TestPipeOrderBy (0.00s)
    --- PASS: TestPipeOrderBy/#00 (0.00s)
    --- PASS: TestPipeOrderBy/size (0.00s)
    --- PASS: TestPipeOrderBy/name (0.00s)
    --- PASS: TestPipeOrderBy/modtime (0.00s)
    --- PASS: TestPipeOrderBy/size,ascending (0.00s)
    --- PASS: TestPipeOrderBy/name,asc (0.00s)
    --- PASS: TestPipeOrderBy/modtime,ascending (0.00s)
    --- PASS: TestPipeOrderBy/size,descending (0.00s)
    --- PASS: TestPipeOrderBy/name,desc (0.00s)
    --- PASS: TestPipeOrderBy/modtime,descending (0.00s)
    --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s)
    --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s)
=== RUN   TestNewLess
=== RUN   TestNewLess/blankOK
=== RUN   TestNewLess/tooManyParts
=== RUN   TestNewLess/tooManyParts2
=== RUN   TestNewLess/badMixed
=== RUN   TestNewLess/unknownComparison
=== RUN   TestNewLess/unknownSortDirection
=== RUN   TestNewLess/size
=== RUN   TestNewLess/name
=== RUN   TestNewLess/modtime
=== RUN   TestNewLess/size,ascending
=== RUN   TestNewLess/name,asc
=== RUN   TestNewLess/modtime,ascending
=== RUN   TestNewLess/size,descending
=== RUN   TestNewLess/name,desc
=== RUN   TestNewLess/modtime,descending
=== RUN   TestNewLess/modtime,mixed
=== RUN   TestNewLess/modtime,mixed,30
--- PASS: TestNewLess (0.00s)
    --- PASS: TestNewLess/blankOK (0.00s)
    --- PASS: TestNewLess/tooManyParts (0.00s)
    --- PASS: TestNewLess/tooManyParts2 (0.00s)
    --- PASS: TestNewLess/badMixed (0.00s)
    --- PASS: TestNewLess/unknownComparison (0.00s)
    --- PASS: TestNewLess/unknownSortDirection (0.00s)
    --- PASS: TestNewLess/size (0.00s)
    --- PASS: TestNewLess/name (0.00s)
    --- PASS: TestNewLess/modtime (0.00s)
    --- PASS: TestNewLess/size,ascending (0.00s)
    --- PASS: TestNewLess/name,asc (0.00s)
    --- PASS: TestNewLess/modtime,ascending (0.00s)
    --- PASS: TestNewLess/size,descending (0.00s)
    --- PASS: TestNewLess/name,desc (0.00s)
    --- PASS: TestNewLess/modtime,descending (0.00s)
    --- PASS: TestNewLess/modtime,mixed (0.00s)
    --- PASS: TestNewLess/modtime,mixed,30 (0.00s)
=== RUN   TestRcCopy
    rc_test.go:16: Skipping test on non local remote
--- SKIP: TestRcCopy (0.00s)
=== RUN   TestRcMove
    rc_test.go:16: Skipping test on non local remote
--- SKIP: TestRcMove (0.00s)
=== RUN   TestRcSync
    rc_test.go:16: Skipping test on non local remote
--- SKIP: TestRcSync (0.00s)
=== RUN   TestCopyWithDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:04:56 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/09 01:04:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/09 01:04:56 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2025/05/09 01:04:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:04:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:04:56 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (2.52s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:04:57 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/05/09 01:04:58 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/09 01:04:58 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/09 01:04:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:04:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:05:00 DEBUG : sub dir/hello world: md5 = 2282b2635de73082e7d4b1426619be52 OK
2025/05/09 01:05:00 INFO  : sub dir/hello world: Copied (new)
2025/05/09 01:05:00 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:05:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (6.23s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:05:04 DEBUG : metadata sub dir: Making directory with metadata
2025/05/09 01:05:04 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/09 01:05:04 DEBUG : empty metadata sub dir: Making directory with metadata
2025/05/09 01:05:04 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/09 01:05:04 DEBUG : Local file system at /tmp/rclone2669512264: File to upload is small (21 bytes), uploading instead of streaming
2025/05/09 01:05:04 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2025/05/09 01:05:04 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2025/05/09 01:05:04 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2025/05/09 01:05:04 DEBUG : Google drive root 'crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0': Skipping btime metadata as can't update it on an existing file: 2025-05-09T01:05:04.180794986Z
2025/05/09 01:05:05 INFO  : empty metadata sub dir: Updated directory metadata
2025/05/09 01:05:05 DEBUG : Google drive root 'crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0': Skipping btime metadata as can't update it on an existing file: 2025-05-09T01:05:04.180794986Z
2025/05/09 01:05:06 INFO  : metadata sub dir: Updated directory metadata
2025/05/09 01:05:06 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2025/05/09 01:05:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:05:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:05:07 DEBUG : metadata sub dir/hello metadata world: md5 = 554a4472af19dd5007c9b5db7699f0e0 OK
2025/05/09 01:05:07 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:05:10 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (8.14s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:05:12 DEBUG : metadata sub dir: Making directory with metadata
2025/05/09 01:05:12 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/09 01:05:12 DEBUG : empty metadata sub dir: Making directory with metadata
2025/05/09 01:05:12 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/09 01:05:12 DEBUG : Local file system at /tmp/rclone2669512264: File to upload is small (21 bytes), uploading instead of streaming
2025/05/09 01:05:12 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2025/05/09 01:05:12 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2025/05/09 01:05:12 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2025/05/09 01:05:12 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2025/05/09 01:05:12 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2025/05/09 01:05:12 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2025/05/09 01:05:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:05:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:05:14 DEBUG : metadata sub dir/hello metadata world: md5 = 791ba5fde4fa02701314f9ae0bdcb2ed OK
2025/05/09 01:05:14 INFO  : metadata sub dir/hello metadata world: Copied (new)
2025/05/09 01:05:14 DEBUG : Google drive root 'crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0': Skipping btime metadata as can't update it on an existing file: 2025-05-09T01:05:12.31680343Z
2025/05/09 01:05:15 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:05:18 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (7.17s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:05:19 DEBUG : Creating backend with remote "/non-existing"
2025/05/09 01:05:19 DEBUG : Config file has changed externally - reloading
2025/05/09 01:05:19 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2025/05/09 01:05:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:05:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.09s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:05:20 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/09 01:05:20 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/09 01:05:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:05:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:05:23 DEBUG : sub dir/hello world: md5 = 2ebd71ea3996362b2a70c0c5b3238363 OK
2025/05/09 01:05:23 INFO  : sub dir/hello world: Copied (new)
2025/05/09 01:05:23 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:05:25 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (5.86s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:05:26 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Running all checks before starting transfers
2025/05/09 01:05:26 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/09 01:05:26 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/09 01:05:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:05:26 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Checks finished, now starting transfers
2025/05/09 01:05:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:05:28 DEBUG : sub dir/hello world: md5 = f5503b0b699cf0795f54c54926d4d9d1 OK
2025/05/09 01:05:28 INFO  : sub dir/hello world: Copied (new)
2025/05/09 01:05:29 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:05:31 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (5.75s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:05:32 ERROR : Ignoring --no-traverse with sync
2025/05/09 01:05:32 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/09 01:05:32 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/09 01:05:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:05:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:05:34 DEBUG : sub dir/hello world: md5 = 48250c625136c578f725d0df40ad8087 OK
2025/05/09 01:05:34 INFO  : sub dir/hello world: Copied (new)
2025/05/09 01:05:34 DEBUG : Waiting for deletions to finish
2025/05/09 01:05:35 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:05:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (5.66s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:05:38 DEBUG : hello world2: Need to transfer - File not found at Destination
2025/05/09 01:05:38 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/09 01:05:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:05:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:05:39 DEBUG : hello world2: md5 = b3a435529349b6410ee554616a45d3ed OK
2025/05/09 01:05:39 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestCopyWithDepth (3.11s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:05:41 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/09 01:05:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:05:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:05:42 DEBUG : potato2: md5 = f5063a0d1cd611a802788bf8ff0a3a27 OK
2025/05/09 01:05:42 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (3.15s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:05:44 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/09 01:05:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:05:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:05:45 DEBUG : potato2: md5 = fbd2930824a08d19d5f3c8eb96cb094c OK
2025/05/09 01:05:45 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (3.38s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:05:47 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/05/09 01:05:47 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/09 01:05:47 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/05/09 01:05:47 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/05/09 01:05:47 DEBUG : sub dir: Making directory with metadata
2025/05/09 01:05:48 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/05/09 01:05:48 DEBUG : sub dir2: Making directory with metadata
2025/05/09 01:05:49 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/09 01:05:49 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/05/09 01:05:49 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/09 01:05:50 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/09 01:05:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:05:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:05:50 DEBUG : sub dir/hello world: md5 = 468fa94cd8e8f0c013cb50dcb17e96b9 OK
2025/05/09 01:05:50 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:05:54 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2025/05/09 01:05:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (8.81s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:05:56 INFO  : sub dir2: Making directory
2025/05/09 01:05:56 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/05/09 01:05:56 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/09 01:05:56 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/09 01:05:56 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/05/09 01:05:56 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2025/05/09 01:05:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/09 01:05:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:05:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:05:58 DEBUG : sub dir/hello world: md5 = fe9328fe25ea5b906660daf986c42893 OK
2025/05/09 01:05:58 INFO  : sub dir/hello world: Copied (new)
2025/05/09 01:05:59 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/05/09 01:06:01 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (5.47s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:06:01 DEBUG : sub dir2: Making directory with metadata
2025/05/09 01:06:01 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/09 01:06:01 DEBUG : sub dir: Making directory with metadata
2025/05/09 01:06:02 INFO  : sub dir: Made directory with metadata (mtime=2025-05-09T01:06:01.784854863Z)
2025/05/09 01:06:02 DEBUG : sub dir2: Making directory with metadata
2025/05/09 01:06:03 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/09 01:06:03 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/09 01:06:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:06:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:06:04 DEBUG : sub dir/hello world: md5 = ddca882be3ef98747b1e23bca578a4db OK
2025/05/09 01:06:04 INFO  : sub dir/hello world: Copied (new)
2025/05/09 01:06:04 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:06:07 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (7.07s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:06:08 DEBUG : sub dir no update dir modtime: Making directory with metadata
2025/05/09 01:06:08 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/05/09 01:06:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:06:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:06:10 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (3.90s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:06:12 INFO  : sub dir2: Making directory
2025/05/09 01:06:12 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/09 01:06:12 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/05/09 01:06:12 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/09 01:06:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:06:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:06:15 DEBUG : sub dir/hello world: md5 = ea9af83287088faa46d07b2ab798f84f OK
2025/05/09 01:06:15 INFO  : sub dir/hello world: Copied (new)
2025/05/09 01:06:15 INFO  : sub dir/hello world: Deleted
2025/05/09 01:06:15 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/05/09 01:06:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (5.29s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:06:18 DEBUG : sub dir2: Making directory with metadata
2025/05/09 01:06:18 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/09 01:06:18 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/05/09 01:06:18 DEBUG : sub dir: Making directory with metadata
2025/05/09 01:06:19 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/05/09 01:06:19 DEBUG : sub dir2: Making directory with metadata
2025/05/09 01:06:19 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/09 01:06:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/09 01:06:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:06:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:06:21 DEBUG : sub dir/hello world: md5 = 46470be9199ca4f53692b5726da240fd OK
2025/05/09 01:06:21 INFO  : sub dir/hello world: Copied (new)
2025/05/09 01:06:21 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:06:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (7.36s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.44s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:06:25 INFO  : sub dir2: Making directory
2025/05/09 01:06:26 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/09 01:06:26 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/05/09 01:06:26 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/09 01:06:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:06:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:06:28 DEBUG : sub dir/hello world: md5 = f3de08ee078f1ed814fdec8bbe06f273 OK
2025/05/09 01:06:28 INFO  : sub dir/hello world: Copied (new)
2025/05/09 01:06:28 DEBUG : Waiting for deletions to finish
2025/05/09 01:06:28 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/05/09 01:06:30 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (5.33s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:06:33 DEBUG : sub dir/hello world: md5 = 1b036e4b29f612572765e1d1a1f46ff9 OK
2025/05/09 01:06:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nutenel4fujo"
2025/05/09 01:06:33 DEBUG : Config file has changed externally - reloading
2025/05/09 01:06:33 DEBUG : Creating backend with remote "TestDrive:crypt/clhifdcrsn45f2g184lbpqfctjaa80hpj1k5ccqvmanrmnbcefh0"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu' -> Encrypted drive 'TestCryptDrive:rclone-test-nutenel4fujo'
2025/05/09 01:06:35 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/09 01:06:35 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/09 01:06:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nutenel4fujo': Waiting for checks to finish
2025/05/09 01:06:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nutenel4fujo': Waiting for transfers to finish
2025/05/09 01:06:37 INFO  : sub dir/hello world: Copied (server-side copy)
2025/05/09 01:06:38 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:06:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nutenel4fujo': Purge remote
2025/05/09 01:06:40 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (10.30s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:06:43 DEBUG : sub dir/hello world: md5 = bf9c686b5761f4d71e2e250e0effca15 OK
2025/05/09 01:06:44 INFO  : sub dir: Set directory modification time (using SetModTime)
2025/05/09 01:06:44 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/05/09 01:06:44 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/05/09 01:06:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:06:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:06:46 DEBUG : sub dir/hello world: md5 = 7fe789c22e59c9c4a7cefc6f499daf44 OK
2025/05/09 01:06:46 INFO  : sub dir/hello world: Copied (replaced existing)
2025/05/09 01:06:46 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:06:48 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (7.73s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:06:51 DEBUG : sub dir/hello world: md5 = 1f6662c0b87d1a52b4bb3d3695584a86 OK
2025/05/09 01:06:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-butuqir0yoke"
2025/05/09 01:06:51 DEBUG : Config file has changed externally - reloading
2025/05/09 01:06:51 DEBUG : Creating backend with remote "TestDrive:crypt/bs863u9fjropirhje8q8gtquqk0katftsfunivvbk3veuir9cnbg"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu' -> Encrypted drive 'TestCryptDrive:rclone-test-butuqir0yoke'
2025/05/09 01:06:53 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/09 01:06:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/09 01:06:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-butuqir0yoke': Waiting for checks to finish
2025/05/09 01:06:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-butuqir0yoke': Waiting for transfers to finish
2025/05/09 01:06:55 INFO  : sub dir/hello world: Copied (server-side copy)
2025/05/09 01:06:56 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:06:58 DEBUG : sub dir/hello world: md5 = f2ca0b616675031b85143d4925592a63 OK
2025/05/09 01:06:59 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/05/09 01:06:59 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/05/09 01:06:59 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/05/09 01:06:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-butuqir0yoke': Waiting for checks to finish
2025/05/09 01:06:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-butuqir0yoke': Waiting for transfers to finish
2025/05/09 01:07:00 INFO  : sub dir/hello world: Copied (server-side copy)
2025/05/09 01:07:00 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:07:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-butuqir0yoke': Purge remote
2025/05/09 01:07:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (15.36s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:07:06 DEBUG : sub dir/hello world: md5 = 0b548bc53d959f588a3e549dcf9b0ca6 OK
2025/05/09 01:07:07 INFO  : sub dir: Set directory modification time (using SetModTime)
2025/05/09 01:07:07 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/05/09 01:07:07 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/05/09 01:07:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:07:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:07:09 DEBUG : sub dir/hello world: md5 = ffb3874c67247e91e5aabbe440347dec OK
2025/05/09 01:07:09 INFO  : sub dir/hello world: Copied (replaced existing)
2025/05/09 01:07:09 INFO  : sub dir/hello world: Deleted
2025/05/09 01:07:09 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:07:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (7.73s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:07:14 DEBUG : sub dir/hello world: md5 = df94a4071a608fcf2c1c55b5235c25b3 OK
2025/05/09 01:07:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-taqogil0sopu"
2025/05/09 01:07:14 DEBUG : Config file has changed externally - reloading
2025/05/09 01:07:14 DEBUG : Creating backend with remote "TestDrive:crypt/ob7peqvseh3ocbr63grhfaptiihvnhiorqj5v3b4i59h50tt2g60"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu' -> Encrypted drive 'TestCryptDrive:rclone-test-taqogil0sopu'
2025/05/09 01:07:16 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/09 01:07:16 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/09 01:07:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-taqogil0sopu': Waiting for checks to finish
2025/05/09 01:07:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-taqogil0sopu': Waiting for transfers to finish
2025/05/09 01:07:19 INFO  : sub dir/hello world: Copied (server-side copy)
2025/05/09 01:07:19 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:07:21 DEBUG : sub dir/hello world: md5 = 6d80c3b5f1de90f2baf9ca53a387c261 OK
2025/05/09 01:07:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-taqogil0sopu': Using server-side directory move
2025/05/09 01:07:22 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-taqogil0sopu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/05/09 01:07:22 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/05/09 01:07:22 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/05/09 01:07:22 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/05/09 01:07:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-taqogil0sopu': Waiting for checks to finish
2025/05/09 01:07:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-taqogil0sopu': Waiting for transfers to finish
2025/05/09 01:07:23 INFO  : sub dir/hello world: Deleted
2025/05/09 01:07:23 INFO  : sub dir/hello world: Moved (server-side)
2025/05/09 01:07:24 INFO  : sub dir: Set directory modification time (using SetModTime)
2025/05/09 01:07:26 DEBUG : sub dir/hello world: md5 = 5d8cc49e586c3c4de4ddc565d0fd2cf7 OK
2025/05/09 01:07:26 DEBUG : testing file moves
2025/05/09 01:07:27 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/05/09 01:07:27 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/05/09 01:07:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-taqogil0sopu': Waiting for checks to finish
2025/05/09 01:07:27 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2025/05/09 01:07:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-taqogil0sopu': Waiting for transfers to finish
2025/05/09 01:07:27 INFO  : sub dir/hello world: Deleted
2025/05/09 01:07:28 INFO  : sub dir/hello world: Moved (server-side)
2025/05/09 01:07:28 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:07:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-taqogil0sopu': Purge remote
--- PASS: TestServerSideMoveOverSelf (20.05s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:07:34 DEBUG : sub dir/hello world: md5 = 54d3c9a7539f60828f08db5d44322125 OK
2025/05/09 01:07:34 ERROR : : error listing: directory not found
2025/05/09 01:07:35 INFO  : Local file system at /tmp/rclone2669512264: Making directory
2025/05/09 01:07:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:07:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:07:37 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (5.94s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:07:40 DEBUG : sub dir/hello world: md5 = 7e1abe60def1cbff54d9e7f424d83568 OK
2025/05/09 01:07:41 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/09 01:07:41 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/09 01:07:41 DEBUG : Local file system at /tmp/rclone2669512264: Waiting for checks to finish
2025/05/09 01:07:41 DEBUG : Local file system at /tmp/rclone2669512264: Waiting for transfers to finish
2025/05/09 01:07:42 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2025/05/09 01:07:42 INFO  : sub dir/hello world: Copied (new)
2025/05/09 01:07:42 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:07:43 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (6.42s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:07:44 DEBUG : check sum: Need to transfer - File not found at Destination
2025/05/09 01:07:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:07:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:07:46 DEBUG : check sum: md5 = c366f80e9aca99296cdba49de99205ad OK
2025/05/09 01:07:46 INFO  : check sum: Copied (new)
2025/05/09 01:07:46 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:07:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:07:46 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2025/05/09 01:07:46 DEBUG : check sum: Size of src and dst objects identical
2025/05/09 01:07:46 DEBUG : check sum: Unchanged skipping
2025/05/09 01:07:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:07:46 DEBUG : Waiting for deletions to finish
2025/05/09 01:07:46 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (4.16s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:07:49 DEBUG : sizeonly: Need to transfer - File not found at Destination
2025/05/09 01:07:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:07:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:07:50 DEBUG : sizeonly: md5 = f4552cf958833bdea2b750e3ce56346d OK
2025/05/09 01:07:50 INFO  : sizeonly: Copied (new)
2025/05/09 01:07:50 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:07:50 DEBUG : sizeonly: Sizes identical
2025/05/09 01:07:50 DEBUG : sizeonly: Unchanged skipping
2025/05/09 01:07:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:07:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:07:50 DEBUG : Waiting for deletions to finish
2025/05/09 01:07:50 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (4.01s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:07:53 DEBUG : ignore-size: Need to transfer - File not found at Destination
2025/05/09 01:07:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:07:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:07:54 DEBUG : ignore-size: md5 = cc821311580ba7724ec9001694cb3df6 OK
2025/05/09 01:07:54 INFO  : ignore-size: Copied (new)
2025/05/09 01:07:54 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:07:55 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:07:55 DEBUG : ignore-size: Unchanged skipping
2025/05/09 01:07:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:07:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:07:55 DEBUG : Waiting for deletions to finish
2025/05/09 01:07:55 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (4.15s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:07:58 DEBUG : existing: md5 = d20db7824857f9fe4a650d895776da7a OK
2025/05/09 01:07:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:07:58 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:07:58 DEBUG : existing: Unchanged skipping
2025/05/09 01:07:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:07:58 DEBUG : Waiting for deletions to finish
2025/05/09 01:07:58 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:07:59 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2025/05/09 01:07:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:07:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:08:00 DEBUG : existing: md5 = 4221b803c191aa51a129ace11a03e255 OK
2025/05/09 01:08:00 INFO  : existing: Copied (replaced existing)
2025/05/09 01:08:00 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (5.07s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:08:02 DEBUG : existing: Need to transfer - File not found at Destination
2025/05/09 01:08:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:08:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:08:03 DEBUG : existing: md5 = eaf1b8ffd79203c3e2a715b17c93d720 OK
2025/05/09 01:08:03 INFO  : existing: Copied (new)
2025/05/09 01:08:03 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:08:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:08:04 DEBUG : existing: Destination exists, skipping
2025/05/09 01:08:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:08:04 DEBUG : Waiting for deletions to finish
2025/05/09 01:08:04 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (3.96s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:08:08 DEBUG : b/potato: md5 = 2d36557fd903fd4e1d0e61a5bb438647 OK
2025/05/09 01:08:10 DEBUG : c/non empty space: md5 = 4b3601bd8199be6cfb23db53f8831066 OK
2025/05/09 01:08:10 INFO  : d: Making directory
2025/05/09 01:08:12 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/05/09 01:08:12 INFO  : c: Set directory modification time (using SetModTime)
2025/05/09 01:08:12 DEBUG : Added delayed dir = "c", newDst=c
2025/05/09 01:08:12 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:08:12 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/05/09 01:08:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:08:12 DEBUG : c/non empty space: Unchanged skipping
2025/05/09 01:08:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:08:14 DEBUG : a/potato2: md5 = 47e09794df7911dce9098d0abad990ab OK
2025/05/09 01:08:14 INFO  : a/potato2: Copied (new)
2025/05/09 01:08:14 DEBUG : Waiting for deletions to finish
2025/05/09 01:08:15 INFO  : b/potato: Deleted
2025/05/09 01:08:15 INFO  : a: Set directory modification time (using DirSetModTime)
2025/05/09 01:08:15 INFO  : d: Removing directory
2025/05/09 01:08:16 INFO  : b: Removing directory
2025/05/09 01:08:16 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/05/09 01:08:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:08:19 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/05/09 01:08:19 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (14.83s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:08:22 DEBUG : empty space: md5 = 94aa23c21ce4bb066727ad1a18142516 OK
2025/05/09 01:08:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:08:22 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2025/05/09 01:08:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:08:22 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2025/05/09 01:08:22 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:08:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:08:23 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2025/05/09 01:08:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:08:24 DEBUG : empty space: md5 = 5598e013774af03463a7d9605e7ca17a OK
2025/05/09 01:08:24 INFO  : empty space: Copied (replaced existing)
2025/05/09 01:08:24 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (5.23s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.42s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:08:28 DEBUG : foo: md5 = 2125cb6db8c6ba378a620a6b56baed9a OK
2025/05/09 01:08:28 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2025/05/09 01:08:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:08:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:08:29 DEBUG : foo: md5 = 8ff79f486880f3672bb41f526d4373a7 OK
2025/05/09 01:08:29 INFO  : foo: Copied (replaced existing)
2025/05/09 01:08:29 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (4.50s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:08:32 DEBUG : empty space: md5 = e72bd994717d5dcfacc6f29199ef90e9 OK
2025/05/09 01:08:32 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:08:32 DEBUG : potato: Need to transfer - File not found at Destination
2025/05/09 01:08:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:08:32 DEBUG : empty space: Unchanged skipping
2025/05/09 01:08:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:08:34 DEBUG : potato: md5 = eca4130e744af03d94ed246b23f8e914 OK
2025/05/09 01:08:34 INFO  : potato: Copied (new)
2025/05/09 01:08:34 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (4.97s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:08:37 DEBUG : potato: md5 = b985f91b5cfa4d804005857e5a97d39b OK
2025/05/09 01:08:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:08:37 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2025/05/09 01:08:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:08:38 DEBUG : potato: md5 = cbc7818df08e2b456a252126d7e0f6f1 OK
2025/05/09 01:08:38 INFO  : potato: Copied (replaced existing)
2025/05/09 01:08:38 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (4.48s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:08:41 DEBUG : potato: md5 = 1a1c812c685708d48044419a18dbb0d0 OK
2025/05/09 01:08:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:08:42 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC
2025/05/09 01:08:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:08:43 DEBUG : potato: md5 = 611684e7f0b028ab97335ebfd6e42849 OK
2025/05/09 01:08:43 INFO  : potato: Copied (replaced existing)
2025/05/09 01:08:43 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (4.65s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:08:46 DEBUG : potato: md5 = 87f71181568f1a56e8c6896729af6d66 OK
2025/05/09 01:08:47 DEBUG : empty space: md5 = 4196d030442dcea11714978e0265141e OK
2025/05/09 01:08:48 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/09 01:08:48 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:08:48 DEBUG : empty space: Unchanged skipping
2025/05/09 01:08:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:08:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:08:48 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2025/05/09 01:08:48 DEBUG : Waiting for deletions to finish
2025/05/09 01:08:48 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (4.81s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:08:51 DEBUG : potato: md5 = fd0fe4f5b0a07393cca57df455fadcee OK
2025/05/09 01:08:52 DEBUG : empty space: md5 = aba06a7460771e9749846af4fe92f96c OK
2025/05/09 01:08:53 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:08:53 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/09 01:08:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:08:53 DEBUG : empty space: Unchanged skipping
2025/05/09 01:08:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:08:54 DEBUG : potato2: md5 = 14bbd7f5905ce8f1f6f1f013a84cc97c OK
2025/05/09 01:08:54 INFO  : potato2: Copied (new)
2025/05/09 01:08:54 DEBUG : Waiting for deletions to finish
2025/05/09 01:08:54 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (6.97s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:08:58 DEBUG : b/potato: md5 = 72d15321a332bf88781b7846d33c3979 OK
2025/05/09 01:09:01 DEBUG : c/non empty space: md5 = 272c82884875c50b9a44cf5c4b7bf6dc OK
2025/05/09 01:09:01 INFO  : d: Making directory
2025/05/09 01:09:01 INFO  : d/e: Making directory
2025/05/09 01:09:03 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/05/09 01:09:04 INFO  : c: Set directory modification time (using SetModTime)
2025/05/09 01:09:04 DEBUG : Added delayed dir = "c", newDst=c
2025/05/09 01:09:04 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:09:04 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/05/09 01:09:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:09:04 DEBUG : c/non empty space: Unchanged skipping
2025/05/09 01:09:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:09:06 DEBUG : a/potato2: md5 = e74c9695c0fed10f40a5e9ba69f5ae06 OK
2025/05/09 01:09:06 INFO  : a/potato2: Copied (new)
2025/05/09 01:09:06 DEBUG : Waiting for deletions to finish
2025/05/09 01:09:06 INFO  : b/potato: Deleted
2025/05/09 01:09:07 INFO  : a: Set directory modification time (using DirSetModTime)
2025/05/09 01:09:07 INFO  : d/e: Removing directory
2025/05/09 01:09:07 INFO  : d: Removing directory
2025/05/09 01:09:08 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2025/05/09 01:09:08 INFO  : b: Removing directory
2025/05/09 01:09:08 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/05/09 01:09:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:09:11 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/05/09 01:09:11 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (16.13s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:09:14 DEBUG : b/potato: md5 = 1ad3019274cd9cbdbb1197a275d6a10f OK
2025/05/09 01:09:17 DEBUG : c/non empty space: md5 = 7e0355405424a231c75e1f6f4b777887 OK
2025/05/09 01:09:17 INFO  : d: Making directory
2025/05/09 01:09:18 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/05/09 01:09:19 INFO  : c: Set directory modification time (using SetModTime)
2025/05/09 01:09:19 DEBUG : Added delayed dir = "c", newDst=c
2025/05/09 01:09:19 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:09:19 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/05/09 01:09:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:09:19 DEBUG : c/non empty space: Unchanged skipping
2025/05/09 01:09:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:09:21 DEBUG : a/potato2: md5 = dc06927502f512987df36f0414087228 OK
2025/05/09 01:09:21 INFO  : a/potato2: Copied (new)
2025/05/09 01:09:21 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': not deleting files as there were IO errors
2025/05/09 01:09:22 INFO  : a: Set directory modification time (using DirSetModTime)
2025/05/09 01:09:22 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:09:25 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/05/09 01:09:26 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/05/09 01:09:26 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (14.68s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:09:29 DEBUG : potato: md5 = af05dc8ebd634288cd5018d5a858f325 OK
2025/05/09 01:09:30 DEBUG : empty space: md5 = 41dab909847eda7b483899fc2324db05 OK
2025/05/09 01:09:30 DEBUG : Waiting for deletions to finish
2025/05/09 01:09:30 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:09:30 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/09 01:09:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:09:30 DEBUG : empty space: Unchanged skipping
2025/05/09 01:09:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:09:31 INFO  : potato: Deleted
2025/05/09 01:09:32 DEBUG : potato2: md5 = 219da11ffa38941a1eee466f836bff41 OK
2025/05/09 01:09:32 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (6.32s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:09:35 DEBUG : potato: md5 = e7ffbdde1a7687ecdafcbd4358611ae6 OK
2025/05/09 01:09:36 DEBUG : empty space: md5 = 3dfec967c3e7fea4458e3f8aa0536208 OK
2025/05/09 01:09:36 DEBUG : Waiting for deletions to finish
2025/05/09 01:09:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:09:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:09:37 INFO  : potato: Deleted
2025/05/09 01:09:38 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:09:38 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/09 01:09:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:09:38 DEBUG : empty space: Unchanged skipping
2025/05/09 01:09:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:09:39 DEBUG : potato2: md5 = 0920542ee316715a4ce6fddb0bb9d73d OK
2025/05/09 01:09:39 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (7.37s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:09:42 DEBUG : potato: md5 = df55ef21e48ce22e17e838f946a4b14e OK
2025/05/09 01:09:43 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/09 01:09:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:09:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:09:44 DEBUG : potato2: md5 = 0395bdbdd39548bc2d881924a75050f4 OK
2025/05/09 01:09:44 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (5.29s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:09:48 DEBUG : potato2: md5 = da87933b4981084a0ae22c19f2339d33 OK
2025/05/09 01:09:49 DEBUG : empty space: md5 = c8e4fa0c8e4164a673efa0e56a85a549 OK
2025/05/09 01:09:49 DEBUG : enormous: Excluded (Size Filter)
2025/05/09 01:09:49 DEBUG : enormous: Excluded
2025/05/09 01:09:49 DEBUG : potato2: Excluded (Size Filter)
2025/05/09 01:09:49 DEBUG : potato2: Excluded
2025/05/09 01:09:49 DEBUG : potato2: Excluded (Size Filter)
2025/05/09 01:09:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:09:49 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:09:49 DEBUG : empty space: Unchanged skipping
2025/05/09 01:09:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:09:49 DEBUG : Waiting for deletions to finish
2025/05/09 01:09:49 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:09:50 DEBUG : enormous: Excluded (Size Filter)
2025/05/09 01:09:50 DEBUG : enormous: Excluded
2025/05/09 01:09:50 DEBUG : potato2: Excluded (Size Filter)
2025/05/09 01:09:50 DEBUG : potato2: Excluded
2025/05/09 01:09:50 DEBUG : potato2: Excluded (Size Filter)
2025/05/09 01:09:50 DEBUG : Local file system at /tmp/rclone2669512264: Waiting for checks to finish
2025/05/09 01:09:50 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2025/05/09 01:09:50 DEBUG : empty space: Unchanged skipping
2025/05/09 01:09:50 DEBUG : Local file system at /tmp/rclone2669512264: Waiting for transfers to finish
2025/05/09 01:09:50 DEBUG : Waiting for deletions to finish
2025/05/09 01:09:50 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncWithExclude (6.13s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:09:54 DEBUG : potato2: md5 = 8ba58ba2459ac03ad0c7a4506f495204 OK
2025/05/09 01:09:55 DEBUG : empty space: md5 = f84af33f0348ea7256d31abb66ed437f OK
2025/05/09 01:09:56 DEBUG : enormous: md5 = 7398c318da5292bb0a9f4d0256304e0c OK
2025/05/09 01:09:56 DEBUG : enormous: Excluded (Size Filter)
2025/05/09 01:09:57 DEBUG : enormous: Excluded
2025/05/09 01:09:57 DEBUG : potato2: Excluded (Size Filter)
2025/05/09 01:09:57 DEBUG : potato2: Excluded
2025/05/09 01:09:57 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:09:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:09:57 DEBUG : empty space: Unchanged skipping
2025/05/09 01:09:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:09:57 DEBUG : Waiting for deletions to finish
2025/05/09 01:09:57 INFO  : potato2: Deleted
2025/05/09 01:09:57 INFO  : enormous: Deleted
2025/05/09 01:09:57 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:09:58 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2025/05/09 01:09:58 DEBUG : empty space: Unchanged skipping
2025/05/09 01:09:58 DEBUG : Local file system at /tmp/rclone2669512264: Waiting for checks to finish
2025/05/09 01:09:58 DEBUG : Local file system at /tmp/rclone2669512264: Waiting for transfers to finish
2025/05/09 01:09:58 DEBUG : Waiting for deletions to finish
2025/05/09 01:09:58 INFO  : potato2: Deleted
2025/05/09 01:09:58 INFO  : enormous: Deleted
2025/05/09 01:09:58 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (7.02s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:10:01 DEBUG : one: md5 = 07c5fe37235b3ec1064b65ed2180088e OK
2025/05/09 01:10:02 DEBUG : two: md5 = 84da9accd3c2a782bd97f392f316b139 OK
2025/05/09 01:10:03 DEBUG : three: md5 = 39dcaf603726e2edf93cdd74b8bf2315 OK
2025/05/09 01:10:04 DEBUG : four: md5 = 0a43fecd073c4327c1a3288256f31e08 OK
2025/05/09 01:10:05 DEBUG : five: Need to transfer - File not found at Destination
2025/05/09 01:10:05 DEBUG : one: Destination is newer than source, skipping
2025/05/09 01:10:05 DEBUG : three: Sizes identical
2025/05/09 01:10:05 DEBUG : four: Sizes differ (src 4 vs dst 8)
2025/05/09 01:10:05 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2025/05/09 01:10:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:10:05 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2025/05/09 01:10:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:10:06 DEBUG : two: md5 = 9883f2c2facd1406ded86cf728bd148f OK
2025/05/09 01:10:06 INFO  : two: Copied (replaced existing)
2025/05/09 01:10:06 DEBUG : four: md5 = f3a45b2c072b815d6564d91fb6044c8d OK
2025/05/09 01:10:06 INFO  : four: Copied (replaced existing)
2025/05/09 01:10:06 DEBUG : five: md5 = 23b8e4b6a4250072d580c95de44dd48b OK
2025/05/09 01:10:06 INFO  : five: Copied (new)
2025/05/09 01:10:06 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (9.79s)
=== 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-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2025/05/09 01:10:09 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Ignoring --track-renames as the source and destination do not have a common hash
2025/05/09 01:10:09 DEBUG : potato: Need to transfer - File not found at Destination
2025/05/09 01:10:09 DEBUG : yam: Need to transfer - File not found at Destination
2025/05/09 01:10:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:10:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:10:11 DEBUG : yam: md5 = 2d87279df61d4599334f7586836b9989 OK
2025/05/09 01:10:11 INFO  : yam: Copied (new)
2025/05/09 01:10:11 DEBUG : potato: md5 = b7bfe62e0c3199dc22d5b7b0441bbb19 OK
2025/05/09 01:10:11 INFO  : potato: Copied (new)
2025/05/09 01:10:11 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:10:11 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Ignoring --track-renames as the source and destination do not have a common hash
2025/05/09 01:10:11 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:10:11 DEBUG : yaml: Need to transfer - File not found at Destination
2025/05/09 01:10:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:10:11 DEBUG : potato: Unchanged skipping
2025/05/09 01:10:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:10:13 DEBUG : yaml: md5 = d9fac52f757171931de363c978459fef OK
2025/05/09 01:10:13 INFO  : yaml: Copied (new)
2025/05/09 01:10:13 DEBUG : Waiting for deletions to finish
2025/05/09 01:10:13 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (8.08s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2025/05/09 01:10:17 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Making map for --track-renames
2025/05/09 01:10:17 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Finished making map for --track-renames
2025/05/09 01:10:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:10:17 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/05/09 01:10:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for renames to finish
2025/05/09 01:10:17 DEBUG : yam: Need to transfer - No matching file found at Destination
2025/05/09 01:10:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:10:19 DEBUG : yam: md5 = f80d701d402699960693814995fbb542 OK
2025/05/09 01:10:19 INFO  : yam: Copied (new)
2025/05/09 01:10:19 DEBUG : potato: md5 = 0487fc7e926ab5b04ccd686d134d3501 OK
2025/05/09 01:10:19 INFO  : potato: Copied (new)
2025/05/09 01:10:19 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:10:19 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:10:19 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Making map for --track-renames
2025/05/09 01:10:19 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Finished making map for --track-renames
2025/05/09 01:10:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:10:19 DEBUG : potato: Unchanged skipping
2025/05/09 01:10:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for renames to finish
2025/05/09 01:10:20 INFO  : yam: Moved (server-side) to: yaml
2025/05/09 01:10:20 INFO  : yaml: Renamed from "yam"
2025/05/09 01:10:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:10:20 DEBUG : Waiting for deletions to finish
2025/05/09 01:10:20 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (5.18s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2025/05/09 01:10:23 DEBUG : Added delayed dir = "sub", newDst=<nil>
2025/05/09 01:10:23 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Making map for --track-renames
2025/05/09 01:10:23 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Finished making map for --track-renames
2025/05/09 01:10:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:10:23 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/05/09 01:10:23 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2025/05/09 01:10:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for renames to finish
2025/05/09 01:10:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:10:25 DEBUG : sub/yam: md5 = c9d4c0de0c79e0e76c5dfb8cfd3a65c6 OK
2025/05/09 01:10:25 INFO  : sub/yam: Copied (new)
2025/05/09 01:10:25 DEBUG : potato: md5 = 1eadd3e6d9bba49c3facd0481e925c92 OK
2025/05/09 01:10:25 INFO  : potato: Copied (new)
2025/05/09 01:10:25 DEBUG : Waiting for deletions to finish
2025/05/09 01:10:25 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:10:26 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:10:26 DEBUG : potato: Unchanged skipping
2025/05/09 01:10:26 INFO  : sub: Set directory modification time (using SetModTime)
2025/05/09 01:10:26 DEBUG : Added delayed dir = "sub", newDst=sub
2025/05/09 01:10:26 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Making map for --track-renames
2025/05/09 01:10:26 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Finished making map for --track-renames
2025/05/09 01:10:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:10:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for renames to finish
2025/05/09 01:10:27 INFO  : sub/yam: Moved (server-side) to: yam
2025/05/09 01:10:27 INFO  : yam: Renamed from "sub/yam"
2025/05/09 01:10:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:10:27 DEBUG : Waiting for deletions to finish
2025/05/09 01:10:27 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (8.46s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:10:31 DEBUG : Creating backend with remote "/tmp/rclone2669512264/dir1"
2025/05/09 01:10:31 DEBUG : Config file has changed externally - reloading
2025/05/09 01:10:31 DEBUG : Creating backend with remote "/tmp/rclone2669512264/dir2"
2025/05/09 01:10:31 DEBUG : Local file system at /tmp/rclone2669512264/dir2: Using server-side directory move
2025/05/09 01:10:31 INFO  : Local file system at /tmp/rclone2669512264/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/05/09 01:10:31 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/05/09 01:10:31 DEBUG : Local file system at /tmp/rclone2669512264/dir2: Waiting for checks to finish
2025/05/09 01:10:31 DEBUG : Local file system at /tmp/rclone2669512264/dir2: Waiting for transfers to finish
2025/05/09 01:10:31 INFO  : file1.txt: Moved (server-side)
--- PASS: TestServerSideMoveLocal (0.42s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:10:31 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/05/09 01:10:31 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/09 01:10:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/09 01:10:31 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/05/09 01:10:31 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/05/09 01:10:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:10:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:10:34 DEBUG : sub dir/hello world: md5 = 1c447dd4451abcd3cc7089aeae799883 OK
2025/05/09 01:10:34 INFO  : sub dir/hello world: Copied (new)
2025/05/09 01:10:34 INFO  : sub dir/hello world: Deleted
2025/05/09 01:10:35 DEBUG : nested/sub dir/file: md5 = a4daf98944ec77bf3b85fb4648696f4c OK
2025/05/09 01:10:35 INFO  : nested/sub dir/file: Copied (new)
2025/05/09 01:10:35 INFO  : nested/sub dir/file: Deleted
2025/05/09 01:10:36 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/05/09 01:10:36 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/05/09 01:10:36 INFO  : nested: Set directory modification time (using DirSetModTime)
2025/05/09 01:10:36 INFO  : sub dir: Removing directory
2025/05/09 01:10:36 INFO  : nested/sub dir: Removing directory
2025/05/09 01:10:36 INFO  : nested: Removing directory
2025/05/09 01:10:36 DEBUG : Local file system at /tmp/rclone2669512264: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:10:39 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/05/09 01:10:40 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2025/05/09 01:10:40 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (10.06s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:10:42 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/05/09 01:10:42 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/05/09 01:10:42 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/05/09 01:10:42 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/05/09 01:10:42 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/05/09 01:10:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:10:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:10:44 DEBUG : sub dir/hello world: md5 = e81ce4649936cfc439ca2d317d621c0c OK
2025/05/09 01:10:44 INFO  : sub dir/hello world: Copied (new)
2025/05/09 01:10:44 INFO  : sub dir/hello world: Deleted
2025/05/09 01:10:45 DEBUG : nested/sub dir/file: md5 = 042910ae1cdc5bcfdc8591f0df5af486 OK
2025/05/09 01:10:45 INFO  : nested/sub dir/file: Copied (new)
2025/05/09 01:10:45 INFO  : nested/sub dir/file: Deleted
2025/05/09 01:10:46 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/05/09 01:10:46 INFO  : nested: Set directory modification time (using DirSetModTime)
2025/05/09 01:10:46 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:10:50 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/05/09 01:10:51 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2025/05/09 01:10:51 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (11.00s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:10:53 DEBUG : existing: Need to transfer - File not found at Destination
2025/05/09 01:10:53 DEBUG : existing-b: Need to transfer - File not found at Destination
2025/05/09 01:10:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:10:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:10:54 DEBUG : existing: md5 = 5d1c8336fd7634df35b752116b2f9456 OK
2025/05/09 01:10:54 INFO  : existing: Copied (new)
2025/05/09 01:10:54 INFO  : existing: Deleted
2025/05/09 01:10:54 DEBUG : existing-b: md5 = 075213ac2f6fc207a49a0c2d11d50168 OK
2025/05/09 01:10:54 INFO  : existing-b: Copied (new)
2025/05/09 01:10:54 INFO  : existing-b: Deleted
2025/05/09 01:10:54 DEBUG : existing: Destination exists, skipping
2025/05/09 01:10:54 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2025/05/09 01:10:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:10:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:10:54 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (4.19s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:10:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-culosum6bopi"
2025/05/09 01:10:57 DEBUG : Config file has changed externally - reloading
2025/05/09 01:10:57 DEBUG : Creating backend with remote "TestDrive:crypt/8vb5c4ike26aog802v8u493qeccb05tqpjih6b2q8q4a1tpuhoeg"
2025/05/09 01:10:59 DEBUG : potato2: md5 = e05b39b739debb9464f949b132bbcb9e OK
2025/05/09 01:11:00 DEBUG : empty space: md5 = f9ebf6b4182f1aaf47bf26d4df2b7d52 OK
2025/05/09 01:11:02 DEBUG : potato3: md5 = f3a30a5571bccdccdf33ee0342ccfd4b OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu' -> Encrypted drive 'TestCryptDrive:rclone-test-culosum6bopi'
2025/05/09 01:11:04 DEBUG : empty space: md5 = e757aad448bfe6b565d275831a814a92 OK
2025/05/09 01:11:05 DEBUG : potato3: md5 = 53c887b52500668d0b74aa8278ce880e OK
2025/05/09 01:11:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-culosum6bopi': Using server-side directory move
2025/05/09 01:11:05 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-culosum6bopi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/05/09 01:11:06 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/09 01:11:06 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/05/09 01:11:06 DEBUG : empty space: Unchanged skipping
2025/05/09 01:11:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-culosum6bopi': Waiting for checks to finish
2025/05/09 01:11:06 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/05/09 01:11:06 INFO  : empty space: Deleted
2025/05/09 01:11:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-culosum6bopi': Waiting for transfers to finish
2025/05/09 01:11:06 INFO  : potato3: Deleted
2025/05/09 01:11:06 INFO  : potato2: Moved (server-side)
2025/05/09 01:11:07 INFO  : potato3: Moved (server-side)
2025/05/09 01:11:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tukihuh8page"
2025/05/09 01:11:07 DEBUG : Config file has changed externally - reloading
2025/05/09 01:11:07 DEBUG : Creating backend with remote "TestDrive:crypt/b6g93fs2q2n21nkbfenuec7ti3coplufrnsckmnufcg9gte54l50"
2025/05/09 01:11:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tukihuh8page': Using server-side directory move
2025/05/09 01:11:09 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tukihuh8page': Server side directory move succeeded
2025/05/09 01:11:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tukihuh8page': Purge remote
2025/05/09 01:11:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-culosum6bopi': Purge remote
2025/05/09 01:11:11 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (14.41s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:11:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yahimil5buzi"
2025/05/09 01:11:11 DEBUG : Creating backend with remote "TestDrive:crypt/hqeeme3er0ke14tbb09stb848t029rmdbgkbspcqj85596svvfn0"
2025/05/09 01:11:13 DEBUG : potato2: md5 = 1dba03cfc7eae043595becf630104b2f OK
2025/05/09 01:11:15 DEBUG : empty space: md5 = 9fb1da727dca75a68085bfb2e2632f64 OK
2025/05/09 01:11:16 DEBUG : potato3: md5 = 59577a9426ea7f018c1b94851e1e8546 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu' -> Encrypted drive 'TestCryptDrive:rclone-test-yahimil5buzi'
2025/05/09 01:11:18 DEBUG : empty space: md5 = b9b03230985c96e6cb982aa74a3d5e15 OK
2025/05/09 01:11:20 DEBUG : potato3: md5 = d4e02f2682d23f65641766854a1aa3b0 OK
2025/05/09 01:11:20 DEBUG : empty space: Excluded (Size Filter)
2025/05/09 01:11:20 DEBUG : empty space: Excluded (Size Filter)
2025/05/09 01:11:20 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/09 01:11:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yahimil5buzi': Waiting for checks to finish
2025/05/09 01:11:20 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/05/09 01:11:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yahimil5buzi': Waiting for transfers to finish
2025/05/09 01:11:21 INFO  : potato3: Deleted
2025/05/09 01:11:21 INFO  : potato2: Moved (server-side)
2025/05/09 01:11:21 INFO  : potato3: Moved (server-side)
2025/05/09 01:11:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fiduxak1nibu"
2025/05/09 01:11:22 DEBUG : Config file has changed externally - reloading
2025/05/09 01:11:22 DEBUG : Creating backend with remote "TestDrive:crypt/jft8vs549631kja8hcd0atqc6obbqfq15ppugiv79vavrhd00glg"
2025/05/09 01:11:23 DEBUG : empty space: Excluded (Size Filter)
2025/05/09 01:11:23 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/09 01:11:23 DEBUG : potato3: Need to transfer - File not found at Destination
2025/05/09 01:11:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fiduxak1nibu': Waiting for checks to finish
2025/05/09 01:11:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fiduxak1nibu': Waiting for transfers to finish
2025/05/09 01:11:25 INFO  : potato2: Moved (server-side)
2025/05/09 01:11:25 INFO  : potato3: Moved (server-side)
2025/05/09 01:11:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fiduxak1nibu': Purge remote
2025/05/09 01:11:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yahimil5buzi': Purge remote
--- PASS: TestServerSideMoveWithFilter (16.50s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:11:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-talirak4nuqo"
2025/05/09 01:11:28 DEBUG : Creating backend with remote "TestDrive:crypt/fsps8hdu9vc2jsqbuh2gj56oi65v9e3rldb6pon9849rt5gn6i7g"
2025/05/09 01:11:30 DEBUG : potato2: md5 = 7e608f6fd66be49aa4c5fe1eca1f2f64 OK
2025/05/09 01:11:31 DEBUG : empty space: md5 = 1e6551d3229c357c05d2e38616b932c8 OK
2025/05/09 01:11:32 DEBUG : potato3: md5 = cf033e1e216e675563d85b0a7a2b1a9d OK
2025/05/09 01:11:32 INFO  : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu' -> Encrypted drive 'TestCryptDrive:rclone-test-talirak4nuqo'
2025/05/09 01:11:36 DEBUG : empty space: md5 = 448cb28093e17c20f728554e6238fc33 OK
2025/05/09 01:11:37 DEBUG : potato3: md5 = cf55bafeb2b93942a480d415cd971f0a OK
2025/05/09 01:11:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-talirak4nuqo': Using server-side directory move
2025/05/09 01:11:37 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-talirak4nuqo': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/05/09 01:11:38 DEBUG : potato2: Need to transfer - File not found at Destination
2025/05/09 01:11:38 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2025/05/09 01:11:38 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/05/09 01:11:38 DEBUG : empty space: Unchanged skipping
2025/05/09 01:11:38 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/05/09 01:11:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-talirak4nuqo': Waiting for checks to finish
2025/05/09 01:11:38 INFO  : empty space: Deleted
2025/05/09 01:11:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-talirak4nuqo': Waiting for transfers to finish
2025/05/09 01:11:38 INFO  : potato3: Deleted
2025/05/09 01:11:38 INFO  : potato2: Moved (server-side)
2025/05/09 01:11:39 INFO  : potato3: Moved (server-side)
2025/05/09 01:11:39 INFO  : tomatoDir: Removing directory
2025/05/09 01:11:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': deleted 1 directories
2025/05/09 01:11:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xugobif9nase"
2025/05/09 01:11:40 DEBUG : Creating backend with remote "TestDrive:crypt/4hn9cl4b4j6pa1mn5i9s9kisfptn82tepohejp639bluhfr0r5sg"
2025/05/09 01:11:41 INFO  : tomatoDir: Making directory
2025/05/09 01:11:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xugobif9nase': Using server-side directory move
2025/05/09 01:11:43 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-xugobif9nase': Server side directory move succeeded
2025/05/09 01:11:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xugobif9nase': Purge remote
2025/05/09 01:11:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-talirak4nuqo': Purge remote
2025/05/09 01:11:45 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (17.70s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.44s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:11:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/rclone-sync-test"
2025/05/09 01:11:46 DEBUG : Config file has changed externally - reloading
2025/05/09 01:11:46 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncOverlap (3.70s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:11:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/rclone-sync-test"
2025/05/09 01:11:49 DEBUG : Config file has changed externally - reloading
2025/05/09 01:11:49 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2025/05/09 01:11:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/rclone-sync-test-include/layer2"
2025/05/09 01:11:51 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2025/05/09 01:11:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/rclone-sync-test-ignore-file"
2025/05/09 01:11:54 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2025/05/09 01:11:58 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 4147f356ca6db10fc3114b90235e90fc OK
2025/05/09 01:12:00 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/05/09 01:12:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/rclone-sync-test': Waiting for checks to finish
2025/05/09 01:12:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/rclone-sync-test': Waiting for transfers to finish
2025/05/09 01:12:00 DEBUG : Waiting for deletions to finish
2025/05/09 01:12:00 INFO  : There was nothing to transfer
2025/05/09 01:12:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:12:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:12:02 DEBUG : Waiting for deletions to finish
2025/05/09 01:12:02 INFO  : rclone-sync-test-include: Removing directory
2025/05/09 01:12:02 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/05/09 01:12:02 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2025/05/09 01:12:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': failed to delete 1 directories
2025/05/09 01:12:02 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:12:04 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/05/09 01:12:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/rclone-sync-test-include/layer2': Waiting for checks to finish
2025/05/09 01:12:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/rclone-sync-test-include/layer2': Waiting for transfers to finish
2025/05/09 01:12:04 DEBUG : Waiting for deletions to finish
2025/05/09 01:12:04 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:12:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:12:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:12:06 DEBUG : Waiting for deletions to finish
2025/05/09 01:12:06 INFO  : rclone-sync-test-include: Removing directory
2025/05/09 01:12:06 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/05/09 01:12:06 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2025/05/09 01:12:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': failed to delete 1 directories
2025/05/09 01:12:06 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:12:08 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/05/09 01:12:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/rclone-sync-test-ignore-file': Waiting for checks to finish
2025/05/09 01:12:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/rclone-sync-test-ignore-file': Waiting for transfers to finish
2025/05/09 01:12:08 DEBUG : Waiting for deletions to finish
2025/05/09 01:12:08 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:12:10 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/05/09 01:12:10 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (29.71s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:12:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/dst"
2025/05/09 01:12:19 DEBUG : Config file has changed externally - reloading
2025/05/09 01:12:19 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/31u3jie661vd5p8j7rtc3hgbh0"
2025/05/09 01:12:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/CompareDest"
2025/05/09 01:12:21 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/gveqi14airsml4bgu7krj116o8"
2025/05/09 01:12:22 DEBUG : one: Need to transfer - File not found at Destination
2025/05/09 01:12:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for checks to finish
2025/05/09 01:12:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for transfers to finish
2025/05/09 01:12:24 DEBUG : one: md5 = f0e88f490239523f4403a32cfac6303c OK
2025/05/09 01:12:24 INFO  : one: Copied (new)
2025/05/09 01:12:24 DEBUG : Waiting for deletions to finish
2025/05/09 01:12:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for checks to finish
2025/05/09 01:12:26 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/05/09 01:12:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for transfers to finish
2025/05/09 01:12:27 DEBUG : one: md5 = da4f4e5002c0b641db92da136887fcd0 OK
2025/05/09 01:12:27 INFO  : one: Copied (replaced existing)
2025/05/09 01:12:27 DEBUG : Waiting for deletions to finish
2025/05/09 01:12:29 DEBUG : dst/one: md5 = 5af9ec6f806a570fc0f4ff7ab205a1ae OK
2025/05/09 01:12:31 DEBUG : CompareDest/one: md5 = f087341bedc7b5295fbe8bb7aee5c1dc OK
2025/05/09 01:12:32 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/05/09 01:12:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for checks to finish
2025/05/09 01:12:32 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:12:32 DEBUG : one: Destination found in --compare-dest, skipping
2025/05/09 01:12:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for transfers to finish
2025/05/09 01:12:32 DEBUG : Waiting for deletions to finish
2025/05/09 01:12:32 INFO  : There was nothing to transfer
2025/05/09 01:12:34 DEBUG : CompareDest/two: md5 = 3ee332ca86d82f0069eb71d44e2519f3 OK
2025/05/09 01:12:35 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/05/09 01:12:35 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:12:35 DEBUG : two: Destination found in --compare-dest, skipping
2025/05/09 01:12:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for checks to finish
2025/05/09 01:12:35 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:12:35 DEBUG : one: Destination found in --compare-dest, skipping
2025/05/09 01:12:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for transfers to finish
2025/05/09 01:12:35 DEBUG : Waiting for deletions to finish
2025/05/09 01:12:35 INFO  : There was nothing to transfer
2025/05/09 01:12:36 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/05/09 01:12:36 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:12:36 DEBUG : two: Destination found in --compare-dest, skipping
2025/05/09 01:12:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for checks to finish
2025/05/09 01:12:36 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:12:36 DEBUG : one: Destination found in --compare-dest, skipping
2025/05/09 01:12:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for transfers to finish
2025/05/09 01:12:36 DEBUG : Waiting for deletions to finish
2025/05/09 01:12:36 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2025/05/09 01:12:37 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/05/09 01:12:37 DEBUG : two: Sizes differ (src 5 vs dst 3)
2025/05/09 01:12:37 DEBUG : two: Need to transfer - File not found at Destination
2025/05/09 01:12:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for checks to finish
2025/05/09 01:12:37 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:12:37 DEBUG : one: Destination found in --compare-dest, skipping
2025/05/09 01:12:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for transfers to finish
2025/05/09 01:12:39 DEBUG : two: md5 = 23969b1a5aea9f1b8fc9312c3dde1dcb OK
2025/05/09 01:12:39 INFO  : two: Copied (new)
2025/05/09 01:12:39 DEBUG : Waiting for deletions to finish
2025/05/09 01:12:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/05/09 01:12:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/09 01:12:43 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/05/09 01:12:43 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCompareDest (24.32s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:12:45 DEBUG : pre-dest1/1: md5 = 9232029d42947840d016382ac2588357 OK
2025/05/09 01:12:47 DEBUG : pre-dest2/2: md5 = cad9f75319267e148dcd01d0f4e52162 OK
2025/05/09 01:12:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/dest"
2025/05/09 01:12:48 DEBUG : Config file has changed externally - reloading
2025/05/09 01:12:48 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/rg03c1jvnehrrc617i0lnqjddc"
2025/05/09 01:12:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/pre-dest1"
2025/05/09 01:12:49 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/bbnblvh6k061ssopqrp18kd7gc"
2025/05/09 01:12:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/pre-dest2"
2025/05/09 01:12:50 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/dgicm1h6b5ejvlltm8eeif0bnk"
2025/05/09 01:12:51 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:12:51 DEBUG : 1: Destination found in --compare-dest, skipping
2025/05/09 01:12:52 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:12:52 DEBUG : 2: Destination found in --compare-dest, skipping
2025/05/09 01:12:52 DEBUG : 3: Need to transfer - File not found at Destination
2025/05/09 01:12:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dest': Waiting for checks to finish
2025/05/09 01:12:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dest': Waiting for transfers to finish
2025/05/09 01:12:54 DEBUG : 3: md5 = 785124b56151c57821aeefe2df0df198 OK
2025/05/09 01:12:54 INFO  : 3: Copied (new)
2025/05/09 01:12:54 DEBUG : Waiting for deletions to finish
2025/05/09 01:12:57 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2025/05/09 01:12:58 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2025/05/09 01:12:58 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (15.67s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:12:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/dst"
2025/05/09 01:12:59 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/31u3jie661vd5p8j7rtc3hgbh0"
2025/05/09 01:13:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/CopyDest"
2025/05/09 01:13:00 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/d09o6po3f7bm6ce32vdgs8h9ls"
2025/05/09 01:13:02 DEBUG : one: Need to transfer - File not found at Destination
2025/05/09 01:13:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for checks to finish
2025/05/09 01:13:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for transfers to finish
2025/05/09 01:13:04 DEBUG : one: md5 = d2b03ea424f00b327612e76441fe62c3 OK
2025/05/09 01:13:04 INFO  : one: Copied (new)
2025/05/09 01:13:04 DEBUG : Waiting for deletions to finish
2025/05/09 01:13:05 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/05/09 01:13:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for checks to finish
2025/05/09 01:13:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for transfers to finish
2025/05/09 01:13:07 DEBUG : one: md5 = e1da0de575428788d7111b6e65290c4c OK
2025/05/09 01:13:07 INFO  : one: Copied (replaced existing)
2025/05/09 01:13:07 DEBUG : Waiting for deletions to finish
2025/05/09 01:13:09 DEBUG : dst/one: md5 = e0b4b0ace0157a73b31889662576acb2 OK
2025/05/09 01:13:11 DEBUG : CopyDest/one: md5 = 3526ad62ed4d178c49a649efade82a25 OK
2025/05/09 01:13:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/BackupDir"
2025/05/09 01:13:11 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/s6dbk3lfi7c9kfvo6j7bla9m0g"
2025/05/09 01:13:13 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/05/09 01:13:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for checks to finish
2025/05/09 01:13:13 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:13:13 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/05/09 01:13:15 INFO  : one: Moved (server-side)
2025/05/09 01:13:16 INFO  : one: Copied (server-side copy)
2025/05/09 01:13:16 DEBUG : one: Destination found in --copy-dest, using server-side copy
2025/05/09 01:13:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for transfers to finish
2025/05/09 01:13:16 DEBUG : Waiting for deletions to finish
2025/05/09 01:13:18 DEBUG : CopyDest/two: md5 = b4ca5a30c7e9a5bea2a465cec76c6806 OK
2025/05/09 01:13:18 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:13:18 DEBUG : one: Unchanged skipping
2025/05/09 01:13:18 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:13:19 INFO  : two: Copied (server-side copy)
2025/05/09 01:13:19 DEBUG : two: Destination found in --copy-dest, using server-side copy
2025/05/09 01:13:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for checks to finish
2025/05/09 01:13:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for transfers to finish
2025/05/09 01:13:19 DEBUG : Waiting for deletions to finish
2025/05/09 01:13:20 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:13:20 DEBUG : one: Unchanged skipping
2025/05/09 01:13:20 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:13:20 DEBUG : two: Unchanged skipping
2025/05/09 01:13:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for checks to finish
2025/05/09 01:13:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for transfers to finish
2025/05/09 01:13:20 DEBUG : Waiting for deletions to finish
2025/05/09 01:13:20 INFO  : There was nothing to transfer
2025/05/09 01:13:22 DEBUG : CopyDest/three: md5 = bf888708bc4f3f3c8c9b1afe9e7f5f2a OK
2025/05/09 01:13:23 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:13:23 DEBUG : one: Unchanged skipping
2025/05/09 01:13:23 DEBUG : three: Sizes differ (src 7 vs dst 5)
2025/05/09 01:13:23 DEBUG : three: Destination not found in --copy-dest
2025/05/09 01:13:23 DEBUG : three: Need to transfer - File not found at Destination
2025/05/09 01:13:23 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/05/09 01:13:23 DEBUG : two: Unchanged skipping
2025/05/09 01:13:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for checks to finish
2025/05/09 01:13:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for transfers to finish
2025/05/09 01:13:24 DEBUG : three: md5 = 986ef57e451d3152d14723afc65f4e18 OK
2025/05/09 01:13:24 INFO  : three: Copied (new)
2025/05/09 01:13:24 DEBUG : Waiting for deletions to finish
2025/05/09 01:13:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2025/05/09 01:13:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/09 01:13:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/05/09 01:13:29 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/05/09 01:13:29 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/09 01:13:29 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2025/05/09 01:13:30 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (31.32s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:13:32 DEBUG : dst/one: md5 = 68a87c23b4708b077abd9c18a7f5a232 OK
2025/05/09 01:13:34 DEBUG : dst/two: md5 = f951282f08b102eeb914d0dd442e179a OK
2025/05/09 01:13:35 DEBUG : dst/three.txt: md5 = 35601161b6a0967f43ae173bf7191db9 OK
2025/05/09 01:13:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/dst"
2025/05/09 01:13:35 DEBUG : Config file has changed externally - reloading
2025/05/09 01:13:35 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/31u3jie661vd5p8j7rtc3hgbh0"
2025/05/09 01:13:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/backup"
2025/05/09 01:13:36 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/1nrff024r7pq65ecp72fc28jb0"
2025/05/09 01:13:39 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/05/09 01:13:39 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:13:39 DEBUG : two: Unchanged skipping
2025/05/09 01:13:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for checks to finish
2025/05/09 01:13:40 INFO  : one: Moved (server-side)
2025/05/09 01:13:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for transfers to finish
2025/05/09 01:13:41 DEBUG : one: md5 = a6aecfb8f57173fd5578c30f214b2658 OK
2025/05/09 01:13:41 INFO  : one: Copied (new)
2025/05/09 01:13:41 DEBUG : Waiting for deletions to finish
2025/05/09 01:13:42 INFO  : three.txt: Moved (server-side)
2025/05/09 01:13:42 INFO  : three.txt: Moved into backup dir
2025/05/09 01:13:44 DEBUG : dst/three.txt: md5 = 3f7f2e04c5e1ab77bccfbd2a51092f9e OK
2025/05/09 01:13:45 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/05/09 01:13:45 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:13:45 DEBUG : two: Unchanged skipping
2025/05/09 01:13:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for checks to finish
2025/05/09 01:13:45 INFO  : one: Deleted
2025/05/09 01:13:46 INFO  : one: Moved (server-side)
2025/05/09 01:13:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for transfers to finish
2025/05/09 01:13:47 DEBUG : one: md5 = 0090cf1dd4c349ba998d46731676a4b1 OK
2025/05/09 01:13:47 INFO  : one: Copied (new)
2025/05/09 01:13:47 DEBUG : Waiting for deletions to finish
2025/05/09 01:13:48 INFO  : three.txt: Deleted
2025/05/09 01:13:48 INFO  : three.txt: Moved (server-side)
2025/05/09 01:13:48 INFO  : three.txt: Moved into backup dir
2025/05/09 01:13:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/09 01:13:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/05/09 01:13:52 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/05/09 01:13:52 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/09 01:13:52 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/05/09 01:13:52 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncBackupDir (22.41s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:13:55 DEBUG : dst/one: md5 = 3cf3501d9a67963738c391fc9926465d OK
2025/05/09 01:13:56 DEBUG : dst/two: md5 = 56e453447f6eba36c4b9957af1cc51c1 OK
2025/05/09 01:13:57 DEBUG : dst/three.txt: md5 = 6a2c31e9828e8c39f7e4ae9cae600fc4 OK
2025/05/09 01:13:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/dst"
2025/05/09 01:13:58 DEBUG : Config file has changed externally - reloading
2025/05/09 01:13:58 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/31u3jie661vd5p8j7rtc3hgbh0"
2025/05/09 01:13:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/backup"
2025/05/09 01:13:59 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/1nrff024r7pq65ecp72fc28jb0"
2025/05/09 01:14:00 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/05/09 01:14:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for checks to finish
2025/05/09 01:14:00 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:14:00 DEBUG : two: Unchanged skipping
2025/05/09 01:14:02 INFO  : one: Moved (server-side) to: one.bak
2025/05/09 01:14:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for transfers to finish
2025/05/09 01:14:03 DEBUG : one: md5 = 02a1d50f0365776aa687f2f776778af8 OK
2025/05/09 01:14:03 INFO  : one: Copied (new)
2025/05/09 01:14:03 DEBUG : Waiting for deletions to finish
2025/05/09 01:14:04 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/05/09 01:14:04 INFO  : three.txt: Moved into backup dir
2025/05/09 01:14:06 DEBUG : dst/three.txt: md5 = 1a4b6e484113d17d5b5030ca7b7a7a0d OK
2025/05/09 01:14:06 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/05/09 01:14:06 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:14:06 DEBUG : two: Unchanged skipping
2025/05/09 01:14:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for checks to finish
2025/05/09 01:14:07 INFO  : one.bak: Deleted
2025/05/09 01:14:08 INFO  : one: Moved (server-side) to: one.bak
2025/05/09 01:14:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for transfers to finish
2025/05/09 01:14:09 DEBUG : one: md5 = da2a26698680df2d29bf5a36f96762b2 OK
2025/05/09 01:14:09 INFO  : one: Copied (new)
2025/05/09 01:14:09 DEBUG : Waiting for deletions to finish
2025/05/09 01:14:10 INFO  : three.txt.bak: Deleted
2025/05/09 01:14:10 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/05/09 01:14:10 INFO  : three.txt: Moved into backup dir
2025/05/09 01:14:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/09 01:14:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/05/09 01:14:14 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/05/09 01:14:14 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/05/09 01:14:14 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/05/09 01:14:14 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncBackupDirWithSuffix (21.40s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:14:16 DEBUG : dst/one: md5 = 983ba640fc24ca435647e22aa7607d62 OK
2025/05/09 01:14:17 DEBUG : dst/two: md5 = b7c4f1013b48100bdc78dc8ff16b7091 OK
2025/05/09 01:14:19 DEBUG : dst/three.txt: md5 = 3869ddfc87915cd883ad7a35dc02f318 OK
2025/05/09 01:14:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/dst"
2025/05/09 01:14:19 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/31u3jie661vd5p8j7rtc3hgbh0"
2025/05/09 01:14:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/backup"
2025/05/09 01:14:20 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/1nrff024r7pq65ecp72fc28jb0"
2025/05/09 01:14:22 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/05/09 01:14:22 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:14:22 DEBUG : two: Unchanged skipping
2025/05/09 01:14:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for checks to finish
2025/05/09 01:14:23 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/05/09 01:14:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for transfers to finish
2025/05/09 01:14:24 DEBUG : one: md5 = 20e9c091d6eaa0585729bd390bd2511f OK
2025/05/09 01:14:24 INFO  : one: Copied (new)
2025/05/09 01:14:24 DEBUG : Waiting for deletions to finish
2025/05/09 01:14:25 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/05/09 01:14:25 INFO  : three.txt: Moved into backup dir
2025/05/09 01:14:27 DEBUG : dst/three.txt: md5 = 0e238059b213e36055325b6752d2405d OK
2025/05/09 01:14:28 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/05/09 01:14:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for checks to finish
2025/05/09 01:14:28 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:14:28 DEBUG : two: Unchanged skipping
2025/05/09 01:14:28 INFO  : one-2019-01-01: Deleted
2025/05/09 01:14:29 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/05/09 01:14:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for transfers to finish
2025/05/09 01:14:30 DEBUG : one: md5 = 6fcf45039764c045e8859646029c9e58 OK
2025/05/09 01:14:30 INFO  : one: Copied (new)
2025/05/09 01:14:30 DEBUG : Waiting for deletions to finish
2025/05/09 01:14:31 INFO  : three-2019-01-01.txt: Deleted
2025/05/09 01:14:31 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/05/09 01:14:31 INFO  : three.txt: Moved into backup dir
2025/05/09 01:14:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/09 01:14:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/05/09 01:14:36 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/05/09 01:14:36 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/05/09 01:14:36 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/05/09 01:14:36 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (22.03s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:14:38 DEBUG : dst/one: md5 = 112093a51d7bef622aec10b61e6316be OK
2025/05/09 01:14:39 DEBUG : dst/two: md5 = c378c4cca975fab48b9caf2306f304f6 OK
2025/05/09 01:14:41 DEBUG : dst/three.txt: md5 = 972824e7e63ad3ac8c54c4d9a91efd55 OK
2025/05/09 01:14:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/dst"
2025/05/09 01:14:41 DEBUG : Config file has changed externally - reloading
2025/05/09 01:14:41 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/31u3jie661vd5p8j7rtc3hgbh0"
2025/05/09 01:14:42 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/05/09 01:14:42 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:14:42 DEBUG : two: Unchanged skipping
2025/05/09 01:14:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for checks to finish
2025/05/09 01:14:43 INFO  : one: Moved (server-side) to: one.bak
2025/05/09 01:14:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for transfers to finish
2025/05/09 01:14:44 DEBUG : one: md5 = 9a9984094f8a5bec13a653563c8c6567 OK
2025/05/09 01:14:44 INFO  : one: Copied (new)
2025/05/09 01:14:44 DEBUG : Waiting for deletions to finish
2025/05/09 01:14:45 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/05/09 01:14:45 INFO  : three.txt: Moved into backup dir
2025/05/09 01:14:47 DEBUG : dst/three.txt: md5 = edd876eb690cce9e7141aebb0859dfef OK
2025/05/09 01:14:48 DEBUG : one.bak: Excluded (Path Filter)
2025/05/09 01:14:48 DEBUG : three.txt.bak: Excluded (Path Filter)
2025/05/09 01:14:48 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/05/09 01:14:48 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:14:48 DEBUG : two: Unchanged skipping
2025/05/09 01:14:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for checks to finish
2025/05/09 01:14:48 INFO  : one.bak: Deleted
2025/05/09 01:14:49 INFO  : one: Moved (server-side) to: one.bak
2025/05/09 01:14:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu/dst': Waiting for transfers to finish
2025/05/09 01:14:50 DEBUG : one: md5 = 7911d63ef4aa5dfae891ef149eca05b1 OK
2025/05/09 01:14:50 INFO  : one: Copied (new)
2025/05/09 01:14:50 DEBUG : Waiting for deletions to finish
2025/05/09 01:14:51 INFO  : three.txt.bak: Deleted
2025/05/09 01:14:51 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/05/09 01:14:51 INFO  : three.txt: Moved into backup dir
2025/05/09 01:14:54 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/09 01:14:54 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/05/09 01:14:54 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/05/09 01:14:54 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/05/09 01:14:54 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/05/09 01:14:54 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncBackupDirSuffixOnly (18.71s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:14:57 DEBUG : dst/one: md5 = 9536ee93a95376677c5366781975431e OK
2025/05/09 01:14:58 DEBUG : dst/two: md5 = c5b9d6f279fdae85569dbaa75fc69b7a OK
2025/05/09 01:14:59 DEBUG : dst/three.txt: md5 = 0f76cfc47269c0deec9af13d1ebd2201 OK
2025/05/09 01:15:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/dst"
2025/05/09 01:15:00 DEBUG : Config file has changed externally - reloading
2025/05/09 01:15:00 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/31u3jie661vd5p8j7rtc3hgbh0"
2025/05/09 01:15:01 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/05/09 01:15:02 INFO  : one: Moved (server-side) to: one.bak
2025/05/09 01:15:03 DEBUG : one: md5 = ca08b22601d4357f65e71ea392eef533 OK
2025/05/09 01:15:03 INFO  : one: Copied (new)
2025/05/09 01:15:03 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:15:03 DEBUG : two: Unchanged skipping
2025/05/09 01:15:03 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/05/09 01:15:04 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/05/09 01:15:05 DEBUG : three.txt: md5 = 946a823cecfe8e946f78402ef970955b OK
2025/05/09 01:15:05 INFO  : three.txt: Copied (new)
2025/05/09 01:15:06 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/05/09 01:15:07 INFO  : one.bak: Deleted
2025/05/09 01:15:08 INFO  : one: Moved (server-side) to: one.bak
2025/05/09 01:15:09 DEBUG : one: md5 = 0b9d3fabb97528afa25adfdcf9ddbf75 OK
2025/05/09 01:15:09 INFO  : one: Copied (new)
2025/05/09 01:15:09 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:15:09 DEBUG : two: Unchanged skipping
2025/05/09 01:15:10 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/05/09 01:15:10 INFO  : three.txt.bak: Deleted
2025/05/09 01:15:11 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/05/09 01:15:12 DEBUG : three.txt: md5 = ff3f19c9809d5440f4c93e12e56e77d5 OK
2025/05/09 01:15:12 INFO  : three.txt: Copied (new)
2025/05/09 01:15:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/09 01:15:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/05/09 01:15:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/05/09 01:15:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/05/09 01:15:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/05/09 01:15:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/05/09 01:15:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncSuffix (21.25s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:15:18 DEBUG : dst/one: md5 = 114bf6c93a1f8f2424df9378d68eb758 OK
2025/05/09 01:15:20 DEBUG : dst/two: md5 = c4915171943dbd940227c99f5aea2a17 OK
2025/05/09 01:15:21 DEBUG : dst/three.txt: md5 = e45bff885ba7760f8a1951834b043c05 OK
2025/05/09 01:15:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gotinuz3qesu/dst"
2025/05/09 01:15:21 DEBUG : Config file has changed externally - reloading
2025/05/09 01:15:21 DEBUG : Creating backend with remote "TestDrive:crypt/43dfprlfp7q80bqf2em08tpl0vd6qdk5p81vfcdrjt8cq1le80p0/31u3jie661vd5p8j7rtc3hgbh0"
2025/05/09 01:15:22 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/05/09 01:15:23 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/05/09 01:15:24 DEBUG : one: md5 = 4dddc34516592b8b4c6ad4394ec62f2a OK
2025/05/09 01:15:24 INFO  : one: Copied (new)
2025/05/09 01:15:25 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:15:25 DEBUG : two: Unchanged skipping
2025/05/09 01:15:25 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/05/09 01:15:26 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/05/09 01:15:27 DEBUG : three.txt: md5 = 433c67fcea023a2c85445b0fb00149e9 OK
2025/05/09 01:15:27 INFO  : three.txt: Copied (new)
2025/05/09 01:15:28 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/05/09 01:15:29 INFO  : one-2019-01-01: Deleted
2025/05/09 01:15:29 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/05/09 01:15:31 DEBUG : one: md5 = 4eeefbfee732ea47219f4083d7a1f4fc OK
2025/05/09 01:15:31 INFO  : one: Copied (new)
2025/05/09 01:15:31 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:15:31 DEBUG : two: Unchanged skipping
2025/05/09 01:15:31 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/05/09 01:15:32 INFO  : three-2019-01-01.txt: Deleted
2025/05/09 01:15:32 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/05/09 01:15:33 DEBUG : three.txt: md5 = 2ac9c9aff1d9153d9f92ee72df5a16cc OK
2025/05/09 01:15:33 INFO  : three.txt: Copied (new)
2025/05/09 01:15:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/05/09 01:15:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/05/09 01:15:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/05/09 01:15:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/05/09 01:15:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/05/09 01:15:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/05/09 01:15:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncSuffixKeepExtension (21.22s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:15:39 DEBUG : Testêé: md5 = f990062331796d8421c0673fab56bf3b OK
2025/05/09 01:15:39 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2025/05/09 01:15:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:15:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:15:40 DEBUG : Testêé: md5 = c9d8ab7ef4b336bc16a446f9e9db11d3 OK
2025/05/09 01:15:40 INFO  : Testêé: Copied (replaced existing) to: Testêé
2025/05/09 01:15:40 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (3.86s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:15:42 DEBUG : existing: Need to transfer - File not found at Destination
2025/05/09 01:15:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:15:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:15:43 DEBUG : existing: md5 = 245823d58c323eff71265e741ada3172 OK
2025/05/09 01:15:43 INFO  : existing: Copied (new)
2025/05/09 01:15:43 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:15:44 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2025/05/09 01:15:44 ERROR : existing: Source and destination exist but do not match: immutable file modified
2025/05/09 01:15:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:15:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:15:44 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': not deleting files as there were IO errors
2025/05/09 01:15:44 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncImmutable (4.53s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:15:47 DEBUG : EXISTING: md5 = d584f44f43a8db5a5e949cbe921557fd OK
2025/05/09 01:15:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:15:47 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:15:47 DEBUG : existing: Unchanged skipping
2025/05/09 01:15:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:15:47 DEBUG : Waiting for deletions to finish
2025/05/09 01:15:47 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (3.07s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    sync_test.go:2635: Skipping test as local or remote are case-sensitive
--- SKIP: TestFixCase (0.45s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", 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-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", 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-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.33s)
    --- SKIP: TestMaxTransfer/Hard (0.47s)
    --- SKIP: TestMaxTransfer/Soft (0.43s)
    --- SKIP: TestMaxTransfer/Cautious (0.43s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:15:52 DEBUG : both0: md5 = 7ff68b0ace8adfaced9f03bdaba4bfdd OK
2025/05/09 01:15:53 DEBUG : only0: md5 = 0ecd4c47967dbd98be3ed3ee30db88f7 OK
2025/05/09 01:15:55 DEBUG : both1: md5 = 42e0bf425559cb0feda0dc85644a85a8 OK
2025/05/09 01:15:56 DEBUG : only1: md5 = f2a7136885a4a9c76f7d4faa660bad51 OK
2025/05/09 01:15:57 DEBUG : both2: md5 = fc93c444374dc102de0c40f8ab392c86 OK
2025/05/09 01:15:59 DEBUG : only2: md5 = f0b24c4bab3a1b33c07dbb8aab824b05 OK
2025/05/09 01:16:00 DEBUG : both3: md5 = a41c6f058536ceeca2de6da48233d229 OK
2025/05/09 01:16:01 DEBUG : only3: md5 = 7e49f747b931698a626f9b3859557d8a OK
2025/05/09 01:16:02 DEBUG : both4: md5 = 6fdc3a89e04adf8af799566d2fb40751 OK
2025/05/09 01:16:04 DEBUG : only4: md5 = 843417e585cdd09f4b910c47fba22892 OK
2025/05/09 01:16:05 DEBUG : both5: md5 = dc84a52be63eeb4f7af94733556837af OK
2025/05/09 01:16:06 DEBUG : only5: md5 = 52a7d2a7cce576f9fc86216c3afa4941 OK
2025/05/09 01:16:08 DEBUG : both6: md5 = e1db8604d6a9250fd1e37f44c4a30253 OK
2025/05/09 01:16:09 DEBUG : only6: md5 = 267ab312eb83e1ab74ef391832324789 OK
2025/05/09 01:16:10 DEBUG : both7: md5 = 22882a4d97bf5c7d96c38187437d48ba OK
2025/05/09 01:16:11 DEBUG : only7: md5 = 8fc874ef502877bfa4391a6d7e40b318 OK
2025/05/09 01:16:13 DEBUG : both8: md5 = 79a4bdc6a8fbc8e62fa5ae2ec0728fb4 OK
2025/05/09 01:16:14 DEBUG : only8: md5 = b3a38fdf417b8d7507c854473578e1dd OK
2025/05/09 01:16:15 DEBUG : both9: md5 = 584b74b568eae007b00b87824c7ae47e OK
2025/05/09 01:16:17 DEBUG : only9: md5 = 9d862165728396ea6571fd5676a8bb8e OK
2025/05/09 01:16:18 DEBUG : both10: md5 = fd618e048624161a3fd249a94c8dce83 OK
2025/05/09 01:16:19 DEBUG : only10: md5 = 4d540612c3b92ec61ef3d0e13e6a2038 OK
2025/05/09 01:16:21 DEBUG : both11: md5 = 863cf9d34424e5c673e65191561fd2ec OK
2025/05/09 01:16:22 DEBUG : only11: md5 = c02319b08d67f6d857e040d551a1ed99 OK
2025/05/09 01:16:23 DEBUG : both12: md5 = 73c574c6bba3e2efff8e07fa23be7761 OK
2025/05/09 01:16:25 DEBUG : only12: md5 = f5e320fac23f90ad1d86f214f0d5d4f6 OK
2025/05/09 01:16:26 DEBUG : both13: md5 = 0c7e517a7d72a80dbf3a4f7ae0468b30 OK
2025/05/09 01:16:27 DEBUG : only13: md5 = 78939d4107dd82edf2a5c96e4bc33674 OK
2025/05/09 01:16:31 DEBUG : both14: md5 = 005dc9711d677821539b595d64fa6d2b OK
2025/05/09 01:16:32 DEBUG : only14: md5 = 023cc981a0ea64b78d158f7b90213231 OK
2025/05/09 01:16:33 DEBUG : both15: md5 = 5548a6353db93c989c06c2a193e4ef26 OK
2025/05/09 01:16:34 DEBUG : only15: md5 = 710f91bccda1212a277f066613e7fd84 OK
2025/05/09 01:16:36 DEBUG : both16: md5 = f82298a0805e5ddf0056c5724d933be7 OK
2025/05/09 01:16:37 DEBUG : only16: md5 = 5d756e83234908abef77af4816538363 OK
2025/05/09 01:16:38 DEBUG : both17: md5 = a238e562f70ac15ada8fa5e8f8945f09 OK
2025/05/09 01:16:40 DEBUG : only17: md5 = c5bfa1ef8193953e032bfa0c75bd19e6 OK
2025/05/09 01:16:41 DEBUG : both18: md5 = 6aae20ec63c0d52c4826f221e3769380 OK
2025/05/09 01:16:42 DEBUG : only18: md5 = 7a334843764d080488c91899495caa06 OK
2025/05/09 01:16:44 DEBUG : both19: md5 = 5958c88c9586638de36bdb86dcc82b7b OK
2025/05/09 01:16:45 DEBUG : only19: md5 = ca7be15c1ff294d36a645713409b67cb OK
2025/05/09 01:16:46 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:16:46 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:16:46 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:16:46 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:16:46 DEBUG : both1: Unchanged skipping
2025/05/09 01:16:46 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:16:46 DEBUG : both12: Unchanged skipping
2025/05/09 01:16:46 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:16:46 DEBUG : both13: Unchanged skipping
2025/05/09 01:16:46 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:16:46 DEBUG : both14: Unchanged skipping
2025/05/09 01:16:46 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:16:46 DEBUG : both15: Unchanged skipping
2025/05/09 01:16:46 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:16:46 DEBUG : both16: Unchanged skipping
2025/05/09 01:16:46 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:16:46 DEBUG : both17: Unchanged skipping
2025/05/09 01:16:46 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:16:46 DEBUG : both18: Unchanged skipping
2025/05/09 01:16:46 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:16:46 DEBUG : both19: Unchanged skipping
2025/05/09 01:16:46 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:16:46 DEBUG : both2: Unchanged skipping
2025/05/09 01:16:46 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:16:46 DEBUG : both3: Unchanged skipping
2025/05/09 01:16:46 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:16:46 DEBUG : both4: Unchanged skipping
2025/05/09 01:16:46 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:16:46 DEBUG : both5: Unchanged skipping
2025/05/09 01:16:46 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:16:46 DEBUG : both6: Unchanged skipping
2025/05/09 01:16:46 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:16:46 DEBUG : both7: Unchanged skipping
2025/05/09 01:16:46 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:16:46 DEBUG : both8: Unchanged skipping
2025/05/09 01:16:46 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:16:46 DEBUG : both9: Unchanged skipping
2025/05/09 01:16:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:16:46 DEBUG : both11: Unchanged skipping
2025/05/09 01:16:46 DEBUG : both0: Unchanged skipping
2025/05/09 01:16:46 DEBUG : both10: Unchanged skipping
2025/05/09 01:16:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:16:46 DEBUG : Waiting for deletions to finish
2025/05/09 01:16:46 INFO  : only19: Deleted
2025/05/09 01:16:46 INFO  : only2: Deleted
2025/05/09 01:16:46 INFO  : only10: Deleted
2025/05/09 01:16:46 INFO  : only6: Deleted
2025/05/09 01:16:46 INFO  : only11: Deleted
2025/05/09 01:16:46 INFO  : only12: Deleted
2025/05/09 01:16:46 INFO  : only15: Deleted
2025/05/09 01:16:47 INFO  : only18: Deleted
2025/05/09 01:16:47 INFO  : only8: Deleted
2025/05/09 01:16:47 INFO  : only0: Deleted
2025/05/09 01:16:47 INFO  : only5: Deleted
2025/05/09 01:16:47 INFO  : only1: Deleted
2025/05/09 01:16:47 INFO  : only14: Deleted
2025/05/09 01:16:47 INFO  : only4: Deleted
2025/05/09 01:16:47 INFO  : only17: Deleted
2025/05/09 01:16:47 INFO  : only7: Deleted
2025/05/09 01:16:48 INFO  : only13: Deleted
2025/05/09 01:16:48 INFO  : only3: Deleted
2025/05/09 01:16:48 INFO  : only16: Deleted
2025/05/09 01:16:48 INFO  : only9: Deleted
2025/05/09 01:16:48 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (66.96s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:16:59 DEBUG : both0: md5 = 7c4bbd168381adcb24629425805e66ce OK
2025/05/09 01:17:00 DEBUG : only0: md5 = ee3917bf20ab1f80ef037133c8cbda0d OK
2025/05/09 01:17:01 DEBUG : both1: md5 = af6084bd0e1fad3738cd4b047056a498 OK
2025/05/09 01:17:03 DEBUG : only1: md5 = 1dbffbe0389b7ffd36a4967fc7dc9f11 OK
2025/05/09 01:17:04 DEBUG : both2: md5 = 3e164f5c040c887e6b474cb6a59bd6f8 OK
2025/05/09 01:17:05 DEBUG : only2: md5 = 70ea89e31b3e64234aeaa3b21d796ec3 OK
2025/05/09 01:17:07 DEBUG : both3: md5 = cd9aa024581d709cae363ee43bb10cee OK
2025/05/09 01:17:08 DEBUG : only3: md5 = 30b95647e23e3b3e87b48b40005eb381 OK
2025/05/09 01:17:09 DEBUG : both4: md5 = d8272fe05c5163400b099a9401c032b0 OK
2025/05/09 01:17:11 DEBUG : only4: md5 = 7266f25a373de364e93f3616b4e0c4f4 OK
2025/05/09 01:17:12 DEBUG : both5: md5 = 526e5471d697abf10117c2072c3f35aa OK
2025/05/09 01:17:13 DEBUG : only5: md5 = 7e2df0b31ce0d15c2cc7f06e8f6eeaf4 OK
2025/05/09 01:17:15 DEBUG : both6: md5 = f76a68bac51c0ac2015a7a05d6ceb8df OK
2025/05/09 01:17:16 DEBUG : only6: md5 = 52c49e952973d4a8d1947e7c9e329e23 OK
2025/05/09 01:17:17 DEBUG : both7: md5 = c37350f2a83153fc6ec88ac89a094012 OK
2025/05/09 01:17:19 DEBUG : only7: md5 = fca1914276dd85127dab9141eb1f0a96 OK
2025/05/09 01:17:20 DEBUG : both8: md5 = 1092195a3eb9a7ef8a1e7e0db4c9a36c OK
2025/05/09 01:17:22 DEBUG : only8: md5 = ef1991c5224d5fd721da118a78ae1ca5 OK
2025/05/09 01:17:23 DEBUG : both9: md5 = 442f3703b8297df0a4f92a89b52e59a2 OK
2025/05/09 01:17:24 DEBUG : only9: md5 = f8beddc3a416f7733169f19338ca9420 OK
2025/05/09 01:17:25 DEBUG : both10: md5 = 97e45a3f5f0693e44bbd0cee5b68f6fd OK
2025/05/09 01:17:27 DEBUG : only10: md5 = 2ba2c0f597fd3caf78c50e6d59a8b719 OK
2025/05/09 01:17:28 DEBUG : both11: md5 = 8681b2394b18efd4ab948b456d9aa6d2 OK
2025/05/09 01:17:29 DEBUG : only11: md5 = 5e059b4427c404acbe92dc7ec78a8b99 OK
2025/05/09 01:17:31 DEBUG : both12: md5 = 92888a97bfbe8cb29842047883d78369 OK
2025/05/09 01:17:32 DEBUG : only12: md5 = 8155b6ebbfb41e741d9e2ba35efd791a OK
2025/05/09 01:17:33 DEBUG : both13: md5 = 5605508478baedb6ab3f3853a90e9590 OK
2025/05/09 01:17:35 DEBUG : only13: md5 = 71644def963a291e04947e9d1783f602 OK
2025/05/09 01:17:36 DEBUG : both14: md5 = cf2b418d528cd11f84b088d08fc86961 OK
2025/05/09 01:17:37 DEBUG : only14: md5 = dcc5b414d334673099e72e3077337a59 OK
2025/05/09 01:17:39 DEBUG : both15: md5 = 3b226b100628a61c7007da3288f990fd OK
2025/05/09 01:17:40 DEBUG : only15: md5 = 8d52d7d7943364e91d9dfaa2cff92bca OK
2025/05/09 01:17:41 DEBUG : both16: md5 = 40341afb175c3cfb309ab1fb1faddd51 OK
2025/05/09 01:17:43 DEBUG : only16: md5 = 7e0fddf6c6249bda03bbc059c7d4bf52 OK
2025/05/09 01:17:44 DEBUG : both17: md5 = 4534c41e922ff10e112303b348964a7c OK
2025/05/09 01:17:45 DEBUG : only17: md5 = 432bb79a44f623da35ca8515dd0cd71a OK
2025/05/09 01:17:46 DEBUG : both18: md5 = 0ec6243f5953a0dcc39bd6ef170aeeda OK
2025/05/09 01:17:48 DEBUG : only18: md5 = ca831e122c5d39396f55a3aa3fa28f2f OK
2025/05/09 01:17:49 DEBUG : both19: md5 = e2c89139bd8f126cc1c720513fc724b7 OK
2025/05/09 01:17:50 DEBUG : only19: md5 = 1856ca6000bbf902916acb018ad3b5a9 OK
2025/05/09 01:17:51 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:17:51 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:17:51 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:17:51 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:17:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for checks to finish
2025/05/09 01:17:51 DEBUG : both0: Unchanged skipping
2025/05/09 01:17:51 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:17:51 DEBUG : both12: Unchanged skipping
2025/05/09 01:17:51 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:17:51 DEBUG : both13: Unchanged skipping
2025/05/09 01:17:51 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:17:51 DEBUG : both14: Unchanged skipping
2025/05/09 01:17:51 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:17:51 DEBUG : both15: Unchanged skipping
2025/05/09 01:17:51 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:17:51 DEBUG : both16: Unchanged skipping
2025/05/09 01:17:51 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:17:51 DEBUG : both10: Unchanged skipping
2025/05/09 01:17:51 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:17:51 DEBUG : both1: Unchanged skipping
2025/05/09 01:17:51 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:17:51 DEBUG : both11: Unchanged skipping
2025/05/09 01:17:51 DEBUG : both17: Unchanged skipping
2025/05/09 01:17:51 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:17:51 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:17:51 DEBUG : both18: Unchanged skipping
2025/05/09 01:17:51 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:17:51 DEBUG : both4: Unchanged skipping
2025/05/09 01:17:51 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:17:51 DEBUG : both19: Unchanged skipping
2025/05/09 01:17:51 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:17:51 DEBUG : both6: Unchanged skipping
2025/05/09 01:17:51 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:17:51 DEBUG : both7: Unchanged skipping
2025/05/09 01:17:51 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:17:51 DEBUG : both8: Unchanged skipping
2025/05/09 01:17:51 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/05/09 01:17:51 DEBUG : both2: Unchanged skipping
2025/05/09 01:17:51 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2025/05/09 01:17:51 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2025/05/09 01:17:51 DEBUG : both3: Unchanged skipping
2025/05/09 01:17:51 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2025/05/09 01:17:51 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2025/05/09 01:17:51 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2025/05/09 01:17:51 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2025/05/09 01:17:51 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2025/05/09 01:17:51 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2025/05/09 01:17:51 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2025/05/09 01:17:51 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2025/05/09 01:17:51 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2025/05/09 01:17:51 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2025/05/09 01:17:51 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2025/05/09 01:17:51 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2025/05/09 01:17:51 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2025/05/09 01:17:51 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2025/05/09 01:17:51 DEBUG : both9: Unchanged skipping
2025/05/09 01:17:51 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2025/05/09 01:17:51 DEBUG : both5: Unchanged skipping
2025/05/09 01:17:51 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2025/05/09 01:17:51 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2025/05/09 01:17:51 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2025/05/09 01:17:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Waiting for transfers to finish
2025/05/09 01:17:52 DEBUG : only12: md5 = d44a3b081895f462c1d1172f234ed62a OK
2025/05/09 01:17:52 INFO  : only12: Copied (replaced existing)
2025/05/09 01:17:52 DEBUG : only10: md5 = 84f91ab1996ca7f4f45b584651204d9f OK
2025/05/09 01:17:52 INFO  : only10: Copied (replaced existing)
2025/05/09 01:17:52 DEBUG : only11: md5 = 03bdc0ce83f3b8b4282f21d4172bd27a OK
2025/05/09 01:17:52 INFO  : only11: Copied (replaced existing)
2025/05/09 01:17:52 DEBUG : only0: md5 = 9089bf27d99a2850e09b646d704dbab9 OK
2025/05/09 01:17:52 INFO  : only0: Copied (replaced existing)
2025/05/09 01:17:53 DEBUG : only13: md5 = 716c71c6cb74955fea2243f497109e08 OK
2025/05/09 01:17:53 INFO  : only13: Copied (replaced existing)
2025/05/09 01:17:53 DEBUG : only15: md5 = 1ce0dfd28e0f8707adec559e526930a8 OK
2025/05/09 01:17:53 INFO  : only15: Copied (replaced existing)
2025/05/09 01:17:53 DEBUG : only16: md5 = 685872d4da59307e4b6c7f22b28f3809 OK
2025/05/09 01:17:53 INFO  : only16: Copied (replaced existing)
2025/05/09 01:17:53 DEBUG : only14: md5 = 8c6194b8ce3693cdc018b643d1c156a8 OK
2025/05/09 01:17:53 INFO  : only14: Copied (replaced existing)
2025/05/09 01:17:54 DEBUG : only17: md5 = cc222341e0684342659022bc1df8a3b5 OK
2025/05/09 01:17:54 INFO  : only17: Copied (replaced existing)
2025/05/09 01:17:54 DEBUG : only19: md5 = add43e5f116978d22558a8a87efac204 OK
2025/05/09 01:17:54 INFO  : only19: Copied (replaced existing)
2025/05/09 01:17:54 DEBUG : only18: md5 = f2a57f0de15ca8d6f5b74917c6759db0 OK
2025/05/09 01:17:54 INFO  : only18: Copied (replaced existing)
2025/05/09 01:17:54 DEBUG : only2: md5 = d20c08caa95aaa26b5d8891d875b2e89 OK
2025/05/09 01:17:54 INFO  : only2: Copied (replaced existing)
2025/05/09 01:17:55 DEBUG : only3: md5 = 067c48cf8aa00a7e0f1c8fd2bfcc7c42 OK
2025/05/09 01:17:55 INFO  : only3: Copied (replaced existing)
2025/05/09 01:17:55 DEBUG : only4: md5 = 6f9cc618413fcb549bbd55128171ba03 OK
2025/05/09 01:17:55 INFO  : only4: Copied (replaced existing)
2025/05/09 01:17:55 DEBUG : only5: md5 = 708260927a5631541e9e3d8cfdfd735f OK
2025/05/09 01:17:55 INFO  : only5: Copied (replaced existing)
2025/05/09 01:17:55 DEBUG : only1: md5 = 551c176d9517251a252c5916a719142b OK
2025/05/09 01:17:55 INFO  : only1: Copied (replaced existing)
2025/05/09 01:17:56 DEBUG : only7: md5 = 0ee3ed3a53c5ac91655bb4139743e3d7 OK
2025/05/09 01:17:56 INFO  : only7: Copied (replaced existing)
2025/05/09 01:17:56 DEBUG : only8: md5 = f6bceea3f54a9caa05006e539103e7bd OK
2025/05/09 01:17:56 INFO  : only8: Copied (replaced existing)
2025/05/09 01:17:56 DEBUG : only6: md5 = e31b6383e6bca89c308fb6a956c733db OK
2025/05/09 01:17:56 INFO  : only6: Copied (replaced existing)
2025/05/09 01:17:56 DEBUG : only9: md5 = 744bb5ea3e883ff90a1f759f24772a0f OK
2025/05/09 01:17:56 INFO  : only9: Copied (replaced existing)
2025/05/09 01:17:56 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (77.64s)
=== RUN   TestSyncReplaceDirModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:18:15 DEBUG : empty_dir: Making directory with metadata
2025/05/09 01:18:15 INFO  : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/09 01:18:15 DEBUG : empty_on_remote: Making directory with metadata
2025/05/09 01:18:15 INFO  : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/09 01:18:15 DEBUG : empty_on_remote: Making directory with metadata
2025/05/09 01:18:16 INFO  : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:18:21 INFO  : test_dir1: Set directory modification time (using DirSetModTime)
2025/05/09 01:18:21 INFO  : test_dir2: Set directory modification time (using DirSetModTime)
2025/05/09 01:18:21 INFO  : test_dir2/sub_dir: Set directory modification time (using DirSetModTime)
2025/05/09 01:18:21 INFO  : empty_on_remote: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:18:28 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto"
2025/05/09 01:18:28 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8"
2025/05/09 01:18:29 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00"
--- PASS: TestSyncReplaceDirModTime (15.71s)
=== RUN   TestSyncReplaceDirModTimeWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:18:31 DEBUG : empty_dir: Making directory with metadata
2025/05/09 01:18:31 INFO  : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/09 01:18:31 DEBUG : empty_on_remote: Making directory with metadata
2025/05/09 01:18:31 INFO  : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/09 01:18:31 DEBUG : empty_on_remote: Making directory with metadata
2025/05/09 01:18: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-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:18:36 INFO  : test_dir1: Set directory modification time (using DirSetModTime)
2025/05/09 01:18:36 INFO  : test_dir2: Set directory modification time (using DirSetModTime)
2025/05/09 01:18:36 INFO  : test_dir2/sub_dir: Set directory modification time (using DirSetModTime)
2025/05/09 01:18:36 INFO  : empty_on_remote: Set directory modification time (using DirSetModTime)
2025/05/09 01:18:36 INFO  : empty_dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:18:43 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto"
2025/05/09 01:18:44 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8"
2025/05/09 01:18:44 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00"
--- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (16.21s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:18:47 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/05/09 01:18:47 DEBUG : sub dir: Making directory with metadata
2025/05/09 01:18:48 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:19:04 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/05/09 01:19:05 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/05/09 01:19:05 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/09 01:19:05 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:19:18 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2025/05/09 01:19:19 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/05/09 01:19:20 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2025/05/09 01:19:20 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2025/05/09 01:19:21 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/05/09 01:19:22 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/05/09 01:19:22 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/05/09 01:19:23 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/05/09 01:19:24 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/05/09 01:19:25 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2025/05/09 01:19:25 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/05/09 01:19:25 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (39.98s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:19:27 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/05/09 01:19:27 DEBUG : sub dir: Making directory with metadata
2025/05/09 01:19:28 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:19:48 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/05/09 01:19:49 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/05/09 01:19:49 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/05/09 01:19:49 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu'", Local "Local file system at /tmp/rclone2669512264", Modify Window "1ms"
2025/05/09 01:20:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/05/09 01:20:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2025/05/09 01:20:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2025/05/09 01:20:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/05/09 01:20:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/05/09 01:20:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/05/09 01:20:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/05/09 01:20:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/05/09 01:20:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2025/05/09 01:20:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/05/09 01:20:07 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (41.32s)
PASS
2025/05/09 01:20:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gotinuz3qesu': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 15m15.170914117s (try 1/5)