"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5)
2024/11/06 04:56:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate"
2024/11/06 04:56:03 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2024/11/06 04:56:03 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0"
2024/11/06 04:56:04 DEBUG : Creating backend with remote "/tmp/rclone884933605"
=== 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-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:56:06 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/06 04:56:06 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/06 04:56:06 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2024/11/06 04:56:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:56:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:56:06 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (2.87s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:56:07 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/06 04:56:07 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/06 04:56:07 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/06 04:56:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:56:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:56:10 DEBUG : sub dir/hello world: md5 = 4376f43af899895a62173a020de643e9 OK
2024/11/06 04:56:10 INFO  : sub dir/hello world: Copied (new)
2024/11/06 04:56:11 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:56:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (7.67s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:56:15 DEBUG : metadata sub dir: Making directory with metadata
2024/11/06 04:56:15 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/06 04:56:15 DEBUG : empty metadata sub dir: Making directory with metadata
2024/11/06 04:56:15 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/06 04:56:15 DEBUG : Local file system at /tmp/rclone884933605: File to upload is small (21 bytes), uploading instead of streaming
2024/11/06 04:56:15 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/11/06 04:56:15 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/11/06 04:56:15 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/11/06 04:56:15 DEBUG : Google drive root 'crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0': Skipping btime metadata as can't update it on an existing file: 2024-11-06T04:56:15.146655737Z
2024/11/06 04:56:16 INFO  : empty metadata sub dir: Updated directory metadata
2024/11/06 04:56:16 DEBUG : Google drive root 'crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0': Skipping btime metadata as can't update it on an existing file: 2024-11-06T04:56:15.146655737Z
2024/11/06 04:56:17 INFO  : metadata sub dir: Updated directory metadata
2024/11/06 04:56:17 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/11/06 04:56:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:56:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:56:19 DEBUG : metadata sub dir/hello metadata world: md5 = 41e2e5ae21847a9026eba4da0ae9f058 OK
2024/11/06 04:56:19 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:56:22 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (10.24s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:56:25 DEBUG : metadata sub dir: Making directory with metadata
2024/11/06 04:56:25 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/06 04:56:25 DEBUG : empty metadata sub dir: Making directory with metadata
2024/11/06 04:56:25 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/06 04:56:25 DEBUG : Local file system at /tmp/rclone884933605: File to upload is small (21 bytes), uploading instead of streaming
2024/11/06 04:56:25 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/11/06 04:56:25 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/11/06 04:56:25 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/11/06 04:56:25 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2024/11/06 04:56:25 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2024/11/06 04:56:25 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/11/06 04:56:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:56:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:56:28 DEBUG : metadata sub dir/hello metadata world: md5 = 9ea30d193fd05762f89c8b029113c0a6 OK
2024/11/06 04:56:28 INFO  : metadata sub dir/hello metadata world: Copied (new)
2024/11/06 04:56:28 DEBUG : Google drive root 'crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0': Skipping btime metadata as can't update it on an existing file: 2024-11-06T04:56:25.386594253Z
2024/11/06 04:56:29 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:56:32 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (8.78s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:56:34 DEBUG : Creating backend with remote "/non-existing"
2024/11/06 04:56:34 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2024/11/06 04:56:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:56:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.26s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:56:35 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/06 04:56:35 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/06 04:56:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:56:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:56:38 DEBUG : sub dir/hello world: md5 = 6761157c78d7443ea40ea9323d37bc0a OK
2024/11/06 04:56:38 INFO  : sub dir/hello world: Copied (new)
2024/11/06 04:56:39 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:56:41 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (7.78s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:56:43 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Running all checks before starting transfers
2024/11/06 04:56:43 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/06 04:56:43 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/06 04:56:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:56:43 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Checks finished, now starting transfers
2024/11/06 04:56:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:56:46 DEBUG : sub dir/hello world: md5 = 66e5c67a83655fe5aa8453de644e264e OK
2024/11/06 04:56:46 INFO  : sub dir/hello world: Copied (new)
2024/11/06 04:56:47 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:56:49 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (7.55s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:56:50 ERROR : Ignoring --no-traverse with sync
2024/11/06 04:56:51 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/06 04:56:51 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/06 04:56:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:56:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:56:54 DEBUG : sub dir/hello world: md5 = 57527d8ac2136938fef3df05f280b007 OK
2024/11/06 04:56:54 INFO  : sub dir/hello world: Copied (new)
2024/11/06 04:56:54 DEBUG : Waiting for deletions to finish
2024/11/06 04:56:54 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:56:56 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (7.59s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:56:58 DEBUG : hello world2: Need to transfer - File not found at Destination
2024/11/06 04:56:58 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/06 04:56:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:56:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:57:00 DEBUG : hello world2: md5 = 6f143a2d6f9c7318c194df2f41dd8b1c OK
2024/11/06 04:57:00 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestCopyWithDepth (4.09s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:57:02 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/06 04:57:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:57:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:57:04 DEBUG : potato2: md5 = 824c858edd749ec8683e4d1ba95280f8 OK
2024/11/06 04:57:04 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (4.21s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:57:06 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/06 04:57:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:57:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:57:08 DEBUG : potato2: md5 = 37ea8f6e9d57486b9ce69397ad587ef5 OK
2024/11/06 04:57:08 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (3.94s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:57:10 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/06 04:57:10 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/06 04:57:10 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/06 04:57:10 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/06 04:57:10 DEBUG : sub dir: Making directory with metadata
2024/11/06 04:57:12 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/06 04:57:12 DEBUG : sub dir2: Making directory with metadata
2024/11/06 04:57:13 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/06 04:57:13 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/06 04:57:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/06 04:57:14 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/06 04:57:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:57:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:57:15 DEBUG : sub dir/hello world: md5 = c0fab01bedebd4a6811c0b2973381f8d OK
2024/11/06 04:57:15 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:57:20 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2024/11/06 04:57:21 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (12.10s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:57:22 DEBUG : sub dir2: Making directory
2024/11/06 04:57:22 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/06 04:57:22 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/06 04:57:22 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/06 04:57:22 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/06 04:57:22 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2024/11/06 04:57:22 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/06 04:57:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:57:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:57:25 DEBUG : sub dir/hello world: md5 = af2c2e5e9c493afcb6c962b69e776524 OK
2024/11/06 04:57:25 INFO  : sub dir/hello world: Copied (new)
2024/11/06 04:57:26 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/06 04:57:28 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (6.90s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:57:29 DEBUG : sub dir2: Making directory with metadata
2024/11/06 04:57:29 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/06 04:57:29 DEBUG : sub dir: Making directory with metadata
2024/11/06 04:57:30 INFO  : sub dir: Made directory with metadata (mtime=2024-11-06T04:57:29.574207651Z)
2024/11/06 04:57:30 DEBUG : sub dir2: Making directory with metadata
2024/11/06 04:57:31 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/06 04:57:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/06 04:57:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:57:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:57:33 DEBUG : sub dir/hello world: md5 = af21bcce293c88e2c07a000679f8b77f OK
2024/11/06 04:57:33 INFO  : sub dir/hello world: Copied (new)
2024/11/06 04:57:33 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:57:37 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (9.46s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:57:39 DEBUG : sub dir no update dir modtime: Making directory with metadata
2024/11/06 04:57:39 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/06 04:57:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:57:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:57:40 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (5.00s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:57:44 DEBUG : sub dir2: Making directory
2024/11/06 04:57:44 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/06 04:57:44 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/06 04:57:44 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/06 04:57:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:57:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:57:47 DEBUG : sub dir/hello world: md5 = 048df3d43a00ea98b7d683a070cda2e1 OK
2024/11/06 04:57:47 INFO  : sub dir/hello world: Copied (new)
2024/11/06 04:57:47 INFO  : sub dir/hello world: Deleted
2024/11/06 04:57:48 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/06 04:57:50 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (7.17s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:57:51 DEBUG : sub dir2: Making directory with metadata
2024/11/06 04:57:51 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/06 04:57:51 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/06 04:57:51 DEBUG : sub dir: Making directory with metadata
2024/11/06 04:57:52 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/06 04:57:52 DEBUG : sub dir2: Making directory with metadata
2024/11/06 04:57:53 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/06 04:57:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/06 04:57:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:57:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:57:55 DEBUG : sub dir/hello world: md5 = 899384fbe7221f7b7485ba85f1b7a318 OK
2024/11/06 04:57:55 INFO  : sub dir/hello world: Copied (new)
2024/11/06 04:57:55 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:57:59 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (9.34s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.51s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:58:01 DEBUG : sub dir2: Making directory
2024/11/06 04:58:01 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/06 04:58:01 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/06 04:58:01 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/06 04:58:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:58:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:58:04 DEBUG : sub dir/hello world: md5 = d497dd545cb188d25ce9a3cde2d6d5a4 OK
2024/11/06 04:58:04 INFO  : sub dir/hello world: Copied (new)
2024/11/06 04:58:04 DEBUG : Waiting for deletions to finish
2024/11/06 04:58:04 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/06 04:58:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (6.60s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:58:10 DEBUG : sub dir/hello world: md5 = a37cffbf8fb8136e4ecda79a992f10dc OK
2024/11/06 04:58:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zufekod5cohu"
2024/11/06 04:58:11 DEBUG : Creating backend with remote "TestDrive:crypt/rs7p1v8vv0kpaadqt8pbnvb6png86pa0s06k2m88drbn11t2jo5g"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate' -> Encrypted drive 'TestCryptDrive:rclone-test-zufekod5cohu'
2024/11/06 04:58:12 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/06 04:58:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/06 04:58:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zufekod5cohu': Waiting for checks to finish
2024/11/06 04:58:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zufekod5cohu': Waiting for transfers to finish
2024/11/06 04:58:17 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/06 04:58:17 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:58:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zufekod5cohu': Purge remote
2024/11/06 04:58:20 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (14.64s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:58:25 DEBUG : sub dir/hello world: md5 = 1d09fd33e769f3662b5f7f613ddb91a6 OK
2024/11/06 04:58:26 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/06 04:58:26 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/06 04:58:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:58:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:58:28 DEBUG : sub dir/hello world: md5 = a77138dd42c08559df3e71d69026f7c8 OK
2024/11/06 04:58:28 INFO  : sub dir/hello world: Copied (replaced existing)
2024/11/06 04:58:28 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:58:31 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (10.24s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:58:35 DEBUG : sub dir/hello world: md5 = fb52fbe05fca1f03ac2fd0e72ddf689d OK
2024/11/06 04:58:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sihosox7juza"
2024/11/06 04:58:36 DEBUG : Creating backend with remote "TestDrive:crypt/refe8jr6snf05c2o45gjijtlbgn2s4kk54jnsujbulhu1cvmglf0"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate' -> Encrypted drive 'TestCryptDrive:rclone-test-sihosox7juza'
2024/11/06 04:58:37 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/06 04:58:37 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/06 04:58:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sihosox7juza': Waiting for checks to finish
2024/11/06 04:58:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sihosox7juza': Waiting for transfers to finish
2024/11/06 04:58:41 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/06 04:58:42 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:58:44 DEBUG : sub dir/hello world: md5 = a8e04eaf56b18e20c3fb32c03dd50ce1 OK
2024/11/06 04:58:45 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/06 04:58:45 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/06 04:58:45 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/06 04:58:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sihosox7juza': Waiting for checks to finish
2024/11/06 04:58:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sihosox7juza': Waiting for transfers to finish
2024/11/06 04:58:48 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/06 04:58:48 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:58:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sihosox7juza': Purge remote
2024/11/06 04:58:51 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (21.00s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:58:56 DEBUG : sub dir/hello world: md5 = a35587e14df766e32dac06b2661ca021 OK
2024/11/06 04:58:57 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/06 04:58:57 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/06 04:58:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:58:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:58:59 DEBUG : sub dir/hello world: md5 = 240187ddb096f9601f69a0e83216c228 OK
2024/11/06 04:58:59 INFO  : sub dir/hello world: Copied (replaced existing)
2024/11/06 04:58:59 INFO  : sub dir/hello world: Deleted
2024/11/06 04:59:00 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:59:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (10.12s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:59:06 DEBUG : sub dir/hello world: md5 = 0d992da5d48776d05ec4d166261779ab OK
2024/11/06 04:59:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tisowal0tate"
2024/11/06 04:59:07 DEBUG : Creating backend with remote "TestDrive:crypt/56f7bggm2j4kihi7ep6d769tgogfv161j5oqqnicvjqo69hc2720"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate' -> Encrypted drive 'TestCryptDrive:rclone-test-tisowal0tate'
2024/11/06 04:59:08 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/06 04:59:08 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/06 04:59:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisowal0tate': Waiting for checks to finish
2024/11/06 04:59:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisowal0tate': Waiting for transfers to finish
2024/11/06 04:59:12 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/06 04:59:13 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:59:15 DEBUG : sub dir/hello world: md5 = c60ff1f9c0bcb8eda084eca15ce7d716 OK
2024/11/06 04:59:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisowal0tate': Using server-side directory move
2024/11/06 04:59:16 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tisowal0tate': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/06 04:59:16 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/06 04:59:16 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/06 04:59:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisowal0tate': Waiting for checks to finish
2024/11/06 04:59:16 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/06 04:59:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisowal0tate': Waiting for transfers to finish
2024/11/06 04:59:17 INFO  : sub dir/hello world: Deleted
2024/11/06 04:59:18 INFO  : sub dir/hello world: Moved (server-side)
2024/11/06 04:59:19 INFO  : sub dir: Set directory modification time (using SetModTime)
2024/11/06 04:59:21 DEBUG : sub dir/hello world: md5 = 7b59d2043d053ee5af81bfb0bfdeabd5 OK
2024/11/06 04:59:22 DEBUG : testing file moves
2024/11/06 04:59:22 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/06 04:59:22 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/06 04:59:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisowal0tate': Waiting for checks to finish
2024/11/06 04:59:23 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2024/11/06 04:59:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisowal0tate': Waiting for transfers to finish
2024/11/06 04:59:24 INFO  : sub dir/hello world: Deleted
2024/11/06 04:59:25 INFO  : sub dir/hello world: Moved (server-side)
2024/11/06 04:59:25 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:59:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tisowal0tate': Purge remote
--- PASS: TestServerSideMoveOverSelf (26.63s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:59:33 DEBUG : sub dir/hello world: md5 = 2666495b65888fa85092e8b1cf86d09f OK
2024/11/06 04:59:33 ERROR : : error listing: directory not found
2024/11/06 04:59:33 DEBUG : Local file system at /tmp/rclone884933605: Making directory
2024/11/06 04:59:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:59:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:59:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (7.67s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:59:40 DEBUG : sub dir/hello world: md5 = ba907de79ceb6fdd9be503939e166790 OK
2024/11/06 04:59:41 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/06 04:59:42 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/06 04:59:42 DEBUG : Local file system at /tmp/rclone884933605: Waiting for checks to finish
2024/11/06 04:59:42 DEBUG : Local file system at /tmp/rclone884933605: Waiting for transfers to finish
2024/11/06 04:59:43 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2024/11/06 04:59:43 INFO  : sub dir/hello world: Copied (new)
2024/11/06 04:59:43 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:59:45 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (9.15s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:59:47 DEBUG : check sum: Need to transfer - File not found at Destination
2024/11/06 04:59:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:59:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:59:49 DEBUG : check sum: md5 = abbdbb7c7389f342a3109b4a0c84f86c OK
2024/11/06 04:59:49 INFO  : check sum: Copied (new)
2024/11/06 04:59:49 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:59:49 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2024/11/06 04:59:49 DEBUG : check sum: Size of src and dst objects identical
2024/11/06 04:59:49 DEBUG : check sum: Unchanged skipping
2024/11/06 04:59:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:59:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:59:49 DEBUG : Waiting for deletions to finish
2024/11/06 04:59:49 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (5.20s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:59:52 DEBUG : sizeonly: Need to transfer - File not found at Destination
2024/11/06 04:59:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:59:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:59:54 DEBUG : sizeonly: md5 = b6488f4644c641ccaa147966ad5c7357 OK
2024/11/06 04:59:54 INFO  : sizeonly: Copied (new)
2024/11/06 04:59:54 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:59:55 DEBUG : sizeonly: Sizes identical
2024/11/06 04:59:55 DEBUG : sizeonly: Unchanged skipping
2024/11/06 04:59:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:59:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:59:55 DEBUG : Waiting for deletions to finish
2024/11/06 04:59:55 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (5.33s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 04:59:57 DEBUG : ignore-size: Need to transfer - File not found at Destination
2024/11/06 04:59:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 04:59:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 04:59:59 DEBUG : ignore-size: md5 = efff9c29985f2cf69081d32d80f51fb9 OK
2024/11/06 04:59:59 INFO  : ignore-size: Copied (new)
2024/11/06 04:59:59 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:00:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:00:00 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:00:00 DEBUG : ignore-size: Unchanged skipping
2024/11/06 05:00:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:00:00 DEBUG : Waiting for deletions to finish
2024/11/06 05:00:00 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (5.32s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:00:04 DEBUG : existing: md5 = bff58cc7aa8b4a26b9a7e3b68d75c8d5 OK
2024/11/06 05:00:05 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:00:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:00:05 DEBUG : existing: Unchanged skipping
2024/11/06 05:00:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:00:05 DEBUG : Waiting for deletions to finish
2024/11/06 05:00:05 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:00:05 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2024/11/06 05:00:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:00:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:00:07 DEBUG : existing: md5 = 02dade2dee46b9728957f4a3fa5add53 OK
2024/11/06 05:00:07 INFO  : existing: Copied (replaced existing)
2024/11/06 05:00:07 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (6.63s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:00:09 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/06 05:00:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:00:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:00:11 DEBUG : existing: md5 = b0c8ea7b1c6250abf80cbd88bc953622 OK
2024/11/06 05:00:11 INFO  : existing: Copied (new)
2024/11/06 05:00:11 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:00:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:00:12 DEBUG : existing: Destination exists, skipping
2024/11/06 05:00:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:00:12 DEBUG : Waiting for deletions to finish
2024/11/06 05:00:12 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (5.42s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:00:18 DEBUG : b/potato: md5 = e68ba9f3df74e3f2cc65aed6a96ee58e OK
2024/11/06 05:00:21 DEBUG : c/non empty space: md5 = 58858136d3948268508c5cabcdea1d90 OK
2024/11/06 05:00:21 DEBUG : d: Making directory
2024/11/06 05:00:23 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/06 05:00:23 DEBUG : Added delayed dir = "c", newDst=c
2024/11/06 05:00:23 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/06 05:00:23 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:00:23 DEBUG : c/non empty space: Unchanged skipping
2024/11/06 05:00:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:00:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:00:26 DEBUG : a/potato2: md5 = 901d948bcae72cbec2d1a903d81ee196 OK
2024/11/06 05:00:26 INFO  : a/potato2: Copied (new)
2024/11/06 05:00:26 DEBUG : Waiting for deletions to finish
2024/11/06 05:00:27 INFO  : b/potato: Deleted
2024/11/06 05:00:28 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/06 05:00:28 INFO  : d: Removing directory
2024/11/06 05:00:29 INFO  : b: Removing directory
2024/11/06 05:00:29 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/06 05:00:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:00:32 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/06 05:00:33 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (20.10s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:00:36 DEBUG : empty space: md5 = 000864f0af28979fe19b2960809aeca8 OK
2024/11/06 05:00:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:00:37 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
2024/11/06 05:00:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:00:37 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2024/11/06 05:00:37 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:00:38 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
2024/11/06 05:00:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:00:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:00:39 DEBUG : empty space: md5 = eeb5786f957ad99bd6077ce1e757dc70 OK
2024/11/06 05:00:39 INFO  : empty space: Copied (replaced existing)
2024/11/06 05:00:39 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (7.18s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.50s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:00:44 DEBUG : foo: md5 = 1f6f655b2ede2ac7492c0471e8364c57 OK
2024/11/06 05:00:45 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
2024/11/06 05:00:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:00:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:00:46 DEBUG : foo: md5 = 1025beab9e05c7b900a7237f6e70e16b OK
2024/11/06 05:00:46 INFO  : foo: Copied (replaced existing)
2024/11/06 05:00:46 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (5.97s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:00:50 DEBUG : empty space: md5 = dff2738dc6f9e1a359e8bafcd554efe8 OK
2024/11/06 05:00:51 DEBUG : potato: Need to transfer - File not found at Destination
2024/11/06 05:00:51 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:00:51 DEBUG : empty space: Unchanged skipping
2024/11/06 05:00:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:00:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:00:53 DEBUG : potato: md5 = 489a037af50e0f5a10d7cd2b4dcc743c OK
2024/11/06 05:00:53 INFO  : potato: Copied (new)
2024/11/06 05:00:53 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (6.90s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:00:57 DEBUG : potato: md5 = 4b1711fe592240efc8014c7a2b86079e OK
2024/11/06 05:00:58 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2024/11/06 05:00:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:00:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:00:59 DEBUG : potato: md5 = 23c2e2d991a47bd775df7c0707eaeefb OK
2024/11/06 05:00:59 INFO  : potato: Copied (replaced existing)
2024/11/06 05:00:59 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (5.99s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:01:03 DEBUG : potato: md5 = 8711852e34389d5567c994a532610a50 OK
2024/11/06 05:01:04 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
2024/11/06 05:01:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:01:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:01:05 DEBUG : potato: md5 = 58552a018be10235c285995cfef33dd6 OK
2024/11/06 05:01:05 INFO  : potato: Copied (replaced existing)
2024/11/06 05:01:05 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (6.24s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:01:10 DEBUG : potato: md5 = 3876abc875584c3ed81335a2dab9000c OK
2024/11/06 05:01:12 DEBUG : empty space: md5 = a47b2806c6eee2133216d0eceb1284c2 OK
2024/11/06 05:01:12 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/06 05:01:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:01:12 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:01:12 DEBUG : empty space: Unchanged skipping
2024/11/06 05:01:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:01:12 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2024/11/06 05:01:12 DEBUG : Waiting for deletions to finish
2024/11/06 05:01:12 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (7.12s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:01:17 DEBUG : potato: md5 = 20e2b8d4859f5471bf67307ecff9f012 OK
2024/11/06 05:01:18 DEBUG : empty space: md5 = 80a2416e9c3ece78f4318e939dccf720 OK
2024/11/06 05:01:19 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/06 05:01:19 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:01:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:01:19 DEBUG : empty space: Unchanged skipping
2024/11/06 05:01:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:01:21 DEBUG : potato2: md5 = d81af3de9a1f79a33e5bba68fd68da84 OK
2024/11/06 05:01:21 INFO  : potato2: Copied (new)
2024/11/06 05:01:21 DEBUG : Waiting for deletions to finish
2024/11/06 05:01:22 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (9.89s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:01:27 DEBUG : b/potato: md5 = 6d2fa411b517d558f26c969a2018928c OK
2024/11/06 05:01:30 DEBUG : c/non empty space: md5 = 25c708476c373da1e2b8ab61c18025ba OK
2024/11/06 05:01:30 DEBUG : d: Making directory
2024/11/06 05:01:32 DEBUG : d/e: Making directory
2024/11/06 05:01:34 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/06 05:01:34 DEBUG : Added delayed dir = "c", newDst=c
2024/11/06 05:01:34 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/06 05:01:34 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:01:34 DEBUG : c/non empty space: Unchanged skipping
2024/11/06 05:01:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:01:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:01:37 DEBUG : a/potato2: md5 = aa299fbc1cb7dd4c2d547342da995b7b OK
2024/11/06 05:01:37 INFO  : a/potato2: Copied (new)
2024/11/06 05:01:37 DEBUG : Waiting for deletions to finish
2024/11/06 05:01:38 INFO  : b/potato: Deleted
2024/11/06 05:01:39 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/06 05:01:39 INFO  : d/e: Removing directory
2024/11/06 05:01:40 INFO  : d: Removing directory
2024/11/06 05:01:40 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2024/11/06 05:01:40 INFO  : b: Removing directory
2024/11/06 05:01:41 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/06 05:01:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:01:44 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/06 05:01:45 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (22.27s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:01:50 DEBUG : b/potato: md5 = 3a4a006b5872f3f896557de638da8740 OK
2024/11/06 05:01:53 DEBUG : c/non empty space: md5 = 4cbb5b8394f1415d1d346b16ef66f341 OK
2024/11/06 05:01:53 DEBUG : d: Making directory
2024/11/06 05:01:55 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/06 05:01:55 DEBUG : Added delayed dir = "c", newDst=c
2024/11/06 05:01:55 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/06 05:01:55 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:01:55 DEBUG : c/non empty space: Unchanged skipping
2024/11/06 05:01:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:01:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:01:58 DEBUG : a/potato2: md5 = 2c1bcd33eb7ed731747e057c0dee6f3b OK
2024/11/06 05:01:58 INFO  : a/potato2: Copied (new)
2024/11/06 05:01:58 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': not deleting files as there were IO errors
2024/11/06 05:01:58 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/06 05:01:58 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:02:03 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/06 05:02:04 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/06 05:02:05 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (19.52s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:02:08 DEBUG : potato: md5 = 31361390f297765d54b01fc7c275413a OK
2024/11/06 05:02:10 DEBUG : empty space: md5 = 3675dc84d2ad30d823a59acdfe83051b OK
2024/11/06 05:02:10 DEBUG : Waiting for deletions to finish
2024/11/06 05:02:10 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/06 05:02:10 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:02:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:02:10 DEBUG : empty space: Unchanged skipping
2024/11/06 05:02:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:02:11 INFO  : potato: Deleted
2024/11/06 05:02:12 DEBUG : potato2: md5 = e9ac5b2c4134c4507d377d7fb098aef0 OK
2024/11/06 05:02:12 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (8.81s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:02:17 DEBUG : potato: md5 = 9f1c8ae94cea03c08a1562417dd2554f OK
2024/11/06 05:02:19 DEBUG : empty space: md5 = 588782384acc954c68c6784cdbe95d88 OK
2024/11/06 05:02:19 DEBUG : Waiting for deletions to finish
2024/11/06 05:02:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:02:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:02:20 INFO  : potato: Deleted
2024/11/06 05:02:20 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/06 05:02:20 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:02:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:02:20 DEBUG : empty space: Unchanged skipping
2024/11/06 05:02:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:02:22 DEBUG : potato2: md5 = d7edae40fdcec7f1d35e486d80b4be7c OK
2024/11/06 05:02:22 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (10.04s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:02:27 DEBUG : potato: md5 = a450932f6ad6a871e6e60a47b53e2bce OK
2024/11/06 05:02:28 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/06 05:02:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:02:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:02:30 DEBUG : potato2: md5 = 406142471659cd7d597b82fe21026b15 OK
2024/11/06 05:02:30 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (7.37s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:02:34 DEBUG : potato2: md5 = 989be4305f7ca67849f0108cf59e0f79 OK
2024/11/06 05:02:36 DEBUG : empty space: md5 = 20e0841dd34b0a13e59a15c6a7d2b7dc OK
2024/11/06 05:02:37 DEBUG : enormous: Excluded (Size Filter)
2024/11/06 05:02:37 DEBUG : enormous: Excluded
2024/11/06 05:02:37 DEBUG : potato2: Excluded (Size Filter)
2024/11/06 05:02:37 DEBUG : potato2: Excluded
2024/11/06 05:02:37 DEBUG : potato2: Excluded (Size Filter)
2024/11/06 05:02:37 DEBUG : potato2: Excluded
2024/11/06 05:02:37 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:02:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:02:37 DEBUG : empty space: Unchanged skipping
2024/11/06 05:02:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:02:37 DEBUG : Waiting for deletions to finish
2024/11/06 05:02:37 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:02:37 DEBUG : enormous: Excluded (Size Filter)
2024/11/06 05:02:37 DEBUG : enormous: Excluded
2024/11/06 05:02:37 DEBUG : potato2: Excluded (Size Filter)
2024/11/06 05:02:37 DEBUG : potato2: Excluded
2024/11/06 05:02:37 DEBUG : potato2: Excluded (Size Filter)
2024/11/06 05:02:37 DEBUG : potato2: Excluded
2024/11/06 05:02:37 DEBUG : Local file system at /tmp/rclone884933605: Waiting for checks to finish
2024/11/06 05:02:37 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/11/06 05:02:37 DEBUG : empty space: Unchanged skipping
2024/11/06 05:02:37 DEBUG : Local file system at /tmp/rclone884933605: Waiting for transfers to finish
2024/11/06 05:02:37 DEBUG : Waiting for deletions to finish
2024/11/06 05:02:37 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncWithExclude (10.03s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:02:44 DEBUG : potato2: md5 = e1162c88b22a80d9c40aa36a1d161721 OK
2024/11/06 05:02:47 DEBUG : empty space: md5 = 027afee1ef12c829088ecd38ecc3cb5f OK
2024/11/06 05:02:48 DEBUG : enormous: md5 = 874f3bb4ec8c3d4cff09ee810a2affcd OK
2024/11/06 05:02:49 DEBUG : enormous: Excluded (Size Filter)
2024/11/06 05:02:49 DEBUG : enormous: Excluded
2024/11/06 05:02:49 DEBUG : potato2: Excluded (Size Filter)
2024/11/06 05:02:49 DEBUG : potato2: Excluded
2024/11/06 05:02:49 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:02:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:02:49 DEBUG : empty space: Unchanged skipping
2024/11/06 05:02:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:02:49 DEBUG : Waiting for deletions to finish
2024/11/06 05:02:50 INFO  : potato2: Deleted
2024/11/06 05:02:50 INFO  : enormous: Deleted
2024/11/06 05:02:50 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:02:50 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/11/06 05:02:50 DEBUG : Local file system at /tmp/rclone884933605: Waiting for checks to finish
2024/11/06 05:02:50 DEBUG : empty space: Unchanged skipping
2024/11/06 05:02:50 DEBUG : Local file system at /tmp/rclone884933605: Waiting for transfers to finish
2024/11/06 05:02:50 DEBUG : Waiting for deletions to finish
2024/11/06 05:02:50 INFO  : enormous: Deleted
2024/11/06 05:02:50 INFO  : potato2: Deleted
2024/11/06 05:02:50 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (10.20s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:02:54 DEBUG : one: md5 = 9b132338afde868dca87cd9fd5b0ccf5 OK
2024/11/06 05:02:56 DEBUG : two: md5 = 5f67659f07afd0f9f9a5e89dc389cf1c OK
2024/11/06 05:02:58 DEBUG : three: md5 = e5c76f661f251a3d04f1599d2a67c9e8 OK
2024/11/06 05:03:00 DEBUG : four: md5 = cc141ea64c82c629a25ad7430a639342 OK
2024/11/06 05:03:01 DEBUG : five: Need to transfer - File not found at Destination
2024/11/06 05:03:01 DEBUG : four: Sizes differ (src 4 vs dst 8)
2024/11/06 05:03:01 DEBUG : one: Destination is newer than source, skipping
2024/11/06 05:03:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:03:01 DEBUG : three: Sizes identical
2024/11/06 05:03:01 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2024/11/06 05:03:01 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2024/11/06 05:03:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:03:02 DEBUG : four: md5 = 48f676dad53cefb2489f8df8c3fdada8 OK
2024/11/06 05:03:02 INFO  : four: Copied (replaced existing)
2024/11/06 05:03:02 DEBUG : two: md5 = 94ab627fdc9461f416319e781b9defca OK
2024/11/06 05:03:02 INFO  : two: Copied (replaced existing)
2024/11/06 05:03:03 DEBUG : five: md5 = 72009518b10f41172eb6471c4864ea07 OK
2024/11/06 05:03:03 INFO  : five: Copied (new)
2024/11/06 05:03:03 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (14.51s)
=== 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-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2024/11/06 05:03:07 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Ignoring --track-renames as the source and destination do not have a common hash
2024/11/06 05:03:07 DEBUG : potato: Need to transfer - File not found at Destination
2024/11/06 05:03:07 DEBUG : yam: Need to transfer - File not found at Destination
2024/11/06 05:03:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:03:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:03:09 DEBUG : potato: md5 = 60d0131f035d0afb596f43fd145b4598 OK
2024/11/06 05:03:09 INFO  : potato: Copied (new)
2024/11/06 05:03:09 DEBUG : yam: md5 = 1c0ffea19d3a771e81ee55c314c49f17 OK
2024/11/06 05:03:09 INFO  : yam: Copied (new)
2024/11/06 05:03:09 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:03:09 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Ignoring --track-renames as the source and destination do not have a common hash
2024/11/06 05:03:10 DEBUG : yaml: Need to transfer - File not found at Destination
2024/11/06 05:03:10 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:03:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:03:10 DEBUG : potato: Unchanged skipping
2024/11/06 05:03:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:03:12 DEBUG : yaml: md5 = e23c6cbe694216d19aff4a67974fa326 OK
2024/11/06 05:03:12 INFO  : yaml: Copied (new)
2024/11/06 05:03:12 DEBUG : Waiting for deletions to finish
2024/11/06 05:03:12 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (8.61s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2024/11/06 05:03:16 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Making map for --track-renames
2024/11/06 05:03:16 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Finished making map for --track-renames
2024/11/06 05:03:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:03:16 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/11/06 05:03:16 DEBUG : yam: Need to transfer - No matching file found at Destination
2024/11/06 05:03:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for renames to finish
2024/11/06 05:03:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:03:18 DEBUG : yam: md5 = 62303e8207f93c63759196d6eacc4281 OK
2024/11/06 05:03:18 INFO  : yam: Copied (new)
2024/11/06 05:03:18 DEBUG : potato: md5 = 7fa8ddbdc1d3e3f3df33b4b2fdbca258 OK
2024/11/06 05:03:18 INFO  : potato: Copied (new)
2024/11/06 05:03:18 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:03:18 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:03:18 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Making map for --track-renames
2024/11/06 05:03:18 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Finished making map for --track-renames
2024/11/06 05:03:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:03:18 DEBUG : potato: Unchanged skipping
2024/11/06 05:03:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for renames to finish
2024/11/06 05:03:19 INFO  : yam: Moved (server-side) to: yaml
2024/11/06 05:03:19 INFO  : yaml: Renamed from "yam"
2024/11/06 05:03:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:03:19 DEBUG : Waiting for deletions to finish
2024/11/06 05:03:19 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (6.82s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2024/11/06 05:03:23 DEBUG : Added delayed dir = "sub", newDst=<nil>
2024/11/06 05:03:23 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Making map for --track-renames
2024/11/06 05:03:23 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Finished making map for --track-renames
2024/11/06 05:03:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:03:23 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/11/06 05:03:23 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2024/11/06 05:03:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for renames to finish
2024/11/06 05:03:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:03:26 DEBUG : sub/yam: md5 = 19b542e95795593348fe2328733b6a26 OK
2024/11/06 05:03:26 INFO  : sub/yam: Copied (new)
2024/11/06 05:03:26 DEBUG : potato: md5 = 66875850d80ff4c65fbdcdd0a1c282fb OK
2024/11/06 05:03:26 INFO  : potato: Copied (new)
2024/11/06 05:03:26 DEBUG : Waiting for deletions to finish
2024/11/06 05:03:27 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:03:28 DEBUG : Added delayed dir = "sub", newDst=sub
2024/11/06 05:03:28 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:03:28 DEBUG : potato: Unchanged skipping
2024/11/06 05:03:28 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Making map for --track-renames
2024/11/06 05:03:28 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Finished making map for --track-renames
2024/11/06 05:03:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:03:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for renames to finish
2024/11/06 05:03:29 INFO  : sub/yam: Moved (server-side) to: yam
2024/11/06 05:03:29 INFO  : yam: Renamed from "sub/yam"
2024/11/06 05:03:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:03:29 DEBUG : Waiting for deletions to finish
2024/11/06 05:03:29 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (11.71s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:03:34 DEBUG : Creating backend with remote "/tmp/rclone884933605/dir1"
2024/11/06 05:03:34 DEBUG : Config file has changed externally - reloading
2024/11/06 05:03:34 DEBUG : Creating backend with remote "/tmp/rclone884933605/dir2"
2024/11/06 05:03:34 DEBUG : Local file system at /tmp/rclone884933605/dir2: Using server-side directory move
2024/11/06 05:03:34 INFO  : Local file system at /tmp/rclone884933605/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/06 05:03:34 DEBUG : file1.txt: Need to transfer - File not found at Destination
2024/11/06 05:03:34 INFO  : file1.txt: Moved (server-side)
2024/11/06 05:03:34 DEBUG : Local file system at /tmp/rclone884933605/dir2: Waiting for checks to finish
2024/11/06 05:03:34 DEBUG : Local file system at /tmp/rclone884933605/dir2: Waiting for transfers to finish
--- PASS: TestServerSideMoveLocal (0.49s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:03:35 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/11/06 05:03:35 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/06 05:03:35 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/06 05:03:35 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/11/06 05:03:35 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/11/06 05:03:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:03:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:03:38 DEBUG : sub dir/hello world: md5 = 855bcf59d316ff6672cad271d1be7b29 OK
2024/11/06 05:03:38 INFO  : sub dir/hello world: Copied (new)
2024/11/06 05:03:38 INFO  : sub dir/hello world: Deleted
2024/11/06 05:03:41 DEBUG : nested/sub dir/file: md5 = 36c538cf8f4104d0ce3267e630d54f38 OK
2024/11/06 05:03:41 INFO  : nested/sub dir/file: Copied (new)
2024/11/06 05:03:41 INFO  : nested/sub dir/file: Deleted
2024/11/06 05:03:42 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/11/06 05:03:42 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/06 05:03:42 INFO  : nested: Set directory modification time (using DirSetModTime)
2024/11/06 05:03:42 INFO  : sub dir: Removing directory
2024/11/06 05:03:42 INFO  : nested/sub dir: Removing directory
2024/11/06 05:03:42 INFO  : nested: Removing directory
2024/11/06 05:03:42 DEBUG : Local file system at /tmp/rclone884933605: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:03:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/06 05:03:47 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/11/06 05:03:48 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (14.31s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:03:49 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/11/06 05:03:49 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/06 05:03:49 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/06 05:03:49 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/11/06 05:03:49 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/11/06 05:03:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:03:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:03:52 DEBUG : sub dir/hello world: md5 = da3e8ca9f638075687812d7876177d6f OK
2024/11/06 05:03:52 INFO  : sub dir/hello world: Copied (new)
2024/11/06 05:03:52 INFO  : sub dir/hello world: Deleted
2024/11/06 05:03:55 DEBUG : nested/sub dir/file: md5 = cca12a79b850d0177eccf6ed9c67aae8 OK
2024/11/06 05:03:55 INFO  : nested/sub dir/file: Copied (new)
2024/11/06 05:03:55 INFO  : nested/sub dir/file: Deleted
2024/11/06 05:03:56 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/11/06 05:03:57 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/06 05:03:57 INFO  : nested: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:04:00 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/06 05:04:01 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/11/06 05:04:02 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (14.25s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:04:04 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/06 05:04:04 DEBUG : existing-b: Need to transfer - File not found at Destination
2024/11/06 05:04:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:04:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:04:05 DEBUG : existing: md5 = e30339dff530630c548de0235ce9def7 OK
2024/11/06 05:04:05 INFO  : existing: Copied (new)
2024/11/06 05:04:05 INFO  : existing: Deleted
2024/11/06 05:04:05 DEBUG : existing-b: md5 = ff01669b18771e77eeb8288682601fc3 OK
2024/11/06 05:04:05 INFO  : existing-b: Copied (new)
2024/11/06 05:04:05 INFO  : existing-b: Deleted
2024/11/06 05:04:06 DEBUG : existing: Destination exists, skipping
2024/11/06 05:04:06 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2024/11/06 05:04:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:04:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:04:06 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (5.45s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:04:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yozopaj7ruwu"
2024/11/06 05:04:09 DEBUG : Creating backend with remote "TestDrive:crypt/pkfm9d3rbo1dcmbbsru109jr8uiak4bt2ppksgdbufpm9chb3jf0"
2024/11/06 05:04:12 DEBUG : potato2: md5 = 2a42dfbbd8f3a2e0f1118997d7360898 OK
2024/11/06 05:04:14 DEBUG : empty space: md5 = df13ecdee3b0f786982f4cd7eea9f6c8 OK
2024/11/06 05:04:16 DEBUG : potato3: md5 = a26b33ae4bbe34458aa184a307ba7b2e OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate' -> Encrypted drive 'TestCryptDrive:rclone-test-yozopaj7ruwu'
2024/11/06 05:04:19 DEBUG : empty space: md5 = 9c40a324ed86e8f6d7d0bb0953b67466 OK
2024/11/06 05:04:21 DEBUG : potato3: md5 = 4f48b5fa88e0d0cf42c7841e280ab5af OK
2024/11/06 05:04:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yozopaj7ruwu': Using server-side directory move
2024/11/06 05:04:21 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-yozopaj7ruwu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/06 05:04:21 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/06 05:04:21 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/11/06 05:04:21 DEBUG : empty space: Unchanged skipping
2024/11/06 05:04:21 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/06 05:04:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yozopaj7ruwu': Waiting for checks to finish
2024/11/06 05:04:22 INFO  : empty space: Deleted
2024/11/06 05:04:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yozopaj7ruwu': Waiting for transfers to finish
2024/11/06 05:04:22 INFO  : potato3: Deleted
2024/11/06 05:04:22 INFO  : potato2: Moved (server-side)
2024/11/06 05:04:23 INFO  : potato3: Moved (server-side)
2024/11/06 05:04:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-watanoj5jofu"
2024/11/06 05:04:24 DEBUG : Creating backend with remote "TestDrive:crypt/vrbta1f5vojledhh15gq4fbivnric7ir02v6u7q1ddcg6u15acm0"
2024/11/06 05:04:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-watanoj5jofu': Using server-side directory move
2024/11/06 05:04:26 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-watanoj5jofu': Server side directory move succeeded
2024/11/06 05:04:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-watanoj5jofu': Purge remote
2024/11/06 05:04:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yozopaj7ruwu': Purge remote
2024/11/06 05:04:28 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (19.66s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:04:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hinicah9qoce"
2024/11/06 05:04:28 DEBUG : Creating backend with remote "TestDrive:crypt/ds8u1ui0v56lk8dhddlfgi3tpoo3vqbhh2cps8p8qr7g43lba650"
2024/11/06 05:04:31 DEBUG : potato2: md5 = ee3a859f210555923fdec79f2fd2624f OK
2024/11/06 05:04:33 DEBUG : empty space: md5 = dbfb0b0c4cbbfe5b7b963fc429b51c88 OK
2024/11/06 05:04:35 DEBUG : potato3: md5 = 7a933e95cb1b51e27dd3314b22306c62 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate' -> Encrypted drive 'TestCryptDrive:rclone-test-hinicah9qoce'
2024/11/06 05:04:38 DEBUG : empty space: md5 = 9a13eac473c2674e14ff1d6676873715 OK
2024/11/06 05:04:40 DEBUG : potato3: md5 = 88efdbb0378eb43833edb92d17d6f2ca OK
2024/11/06 05:04:41 DEBUG : empty space: Excluded (Size Filter)
2024/11/06 05:04:41 DEBUG : empty space: Excluded
2024/11/06 05:04:41 DEBUG : empty space: Excluded (Size Filter)
2024/11/06 05:04:41 DEBUG : empty space: Excluded
2024/11/06 05:04:41 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/06 05:04:41 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/06 05:04:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hinicah9qoce': Waiting for checks to finish
2024/11/06 05:04:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hinicah9qoce': Waiting for transfers to finish
2024/11/06 05:04:41 INFO  : potato3: Deleted
2024/11/06 05:04:42 INFO  : potato2: Moved (server-side)
2024/11/06 05:04:42 INFO  : potato3: Moved (server-side)
2024/11/06 05:04:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-niwicas5xohu"
2024/11/06 05:04:43 DEBUG : Config file has changed externally - reloading
2024/11/06 05:04:43 DEBUG : Creating backend with remote "TestDrive:crypt/kvqcheaiu01tnccd96b644g75u0g5f25ltbbih07h0aqf0v14h4g"
2024/11/06 05:04:44 DEBUG : empty space: Excluded (Size Filter)
2024/11/06 05:04:44 DEBUG : empty space: Excluded
2024/11/06 05:04:44 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/06 05:04:44 DEBUG : potato3: Need to transfer - File not found at Destination
2024/11/06 05:04:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-niwicas5xohu': Waiting for checks to finish
2024/11/06 05:04:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-niwicas5xohu': Waiting for transfers to finish
2024/11/06 05:04:47 INFO  : potato2: Moved (server-side)
2024/11/06 05:04:47 INFO  : potato3: Moved (server-side)
2024/11/06 05:04:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-niwicas5xohu': Purge remote
2024/11/06 05:04:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hinicah9qoce': Purge remote
--- PASS: TestServerSideMoveWithFilter (22.63s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:04:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rewokil2hiva"
2024/11/06 05:04:51 DEBUG : Creating backend with remote "TestDrive:crypt/rgpci762nt00b4i0768s282odhl4un6ppd5rhtm3q51tes7tae8g"
2024/11/06 05:04:54 DEBUG : potato2: md5 = 0a2b3ec41f22667304bdf35c5804ac0e OK
2024/11/06 05:04:56 DEBUG : empty space: md5 = 3701c789bb6ebff57697c12fc7de2f45 OK
2024/11/06 05:04:58 DEBUG : potato3: md5 = 9c8c93cf3ea51c3cf35ee45c7baf1ecc OK
2024/11/06 05:04:58 DEBUG : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate' -> Encrypted drive 'TestCryptDrive:rclone-test-rewokil2hiva'
2024/11/06 05:05:03 DEBUG : empty space: md5 = 02fb83e55ff8f1441384e7a5e2fdc8b3 OK
2024/11/06 05:05:05 DEBUG : potato3: md5 = 7d7ff4837d52bb2f584dc77fcb521d2e OK
2024/11/06 05:05:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rewokil2hiva': Using server-side directory move
2024/11/06 05:05:05 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-rewokil2hiva': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/06 05:05:05 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/06 05:05:05 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2024/11/06 05:05:05 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/11/06 05:05:05 DEBUG : empty space: Unchanged skipping
2024/11/06 05:05:05 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/06 05:05:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rewokil2hiva': Waiting for checks to finish
2024/11/06 05:05:06 INFO  : potato3: Deleted
2024/11/06 05:05:06 INFO  : empty space: Deleted
2024/11/06 05:05:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rewokil2hiva': Waiting for transfers to finish
2024/11/06 05:05:06 INFO  : potato2: Moved (server-side)
2024/11/06 05:05:07 INFO  : potato3: Moved (server-side)
2024/11/06 05:05:07 INFO  : tomatoDir: Removing directory
2024/11/06 05:05:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': deleted 1 directories
2024/11/06 05:05:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-colodat4kobu"
2024/11/06 05:05:09 DEBUG : Creating backend with remote "TestDrive:crypt/aob21fgnscuqt4r7npjt8iphk3hstv0ss0hjnmd158eqv98n4qv0"
2024/11/06 05:05:10 DEBUG : tomatoDir: Making directory
2024/11/06 05:05:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-colodat4kobu': Using server-side directory move
2024/11/06 05:05:12 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-colodat4kobu': Server side directory move succeeded
2024/11/06 05:05:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-colodat4kobu': Purge remote
2024/11/06 05:05:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rewokil2hiva': Purge remote
2024/11/06 05:05:14 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (23.73s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.53s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:05:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/rclone-sync-test"
2024/11/06 05:05:15 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncOverlap (4.13s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:05:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/rclone-sync-test"
2024/11/06 05:05:19 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2024/11/06 05:05:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/rclone-sync-test-include/layer2"
2024/11/06 05:05:22 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2024/11/06 05:05:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/rclone-sync-test-ignore-file"
2024/11/06 05:05:26 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2024/11/06 05:05:31 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 059e6947370446262b2a87dbea2ae72c OK
2024/11/06 05:05:32 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/11/06 05:05:33 DEBUG : rclone-sync-test: Excluded
2024/11/06 05:05:33 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/06 05:05:33 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/11/06 05:05:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/rclone-sync-test': Waiting for checks to finish
2024/11/06 05:05:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/rclone-sync-test': Waiting for transfers to finish
2024/11/06 05:05:33 DEBUG : Waiting for deletions to finish
2024/11/06 05:05:33 INFO  : There was nothing to transfer
2024/11/06 05:05:34 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/11/06 05:05:35 DEBUG : rclone-sync-test: Excluded
2024/11/06 05:05:35 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/11/06 05:05:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:05:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:05:35 DEBUG : Waiting for deletions to finish
2024/11/06 05:05:35 INFO  : rclone-sync-test-include: Removing directory
2024/11/06 05:05:35 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/06 05:05:35 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/11/06 05:05:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': failed to delete 1 directories
2024/11/06 05:05:35 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:05:36 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/11/06 05:05:37 DEBUG : rclone-sync-test: Excluded
2024/11/06 05:05:37 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/06 05:05:37 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/11/06 05:05:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/rclone-sync-test-include/layer2': Waiting for checks to finish
2024/11/06 05:05:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/rclone-sync-test-include/layer2': Waiting for transfers to finish
2024/11/06 05:05:37 DEBUG : Waiting for deletions to finish
2024/11/06 05:05:37 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:05:38 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/11/06 05:05:38 DEBUG : rclone-sync-test: Excluded
2024/11/06 05:05:39 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/11/06 05:05:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:05:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:05:39 DEBUG : Waiting for deletions to finish
2024/11/06 05:05:39 INFO  : rclone-sync-test-include: Removing directory
2024/11/06 05:05:39 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/06 05:05:39 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/11/06 05:05:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': failed to delete 1 directories
2024/11/06 05:05:39 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:05:40 DEBUG : : Excluded
2024/11/06 05:05:40 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/11/06 05:05:41 DEBUG : rclone-sync-test: Excluded
2024/11/06 05:05:41 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/06 05:05:41 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/11/06 05:05:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/rclone-sync-test-ignore-file': Waiting for checks to finish
2024/11/06 05:05:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/rclone-sync-test-ignore-file': Waiting for transfers to finish
2024/11/06 05:05:41 DEBUG : Waiting for deletions to finish
2024/11/06 05:05:41 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:05:44 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/06 05:05:45 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (35.89s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:05:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/dst"
2024/11/06 05:05:55 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/06 05:05:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/CompareDest"
2024/11/06 05:05:57 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/gveqi14airsml4bgu7krj116o8"
2024/11/06 05:05:59 DEBUG : one: Need to transfer - File not found at Destination
2024/11/06 05:05:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for checks to finish
2024/11/06 05:05:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for transfers to finish
2024/11/06 05:06:02 DEBUG : one: md5 = 6fe815f9348c3b32f6a9fd0b91a38cbb OK
2024/11/06 05:06:02 INFO  : one: Copied (new)
2024/11/06 05:06:02 DEBUG : Waiting for deletions to finish
2024/11/06 05:06:04 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/06 05:06:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for checks to finish
2024/11/06 05:06:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for transfers to finish
2024/11/06 05:06:05 DEBUG : one: md5 = 8b4c15e9b7ab74bbc4a9c5e124f99870 OK
2024/11/06 05:06:05 INFO  : one: Copied (replaced existing)
2024/11/06 05:06:05 DEBUG : Waiting for deletions to finish
2024/11/06 05:06:08 DEBUG : dst/one: md5 = 6b78bf8717965367bfd61fe7485d6494 OK
2024/11/06 05:06:11 DEBUG : CompareDest/one: md5 = 35139225b509e1d376e2ec8b816cb038 OK
2024/11/06 05:06:12 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/06 05:06:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for checks to finish
2024/11/06 05:06:12 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:06:12 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/06 05:06:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for transfers to finish
2024/11/06 05:06:12 DEBUG : Waiting for deletions to finish
2024/11/06 05:06:12 INFO  : There was nothing to transfer
2024/11/06 05:06:14 DEBUG : CompareDest/two: md5 = d8a1cef91d15a351159f4dbe5305a012 OK
2024/11/06 05:06:16 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:06:16 DEBUG : two: Destination found in --compare-dest, skipping
2024/11/06 05:06:16 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/06 05:06:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for checks to finish
2024/11/06 05:06:16 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:06:16 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/06 05:06:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for transfers to finish
2024/11/06 05:06:16 DEBUG : Waiting for deletions to finish
2024/11/06 05:06:16 INFO  : There was nothing to transfer
2024/11/06 05:06:17 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:06:17 DEBUG : two: Destination found in --compare-dest, skipping
2024/11/06 05:06:17 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/06 05:06:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for checks to finish
2024/11/06 05:06:17 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:06:17 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/06 05:06:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for transfers to finish
2024/11/06 05:06:17 DEBUG : Waiting for deletions to finish
2024/11/06 05:06:17 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2024/11/06 05:06:19 DEBUG : two: Sizes differ (src 5 vs dst 3)
2024/11/06 05:06:19 DEBUG : two: Need to transfer - File not found at Destination
2024/11/06 05:06:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for checks to finish
2024/11/06 05:06:19 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/06 05:06:19 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:06:19 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/06 05:06:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for transfers to finish
2024/11/06 05:06:21 DEBUG : two: md5 = 1b8411b024a4071d2e8b70951342e381 OK
2024/11/06 05:06:21 INFO  : two: Copied (new)
2024/11/06 05:06:21 DEBUG : Waiting for deletions to finish
2024/11/06 05:06:25 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/06 05:06:25 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/06 05:06:26 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/06 05:06:26 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncCompareDest (31.40s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:06:30 DEBUG : pre-dest1/1: md5 = c298191092556445c93e94219942f713 OK
2024/11/06 05:06:33 DEBUG : pre-dest2/2: md5 = 8b051c284ffa5bc8702a45fd9850829a OK
2024/11/06 05:06:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/dest"
2024/11/06 05:06:34 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/rg03c1jvnehrrc617i0lnqjddc"
2024/11/06 05:06:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/pre-dest1"
2024/11/06 05:06:35 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/bbnblvh6k061ssopqrp18kd7gc"
2024/11/06 05:06:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/pre-dest2"
2024/11/06 05:06:36 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/dgicm1h6b5ejvlltm8eeif0bnk"
2024/11/06 05:06:38 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:06:38 DEBUG : 1: Destination found in --compare-dest, skipping
2024/11/06 05:06:38 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:06:38 DEBUG : 2: Destination found in --compare-dest, skipping
2024/11/06 05:06:39 DEBUG : 3: Need to transfer - File not found at Destination
2024/11/06 05:06:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dest': Waiting for checks to finish
2024/11/06 05:06:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dest': Waiting for transfers to finish
2024/11/06 05:06:42 DEBUG : 3: md5 = c149d557c055d55610e68505b4c05b96 OK
2024/11/06 05:06:42 INFO  : 3: Copied (new)
2024/11/06 05:06:42 DEBUG : Waiting for deletions to finish
2024/11/06 05:06:45 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2024/11/06 05:06:46 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2024/11/06 05:06:47 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (21.18s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:06:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/dst"
2024/11/06 05:06:48 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/06 05:06:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/CopyDest"
2024/11/06 05:06:50 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/d09o6po3f7bm6ce32vdgs8h9ls"
2024/11/06 05:06:52 DEBUG : one: Need to transfer - File not found at Destination
2024/11/06 05:06:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for checks to finish
2024/11/06 05:06:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for transfers to finish
2024/11/06 05:06:55 DEBUG : one: md5 = 95041e11cbee70a84658eb18aa3e3af4 OK
2024/11/06 05:06:55 INFO  : one: Copied (new)
2024/11/06 05:06:55 DEBUG : Waiting for deletions to finish
2024/11/06 05:06:56 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/06 05:06:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for checks to finish
2024/11/06 05:06:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for transfers to finish
2024/11/06 05:06:58 DEBUG : one: md5 = aee796580fcfcadb4c85020133d33d4d OK
2024/11/06 05:06:58 INFO  : one: Copied (replaced existing)
2024/11/06 05:06:58 DEBUG : Waiting for deletions to finish
2024/11/06 05:07:00 DEBUG : dst/one: md5 = b32409ac0def8652fce57176afd63817 OK
2024/11/06 05:07:03 DEBUG : CopyDest/one: md5 = a80ed2e2326b9f3db283d39a978b97aa OK
2024/11/06 05:07:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/BackupDir"
2024/11/06 05:07:04 DEBUG : Config file has changed externally - reloading
2024/11/06 05:07:04 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/s6dbk3lfi7c9kfvo6j7bla9m0g"
2024/11/06 05:07:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for checks to finish
2024/11/06 05:07:06 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/06 05:07:06 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:07:06 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/06 05:07:09 INFO  : one: Moved (server-side)
2024/11/06 05:07:11 INFO  : one: Copied (server-side copy)
2024/11/06 05:07:11 DEBUG : one: Destination found in --copy-dest, using server-side copy
2024/11/06 05:07:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for transfers to finish
2024/11/06 05:07:11 DEBUG : Waiting for deletions to finish
2024/11/06 05:07:13 DEBUG : CopyDest/two: md5 = 7b37a84d9dd415a791f02a7dda03c230 OK
2024/11/06 05:07:14 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:07:16 INFO  : two: Copied (server-side copy)
2024/11/06 05:07:16 DEBUG : two: Destination found in --copy-dest, using server-side copy
2024/11/06 05:07:16 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:07:16 DEBUG : one: Unchanged skipping
2024/11/06 05:07:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for checks to finish
2024/11/06 05:07:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for transfers to finish
2024/11/06 05:07:16 DEBUG : Waiting for deletions to finish
2024/11/06 05:07:17 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:07:17 DEBUG : one: Unchanged skipping
2024/11/06 05:07:17 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:07:17 DEBUG : two: Unchanged skipping
2024/11/06 05:07:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for checks to finish
2024/11/06 05:07:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for transfers to finish
2024/11/06 05:07:17 DEBUG : Waiting for deletions to finish
2024/11/06 05:07:17 INFO  : There was nothing to transfer
2024/11/06 05:07:19 DEBUG : CopyDest/three: md5 = a1e37a022a214658433075d224a1ada5 OK
2024/11/06 05:07:20 DEBUG : three: Sizes differ (src 7 vs dst 5)
2024/11/06 05:07:20 DEBUG : three: Destination not found in --copy-dest
2024/11/06 05:07:20 DEBUG : three: Need to transfer - File not found at Destination
2024/11/06 05:07:20 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:07:20 DEBUG : one: Unchanged skipping
2024/11/06 05:07:20 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/06 05:07:20 DEBUG : two: Unchanged skipping
2024/11/06 05:07:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for checks to finish
2024/11/06 05:07:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for transfers to finish
2024/11/06 05:07:22 DEBUG : three: md5 = 9b427274c6430170d3b6d4d92049ba99 OK
2024/11/06 05:07:22 INFO  : three: Copied (new)
2024/11/06 05:07:22 DEBUG : Waiting for deletions to finish
2024/11/06 05:07:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/11/06 05:07:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/06 05:07:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/06 05:07:29 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/06 05:07:29 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/06 05:07:29 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/11/06 05:07:30 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (43.37s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:07:34 DEBUG : dst/one: md5 = 28f067ac0b192a693b9c80447926b5ca OK
2024/11/06 05:07:36 DEBUG : dst/two: md5 = ed92b90250d72bed18f93a21840aa171 OK
2024/11/06 05:07:38 DEBUG : dst/three.txt: md5 = e1262a56938bf55d5b956fc5adfb5bf8 OK
2024/11/06 05:07:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/dst"
2024/11/06 05:07:39 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/06 05:07:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/backup"
2024/11/06 05:07:39 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/1nrff024r7pq65ecp72fc28jb0"
2024/11/06 05:07:41 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/06 05:07:41 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:07:41 DEBUG : two: Unchanged skipping
2024/11/06 05:07:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for checks to finish
2024/11/06 05:07:44 INFO  : one: Moved (server-side)
2024/11/06 05:07:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for transfers to finish
2024/11/06 05:07:46 DEBUG : one: md5 = 738480c1e41719677991f09e8fa7a7ee OK
2024/11/06 05:07:46 INFO  : one: Copied (new)
2024/11/06 05:07:46 DEBUG : Waiting for deletions to finish
2024/11/06 05:07:47 INFO  : three.txt: Moved (server-side)
2024/11/06 05:07:47 INFO  : three.txt: Moved into backup dir
2024/11/06 05:07:50 DEBUG : dst/three.txt: md5 = aadb8007a3c0207248971f362e6b1a19 OK
2024/11/06 05:07:51 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/06 05:07:51 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:07:51 DEBUG : two: Unchanged skipping
2024/11/06 05:07:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for checks to finish
2024/11/06 05:07:51 INFO  : one: Deleted
2024/11/06 05:07:53 INFO  : one: Moved (server-side)
2024/11/06 05:07:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for transfers to finish
2024/11/06 05:07:55 DEBUG : one: md5 = 16c14de19c2e538035655a3458b9cbc3 OK
2024/11/06 05:07:55 INFO  : one: Copied (new)
2024/11/06 05:07:55 DEBUG : Waiting for deletions to finish
2024/11/06 05:07:56 INFO  : three.txt: Deleted
2024/11/06 05:07:57 INFO  : three.txt: Moved (server-side)
2024/11/06 05:07:57 INFO  : three.txt: Moved into backup dir
2024/11/06 05:08:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/06 05:08:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/06 05:08:02 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/06 05:08:02 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/06 05:08:02 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/06 05:08:02 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
--- PASS: TestSyncBackupDir (31.58s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:08:06 DEBUG : dst/one: md5 = cdd65e05b0334f1a6eeccebf4f753f7d OK
2024/11/06 05:08:08 DEBUG : dst/two: md5 = e1d4453f439ae15c94aff683dc90c3d1 OK
2024/11/06 05:08:10 DEBUG : dst/three.txt: md5 = e1374461c9779aafe0a35f58f632f873 OK
2024/11/06 05:08:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/dst"
2024/11/06 05:08:11 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/06 05:08:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/backup"
2024/11/06 05:08:11 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/1nrff024r7pq65ecp72fc28jb0"
2024/11/06 05:08:14 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/06 05:08:14 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:08:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for checks to finish
2024/11/06 05:08:14 DEBUG : two: Unchanged skipping
2024/11/06 05:08:16 INFO  : one: Moved (server-side) to: one.bak
2024/11/06 05:08:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for transfers to finish
2024/11/06 05:08:18 DEBUG : one: md5 = b5b6f2033b4e603c40ba562beb2f88b7 OK
2024/11/06 05:08:18 INFO  : one: Copied (new)
2024/11/06 05:08:18 DEBUG : Waiting for deletions to finish
2024/11/06 05:08:19 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/06 05:08:19 INFO  : three.txt: Moved into backup dir
2024/11/06 05:08:22 DEBUG : dst/three.txt: md5 = 598ab6be3470917ed0efa444808f5aea OK
2024/11/06 05:08:23 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/06 05:08:23 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:08:23 DEBUG : two: Unchanged skipping
2024/11/06 05:08:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for checks to finish
2024/11/06 05:08:24 INFO  : one.bak: Deleted
2024/11/06 05:08:25 INFO  : one: Moved (server-side) to: one.bak
2024/11/06 05:08:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for transfers to finish
2024/11/06 05:08:27 DEBUG : one: md5 = d532e7714e48b8a2a07c54efa44080a7 OK
2024/11/06 05:08:27 INFO  : one: Copied (new)
2024/11/06 05:08:27 DEBUG : Waiting for deletions to finish
2024/11/06 05:08:28 INFO  : three.txt.bak: Deleted
2024/11/06 05:08:29 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/06 05:08:29 INFO  : three.txt: Moved into backup dir
2024/11/06 05:08:33 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/06 05:08:33 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/06 05:08:35 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/06 05:08:35 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/06 05:08:35 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/06 05:08:35 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncBackupDirWithSuffix (32.74s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:08:39 DEBUG : dst/one: md5 = 6fc780fe54c9bf780a7a4af56c1fcd29 OK
2024/11/06 05:08:41 DEBUG : dst/two: md5 = 1e3d16b62eda9572e1d94e65e89803ad OK
2024/11/06 05:08:43 DEBUG : dst/three.txt: md5 = fbe8777e3822c9f75f2ead4a5f72db73 OK
2024/11/06 05:08:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/dst"
2024/11/06 05:08:43 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/06 05:08:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/backup"
2024/11/06 05:08:44 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/1nrff024r7pq65ecp72fc28jb0"
2024/11/06 05:08:46 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/06 05:08:46 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:08:46 DEBUG : two: Unchanged skipping
2024/11/06 05:08:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for checks to finish
2024/11/06 05:08:48 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/06 05:08:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for transfers to finish
2024/11/06 05:08:50 DEBUG : one: md5 = 27209c9f9dc47014d2a1c0314eee0f96 OK
2024/11/06 05:08:50 INFO  : one: Copied (new)
2024/11/06 05:08:50 DEBUG : Waiting for deletions to finish
2024/11/06 05:08:51 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/06 05:08:51 INFO  : three.txt: Moved into backup dir
2024/11/06 05:08:54 DEBUG : dst/three.txt: md5 = 21110eff56d6412bc8c48acb7adf7659 OK
2024/11/06 05:08:55 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/06 05:08:55 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:08:55 DEBUG : two: Unchanged skipping
2024/11/06 05:08:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for checks to finish
2024/11/06 05:08:56 INFO  : one-2019-01-01: Deleted
2024/11/06 05:08:57 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/06 05:08:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for transfers to finish
2024/11/06 05:08:59 DEBUG : one: md5 = dd3c1653d0440ede441c595e335b4cee OK
2024/11/06 05:08:59 INFO  : one: Copied (new)
2024/11/06 05:08:59 DEBUG : Waiting for deletions to finish
2024/11/06 05:09:00 INFO  : three-2019-01-01.txt: Deleted
2024/11/06 05:09:01 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/06 05:09:01 INFO  : three.txt: Moved into backup dir
2024/11/06 05:09:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/06 05:09:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/06 05:09:06 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/06 05:09:06 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/06 05:09:06 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/06 05:09:06 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (31.21s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:09:10 DEBUG : dst/one: md5 = 1385ebc9bef7a62b93e627a51e912c22 OK
2024/11/06 05:09:12 DEBUG : dst/two: md5 = 899a71e3ec93e36708d8178eb122a1b7 OK
2024/11/06 05:09:13 DEBUG : dst/three.txt: md5 = 07de799930154f5555565acade6b08a3 OK
2024/11/06 05:09:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/dst"
2024/11/06 05:09:14 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/06 05:09:15 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/06 05:09:15 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:09:15 DEBUG : two: Unchanged skipping
2024/11/06 05:09:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for checks to finish
2024/11/06 05:09:16 INFO  : one: Moved (server-side) to: one.bak
2024/11/06 05:09:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for transfers to finish
2024/11/06 05:09:18 DEBUG : one: md5 = 71ade3d5fedd5b41f00eb10da1c7cde8 OK
2024/11/06 05:09:18 INFO  : one: Copied (new)
2024/11/06 05:09:18 DEBUG : Waiting for deletions to finish
2024/11/06 05:09:19 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/06 05:09:19 INFO  : three.txt: Moved into backup dir
2024/11/06 05:09:21 DEBUG : dst/three.txt: md5 = 2a6729277c66e9a20de65a719a5c0fa5 OK
2024/11/06 05:09:22 DEBUG : three.txt.bak: Excluded (Path Filter)
2024/11/06 05:09:22 DEBUG : three.txt.bak: Excluded
2024/11/06 05:09:22 DEBUG : one.bak: Excluded (Path Filter)
2024/11/06 05:09:22 DEBUG : one.bak: Excluded
2024/11/06 05:09:22 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/06 05:09:22 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:09:22 DEBUG : two: Unchanged skipping
2024/11/06 05:09:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for checks to finish
2024/11/06 05:09:23 INFO  : one.bak: Deleted
2024/11/06 05:09:24 INFO  : one: Moved (server-side) to: one.bak
2024/11/06 05:09:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate/dst': Waiting for transfers to finish
2024/11/06 05:09:26 DEBUG : one: md5 = 77d636acc46f3f14fda6ddcad3d7f8de OK
2024/11/06 05:09:26 INFO  : one: Copied (new)
2024/11/06 05:09:26 DEBUG : Waiting for deletions to finish
2024/11/06 05:09:27 INFO  : three.txt.bak: Deleted
2024/11/06 05:09:28 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/06 05:09:28 INFO  : three.txt: Moved into backup dir
2024/11/06 05:09:32 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/06 05:09:32 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/06 05:09:32 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/06 05:09:32 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/06 05:09:32 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/06 05:09:32 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncBackupDirSuffixOnly (26.16s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:09:37 DEBUG : dst/one: md5 = 55ad35c63502ee9f361b9f86f510f174 OK
2024/11/06 05:09:38 DEBUG : dst/two: md5 = d64a5de90551d1a5660f6dadd590514f OK
2024/11/06 05:09:40 DEBUG : dst/three.txt: md5 = 883b898fcd4c7efc4e6203f4b25ab369 OK
2024/11/06 05:09:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/dst"
2024/11/06 05:09:41 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/06 05:09:42 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/06 05:09:43 INFO  : one: Moved (server-side) to: one.bak
2024/11/06 05:09:45 DEBUG : one: md5 = 034d445b2aaf8450388b372deedebdba OK
2024/11/06 05:09:45 INFO  : one: Copied (new)
2024/11/06 05:09:45 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:09:45 DEBUG : two: Unchanged skipping
2024/11/06 05:09:46 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/11/06 05:09:47 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/06 05:09:49 DEBUG : three.txt: md5 = 388c8635b41b63646388ad10cddd897c OK
2024/11/06 05:09:49 INFO  : three.txt: Copied (new)
2024/11/06 05:09:50 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/06 05:09:51 INFO  : one.bak: Deleted
2024/11/06 05:09:52 INFO  : one: Moved (server-side) to: one.bak
2024/11/06 05:09:53 DEBUG : one: md5 = 0481620f1e6eeeed5bdc790701954dd6 OK
2024/11/06 05:09:53 INFO  : one: Copied (new)
2024/11/06 05:09:54 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:09:54 DEBUG : two: Unchanged skipping
2024/11/06 05:09:54 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/11/06 05:09:55 INFO  : three.txt.bak: Deleted
2024/11/06 05:09:56 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/06 05:09:57 DEBUG : three.txt: md5 = a6f79ea0e0474e19e43fa1c99352540a OK
2024/11/06 05:09:57 INFO  : three.txt: Copied (new)
2024/11/06 05:10:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/06 05:10:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/06 05:10:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/06 05:10:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/06 05:10:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/06 05:10:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/06 05:10:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncSuffix (29.98s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:10:06 DEBUG : dst/one: md5 = 08a1b0eeae1a1aad4ce6c9035a4f3f5e OK
2024/11/06 05:10:08 DEBUG : dst/two: md5 = 8703a357a523634f5c46f0f12eecd8a9 OK
2024/11/06 05:10:10 DEBUG : dst/three.txt: md5 = 479eda3ba85762f5929d6dea6eaa4c50 OK
2024/11/06 05:10:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekosud6nate/dst"
2024/11/06 05:10:10 DEBUG : Creating backend with remote "TestDrive:crypt/9h4nce1b3meocgoi36blcl7ens8l8bebn1vooi72fcaqedn1uuc0/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/06 05:10:11 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/06 05:10:12 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/06 05:10:14 DEBUG : one: md5 = ea8f632db6bb6d175bb368dd79e524ba OK
2024/11/06 05:10:14 INFO  : one: Copied (new)
2024/11/06 05:10:15 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:10:15 DEBUG : two: Unchanged skipping
2024/11/06 05:10:15 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/11/06 05:10:16 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/06 05:10:18 DEBUG : three.txt: md5 = 4bbe2ac055e9e38e82d6e7ff20a9ff81 OK
2024/11/06 05:10:18 INFO  : three.txt: Copied (new)
2024/11/06 05:10:19 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/06 05:10:20 INFO  : one-2019-01-01: Deleted
2024/11/06 05:10:21 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/06 05:10:22 DEBUG : one: md5 = 342ce6bd8833672d8b7fc49165932914 OK
2024/11/06 05:10:22 INFO  : one: Copied (new)
2024/11/06 05:10:23 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:10:23 DEBUG : two: Unchanged skipping
2024/11/06 05:10:23 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/11/06 05:10:24 INFO  : three-2019-01-01.txt: Deleted
2024/11/06 05:10:25 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/06 05:10:27 DEBUG : three.txt: md5 = ae5c9d013ee085a5d7cf3b5729ec9683 OK
2024/11/06 05:10:27 INFO  : three.txt: Copied (new)
2024/11/06 05:10:32 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/06 05:10:32 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/06 05:10:32 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/06 05:10:32 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/06 05:10:32 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/06 05:10:32 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/06 05:10:32 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncSuffixKeepExtension (29.74s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:10:34 DEBUG : Testêé: md5 = 35a97cf1499c929cb62c68b6eaf4fa86 OK
2024/11/06 05:10:35 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2024/11/06 05:10:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:10:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:10:36 DEBUG : Testêé: md5 = a1a42bc5228a86e15067b73d4a95f0df OK
2024/11/06 05:10:36 INFO  : Testêé: Copied (replaced existing) to: Testêé
2024/11/06 05:10:36 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (5.22s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:10:38 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/06 05:10:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:10:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:10:40 DEBUG : existing: md5 = 173b85a714f05db68fba40c0f740165c OK
2024/11/06 05:10:40 INFO  : existing: Copied (new)
2024/11/06 05:10:40 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:10:41 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2024/11/06 05:10:41 ERROR : existing: Source and destination exist but do not match: immutable file modified
2024/11/06 05:10:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:10:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:10:41 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': not deleting files as there were IO errors
2024/11/06 05:10:41 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncImmutable (5.66s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:10:46 DEBUG : EXISTING: md5 = c4bba27b2d8918d85b2b288e7d915ede OK
2024/11/06 05:10:46 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:10:46 DEBUG : existing: Unchanged skipping
2024/11/06 05:10:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:10:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:10:46 DEBUG : Waiting for deletions to finish
2024/11/06 05:10:46 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (4.03s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    sync_test.go:2635: Skipping test as local or remote are case-sensitive
--- SKIP: TestFixCase (0.49s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", 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-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", 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-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.49s)
    --- SKIP: TestMaxTransfer/Hard (0.52s)
    --- SKIP: TestMaxTransfer/Soft (0.47s)
    --- SKIP: TestMaxTransfer/Cautious (0.51s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:10:52 DEBUG : both0: md5 = 1197d490ffb5e8c9bc70cef8c9838ae4 OK
2024/11/06 05:10:53 DEBUG : only0: md5 = a5994da3dab01bb2c22d38e78293ef71 OK
2024/11/06 05:10:55 DEBUG : both1: md5 = c2a1c652194a7f850f3276066719a1e9 OK
2024/11/06 05:10:57 DEBUG : only1: md5 = bfc253b06e6aca2e272a5de54f1f151b OK
2024/11/06 05:10:59 DEBUG : both2: md5 = e449e6b3b7a5b30acf9f15622e67d79e OK
2024/11/06 05:11:01 DEBUG : only2: md5 = 0b1f5549cbc55983081c37273f3d1b43 OK
2024/11/06 05:11:03 DEBUG : both3: md5 = 8fd2d5e9222c8934e9a18ec9f0ffc7d2 OK
2024/11/06 05:11:04 DEBUG : only3: md5 = 51375b7dd90336610ec8ac63985a2596 OK
2024/11/06 05:11:06 DEBUG : both4: md5 = eb8cc9343302cf7d251fe5b799dda052 OK
2024/11/06 05:11:08 DEBUG : only4: md5 = af8698657bf648ebcfdf5e72df3c009c OK
2024/11/06 05:11:10 DEBUG : both5: md5 = f8955bf461f06292e9a8c26c54093501 OK
2024/11/06 05:11:12 DEBUG : only5: md5 = 0a0982b7afb30d6fecff173b8d4955d0 OK
2024/11/06 05:11:14 DEBUG : both6: md5 = 26017997486352e32ae4cb39375e219b OK
2024/11/06 05:11:16 DEBUG : only6: md5 = ca03ed5cb861ff70605f08533408f25e OK
2024/11/06 05:11:18 DEBUG : both7: md5 = ca086698c97de57378c29050fb733d92 OK
2024/11/06 05:11:20 DEBUG : only7: md5 = 19df42e5fbf0ea87e35804ac03696e37 OK
2024/11/06 05:11:22 DEBUG : both8: md5 = 46314d53530af2688f459fac5b3c4188 OK
2024/11/06 05:11:23 DEBUG : only8: md5 = bc7c969d50b30f20ce2b6d7553ffde63 OK
2024/11/06 05:11:25 DEBUG : both9: md5 = a6ffa266edec75f73870aef21f5ed713 OK
2024/11/06 05:11:27 DEBUG : only9: md5 = 8440372aa4f2d24df10d73d5b16f07dd OK
2024/11/06 05:11:29 DEBUG : both10: md5 = ccbdfa7f8e588c5209a2e800de8cfa73 OK
2024/11/06 05:11:30 DEBUG : only10: md5 = fdcb4f1bf7289adf3272a52ca18728d1 OK
2024/11/06 05:11:32 DEBUG : both11: md5 = 1515fd46c7cae6f48892ac9a6f5a160d OK
2024/11/06 05:11:34 DEBUG : only11: md5 = 59182177d523a508a98febda10738ca8 OK
2024/11/06 05:11:36 DEBUG : both12: md5 = fb4471d8650295d7af5578de9b92e8cc OK
2024/11/06 05:11:38 DEBUG : only12: md5 = 74e49d67cabb83fae74863fac23370cb OK
2024/11/06 05:11:40 DEBUG : both13: md5 = e584f4f91c1b0070debe31e67cbbf75d OK
2024/11/06 05:11:42 DEBUG : only13: md5 = 48a121028d576def23f90c39a217a879 OK
2024/11/06 05:11:44 DEBUG : both14: md5 = 385d5356dae1e8049178928206bd35de OK
2024/11/06 05:11:45 DEBUG : only14: md5 = 72359c03841ad69c280b483ac3d204ab OK
2024/11/06 05:11:47 DEBUG : both15: md5 = 67b87a97dc231eb5b4b1ee736b45da73 OK
2024/11/06 05:11:49 DEBUG : only15: md5 = b076e058f80e3ac7146da845aabf5267 OK
2024/11/06 05:11:51 DEBUG : both16: md5 = ca9475a50f0d072649a6959978d4163d OK
2024/11/06 05:11:53 DEBUG : only16: md5 = bad33a8737bd6aa0a754cdeb6063c699 OK
2024/11/06 05:11:55 DEBUG : both17: md5 = f43ccfebae11c789fc450eac8eed317e OK
2024/11/06 05:11:57 DEBUG : only17: md5 = 6ce963cda45a03978527f88cc2b7a9cb OK
2024/11/06 05:11:58 DEBUG : both18: md5 = 538e3c6b17d3772997d0d361f6240917 OK
2024/11/06 05:12:00 DEBUG : only18: md5 = 41960d74832e5e5bde5736faefc0af22 OK
2024/11/06 05:12:02 DEBUG : both19: md5 = ef5377659b1a630ec1cb4eb9950c77f2 OK
2024/11/06 05:12:04 DEBUG : only19: md5 = beec3cb9246091a7f71f224dd43f5972 OK
2024/11/06 05:12:04 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:12:04 DEBUG : both0: Unchanged skipping
2024/11/06 05:12:04 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:12:04 DEBUG : both1: Unchanged skipping
2024/11/06 05:12:04 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:12:04 DEBUG : both10: Unchanged skipping
2024/11/06 05:12:04 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:12:04 DEBUG : both11: Unchanged skipping
2024/11/06 05:12:04 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:12:04 DEBUG : both12: Unchanged skipping
2024/11/06 05:12:04 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:12:04 DEBUG : both13: Unchanged skipping
2024/11/06 05:12:04 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:12:04 DEBUG : both14: Unchanged skipping
2024/11/06 05:12:04 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:12:04 DEBUG : both15: Unchanged skipping
2024/11/06 05:12:04 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:12:04 DEBUG : both16: Unchanged skipping
2024/11/06 05:12:04 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:12:04 DEBUG : both17: Unchanged skipping
2024/11/06 05:12:04 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:12:04 DEBUG : both18: Unchanged skipping
2024/11/06 05:12:04 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:12:04 DEBUG : both19: Unchanged skipping
2024/11/06 05:12:04 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:12:04 DEBUG : both2: Unchanged skipping
2024/11/06 05:12:04 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:12:04 DEBUG : both3: Unchanged skipping
2024/11/06 05:12:04 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:12:04 DEBUG : both4: Unchanged skipping
2024/11/06 05:12:04 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:12:04 DEBUG : both5: Unchanged skipping
2024/11/06 05:12:04 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:12:04 DEBUG : both6: Unchanged skipping
2024/11/06 05:12:04 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:12:04 DEBUG : both7: Unchanged skipping
2024/11/06 05:12:04 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:12:04 DEBUG : both8: Unchanged skipping
2024/11/06 05:12:04 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:12:04 DEBUG : both9: Unchanged skipping
2024/11/06 05:12:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:12:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:12:04 DEBUG : Waiting for deletions to finish
2024/11/06 05:12:05 INFO  : only2: Deleted
2024/11/06 05:12:05 INFO  : only17: Deleted
2024/11/06 05:12:05 INFO  : only14: Deleted
2024/11/06 05:12:05 INFO  : only18: Deleted
2024/11/06 05:12:06 INFO  : only9: Deleted
2024/11/06 05:12:06 INFO  : only7: Deleted
2024/11/06 05:12:06 INFO  : only11: Deleted
2024/11/06 05:12:06 INFO  : only13: Deleted
2024/11/06 05:12:06 INFO  : only3: Deleted
2024/11/06 05:12:06 INFO  : only6: Deleted
2024/11/06 05:12:06 INFO  : only15: Deleted
2024/11/06 05:12:06 INFO  : only12: Deleted
2024/11/06 05:12:07 INFO  : only19: Deleted
2024/11/06 05:12:07 INFO  : only1: Deleted
2024/11/06 05:12:07 INFO  : only0: Deleted
2024/11/06 05:12:07 INFO  : only10: Deleted
2024/11/06 05:12:07 INFO  : only16: Deleted
2024/11/06 05:12:08 INFO  : only5: Deleted
2024/11/06 05:12:08 INFO  : only8: Deleted
2024/11/06 05:12:08 INFO  : only4: Deleted
2024/11/06 05:12:08 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (93.27s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:12:25 DEBUG : both0: md5 = 3339d79302cad38f1c7c67d5437ab394 OK
2024/11/06 05:12:26 DEBUG : only0: md5 = 2aebb77a742d20b27f121014d037cb86 OK
2024/11/06 05:12:28 DEBUG : both1: md5 = 3fafe57efe5e69622d32bc16d2a8d58b OK
2024/11/06 05:12:30 DEBUG : only1: md5 = 762e27368f04fdd4e4c5382b97489883 OK
2024/11/06 05:12:32 DEBUG : both2: md5 = 7ccb9a5430a320a81f45ac4cc506dc7d OK
2024/11/06 05:12:34 DEBUG : only2: md5 = 0e6a09901e8911f4afb116dd648819ed OK
2024/11/06 05:12:35 DEBUG : both3: md5 = 233568d297881a5f92d35aac47e7812d OK
2024/11/06 05:12:37 DEBUG : only3: md5 = 4d3af3e887e537dc3a09c95ca9ab2785 OK
2024/11/06 05:12:39 DEBUG : both4: md5 = 2f8856c5e4215d11fb99f06afb583a27 OK
2024/11/06 05:12:41 DEBUG : only4: md5 = ffbddabb147805951bd78e91b3b3f028 OK
2024/11/06 05:12:43 DEBUG : both5: md5 = 0f5eb3b6cf6836f4f8b95b295c943a77 OK
2024/11/06 05:12:44 DEBUG : only5: md5 = 01325713be48c7e1919720ac3c2301d6 OK
2024/11/06 05:12:46 DEBUG : both6: md5 = 25540d81e9ec5ab34d8072168528f7ed OK
2024/11/06 05:12:48 DEBUG : only6: md5 = 622d74ddef6afab8753506a4d3334d4f OK
2024/11/06 05:12:50 DEBUG : both7: md5 = a860d0a3c3837e4b0f761d85880d176c OK
2024/11/06 05:12:52 DEBUG : only7: md5 = 9c4cbed63d54e1b63f605c5589837e32 OK
2024/11/06 05:12:54 DEBUG : both8: md5 = edd45ee92c0f99d4758be10e2f9204b9 OK
2024/11/06 05:12:55 DEBUG : only8: md5 = 94c9a1344d1440c6e565983d1de14a6c OK
2024/11/06 05:12:57 DEBUG : both9: md5 = 7fe694aaa399a3cfb68400b93aa9cead OK
2024/11/06 05:12:59 DEBUG : only9: md5 = ed28197e7b918ed6e1edeb68a5259088 OK
2024/11/06 05:13:01 DEBUG : both10: md5 = 6ea9c738ab0f7da86ef182db3c432582 OK
2024/11/06 05:13:03 DEBUG : only10: md5 = dfa09f0bc212bb1048c81c33edb598b5 OK
2024/11/06 05:13:05 DEBUG : both11: md5 = 41311b968e322de82bdda5b9f9914d3f OK
2024/11/06 05:13:07 DEBUG : only11: md5 = 0152ea5dbd81d03e3215772232756d1e OK
2024/11/06 05:13:09 DEBUG : both12: md5 = 7693f0dd7b8c0bdb56fff330d33b49d1 OK
2024/11/06 05:13:11 DEBUG : only12: md5 = ec452923e9ed230b3d7272250762c9f8 OK
2024/11/06 05:13:12 DEBUG : both13: md5 = df06cc355867df3ff8412d63318bb66e OK
2024/11/06 05:13:14 DEBUG : only13: md5 = f190a0fb13989fe1c21a1750a8e2d4a6 OK
2024/11/06 05:13:16 DEBUG : both14: md5 = 8abc0affa74764ad313b57c2e519c481 OK
2024/11/06 05:13:18 DEBUG : only14: md5 = 55b41bc6d76aebfa944418abd364191c OK
2024/11/06 05:13:20 DEBUG : both15: md5 = 72875532d1f3e85f35d117d8273ec7d8 OK
2024/11/06 05:13:22 DEBUG : only15: md5 = 7def79f259b5dff2a6fc3cc400a80d42 OK
2024/11/06 05:13:24 DEBUG : both16: md5 = 0a6e0e39eae5e10f6bcbdcecc18f76c1 OK
2024/11/06 05:13:26 DEBUG : only16: md5 = 2c4fda012fdb6b763b3feebff99ad099 OK
2024/11/06 05:13:27 DEBUG : both17: md5 = d878736210104ccc3ec30aa4ac0ca336 OK
2024/11/06 05:13:29 DEBUG : only17: md5 = e0eadea1e5d594d2e22e41faf98c80d3 OK
2024/11/06 05:13:32 DEBUG : both18: md5 = f2f715c9bfe6ad3b9a2b17fa4e81d91b OK
2024/11/06 05:13:33 DEBUG : only18: md5 = b3fecfaaa6413440cefee76cb86102a8 OK
2024/11/06 05:13:35 DEBUG : both19: md5 = 7c0f2d2d9c473ae10aba781d1e0cfc3d OK
2024/11/06 05:13:37 DEBUG : only19: md5 = 7453a98e852271523e8ce87595b4b802 OK
2024/11/06 05:13:38 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:13:38 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:13:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for checks to finish
2024/11/06 05:13:38 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:13:38 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:13:38 DEBUG : both0: Unchanged skipping
2024/11/06 05:13:38 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:13:38 DEBUG : both1: Unchanged skipping
2024/11/06 05:13:38 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:13:38 DEBUG : both12: Unchanged skipping
2024/11/06 05:13:38 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:13:38 DEBUG : both10: Unchanged skipping
2024/11/06 05:13:38 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:13:38 DEBUG : both15: Unchanged skipping
2024/11/06 05:13:38 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:13:38 DEBUG : both16: Unchanged skipping
2024/11/06 05:13:38 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:13:38 DEBUG : both17: Unchanged skipping
2024/11/06 05:13:38 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:13:38 DEBUG : both18: Unchanged skipping
2024/11/06 05:13:38 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:13:38 DEBUG : both19: Unchanged skipping
2024/11/06 05:13:38 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:13:38 DEBUG : both11: Unchanged skipping
2024/11/06 05:13:38 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:13:38 DEBUG : both13: Unchanged skipping
2024/11/06 05:13:38 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:13:38 DEBUG : both4: Unchanged skipping
2024/11/06 05:13:38 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:13:38 DEBUG : both5: Unchanged skipping
2024/11/06 05:13:38 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:13:38 DEBUG : both14: Unchanged skipping
2024/11/06 05:13:38 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:13:38 DEBUG : both7: Unchanged skipping
2024/11/06 05:13:38 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:13:38 DEBUG : both8: Unchanged skipping
2024/11/06 05:13:38 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/06 05:13:38 DEBUG : both9: Unchanged skipping
2024/11/06 05:13:38 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2024/11/06 05:13:38 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2024/11/06 05:13:38 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2024/11/06 05:13:38 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2024/11/06 05:13:38 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2024/11/06 05:13:38 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2024/11/06 05:13:38 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2024/11/06 05:13:38 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2024/11/06 05:13:38 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2024/11/06 05:13:38 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2024/11/06 05:13:38 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2024/11/06 05:13:38 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2024/11/06 05:13:38 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2024/11/06 05:13:38 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2024/11/06 05:13:38 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2024/11/06 05:13:38 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2024/11/06 05:13:38 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2024/11/06 05:13:38 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2024/11/06 05:13:38 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2024/11/06 05:13:38 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2024/11/06 05:13:38 DEBUG : both2: Unchanged skipping
2024/11/06 05:13:38 DEBUG : both3: Unchanged skipping
2024/11/06 05:13:38 DEBUG : both6: Unchanged skipping
2024/11/06 05:13:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Waiting for transfers to finish
2024/11/06 05:13:39 DEBUG : only0: md5 = 6856fe3f7ec5df0d6ee39c176e5eaea0 OK
2024/11/06 05:13:39 INFO  : only0: Copied (replaced existing)
2024/11/06 05:13:39 DEBUG : only11: md5 = ceabd389aacb6851212b5dad4494f85b OK
2024/11/06 05:13:39 INFO  : only11: Copied (replaced existing)
2024/11/06 05:13:39 DEBUG : only10: md5 = 1115bd9b134c5c38aa7332d233cf9c0f OK
2024/11/06 05:13:39 INFO  : only10: Copied (replaced existing)
2024/11/06 05:13:40 DEBUG : only1: md5 = 94b90655b929e3c64777a11838dee166 OK
2024/11/06 05:13:40 INFO  : only1: Copied (replaced existing)
2024/11/06 05:13:41 DEBUG : only12: md5 = e3d87975443ca032b0dab4de69ff30c4 OK
2024/11/06 05:13:41 INFO  : only12: Copied (replaced existing)
2024/11/06 05:13:41 DEBUG : only14: md5 = 41c76e24d19a4a24e5563d662f5b7eeb OK
2024/11/06 05:13:41 INFO  : only14: Copied (replaced existing)
2024/11/06 05:13:41 DEBUG : only13: md5 = ecb5acb8249559fa6f0de694f215e893 OK
2024/11/06 05:13:41 INFO  : only13: Copied (replaced existing)
2024/11/06 05:13:41 DEBUG : only15: md5 = 464c0e2f2918caa1e75b90910c2b33db OK
2024/11/06 05:13:41 INFO  : only15: Copied (replaced existing)
2024/11/06 05:13:42 DEBUG : only16: md5 = 6c8aaf506bf6df173a5f98bf9d37db4e OK
2024/11/06 05:13:42 INFO  : only16: Copied (replaced existing)
2024/11/06 05:13:42 DEBUG : only18: md5 = 805d0158ba1959988f2d68ab7b0db431 OK
2024/11/06 05:13:42 INFO  : only18: Copied (replaced existing)
2024/11/06 05:13:42 DEBUG : only17: md5 = 3a3c58994338c85f57b78ac28304ac99 OK
2024/11/06 05:13:42 INFO  : only17: Copied (replaced existing)
2024/11/06 05:13:42 DEBUG : only19: md5 = 6b6a78a1ff51f2d3c7fd26e8760d3a68 OK
2024/11/06 05:13:42 INFO  : only19: Copied (replaced existing)
2024/11/06 05:13:44 DEBUG : only3: md5 = 8165503380eead7cd1f3dabc8c03c2c7 OK
2024/11/06 05:13:44 INFO  : only3: Copied (replaced existing)
2024/11/06 05:13:44 DEBUG : only2: md5 = 0d5516c4dc5383c2a1ef7425eaa9b2a1 OK
2024/11/06 05:13:44 INFO  : only2: Copied (replaced existing)
2024/11/06 05:13:44 DEBUG : only5: md5 = db3b7307c5202112e5511e76a05a4f2c OK
2024/11/06 05:13:44 INFO  : only5: Copied (replaced existing)
2024/11/06 05:13:44 DEBUG : only4: md5 = 09f01074978af720665d62decbd55fda OK
2024/11/06 05:13:44 INFO  : only4: Copied (replaced existing)
2024/11/06 05:13:45 DEBUG : only7: md5 = aa300bee798e9d6678a41b2aa40ec655 OK
2024/11/06 05:13:45 INFO  : only7: Copied (replaced existing)
2024/11/06 05:13:45 DEBUG : only6: md5 = 9e88fd858601afa6da87b39679bdc4f5 OK
2024/11/06 05:13:45 INFO  : only6: Copied (replaced existing)
2024/11/06 05:13:46 DEBUG : only8: md5 = 93a17c7f3281acdd8dadecbbd4d8ef8f OK
2024/11/06 05:13:46 INFO  : only8: Copied (replaced existing)
2024/11/06 05:13:46 DEBUG : only9: md5 = fb1b68a4daa6cb14c4491dc5f3b1aa9f OK
2024/11/06 05:13:46 INFO  : only9: Copied (replaced existing)
2024/11/06 05:13:46 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (111.81s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:14:15 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/06 05:14:15 DEBUG : sub dir: Making directory with metadata
2024/11/06 05:14:16 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:14:38 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/06 05:14:39 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/06 05:14:39 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/06 05:14:39 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:14:54 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2024/11/06 05:14:56 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/06 05:14:57 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/11/06 05:14:58 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/11/06 05:14:59 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/06 05:15:00 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/06 05:15:00 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/06 05:15:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/06 05:15:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/06 05:15:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/11/06 05:15:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/06 05:15:04 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (51.95s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:15:07 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/06 05:15:07 DEBUG : sub dir: Making directory with metadata
2024/11/06 05:15:08 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:15:36 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/06 05:15:36 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/06 05:15:36 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/06 05:15:36 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate'", Local "Local file system at /tmp/rclone884933605", Modify Window "1ms"
2024/11/06 05:15:50 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/06 05:15:51 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/11/06 05:15:52 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/11/06 05:15:53 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/06 05:15:54 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/06 05:15:55 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/06 05:15:56 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/06 05:15:57 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/06 05:15:58 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/11/06 05:15:58 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/06 05:15:59 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (54.75s)
PASS
2024/11/06 05:16:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekosud6nate': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 19m59.065754682s (try 1/5)