"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5)
2025/01/09 01:22:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi"
2025/01/09 01:22:05 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/01/09 01:22:05 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0"
2025/01/09 01:22:06 DEBUG : Creating backend with remote "/tmp/rclone2858783104"
=== RUN   TestPipe
--- PASS: TestPipe (0.00s)
=== RUN   TestPipeConcurrent
--- PASS: TestPipeConcurrent (0.02s)
=== RUN   TestPipeOrderBy
=== RUN   TestPipeOrderBy/#00
=== RUN   TestPipeOrderBy/size
=== RUN   TestPipeOrderBy/name
=== RUN   TestPipeOrderBy/modtime
=== RUN   TestPipeOrderBy/size,ascending
=== RUN   TestPipeOrderBy/name,asc
=== RUN   TestPipeOrderBy/modtime,ascending
=== RUN   TestPipeOrderBy/size,descending
=== RUN   TestPipeOrderBy/name,desc
=== RUN   TestPipeOrderBy/modtime,descending
=== RUN   TestPipeOrderBy/size,mixed,50
=== RUN   TestPipeOrderBy/size,mixed,51
--- PASS: TestPipeOrderBy (0.00s)
    --- PASS: TestPipeOrderBy/#00 (0.00s)
    --- PASS: TestPipeOrderBy/size (0.00s)
    --- PASS: TestPipeOrderBy/name (0.00s)
    --- PASS: TestPipeOrderBy/modtime (0.00s)
    --- PASS: TestPipeOrderBy/size,ascending (0.00s)
    --- PASS: TestPipeOrderBy/name,asc (0.00s)
    --- PASS: TestPipeOrderBy/modtime,ascending (0.00s)
    --- PASS: TestPipeOrderBy/size,descending (0.00s)
    --- PASS: TestPipeOrderBy/name,desc (0.00s)
    --- PASS: TestPipeOrderBy/modtime,descending (0.00s)
    --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s)
    --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s)
=== RUN   TestNewLess
=== RUN   TestNewLess/blankOK
=== RUN   TestNewLess/tooManyParts
=== RUN   TestNewLess/tooManyParts2
=== RUN   TestNewLess/badMixed
=== RUN   TestNewLess/unknownComparison
=== RUN   TestNewLess/unknownSortDirection
=== RUN   TestNewLess/size
=== RUN   TestNewLess/name
=== RUN   TestNewLess/modtime
=== RUN   TestNewLess/size,ascending
=== RUN   TestNewLess/name,asc
=== RUN   TestNewLess/modtime,ascending
=== RUN   TestNewLess/size,descending
=== RUN   TestNewLess/name,desc
=== RUN   TestNewLess/modtime,descending
=== RUN   TestNewLess/modtime,mixed
=== RUN   TestNewLess/modtime,mixed,30
--- PASS: TestNewLess (0.00s)
    --- PASS: TestNewLess/blankOK (0.00s)
    --- PASS: TestNewLess/tooManyParts (0.00s)
    --- PASS: TestNewLess/tooManyParts2 (0.00s)
    --- PASS: TestNewLess/badMixed (0.00s)
    --- PASS: TestNewLess/unknownComparison (0.00s)
    --- PASS: TestNewLess/unknownSortDirection (0.00s)
    --- PASS: TestNewLess/size (0.00s)
    --- PASS: TestNewLess/name (0.00s)
    --- PASS: TestNewLess/modtime (0.00s)
    --- PASS: TestNewLess/size,ascending (0.00s)
    --- PASS: TestNewLess/name,asc (0.00s)
    --- PASS: TestNewLess/modtime,ascending (0.00s)
    --- PASS: TestNewLess/size,descending (0.00s)
    --- PASS: TestNewLess/name,desc (0.00s)
    --- PASS: TestNewLess/modtime,descending (0.00s)
    --- PASS: TestNewLess/modtime,mixed (0.00s)
    --- PASS: TestNewLess/modtime,mixed,30 (0.00s)
=== RUN   TestRcCopy
    rc_test.go:16: Skipping test on non local remote
--- SKIP: TestRcCopy (0.00s)
=== RUN   TestRcMove
    rc_test.go:16: Skipping test on non local remote
--- SKIP: TestRcMove (0.00s)
=== RUN   TestRcSync
    rc_test.go:16: Skipping test on non local remote
