"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5)
2025/01/24 01:57:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo"
2025/01/24 01:57:01 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/01/24 01:57:02 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg"
2025/01/24 01:57:03 DEBUG : Creating backend with remote "/tmp/rclone3053794225"
=== 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-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:57:04 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/24 01:57:04 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/24 01:57:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 01:57:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 01:57:04 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2025/01/24 01:57:04 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (2.46s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:57:05 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/24 01:57:05 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/24 01:57:05 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/24 01:57:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 01:57:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 01:57:08 DEBUG : sub dir/hello world: md5 = b8ec9d052b134c0cd96dc6595b5e4028 OK
2025/01/24 01:57:08 INFO  : sub dir/hello world: Copied (new)
2025/01/24 01:57:09 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:57:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (7.15s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:57:12 DEBUG : metadata sub dir: Making directory with metadata
2025/01/24 01:57:12 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/24 01:57:12 DEBUG : empty metadata sub dir: Making directory with metadata
2025/01/24 01:57:12 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/24 01:57:12 DEBUG : Local file system at /tmp/rclone3053794225: File to upload is small (21 bytes), uploading instead of streaming
2025/01/24 01:57:12 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2025/01/24 01:57:12 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2025/01/24 01:57:12 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2025/01/24 01:57:13 DEBUG : Google drive root 'crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg': Skipping btime metadata as can't update it on an existing file: 2025-01-24T01:57:12.629774734Z
2025/01/24 01:57:13 INFO  : empty metadata sub dir: Updated directory metadata
2025/01/24 01:57:14 DEBUG : Google drive root 'crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg': Skipping btime metadata as can't update it on an existing file: 2025-01-24T01:57:12.629774734Z
2025/01/24 01:57:15 INFO  : metadata sub dir: Updated directory metadata
2025/01/24 01:57:15 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2025/01/24 01:57:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 01:57:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 01:57:16 DEBUG : metadata sub dir/hello metadata world: md5 = 705bd571bf66e31c45c666088b26df0d OK
2025/01/24 01:57:16 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:57:20 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (9.79s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:57:22 DEBUG : metadata sub dir: Making directory with metadata
2025/01/24 01:57:22 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/24 01:57:22 DEBUG : empty metadata sub dir: Making directory with metadata
2025/01/24 01:57:22 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/24 01:57:22 DEBUG : Local file system at /tmp/rclone3053794225: File to upload is small (21 bytes), uploading instead of streaming
2025/01/24 01:57:22 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2025/01/24 01:57:22 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2025/01/24 01:57:22 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2025/01/24 01:57:22 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2025/01/24 01:57:22 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2025/01/24 01:57:22 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2025/01/24 01:57:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 01:57:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 01:57:25 DEBUG : metadata sub dir/hello metadata world: md5 = 2e6b92a9ca36f7132cb9d5ac9a094496 OK
2025/01/24 01:57:25 INFO  : metadata sub dir/hello metadata world: Copied (new)
2025/01/24 01:57:25 DEBUG : Google drive root 'crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg': Skipping btime metadata as can't update it on an existing file: 2025-01-24T01:57:22.421698726Z
2025/01/24 01:57:26 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:57:29 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (8.11s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:57:30 DEBUG : Creating backend with remote "/non-existing"
2025/01/24 01:57:30 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2025/01/24 01:57:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 01:57:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.14s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:57:31 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/24 01:57:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/24 01:57:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 01:57:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 01:57:34 DEBUG : sub dir/hello world: md5 = 8ba339ceac75a52f37007613f3242454 OK
2025/01/24 01:57:34 INFO  : sub dir/hello world: Copied (new)
2025/01/24 01:57:35 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:57:37 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (7.08s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:57:38 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Running all checks before starting transfers
2025/01/24 01:57:39 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/24 01:57:39 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/24 01:57:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 01:57:39 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Checks finished, now starting transfers
2025/01/24 01:57:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 01:57:41 DEBUG : sub dir/hello world: md5 = 5d20bd58266afc4b1d21ab82aadb7409 OK
2025/01/24 01:57:41 INFO  : sub dir/hello world: Copied (new)
2025/01/24 01:57:42 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:57:44 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (7.22s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:57:45 ERROR : Ignoring --no-traverse with sync
2025/01/24 01:57:46 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/24 01:57:46 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/24 01:57:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 01:57:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 01:57:48 DEBUG : sub dir/hello world: md5 = c25fb19a0d80ba025b594cbc1125c2ab OK
2025/01/24 01:57:48 INFO  : sub dir/hello world: Copied (new)
2025/01/24 01:57:48 DEBUG : Waiting for deletions to finish
2025/01/24 01:57:49 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:57:51 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (6.76s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:57:52 DEBUG : hello world2: Need to transfer - File not found at Destination
2025/01/24 01:57:52 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/24 01:57:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 01:57:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 01:57:54 DEBUG : hello world2: md5 = 43ba9f5196c1a6685ffb912f27fa8212 OK
2025/01/24 01:57:54 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestCopyWithDepth (3.61s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:57:56 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/24 01:57:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 01:57:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 01:57:58 DEBUG : potato2: md5 = 19f175825c4d8e99c9dcc812bd5a66d5 OK
2025/01/24 01:57:58 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (3.99s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:58:00 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/24 01:58:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 01:58:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 01:58:02 DEBUG : potato2: md5 = 5913d2d3f603e5394b405f570bfc772b OK
2025/01/24 01:58:02 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (3.70s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:58:04 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/01/24 01:58:04 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/24 01:58:04 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/24 01:58:04 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/24 01:58:04 DEBUG : sub dir: Making directory with metadata
2025/01/24 01:58:05 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/01/24 01:58:05 DEBUG : sub dir2: Making directory with metadata
2025/01/24 01:58:06 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/24 01:58:06 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/24 01:58:06 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/01/24 01:58:07 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/24 01:58:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 01:58:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 01:58:08 DEBUG : sub dir/hello world: md5 = b8cbf28ce888cfe6ec48eb59a4ab3835 OK
2025/01/24 01:58:08 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:58:12 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2025/01/24 01:58:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (10.43s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:58:14 INFO  : sub dir2: Making directory
2025/01/24 01:58:14 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/01/24 01:58:14 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/24 01:58:14 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/24 01:58:14 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/01/24 01:58:14 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2025/01/24 01:58:14 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/24 01:58:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 01:58:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 01:58:17 DEBUG : sub dir/hello world: md5 = f3104f6b950b3a393f36b85fbedd9722 OK
2025/01/24 01:58:17 INFO  : sub dir/hello world: Copied (new)
2025/01/24 01:58:18 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/24 01:58:19 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (6.42s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:58:20 DEBUG : sub dir2: Making directory with metadata
2025/01/24 01:58:20 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/24 01:58:21 DEBUG : sub dir: Making directory with metadata
2025/01/24 01:58:22 INFO  : sub dir: Made directory with metadata (mtime=2025-01-24T01:58:20.877247445Z)
2025/01/24 01:58:22 DEBUG : sub dir2: Making directory with metadata
2025/01/24 01:58:23 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/24 01:58:23 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/24 01:58:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 01:58:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 01:58:24 DEBUG : sub dir/hello world: md5 = fffcd8afca36d73784eea2e2eaac00d1 OK
2025/01/24 01:58:24 INFO  : sub dir/hello world: Copied (new)
2025/01/24 01:58:24 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:58:27 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (8.31s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:58:29 DEBUG : sub dir no update dir modtime: Making directory with metadata
2025/01/24 01:58:29 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/01/24 01:58:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 01:58:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 01:58:30 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (4.46s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:58:33 INFO  : sub dir2: Making directory
2025/01/24 01:58:33 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/24 01:58:33 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/01/24 01:58:33 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/24 01:58:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 01:58:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 01:58:36 DEBUG : sub dir/hello world: md5 = ab88457fe64e04db16100fe703109ef2 OK
2025/01/24 01:58:36 INFO  : sub dir/hello world: Copied (new)
2025/01/24 01:58:36 INFO  : sub dir/hello world: Deleted
2025/01/24 01:58:37 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/24 01:58:39 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (6.57s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:58:40 DEBUG : sub dir2: Making directory with metadata
2025/01/24 01:58:40 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/24 01:58:40 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/24 01:58:40 DEBUG : sub dir: Making directory with metadata
2025/01/24 01:58:41 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/01/24 01:58:41 DEBUG : sub dir2: Making directory with metadata
2025/01/24 01:58:42 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/24 01:58:42 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/24 01:58:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 01:58:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 01:58:44 DEBUG : sub dir/hello world: md5 = 24629716d6983d69be0d749a7b91c20d OK
2025/01/24 01:58:44 INFO  : sub dir/hello world: Copied (new)
2025/01/24 01:58:44 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:58:47 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (8.54s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.44s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:58:49 INFO  : sub dir2: Making directory
2025/01/24 01:58:49 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/24 01:58:49 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/01/24 01:58:49 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/24 01:58:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 01:58:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 01:58:51 DEBUG : sub dir/hello world: md5 = 2b99a6368eb4ec023e544fe1686add16 OK
2025/01/24 01:58:51 INFO  : sub dir/hello world: Copied (new)
2025/01/24 01:58:51 DEBUG : Waiting for deletions to finish
2025/01/24 01:58:52 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/24 01:58:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (6.25s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:58:58 DEBUG : sub dir/hello world: md5 = fe8262eda951c836ee8a1c1de8f318ed OK
2025/01/24 01:58:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-masorev0nuga"
2025/01/24 01:58:58 DEBUG : Creating backend with remote "TestDrive:crypt/e4fttpmne8o5v30n3did5vkgb5ec8jmqbnsa9mvi5dsvd940pqb0"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo' -> Encrypted drive 'TestCryptDrive:rclone-test-masorev0nuga'
2025/01/24 01:59:00 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/24 01:59:00 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/24 01:59:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-masorev0nuga': Waiting for checks to finish
2025/01/24 01:59:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-masorev0nuga': Waiting for transfers to finish
2025/01/24 01:59:03 INFO  : sub dir/hello world: Copied (server-side copy)
2025/01/24 01:59:05 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:59:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-masorev0nuga': Purge remote
2025/01/24 01:59:07 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (13.84s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:59:12 DEBUG : sub dir/hello world: md5 = a57f4aaf1569221bbbf7ba01e7fb48b5 OK
2025/01/24 01:59:12 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/24 01:59:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 01:59:13 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/01/24 01:59:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 01:59:14 DEBUG : sub dir/hello world: md5 = 507d4df9f0669f010fb1b114c0c7ed35 OK
2025/01/24 01:59:14 INFO  : sub dir/hello world: Copied (replaced existing)
2025/01/24 01:59:14 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:59:16 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (8.64s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:59:20 DEBUG : sub dir/hello world: md5 = eeb88d773159b741e2f4820bb4bb00e8 OK
2025/01/24 01:59:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wopoluf2mija"
2025/01/24 01:59:21 DEBUG : Creating backend with remote "TestDrive:crypt/5vad5unfmatn5c4pdljtjtof78eujjq5415d4m1jg70duc49l840"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo' -> Encrypted drive 'TestCryptDrive:rclone-test-wopoluf2mija'
2025/01/24 01:59:22 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/24 01:59:22 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/24 01:59:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wopoluf2mija': Waiting for checks to finish
2025/01/24 01:59:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wopoluf2mija': Waiting for transfers to finish
2025/01/24 01:59:26 INFO  : sub dir/hello world: Copied (server-side copy)
2025/01/24 01:59:26 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:59:28 DEBUG : sub dir/hello world: md5 = ba2513d8c524d9036d186412ba3b8358 OK
2025/01/24 01:59:29 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/01/24 01:59:29 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/24 01:59:29 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/01/24 01:59:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wopoluf2mija': Waiting for checks to finish
2025/01/24 01:59:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wopoluf2mija': Waiting for transfers to finish
2025/01/24 01:59:31 INFO  : sub dir/hello world: Copied (server-side copy)
2025/01/24 01:59:32 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:59:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wopoluf2mija': Purge remote
2025/01/24 01:59:34 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (18.78s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:59:39 DEBUG : sub dir/hello world: md5 = 145231120601c374acb525e34b1cb22a OK
2025/01/24 01:59:40 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/24 01:59:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 01:59:40 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/01/24 01:59:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 01:59:41 DEBUG : sub dir/hello world: md5 = f68dd0edfe090e72ea116e0546d4c3e5 OK
2025/01/24 01:59:41 INFO  : sub dir/hello world: Copied (replaced existing)
2025/01/24 01:59:41 INFO  : sub dir/hello world: Deleted
2025/01/24 01:59:42 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:59:44 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (9.18s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:59:48 DEBUG : sub dir/hello world: md5 = 96b5fada9d16bd8b6959c78077f683b9 OK
2025/01/24 01:59:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wamewig6rudu"
2025/01/24 01:59:48 DEBUG : Creating backend with remote "TestDrive:crypt/1uj8u0sgboj16nb77ju6o4f8v7999ncn70pno62ee8939nnc83vg"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo' -> Encrypted drive 'TestCryptDrive:rclone-test-wamewig6rudu'
2025/01/24 01:59:50 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/24 01:59:50 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/24 01:59:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wamewig6rudu': Waiting for checks to finish
2025/01/24 01:59:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wamewig6rudu': Waiting for transfers to finish
2025/01/24 01:59:54 INFO  : sub dir/hello world: Copied (server-side copy)
2025/01/24 01:59:55 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 01:59:57 DEBUG : sub dir/hello world: md5 = 13b90f97467eec35a7d6bc1b775703ab OK
2025/01/24 01:59:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wamewig6rudu': Using server-side directory move
2025/01/24 01:59:58 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-wamewig6rudu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/01/24 01:59:58 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/01/24 01:59:58 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/24 01:59:58 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/01/24 01:59:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wamewig6rudu': Waiting for checks to finish
2025/01/24 01:59:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wamewig6rudu': Waiting for transfers to finish
2025/01/24 01:59:59 INFO  : sub dir/hello world: Deleted
2025/01/24 01:59:59 INFO  : sub dir/hello world: Moved (server-side)
2025/01/24 02:00:00 INFO  : sub dir: Set directory modification time (using SetModTime)
2025/01/24 02:00:03 DEBUG : sub dir/hello world: md5 = 5a89f39ec37c0ba2536135f7bc35c942 OK
2025/01/24 02:00:03 DEBUG : testing file moves
2025/01/24 02:00:03 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/01/24 02:00:03 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/24 02:00:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wamewig6rudu': Waiting for checks to finish
2025/01/24 02:00:04 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2025/01/24 02:00:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wamewig6rudu': Waiting for transfers to finish
2025/01/24 02:00:04 INFO  : sub dir/hello world: Deleted
2025/01/24 02:00:05 INFO  : sub dir/hello world: Moved (server-side)
2025/01/24 02:00:06 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:00:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wamewig6rudu': Purge remote
--- PASS: TestServerSideMoveOverSelf (24.58s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:00:13 DEBUG : sub dir/hello world: md5 = a4243fd171a1b27f3fef938d63aac996 OK
2025/01/24 02:00:13 ERROR : : error listing: directory not found
2025/01/24 02:00:13 INFO  : Local file system at /tmp/rclone3053794225: Making directory
2025/01/24 02:00:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:00:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:00:16 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (7.12s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:00:20 DEBUG : sub dir/hello world: md5 = 563a4b1e7357b116d9b5dfc6196cb868 OK
2025/01/24 02:00:21 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/24 02:00:21 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/24 02:00:21 DEBUG : Local file system at /tmp/rclone3053794225: Waiting for checks to finish
2025/01/24 02:00:21 DEBUG : Local file system at /tmp/rclone3053794225: Waiting for transfers to finish
2025/01/24 02:00:22 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2025/01/24 02:00:22 INFO  : sub dir/hello world: Copied (new)
2025/01/24 02:00:22 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:00:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (7.81s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:00:25 DEBUG : check sum: Need to transfer - File not found at Destination
2025/01/24 02:00:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:00:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:00:27 DEBUG : check sum: md5 = 62661e79891b02a53da14eb3ab6aedcb OK
2025/01/24 02:00:27 INFO  : check sum: Copied (new)
2025/01/24 02:00:27 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:00:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:00:28 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2025/01/24 02:00:28 DEBUG : check sum: Size of src and dst objects identical
2025/01/24 02:00:28 DEBUG : check sum: Unchanged skipping
2025/01/24 02:00:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:00:28 DEBUG : Waiting for deletions to finish
2025/01/24 02:00:28 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (5.56s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:00:31 DEBUG : sizeonly: Need to transfer - File not found at Destination
2025/01/24 02:00:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:00:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:00:33 DEBUG : sizeonly: md5 = b18ed7df9f78565e0223875725d1e939 OK
2025/01/24 02:00:33 INFO  : sizeonly: Copied (new)
2025/01/24 02:00:33 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:00:33 DEBUG : sizeonly: Sizes identical
2025/01/24 02:00:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:00:33 DEBUG : sizeonly: Unchanged skipping
2025/01/24 02:00:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:00:33 DEBUG : Waiting for deletions to finish
2025/01/24 02:00:33 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (4.98s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:00:36 DEBUG : ignore-size: Need to transfer - File not found at Destination
2025/01/24 02:00:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:00:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:00:38 DEBUG : ignore-size: md5 = 2490ec1caba01552dbadf2a87f32711d OK
2025/01/24 02:00:38 INFO  : ignore-size: Copied (new)
2025/01/24 02:00:38 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:00:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:00:38 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:00:38 DEBUG : ignore-size: Unchanged skipping
2025/01/24 02:00:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:00:38 DEBUG : Waiting for deletions to finish
2025/01/24 02:00:38 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (6.19s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:00:43 DEBUG : existing: md5 = 23d71de70499f4e8e30cae49021d66be OK
2025/01/24 02:00:44 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:00:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:00:44 DEBUG : existing: Unchanged skipping
2025/01/24 02:00:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:00:44 DEBUG : Waiting for deletions to finish
2025/01/24 02:00:44 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:00:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:00:44 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2025/01/24 02:00:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:00:45 DEBUG : existing: md5 = 3fc1215720b4654e69cd2d2e30705e35 OK
2025/01/24 02:00:45 INFO  : existing: Copied (replaced existing)
2025/01/24 02:00:45 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (6.97s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:00:49 DEBUG : existing: Need to transfer - File not found at Destination
2025/01/24 02:00:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:00:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:00:51 DEBUG : existing: md5 = 8e24d5af75e21e86980e71477da9b7d6 OK
2025/01/24 02:00:51 INFO  : existing: Copied (new)
2025/01/24 02:00:51 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:00:51 DEBUG : existing: Destination exists, skipping
2025/01/24 02:00:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:00:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:00:51 DEBUG : Waiting for deletions to finish
2025/01/24 02:00:51 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (4.58s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:00:56 DEBUG : b/potato: md5 = b5bc1ae5a1e9169cec3d5346a65bba49 OK
2025/01/24 02:00:59 DEBUG : c/non empty space: md5 = 080e378acf7c8be444f529d67cd64f30 OK
2025/01/24 02:00:59 INFO  : d: Making directory
2025/01/24 02:01:01 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/01/24 02:01:01 DEBUG : Added delayed dir = "c", newDst=c
2025/01/24 02:01:01 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/01/24 02:01:01 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:01:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:01:01 DEBUG : c/non empty space: Unchanged skipping
2025/01/24 02:01:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:01:04 DEBUG : a/potato2: md5 = bf52d86fcbafc1f0c49828c105371ead OK
2025/01/24 02:01:04 INFO  : a/potato2: Copied (new)
2025/01/24 02:01:04 DEBUG : Waiting for deletions to finish
2025/01/24 02:01:05 INFO  : b/potato: Deleted
2025/01/24 02:01:05 INFO  : a: Set directory modification time (using DirSetModTime)
2025/01/24 02:01:05 INFO  : d: Removing directory
2025/01/24 02:01:06 INFO  : b: Removing directory
2025/01/24 02:01:06 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/01/24 02:01:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:01:09 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/01/24 02:01:10 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (18.37s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:01:13 DEBUG : empty space: md5 = 242f6b03a2be5a212edc749b4db01d2c OK
2025/01/24 02:01:14 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2025/01/24 02:01:14 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2025/01/24 02:01:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:01:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:01:14 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:01:14 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2025/01/24 02:01:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:01:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:01:16 DEBUG : empty space: md5 = d4d4c36e9591578b53ef84636870ea1b OK
2025/01/24 02:01:16 INFO  : empty space: Copied (replaced existing)
2025/01/24 02:01:16 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (6.61s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.46s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:01:20 DEBUG : foo: md5 = 754b8511f27f6c89eb99539786fbd1d6 OK
2025/01/24 02:01:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:01:21 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2025/01/24 02:01:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:01:22 DEBUG : foo: md5 = 73e8ff4c8fb8955e327ae832bdcb89ee OK
2025/01/24 02:01:22 INFO  : foo: Copied (replaced existing)
2025/01/24 02:01:22 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (5.15s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:01:25 DEBUG : empty space: md5 = ec35b40cc460e21bf9ef44c6bfc70085 OK
2025/01/24 02:01:26 DEBUG : potato: Need to transfer - File not found at Destination
2025/01/24 02:01:26 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:01:26 DEBUG : empty space: Unchanged skipping
2025/01/24 02:01:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:01:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:01:28 DEBUG : potato: md5 = af251207c15936b580952f11391fc787 OK
2025/01/24 02:01:28 INFO  : potato: Copied (new)
2025/01/24 02:01:28 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (6.04s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:01:31 DEBUG : potato: md5 = 5d4813123dc3e486f0ae5f83a6c4a9df OK
2025/01/24 02:01:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:01:32 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2025/01/24 02:01:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:01:33 DEBUG : potato: md5 = 3223fa62c35c0fac67fe6126fb8070dc OK
2025/01/24 02:01:33 INFO  : potato: Copied (replaced existing)
2025/01/24 02:01:33 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (5.18s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:01:37 DEBUG : potato: md5 = b0d1f319939ee6247524a3caa040f615 OK
2025/01/24 02:01:37 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC
2025/01/24 02:01:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:01:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:01:39 DEBUG : potato: md5 = 582585c174856ae19700f50fbe516ced OK
2025/01/24 02:01:39 INFO  : potato: Copied (replaced existing)
2025/01/24 02:01:39 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (5.48s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:01:42 DEBUG : potato: md5 = be090a72fccef24d6731595acd626c4f OK
2025/01/24 02:01:44 DEBUG : empty space: md5 = 181a26f90cc56ce17afda32b28d0c3e6 OK
2025/01/24 02:01:44 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/24 02:01:44 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:01:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:01:44 DEBUG : empty space: Unchanged skipping
2025/01/24 02:01:44 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2025/01/24 02:01:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:01:44 DEBUG : Waiting for deletions to finish
2025/01/24 02:01:44 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (6.13s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:01:49 DEBUG : potato: md5 = 783b37f302528f61f6ed9ddaa41cfa13 OK
2025/01/24 02:01:50 DEBUG : empty space: md5 = a3007194529c0b13bd8304b04ae48c87 OK
2025/01/24 02:01:51 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/24 02:01:51 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:01:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:01:51 DEBUG : empty space: Unchanged skipping
2025/01/24 02:01:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:01:52 DEBUG : potato2: md5 = f922cf00130b5188d6af926f627857af OK
2025/01/24 02:01:52 INFO  : potato2: Copied (new)
2025/01/24 02:01:52 DEBUG : Waiting for deletions to finish
2025/01/24 02:01:53 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.90s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:01:58 DEBUG : b/potato: md5 = ebfe01bbe1e27de2c3fba194baf26335 OK
2025/01/24 02:02:01 DEBUG : c/non empty space: md5 = 73684c35955ac85bccec96e3906562c6 OK
2025/01/24 02:02:01 INFO  : d: Making directory
2025/01/24 02:02:02 INFO  : d/e: Making directory
2025/01/24 02:02:04 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/01/24 02:02:04 DEBUG : Added delayed dir = "c", newDst=c
2025/01/24 02:02:04 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/01/24 02:02:04 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:02:04 DEBUG : c/non empty space: Unchanged skipping
2025/01/24 02:02:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:02:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:02:06 DEBUG : a/potato2: md5 = a6987d837806f43eb7a2a4bb0348fd19 OK
2025/01/24 02:02:06 INFO  : a/potato2: Copied (new)
2025/01/24 02:02:06 DEBUG : Waiting for deletions to finish
2025/01/24 02:02:07 INFO  : b/potato: Deleted
2025/01/24 02:02:07 INFO  : a: Set directory modification time (using DirSetModTime)
2025/01/24 02:02:07 INFO  : d/e: Removing directory
2025/01/24 02:02:08 INFO  : d: Removing directory
2025/01/24 02:02:08 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2025/01/24 02:02:09 INFO  : b: Removing directory
2025/01/24 02:02:09 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/01/24 02:02:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:02:13 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/01/24 02:02:13 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (19.14s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:02:17 DEBUG : b/potato: md5 = f16d2f60eb8960ea4cb82b719222c4d7 OK
2025/01/24 02:02:20 DEBUG : c/non empty space: md5 = 87129645e0c20decbd199786817e5a35 OK
2025/01/24 02:02:20 INFO  : d: Making directory
2025/01/24 02:02:22 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/01/24 02:02:22 DEBUG : Added delayed dir = "c", newDst=c
2025/01/24 02:02:22 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/01/24 02:02:22 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:02:22 DEBUG : c/non empty space: Unchanged skipping
2025/01/24 02:02:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:02:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:02:24 DEBUG : a/potato2: md5 = 5385f1033099e17726133c057a252a7c OK
2025/01/24 02:02:24 INFO  : a/potato2: Copied (new)
2025/01/24 02:02:24 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': not deleting files as there were IO errors
2025/01/24 02:02:25 INFO  : a: Set directory modification time (using DirSetModTime)
2025/01/24 02:02:25 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:02:29 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/01/24 02:02:30 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/01/24 02:02:31 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (17.24s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:02:34 DEBUG : potato: md5 = 3bc5aa3309b70558afa8faeecb833b12 OK
2025/01/24 02:02:35 DEBUG : empty space: md5 = a257790eb7635b1ffe6a170682d945c1 OK
2025/01/24 02:02:36 DEBUG : Waiting for deletions to finish
2025/01/24 02:02:36 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/24 02:02:36 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:02:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:02:36 DEBUG : empty space: Unchanged skipping
2025/01/24 02:02:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:02:36 INFO  : potato: Deleted
2025/01/24 02:02:38 DEBUG : potato2: md5 = 25e54c0f65588ce2522f2794ac0b2c03 OK
2025/01/24 02:02:38 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (8.14s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:02:42 DEBUG : potato: md5 = 3349b9dc87a0a9294f61678ab0b5db5e OK
2025/01/24 02:02:44 DEBUG : empty space: md5 = 5ff9c3a4bae173039fe32b69e52e3f9a OK
2025/01/24 02:02:44 DEBUG : Waiting for deletions to finish
2025/01/24 02:02:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:02:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:02:45 INFO  : potato: Deleted
2025/01/24 02:02:45 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/24 02:02:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:02:45 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:02:45 DEBUG : empty space: Unchanged skipping
2025/01/24 02:02:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:02:47 DEBUG : potato2: md5 = 15207c6dbc7b935318491cc71247c44c OK
2025/01/24 02:02:47 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (9.39s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:02:51 DEBUG : potato: md5 = 1c41b5ac8c06a1aabdf15067dedd2c7f OK
2025/01/24 02:02:52 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/24 02:02:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:02:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:02:53 DEBUG : potato2: md5 = a8c5dc5c0d37dc5d2569c922dfeea2a7 OK
2025/01/24 02:02:53 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (6.20s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:02:57 DEBUG : potato2: md5 = 7dc38e47b4cc7f0d2124e4b331f01fca OK
2025/01/24 02:02:59 DEBUG : empty space: md5 = b81612c99e9e932c4d7a3f7d7c206900 OK
2025/01/24 02:02:59 DEBUG : enormous: Excluded (Size Filter)
2025/01/24 02:02:59 DEBUG : enormous: Excluded
2025/01/24 02:02:59 DEBUG : potato2: Excluded (Size Filter)
2025/01/24 02:02:59 DEBUG : potato2: Excluded
2025/01/24 02:03:00 DEBUG : potato2: Excluded (Size Filter)
2025/01/24 02:03:00 DEBUG : potato2: Excluded
2025/01/24 02:03:00 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:03:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:03:00 DEBUG : empty space: Unchanged skipping
2025/01/24 02:03:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:03:00 DEBUG : Waiting for deletions to finish
2025/01/24 02:03:00 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:03:00 DEBUG : enormous: Excluded (Size Filter)
2025/01/24 02:03:00 DEBUG : enormous: Excluded
2025/01/24 02:03:00 DEBUG : potato2: Excluded (Size Filter)
2025/01/24 02:03:00 DEBUG : potato2: Excluded
2025/01/24 02:03:00 DEBUG : potato2: Excluded (Size Filter)
2025/01/24 02:03:00 DEBUG : potato2: Excluded
2025/01/24 02:03:00 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2025/01/24 02:03:00 DEBUG : Local file system at /tmp/rclone3053794225: Waiting for checks to finish
2025/01/24 02:03:00 DEBUG : empty space: Unchanged skipping
2025/01/24 02:03:00 DEBUG : Local file system at /tmp/rclone3053794225: Waiting for transfers to finish
2025/01/24 02:03:00 DEBUG : Waiting for deletions to finish
2025/01/24 02:03:00 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncWithExclude (7.21s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:03:04 DEBUG : potato2: md5 = b0c8df860fb8cfef7cb6bb6bd20a6bd5 OK
2025/01/24 02:03:06 DEBUG : empty space: md5 = 154269537042674bf9b21b46eda58199 OK
2025/01/24 02:03:08 DEBUG : enormous: md5 = 7cb07967e85e06ac144339bc0cc03acc OK
2025/01/24 02:03:08 DEBUG : enormous: Excluded (Size Filter)
2025/01/24 02:03:08 DEBUG : enormous: Excluded
2025/01/24 02:03:08 DEBUG : potato2: Excluded (Size Filter)
2025/01/24 02:03:08 DEBUG : potato2: Excluded
2025/01/24 02:03:08 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:03:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:03:08 DEBUG : empty space: Unchanged skipping
2025/01/24 02:03:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:03:08 DEBUG : Waiting for deletions to finish
2025/01/24 02:03:09 INFO  : potato2: Deleted
2025/01/24 02:03:09 INFO  : enormous: Deleted
2025/01/24 02:03:09 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:03:10 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2025/01/24 02:03:10 DEBUG : empty space: Unchanged skipping
2025/01/24 02:03:10 DEBUG : Local file system at /tmp/rclone3053794225: Waiting for checks to finish
2025/01/24 02:03:10 DEBUG : Local file system at /tmp/rclone3053794225: Waiting for transfers to finish
2025/01/24 02:03:10 DEBUG : Waiting for deletions to finish
2025/01/24 02:03:10 INFO  : enormous: Deleted
2025/01/24 02:03:10 INFO  : potato2: Deleted
2025/01/24 02:03:10 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (8.78s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:03:13 DEBUG : one: md5 = dbfe2b3702670ed86d1954774e81b9dd OK
2025/01/24 02:03:15 DEBUG : two: md5 = 401aa8a3c8b5ffe66ad2baf5752a59cf OK
2025/01/24 02:03:17 DEBUG : three: md5 = 0fa7060836c9f83cf54dad4bd9eda5ec OK
2025/01/24 02:03:18 DEBUG : four: md5 = 80e6cda4e966a240b01cdc41cc343bf2 OK
2025/01/24 02:03:19 DEBUG : five: Need to transfer - File not found at Destination
2025/01/24 02:03:19 DEBUG : four: Sizes differ (src 4 vs dst 8)
2025/01/24 02:03:19 DEBUG : one: Destination is newer than source, skipping
2025/01/24 02:03:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:03:19 DEBUG : three: Sizes identical
2025/01/24 02:03:19 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2025/01/24 02:03:19 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2025/01/24 02:03:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:03:20 DEBUG : five: md5 = 3a40ed6cedbd6732cccae811a1f7a383 OK
2025/01/24 02:03:20 INFO  : five: Copied (new)
2025/01/24 02:03:20 DEBUG : two: md5 = 571c8896ec1d98f2c83739276bec869d OK
2025/01/24 02:03:20 INFO  : two: Copied (replaced existing)
2025/01/24 02:03:21 DEBUG : four: md5 = c6104d61f20cb89ba33b0ca0458f1b4f OK
2025/01/24 02:03:21 INFO  : four: Copied (replaced existing)
2025/01/24 02:03:21 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (12.70s)
=== 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-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2025/01/24 02:03:24 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Ignoring --track-renames as the source and destination do not have a common hash
2025/01/24 02:03:25 DEBUG : potato: Need to transfer - File not found at Destination
2025/01/24 02:03:25 DEBUG : yam: Need to transfer - File not found at Destination
2025/01/24 02:03:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:03:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:03:26 DEBUG : potato: md5 = a274d86e7bcddd703fdcba939f2f20b3 OK
2025/01/24 02:03:26 INFO  : potato: Copied (new)
2025/01/24 02:03:26 DEBUG : yam: md5 = 92444cca03fc3de9aa8cee642cf43a15 OK
2025/01/24 02:03:26 INFO  : yam: Copied (new)
2025/01/24 02:03:26 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:03:27 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Ignoring --track-renames as the source and destination do not have a common hash
2025/01/24 02:03:27 DEBUG : yaml: Need to transfer - File not found at Destination
2025/01/24 02:03:27 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:03:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:03:27 DEBUG : potato: Unchanged skipping
2025/01/24 02:03:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:03:29 DEBUG : yaml: md5 = 62aeeaf6a3b8ad2af925ae12d1151d6b OK
2025/01/24 02:03:29 INFO  : yaml: Copied (new)
2025/01/24 02:03:29 DEBUG : Waiting for deletions to finish
2025/01/24 02:03:29 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (7.98s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2025/01/24 02:03:33 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Making map for --track-renames
2025/01/24 02:03:33 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Finished making map for --track-renames
2025/01/24 02:03:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:03:33 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/01/24 02:03:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for renames to finish
2025/01/24 02:03:33 DEBUG : yam: Need to transfer - No matching file found at Destination
2025/01/24 02:03:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:03:34 DEBUG : yam: md5 = ce4a1227eab503f7c138fc9095b6872d OK
2025/01/24 02:03:34 INFO  : yam: Copied (new)
2025/01/24 02:03:34 DEBUG : potato: md5 = 2628ce09a766470446b5a2a7d9ace0e4 OK
2025/01/24 02:03:34 INFO  : potato: Copied (new)
2025/01/24 02:03:34 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:03:35 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:03:35 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Making map for --track-renames
2025/01/24 02:03:35 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Finished making map for --track-renames
2025/01/24 02:03:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:03:35 DEBUG : potato: Unchanged skipping
2025/01/24 02:03:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for renames to finish
2025/01/24 02:03:35 INFO  : yam: Moved (server-side) to: yaml
2025/01/24 02:03:35 INFO  : yaml: Renamed from "yam"
2025/01/24 02:03:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:03:35 DEBUG : Waiting for deletions to finish
2025/01/24 02:03:35 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (6.09s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2025/01/24 02:03:39 DEBUG : Added delayed dir = "sub", newDst=<nil>
2025/01/24 02:03:39 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Making map for --track-renames
2025/01/24 02:03:39 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Finished making map for --track-renames
2025/01/24 02:03:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:03:39 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/01/24 02:03:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for renames to finish
2025/01/24 02:03:39 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2025/01/24 02:03:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:03:41 DEBUG : sub/yam: md5 = 6558bf4c233b400acdee4e61ade8d96d OK
2025/01/24 02:03:41 INFO  : sub/yam: Copied (new)
2025/01/24 02:03:41 DEBUG : potato: md5 = 4dd1ebe09e30bbee8e929cf132f9e2cd OK
2025/01/24 02:03:41 INFO  : potato: Copied (new)
2025/01/24 02:03:41 DEBUG : Waiting for deletions to finish
2025/01/24 02:03:42 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:03:43 DEBUG : Added delayed dir = "sub", newDst=sub
2025/01/24 02:03:43 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:03:43 DEBUG : potato: Unchanged skipping
2025/01/24 02:03:43 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Making map for --track-renames
2025/01/24 02:03:43 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Finished making map for --track-renames
2025/01/24 02:03:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:03:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for renames to finish
2025/01/24 02:03:44 INFO  : sub/yam: Moved (server-side) to: yam
2025/01/24 02:03:44 INFO  : yam: Renamed from "sub/yam"
2025/01/24 02:03:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:03:44 DEBUG : Waiting for deletions to finish
2025/01/24 02:03:44 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (10.03s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:03:48 DEBUG : Creating backend with remote "/tmp/rclone3053794225/dir1"
2025/01/24 02:03:48 DEBUG : Creating backend with remote "/tmp/rclone3053794225/dir2"
2025/01/24 02:03:48 DEBUG : Local file system at /tmp/rclone3053794225/dir2: Using server-side directory move
2025/01/24 02:03:48 INFO  : Local file system at /tmp/rclone3053794225/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/01/24 02:03:48 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/01/24 02:03:48 DEBUG : Local file system at /tmp/rclone3053794225/dir2: Waiting for checks to finish
2025/01/24 02:03:48 DEBUG : Local file system at /tmp/rclone3053794225/dir2: Waiting for transfers to finish
2025/01/24 02:03:48 INFO  : file1.txt: Moved (server-side)
--- PASS: TestServerSideMoveLocal (0.46s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:03:49 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/01/24 02:03:49 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/24 02:03:49 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/24 02:03:49 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/01/24 02:03:49 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/01/24 02:03:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:03:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:03:52 DEBUG : sub dir/hello world: md5 = 71df95ed9627169fefdadce316ba62fc OK
2025/01/24 02:03:52 INFO  : sub dir/hello world: Copied (new)
2025/01/24 02:03:52 INFO  : sub dir/hello world: Deleted
2025/01/24 02:03:54 DEBUG : nested/sub dir/file: md5 = f977f3090acf9463099e20ecaca2d2bc OK
2025/01/24 02:03:54 INFO  : nested/sub dir/file: Copied (new)
2025/01/24 02:03:54 INFO  : nested/sub dir/file: Deleted
2025/01/24 02:03:54 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/01/24 02:03:55 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/24 02:03:55 INFO  : nested: Set directory modification time (using DirSetModTime)
2025/01/24 02:03:55 INFO  : sub dir: Removing directory
2025/01/24 02:03:55 INFO  : nested/sub dir: Removing directory
2025/01/24 02:03:55 INFO  : nested: Removing directory
2025/01/24 02:03:55 DEBUG : Local file system at /tmp/rclone3053794225: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:03:58 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/24 02:03:59 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2025/01/24 02:04:00 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (12.97s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:04:02 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/01/24 02:04:02 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/24 02:04:02 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/24 02:04:02 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/01/24 02:04:02 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/01/24 02:04:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:04:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:04:05 DEBUG : sub dir/hello world: md5 = ce4a6ae246d0876c536eaaca4c0888a2 OK
2025/01/24 02:04:05 INFO  : sub dir/hello world: Copied (new)
2025/01/24 02:04:05 INFO  : sub dir/hello world: Deleted
2025/01/24 02:04:07 DEBUG : nested/sub dir/file: md5 = 80c40aa6ae33dcc38689f9afc4532e6c OK
2025/01/24 02:04:07 INFO  : nested/sub dir/file: Copied (new)
2025/01/24 02:04:07 INFO  : nested/sub dir/file: Deleted
2025/01/24 02:04:08 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/01/24 02:04:08 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/24 02:04:08 INFO  : nested: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:04:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/24 02:04:12 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2025/01/24 02:04:13 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (12.59s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:04:15 DEBUG : existing: Need to transfer - File not found at Destination
2025/01/24 02:04:15 DEBUG : existing-b: Need to transfer - File not found at Destination
2025/01/24 02:04:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:04:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:04:16 DEBUG : existing-b: md5 = 070b1257eace600bea935ef09bad18fa OK
2025/01/24 02:04:16 INFO  : existing-b: Copied (new)
2025/01/24 02:04:16 INFO  : existing-b: Deleted
2025/01/24 02:04:16 DEBUG : existing: md5 = 4b41d15ec0c498a85725594cd3ea3e97 OK
2025/01/24 02:04:16 INFO  : existing: Copied (new)
2025/01/24 02:04:16 INFO  : existing: Deleted
2025/01/24 02:04:17 DEBUG : existing: Destination exists, skipping
2025/01/24 02:04:17 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2025/01/24 02:04:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:04:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:04:17 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (4.86s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:04:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-moropuf1kori"
2025/01/24 02:04:19 DEBUG : Creating backend with remote "TestDrive:crypt/nht5slmjce49heq3sr86pub9k8juj3nvqi0vcjfkji1pqafut73g"
2025/01/24 02:04:22 DEBUG : potato2: md5 = 125af0c1007a425775238070d99ac2ff OK
2025/01/24 02:04:24 DEBUG : empty space: md5 = 66ada606e4e4d707998af98ed6c7d31a OK
2025/01/24 02:04:26 DEBUG : potato3: md5 = a6fa9472248dcd9601b149c1dabc7b74 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo' -> Encrypted drive 'TestCryptDrive:rclone-test-moropuf1kori'
2025/01/24 02:04:29 DEBUG : empty space: md5 = 6fd19d408f728440c6ce3fc8f5b23cb5 OK
2025/01/24 02:04:30 DEBUG : potato3: md5 = 29b5bb3ae292b9ea83b26fbe6d5ca277 OK
2025/01/24 02:04:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moropuf1kori': Using server-side directory move
2025/01/24 02:04:30 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-moropuf1kori': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/01/24 02:04:31 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/24 02:04:31 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/01/24 02:04:31 DEBUG : empty space: Unchanged skipping
2025/01/24 02:04:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moropuf1kori': Waiting for checks to finish
2025/01/24 02:04:31 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/01/24 02:04:31 INFO  : potato3: Deleted
2025/01/24 02:04:31 INFO  : empty space: Deleted
2025/01/24 02:04:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moropuf1kori': Waiting for transfers to finish
2025/01/24 02:04:32 INFO  : potato2: Moved (server-side)
2025/01/24 02:04:32 INFO  : potato3: Moved (server-side)
2025/01/24 02:04:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xevevub0muzu"
2025/01/24 02:04:33 DEBUG : Creating backend with remote "TestDrive:crypt/24k4abrekc547on2j81sc5egi3bjr9fd3muoib2m4vfkb0h0u870"
2025/01/24 02:04:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xevevub0muzu': Using server-side directory move
2025/01/24 02:04:34 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-xevevub0muzu': Server side directory move succeeded
2025/01/24 02:04:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xevevub0muzu': Purge remote
2025/01/24 02:04:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-moropuf1kori': Purge remote
2025/01/24 02:04:36 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (17.45s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:04:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fedazuf4hoxi"
2025/01/24 02:04:37 DEBUG : Creating backend with remote "TestDrive:crypt/neuacnk9cc8g8ih9diee5eitlg7lglcisgpp14viiqtm7r54gfrg"
2025/01/24 02:04:39 DEBUG : potato2: md5 = 682cdadf0931d685b9356e0bd9ab2247 OK
2025/01/24 02:04:41 DEBUG : empty space: md5 = 502bc59db6cd3b99c17d4f49d5ea5de4 OK
2025/01/24 02:04:43 DEBUG : potato3: md5 = 3c7a18f6772c149d637a84a7aa9bdd26 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo' -> Encrypted drive 'TestCryptDrive:rclone-test-fedazuf4hoxi'
2025/01/24 02:04:46 DEBUG : empty space: md5 = 375a992648b30f4345f9e79949294df7 OK
2025/01/24 02:04:47 DEBUG : potato3: md5 = c0dfb253f8cff4d3f8221519484dd01b OK
2025/01/24 02:04:48 DEBUG : empty space: Excluded (Size Filter)
2025/01/24 02:04:48 DEBUG : empty space: Excluded
2025/01/24 02:04:48 DEBUG : empty space: Excluded (Size Filter)
2025/01/24 02:04:48 DEBUG : empty space: Excluded
2025/01/24 02:04:48 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/24 02:04:48 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/01/24 02:04:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fedazuf4hoxi': Waiting for checks to finish
2025/01/24 02:04:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fedazuf4hoxi': Waiting for transfers to finish
2025/01/24 02:04:48 INFO  : potato3: Deleted
2025/01/24 02:04:49 INFO  : potato2: Moved (server-side)
2025/01/24 02:04:50 INFO  : potato3: Moved (server-side)
2025/01/24 02:04:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-foburin7nele"
2025/01/24 02:04:50 DEBUG : Creating backend with remote "TestDrive:crypt/1nb43vc2dmtoloahqokhanufui3bms98u00t80l333s7dc80j8h0"
2025/01/24 02:04:51 DEBUG : empty space: Excluded (Size Filter)
2025/01/24 02:04:51 DEBUG : empty space: Excluded
2025/01/24 02:04:51 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/24 02:04:51 DEBUG : potato3: Need to transfer - File not found at Destination
2025/01/24 02:04:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-foburin7nele': Waiting for checks to finish
2025/01/24 02:04:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-foburin7nele': Waiting for transfers to finish
2025/01/24 02:04:53 INFO  : potato3: Moved (server-side)
2025/01/24 02:04:54 INFO  : potato2: Moved (server-side)
2025/01/24 02:04:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-foburin7nele': Purge remote
2025/01/24 02:04:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fedazuf4hoxi': Purge remote
--- PASS: TestServerSideMoveWithFilter (19.75s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:04:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-joherez2cuco"
2025/01/24 02:04:57 DEBUG : Creating backend with remote "TestDrive:crypt/g8rr9v1fg9ulasavhtcre3f0f5hlobfoj0kq5dbderakvn7b786g"
2025/01/24 02:04:59 DEBUG : potato2: md5 = 5d8da522f6403206d1d2183e13d732a4 OK
2025/01/24 02:05:01 DEBUG : empty space: md5 = 8452621045322a2bb2106657443badfe OK
2025/01/24 02:05:03 DEBUG : potato3: md5 = 816f673531828822202beac1293dbd42 OK
2025/01/24 02:05:03 INFO  : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo' -> Encrypted drive 'TestCryptDrive:rclone-test-joherez2cuco'
2025/01/24 02:05:08 DEBUG : empty space: md5 = f803956f741f085f66cee159067fbf0d OK
2025/01/24 02:05:09 DEBUG : potato3: md5 = d22b3c0bf8197c511553ce299379a160 OK
2025/01/24 02:05:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-joherez2cuco': Using server-side directory move
2025/01/24 02:05:10 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-joherez2cuco': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/01/24 02:05:10 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/24 02:05:10 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2025/01/24 02:05:10 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/01/24 02:05:10 DEBUG : empty space: Unchanged skipping
2025/01/24 02:05:10 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/01/24 02:05:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-joherez2cuco': Waiting for checks to finish
2025/01/24 02:05:10 INFO  : potato3: Deleted
2025/01/24 02:05:10 INFO  : empty space: Deleted
2025/01/24 02:05:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-joherez2cuco': Waiting for transfers to finish
2025/01/24 02:05:11 INFO  : potato2: Moved (server-side)
2025/01/24 02:05:11 INFO  : potato3: Moved (server-side)
2025/01/24 02:05:11 INFO  : tomatoDir: Removing directory
2025/01/24 02:05:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': deleted 1 directories
2025/01/24 02:05:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nejenam9qasi"
2025/01/24 02:05:13 DEBUG : Creating backend with remote "TestDrive:crypt/clbp4ege352ngvhav8dkagtlnho2fbqkj0k0gjhc12o7h6917tjg"
2025/01/24 02:05:14 INFO  : tomatoDir: Making directory
2025/01/24 02:05:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nejenam9qasi': Using server-side directory move
2025/01/24 02:05:16 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-nejenam9qasi': Server side directory move succeeded
2025/01/24 02:05:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nejenam9qasi': Purge remote
2025/01/24 02:05:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-joherez2cuco': Purge remote
2025/01/24 02:05:18 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (21.83s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.46s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:05:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/rclone-sync-test"
2025/01/24 02:05:19 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncOverlap (3.81s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:05:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/rclone-sync-test"
2025/01/24 02:05:23 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2025/01/24 02:05:25 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/rclone-sync-test-include/layer2"
2025/01/24 02:05:25 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2025/01/24 02:05:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/rclone-sync-test-ignore-file"
2025/01/24 02:05:29 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2025/01/24 02:05:33 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 2c04d053d8951286ce371e99f6274c04 OK
2025/01/24 02:05:34 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/01/24 02:05:35 DEBUG : rclone-sync-test: Excluded
2025/01/24 02:05:35 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/01/24 02:05:35 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/01/24 02:05:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/rclone-sync-test': Waiting for checks to finish
2025/01/24 02:05:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/rclone-sync-test': Waiting for transfers to finish
2025/01/24 02:05:35 DEBUG : Waiting for deletions to finish
2025/01/24 02:05:35 INFO  : There was nothing to transfer
2025/01/24 02:05:36 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/01/24 02:05:36 DEBUG : rclone-sync-test: Excluded
2025/01/24 02:05:37 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/01/24 02:05:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:05:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:05:37 DEBUG : Waiting for deletions to finish
2025/01/24 02:05:37 INFO  : rclone-sync-test-include: Removing directory
2025/01/24 02:05:37 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/01/24 02:05:37 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2025/01/24 02:05:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': failed to delete 1 directories
2025/01/24 02:05:37 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:05:38 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/01/24 02:05:38 DEBUG : rclone-sync-test: Excluded
2025/01/24 02:05:38 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/01/24 02:05:39 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/01/24 02:05:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/rclone-sync-test-include/layer2': Waiting for checks to finish
2025/01/24 02:05:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/rclone-sync-test-include/layer2': Waiting for transfers to finish
2025/01/24 02:05:39 DEBUG : Waiting for deletions to finish
2025/01/24 02:05:39 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:05:39 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/01/24 02:05:40 DEBUG : rclone-sync-test: Excluded
2025/01/24 02:05:40 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/01/24 02:05:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:05:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:05:40 DEBUG : Waiting for deletions to finish
2025/01/24 02:05:40 INFO  : rclone-sync-test-include: Removing directory
2025/01/24 02:05:41 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/01/24 02:05:41 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2025/01/24 02:05:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': failed to delete 1 directories
2025/01/24 02:05:41 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:05:41 DEBUG : : Excluded
2025/01/24 02:05:41 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/01/24 02:05:42 DEBUG : rclone-sync-test: Excluded
2025/01/24 02:05:42 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/01/24 02:05:42 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/01/24 02:05:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/rclone-sync-test-ignore-file': Waiting for checks to finish
2025/01/24 02:05:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/rclone-sync-test-ignore-file': Waiting for transfers to finish
2025/01/24 02:05:42 DEBUG : Waiting for deletions to finish
2025/01/24 02:05:42 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:05:45 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/01/24 02:05:46 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (33.00s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:05:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/dst"
2025/01/24 02:05:56 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/24 02:05:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/CompareDest"
2025/01/24 02:05:57 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/gveqi14airsml4bgu7krj116o8"
2025/01/24 02:05:59 DEBUG : one: Need to transfer - File not found at Destination
2025/01/24 02:05:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for checks to finish
2025/01/24 02:05:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for transfers to finish
2025/01/24 02:06:02 DEBUG : one: md5 = 848e02ecd1c9a06e6f627aaea5a178bf OK
2025/01/24 02:06:02 INFO  : one: Copied (new)
2025/01/24 02:06:02 DEBUG : Waiting for deletions to finish
2025/01/24 02:06:03 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/24 02:06:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for checks to finish
2025/01/24 02:06:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for transfers to finish
2025/01/24 02:06:05 DEBUG : one: md5 = c40e938a771857192799639929b49f4e OK
2025/01/24 02:06:05 INFO  : one: Copied (replaced existing)
2025/01/24 02:06:05 DEBUG : Waiting for deletions to finish
2025/01/24 02:06:07 DEBUG : dst/one: md5 = 8c099508d1c2e61202b2864a63b1bbcd OK
2025/01/24 02:06:10 DEBUG : CompareDest/one: md5 = 4c0274049c752ca4f48c6d89aec95d5f OK
2025/01/24 02:06:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for checks to finish
2025/01/24 02:06:11 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/24 02:06:11 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:06:11 DEBUG : one: Destination found in --compare-dest, skipping
2025/01/24 02:06:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for transfers to finish
2025/01/24 02:06:11 DEBUG : Waiting for deletions to finish
2025/01/24 02:06:11 INFO  : There was nothing to transfer
2025/01/24 02:06:13 DEBUG : CompareDest/two: md5 = 401297237361b4d8e2708505a9f20866 OK
2025/01/24 02:06:14 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:06:14 DEBUG : two: Destination found in --compare-dest, skipping
2025/01/24 02:06:14 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/24 02:06:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for checks to finish
2025/01/24 02:06:14 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:06:14 DEBUG : one: Destination found in --compare-dest, skipping
2025/01/24 02:06:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for transfers to finish
2025/01/24 02:06:14 DEBUG : Waiting for deletions to finish
2025/01/24 02:06:14 INFO  : There was nothing to transfer
2025/01/24 02:06:16 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:06:16 DEBUG : two: Destination found in --compare-dest, skipping
2025/01/24 02:06:16 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/24 02:06:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for checks to finish
2025/01/24 02:06:16 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:06:16 DEBUG : one: Destination found in --compare-dest, skipping
2025/01/24 02:06:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for transfers to finish
2025/01/24 02:06:16 DEBUG : Waiting for deletions to finish
2025/01/24 02:06:16 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2025/01/24 02:06:17 DEBUG : two: Sizes differ (src 5 vs dst 3)
2025/01/24 02:06:17 DEBUG : two: Need to transfer - File not found at Destination
2025/01/24 02:06:17 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/24 02:06:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for checks to finish
2025/01/24 02:06:17 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:06:17 DEBUG : one: Destination found in --compare-dest, skipping
2025/01/24 02:06:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for transfers to finish
2025/01/24 02:06:19 DEBUG : two: md5 = 590a3ea621d2399f864ce0b7d8f655df OK
2025/01/24 02:06:19 INFO  : two: Copied (new)
2025/01/24 02:06:19 DEBUG : Waiting for deletions to finish
2025/01/24 02:06:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/24 02:06:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/24 02:06:23 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/24 02:06:23 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCompareDest (28.52s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:06:27 DEBUG : pre-dest1/1: md5 = cf6bdffa4477c44c66078458c58aa782 OK
2025/01/24 02:06:29 DEBUG : pre-dest2/2: md5 = 3bd4c322e8813bce22de2a61bea3ef85 OK
2025/01/24 02:06:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/dest"
2025/01/24 02:06:30 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/rg03c1jvnehrrc617i0lnqjddc"
2025/01/24 02:06:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/pre-dest1"
2025/01/24 02:06:31 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/bbnblvh6k061ssopqrp18kd7gc"
2025/01/24 02:06:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/pre-dest2"
2025/01/24 02:06:32 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/dgicm1h6b5ejvlltm8eeif0bnk"
2025/01/24 02:06:33 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:06:33 DEBUG : 1: Destination found in --compare-dest, skipping
2025/01/24 02:06:34 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:06:34 DEBUG : 2: Destination found in --compare-dest, skipping
2025/01/24 02:06:34 DEBUG : 3: Need to transfer - File not found at Destination
2025/01/24 02:06:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dest': Waiting for checks to finish
2025/01/24 02:06:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dest': Waiting for transfers to finish
2025/01/24 02:06:37 DEBUG : 3: md5 = fa0579204422013b9571112e73aee5b1 OK
2025/01/24 02:06:37 INFO  : 3: Copied (new)
2025/01/24 02:06:37 DEBUG : Waiting for deletions to finish
2025/01/24 02:06:41 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2025/01/24 02:06:42 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2025/01/24 02:06:43 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (19.26s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:06:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/dst"
2025/01/24 02:06:43 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/24 02:06:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/CopyDest"
2025/01/24 02:06:45 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/d09o6po3f7bm6ce32vdgs8h9ls"
2025/01/24 02:06:47 DEBUG : one: Need to transfer - File not found at Destination
2025/01/24 02:06:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for checks to finish
2025/01/24 02:06:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for transfers to finish
2025/01/24 02:06:50 DEBUG : one: md5 = c24494d60beb98f0c0087b95f40e9c82 OK
2025/01/24 02:06:50 INFO  : one: Copied (new)
2025/01/24 02:06:50 DEBUG : Waiting for deletions to finish
2025/01/24 02:06:51 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/24 02:06:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for checks to finish
2025/01/24 02:06:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for transfers to finish
2025/01/24 02:06:53 DEBUG : one: md5 = da7cbcda5901c12a3ad45f00f7a11fcb OK
2025/01/24 02:06:53 INFO  : one: Copied (replaced existing)
2025/01/24 02:06:53 DEBUG : Waiting for deletions to finish
2025/01/24 02:06:55 DEBUG : dst/one: md5 = ed72b4e72833df33bd07177a11ea503d OK
2025/01/24 02:06:57 DEBUG : CopyDest/one: md5 = 96bcb58ac0ee840d0a0a7f9a4346bd7f OK
2025/01/24 02:06:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/BackupDir"
2025/01/24 02:06:58 DEBUG : Config file has changed externally - reloading
2025/01/24 02:06:58 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/s6dbk3lfi7c9kfvo6j7bla9m0g"
2025/01/24 02:07:00 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/24 02:07:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for checks to finish
2025/01/24 02:07:00 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:07:00 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/24 02:07:02 INFO  : one: Moved (server-side)
2025/01/24 02:07:04 INFO  : one: Copied (server-side copy)
2025/01/24 02:07:04 DEBUG : one: Destination found in --copy-dest, using server-side copy
2025/01/24 02:07:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for transfers to finish
2025/01/24 02:07:04 DEBUG : Waiting for deletions to finish
2025/01/24 02:07:06 DEBUG : CopyDest/two: md5 = 7e73a9c573fe30e324180c77a7c6904b OK
2025/01/24 02:07:07 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:07:08 INFO  : two: Copied (server-side copy)
2025/01/24 02:07:08 DEBUG : two: Destination found in --copy-dest, using server-side copy
2025/01/24 02:07:08 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:07:08 DEBUG : one: Unchanged skipping
2025/01/24 02:07:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for checks to finish
2025/01/24 02:07:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for transfers to finish
2025/01/24 02:07:08 DEBUG : Waiting for deletions to finish
2025/01/24 02:07:09 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:07:09 DEBUG : one: Unchanged skipping
2025/01/24 02:07:09 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:07:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for checks to finish
2025/01/24 02:07:09 DEBUG : two: Unchanged skipping
2025/01/24 02:07:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for transfers to finish
2025/01/24 02:07:09 DEBUG : Waiting for deletions to finish
2025/01/24 02:07:09 INFO  : There was nothing to transfer
2025/01/24 02:07:11 DEBUG : CopyDest/three: md5 = b9583320e4bab5931c5b74ac066297aa OK
2025/01/24 02:07:12 DEBUG : three: Sizes differ (src 7 vs dst 5)
2025/01/24 02:07:12 DEBUG : three: Destination not found in --copy-dest
2025/01/24 02:07:12 DEBUG : three: Need to transfer - File not found at Destination
2025/01/24 02:07:12 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:07:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for checks to finish
2025/01/24 02:07:12 DEBUG : one: Unchanged skipping
2025/01/24 02:07:12 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/24 02:07:12 DEBUG : two: Unchanged skipping
2025/01/24 02:07:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for transfers to finish
2025/01/24 02:07:14 DEBUG : three: md5 = b8faf5ee76156b9a71fe9c60b9f20267 OK
2025/01/24 02:07:14 INFO  : three: Copied (new)
2025/01/24 02:07:14 DEBUG : Waiting for deletions to finish
2025/01/24 02:07:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2025/01/24 02:07:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/24 02:07:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/24 02:07:22 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2025/01/24 02:07:22 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/24 02:07:22 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/24 02:07:22 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (39.88s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:07:26 DEBUG : dst/one: md5 = dd07a57499925d0400905bc37f62387a OK
2025/01/24 02:07:28 DEBUG : dst/two: md5 = 2919497ac304db03c137adba693ed7c6 OK
2025/01/24 02:07:29 DEBUG : dst/three.txt: md5 = f1566c430a534a96773567f0185c9f81 OK
2025/01/24 02:07:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/dst"
2025/01/24 02:07:30 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/24 02:07:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/backup"
2025/01/24 02:07:31 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/1nrff024r7pq65ecp72fc28jb0"
2025/01/24 02:07:32 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/24 02:07:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for checks to finish
2025/01/24 02:07:32 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:07:32 DEBUG : two: Unchanged skipping
2025/01/24 02:07:35 INFO  : one: Moved (server-side)
2025/01/24 02:07:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for transfers to finish
2025/01/24 02:07:36 DEBUG : one: md5 = 65dff5fbe79d365ca30f1913aedd247e OK
2025/01/24 02:07:36 INFO  : one: Copied (new)
2025/01/24 02:07:36 DEBUG : Waiting for deletions to finish
2025/01/24 02:07:38 INFO  : three.txt: Moved (server-side)
2025/01/24 02:07:38 INFO  : three.txt: Moved into backup dir
2025/01/24 02:07:40 DEBUG : dst/three.txt: md5 = 41bd72061ec9dfaacaf2451774840341 OK
2025/01/24 02:07:41 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/24 02:07:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for checks to finish
2025/01/24 02:07:41 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:07:41 DEBUG : two: Unchanged skipping
2025/01/24 02:07:42 INFO  : one: Deleted
2025/01/24 02:07:43 INFO  : one: Moved (server-side)
2025/01/24 02:07:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for transfers to finish
2025/01/24 02:07:44 DEBUG : one: md5 = d9b6187a8f53565c6b9475fda085a0bc OK
2025/01/24 02:07:44 INFO  : one: Copied (new)
2025/01/24 02:07:44 DEBUG : Waiting for deletions to finish
2025/01/24 02:07:45 INFO  : three.txt: Deleted
2025/01/24 02:07:46 INFO  : three.txt: Moved (server-side)
2025/01/24 02:07:46 INFO  : three.txt: Moved into backup dir
2025/01/24 02:07:50 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/24 02:07:50 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/24 02:07:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/01/24 02:07:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/24 02:07:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/01/24 02:07:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncBackupDir (28.14s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:07:54 DEBUG : dst/one: md5 = 9a634a09cf4fa58964e9113c0b0b7765 OK
2025/01/24 02:07:56 DEBUG : dst/two: md5 = 4273da22ba7c53dbdf65f39722f7d5d9 OK
2025/01/24 02:07:57 DEBUG : dst/three.txt: md5 = a0f0b6ddf2ae4efa008c63fdfce19f52 OK
2025/01/24 02:07:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/dst"
2025/01/24 02:07:58 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/24 02:07:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/backup"
2025/01/24 02:07:59 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/1nrff024r7pq65ecp72fc28jb0"
2025/01/24 02:08:01 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/24 02:08:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for checks to finish
2025/01/24 02:08:01 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:08:01 DEBUG : two: Unchanged skipping
2025/01/24 02:08:03 INFO  : one: Moved (server-side) to: one.bak
2025/01/24 02:08:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for transfers to finish
2025/01/24 02:08:04 DEBUG : one: md5 = 18a86a4ba584412e0ce15023b097277b OK
2025/01/24 02:08:04 INFO  : one: Copied (new)
2025/01/24 02:08:04 DEBUG : Waiting for deletions to finish
2025/01/24 02:08:06 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/24 02:08:06 INFO  : three.txt: Moved into backup dir
2025/01/24 02:08:08 DEBUG : dst/three.txt: md5 = 4462ce32eadec72750f1813b7a486955 OK
2025/01/24 02:08:08 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/24 02:08:08 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:08:08 DEBUG : two: Unchanged skipping
2025/01/24 02:08:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for checks to finish
2025/01/24 02:08:09 INFO  : one.bak: Deleted
2025/01/24 02:08:10 INFO  : one: Moved (server-side) to: one.bak
2025/01/24 02:08:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for transfers to finish
2025/01/24 02:08:12 DEBUG : one: md5 = 3b9d86c57d0b24532e1b7f80185a674b OK
2025/01/24 02:08:12 INFO  : one: Copied (new)
2025/01/24 02:08:12 DEBUG : Waiting for deletions to finish
2025/01/24 02:08:13 INFO  : three.txt.bak: Deleted
2025/01/24 02:08:14 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/24 02:08:14 INFO  : three.txt: Moved into backup dir
2025/01/24 02:08:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/24 02:08:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/24 02:08:18 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/24 02:08:18 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/24 02:08:18 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/24 02:08:18 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncBackupDirWithSuffix (27.77s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:08:22 DEBUG : dst/one: md5 = 5d8c537368b9805ea452f7c97e561ef7 OK
2025/01/24 02:08:24 DEBUG : dst/two: md5 = 9119adbfe8f6c192327b50120a028e65 OK
2025/01/24 02:08:25 DEBUG : dst/three.txt: md5 = 07d246bddb976ffdbdfa9518e94ed650 OK
2025/01/24 02:08:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/dst"
2025/01/24 02:08:26 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/24 02:08:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/backup"
2025/01/24 02:08:27 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/1nrff024r7pq65ecp72fc28jb0"
2025/01/24 02:08:28 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/24 02:08:28 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:08:28 DEBUG : two: Unchanged skipping
2025/01/24 02:08:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for checks to finish
2025/01/24 02:08:31 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/01/24 02:08:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for transfers to finish
2025/01/24 02:08:32 DEBUG : one: md5 = ec5b893cc7b109747fa9fd13cdaaac3d OK
2025/01/24 02:08:32 INFO  : one: Copied (new)
2025/01/24 02:08:32 DEBUG : Waiting for deletions to finish
2025/01/24 02:08:33 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/01/24 02:08:33 INFO  : three.txt: Moved into backup dir
2025/01/24 02:08:36 DEBUG : dst/three.txt: md5 = 13857a2663c4352d419a6b1fa19011f3 OK
2025/01/24 02:08:36 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/24 02:08:36 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:08:36 DEBUG : two: Unchanged skipping
2025/01/24 02:08:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for checks to finish
2025/01/24 02:08:37 INFO  : one-2019-01-01: Deleted
2025/01/24 02:08:38 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/01/24 02:08:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for transfers to finish
2025/01/24 02:08:40 DEBUG : one: md5 = ff4b3d37af55849ffed28020d74e64f9 OK
2025/01/24 02:08:40 INFO  : one: Copied (new)
2025/01/24 02:08:40 DEBUG : Waiting for deletions to finish
2025/01/24 02:08:41 INFO  : three-2019-01-01.txt: Deleted
2025/01/24 02:08:41 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/01/24 02:08:41 INFO  : three.txt: Moved into backup dir
2025/01/24 02:08:45 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/24 02:08:45 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/24 02:08:46 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/01/24 02:08:46 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/01/24 02:08:46 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/01/24 02:08:46 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (27.73s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:08:50 DEBUG : dst/one: md5 = 1ce7bb0545bca75763d698beb4c3fc83 OK
2025/01/24 02:08:51 DEBUG : dst/two: md5 = 3dd0eb1c57ac9916e852e82ea70a2986 OK
2025/01/24 02:08:53 DEBUG : dst/three.txt: md5 = b845267319cbb70d151a63ad702bccca OK
2025/01/24 02:08:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/dst"
2025/01/24 02:08:54 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/24 02:08:55 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/24 02:08:55 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:08:55 DEBUG : two: Unchanged skipping
2025/01/24 02:08:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for checks to finish
2025/01/24 02:08:56 INFO  : one: Moved (server-side) to: one.bak
2025/01/24 02:08:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for transfers to finish
2025/01/24 02:08:57 DEBUG : one: md5 = 804a8942060e805abc583c0605c89dc7 OK
2025/01/24 02:08:57 INFO  : one: Copied (new)
2025/01/24 02:08:57 DEBUG : Waiting for deletions to finish
2025/01/24 02:08:58 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/24 02:08:58 INFO  : three.txt: Moved into backup dir
2025/01/24 02:09:00 DEBUG : dst/three.txt: md5 = 2d9903e736df3e08e6a2d7aa680464fd OK
2025/01/24 02:09:01 DEBUG : one.bak: Excluded (Path Filter)
2025/01/24 02:09:01 DEBUG : one.bak: Excluded
2025/01/24 02:09:01 DEBUG : three.txt.bak: Excluded (Path Filter)
2025/01/24 02:09:01 DEBUG : three.txt.bak: Excluded
2025/01/24 02:09:01 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/24 02:09:01 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:09:01 DEBUG : two: Unchanged skipping
2025/01/24 02:09:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for checks to finish
2025/01/24 02:09:02 INFO  : one.bak: Deleted
2025/01/24 02:09:02 INFO  : one: Moved (server-side) to: one.bak
2025/01/24 02:09:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo/dst': Waiting for transfers to finish
2025/01/24 02:09:04 DEBUG : one: md5 = ad70c3b1188fb0878f83bb8ca4a6872b OK
2025/01/24 02:09:04 INFO  : one: Copied (new)
2025/01/24 02:09:04 DEBUG : Waiting for deletions to finish
2025/01/24 02:09:05 INFO  : three.txt.bak: Deleted
2025/01/24 02:09:06 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/24 02:09:06 INFO  : three.txt: Moved into backup dir
2025/01/24 02:09:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/24 02:09:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/24 02:09:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/24 02:09:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/24 02:09:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/24 02:09:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncBackupDirSuffixOnly (22.95s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:09:13 DEBUG : dst/one: md5 = 55b56f7d4338d5a4a50bc8eb8514de8b OK
2025/01/24 02:09:14 DEBUG : dst/two: md5 = b39f131e1a51916cc19a14a586bb9cbb OK
2025/01/24 02:09:16 DEBUG : dst/three.txt: md5 = 9f43d38779deb5dcd4d2bae0e1631a3b OK
2025/01/24 02:09:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/dst"
2025/01/24 02:09:16 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/24 02:09:17 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/24 02:09:18 INFO  : one: Moved (server-side) to: one.bak
2025/01/24 02:09:20 DEBUG : one: md5 = 6cb33a9eb1b8d0218f6e46ba6b8f6ad7 OK
2025/01/24 02:09:20 INFO  : one: Copied (new)
2025/01/24 02:09:20 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:09:20 DEBUG : two: Unchanged skipping
2025/01/24 02:09:21 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/01/24 02:09:21 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/24 02:09:23 DEBUG : three.txt: md5 = 9b0353353e3411fa60a14ad888b744a0 OK
2025/01/24 02:09:23 INFO  : three.txt: Copied (new)
2025/01/24 02:09:24 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/24 02:09:25 INFO  : one.bak: Deleted
2025/01/24 02:09:26 INFO  : one: Moved (server-side) to: one.bak
2025/01/24 02:09:27 DEBUG : one: md5 = 653d3975ff26bfbe121796e89662d177 OK
2025/01/24 02:09:27 INFO  : one: Copied (new)
2025/01/24 02:09:27 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:09:27 DEBUG : two: Unchanged skipping
2025/01/24 02:09:28 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/01/24 02:09:28 INFO  : three.txt.bak: Deleted
2025/01/24 02:09:29 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/24 02:09:31 DEBUG : three.txt: md5 = 813ec81c282c1097330c96f70c80dc8c OK
2025/01/24 02:09:31 INFO  : three.txt: Copied (new)
2025/01/24 02:09:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/24 02:09:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/01/24 02:09:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/24 02:09:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/24 02:09:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/24 02:09:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/24 02:09:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncSuffix (25.91s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:09:39 DEBUG : dst/one: md5 = afea61a42366208340ff9d4af6cae16a OK
2025/01/24 02:09:40 DEBUG : dst/two: md5 = 3381a9cc1e638e2c5fed3209f0e6b2e6 OK
2025/01/24 02:09:42 DEBUG : dst/three.txt: md5 = 208004ca08bdecfa885e9a521dcc263b OK
2025/01/24 02:09:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-molibiw5valo/dst"
2025/01/24 02:09:43 DEBUG : Creating backend with remote "TestDrive:crypt/j7aft8navfojv1oul2tg5qj0efagn2l3lovgb1q5b6dnms6iqklg/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/24 02:09:44 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/24 02:09:44 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/01/24 02:09:46 DEBUG : one: md5 = b6ac285b984a810f6a06a4d07356422d OK
2025/01/24 02:09:46 INFO  : one: Copied (new)
2025/01/24 02:09:46 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:09:46 DEBUG : two: Unchanged skipping
2025/01/24 02:09:47 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/01/24 02:09:47 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/01/24 02:09:49 DEBUG : three.txt: md5 = d76dece95721bdfd8f98908c5342ede3 OK
2025/01/24 02:09:49 INFO  : three.txt: Copied (new)
2025/01/24 02:09:50 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/24 02:09:51 INFO  : one-2019-01-01: Deleted
2025/01/24 02:09:52 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/01/24 02:09:54 DEBUG : one: md5 = 85fb4b557b7941ae7e2b03d706475c78 OK
2025/01/24 02:09:54 INFO  : one: Copied (new)
2025/01/24 02:09:54 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:09:54 DEBUG : two: Unchanged skipping
2025/01/24 02:09:55 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/01/24 02:09:55 INFO  : three-2019-01-01.txt: Deleted
2025/01/24 02:09:56 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/01/24 02:09:58 DEBUG : three.txt: md5 = 3f47fb46d1e91ae771e8d2f983fffa1d OK
2025/01/24 02:09:58 INFO  : three.txt: Copied (new)
2025/01/24 02:10:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/01/24 02:10:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/24 02:10:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/01/24 02:10:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/24 02:10:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/01/24 02:10:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/01/24 02:10:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncSuffixKeepExtension (26.83s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:10:04 DEBUG : Testêé: md5 = 4815d6c2a3cc8903ea4cc1d1a5ed25b4 OK
2025/01/24 02:10:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:10:05 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2025/01/24 02:10:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:10:06 DEBUG : Testêé: md5 = 4cf202537274a3eb5c5399e161f93361 OK
2025/01/24 02:10:06 INFO  : Testêé: Copied (replaced existing) to: Testêé
2025/01/24 02:10:06 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (5.05s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:10:08 DEBUG : existing: Need to transfer - File not found at Destination
2025/01/24 02:10:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:10:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:10:10 DEBUG : existing: md5 = 66b77eb7033dd0f0c77e80c48aa2953d OK
2025/01/24 02:10:10 INFO  : existing: Copied (new)
2025/01/24 02:10:10 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:10:11 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2025/01/24 02:10:11 ERROR : existing: Source and destination exist but do not match: immutable file modified
2025/01/24 02:10:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:10:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:10:11 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': not deleting files as there were IO errors
2025/01/24 02:10:11 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncImmutable (5.27s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:10:15 DEBUG : EXISTING: md5 = c7de16845d5e0d65a33df9bc5ff927f1 OK
2025/01/24 02:10:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:10:15 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:10:15 DEBUG : existing: Unchanged skipping
2025/01/24 02:10:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:10:15 DEBUG : Waiting for deletions to finish
2025/01/24 02:10:15 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (3.42s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    sync_test.go:2635: Skipping test as local or remote are case-sensitive
--- SKIP: TestFixCase (0.47s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", 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-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", 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-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.37s)
    --- SKIP: TestMaxTransfer/Hard (0.46s)
    --- SKIP: TestMaxTransfer/Soft (0.43s)
    --- SKIP: TestMaxTransfer/Cautious (0.47s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:10:20 DEBUG : both0: md5 = 9412f9d84e826bd7f0f8647a350d4b59 OK
2025/01/24 02:10:22 DEBUG : only0: md5 = d92ceeabf59fdb1afb7257f18fcf32d4 OK
2025/01/24 02:10:23 DEBUG : both1: md5 = b4d90123a3947903b06ab66667141637 OK
2025/01/24 02:10:25 DEBUG : only1: md5 = e69275148a0d173a3da3244ba7cda32b OK
2025/01/24 02:10:27 DEBUG : both2: md5 = f51e66bfe4b1be4e8c2883cea4f66b78 OK
2025/01/24 02:10:28 DEBUG : only2: md5 = dc6c9a3f035ebc29eecaf7cc7f2cd9f7 OK
2025/01/24 02:10:30 DEBUG : both3: md5 = f591185a9bc9c325b1ee0d479a90a519 OK
2025/01/24 02:10:32 DEBUG : only3: md5 = 96a68f08718bdabe5d0a2015aa94da87 OK
2025/01/24 02:10:34 DEBUG : both4: md5 = daf338348d34292a53e19422b3989299 OK
2025/01/24 02:10:36 DEBUG : only4: md5 = f78407b7bcf5e04a1c7aea738ece1dfc OK
2025/01/24 02:10:37 DEBUG : both5: md5 = 2336590c6b498c8db7fc63c58fc15916 OK
2025/01/24 02:10:39 DEBUG : only5: md5 = 8c5bbb2d0d0d30a91291be1db207dfa5 OK
2025/01/24 02:10:41 DEBUG : both6: md5 = 19e5b6d6514c5c410a6d9acc462bbf98 OK
2025/01/24 02:10:42 DEBUG : only6: md5 = 37b98d7a62ce3e6947311c910ef9ea88 OK
2025/01/24 02:10:44 DEBUG : both7: md5 = 1757834b028b3fb7f09c82ec6f58599e OK
2025/01/24 02:10:46 DEBUG : only7: md5 = 89967df71771304544fa072f2d006e91 OK
2025/01/24 02:10:47 DEBUG : both8: md5 = 6c75689555fa8c5beefff90cf81c1dc2 OK
2025/01/24 02:10:49 DEBUG : only8: md5 = 2f405e0eee5fe06d5ee5ddb0227f3173 OK
2025/01/24 02:10:51 DEBUG : both9: md5 = bc4b1511179614c22521f8ee17bb635b OK
2025/01/24 02:10:52 DEBUG : only9: md5 = 426133bb7ee341d1953c8c638b451f43 OK
2025/01/24 02:10:54 DEBUG : both10: md5 = c84c60d6653f442b435a87b82bd37772 OK
2025/01/24 02:10:55 DEBUG : only10: md5 = bc5bdb886038b5e3b765c9e00cf326ba OK
2025/01/24 02:10:57 DEBUG : both11: md5 = 5a43e0214f681d4951f9768072f6da81 OK
2025/01/24 02:10:59 DEBUG : only11: md5 = 3d7218d0d8dbcf7b67376cb4142bd54f OK
2025/01/24 02:11:01 DEBUG : both12: md5 = 98a455875587024f3d47bd61e67169b2 OK
2025/01/24 02:11:03 DEBUG : only12: md5 = bc3674842993f6e2c0b3a8df71dda28c OK
2025/01/24 02:11:04 DEBUG : both13: md5 = 98a7e7027ddff5694d8193891c47506c OK
2025/01/24 02:11:06 DEBUG : only13: md5 = 49ce30c2f4aa5769e7e51f1b251b4689 OK
2025/01/24 02:11:08 DEBUG : both14: md5 = 5e460aa6b0fb20d8321919e1c2edce05 OK
2025/01/24 02:11:10 DEBUG : only14: md5 = 1a910ecab1c4238a4da5f6064523ee27 OK
2025/01/24 02:11:11 DEBUG : both15: md5 = 23f5e326b9b2e4695c27c02dc1616a9d OK
2025/01/24 02:11:13 DEBUG : only15: md5 = 14dd8e3bfcce25f2227889159d5bea35 OK
2025/01/24 02:11:15 DEBUG : both16: md5 = 7c9f0c441da1cfb58bd2fb259216c47d OK
2025/01/24 02:11:17 DEBUG : only16: md5 = fd31aba2e57e9d59cb5eda536fbcc3a9 OK
2025/01/24 02:11:19 DEBUG : both17: md5 = b00cf869d1bcf57abf5f16d1180962f6 OK
2025/01/24 02:11:20 DEBUG : only17: md5 = 7963f6acf3e22650fd64be6416d1a498 OK
2025/01/24 02:11:22 DEBUG : both18: md5 = aaeecd6bfed23021e240a3a5f3443796 OK
2025/01/24 02:11:23 DEBUG : only18: md5 = 4d10453ad32b31af01f2914619d5d0e2 OK
2025/01/24 02:11:25 DEBUG : both19: md5 = cc2a3083917ccd5319bad78ca7160999 OK
2025/01/24 02:11:27 DEBUG : only19: md5 = a8df0544c232feed17e721a7ce53d4a8 OK
2025/01/24 02:11:27 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:11:27 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:11:27 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:11:27 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:11:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:11:27 DEBUG : both0: Unchanged skipping
2025/01/24 02:11:27 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:11:27 DEBUG : both12: Unchanged skipping
2025/01/24 02:11:27 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:11:27 DEBUG : both13: Unchanged skipping
2025/01/24 02:11:27 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:11:27 DEBUG : both14: Unchanged skipping
2025/01/24 02:11:27 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:11:27 DEBUG : both15: Unchanged skipping
2025/01/24 02:11:27 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:11:27 DEBUG : both1: Unchanged skipping
2025/01/24 02:11:27 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:11:27 DEBUG : both17: Unchanged skipping
2025/01/24 02:11:27 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:11:27 DEBUG : both18: Unchanged skipping
2025/01/24 02:11:27 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:11:27 DEBUG : both19: Unchanged skipping
2025/01/24 02:11:27 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:11:27 DEBUG : both2: Unchanged skipping
2025/01/24 02:11:27 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:11:27 DEBUG : both10: Unchanged skipping
2025/01/24 02:11:27 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:11:27 DEBUG : both16: Unchanged skipping
2025/01/24 02:11:27 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:11:27 DEBUG : both5: Unchanged skipping
2025/01/24 02:11:27 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:11:27 DEBUG : both11: Unchanged skipping
2025/01/24 02:11:27 DEBUG : both6: Unchanged skipping
2025/01/24 02:11:27 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:11:27 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:11:27 DEBUG : both4: Unchanged skipping
2025/01/24 02:11:27 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:11:27 DEBUG : both3: Unchanged skipping
2025/01/24 02:11:27 DEBUG : both8: Unchanged skipping
2025/01/24 02:11:27 DEBUG : both7: Unchanged skipping
2025/01/24 02:11:27 DEBUG : both9: Unchanged skipping
2025/01/24 02:11:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:11:27 DEBUG : Waiting for deletions to finish
2025/01/24 02:11:28 INFO  : only8: Deleted
2025/01/24 02:11:28 INFO  : only10: Deleted
2025/01/24 02:11:28 INFO  : only7: Deleted
2025/01/24 02:11:28 INFO  : only12: Deleted
2025/01/24 02:11:28 INFO  : only5: Deleted
2025/01/24 02:11:28 INFO  : only18: Deleted
2025/01/24 02:11:29 INFO  : only6: Deleted
2025/01/24 02:11:29 INFO  : only16: Deleted
2025/01/24 02:11:29 INFO  : only1: Deleted
2025/01/24 02:11:29 INFO  : only0: Deleted
2025/01/24 02:11:29 INFO  : only19: Deleted
2025/01/24 02:11:29 INFO  : only2: Deleted
2025/01/24 02:11:30 INFO  : only4: Deleted
2025/01/24 02:11:30 INFO  : only14: Deleted
2025/01/24 02:11:30 INFO  : only11: Deleted
2025/01/24 02:11:30 INFO  : only15: Deleted
2025/01/24 02:11:30 INFO  : only13: Deleted
2025/01/24 02:11:30 INFO  : only17: Deleted
2025/01/24 02:11:30 INFO  : only3: Deleted
2025/01/24 02:11:30 INFO  : only9: Deleted
2025/01/24 02:11:30 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (85.18s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:11:45 DEBUG : both0: md5 = b0342cfeba930280a282d14ee320ffb7 OK
2025/01/24 02:11:47 DEBUG : only0: md5 = c741fa6e73ec8e3abbc7f3d94cdb93cd OK
2025/01/24 02:11:48 DEBUG : both1: md5 = 76914dae26eb1523eb40fc8654300846 OK
2025/01/24 02:11:50 DEBUG : only1: md5 = d92a44063443badc07d0885630b0121f OK
2025/01/24 02:11:52 DEBUG : both2: md5 = ae45a03b79379b5de9f3284343533d99 OK
2025/01/24 02:11:53 DEBUG : only2: md5 = 756434493526e80e468c3eb64ca3541d OK
2025/01/24 02:11:55 DEBUG : both3: md5 = 27e13ff313db07181fbcdf5025962e00 OK
2025/01/24 02:11:57 DEBUG : only3: md5 = f2ec2e3e00726e217835e57d9867d0ce OK
2025/01/24 02:11:58 DEBUG : both4: md5 = 60db66c1fe46a7fe2c26cbda65974708 OK
2025/01/24 02:12:00 DEBUG : only4: md5 = f87f83fb7fb15a2e76cb4de9ae4cfc5a OK
2025/01/24 02:12:02 DEBUG : both5: md5 = ddbaa08c80f486aecd07665ce9ce6cea OK
2025/01/24 02:12:03 DEBUG : only5: md5 = b1afc594a929980ce6469eb9d369d026 OK
2025/01/24 02:12:05 DEBUG : both6: md5 = 532d424caa99aefbe4b78fe2c27a2ae4 OK
2025/01/24 02:12:06 DEBUG : only6: md5 = be6da03c25297ffb0b354c5f894d28ec OK
2025/01/24 02:12:08 DEBUG : both7: md5 = 2dc811a7b7fa12c61b71e8c8f494fd8b OK
2025/01/24 02:12:10 DEBUG : only7: md5 = b801fb615b87805d98013e8baf9132ed OK
2025/01/24 02:12:11 DEBUG : both8: md5 = fe22103d2319e22eda63b8ee15aecbb5 OK
2025/01/24 02:12:13 DEBUG : only8: md5 = e0562c38f1c747433f928c81dc63f923 OK
2025/01/24 02:12:15 DEBUG : both9: md5 = 81256e283938e910705bcffb64a192b2 OK
2025/01/24 02:12:16 DEBUG : only9: md5 = 990ece5e2af82a7af6a8c8f412845970 OK
2025/01/24 02:12:18 DEBUG : both10: md5 = 7d18520d7e16de07bf2acf300922d54d OK
2025/01/24 02:12:20 DEBUG : only10: md5 = f75c93a9ea387b3fc005082313fdc18d OK
2025/01/24 02:12:21 DEBUG : both11: md5 = de01636452c687cd6f7d71650c145c66 OK
2025/01/24 02:12:23 DEBUG : only11: md5 = 4beca9708a257c864c4b889a3a36fc6d OK
2025/01/24 02:12:25 DEBUG : both12: md5 = cb39849234d9533b496d282cc9d0b6d0 OK
2025/01/24 02:12:27 DEBUG : only12: md5 = d23d00a450d47085aa94065aff5ec55c OK
2025/01/24 02:12:29 DEBUG : both13: md5 = 1e6e5bb3bd4fc487277fb038e345f3be OK
2025/01/24 02:12:30 DEBUG : only13: md5 = a4f7cc2c4385f4f27ff9522114992e86 OK
2025/01/24 02:12:32 DEBUG : both14: md5 = 5c877ff2ec24d3f78b4158e75818a039 OK
2025/01/24 02:12:34 DEBUG : only14: md5 = e06632fcec88e1a2144c8f5846a69fad OK
2025/01/24 02:12:35 DEBUG : both15: md5 = 4510de1bc2f03f1568116ac651dce9ab OK
2025/01/24 02:12:37 DEBUG : only15: md5 = b400da9b1858ddce35c543ef320431a7 OK
2025/01/24 02:12:39 DEBUG : both16: md5 = ac5dd9fe3e52ea6daf55666e9bfeeb60 OK
2025/01/24 02:12:41 DEBUG : only16: md5 = 20dae44ed91e503db43e2fef1ef967c2 OK
2025/01/24 02:12:42 DEBUG : both17: md5 = 2d997f09ee4cac56600ebc962a01a992 OK
2025/01/24 02:12:44 DEBUG : only17: md5 = b2806eb7d9a47e9ad8686a157fa775bb OK
2025/01/24 02:12:46 DEBUG : both18: md5 = d2473495f0176bf03380681c5bf36922 OK
2025/01/24 02:12:47 DEBUG : only18: md5 = b58f0c28c327a06865cd0dd30e3e6c98 OK
2025/01/24 02:12:49 DEBUG : both19: md5 = 663812a159fe669c6e0115c13a7e0108 OK
2025/01/24 02:12:51 DEBUG : only19: md5 = ba29b43a14b4356bc5d518179f64d1b4 OK
2025/01/24 02:12:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for checks to finish
2025/01/24 02:12:51 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:12:51 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:12:51 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:12:51 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:12:51 DEBUG : both1: Unchanged skipping
2025/01/24 02:12:51 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:12:51 DEBUG : both11: Unchanged skipping
2025/01/24 02:12:51 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:12:51 DEBUG : both12: Unchanged skipping
2025/01/24 02:12:51 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:12:51 DEBUG : both10: Unchanged skipping
2025/01/24 02:12:51 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:12:51 DEBUG : both0: Unchanged skipping
2025/01/24 02:12:51 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:12:51 DEBUG : both16: Unchanged skipping
2025/01/24 02:12:51 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:12:51 DEBUG : both17: Unchanged skipping
2025/01/24 02:12:51 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:12:51 DEBUG : both18: Unchanged skipping
2025/01/24 02:12:51 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:12:51 DEBUG : both19: Unchanged skipping
2025/01/24 02:12:51 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:12:51 DEBUG : both13: Unchanged skipping
2025/01/24 02:12:51 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:12:51 DEBUG : both14: Unchanged skipping
2025/01/24 02:12:51 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:12:51 DEBUG : both4: Unchanged skipping
2025/01/24 02:12:51 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:12:51 DEBUG : both15: Unchanged skipping
2025/01/24 02:12:51 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:12:51 DEBUG : both6: Unchanged skipping
2025/01/24 02:12:51 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:12:51 DEBUG : both2: Unchanged skipping
2025/01/24 02:12:51 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:12:51 DEBUG : both8: Unchanged skipping
2025/01/24 02:12:51 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/24 02:12:51 DEBUG : both3: Unchanged skipping
2025/01/24 02:12:51 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2025/01/24 02:12:51 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2025/01/24 02:12:51 DEBUG : both5: Unchanged skipping
2025/01/24 02:12:51 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2025/01/24 02:12:51 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2025/01/24 02:12:51 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2025/01/24 02:12:51 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2025/01/24 02:12:51 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2025/01/24 02:12:51 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2025/01/24 02:12:51 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2025/01/24 02:12:51 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2025/01/24 02:12:51 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2025/01/24 02:12:51 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2025/01/24 02:12:51 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2025/01/24 02:12:51 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2025/01/24 02:12:51 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2025/01/24 02:12:51 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2025/01/24 02:12:51 DEBUG : both7: Unchanged skipping
2025/01/24 02:12:51 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2025/01/24 02:12:51 DEBUG : both9: Unchanged skipping
2025/01/24 02:12:51 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2025/01/24 02:12:51 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2025/01/24 02:12:51 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2025/01/24 02:12:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Waiting for transfers to finish
2025/01/24 02:12:53 DEBUG : only0: md5 = c1554e637aaaf437197c7d0947fe6cac OK
2025/01/24 02:12:53 INFO  : only0: Copied (replaced existing)
2025/01/24 02:12:53 DEBUG : only10: md5 = 50393b4af6d008248b12831812773194 OK
2025/01/24 02:12:53 INFO  : only10: Copied (replaced existing)
2025/01/24 02:12:53 DEBUG : only12: md5 = 560b35467a5d1f05bdd647eaf093ec67 OK
2025/01/24 02:12:53 INFO  : only12: Copied (replaced existing)
2025/01/24 02:12:53 DEBUG : only11: md5 = 7b0999f700a86051f3bcdf83129986b2 OK
2025/01/24 02:12:53 INFO  : only11: Copied (replaced existing)
2025/01/24 02:12:54 DEBUG : only14: md5 = 66d98e8307356787d41273dd733a7a29 OK
2025/01/24 02:12:54 INFO  : only14: Copied (replaced existing)
2025/01/24 02:12:54 DEBUG : only13: md5 = c43d55124ca002bf15da2b40725a5447 OK
2025/01/24 02:12:54 INFO  : only13: Copied (replaced existing)
2025/01/24 02:12:54 DEBUG : only16: md5 = 1eea95d3e04620b215abe7ea9e470f67 OK
2025/01/24 02:12:54 INFO  : only16: Copied (replaced existing)
2025/01/24 02:12:54 DEBUG : only15: md5 = 213496801e6c3193e816c2858ec4ad44 OK
2025/01/24 02:12:54 INFO  : only15: Copied (replaced existing)
2025/01/24 02:12:55 DEBUG : only17: md5 = 02cbe2e7c7577b22c7a19014fdbc55f8 OK
2025/01/24 02:12:55 INFO  : only17: Copied (replaced existing)
2025/01/24 02:12:55 DEBUG : only18: md5 = ee356eecc74699bb56a93cf0f5ff85b2 OK
2025/01/24 02:12:55 INFO  : only18: Copied (replaced existing)
2025/01/24 02:12:55 DEBUG : only2: md5 = b3cbbf8e887a4532465defdaf1b44c9c OK
2025/01/24 02:12:55 INFO  : only2: Copied (replaced existing)
2025/01/24 02:12:55 DEBUG : only19: md5 = 9aef064e03e6d37a4ad8efa7797f2d9a OK
2025/01/24 02:12:55 INFO  : only19: Copied (replaced existing)
2025/01/24 02:12:56 DEBUG : only3: md5 = cece88e46b763af2e9c2dbaae1414db8 OK
2025/01/24 02:12:56 INFO  : only3: Copied (replaced existing)
2025/01/24 02:12:57 DEBUG : only4: md5 = b1c98aa293ed5101cce1b4f7ce64e96e OK
2025/01/24 02:12:57 INFO  : only4: Copied (replaced existing)
2025/01/24 02:12:57 DEBUG : only1: md5 = 6e6c70c23d704887404fd7f4548d6f53 OK
2025/01/24 02:12:57 INFO  : only1: Copied (replaced existing)
2025/01/24 02:12:57 DEBUG : only8: md5 = 4287f2b74146baec437530dd70a73014 OK
2025/01/24 02:12:57 INFO  : only8: Copied (replaced existing)
2025/01/24 02:12:58 DEBUG : only6: md5 = ccc52f699c6899efbbf7652dfd0453b9 OK
2025/01/24 02:12:58 INFO  : only6: Copied (replaced existing)
2025/01/24 02:12:58 DEBUG : only9: md5 = 4305412682a384537604ddedc7801bf0 OK
2025/01/24 02:12:58 INFO  : only9: Copied (replaced existing)
2025/01/24 02:12:58 DEBUG : only5: md5 = 04627c030955be4f1429063dc2eeb2dc OK
2025/01/24 02:12:58 INFO  : only5: Copied (replaced existing)
2025/01/24 02:12:58 DEBUG : only7: md5 = 7b1ff20d2cfad9afdcb6fef3fbea2071 OK
2025/01/24 02:12:58 INFO  : only7: Copied (replaced existing)
2025/01/24 02:12:58 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (99.58s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:13:23 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/24 02:13:23 DEBUG : sub dir: Making directory with metadata
2025/01/24 02:13:24 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:13:44 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/24 02:13:44 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/24 02:13:44 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/24 02:13:44 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:13:58 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2025/01/24 02:13:59 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/24 02:13:59 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2025/01/24 02:14:00 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2025/01/24 02:14:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/24 02:14:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/24 02:14:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/24 02:14:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/24 02:14:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/24 02:14:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2025/01/24 02:14:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/24 02:14:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (45.72s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:14:09 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/24 02:14:09 DEBUG : sub dir: Making directory with metadata
2025/01/24 02:14:10 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:14:34 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/24 02:14:35 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/24 02:14:35 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/24 02:14:35 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo'", Local "Local file system at /tmp/rclone3053794225", Modify Window "1ms"
2025/01/24 02:14:47 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/24 02:14:48 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2025/01/24 02:14:49 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2025/01/24 02:14:49 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/24 02:14:50 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/24 02:14:51 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/24 02:14:52 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/24 02:14:53 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/24 02:14:54 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2025/01/24 02:14:54 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/24 02:14:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (48.11s)
PASS
2025/01/24 02:14:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-molibiw5valo': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 17m55.87312137s (try 1/5)