"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5)
2025/01/11 01:31:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo"
2025/01/11 01:31:44 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/01/11 01:31:44 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0"
2025/01/11 01:31:45 DEBUG : Creating backend with remote "/tmp/rclone3400890828"
=== 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-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:31:46 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/11 01:31:46 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/11 01:31:46 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2025/01/11 01:31:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:31:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:31:46 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (2.32s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:31:47 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/11 01:31:48 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/11 01:31:48 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/11 01:31:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:31:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:31:50 DEBUG : sub dir/hello world: md5 = 13e7fe688baa24b39e2049d638b66558 OK
2025/01/11 01:31:50 INFO  : sub dir/hello world: Copied (new)
2025/01/11 01:31:51 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:31:53 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (6.69s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:31:54 DEBUG : metadata sub dir: Making directory with metadata
2025/01/11 01:31:54 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/11 01:31:54 DEBUG : empty metadata sub dir: Making directory with metadata
2025/01/11 01:31:54 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/11 01:31:54 DEBUG : Local file system at /tmp/rclone3400890828: File to upload is small (21 bytes), uploading instead of streaming
2025/01/11 01:31:54 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2025/01/11 01:31:54 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2025/01/11 01:31:54 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2025/01/11 01:31:55 DEBUG : Google drive root 'crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0': Skipping btime metadata as can't update it on an existing file: 2025-01-11T01:31:54.576378499Z
2025/01/11 01:31:55 INFO  : empty metadata sub dir: Updated directory metadata
2025/01/11 01:31:56 DEBUG : Google drive root 'crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0': Skipping btime metadata as can't update it on an existing file: 2025-01-11T01:31:54.576378499Z
2025/01/11 01:31:56 INFO  : metadata sub dir: Updated directory metadata
2025/01/11 01:31:56 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2025/01/11 01:31:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:31:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:31:58 DEBUG : metadata sub dir/hello metadata world: md5 = 96db0203c6535ac4a8c26169a80f5866 OK
2025/01/11 01:31:58 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:32:01 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (8.86s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:32:03 DEBUG : metadata sub dir: Making directory with metadata
2025/01/11 01:32:03 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/11 01:32:03 DEBUG : empty metadata sub dir: Making directory with metadata
2025/01/11 01:32:03 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/11 01:32:03 DEBUG : Local file system at /tmp/rclone3400890828: File to upload is small (21 bytes), uploading instead of streaming
2025/01/11 01:32:03 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2025/01/11 01:32:03 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2025/01/11 01:32:03 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2025/01/11 01:32:03 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2025/01/11 01:32:03 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2025/01/11 01:32:03 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2025/01/11 01:32:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:32:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:32:06 DEBUG : metadata sub dir/hello metadata world: md5 = 1d76af6b166bc2d474d9ff85142ce139 OK
2025/01/11 01:32:06 INFO  : metadata sub dir/hello metadata world: Copied (new)
2025/01/11 01:32:06 DEBUG : Google drive root 'crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0': Skipping btime metadata as can't update it on an existing file: 2025-01-11T01:32:03.436288275Z
2025/01/11 01:32:07 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:32:10 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (7.91s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:32:11 DEBUG : Creating backend with remote "/non-existing"
2025/01/11 01:32:11 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2025/01/11 01:32:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:32:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.06s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:32:12 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/11 01:32:12 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/11 01:32:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:32:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:32:15 DEBUG : sub dir/hello world: md5 = b6839fbf275b35de5eea0110fcd60234 OK
2025/01/11 01:32:15 INFO  : sub dir/hello world: Copied (new)
2025/01/11 01:32:16 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:32:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (6.62s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:32:19 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Running all checks before starting transfers
2025/01/11 01:32:19 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/11 01:32:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/11 01:32:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:32:19 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Checks finished, now starting transfers
2025/01/11 01:32:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:32:21 DEBUG : sub dir/hello world: md5 = a53a35c840392756ffb7e3fd21d187b2 OK
2025/01/11 01:32:21 INFO  : sub dir/hello world: Copied (new)
2025/01/11 01:32:22 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:32:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (6.51s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:32:25 ERROR : Ignoring --no-traverse with sync
2025/01/11 01:32:25 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/11 01:32:25 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/11 01:32:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:32:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:32:28 DEBUG : sub dir/hello world: md5 = a4d7503fca4a44f0dbde8a99260c159d OK
2025/01/11 01:32:28 INFO  : sub dir/hello world: Copied (new)
2025/01/11 01:32:28 DEBUG : Waiting for deletions to finish
2025/01/11 01:32:29 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:32:31 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (7.05s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:32:32 DEBUG : hello world2: Need to transfer - File not found at Destination
2025/01/11 01:32:32 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/11 01:32:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:32:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:32:34 DEBUG : hello world2: md5 = c9e590bebf0d9740fbd6546b0008e459 OK
2025/01/11 01:32:34 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestCopyWithDepth (3.61s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:32:36 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/11 01:32:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:32:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:32:38 DEBUG : potato2: md5 = e4c39c9da243978c7d1c32691585192a OK
2025/01/11 01:32:38 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (3.67s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:32:40 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/11 01:32:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:32:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:32:41 DEBUG : potato2: md5 = 4ffae43d68facafde6c9c21f415a4c2d OK
2025/01/11 01:32:41 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (3.81s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:32:43 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/01/11 01:32:43 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/11 01:32:43 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/11 01:32:43 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/11 01:32:43 DEBUG : sub dir: Making directory with metadata
2025/01/11 01:32:45 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/01/11 01:32:45 DEBUG : sub dir2: Making directory with metadata
2025/01/11 01:32:46 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/11 01:32:46 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/01/11 01:32:46 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/11 01:32:47 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/11 01:32:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:32:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:32:47 DEBUG : sub dir/hello world: md5 = b303f00dc870240698c2a1373f34945e OK
2025/01/11 01:32:47 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:32:51 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2025/01/11 01:32:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (10.19s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:32:53 INFO  : sub dir2: Making directory
2025/01/11 01:32:53 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/01/11 01:32:53 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/11 01:32:54 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/11 01:32:54 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/01/11 01:32:54 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2025/01/11 01:32:54 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/11 01:32:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:32:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:32:56 DEBUG : sub dir/hello world: md5 = f28e2e1ffe2d9b2d7a9797eb5f27af36 OK
2025/01/11 01:32:56 INFO  : sub dir/hello world: Copied (new)
2025/01/11 01:32:57 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/11 01:32:59 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (6.05s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:32:59 DEBUG : sub dir2: Making directory with metadata
2025/01/11 01:32:59 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/11 01:33:00 DEBUG : sub dir: Making directory with metadata
2025/01/11 01:33:01 INFO  : sub dir: Made directory with metadata (mtime=2025-01-11T01:32:59.911720519Z)
2025/01/11 01:33:01 DEBUG : sub dir2: Making directory with metadata
2025/01/11 01:33:02 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/11 01:33:02 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/11 01:33:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:33:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:33:04 DEBUG : sub dir/hello world: md5 = a5f5bd7de603f1fbdf62ba3fcdbc2ed9 OK
2025/01/11 01:33:04 INFO  : sub dir/hello world: Copied (new)
2025/01/11 01:33:04 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:33:07 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (8.52s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:33:08 DEBUG : sub dir no update dir modtime: Making directory with metadata
2025/01/11 01:33:08 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/01/11 01:33:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:33:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:33:10 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (4.50s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:33:12 INFO  : sub dir2: Making directory
2025/01/11 01:33:13 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/11 01:33:13 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/01/11 01:33:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/11 01:33:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:33:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:33:15 DEBUG : sub dir/hello world: md5 = 7d1b958d149a7ed287904f8392c6d21b OK
2025/01/11 01:33:15 INFO  : sub dir/hello world: Copied (new)
2025/01/11 01:33:15 INFO  : sub dir/hello world: Deleted
2025/01/11 01:33:16 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/11 01:33:18 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (5.94s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:33:18 DEBUG : sub dir2: Making directory with metadata
2025/01/11 01:33:18 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/11 01:33:18 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/11 01:33:19 DEBUG : sub dir: Making directory with metadata
2025/01/11 01:33:20 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/01/11 01:33:20 DEBUG : sub dir2: Making directory with metadata
2025/01/11 01:33:21 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/11 01:33:21 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/11 01:33:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:33:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:33:23 DEBUG : sub dir/hello world: md5 = bcccfc9dad6610aaba6af8e15d861266 OK
2025/01/11 01:33:23 INFO  : sub dir/hello world: Copied (new)
2025/01/11 01:33:23 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:33:26 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (8.63s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.45s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:33:27 INFO  : sub dir2: Making directory
2025/01/11 01:33:28 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/11 01:33:28 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/01/11 01:33:28 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/11 01:33:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:33:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:33:30 DEBUG : sub dir/hello world: md5 = 51a4d690518ba6287dd89168903f5e8c OK
2025/01/11 01:33:30 INFO  : sub dir/hello world: Copied (new)
2025/01/11 01:33:30 DEBUG : Waiting for deletions to finish
2025/01/11 01:33:31 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/11 01:33:33 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (6.89s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:33:37 DEBUG : sub dir/hello world: md5 = c958eeec6fae246797c467f5531e8e22 OK
2025/01/11 01:33:38 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yimupuq4peri"
2025/01/11 01:33:38 DEBUG : Creating backend with remote "TestDrive:crypt/qgkvm99n15tu0a8i16a7p8phe16njgj6tdll0id0pe7q18ulklag"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo' -> Encrypted drive 'TestCryptDrive:rclone-test-yimupuq4peri'
2025/01/11 01:33:39 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/11 01:33:39 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/11 01:33:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yimupuq4peri': Waiting for checks to finish
2025/01/11 01:33:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yimupuq4peri': Waiting for transfers to finish
2025/01/11 01:33:43 INFO  : sub dir/hello world: Copied (server-side copy)
2025/01/11 01:33:43 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:33:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yimupuq4peri': Purge remote
2025/01/11 01:33:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (12.81s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:33:50 DEBUG : sub dir/hello world: md5 = 380fa9b6825ee636ee4d922543e60272 OK
2025/01/11 01:33:51 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/11 01:33:51 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/01/11 01:33:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:33:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:33:52 DEBUG : sub dir/hello world: md5 = 256025098984ef2fd522def228d7d0af OK
2025/01/11 01:33:52 INFO  : sub dir/hello world: Copied (replaced existing)
2025/01/11 01:33:53 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:33:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (8.39s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:33:58 DEBUG : sub dir/hello world: md5 = d67e2e6c3c5119cb25d50e27100fc4ac OK
2025/01/11 01:33:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kogumul2caci"
2025/01/11 01:33:59 DEBUG : Creating backend with remote "TestDrive:crypt/qs6k1d6bq18rosa8nvgqvon0ooclfjolmqt8bular7a20r8593l0"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo' -> Encrypted drive 'TestCryptDrive:rclone-test-kogumul2caci'
2025/01/11 01:34:00 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/11 01:34:00 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/11 01:34:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kogumul2caci': Waiting for checks to finish
2025/01/11 01:34:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kogumul2caci': Waiting for transfers to finish
2025/01/11 01:34:04 INFO  : sub dir/hello world: Copied (server-side copy)
2025/01/11 01:34:05 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:34:06 DEBUG : sub dir/hello world: md5 = 85fc23efc7e700d870207e21277cdca9 OK
2025/01/11 01:34:07 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/01/11 01:34:07 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/11 01:34:07 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/01/11 01:34:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kogumul2caci': Waiting for checks to finish
2025/01/11 01:34:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kogumul2caci': Waiting for transfers to finish
2025/01/11 01:34:09 INFO  : sub dir/hello world: Copied (server-side copy)
2025/01/11 01:34:10 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:34:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kogumul2caci': Purge remote
2025/01/11 01:34:12 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (18.40s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:34:17 DEBUG : sub dir/hello world: md5 = bd66e0262292894bd1711ecd792ba84d OK
2025/01/11 01:34:18 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/11 01:34:18 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/01/11 01:34:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:34:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:34:20 DEBUG : sub dir/hello world: md5 = 3342e0fb6b6fc71081cbc881523ca04f OK
2025/01/11 01:34:20 INFO  : sub dir/hello world: Copied (replaced existing)
2025/01/11 01:34:20 INFO  : sub dir/hello world: Deleted
2025/01/11 01:34:20 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:34:22 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (9.31s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:34:26 DEBUG : sub dir/hello world: md5 = db49e0fd2dad63e4718c3ddfeeba1dd9 OK
2025/01/11 01:34:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wulexab7feqo"
2025/01/11 01:34:26 DEBUG : Creating backend with remote "TestDrive:crypt/0ha0mrivo0s498nkkoktj1vd1qk19ibuktr3m2m3agb9ajssllu0"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo' -> Encrypted drive 'TestCryptDrive:rclone-test-wulexab7feqo'
2025/01/11 01:34:28 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/11 01:34:28 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/11 01:34:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wulexab7feqo': Waiting for checks to finish
2025/01/11 01:34:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wulexab7feqo': Waiting for transfers to finish
2025/01/11 01:34:31 INFO  : sub dir/hello world: Copied (server-side copy)
2025/01/11 01:34:32 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:34:34 DEBUG : sub dir/hello world: md5 = 5241f6fa981725aa7c56f15c4c87570f OK
2025/01/11 01:34:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wulexab7feqo': Using server-side directory move
2025/01/11 01:34:35 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-wulexab7feqo': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/01/11 01:34:35 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/01/11 01:34:35 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/11 01:34:35 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/01/11 01:34:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wulexab7feqo': Waiting for checks to finish
2025/01/11 01:34:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wulexab7feqo': Waiting for transfers to finish
2025/01/11 01:34:36 INFO  : sub dir/hello world: Deleted
2025/01/11 01:34:37 INFO  : sub dir/hello world: Moved (server-side)
2025/01/11 01:34:38 INFO  : sub dir: Set directory modification time (using SetModTime)
2025/01/11 01:34:40 DEBUG : sub dir/hello world: md5 = 1c83d6b89bf3100d53afd958a168d522 OK
2025/01/11 01:34:41 DEBUG : testing file moves
2025/01/11 01:34:41 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/01/11 01:34:41 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/11 01:34:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wulexab7feqo': Waiting for checks to finish
2025/01/11 01:34:41 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2025/01/11 01:34:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wulexab7feqo': Waiting for transfers to finish
2025/01/11 01:34:42 INFO  : sub dir/hello world: Deleted
2025/01/11 01:34:42 INFO  : sub dir/hello world: Moved (server-side)
2025/01/11 01:34:43 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:34:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wulexab7feqo': Purge remote
--- PASS: TestServerSideMoveOverSelf (23.73s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:34:50 DEBUG : sub dir/hello world: md5 = ed2d404e0da8f644b7bd8d67f6fe006d OK
2025/01/11 01:34:50 ERROR : : error listing: directory not found
2025/01/11 01:34:50 INFO  : Local file system at /tmp/rclone3400890828: Making directory
2025/01/11 01:34:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:34:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:34:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (6.83s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:34:56 DEBUG : sub dir/hello world: md5 = 6a141ab6bacd293c25644b25ac5ddd0f OK
2025/01/11 01:34:57 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/11 01:34:57 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/11 01:34:57 DEBUG : Local file system at /tmp/rclone3400890828: Waiting for checks to finish
2025/01/11 01:34:57 DEBUG : Local file system at /tmp/rclone3400890828: Waiting for transfers to finish
2025/01/11 01:34:58 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2025/01/11 01:34:58 INFO  : sub dir/hello world: Copied (new)
2025/01/11 01:34:58 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:35:00 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (7.03s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:35:01 DEBUG : check sum: Need to transfer - File not found at Destination
2025/01/11 01:35:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:35:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:35:03 DEBUG : check sum: md5 = d17ed332bc4dd02721a08d3e54f7967e OK
2025/01/11 01:35:03 INFO  : check sum: Copied (new)
2025/01/11 01:35:03 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:35:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:35:03 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2025/01/11 01:35:03 DEBUG : check sum: Size of src and dst objects identical
2025/01/11 01:35:03 DEBUG : check sum: Unchanged skipping
2025/01/11 01:35:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:35:03 DEBUG : Waiting for deletions to finish
2025/01/11 01:35:03 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (4.42s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:35:05 DEBUG : sizeonly: Need to transfer - File not found at Destination
2025/01/11 01:35:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:35:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:35:07 DEBUG : sizeonly: md5 = 2ff1b1fc4ef7c22e0a6ad79d4945bc0b OK
2025/01/11 01:35:07 INFO  : sizeonly: Copied (new)
2025/01/11 01:35:07 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:35:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:35:08 DEBUG : sizeonly: Sizes identical
2025/01/11 01:35:08 DEBUG : sizeonly: Unchanged skipping
2025/01/11 01:35:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:35:08 DEBUG : Waiting for deletions to finish
2025/01/11 01:35:08 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (4.66s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:35:10 DEBUG : ignore-size: Need to transfer - File not found at Destination
2025/01/11 01:35:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:35:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:35:12 DEBUG : ignore-size: md5 = 0cc259c20627e3fdb381efd87220b83e OK
2025/01/11 01:35:12 INFO  : ignore-size: Copied (new)
2025/01/11 01:35:12 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:35:12 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:35:12 DEBUG : ignore-size: Unchanged skipping
2025/01/11 01:35:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:35:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:35:12 DEBUG : Waiting for deletions to finish
2025/01/11 01:35:12 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (4.67s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:35:16 DEBUG : existing: md5 = 53071f48ea4b9d53e4176a785e140a2d OK
2025/01/11 01:35:17 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:35:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:35:17 DEBUG : existing: Unchanged skipping
2025/01/11 01:35:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:35:17 DEBUG : Waiting for deletions to finish
2025/01/11 01:35:17 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:35:17 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2025/01/11 01:35:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:35:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:35:18 DEBUG : existing: md5 = 3ea78f1039db89322dfec18f38dde77e OK
2025/01/11 01:35:18 INFO  : existing: Copied (replaced existing)
2025/01/11 01:35:18 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (5.93s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:35:21 DEBUG : existing: Need to transfer - File not found at Destination
2025/01/11 01:35:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:35:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:35:23 DEBUG : existing: md5 = 87cc521d202b052b1f31567811247f30 OK
2025/01/11 01:35:23 INFO  : existing: Copied (new)
2025/01/11 01:35:23 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:35:23 DEBUG : existing: Destination exists, skipping
2025/01/11 01:35:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:35:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:35:23 DEBUG : Waiting for deletions to finish
2025/01/11 01:35:23 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (4.78s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:35:28 DEBUG : b/potato: md5 = a0d9626154602e034ba615a6755a71de OK
2025/01/11 01:35:31 DEBUG : c/non empty space: md5 = 0d1c8a8b17de62d8c7d502b51cbe11e9 OK
2025/01/11 01:35:31 INFO  : d: Making directory
2025/01/11 01:35:33 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/01/11 01:35:33 DEBUG : Added delayed dir = "c", newDst=c
2025/01/11 01:35:33 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:35:33 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/01/11 01:35:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:35:33 DEBUG : c/non empty space: Unchanged skipping
2025/01/11 01:35:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:35:36 DEBUG : a/potato2: md5 = 31253746caba18de1ba4307c63dc64f5 OK
2025/01/11 01:35:36 INFO  : a/potato2: Copied (new)
2025/01/11 01:35:36 DEBUG : Waiting for deletions to finish
2025/01/11 01:35:36 INFO  : b/potato: Deleted
2025/01/11 01:35:37 INFO  : a: Set directory modification time (using DirSetModTime)
2025/01/11 01:35:37 INFO  : d: Removing directory
2025/01/11 01:35:37 INFO  : b: Removing directory
2025/01/11 01:35:38 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/01/11 01:35:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:35:41 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/01/11 01:35:42 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (17.48s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:35:44 DEBUG : empty space: md5 = 9495f6622da6e2967465a4a3aac0d645 OK
2025/01/11 01:35:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:35:45 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/11 01:35:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:35:45 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2025/01/11 01:35:45 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:35:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:35:45 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/11 01:35:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:35:47 DEBUG : empty space: md5 = 2ff47267c02b5a14eb898cc25789d185 OK
2025/01/11 01:35:47 INFO  : empty space: Copied (replaced existing)
2025/01/11 01:35:47 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (5.99s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", 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-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:35:51 DEBUG : foo: md5 = 4cb5d07425b22da96e646ab9e55cebcd OK
2025/01/11 01:35:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:35:51 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/11 01:35:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:35:53 DEBUG : foo: md5 = 6f62ffba85ccdcf6c7d3afeb4958c9fd OK
2025/01/11 01:35:53 INFO  : foo: Copied (replaced existing)
2025/01/11 01:35:53 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (5.42s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:35:56 DEBUG : empty space: md5 = d4cfe94db6db60d0da25b3103a607d13 OK
2025/01/11 01:35:57 DEBUG : potato: Need to transfer - File not found at Destination
2025/01/11 01:35:57 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:35:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:35:57 DEBUG : empty space: Unchanged skipping
2025/01/11 01:35:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:35:58 DEBUG : potato: md5 = e293b7f9d3d630fbdb82a5090ebd1c6b OK
2025/01/11 01:35:58 INFO  : potato: Copied (new)
2025/01/11 01:35:58 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (5.89s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:36:02 DEBUG : potato: md5 = eaed07c233ec595e0c4a4664de3cd5e4 OK
2025/01/11 01:36:03 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2025/01/11 01:36:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:36:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:36:04 DEBUG : potato: md5 = 7e53e1b28629f53a92f78e3db58921ae OK
2025/01/11 01:36:04 INFO  : potato: Copied (replaced existing)
2025/01/11 01:36:04 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (5.12s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:36:07 DEBUG : potato: md5 = 9f4b17c044891b8d9e06c3e1ac02d6a8 OK
2025/01/11 01:36:08 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/11 01:36:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:36:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:36:09 DEBUG : potato: md5 = 5a3025c513a2e5caa961099d9fa39bb4 OK
2025/01/11 01:36:09 INFO  : potato: Copied (replaced existing)
2025/01/11 01:36:09 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (5.27s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:36:12 DEBUG : potato: md5 = 801a8c1e1f632d291e3e194594ed41e9 OK
2025/01/11 01:36:14 DEBUG : empty space: md5 = 1ede4eeac4bee7eece01b6032f450ad9 OK
2025/01/11 01:36:14 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/11 01:36:14 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2025/01/11 01:36:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:36:14 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:36:14 DEBUG : empty space: Unchanged skipping
2025/01/11 01:36:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:36:14 DEBUG : Waiting for deletions to finish
2025/01/11 01:36:14 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.48s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:36:18 DEBUG : potato: md5 = 2b912ff28422b332d9a1c9ac0e251368 OK
2025/01/11 01:36:20 DEBUG : empty space: md5 = 95d1f7dffbcd0dbe076fa8ee6a2a0fcb OK
2025/01/11 01:36:20 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/11 01:36:20 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:36:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:36:20 DEBUG : empty space: Unchanged skipping
2025/01/11 01:36:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:36:22 DEBUG : potato2: md5 = ebef74c8e3de6a1c9e5ca17d2280d7c7 OK
2025/01/11 01:36:22 INFO  : potato2: Copied (new)
2025/01/11 01:36:22 DEBUG : Waiting for deletions to finish
2025/01/11 01:36:22 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.01s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:36:27 DEBUG : b/potato: md5 = 23143167be846208a70d4c58b3e617ec OK
2025/01/11 01:36:29 DEBUG : c/non empty space: md5 = 4c7459436abce87c742f6f12a4e4f8c6 OK
2025/01/11 01:36:29 INFO  : d: Making directory
2025/01/11 01:36:30 INFO  : d/e: Making directory
2025/01/11 01:36:33 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/01/11 01:36:33 DEBUG : Added delayed dir = "c", newDst=c
2025/01/11 01:36:33 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:36:33 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/01/11 01:36:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:36:33 DEBUG : c/non empty space: Unchanged skipping
2025/01/11 01:36:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:36:35 DEBUG : a/potato2: md5 = 22818bc1578cb59946ee5fc5294cd27b OK
2025/01/11 01:36:35 INFO  : a/potato2: Copied (new)
2025/01/11 01:36:35 DEBUG : Waiting for deletions to finish
2025/01/11 01:36:36 INFO  : b/potato: Deleted
2025/01/11 01:36:36 INFO  : a: Set directory modification time (using DirSetModTime)
2025/01/11 01:36:36 INFO  : d/e: Removing directory
2025/01/11 01:36:37 INFO  : d: Removing directory
2025/01/11 01:36:37 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2025/01/11 01:36:38 INFO  : b: Removing directory
2025/01/11 01:36:38 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/01/11 01:36:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:36:41 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/01/11 01:36:42 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (18.83s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:36:46 DEBUG : b/potato: md5 = c45a53c63c6d09f921df7601e9c4a2c2 OK
2025/01/11 01:36:48 DEBUG : c/non empty space: md5 = a69b347dc354566ef155c0fca6640ea7 OK
2025/01/11 01:36:48 INFO  : d: Making directory
2025/01/11 01:36:50 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/01/11 01:36:50 DEBUG : Added delayed dir = "c", newDst=c
2025/01/11 01:36:50 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:36:50 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/01/11 01:36:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:36:50 DEBUG : c/non empty space: Unchanged skipping
2025/01/11 01:36:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:36:53 DEBUG : a/potato2: md5 = eb759d81757434bbf80e8a17510339c2 OK
2025/01/11 01:36:53 INFO  : a/potato2: Copied (new)
2025/01/11 01:36:53 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': not deleting files as there were IO errors
2025/01/11 01:36:53 INFO  : a: Set directory modification time (using DirSetModTime)
2025/01/11 01:36:53 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:36:57 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/01/11 01:36:58 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/01/11 01:36:58 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (16.39s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:37:01 DEBUG : potato: md5 = 3253bfc6924a65f4a78154a4e06b82ae OK
2025/01/11 01:37:03 DEBUG : empty space: md5 = e5914cd23f02caf9e1e08bc839e19296 OK
2025/01/11 01:37:03 DEBUG : Waiting for deletions to finish
2025/01/11 01:37:04 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/11 01:37:04 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:37:04 DEBUG : empty space: Unchanged skipping
2025/01/11 01:37:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:37:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:37:04 INFO  : potato: Deleted
2025/01/11 01:37:05 DEBUG : potato2: md5 = 72f212d4149852ff9a709c72777c9083 OK
2025/01/11 01:37:05 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (9.42s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:37:11 DEBUG : potato: md5 = 1222dc6ab6f7f8f519217298c3f08cfb OK
2025/01/11 01:37:12 DEBUG : empty space: md5 = f99e7ba5827f6ef3f8fc5f0fa3c7c54e OK
2025/01/11 01:37:13 DEBUG : Waiting for deletions to finish
2025/01/11 01:37:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:37:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:37:13 INFO  : potato: Deleted
2025/01/11 01:37:14 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/11 01:37:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:37:14 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:37:14 DEBUG : empty space: Unchanged skipping
2025/01/11 01:37:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:37:15 DEBUG : potato2: md5 = f3af0b862faf98f1085d6a9328b944a1 OK
2025/01/11 01:37:15 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (8.34s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:37:19 DEBUG : potato: md5 = 1e85cdb2272e4128b1566696d1c1cfd3 OK
2025/01/11 01:37:19 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/11 01:37:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:37:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:37:21 DEBUG : potato2: md5 = 15fd8c62fb48f78139693ed29db30fb4 OK
2025/01/11 01:37:21 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (5.53s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:37:24 DEBUG : potato2: md5 = 2a355cc33f6763de3219ed9ea00e4560 OK
2025/01/11 01:37:26 DEBUG : empty space: md5 = 73b29489ea6e52578b257490451d979a OK
2025/01/11 01:37:26 DEBUG : enormous: Excluded (Size Filter)
2025/01/11 01:37:26 DEBUG : enormous: Excluded
2025/01/11 01:37:26 DEBUG : potato2: Excluded (Size Filter)
2025/01/11 01:37:26 DEBUG : potato2: Excluded
2025/01/11 01:37:27 DEBUG : potato2: Excluded (Size Filter)
2025/01/11 01:37:27 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:37:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:37:27 DEBUG : empty space: Unchanged skipping
2025/01/11 01:37:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:37:27 DEBUG : Waiting for deletions to finish
2025/01/11 01:37:27 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:37:27 DEBUG : enormous: Excluded (Size Filter)
2025/01/11 01:37:27 DEBUG : enormous: Excluded
2025/01/11 01:37:27 DEBUG : potato2: Excluded (Size Filter)
2025/01/11 01:37:27 DEBUG : potato2: Excluded
2025/01/11 01:37:27 DEBUG : potato2: Excluded (Size Filter)
2025/01/11 01:37:27 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2025/01/11 01:37:27 DEBUG : empty space: Unchanged skipping
2025/01/11 01:37:27 DEBUG : Local file system at /tmp/rclone3400890828: Waiting for checks to finish
2025/01/11 01:37:27 DEBUG : Local file system at /tmp/rclone3400890828: Waiting for transfers to finish
2025/01/11 01:37:27 DEBUG : Waiting for deletions to finish
2025/01/11 01:37:27 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncWithExclude (6.60s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:37:31 DEBUG : potato2: md5 = 02b98026f7f1e45eec429f802dae3cda OK
2025/01/11 01:37:33 DEBUG : empty space: md5 = 52b4a78a949b07f8257f5aea8ac7b67c OK
2025/01/11 01:37:34 DEBUG : enormous: md5 = 769f099e2c29676b0c2b9942e7165dde OK
2025/01/11 01:37:34 DEBUG : enormous: Excluded (Size Filter)
2025/01/11 01:37:34 DEBUG : enormous: Excluded
2025/01/11 01:37:34 DEBUG : potato2: Excluded (Size Filter)
2025/01/11 01:37:34 DEBUG : potato2: Excluded
2025/01/11 01:37:35 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:37:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:37:35 DEBUG : empty space: Unchanged skipping
2025/01/11 01:37:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:37:35 DEBUG : Waiting for deletions to finish
2025/01/11 01:37:35 INFO  : potato2: Deleted
2025/01/11 01:37:35 INFO  : enormous: Deleted
2025/01/11 01:37:35 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:37:36 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2025/01/11 01:37:36 DEBUG : empty space: Unchanged skipping
2025/01/11 01:37:36 DEBUG : Local file system at /tmp/rclone3400890828: Waiting for checks to finish
2025/01/11 01:37:36 DEBUG : Local file system at /tmp/rclone3400890828: Waiting for transfers to finish
2025/01/11 01:37:36 DEBUG : Waiting for deletions to finish
2025/01/11 01:37:36 INFO  : enormous: Deleted
2025/01/11 01:37:36 INFO  : potato2: Deleted
2025/01/11 01:37:36 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (8.05s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:37:39 DEBUG : one: md5 = f22ec8d3a84478f0f6883654ebf22c77 OK
2025/01/11 01:37:41 DEBUG : two: md5 = 1425f60e5af499f1f41948194fa1a844 OK
2025/01/11 01:37:43 DEBUG : three: md5 = 98c026add86747ce525e6ca792310e77 OK
2025/01/11 01:37:44 DEBUG : four: md5 = cecfbc52cdf65675c7a0aae077d1323b OK
2025/01/11 01:37:45 DEBUG : five: Need to transfer - File not found at Destination
2025/01/11 01:37:45 DEBUG : four: Sizes differ (src 4 vs dst 8)
2025/01/11 01:37:45 DEBUG : one: Destination is newer than source, skipping
2025/01/11 01:37:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:37:45 DEBUG : three: Sizes identical
2025/01/11 01:37:45 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2025/01/11 01:37:45 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2025/01/11 01:37:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:37:46 DEBUG : two: md5 = dabaaf2317ba608bab9b4795c1dd9811 OK
2025/01/11 01:37:46 INFO  : two: Copied (replaced existing)
2025/01/11 01:37:46 DEBUG : four: md5 = 20f682189c04bd3861db745ed5cfe966 OK
2025/01/11 01:37:46 INFO  : four: Copied (replaced existing)
2025/01/11 01:37:47 DEBUG : five: md5 = f9b278581289f85a84fa7572a2932dcb OK
2025/01/11 01:37:47 INFO  : five: Copied (new)
2025/01/11 01:37:47 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (12.23s)
=== 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-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2025/01/11 01:37:50 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Ignoring --track-renames as the source and destination do not have a common hash
2025/01/11 01:37:50 DEBUG : potato: Need to transfer - File not found at Destination
2025/01/11 01:37:50 DEBUG : yam: Need to transfer - File not found at Destination
2025/01/11 01:37:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:37:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:37:52 DEBUG : yam: md5 = 7f6cc07c99cac28901a2585dcd214276 OK
2025/01/11 01:37:52 INFO  : yam: Copied (new)
2025/01/11 01:37:52 DEBUG : potato: md5 = 8248bde5ca005916be847e4fadeeb8dd OK
2025/01/11 01:37:52 INFO  : potato: Copied (new)
2025/01/11 01:37:52 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:37:52 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Ignoring --track-renames as the source and destination do not have a common hash
2025/01/11 01:37:52 DEBUG : yaml: Need to transfer - File not found at Destination
2025/01/11 01:37:52 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:37:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:37:52 DEBUG : potato: Unchanged skipping
2025/01/11 01:37:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:37:54 DEBUG : yaml: md5 = ffdd42f4ecf473863ed2b15aa64668f3 OK
2025/01/11 01:37:54 INFO  : yaml: Copied (new)
2025/01/11 01:37:54 DEBUG : Waiting for deletions to finish
2025/01/11 01:37:54 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (6.89s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2025/01/11 01:37:57 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Making map for --track-renames
2025/01/11 01:37:57 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Finished making map for --track-renames
2025/01/11 01:37:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:37:57 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/01/11 01:37:57 DEBUG : yam: Need to transfer - No matching file found at Destination
2025/01/11 01:37:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for renames to finish
2025/01/11 01:37:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:37:58 DEBUG : yam: md5 = 0286bccb77f91e5a6f81818bafc18e0c OK
2025/01/11 01:37:58 INFO  : yam: Copied (new)
2025/01/11 01:37:59 DEBUG : potato: md5 = 329ec98795a9e698e2a11ff12cb0c4ec OK
2025/01/11 01:37:59 INFO  : potato: Copied (new)
2025/01/11 01:37:59 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:37:59 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:37:59 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Making map for --track-renames
2025/01/11 01:37:59 DEBUG : potato: Unchanged skipping
2025/01/11 01:37:59 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Finished making map for --track-renames
2025/01/11 01:37:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:37:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for renames to finish
2025/01/11 01:38:00 INFO  : yam: Moved (server-side) to: yaml
2025/01/11 01:38:00 INFO  : yaml: Renamed from "yam"
2025/01/11 01:38:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:38:00 DEBUG : Waiting for deletions to finish
2025/01/11 01:38:00 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (5.64s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2025/01/11 01:38:03 DEBUG : Added delayed dir = "sub", newDst=<nil>
2025/01/11 01:38:03 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Making map for --track-renames
2025/01/11 01:38:03 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Finished making map for --track-renames
2025/01/11 01:38:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:38:03 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/01/11 01:38:03 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2025/01/11 01:38:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for renames to finish
2025/01/11 01:38:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:38:05 DEBUG : sub/yam: md5 = 53daef3b912714c1e5177b5ce0a361af OK
2025/01/11 01:38:05 INFO  : sub/yam: Copied (new)
2025/01/11 01:38:05 DEBUG : potato: md5 = 09ac3da5a062ac5a2b6d111d08cfd986 OK
2025/01/11 01:38:05 INFO  : potato: Copied (new)
2025/01/11 01:38:05 DEBUG : Waiting for deletions to finish
2025/01/11 01:38:06 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:38:07 DEBUG : Added delayed dir = "sub", newDst=sub
2025/01/11 01:38:07 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:38:07 DEBUG : potato: Unchanged skipping
2025/01/11 01:38:07 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Making map for --track-renames
2025/01/11 01:38:07 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Finished making map for --track-renames
2025/01/11 01:38:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:38:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for renames to finish
2025/01/11 01:38:08 INFO  : sub/yam: Moved (server-side) to: yam
2025/01/11 01:38:08 INFO  : yam: Renamed from "sub/yam"
2025/01/11 01:38:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:38:08 DEBUG : Waiting for deletions to finish
2025/01/11 01:38:08 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.45s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:38:12 DEBUG : Creating backend with remote "/tmp/rclone3400890828/dir1"
2025/01/11 01:38:12 DEBUG : Config file has changed externally - reloading
2025/01/11 01:38:12 DEBUG : Creating backend with remote "/tmp/rclone3400890828/dir2"
2025/01/11 01:38:12 DEBUG : Local file system at /tmp/rclone3400890828/dir2: Using server-side directory move
2025/01/11 01:38:12 INFO  : Local file system at /tmp/rclone3400890828/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/01/11 01:38:12 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/01/11 01:38:12 INFO  : file1.txt: Moved (server-side)
2025/01/11 01:38:12 DEBUG : Local file system at /tmp/rclone3400890828/dir2: Waiting for checks to finish
2025/01/11 01:38:12 DEBUG : Local file system at /tmp/rclone3400890828/dir2: Waiting for transfers to finish
--- PASS: TestServerSideMoveLocal (0.47s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:38:12 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/01/11 01:38:12 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/11 01:38:12 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/11 01:38:12 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/01/11 01:38:12 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/01/11 01:38:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:38:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:38:16 DEBUG : sub dir/hello world: md5 = 4ca8497b82eade6baa248f96b5abf486 OK
2025/01/11 01:38:16 INFO  : sub dir/hello world: Copied (new)
2025/01/11 01:38:16 INFO  : sub dir/hello world: Deleted
2025/01/11 01:38:18 DEBUG : nested/sub dir/file: md5 = 135600cc40b8844fd0f0d5c6e4c4f370 OK
2025/01/11 01:38:18 INFO  : nested/sub dir/file: Copied (new)
2025/01/11 01:38:18 INFO  : nested/sub dir/file: Deleted
2025/01/11 01:38:19 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/01/11 01:38:19 INFO  : nested: Set directory modification time (using DirSetModTime)
2025/01/11 01:38:19 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/11 01:38:19 INFO  : sub dir: Removing directory
2025/01/11 01:38:19 INFO  : nested/sub dir: Removing directory
2025/01/11 01:38:19 INFO  : nested: Removing directory
2025/01/11 01:38:19 DEBUG : Local file system at /tmp/rclone3400890828: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:38:22 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/11 01:38:23 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2025/01/11 01:38:24 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (13.04s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:38:26 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/01/11 01:38:26 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/11 01:38:26 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/11 01:38:26 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/01/11 01:38:26 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/01/11 01:38:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:38:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:38:28 DEBUG : sub dir/hello world: md5 = bb9bf7194ccf8448ed873b421fdc43b0 OK
2025/01/11 01:38:28 INFO  : sub dir/hello world: Copied (new)
2025/01/11 01:38:28 INFO  : sub dir/hello world: Deleted
2025/01/11 01:38:30 DEBUG : nested/sub dir/file: md5 = 1d71b91ac13ab6aa90876c8e2767ea51 OK
2025/01/11 01:38:30 INFO  : nested/sub dir/file: Copied (new)
2025/01/11 01:38:30 INFO  : nested/sub dir/file: Deleted
2025/01/11 01:38:31 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/01/11 01:38:31 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/11 01:38:32 INFO  : nested: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:38:34 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/11 01:38:35 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2025/01/11 01:38:36 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (12.07s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:38:38 DEBUG : existing: Need to transfer - File not found at Destination
2025/01/11 01:38:38 DEBUG : existing-b: Need to transfer - File not found at Destination
2025/01/11 01:38:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:38:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:38:39 DEBUG : existing: md5 = 75c5e9647a23038e34e718d670cff4c1 OK
2025/01/11 01:38:39 INFO  : existing: Copied (new)
2025/01/11 01:38:39 INFO  : existing: Deleted
2025/01/11 01:38:39 DEBUG : existing-b: md5 = e80922ae16bd25e1298176197d487f4c OK
2025/01/11 01:38:39 INFO  : existing-b: Copied (new)
2025/01/11 01:38:39 INFO  : existing-b: Deleted
2025/01/11 01:38:40 DEBUG : existing: Destination exists, skipping
2025/01/11 01:38:40 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2025/01/11 01:38:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:38:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:38:40 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (4.55s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:38:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wilufan2qefa"
2025/01/11 01:38:42 DEBUG : Creating backend with remote "TestDrive:crypt/l401ps24hjol4jne3q3ke3uc9r56637lrviijv6q62471mqvcf4g"
2025/01/11 01:38:45 DEBUG : potato2: md5 = 1ed080054459348c7527b041094a0d12 OK
2025/01/11 01:38:46 DEBUG : empty space: md5 = 347c32983ec395834b75666e7036afc1 OK
2025/01/11 01:38:48 DEBUG : potato3: md5 = a4e90234b2a9667eb8866fddc920c5db OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo' -> Encrypted drive 'TestCryptDrive:rclone-test-wilufan2qefa'
2025/01/11 01:38:51 DEBUG : empty space: md5 = 43aa52f326040a8e5ce5329fe1e2d211 OK
2025/01/11 01:38:53 DEBUG : potato3: md5 = 5f9acf5c99f02e9799d1b48bbf57dd82 OK
2025/01/11 01:38:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wilufan2qefa': Using server-side directory move
2025/01/11 01:38:53 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-wilufan2qefa': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/01/11 01:38:53 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/11 01:38:53 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/01/11 01:38:53 DEBUG : empty space: Unchanged skipping
2025/01/11 01:38:53 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/01/11 01:38:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wilufan2qefa': Waiting for checks to finish
2025/01/11 01:38:54 INFO  : potato3: Deleted
2025/01/11 01:38:54 INFO  : empty space: Deleted
2025/01/11 01:38:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wilufan2qefa': Waiting for transfers to finish
2025/01/11 01:38:54 INFO  : potato2: Moved (server-side)
2025/01/11 01:38:55 INFO  : potato3: Moved (server-side)
2025/01/11 01:38:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-seboxuj5buno"
2025/01/11 01:38:55 DEBUG : Creating backend with remote "TestDrive:crypt/b3fhiuid4rqvfgaet6sg5mrv32kus1haf33qebd3lstjmha6qcmg"
2025/01/11 01:38:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-seboxuj5buno': Using server-side directory move
2025/01/11 01:38:57 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-seboxuj5buno': Server side directory move succeeded
2025/01/11 01:38:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-seboxuj5buno': Purge remote
2025/01/11 01:38:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wilufan2qefa': Purge remote
2025/01/11 01:38:59 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (17.53s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:38:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sacamuz4nalo"
2025/01/11 01:38:59 DEBUG : Creating backend with remote "TestDrive:crypt/qfcjnekpfd9i43n5m5t3ukcq9h4qs2sirbd4algguvgbss5u50ng"
2025/01/11 01:39:02 DEBUG : potato2: md5 = dfdba9e1f53acb71d160736c12b62e69 OK
2025/01/11 01:39:04 DEBUG : empty space: md5 = 1035b28ad8229434ca62ee6949b2b40a OK
2025/01/11 01:39:06 DEBUG : potato3: md5 = 61c26d93392cecd5cc623817f591b16a OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo' -> Encrypted drive 'TestCryptDrive:rclone-test-sacamuz4nalo'
2025/01/11 01:39:08 DEBUG : empty space: md5 = 65e32d72e49867387fe7ddea3159c8d3 OK
2025/01/11 01:39:10 DEBUG : potato3: md5 = 4b1e17cdee47c09c3f5a240ec9b44c3c OK
2025/01/11 01:39:11 DEBUG : empty space: Excluded (Size Filter)
2025/01/11 01:39:11 DEBUG : empty space: Excluded (Size Filter)
2025/01/11 01:39:11 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/11 01:39:11 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/01/11 01:39:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sacamuz4nalo': Waiting for checks to finish
2025/01/11 01:39:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sacamuz4nalo': Waiting for transfers to finish
2025/01/11 01:39:11 INFO  : potato3: Deleted
2025/01/11 01:39:12 INFO  : potato2: Moved (server-side)
2025/01/11 01:39:12 INFO  : potato3: Moved (server-side)
2025/01/11 01:39:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vasohoc5reye"
2025/01/11 01:39:13 DEBUG : Creating backend with remote "TestDrive:crypt/suvj1h0mkk9dh4rasudinu8ijfq7596dvf8tq06a1g17hb8lvacg"
2025/01/11 01:39:14 DEBUG : empty space: Excluded (Size Filter)
2025/01/11 01:39:14 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/11 01:39:14 DEBUG : potato3: Need to transfer - File not found at Destination
2025/01/11 01:39:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vasohoc5reye': Waiting for checks to finish
2025/01/11 01:39:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vasohoc5reye': Waiting for transfers to finish
2025/01/11 01:39:16 INFO  : potato3: Moved (server-side)
2025/01/11 01:39:17 INFO  : potato2: Moved (server-side)
2025/01/11 01:39:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vasohoc5reye': Purge remote
2025/01/11 01:39:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sacamuz4nalo': Purge remote
--- PASS: TestServerSideMoveWithFilter (19.77s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:39:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gapaxap6yija"
2025/01/11 01:39:19 DEBUG : Creating backend with remote "TestDrive:crypt/tuo2p5pnp58hbhtcakg7vtnpdvobdf2vcgh0gdc265p2i6lsonp0"
2025/01/11 01:39:22 DEBUG : potato2: md5 = 605cd114dc660b7812e15e132124c388 OK
2025/01/11 01:39:24 DEBUG : empty space: md5 = 087089ee9aeddde926e52cf7b8c7591a OK
2025/01/11 01:39:25 DEBUG : potato3: md5 = 857adb1201ad1448300931085e90e8f2 OK
2025/01/11 01:39:25 INFO  : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo' -> Encrypted drive 'TestCryptDrive:rclone-test-gapaxap6yija'
2025/01/11 01:39:30 DEBUG : empty space: md5 = 27f06341002f23b31bb9d7d5bf6b1c6f OK
2025/01/11 01:39:32 DEBUG : potato3: md5 = 4298386edc165489f38fedbd9eb58979 OK
2025/01/11 01:39:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gapaxap6yija': Using server-side directory move
2025/01/11 01:39:32 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gapaxap6yija': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/01/11 01:39:32 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/11 01:39:32 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2025/01/11 01:39:32 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/01/11 01:39:32 DEBUG : empty space: Unchanged skipping
2025/01/11 01:39:32 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/01/11 01:39:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gapaxap6yija': Waiting for checks to finish
2025/01/11 01:39:33 INFO  : potato3: Deleted
2025/01/11 01:39:33 INFO  : empty space: Deleted
2025/01/11 01:39:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gapaxap6yija': Waiting for transfers to finish
2025/01/11 01:39:33 INFO  : potato2: Moved (server-side)
2025/01/11 01:39:34 INFO  : potato3: Moved (server-side)
2025/01/11 01:39:34 INFO  : tomatoDir: Removing directory
2025/01/11 01:39:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': deleted 1 directories
2025/01/11 01:39:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yidetoq4suja"
2025/01/11 01:39:35 DEBUG : Creating backend with remote "TestDrive:crypt/7ccmi8iobi33cjo7bk41o4cr0fpr0628vr5hi5gf8eshptrlbvn0"
2025/01/11 01:39:36 INFO  : tomatoDir: Making directory
2025/01/11 01:39:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yidetoq4suja': Using server-side directory move
2025/01/11 01:39:38 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-yidetoq4suja': Server side directory move succeeded
2025/01/11 01:39:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yidetoq4suja': Purge remote
2025/01/11 01:39:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gapaxap6yija': Purge remote
2025/01/11 01:39:40 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (21.72s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.44s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:39:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/rclone-sync-test"
2025/01/11 01:39:41 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncOverlap (3.69s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:39:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/rclone-sync-test"
2025/01/11 01:39:45 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2025/01/11 01:39:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/rclone-sync-test-include/layer2"
2025/01/11 01:39:48 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2025/01/11 01:39:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/rclone-sync-test-ignore-file"
2025/01/11 01:39:51 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2025/01/11 01:39:55 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 736d4aa447b31408d781719b0956e433 OK
2025/01/11 01:39:57 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/01/11 01:39:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/rclone-sync-test': Waiting for checks to finish
2025/01/11 01:39:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/rclone-sync-test': Waiting for transfers to finish
2025/01/11 01:39:57 DEBUG : Waiting for deletions to finish
2025/01/11 01:39:57 INFO  : There was nothing to transfer
2025/01/11 01:39:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:39:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:39:59 DEBUG : Waiting for deletions to finish
2025/01/11 01:39:59 INFO  : rclone-sync-test-include: Removing directory
2025/01/11 01:39:59 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/01/11 01:39:59 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2025/01/11 01:39:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': failed to delete 1 directories
2025/01/11 01:39:59 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:40:01 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/01/11 01:40:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/rclone-sync-test-include/layer2': Waiting for checks to finish
2025/01/11 01:40:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/rclone-sync-test-include/layer2': Waiting for transfers to finish
2025/01/11 01:40:01 DEBUG : Waiting for deletions to finish
2025/01/11 01:40:01 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:40:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:40:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:40:03 DEBUG : Waiting for deletions to finish
2025/01/11 01:40:03 INFO  : rclone-sync-test-include: Removing directory
2025/01/11 01:40:03 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/01/11 01:40:03 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2025/01/11 01:40:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': failed to delete 1 directories
2025/01/11 01:40:03 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:40:05 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/01/11 01:40:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/rclone-sync-test-ignore-file': Waiting for checks to finish
2025/01/11 01:40:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/rclone-sync-test-ignore-file': Waiting for transfers to finish
2025/01/11 01:40:05 DEBUG : Waiting for deletions to finish
2025/01/11 01:40:05 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:40:07 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/01/11 01:40:08 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (32.97s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:40:18 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/dst"
2025/01/11 01:40:18 DEBUG : Config file has changed externally - reloading
2025/01/11 01:40:18 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/11 01:40:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/CompareDest"
2025/01/11 01:40:20 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/gveqi14airsml4bgu7krj116o8"
2025/01/11 01:40:22 DEBUG : one: Need to transfer - File not found at Destination
2025/01/11 01:40:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for checks to finish
2025/01/11 01:40:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for transfers to finish
2025/01/11 01:40:24 DEBUG : one: md5 = e9589a6a5b89d6ddb36b11a3a4094b31 OK
2025/01/11 01:40:24 INFO  : one: Copied (new)
2025/01/11 01:40:24 DEBUG : Waiting for deletions to finish
2025/01/11 01:40:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for checks to finish
2025/01/11 01:40:26 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/11 01:40:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for transfers to finish
2025/01/11 01:40:27 DEBUG : one: md5 = 8fde75c35dc68ce3e4b5cfb15a0be5eb OK
2025/01/11 01:40:27 INFO  : one: Copied (replaced existing)
2025/01/11 01:40:27 DEBUG : Waiting for deletions to finish
2025/01/11 01:40:30 DEBUG : dst/one: md5 = 9b0c2be018b5ac27d9b3f63b0db0f496 OK
2025/01/11 01:40:32 DEBUG : CompareDest/one: md5 = c1fcfe6d0b1dba3da38f99d75128647f OK
2025/01/11 01:40:33 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/11 01:40:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for checks to finish
2025/01/11 01:40:34 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:40:34 DEBUG : one: Destination found in --compare-dest, skipping
2025/01/11 01:40:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for transfers to finish
2025/01/11 01:40:34 DEBUG : Waiting for deletions to finish
2025/01/11 01:40:34 INFO  : There was nothing to transfer
2025/01/11 01:40:36 DEBUG : CompareDest/two: md5 = aabb5c3bcdacbaba6a3e3d7575367841 OK
2025/01/11 01:40:37 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:40:37 DEBUG : two: Destination found in --compare-dest, skipping
2025/01/11 01:40:37 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/11 01:40:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for checks to finish
2025/01/11 01:40:37 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:40:37 DEBUG : one: Destination found in --compare-dest, skipping
2025/01/11 01:40:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for transfers to finish
2025/01/11 01:40:37 DEBUG : Waiting for deletions to finish
2025/01/11 01:40:37 INFO  : There was nothing to transfer
2025/01/11 01:40:38 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:40:38 DEBUG : two: Destination found in --compare-dest, skipping
2025/01/11 01:40:38 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/11 01:40:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for checks to finish
2025/01/11 01:40:38 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:40:38 DEBUG : one: Destination found in --compare-dest, skipping
2025/01/11 01:40:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for transfers to finish
2025/01/11 01:40:38 DEBUG : Waiting for deletions to finish
2025/01/11 01:40:38 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2025/01/11 01:40:40 DEBUG : two: Sizes differ (src 5 vs dst 3)
2025/01/11 01:40:40 DEBUG : two: Need to transfer - File not found at Destination
2025/01/11 01:40:40 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/11 01:40:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for checks to finish
2025/01/11 01:40:40 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:40:40 DEBUG : one: Destination found in --compare-dest, skipping
2025/01/11 01:40:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for transfers to finish
2025/01/11 01:40:42 DEBUG : two: md5 = 08140517c45fbf3e4d4d994295b5dbc0 OK
2025/01/11 01:40:42 INFO  : two: Copied (new)
2025/01/11 01:40:42 DEBUG : Waiting for deletions to finish
2025/01/11 01:40:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/11 01:40:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/11 01:40:46 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/11 01:40:46 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCompareDest (29.36s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:40:50 DEBUG : pre-dest1/1: md5 = 6dda529537f74669bacb1152408f1e80 OK
2025/01/11 01:40:53 DEBUG : pre-dest2/2: md5 = 5de2897da0886bfc4f83b050fd90b355 OK
2025/01/11 01:40:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/dest"
2025/01/11 01:40:54 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/rg03c1jvnehrrc617i0lnqjddc"
2025/01/11 01:40:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/pre-dest1"
2025/01/11 01:40:55 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/bbnblvh6k061ssopqrp18kd7gc"
2025/01/11 01:40:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/pre-dest2"
2025/01/11 01:40:56 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/dgicm1h6b5ejvlltm8eeif0bnk"
2025/01/11 01:40:57 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:40:57 DEBUG : 1: Destination found in --compare-dest, skipping
2025/01/11 01:40:58 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:40:58 DEBUG : 2: Destination found in --compare-dest, skipping
2025/01/11 01:40:58 DEBUG : 3: Need to transfer - File not found at Destination
2025/01/11 01:40:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dest': Waiting for checks to finish
2025/01/11 01:40:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dest': Waiting for transfers to finish
2025/01/11 01:41:01 DEBUG : 3: md5 = 93dbd163b2afe0dcfb038fc362b52ba1 OK
2025/01/11 01:41:01 INFO  : 3: Copied (new)
2025/01/11 01:41:01 DEBUG : Waiting for deletions to finish
2025/01/11 01:41:04 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2025/01/11 01:41:05 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2025/01/11 01:41:06 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (19.52s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:41:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/dst"
2025/01/11 01:41:07 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/11 01:41:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/CopyDest"
2025/01/11 01:41:08 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/d09o6po3f7bm6ce32vdgs8h9ls"
2025/01/11 01:41:11 DEBUG : one: Need to transfer - File not found at Destination
2025/01/11 01:41:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for checks to finish
2025/01/11 01:41:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for transfers to finish
2025/01/11 01:41:13 DEBUG : one: md5 = 6f0e15b2304e8a2cea3952448f101f55 OK
2025/01/11 01:41:13 INFO  : one: Copied (new)
2025/01/11 01:41:13 DEBUG : Waiting for deletions to finish
2025/01/11 01:41:14 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/11 01:41:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for checks to finish
2025/01/11 01:41:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for transfers to finish
2025/01/11 01:41:16 DEBUG : one: md5 = a4e59c1f30c6df554a6d5aeeba03b21f OK
2025/01/11 01:41:16 INFO  : one: Copied (replaced existing)
2025/01/11 01:41:16 DEBUG : Waiting for deletions to finish
2025/01/11 01:41:18 DEBUG : dst/one: md5 = f878316de67fbe04faa221295c5b87c4 OK
2025/01/11 01:41:21 DEBUG : CopyDest/one: md5 = b4ca2be4971ea34030f00691ce14ad69 OK
2025/01/11 01:41:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/BackupDir"
2025/01/11 01:41:21 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/s6dbk3lfi7c9kfvo6j7bla9m0g"
2025/01/11 01:41:23 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/11 01:41:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for checks to finish
2025/01/11 01:41:24 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:41:24 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/11 01:41:26 INFO  : one: Moved (server-side)
2025/01/11 01:41:27 INFO  : one: Copied (server-side copy)
2025/01/11 01:41:27 DEBUG : one: Destination found in --copy-dest, using server-side copy
2025/01/11 01:41:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for transfers to finish
2025/01/11 01:41:27 DEBUG : Waiting for deletions to finish
2025/01/11 01:41:29 DEBUG : CopyDest/two: md5 = 82ed7175d22733087ed892cab45dd4db OK
2025/01/11 01:41:30 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:41:32 INFO  : two: Copied (server-side copy)
2025/01/11 01:41:32 DEBUG : two: Destination found in --copy-dest, using server-side copy
2025/01/11 01:41:32 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:41:32 DEBUG : one: Unchanged skipping
2025/01/11 01:41:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for checks to finish
2025/01/11 01:41:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for transfers to finish
2025/01/11 01:41:32 DEBUG : Waiting for deletions to finish
2025/01/11 01:41:32 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:41:32 DEBUG : one: Unchanged skipping
2025/01/11 01:41:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for checks to finish
2025/01/11 01:41:32 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:41:32 DEBUG : two: Unchanged skipping
2025/01/11 01:41:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for transfers to finish
2025/01/11 01:41:32 DEBUG : Waiting for deletions to finish
2025/01/11 01:41:32 INFO  : There was nothing to transfer
2025/01/11 01:41:34 DEBUG : CopyDest/three: md5 = 3d6ebf77ec75236424b122c6be0d8cfd OK
2025/01/11 01:41:35 DEBUG : three: Sizes differ (src 7 vs dst 5)
2025/01/11 01:41:35 DEBUG : three: Destination not found in --copy-dest
2025/01/11 01:41:35 DEBUG : three: Need to transfer - File not found at Destination
2025/01/11 01:41:35 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:41:35 DEBUG : one: Unchanged skipping
2025/01/11 01:41:35 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/11 01:41:35 DEBUG : two: Unchanged skipping
2025/01/11 01:41:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for checks to finish
2025/01/11 01:41:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for transfers to finish
2025/01/11 01:41:37 DEBUG : three: md5 = 4ac7c5ed64f1c43f58546915d135ee19 OK
2025/01/11 01:41:37 INFO  : three: Copied (new)
2025/01/11 01:41:37 DEBUG : Waiting for deletions to finish
2025/01/11 01:41:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2025/01/11 01:41:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/11 01:41:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/11 01:41:43 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/11 01:41:43 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2025/01/11 01:41:43 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/11 01:41:44 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (37.65s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:41:47 DEBUG : dst/one: md5 = b53a0cea0895adc60138f1b9e42d41f1 OK
2025/01/11 01:41:49 DEBUG : dst/two: md5 = 30762cb4474df63a0287fd9cc44fbc8c OK
2025/01/11 01:41:51 DEBUG : dst/three.txt: md5 = 555deadec852c3f3dc99c6f4bee811f0 OK
2025/01/11 01:41:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/dst"
2025/01/11 01:41:51 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/11 01:41:52 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/backup"
2025/01/11 01:41:52 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/1nrff024r7pq65ecp72fc28jb0"
2025/01/11 01:41:53 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/11 01:41:53 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:41:53 DEBUG : two: Unchanged skipping
2025/01/11 01:41:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for checks to finish
2025/01/11 01:41:56 INFO  : one: Moved (server-side)
2025/01/11 01:41:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for transfers to finish
2025/01/11 01:41:57 DEBUG : one: md5 = f735cd08e7450b3174338cacf7af2f25 OK
2025/01/11 01:41:57 INFO  : one: Copied (new)
2025/01/11 01:41:57 DEBUG : Waiting for deletions to finish
2025/01/11 01:41:59 INFO  : three.txt: Moved (server-side)
2025/01/11 01:41:59 INFO  : three.txt: Moved into backup dir
2025/01/11 01:42:01 DEBUG : dst/three.txt: md5 = a7380758e7251fa76203db45435980d0 OK
2025/01/11 01:42:02 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/11 01:42:02 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:42:02 DEBUG : two: Unchanged skipping
2025/01/11 01:42:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for checks to finish
2025/01/11 01:42:02 INFO  : one: Deleted
2025/01/11 01:42:03 INFO  : one: Moved (server-side)
2025/01/11 01:42:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for transfers to finish
2025/01/11 01:42:05 DEBUG : one: md5 = 34d7099f4e856ae05e5e1d73c5fa7876 OK
2025/01/11 01:42:05 INFO  : one: Copied (new)
2025/01/11 01:42:05 DEBUG : Waiting for deletions to finish
2025/01/11 01:42:06 INFO  : three.txt: Deleted
2025/01/11 01:42:07 INFO  : three.txt: Moved (server-side)
2025/01/11 01:42:07 INFO  : three.txt: Moved into backup dir
2025/01/11 01:42:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/11 01:42:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/11 01:42:11 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/11 01:42:11 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/01/11 01:42:11 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/01/11 01:42:11 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncBackupDir (27.18s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:42:14 DEBUG : dst/one: md5 = 268c4593516926ae4d70a707840e3705 OK
2025/01/11 01:42:16 DEBUG : dst/two: md5 = 0fe1f164d00662555b98a77f35cf6ab0 OK
2025/01/11 01:42:18 DEBUG : dst/three.txt: md5 = 5eb45f8a9ca6900b05524e83e24bf5a4 OK
2025/01/11 01:42:18 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/dst"
2025/01/11 01:42:18 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/11 01:42:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/backup"
2025/01/11 01:42:19 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/1nrff024r7pq65ecp72fc28jb0"
2025/01/11 01:42:21 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/11 01:42:21 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:42:21 DEBUG : two: Unchanged skipping
2025/01/11 01:42:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for checks to finish
2025/01/11 01:42:23 INFO  : one: Moved (server-side) to: one.bak
2025/01/11 01:42:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for transfers to finish
2025/01/11 01:42:25 DEBUG : one: md5 = 902eb4b7ef324db8df809c5bc2eb6e3b OK
2025/01/11 01:42:25 INFO  : one: Copied (new)
2025/01/11 01:42:25 DEBUG : Waiting for deletions to finish
2025/01/11 01:42:26 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/11 01:42:26 INFO  : three.txt: Moved into backup dir
2025/01/11 01:42:28 DEBUG : dst/three.txt: md5 = 5c77e308a041871c330bbe0d6264ec84 OK
2025/01/11 01:42:29 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/11 01:42:29 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:42:29 DEBUG : two: Unchanged skipping
2025/01/11 01:42:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for checks to finish
2025/01/11 01:42:29 INFO  : one.bak: Deleted
2025/01/11 01:42:30 INFO  : one: Moved (server-side) to: one.bak
2025/01/11 01:42:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for transfers to finish
2025/01/11 01:42:32 DEBUG : one: md5 = e1e987068986f609de7f28a5f9035bbd OK
2025/01/11 01:42:32 INFO  : one: Copied (new)
2025/01/11 01:42:32 DEBUG : Waiting for deletions to finish
2025/01/11 01:42:33 INFO  : three.txt.bak: Deleted
2025/01/11 01:42:34 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/11 01:42:34 INFO  : three.txt: Moved into backup dir
2025/01/11 01:42:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/11 01:42:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/11 01:42:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/11 01:42:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/11 01:42:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/11 01:42:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncBackupDirWithSuffix (27.32s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:42:42 DEBUG : dst/one: md5 = cce23e10510d4431c5b09b2d9d9dd407 OK
2025/01/11 01:42:43 DEBUG : dst/two: md5 = 9166ffa85b636cec9c3ffddf785ea6f0 OK
2025/01/11 01:42:45 DEBUG : dst/three.txt: md5 = 8982d94b8a31afa7ca9cb23c139a8ff7 OK
2025/01/11 01:42:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/dst"
2025/01/11 01:42:46 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/11 01:42:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/backup"
2025/01/11 01:42:46 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/1nrff024r7pq65ecp72fc28jb0"
2025/01/11 01:42:48 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/11 01:42:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for checks to finish
2025/01/11 01:42:48 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:42:48 DEBUG : two: Unchanged skipping
2025/01/11 01:42:50 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/01/11 01:42:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for transfers to finish
2025/01/11 01:42:52 DEBUG : one: md5 = a8981c5245ff6f31081b01f056bc0838 OK
2025/01/11 01:42:52 INFO  : one: Copied (new)
2025/01/11 01:42:52 DEBUG : Waiting for deletions to finish
2025/01/11 01:42:54 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/01/11 01:42:54 INFO  : three.txt: Moved into backup dir
2025/01/11 01:42:57 DEBUG : dst/three.txt: md5 = 9af05242f6f4fc3a7861c6a3c3f33dc0 OK
2025/01/11 01:42:58 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/11 01:42:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for checks to finish
2025/01/11 01:42:58 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:42:58 DEBUG : two: Unchanged skipping
2025/01/11 01:42:58 INFO  : one-2019-01-01: Deleted
2025/01/11 01:42:59 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/01/11 01:42:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for transfers to finish
2025/01/11 01:43:01 DEBUG : one: md5 = c101171e1a21c3fd685adc66fb830293 OK
2025/01/11 01:43:01 INFO  : one: Copied (new)
2025/01/11 01:43:01 DEBUG : Waiting for deletions to finish
2025/01/11 01:43:02 INFO  : three-2019-01-01.txt: Deleted
2025/01/11 01:43:03 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/01/11 01:43:03 INFO  : three.txt: Moved into backup dir
2025/01/11 01:43:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/11 01:43:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/11 01:43:07 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/01/11 01:43:07 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/01/11 01:43:07 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/01/11 01:43:07 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (28.63s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:43:10 DEBUG : dst/one: md5 = 15b5acd00d0b8f542f0476370048f3e7 OK
2025/01/11 01:43:12 DEBUG : dst/two: md5 = 42dc9c7772fffd058f6e9dca3dce63af OK
2025/01/11 01:43:14 DEBUG : dst/three.txt: md5 = 28c9548aff66364871a2239812d89a6f OK
2025/01/11 01:43:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/dst"
2025/01/11 01:43:14 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/11 01:43:15 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/11 01:43:15 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:43:15 DEBUG : two: Unchanged skipping
2025/01/11 01:43:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for checks to finish
2025/01/11 01:43:16 INFO  : one: Moved (server-side) to: one.bak
2025/01/11 01:43:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for transfers to finish
2025/01/11 01:43:18 DEBUG : one: md5 = aff588007a10d97d6cf09c48caae0adc OK
2025/01/11 01:43:18 INFO  : one: Copied (new)
2025/01/11 01:43:18 DEBUG : Waiting for deletions to finish
2025/01/11 01:43:19 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/11 01:43:19 INFO  : three.txt: Moved into backup dir
2025/01/11 01:43:21 DEBUG : dst/three.txt: md5 = 2c4f3c647f4d538870e3db66dc1ffc1f OK
2025/01/11 01:43:22 DEBUG : three.txt.bak: Excluded (Path Filter)
2025/01/11 01:43:22 DEBUG : one.bak: Excluded (Path Filter)
2025/01/11 01:43:22 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/11 01:43:22 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:43:22 DEBUG : two: Unchanged skipping
2025/01/11 01:43:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for checks to finish
2025/01/11 01:43:22 INFO  : one.bak: Deleted
2025/01/11 01:43:23 INFO  : one: Moved (server-side) to: one.bak
2025/01/11 01:43:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo/dst': Waiting for transfers to finish
2025/01/11 01:43:25 DEBUG : one: md5 = 911a329636b0ff46ebcb8383593ae8bc OK
2025/01/11 01:43:25 INFO  : one: Copied (new)
2025/01/11 01:43:25 DEBUG : Waiting for deletions to finish
2025/01/11 01:43:25 INFO  : three.txt.bak: Deleted
2025/01/11 01:43:26 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/11 01:43:26 INFO  : three.txt: Moved into backup dir
2025/01/11 01:43:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/11 01:43:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/11 01:43:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/11 01:43:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/11 01:43:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/11 01:43:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncBackupDirSuffixOnly (22.66s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:43:33 DEBUG : dst/one: md5 = 0a7e636a7b94267a43aa0aadacfa3fec OK
2025/01/11 01:43:35 DEBUG : dst/two: md5 = 52bd0e9b3d0980ff917f3f4931b36179 OK
2025/01/11 01:43:36 DEBUG : dst/three.txt: md5 = 6faf7f48fa105c2cbf3dc74f6b0c4968 OK
2025/01/11 01:43:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/dst"
2025/01/11 01:43:37 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/11 01:43:38 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/11 01:43:39 INFO  : one: Moved (server-side) to: one.bak
2025/01/11 01:43:41 DEBUG : one: md5 = 935c5898514f99258bbff3ad4de6a8e5 OK
2025/01/11 01:43:41 INFO  : one: Copied (new)
2025/01/11 01:43:41 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:43:41 DEBUG : two: Unchanged skipping
2025/01/11 01:43:41 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/01/11 01:43:42 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/11 01:43:43 DEBUG : three.txt: md5 = 5e9797c7fe8ae5e9d0a897c3f4cb6882 OK
2025/01/11 01:43:43 INFO  : three.txt: Copied (new)
2025/01/11 01:43:44 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/11 01:43:45 INFO  : one.bak: Deleted
2025/01/11 01:43:46 INFO  : one: Moved (server-side) to: one.bak
2025/01/11 01:43:47 DEBUG : one: md5 = 363297f8b6b38b092a110cc3a8a2b6e5 OK
2025/01/11 01:43:47 INFO  : one: Copied (new)
2025/01/11 01:43:48 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:43:48 DEBUG : two: Unchanged skipping
2025/01/11 01:43:48 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/01/11 01:43:49 INFO  : three.txt.bak: Deleted
2025/01/11 01:43:49 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/11 01:43:51 DEBUG : three.txt: md5 = f713db6175728e32d5735f91cf96c7eb OK
2025/01/11 01:43:51 INFO  : three.txt: Copied (new)
2025/01/11 01:43:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/11 01:43:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/01/11 01:43:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/11 01:43:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/11 01:43:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/11 01:43:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/11 01:43:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncSuffix (25.44s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:43:58 DEBUG : dst/one: md5 = db04be0c5cb25ac3da14802783df9349 OK
2025/01/11 01:44:00 DEBUG : dst/two: md5 = 35a28bc9ea3e4c69fcea91365133b9bc OK
2025/01/11 01:44:02 DEBUG : dst/three.txt: md5 = 170c94207e2c2a314c6a039e4f3b09f3 OK
2025/01/11 01:44:02 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisipur3fufo/dst"
2025/01/11 01:44:02 DEBUG : Creating backend with remote "TestDrive:crypt/m8dsrcmeaatnkq1ag9iv2vgu1uh6h2v4herrcvvl7a15bjr8u2q0/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/11 01:44:03 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/11 01:44:04 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/01/11 01:44:06 DEBUG : one: md5 = 2b691c76eb75325435b8d1c6a3f14f17 OK
2025/01/11 01:44:06 INFO  : one: Copied (new)
2025/01/11 01:44:06 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:44:06 DEBUG : two: Unchanged skipping
2025/01/11 01:44:06 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/01/11 01:44:07 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/01/11 01:44:09 DEBUG : three.txt: md5 = 9a941116007068b8316bb412be5f98e4 OK
2025/01/11 01:44:09 INFO  : three.txt: Copied (new)
2025/01/11 01:44:10 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/11 01:44:11 INFO  : one-2019-01-01: Deleted
2025/01/11 01:44:11 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/01/11 01:44:13 DEBUG : one: md5 = aa2c4ddb16574fe3510e51026f84db40 OK
2025/01/11 01:44:13 INFO  : one: Copied (new)
2025/01/11 01:44:13 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:44:13 DEBUG : two: Unchanged skipping
2025/01/11 01:44:14 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/01/11 01:44:14 INFO  : three-2019-01-01.txt: Deleted
2025/01/11 01:44:15 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/01/11 01:44:17 DEBUG : three.txt: md5 = a966c7fb670360699b4972c9a40170c2 OK
2025/01/11 01:44:17 INFO  : three.txt: Copied (new)
2025/01/11 01:44:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/11 01:44:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/01/11 01:44:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/01/11 01:44:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/01/11 01:44:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/01/11 01:44:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/01/11 01:44:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncSuffixKeepExtension (25.60s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:44:23 DEBUG : Testêé: md5 = 3dbcdd360081ff9ebf6870b55ab3cba2 OK
2025/01/11 01:44:24 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2025/01/11 01:44:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:44:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:44:25 DEBUG : Testêé: md5 = 96910a0d20afd136cdb6b48ac5cc909b OK
2025/01/11 01:44:25 INFO  : Testêé: Copied (replaced existing) to: Testêé
2025/01/11 01:44:25 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (5.13s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:44:27 DEBUG : existing: Need to transfer - File not found at Destination
2025/01/11 01:44:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:44:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:44:29 DEBUG : existing: md5 = f3a2859b2a3a569461e8f185daeb679e OK
2025/01/11 01:44:29 INFO  : existing: Copied (new)
2025/01/11 01:44:29 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:44:29 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2025/01/11 01:44:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:44:29 ERROR : existing: Source and destination exist but do not match: immutable file modified
2025/01/11 01:44:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:44:29 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': not deleting files as there were IO errors
2025/01/11 01:44:29 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncImmutable (5.11s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:44:33 DEBUG : EXISTING: md5 = 74910cc7beee0f32cc9a548f913613f1 OK
2025/01/11 01:44:34 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:44:34 DEBUG : existing: Unchanged skipping
2025/01/11 01:44:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:44:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:44:34 DEBUG : Waiting for deletions to finish
2025/01/11 01:44:34 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (3.49s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    sync_test.go:2635: Skipping test as local or remote are case-sensitive
--- SKIP: TestFixCase (0.46s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", 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-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", 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-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.36s)
    --- SKIP: TestMaxTransfer/Hard (0.47s)
    --- SKIP: TestMaxTransfer/Soft (0.45s)
    --- SKIP: TestMaxTransfer/Cautious (0.44s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:44:38 DEBUG : both0: md5 = 8cce25797f6369c0ee9ee64fdb34fdaa OK
2025/01/11 01:44:40 DEBUG : only0: md5 = 84c306036dec8e324e6b27c077b268bf OK
2025/01/11 01:44:42 DEBUG : both1: md5 = 7e021351a4b8d282df5bc9b5d1d98743 OK
2025/01/11 01:44:43 DEBUG : only1: md5 = 30c588fb935d5eb366bd37fc1c19b35b OK
2025/01/11 01:44:45 DEBUG : both2: md5 = e9d166df8b6a80139bd515d11aeb905a OK
2025/01/11 01:44:46 DEBUG : only2: md5 = 2a02c24fe8d3e4c0f2c0806af517259e OK
2025/01/11 01:44:48 DEBUG : both3: md5 = 2f2b6f29e87b9373d136e9bc3f5ce26d OK
2025/01/11 01:44:50 DEBUG : only3: md5 = 58d6acad87b1336f9414f4583a127d76 OK
2025/01/11 01:44:51 DEBUG : both4: md5 = 1889c246a90acf162e174fb8e8d478cb OK
2025/01/11 01:44:53 DEBUG : only4: md5 = 7145fbf0f776138eb9e429bc6efd1c8a OK
2025/01/11 01:44:55 DEBUG : both5: md5 = 62ff3d550ded1ca4e79329e27fa2caf4 OK
2025/01/11 01:44:57 DEBUG : only5: md5 = 8449c60e9a1574c43ce3ac3d83d3a8da OK
2025/01/11 01:44:58 DEBUG : both6: md5 = b173dc303cafd2a0d9fb1d1bf2b6a4e3 OK
2025/01/11 01:45:00 DEBUG : only6: md5 = d858d7992fcaac8404b344889a2cee72 OK
2025/01/11 01:45:02 DEBUG : both7: md5 = 3ef413fc948560f390402d5462dd8ce8 OK
2025/01/11 01:45:03 DEBUG : only7: md5 = 4e51bdf7c6142dcfc89c57c961e37e3e OK
2025/01/11 01:45:05 DEBUG : both8: md5 = 6e8fc6cce993144266d0686904a80c7d OK
2025/01/11 01:45:06 DEBUG : only8: md5 = 321498b528b8a9c47aec2ae7efce6ad4 OK
2025/01/11 01:45:08 DEBUG : both9: md5 = bc18f7ece4fd1c1a0aafa90300dfa597 OK
2025/01/11 01:45:10 DEBUG : only9: md5 = 6fddcb054a83e9eb7ddc27cd62326eca OK
2025/01/11 01:45:11 DEBUG : both10: md5 = 612b2210ef6b59db92e53149a81c6f72 OK
2025/01/11 01:45:13 DEBUG : only10: md5 = 8391e9596b21d6cfed06435736d2dd31 OK
2025/01/11 01:45:15 DEBUG : both11: md5 = f572c797e1ed18c72911148b5ab63016 OK
2025/01/11 01:45:16 DEBUG : only11: md5 = bc14995d9cd3f18cc8e83182a1bd908a OK
2025/01/11 01:45:18 DEBUG : both12: md5 = d33232429c8b8b2853158b8214ac3054 OK
2025/01/11 01:45:19 DEBUG : only12: md5 = bb48c1fc37d481aef0d326ea26fb7ac5 OK
2025/01/11 01:45:21 DEBUG : both13: md5 = 73604803b2b31d52305362bb2fd87771 OK
2025/01/11 01:45:23 DEBUG : only13: md5 = 17a536b89cb82889bcda76afebeca18c OK
2025/01/11 01:45:24 DEBUG : both14: md5 = ab4c6964639f631df877f60589ea0623 OK
2025/01/11 01:45:26 DEBUG : only14: md5 = ea3409937a4f275abcefef2d8249b657 OK
2025/01/11 01:45:28 DEBUG : both15: md5 = 94ee303cab9fd51364f69170ff946042 OK
2025/01/11 01:45:29 DEBUG : only15: md5 = 702ac8468cc484160482fcbfc23f3e57 OK
2025/01/11 01:45:31 DEBUG : both16: md5 = a17c8e919d5d6fff08f0a45a1bfbb5ce OK
2025/01/11 01:45:32 DEBUG : only16: md5 = d5e01f5dbd22be1953ba662ec7251a9a OK
2025/01/11 01:45:34 DEBUG : both17: md5 = 4357ffb8892ee5e81d65edbc21b48984 OK
2025/01/11 01:45:36 DEBUG : only17: md5 = be66f9687ea0f45698ac8c54f379a65d OK
2025/01/11 01:45:37 DEBUG : both18: md5 = 1389d24a754db6459be813da755adb97 OK
2025/01/11 01:45:39 DEBUG : only18: md5 = 06fa41372bc14660b610fb16262a4f9d OK
2025/01/11 01:45:41 DEBUG : both19: md5 = dd82900addee948e693aec95731f27e3 OK
2025/01/11 01:45:42 DEBUG : only19: md5 = 96a38edd7eed4af7e6a17a70961da523 OK
2025/01/11 01:45:43 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:45:43 DEBUG : both0: Unchanged skipping
2025/01/11 01:45:43 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:45:43 DEBUG : both1: Unchanged skipping
2025/01/11 01:45:43 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:45:43 DEBUG : both10: Unchanged skipping
2025/01/11 01:45:43 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:45:43 DEBUG : both11: Unchanged skipping
2025/01/11 01:45:43 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:45:43 DEBUG : both12: Unchanged skipping
2025/01/11 01:45:43 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:45:43 DEBUG : both13: Unchanged skipping
2025/01/11 01:45:43 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:45:43 DEBUG : both14: Unchanged skipping
2025/01/11 01:45:43 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:45:43 DEBUG : both15: Unchanged skipping
2025/01/11 01:45:43 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:45:43 DEBUG : both16: Unchanged skipping
2025/01/11 01:45:43 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:45:43 DEBUG : both17: Unchanged skipping
2025/01/11 01:45:43 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:45:43 DEBUG : both18: Unchanged skipping
2025/01/11 01:45:43 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:45:43 DEBUG : both19: Unchanged skipping
2025/01/11 01:45:43 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:45:43 DEBUG : both2: Unchanged skipping
2025/01/11 01:45:43 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:45:43 DEBUG : both3: Unchanged skipping
2025/01/11 01:45:43 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:45:43 DEBUG : both4: Unchanged skipping
2025/01/11 01:45:43 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:45:43 DEBUG : both5: Unchanged skipping
2025/01/11 01:45:43 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:45:43 DEBUG : both6: Unchanged skipping
2025/01/11 01:45:43 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:45:43 DEBUG : both7: Unchanged skipping
2025/01/11 01:45:43 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:45:43 DEBUG : both8: Unchanged skipping
2025/01/11 01:45:43 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:45:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:45:43 DEBUG : both9: Unchanged skipping
2025/01/11 01:45:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:45:43 DEBUG : Waiting for deletions to finish
2025/01/11 01:45:43 INFO  : only1: Deleted
2025/01/11 01:45:43 INFO  : only14: Deleted
2025/01/11 01:45:43 INFO  : only13: Deleted
2025/01/11 01:45:43 INFO  : only17: Deleted
2025/01/11 01:45:44 INFO  : only0: Deleted
2025/01/11 01:45:44 INFO  : only9: Deleted
2025/01/11 01:45:44 INFO  : only12: Deleted
2025/01/11 01:45:44 INFO  : only10: Deleted
2025/01/11 01:45:44 INFO  : only16: Deleted
2025/01/11 01:45:44 INFO  : only2: Deleted
2025/01/11 01:45:44 INFO  : only7: Deleted
2025/01/11 01:45:44 INFO  : only4: Deleted
2025/01/11 01:45:45 INFO  : only8: Deleted
2025/01/11 01:45:45 INFO  : only6: Deleted
2025/01/11 01:45:45 INFO  : only11: Deleted
2025/01/11 01:45:45 INFO  : only15: Deleted
2025/01/11 01:45:45 INFO  : only18: Deleted
2025/01/11 01:45:46 INFO  : only3: Deleted
2025/01/11 01:45:46 INFO  : only19: Deleted
2025/01/11 01:45:46 INFO  : only5: Deleted
2025/01/11 01:45:46 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (80.83s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:45:59 DEBUG : both0: md5 = 2b171ed7e6c9a1de964b5bd5cb2baa59 OK
2025/01/11 01:46:01 DEBUG : only0: md5 = 0a19c9ae00f9fc9dd13c27b65dc21a12 OK
2025/01/11 01:46:03 DEBUG : both1: md5 = 931dcb6b045349627dfb63bfd94d4d89 OK
2025/01/11 01:46:04 DEBUG : only1: md5 = c67b7e2dec3428ad350915dd72f6fded OK
2025/01/11 01:46:06 DEBUG : both2: md5 = 4f190aa37f2b89d85976595c72807b01 OK
2025/01/11 01:46:08 DEBUG : only2: md5 = 1282068bbbd25ddc0dc08f5859332853 OK
2025/01/11 01:46:09 DEBUG : both3: md5 = d490497fd3bb2a97492f1a441324238d OK
2025/01/11 01:46:11 DEBUG : only3: md5 = e29bde60cea8f8fbdcaf0c2d5d17ad20 OK
2025/01/11 01:46:13 DEBUG : both4: md5 = e0efe65fab301ec0f1e38b4110919ee7 OK
2025/01/11 01:46:14 DEBUG : only4: md5 = bb6792f717fb8a2b3f4d033ba8d2de74 OK
2025/01/11 01:46:16 DEBUG : both5: md5 = cfc97d781b770a638a890a4999ba7c33 OK
2025/01/11 01:46:18 DEBUG : only5: md5 = fd67742fc63f0c4cc30f42ea26b7c5f1 OK
2025/01/11 01:46:19 DEBUG : both6: md5 = dc48e1a74f0b78eb028353db4448675c OK
2025/01/11 01:46:21 DEBUG : only6: md5 = 829782579f0edb7381feddb8177caa2d OK
2025/01/11 01:46:23 DEBUG : both7: md5 = ad78a124a7c75b5c9be17456f1e6281d OK
2025/01/11 01:46:24 DEBUG : only7: md5 = d0a439e9eda72f23159dc458a7d5e272 OK
2025/01/11 01:46:26 DEBUG : both8: md5 = aebf18b2d6e7c60623fab863c1c511a8 OK
2025/01/11 01:46:28 DEBUG : only8: md5 = 75af92457a4b0229a60e14d28ae56c10 OK
2025/01/11 01:46:29 DEBUG : both9: md5 = 6eebc91ad16bafc5517408a7b853ebc7 OK
2025/01/11 01:46:31 DEBUG : only9: md5 = 0848f40018c4d58a8d1759f9e4e82848 OK
2025/01/11 01:46:33 DEBUG : both10: md5 = cf2e3e6cb308cd34bf05301e69287f92 OK
2025/01/11 01:46:34 DEBUG : only10: md5 = adcbdb67f3a8058f71a278083da3487a OK
2025/01/11 01:46:36 DEBUG : both11: md5 = 9b3132f47488aaf34cc4a0977baa4540 OK
2025/01/11 01:46:38 DEBUG : only11: md5 = d8f6f0a65cbbfd32d2f1b9dd05f6782d OK
2025/01/11 01:46:39 DEBUG : both12: md5 = 024ba69594cbe8d0fb42a51366cd688e OK
2025/01/11 01:46:41 DEBUG : only12: md5 = a193c7806e21e9a5c3aaa3d6fd25f887 OK
2025/01/11 01:46:43 DEBUG : both13: md5 = ed272b6a38d8db956d98122f67f42a60 OK
2025/01/11 01:46:44 DEBUG : only13: md5 = 2c44276e522a377313b302ae1fa265e5 OK
2025/01/11 01:46:46 DEBUG : both14: md5 = 507ea0c50e62bc908db36933cdd48445 OK
2025/01/11 01:46:48 DEBUG : only14: md5 = 21d64c9444e92692f3e048ef629746ff OK
2025/01/11 01:46:50 DEBUG : both15: md5 = ddf83895bd58225a55d42759469ea855 OK
2025/01/11 01:46:51 DEBUG : only15: md5 = 7717037986f4e6bbe2396b3c7233e557 OK
2025/01/11 01:46:53 DEBUG : both16: md5 = 47e1136269974622a6e0234298faa1cd OK
2025/01/11 01:46:55 DEBUG : only16: md5 = f6258928e9a00203dabad17dd11ee7ed OK
2025/01/11 01:46:56 DEBUG : both17: md5 = 43754752692f482fc23d15a1c453217a OK
2025/01/11 01:46:59 DEBUG : only17: md5 = 1af8745cbace02b2432ea669359df893 OK
2025/01/11 01:47:00 DEBUG : both18: md5 = d81a8c3929a9ec4c9b05237171e419d1 OK
2025/01/11 01:47:02 DEBUG : only18: md5 = 32c559dc3aec0260d06858453379828b OK
2025/01/11 01:47:03 DEBUG : both19: md5 = 54a6fd5aceab691899c1af427071ee4d OK
2025/01/11 01:47:05 DEBUG : only19: md5 = af796fa58280b52197fe1025ceeeaa26 OK
2025/01/11 01:47:06 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:47:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for checks to finish
2025/01/11 01:47:06 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:47:06 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:47:06 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:47:06 DEBUG : both0: Unchanged skipping
2025/01/11 01:47:06 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:47:06 DEBUG : both12: Unchanged skipping
2025/01/11 01:47:06 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:47:06 DEBUG : both1: Unchanged skipping
2025/01/11 01:47:06 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:47:06 DEBUG : both11: Unchanged skipping
2025/01/11 01:47:06 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:47:06 DEBUG : both15: Unchanged skipping
2025/01/11 01:47:06 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:47:06 DEBUG : both16: Unchanged skipping
2025/01/11 01:47:06 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:47:06 DEBUG : both17: Unchanged skipping
2025/01/11 01:47:06 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:47:06 DEBUG : both13: Unchanged skipping
2025/01/11 01:47:06 DEBUG : both10: Unchanged skipping
2025/01/11 01:47:06 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:47:06 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:47:06 DEBUG : both19: Unchanged skipping
2025/01/11 01:47:06 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:47:06 DEBUG : both3: Unchanged skipping
2025/01/11 01:47:06 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:47:06 DEBUG : both2: Unchanged skipping
2025/01/11 01:47:06 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:47:06 DEBUG : both5: Unchanged skipping
2025/01/11 01:47:06 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:47:06 DEBUG : both6: Unchanged skipping
2025/01/11 01:47:06 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:47:06 DEBUG : both7: Unchanged skipping
2025/01/11 01:47:06 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:47:06 DEBUG : both8: Unchanged skipping
2025/01/11 01:47:06 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/11 01:47:06 DEBUG : both9: Unchanged skipping
2025/01/11 01:47:06 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2025/01/11 01:47:06 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2025/01/11 01:47:06 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2025/01/11 01:47:06 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2025/01/11 01:47:06 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2025/01/11 01:47:06 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2025/01/11 01:47:06 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2025/01/11 01:47:06 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2025/01/11 01:47:06 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2025/01/11 01:47:06 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2025/01/11 01:47:06 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2025/01/11 01:47:06 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2025/01/11 01:47:06 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2025/01/11 01:47:06 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2025/01/11 01:47:06 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2025/01/11 01:47:06 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2025/01/11 01:47:06 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2025/01/11 01:47:06 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2025/01/11 01:47:06 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2025/01/11 01:47:06 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2025/01/11 01:47:06 DEBUG : both18: Unchanged skipping
2025/01/11 01:47:06 DEBUG : both14: Unchanged skipping
2025/01/11 01:47:06 DEBUG : both4: Unchanged skipping
2025/01/11 01:47:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Waiting for transfers to finish
2025/01/11 01:47:07 DEBUG : only1: md5 = b79f88dce06b6ce988a6468fd10457b6 OK
2025/01/11 01:47:07 INFO  : only1: Copied (replaced existing)
2025/01/11 01:47:07 DEBUG : only10: md5 = ea9f7ee2e8f36bdbd6b256c48413fd91 OK
2025/01/11 01:47:07 INFO  : only10: Copied (replaced existing)
2025/01/11 01:47:07 DEBUG : only0: md5 = d2df68df38f849c4f62509325bcaeab4 OK
2025/01/11 01:47:07 INFO  : only0: Copied (replaced existing)
2025/01/11 01:47:07 DEBUG : only11: md5 = 1c893d559f22733cb993f4c0f88476e4 OK
2025/01/11 01:47:07 INFO  : only11: Copied (replaced existing)
2025/01/11 01:47:08 DEBUG : only13: md5 = d8a77f1d0dbb1cbd29a3260863e95095 OK
2025/01/11 01:47:08 INFO  : only13: Copied (replaced existing)
2025/01/11 01:47:08 DEBUG : only12: md5 = f5a17a197f8b4231740bd201c5e55848 OK
2025/01/11 01:47:08 INFO  : only12: Copied (replaced existing)
2025/01/11 01:47:08 DEBUG : only15: md5 = bf42d6ae45a669023c44e26d7f732d42 OK
2025/01/11 01:47:08 INFO  : only15: Copied (replaced existing)
2025/01/11 01:47:09 DEBUG : only14: md5 = b6c773e804d128195cf84a421d006cc6 OK
2025/01/11 01:47:09 INFO  : only14: Copied (replaced existing)
2025/01/11 01:47:10 DEBUG : only16: md5 = fa13eaccbe018bd84db2cc89e572afd2 OK
2025/01/11 01:47:10 INFO  : only16: Copied (replaced existing)
2025/01/11 01:47:10 DEBUG : only17: md5 = b273f35bd8f521d10da46fe7b95752c9 OK
2025/01/11 01:47:10 INFO  : only17: Copied (replaced existing)
2025/01/11 01:47:10 DEBUG : only18: md5 = e658fb19b71e1f15f6887a0a7d1c0925 OK
2025/01/11 01:47:10 INFO  : only18: Copied (replaced existing)
2025/01/11 01:47:10 DEBUG : only19: md5 = b4e7dcd815df7b59a1751f8215890305 OK
2025/01/11 01:47:10 INFO  : only19: Copied (replaced existing)
2025/01/11 01:47:11 DEBUG : only2: md5 = b8d33a3a519968f3504a2f90e7cdcbcd OK
2025/01/11 01:47:11 INFO  : only2: Copied (replaced existing)
2025/01/11 01:47:11 DEBUG : only4: md5 = 54c21087096ad05bdf2b396e4f1cbb22 OK
2025/01/11 01:47:11 INFO  : only4: Copied (replaced existing)
2025/01/11 01:47:11 DEBUG : only3: md5 = ccd7a1a5642db67c0418d669775028fc OK
2025/01/11 01:47:11 INFO  : only3: Copied (replaced existing)
2025/01/11 01:47:11 DEBUG : only5: md5 = e55fc5983d5def72a2c57f33a9ada137 OK
2025/01/11 01:47:11 INFO  : only5: Copied (replaced existing)
2025/01/11 01:47:12 DEBUG : only6: md5 = 0f8b113596e2164d5af70a582c97ae88 OK
2025/01/11 01:47:12 INFO  : only6: Copied (replaced existing)
2025/01/11 01:47:12 DEBUG : only7: md5 = 83515f49b478c67c08640292c3121910 OK
2025/01/11 01:47:12 INFO  : only7: Copied (replaced existing)
2025/01/11 01:47:12 DEBUG : only8: md5 = 439e29aa73accc2489f942689d52d475 OK
2025/01/11 01:47:12 INFO  : only8: Copied (replaced existing)
2025/01/11 01:47:13 DEBUG : only9: md5 = 32563681d83cdc3be7b087a0d82288ec OK
2025/01/11 01:47:13 INFO  : only9: Copied (replaced existing)
2025/01/11 01:47:13 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (97.92s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:47:36 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/11 01:47:36 DEBUG : sub dir: Making directory with metadata
2025/01/11 01:47:37 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:47:57 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/11 01:47:58 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/11 01:47:58 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/11 01:47:58 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:48:13 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2025/01/11 01:48:13 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/11 01:48:14 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2025/01/11 01:48:15 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2025/01/11 01:48:16 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/11 01:48:17 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/11 01:48:18 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/11 01:48:18 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/11 01:48:19 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/11 01:48:20 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2025/01/11 01:48:20 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/11 01:48:21 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (47.57s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:48:23 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/11 01:48:23 DEBUG : sub dir: Making directory with metadata
2025/01/11 01:48:24 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:48:50 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/11 01:48:50 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/11 01:48:50 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/11 01:48:50 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo'", Local "Local file system at /tmp/rclone3400890828", Modify Window "1ms"
2025/01/11 01:49:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/11 01:49:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2025/01/11 01:49:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2025/01/11 01:49:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/11 01:49:07 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/11 01:49:08 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/11 01:49:09 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/11 01:49:10 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/11 01:49:10 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2025/01/11 01:49:10 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/11 01:49:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (50.16s)
PASS
2025/01/11 01:49:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisipur3fufo': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 17m29.971286874s (try 1/5)