--- SKIP: TestRcSync (0.00s)
=== RUN   TestCopyWithDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:22:07 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/09 01:22:07 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/09 01:22:07 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2025/01/09 01:22:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:22:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:22:07 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (2.57s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:22:09 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/09 01:22:09 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/09 01:22:09 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/09 01:22:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:22:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:22:12 DEBUG : sub dir/hello world: md5 = 904201266ff92eda7e7e9cbdeefc26ab OK
2025/01/09 01:22:12 INFO  : sub dir/hello world: Copied (new)
2025/01/09 01:22:12 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:22:14 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (6.94s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:22:16 DEBUG : metadata sub dir: Making directory with metadata
2025/01/09 01:22:16 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/09 01:22:16 DEBUG : empty metadata sub dir: Making directory with metadata
2025/01/09 01:22:16 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/09 01:22:16 DEBUG : Local file system at /tmp/rclone2858783104: File to upload is small (21 bytes), uploading instead of streaming
2025/01/09 01:22:16 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2025/01/09 01:22:16 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2025/01/09 01:22:16 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2025/01/09 01:22:16 DEBUG : Google drive root 'crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0': Skipping btime metadata as can't update it on an existing file: 2025-01-09T01:22:16.009922103Z
2025/01/09 01:22:17 INFO  : empty metadata sub dir: Updated directory metadata
2025/01/09 01:22:17 DEBUG : Google drive root 'crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0': Skipping btime metadata as can't update it on an existing file: 2025-01-09T01:22:16.009922103Z
2025/01/09 01:22:18 INFO  : metadata sub dir: Updated directory metadata
2025/01/09 01:22:18 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2025/01/09 01:22:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:22:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:22:19 DEBUG : metadata sub dir/hello metadata world: md5 = dd1f6c3823dac22a04de3d5788b9cced OK
2025/01/09 01:22:19 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:22:22 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (8.68s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:22:24 DEBUG : metadata sub dir: Making directory with metadata
2025/01/09 01:22:24 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/09 01:22:24 DEBUG : empty metadata sub dir: Making directory with metadata
2025/01/09 01:22:24 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/09 01:22:24 DEBUG : Local file system at /tmp/rclone2858783104: File to upload is small (21 bytes), uploading instead of streaming
2025/01/09 01:22:24 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2025/01/09 01:22:24 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2025/01/09 01:22:24 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2025/01/09 01:22:24 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2025/01/09 01:22:24 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2025/01/09 01:22:24 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2025/01/09 01:22:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:22:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:22:27 DEBUG : metadata sub dir/hello metadata world: md5 = d28135f75c951807fe630cd07ad9e315 OK
2025/01/09 01:22:27 INFO  : metadata sub dir/hello metadata world: Copied (new)
2025/01/09 01:22:27 DEBUG : Google drive root 'crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0': Skipping btime metadata as can't update it on an existing file: 2025-01-09T01:22:24.689871162Z
2025/01/09 01:22:28 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:22:31 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (7.64s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:22:32 DEBUG : Creating backend with remote "/non-existing"
2025/01/09 01:22:32 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2025/01/09 01:22:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:22:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.13s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:22:33 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/09 01:22:33 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/09 01:22:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:22:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:22:36 DEBUG : sub dir/hello world: md5 = 88ad14111ae07515dfd6971a313b292d OK
2025/01/09 01:22:36 INFO  : sub dir/hello world: Copied (new)
2025/01/09 01:22:36 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:22:38 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (6.27s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:22:39 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Running all checks before starting transfers
2025/01/09 01:22:39 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/09 01:22:39 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/09 01:22:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:22:39 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Checks finished, now starting transfers
2025/01/09 01:22:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:22:42 DEBUG : sub dir/hello world: md5 = f473c75ef2e5136f7f798317bbf1e0bf OK
2025/01/09 01:22:42 INFO  : sub dir/hello world: Copied (new)
2025/01/09 01:22:43 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:22:44 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (6.52s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:22:46 ERROR : Ignoring --no-traverse with sync
2025/01/09 01:22:46 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/09 01:22:46 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/09 01:22:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:22:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:22:49 DEBUG : sub dir/hello world: md5 = 921565a68a8da8973038040a13982a9f OK
2025/01/09 01:22:49 INFO  : sub dir/hello world: Copied (new)
2025/01/09 01:22:49 DEBUG : Waiting for deletions to finish
2025/01/09 01:22:49 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:22:51 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (6.29s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:22:52 DEBUG : hello world2: Need to transfer - File not found at Destination
2025/01/09 01:22:52 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/09 01:22:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:22:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:22:54 DEBUG : hello world2: md5 = 1e25f69966fd5bc8299afe1433cfc601 OK
2025/01/09 01:22:54 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestCopyWithDepth (3.69s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:22:56 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/09 01:22:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:22:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:22:57 DEBUG : potato2: md5 = 20944dae4a681e742f0342fb7e68aac3 OK
2025/01/09 01:22:57 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (3.42s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:22:59 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/09 01:22:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:22:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:23:01 DEBUG : potato2: md5 = 941c687a203b341262bd23adcac03c8a OK
2025/01/09 01:23:01 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (3.54s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:23:03 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/01/09 01:23:03 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/09 01:23:03 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/09 01:23:03 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/09 01:23:03 DEBUG : sub dir: Making directory with metadata
2025/01/09 01:23:04 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/01/09 01:23:04 DEBUG : sub dir2: Making directory with metadata
2025/01/09 01:23:05 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/09 01:23:05 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/09 01:23:05 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/01/09 01:23:06 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/09 01:23:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:23:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:23:06 DEBUG : sub dir/hello world: md5 = abf1cc6a754c98e1f55ad0f4457e3027 OK
2025/01/09 01:23:06 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:23:10 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2025/01/09 01:23:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (9.61s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:23:12 INFO  : sub dir2: Making directory
2025/01/09 01:23:12 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/01/09 01:23:12 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/09 01:23:13 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/09 01:23:13 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/01/09 01:23:13 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2025/01/09 01:23:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/09 01:23:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:23:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:23:15 DEBUG : sub dir/hello world: md5 = f5abf5e975f1451ab8f4260353c2c27e OK
2025/01/09 01:23:15 INFO  : sub dir/hello world: Copied (new)
2025/01/09 01:23:16 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/09 01:23:18 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (6.31s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:23:19 DEBUG : sub dir2: Making directory with metadata
2025/01/09 01:23:19 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/09 01:23:19 DEBUG : sub dir: Making directory with metadata
2025/01/09 01:23:20 INFO  : sub dir: Made directory with metadata (mtime=2025-01-09T01:23:19.113551411Z)
2025/01/09 01:23:20 DEBUG : sub dir2: Making directory with metadata
2025/01/09 01:23:21 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/09 01:23:21 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/09 01:23:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:23:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:23:23 DEBUG : sub dir/hello world: md5 = bf83ab3a8fa30d15a1feb8d3649549af OK
2025/01/09 01:23:23 INFO  : sub dir/hello world: Copied (new)
2025/01/09 01:23:23 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:23:26 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (8.79s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:23:27 DEBUG : sub dir no update dir modtime: Making directory with metadata
2025/01/09 01:23:27 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/01/09 01:23:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:23:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:23:29 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (4.54s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:23:32 INFO  : sub dir2: Making directory
2025/01/09 01:23:32 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/09 01:23:32 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/01/09 01:23:32 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/09 01:23:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:23:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:23:35 DEBUG : sub dir/hello world: md5 = d7ecf66b5143d8c051846b976cd8ce31 OK
2025/01/09 01:23:35 INFO  : sub dir/hello world: Copied (new)
2025/01/09 01:23:35 INFO  : sub dir/hello world: Deleted
2025/01/09 01:23:35 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/09 01:23:37 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (6.11s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:23:38 DEBUG : sub dir2: Making directory with metadata
2025/01/09 01:23:38 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/09 01:23:38 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/09 01:23:38 DEBUG : sub dir: Making directory with metadata
2025/01/09 01:23:39 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/01/09 01:23:39 DEBUG : sub dir2: Making directory with metadata
2025/01/09 01:23:40 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/09 01:23:40 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/09 01:23:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:23:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:23:42 DEBUG : sub dir/hello world: md5 = 27bfeb4a82cb1a1b68cd9a2e4cfa13b5 OK
2025/01/09 01:23:42 INFO  : sub dir/hello world: Copied (new)
2025/01/09 01:23:42 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:23:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (8.81s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.59s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:23:47 INFO  : sub dir2: Making directory
2025/01/09 01:23:48 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/09 01:23:48 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/01/09 01:23:48 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/09 01:23:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:23:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:23:51 DEBUG : sub dir/hello world: md5 = 9101a938efbed18687fc0331403e00b7 OK
2025/01/09 01:23:51 INFO  : sub dir/hello world: Copied (new)
2025/01/09 01:23:51 DEBUG : Waiting for deletions to finish
2025/01/09 01:23:51 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/09 01:23:53 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (6.87s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:23:57 DEBUG : sub dir/hello world: md5 = a1a38aa68428333874d6502e9d2318aa OK
2025/01/09 01:23:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-huxobal5wopo"
2025/01/09 01:23:58 DEBUG : Creating backend with remote "TestDrive:crypt/aer5iui1oklm11cvoetck2ef53u2g9es97ko7bskgb0109kb5hb0"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi' -> Encrypted drive 'TestCryptDrive:rclone-test-huxobal5wopo'
2025/01/09 01:23:59 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/09 01:23:59 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/09 01:23:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-huxobal5wopo': Waiting for checks to finish
2025/01/09 01:23:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-huxobal5wopo': Waiting for transfers to finish
2025/01/09 01:24:02 INFO  : sub dir/hello world: Copied (server-side copy)
2025/01/09 01:24:04 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:24:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-huxobal5wopo': Purge remote
2025/01/09 01:24:07 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (13.87s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:24:11 DEBUG : sub dir/hello world: md5 = d092db751ebe8bf5de8d404f45f3467e OK
2025/01/09 01:24:12 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/09 01:24:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:24:12 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/01/09 01:24:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:24:13 DEBUG : sub dir/hello world: md5 = 84208be8989b49acb78e42da9030eaeb OK
2025/01/09 01:24:13 INFO  : sub dir/hello world: Copied (replaced existing)
2025/01/09 01:24:14 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:24:16 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (9.46s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:24:20 DEBUG : sub dir/hello world: md5 = 9f1224f2609226bb076f8bd610329cf8 OK
2025/01/09 01:24:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qojewiv3johu"
2025/01/09 01:24:21 DEBUG : Creating backend with remote "TestDrive:crypt/gt00boobjkgvfm12d7m3qdok3p4vitajqs28672qgthqbgo27vc0"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi' -> Encrypted drive 'TestCryptDrive:rclone-test-qojewiv3johu'
2025/01/09 01:24:22 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/09 01:24:22 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/09 01:24:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qojewiv3johu': Waiting for checks to finish
2025/01/09 01:24:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qojewiv3johu': Waiting for transfers to finish
2025/01/09 01:24:26 INFO  : sub dir/hello world: Copied (server-side copy)
2025/01/09 01:24:26 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:24:29 DEBUG : sub dir/hello world: md5 = c79d5afadd08c68a7fa8f0546b86f487 OK
2025/01/09 01:24:29 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/01/09 01:24:29 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/09 01:24:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qojewiv3johu': Waiting for checks to finish
2025/01/09 01:24:29 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/01/09 01:24:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qojewiv3johu': Waiting for transfers to finish
2025/01/09 01:24:32 INFO  : sub dir/hello world: Copied (server-side copy)
2025/01/09 01:24:32 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:24:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qojewiv3johu': Purge remote
2025/01/09 01:24:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (18.65s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:24:39 DEBUG : sub dir/hello world: md5 = 482d462a26ef1425ddd2664ba5f8a88d OK
2025/01/09 01:24:40 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/09 01:24:40 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/01/09 01:24:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:24:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:24:41 DEBUG : sub dir/hello world: md5 = 8036252882d599ccd7b82b055c0923c0 OK
2025/01/09 01:24:41 INFO  : sub dir/hello world: Copied (replaced existing)
2025/01/09 01:24:41 INFO  : sub dir/hello world: Deleted
2025/01/09 01:24:42 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:24:44 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (8.77s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:24:48 DEBUG : sub dir/hello world: md5 = e1cdef7f535e0f83f120fc2592e4578e OK
2025/01/09 01:24:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hitezak2nawu"
2025/01/09 01:24:48 DEBUG : Creating backend with remote "TestDrive:crypt/duefsa78i3bpl2u0pvlgs8a8givtpcv4ue7mq9lq8skdfm83b9c0"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi' -> Encrypted drive 'TestCryptDrive:rclone-test-hitezak2nawu'
2025/01/09 01:24:50 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/09 01:24:50 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/09 01:24:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hitezak2nawu': Waiting for checks to finish
2025/01/09 01:24:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hitezak2nawu': Waiting for transfers to finish
2025/01/09 01:24:53 INFO  : sub dir/hello world: Copied (server-side copy)
2025/01/09 01:24:55 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:24:57 DEBUG : sub dir/hello world: md5 = fee9fd8f944a551c8837481fda4cd3aa OK
2025/01/09 01:24:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hitezak2nawu': Using server-side directory move
2025/01/09 01:24:57 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-hitezak2nawu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/01/09 01:24:58 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/01/09 01:24:58 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/09 01:24:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hitezak2nawu': Waiting for checks to finish
2025/01/09 01:24:58 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/01/09 01:24:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hitezak2nawu': Waiting for transfers to finish
2025/01/09 01:24:58 INFO  : sub dir/hello world: Deleted
2025/01/09 01:24:59 INFO  : sub dir/hello world: Moved (server-side)
2025/01/09 01:25:00 INFO  : sub dir: Set directory modification time (using SetModTime)
2025/01/09 01:25:03 DEBUG : sub dir/hello world: md5 = 9b347feb51a151db38852e0efcfb1d78 OK
2025/01/09 01:25:03 DEBUG : testing file moves
2025/01/09 01:25:03 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/01/09 01:25:03 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/09 01:25:04 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2025/01/09 01:25:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hitezak2nawu': Waiting for checks to finish
2025/01/09 01:25:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hitezak2nawu': Waiting for transfers to finish
2025/01/09 01:25:04 INFO  : sub dir/hello world: Deleted
2025/01/09 01:25:05 INFO  : sub dir/hello world: Moved (server-side)
2025/01/09 01:25:05 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:25:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hitezak2nawu': Purge remote
--- PASS: TestServerSideMoveOverSelf (24.31s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:25:12 DEBUG : sub dir/hello world: md5 = 2ecce279bd75408be2c6986325f8dccc OK
2025/01/09 01:25:12 ERROR : : error listing: directory not found
2025/01/09 01:25:13 INFO  : Local file system at /tmp/rclone2858783104: Making directory
2025/01/09 01:25:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:25:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:25:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (7.03s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:25:19 DEBUG : sub dir/hello world: md5 = cec6cd115e8462e861cab87af06a7138 OK
2025/01/09 01:25:20 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/09 01:25:20 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/09 01:25:20 DEBUG : Local file system at /tmp/rclone2858783104: Waiting for checks to finish
2025/01/09 01:25:20 DEBUG : Local file system at /tmp/rclone2858783104: Waiting for transfers to finish
2025/01/09 01:25:21 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2025/01/09 01:25:21 INFO  : sub dir/hello world: Copied (new)
2025/01/09 01:25:21 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:25:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (7.37s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:25:24 DEBUG : check sum: Need to transfer - File not found at Destination
2025/01/09 01:25:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:25:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:25:26 DEBUG : check sum: md5 = 40dc0a45f2c8bda254c4e6ac30dbb6a0 OK
2025/01/09 01:25:26 INFO  : check sum: Copied (new)
2025/01/09 01:25:26 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:25:26 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2025/01/09 01:25:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:25:26 DEBUG : check sum: Size of src and dst objects identical
2025/01/09 01:25:26 DEBUG : check sum: Unchanged skipping
2025/01/09 01:25:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:25:26 DEBUG : Waiting for deletions to finish
2025/01/09 01:25:26 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (4.72s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:25:29 DEBUG : sizeonly: Need to transfer - File not found at Destination
2025/01/09 01:25:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:25:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:25:30 DEBUG : sizeonly: md5 = 8accd9a571354216e51d9901f35601b1 OK
2025/01/09 01:25:30 INFO  : sizeonly: Copied (new)
2025/01/09 01:25:30 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:25:31 DEBUG : sizeonly: Sizes identical
2025/01/09 01:25:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:25:31 DEBUG : sizeonly: Unchanged skipping
2025/01/09 01:25:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:25:31 DEBUG : Waiting for deletions to finish
2025/01/09 01:25:31 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (4.58s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:25:33 DEBUG : ignore-size: Need to transfer - File not found at Destination
2025/01/09 01:25:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:25:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:25:35 DEBUG : ignore-size: md5 = 81e21b7fec35b68db4a3aa83b0fbda5c OK
2025/01/09 01:25:35 INFO  : ignore-size: Copied (new)
2025/01/09 01:25:35 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:25:36 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:25:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:25:36 DEBUG : ignore-size: Unchanged skipping
2025/01/09 01:25:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:25:36 DEBUG : Waiting for deletions to finish
2025/01/09 01:25:36 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (4.60s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:25:40 DEBUG : existing: md5 = 5d07d97eac07f0ff2333a99e981daeb6 OK
2025/01/09 01:25:40 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:25:40 DEBUG : existing: Unchanged skipping
2025/01/09 01:25:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:25:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:25:40 DEBUG : Waiting for deletions to finish
2025/01/09 01:25:40 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:25:41 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2025/01/09 01:25:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:25:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:25:42 DEBUG : existing: md5 = baf5b7fbb0bf72ccae54308e5a7e8c06 OK
2025/01/09 01:25:42 INFO  : existing: Copied (replaced existing)
2025/01/09 01:25:42 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (6.42s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:25:44 DEBUG : existing: Need to transfer - File not found at Destination
2025/01/09 01:25:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:25:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:25:46 DEBUG : existing: md5 = 4ba721c3988a7901e0c1f863a77b0412 OK
2025/01/09 01:25:46 INFO  : existing: Copied (new)
2025/01/09 01:25:46 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:25:47 DEBUG : existing: Destination exists, skipping
2025/01/09 01:25:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:25:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:25:47 DEBUG : Waiting for deletions to finish
2025/01/09 01:25:47 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (4.78s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:25:52 DEBUG : b/potato: md5 = 173563c79bf612c799bc3a311f11e1b3 OK
2025/01/09 01:25:54 DEBUG : c/non empty space: md5 = ebdc1402848a7c45c2ddba01a92e6a4b OK
2025/01/09 01:25:54 INFO  : d: Making directory
2025/01/09 01:25:57 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/01/09 01:25:57 DEBUG : Added delayed dir = "c", newDst=c
2025/01/09 01:25:57 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/01/09 01:25:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:25:57 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:25:57 DEBUG : c/non empty space: Unchanged skipping
2025/01/09 01:25:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:25:59 DEBUG : a/potato2: md5 = 9cd1e44278757ac9ae68f140ab7920d7 OK
2025/01/09 01:25:59 INFO  : a/potato2: Copied (new)
2025/01/09 01:25:59 DEBUG : Waiting for deletions to finish
2025/01/09 01:26:00 INFO  : b/potato: Deleted
2025/01/09 01:26:01 INFO  : a: Set directory modification time (using DirSetModTime)
2025/01/09 01:26:01 INFO  : d: Removing directory
2025/01/09 01:26:01 INFO  : b: Removing directory
2025/01/09 01:26:02 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/01/09 01:26:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:26:05 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/01/09 01:26:06 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (17.94s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:26:08 DEBUG : empty space: md5 = c0ca2ddfd0eaf24f7e985fe96eb034d5 OK
2025/01/09 01:26:09 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2025/01/09 01:26:09 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2025/01/09 01:26:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:26:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:26:09 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:26:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:26:09 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2025/01/09 01:26:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:26:11 DEBUG : empty space: md5 = 7d0e7f8955ee21f7c5a91b7d1b06520e OK
2025/01/09 01:26:11 INFO  : empty space: Copied (replaced existing)
2025/01/09 01:26:11 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (6.13s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.44s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:26:15 DEBUG : foo: md5 = 02741466a96edcf9fbc4369b89b1878d OK
2025/01/09 01:26:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:26:16 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2025/01/09 01:26:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:26:17 DEBUG : foo: md5 = b3a5f3f7dc8bfb1ac4c3ac26f5eebeca OK
2025/01/09 01:26:17 INFO  : foo: Copied (replaced existing)
2025/01/09 01:26:17 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (5.38s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:26:20 DEBUG : empty space: md5 = 406185231e8de7a7c5f75ce7783acf6e OK
2025/01/09 01:26:21 DEBUG : potato: Need to transfer - File not found at Destination
2025/01/09 01:26:21 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:26:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:26:21 DEBUG : empty space: Unchanged skipping
2025/01/09 01:26:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:26:23 DEBUG : potato: md5 = 5e5b343ba34b06886d67cd4341fb275b OK
2025/01/09 01:26:23 INFO  : potato: Copied (new)
2025/01/09 01:26:23 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (6.08s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:26:26 DEBUG : potato: md5 = 73b439396eda3133fb980e43df524e6a OK
2025/01/09 01:26:27 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2025/01/09 01:26:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:26:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:26:28 DEBUG : potato: md5 = 398ceaf96f544c2bb62ccb33b16d61b8 OK
2025/01/09 01:26:28 INFO  : potato: Copied (replaced existing)
2025/01/09 01:26:28 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (5.15s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:26:32 DEBUG : potato: md5 = a33f2d9943fcce10df455e9722c9f7fd OK
2025/01/09 01:26:32 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC
2025/01/09 01:26:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:26:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:26:34 DEBUG : potato: md5 = 2f5d8c810ecb35950054f24f3cd1137f OK
2025/01/09 01:26:34 INFO  : potato: Copied (replaced existing)
2025/01/09 01:26:34 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (5.37s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:26:37 DEBUG : potato: md5 = e17687002a95fabd85374fff5df8eb2d OK
2025/01/09 01:26:39 DEBUG : empty space: md5 = 3921430df7926d78d2efd867e88d85ba OK
2025/01/09 01:26:39 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/09 01:26:39 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2025/01/09 01:26:39 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:26:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:26:39 DEBUG : empty space: Unchanged skipping
2025/01/09 01:26:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:26:39 DEBUG : Waiting for deletions to finish
2025/01/09 01:26:39 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (6.06s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:26:43 DEBUG : potato: md5 = ad62976f05e769d46172fcc00e9c8cb3 OK
2025/01/09 01:26:45 DEBUG : empty space: md5 = 3e7db6034435100eeb6cf837e3f535f4 OK
2025/01/09 01:26:45 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/09 01:26:45 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:26:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:26:45 DEBUG : empty space: Unchanged skipping
2025/01/09 01:26:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:26:47 DEBUG : potato2: md5 = 1d0b4c457c652bf5f6855316309ce69f OK
2025/01/09 01:26:47 INFO  : potato2: Copied (new)
2025/01/09 01:26:47 DEBUG : Waiting for deletions to finish
2025/01/09 01:26:47 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.24s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:26:52 DEBUG : b/potato: md5 = 45ac9834b4791a96932d83e6c67a40a8 OK
2025/01/09 01:26:55 DEBUG : c/non empty space: md5 = 3913447cb5d8c1cf38411f55935b9daa OK
2025/01/09 01:26:55 INFO  : d: Making directory
2025/01/09 01:26:56 INFO  : d/e: Making directory
2025/01/09 01:26:58 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/01/09 01:26:58 DEBUG : Added delayed dir = "c", newDst=c
2025/01/09 01:26:58 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/01/09 01:26:58 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:26:58 DEBUG : c/non empty space: Unchanged skipping
2025/01/09 01:27:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:27:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:27:01 DEBUG : a/potato2: md5 = 85326c52f17304c0ede72c4a43298ad8 OK
2025/01/09 01:27:01 INFO  : a/potato2: Copied (new)
2025/01/09 01:27:01 DEBUG : Waiting for deletions to finish
2025/01/09 01:27:01 INFO  : b/potato: Deleted
2025/01/09 01:27:02 INFO  : a: Set directory modification time (using DirSetModTime)
2025/01/09 01:27:02 INFO  : d/e: Removing directory
2025/01/09 01:27:03 INFO  : d: Removing directory
2025/01/09 01:27:03 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2025/01/09 01:27:04 INFO  : b: Removing directory
2025/01/09 01:27:04 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/01/09 01:27:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:27:07 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/01/09 01:27:08 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (19.47s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:27:12 DEBUG : b/potato: md5 = 595d3deadcbe80e7d3b1e0d7728dd030 OK
2025/01/09 01:27:14 DEBUG : c/non empty space: md5 = c8ac10752de1d2995fc055707475646e OK
2025/01/09 01:27:14 INFO  : d: Making directory
2025/01/09 01:27:16 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/01/09 01:27:16 DEBUG : Added delayed dir = "c", newDst=c
2025/01/09 01:27:16 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/01/09 01:27:16 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:27:16 DEBUG : c/non empty space: Unchanged skipping
2025/01/09 01:27:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:27:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:27:19 DEBUG : a/potato2: md5 = 9aa9163a9f7ac642ea39f32b3544dada OK
2025/01/09 01:27:19 INFO  : a/potato2: Copied (new)
2025/01/09 01:27:19 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': not deleting files as there were IO errors
2025/01/09 01:27:20 INFO  : a: Set directory modification time (using DirSetModTime)
2025/01/09 01:27:20 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:27:23 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/01/09 01:27:24 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/01/09 01:27:25 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (18.79s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:27:30 DEBUG : potato: md5 = b4c9f661ee00e9fe3e8fa35be639b7dd OK
2025/01/09 01:27:31 DEBUG : empty space: md5 = 46e66095bce8b860b15f127ca2aea772 OK
2025/01/09 01:27:32 DEBUG : Waiting for deletions to finish
2025/01/09 01:27:32 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/09 01:27:32 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:27:32 DEBUG : empty space: Unchanged skipping
2025/01/09 01:27:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:27:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:27:32 INFO  : potato: Deleted
2025/01/09 01:27:33 DEBUG : potato2: md5 = 0d6a97e38225f5f97856c390bee15200 OK
2025/01/09 01:27:33 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (7.81s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:27:38 DEBUG : potato: md5 = 673b125fb543e70a9b4a2ab11c72f56e OK
2025/01/09 01:27:39 DEBUG : empty space: md5 = ed72881768e85b12bfc12d4f1a214abb OK
2025/01/09 01:27:39 DEBUG : Waiting for deletions to finish
2025/01/09 01:27:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:27:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:27:40 INFO  : potato: Deleted
2025/01/09 01:27:40 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/09 01:27:40 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:27:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:27:40 DEBUG : empty space: Unchanged skipping
2025/01/09 01:27:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:27:42 DEBUG : potato2: md5 = cc67f11f4c9ab6253b560feb7af48aba OK
2025/01/09 01:27:42 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (8.90s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:27:46 DEBUG : potato: md5 = d2c089a0cb108c28543aa878619286fe OK
2025/01/09 01:27:47 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/09 01:27:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:27:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:27:48 DEBUG : potato2: md5 = be655917f6573387781985d4febb8fc8 OK
2025/01/09 01:27:48 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (6.04s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:27:52 DEBUG : potato2: md5 = a990102e9eaf718eea191d7dec3998a0 OK
2025/01/09 01:27:54 DEBUG : empty space: md5 = 472e3a292de46af4c9cf5085188d8385 OK
2025/01/09 01:27:54 DEBUG : enormous: Excluded (Size Filter)
2025/01/09 01:27:54 DEBUG : enormous: Excluded
2025/01/09 01:27:54 DEBUG : potato2: Excluded (Size Filter)
2025/01/09 01:27:54 DEBUG : potato2: Excluded
2025/01/09 01:27:55 DEBUG : potato2: Excluded (Size Filter)
2025/01/09 01:27:55 DEBUG : potato2: Excluded
2025/01/09 01:27:55 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:27:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:27:55 DEBUG : empty space: Unchanged skipping
2025/01/09 01:27:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:27:55 DEBUG : Waiting for deletions to finish
2025/01/09 01:27:55 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:27:55 DEBUG : enormous: Excluded (Size Filter)
2025/01/09 01:27:55 DEBUG : enormous: Excluded
2025/01/09 01:27:55 DEBUG : potato2: Excluded (Size Filter)
2025/01/09 01:27:55 DEBUG : potato2: Excluded
2025/01/09 01:27:55 DEBUG : potato2: Excluded (Size Filter)
2025/01/09 01:27:55 DEBUG : potato2: Excluded
2025/01/09 01:27:55 DEBUG : Local file system at /tmp/rclone2858783104: Waiting for checks to finish
2025/01/09 01:27:55 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2025/01/09 01:27:55 DEBUG : empty space: Unchanged skipping
2025/01/09 01:27:55 DEBUG : Local file system at /tmp/rclone2858783104: Waiting for transfers to finish
2025/01/09 01:27:55 DEBUG : Waiting for deletions to finish
2025/01/09 01:27:55 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncWithExclude (7.02s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:27:59 DEBUG : potato2: md5 = 8a2276bebb15ded64258016c22d7e821 OK
2025/01/09 01:28:01 DEBUG : empty space: md5 = 6f4ce578336af08b790dac4e19e978c0 OK
2025/01/09 01:28:03 DEBUG : enormous: md5 = 42aeec95f5581a25a2419bc790864f21 OK
2025/01/09 01:28:03 DEBUG : enormous: Excluded (Size Filter)
2025/01/09 01:28:03 DEBUG : enormous: Excluded
2025/01/09 01:28:03 DEBUG : potato2: Excluded (Size Filter)
2025/01/09 01:28:03 DEBUG : potato2: Excluded
2025/01/09 01:28:03 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:28:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:28:03 DEBUG : empty space: Unchanged skipping
2025/01/09 01:28:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:28:03 DEBUG : Waiting for deletions to finish
2025/01/09 01:28:04 INFO  : potato2: Deleted
2025/01/09 01:28:04 INFO  : enormous: Deleted
2025/01/09 01:28:04 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:28:04 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2025/01/09 01:28:04 DEBUG : Local file system at /tmp/rclone2858783104: Waiting for checks to finish
2025/01/09 01:28:04 DEBUG : empty space: Unchanged skipping
2025/01/09 01:28:04 DEBUG : Local file system at /tmp/rclone2858783104: Waiting for transfers to finish
2025/01/09 01:28:04 DEBUG : Waiting for deletions to finish
2025/01/09 01:28:04 INFO  : enormous: Deleted
2025/01/09 01:28:04 INFO  : potato2: Deleted
2025/01/09 01:28:04 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (8.71s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:28:08 DEBUG : one: md5 = fead751710209c80a8f0a921e5336c83 OK
2025/01/09 01:28:10 DEBUG : two: md5 = d0e0af44719029d1a4f64ecf3747b1bd OK
2025/01/09 01:28:12 DEBUG : three: md5 = 58e41decef3728683ef0bc2499f0df81 OK
2025/01/09 01:28:13 DEBUG : four: md5 = 6a2a180ae1ecc5b79115f2588719c59f OK
2025/01/09 01:28:14 DEBUG : five: Need to transfer - File not found at Destination
2025/01/09 01:28:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:28:14 DEBUG : four: Sizes differ (src 4 vs dst 8)
2025/01/09 01:28:14 DEBUG : one: Destination is newer than source, skipping
2025/01/09 01:28:14 DEBUG : three: Sizes identical
2025/01/09 01:28:14 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2025/01/09 01:28:14 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2025/01/09 01:28:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:28:15 DEBUG : four: md5 = 2ab942891195de14fb1a0dd43db45e3e OK
2025/01/09 01:28:15 INFO  : four: Copied (replaced existing)
2025/01/09 01:28:15 DEBUG : two: md5 = c3a511eec453e522be67316abc4337f1 OK
2025/01/09 01:28:15 INFO  : two: Copied (replaced existing)
2025/01/09 01:28:15 DEBUG : five: md5 = 296326a6ede877ea84c9bad1945224a9 OK
2025/01/09 01:28:15 INFO  : five: Copied (new)
2025/01/09 01:28:15 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (12.24s)
=== 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-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2025/01/09 01:28:19 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Ignoring --track-renames as the source and destination do not have a common hash
2025/01/09 01:28:19 DEBUG : potato: Need to transfer - File not found at Destination
2025/01/09 01:28:19 DEBUG : yam: Need to transfer - File not found at Destination
2025/01/09 01:28:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:28:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:28:20 DEBUG : potato: md5 = 07eb455f29fadf5456b678e139063051 OK
2025/01/09 01:28:20 INFO  : potato: Copied (new)
2025/01/09 01:28:20 DEBUG : yam: md5 = 9353447ca68b1fdafa55d0631662c072 OK
2025/01/09 01:28:20 INFO  : yam: Copied (new)
2025/01/09 01:28:20 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:28:21 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Ignoring --track-renames as the source and destination do not have a common hash
2025/01/09 01:28:21 DEBUG : yaml: Need to transfer - File not found at Destination
2025/01/09 01:28:21 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:28:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:28:21 DEBUG : potato: Unchanged skipping
2025/01/09 01:28:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:28:23 DEBUG : yaml: md5 = 48e2f993b20db187839b90040992d789 OK
2025/01/09 01:28:23 INFO  : yaml: Copied (new)
2025/01/09 01:28:23 DEBUG : Waiting for deletions to finish
2025/01/09 01:28:23 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (7.12s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2025/01/09 01:28:26 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Making map for --track-renames
2025/01/09 01:28:26 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Finished making map for --track-renames
2025/01/09 01:28:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:28:26 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/01/09 01:28:26 DEBUG : yam: Need to transfer - No matching file found at Destination
2025/01/09 01:28:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for renames to finish
2025/01/09 01:28:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:28:28 DEBUG : potato: md5 = a63d23719901c6af3ce45211e66672f6 OK
2025/01/09 01:28:28 INFO  : potato: Copied (new)
2025/01/09 01:28:28 DEBUG : yam: md5 = e5546da7d560a5667db9218eaff3368a OK
2025/01/09 01:28:28 INFO  : yam: Copied (new)
2025/01/09 01:28:28 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:28:28 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:28:28 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Making map for --track-renames
2025/01/09 01:28:28 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Finished making map for --track-renames
2025/01/09 01:28:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:28:28 DEBUG : potato: Unchanged skipping
2025/01/09 01:28:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for renames to finish
2025/01/09 01:28:29 INFO  : yam: Moved (server-side) to: yaml
2025/01/09 01:28:29 INFO  : yaml: Renamed from "yam"
2025/01/09 01:28:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:28:29 DEBUG : Waiting for deletions to finish
2025/01/09 01:28:29 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (6.55s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2025/01/09 01:28:33 DEBUG : Added delayed dir = "sub", newDst=<nil>
2025/01/09 01:28:33 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Making map for --track-renames
2025/01/09 01:28:33 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Finished making map for --track-renames
2025/01/09 01:28:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:28:33 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/01/09 01:28:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for renames to finish
2025/01/09 01:28:33 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2025/01/09 01:28:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:28:35 DEBUG : sub/yam: md5 = 051d769164590deefad612437112d1d2 OK
2025/01/09 01:28:35 INFO  : sub/yam: Copied (new)
2025/01/09 01:28:35 DEBUG : potato: md5 = ccbfca401cab57dd3e43fb3a09f778b1 OK
2025/01/09 01:28:35 INFO  : potato: Copied (new)
2025/01/09 01:28:35 DEBUG : Waiting for deletions to finish
2025/01/09 01:28:36 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:28:37 DEBUG : Added delayed dir = "sub", newDst=sub
2025/01/09 01:28:37 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:28:37 DEBUG : potato: Unchanged skipping
2025/01/09 01:28:37 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Making map for --track-renames
2025/01/09 01:28:37 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Finished making map for --track-renames
2025/01/09 01:28:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:28:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for renames to finish
2025/01/09 01:28:38 INFO  : sub/yam: Moved (server-side) to: yam
2025/01/09 01:28:38 INFO  : yam: Renamed from "sub/yam"
2025/01/09 01:28:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:28:38 DEBUG : Waiting for deletions to finish
2025/01/09 01:28:38 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.88s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:28:42 DEBUG : Creating backend with remote "/tmp/rclone2858783104/dir1"
2025/01/09 01:28:42 DEBUG : Config file has changed externally - reloading
2025/01/09 01:28:42 DEBUG : Creating backend with remote "/tmp/rclone2858783104/dir2"
2025/01/09 01:28:42 DEBUG : Local file system at /tmp/rclone2858783104/dir2: Using server-side directory move
2025/01/09 01:28:42 INFO  : Local file system at /tmp/rclone2858783104/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/01/09 01:28:42 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/01/09 01:28:42 INFO  : file1.txt: Moved (server-side)
2025/01/09 01:28:42 DEBUG : Local file system at /tmp/rclone2858783104/dir2: Waiting for checks to finish
2025/01/09 01:28:42 DEBUG : Local file system at /tmp/rclone2858783104/dir2: Waiting for transfers to finish
--- PASS: TestServerSideMoveLocal (0.45s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:28:43 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/01/09 01:28:43 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/09 01:28:43 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/01/09 01:28:43 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/01/09 01:28:43 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/09 01:28:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:28:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:28:47 DEBUG : nested/sub dir/file: md5 = 2ec9f44a8cee1418ecb9de02241dde9e OK
2025/01/09 01:28:47 INFO  : nested/sub dir/file: Copied (new)
2025/01/09 01:28:47 INFO  : nested/sub dir/file: Deleted
2025/01/09 01:28:48 DEBUG : sub dir/hello world: md5 = 46b8edacac071ecc8632be5fccf5b743 OK
2025/01/09 01:28:48 INFO  : sub dir/hello world: Copied (new)
2025/01/09 01:28:48 INFO  : sub dir/hello world: Deleted
2025/01/09 01:28:49 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/01/09 01:28:50 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/09 01:28:50 INFO  : nested: Set directory modification time (using DirSetModTime)
2025/01/09 01:28:50 INFO  : sub dir: Removing directory
2025/01/09 01:28:50 INFO  : nested/sub dir: Removing directory
2025/01/09 01:28:50 INFO  : nested: Removing directory
2025/01/09 01:28:50 DEBUG : Local file system at /tmp/rclone2858783104: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:28:53 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/09 01:28:54 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2025/01/09 01:28:54 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (13.22s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:28:56 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/01/09 01:28:56 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/09 01:28:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/09 01:28:56 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/01/09 01:28:56 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/01/09 01:28:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:28:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:28:59 DEBUG : sub dir/hello world: md5 = f3f988830697834ce59d54cd54631fdc OK
2025/01/09 01:28:59 INFO  : sub dir/hello world: Copied (new)
2025/01/09 01:28:59 INFO  : sub dir/hello world: Deleted
2025/01/09 01:29:01 DEBUG : nested/sub dir/file: md5 = a056aabb24c531722f541cb8952a11c0 OK
2025/01/09 01:29:01 INFO  : nested/sub dir/file: Copied (new)
2025/01/09 01:29:01 INFO  : nested/sub dir/file: Deleted
2025/01/09 01:29:02 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/01/09 01:29:02 INFO  : nested: Set directory modification time (using DirSetModTime)
2025/01/09 01:29:02 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:29:05 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/09 01:29:06 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2025/01/09 01:29:07 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (12.27s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:29:08 DEBUG : existing: Need to transfer - File not found at Destination
2025/01/09 01:29:08 DEBUG : existing-b: Need to transfer - File not found at Destination
2025/01/09 01:29:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:29:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:29:10 DEBUG : existing-b: md5 = e12da5cfab6f2ab5ab15333e2ad92e44 OK
2025/01/09 01:29:10 INFO  : existing-b: Copied (new)
2025/01/09 01:29:10 INFO  : existing-b: Deleted
2025/01/09 01:29:10 DEBUG : existing: md5 = 71f1beb60a9e347964864cbb34b29adf OK
2025/01/09 01:29:10 INFO  : existing: Copied (new)
2025/01/09 01:29:10 INFO  : existing: Deleted
2025/01/09 01:29:11 DEBUG : existing: Destination exists, skipping
2025/01/09 01:29:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:29:11 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2025/01/09 01:29:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:29:11 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (4.75s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:29:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gohosad9licu"
2025/01/09 01:29:13 DEBUG : Creating backend with remote "TestDrive:crypt/t4l3jh7gp0kqpnl4mp4kogt0slr5v2ninmg2h79cpk3ismiv3u8g"
2025/01/09 01:29:15 DEBUG : potato2: md5 = 98e9b4a2cd6f0c661588867bf0dbbc60 OK
2025/01/09 01:29:17 DEBUG : empty space: md5 = a16efa6e6a7b626dc5cc41078222b6c8 OK
2025/01/09 01:29:19 DEBUG : potato3: md5 = 8a7f3d29a749e00ea3220f0b5cd979ff OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi' -> Encrypted drive 'TestCryptDrive:rclone-test-gohosad9licu'
2025/01/09 01:29:22 DEBUG : empty space: md5 = 455f22ce38b04ffb3b46985c7acfe8f8 OK
2025/01/09 01:29:23 DEBUG : potato3: md5 = 3a022d974348492539492c42f63f3e95 OK
2025/01/09 01:29:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gohosad9licu': Using server-side directory move
2025/01/09 01:29:24 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gohosad9licu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/01/09 01:29:24 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/09 01:29:24 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/01/09 01:29:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gohosad9licu': Waiting for checks to finish
2025/01/09 01:29:24 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/01/09 01:29:24 DEBUG : empty space: Unchanged skipping
2025/01/09 01:29:24 INFO  : empty space: Deleted
2025/01/09 01:29:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gohosad9licu': Waiting for transfers to finish
2025/01/09 01:29:24 INFO  : potato3: Deleted
2025/01/09 01:29:25 INFO  : potato2: Moved (server-side)
2025/01/09 01:29:25 INFO  : potato3: Moved (server-side)
2025/01/09 01:29:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dodivad9reba"
2025/01/09 01:29:26 DEBUG : Config file has changed externally - reloading
2025/01/09 01:29:26 DEBUG : Creating backend with remote "TestDrive:crypt/qpeiinipmhogcl3o9tpicq4d5cunmhqqgcjh7u1582q37ptodp10"
2025/01/09 01:29:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dodivad9reba': Using server-side directory move
2025/01/09 01:29:28 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-dodivad9reba': Server side directory move succeeded
2025/01/09 01:29:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dodivad9reba': Purge remote
2025/01/09 01:29:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gohosad9licu': Purge remote
2025/01/09 01:29:30 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (17.19s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:29:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qasiduj6wede"
2025/01/09 01:29:30 DEBUG : Creating backend with remote "TestDrive:crypt/sj167q68miimdcf7s0ft7a2h3pnjnjvacgp9s30p9qs239cdsgdg"
2025/01/09 01:29:33 DEBUG : potato2: md5 = e659c5333a67d7773fc72076f51ae50b OK
2025/01/09 01:29:34 DEBUG : empty space: md5 = f9f50e009c7b6d8bfab4c250db2d25d3 OK
2025/01/09 01:29:36 DEBUG : potato3: md5 = 95537ec526a6f6da8078749a1ff308d2 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi' -> Encrypted drive 'TestCryptDrive:rclone-test-qasiduj6wede'
2025/01/09 01:29:39 DEBUG : empty space: md5 = 82415f64afd1f8ff5ce3586b70f2118b OK
2025/01/09 01:29:41 DEBUG : potato3: md5 = 10f84a0a810fb6ba7c13757ce49fe67f OK
2025/01/09 01:29:41 DEBUG : empty space: Excluded (Size Filter)
2025/01/09 01:29:41 DEBUG : empty space: Excluded
2025/01/09 01:29:41 DEBUG : empty space: Excluded (Size Filter)
2025/01/09 01:29:41 DEBUG : empty space: Excluded
2025/01/09 01:29:41 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/09 01:29:41 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/01/09 01:29:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qasiduj6wede': Waiting for checks to finish
2025/01/09 01:29:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qasiduj6wede': Waiting for transfers to finish
2025/01/09 01:29:42 INFO  : potato3: Deleted
2025/01/09 01:29:42 INFO  : potato2: Moved (server-side)
2025/01/09 01:29:42 INFO  : potato3: Moved (server-side)
2025/01/09 01:29:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-voyasih1gizo"
2025/01/09 01:29:43 DEBUG : Creating backend with remote "TestDrive:crypt/irnab05kalusogd5nh4d6c1hpdtil6c65db2upj7bqadm4i987og"
2025/01/09 01:29:44 DEBUG : empty space: Excluded (Size Filter)
2025/01/09 01:29:44 DEBUG : empty space: Excluded
2025/01/09 01:29:44 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/09 01:29:44 DEBUG : potato3: Need to transfer - File not found at Destination
2025/01/09 01:29:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voyasih1gizo': Waiting for checks to finish
2025/01/09 01:29:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voyasih1gizo': Waiting for transfers to finish
2025/01/09 01:29:46 INFO  : potato2: Moved (server-side)
2025/01/09 01:29:47 INFO  : potato3: Moved (server-side)
2025/01/09 01:29:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-voyasih1gizo': Purge remote
2025/01/09 01:29:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qasiduj6wede': Purge remote
--- PASS: TestServerSideMoveWithFilter (19.57s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:29:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-jupuhoy2vahe"
2025/01/09 01:29:50 DEBUG : Creating backend with remote "TestDrive:crypt/dpe02j7n1gnn1g79qmeru34h8baajv8vqtbvelreothmm8almr8g"
2025/01/09 01:29:52 DEBUG : potato2: md5 = 280f036d585b355170d545b85174392c OK
2025/01/09 01:29:54 DEBUG : empty space: md5 = 8611add6d17dc481feb60e4ba11354ff OK
2025/01/09 01:29:56 DEBUG : potato3: md5 = 48eb5330304fdc1c9796a8323c165e09 OK
2025/01/09 01:29:56 INFO  : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi' -> Encrypted drive 'TestCryptDrive:rclone-test-jupuhoy2vahe'
2025/01/09 01:30:00 DEBUG : empty space: md5 = 372379458e12b1eebdb89e20a431d390 OK
2025/01/09 01:30:02 DEBUG : potato3: md5 = d6920a0930413cf69f73001cf271fb1a OK
2025/01/09 01:30:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jupuhoy2vahe': Using server-side directory move
2025/01/09 01:30:02 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-jupuhoy2vahe': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/01/09 01:30:02 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/09 01:30:02 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2025/01/09 01:30:02 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/01/09 01:30:02 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/01/09 01:30:02 DEBUG : empty space: Unchanged skipping
2025/01/09 01:30:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jupuhoy2vahe': Waiting for checks to finish
2025/01/09 01:30:03 INFO  : potato3: Deleted
2025/01/09 01:30:03 INFO  : empty space: Deleted
2025/01/09 01:30:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jupuhoy2vahe': Waiting for transfers to finish
2025/01/09 01:30:04 INFO  : potato2: Moved (server-side)
2025/01/09 01:30:04 INFO  : potato3: Moved (server-side)
2025/01/09 01:30:04 INFO  : tomatoDir: Removing directory
2025/01/09 01:30:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': deleted 1 directories
2025/01/09 01:30:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sakekez4yeta"
2025/01/09 01:30:05 DEBUG : Config file has changed externally - reloading
2025/01/09 01:30:05 DEBUG : Creating backend with remote "TestDrive:crypt/jteo2speg2uljr8ld0koan0e3dbp586p953fksdu1hco95g56nv0"
2025/01/09 01:30:06 INFO  : tomatoDir: Making directory
2025/01/09 01:30:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sakekez4yeta': Using server-side directory move
2025/01/09 01:30:08 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-sakekez4yeta': Server side directory move succeeded
2025/01/09 01:30:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sakekez4yeta': Purge remote
2025/01/09 01:30:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jupuhoy2vahe': Purge remote
2025/01/09 01:30:11 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (21.45s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.47s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:30:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/rclone-sync-test"
2025/01/09 01:30:12 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncOverlap (3.82s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:30:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/rclone-sync-test"
2025/01/09 01:30:15 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2025/01/09 01:30:18 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/rclone-sync-test-include/layer2"
2025/01/09 01:30:18 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2025/01/09 01:30:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/rclone-sync-test-ignore-file"
2025/01/09 01:30:22 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2025/01/09 01:30:26 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 4e8681904d0c486a10f7eccb5d06868a OK
2025/01/09 01:30:27 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/01/09 01:30:27 DEBUG : rclone-sync-test: Excluded
2025/01/09 01:30:27 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/01/09 01:30:28 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/01/09 01:30:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/rclone-sync-test': Waiting for checks to finish
2025/01/09 01:30:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/rclone-sync-test': Waiting for transfers to finish
2025/01/09 01:30:28 DEBUG : Waiting for deletions to finish
2025/01/09 01:30:28 INFO  : There was nothing to transfer
2025/01/09 01:30:28 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/01/09 01:30:29 DEBUG : rclone-sync-test: Excluded
2025/01/09 01:30:29 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/01/09 01:30:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:30:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:30:29 DEBUG : Waiting for deletions to finish
2025/01/09 01:30:29 INFO  : rclone-sync-test-include: Removing directory
2025/01/09 01:30:30 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/01/09 01:30:30 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2025/01/09 01:30:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': failed to delete 1 directories
2025/01/09 01:30:30 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:30:30 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/01/09 01:30:31 DEBUG : rclone-sync-test: Excluded
2025/01/09 01:30:31 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/01/09 01:30:31 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/01/09 01:30:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/rclone-sync-test-include/layer2': Waiting for checks to finish
2025/01/09 01:30:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/rclone-sync-test-include/layer2': Waiting for transfers to finish
2025/01/09 01:30:31 DEBUG : Waiting for deletions to finish
2025/01/09 01:30:31 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:30:32 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/01/09 01:30:33 DEBUG : rclone-sync-test: Excluded
2025/01/09 01:30:33 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/01/09 01:30:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:30:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:30:33 DEBUG : Waiting for deletions to finish
2025/01/09 01:30:33 INFO  : rclone-sync-test-include: Removing directory
2025/01/09 01:30:33 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/01/09 01:30:33 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2025/01/09 01:30:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': failed to delete 1 directories
2025/01/09 01:30:33 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:30:34 DEBUG : : Excluded
2025/01/09 01:30:34 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/01/09 01:30:34 DEBUG : rclone-sync-test: Excluded
2025/01/09 01:30:34 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/01/09 01:30:35 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/01/09 01:30:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/rclone-sync-test-ignore-file': Waiting for checks to finish
2025/01/09 01:30:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/rclone-sync-test-ignore-file': Waiting for transfers to finish
2025/01/09 01:30:35 DEBUG : Waiting for deletions to finish
2025/01/09 01:30:35 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:30:37 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/01/09 01:30:38 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (32.29s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:30:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/dst"
2025/01/09 01:30:48 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/09 01:30:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/CompareDest"
2025/01/09 01:30:49 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/gveqi14airsml4bgu7krj116o8"
2025/01/09 01:30:51 DEBUG : one: Need to transfer - File not found at Destination
2025/01/09 01:30:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for checks to finish
2025/01/09 01:30:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for transfers to finish
2025/01/09 01:30:54 DEBUG : one: md5 = 5802e70f980a0af9a19bfb79b7c87872 OK
2025/01/09 01:30:54 INFO  : one: Copied (new)
2025/01/09 01:30:54 DEBUG : Waiting for deletions to finish
2025/01/09 01:30:55 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/09 01:30:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for checks to finish
2025/01/09 01:30:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for transfers to finish
2025/01/09 01:30:56 DEBUG : one: md5 = 703b646c93e4fc1844eced81fd1f8db9 OK
2025/01/09 01:30:56 INFO  : one: Copied (replaced existing)
2025/01/09 01:30:56 DEBUG : Waiting for deletions to finish
2025/01/09 01:30:58 DEBUG : dst/one: md5 = 42c2968c7cb94e66372596e5f4494436 OK
2025/01/09 01:31:01 DEBUG : CompareDest/one: md5 = 4233857970a3a259caad8a75b44f11b6 OK
2025/01/09 01:31:02 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/09 01:31:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for checks to finish
2025/01/09 01:31:02 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:31:02 DEBUG : one: Destination found in --compare-dest, skipping
2025/01/09 01:31:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for transfers to finish
2025/01/09 01:31:02 DEBUG : Waiting for deletions to finish
2025/01/09 01:31:02 INFO  : There was nothing to transfer
2025/01/09 01:31:04 DEBUG : CompareDest/two: md5 = 12a8ab6b0acbe4997eeb56ffd514dcbd OK
2025/01/09 01:31:05 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:31:05 DEBUG : two: Destination found in --compare-dest, skipping
2025/01/09 01:31:05 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/09 01:31:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for checks to finish
2025/01/09 01:31:06 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:31:06 DEBUG : one: Destination found in --compare-dest, skipping
2025/01/09 01:31:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for transfers to finish
2025/01/09 01:31:06 DEBUG : Waiting for deletions to finish
2025/01/09 01:31:06 INFO  : There was nothing to transfer
2025/01/09 01:31:07 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:31:07 DEBUG : two: Destination found in --compare-dest, skipping
2025/01/09 01:31:07 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/09 01:31:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for checks to finish
2025/01/09 01:31:07 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:31:07 DEBUG : one: Destination found in --compare-dest, skipping
2025/01/09 01:31:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for transfers to finish
2025/01/09 01:31:07 DEBUG : Waiting for deletions to finish
2025/01/09 01:31:07 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2025/01/09 01:31:08 DEBUG : two: Sizes differ (src 5 vs dst 3)
2025/01/09 01:31:08 DEBUG : two: Need to transfer - File not found at Destination
2025/01/09 01:31:08 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/09 01:31:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for checks to finish
2025/01/09 01:31:09 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:31:09 DEBUG : one: Destination found in --compare-dest, skipping
2025/01/09 01:31:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for transfers to finish
2025/01/09 01:31:10 DEBUG : two: md5 = 7a0218bb90e45e8d78bc6b3dfa970d01 OK
2025/01/09 01:31:10 INFO  : two: Copied (new)
2025/01/09 01:31:10 DEBUG : Waiting for deletions to finish
2025/01/09 01:31:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/09 01:31:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/09 01:31:15 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/09 01:31:15 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncCompareDest (27.98s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:31:18 DEBUG : pre-dest1/1: md5 = dcde72781b223c5ebba4159a63eddbbc OK
2025/01/09 01:31:21 DEBUG : pre-dest2/2: md5 = 35d918e2245548b1a7d2b7db84110125 OK
2025/01/09 01:31:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/dest"
2025/01/09 01:31:22 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/rg03c1jvnehrrc617i0lnqjddc"
2025/01/09 01:31:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/pre-dest1"
2025/01/09 01:31:23 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/bbnblvh6k061ssopqrp18kd7gc"
2025/01/09 01:31:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/pre-dest2"
2025/01/09 01:31:24 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/dgicm1h6b5ejvlltm8eeif0bnk"
2025/01/09 01:31:25 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:31:25 DEBUG : 1: Destination found in --compare-dest, skipping
2025/01/09 01:31:26 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:31:26 DEBUG : 2: Destination found in --compare-dest, skipping
2025/01/09 01:31:26 DEBUG : 3: Need to transfer - File not found at Destination
2025/01/09 01:31:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dest': Waiting for checks to finish
2025/01/09 01:31:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dest': Waiting for transfers to finish
2025/01/09 01:31:29 DEBUG : 3: md5 = 192430ae7d6f56656f5e2e48d299cc28 OK
2025/01/09 01:31:29 INFO  : 3: Copied (new)
2025/01/09 01:31:29 DEBUG : Waiting for deletions to finish
2025/01/09 01:31:32 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2025/01/09 01:31:33 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2025/01/09 01:31:34 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (19.26s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:31:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/dst"
2025/01/09 01:31:35 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/09 01:31:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/CopyDest"
2025/01/09 01:31:36 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/d09o6po3f7bm6ce32vdgs8h9ls"
2025/01/09 01:31:39 DEBUG : one: Need to transfer - File not found at Destination
2025/01/09 01:31:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for checks to finish
2025/01/09 01:31:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for transfers to finish
2025/01/09 01:31:41 DEBUG : one: md5 = 97eb875dbc7b11b9db0b981e1cffce62 OK
2025/01/09 01:31:41 INFO  : one: Copied (new)
2025/01/09 01:31:41 DEBUG : Waiting for deletions to finish
2025/01/09 01:31:43 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/09 01:31:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for checks to finish
2025/01/09 01:31:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for transfers to finish
2025/01/09 01:31:44 DEBUG : one: md5 = ee2c1b4f8bd6a24e70a6d9fe80af64df OK
2025/01/09 01:31:44 INFO  : one: Copied (replaced existing)
2025/01/09 01:31:44 DEBUG : Waiting for deletions to finish
2025/01/09 01:31:46 DEBUG : dst/one: md5 = bc28300e0b99172dd767091d000a15ce OK
2025/01/09 01:31:49 DEBUG : CopyDest/one: md5 = fa8d33f42c00a3e26c1b8786e166cb21 OK
2025/01/09 01:31:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/BackupDir"
2025/01/09 01:31:50 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/s6dbk3lfi7c9kfvo6j7bla9m0g"
2025/01/09 01:31:51 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/09 01:31:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for checks to finish
2025/01/09 01:31:52 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:31:52 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/09 01:31:54 INFO  : one: Moved (server-side)
2025/01/09 01:31:55 INFO  : one: Copied (server-side copy)
2025/01/09 01:31:55 DEBUG : one: Destination found in --copy-dest, using server-side copy
2025/01/09 01:31:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for transfers to finish
2025/01/09 01:31:55 DEBUG : Waiting for deletions to finish
2025/01/09 01:31:58 DEBUG : CopyDest/two: md5 = d0f4c6706cda559ff1f3ddf9a7aa67ed OK
2025/01/09 01:31:59 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:32:00 INFO  : two: Copied (server-side copy)
2025/01/09 01:32:00 DEBUG : two: Destination found in --copy-dest, using server-side copy
2025/01/09 01:32:00 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:32:00 DEBUG : one: Unchanged skipping
2025/01/09 01:32:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for checks to finish
2025/01/09 01:32:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for transfers to finish
2025/01/09 01:32:00 DEBUG : Waiting for deletions to finish
2025/01/09 01:32:01 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:32:01 DEBUG : one: Unchanged skipping
2025/01/09 01:32:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for checks to finish
2025/01/09 01:32:01 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:32:01 DEBUG : two: Unchanged skipping
2025/01/09 01:32:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for transfers to finish
2025/01/09 01:32:01 DEBUG : Waiting for deletions to finish
2025/01/09 01:32:01 INFO  : There was nothing to transfer
2025/01/09 01:32:03 DEBUG : CopyDest/three: md5 = a3cd8bdc19521da047544830e1a400da OK
2025/01/09 01:32:04 DEBUG : three: Sizes differ (src 7 vs dst 5)
2025/01/09 01:32:04 DEBUG : three: Destination not found in --copy-dest
2025/01/09 01:32:04 DEBUG : three: Need to transfer - File not found at Destination
2025/01/09 01:32:04 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:32:04 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/09 01:32:04 DEBUG : two: Unchanged skipping
2025/01/09 01:32:04 DEBUG : one: Unchanged skipping
2025/01/09 01:32:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for checks to finish
2025/01/09 01:32:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for transfers to finish
2025/01/09 01:32:05 DEBUG : three: md5 = cb94df2b89180f9a5ec4be1b89fc668c OK
2025/01/09 01:32:05 INFO  : three: Copied (new)
2025/01/09 01:32:05 DEBUG : Waiting for deletions to finish
2025/01/09 01:32:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2025/01/09 01:32:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/09 01:32:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/09 01:32:12 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/09 01:32:12 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2025/01/09 01:32:12 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/09 01:32:12 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (38.35s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:32:16 DEBUG : dst/one: md5 = 988ff7d72c5de0565fa48ea9b59fe963 OK
2025/01/09 01:32:18 DEBUG : dst/two: md5 = 6506863b3133251533a332e417a101dd OK
2025/01/09 01:32:20 DEBUG : dst/three.txt: md5 = a0d842d7f0503dc950bc12e35882018f OK
2025/01/09 01:32:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/dst"
2025/01/09 01:32:20 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/09 01:32:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/backup"
2025/01/09 01:32:21 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/1nrff024r7pq65ecp72fc28jb0"
2025/01/09 01:32:23 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/09 01:32:23 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:32:23 DEBUG : two: Unchanged skipping
2025/01/09 01:32:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for checks to finish
2025/01/09 01:32:25 INFO  : one: Moved (server-side)
2025/01/09 01:32:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for transfers to finish
2025/01/09 01:32:27 DEBUG : one: md5 = 47485fc8e238beb084392346e9ff959a OK
2025/01/09 01:32:27 INFO  : one: Copied (new)
2025/01/09 01:32:27 DEBUG : Waiting for deletions to finish
2025/01/09 01:32:28 INFO  : three.txt: Moved (server-side)
2025/01/09 01:32:28 INFO  : three.txt: Moved into backup dir
2025/01/09 01:32:30 DEBUG : dst/three.txt: md5 = 97703e1bb86c51c10e2e68bedbb96083 OK
2025/01/09 01:32:31 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/09 01:32:31 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:32:31 DEBUG : two: Unchanged skipping
2025/01/09 01:32:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for checks to finish
2025/01/09 01:32:32 INFO  : one: Deleted
2025/01/09 01:32:33 INFO  : one: Moved (server-side)
2025/01/09 01:32:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for transfers to finish
2025/01/09 01:32:34 DEBUG : one: md5 = d17364daff1c3e8139acbad928ac4ea9 OK
2025/01/09 01:32:34 INFO  : one: Copied (new)
2025/01/09 01:32:34 DEBUG : Waiting for deletions to finish
2025/01/09 01:32:35 INFO  : three.txt: Deleted
2025/01/09 01:32:36 INFO  : three.txt: Moved (server-side)
2025/01/09 01:32:36 INFO  : three.txt: Moved into backup dir
2025/01/09 01:32:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/09 01:32:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/09 01:32:40 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/09 01:32:40 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/01/09 01:32:40 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/01/09 01:32:40 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncBackupDir (27.86s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:32:44 DEBUG : dst/one: md5 = 231cf90d94a36beb8060697d31c8e47c OK
2025/01/09 01:32:45 DEBUG : dst/two: md5 = e9d778b213f839fb4823a1e4847b3da0 OK
2025/01/09 01:32:47 DEBUG : dst/three.txt: md5 = e41c248bc6712bf214c05cc0c6c030a2 OK
2025/01/09 01:32:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/dst"
2025/01/09 01:32:48 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/09 01:32:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/backup"
2025/01/09 01:32:49 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/1nrff024r7pq65ecp72fc28jb0"
2025/01/09 01:32:50 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/09 01:32:50 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:32:50 DEBUG : two: Unchanged skipping
2025/01/09 01:32:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for checks to finish
2025/01/09 01:32:53 INFO  : one: Moved (server-side) to: one.bak
2025/01/09 01:32:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for transfers to finish
2025/01/09 01:32:54 DEBUG : one: md5 = 3dad72ba7e06399dcdb58c365e2a02c6 OK
2025/01/09 01:32:54 INFO  : one: Copied (new)
2025/01/09 01:32:54 DEBUG : Waiting for deletions to finish
2025/01/09 01:32:56 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/09 01:32:56 INFO  : three.txt: Moved into backup dir
2025/01/09 01:32:58 DEBUG : dst/three.txt: md5 = 4889af58b045916d3d6d58561d9f23e1 OK
2025/01/09 01:32:59 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/09 01:32:59 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:32:59 DEBUG : two: Unchanged skipping
2025/01/09 01:32:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for checks to finish
2025/01/09 01:33:00 INFO  : one.bak: Deleted
2025/01/09 01:33:01 INFO  : one: Moved (server-side) to: one.bak
2025/01/09 01:33:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for transfers to finish
2025/01/09 01:33:02 DEBUG : one: md5 = 37bc27bdec4253f7d4e885e461ca59ba OK
2025/01/09 01:33:02 INFO  : one: Copied (new)
2025/01/09 01:33:02 DEBUG : Waiting for deletions to finish
2025/01/09 01:33:03 INFO  : three.txt.bak: Deleted
2025/01/09 01:33:04 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/09 01:33:04 INFO  : three.txt: Moved into backup dir
2025/01/09 01:33:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/09 01:33:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/09 01:33:08 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/09 01:33:08 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/09 01:33:08 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/09 01:33:08 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncBackupDirWithSuffix (28.08s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:33:12 DEBUG : dst/one: md5 = d5b304f1dba1197ee9aaf92e8b12e896 OK
2025/01/09 01:33:14 DEBUG : dst/two: md5 = c2910c75b22ec20d6e2833f88211bf87 OK
2025/01/09 01:33:15 DEBUG : dst/three.txt: md5 = b7b981e6767fb5d2549e5ebe47556c7d OK
2025/01/09 01:33:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/dst"
2025/01/09 01:33:16 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/09 01:33:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/backup"
2025/01/09 01:33:17 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/1nrff024r7pq65ecp72fc28jb0"
2025/01/09 01:33:19 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/09 01:33:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for checks to finish
2025/01/09 01:33:19 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:33:19 DEBUG : two: Unchanged skipping
2025/01/09 01:33:21 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/01/09 01:33:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for transfers to finish
2025/01/09 01:33:22 DEBUG : one: md5 = 53e1834bd82d77cae4b60e0f2677a53c OK
2025/01/09 01:33:22 INFO  : one: Copied (new)
2025/01/09 01:33:22 DEBUG : Waiting for deletions to finish
2025/01/09 01:33:24 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/01/09 01:33:24 INFO  : three.txt: Moved into backup dir
2025/01/09 01:33:26 DEBUG : dst/three.txt: md5 = 9d58e43a56b59ecf1fd403ad3c194f67 OK
2025/01/09 01:33:27 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/09 01:33:27 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:33:27 DEBUG : two: Unchanged skipping
2025/01/09 01:33:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for checks to finish
2025/01/09 01:33:27 INFO  : one-2019-01-01: Deleted
2025/01/09 01:33:28 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/01/09 01:33:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for transfers to finish
2025/01/09 01:33:30 DEBUG : one: md5 = 87b0b30194f70334786a4aaf6c750d68 OK
2025/01/09 01:33:30 INFO  : one: Copied (new)
2025/01/09 01:33:30 DEBUG : Waiting for deletions to finish
2025/01/09 01:33:31 INFO  : three-2019-01-01.txt: Deleted
2025/01/09 01:33:31 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/01/09 01:33:31 INFO  : three.txt: Moved into backup dir
2025/01/09 01:33:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/09 01:33:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/09 01:33:36 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/01/09 01:33:36 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/01/09 01:33:36 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/01/09 01:33:36 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (27.89s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:33:40 DEBUG : dst/one: md5 = 3d065fb4cdd7bec7508aeee84d923642 OK
2025/01/09 01:33:41 DEBUG : dst/two: md5 = 3bf115cbd46fe1f5377cc5523b5a8317 OK
2025/01/09 01:33:43 DEBUG : dst/three.txt: md5 = 9d420d22ac01fb1bd29b1fe509483b9e OK
2025/01/09 01:33:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/dst"
2025/01/09 01:33:44 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/09 01:33:45 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/09 01:33:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for checks to finish
2025/01/09 01:33:45 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:33:45 DEBUG : two: Unchanged skipping
2025/01/09 01:33:46 INFO  : one: Moved (server-side) to: one.bak
2025/01/09 01:33:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for transfers to finish
2025/01/09 01:33:47 DEBUG : one: md5 = ff6f36d579545f68ea81971900234b62 OK
2025/01/09 01:33:47 INFO  : one: Copied (new)
2025/01/09 01:33:47 DEBUG : Waiting for deletions to finish
2025/01/09 01:33:48 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/09 01:33:48 INFO  : three.txt: Moved into backup dir
2025/01/09 01:33:51 DEBUG : dst/three.txt: md5 = 0c9e0f8e7a627c4b1c7eec27e27d7e57 OK
2025/01/09 01:33:52 DEBUG : one.bak: Excluded (Path Filter)
2025/01/09 01:33:52 DEBUG : one.bak: Excluded
2025/01/09 01:33:52 DEBUG : three.txt.bak: Excluded (Path Filter)
2025/01/09 01:33:52 DEBUG : three.txt.bak: Excluded
2025/01/09 01:33:52 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/09 01:33:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for checks to finish
2025/01/09 01:33:52 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:33:52 DEBUG : two: Unchanged skipping
2025/01/09 01:33:52 INFO  : one.bak: Deleted
2025/01/09 01:33:53 INFO  : one: Moved (server-side) to: one.bak
2025/01/09 01:33:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi/dst': Waiting for transfers to finish
2025/01/09 01:33:55 DEBUG : one: md5 = cb56a1bd745a7a51f435b8ed05044a1f OK
2025/01/09 01:33:55 INFO  : one: Copied (new)
2025/01/09 01:33:55 DEBUG : Waiting for deletions to finish
2025/01/09 01:33:55 INFO  : three.txt.bak: Deleted
2025/01/09 01:33:56 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/09 01:33:56 INFO  : three.txt: Moved into backup dir
2025/01/09 01:34:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/09 01:34:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/09 01:34:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/09 01:34:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/09 01:34:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/09 01:34:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncBackupDirSuffixOnly (23.91s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:34:04 DEBUG : dst/one: md5 = 284d99183ecca9e4a2d057d63ae6fcd1 OK
2025/01/09 01:34:06 DEBUG : dst/two: md5 = abd3038baa0e212d6fbd2c9e68cc112c OK
2025/01/09 01:34:08 DEBUG : dst/three.txt: md5 = 6b5f92d2fcfbcc1d62bc74c04c9dec58 OK
2025/01/09 01:34:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/dst"
2025/01/09 01:34:08 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/09 01:34:09 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/09 01:34:10 INFO  : one: Moved (server-side) to: one.bak
2025/01/09 01:34:12 DEBUG : one: md5 = 2c67e7eeb3e4e43017a2c338544698c8 OK
2025/01/09 01:34:12 INFO  : one: Copied (new)
2025/01/09 01:34:12 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:34:12 DEBUG : two: Unchanged skipping
2025/01/09 01:34:12 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/01/09 01:34:13 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/09 01:34:15 DEBUG : three.txt: md5 = 9af3bc7a837dae62986528b79260eec1 OK
2025/01/09 01:34:15 INFO  : three.txt: Copied (new)
2025/01/09 01:34:16 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/09 01:34:17 INFO  : one.bak: Deleted
2025/01/09 01:34:18 INFO  : one: Moved (server-side) to: one.bak
2025/01/09 01:34:19 DEBUG : one: md5 = 09b4d3d86da2c614fbec8c7c8e1b6253 OK
2025/01/09 01:34:19 INFO  : one: Copied (new)
2025/01/09 01:34:20 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:34:20 DEBUG : two: Unchanged skipping
2025/01/09 01:34:20 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/01/09 01:34:21 INFO  : three.txt.bak: Deleted
2025/01/09 01:34:22 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/09 01:34:23 DEBUG : three.txt: md5 = 7835f4e8cbaa71f16b58a5273f87acd2 OK
2025/01/09 01:34:23 INFO  : three.txt: Copied (new)
2025/01/09 01:34:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/01/09 01:34:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/09 01:34:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/09 01:34:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/09 01:34:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/09 01:34:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/09 01:34:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncSuffix (27.57s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:34:31 DEBUG : dst/one: md5 = a5ecc11e1a3d4f0421304ba6de23d2c3 OK
2025/01/09 01:34:33 DEBUG : dst/two: md5 = 5c1289cb8eb1f857c8e3b68232a29c4a OK
2025/01/09 01:34:35 DEBUG : dst/three.txt: md5 = bf2fe384d7d065b1d3433448f2162177 OK
2025/01/09 01:34:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tobubat7kixi/dst"
2025/01/09 01:34:35 DEBUG : Creating backend with remote "TestDrive:crypt/umscjl1j7gi3c127q3gmrpvf4uh574ems151vr45rretb3amrnu0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/09 01:34:36 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/09 01:34:37 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/01/09 01:34:39 DEBUG : one: md5 = 3e1c6248c773f7e5c3c4220b54061465 OK
2025/01/09 01:34:39 INFO  : one: Copied (new)
2025/01/09 01:34:39 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:34:39 DEBUG : two: Unchanged skipping
2025/01/09 01:34:39 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/01/09 01:34:40 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/01/09 01:34:42 DEBUG : three.txt: md5 = e0c12a9f44a986fb5981863c77b1c1e0 OK
2025/01/09 01:34:42 INFO  : three.txt: Copied (new)
2025/01/09 01:34:43 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/09 01:34:44 INFO  : one-2019-01-01: Deleted
2025/01/09 01:34:45 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/01/09 01:34:46 DEBUG : one: md5 = d8731079945a553adacaa09ee0375220 OK
2025/01/09 01:34:46 INFO  : one: Copied (new)
2025/01/09 01:34:47 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:34:47 DEBUG : two: Unchanged skipping
2025/01/09 01:34:47 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/01/09 01:34:48 INFO  : three-2019-01-01.txt: Deleted
2025/01/09 01:34:48 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/01/09 01:34:50 DEBUG : three.txt: md5 = 55f29c310ba39c53d1931cf6f879aced OK
2025/01/09 01:34:50 INFO  : three.txt: Copied (new)
2025/01/09 01:34:56 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/01/09 01:34:56 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/09 01:34:56 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/01/09 01:34:56 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/09 01:34:56 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/01/09 01:34:56 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/01/09 01:34:56 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncSuffixKeepExtension (28.25s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:34:59 DEBUG : Testêé: md5 = e0b3e8ef8f0072566ac5c643b4574adc OK
2025/01/09 01:34:59 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2025/01/09 01:34:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:34:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:35:01 DEBUG : Testêé: md5 = 39f798010de1d8ae3591f0aad834bbc4 OK
2025/01/09 01:35:01 INFO  : Testêé: Copied (replaced existing) to: Testêé
2025/01/09 01:35:01 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (5.06s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:35:02 DEBUG : existing: Need to transfer - File not found at Destination
2025/01/09 01:35:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:35:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:35:04 DEBUG : existing: md5 = e045306cefb4bee5e800f6ef31310b62 OK
2025/01/09 01:35:04 INFO  : existing: Copied (new)
2025/01/09 01:35:04 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:35:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:35:05 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2025/01/09 01:35:05 ERROR : existing: Source and destination exist but do not match: immutable file modified
2025/01/09 01:35:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:35:05 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': not deleting files as there were IO errors
2025/01/09 01:35:05 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncImmutable (5.27s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:35:09 DEBUG : EXISTING: md5 = 9f51d34246f4f20b02a5317b2177b2d9 OK
2025/01/09 01:35:09 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:35:09 DEBUG : existing: Unchanged skipping
2025/01/09 01:35:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:35:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:35:09 DEBUG : Waiting for deletions to finish
2025/01/09 01:35:09 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (3.69s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    sync_test.go:2635: Skipping test as local or remote are case-sensitive
--- SKIP: TestFixCase (0.48s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", 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-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", 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-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.37s)
    --- SKIP: TestMaxTransfer/Hard (0.43s)
    --- SKIP: TestMaxTransfer/Soft (0.47s)
    --- SKIP: TestMaxTransfer/Cautious (0.47s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:35:14 DEBUG : both0: md5 = aa2cb4a7e8b2454a4de9d1ae9118216c OK
2025/01/09 01:35:16 DEBUG : only0: md5 = 26f348cfa68c8dfdfbb0d8fc4ec1a033 OK
2025/01/09 01:35:18 DEBUG : both1: md5 = 50af1f03ca2bcb28fe90966455669ecb OK
2025/01/09 01:35:20 DEBUG : only1: md5 = 557e874c8085ce829c9d31113827302e OK
2025/01/09 01:35:22 DEBUG : both2: md5 = e74c50b18664d9de364bb98b78f2be50 OK
2025/01/09 01:35:23 DEBUG : only2: md5 = b4c46129a8c157ffc68f63e99e2c426c OK
2025/01/09 01:35:25 DEBUG : both3: md5 = 211dfc583adb5b75f15a95f2ed67ab4b OK
2025/01/09 01:35:27 DEBUG : only3: md5 = 14e0938fc6538c9d5a48ceebdce812a8 OK
2025/01/09 01:35:29 DEBUG : both4: md5 = 6e3d199375c8f6a8e4c90ef9b7c17b75 OK
2025/01/09 01:35:31 DEBUG : only4: md5 = 073104bf7161de94d85aa72a30c82681 OK
2025/01/09 01:35:32 DEBUG : both5: md5 = 562f49c47fdd81f8012759ebfcb539a0 OK
2025/01/09 01:35:34 DEBUG : only5: md5 = 57154719cf962bbac527ad48602558cb OK
2025/01/09 01:35:36 DEBUG : both6: md5 = aa567e460616a69ea33e1423649d8691 OK
2025/01/09 01:35:38 DEBUG : only6: md5 = 0d59508120da084cc63412fa224eb6d9 OK
2025/01/09 01:35:39 DEBUG : both7: md5 = 1cfde0aefa5e59cbabc0707de2b532fc OK
2025/01/09 01:35:41 DEBUG : only7: md5 = bd963b73a2496c1bc14685474429b9bb OK
2025/01/09 01:35:43 DEBUG : both8: md5 = 04ad99e5a24dbae90f407e5cfb0e1394 OK
2025/01/09 01:35:45 DEBUG : only8: md5 = 9cd238197fb6b666a704b398c973af74 OK
2025/01/09 01:35:47 DEBUG : both9: md5 = a76b7f94b8f06e7e4891fede5d104cb6 OK
2025/01/09 01:35:48 DEBUG : only9: md5 = 63df422a7cbe838dcc1f609f732f5ffc OK
2025/01/09 01:35:50 DEBUG : both10: md5 = a29dcb36b9f417f0729599b5ee84cddf OK
2025/01/09 01:35:52 DEBUG : only10: md5 = 3f3efc9a6e7157f50e94876c480783fd OK
2025/01/09 01:35:54 DEBUG : both11: md5 = d13ed2faae061eeb2b17eb5b09003230 OK
2025/01/09 01:35:55 DEBUG : only11: md5 = 62afcc76fb1393f06356b234aa276b8f OK
2025/01/09 01:35:57 DEBUG : both12: md5 = ae6be15672965b9e0248da868573c0c9 OK
2025/01/09 01:35:59 DEBUG : only12: md5 = 2069cb4ee1776cae08a3809a8ea437c3 OK
2025/01/09 01:36:01 DEBUG : both13: md5 = aa794d0678a81204b6ef96a74fa11926 OK
2025/01/09 01:36:02 DEBUG : only13: md5 = 2b487c9386abe8bff73d84ebfaa8015b OK
2025/01/09 01:36:04 DEBUG : both14: md5 = 45670cffdb19840fdc1e0a1da27eb282 OK
2025/01/09 01:36:06 DEBUG : only14: md5 = a533e3cddcad3c4c269cadbc77d4667a OK
2025/01/09 01:36:07 DEBUG : both15: md5 = 50417cb874d411e272f8b1d63c2a8843 OK
2025/01/09 01:36:09 DEBUG : only15: md5 = 29c63c8a9ebff34fa4c5a6e1f6f89d51 OK
2025/01/09 01:36:11 DEBUG : both16: md5 = c71714c46c8af6b184f4a151f1692647 OK
2025/01/09 01:36:13 DEBUG : only16: md5 = 582df380035a61dac8ecd9e58ce25bd0 OK
2025/01/09 01:36:14 DEBUG : both17: md5 = b703b499a778a39f9074db674c15749d OK
2025/01/09 01:36:16 DEBUG : only17: md5 = 39efba49d7b49428dfa3c4718bfbf4f6 OK
2025/01/09 01:36:18 DEBUG : both18: md5 = 03208b92a9341328236f1e9e8b14cbce OK
2025/01/09 01:36:20 DEBUG : only18: md5 = ce69425e2243dff7b043f769d8523440 OK
2025/01/09 01:36:21 DEBUG : both19: md5 = b6a76f072bd7ee97acbfcb414b8405b6 OK
2025/01/09 01:36:23 DEBUG : only19: md5 = 14007f87d4b2e23c4a04f182e867ecfd OK
2025/01/09 01:36:24 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:36:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:36:24 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:36:24 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:36:24 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:36:24 DEBUG : both0: Unchanged skipping
2025/01/09 01:36:24 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:36:24 DEBUG : both12: Unchanged skipping
2025/01/09 01:36:24 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:36:24 DEBUG : both11: Unchanged skipping
2025/01/09 01:36:24 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:36:24 DEBUG : both14: Unchanged skipping
2025/01/09 01:36:24 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:36:24 DEBUG : both15: Unchanged skipping
2025/01/09 01:36:24 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:36:24 DEBUG : both16: Unchanged skipping
2025/01/09 01:36:24 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:36:24 DEBUG : both17: Unchanged skipping
2025/01/09 01:36:24 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:36:24 DEBUG : both18: Unchanged skipping
2025/01/09 01:36:24 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:36:24 DEBUG : both19: Unchanged skipping
2025/01/09 01:36:24 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:36:24 DEBUG : both2: Unchanged skipping
2025/01/09 01:36:24 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:36:24 DEBUG : both3: Unchanged skipping
2025/01/09 01:36:24 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:36:24 DEBUG : both1: Unchanged skipping
2025/01/09 01:36:24 DEBUG : both10: Unchanged skipping
2025/01/09 01:36:24 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:36:24 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:36:24 DEBUG : both13: Unchanged skipping
2025/01/09 01:36:24 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:36:24 DEBUG : both7: Unchanged skipping
2025/01/09 01:36:24 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:36:24 DEBUG : both8: Unchanged skipping
2025/01/09 01:36:24 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:36:24 DEBUG : both9: Unchanged skipping
2025/01/09 01:36:24 DEBUG : both4: Unchanged skipping
2025/01/09 01:36:24 DEBUG : both5: Unchanged skipping
2025/01/09 01:36:24 DEBUG : both6: Unchanged skipping
2025/01/09 01:36:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:36:24 DEBUG : Waiting for deletions to finish
2025/01/09 01:36:24 INFO  : only14: Deleted
2025/01/09 01:36:24 INFO  : only15: Deleted
2025/01/09 01:36:24 INFO  : only16: Deleted
2025/01/09 01:36:25 INFO  : only19: Deleted
2025/01/09 01:36:25 INFO  : only4: Deleted
2025/01/09 01:36:25 INFO  : only5: Deleted
2025/01/09 01:36:25 INFO  : only13: Deleted
2025/01/09 01:36:25 INFO  : only1: Deleted
2025/01/09 01:36:26 INFO  : only3: Deleted
2025/01/09 01:36:26 INFO  : only0: Deleted
2025/01/09 01:36:26 INFO  : only2: Deleted
2025/01/09 01:36:26 INFO  : only10: Deleted
2025/01/09 01:36:26 INFO  : only8: Deleted
2025/01/09 01:36:26 INFO  : only17: Deleted
2025/01/09 01:36:26 INFO  : only18: Deleted
2025/01/09 01:36:26 INFO  : only6: Deleted
2025/01/09 01:36:27 INFO  : only7: Deleted
2025/01/09 01:36:27 INFO  : only9: Deleted
2025/01/09 01:36:27 INFO  : only11: Deleted
2025/01/09 01:36:27 INFO  : only12: Deleted
2025/01/09 01:36:27 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (88.16s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:36:42 DEBUG : both0: md5 = 4fb29928202c2a5d44813d46e8137a72 OK
2025/01/09 01:36:44 DEBUG : only0: md5 = 27a832d374ffa5a4df659f6eac733367 OK
2025/01/09 01:36:46 DEBUG : both1: md5 = efc5702c8207389dc6d6d16fad91e8b3 OK
2025/01/09 01:36:48 DEBUG : only1: md5 = 452a78a207c184e010b1c50c09588de0 OK
2025/01/09 01:36:49 DEBUG : both2: md5 = 8ec6427377d5c2db47249b82078b574a OK
2025/01/09 01:36:51 DEBUG : only2: md5 = 4142258eb4c42ced5fba71767a946fc8 OK
2025/01/09 01:36:53 DEBUG : both3: md5 = e48bee39b5c20c317d538b808de7473f OK
2025/01/09 01:36:55 DEBUG : only3: md5 = 2efafebc60ed2345c17fce319c7d7939 OK
2025/01/09 01:36:56 DEBUG : both4: md5 = e91d0962b2ef94eaa4c96e23543e3476 OK
2025/01/09 01:36:58 DEBUG : only4: md5 = 24f210bdeaebf2ed34a4ca25fa39f18f OK
2025/01/09 01:37:00 DEBUG : both5: md5 = 82b3081a4ac62293a493093636659219 OK
2025/01/09 01:37:01 DEBUG : only5: md5 = 9b933ff4c6e548d65e7168f3d115dc6b OK
2025/01/09 01:37:03 DEBUG : both6: md5 = d0fb3cb25d03cc10edc8ab2b923ccbac OK
2025/01/09 01:37:05 DEBUG : only6: md5 = eb76b5eef40ed9d9c22abbc06c826814 OK
2025/01/09 01:37:07 DEBUG : both7: md5 = 458fce9d1903766886db0ef6e9659a5c OK
2025/01/09 01:37:08 DEBUG : only7: md5 = 414005b7b86bf186288cb7f4f5ae9934 OK
2025/01/09 01:37:10 DEBUG : both8: md5 = e7b93e2c958d715cbeaac13d08317807 OK
2025/01/09 01:37:12 DEBUG : only8: md5 = fe2ced450881095b82c85d1ed58c446f OK
2025/01/09 01:37:14 DEBUG : both9: md5 = b04de7d3521f13df114a97355c538e44 OK
2025/01/09 01:37:15 DEBUG : only9: md5 = 1cdf44c2e83734bc1b2aeba64b812401 OK
2025/01/09 01:37:17 DEBUG : both10: md5 = c878c07182d8beb6fdab3df04da490a1 OK
2025/01/09 01:37:19 DEBUG : only10: md5 = 650dbad9b4920d86d19ba3de6d98cb48 OK
2025/01/09 01:37:20 DEBUG : both11: md5 = 9ebadde7299034dc06ce4aeea4659a47 OK
2025/01/09 01:37:22 DEBUG : only11: md5 = 682d25c94430fa9150fa550753136910 OK
2025/01/09 01:37:24 DEBUG : both12: md5 = 65daf609522fd36720890bbe7651ef40 OK
2025/01/09 01:37:25 DEBUG : only12: md5 = 3ef635ae59d1d4bccbbb4f2a725fd77c OK
2025/01/09 01:37:27 DEBUG : both13: md5 = 81fcde923122ca9264b111d7514dd4e9 OK
2025/01/09 01:37:29 DEBUG : only13: md5 = 4b8649831b41aa9717ce1e7d49dcbce5 OK
2025/01/09 01:37:31 DEBUG : both14: md5 = 465e24eeb1bde097a9a45227be38e20e OK
2025/01/09 01:37:32 DEBUG : only14: md5 = 2dd1d2209476c887abcdaf6465c0b8ab OK
2025/01/09 01:37:34 DEBUG : both15: md5 = fb93e551769ed1656b3db57cdf6cfe21 OK
2025/01/09 01:37:36 DEBUG : only15: md5 = 53c26f7115734dab894261a1eafdd55e OK
2025/01/09 01:37:37 DEBUG : both16: md5 = 7197a72fd00c2cec6175560107b264bf OK
2025/01/09 01:37:39 DEBUG : only16: md5 = 187a072403be529476488f759f804911 OK
2025/01/09 01:37:40 DEBUG : both17: md5 = 507339b28fe66b6572125384dcd31e73 OK
2025/01/09 01:37:42 DEBUG : only17: md5 = b38efee60d6f2ea4d3572980933ddac7 OK
2025/01/09 01:37:44 DEBUG : both18: md5 = 51805dd31dc8903715a5bc6bff939259 OK
2025/01/09 01:37:46 DEBUG : only18: md5 = e12f2c93240eebbb047772f12f762234 OK
2025/01/09 01:37:47 DEBUG : both19: md5 = 12e62f75b6662a7431efaeda696cd916 OK
2025/01/09 01:37:49 DEBUG : only19: md5 = 565aaf4d5369e8e9a49947a8d29343de OK
2025/01/09 01:37:49 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:37:49 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:37:49 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:37:49 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:37:49 DEBUG : both0: Unchanged skipping
2025/01/09 01:37:49 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:37:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for checks to finish
2025/01/09 01:37:49 DEBUG : both1: Unchanged skipping
2025/01/09 01:37:49 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:37:49 DEBUG : both13: Unchanged skipping
2025/01/09 01:37:49 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:37:49 DEBUG : both14: Unchanged skipping
2025/01/09 01:37:49 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:37:49 DEBUG : both15: Unchanged skipping
2025/01/09 01:37:49 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:37:49 DEBUG : both16: Unchanged skipping
2025/01/09 01:37:49 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:37:49 DEBUG : both17: Unchanged skipping
2025/01/09 01:37:49 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:37:49 DEBUG : both18: Unchanged skipping
2025/01/09 01:37:49 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:37:49 DEBUG : both19: Unchanged skipping
2025/01/09 01:37:49 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:37:49 DEBUG : both2: Unchanged skipping
2025/01/09 01:37:49 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:37:49 DEBUG : both3: Unchanged skipping
2025/01/09 01:37:49 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:37:49 DEBUG : both4: Unchanged skipping
2025/01/09 01:37:49 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:37:49 DEBUG : both5: Unchanged skipping
2025/01/09 01:37:49 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:37:49 DEBUG : both6: Unchanged skipping
2025/01/09 01:37:49 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:37:49 DEBUG : both7: Unchanged skipping
2025/01/09 01:37:49 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:37:49 DEBUG : both8: Unchanged skipping
2025/01/09 01:37:49 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/09 01:37:49 DEBUG : both9: Unchanged skipping
2025/01/09 01:37:49 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2025/01/09 01:37:49 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2025/01/09 01:37:49 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2025/01/09 01:37:49 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2025/01/09 01:37:49 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2025/01/09 01:37:49 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2025/01/09 01:37:49 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2025/01/09 01:37:49 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2025/01/09 01:37:49 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2025/01/09 01:37:49 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2025/01/09 01:37:49 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2025/01/09 01:37:49 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2025/01/09 01:37:49 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2025/01/09 01:37:49 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2025/01/09 01:37:49 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2025/01/09 01:37:49 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2025/01/09 01:37:49 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2025/01/09 01:37:49 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2025/01/09 01:37:49 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2025/01/09 01:37:49 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2025/01/09 01:37:49 DEBUG : both10: Unchanged skipping
2025/01/09 01:37:49 DEBUG : both11: Unchanged skipping
2025/01/09 01:37:49 DEBUG : both12: Unchanged skipping
2025/01/09 01:37:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Waiting for transfers to finish
2025/01/09 01:37:51 DEBUG : only1: md5 = de45cb39f182766eb18433db107772b1 OK
2025/01/09 01:37:51 INFO  : only1: Copied (replaced existing)
2025/01/09 01:37:51 DEBUG : only0: md5 = a7b1ad6032454ccf214b9cbf1b1a811b OK
2025/01/09 01:37:51 INFO  : only0: Copied (replaced existing)
2025/01/09 01:37:51 DEBUG : only11: md5 = 601fbe262b23cc5d2d70baf303c20e3a OK
2025/01/09 01:37:51 INFO  : only11: Copied (replaced existing)
2025/01/09 01:37:51 DEBUG : only10: md5 = f2b8d8f39c0f814dd3406e71ae038427 OK
2025/01/09 01:37:51 INFO  : only10: Copied (replaced existing)
2025/01/09 01:37:52 DEBUG : only13: md5 = 1b39781c69c04385363b1c19e3998fbf OK
2025/01/09 01:37:52 INFO  : only13: Copied (replaced existing)
2025/01/09 01:37:52 DEBUG : only12: md5 = ada10eb28486e777ddb10eaca1563195 OK
2025/01/09 01:37:52 INFO  : only12: Copied (replaced existing)
2025/01/09 01:37:52 DEBUG : only15: md5 = a919793b3ee688777a09f3941bafcdf4 OK
2025/01/09 01:37:52 INFO  : only15: Copied (replaced existing)
2025/01/09 01:37:52 DEBUG : only14: md5 = c1d11010ff2be389b8fbca1bdf34246b OK
2025/01/09 01:37:52 INFO  : only14: Copied (replaced existing)
2025/01/09 01:37:53 DEBUG : only16: md5 = eaae384072c112d658e3a2f32e87f2a0 OK
2025/01/09 01:37:53 INFO  : only16: Copied (replaced existing)
2025/01/09 01:37:53 DEBUG : only17: md5 = 084c5b457f772879c81af4be3288eca8 OK
2025/01/09 01:37:53 INFO  : only17: Copied (replaced existing)
2025/01/09 01:37:53 DEBUG : only18: md5 = 05ce7ea4e5461004c8dcdc3efb079730 OK
2025/01/09 01:37:53 INFO  : only18: Copied (replaced existing)
2025/01/09 01:37:54 DEBUG : only19: md5 = 221a139110a43892708a6d53df6a69b5 OK
2025/01/09 01:37:54 INFO  : only19: Copied (replaced existing)
2025/01/09 01:37:55 DEBUG : only2: md5 = cd8331a0546b5351b6011e5373a5e9ee OK
2025/01/09 01:37:55 INFO  : only2: Copied (replaced existing)
2025/01/09 01:37:55 DEBUG : only3: md5 = d59ad840e9c84c12c796f05c8ef92a8e OK
2025/01/09 01:37:55 INFO  : only3: Copied (replaced existing)
2025/01/09 01:37:55 DEBUG : only4: md5 = 7e4ff9eab2fa8c84e461da9db75f64c9 OK
2025/01/09 01:37:55 INFO  : only4: Copied (replaced existing)
2025/01/09 01:37:55 DEBUG : only5: md5 = 576a6e4229f56556afeda4c8ec4ea728 OK
2025/01/09 01:37:55 INFO  : only5: Copied (replaced existing)
2025/01/09 01:37:56 DEBUG : only6: md5 = ddbb418a64e2289b782f3a1da17d5c41 OK
2025/01/09 01:37:56 INFO  : only6: Copied (replaced existing)
2025/01/09 01:37:56 DEBUG : only9: md5 = ee589bbc980e66d768cc5da8c535d360 OK
2025/01/09 01:37:56 INFO  : only9: Copied (replaced existing)
2025/01/09 01:37:56 DEBUG : only7: md5 = 911f19d5dc356a8fa0f5de3ea0dbf080 OK
2025/01/09 01:37:56 INFO  : only7: Copied (replaced existing)
2025/01/09 01:37:56 DEBUG : only8: md5 = 241aaf05b4705b9d7d6c354ba5d739ac OK
2025/01/09 01:37:56 INFO  : only8: Copied (replaced existing)
2025/01/09 01:37:56 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (100.17s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:38:21 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/09 01:38:21 DEBUG : sub dir: Making directory with metadata
2025/01/09 01:38:22 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:38:42 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/09 01:38:43 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/09 01:38:43 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/09 01:38:43 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:38:56 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2025/01/09 01:38:57 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/09 01:38:58 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2025/01/09 01:38:59 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2025/01/09 01:39:00 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/09 01:39:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/09 01:39:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/09 01:39:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/09 01:39:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/09 01:39:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2025/01/09 01:39:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/09 01:39:05 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (46.43s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:39:07 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/09 01:39:07 DEBUG : sub dir: Making directory with metadata
2025/01/09 01:39:08 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:39:34 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/09 01:39:34 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/09 01:39:34 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/09 01:39:34 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi'", Local "Local file system at /tmp/rclone2858783104", Modify Window "1ms"
2025/01/09 01:39:47 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/09 01:39:48 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2025/01/09 01:39:49 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2025/01/09 01:39:50 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/09 01:39:51 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/09 01:39:52 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/09 01:39:52 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/09 01:39:53 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/09 01:39:54 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2025/01/09 01:39:54 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/09 01:39:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (49.68s)
PASS
2025/01/09 01:39:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tobubat7kixi': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 17m53.103733737s (try 1/5)