"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5)
2024/11/28 01:39:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki"
2024/11/28 01:39:53 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2024/11/28 01:39:53 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg"
2024/11/28 01:39:54 DEBUG : Creating backend with remote "/tmp/rclone3020861414"
=== 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-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:39:56 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 01:39:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 01:39:56 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2024/11/28 01:39:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:39:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:39:56 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (2.89s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:39:57 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 01:39:57 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 01:39:57 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 01:39:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:39:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:40:00 DEBUG : sub dir/hello world: md5 = b2d638b2ce1c242bb694d49420ff821e OK
2024/11/28 01:40:00 INFO  : sub dir/hello world: Copied (new)
2024/11/28 01:40:01 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:40:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (7.92s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:40:05 DEBUG : metadata sub dir: Making directory with metadata
2024/11/28 01:40:05 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 01:40:05 DEBUG : empty metadata sub dir: Making directory with metadata
2024/11/28 01:40:05 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 01:40:05 DEBUG : Local file system at /tmp/rclone3020861414: File to upload is small (21 bytes), uploading instead of streaming
2024/11/28 01:40:05 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/11/28 01:40:05 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/11/28 01:40:05 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 01:40:05 DEBUG : Google drive root 'crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg': Skipping btime metadata as can't update it on an existing file: 2024-11-28T01:40:05.408557754Z
2024/11/28 01:40:06 INFO  : empty metadata sub dir: Updated directory metadata
2024/11/28 01:40:07 DEBUG : Google drive root 'crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg': Skipping btime metadata as can't update it on an existing file: 2024-11-28T01:40:05.408557754Z
2024/11/28 01:40:07 INFO  : metadata sub dir: Updated directory metadata
2024/11/28 01:40:07 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/11/28 01:40:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:40:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:40:09 DEBUG : metadata sub dir/hello metadata world: md5 = 1afb87a58e508a1480fb9966feb498a7 OK
2024/11/28 01:40:09 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:40:12 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (9.93s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:40:15 DEBUG : metadata sub dir: Making directory with metadata
2024/11/28 01:40:15 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 01:40:15 DEBUG : empty metadata sub dir: Making directory with metadata
2024/11/28 01:40:15 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 01:40:15 DEBUG : Local file system at /tmp/rclone3020861414: File to upload is small (21 bytes), uploading instead of streaming
2024/11/28 01:40:15 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/11/28 01:40:15 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/11/28 01:40:15 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 01:40:15 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2024/11/28 01:40:15 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2024/11/28 01:40:15 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/11/28 01:40:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:40:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:40:18 DEBUG : metadata sub dir/hello metadata world: md5 = 2cc5c140f025bd1ec9293d6ab3b18a3d OK
2024/11/28 01:40:18 INFO  : metadata sub dir/hello metadata world: Copied (new)
2024/11/28 01:40:18 DEBUG : Google drive root 'crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg': Skipping btime metadata as can't update it on an existing file: 2024-11-28T01:40:15.340488143Z
2024/11/28 01:40:19 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:40:22 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (8.53s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:40:23 DEBUG : Creating backend with remote "/non-existing"
2024/11/28 01:40:24 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2024/11/28 01:40:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:40:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.16s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:40:25 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 01:40:25 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 01:40:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:40:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:40:28 DEBUG : sub dir/hello world: md5 = 77a43481f58373eea345c3efcd5dab94 OK
2024/11/28 01:40:28 INFO  : sub dir/hello world: Copied (new)
2024/11/28 01:40:28 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:40:30 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (7.21s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:40:32 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Running all checks before starting transfers
2024/11/28 01:40:32 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 01:40:32 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 01:40:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:40:32 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Checks finished, now starting transfers
2024/11/28 01:40:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:40:35 DEBUG : sub dir/hello world: md5 = 49629db21f0cb6184c5c30208970140e OK
2024/11/28 01:40:35 INFO  : sub dir/hello world: Copied (new)
2024/11/28 01:40:36 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:40:38 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (7.42s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:40:39 ERROR : Ignoring --no-traverse with sync
2024/11/28 01:40:39 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 01:40:39 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 01:40:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:40:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:40:42 DEBUG : sub dir/hello world: md5 = 46fc5e64e47c82597db006de9d8b18a8 OK
2024/11/28 01:40:42 INFO  : sub dir/hello world: Copied (new)
2024/11/28 01:40:42 DEBUG : Waiting for deletions to finish
2024/11/28 01:40:43 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:40:45 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (7.29s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:40:47 DEBUG : hello world2: Need to transfer - File not found at Destination
2024/11/28 01:40:47 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 01:40:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:40:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:40:48 DEBUG : hello world2: md5 = 3d7dc9e19a4b68e2cc885f7d71595191 OK
2024/11/28 01:40:48 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestCopyWithDepth (3.84s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:40:51 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 01:40:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:40:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:40:52 DEBUG : potato2: md5 = 783ad3e01ebad374819906b6544903c3 OK
2024/11/28 01:40:52 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (3.84s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:40:54 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 01:40:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:40:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:40:56 DEBUG : potato2: md5 = 95a660e671b70a86d2deae2fe826cc6f OK
2024/11/28 01:40:56 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (3.99s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:40:58 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/28 01:40:58 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 01:40:58 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/28 01:40:58 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 01:40:58 DEBUG : sub dir: Making directory with metadata
2024/11/28 01:40:59 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/28 01:40:59 DEBUG : sub dir2: Making directory with metadata
2024/11/28 01:41:01 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 01:41:01 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 01:41:01 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/28 01:41:02 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 01:41:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:41:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:41:03 DEBUG : sub dir/hello world: md5 = 59b4b01768a848c2ebf07218e00ce47d OK
2024/11/28 01:41:03 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:41:07 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2024/11/28 01:41:08 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (11.23s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:41:09 DEBUG : sub dir2: Making directory
2024/11/28 01:41:09 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/11/28 01:41:09 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 01:41:10 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 01:41:10 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/28 01:41:10 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2024/11/28 01:41:10 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 01:41:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:41:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:41:13 DEBUG : sub dir/hello world: md5 = da068a71d6c9f35b23e6f86ea37dabde OK
2024/11/28 01:41:13 INFO  : sub dir/hello world: Copied (new)
2024/11/28 01:41:13 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 01:41:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (7.02s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:41:16 DEBUG : sub dir2: Making directory with metadata
2024/11/28 01:41:16 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 01:41:17 DEBUG : sub dir: Making directory with metadata
2024/11/28 01:41:18 INFO  : sub dir: Made directory with metadata (mtime=2024-11-28T01:41:16.868057364Z)
2024/11/28 01:41:18 DEBUG : sub dir2: Making directory with metadata
2024/11/28 01:41:19 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 01:41:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 01:41:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:41:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:41:21 DEBUG : sub dir/hello world: md5 = 5a77d29e571900e9dde9d89c8ba76edb OK
2024/11/28 01:41:21 INFO  : sub dir/hello world: Copied (new)
2024/11/28 01:41:21 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:41:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (9.53s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:41:26 DEBUG : sub dir no update dir modtime: Making directory with metadata
2024/11/28 01:41:26 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/28 01:41:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:41:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:41:28 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (5.19s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:41:31 DEBUG : sub dir2: Making directory
2024/11/28 01:41:31 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 01:41:31 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/28 01:41:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 01:41:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:41:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:41:34 DEBUG : sub dir/hello world: md5 = 6a85dfcd138b4bda91f4893fb2ccd6b2 OK
2024/11/28 01:41:34 INFO  : sub dir/hello world: Copied (new)
2024/11/28 01:41:34 INFO  : sub dir/hello world: Deleted
2024/11/28 01:41:35 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 01:41:37 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (7.26s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:41:38 DEBUG : sub dir2: Making directory with metadata
2024/11/28 01:41:38 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 01:41:38 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 01:41:39 DEBUG : sub dir: Making directory with metadata
2024/11/28 01:41:40 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/11/28 01:41:40 DEBUG : sub dir2: Making directory with metadata
2024/11/28 01:41:41 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 01:41:41 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 01:41:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:41:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:41:43 DEBUG : sub dir/hello world: md5 = 50fc48139899e3f2a1524f00609b1343 OK
2024/11/28 01:41:43 INFO  : sub dir/hello world: Copied (new)
2024/11/28 01:41:43 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:41:47 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (9.60s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.59s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:41:49 DEBUG : sub dir2: Making directory
2024/11/28 01:41:49 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 01:41:49 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/11/28 01:41:49 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 01:41:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:41:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:41:51 DEBUG : sub dir/hello world: md5 = bb3cb15ba5d6b196ba88eefe6a720a61 OK
2024/11/28 01:41:51 INFO  : sub dir/hello world: Copied (new)
2024/11/28 01:41:51 DEBUG : Waiting for deletions to finish
2024/11/28 01:41:52 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 01:41:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (6.44s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:41:58 DEBUG : sub dir/hello world: md5 = b584c18798ad12d574d24110671a7ede OK
2024/11/28 01:41:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dabizuh2lode"
2024/11/28 01:41:58 DEBUG : Creating backend with remote "TestDrive:crypt/rgpjmp0b8qufudvmrv3ofhhtrfqpqj22eot6jjas4pnna0u838hg"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki' -> Encrypted drive 'TestCryptDrive:rclone-test-dabizuh2lode'
2024/11/28 01:42:00 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 01:42:00 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 01:42:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dabizuh2lode': Waiting for checks to finish
2024/11/28 01:42:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dabizuh2lode': Waiting for transfers to finish
2024/11/28 01:42:03 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/28 01:42:05 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:42:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dabizuh2lode': Purge remote
2024/11/28 01:42:08 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (14.13s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:42:12 DEBUG : sub dir/hello world: md5 = e75e9bfca9546abfd9d9111064fb118c OK
2024/11/28 01:42:13 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/28 01:42:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:42:13 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/28 01:42:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:42:15 DEBUG : sub dir/hello world: md5 = 98e45f96d05af0dc17c2dc8fe9098048 OK
2024/11/28 01:42:15 INFO  : sub dir/hello world: Copied (replaced existing)
2024/11/28 01:42:15 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:42:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (9.54s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:42:22 DEBUG : sub dir/hello world: md5 = 44c389595ae16b3ecd1c6bf7d7e4e7e0 OK
2024/11/28 01:42:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zexiviy6woma"
2024/11/28 01:42:22 DEBUG : Creating backend with remote "TestDrive:crypt/e1d6vfpng6v64f51nfgsruvjpd4ondhvi94fio0rr0b6n9v9uddg"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki' -> Encrypted drive 'TestCryptDrive:rclone-test-zexiviy6woma'
2024/11/28 01:42:24 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 01:42:24 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 01:42:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zexiviy6woma': Waiting for checks to finish
2024/11/28 01:42:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zexiviy6woma': Waiting for transfers to finish
2024/11/28 01:42:27 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/28 01:42:28 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:42:30 DEBUG : sub dir/hello world: md5 = d826d8c7fde2d71864bda8e9b0abbe40 OK
2024/11/28 01:42:31 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/28 01:42:31 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/28 01:42:31 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/28 01:42:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zexiviy6woma': Waiting for checks to finish
2024/11/28 01:42:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zexiviy6woma': Waiting for transfers to finish
2024/11/28 01:42:33 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/28 01:42:34 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:42:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zexiviy6woma': Purge remote
2024/11/28 01:42:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (19.49s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:42:41 DEBUG : sub dir/hello world: md5 = f8c5f0e9b752a41cabe87b6b58b5ad5c OK
2024/11/28 01:42:42 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/28 01:42:42 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/28 01:42:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:42:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:42:43 DEBUG : sub dir/hello world: md5 = 2388f2bddfa8b2bde95ca175a6859c93 OK
2024/11/28 01:42:43 INFO  : sub dir/hello world: Copied (replaced existing)
2024/11/28 01:42:43 INFO  : sub dir/hello world: Deleted
2024/11/28 01:42:44 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:42:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (9.46s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:42:50 DEBUG : sub dir/hello world: md5 = a57fd1973df7ca3d6e319ea037e0267b OK
2024/11/28 01:42:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beneyiq8dada"
2024/11/28 01:42:51 DEBUG : Creating backend with remote "TestDrive:crypt/sa8gp6gd8rf1huh86m9ut75baiaasghhdlltb0dfadl2cmkjek00"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki' -> Encrypted drive 'TestCryptDrive:rclone-test-beneyiq8dada'
2024/11/28 01:42:53 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 01:42:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 01:42:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beneyiq8dada': Waiting for checks to finish
2024/11/28 01:42:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beneyiq8dada': Waiting for transfers to finish
2024/11/28 01:42:56 INFO  : sub dir/hello world: Copied (server-side copy)
2024/11/28 01:42:57 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:42:59 DEBUG : sub dir/hello world: md5 = 23af16e14b70a4562d1a031ef734b933 OK
2024/11/28 01:43:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beneyiq8dada': Using server-side directory move
2024/11/28 01:43:00 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-beneyiq8dada': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/28 01:43:00 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/28 01:43:00 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/28 01:43:00 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/11/28 01:43:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beneyiq8dada': Waiting for checks to finish
2024/11/28 01:43:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beneyiq8dada': Waiting for transfers to finish
2024/11/28 01:43:01 INFO  : sub dir/hello world: Deleted
2024/11/28 01:43:02 INFO  : sub dir/hello world: Moved (server-side)
2024/11/28 01:43:03 INFO  : sub dir: Set directory modification time (using SetModTime)
2024/11/28 01:43:05 DEBUG : sub dir/hello world: md5 = da85f5baf5f1e87cece912aa82f965a5 OK
2024/11/28 01:43:06 DEBUG : testing file moves
2024/11/28 01:43:06 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/11/28 01:43:06 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/11/28 01:43:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beneyiq8dada': Waiting for checks to finish
2024/11/28 01:43:06 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2024/11/28 01:43:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beneyiq8dada': Waiting for transfers to finish
2024/11/28 01:43:07 INFO  : sub dir/hello world: Deleted
2024/11/28 01:43:08 INFO  : sub dir/hello world: Moved (server-side)
2024/11/28 01:43:08 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:43:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beneyiq8dada': Purge remote
--- PASS: TestServerSideMoveOverSelf (24.99s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:43:16 DEBUG : sub dir/hello world: md5 = 811302a45d38b94d41ef1003002be348 OK
2024/11/28 01:43:16 ERROR : : error listing: directory not found
2024/11/28 01:43:16 DEBUG : Local file system at /tmp/rclone3020861414: Making directory
2024/11/28 01:43:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:43:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:43:19 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (7.31s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:43:23 DEBUG : sub dir/hello world: md5 = 652681ab2703df727b51283de2d7838a OK
2024/11/28 01:43:24 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 01:43:24 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 01:43:24 DEBUG : Local file system at /tmp/rclone3020861414: Waiting for checks to finish
2024/11/28 01:43:24 DEBUG : Local file system at /tmp/rclone3020861414: Waiting for transfers to finish
2024/11/28 01:43:25 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2024/11/28 01:43:25 INFO  : sub dir/hello world: Copied (new)
2024/11/28 01:43:25 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:43:27 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (8.18s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:43:28 DEBUG : check sum: Need to transfer - File not found at Destination
2024/11/28 01:43:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:43:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:43:30 DEBUG : check sum: md5 = 212ef54de64a1133b01231d91ffc99ae OK
2024/11/28 01:43:30 INFO  : check sum: Copied (new)
2024/11/28 01:43:30 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:43:31 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2024/11/28 01:43:31 DEBUG : check sum: Size of src and dst objects identical
2024/11/28 01:43:31 DEBUG : check sum: Unchanged skipping
2024/11/28 01:43:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:43:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:43:31 DEBUG : Waiting for deletions to finish
2024/11/28 01:43:31 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (5.14s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:43:33 DEBUG : sizeonly: Need to transfer - File not found at Destination
2024/11/28 01:43:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:43:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:43:35 DEBUG : sizeonly: md5 = 6bc6b2b8c62b036dace4a5f5cb186474 OK
2024/11/28 01:43:35 INFO  : sizeonly: Copied (new)
2024/11/28 01:43:35 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:43:36 DEBUG : sizeonly: Sizes identical
2024/11/28 01:43:36 DEBUG : sizeonly: Unchanged skipping
2024/11/28 01:43:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:43:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:43:36 DEBUG : Waiting for deletions to finish
2024/11/28 01:43:36 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (4.78s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:43:38 DEBUG : ignore-size: Need to transfer - File not found at Destination
2024/11/28 01:43:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:43:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:43:40 DEBUG : ignore-size: md5 = 8a69e166227c042cf124c65ba6eef00c OK
2024/11/28 01:43:40 INFO  : ignore-size: Copied (new)
2024/11/28 01:43:40 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:43:41 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:43:41 DEBUG : ignore-size: Unchanged skipping
2024/11/28 01:43:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:43:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:43:41 DEBUG : Waiting for deletions to finish
2024/11/28 01:43:41 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (4.93s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:43:45 DEBUG : existing: md5 = 22751114b5762850b744dc22291ac045 OK
2024/11/28 01:43:45 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:43:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:43:45 DEBUG : existing: Unchanged skipping
2024/11/28 01:43:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:43:45 DEBUG : Waiting for deletions to finish
2024/11/28 01:43:45 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:43:45 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2024/11/28 01:43:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:43:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:43:47 DEBUG : existing: md5 = 9e1d9c22f8a4b68a32aa991b27fba313 OK
2024/11/28 01:43:47 INFO  : existing: Copied (replaced existing)
2024/11/28 01:43:47 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (6.12s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:43:49 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/28 01:43:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:43:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:43:51 DEBUG : existing: md5 = 2f49f0b0188bbbc91d841d1ce48b43b6 OK
2024/11/28 01:43:51 INFO  : existing: Copied (new)
2024/11/28 01:43:51 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:43:51 DEBUG : existing: Destination exists, skipping
2024/11/28 01:43:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:43:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:43:51 DEBUG : Waiting for deletions to finish
2024/11/28 01:43:51 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (4.58s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:43:57 DEBUG : b/potato: md5 = 288329a8c503350786f46e572b487dae OK
2024/11/28 01:44:00 DEBUG : c/non empty space: md5 = 25e4ca53e11009865e96db22e8773218 OK
2024/11/28 01:44:00 DEBUG : d: Making directory
2024/11/28 01:44:02 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/28 01:44:02 DEBUG : Added delayed dir = "c", newDst=c
2024/11/28 01:44:02 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:44:02 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/28 01:44:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:44:02 DEBUG : c/non empty space: Unchanged skipping
2024/11/28 01:44:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:44:05 DEBUG : a/potato2: md5 = 423d7acbe90a9f04c6e214b2c6a8e7ec OK
2024/11/28 01:44:05 INFO  : a/potato2: Copied (new)
2024/11/28 01:44:05 DEBUG : Waiting for deletions to finish
2024/11/28 01:44:06 INFO  : b/potato: Deleted
2024/11/28 01:44:06 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/28 01:44:06 INFO  : d: Removing directory
2024/11/28 01:44:07 INFO  : b: Removing directory
2024/11/28 01:44:07 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/28 01:44:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:44:11 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/28 01:44:12 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (19.43s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:44:15 DEBUG : empty space: md5 = 05ff503ddf2202b8e88cfabc9ad52b91 OK
2024/11/28 01:44:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:44:15 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2024/11/28 01:44:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:44:15 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2024/11/28 01:44:15 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:44:16 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2024/11/28 01:44:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:44:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:44:17 DEBUG : empty space: md5 = e061867b91cda586364eab56998e7e2c OK
2024/11/28 01:44:17 INFO  : empty space: Copied (replaced existing)
2024/11/28 01:44:17 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (6.42s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.48s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:44:22 DEBUG : foo: md5 = 6b7abed5b66478b0d23da5d7c96c5f11 OK
2024/11/28 01:44:22 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2024/11/28 01:44:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:44:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:44:24 DEBUG : foo: md5 = 1c1bdbcf5aadd15a35e20032a7c142a6 OK
2024/11/28 01:44:24 INFO  : foo: Copied (replaced existing)
2024/11/28 01:44:24 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (6.40s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:44:28 DEBUG : empty space: md5 = 5675c9871d9a2a4433a5b52a1ecc22a0 OK
2024/11/28 01:44:29 DEBUG : potato: Need to transfer - File not found at Destination
2024/11/28 01:44:29 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:44:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:44:29 DEBUG : empty space: Unchanged skipping
2024/11/28 01:44:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:44:30 DEBUG : potato: md5 = 746519dbd70658f004774be547322c87 OK
2024/11/28 01:44:30 INFO  : potato: Copied (new)
2024/11/28 01:44:30 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (6.65s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:44:35 DEBUG : potato: md5 = 68d7344ac1534cb10971dc2ef6eb3d45 OK
2024/11/28 01:44:35 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2024/11/28 01:44:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:44:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:44:37 DEBUG : potato: md5 = 33c2bf0444522dc694639a2dd4e2bd78 OK
2024/11/28 01:44:37 INFO  : potato: Copied (replaced existing)
2024/11/28 01:44:37 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (5.64s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:44:40 DEBUG : potato: md5 = 0f45fa96b64f2e59dc6c2e45ae40f9dd OK
2024/11/28 01:44:41 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC
2024/11/28 01:44:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:44:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:44:42 DEBUG : potato: md5 = 4f70d183e24dcf68e552e5db0dd42b76 OK
2024/11/28 01:44:42 INFO  : potato: Copied (replaced existing)
2024/11/28 01:44:42 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (5.60s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:44:46 DEBUG : potato: md5 = b80ebc351070fedebc4177f297eb6fd2 OK
2024/11/28 01:44:48 DEBUG : empty space: md5 = 2acc536f466801769dfe6fc5a10f1bb8 OK
2024/11/28 01:44:48 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 01:44:48 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2024/11/28 01:44:48 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:44:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:44:48 DEBUG : empty space: Unchanged skipping
2024/11/28 01:44:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:44:48 DEBUG : Waiting for deletions to finish
2024/11/28 01:44:48 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (6.37s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:44:52 DEBUG : potato: md5 = 672a3eb08247b6b347f5d2c176ccac8e OK
2024/11/28 01:44:54 DEBUG : empty space: md5 = 1864c2d2da6f9761f45d371f4883a9cd OK
2024/11/28 01:44:55 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 01:44:55 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:44:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:44:55 DEBUG : empty space: Unchanged skipping
2024/11/28 01:44:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:44:56 DEBUG : potato2: md5 = 46f37bf8d28fca0f54a99051076a97e8 OK
2024/11/28 01:44:56 INFO  : potato2: Copied (new)
2024/11/28 01:44:56 DEBUG : Waiting for deletions to finish
2024/11/28 01:44:57 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.81s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:45:02 DEBUG : b/potato: md5 = 1fa0d9361c17e853800af23cef5268ab OK
2024/11/28 01:45:05 DEBUG : c/non empty space: md5 = 7d4dbb5ac4a75c74970a65bba09f276f OK
2024/11/28 01:45:05 DEBUG : d: Making directory
2024/11/28 01:45:06 DEBUG : d/e: Making directory
2024/11/28 01:45:09 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/28 01:45:09 DEBUG : Added delayed dir = "c", newDst=c
2024/11/28 01:45:09 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:45:09 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/28 01:45:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:45:09 DEBUG : c/non empty space: Unchanged skipping
2024/11/28 01:45:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:45:12 DEBUG : a/potato2: md5 = 58f05fd36d0fff99caf6806fbd502bff OK
2024/11/28 01:45:12 INFO  : a/potato2: Copied (new)
2024/11/28 01:45:12 DEBUG : Waiting for deletions to finish
2024/11/28 01:45:12 INFO  : b/potato: Deleted
2024/11/28 01:45:13 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/28 01:45:13 INFO  : d/e: Removing directory
2024/11/28 01:45:14 INFO  : d: Removing directory
2024/11/28 01:45:14 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2024/11/28 01:45:15 INFO  : b: Removing directory
2024/11/28 01:45:15 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/28 01:45:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:45:18 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/28 01:45:19 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (21.27s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:45:24 DEBUG : b/potato: md5 = a8a29ee0dca3db4dccd2ec4bdf412179 OK
2024/11/28 01:45:27 DEBUG : c/non empty space: md5 = a76e5bf0550cde77ef141e4995eaf051 OK
2024/11/28 01:45:27 DEBUG : d: Making directory
2024/11/28 01:45:29 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/11/28 01:45:29 DEBUG : Added delayed dir = "c", newDst=c
2024/11/28 01:45:29 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:45:29 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/11/28 01:45:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:45:29 DEBUG : c/non empty space: Unchanged skipping
2024/11/28 01:45:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:45:32 DEBUG : a/potato2: md5 = 5f44be152046dde53e58fbb51f7ab8d1 OK
2024/11/28 01:45:32 INFO  : a/potato2: Copied (new)
2024/11/28 01:45:32 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': not deleting files as there were IO errors
2024/11/28 01:45:33 INFO  : a: Set directory modification time (using DirSetModTime)
2024/11/28 01:45:33 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:45:38 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/11/28 01:45:39 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/11/28 01:45:39 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (20.33s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:45:43 DEBUG : potato: md5 = b80fb42ead9a8e9dd731773579ebbd35 OK
2024/11/28 01:45:44 DEBUG : empty space: md5 = ff36749c846da024d48c2cab581b10ff OK
2024/11/28 01:45:45 DEBUG : Waiting for deletions to finish
2024/11/28 01:45:45 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 01:45:45 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:45:45 DEBUG : empty space: Unchanged skipping
2024/11/28 01:45:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:45:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:45:46 INFO  : potato: Deleted
2024/11/28 01:45:47 DEBUG : potato2: md5 = f80ce8b4cbd471d9b7468bf19adcce8c OK
2024/11/28 01:45:47 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (8.56s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:45:51 DEBUG : potato: md5 = afb271f32f6e3f41a13b67fbef872044 OK
2024/11/28 01:45:53 DEBUG : empty space: md5 = 69b58a5f61e939993d169dfccabea258 OK
2024/11/28 01:45:54 DEBUG : Waiting for deletions to finish
2024/11/28 01:45:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:45:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:45:54 INFO  : potato: Deleted
2024/11/28 01:45:55 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 01:45:55 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:45:55 DEBUG : empty space: Unchanged skipping
2024/11/28 01:45:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:45:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:45:56 DEBUG : potato2: md5 = 7b400d58c02268698f3f0de981edec3b OK
2024/11/28 01:45:56 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (9.18s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:46:01 DEBUG : potato: md5 = db514996e4cf1db01a022d0bb7b19306 OK
2024/11/28 01:46:01 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 01:46:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:46:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:46:03 DEBUG : potato2: md5 = 3320559f91345e9cb85a64278da0f690 OK
2024/11/28 01:46:03 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (6.55s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:46:07 DEBUG : potato2: md5 = 0c5d4157a1d5906c3e2bfc28471e5aad OK
2024/11/28 01:46:09 DEBUG : empty space: md5 = 32a9390cb7f0591a41a41f253b3d0cc1 OK
2024/11/28 01:46:09 DEBUG : enormous: Excluded (Size Filter)
2024/11/28 01:46:09 DEBUG : enormous: Excluded
2024/11/28 01:46:09 DEBUG : potato2: Excluded (Size Filter)
2024/11/28 01:46:09 DEBUG : potato2: Excluded
2024/11/28 01:46:09 DEBUG : potato2: Excluded (Size Filter)
2024/11/28 01:46:09 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:46:09 DEBUG : empty space: Unchanged skipping
2024/11/28 01:46:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:46:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:46:09 DEBUG : Waiting for deletions to finish
2024/11/28 01:46:09 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:46:10 DEBUG : enormous: Excluded (Size Filter)
2024/11/28 01:46:10 DEBUG : enormous: Excluded
2024/11/28 01:46:10 DEBUG : potato2: Excluded (Size Filter)
2024/11/28 01:46:10 DEBUG : potato2: Excluded
2024/11/28 01:46:10 DEBUG : potato2: Excluded (Size Filter)
2024/11/28 01:46:10 DEBUG : Local file system at /tmp/rclone3020861414: Waiting for checks to finish
2024/11/28 01:46:10 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/11/28 01:46:10 DEBUG : empty space: Unchanged skipping
2024/11/28 01:46:10 DEBUG : Local file system at /tmp/rclone3020861414: Waiting for transfers to finish
2024/11/28 01:46:10 DEBUG : Waiting for deletions to finish
2024/11/28 01:46:10 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncWithExclude (7.31s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:46:14 DEBUG : potato2: md5 = f8224b1d44aa0a7c894d230c168cac58 OK
2024/11/28 01:46:16 DEBUG : empty space: md5 = fa2053df195d0f0ebd8906548ef6c7c5 OK
2024/11/28 01:46:18 DEBUG : enormous: md5 = 8f5036f4ef8b34710b55a526873d7779 OK
2024/11/28 01:46:18 DEBUG : enormous: Excluded (Size Filter)
2024/11/28 01:46:18 DEBUG : enormous: Excluded
2024/11/28 01:46:18 DEBUG : potato2: Excluded (Size Filter)
2024/11/28 01:46:18 DEBUG : potato2: Excluded
2024/11/28 01:46:18 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:46:18 DEBUG : empty space: Unchanged skipping
2024/11/28 01:46:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:46:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:46:18 DEBUG : Waiting for deletions to finish
2024/11/28 01:46:19 INFO  : enormous: Deleted
2024/11/28 01:46:19 INFO  : potato2: Deleted
2024/11/28 01:46:19 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:46:19 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/11/28 01:46:19 DEBUG : empty space: Unchanged skipping
2024/11/28 01:46:19 DEBUG : Local file system at /tmp/rclone3020861414: Waiting for checks to finish
2024/11/28 01:46:19 DEBUG : Local file system at /tmp/rclone3020861414: Waiting for transfers to finish
2024/11/28 01:46:19 DEBUG : Waiting for deletions to finish
2024/11/28 01:46:19 INFO  : enormous: Deleted
2024/11/28 01:46:19 INFO  : potato2: Deleted
2024/11/28 01:46:19 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (8.83s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:46:23 DEBUG : one: md5 = 051375c0a255eccebf1586aa79ab3f53 OK
2024/11/28 01:46:25 DEBUG : two: md5 = 843f44e597f2adf8132441eb2871a11f OK
2024/11/28 01:46:27 DEBUG : three: md5 = 77c9b06621eff6b958972ec26ff68216 OK
2024/11/28 01:46:29 DEBUG : four: md5 = 4ffc103cb53492467875c6a632be6467 OK
2024/11/28 01:46:29 DEBUG : five: Need to transfer - File not found at Destination
2024/11/28 01:46:29 DEBUG : four: Sizes differ (src 4 vs dst 8)
2024/11/28 01:46:29 DEBUG : one: Destination is newer than source, skipping
2024/11/28 01:46:29 DEBUG : three: Sizes identical
2024/11/28 01:46:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:46:29 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2024/11/28 01:46:29 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2024/11/28 01:46:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:46:31 DEBUG : four: md5 = 835bd4708727c3ab9c0944118495642d OK
2024/11/28 01:46:31 INFO  : four: Copied (replaced existing)
2024/11/28 01:46:31 DEBUG : two: md5 = 9530141322791d3f78914fc69da7c0aa OK
2024/11/28 01:46:31 INFO  : two: Copied (replaced existing)
2024/11/28 01:46:31 DEBUG : five: md5 = 86db6c19d6658bc8ccf94b98a65bb2fd OK
2024/11/28 01:46:31 INFO  : five: Copied (new)
2024/11/28 01:46:31 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (13.42s)
=== 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-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2024/11/28 01:46:35 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Ignoring --track-renames as the source and destination do not have a common hash
2024/11/28 01:46:35 DEBUG : potato: Need to transfer - File not found at Destination
2024/11/28 01:46:35 DEBUG : yam: Need to transfer - File not found at Destination
2024/11/28 01:46:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:46:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:46:37 DEBUG : yam: md5 = 8f6f51558bf40343cc49ba0a5a532aca OK
2024/11/28 01:46:37 INFO  : yam: Copied (new)
2024/11/28 01:46:37 DEBUG : potato: md5 = 994e5b000c4c889cc07f84b1abd9b612 OK
2024/11/28 01:46:37 INFO  : potato: Copied (new)
2024/11/28 01:46:37 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:46:37 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Ignoring --track-renames as the source and destination do not have a common hash
2024/11/28 01:46:37 DEBUG : yaml: Need to transfer - File not found at Destination
2024/11/28 01:46:37 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:46:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:46:37 DEBUG : potato: Unchanged skipping
2024/11/28 01:46:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:46:39 DEBUG : yaml: md5 = ea03132188daf8339fe378bad97b92eb OK
2024/11/28 01:46:39 INFO  : yaml: Copied (new)
2024/11/28 01:46:39 DEBUG : Waiting for deletions to finish
2024/11/28 01:46:40 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", 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-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2024/11/28 01:46:43 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Making map for --track-renames
2024/11/28 01:46:43 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Finished making map for --track-renames
2024/11/28 01:46:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:46:43 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/11/28 01:46:43 DEBUG : yam: Need to transfer - No matching file found at Destination
2024/11/28 01:46:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for renames to finish
2024/11/28 01:46:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:46:45 DEBUG : yam: md5 = be187c30a46785c7c39925092ea3e7a8 OK
2024/11/28 01:46:45 INFO  : yam: Copied (new)
2024/11/28 01:46:45 DEBUG : potato: md5 = 0689fe2b784904a43621f11345c2200d OK
2024/11/28 01:46:45 INFO  : potato: Copied (new)
2024/11/28 01:46:45 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:46:46 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:46:46 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Making map for --track-renames
2024/11/28 01:46:46 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Finished making map for --track-renames
2024/11/28 01:46:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:46:46 DEBUG : potato: Unchanged skipping
2024/11/28 01:46:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for renames to finish
2024/11/28 01:46:46 INFO  : yam: Moved (server-side) to: yaml
2024/11/28 01:46:46 INFO  : yaml: Renamed from "yam"
2024/11/28 01:46:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:46:46 DEBUG : Waiting for deletions to finish
2024/11/28 01:46:46 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (6.48s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2024/11/28 01:46:50 DEBUG : Added delayed dir = "sub", newDst=<nil>
2024/11/28 01:46:50 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Making map for --track-renames
2024/11/28 01:46:50 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Finished making map for --track-renames
2024/11/28 01:46:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:46:50 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/11/28 01:46:50 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2024/11/28 01:46:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for renames to finish
2024/11/28 01:46:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:46:52 DEBUG : sub/yam: md5 = 403c5f159080681a16533ffa4a49e28e OK
2024/11/28 01:46:52 INFO  : sub/yam: Copied (new)
2024/11/28 01:46:52 DEBUG : potato: md5 = 64eddaa30f274b1548ed7d5cce333151 OK
2024/11/28 01:46:52 INFO  : potato: Copied (new)
2024/11/28 01:46:52 DEBUG : Waiting for deletions to finish
2024/11/28 01:46:53 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:46:54 DEBUG : Added delayed dir = "sub", newDst=sub
2024/11/28 01:46:54 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:46:54 DEBUG : potato: Unchanged skipping
2024/11/28 01:46:54 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Making map for --track-renames
2024/11/28 01:46:54 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Finished making map for --track-renames
2024/11/28 01:46:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:46:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for renames to finish
2024/11/28 01:46:55 INFO  : sub/yam: Moved (server-side) to: yam
2024/11/28 01:46:55 INFO  : yam: Renamed from "sub/yam"
2024/11/28 01:46:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:46:55 DEBUG : Waiting for deletions to finish
2024/11/28 01:46:55 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (10.38s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:47:00 DEBUG : Creating backend with remote "/tmp/rclone3020861414/dir1"
2024/11/28 01:47:00 DEBUG : Config file has changed externally - reloading
2024/11/28 01:47:00 DEBUG : Creating backend with remote "/tmp/rclone3020861414/dir2"
2024/11/28 01:47:00 DEBUG : Local file system at /tmp/rclone3020861414/dir2: Using server-side directory move
2024/11/28 01:47:00 INFO  : Local file system at /tmp/rclone3020861414/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/28 01:47:00 DEBUG : file1.txt: Need to transfer - File not found at Destination
2024/11/28 01:47:00 INFO  : file1.txt: Moved (server-side)
2024/11/28 01:47:00 DEBUG : Local file system at /tmp/rclone3020861414/dir2: Waiting for checks to finish
2024/11/28 01:47:00 DEBUG : Local file system at /tmp/rclone3020861414/dir2: Waiting for transfers to finish
--- PASS: TestServerSideMoveLocal (0.48s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:47:00 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/11/28 01:47:00 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 01:47:00 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 01:47:00 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/11/28 01:47:00 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/11/28 01:47:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:47:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:47:03 DEBUG : sub dir/hello world: md5 = fddae55b9cf9845739c20b6b41aa479b OK
2024/11/28 01:47:03 INFO  : sub dir/hello world: Copied (new)
2024/11/28 01:47:03 INFO  : sub dir/hello world: Deleted
2024/11/28 01:47:06 DEBUG : nested/sub dir/file: md5 = 2352ea23090e56c7cbcc8501c1fa2ba9 OK
2024/11/28 01:47:06 INFO  : nested/sub dir/file: Copied (new)
2024/11/28 01:47:06 INFO  : nested/sub dir/file: Deleted
2024/11/28 01:47:07 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 01:47:08 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 01:47:08 INFO  : nested: Set directory modification time (using DirSetModTime)
2024/11/28 01:47:08 INFO  : sub dir: Removing directory
2024/11/28 01:47:08 INFO  : nested/sub dir: Removing directory
2024/11/28 01:47:08 INFO  : nested: Removing directory
2024/11/28 01:47:08 DEBUG : Local file system at /tmp/rclone3020861414: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:47:10 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/28 01:47:12 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/11/28 01:47:13 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (13.81s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:47:14 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/11/28 01:47:14 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/11/28 01:47:14 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/11/28 01:47:14 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/11/28 01:47:14 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/11/28 01:47:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:47:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:47:17 DEBUG : sub dir/hello world: md5 = cb33c7cebe54f8b85badad505ef3f576 OK
2024/11/28 01:47:17 INFO  : sub dir/hello world: Copied (new)
2024/11/28 01:47:17 INFO  : sub dir/hello world: Deleted
2024/11/28 01:47:20 DEBUG : nested/sub dir/file: md5 = 27cddc4d82f477e9e430bfa4ac43f877 OK
2024/11/28 01:47:20 INFO  : nested/sub dir/file: Copied (new)
2024/11/28 01:47:20 INFO  : nested/sub dir/file: Deleted
2024/11/28 01:47:20 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 01:47:21 INFO  : nested: Set directory modification time (using DirSetModTime)
2024/11/28 01:47:21 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:47:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/28 01:47:25 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/11/28 01:47:26 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (13.29s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:47:28 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/28 01:47:28 DEBUG : existing-b: Need to transfer - File not found at Destination
2024/11/28 01:47:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:47:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:47:29 DEBUG : existing: md5 = 0ff8225bd29989b6fde3fa811aef01df OK
2024/11/28 01:47:29 INFO  : existing: Copied (new)
2024/11/28 01:47:29 INFO  : existing: Deleted
2024/11/28 01:47:29 DEBUG : existing-b: md5 = d8d0fcc38a86487a67fdaca3cb695105 OK
2024/11/28 01:47:29 INFO  : existing-b: Copied (new)
2024/11/28 01:47:29 INFO  : existing-b: Deleted
2024/11/28 01:47:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:47:30 DEBUG : existing: Destination exists, skipping
2024/11/28 01:47:30 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2024/11/28 01:47:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:47:30 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (5.17s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:47:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gakajez0doku"
2024/11/28 01:47:33 DEBUG : Creating backend with remote "TestDrive:crypt/ba5tbh4an75npb81fl4qu83mh2jcmt9ub2m3fpcvuqrk416nb6d0"
2024/11/28 01:47:35 DEBUG : potato2: md5 = 1aa05e736c695d2fe216726e191ac3a1 OK
2024/11/28 01:47:37 DEBUG : empty space: md5 = 428e772bec55a5ffb51c6c4e34c8141d OK
2024/11/28 01:47:39 DEBUG : potato3: md5 = 4433c960107cf11db29e251885520f81 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki' -> Encrypted drive 'TestCryptDrive:rclone-test-gakajez0doku'
2024/11/28 01:47:46 DEBUG : empty space: md5 = 67607faee000794804aeff7ea753c883 OK
2024/11/28 01:47:48 DEBUG : potato3: md5 = 4efaa23804e453793bf4010324695b84 OK
2024/11/28 01:47:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gakajez0doku': Using server-side directory move
2024/11/28 01:47:48 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gakajez0doku': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/28 01:47:48 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 01:47:48 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/11/28 01:47:48 DEBUG : empty space: Unchanged skipping
2024/11/28 01:47:48 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/28 01:47:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gakajez0doku': Waiting for checks to finish
2024/11/28 01:47:49 INFO  : potato3: Deleted
2024/11/28 01:47:49 INFO  : empty space: Deleted
2024/11/28 01:47:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gakajez0doku': Waiting for transfers to finish
2024/11/28 01:47:49 INFO  : potato2: Moved (server-side)
2024/11/28 01:47:50 INFO  : potato3: Moved (server-side)
2024/11/28 01:47:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fepuvis6foza"
2024/11/28 01:47:50 DEBUG : Config file has changed externally - reloading
2024/11/28 01:47:50 DEBUG : Creating backend with remote "TestDrive:crypt/29s43qjqqggcuo3r7q0sfomiaeal5ql4o3krk2525q7576egaudg"
2024/11/28 01:47:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fepuvis6foza': Using server-side directory move
2024/11/28 01:47:52 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-fepuvis6foza': Server side directory move succeeded
2024/11/28 01:47:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fepuvis6foza': Purge remote
2024/11/28 01:47:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gakajez0doku': Purge remote
2024/11/28 01:47:54 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (22.21s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:47:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-satadun7necu"
2024/11/28 01:47:55 DEBUG : Creating backend with remote "TestDrive:crypt/f3fgkhkuq1ll95jv27p403ss7ji8o78v45pm7tmiihk9hn8mofvg"
2024/11/28 01:47:58 DEBUG : potato2: md5 = b7027aec73b3610af138d2709344745e OK
2024/11/28 01:48:00 DEBUG : empty space: md5 = e10c265064153216f1d31682b60cbeea OK
2024/11/28 01:48:01 DEBUG : potato3: md5 = 0a3d8be81429e4b6b81a40ec4a70fdfe OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki' -> Encrypted drive 'TestCryptDrive:rclone-test-satadun7necu'
2024/11/28 01:48:05 DEBUG : empty space: md5 = 22bdc6c61013a0fe3512138e4b40189e OK
2024/11/28 01:48:06 DEBUG : potato3: md5 = 02b344d10dced5b5e0f46bc7fe9a1582 OK
2024/11/28 01:48:07 DEBUG : empty space: Excluded (Size Filter)
2024/11/28 01:48:07 DEBUG : empty space: Excluded (Size Filter)
2024/11/28 01:48:07 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 01:48:07 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/28 01:48:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-satadun7necu': Waiting for checks to finish
2024/11/28 01:48:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-satadun7necu': Waiting for transfers to finish
2024/11/28 01:48:07 INFO  : potato3: Deleted
2024/11/28 01:48:08 INFO  : potato2: Moved (server-side)
2024/11/28 01:48:08 INFO  : potato3: Moved (server-side)
2024/11/28 01:48:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yufaqef8nene"
2024/11/28 01:48:09 DEBUG : Creating backend with remote "TestDrive:crypt/nrkubquerdednrtsh6fv6ja09b2451pr3mo552k8oqbiam5ghn40"
2024/11/28 01:48:10 DEBUG : empty space: Excluded (Size Filter)
2024/11/28 01:48:10 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 01:48:10 DEBUG : potato3: Need to transfer - File not found at Destination
2024/11/28 01:48:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yufaqef8nene': Waiting for checks to finish
2024/11/28 01:48:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yufaqef8nene': Waiting for transfers to finish
2024/11/28 01:48:13 INFO  : potato3: Moved (server-side)
2024/11/28 01:48:13 INFO  : potato2: Moved (server-side)
2024/11/28 01:48:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yufaqef8nene': Purge remote
2024/11/28 01:48:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-satadun7necu': Purge remote
--- PASS: TestServerSideMoveWithFilter (21.71s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:48:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yuwewoy6javi"
2024/11/28 01:48:16 DEBUG : Creating backend with remote "TestDrive:crypt/ud3rpq3g5gg8e2vkorv3voi8kvtcudtjbu7623bqdnp7talcd3hg"
2024/11/28 01:48:19 DEBUG : potato2: md5 = 123160e99c7c7ddbfde4f9c74e7a07fd OK
2024/11/28 01:48:21 DEBUG : empty space: md5 = 364ea794fbc332bbe694a208ef58454a OK
2024/11/28 01:48:23 DEBUG : potato3: md5 = 54a8899deecf45d96e6ff4493c3df944 OK
2024/11/28 01:48:23 DEBUG : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki' -> Encrypted drive 'TestCryptDrive:rclone-test-yuwewoy6javi'
2024/11/28 01:48:27 DEBUG : empty space: md5 = 0ed3c82932ea0a4f26fcbf25682f79ce OK
2024/11/28 01:48:29 DEBUG : potato3: md5 = e33ddd30d294021c51be5dd61d1ff4a1 OK
2024/11/28 01:48:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yuwewoy6javi': Using server-side directory move
2024/11/28 01:48:29 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-yuwewoy6javi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/11/28 01:48:29 DEBUG : potato2: Need to transfer - File not found at Destination
2024/11/28 01:48:29 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2024/11/28 01:48:29 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/11/28 01:48:29 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/11/28 01:48:29 DEBUG : empty space: Unchanged skipping
2024/11/28 01:48:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yuwewoy6javi': Waiting for checks to finish
2024/11/28 01:48:30 INFO  : empty space: Deleted
2024/11/28 01:48:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yuwewoy6javi': Waiting for transfers to finish
2024/11/28 01:48:30 INFO  : potato3: Deleted
2024/11/28 01:48:31 INFO  : potato2: Moved (server-side)
2024/11/28 01:48:31 INFO  : potato3: Moved (server-side)
2024/11/28 01:48:31 INFO  : tomatoDir: Removing directory
2024/11/28 01:48:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': deleted 1 directories
2024/11/28 01:48:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zugojin7jipu"
2024/11/28 01:48:33 DEBUG : Creating backend with remote "TestDrive:crypt/8eb9bvheqd11rjfuk9td0itjrdgcpfkdv1fu69bm96mlprttusp0"
2024/11/28 01:48:34 DEBUG : tomatoDir: Making directory
2024/11/28 01:48:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zugojin7jipu': Using server-side directory move
2024/11/28 01:48:36 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-zugojin7jipu': Server side directory move succeeded
2024/11/28 01:48:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zugojin7jipu': Purge remote
2024/11/28 01:48:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yuwewoy6javi': Purge remote
2024/11/28 01:48:38 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (22.49s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.49s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:48:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/rclone-sync-test"
2024/11/28 01:48:39 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncOverlap (4.14s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:48:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/rclone-sync-test"
2024/11/28 01:48:44 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2024/11/28 01:48:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/rclone-sync-test-include/layer2"
2024/11/28 01:48:47 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2024/11/28 01:48:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/rclone-sync-test-ignore-file"
2024/11/28 01:48:51 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2024/11/28 01:48:55 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 3004054f47606684986ae8ded5acb44d OK
2024/11/28 01:48:58 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/28 01:48:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/rclone-sync-test': Waiting for checks to finish
2024/11/28 01:48:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/rclone-sync-test': Waiting for transfers to finish
2024/11/28 01:48:58 DEBUG : Waiting for deletions to finish
2024/11/28 01:48:58 INFO  : There was nothing to transfer
2024/11/28 01:48:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:48:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:48:59 DEBUG : Waiting for deletions to finish
2024/11/28 01:48:59 INFO  : rclone-sync-test-include: Removing directory
2024/11/28 01:49:00 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/28 01:49:00 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/11/28 01:49:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': failed to delete 1 directories
2024/11/28 01:49:00 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:49:02 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/28 01:49:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/rclone-sync-test-include/layer2': Waiting for checks to finish
2024/11/28 01:49:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/rclone-sync-test-include/layer2': Waiting for transfers to finish
2024/11/28 01:49:02 DEBUG : Waiting for deletions to finish
2024/11/28 01:49:02 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:49:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:49:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:49:04 DEBUG : Waiting for deletions to finish
2024/11/28 01:49:04 INFO  : rclone-sync-test-include: Removing directory
2024/11/28 01:49:04 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/28 01:49:04 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/11/28 01:49:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': failed to delete 1 directories
2024/11/28 01:49:04 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:49:06 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/11/28 01:49:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/rclone-sync-test-ignore-file': Waiting for checks to finish
2024/11/28 01:49:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/rclone-sync-test-ignore-file': Waiting for transfers to finish
2024/11/28 01:49:06 DEBUG : Waiting for deletions to finish
2024/11/28 01:49:06 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:49:08 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/11/28 01:49:09 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (35.67s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:49:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/dst"
2024/11/28 01:49:19 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/28 01:49:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/CompareDest"
2024/11/28 01:49:21 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/gveqi14airsml4bgu7krj116o8"
2024/11/28 01:49:23 DEBUG : one: Need to transfer - File not found at Destination
2024/11/28 01:49:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for checks to finish
2024/11/28 01:49:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for transfers to finish
2024/11/28 01:49:25 DEBUG : one: md5 = 2cc3c3f4cd91009988fea86182b4313c OK
2024/11/28 01:49:25 INFO  : one: Copied (new)
2024/11/28 01:49:25 DEBUG : Waiting for deletions to finish
2024/11/28 01:49:27 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/28 01:49:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for checks to finish
2024/11/28 01:49:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for transfers to finish
2024/11/28 01:49:28 DEBUG : one: md5 = f19696fc76b2b7f95e13611011042203 OK
2024/11/28 01:49:28 INFO  : one: Copied (replaced existing)
2024/11/28 01:49:28 DEBUG : Waiting for deletions to finish
2024/11/28 01:49:31 DEBUG : dst/one: md5 = 64778a5d91115eaa363e1a702d778628 OK
2024/11/28 01:49:33 DEBUG : CompareDest/one: md5 = f9c7a7798c82633472d25271429be9ed OK
2024/11/28 01:49:34 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/28 01:49:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for checks to finish
2024/11/28 01:49:35 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:49:35 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/28 01:49:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for transfers to finish
2024/11/28 01:49:35 DEBUG : Waiting for deletions to finish
2024/11/28 01:49:35 INFO  : There was nothing to transfer
2024/11/28 01:49:37 DEBUG : CompareDest/two: md5 = 6ac06ac34259e3ec945d161f32231b40 OK
2024/11/28 01:49:38 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:49:38 DEBUG : two: Destination found in --compare-dest, skipping
2024/11/28 01:49:38 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/28 01:49:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for checks to finish
2024/11/28 01:49:38 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:49:38 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/28 01:49:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for transfers to finish
2024/11/28 01:49:38 DEBUG : Waiting for deletions to finish
2024/11/28 01:49:38 INFO  : There was nothing to transfer
2024/11/28 01:49:39 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:49:39 DEBUG : two: Destination found in --compare-dest, skipping
2024/11/28 01:49:39 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/28 01:49:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for checks to finish
2024/11/28 01:49:39 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:49:39 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/28 01:49:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for transfers to finish
2024/11/28 01:49:39 DEBUG : Waiting for deletions to finish
2024/11/28 01:49:39 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2024/11/28 01:49:41 DEBUG : two: Sizes differ (src 5 vs dst 3)
2024/11/28 01:49:41 DEBUG : two: Need to transfer - File not found at Destination
2024/11/28 01:49:41 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/28 01:49:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for checks to finish
2024/11/28 01:49:41 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:49:41 DEBUG : one: Destination found in --compare-dest, skipping
2024/11/28 01:49:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for transfers to finish
2024/11/28 01:49:44 DEBUG : two: md5 = 07dad06889cf8f6bd8fc8312f4c885aa OK
2024/11/28 01:49:44 INFO  : two: Copied (new)
2024/11/28 01:49:44 DEBUG : Waiting for deletions to finish
2024/11/28 01:49:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/28 01:49:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/28 01:49:48 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/28 01:49:48 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCompareDest (29.76s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:49:52 DEBUG : pre-dest1/1: md5 = 41e5c4c95f5825b6568ac98cd08a5551 OK
2024/11/28 01:49:55 DEBUG : pre-dest2/2: md5 = 256f8a892b9c604e68762023b2d3439e OK
2024/11/28 01:49:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/dest"
2024/11/28 01:49:55 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/rg03c1jvnehrrc617i0lnqjddc"
2024/11/28 01:49:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/pre-dest1"
2024/11/28 01:49:57 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/bbnblvh6k061ssopqrp18kd7gc"
2024/11/28 01:49:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/pre-dest2"
2024/11/28 01:49:58 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/dgicm1h6b5ejvlltm8eeif0bnk"
2024/11/28 01:49:59 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:49:59 DEBUG : 1: Destination found in --compare-dest, skipping
2024/11/28 01:49:59 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:49:59 DEBUG : 2: Destination found in --compare-dest, skipping
2024/11/28 01:50:00 DEBUG : 3: Need to transfer - File not found at Destination
2024/11/28 01:50:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dest': Waiting for checks to finish
2024/11/28 01:50:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dest': Waiting for transfers to finish
2024/11/28 01:50:03 DEBUG : 3: md5 = da08e02d4f16fc081bdf42f1acddb1ad OK
2024/11/28 01:50:03 INFO  : 3: Copied (new)
2024/11/28 01:50:03 DEBUG : Waiting for deletions to finish
2024/11/28 01:50:06 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2024/11/28 01:50:07 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2024/11/28 01:50:08 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (19.87s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:50:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/dst"
2024/11/28 01:50:09 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/28 01:50:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/CopyDest"
2024/11/28 01:50:10 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/d09o6po3f7bm6ce32vdgs8h9ls"
2024/11/28 01:50:12 DEBUG : one: Need to transfer - File not found at Destination
2024/11/28 01:50:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for checks to finish
2024/11/28 01:50:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for transfers to finish
2024/11/28 01:50:15 DEBUG : one: md5 = c5021b1da5711192425df742c2dd6b9e OK
2024/11/28 01:50:15 INFO  : one: Copied (new)
2024/11/28 01:50:15 DEBUG : Waiting for deletions to finish
2024/11/28 01:50:17 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/28 01:50:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for checks to finish
2024/11/28 01:50:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for transfers to finish
2024/11/28 01:50:18 DEBUG : one: md5 = 9c9168ef10829ae43fa004ee429f85d3 OK
2024/11/28 01:50:18 INFO  : one: Copied (replaced existing)
2024/11/28 01:50:18 DEBUG : Waiting for deletions to finish
2024/11/28 01:50:20 DEBUG : dst/one: md5 = f29e9f8a97bc062e5b43e924fb48a517 OK
2024/11/28 01:50:23 DEBUG : CopyDest/one: md5 = 9e995eee31f011992c242ca70696530c OK
2024/11/28 01:50:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/BackupDir"
2024/11/28 01:50:24 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/s6dbk3lfi7c9kfvo6j7bla9m0g"
2024/11/28 01:50:26 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/28 01:50:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for checks to finish
2024/11/28 01:50:26 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:50:26 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/11/28 01:50:29 INFO  : one: Moved (server-side)
2024/11/28 01:50:30 INFO  : one: Copied (server-side copy)
2024/11/28 01:50:30 DEBUG : one: Destination found in --copy-dest, using server-side copy
2024/11/28 01:50:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for transfers to finish
2024/11/28 01:50:30 DEBUG : Waiting for deletions to finish
2024/11/28 01:50:32 DEBUG : CopyDest/two: md5 = fdccb88dc8f29ca02d688e51bb68d8f6 OK
2024/11/28 01:50:33 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:50:35 INFO  : two: Copied (server-side copy)
2024/11/28 01:50:35 DEBUG : two: Destination found in --copy-dest, using server-side copy
2024/11/28 01:50:35 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:50:35 DEBUG : one: Unchanged skipping
2024/11/28 01:50:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for checks to finish
2024/11/28 01:50:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for transfers to finish
2024/11/28 01:50:35 DEBUG : Waiting for deletions to finish
2024/11/28 01:50:36 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:50:36 DEBUG : one: Unchanged skipping
2024/11/28 01:50:36 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:50:36 DEBUG : two: Unchanged skipping
2024/11/28 01:50:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for checks to finish
2024/11/28 01:50:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for transfers to finish
2024/11/28 01:50:36 DEBUG : Waiting for deletions to finish
2024/11/28 01:50:36 INFO  : There was nothing to transfer
2024/11/28 01:50:38 DEBUG : CopyDest/three: md5 = 3ff02fa4ab9e08ad4c15bee07df377d4 OK
2024/11/28 01:50:39 DEBUG : three: Sizes differ (src 7 vs dst 5)
2024/11/28 01:50:39 DEBUG : three: Destination not found in --copy-dest
2024/11/28 01:50:39 DEBUG : three: Need to transfer - File not found at Destination
2024/11/28 01:50:39 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:50:39 DEBUG : one: Unchanged skipping
2024/11/28 01:50:39 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/11/28 01:50:39 DEBUG : two: Unchanged skipping
2024/11/28 01:50:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for checks to finish
2024/11/28 01:50:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for transfers to finish
2024/11/28 01:50:41 DEBUG : three: md5 = 2d198c14e87da0b44825dee0e8316b02 OK
2024/11/28 01:50:41 INFO  : three: Copied (new)
2024/11/28 01:50:41 DEBUG : Waiting for deletions to finish
2024/11/28 01:50:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/11/28 01:50:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/28 01:50:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/28 01:50:47 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/11/28 01:50:47 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/28 01:50:47 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/28 01:50:48 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (39.97s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:50:52 DEBUG : dst/one: md5 = 56cba23f633ce32284e0554942428aa4 OK
2024/11/28 01:50:53 DEBUG : dst/two: md5 = 49acecca8bcb6bb0640e8292bc54e855 OK
2024/11/28 01:50:55 DEBUG : dst/three.txt: md5 = f284c5691401ab6490ccad7b415ce201 OK
2024/11/28 01:50:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/dst"
2024/11/28 01:50:56 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/28 01:50:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/backup"
2024/11/28 01:50:57 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/1nrff024r7pq65ecp72fc28jb0"
2024/11/28 01:50:58 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/28 01:50:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for checks to finish
2024/11/28 01:50:58 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:50:58 DEBUG : two: Unchanged skipping
2024/11/28 01:51:01 INFO  : one: Moved (server-side)
2024/11/28 01:51:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for transfers to finish
2024/11/28 01:51:02 DEBUG : one: md5 = 7bb0151d23c056358fd25aeb670c0352 OK
2024/11/28 01:51:02 INFO  : one: Copied (new)
2024/11/28 01:51:02 DEBUG : Waiting for deletions to finish
2024/11/28 01:51:04 INFO  : three.txt: Moved (server-side)
2024/11/28 01:51:04 INFO  : three.txt: Moved into backup dir
2024/11/28 01:51:06 DEBUG : dst/three.txt: md5 = f64f6fa6c2c2665ab85d0905693f93c8 OK
2024/11/28 01:51:07 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/28 01:51:07 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:51:07 DEBUG : two: Unchanged skipping
2024/11/28 01:51:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for checks to finish
2024/11/28 01:51:08 INFO  : one: Deleted
2024/11/28 01:51:09 INFO  : one: Moved (server-side)
2024/11/28 01:51:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for transfers to finish
2024/11/28 01:51:10 DEBUG : one: md5 = faa7b03b53b183286afba1a25a08b842 OK
2024/11/28 01:51:10 INFO  : one: Copied (new)
2024/11/28 01:51:10 DEBUG : Waiting for deletions to finish
2024/11/28 01:51:11 INFO  : three.txt: Deleted
2024/11/28 01:51:13 INFO  : three.txt: Moved (server-side)
2024/11/28 01:51:13 INFO  : three.txt: Moved into backup dir
2024/11/28 01:51:16 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/28 01:51:16 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/28 01:51:17 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/28 01:51:17 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/28 01:51:17 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/28 01:51:17 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncBackupDir (29.23s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:51:21 DEBUG : dst/one: md5 = 1df8f8c006ada1601528c8d3dd01bbaf OK
2024/11/28 01:51:23 DEBUG : dst/two: md5 = fbddd153a464b9c8bff6c9d6d8fbeaa9 OK
2024/11/28 01:51:24 DEBUG : dst/three.txt: md5 = 2f4c88fa51270bcdf30af08d8ca98e39 OK
2024/11/28 01:51:25 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/dst"
2024/11/28 01:51:25 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/28 01:51:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/backup"
2024/11/28 01:51:26 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/1nrff024r7pq65ecp72fc28jb0"
2024/11/28 01:51:28 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/28 01:51:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for checks to finish
2024/11/28 01:51:28 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:51:28 DEBUG : two: Unchanged skipping
2024/11/28 01:51:30 INFO  : one: Moved (server-side) to: one.bak
2024/11/28 01:51:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for transfers to finish
2024/11/28 01:51:32 DEBUG : one: md5 = 3f22b72a49300c08494cb3899ba76d20 OK
2024/11/28 01:51:32 INFO  : one: Copied (new)
2024/11/28 01:51:32 DEBUG : Waiting for deletions to finish
2024/11/28 01:51:33 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/28 01:51:33 INFO  : three.txt: Moved into backup dir
2024/11/28 01:51:35 DEBUG : dst/three.txt: md5 = 102d5a508cf0ea0a722095b76301c587 OK
2024/11/28 01:51:36 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/28 01:51:36 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:51:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for checks to finish
2024/11/28 01:51:36 DEBUG : two: Unchanged skipping
2024/11/28 01:51:37 INFO  : one.bak: Deleted
2024/11/28 01:51:38 INFO  : one: Moved (server-side) to: one.bak
2024/11/28 01:51:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for transfers to finish
2024/11/28 01:51:40 DEBUG : one: md5 = 8e211726e27d8cae3b4bb8cb733418ec OK
2024/11/28 01:51:40 INFO  : one: Copied (new)
2024/11/28 01:51:40 DEBUG : Waiting for deletions to finish
2024/11/28 01:51:41 INFO  : three.txt.bak: Deleted
2024/11/28 01:51:42 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/28 01:51:42 INFO  : three.txt: Moved into backup dir
2024/11/28 01:51:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/28 01:51:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/28 01:51:46 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/28 01:51:46 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/28 01:51:46 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/28 01:51:46 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncBackupDirWithSuffix (29.15s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:51:50 DEBUG : dst/one: md5 = 45c3d1243abaa9500deea2186919dbe6 OK
2024/11/28 01:51:52 DEBUG : dst/two: md5 = 0e7b165049e49fd79a8e5ef15bc203a8 OK
2024/11/28 01:51:53 DEBUG : dst/three.txt: md5 = cd7cbe2800a29c3e1a84eeb43a0ec7f0 OK
2024/11/28 01:51:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/dst"
2024/11/28 01:51:54 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/28 01:51:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/backup"
2024/11/28 01:51:55 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/1nrff024r7pq65ecp72fc28jb0"
2024/11/28 01:51:57 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/28 01:51:57 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:51:57 DEBUG : two: Unchanged skipping
2024/11/28 01:51:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for checks to finish
2024/11/28 01:51:59 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/28 01:51:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for transfers to finish
2024/11/28 01:52:01 DEBUG : one: md5 = 7fa06a5c480f9c340c515decb49aa114 OK
2024/11/28 01:52:01 INFO  : one: Copied (new)
2024/11/28 01:52:01 DEBUG : Waiting for deletions to finish
2024/11/28 01:52:02 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/28 01:52:02 INFO  : three.txt: Moved into backup dir
2024/11/28 01:52:04 DEBUG : dst/three.txt: md5 = d7857ce42289b5f548acdec1c6d1db01 OK
2024/11/28 01:52:05 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/28 01:52:05 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:52:05 DEBUG : two: Unchanged skipping
2024/11/28 01:52:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for checks to finish
2024/11/28 01:52:06 INFO  : one-2019-01-01: Deleted
2024/11/28 01:52:07 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/28 01:52:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for transfers to finish
2024/11/28 01:52:09 DEBUG : one: md5 = c5053c41978b99686402b7c0693204d1 OK
2024/11/28 01:52:09 INFO  : one: Copied (new)
2024/11/28 01:52:09 DEBUG : Waiting for deletions to finish
2024/11/28 01:52:10 INFO  : three-2019-01-01.txt: Deleted
2024/11/28 01:52:11 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/28 01:52:11 INFO  : three.txt: Moved into backup dir
2024/11/28 01:52:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/28 01:52:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/28 01:52:16 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/28 01:52:16 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/28 01:52:16 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/28 01:52:16 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (29.36s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:52:19 DEBUG : dst/one: md5 = 9b9816790a48948fd2ec023c847cd844 OK
2024/11/28 01:52:21 DEBUG : dst/two: md5 = 3d7345c6fe0c06fffa8350b39682f392 OK
2024/11/28 01:52:23 DEBUG : dst/three.txt: md5 = 6b748b2fdf1885e5c9c68fa690284054 OK
2024/11/28 01:52:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/dst"
2024/11/28 01:52:23 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/28 01:52:24 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/28 01:52:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for checks to finish
2024/11/28 01:52:24 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:52:24 DEBUG : two: Unchanged skipping
2024/11/28 01:52:25 INFO  : one: Moved (server-side) to: one.bak
2024/11/28 01:52:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for transfers to finish
2024/11/28 01:52:27 DEBUG : one: md5 = 9fb660057a8dd02944a9fe6af890e269 OK
2024/11/28 01:52:27 INFO  : one: Copied (new)
2024/11/28 01:52:27 DEBUG : Waiting for deletions to finish
2024/11/28 01:52:28 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/28 01:52:28 INFO  : three.txt: Moved into backup dir
2024/11/28 01:52:30 DEBUG : dst/three.txt: md5 = 30a19a41ac66ffd723ebc0d58889c040 OK
2024/11/28 01:52:31 DEBUG : one.bak: Excluded (Path Filter)
2024/11/28 01:52:31 DEBUG : three.txt.bak: Excluded (Path Filter)
2024/11/28 01:52:31 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/28 01:52:31 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:52:31 DEBUG : two: Unchanged skipping
2024/11/28 01:52:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for checks to finish
2024/11/28 01:52:32 INFO  : one.bak: Deleted
2024/11/28 01:52:32 INFO  : one: Moved (server-side) to: one.bak
2024/11/28 01:52:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki/dst': Waiting for transfers to finish
2024/11/28 01:52:34 DEBUG : one: md5 = 48edf1c30119e6865a83d624b60e35d4 OK
2024/11/28 01:52:34 INFO  : one: Copied (new)
2024/11/28 01:52:34 DEBUG : Waiting for deletions to finish
2024/11/28 01:52:35 INFO  : three.txt.bak: Deleted
2024/11/28 01:52:36 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/28 01:52:36 INFO  : three.txt: Moved into backup dir
2024/11/28 01:52:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/28 01:52:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/28 01:52:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/28 01:52:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/28 01:52:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/28 01:52:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncBackupDirSuffixOnly (23.35s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:52:43 DEBUG : dst/one: md5 = be929d0351e8a8e534b3bba4cac3e624 OK
2024/11/28 01:52:44 DEBUG : dst/two: md5 = 5d29290cc912728632c056ebd7bf876c OK
2024/11/28 01:52:46 DEBUG : dst/three.txt: md5 = 5a544d7a3a19398634983772b25ca6c5 OK
2024/11/28 01:52:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/dst"
2024/11/28 01:52:47 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/28 01:52:48 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/28 01:52:49 INFO  : one: Moved (server-side) to: one.bak
2024/11/28 01:52:50 DEBUG : one: md5 = 4f63d30126f73e722677cb6416334161 OK
2024/11/28 01:52:50 INFO  : one: Copied (new)
2024/11/28 01:52:50 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:52:50 DEBUG : two: Unchanged skipping
2024/11/28 01:52:51 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/11/28 01:52:52 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/28 01:52:53 DEBUG : three.txt: md5 = 30ced3879f0862dc59e415ec2c41c92b OK
2024/11/28 01:52:53 INFO  : three.txt: Copied (new)
2024/11/28 01:52:55 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/28 01:52:55 INFO  : one.bak: Deleted
2024/11/28 01:52:56 INFO  : one: Moved (server-side) to: one.bak
2024/11/28 01:52:58 DEBUG : one: md5 = 93b30be7ae23079af39658476e79e058 OK
2024/11/28 01:52:58 INFO  : one: Copied (new)
2024/11/28 01:52:58 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:52:58 DEBUG : two: Unchanged skipping
2024/11/28 01:52:58 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/11/28 01:52:59 INFO  : three.txt.bak: Deleted
2024/11/28 01:53:00 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/11/28 01:53:02 DEBUG : three.txt: md5 = 8d20d8075b9cd362e2b63f29a17052e2 OK
2024/11/28 01:53:02 INFO  : three.txt: Copied (new)
2024/11/28 01:53:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/28 01:53:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/28 01:53:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/28 01:53:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/28 01:53:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/11/28 01:53:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/11/28 01:53:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncSuffix (26.90s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:53:09 DEBUG : dst/one: md5 = a4273cccc9a1acac9f013680a75c4236 OK
2024/11/28 01:53:11 DEBUG : dst/two: md5 = b47669f8b80a9f9fdf19424f2482e8dc OK
2024/11/28 01:53:13 DEBUG : dst/three.txt: md5 = b7fa350cfe0fa6b76c6bc7bfe6eb793a OK
2024/11/28 01:53:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovinol5toki/dst"
2024/11/28 01:53:13 DEBUG : Creating backend with remote "TestDrive:crypt/mps6ja8qir7cmggfaa0mi36vhmpsg0tgilv8ssmnr7q4u5dd3mfg/31u3jie661vd5p8j7rtc3hgbh0"
2024/11/28 01:53:15 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/11/28 01:53:16 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/28 01:53:17 DEBUG : one: md5 = c6123384960fcd2171fb71f3bb9aaee1 OK
2024/11/28 01:53:17 INFO  : one: Copied (new)
2024/11/28 01:53:18 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:53:18 DEBUG : two: Unchanged skipping
2024/11/28 01:53:18 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/11/28 01:53:19 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/28 01:53:21 DEBUG : three.txt: md5 = 665435f3d76899f60fb47007a80d51f2 OK
2024/11/28 01:53:21 INFO  : three.txt: Copied (new)
2024/11/28 01:53:22 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/11/28 01:53:23 INFO  : one-2019-01-01: Deleted
2024/11/28 01:53:23 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/11/28 01:53:25 DEBUG : one: md5 = 2cbd2d1ec7b6a76214aaf3d8400e97fb OK
2024/11/28 01:53:25 INFO  : one: Copied (new)
2024/11/28 01:53:26 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:53:26 DEBUG : two: Unchanged skipping
2024/11/28 01:53:26 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/11/28 01:53:27 INFO  : three-2019-01-01.txt: Deleted
2024/11/28 01:53:27 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/11/28 01:53:29 DEBUG : three.txt: md5 = df81b941b9e457cdb330636b8e3e5a8d OK
2024/11/28 01:53:29 INFO  : three.txt: Copied (new)
2024/11/28 01:53:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/11/28 01:53:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/11/28 01:53:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/28 01:53:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/11/28 01:53:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/11/28 01:53:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/11/28 01:53:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncSuffixKeepExtension (28.29s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:53:37 DEBUG : Testêé: md5 = 83ab919e8fa3aa88d49612790df65760 OK
2024/11/28 01:53:37 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2024/11/28 01:53:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:53:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:53:39 DEBUG : Testêé: md5 = 6837c07a36ae0a540640c4ab6a276141 OK
2024/11/28 01:53:39 INFO  : Testêé: Copied (replaced existing) to: Testêé
2024/11/28 01:53:39 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (5.34s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:53:41 DEBUG : existing: Need to transfer - File not found at Destination
2024/11/28 01:53:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:53:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:53:43 DEBUG : existing: md5 = 1d490e2bbeeedaa2187e672d5e5728d2 OK
2024/11/28 01:53:43 INFO  : existing: Copied (new)
2024/11/28 01:53:43 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:53:44 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2024/11/28 01:53:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:53:44 ERROR : existing: Source and destination exist but do not match: immutable file modified
2024/11/28 01:53:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:53:44 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': not deleting files as there were IO errors
2024/11/28 01:53:44 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncImmutable (6.38s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:53:49 DEBUG : EXISTING: md5 = d9b75d62322308832ef45f93c9440078 OK
2024/11/28 01:53:49 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:53:49 DEBUG : existing: Unchanged skipping
2024/11/28 01:53:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:53:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:53:49 DEBUG : Waiting for deletions to finish
2024/11/28 01:53:49 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (3.62s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    sync_test.go:2635: Skipping test as local or remote are case-sensitive
--- SKIP: TestFixCase (0.62s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", 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-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", 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-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.83s)
    --- SKIP: TestMaxTransfer/Hard (0.50s)
    --- SKIP: TestMaxTransfer/Soft (0.86s)
    --- SKIP: TestMaxTransfer/Cautious (0.47s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:53:55 DEBUG : both0: md5 = 40aa8865736b025abe6a6b879e57ae6d OK
2024/11/28 01:53:56 DEBUG : only0: md5 = bdf64e669ef4eb69527e20ee9a2de927 OK
2024/11/28 01:53:58 DEBUG : both1: md5 = e35e24f37a90fb4f07bb66712dd5c185 OK
2024/11/28 01:54:00 DEBUG : only1: md5 = 3152609db091212532291de30eaf1cfa OK
2024/11/28 01:54:02 DEBUG : both2: md5 = e2f36f023aef102565b1f8bf2a5fa013 OK
2024/11/28 01:54:04 DEBUG : only2: md5 = 16054c84500f2881bb899dfcc9eefeb0 OK
2024/11/28 01:54:06 DEBUG : both3: md5 = b8f44cecacb655872d433ebf5b2e4961 OK
2024/11/28 01:54:07 DEBUG : only3: md5 = 3f03838eedfed5590eec296304c880b6 OK
2024/11/28 01:54:09 DEBUG : both4: md5 = 2e43909499b20aeee88d8d1c5d2bd7a6 OK
2024/11/28 01:54:11 DEBUG : only4: md5 = 5d044a410391f99dbd2142dfb36a214f OK
2024/11/28 01:54:13 DEBUG : both5: md5 = 63c14397853c118a7dfdbaf53506f5aa OK
2024/11/28 01:54:15 DEBUG : only5: md5 = e9933ddd6514eef03d8f87cbdb303fcb OK
2024/11/28 01:54:16 DEBUG : both6: md5 = e248e5007b6a08e1511bcc81439c4409 OK
2024/11/28 01:54:18 DEBUG : only6: md5 = bd120e07a04642b9c57b8cec689c6fdb OK
2024/11/28 01:54:20 DEBUG : both7: md5 = d3757fe213779f4d30a29d8d627fe08c OK
2024/11/28 01:54:21 DEBUG : only7: md5 = bcfc220bc54b83c7c2cabfab092d4008 OK
2024/11/28 01:54:23 DEBUG : both8: md5 = 6d04b19938eaf3d44527a069b5b36ea7 OK
2024/11/28 01:54:25 DEBUG : only8: md5 = 1a0e7475db6a24140f3205396d82a7cf OK
2024/11/28 01:54:26 DEBUG : both9: md5 = 1865569934076bdb8eaec72a10f0be56 OK
2024/11/28 01:54:28 DEBUG : only9: md5 = d9f4aa61f8a9bdaa0a4150a5fb180958 OK
2024/11/28 01:54:30 DEBUG : both10: md5 = c5f3e034b9fedf2cf1fd209669a0c0e4 OK
2024/11/28 01:54:31 DEBUG : only10: md5 = cdb8825f5624bef2489183fa9503b15e OK
2024/11/28 01:54:33 DEBUG : both11: md5 = 2fefc306b6f1b6c4d49db9d721d78326 OK
2024/11/28 01:54:35 DEBUG : only11: md5 = ba3fa891ac91f7e0a258496a22f221c4 OK
2024/11/28 01:54:37 DEBUG : both12: md5 = 2a8e8aeba8e01d932efd8a0bd550bfce OK
2024/11/28 01:54:39 DEBUG : only12: md5 = 573d40a30e62a839fa963c33bd28aa2b OK
2024/11/28 01:54:40 DEBUG : both13: md5 = 4db9377353c4b040fdfa7b07ecbf3fef OK
2024/11/28 01:54:42 DEBUG : only13: md5 = 52c7d447295ac6a9bcc9daf80ec51075 OK
2024/11/28 01:54:44 DEBUG : both14: md5 = d1183ffc58e4147b18e95c6cc70d51e7 OK
2024/11/28 01:54:45 DEBUG : only14: md5 = 0615bcee12d81320155e7f1971ff408b OK
2024/11/28 01:54:47 DEBUG : both15: md5 = f5a5fb5c62192090130dcaa5d1acf136 OK
2024/11/28 01:54:49 DEBUG : only15: md5 = 7db7fd49aed1cbbdea2b3a4b4d94beca OK
2024/11/28 01:54:51 DEBUG : both16: md5 = 70333866a924b0df90cea5bb9660108d OK
2024/11/28 01:54:52 DEBUG : only16: md5 = c53b26d37b849f3f872c6de9355cc6e9 OK
2024/11/28 01:54:54 DEBUG : both17: md5 = 735e011e3b309903ab6c1902d59cc8b7 OK
2024/11/28 01:54:56 DEBUG : only17: md5 = 63f531e7a1b0d531c1640a3a9feea8a8 OK
2024/11/28 01:54:58 DEBUG : both18: md5 = fd1ddb1636fbf89cdcfd8aca2c636602 OK
2024/11/28 01:54:59 DEBUG : only18: md5 = a52074f8b17d67bbca632adc7a66c2f8 OK
2024/11/28 01:55:01 DEBUG : both19: md5 = a293d697aa1c87b9d3f6140c07685d2f OK
2024/11/28 01:55:03 DEBUG : only19: md5 = 3c53f79dae579c06213603ee93a5ca3c OK
2024/11/28 01:55:03 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:55:03 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:55:03 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:55:03 DEBUG : both0: Unchanged skipping
2024/11/28 01:55:03 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:55:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:55:03 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:55:03 DEBUG : both10: Unchanged skipping
2024/11/28 01:55:03 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:55:03 DEBUG : both13: Unchanged skipping
2024/11/28 01:55:03 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:55:03 DEBUG : both14: Unchanged skipping
2024/11/28 01:55:03 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:55:03 DEBUG : both15: Unchanged skipping
2024/11/28 01:55:03 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:55:03 DEBUG : both16: Unchanged skipping
2024/11/28 01:55:03 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:55:03 DEBUG : both17: Unchanged skipping
2024/11/28 01:55:03 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:55:03 DEBUG : both11: Unchanged skipping
2024/11/28 01:55:03 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:55:03 DEBUG : both19: Unchanged skipping
2024/11/28 01:55:03 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:55:03 DEBUG : both2: Unchanged skipping
2024/11/28 01:55:03 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:55:03 DEBUG : both3: Unchanged skipping
2024/11/28 01:55:03 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:55:03 DEBUG : both4: Unchanged skipping
2024/11/28 01:55:03 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:55:03 DEBUG : both5: Unchanged skipping
2024/11/28 01:55:03 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:55:03 DEBUG : both6: Unchanged skipping
2024/11/28 01:55:03 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:55:03 DEBUG : both7: Unchanged skipping
2024/11/28 01:55:03 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:55:03 DEBUG : both8: Unchanged skipping
2024/11/28 01:55:03 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:55:03 DEBUG : both9: Unchanged skipping
2024/11/28 01:55:03 DEBUG : both1: Unchanged skipping
2024/11/28 01:55:03 DEBUG : both12: Unchanged skipping
2024/11/28 01:55:03 DEBUG : both18: Unchanged skipping
2024/11/28 01:55:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:55:03 DEBUG : Waiting for deletions to finish
2024/11/28 01:55:04 INFO  : only14: Deleted
2024/11/28 01:55:04 INFO  : only5: Deleted
2024/11/28 01:55:04 INFO  : only11: Deleted
2024/11/28 01:55:04 INFO  : only16: Deleted
2024/11/28 01:55:05 INFO  : only6: Deleted
2024/11/28 01:55:05 INFO  : only10: Deleted
2024/11/28 01:55:05 INFO  : only7: Deleted
2024/11/28 01:55:05 INFO  : only13: Deleted
2024/11/28 01:55:05 INFO  : only15: Deleted
2024/11/28 01:55:05 INFO  : only2: Deleted
2024/11/28 01:55:05 INFO  : only12: Deleted
2024/11/28 01:55:05 INFO  : only9: Deleted
2024/11/28 01:55:06 INFO  : only19: Deleted
2024/11/28 01:55:06 INFO  : only3: Deleted
2024/11/28 01:55:06 INFO  : only17: Deleted
2024/11/28 01:55:06 INFO  : only18: Deleted
2024/11/28 01:55:06 INFO  : only1: Deleted
2024/11/28 01:55:06 INFO  : only8: Deleted
2024/11/28 01:55:07 INFO  : only4: Deleted
2024/11/28 01:55:07 INFO  : only0: Deleted
2024/11/28 01:55:07 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (87.13s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:55:22 DEBUG : both0: md5 = c78907b17d8cb934b3b36f561c65aa5d OK
2024/11/28 01:55:23 DEBUG : only0: md5 = b608291dd9544ea9b98023034cc3b6aa OK
2024/11/28 01:55:25 DEBUG : both1: md5 = 68eedc7df1f00463a2f731d4797fd16e OK
2024/11/28 01:55:27 DEBUG : only1: md5 = e597acdac6d28882329353c7bc0da717 OK
2024/11/28 01:55:29 DEBUG : both2: md5 = 60f02cc30fd5a44c875711668518f4eb OK
2024/11/28 01:55:30 DEBUG : only2: md5 = e5919a711006ee9a67a898c21b094282 OK
2024/11/28 01:55:32 DEBUG : both3: md5 = 92f79a2a0312a6b600a48cbaf152fb6f OK
2024/11/28 01:55:33 DEBUG : only3: md5 = 1239b51212f07b0fc360dfbbc338d9b2 OK
2024/11/28 01:55:35 DEBUG : both4: md5 = 323b3d0b2946330fd6425ba9cdb9ec12 OK
2024/11/28 01:55:37 DEBUG : only4: md5 = 50c3ca2db9471a1930f76d51c24123e1 OK
2024/11/28 01:55:39 DEBUG : both5: md5 = 80cafb443fee62910ea31f0289f1e0ec OK
2024/11/28 01:55:41 DEBUG : only5: md5 = b454b164150660ca3faf08e79976b666 OK
2024/11/28 01:55:42 DEBUG : both6: md5 = 0c668e6c8337117af2e4ac7d3649ba70 OK
2024/11/28 01:55:44 DEBUG : only6: md5 = bea08f81e059520da4b06857001c3bae OK
2024/11/28 01:55:46 DEBUG : both7: md5 = 40cc26c9ea74795f55961a56e9cb3dab OK
2024/11/28 01:55:48 DEBUG : only7: md5 = 40d72cebec757537a265d8d8fc6b0154 OK
2024/11/28 01:55:49 DEBUG : both8: md5 = d7805becebfaf3fa6be64bc1f9516d61 OK
2024/11/28 01:55:51 DEBUG : only8: md5 = 4a9c9200aa24084540cc2efca3612c0c OK
2024/11/28 01:55:53 DEBUG : both9: md5 = 90b0bd2528ab0c39ec7dac249a453356 OK
2024/11/28 01:55:55 DEBUG : only9: md5 = e931054629136c15ed06fe020aac8d7f OK
2024/11/28 01:55:57 DEBUG : both10: md5 = 8f5f7625081ae3330a19ea3337a66cc0 OK
2024/11/28 01:55:58 DEBUG : only10: md5 = 12a337221a8362d6242cbf33ad4107d7 OK
2024/11/28 01:56:00 DEBUG : both11: md5 = c3b22b52d05c37d7d28934675594b113 OK
2024/11/28 01:56:02 DEBUG : only11: md5 = c32efca22039f552023433079b4b5d85 OK
2024/11/28 01:56:03 DEBUG : both12: md5 = c06568001f1bc2ecebeacba35475267e OK
2024/11/28 01:56:05 DEBUG : only12: md5 = 60fbb3e2d4ef18a2b70582c70ec440cf OK
2024/11/28 01:56:06 DEBUG : both13: md5 = 92f5e305e41ed877613693901b224fa7 OK
2024/11/28 01:56:08 DEBUG : only13: md5 = e904f59a28d2380f87f2c8c39c27d0b2 OK
2024/11/28 01:56:10 DEBUG : both14: md5 = 5c26fd392b24090d22e457f376bf9768 OK
2024/11/28 01:56:12 DEBUG : only14: md5 = d92989b9edcaf5847184d9009ca6049a OK
2024/11/28 01:56:13 DEBUG : both15: md5 = ff979d70650f85a1f9b958395106d9a0 OK
2024/11/28 01:56:15 DEBUG : only15: md5 = 0d15581d224b97c815ce244d1f9a0688 OK
2024/11/28 01:56:17 DEBUG : both16: md5 = 681110b3d66c27e6463a4b75e8cfef06 OK
2024/11/28 01:56:18 DEBUG : only16: md5 = 43e7918fba5ef0e205274c47287d8202 OK
2024/11/28 01:56:20 DEBUG : both17: md5 = 42311fe1a26885c24480bda73bf77b3e OK
2024/11/28 01:56:22 DEBUG : only17: md5 = f1ac203bc01d1babe2617fbeaaf851f5 OK
2024/11/28 01:56:24 DEBUG : both18: md5 = 4754f3ef3ae12087dc52916a4a11a8cf OK
2024/11/28 01:56:25 DEBUG : only18: md5 = aff348f4bc260224031996947b4f725d OK
2024/11/28 01:56:27 DEBUG : both19: md5 = 186fbe165d679d80f4f924b28bc89d09 OK
2024/11/28 01:56:29 DEBUG : only19: md5 = e420f9e170084ad7e622a63ae5dcdac3 OK
2024/11/28 01:56:29 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:56:29 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:56:29 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:56:29 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:56:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for checks to finish
2024/11/28 01:56:29 DEBUG : both0: Unchanged skipping
2024/11/28 01:56:29 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:56:29 DEBUG : both1: Unchanged skipping
2024/11/28 01:56:29 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:56:29 DEBUG : both13: Unchanged skipping
2024/11/28 01:56:29 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:56:29 DEBUG : both14: Unchanged skipping
2024/11/28 01:56:29 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:56:29 DEBUG : both15: Unchanged skipping
2024/11/28 01:56:29 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:56:29 DEBUG : both16: Unchanged skipping
2024/11/28 01:56:29 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:56:29 DEBUG : both17: Unchanged skipping
2024/11/28 01:56:29 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:56:29 DEBUG : both18: Unchanged skipping
2024/11/28 01:56:29 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:56:29 DEBUG : both19: Unchanged skipping
2024/11/28 01:56:29 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:56:29 DEBUG : both11: Unchanged skipping
2024/11/28 01:56:29 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:56:29 DEBUG : both10: Unchanged skipping
2024/11/28 01:56:29 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:56:29 DEBUG : both12: Unchanged skipping
2024/11/28 01:56:29 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:56:29 DEBUG : both2: Unchanged skipping
2024/11/28 01:56:29 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:56:29 DEBUG : both6: Unchanged skipping
2024/11/28 01:56:29 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:56:29 DEBUG : both7: Unchanged skipping
2024/11/28 01:56:29 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:56:29 DEBUG : both8: Unchanged skipping
2024/11/28 01:56:29 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/11/28 01:56:29 DEBUG : both3: Unchanged skipping
2024/11/28 01:56:29 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2024/11/28 01:56:29 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2024/11/28 01:56:29 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2024/11/28 01:56:29 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2024/11/28 01:56:29 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2024/11/28 01:56:29 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2024/11/28 01:56:29 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2024/11/28 01:56:29 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2024/11/28 01:56:29 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2024/11/28 01:56:29 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2024/11/28 01:56:29 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2024/11/28 01:56:29 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2024/11/28 01:56:29 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2024/11/28 01:56:29 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2024/11/28 01:56:29 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2024/11/28 01:56:29 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2024/11/28 01:56:29 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2024/11/28 01:56:29 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2024/11/28 01:56:29 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2024/11/28 01:56:29 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2024/11/28 01:56:29 DEBUG : both4: Unchanged skipping
2024/11/28 01:56:29 DEBUG : both5: Unchanged skipping
2024/11/28 01:56:29 DEBUG : both9: Unchanged skipping
2024/11/28 01:56:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Waiting for transfers to finish
2024/11/28 01:56:31 DEBUG : only0: md5 = 46148b3bf9666e612cc6ee2301dc9277 OK
2024/11/28 01:56:31 INFO  : only0: Copied (replaced existing)
2024/11/28 01:56:31 DEBUG : only10: md5 = a9778dd6ee2ad8911d80253f33e30460 OK
2024/11/28 01:56:31 INFO  : only10: Copied (replaced existing)
2024/11/28 01:56:31 DEBUG : only1: md5 = 732c9fa6dd09b14d57f79a92f200e387 OK
2024/11/28 01:56:31 INFO  : only1: Copied (replaced existing)
2024/11/28 01:56:31 DEBUG : only11: md5 = 159ab0511f9b582853216b9aca5b3b71 OK
2024/11/28 01:56:31 INFO  : only11: Copied (replaced existing)
2024/11/28 01:56:32 DEBUG : only12: md5 = d867028e9084ba6cb1feac8c0bb374cc OK
2024/11/28 01:56:32 INFO  : only12: Copied (replaced existing)
2024/11/28 01:56:32 DEBUG : only14: md5 = e3d5bb9722d3c224b824f474fc2bf67a OK
2024/11/28 01:56:32 INFO  : only14: Copied (replaced existing)
2024/11/28 01:56:32 DEBUG : only13: md5 = 4bec120ee30c40b4cb77dc29e3538fbf OK
2024/11/28 01:56:32 INFO  : only13: Copied (replaced existing)
2024/11/28 01:56:32 DEBUG : only15: md5 = 912e8a9c179704a0989c512af3efb6d6 OK
2024/11/28 01:56:32 INFO  : only15: Copied (replaced existing)
2024/11/28 01:56:33 DEBUG : only16: md5 = fa905761710c4388313e8e5541c9773a OK
2024/11/28 01:56:33 INFO  : only16: Copied (replaced existing)
2024/11/28 01:56:34 DEBUG : only19: md5 = f53999dae2953689f33b4368176f7c58 OK
2024/11/28 01:56:34 INFO  : only19: Copied (replaced existing)
2024/11/28 01:56:34 DEBUG : only18: md5 = 446ced8dad462ea39a6689dd878b5ccc OK
2024/11/28 01:56:34 INFO  : only18: Copied (replaced existing)
2024/11/28 01:56:34 DEBUG : only17: md5 = f79ca75cdfe310f8a755512d2ad71389 OK
2024/11/28 01:56:34 INFO  : only17: Copied (replaced existing)
2024/11/28 01:56:35 DEBUG : only2: md5 = 4276fc6203dbc9068088aa803f28864d OK
2024/11/28 01:56:35 INFO  : only2: Copied (replaced existing)
2024/11/28 01:56:35 DEBUG : only4: md5 = 10f6bfbfa4eb7005c64e5489e8928d25 OK
2024/11/28 01:56:35 INFO  : only4: Copied (replaced existing)
2024/11/28 01:56:35 DEBUG : only5: md5 = 016a4b222ce4faa49db18dc7ccffb143 OK
2024/11/28 01:56:35 INFO  : only5: Copied (replaced existing)
2024/11/28 01:56:35 DEBUG : only3: md5 = f328df671685099fd1e20c641c85271f OK
2024/11/28 01:56:35 INFO  : only3: Copied (replaced existing)
2024/11/28 01:56:36 DEBUG : only6: md5 = 79130d836ce7f2e6c8feef457ac341fe OK
2024/11/28 01:56:36 INFO  : only6: Copied (replaced existing)
2024/11/28 01:56:36 DEBUG : only7: md5 = 30bcaca2d0e19b01c0fed722931ab590 OK
2024/11/28 01:56:36 INFO  : only7: Copied (replaced existing)
2024/11/28 01:56:36 DEBUG : only8: md5 = b39cf6ab2c9f186357a709809da4a937 OK
2024/11/28 01:56:36 INFO  : only8: Copied (replaced existing)
2024/11/28 01:56:36 DEBUG : only9: md5 = 74af1b473a646566371eafb6a6fbb0fc OK
2024/11/28 01:56:36 INFO  : only9: Copied (replaced existing)
2024/11/28 01:56:36 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (101.59s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:57:02 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 01:57:02 DEBUG : sub dir: Making directory with metadata
2024/11/28 01:57:03 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:57:24 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/28 01:57:24 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/28 01:57:24 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 01:57:24 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:57:41 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2024/11/28 01:57:42 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/28 01:57:43 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/11/28 01:57:45 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/11/28 01:57:46 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/28 01:57:47 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/28 01:57:48 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/28 01:57:49 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/28 01:57:50 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/28 01:57:51 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/11/28 01:57:51 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/28 01:57:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (52.33s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:57:54 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/11/28 01:57:54 DEBUG : sub dir: Making directory with metadata
2024/11/28 01:57:55 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:58:21 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/28 01:58:22 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/11/28 01:58:22 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/11/28 01:58:22 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki'", Local "Local file system at /tmp/rclone3020861414", Modify Window "1ms"
2024/11/28 01:58:37 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/28 01:58:38 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/11/28 01:58:39 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/11/28 01:58:39 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/28 01:58:40 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/28 01:58:41 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/28 01:58:42 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/28 01:58:43 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/11/28 01:58:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/11/28 01:58:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/11/28 01:58:45 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (53.51s)
PASS
2024/11/28 01:58:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovinol5toki': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 18m55.200286323s (try 1/5)