"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5)
2024/12/29 04:44:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu"
2024/12/29 04:44:30 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2024/12/29 04:44:30 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30"
2024/12/29 04:44:31 DEBUG : Creating backend with remote "/tmp/rclone1793336062"
=== 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-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:44:32 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/29 04:44:32 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/29 04:44:32 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2024/12/29 04:44:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:44:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:44:32 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (2.34s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:44:33 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/29 04:44:34 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/29 04:44:34 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/29 04:44:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:44:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:44:36 DEBUG : sub dir/hello world: md5 = 2fbe5a8e271736aa3a5442b3ee416b4e OK
2024/12/29 04:44:36 INFO  : sub dir/hello world: Copied (new)
2024/12/29 04:44:37 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:44:39 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (6.70s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:44:40 DEBUG : metadata sub dir: Making directory with metadata
2024/12/29 04:44:40 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/29 04:44:40 DEBUG : empty metadata sub dir: Making directory with metadata
2024/12/29 04:44:40 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/29 04:44:40 DEBUG : Local file system at /tmp/rclone1793336062: File to upload is small (21 bytes), uploading instead of streaming
2024/12/29 04:44:40 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/12/29 04:44:40 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/12/29 04:44:40 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/12/29 04:44:41 DEBUG : Google drive root 'crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30': Skipping btime metadata as can't update it on an existing file: 2024-12-29T04:44:40.616938091Z
2024/12/29 04:44:41 INFO  : empty metadata sub dir: Updated directory metadata
2024/12/29 04:44:42 DEBUG : Google drive root 'crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30': Skipping btime metadata as can't update it on an existing file: 2024-12-29T04:44:40.616938091Z
2024/12/29 04:44:42 INFO  : metadata sub dir: Updated directory metadata
2024/12/29 04:44:42 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/12/29 04:44:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:44:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:44:44 DEBUG : metadata sub dir/hello metadata world: md5 = 0c2d8b766bcfa44c205b34dc36a804bb OK
2024/12/29 04:44:44 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:44:47 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (8.55s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:44:49 DEBUG : metadata sub dir: Making directory with metadata
2024/12/29 04:44:49 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/29 04:44:49 DEBUG : empty metadata sub dir: Making directory with metadata
2024/12/29 04:44:49 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/29 04:44:49 DEBUG : Local file system at /tmp/rclone1793336062: File to upload is small (21 bytes), uploading instead of streaming
2024/12/29 04:44:49 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/12/29 04:44:49 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/12/29 04:44:49 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/12/29 04:44:49 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2024/12/29 04:44:49 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2024/12/29 04:44:49 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/12/29 04:44:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:44:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:44:51 DEBUG : metadata sub dir/hello metadata world: md5 = b6874d2afa2e65e606a9f376a2769d21 OK
2024/12/29 04:44:51 INFO  : metadata sub dir/hello metadata world: Copied (new)
2024/12/29 04:44:51 DEBUG : Google drive root 'crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30': Skipping btime metadata as can't update it on an existing file: 2024-12-29T04:44:49.164893538Z
2024/12/29 04:44:52 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:44:55 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (7.56s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:44:56 DEBUG : Creating backend with remote "/non-existing"
2024/12/29 04:44:56 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2024/12/29 04:44:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:44:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.14s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:44:57 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/29 04:44:58 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/29 04:44:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:44:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:45:00 DEBUG : sub dir/hello world: md5 = dcbbc59feb388b324e5af19593fa1a45 OK
2024/12/29 04:45:00 INFO  : sub dir/hello world: Copied (new)
2024/12/29 04:45:01 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:45:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (6.28s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:45:04 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Running all checks before starting transfers
2024/12/29 04:45:04 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/29 04:45:04 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/29 04:45:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:45:04 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Checks finished, now starting transfers
2024/12/29 04:45:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:45:06 DEBUG : sub dir/hello world: md5 = e82a251263a4c77366e9754e1cefcf17 OK
2024/12/29 04:45:06 INFO  : sub dir/hello world: Copied (new)
2024/12/29 04:45:07 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:45:09 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (6.37s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:45:10 ERROR : Ignoring --no-traverse with sync
2024/12/29 04:45:10 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/29 04:45:10 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/29 04:45:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:45:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:45:13 DEBUG : sub dir/hello world: md5 = 87651a68dcf4528a401aa059c172e496 OK
2024/12/29 04:45:13 INFO  : sub dir/hello world: Copied (new)
2024/12/29 04:45:13 DEBUG : Waiting for deletions to finish
2024/12/29 04:45:13 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:45:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (6.34s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:45:17 DEBUG : hello world2: Need to transfer - File not found at Destination
2024/12/29 04:45:17 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/29 04:45:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:45:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:45:18 DEBUG : hello world2: md5 = d56b6073002ebc4ac9b17cdff3eddebf OK
2024/12/29 04:45:18 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestCopyWithDepth (3.70s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:45:20 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/29 04:45:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:45:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:45:22 DEBUG : potato2: md5 = 87395cae1e0245c04dcbe2276556008a OK
2024/12/29 04:45:22 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (3.63s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:45:24 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/29 04:45:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:45:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:45:25 DEBUG : potato2: md5 = 29111108bb82da7db45b7bc4bb36e5bb OK
2024/12/29 04:45:25 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (3.67s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:45:27 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/12/29 04:45:27 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/29 04:45:27 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/12/29 04:45:27 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/29 04:45:28 DEBUG : sub dir: Making directory with metadata
2024/12/29 04:45:29 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/12/29 04:45:29 DEBUG : sub dir2: Making directory with metadata
2024/12/29 04:45:29 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/29 04:45:29 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/12/29 04:45:29 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/29 04:45:30 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/29 04:45:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:45:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:45:31 DEBUG : sub dir/hello world: md5 = 2265f6302e6171cc1b8a7a6c245ac3be OK
2024/12/29 04:45:31 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:45:35 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2024/12/29 04:45:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (9.69s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:45:37 DEBUG : sub dir2: Making directory
2024/12/29 04:45:37 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/12/29 04:45:37 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/29 04:45:37 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/29 04:45:37 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/12/29 04:45:37 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2024/12/29 04:45:37 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/29 04:45:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:45:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:45:40 DEBUG : sub dir/hello world: md5 = 43c535c2eebba93ff3fd30020defbb16 OK
2024/12/29 04:45:40 INFO  : sub dir/hello world: Copied (new)
2024/12/29 04:45:40 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/29 04:45:42 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (5.73s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:45:43 DEBUG : sub dir2: Making directory with metadata
2024/12/29 04:45:43 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/29 04:45:43 DEBUG : sub dir: Making directory with metadata
2024/12/29 04:45:44 INFO  : sub dir: Made directory with metadata (mtime=2024-12-29T04:45:43.28061105Z)
2024/12/29 04:45:44 DEBUG : sub dir2: Making directory with metadata
2024/12/29 04:45:45 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/29 04:45:45 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/29 04:45:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:45:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:45:46 DEBUG : sub dir/hello world: md5 = 48d405baf5bd42a43e68187e9f5253a8 OK
2024/12/29 04:45:46 INFO  : sub dir/hello world: Copied (new)
2024/12/29 04:45:46 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:45:49 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (7.95s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:45:51 DEBUG : sub dir no update dir modtime: Making directory with metadata
2024/12/29 04:45:51 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/12/29 04:45:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:45:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:45:52 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (4.22s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:45:55 DEBUG : sub dir2: Making directory
2024/12/29 04:45:55 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/29 04:45:55 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/12/29 04:45:55 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/29 04:45:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:45:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:45:58 DEBUG : sub dir/hello world: md5 = ce6a9df48a36bc9f49d8250e4b3e6936 OK
2024/12/29 04:45:58 INFO  : sub dir/hello world: Copied (new)
2024/12/29 04:45:58 INFO  : sub dir/hello world: Deleted
2024/12/29 04:45:59 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/29 04:46:00 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (6.04s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:46:01 DEBUG : sub dir2: Making directory with metadata
2024/12/29 04:46:01 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/29 04:46:01 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/29 04:46:01 DEBUG : sub dir: Making directory with metadata
2024/12/29 04:46:02 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/12/29 04:46:02 DEBUG : sub dir2: Making directory with metadata
2024/12/29 04:46:03 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/29 04:46:03 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/29 04:46:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:46:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:46:05 DEBUG : sub dir/hello world: md5 = 5fd2ca31d5ec5ffa644ef3ef290b8052 OK
2024/12/29 04:46:05 INFO  : sub dir/hello world: Copied (new)
2024/12/29 04:46:05 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:46:08 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (8.19s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.41s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:46:10 DEBUG : sub dir2: Making directory
2024/12/29 04:46:10 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/29 04:46:10 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/12/29 04:46:10 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/29 04:46:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:46:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:46:12 DEBUG : sub dir/hello world: md5 = 7f99bbacbbc2793767d0f43270cd17b4 OK
2024/12/29 04:46:12 INFO  : sub dir/hello world: Copied (new)
2024/12/29 04:46:13 DEBUG : Waiting for deletions to finish
2024/12/29 04:46:13 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/29 04:46:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (5.99s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:46:18 DEBUG : sub dir/hello world: md5 = 706b7cc27614eba41c1d169a61fd9951 OK
2024/12/29 04:46:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suhumik1qino"
2024/12/29 04:46:19 DEBUG : Creating backend with remote "TestDrive:crypt/q6jh6a1koj307nriuaal11ajak37atrkk630csv21l90mi2451jg"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu' -> Encrypted drive 'TestCryptDrive:rclone-test-suhumik1qino'
2024/12/29 04:46:20 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/29 04:46:20 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/29 04:46:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suhumik1qino': Waiting for checks to finish
2024/12/29 04:46:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suhumik1qino': Waiting for transfers to finish
2024/12/29 04:46:23 INFO  : sub dir/hello world: Copied (server-side copy)
2024/12/29 04:46:25 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:46:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suhumik1qino': Purge remote
2024/12/29 04:46:27 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (12.48s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:46:30 DEBUG : sub dir/hello world: md5 = 6a197ae1ca547e55e7c4926e214616dd OK
2024/12/29 04:46:31 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/12/29 04:46:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:46:31 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/12/29 04:46:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:46:33 DEBUG : sub dir/hello world: md5 = e3b7d6b3079ffc4352ac1da0faa38d65 OK
2024/12/29 04:46:33 INFO  : sub dir/hello world: Copied (replaced existing)
2024/12/29 04:46:33 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:46:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (8.25s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:46:39 DEBUG : sub dir/hello world: md5 = 9a480a6aa1cd40b4a341f3fccfb25cbf OK
2024/12/29 04:46:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qerayas2yidu"
2024/12/29 04:46:39 DEBUG : Creating backend with remote "TestDrive:crypt/bdn6fb6t86njnoo3i2696ij1opflhc06rgdcr9l7g94ehcojmocg"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu' -> Encrypted drive 'TestCryptDrive:rclone-test-qerayas2yidu'
2024/12/29 04:46:40 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/29 04:46:41 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/29 04:46:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qerayas2yidu': Waiting for checks to finish
2024/12/29 04:46:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qerayas2yidu': Waiting for transfers to finish
2024/12/29 04:46:44 INFO  : sub dir/hello world: Copied (server-side copy)
2024/12/29 04:46:44 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:46:47 DEBUG : sub dir/hello world: md5 = b46446c58e68090fc8d9a8b2bfb83652 OK
2024/12/29 04:46:47 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/12/29 04:46:47 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/12/29 04:46:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qerayas2yidu': Waiting for checks to finish
2024/12/29 04:46:48 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/12/29 04:46:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qerayas2yidu': Waiting for transfers to finish
2024/12/29 04:46:49 INFO  : sub dir/hello world: Copied (server-side copy)
2024/12/29 04:46:50 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:46:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qerayas2yidu': Purge remote
2024/12/29 04:46:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (17.49s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:46:56 DEBUG : sub dir/hello world: md5 = e32d8b31c84400688f0047c05efe5db4 OK
2024/12/29 04:46:57 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/12/29 04:46:57 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/12/29 04:46:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:46:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:46:58 DEBUG : sub dir/hello world: md5 = 80f6049b13f9f955ca346c145bd725fb OK
2024/12/29 04:46:58 INFO  : sub dir/hello world: Copied (replaced existing)
2024/12/29 04:46:58 INFO  : sub dir/hello world: Deleted
2024/12/29 04:46:59 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:47:01 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (8.34s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:47:05 DEBUG : sub dir/hello world: md5 = 6ce14f22e0f9a27bc5d340b2cd882926 OK
2024/12/29 04:47:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bidigub9fexi"
2024/12/29 04:47:05 DEBUG : Creating backend with remote "TestDrive:crypt/7s2er1f87pro19pmo0af2ltk66jiu64lp76u4u5i0336b3thjdkg"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu' -> Encrypted drive 'TestCryptDrive:rclone-test-bidigub9fexi'
2024/12/29 04:47:06 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/29 04:47:07 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/29 04:47:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bidigub9fexi': Waiting for checks to finish
2024/12/29 04:47:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bidigub9fexi': Waiting for transfers to finish
2024/12/29 04:47:10 INFO  : sub dir/hello world: Copied (server-side copy)
2024/12/29 04:47:11 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:47:13 DEBUG : sub dir/hello world: md5 = ddfa1a8a08b810acdacf65cd703e7976 OK
2024/12/29 04:47:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bidigub9fexi': Using server-side directory move
2024/12/29 04:47:14 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-bidigub9fexi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/12/29 04:47:14 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/12/29 04:47:14 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/12/29 04:47:14 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/12/29 04:47:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bidigub9fexi': Waiting for checks to finish
2024/12/29 04:47:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bidigub9fexi': Waiting for transfers to finish
2024/12/29 04:47:15 INFO  : sub dir/hello world: Deleted
2024/12/29 04:47:16 INFO  : sub dir/hello world: Moved (server-side)
2024/12/29 04:47:16 INFO  : sub dir: Set directory modification time (using SetModTime)
2024/12/29 04:47:19 DEBUG : sub dir/hello world: md5 = 2dde1e00a3552b45ccf2ecc31847af8c OK
2024/12/29 04:47:19 DEBUG : testing file moves
2024/12/29 04:47:19 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/12/29 04:47:19 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/12/29 04:47:20 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2024/12/29 04:47:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bidigub9fexi': Waiting for checks to finish
2024/12/29 04:47:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bidigub9fexi': Waiting for transfers to finish
2024/12/29 04:47:20 INFO  : sub dir/hello world: Deleted
2024/12/29 04:47:21 INFO  : sub dir/hello world: Moved (server-side)
2024/12/29 04:47:22 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:47:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bidigub9fexi': Purge remote
--- PASS: TestServerSideMoveOverSelf (23.23s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:47:28 DEBUG : sub dir/hello world: md5 = 4901ea15cc52f9fd028e2678541e30ce OK
2024/12/29 04:47:28 ERROR : : error listing: directory not found
2024/12/29 04:47:29 DEBUG : Local file system at /tmp/rclone1793336062: Making directory
2024/12/29 04:47:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:47:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:47:31 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (6.42s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:47:34 DEBUG : sub dir/hello world: md5 = c2362cfc0886200e76e53a2d03bb14e8 OK
2024/12/29 04:47:35 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/29 04:47:35 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/29 04:47:35 DEBUG : Local file system at /tmp/rclone1793336062: Waiting for checks to finish
2024/12/29 04:47:35 DEBUG : Local file system at /tmp/rclone1793336062: Waiting for transfers to finish
2024/12/29 04:47:36 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2024/12/29 04:47:36 INFO  : sub dir/hello world: Copied (new)
2024/12/29 04:47:36 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:47:38 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (6.88s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:47:39 DEBUG : check sum: Need to transfer - File not found at Destination
2024/12/29 04:47:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:47:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:47:40 DEBUG : check sum: md5 = 23a939328488be31ea9fd35e8dfb119b OK
2024/12/29 04:47:40 INFO  : check sum: Copied (new)
2024/12/29 04:47:40 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:47:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:47:41 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2024/12/29 04:47:41 DEBUG : check sum: Size of src and dst objects identical
2024/12/29 04:47:41 DEBUG : check sum: Unchanged skipping
2024/12/29 04:47:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:47:41 DEBUG : Waiting for deletions to finish
2024/12/29 04:47:41 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (5.09s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:47:44 DEBUG : sizeonly: Need to transfer - File not found at Destination
2024/12/29 04:47:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:47:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:47:46 DEBUG : sizeonly: md5 = 4883893848eeeb1b22b74f9715d7821e OK
2024/12/29 04:47:46 INFO  : sizeonly: Copied (new)
2024/12/29 04:47:46 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:47:46 DEBUG : sizeonly: Sizes identical
2024/12/29 04:47:46 DEBUG : sizeonly: Unchanged skipping
2024/12/29 04:47:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:47:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:47:46 DEBUG : Waiting for deletions to finish
2024/12/29 04:47:46 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (4.55s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:47:49 DEBUG : ignore-size: Need to transfer - File not found at Destination
2024/12/29 04:47:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:47:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:47:50 DEBUG : ignore-size: md5 = f5378d355bc24ab2cef95c6a1971fada OK
2024/12/29 04:47:50 INFO  : ignore-size: Copied (new)
2024/12/29 04:47:50 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:47:51 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:47:51 DEBUG : ignore-size: Unchanged skipping
2024/12/29 04:47:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:47:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:47:51 DEBUG : Waiting for deletions to finish
2024/12/29 04:47:51 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (5.78s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:47:56 DEBUG : existing: md5 = 0d73f3b9b9e1b4439b99b0156ddb8c77 OK
2024/12/29 04:47:56 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:47:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:47:56 DEBUG : existing: Unchanged skipping
2024/12/29 04:47:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:47:56 DEBUG : Waiting for deletions to finish
2024/12/29 04:47:56 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:47:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:47:56 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2024/12/29 04:47:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:47:58 DEBUG : existing: md5 = cfc6b528828d240053f7c7b46776326e OK
2024/12/29 04:47:58 INFO  : existing: Copied (replaced existing)
2024/12/29 04:47:58 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (5.74s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:48:00 DEBUG : existing: Need to transfer - File not found at Destination
2024/12/29 04:48:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:48:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:48:02 DEBUG : existing: md5 = f73bd23345ba88ce6573e692941ef847 OK
2024/12/29 04:48:02 INFO  : existing: Copied (new)
2024/12/29 04:48:02 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:48:02 DEBUG : existing: Destination exists, skipping
2024/12/29 04:48:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:48:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:48:02 DEBUG : Waiting for deletions to finish
2024/12/29 04:48:02 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (4.50s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:48:07 DEBUG : b/potato: md5 = ed07be212d99e2f1cf8e66ea46236955 OK
2024/12/29 04:48:09 DEBUG : c/non empty space: md5 = 17328db5d4ad9e4b29b94e02d7a4bd1f OK
2024/12/29 04:48:09 DEBUG : d: Making directory
2024/12/29 04:48:11 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/12/29 04:48:11 DEBUG : Added delayed dir = "c", newDst=c
2024/12/29 04:48:11 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/12/29 04:48:11 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:48:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:48:11 DEBUG : c/non empty space: Unchanged skipping
2024/12/29 04:48:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:48:14 DEBUG : a/potato2: md5 = 27dfae4ac26e928fd44d601155baabbb OK
2024/12/29 04:48:14 INFO  : a/potato2: Copied (new)
2024/12/29 04:48:14 DEBUG : Waiting for deletions to finish
2024/12/29 04:48:14 INFO  : b/potato: Deleted
2024/12/29 04:48:15 INFO  : a: Set directory modification time (using DirSetModTime)
2024/12/29 04:48:15 INFO  : d: Removing directory
2024/12/29 04:48:16 INFO  : b: Removing directory
2024/12/29 04:48:16 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/12/29 04:48:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:48:19 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/12/29 04:48:20 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (16.34s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:48:22 DEBUG : empty space: md5 = 4a8c325a06f0b70741a4f3962d18487e OK
2024/12/29 04:48:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:48:23 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2024/12/29 04:48:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:48:23 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2024/12/29 04:48:23 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:48:23 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2024/12/29 04:48:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:48:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:48:25 DEBUG : empty space: md5 = 56a3f3f782586e32ef63256de9e461cf OK
2024/12/29 04:48:25 INFO  : empty space: Copied (replaced existing)
2024/12/29 04:48:25 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (6.12s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.45s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:48:29 DEBUG : foo: md5 = 65f8680dfe0866884c90693bef18ac01 OK
2024/12/29 04:48:29 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/12/29 04:48:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:48:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:48:31 DEBUG : foo: md5 = 6bbd39ce4b3b79e0a4f1cf5cafa56543 OK
2024/12/29 04:48:31 INFO  : foo: Copied (replaced existing)
2024/12/29 04:48:31 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (5.13s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:48:34 DEBUG : empty space: md5 = c31376b29b738c610dc9a9c762043ce7 OK
2024/12/29 04:48:35 DEBUG : potato: Need to transfer - File not found at Destination
2024/12/29 04:48:35 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:48:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:48:35 DEBUG : empty space: Unchanged skipping
2024/12/29 04:48:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:48:36 DEBUG : potato: md5 = 337261426e1497c875d57d7f22c96832 OK
2024/12/29 04:48:36 INFO  : potato: Copied (new)
2024/12/29 04:48:36 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (6.19s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:48:40 DEBUG : potato: md5 = 9a503277a1c107793374bc1d906c9b37 OK
2024/12/29 04:48:41 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2024/12/29 04:48:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:48:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:48:42 DEBUG : potato: md5 = 9183ed4b96c51f950040648a9744f8dc OK
2024/12/29 04:48:42 INFO  : potato: Copied (replaced existing)
2024/12/29 04:48:42 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (4.88s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:48:45 DEBUG : potato: md5 = 83067ffcec8f1af914f8c673b8efd8bb OK
2024/12/29 04:48:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:48:46 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/12/29 04:48:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:48:47 DEBUG : potato: md5 = ae1c354494acc2713939f532aa45640a OK
2024/12/29 04:48:47 INFO  : potato: Copied (replaced existing)
2024/12/29 04:48:47 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (5.38s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:48:50 DEBUG : potato: md5 = 5b33f242dba06be1ae6761e5f30ab8e8 OK
2024/12/29 04:48:52 DEBUG : empty space: md5 = e1ebbaad2ff679776f46ecf7581e8165 OK
2024/12/29 04:48:52 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/29 04:48:52 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2024/12/29 04:48:52 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:48:52 DEBUG : empty space: Unchanged skipping
2024/12/29 04:48:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:48:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:48:52 DEBUG : Waiting for deletions to finish
2024/12/29 04:48:52 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.56s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:48:56 DEBUG : potato: md5 = c620df1c027c1f7616dfb7236acd2f7a OK
2024/12/29 04:48:58 DEBUG : empty space: md5 = 48e0eb30b6213d485b077b4a73738c3c OK
2024/12/29 04:48:58 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/29 04:48:58 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:48:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:48:58 DEBUG : empty space: Unchanged skipping
2024/12/29 04:48:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:49:00 DEBUG : potato2: md5 = 80fa392a33980fd9809f8e88908b8b9c OK
2024/12/29 04:49:00 INFO  : potato2: Copied (new)
2024/12/29 04:49:00 DEBUG : Waiting for deletions to finish
2024/12/29 04:49:00 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.18s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:49:05 DEBUG : b/potato: md5 = 336ae3bee2fe39f387f0f65ed644d83e OK
2024/12/29 04:49:08 DEBUG : c/non empty space: md5 = e5863ed04b912e6abf85dd89761c366a OK
2024/12/29 04:49:08 DEBUG : d: Making directory
2024/12/29 04:49:08 DEBUG : d/e: Making directory
2024/12/29 04:49:10 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/12/29 04:49:10 DEBUG : Added delayed dir = "c", newDst=c
2024/12/29 04:49:10 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/12/29 04:49:11 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:49:11 DEBUG : c/non empty space: Unchanged skipping
2024/12/29 04:49:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:49:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:49:13 DEBUG : a/potato2: md5 = 021fa24003571cf412760d05f930fafe OK
2024/12/29 04:49:13 INFO  : a/potato2: Copied (new)
2024/12/29 04:49:13 DEBUG : Waiting for deletions to finish
2024/12/29 04:49:13 INFO  : b/potato: Deleted
2024/12/29 04:49:14 INFO  : a: Set directory modification time (using DirSetModTime)
2024/12/29 04:49:14 INFO  : d/e: Removing directory
2024/12/29 04:49:15 INFO  : d: Removing directory
2024/12/29 04:49:15 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2024/12/29 04:49:16 INFO  : b: Removing directory
2024/12/29 04:49:16 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/12/29 04:49:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:49:19 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/12/29 04:49:19 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (18.10s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:49:23 DEBUG : b/potato: md5 = 2af15dbe44dc431250bfb665480fd3e9 OK
2024/12/29 04:49:26 DEBUG : c/non empty space: md5 = 8e363d15e643145b8e8352991eaaf455 OK
2024/12/29 04:49:26 DEBUG : d: Making directory
2024/12/29 04:49:28 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/12/29 04:49:28 DEBUG : Added delayed dir = "c", newDst=c
2024/12/29 04:49:28 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/12/29 04:49:28 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:49:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:49:28 DEBUG : c/non empty space: Unchanged skipping
2024/12/29 04:49:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:49:30 DEBUG : a/potato2: md5 = 1ccb1371358f3f5aba9a42e1fe6eb751 OK
2024/12/29 04:49:30 INFO  : a/potato2: Copied (new)
2024/12/29 04:49:30 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': not deleting files as there were IO errors
2024/12/29 04:49:31 INFO  : a: Set directory modification time (using DirSetModTime)
2024/12/29 04:49:31 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:49:34 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/12/29 04:49:35 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/12/29 04:49:36 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (16.36s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:49:39 DEBUG : potato: md5 = 53cfabf779f2f64ba132c0498a957d3f OK
2024/12/29 04:49:40 DEBUG : empty space: md5 = d00cde9d1f8f5bb98dd69789ec73c3dc OK
2024/12/29 04:49:40 DEBUG : Waiting for deletions to finish
2024/12/29 04:49:41 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/29 04:49:41 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:49:41 DEBUG : empty space: Unchanged skipping
2024/12/29 04:49:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:49:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:49:41 INFO  : potato: Deleted
2024/12/29 04:49:42 DEBUG : potato2: md5 = 80bf7b27b30a40f6cbc10b49b44fd7e6 OK
2024/12/29 04:49:42 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (7.56s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:49:46 DEBUG : potato: md5 = f44c4fa321685b313530b4923b0fcee6 OK
2024/12/29 04:49:48 DEBUG : empty space: md5 = 645db101c8f622215e6cee12d5dcad91 OK
2024/12/29 04:49:48 DEBUG : Waiting for deletions to finish
2024/12/29 04:49:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:49:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:49:49 INFO  : potato: Deleted
2024/12/29 04:49:49 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/29 04:49:49 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:49:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:49:49 DEBUG : empty space: Unchanged skipping
2024/12/29 04:49:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:49:51 DEBUG : potato2: md5 = 764dacd4ede1c09a320a5f0ade5d478f OK
2024/12/29 04:49:51 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (8.50s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:49:55 DEBUG : potato: md5 = 1afa60591a59e6cc6d02b3e77587ff87 OK
2024/12/29 04:49:55 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/29 04:49:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:49:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:49:57 DEBUG : potato2: md5 = fe31e20f13adfe1bdeca16f2a9903c59 OK
2024/12/29 04:49:57 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (5.87s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:50:01 DEBUG : potato2: md5 = a814d686187186c2b6ba141aaba313aa OK
2024/12/29 04:50:02 DEBUG : empty space: md5 = 2b4d30d0f97c0061a8cfdf1b5a5ebb5c OK
2024/12/29 04:50:03 DEBUG : enormous: Excluded (Size Filter)
2024/12/29 04:50:03 DEBUG : enormous: Excluded
2024/12/29 04:50:03 DEBUG : potato2: Excluded (Size Filter)
2024/12/29 04:50:03 DEBUG : potato2: Excluded
2024/12/29 04:50:03 DEBUG : potato2: Excluded (Size Filter)
2024/12/29 04:50:03 DEBUG : potato2: Excluded
2024/12/29 04:50:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:50:03 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:50:03 DEBUG : empty space: Unchanged skipping
2024/12/29 04:50:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:50:03 DEBUG : Waiting for deletions to finish
2024/12/29 04:50:03 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:50:03 DEBUG : enormous: Excluded (Size Filter)
2024/12/29 04:50:03 DEBUG : enormous: Excluded
2024/12/29 04:50:03 DEBUG : potato2: Excluded (Size Filter)
2024/12/29 04:50:03 DEBUG : potato2: Excluded
2024/12/29 04:50:03 DEBUG : potato2: Excluded (Size Filter)
2024/12/29 04:50:03 DEBUG : potato2: Excluded
2024/12/29 04:50:03 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/12/29 04:50:03 DEBUG : empty space: Unchanged skipping
2024/12/29 04:50:03 DEBUG : Local file system at /tmp/rclone1793336062: Waiting for checks to finish
2024/12/29 04:50:03 DEBUG : Local file system at /tmp/rclone1793336062: Waiting for transfers to finish
2024/12/29 04:50:03 DEBUG : Waiting for deletions to finish
2024/12/29 04:50:03 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncWithExclude (6.82s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:50:08 DEBUG : potato2: md5 = 42dc25107e8cb1f3fe6f65028c90eff3 OK
2024/12/29 04:50:09 DEBUG : empty space: md5 = 8eba6d1664a0fe00a5976fdda3d83624 OK
2024/12/29 04:50:11 DEBUG : enormous: md5 = 407d45153a52e58aa892ca336eed1b2e OK
2024/12/29 04:50:11 DEBUG : enormous: Excluded (Size Filter)
2024/12/29 04:50:11 DEBUG : enormous: Excluded
2024/12/29 04:50:11 DEBUG : potato2: Excluded (Size Filter)
2024/12/29 04:50:11 DEBUG : potato2: Excluded
2024/12/29 04:50:11 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:50:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:50:11 DEBUG : empty space: Unchanged skipping
2024/12/29 04:50:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:50:11 DEBUG : Waiting for deletions to finish
2024/12/29 04:50:12 INFO  : potato2: Deleted
2024/12/29 04:50:12 INFO  : enormous: Deleted
2024/12/29 04:50:12 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:50:12 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/12/29 04:50:12 DEBUG : empty space: Unchanged skipping
2024/12/29 04:50:12 DEBUG : Local file system at /tmp/rclone1793336062: Waiting for checks to finish
2024/12/29 04:50:12 DEBUG : Local file system at /tmp/rclone1793336062: Waiting for transfers to finish
2024/12/29 04:50:12 DEBUG : Waiting for deletions to finish
2024/12/29 04:50:12 INFO  : enormous: Deleted
2024/12/29 04:50:12 INFO  : potato2: Deleted
2024/12/29 04:50:12 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (8.39s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:50:16 DEBUG : one: md5 = a70b61956c192838824816ceecba65b4 OK
2024/12/29 04:50:17 DEBUG : two: md5 = 8cb113b9b7f95cd81ad87f4872973fd1 OK
2024/12/29 04:50:19 DEBUG : three: md5 = fbe78bc493c333ec05e846d7f0352a97 OK
2024/12/29 04:50:21 DEBUG : four: md5 = 71827ef62d518f083aa2157096796686 OK
2024/12/29 04:50:21 DEBUG : five: Need to transfer - File not found at Destination
2024/12/29 04:50:21 DEBUG : four: Sizes differ (src 4 vs dst 8)
2024/12/29 04:50:21 DEBUG : one: Destination is newer than source, skipping
2024/12/29 04:50:21 DEBUG : three: Sizes identical
2024/12/29 04:50:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:50:21 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2024/12/29 04:50:21 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2024/12/29 04:50:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:50:22 DEBUG : two: md5 = 2606c7ea64f9cea23f1dd27a5f91b913 OK
2024/12/29 04:50:22 INFO  : two: Copied (replaced existing)
2024/12/29 04:50:22 DEBUG : four: md5 = 24260d752b1a92d68f33cb3029c3dc90 OK
2024/12/29 04:50:22 INFO  : four: Copied (replaced existing)
2024/12/29 04:50:23 DEBUG : five: md5 = 40f66fc6a1d64a4e319c8d5c0e4999cc OK
2024/12/29 04:50:23 INFO  : five: Copied (new)
2024/12/29 04:50:23 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (12.57s)
=== 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-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2024/12/29 04:50:27 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Ignoring --track-renames as the source and destination do not have a common hash
2024/12/29 04:50:27 DEBUG : potato: Need to transfer - File not found at Destination
2024/12/29 04:50:27 DEBUG : yam: Need to transfer - File not found at Destination
2024/12/29 04:50:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:50:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:50:28 DEBUG : potato: md5 = df7cdb32e0b33db858e589b3dc36f7dd OK
2024/12/29 04:50:28 INFO  : potato: Copied (new)
2024/12/29 04:50:29 DEBUG : yam: md5 = 7f23e808635969b205e24b841d535f86 OK
2024/12/29 04:50:29 INFO  : yam: Copied (new)
2024/12/29 04:50:29 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:50:29 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Ignoring --track-renames as the source and destination do not have a common hash
2024/12/29 04:50:29 DEBUG : yaml: Need to transfer - File not found at Destination
2024/12/29 04:50:29 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:50:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:50:29 DEBUG : potato: Unchanged skipping
2024/12/29 04:50:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:50:31 DEBUG : yaml: md5 = 7fb709d6a79da143fb24cea4fdd9b8ea OK
2024/12/29 04:50:31 INFO  : yaml: Copied (new)
2024/12/29 04:50:31 DEBUG : Waiting for deletions to finish
2024/12/29 04:50:31 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (7.03s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2024/12/29 04:50:34 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Making map for --track-renames
2024/12/29 04:50:34 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Finished making map for --track-renames
2024/12/29 04:50:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:50:34 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/12/29 04:50:34 DEBUG : yam: Need to transfer - No matching file found at Destination
2024/12/29 04:50:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for renames to finish
2024/12/29 04:50:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:50:35 DEBUG : yam: md5 = c36bd45b1480de0d581a265c9a76c409 OK
2024/12/29 04:50:35 INFO  : yam: Copied (new)
2024/12/29 04:50:36 DEBUG : potato: md5 = 8bd5e529b1e9c1ec85b1df663f8eaaf4 OK
2024/12/29 04:50:36 INFO  : potato: Copied (new)
2024/12/29 04:50:36 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:50:36 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:50:36 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Making map for --track-renames
2024/12/29 04:50:36 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Finished making map for --track-renames
2024/12/29 04:50:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:50:36 DEBUG : potato: Unchanged skipping
2024/12/29 04:50:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for renames to finish
2024/12/29 04:50:37 INFO  : yam: Moved (server-side) to: yaml
2024/12/29 04:50:37 INFO  : yaml: Renamed from "yam"
2024/12/29 04:50:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:50:37 DEBUG : Waiting for deletions to finish
2024/12/29 04:50:37 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (5.73s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2024/12/29 04:50:40 DEBUG : Added delayed dir = "sub", newDst=<nil>
2024/12/29 04:50:40 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Making map for --track-renames
2024/12/29 04:50:40 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Finished making map for --track-renames
2024/12/29 04:50:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:50:40 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/12/29 04:50:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for renames to finish
2024/12/29 04:50:40 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2024/12/29 04:50:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:50:42 DEBUG : potato: md5 = 8f3e721d5d46927ba547643bd78c6343 OK
2024/12/29 04:50:42 INFO  : potato: Copied (new)
2024/12/29 04:50:42 DEBUG : sub/yam: md5 = 93a321cad7939ca5997244adc5efeb3c OK
2024/12/29 04:50:42 INFO  : sub/yam: Copied (new)
2024/12/29 04:50:42 DEBUG : Waiting for deletions to finish
2024/12/29 04:50:43 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:50:44 DEBUG : Added delayed dir = "sub", newDst=sub
2024/12/29 04:50:44 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:50:44 DEBUG : potato: Unchanged skipping
2024/12/29 04:50:44 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Making map for --track-renames
2024/12/29 04:50:44 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Finished making map for --track-renames
2024/12/29 04:50:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:50:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for renames to finish
2024/12/29 04:50:45 INFO  : sub/yam: Moved (server-side) to: yam
2024/12/29 04:50:45 INFO  : yam: Renamed from "sub/yam"
2024/12/29 04:50:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:50:45 DEBUG : Waiting for deletions to finish
2024/12/29 04:50:45 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.39s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:50:49 DEBUG : Creating backend with remote "/tmp/rclone1793336062/dir1"
2024/12/29 04:50:49 DEBUG : Config file has changed externally - reloading
2024/12/29 04:50:49 DEBUG : Creating backend with remote "/tmp/rclone1793336062/dir2"
2024/12/29 04:50:49 DEBUG : Local file system at /tmp/rclone1793336062/dir2: Using server-side directory move
2024/12/29 04:50:49 INFO  : Local file system at /tmp/rclone1793336062/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/12/29 04:50:49 DEBUG : file1.txt: Need to transfer - File not found at Destination
2024/12/29 04:50:49 INFO  : file1.txt: Moved (server-side)
2024/12/29 04:50:49 DEBUG : Local file system at /tmp/rclone1793336062/dir2: Waiting for checks to finish
2024/12/29 04:50:49 DEBUG : Local file system at /tmp/rclone1793336062/dir2: Waiting for transfers to finish
--- PASS: TestServerSideMoveLocal (0.43s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:50:50 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/12/29 04:50:50 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/29 04:50:50 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/29 04:50:50 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/12/29 04:50:50 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/12/29 04:50:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:50:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:50:52 DEBUG : sub dir/hello world: md5 = 2f3e5df8bddc0cb0b6d5668bd86e9491 OK
2024/12/29 04:50:52 INFO  : sub dir/hello world: Copied (new)
2024/12/29 04:50:52 INFO  : sub dir/hello world: Deleted
2024/12/29 04:50:54 DEBUG : nested/sub dir/file: md5 = e770196cb91e3a591455f3278e780472 OK
2024/12/29 04:50:54 INFO  : nested/sub dir/file: Copied (new)
2024/12/29 04:50:54 INFO  : nested/sub dir/file: Deleted
2024/12/29 04:50:55 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/12/29 04:50:55 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/29 04:50:55 INFO  : nested: Set directory modification time (using DirSetModTime)
2024/12/29 04:50:55 INFO  : sub dir: Removing directory
2024/12/29 04:50:55 INFO  : nested/sub dir: Removing directory
2024/12/29 04:50:55 INFO  : nested: Removing directory
2024/12/29 04:50:55 DEBUG : Local file system at /tmp/rclone1793336062: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:50:58 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/12/29 04:50:59 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/12/29 04:51:00 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (11.45s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:51:01 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/12/29 04:51:01 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/12/29 04:51:01 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/12/29 04:51:01 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/12/29 04:51:01 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/12/29 04:51:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:51:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:51:04 DEBUG : sub dir/hello world: md5 = 4e2db31196052570d6dff089575976e8 OK
2024/12/29 04:51:04 INFO  : sub dir/hello world: Copied (new)
2024/12/29 04:51:04 INFO  : sub dir/hello world: Deleted
2024/12/29 04:51:06 DEBUG : nested/sub dir/file: md5 = 425e811315126097fec0df84a511b783 OK
2024/12/29 04:51:06 INFO  : nested/sub dir/file: Copied (new)
2024/12/29 04:51:06 INFO  : nested/sub dir/file: Deleted
2024/12/29 04:51:06 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/12/29 04:51:07 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/29 04:51:07 INFO  : nested: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:51:10 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/12/29 04:51:11 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/12/29 04:51:11 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (11.80s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:51:13 DEBUG : existing: Need to transfer - File not found at Destination
2024/12/29 04:51:13 DEBUG : existing-b: Need to transfer - File not found at Destination
2024/12/29 04:51:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:51:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:51:14 DEBUG : existing: md5 = 408164989c7445db3277b6532fad2a16 OK
2024/12/29 04:51:14 INFO  : existing: Copied (new)
2024/12/29 04:51:14 INFO  : existing: Deleted
2024/12/29 04:51:14 DEBUG : existing-b: md5 = 48630b9ce8f1915b299bc0609b284bab OK
2024/12/29 04:51:14 INFO  : existing-b: Copied (new)
2024/12/29 04:51:14 INFO  : existing-b: Deleted
2024/12/29 04:51:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:51:15 DEBUG : existing: Destination exists, skipping
2024/12/29 04:51:15 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2024/12/29 04:51:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:51:15 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (4.53s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:51:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuzeqif8kuwi"
2024/12/29 04:51:17 DEBUG : Creating backend with remote "TestDrive:crypt/njc1cm0ddahr2roj40ggivsjm39bj1se831jc7t470mqo822hb40"
2024/12/29 04:51:20 DEBUG : potato2: md5 = 18aaa351b83504ae1f2a5e9dcc1577c6 OK
2024/12/29 04:51:21 DEBUG : empty space: md5 = 3c54c1cb74af08d97e71abd18bc74c7c OK
2024/12/29 04:51:23 DEBUG : potato3: md5 = b29c1664be368211c13d048e1459826a OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu' -> Encrypted drive 'TestCryptDrive:rclone-test-tuzeqif8kuwi'
2024/12/29 04:51:26 DEBUG : empty space: md5 = db662484780dd634697d94889b9d061f OK
2024/12/29 04:51:28 DEBUG : potato3: md5 = 5a4fadad9f1cfd92e379b654f4fe6e7c OK
2024/12/29 04:51:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuzeqif8kuwi': Using server-side directory move
2024/12/29 04:51:28 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tuzeqif8kuwi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/12/29 04:51:28 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/29 04:51:28 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/12/29 04:51:28 DEBUG : empty space: Unchanged skipping
2024/12/29 04:51:28 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/12/29 04:51:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuzeqif8kuwi': Waiting for checks to finish
2024/12/29 04:51:28 INFO  : empty space: Deleted
2024/12/29 04:51:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuzeqif8kuwi': Waiting for transfers to finish
2024/12/29 04:51:29 INFO  : potato3: Deleted
2024/12/29 04:51:29 INFO  : potato2: Moved (server-side)
2024/12/29 04:51:29 INFO  : potato3: Moved (server-side)
2024/12/29 04:51:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fipojeg4zaju"
2024/12/29 04:51:30 DEBUG : Creating backend with remote "TestDrive:crypt/7pu3e3o1p19b96vplbev2vg9g0279r0mku8bsbe6r6r2s8h44hjg"
2024/12/29 04:51:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fipojeg4zaju': Using server-side directory move
2024/12/29 04:51:32 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-fipojeg4zaju': Server side directory move succeeded
2024/12/29 04:51:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fipojeg4zaju': Purge remote
2024/12/29 04:51:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuzeqif8kuwi': Purge remote
2024/12/29 04:51:33 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (16.81s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:51:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kemupoj2haci"
2024/12/29 04:51:34 DEBUG : Creating backend with remote "TestDrive:crypt/nohelkc4v1cj8d4t1672h3e0jn04mlfti7dset657fbi7efpu7c0"
2024/12/29 04:51:36 DEBUG : potato2: md5 = e19e05d8cd953cfd85240f74f32fb98d OK
2024/12/29 04:51:38 DEBUG : empty space: md5 = 45b4c3efc52a7a20225bffe83dbdd95e OK
2024/12/29 04:51:40 DEBUG : potato3: md5 = b1a17209b4c64ca83e453c8a055c288e OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu' -> Encrypted drive 'TestCryptDrive:rclone-test-kemupoj2haci'
2024/12/29 04:51:42 DEBUG : empty space: md5 = d0d0726be5eb5b86544d65e589f38f17 OK
2024/12/29 04:51:44 DEBUG : potato3: md5 = feea1e458bf37b4bde9eddb58907cf58 OK
2024/12/29 04:51:45 DEBUG : empty space: Excluded (Size Filter)
2024/12/29 04:51:45 DEBUG : empty space: Excluded
2024/12/29 04:51:45 DEBUG : empty space: Excluded (Size Filter)
2024/12/29 04:51:45 DEBUG : empty space: Excluded
2024/12/29 04:51:45 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/29 04:51:45 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/12/29 04:51:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kemupoj2haci': Waiting for checks to finish
2024/12/29 04:51:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kemupoj2haci': Waiting for transfers to finish
2024/12/29 04:51:45 INFO  : potato3: Deleted
2024/12/29 04:51:46 INFO  : potato2: Moved (server-side)
2024/12/29 04:51:46 INFO  : potato3: Moved (server-side)
2024/12/29 04:51:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-becopor7zazo"
2024/12/29 04:51:47 DEBUG : Creating backend with remote "TestDrive:crypt/7t90cul4r42kh6240capjbejp3pt8pafhm0ma21j7nmk2tdogftg"
2024/12/29 04:51:48 DEBUG : empty space: Excluded (Size Filter)
2024/12/29 04:51:48 DEBUG : empty space: Excluded
2024/12/29 04:51:48 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/29 04:51:48 DEBUG : potato3: Need to transfer - File not found at Destination
2024/12/29 04:51:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-becopor7zazo': Waiting for checks to finish
2024/12/29 04:51:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-becopor7zazo': Waiting for transfers to finish
2024/12/29 04:51:49 INFO  : potato3: Moved (server-side)
2024/12/29 04:51:50 INFO  : potato2: Moved (server-side)
2024/12/29 04:51:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-becopor7zazo': Purge remote
2024/12/29 04:51:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kemupoj2haci': Purge remote
--- PASS: TestServerSideMoveWithFilter (18.84s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:51:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cusijis7vemi"
2024/12/29 04:51:53 DEBUG : Creating backend with remote "TestDrive:crypt/0jj4rkrsc1kdp442k7p70165al37nm8qj838v4o0ht32l6d3sfc0"
2024/12/29 04:51:55 DEBUG : potato2: md5 = 978a491eb54443a0b7f257f457379690 OK
2024/12/29 04:51:57 DEBUG : empty space: md5 = b1640a4fec02fc01a0c2a2576797adb4 OK
2024/12/29 04:51:59 DEBUG : potato3: md5 = 1a8565f0e4cf4add3ca90c424c47c9f5 OK
2024/12/29 04:51:59 DEBUG : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu' -> Encrypted drive 'TestCryptDrive:rclone-test-cusijis7vemi'
2024/12/29 04:52:03 DEBUG : empty space: md5 = 3c35ccf02f40165f24e2d9dcf4303195 OK
2024/12/29 04:52:04 DEBUG : potato3: md5 = 5951c48fe1a5a45b15fbebe98c57168e OK
2024/12/29 04:52:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cusijis7vemi': Using server-side directory move
2024/12/29 04:52:05 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-cusijis7vemi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/12/29 04:52:05 DEBUG : potato2: Need to transfer - File not found at Destination
2024/12/29 04:52:05 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2024/12/29 04:52:05 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/12/29 04:52:05 DEBUG : empty space: Unchanged skipping
2024/12/29 04:52:05 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/12/29 04:52:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cusijis7vemi': Waiting for checks to finish
2024/12/29 04:52:05 INFO  : empty space: Deleted
2024/12/29 04:52:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cusijis7vemi': Waiting for transfers to finish
2024/12/29 04:52:05 INFO  : potato3: Deleted
2024/12/29 04:52:06 INFO  : potato2: Moved (server-side)
2024/12/29 04:52:07 INFO  : potato3: Moved (server-side)
2024/12/29 04:52:07 INFO  : tomatoDir: Removing directory
2024/12/29 04:52:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': deleted 1 directories
2024/12/29 04:52:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fuyosat4nuko"
2024/12/29 04:52:08 DEBUG : Creating backend with remote "TestDrive:crypt/jmbet6686rceu31rl3pctls1l4l5olmsppa3h36ilm8ar9jbk57g"
2024/12/29 04:52:09 DEBUG : tomatoDir: Making directory
2024/12/29 04:52:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fuyosat4nuko': Using server-side directory move
2024/12/29 04:52:11 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-fuyosat4nuko': Server side directory move succeeded
2024/12/29 04:52:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fuyosat4nuko': Purge remote
2024/12/29 04:52:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cusijis7vemi': Purge remote
2024/12/29 04:52:13 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (20.93s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.47s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:52:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/rclone-sync-test"
2024/12/29 04:52:14 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncOverlap (3.80s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:52:18 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/rclone-sync-test"
2024/12/29 04:52:18 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2024/12/29 04:52:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/rclone-sync-test-include/layer2"
2024/12/29 04:52:20 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2024/12/29 04:52:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/rclone-sync-test-ignore-file"
2024/12/29 04:52:24 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2024/12/29 04:52:28 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 2fd7ac5fccc3ada9412bab1f791ef1c3 OK
2024/12/29 04:52:29 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/12/29 04:52:30 DEBUG : rclone-sync-test: Excluded
2024/12/29 04:52:30 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/12/29 04:52:30 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/12/29 04:52:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/rclone-sync-test': Waiting for checks to finish
2024/12/29 04:52:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/rclone-sync-test': Waiting for transfers to finish
2024/12/29 04:52:30 DEBUG : Waiting for deletions to finish
2024/12/29 04:52:30 INFO  : There was nothing to transfer
2024/12/29 04:52:31 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/12/29 04:52:31 DEBUG : rclone-sync-test: Excluded
2024/12/29 04:52:32 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/12/29 04:52:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:52:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:52:32 DEBUG : Waiting for deletions to finish
2024/12/29 04:52:32 INFO  : rclone-sync-test-include: Removing directory
2024/12/29 04:52:32 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/12/29 04:52:32 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/12/29 04:52:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': failed to delete 1 directories
2024/12/29 04:52:32 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:52:33 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/12/29 04:52:33 DEBUG : rclone-sync-test: Excluded
2024/12/29 04:52:33 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/12/29 04:52:34 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/12/29 04:52:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/rclone-sync-test-include/layer2': Waiting for checks to finish
2024/12/29 04:52:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/rclone-sync-test-include/layer2': Waiting for transfers to finish
2024/12/29 04:52:34 DEBUG : Waiting for deletions to finish
2024/12/29 04:52:34 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:52:34 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/12/29 04:52:35 DEBUG : rclone-sync-test: Excluded
2024/12/29 04:52:35 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/12/29 04:52:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:52:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:52:35 DEBUG : Waiting for deletions to finish
2024/12/29 04:52:35 INFO  : rclone-sync-test-include: Removing directory
2024/12/29 04:52:35 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/12/29 04:52:35 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/12/29 04:52:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': failed to delete 1 directories
2024/12/29 04:52:35 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:52:36 DEBUG : : Excluded
2024/12/29 04:52:36 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/12/29 04:52:36 DEBUG : rclone-sync-test: Excluded
2024/12/29 04:52:36 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/12/29 04:52:37 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/12/29 04:52:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/rclone-sync-test-ignore-file': Waiting for checks to finish
2024/12/29 04:52:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/rclone-sync-test-ignore-file': Waiting for transfers to finish
2024/12/29 04:52:37 DEBUG : Waiting for deletions to finish
2024/12/29 04:52:37 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:52:39 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/12/29 04:52:40 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (31.08s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:52:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/dst"
2024/12/29 04:52:49 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/29 04:52:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/CompareDest"
2024/12/29 04:52:50 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/gveqi14airsml4bgu7krj116o8"
2024/12/29 04:52:52 DEBUG : one: Need to transfer - File not found at Destination
2024/12/29 04:52:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for checks to finish
2024/12/29 04:52:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for transfers to finish
2024/12/29 04:52:55 DEBUG : one: md5 = 1889c382ebb4cbe6a23d5c3ae2232a2f OK
2024/12/29 04:52:55 INFO  : one: Copied (new)
2024/12/29 04:52:55 DEBUG : Waiting for deletions to finish
2024/12/29 04:52:56 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/29 04:52:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for checks to finish
2024/12/29 04:52:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for transfers to finish
2024/12/29 04:52:58 DEBUG : one: md5 = 04fb685296fd741af543ec1dd0bad18a OK
2024/12/29 04:52:58 INFO  : one: Copied (replaced existing)
2024/12/29 04:52:58 DEBUG : Waiting for deletions to finish
2024/12/29 04:52:59 DEBUG : dst/one: md5 = cb92daa58d286d08da465250cb759b94 OK
2024/12/29 04:53:02 DEBUG : CompareDest/one: md5 = df810f60b65656ffc91d4c44f36bd130 OK
2024/12/29 04:53:03 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/29 04:53:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for checks to finish
2024/12/29 04:53:04 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:53:04 DEBUG : one: Destination found in --compare-dest, skipping
2024/12/29 04:53:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for transfers to finish
2024/12/29 04:53:04 DEBUG : Waiting for deletions to finish
2024/12/29 04:53:04 INFO  : There was nothing to transfer
2024/12/29 04:53:06 DEBUG : CompareDest/two: md5 = 98bb1227e63fb8d0069db770f997aa77 OK
2024/12/29 04:53:07 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:53:07 DEBUG : two: Destination found in --compare-dest, skipping
2024/12/29 04:53:07 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/29 04:53:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for checks to finish
2024/12/29 04:53:07 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:53:07 DEBUG : one: Destination found in --compare-dest, skipping
2024/12/29 04:53:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for transfers to finish
2024/12/29 04:53:07 DEBUG : Waiting for deletions to finish
2024/12/29 04:53:07 INFO  : There was nothing to transfer
2024/12/29 04:53:08 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:53:08 DEBUG : two: Destination found in --compare-dest, skipping
2024/12/29 04:53:08 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/29 04:53:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for checks to finish
2024/12/29 04:53:08 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:53:08 DEBUG : one: Destination found in --compare-dest, skipping
2024/12/29 04:53:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for transfers to finish
2024/12/29 04:53:08 DEBUG : Waiting for deletions to finish
2024/12/29 04:53:08 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2024/12/29 04:53:10 DEBUG : two: Sizes differ (src 5 vs dst 3)
2024/12/29 04:53:10 DEBUG : two: Need to transfer - File not found at Destination
2024/12/29 04:53:10 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/29 04:53:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for checks to finish
2024/12/29 04:53:10 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:53:10 DEBUG : one: Destination found in --compare-dest, skipping
2024/12/29 04:53:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for transfers to finish
2024/12/29 04:53:11 DEBUG : two: md5 = 5eff6d23dface69379ebd0d8e81aa57a OK
2024/12/29 04:53:11 INFO  : two: Copied (new)
2024/12/29 04:53:11 DEBUG : Waiting for deletions to finish
2024/12/29 04:53:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/29 04:53:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/29 04:53:16 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/29 04:53:16 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncCompareDest (27.37s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:53:19 DEBUG : pre-dest1/1: md5 = 823364c818d828b3bc20266e5600ec4d OK
2024/12/29 04:53:22 DEBUG : pre-dest2/2: md5 = ede3c2b76e9237c646d8b3cf9f63f374 OK
2024/12/29 04:53:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/dest"
2024/12/29 04:53:22 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/rg03c1jvnehrrc617i0lnqjddc"
2024/12/29 04:53:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/pre-dest1"
2024/12/29 04:53:24 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/bbnblvh6k061ssopqrp18kd7gc"
2024/12/29 04:53:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/pre-dest2"
2024/12/29 04:53:24 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/dgicm1h6b5ejvlltm8eeif0bnk"
2024/12/29 04:53:26 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:53:26 DEBUG : 1: Destination found in --compare-dest, skipping
2024/12/29 04:53:26 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:53:26 DEBUG : 2: Destination found in --compare-dest, skipping
2024/12/29 04:53:26 DEBUG : 3: Need to transfer - File not found at Destination
2024/12/29 04:53:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dest': Waiting for checks to finish
2024/12/29 04:53:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dest': Waiting for transfers to finish
2024/12/29 04:53:29 DEBUG : 3: md5 = b967c089d3ac1915cd2243511714ef6d OK
2024/12/29 04:53:29 INFO  : 3: Copied (new)
2024/12/29 04:53:29 DEBUG : Waiting for deletions to finish
2024/12/29 04:53:32 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2024/12/29 04:53:33 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2024/12/29 04:53:34 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (18.03s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:53:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/dst"
2024/12/29 04:53:34 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/29 04:53:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/CopyDest"
2024/12/29 04:53:36 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/d09o6po3f7bm6ce32vdgs8h9ls"
2024/12/29 04:53:38 DEBUG : one: Need to transfer - File not found at Destination
2024/12/29 04:53:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for checks to finish
2024/12/29 04:53:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for transfers to finish
2024/12/29 04:53:40 DEBUG : one: md5 = d53f85e021716b900f2aeb9ed8d312d3 OK
2024/12/29 04:53:40 INFO  : one: Copied (new)
2024/12/29 04:53:40 DEBUG : Waiting for deletions to finish
2024/12/29 04:53:42 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/29 04:53:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for checks to finish
2024/12/29 04:53:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for transfers to finish
2024/12/29 04:53:43 DEBUG : one: md5 = 4d8b1e99018c06c07c3fdffb91c6badb OK
2024/12/29 04:53:43 INFO  : one: Copied (replaced existing)
2024/12/29 04:53:43 DEBUG : Waiting for deletions to finish
2024/12/29 04:53:45 DEBUG : dst/one: md5 = 70e42ba36f0f0afe8faf9ae420e4cbc9 OK
2024/12/29 04:53:48 DEBUG : CopyDest/one: md5 = 2b8030f56acce0d0e4c455ecc70c8577 OK
2024/12/29 04:53:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/BackupDir"
2024/12/29 04:53:48 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/s6dbk3lfi7c9kfvo6j7bla9m0g"
2024/12/29 04:53:50 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/29 04:53:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for checks to finish
2024/12/29 04:53:50 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:53:50 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/12/29 04:53:52 INFO  : one: Moved (server-side)
2024/12/29 04:53:54 INFO  : one: Copied (server-side copy)
2024/12/29 04:53:54 DEBUG : one: Destination found in --copy-dest, using server-side copy
2024/12/29 04:53:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for transfers to finish
2024/12/29 04:53:54 DEBUG : Waiting for deletions to finish
2024/12/29 04:53:56 DEBUG : CopyDest/two: md5 = db2b9c54faaa574e5b2a610bd989694d OK
2024/12/29 04:53:57 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:53:58 INFO  : two: Copied (server-side copy)
2024/12/29 04:53:58 DEBUG : two: Destination found in --copy-dest, using server-side copy
2024/12/29 04:53:58 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:53:58 DEBUG : one: Unchanged skipping
2024/12/29 04:53:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for checks to finish
2024/12/29 04:53:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for transfers to finish
2024/12/29 04:53:58 DEBUG : Waiting for deletions to finish
2024/12/29 04:53:59 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:53:59 DEBUG : one: Unchanged skipping
2024/12/29 04:53:59 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:53:59 DEBUG : two: Unchanged skipping
2024/12/29 04:53:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for checks to finish
2024/12/29 04:53:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for transfers to finish
2024/12/29 04:53:59 DEBUG : Waiting for deletions to finish
2024/12/29 04:53:59 INFO  : There was nothing to transfer
2024/12/29 04:54:01 DEBUG : CopyDest/three: md5 = d3d01323a3cc32936424b41b984835b6 OK
2024/12/29 04:54:02 DEBUG : three: Sizes differ (src 7 vs dst 5)
2024/12/29 04:54:02 DEBUG : three: Destination not found in --copy-dest
2024/12/29 04:54:02 DEBUG : three: Need to transfer - File not found at Destination
2024/12/29 04:54:02 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:54:02 DEBUG : one: Unchanged skipping
2024/12/29 04:54:02 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/12/29 04:54:02 DEBUG : two: Unchanged skipping
2024/12/29 04:54:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for checks to finish
2024/12/29 04:54:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for transfers to finish
2024/12/29 04:54:03 DEBUG : three: md5 = deeea2dd99f88606703ddcb81a26ad9d OK
2024/12/29 04:54:03 INFO  : three: Copied (new)
2024/12/29 04:54:03 DEBUG : Waiting for deletions to finish
2024/12/29 04:54:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/12/29 04:54:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/29 04:54:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/29 04:54:09 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/29 04:54:09 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/12/29 04:54:09 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/29 04:54:10 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (36.57s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:54:14 DEBUG : dst/one: md5 = 547677e4fa4a22588b840f58088c7edf OK
2024/12/29 04:54:16 DEBUG : dst/two: md5 = 34e9daae7dbae85611b1d70a24125575 OK
2024/12/29 04:54:17 DEBUG : dst/three.txt: md5 = e468bd83394753743d4c6e707333b4e3 OK
2024/12/29 04:54:18 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/dst"
2024/12/29 04:54:18 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/29 04:54:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/backup"
2024/12/29 04:54:19 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/1nrff024r7pq65ecp72fc28jb0"
2024/12/29 04:54:20 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/29 04:54:20 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:54:20 DEBUG : two: Unchanged skipping
2024/12/29 04:54:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for checks to finish
2024/12/29 04:54:23 INFO  : one: Moved (server-side)
2024/12/29 04:54:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for transfers to finish
2024/12/29 04:54:24 DEBUG : one: md5 = 94bb6e1f1ed2246209ca70322f9ff5fb OK
2024/12/29 04:54:24 INFO  : one: Copied (new)
2024/12/29 04:54:24 DEBUG : Waiting for deletions to finish
2024/12/29 04:54:25 INFO  : three.txt: Moved (server-side)
2024/12/29 04:54:25 INFO  : three.txt: Moved into backup dir
2024/12/29 04:54:27 DEBUG : dst/three.txt: md5 = 83365391dd6ac2d386ff2f4936748d6f OK
2024/12/29 04:54:28 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/29 04:54:28 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:54:28 DEBUG : two: Unchanged skipping
2024/12/29 04:54:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for checks to finish
2024/12/29 04:54:29 INFO  : one: Deleted
2024/12/29 04:54:30 INFO  : one: Moved (server-side)
2024/12/29 04:54:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for transfers to finish
2024/12/29 04:54:31 DEBUG : one: md5 = 16e35a7e9b562df34a31544f0b451276 OK
2024/12/29 04:54:31 INFO  : one: Copied (new)
2024/12/29 04:54:31 DEBUG : Waiting for deletions to finish
2024/12/29 04:54:32 INFO  : three.txt: Deleted
2024/12/29 04:54:33 INFO  : three.txt: Moved (server-side)
2024/12/29 04:54:33 INFO  : three.txt: Moved into backup dir
2024/12/29 04:54:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/29 04:54:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/29 04:54:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/12/29 04:54:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/29 04:54:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/29 04:54:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
--- PASS: TestSyncBackupDir (27.40s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:54:41 DEBUG : dst/one: md5 = 38a23fffeff20d2d78750ac9ba8b338b OK
2024/12/29 04:54:43 DEBUG : dst/two: md5 = 6d09f09f64438155941ca7da96fed7c1 OK
2024/12/29 04:54:44 DEBUG : dst/three.txt: md5 = 75e40ddf74f8ebfe418d8cc80bab0676 OK
2024/12/29 04:54:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/dst"
2024/12/29 04:54:45 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/29 04:54:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/backup"
2024/12/29 04:54:46 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/1nrff024r7pq65ecp72fc28jb0"
2024/12/29 04:54:47 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/29 04:54:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for checks to finish
2024/12/29 04:54:47 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:54:47 DEBUG : two: Unchanged skipping
2024/12/29 04:54:49 INFO  : one: Moved (server-side) to: one.bak
2024/12/29 04:54:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for transfers to finish
2024/12/29 04:54:51 DEBUG : one: md5 = 5d3010292a71ca9ffb6ccde8e4472697 OK
2024/12/29 04:54:51 INFO  : one: Copied (new)
2024/12/29 04:54:51 DEBUG : Waiting for deletions to finish
2024/12/29 04:54:52 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/29 04:54:52 INFO  : three.txt: Moved into backup dir
2024/12/29 04:54:54 DEBUG : dst/three.txt: md5 = bc41a2a727767f22932c294557a335bb OK
2024/12/29 04:54:55 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/29 04:54:55 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:54:55 DEBUG : two: Unchanged skipping
2024/12/29 04:54:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for checks to finish
2024/12/29 04:54:55 INFO  : one.bak: Deleted
2024/12/29 04:54:56 INFO  : one: Moved (server-side) to: one.bak
2024/12/29 04:54:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for transfers to finish
2024/12/29 04:54:58 DEBUG : one: md5 = 44cbb44305c3227ec7a82d7ebbba5eb8 OK
2024/12/29 04:54:58 INFO  : one: Copied (new)
2024/12/29 04:54:58 DEBUG : Waiting for deletions to finish
2024/12/29 04:55:01 INFO  : three.txt.bak: Deleted
2024/12/29 04:55:04 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/29 04:55:04 INFO  : three.txt: Moved into backup dir
2024/12/29 04:55:08 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/29 04:55:08 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/29 04:55:08 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/12/29 04:55:08 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/12/29 04:55:08 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/12/29 04:55:08 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncBackupDirWithSuffix (30.85s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:55:12 DEBUG : dst/one: md5 = e91d2f1635d9c02bf258b26f766ed0f2 OK
2024/12/29 04:55:13 DEBUG : dst/two: md5 = 33eb9d4639dcecff69e24a44cb4e3c84 OK
2024/12/29 04:55:15 DEBUG : dst/three.txt: md5 = 78d83c75f1de22ae5709803a9e70836d OK
2024/12/29 04:55:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/dst"
2024/12/29 04:55:15 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/29 04:55:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/backup"
2024/12/29 04:55:16 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/1nrff024r7pq65ecp72fc28jb0"
2024/12/29 04:55:18 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/29 04:55:18 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:55:18 DEBUG : two: Unchanged skipping
2024/12/29 04:55:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for checks to finish
2024/12/29 04:55:20 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/12/29 04:55:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for transfers to finish
2024/12/29 04:55:22 DEBUG : one: md5 = 9ee29fb366231568f48b184a4a601a90 OK
2024/12/29 04:55:22 INFO  : one: Copied (new)
2024/12/29 04:55:22 DEBUG : Waiting for deletions to finish
2024/12/29 04:55:23 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/12/29 04:55:23 INFO  : three.txt: Moved into backup dir
2024/12/29 04:55:25 DEBUG : dst/three.txt: md5 = 6aad9fb3ebcd5581181b961018a3fb3e OK
2024/12/29 04:55:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for checks to finish
2024/12/29 04:55:26 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:55:26 DEBUG : two: Unchanged skipping
2024/12/29 04:55:26 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/29 04:55:27 INFO  : one-2019-01-01: Deleted
2024/12/29 04:55:27 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/12/29 04:55:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for transfers to finish
2024/12/29 04:55:29 DEBUG : one: md5 = 5fb644be78d540f611368da31802ecce OK
2024/12/29 04:55:29 INFO  : one: Copied (new)
2024/12/29 04:55:29 DEBUG : Waiting for deletions to finish
2024/12/29 04:55:30 INFO  : three-2019-01-01.txt: Deleted
2024/12/29 04:55:31 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/12/29 04:55:31 INFO  : three.txt: Moved into backup dir
2024/12/29 04:55:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/29 04:55:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/29 04:55:35 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/12/29 04:55:35 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/12/29 04:55:35 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/12/29 04:55:35 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (26.34s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:55:38 DEBUG : dst/one: md5 = 389f07d6f9d2fe4a06e41673d793534c OK
2024/12/29 04:55:40 DEBUG : dst/two: md5 = 38c5c1847a21820265da55d49b131bd9 OK
2024/12/29 04:55:41 DEBUG : dst/three.txt: md5 = 6cf72648db764d235aee471de6811a0e OK
2024/12/29 04:55:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/dst"
2024/12/29 04:55:42 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/29 04:55:43 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/29 04:55:43 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:55:43 DEBUG : two: Unchanged skipping
2024/12/29 04:55:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for checks to finish
2024/12/29 04:55:43 INFO  : one: Moved (server-side) to: one.bak
2024/12/29 04:55:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for transfers to finish
2024/12/29 04:55:45 DEBUG : one: md5 = 666f4b445d06342e150b4aeab28b6627 OK
2024/12/29 04:55:45 INFO  : one: Copied (new)
2024/12/29 04:55:45 DEBUG : Waiting for deletions to finish
2024/12/29 04:55:46 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/29 04:55:46 INFO  : three.txt: Moved into backup dir
2024/12/29 04:55:48 DEBUG : dst/three.txt: md5 = 133f216f9e20f772202bc36b02b52eb8 OK
2024/12/29 04:55:49 DEBUG : one.bak: Excluded (Path Filter)
2024/12/29 04:55:49 DEBUG : one.bak: Excluded
2024/12/29 04:55:49 DEBUG : three.txt.bak: Excluded (Path Filter)
2024/12/29 04:55:49 DEBUG : three.txt.bak: Excluded
2024/12/29 04:55:49 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/29 04:55:49 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:55:49 DEBUG : two: Unchanged skipping
2024/12/29 04:55:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for checks to finish
2024/12/29 04:55:50 INFO  : one.bak: Deleted
2024/12/29 04:55:50 INFO  : one: Moved (server-side) to: one.bak
2024/12/29 04:55:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu/dst': Waiting for transfers to finish
2024/12/29 04:55:52 DEBUG : one: md5 = 25147a8df6ed2f12c8cb1a40173b21ce OK
2024/12/29 04:55:52 INFO  : one: Copied (new)
2024/12/29 04:55:52 DEBUG : Waiting for deletions to finish
2024/12/29 04:55:52 INFO  : three.txt.bak: Deleted
2024/12/29 04:55:53 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/29 04:55:53 INFO  : three.txt: Moved into backup dir
2024/12/29 04:55:57 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/29 04:55:57 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/12/29 04:55:57 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/12/29 04:55:57 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/29 04:55:57 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/12/29 04:55:57 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncBackupDirSuffixOnly (21.70s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:56:00 DEBUG : dst/one: md5 = 739c387d7d788e535628932a5e5574e1 OK
2024/12/29 04:56:02 DEBUG : dst/two: md5 = 62f320d25a58a08fcd0688a5683c3b27 OK
2024/12/29 04:56:03 DEBUG : dst/three.txt: md5 = 0488edf587feab8b01991e1ae967ae90 OK
2024/12/29 04:56:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/dst"
2024/12/29 04:56:04 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/29 04:56:05 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/29 04:56:05 INFO  : one: Moved (server-side) to: one.bak
2024/12/29 04:56:07 DEBUG : one: md5 = b161feee99b3b98bca350c7f92b1f1e2 OK
2024/12/29 04:56:07 INFO  : one: Copied (new)
2024/12/29 04:56:07 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:56:07 DEBUG : two: Unchanged skipping
2024/12/29 04:56:08 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/12/29 04:56:08 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/29 04:56:10 DEBUG : three.txt: md5 = 9aa0c9085d2a38a5550c291c7248ff3a OK
2024/12/29 04:56:10 INFO  : three.txt: Copied (new)
2024/12/29 04:56:11 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/29 04:56:12 INFO  : one.bak: Deleted
2024/12/29 04:56:12 INFO  : one: Moved (server-side) to: one.bak
2024/12/29 04:56:14 DEBUG : one: md5 = b8de70c4115adab332da7815e4ddef42 OK
2024/12/29 04:56:14 INFO  : one: Copied (new)
2024/12/29 04:56:14 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:56:14 DEBUG : two: Unchanged skipping
2024/12/29 04:56:14 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/12/29 04:56:15 INFO  : three.txt.bak: Deleted
2024/12/29 04:56:16 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/12/29 04:56:18 DEBUG : three.txt: md5 = 8c9ac9acda62b767ea39ded21786171a OK
2024/12/29 04:56:18 INFO  : three.txt: Copied (new)
2024/12/29 04:56:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/12/29 04:56:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/29 04:56:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/12/29 04:56:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/12/29 04:56:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/12/29 04:56:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/12/29 04:56:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncSuffix (25.40s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:56:25 DEBUG : dst/one: md5 = 1898baf16240524a5b5d3834c868f968 OK
2024/12/29 04:56:27 DEBUG : dst/two: md5 = 4830f86d612418e7ebff0add0069769c OK
2024/12/29 04:56:29 DEBUG : dst/three.txt: md5 = 3263ab8518d559ce09a908434241802e OK
2024/12/29 04:56:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qulatul2vucu/dst"
2024/12/29 04:56:29 DEBUG : Creating backend with remote "TestDrive:crypt/26acno4lsht7p0b6dinffcgh5i9ku0r32ihgn1gln9hifh0j0l30/31u3jie661vd5p8j7rtc3hgbh0"
2024/12/29 04:56:30 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/12/29 04:56:31 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/12/29 04:56:32 DEBUG : one: md5 = cb5077e92d5bd17bd056bd21a3e4f70d OK
2024/12/29 04:56:32 INFO  : one: Copied (new)
2024/12/29 04:56:32 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:56:32 DEBUG : two: Unchanged skipping
2024/12/29 04:56:33 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/12/29 04:56:33 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/12/29 04:56:35 DEBUG : three.txt: md5 = 0f99e59f0174a3ac54d019e3467ac8d3 OK
2024/12/29 04:56:35 INFO  : three.txt: Copied (new)
2024/12/29 04:56:37 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/12/29 04:56:37 INFO  : one-2019-01-01: Deleted
2024/12/29 04:56:38 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/12/29 04:56:40 DEBUG : one: md5 = 9085a8b5047845aaac9dc56b050fdb0c OK
2024/12/29 04:56:40 INFO  : one: Copied (new)
2024/12/29 04:56:40 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:56:40 DEBUG : two: Unchanged skipping
2024/12/29 04:56:40 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/12/29 04:56:41 INFO  : three-2019-01-01.txt: Deleted
2024/12/29 04:56:41 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/12/29 04:56:43 DEBUG : three.txt: md5 = 60d96133292df8e766d61effbedd0b96 OK
2024/12/29 04:56:43 INFO  : three.txt: Copied (new)
2024/12/29 04:56:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/12/29 04:56:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/12/29 04:56:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/12/29 04:56:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/12/29 04:56:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/12/29 04:56:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/12/29 04:56:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncSuffixKeepExtension (25.17s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:56:50 DEBUG : Testêé: md5 = dd8b0722c40e3e2a56ece57c438ef098 OK
2024/12/29 04:56:50 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2024/12/29 04:56:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:56:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:56:52 DEBUG : Testêé: md5 = ba41726944554b0ff5bba53d89f390b1 OK
2024/12/29 04:56:52 INFO  : Testêé: Copied (replaced existing) to: Testêé
2024/12/29 04:56:52 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (4.96s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:56:53 DEBUG : existing: Need to transfer - File not found at Destination
2024/12/29 04:56:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:56:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:56:55 DEBUG : existing: md5 = c945f680a5135abb3f4fae85ef9780e0 OK
2024/12/29 04:56:55 INFO  : existing: Copied (new)
2024/12/29 04:56:55 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:56:56 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2024/12/29 04:56:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:56:56 ERROR : existing: Source and destination exist but do not match: immutable file modified
2024/12/29 04:56:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:56:56 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': not deleting files as there were IO errors
2024/12/29 04:56:56 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncImmutable (5.02s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:57:00 DEBUG : EXISTING: md5 = f61f487a0a9d5f16a68cd5c5fcb57e03 OK
2024/12/29 04:57:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:57:00 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:57:00 DEBUG : existing: Unchanged skipping
2024/12/29 04:57:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:57:00 DEBUG : Waiting for deletions to finish
2024/12/29 04:57:00 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (3.73s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    sync_test.go:2635: Skipping test as local or remote are case-sensitive
--- SKIP: TestFixCase (0.44s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", 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-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", 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-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.30s)
    --- SKIP: TestMaxTransfer/Hard (0.42s)
    --- SKIP: TestMaxTransfer/Soft (0.44s)
    --- SKIP: TestMaxTransfer/Cautious (0.44s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:57:05 DEBUG : both0: md5 = 2eed23640cd892afeb903e6eec13a085 OK
2024/12/29 04:57:07 DEBUG : only0: md5 = fdec95e829b0285f0254b1439b40f938 OK
2024/12/29 04:57:08 DEBUG : both1: md5 = d8faceab8452722537a758095035495a OK
2024/12/29 04:57:10 DEBUG : only1: md5 = 232886f0345af96bd6ca24c671784336 OK
2024/12/29 04:57:12 DEBUG : both2: md5 = 0461e619f6d7e992ba2b3b1b422dafcb OK
2024/12/29 04:57:13 DEBUG : only2: md5 = c2a0ccf0c86f4100ac162e3dd70ae3f2 OK
2024/12/29 04:57:15 DEBUG : both3: md5 = d6ef0dd6abe81e3ea0f0a0850b445a56 OK
2024/12/29 04:57:17 DEBUG : only3: md5 = 739178b0e1e2b6e4e66bf49244f2219b OK
2024/12/29 04:57:18 DEBUG : both4: md5 = 1f19487a14d6ca56f1a5dd467299a7f2 OK
2024/12/29 04:57:20 DEBUG : only4: md5 = 1ada1c9c437eb864de3163e25f42ec4b OK
2024/12/29 04:57:21 DEBUG : both5: md5 = 5c7014540d7de47765a372911d6c4b43 OK
2024/12/29 04:57:23 DEBUG : only5: md5 = 0a6d37c70f19ea024a03775978ef9b93 OK
2024/12/29 04:57:24 DEBUG : both6: md5 = e2c36f87f82d6e7c86c3c8c5d2222e1e OK
2024/12/29 04:57:26 DEBUG : only6: md5 = c617ec3d6504e552ede27953fab68ef5 OK
2024/12/29 04:57:28 DEBUG : both7: md5 = 5d0d71e3f1308b17a80202cfe7ce700b OK
2024/12/29 04:57:29 DEBUG : only7: md5 = 04de5dd6b9669dba5409a83edc861f89 OK
2024/12/29 04:57:31 DEBUG : both8: md5 = b73963da180951c31a1a85aa39ce6197 OK
2024/12/29 04:57:32 DEBUG : only8: md5 = c140621be1d59b1f9bc288ec68329a0f OK
2024/12/29 04:57:34 DEBUG : both9: md5 = d32cc0d4e2b44a4ea49a1952e6a90be8 OK
2024/12/29 04:57:35 DEBUG : only9: md5 = 8815533efa56eb0323f6d7550ff008a7 OK
2024/12/29 04:57:37 DEBUG : both10: md5 = 2d6ccafd8315cdd6d7e9ea1af099fb59 OK
2024/12/29 04:57:38 DEBUG : only10: md5 = d59b774194d7560bbce44fe02f8d1cd2 OK
2024/12/29 04:57:40 DEBUG : both11: md5 = e3554a0e0854c762e3e3c39404fdd9f1 OK
2024/12/29 04:57:42 DEBUG : only11: md5 = 74d6f48f51a5e493bb78e0f16fc7e7ba OK
2024/12/29 04:57:43 DEBUG : both12: md5 = dd63cda3c17b8255ece453cb68601c25 OK
2024/12/29 04:57:45 DEBUG : only12: md5 = a55722a3b05c737f343c2ed7fd86c265 OK
2024/12/29 04:57:47 DEBUG : both13: md5 = a4e96ba9ad6c7dd656361f13c231d054 OK
2024/12/29 04:57:48 DEBUG : only13: md5 = 05e17e6349ff0daf48345beabe9ed3f8 OK
2024/12/29 04:57:50 DEBUG : both14: md5 = 2cc12b1b86c3e1fe559ff7ddbab7a69b OK
2024/12/29 04:57:52 DEBUG : only14: md5 = 3c61c9388a5cba9128bb414eb025bdff OK
2024/12/29 04:57:53 DEBUG : both15: md5 = 47dde1c77d6e733075eb3beaf9bef991 OK
2024/12/29 04:57:55 DEBUG : only15: md5 = fc6422c61f8e50a590c62b826d9b92ee OK
2024/12/29 04:57:57 DEBUG : both16: md5 = 0be55b6a4df0d999518c2f0f974ce851 OK
2024/12/29 04:57:59 DEBUG : only16: md5 = 18f4b14648a0628c57650da2b114bf1d OK
2024/12/29 04:58:00 DEBUG : both17: md5 = 969d42631990e803e91a355246dcc235 OK
2024/12/29 04:58:02 DEBUG : only17: md5 = 24c600ddf95419f18300629f07a8abb7 OK
2024/12/29 04:58:03 DEBUG : both18: md5 = 931d9809cdb346b2822a8f62db1b0a1f OK
2024/12/29 04:58:05 DEBUG : only18: md5 = 30a0fbb4e875de0e585efcc23b719ece OK
2024/12/29 04:58:06 DEBUG : both19: md5 = 4f22b7d907c676cdda5fbd9314963d3d OK
2024/12/29 04:58:08 DEBUG : only19: md5 = b5aa7c60b9f988c9f895dced44704e13 OK
2024/12/29 04:58:09 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:58:09 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:58:09 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:58:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:58:09 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:58:09 DEBUG : both0: Unchanged skipping
2024/12/29 04:58:09 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:58:09 DEBUG : both12: Unchanged skipping
2024/12/29 04:58:09 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:58:09 DEBUG : both1: Unchanged skipping
2024/12/29 04:58:09 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:58:09 DEBUG : both14: Unchanged skipping
2024/12/29 04:58:09 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:58:09 DEBUG : both11: Unchanged skipping
2024/12/29 04:58:09 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:58:09 DEBUG : both16: Unchanged skipping
2024/12/29 04:58:09 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:58:09 DEBUG : both17: Unchanged skipping
2024/12/29 04:58:09 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:58:09 DEBUG : both18: Unchanged skipping
2024/12/29 04:58:09 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:58:09 DEBUG : both19: Unchanged skipping
2024/12/29 04:58:09 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:58:09 DEBUG : both2: Unchanged skipping
2024/12/29 04:58:09 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:58:09 DEBUG : both3: Unchanged skipping
2024/12/29 04:58:09 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:58:09 DEBUG : both4: Unchanged skipping
2024/12/29 04:58:09 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:58:09 DEBUG : both5: Unchanged skipping
2024/12/29 04:58:09 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:58:09 DEBUG : both6: Unchanged skipping
2024/12/29 04:58:09 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:58:09 DEBUG : both7: Unchanged skipping
2024/12/29 04:58:09 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:58:09 DEBUG : both8: Unchanged skipping
2024/12/29 04:58:09 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:58:09 DEBUG : both9: Unchanged skipping
2024/12/29 04:58:09 DEBUG : both10: Unchanged skipping
2024/12/29 04:58:09 DEBUG : both13: Unchanged skipping
2024/12/29 04:58:09 DEBUG : both15: Unchanged skipping
2024/12/29 04:58:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:58:09 DEBUG : Waiting for deletions to finish
2024/12/29 04:58:09 INFO  : only15: Deleted
2024/12/29 04:58:09 INFO  : only16: Deleted
2024/12/29 04:58:09 INFO  : only19: Deleted
2024/12/29 04:58:09 INFO  : only3: Deleted
2024/12/29 04:58:10 INFO  : only12: Deleted
2024/12/29 04:58:10 INFO  : only7: Deleted
2024/12/29 04:58:10 INFO  : only0: Deleted
2024/12/29 04:58:10 INFO  : only6: Deleted
2024/12/29 04:58:10 INFO  : only1: Deleted
2024/12/29 04:58:10 INFO  : only14: Deleted
2024/12/29 04:58:10 INFO  : only18: Deleted
2024/12/29 04:58:10 INFO  : only2: Deleted
2024/12/29 04:58:11 INFO  : only5: Deleted
2024/12/29 04:58:11 INFO  : only17: Deleted
2024/12/29 04:58:11 INFO  : only9: Deleted
2024/12/29 04:58:11 INFO  : only10: Deleted
2024/12/29 04:58:11 INFO  : only11: Deleted
2024/12/29 04:58:11 INFO  : only13: Deleted
2024/12/29 04:58:12 INFO  : only8: Deleted
2024/12/29 04:58:12 INFO  : only4: Deleted
2024/12/29 04:58:12 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (80.01s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:58:25 DEBUG : both0: md5 = 6d7fccb1bae8243814084a06afc4ca6f OK
2024/12/29 04:58:26 DEBUG : only0: md5 = 90456832518df99cab0c607c93b8865e OK
2024/12/29 04:58:28 DEBUG : both1: md5 = 4e9d918552a0f2162cb974136a9a3e99 OK
2024/12/29 04:58:29 DEBUG : only1: md5 = 3b4e56751c741e49a67edc1e11dd8217 OK
2024/12/29 04:58:31 DEBUG : both2: md5 = 4c2363c16c447fdc607b0910691c2845 OK
2024/12/29 04:58:33 DEBUG : only2: md5 = dc22184648a864fd0c5ca666d4d0cda1 OK
2024/12/29 04:58:35 DEBUG : both3: md5 = fb827cbd0fe99946916d09a19d824e4e OK
2024/12/29 04:58:37 DEBUG : only3: md5 = d1247a44ba6f54cf4858c7c669037437 OK
2024/12/29 04:58:38 DEBUG : both4: md5 = 7ad2db94693162e40ea4e99997da9e23 OK
2024/12/29 04:58:40 DEBUG : only4: md5 = efea58238e3066cbbe15f791cda03786 OK
2024/12/29 04:58:41 DEBUG : both5: md5 = 11206e7622cfab24ae30c20ee7bace8c OK
2024/12/29 04:58:43 DEBUG : only5: md5 = 478a39f5e54cdc86de06c8a750b2f2b6 OK
2024/12/29 04:58:45 DEBUG : both6: md5 = 10133d8b78538b7153cc2e7a925ed0b8 OK
2024/12/29 04:58:46 DEBUG : only6: md5 = d8f039952ccda5c62338a53c766b7759 OK
2024/12/29 04:58:48 DEBUG : both7: md5 = c8a94cc278170d2ce252a8358257b811 OK
2024/12/29 04:58:50 DEBUG : only7: md5 = 9922b1a1357e14decf519b2e72cc6d29 OK
2024/12/29 04:58:51 DEBUG : both8: md5 = b421bc28ecd371e01958ba0280715e12 OK
2024/12/29 04:58:53 DEBUG : only8: md5 = aa854c4bfd3d3e12cca86c64d67c5037 OK
2024/12/29 04:58:55 DEBUG : both9: md5 = ca3d9786a5fec1207ba81c36f77a0b4f OK
2024/12/29 04:58:56 DEBUG : only9: md5 = 9258cca567f4c8923ed4a37d65b3a69d OK
2024/12/29 04:58:58 DEBUG : both10: md5 = af0fa2283e0279df6ea28fc8d2f051ee OK
2024/12/29 04:58:59 DEBUG : only10: md5 = 7d03f146433a92cd527b0795813bafbc OK
2024/12/29 04:59:01 DEBUG : both11: md5 = 6ffe3463e9f9f6a66aa51553edbbe499 OK
2024/12/29 04:59:03 DEBUG : only11: md5 = b76b33c1dbad4684b6e8885cf1ff959a OK
2024/12/29 04:59:04 DEBUG : both12: md5 = 8a512c859df558d960ac130fba590ad4 OK
2024/12/29 04:59:06 DEBUG : only12: md5 = d51485060456e60a111651fa9805b044 OK
2024/12/29 04:59:07 DEBUG : both13: md5 = 2d323d9602ce724aa7030e3b08a93da3 OK
2024/12/29 04:59:09 DEBUG : only13: md5 = d16fe17599a2a8606d1824800117a2d0 OK
2024/12/29 04:59:10 DEBUG : both14: md5 = a26cbcf7a63d01645d69d4a5e1b46cf7 OK
2024/12/29 04:59:12 DEBUG : only14: md5 = 74fe49e9dc6749f5a3ee20e9593fda21 OK
2024/12/29 04:59:14 DEBUG : both15: md5 = 4b40cb51371a5e8f6e19a6c5d3f3696f OK
2024/12/29 04:59:16 DEBUG : only15: md5 = 374c7897054f495c3a7bec46ccdf0ee4 OK
2024/12/29 04:59:17 DEBUG : both16: md5 = 8f7f615123c34b82dcc0990863ce02ea OK
2024/12/29 04:59:19 DEBUG : only16: md5 = da86982ec87a589c1cdf612f9dd06032 OK
2024/12/29 04:59:21 DEBUG : both17: md5 = ea6d648037ad9ed9dfac5884d558204d OK
2024/12/29 04:59:22 DEBUG : only17: md5 = b5a7c923ecc71f859e56fcf388eb2879 OK
2024/12/29 04:59:24 DEBUG : both18: md5 = d8de3f750e8b793ca6dcd7d3ef9696aa OK
2024/12/29 04:59:25 DEBUG : only18: md5 = c417dd116864122481bfa458ad727de4 OK
2024/12/29 04:59:27 DEBUG : both19: md5 = bdc601952b548f4fe48ca4c2ff11525b OK
2024/12/29 04:59:29 DEBUG : only19: md5 = b0f32e0ceb9e41000aab48ac4eff1661 OK
2024/12/29 04:59:29 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:59:29 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:59:29 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:59:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for checks to finish
2024/12/29 04:59:29 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:59:29 DEBUG : both11: Unchanged skipping
2024/12/29 04:59:29 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:59:29 DEBUG : both10: Unchanged skipping
2024/12/29 04:59:29 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:59:29 DEBUG : both1: Unchanged skipping
2024/12/29 04:59:29 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:59:29 DEBUG : both14: Unchanged skipping
2024/12/29 04:59:29 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:59:29 DEBUG : both0: Unchanged skipping
2024/12/29 04:59:29 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:59:29 DEBUG : both13: Unchanged skipping
2024/12/29 04:59:29 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:59:29 DEBUG : both12: Unchanged skipping
2024/12/29 04:59:29 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:59:29 DEBUG : both15: Unchanged skipping
2024/12/29 04:59:29 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:59:29 DEBUG : both18: Unchanged skipping
2024/12/29 04:59:29 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:59:29 DEBUG : both2: Unchanged skipping
2024/12/29 04:59:29 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:59:29 DEBUG : both3: Unchanged skipping
2024/12/29 04:59:29 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:59:29 DEBUG : both19: Unchanged skipping
2024/12/29 04:59:29 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:59:29 DEBUG : both17: Unchanged skipping
2024/12/29 04:59:29 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:59:29 DEBUG : both16: Unchanged skipping
2024/12/29 04:59:29 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:59:29 DEBUG : both4: Unchanged skipping
2024/12/29 04:59:29 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:59:29 DEBUG : both8: Unchanged skipping
2024/12/29 04:59:29 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/12/29 04:59:29 DEBUG : both5: Unchanged skipping
2024/12/29 04:59:29 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2024/12/29 04:59:29 DEBUG : both6: Unchanged skipping
2024/12/29 04:59:29 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2024/12/29 04:59:29 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2024/12/29 04:59:29 DEBUG : both7: Unchanged skipping
2024/12/29 04:59:29 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2024/12/29 04:59:29 DEBUG : both9: Unchanged skipping
2024/12/29 04:59:29 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2024/12/29 04:59:29 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2024/12/29 04:59:29 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2024/12/29 04:59:29 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2024/12/29 04:59:29 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2024/12/29 04:59:29 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2024/12/29 04:59:29 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2024/12/29 04:59:29 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2024/12/29 04:59:29 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2024/12/29 04:59:29 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2024/12/29 04:59:29 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2024/12/29 04:59:29 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2024/12/29 04:59:29 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2024/12/29 04:59:29 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2024/12/29 04:59:29 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2024/12/29 04:59:29 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2024/12/29 04:59:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Waiting for transfers to finish
2024/12/29 04:59:30 DEBUG : only0: md5 = 9a67d8e70de702e05343e3b58d7459e8 OK
2024/12/29 04:59:30 INFO  : only0: Copied (replaced existing)
2024/12/29 04:59:30 DEBUG : only10: md5 = 60266393e195d39d27075586724f9a52 OK
2024/12/29 04:59:30 INFO  : only10: Copied (replaced existing)
2024/12/29 04:59:30 DEBUG : only1: md5 = 1e3a59ab9076b251ff18d8ce76ce0b20 OK
2024/12/29 04:59:30 INFO  : only1: Copied (replaced existing)
2024/12/29 04:59:31 DEBUG : only11: md5 = 72bf7da042d8c29505a1b10cbcdb7d68 OK
2024/12/29 04:59:31 INFO  : only11: Copied (replaced existing)
2024/12/29 04:59:31 DEBUG : only14: md5 = 8caed884a2b59a21e38166dfcdc50d67 OK
2024/12/29 04:59:31 INFO  : only14: Copied (replaced existing)
2024/12/29 04:59:32 DEBUG : only16: md5 = 211f81c9a4294d609064c2d7b425da7a OK
2024/12/29 04:59:32 INFO  : only16: Copied (replaced existing)
2024/12/29 04:59:32 DEBUG : only17: md5 = 8398cca9c183aa2e11b57a9e067b3565 OK
2024/12/29 04:59:32 INFO  : only17: Copied (replaced existing)
2024/12/29 04:59:32 DEBUG : only18: md5 = 1ebdfb1cb3be519e8cf7f933d00dfb57 OK
2024/12/29 04:59:32 INFO  : only18: Copied (replaced existing)
2024/12/29 04:59:33 DEBUG : only19: md5 = 6314e1a5db221c0c57763e1da9cad8bb OK
2024/12/29 04:59:33 INFO  : only19: Copied (replaced existing)
2024/12/29 04:59:33 DEBUG : only2: md5 = 5f6d1c2d9b5850d28328ddbd51b61ba2 OK
2024/12/29 04:59:33 INFO  : only2: Copied (replaced existing)
2024/12/29 04:59:33 DEBUG : only3: md5 = bc74cb3fa17a03a4800fa9ee24e48eb6 OK
2024/12/29 04:59:33 INFO  : only3: Copied (replaced existing)
2024/12/29 04:59:33 DEBUG : only4: md5 = a884ca7b276416c7ff9dc306639f4eb4 OK
2024/12/29 04:59:33 INFO  : only4: Copied (replaced existing)
2024/12/29 04:59:34 DEBUG : only5: md5 = 78fec0dec7faeb4d6b82c14d58cacd2b OK
2024/12/29 04:59:34 INFO  : only5: Copied (replaced existing)
2024/12/29 04:59:34 DEBUG : only7: md5 = d035acfd10ab48ffd6c6b0c3b68bae08 OK
2024/12/29 04:59:34 INFO  : only7: Copied (replaced existing)
2024/12/29 04:59:34 DEBUG : only6: md5 = 9dbd025c80efabfe7ef0eba4ba7460e3 OK
2024/12/29 04:59:34 INFO  : only6: Copied (replaced existing)
2024/12/29 04:59:34 DEBUG : only8: md5 = ceb19cd701865298cdf7f7ee4bbd7cce OK
2024/12/29 04:59:34 INFO  : only8: Copied (replaced existing)
2024/12/29 04:59:35 DEBUG : only9: md5 = f8c1a8e44ac3c323943b033862f1bf7a OK
2024/12/29 04:59:35 INFO  : only9: Copied (replaced existing)
2024/12/29 04:59:35 DEBUG : only12: md5 = 6c0027f41c1c89bb26268527871dd03b OK
2024/12/29 04:59:35 INFO  : only12: Copied (replaced existing)
2024/12/29 04:59:35 DEBUG : only13: md5 = 10344fe4d330d0772ddc6e6ecd43c8d4 OK
2024/12/29 04:59:35 INFO  : only13: Copied (replaced existing)
2024/12/29 04:59:36 DEBUG : only15: md5 = 9900b9cb53969807048681f2ccfd5322 OK
2024/12/29 04:59:36 INFO  : only15: Copied (replaced existing)
2024/12/29 04:59:36 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (95.50s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 04:59:59 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/29 04:59:59 DEBUG : sub dir: Making directory with metadata
2024/12/29 05:00:00 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 05:00:19 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/12/29 05:00:20 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/12/29 05:00:20 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/29 05:00:20 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 05:00:33 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2024/12/29 05:00:34 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/12/29 05:00:34 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/12/29 05:00:35 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/12/29 05:00:36 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/29 05:00:37 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/29 05:00:38 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/29 05:00:38 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/29 05:00:39 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/12/29 05:00:40 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/12/29 05:00:40 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/29 05:00:41 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (44.14s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 05:00:43 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/12/29 05:00:43 DEBUG : sub dir: Making directory with metadata
2024/12/29 05:00:44 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 05:01:08 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/12/29 05:01:08 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/12/29 05:01:08 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/12/29 05:01:08 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu'", Local "Local file system at /tmp/rclone1793336062", Modify Window "1ms"
2024/12/29 05:01:20 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/12/29 05:01:21 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/12/29 05:01:22 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/12/29 05:01:23 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/29 05:01:24 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/29 05:01:24 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/29 05:01:25 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/29 05:01:26 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/12/29 05:01:27 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/12/29 05:01:27 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/12/29 05:01:28 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (46.96s)
PASS
2024/12/29 05:01:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qulatul2vucu': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 17m0.446480236s (try 1/5)