"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5)
2024/10/01 04:11:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko"
2024/10/01 04:11:20 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2024/10/01 04:11:20 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0"
2024/10/01 04:11:21 DEBUG : Creating backend with remote "/tmp/rclone3304300658"
=== RUN   TestPipe
--- PASS: TestPipe (0.00s)
=== RUN   TestPipeConcurrent
--- PASS: TestPipeConcurrent (0.05s)
=== 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-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:11:23 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/10/01 04:11:23 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/10/01 04:11:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:11:23 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2024/10/01 04:11:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:11:23 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (2.69s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:11:24 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/10/01 04:11:24 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/10/01 04:11:24 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/10/01 04:11:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:11:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:11:27 DEBUG : sub dir/hello world: md5 = 030a35cba7c99ac2ec83f671f8db2239 OK
2024/10/01 04:11:27 INFO  : sub dir/hello world: Copied (new)
2024/10/01 04:11:28 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:11:31 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (8.00s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:11:32 DEBUG : metadata sub dir: Making directory with metadata
2024/10/01 04:11:32 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/10/01 04:11:32 DEBUG : empty metadata sub dir: Making directory with metadata
2024/10/01 04:11:32 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/10/01 04:11:32 DEBUG : Local file system at /tmp/rclone3304300658: File to upload is small (21 bytes), uploading instead of streaming
2024/10/01 04:11:32 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/10/01 04:11:32 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/10/01 04:11:32 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/10/01 04:11:33 DEBUG : Google drive root 'crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0': Skipping btime metadata as can't update it on an existing file: 2024-10-01T04:11:32.648127957Z
2024/10/01 04:11:33 INFO  : empty metadata sub dir: Updated directory metadata
2024/10/01 04:11:34 DEBUG : Google drive root 'crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0': Skipping btime metadata as can't update it on an existing file: 2024-10-01T04:11:32.648127957Z
2024/10/01 04:11:35 INFO  : metadata sub dir: Updated directory metadata
2024/10/01 04:11:35 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/10/01 04:11:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:11:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:11:37 DEBUG : metadata sub dir/hello metadata world: md5 = ac77c9541746027a15b51759add770c0 OK
2024/10/01 04:11:37 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:11:40 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (10.22s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:11:42 DEBUG : metadata sub dir: Making directory with metadata
2024/10/01 04:11:42 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/10/01 04:11:42 DEBUG : empty metadata sub dir: Making directory with metadata
2024/10/01 04:11:42 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/10/01 04:11:42 DEBUG : Local file system at /tmp/rclone3304300658: File to upload is small (21 bytes), uploading instead of streaming
2024/10/01 04:11:42 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2024/10/01 04:11:42 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2024/10/01 04:11:42 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2024/10/01 04:11:43 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2024/10/01 04:11:43 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2024/10/01 04:11:43 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2024/10/01 04:11:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:11:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:11:46 DEBUG : metadata sub dir/hello metadata world: md5 = 67519088e3fb770f12833dc9a1aaba3d OK
2024/10/01 04:11:46 INFO  : metadata sub dir/hello metadata world: Copied (new)
2024/10/01 04:11:46 DEBUG : Google drive root 'crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0': Skipping btime metadata as can't update it on an existing file: 2024-10-01T04:11:42.868075583Z
2024/10/01 04:11:46 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:11:50 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (9.10s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:11:51 DEBUG : Creating backend with remote "/non-existing"
2024/10/01 04:11:52 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2024/10/01 04:11:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:11:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.28s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:11:53 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/10/01 04:11:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/10/01 04:11:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:11:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:11:56 DEBUG : sub dir/hello world: md5 = f51aa8e88e0513271f9be11f7b49b4dc OK
2024/10/01 04:11:56 INFO  : sub dir/hello world: Copied (new)
2024/10/01 04:11:57 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:11:59 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (7.63s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:12:00 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Running all checks before starting transfers
2024/10/01 04:12:01 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/10/01 04:12:01 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/10/01 04:12:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:12:01 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Checks finished, now starting transfers
2024/10/01 04:12:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:12:04 DEBUG : sub dir/hello world: md5 = c6b8f9062569fe98d263104a66abffbd OK
2024/10/01 04:12:04 INFO  : sub dir/hello world: Copied (new)
2024/10/01 04:12:04 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:12:07 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (7.78s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:12:08 ERROR : Ignoring --no-traverse with sync
2024/10/01 04:12:08 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/10/01 04:12:08 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/10/01 04:12:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:12:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:12:11 DEBUG : sub dir/hello world: md5 = 3ecc554ffb418eb2e68220b03db5c1f8 OK
2024/10/01 04:12:11 INFO  : sub dir/hello world: Copied (new)
2024/10/01 04:12:11 DEBUG : Waiting for deletions to finish
2024/10/01 04:12:12 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:12:14 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (7.54s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:12:16 DEBUG : hello world2: Need to transfer - File not found at Destination
2024/10/01 04:12:16 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/10/01 04:12:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:12:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:12:18 DEBUG : hello world2: md5 = 770fbce4c7ed667ef59831fce01684d5 OK
2024/10/01 04:12:18 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestCopyWithDepth (4.40s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:12:20 DEBUG : potato2: Need to transfer - File not found at Destination
2024/10/01 04:12:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:12:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:12:22 DEBUG : potato2: md5 = f7a4ebf730b5a9f25fa0fc4ce427a464 OK
2024/10/01 04:12:22 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (4.03s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:12:24 DEBUG : potato2: Need to transfer - File not found at Destination
2024/10/01 04:12:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:12:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:12:26 DEBUG : potato2: md5 = a2c7c45510d587de8eb4664e88d76d4e OK
2024/10/01 04:12:26 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (4.18s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:12:28 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/10/01 04:12:28 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/10/01 04:12:28 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/10/01 04:12:28 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/10/01 04:12:29 DEBUG : sub dir: Making directory with metadata
2024/10/01 04:12:30 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/10/01 04:12:30 DEBUG : sub dir2: Making directory with metadata
2024/10/01 04:12:31 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/10/01 04:12:31 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/10/01 04:12:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/10/01 04:12:32 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/10/01 04:12:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:12:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:12:33 DEBUG : sub dir/hello world: md5 = 41178123479cc620e0e9a0774cf67e6c OK
2024/10/01 04:12:33 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:12:37 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2024/10/01 04:12:38 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (11.41s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:12:40 DEBUG : sub dir2: Making directory
2024/10/01 04:12:40 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2024/10/01 04:12:40 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/10/01 04:12:40 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/10/01 04:12:40 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/10/01 04:12:40 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2024/10/01 04:12:40 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/10/01 04:12:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:12:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:12:43 DEBUG : sub dir/hello world: md5 = fe96b7858f242400cd61c52c5ce7d4e2 OK
2024/10/01 04:12:43 INFO  : sub dir/hello world: Copied (new)
2024/10/01 04:12:43 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/10/01 04:12:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (6.94s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:12:47 DEBUG : sub dir2: Making directory with metadata
2024/10/01 04:12:47 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/10/01 04:12:47 DEBUG : sub dir: Making directory with metadata
2024/10/01 04:12:48 INFO  : sub dir: Made directory with metadata (mtime=2024-10-01T04:12:47.147746106Z)
2024/10/01 04:12:48 DEBUG : sub dir2: Making directory with metadata
2024/10/01 04:12:49 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/10/01 04:12:49 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/10/01 04:12:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:12:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:12:51 DEBUG : sub dir/hello world: md5 = b10555a35a91b8cb2e64ecb11c757977 OK
2024/10/01 04:12:51 INFO  : sub dir/hello world: Copied (new)
2024/10/01 04:12:51 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:12:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (9.22s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:12:56 DEBUG : sub dir no update dir modtime: Making directory with metadata
2024/10/01 04:12:56 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/10/01 04:12:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:12:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:12:58 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (5.31s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:13:01 DEBUG : sub dir2: Making directory
2024/10/01 04:13:01 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/10/01 04:13:01 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/10/01 04:13:01 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/10/01 04:13:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:13:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:13:04 DEBUG : sub dir/hello world: md5 = ce089e098e0a6a5913646564b60918bd OK
2024/10/01 04:13:04 INFO  : sub dir/hello world: Copied (new)
2024/10/01 04:13:04 INFO  : sub dir/hello world: Deleted
2024/10/01 04:13:05 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/10/01 04:13:07 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (6.72s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:13:08 DEBUG : sub dir2: Making directory with metadata
2024/10/01 04:13:08 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/10/01 04:13:08 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/10/01 04:13:08 DEBUG : sub dir: Making directory with metadata
2024/10/01 04:13:09 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2024/10/01 04:13:09 DEBUG : sub dir2: Making directory with metadata
2024/10/01 04:13:10 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/10/01 04:13:10 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/10/01 04:13:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:13:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:13:12 DEBUG : sub dir/hello world: md5 = 96c7e838a9c37950d177fc2c0f3157d1 OK
2024/10/01 04:13:12 INFO  : sub dir/hello world: Copied (new)
2024/10/01 04:13:12 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:13:16 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (9.87s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.52s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:13:18 DEBUG : sub dir2: Making directory
2024/10/01 04:13:19 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/10/01 04:13:19 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2024/10/01 04:13:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/10/01 04:13:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:13:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:13:22 DEBUG : sub dir/hello world: md5 = e51ad8795b5d3a2f537009aef546523f OK
2024/10/01 04:13:22 INFO  : sub dir/hello world: Copied (new)
2024/10/01 04:13:22 DEBUG : Waiting for deletions to finish
2024/10/01 04:13:22 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/10/01 04:13:25 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (7.43s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:13:28 DEBUG : sub dir/hello world: md5 = 3e7feac4b73357d7fad236d222bac6c7 OK
2024/10/01 04:13:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qotases7bowu"
2024/10/01 04:13:29 DEBUG : Config file has changed externally - reloading
2024/10/01 04:13:29 DEBUG : Creating backend with remote "TestDrive:crypt/hluqm08ebt81oigin2rb2gidp6kfld5uti8sen87l2pf2gk2ir10"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko' -> Encrypted drive 'TestCryptDrive:rclone-test-qotases7bowu'
2024/10/01 04:13:32 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/10/01 04:13:32 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/10/01 04:13:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qotases7bowu': Waiting for checks to finish
2024/10/01 04:13:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qotases7bowu': Waiting for transfers to finish
2024/10/01 04:13:36 INFO  : sub dir/hello world: Copied (server-side copy)
2024/10/01 04:13:36 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:13:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qotases7bowu': Purge remote
2024/10/01 04:13:39 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (14.74s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:13:43 DEBUG : sub dir/hello world: md5 = 1e3dfa376fb8b36982c7e1631294aeb3 OK
2024/10/01 04:13:44 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/10/01 04:13:45 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/10/01 04:13:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:13:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:13:46 DEBUG : sub dir/hello world: md5 = 7e5dccb4486d3f0731eb679c01d8324a OK
2024/10/01 04:13:46 INFO  : sub dir/hello world: Copied (replaced existing)
2024/10/01 04:13:47 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:13:50 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (10.81s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:13:54 DEBUG : sub dir/hello world: md5 = a1f5a0642375b0632c5f6bcb63ec013e OK
2024/10/01 04:13:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zayeguh2pevi"
2024/10/01 04:13:55 DEBUG : Config file has changed externally - reloading
2024/10/01 04:13:55 DEBUG : Creating backend with remote "TestDrive:crypt/1374j3btati8o6kg44vrds2o7c1hf8985fff9mtf10du1lc1s840"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko' -> Encrypted drive 'TestCryptDrive:rclone-test-zayeguh2pevi'
2024/10/01 04:13:56 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/10/01 04:13:57 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/10/01 04:13:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zayeguh2pevi': Waiting for checks to finish
2024/10/01 04:13:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zayeguh2pevi': Waiting for transfers to finish
2024/10/01 04:14:00 INFO  : sub dir/hello world: Copied (server-side copy)
2024/10/01 04:14:01 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:14:04 DEBUG : sub dir/hello world: md5 = ca2ca63a61b7ef997e2da172e3f3dca2 OK
2024/10/01 04:14:05 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/10/01 04:14:05 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/10/01 04:14:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zayeguh2pevi': Waiting for checks to finish
2024/10/01 04:14:05 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/10/01 04:14:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zayeguh2pevi': Waiting for transfers to finish
2024/10/01 04:14:07 INFO  : sub dir/hello world: Copied (server-side copy)
2024/10/01 04:14:08 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:14:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zayeguh2pevi': Purge remote
2024/10/01 04:14:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (21.57s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:14:16 DEBUG : sub dir/hello world: md5 = 8a7fa783ee4109450e16cd0c38186888 OK
2024/10/01 04:14:17 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/10/01 04:14:17 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/10/01 04:14:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:14:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:14:19 DEBUG : sub dir/hello world: md5 = 028c2182fcf25edceeb57fe69af8bf96 OK
2024/10/01 04:14:19 INFO  : sub dir/hello world: Copied (replaced existing)
2024/10/01 04:14:19 INFO  : sub dir/hello world: Deleted
2024/10/01 04:14:19 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:14:22 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (10.34s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:14:26 DEBUG : sub dir/hello world: md5 = 292923b8e5aafcf87c23923442c8e609 OK
2024/10/01 04:14:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fonidal8vuvi"
2024/10/01 04:14:27 DEBUG : Config file has changed externally - reloading
2024/10/01 04:14:27 DEBUG : Creating backend with remote "TestDrive:crypt/qd9spebsliua2ibkbuh08cglsci9be63khll7i1ls1rnc5j1mmqg"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko' -> Encrypted drive 'TestCryptDrive:rclone-test-fonidal8vuvi'
2024/10/01 04:14:28 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/10/01 04:14:29 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/10/01 04:14:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fonidal8vuvi': Waiting for checks to finish
2024/10/01 04:14:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fonidal8vuvi': Waiting for transfers to finish
2024/10/01 04:14:33 INFO  : sub dir/hello world: Copied (server-side copy)
2024/10/01 04:14:33 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:14:36 DEBUG : sub dir/hello world: md5 = f906ccf58a597922efbd3291bfe84492 OK
2024/10/01 04:14:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fonidal8vuvi': Using server-side directory move
2024/10/01 04:14:36 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-fonidal8vuvi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/10/01 04:14:37 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/10/01 04:14:37 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/10/01 04:14:37 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2024/10/01 04:14:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fonidal8vuvi': Waiting for checks to finish
2024/10/01 04:14:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fonidal8vuvi': Waiting for transfers to finish
2024/10/01 04:14:38 INFO  : sub dir/hello world: Deleted
2024/10/01 04:14:39 INFO  : sub dir/hello world: Moved (server-side)
2024/10/01 04:14:39 INFO  : sub dir: Set directory modification time (using SetModTime)
2024/10/01 04:14:42 DEBUG : sub dir/hello world: md5 = d18d0e884d8745abd3e8402509ded7e5 OK
2024/10/01 04:14:43 DEBUG : testing file moves
2024/10/01 04:14:44 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2024/10/01 04:14:44 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2024/10/01 04:14:44 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2024/10/01 04:14:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fonidal8vuvi': Waiting for checks to finish
2024/10/01 04:14:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fonidal8vuvi': Waiting for transfers to finish
2024/10/01 04:14:45 INFO  : sub dir/hello world: Deleted
2024/10/01 04:14:45 INFO  : sub dir/hello world: Moved (server-side)
2024/10/01 04:14:46 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:14:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fonidal8vuvi': Purge remote
--- PASS: TestServerSideMoveOverSelf (27.59s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:14:54 DEBUG : sub dir/hello world: md5 = c425f28161830bcb9f316cd7bdaa73f1 OK
2024/10/01 04:14:54 ERROR : : error listing: directory not found
2024/10/01 04:14:55 DEBUG : Local file system at /tmp/rclone3304300658: Making directory
2024/10/01 04:14:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:14:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:14:58 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (8.43s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:15:02 DEBUG : sub dir/hello world: md5 = 5bb2cc812071837750c3f90a9f9bbba1 OK
2024/10/01 04:15:03 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/10/01 04:15:03 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/10/01 04:15:03 DEBUG : Local file system at /tmp/rclone3304300658: Waiting for checks to finish
2024/10/01 04:15:03 DEBUG : Local file system at /tmp/rclone3304300658: Waiting for transfers to finish
2024/10/01 04:15:04 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2024/10/01 04:15:04 INFO  : sub dir/hello world: Copied (new)
2024/10/01 04:15:04 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:15:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (8.24s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:15:08 DEBUG : check sum: Need to transfer - File not found at Destination
2024/10/01 04:15:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:15:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:15:10 DEBUG : check sum: md5 = 158265c124d994d4ba3ac1e2b04d6e29 OK
2024/10/01 04:15:10 INFO  : check sum: Copied (new)
2024/10/01 04:15:10 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:15:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:15:10 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2024/10/01 04:15:10 DEBUG : check sum: Size of src and dst objects identical
2024/10/01 04:15:10 DEBUG : check sum: Unchanged skipping
2024/10/01 04:15:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:15:10 DEBUG : Waiting for deletions to finish
2024/10/01 04:15:10 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (5.41s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:15:13 DEBUG : sizeonly: Need to transfer - File not found at Destination
2024/10/01 04:15:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:15:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:15:15 DEBUG : sizeonly: md5 = 04240d38fff631c4780e11abaa930b00 OK
2024/10/01 04:15:15 INFO  : sizeonly: Copied (new)
2024/10/01 04:15:15 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:15:16 DEBUG : sizeonly: Sizes identical
2024/10/01 04:15:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:15:16 DEBUG : sizeonly: Unchanged skipping
2024/10/01 04:15:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:15:16 DEBUG : Waiting for deletions to finish
2024/10/01 04:15:16 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (5.30s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:15:18 DEBUG : ignore-size: Need to transfer - File not found at Destination
2024/10/01 04:15:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:15:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:15:20 DEBUG : ignore-size: md5 = c982eb7e6b2ab0447753619eb4baf3b1 OK
2024/10/01 04:15:20 INFO  : ignore-size: Copied (new)
2024/10/01 04:15:20 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:15:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:15:21 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:15:21 DEBUG : ignore-size: Unchanged skipping
2024/10/01 04:15:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:15:21 DEBUG : Waiting for deletions to finish
2024/10/01 04:15:21 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (5.40s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:15:26 DEBUG : existing: md5 = bdd78ae50b17c8f5eaadf0e39059cca1 OK
2024/10/01 04:15:26 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:15:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:15:26 DEBUG : existing: Unchanged skipping
2024/10/01 04:15:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:15:26 DEBUG : Waiting for deletions to finish
2024/10/01 04:15:26 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:15:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:15:27 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2024/10/01 04:15:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:15:28 DEBUG : existing: md5 = c0d19d92a806c35cf00ca2ac8d3295bc OK
2024/10/01 04:15:28 INFO  : existing: Copied (replaced existing)
2024/10/01 04:15:28 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (7.20s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:15:31 DEBUG : existing: Need to transfer - File not found at Destination
2024/10/01 04:15:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:15:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:15:33 DEBUG : existing: md5 = ead3bee4baa92a057bf8344d540172fc OK
2024/10/01 04:15:33 INFO  : existing: Copied (new)
2024/10/01 04:15:33 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:15:34 DEBUG : existing: Destination exists, skipping
2024/10/01 04:15:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:15:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:15:34 DEBUG : Waiting for deletions to finish
2024/10/01 04:15:34 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (5.40s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:15:39 DEBUG : b/potato: md5 = 527a88df6f77884afe3a9bc382a7a4c3 OK
2024/10/01 04:15:42 DEBUG : c/non empty space: md5 = a904b899f7368b28dd42e6b05be7ec25 OK
2024/10/01 04:15:42 DEBUG : d: Making directory
2024/10/01 04:15:44 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/10/01 04:15:44 DEBUG : Added delayed dir = "c", newDst=c
2024/10/01 04:15:44 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/10/01 04:15:44 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:15:44 DEBUG : c/non empty space: Unchanged skipping
2024/10/01 04:15:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:15:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:15:47 DEBUG : a/potato2: md5 = 3f34fb1ba432f480352a396193f58b67 OK
2024/10/01 04:15:47 INFO  : a/potato2: Copied (new)
2024/10/01 04:15:47 DEBUG : Waiting for deletions to finish
2024/10/01 04:15:48 INFO  : b/potato: Deleted
2024/10/01 04:15:48 INFO  : a: Set directory modification time (using DirSetModTime)
2024/10/01 04:15:48 INFO  : d: Removing directory
2024/10/01 04:15:49 INFO  : b: Removing directory
2024/10/01 04:15:49 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/10/01 04:15:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:15:53 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/10/01 04:15:54 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (19.24s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:15:57 DEBUG : empty space: md5 = 6ebdb1b06871752b1ea60dd399ce609a OK
2024/10/01 04:15:58 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/10/01 04:15:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:15:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:15:58 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2024/10/01 04:15:58 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:15:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:15:59 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/10/01 04:15:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:16:00 DEBUG : empty space: md5 = 977c5e4011b0128022b4dc83298f22b6 OK
2024/10/01 04:16:00 INFO  : empty space: Copied (replaced existing)
2024/10/01 04:16:00 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (7.35s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.54s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:16:05 DEBUG : foo: md5 = 8d5ef21a676157b0b2ee5bbcec96a593 OK
2024/10/01 04:16:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:16:06 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/10/01 04:16:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:16:08 DEBUG : foo: md5 = 1a2346ac102ce33796b9bc12de276a18 OK
2024/10/01 04:16:08 INFO  : foo: Copied (replaced existing)
2024/10/01 04:16:08 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (6.38s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:16:11 DEBUG : empty space: md5 = 8186608e191e162c6b4699cf9af92626 OK
2024/10/01 04:16:12 DEBUG : potato: Need to transfer - File not found at Destination
2024/10/01 04:16:12 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:16:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:16:12 DEBUG : empty space: Unchanged skipping
2024/10/01 04:16:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:16:14 DEBUG : potato: md5 = 1e377af43b611759a8ae80bf35bbe9bb OK
2024/10/01 04:16:14 INFO  : potato: Copied (new)
2024/10/01 04:16:14 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (7.39s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:16:19 DEBUG : potato: md5 = 7cea6026e2c254657ce0fd14ecb2e436 OK
2024/10/01 04:16:19 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2024/10/01 04:16:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:16:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:16:21 DEBUG : potato: md5 = e480d8c4ca22eb37b3d6a68dc7caa237 OK
2024/10/01 04:16:21 INFO  : potato: Copied (replaced existing)
2024/10/01 04:16:21 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (6.11s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:16:25 DEBUG : potato: md5 = 28fa678cc90525fd93412f809d267b41 OK
2024/10/01 04:16:26 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/10/01 04:16:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:16:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:16:27 DEBUG : potato: md5 = 3245d0816fe8e06b5a5bf1fdfa3c2e02 OK
2024/10/01 04:16:27 INFO  : potato: Copied (replaced existing)
2024/10/01 04:16:27 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (5.89s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:16:31 DEBUG : potato: md5 = 6cee8859dec52c6491e97da0e612987f OK
2024/10/01 04:16:33 DEBUG : empty space: md5 = 91ca091037d1bb423e026094f916a09a OK
2024/10/01 04:16:33 DEBUG : potato2: Need to transfer - File not found at Destination
2024/10/01 04:16:33 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2024/10/01 04:16:33 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:16:33 DEBUG : empty space: Unchanged skipping
2024/10/01 04:16:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:16:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:16:33 DEBUG : Waiting for deletions to finish
2024/10/01 04:16:33 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (6.66s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:16:38 DEBUG : potato: md5 = 12e7773e6e874992112556ffa62be489 OK
2024/10/01 04:16:39 DEBUG : empty space: md5 = df34533b23950a341ddb93d8cf26429c OK
2024/10/01 04:16:40 DEBUG : potato2: Need to transfer - File not found at Destination
2024/10/01 04:16:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:16:40 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:16:40 DEBUG : empty space: Unchanged skipping
2024/10/01 04:16:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:16:42 DEBUG : potato2: md5 = 31f58f6a99587911f6b0dcde7b87e562 OK
2024/10/01 04:16:42 INFO  : potato2: Copied (new)
2024/10/01 04:16:42 DEBUG : Waiting for deletions to finish
2024/10/01 04:16:43 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (9.63s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:16:48 DEBUG : b/potato: md5 = 90f140921c2ff3edf592428ee7013506 OK
2024/10/01 04:16:51 DEBUG : c/non empty space: md5 = 35c4da71f1e847be4821712d1fb5e5ed OK
2024/10/01 04:16:51 DEBUG : d: Making directory
2024/10/01 04:16:52 DEBUG : d/e: Making directory
2024/10/01 04:16:55 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/10/01 04:16:55 DEBUG : Added delayed dir = "c", newDst=c
2024/10/01 04:16:55 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/10/01 04:16:55 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:16:55 DEBUG : c/non empty space: Unchanged skipping
2024/10/01 04:16:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:16:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:16:57 DEBUG : a/potato2: md5 = 2414ca2c88a8f3c4a6cdb0bf70ba0fb1 OK
2024/10/01 04:16:57 INFO  : a/potato2: Copied (new)
2024/10/01 04:16:57 DEBUG : Waiting for deletions to finish
2024/10/01 04:16:58 INFO  : b/potato: Deleted
2024/10/01 04:16:59 INFO  : a: Set directory modification time (using DirSetModTime)
2024/10/01 04:16:59 INFO  : d/e: Removing directory
2024/10/01 04:17:00 INFO  : d: Removing directory
2024/10/01 04:17:00 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2024/10/01 04:17:01 INFO  : b: Removing directory
2024/10/01 04:17:01 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/10/01 04:17:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:17:05 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/10/01 04:17:06 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (21.83s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:17:10 DEBUG : b/potato: md5 = 661cb1c76b2aaeb98a84da77c04abaf2 OK
2024/10/01 04:17:13 DEBUG : c/non empty space: md5 = 84b58ec951f2a3b0ee8dd996c478c6bc OK
2024/10/01 04:17:13 DEBUG : d: Making directory
2024/10/01 04:17:15 DEBUG : Added delayed dir = "a", newDst=<nil>
2024/10/01 04:17:15 DEBUG : Added delayed dir = "c", newDst=c
2024/10/01 04:17:15 DEBUG : a/potato2: Need to transfer - File not found at Destination
2024/10/01 04:17:15 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:17:15 DEBUG : c/non empty space: Unchanged skipping
2024/10/01 04:17:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:17:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:17:18 DEBUG : a/potato2: md5 = 19d4dfe140cad0f6608e05b7e93729ff OK
2024/10/01 04:17:18 INFO  : a/potato2: Copied (new)
2024/10/01 04:17:18 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': not deleting files as there were IO errors
2024/10/01 04:17:19 INFO  : a: Set directory modification time (using DirSetModTime)
2024/10/01 04:17:19 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:17:23 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2024/10/01 04:17:24 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2024/10/01 04:17:25 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (19.77s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:17:29 DEBUG : potato: md5 = 409d5caa6112eb0d198136c0bf75f1d7 OK
2024/10/01 04:17:30 DEBUG : empty space: md5 = 3031558b56f01f47860f163e975b43cb OK
2024/10/01 04:17:31 DEBUG : Waiting for deletions to finish
2024/10/01 04:17:31 DEBUG : potato2: Need to transfer - File not found at Destination
2024/10/01 04:17:31 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:17:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:17:31 DEBUG : empty space: Unchanged skipping
2024/10/01 04:17:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:17:32 INFO  : potato: Deleted
2024/10/01 04:17:33 DEBUG : potato2: md5 = f543de93ce1c24ef9ce322d732371ad9 OK
2024/10/01 04:17:33 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (8.57s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:17:37 DEBUG : potato: md5 = 6e6585f4923ed7b00090f8aac35e41fa OK
2024/10/01 04:17:39 DEBUG : empty space: md5 = 098a10d27524cbfda5fce97151ac5685 OK
2024/10/01 04:17:40 DEBUG : Waiting for deletions to finish
2024/10/01 04:17:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:17:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:17:40 INFO  : potato: Deleted
2024/10/01 04:17:41 DEBUG : potato2: Need to transfer - File not found at Destination
2024/10/01 04:17:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:17:41 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:17:41 DEBUG : empty space: Unchanged skipping
2024/10/01 04:17:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:17:43 DEBUG : potato2: md5 = 133b4e0f589c40f6e023daf7098d8117 OK
2024/10/01 04:17:43 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (9.70s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:17:48 DEBUG : potato: md5 = d3dcd8a55314823e571ddbc092e6ebcc OK
2024/10/01 04:17:48 DEBUG : potato2: Need to transfer - File not found at Destination
2024/10/01 04:17:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:17:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:17:50 DEBUG : potato2: md5 = 7dfaca5ddfacee541a581bdbbb22a29d OK
2024/10/01 04:17:50 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (7.64s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:17:55 DEBUG : potato2: md5 = b1bdb7106f0f82e4150c79074f76e1b9 OK
2024/10/01 04:17:56 DEBUG : empty space: md5 = c205d403f1befdbbb011fafdf8ff4e59 OK
2024/10/01 04:17:57 DEBUG : enormous: Excluded (Size Filter)
2024/10/01 04:17:57 DEBUG : enormous: Excluded
2024/10/01 04:17:57 DEBUG : potato2: Excluded (Size Filter)
2024/10/01 04:17:57 DEBUG : potato2: Excluded
2024/10/01 04:17:57 DEBUG : potato2: Excluded (Size Filter)
2024/10/01 04:17:57 DEBUG : potato2: Excluded
2024/10/01 04:17:57 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:17:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:17:57 DEBUG : empty space: Unchanged skipping
2024/10/01 04:17:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:17:57 DEBUG : Waiting for deletions to finish
2024/10/01 04:17:57 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:17:57 DEBUG : enormous: Excluded (Size Filter)
2024/10/01 04:17:57 DEBUG : enormous: Excluded
2024/10/01 04:17:57 DEBUG : potato2: Excluded (Size Filter)
2024/10/01 04:17:57 DEBUG : potato2: Excluded
2024/10/01 04:17:58 DEBUG : potato2: Excluded (Size Filter)
2024/10/01 04:17:58 DEBUG : potato2: Excluded
2024/10/01 04:17:58 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/10/01 04:17:58 DEBUG : empty space: Unchanged skipping
2024/10/01 04:17:58 DEBUG : Local file system at /tmp/rclone3304300658: Waiting for checks to finish
2024/10/01 04:17:58 DEBUG : Local file system at /tmp/rclone3304300658: Waiting for transfers to finish
2024/10/01 04:17:58 DEBUG : Waiting for deletions to finish
2024/10/01 04:17:58 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncWithExclude (7.80s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:18:02 DEBUG : potato2: md5 = c10ca12a88c3bd83f2ba6f1fc3ad8f65 OK
2024/10/01 04:18:04 DEBUG : empty space: md5 = 29842b465ac01a0c48610b94b2ff3ae8 OK
2024/10/01 04:18:06 DEBUG : enormous: md5 = 1b9b695fec5b94ea64d5c372ddc96ada OK
2024/10/01 04:18:06 DEBUG : enormous: Excluded (Size Filter)
2024/10/01 04:18:06 DEBUG : enormous: Excluded
2024/10/01 04:18:06 DEBUG : potato2: Excluded (Size Filter)
2024/10/01 04:18:06 DEBUG : potato2: Excluded
2024/10/01 04:18:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:18:07 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:18:07 DEBUG : empty space: Unchanged skipping
2024/10/01 04:18:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:18:07 DEBUG : Waiting for deletions to finish
2024/10/01 04:18:07 INFO  : enormous: Deleted
2024/10/01 04:18:07 INFO  : potato2: Deleted
2024/10/01 04:18:07 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:18:08 DEBUG : Local file system at /tmp/rclone3304300658: Waiting for checks to finish
2024/10/01 04:18:08 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2024/10/01 04:18:08 DEBUG : empty space: Unchanged skipping
2024/10/01 04:18:08 DEBUG : Local file system at /tmp/rclone3304300658: Waiting for transfers to finish
2024/10/01 04:18:08 DEBUG : Waiting for deletions to finish
2024/10/01 04:18:08 INFO  : enormous: Deleted
2024/10/01 04:18:08 INFO  : potato2: Deleted
2024/10/01 04:18:08 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (9.88s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:18:12 DEBUG : one: md5 = 7c6f3285fdc23ddca8de51636c278cf0 OK
2024/10/01 04:18:14 DEBUG : two: md5 = c51f8a8647c87e3a75c895193426955f OK
2024/10/01 04:18:16 DEBUG : three: md5 = bb9e474cd264cff84edd87b94878a215 OK
2024/10/01 04:18:18 DEBUG : four: md5 = e7f1ec7cbedf30b8d3c836b5bce66904 OK
2024/10/01 04:18:18 DEBUG : five: Need to transfer - File not found at Destination
2024/10/01 04:18:18 DEBUG : four: Sizes differ (src 4 vs dst 8)
2024/10/01 04:18:18 DEBUG : one: Destination is newer than source, skipping
2024/10/01 04:18:18 DEBUG : three: Sizes identical
2024/10/01 04:18:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:18:18 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2024/10/01 04:18:18 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2024/10/01 04:18:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:18:20 DEBUG : four: md5 = 9f9a798c7e0fe2916b19548d939a231f OK
2024/10/01 04:18:20 INFO  : four: Copied (replaced existing)
2024/10/01 04:18:20 DEBUG : two: md5 = 48361b4a986ce64fc86c7863407e9236 OK
2024/10/01 04:18:20 INFO  : two: Copied (replaced existing)
2024/10/01 04:18:20 DEBUG : five: md5 = b4b036274a1385873bf9f73af9fee151 OK
2024/10/01 04:18:20 INFO  : five: Copied (new)
2024/10/01 04:18:20 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (13.56s)
=== 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-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2024/10/01 04:18:24 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Ignoring --track-renames as the source and destination do not have a common hash
2024/10/01 04:18:24 DEBUG : potato: Need to transfer - File not found at Destination
2024/10/01 04:18:24 DEBUG : yam: Need to transfer - File not found at Destination
2024/10/01 04:18:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:18:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:18:26 DEBUG : potato: md5 = fab790d190ab95e105747dbccb231071 OK
2024/10/01 04:18:26 INFO  : potato: Copied (new)
2024/10/01 04:18:27 DEBUG : yam: md5 = 70d295f2d1d3d127b2b7443e72e3301a OK
2024/10/01 04:18:27 INFO  : yam: Copied (new)
2024/10/01 04:18:27 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:18:27 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Ignoring --track-renames as the source and destination do not have a common hash
2024/10/01 04:18:27 DEBUG : yaml: Need to transfer - File not found at Destination
2024/10/01 04:18:27 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:18:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:18:27 DEBUG : potato: Unchanged skipping
2024/10/01 04:18:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:18:29 DEBUG : yaml: md5 = b0cdc224894b0dfd1030d98284396170 OK
2024/10/01 04:18:29 INFO  : yaml: Copied (new)
2024/10/01 04:18:29 DEBUG : Waiting for deletions to finish
2024/10/01 04:18:30 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (8.84s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2024/10/01 04:18:33 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Making map for --track-renames
2024/10/01 04:18:33 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Finished making map for --track-renames
2024/10/01 04:18:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:18:33 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/10/01 04:18:33 DEBUG : yam: Need to transfer - No matching file found at Destination
2024/10/01 04:18:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for renames to finish
2024/10/01 04:18:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:18:35 DEBUG : potato: md5 = edc9c649aa965ca1fedfc36294f52385 OK
2024/10/01 04:18:35 INFO  : potato: Copied (new)
2024/10/01 04:18:35 DEBUG : yam: md5 = e8ea424dcc061899077bdd06aa3df722 OK
2024/10/01 04:18:35 INFO  : yam: Copied (new)
2024/10/01 04:18:35 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:18:36 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:18:36 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Making map for --track-renames
2024/10/01 04:18:36 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Finished making map for --track-renames
2024/10/01 04:18:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:18:36 DEBUG : potato: Unchanged skipping
2024/10/01 04:18:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for renames to finish
2024/10/01 04:18:37 INFO  : yam: Moved (server-side) to: yaml
2024/10/01 04:18:37 INFO  : yaml: Renamed from "yam"
2024/10/01 04:18:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:18:37 DEBUG : Waiting for deletions to finish
2024/10/01 04:18:37 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (7.28s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2024/10/01 04:18:40 DEBUG : Added delayed dir = "sub", newDst=<nil>
2024/10/01 04:18:40 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Making map for --track-renames
2024/10/01 04:18:40 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Finished making map for --track-renames
2024/10/01 04:18:40 DEBUG : potato: Need to transfer - No matching file found at Destination
2024/10/01 04:18:40 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2024/10/01 04:18:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:18:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for renames to finish
2024/10/01 04:18:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:18:43 DEBUG : potato: md5 = eaeeed754b263f3eb669c6ebf02b05bd OK
2024/10/01 04:18:43 INFO  : potato: Copied (new)
2024/10/01 04:18:43 DEBUG : sub/yam: md5 = 0f279426f1c60dbe4443d1f4e6e58a84 OK
2024/10/01 04:18:43 INFO  : sub/yam: Copied (new)
2024/10/01 04:18:43 DEBUG : Waiting for deletions to finish
2024/10/01 04:18:44 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:18:45 DEBUG : Added delayed dir = "sub", newDst=sub
2024/10/01 04:18:45 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:18:45 DEBUG : potato: Unchanged skipping
2024/10/01 04:18:45 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Making map for --track-renames
2024/10/01 04:18:45 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Finished making map for --track-renames
2024/10/01 04:18:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:18:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for renames to finish
2024/10/01 04:18:47 INFO  : sub/yam: Moved (server-side) to: yam
2024/10/01 04:18:47 INFO  : yam: Renamed from "sub/yam"
2024/10/01 04:18:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:18:47 DEBUG : Waiting for deletions to finish
2024/10/01 04:18:47 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (10.85s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:18:51 DEBUG : Creating backend with remote "/tmp/rclone3304300658/dir1"
2024/10/01 04:18:51 DEBUG : Config file has changed externally - reloading
2024/10/01 04:18:51 DEBUG : Creating backend with remote "/tmp/rclone3304300658/dir2"
2024/10/01 04:18:51 DEBUG : Local file system at /tmp/rclone3304300658/dir2: Using server-side directory move
2024/10/01 04:18:51 INFO  : Local file system at /tmp/rclone3304300658/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/10/01 04:18:51 DEBUG : file1.txt: Need to transfer - File not found at Destination
2024/10/01 04:18:51 DEBUG : Local file system at /tmp/rclone3304300658/dir2: Waiting for checks to finish
2024/10/01 04:18:51 DEBUG : Local file system at /tmp/rclone3304300658/dir2: Waiting for transfers to finish
2024/10/01 04:18:51 INFO  : file1.txt: Moved (server-side)
--- PASS: TestServerSideMoveLocal (0.54s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:18:52 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/10/01 04:18:52 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/10/01 04:18:52 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/10/01 04:18:52 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/10/01 04:18:52 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/10/01 04:18:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:18:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:18:55 DEBUG : sub dir/hello world: md5 = 81f3e441fda374b3a63b408a20f7ae7a OK
2024/10/01 04:18:55 INFO  : sub dir/hello world: Copied (new)
2024/10/01 04:18:55 INFO  : sub dir/hello world: Deleted
2024/10/01 04:18:57 DEBUG : nested/sub dir/file: md5 = 96ba3280b1a105ee44ea6a826a5b9a4b OK
2024/10/01 04:18:57 INFO  : nested/sub dir/file: Copied (new)
2024/10/01 04:18:57 INFO  : nested/sub dir/file: Deleted
2024/10/01 04:18:58 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/10/01 04:18:59 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/10/01 04:18:59 INFO  : nested: Set directory modification time (using DirSetModTime)
2024/10/01 04:18:59 INFO  : sub dir: Removing directory
2024/10/01 04:18:59 INFO  : nested/sub dir: Removing directory
2024/10/01 04:18:59 INFO  : nested: Removing directory
2024/10/01 04:18:59 DEBUG : Local file system at /tmp/rclone3304300658: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:19:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/10/01 04:19:03 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/10/01 04:19:04 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (13.98s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:19:06 DEBUG : Added delayed dir = "nested", newDst=<nil>
2024/10/01 04:19:06 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2024/10/01 04:19:06 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2024/10/01 04:19:06 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2024/10/01 04:19:06 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2024/10/01 04:19:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:19:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:19:09 DEBUG : sub dir/hello world: md5 = 0f08fe947020d699885e22b897483eb9 OK
2024/10/01 04:19:09 INFO  : sub dir/hello world: Copied (new)
2024/10/01 04:19:09 INFO  : sub dir/hello world: Deleted
2024/10/01 04:19:11 DEBUG : nested/sub dir/file: md5 = 23c62638fc74c3d9249ce9aafe8fc3b3 OK
2024/10/01 04:19:11 INFO  : nested/sub dir/file: Copied (new)
2024/10/01 04:19:11 INFO  : nested/sub dir/file: Deleted
2024/10/01 04:19:12 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2024/10/01 04:19:12 INFO  : nested: Set directory modification time (using DirSetModTime)
2024/10/01 04:19:12 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:19:16 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/10/01 04:19:17 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2024/10/01 04:19:18 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (14.21s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:19:20 DEBUG : existing: Need to transfer - File not found at Destination
2024/10/01 04:19:20 DEBUG : existing-b: Need to transfer - File not found at Destination
2024/10/01 04:19:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:19:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:19:22 DEBUG : existing-b: md5 = 02d6f3ee5cd6d95cc46d390ab2c125fd OK
2024/10/01 04:19:22 INFO  : existing-b: Copied (new)
2024/10/01 04:19:22 INFO  : existing-b: Deleted
2024/10/01 04:19:22 DEBUG : existing: md5 = 5a01baed933413df62a16a6a8a8eebf7 OK
2024/10/01 04:19:22 INFO  : existing: Copied (new)
2024/10/01 04:19:22 INFO  : existing: Deleted
2024/10/01 04:19:23 DEBUG : existing: Destination exists, skipping
2024/10/01 04:19:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:19:23 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2024/10/01 04:19:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:19:23 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (5.75s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:19:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kinijuj3quvu"
2024/10/01 04:19:26 DEBUG : Config file has changed externally - reloading
2024/10/01 04:19:26 DEBUG : Creating backend with remote "TestDrive:crypt/ai285h182jchd0s0hp9muil33t033q2litn62mcpo1c6ssgehdeg"
2024/10/01 04:19:29 DEBUG : potato2: md5 = 35fc3d640a06b16cffb62d1ba6c83e38 OK
2024/10/01 04:19:31 DEBUG : empty space: md5 = 96fa43272641ec64e9f858c4895ca78c OK
2024/10/01 04:19:32 DEBUG : potato3: md5 = 7b6e93aace141a745bcc2494a1cbc810 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko' -> Encrypted drive 'TestCryptDrive:rclone-test-kinijuj3quvu'
2024/10/01 04:19:36 DEBUG : empty space: md5 = 2e6c7d97fa26a9510d548b8ee6ac2789 OK
2024/10/01 04:19:37 DEBUG : potato3: md5 = 3ec44bdd374c64655d9e823f55e15b9b OK
2024/10/01 04:19:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kinijuj3quvu': Using server-side directory move
2024/10/01 04:19:38 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-kinijuj3quvu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/10/01 04:19:38 DEBUG : potato2: Need to transfer - File not found at Destination
2024/10/01 04:19:38 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/10/01 04:19:38 DEBUG : empty space: Unchanged skipping
2024/10/01 04:19:38 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/10/01 04:19:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kinijuj3quvu': Waiting for checks to finish
2024/10/01 04:19:39 INFO  : potato3: Deleted
2024/10/01 04:19:39 INFO  : empty space: Deleted
2024/10/01 04:19:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kinijuj3quvu': Waiting for transfers to finish
2024/10/01 04:19:39 INFO  : potato2: Moved (server-side)
2024/10/01 04:19:40 INFO  : potato3: Moved (server-side)
2024/10/01 04:19:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tuwokal5sowi"
2024/10/01 04:19:40 DEBUG : Creating backend with remote "TestDrive:crypt/d9f2mck48dsj304pufq2b091s3iqh6jeji9b54re3qo5m9r4p580"
2024/10/01 04:19:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuwokal5sowi': Using server-side directory move
2024/10/01 04:19:42 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-tuwokal5sowi': Server side directory move succeeded
2024/10/01 04:19:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tuwokal5sowi': Purge remote
2024/10/01 04:19:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kinijuj3quvu': Purge remote
2024/10/01 04:19:44 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (19.28s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:19:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-leseyal8vuyo"
2024/10/01 04:19:45 DEBUG : Creating backend with remote "TestDrive:crypt/uhkjigjjden9l7aqqn7tfkj2cv459lfltiogi29udo6scdbdhekg"
2024/10/01 04:19:48 DEBUG : potato2: md5 = 0ed8d76549b1cbac6429f90d4714c2ec OK
2024/10/01 04:19:50 DEBUG : empty space: md5 = 0dc68db65662932c277256aef9d53a2d OK
2024/10/01 04:19:52 DEBUG : potato3: md5 = 7005e080bb84903ca5e3059d1729c96e OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko' -> Encrypted drive 'TestCryptDrive:rclone-test-leseyal8vuyo'
2024/10/01 04:19:55 DEBUG : empty space: md5 = b410523fefdc719ec021a55310e4ffd7 OK
2024/10/01 04:19:57 DEBUG : potato3: md5 = bcb7e1f01109b4e26c31fdb3cdcefd22 OK
2024/10/01 04:19:57 DEBUG : empty space: Excluded (Size Filter)
2024/10/01 04:19:57 DEBUG : empty space: Excluded
2024/10/01 04:19:57 DEBUG : empty space: Excluded (Size Filter)
2024/10/01 04:19:57 DEBUG : empty space: Excluded
2024/10/01 04:19:57 DEBUG : potato2: Need to transfer - File not found at Destination
2024/10/01 04:19:57 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/10/01 04:19:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-leseyal8vuyo': Waiting for checks to finish
2024/10/01 04:19:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-leseyal8vuyo': Waiting for transfers to finish
2024/10/01 04:19:58 INFO  : potato3: Deleted
2024/10/01 04:19:58 INFO  : potato2: Moved (server-side)
2024/10/01 04:19:59 INFO  : potato3: Moved (server-side)
2024/10/01 04:20:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hagezuy6guha"
2024/10/01 04:20:00 DEBUG : Creating backend with remote "TestDrive:crypt/c2jtoihnbriruok26es4dbefu5231n2b7riedssgf0mir93tce70"
2024/10/01 04:20:01 DEBUG : empty space: Excluded (Size Filter)
2024/10/01 04:20:01 DEBUG : empty space: Excluded
2024/10/01 04:20:01 DEBUG : potato2: Need to transfer - File not found at Destination
2024/10/01 04:20:01 DEBUG : potato3: Need to transfer - File not found at Destination
2024/10/01 04:20:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hagezuy6guha': Waiting for checks to finish
2024/10/01 04:20:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hagezuy6guha': Waiting for transfers to finish
2024/10/01 04:20:03 INFO  : potato2: Moved (server-side)
2024/10/01 04:20:03 INFO  : potato3: Moved (server-side)
2024/10/01 04:20:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hagezuy6guha': Purge remote
2024/10/01 04:20:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-leseyal8vuyo': Purge remote
--- PASS: TestServerSideMoveWithFilter (21.79s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:20:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-foseduh4zitu"
2024/10/01 04:20:07 DEBUG : Creating backend with remote "TestDrive:crypt/hj23p3ruttdimmvmdqfsflo21v9gutgv5fmurd39ppovnuejo400"
2024/10/01 04:20:10 DEBUG : potato2: md5 = ea96d57029a7c3ca072a35439a71e276 OK
2024/10/01 04:20:12 DEBUG : empty space: md5 = 315f125384f127086c34a5585e89b6c1 OK
2024/10/01 04:20:13 DEBUG : potato3: md5 = f192215ae6b9537d18e10806d45d923f OK
2024/10/01 04:20:13 DEBUG : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko' -> Encrypted drive 'TestCryptDrive:rclone-test-foseduh4zitu'
2024/10/01 04:20:18 DEBUG : empty space: md5 = fbb7076305f2f5a3e81ecafe2a4f892f OK
2024/10/01 04:20:19 DEBUG : potato3: md5 = ccbc0b49a768ca2b61df6b3d6f1a99dc OK
2024/10/01 04:20:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-foseduh4zitu': Using server-side directory move
2024/10/01 04:20:20 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-foseduh4zitu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2024/10/01 04:20:20 DEBUG : potato2: Need to transfer - File not found at Destination
2024/10/01 04:20:20 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2024/10/01 04:20:20 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2024/10/01 04:20:20 DEBUG : empty space: Unchanged skipping
2024/10/01 04:20:20 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2024/10/01 04:20:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-foseduh4zitu': Waiting for checks to finish
2024/10/01 04:20:21 INFO  : empty space: Deleted
2024/10/01 04:20:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-foseduh4zitu': Waiting for transfers to finish
2024/10/01 04:20:21 INFO  : potato3: Deleted
2024/10/01 04:20:21 INFO  : potato2: Moved (server-side)
2024/10/01 04:20:22 INFO  : potato3: Moved (server-side)
2024/10/01 04:20:22 INFO  : tomatoDir: Removing directory
2024/10/01 04:20:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': deleted 1 directories
2024/10/01 04:20:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-jepefax3reja"
2024/10/01 04:20:24 DEBUG : Creating backend with remote "TestDrive:crypt/erar666m36qblus4jesc1cuto2q2evrtfasuaagj95smvjdtpol0"
2024/10/01 04:20:25 DEBUG : tomatoDir: Making directory
2024/10/01 04:20:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jepefax3reja': Using server-side directory move
2024/10/01 04:20:27 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-jepefax3reja': Server side directory move succeeded
2024/10/01 04:20:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jepefax3reja': Purge remote
2024/10/01 04:20:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-foseduh4zitu': Purge remote
2024/10/01 04:20:29 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (23.29s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.52s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:20:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/rclone-sync-test"
2024/10/01 04:20:31 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncOverlap (4.36s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:20:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/rclone-sync-test"
2024/10/01 04:20:35 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2024/10/01 04:20:38 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/rclone-sync-test-include/layer2"
2024/10/01 04:20:38 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2024/10/01 04:20:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/rclone-sync-test-ignore-file"
2024/10/01 04:20:42 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2024/10/01 04:20:47 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 4b3ad87577a2eb30e27b389f87033b6f OK
2024/10/01 04:20:48 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/10/01 04:20:48 DEBUG : rclone-sync-test: Excluded
2024/10/01 04:20:48 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/10/01 04:20:49 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/10/01 04:20:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/rclone-sync-test': Waiting for checks to finish
2024/10/01 04:20:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/rclone-sync-test': Waiting for transfers to finish
2024/10/01 04:20:49 DEBUG : Waiting for deletions to finish
2024/10/01 04:20:49 INFO  : There was nothing to transfer
2024/10/01 04:20:50 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/10/01 04:20:50 DEBUG : rclone-sync-test: Excluded
2024/10/01 04:20:51 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/10/01 04:20:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:20:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:20:51 DEBUG : Waiting for deletions to finish
2024/10/01 04:20:51 INFO  : rclone-sync-test-include: Removing directory
2024/10/01 04:20:51 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/10/01 04:20:51 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/10/01 04:20:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': failed to delete 1 directories
2024/10/01 04:20:51 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:20:52 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/10/01 04:20:53 DEBUG : rclone-sync-test: Excluded
2024/10/01 04:20:53 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/10/01 04:20:53 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/10/01 04:20:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/rclone-sync-test-include/layer2': Waiting for checks to finish
2024/10/01 04:20:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/rclone-sync-test-include/layer2': Waiting for transfers to finish
2024/10/01 04:20:53 DEBUG : Waiting for deletions to finish
2024/10/01 04:20:53 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:20:54 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/10/01 04:20:55 DEBUG : rclone-sync-test: Excluded
2024/10/01 04:20:55 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/10/01 04:20:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:20:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:20:55 DEBUG : Waiting for deletions to finish
2024/10/01 04:20:55 INFO  : rclone-sync-test-include: Removing directory
2024/10/01 04:20:56 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/10/01 04:20:56 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2024/10/01 04:20:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': failed to delete 1 directories
2024/10/01 04:20:56 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:20:56 DEBUG : : Excluded
2024/10/01 04:20:57 DEBUG : rclone-sync-test-ignore-file: Excluded
2024/10/01 04:20:57 DEBUG : rclone-sync-test: Excluded
2024/10/01 04:20:57 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2024/10/01 04:20:58 DEBUG : rclone-sync-test-include/layer2: Excluded
2024/10/01 04:20:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/rclone-sync-test-ignore-file': Waiting for checks to finish
2024/10/01 04:20:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/rclone-sync-test-ignore-file': Waiting for transfers to finish
2024/10/01 04:20:58 DEBUG : Waiting for deletions to finish
2024/10/01 04:20:58 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:21:01 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2024/10/01 04:21:01 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (37.53s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:21:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/dst"
2024/10/01 04:21:12 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/31u3jie661vd5p8j7rtc3hgbh0"
2024/10/01 04:21:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/CompareDest"
2024/10/01 04:21:14 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/gveqi14airsml4bgu7krj116o8"
2024/10/01 04:21:17 DEBUG : one: Need to transfer - File not found at Destination
2024/10/01 04:21:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for checks to finish
2024/10/01 04:21:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for transfers to finish
2024/10/01 04:21:20 DEBUG : one: md5 = e571e0b16e23cb6e8bd1c480a90db6eb OK
2024/10/01 04:21:20 INFO  : one: Copied (new)
2024/10/01 04:21:20 DEBUG : Waiting for deletions to finish
2024/10/01 04:21:20 DEBUG : Config file has changed externally - reloading
2024/10/01 04:21:20 DEBUG : TestDrive: Loaded fresh token from config file
2024/10/01 04:21:21 DEBUG : TestDrive: Loaded fresh token from config file
2024/10/01 04:21:21 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/10/01 04:21:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for checks to finish
2024/10/01 04:21:21 DEBUG : TestDrive: Loaded fresh token from config file
2024/10/01 04:21:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for transfers to finish
2024/10/01 04:21:23 DEBUG : one: md5 = 0404122a2972761b0c2bd6d82ea646ea OK
2024/10/01 04:21:23 INFO  : one: Copied (replaced existing)
2024/10/01 04:21:23 DEBUG : Waiting for deletions to finish
2024/10/01 04:21:26 DEBUG : dst/one: md5 = b12a363be541c46f7df90e2dc94aecb6 OK
2024/10/01 04:21:29 DEBUG : CompareDest/one: md5 = ab6348a80e02162e00082a1ff3b564e3 OK
2024/10/01 04:21:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for checks to finish
2024/10/01 04:21:30 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/10/01 04:21:30 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:21:30 DEBUG : one: Destination found in --compare-dest, skipping
2024/10/01 04:21:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for transfers to finish
2024/10/01 04:21:30 DEBUG : Waiting for deletions to finish
2024/10/01 04:21:30 INFO  : There was nothing to transfer
2024/10/01 04:21:33 DEBUG : CompareDest/two: md5 = af8f3830abfe29e0b4937f19332942d0 OK
2024/10/01 04:21:34 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:21:34 DEBUG : two: Destination found in --compare-dest, skipping
2024/10/01 04:21:34 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/10/01 04:21:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for checks to finish
2024/10/01 04:21:34 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:21:34 DEBUG : one: Destination found in --compare-dest, skipping
2024/10/01 04:21:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for transfers to finish
2024/10/01 04:21:34 DEBUG : Waiting for deletions to finish
2024/10/01 04:21:34 INFO  : There was nothing to transfer
2024/10/01 04:21:36 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:21:36 DEBUG : two: Destination found in --compare-dest, skipping
2024/10/01 04:21:36 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/10/01 04:21:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for checks to finish
2024/10/01 04:21:36 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:21:36 DEBUG : one: Destination found in --compare-dest, skipping
2024/10/01 04:21:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for transfers to finish
2024/10/01 04:21:36 DEBUG : Waiting for deletions to finish
2024/10/01 04:21:36 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2024/10/01 04:21:38 DEBUG : two: Sizes differ (src 5 vs dst 3)
2024/10/01 04:21:38 DEBUG : two: Need to transfer - File not found at Destination
2024/10/01 04:21:38 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/10/01 04:21:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for checks to finish
2024/10/01 04:21:38 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:21:38 DEBUG : one: Destination found in --compare-dest, skipping
2024/10/01 04:21:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for transfers to finish
2024/10/01 04:21:40 DEBUG : two: md5 = 810946589ae18115247189758906fcb1 OK
2024/10/01 04:21:40 INFO  : two: Copied (new)
2024/10/01 04:21:40 DEBUG : Waiting for deletions to finish
2024/10/01 04:21:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/10/01 04:21:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/10/01 04:21:45 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/10/01 04:21:45 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncCompareDest (33.68s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:21:49 DEBUG : pre-dest1/1: md5 = b4a1043305921aa00d58c8754e76c7fb OK
2024/10/01 04:21:52 DEBUG : pre-dest2/2: md5 = c15c32acdeed8c1a3014dea768c4ab3b OK
2024/10/01 04:21:52 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/dest"
2024/10/01 04:21:52 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/rg03c1jvnehrrc617i0lnqjddc"
2024/10/01 04:21:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/pre-dest1"
2024/10/01 04:21:54 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/bbnblvh6k061ssopqrp18kd7gc"
2024/10/01 04:21:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/pre-dest2"
2024/10/01 04:21:55 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/dgicm1h6b5ejvlltm8eeif0bnk"
2024/10/01 04:21:57 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:21:57 DEBUG : 1: Destination found in --compare-dest, skipping
2024/10/01 04:21:57 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:21:57 DEBUG : 2: Destination found in --compare-dest, skipping
2024/10/01 04:21:58 DEBUG : 3: Need to transfer - File not found at Destination
2024/10/01 04:21:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dest': Waiting for checks to finish
2024/10/01 04:21:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dest': Waiting for transfers to finish
2024/10/01 04:22:01 DEBUG : 3: md5 = 255aac2abb367d9501ad272f0f4e40a6 OK
2024/10/01 04:22:01 INFO  : 3: Copied (new)
2024/10/01 04:22:01 DEBUG : Waiting for deletions to finish
2024/10/01 04:22:04 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2024/10/01 04:22:05 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2024/10/01 04:22:07 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (21.46s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:22:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/dst"
2024/10/01 04:22:08 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/31u3jie661vd5p8j7rtc3hgbh0"
2024/10/01 04:22:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/CopyDest"
2024/10/01 04:22:09 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/d09o6po3f7bm6ce32vdgs8h9ls"
2024/10/01 04:22:12 DEBUG : one: Need to transfer - File not found at Destination
2024/10/01 04:22:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for checks to finish
2024/10/01 04:22:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for transfers to finish
2024/10/01 04:22:14 DEBUG : one: md5 = d64d77b6b0618bd95fdc0cbba62bc9d8 OK
2024/10/01 04:22:14 INFO  : one: Copied (new)
2024/10/01 04:22:14 DEBUG : Waiting for deletions to finish
2024/10/01 04:22:16 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/10/01 04:22:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for checks to finish
2024/10/01 04:22:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for transfers to finish
2024/10/01 04:22:18 DEBUG : one: md5 = f9b408d7a58782a0186ad7d22842276d OK
2024/10/01 04:22:18 INFO  : one: Copied (replaced existing)
2024/10/01 04:22:18 DEBUG : Waiting for deletions to finish
2024/10/01 04:22:21 DEBUG : dst/one: md5 = c071ce411f30a749c9f2342fa2b52da5 OK
2024/10/01 04:22:23 DEBUG : CopyDest/one: md5 = df2c42d75a843213b1cddee72576bf6d OK
2024/10/01 04:22:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/BackupDir"
2024/10/01 04:22:24 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/s6dbk3lfi7c9kfvo6j7bla9m0g"
2024/10/01 04:22:26 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/10/01 04:22:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for checks to finish
2024/10/01 04:22:27 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:22:27 DEBUG : one: Sizes differ (src 5 vs dst 3)
2024/10/01 04:22:29 INFO  : one: Moved (server-side)
2024/10/01 04:22:31 INFO  : one: Copied (server-side copy)
2024/10/01 04:22:31 DEBUG : one: Destination found in --copy-dest, using server-side copy
2024/10/01 04:22:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for transfers to finish
2024/10/01 04:22:31 DEBUG : Waiting for deletions to finish
2024/10/01 04:22:33 DEBUG : CopyDest/two: md5 = f16d9d1ab57863c7d671885580e3fc65 OK
2024/10/01 04:22:34 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:22:36 INFO  : two: Copied (server-side copy)
2024/10/01 04:22:36 DEBUG : two: Destination found in --copy-dest, using server-side copy
2024/10/01 04:22:36 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:22:36 DEBUG : one: Unchanged skipping
2024/10/01 04:22:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for checks to finish
2024/10/01 04:22:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for transfers to finish
2024/10/01 04:22:36 DEBUG : Waiting for deletions to finish
2024/10/01 04:22:37 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:22:37 DEBUG : one: Unchanged skipping
2024/10/01 04:22:37 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:22:37 DEBUG : two: Unchanged skipping
2024/10/01 04:22:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for checks to finish
2024/10/01 04:22:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for transfers to finish
2024/10/01 04:22:37 DEBUG : Waiting for deletions to finish
2024/10/01 04:22:37 INFO  : There was nothing to transfer
2024/10/01 04:22:39 DEBUG : CopyDest/three: md5 = cc0ef4b821ebbe886d269efce75f1796 OK
2024/10/01 04:22:40 DEBUG : three: Sizes differ (src 7 vs dst 5)
2024/10/01 04:22:40 DEBUG : three: Destination not found in --copy-dest
2024/10/01 04:22:40 DEBUG : three: Need to transfer - File not found at Destination
2024/10/01 04:22:40 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:22:40 DEBUG : one: Unchanged skipping
2024/10/01 04:22:40 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2024/10/01 04:22:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for checks to finish
2024/10/01 04:22:40 DEBUG : two: Unchanged skipping
2024/10/01 04:22:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for transfers to finish
2024/10/01 04:22:42 DEBUG : three: md5 = 777964fcb2bca0c4b897c9636c0bea84 OK
2024/10/01 04:22:42 INFO  : three: Copied (new)
2024/10/01 04:22:42 DEBUG : Waiting for deletions to finish
2024/10/01 04:22:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/10/01 04:22:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/10/01 04:22:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/10/01 04:22:49 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/10/01 04:22:49 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/10/01 04:22:49 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2024/10/01 04:22:50 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (43.76s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:22:54 DEBUG : dst/one: md5 = 8bf32d32aa3b1aeffe200c4b5392e44b OK
2024/10/01 04:22:56 DEBUG : dst/two: md5 = 5f64e9e257980909994729cecc6262ca OK
2024/10/01 04:22:58 DEBUG : dst/three.txt: md5 = 6dc747eac0d7d27ad856b824c996dd02 OK
2024/10/01 04:22:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/dst"
2024/10/01 04:22:59 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/31u3jie661vd5p8j7rtc3hgbh0"
2024/10/01 04:23:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/backup"
2024/10/01 04:23:00 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/1nrff024r7pq65ecp72fc28jb0"
2024/10/01 04:23:02 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/10/01 04:23:02 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:23:02 DEBUG : two: Unchanged skipping
2024/10/01 04:23:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for checks to finish
2024/10/01 04:23:04 INFO  : one: Moved (server-side)
2024/10/01 04:23:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for transfers to finish
2024/10/01 04:23:06 DEBUG : one: md5 = 1a3408f034f220fb05878877aa732695 OK
2024/10/01 04:23:06 INFO  : one: Copied (new)
2024/10/01 04:23:06 DEBUG : Waiting for deletions to finish
2024/10/01 04:23:07 INFO  : three.txt: Moved (server-side)
2024/10/01 04:23:07 INFO  : three.txt: Moved into backup dir
2024/10/01 04:23:10 DEBUG : dst/three.txt: md5 = ab7f3b5624ca48dcff6b24fccd75095c OK
2024/10/01 04:23:11 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/10/01 04:23:11 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:23:11 DEBUG : two: Unchanged skipping
2024/10/01 04:23:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for checks to finish
2024/10/01 04:23:12 INFO  : one: Deleted
2024/10/01 04:23:13 INFO  : one: Moved (server-side)
2024/10/01 04:23:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for transfers to finish
2024/10/01 04:23:14 DEBUG : one: md5 = 3c0a7b6b7600cda812dff30ff53e24b6 OK
2024/10/01 04:23:14 INFO  : one: Copied (new)
2024/10/01 04:23:14 DEBUG : Waiting for deletions to finish
2024/10/01 04:23:15 INFO  : three.txt: Deleted
2024/10/01 04:23:16 INFO  : three.txt: Moved (server-side)
2024/10/01 04:23:16 INFO  : three.txt: Moved into backup dir
2024/10/01 04:23:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/10/01 04:23:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/10/01 04:23:22 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/10/01 04:23:22 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/10/01 04:23:22 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/10/01 04:23:22 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
--- PASS: TestSyncBackupDir (31.26s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:23:26 DEBUG : dst/one: md5 = 5177938e8d07388044719cbe8f73bf29 OK
2024/10/01 04:23:27 DEBUG : dst/two: md5 = 211f941ff4b09e15f8e93e3b54a634e3 OK
2024/10/01 04:23:29 DEBUG : dst/three.txt: md5 = eee0d2d2d2db53db5012df82abf1c5db OK
2024/10/01 04:23:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/dst"
2024/10/01 04:23:30 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/31u3jie661vd5p8j7rtc3hgbh0"
2024/10/01 04:23:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/backup"
2024/10/01 04:23:31 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/1nrff024r7pq65ecp72fc28jb0"
2024/10/01 04:23:33 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/10/01 04:23:33 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:23:33 DEBUG : two: Unchanged skipping
2024/10/01 04:23:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for checks to finish
2024/10/01 04:23:35 INFO  : one: Moved (server-side) to: one.bak
2024/10/01 04:23:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for transfers to finish
2024/10/01 04:23:37 DEBUG : one: md5 = 485a5c28254a107a56ad5e1c75678aec OK
2024/10/01 04:23:37 INFO  : one: Copied (new)
2024/10/01 04:23:37 DEBUG : Waiting for deletions to finish
2024/10/01 04:23:39 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/10/01 04:23:39 INFO  : three.txt: Moved into backup dir
2024/10/01 04:23:41 DEBUG : dst/three.txt: md5 = ba276ffb8446445f2c9f92a2f492fb2e OK
2024/10/01 04:23:42 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/10/01 04:23:42 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:23:42 DEBUG : two: Unchanged skipping
2024/10/01 04:23:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for checks to finish
2024/10/01 04:23:43 INFO  : one.bak: Deleted
2024/10/01 04:23:44 INFO  : one: Moved (server-side) to: one.bak
2024/10/01 04:23:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for transfers to finish
2024/10/01 04:23:46 DEBUG : one: md5 = edb2bcbcd6cecb2e15bffb3cc06abe2b OK
2024/10/01 04:23:46 INFO  : one: Copied (new)
2024/10/01 04:23:46 DEBUG : Waiting for deletions to finish
2024/10/01 04:23:47 INFO  : three.txt.bak: Deleted
2024/10/01 04:23:48 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/10/01 04:23:48 INFO  : three.txt: Moved into backup dir
2024/10/01 04:23:53 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/10/01 04:23:53 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/10/01 04:23:54 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/10/01 04:23:54 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/10/01 04:23:54 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/10/01 04:23:54 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncBackupDirWithSuffix (32.80s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:23:58 DEBUG : dst/one: md5 = 25f0f6f151fecccc2a4d517f8271fc2a OK
2024/10/01 04:24:00 DEBUG : dst/two: md5 = 30e742f4e25d6ba03ab92aa35a4d2166 OK
2024/10/01 04:24:02 DEBUG : dst/three.txt: md5 = cb345b07f202888069090556ab2889db OK
2024/10/01 04:24:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/dst"
2024/10/01 04:24:03 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/31u3jie661vd5p8j7rtc3hgbh0"
2024/10/01 04:24:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/backup"
2024/10/01 04:24:04 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/1nrff024r7pq65ecp72fc28jb0"
2024/10/01 04:24:06 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/10/01 04:24:06 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:24:06 DEBUG : two: Unchanged skipping
2024/10/01 04:24:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for checks to finish
2024/10/01 04:24:08 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/10/01 04:24:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for transfers to finish
2024/10/01 04:24:10 DEBUG : one: md5 = 98c08c704c64e1c08d05255abe8297d1 OK
2024/10/01 04:24:10 INFO  : one: Copied (new)
2024/10/01 04:24:10 DEBUG : Waiting for deletions to finish
2024/10/01 04:24:11 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/10/01 04:24:11 INFO  : three.txt: Moved into backup dir
2024/10/01 04:24:13 DEBUG : dst/three.txt: md5 = 439b0a1f78dd50266a6f8d472f9291b5 OK
2024/10/01 04:24:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for checks to finish
2024/10/01 04:24:14 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/10/01 04:24:14 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:24:14 DEBUG : two: Unchanged skipping
2024/10/01 04:24:15 INFO  : one-2019-01-01: Deleted
2024/10/01 04:24:16 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/10/01 04:24:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for transfers to finish
2024/10/01 04:24:18 DEBUG : one: md5 = 85cf1f0af3742e6b77e8faa104133269 OK
2024/10/01 04:24:18 INFO  : one: Copied (new)
2024/10/01 04:24:18 DEBUG : Waiting for deletions to finish
2024/10/01 04:24:19 INFO  : three-2019-01-01.txt: Deleted
2024/10/01 04:24:20 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/10/01 04:24:20 INFO  : three.txt: Moved into backup dir
2024/10/01 04:24:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/10/01 04:24:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/10/01 04:24:25 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/10/01 04:24:25 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/10/01 04:24:25 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/10/01 04:24:25 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (30.88s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:24:29 DEBUG : dst/one: md5 = 239fa3eea146e510f941a4972adb5235 OK
2024/10/01 04:24:31 DEBUG : dst/two: md5 = 339c138df449d55afbfcbf2efa907d8f OK
2024/10/01 04:24:33 DEBUG : dst/three.txt: md5 = 7f5aa10db133fa80ef9a596ed5c1726e OK
2024/10/01 04:24:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/dst"
2024/10/01 04:24:33 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/31u3jie661vd5p8j7rtc3hgbh0"
2024/10/01 04:24:35 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/10/01 04:24:35 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:24:35 DEBUG : two: Unchanged skipping
2024/10/01 04:24:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for checks to finish
2024/10/01 04:24:36 INFO  : one: Moved (server-side) to: one.bak
2024/10/01 04:24:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for transfers to finish
2024/10/01 04:24:37 DEBUG : one: md5 = 24d1cc69611a62c36f8d726b36b069b5 OK
2024/10/01 04:24:37 INFO  : one: Copied (new)
2024/10/01 04:24:37 DEBUG : Waiting for deletions to finish
2024/10/01 04:24:38 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/10/01 04:24:38 INFO  : three.txt: Moved into backup dir
2024/10/01 04:24:41 DEBUG : dst/three.txt: md5 = d15ed10cb2f112e78287fa585af4ff3e OK
2024/10/01 04:24:42 DEBUG : one.bak: Excluded (Path Filter)
2024/10/01 04:24:42 DEBUG : one.bak: Excluded
2024/10/01 04:24:42 DEBUG : three.txt.bak: Excluded (Path Filter)
2024/10/01 04:24:42 DEBUG : three.txt.bak: Excluded
2024/10/01 04:24:42 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/10/01 04:24:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for checks to finish
2024/10/01 04:24:42 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:24:42 DEBUG : two: Unchanged skipping
2024/10/01 04:24:43 INFO  : one.bak: Deleted
2024/10/01 04:24:43 INFO  : one: Moved (server-side) to: one.bak
2024/10/01 04:24:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko/dst': Waiting for transfers to finish
2024/10/01 04:24:45 DEBUG : one: md5 = 38c3392abf4a17f89eecd2a1b43cb1fd OK
2024/10/01 04:24:45 INFO  : one: Copied (new)
2024/10/01 04:24:45 DEBUG : Waiting for deletions to finish
2024/10/01 04:24:46 INFO  : three.txt.bak: Deleted
2024/10/01 04:24:47 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/10/01 04:24:47 INFO  : three.txt: Moved into backup dir
2024/10/01 04:24:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/10/01 04:24:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/10/01 04:24:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/10/01 04:24:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/10/01 04:24:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/10/01 04:24:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncBackupDirSuffixOnly (25.62s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:24:55 DEBUG : dst/one: md5 = 00ff1226befca4fa975a5a5eaf1408b7 OK
2024/10/01 04:24:57 DEBUG : dst/two: md5 = 45b183367ca3738cec901f30054342d4 OK
2024/10/01 04:24:58 DEBUG : dst/three.txt: md5 = 80263a935d8230a81bc32b96220aad15 OK
2024/10/01 04:24:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/dst"
2024/10/01 04:24:59 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/31u3jie661vd5p8j7rtc3hgbh0"
2024/10/01 04:25:00 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/10/01 04:25:01 INFO  : one: Moved (server-side) to: one.bak
2024/10/01 04:25:03 DEBUG : one: md5 = 47be2a61509f4af1f0578b51d0a37fc5 OK
2024/10/01 04:25:03 INFO  : one: Copied (new)
2024/10/01 04:25:03 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:25:03 DEBUG : two: Unchanged skipping
2024/10/01 04:25:04 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/10/01 04:25:05 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/10/01 04:25:06 DEBUG : three.txt: md5 = 0a9a20991dfb220de8c3f0355951ee63 OK
2024/10/01 04:25:06 INFO  : three.txt: Copied (new)
2024/10/01 04:25:08 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/10/01 04:25:09 INFO  : one.bak: Deleted
2024/10/01 04:25:10 INFO  : one: Moved (server-side) to: one.bak
2024/10/01 04:25:12 DEBUG : one: md5 = ec14df5c37919328fb4600079aee555e OK
2024/10/01 04:25:12 INFO  : one: Copied (new)
2024/10/01 04:25:12 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:25:12 DEBUG : two: Unchanged skipping
2024/10/01 04:25:12 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/10/01 04:25:13 INFO  : three.txt.bak: Deleted
2024/10/01 04:25:14 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2024/10/01 04:25:16 DEBUG : three.txt: md5 = 0d55b95000c98fe982050d8a5e785198 OK
2024/10/01 04:25:16 INFO  : three.txt: Copied (new)
2024/10/01 04:25:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/10/01 04:25:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/10/01 04:25:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/10/01 04:25:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/10/01 04:25:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2024/10/01 04:25:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2024/10/01 04:25:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncSuffix (29.22s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:25:24 DEBUG : dst/one: md5 = 26dd4d2776c37009be6a6ab6bb65ab60 OK
2024/10/01 04:25:26 DEBUG : dst/two: md5 = 02aa3654435ac9c9a0eced01198233ad OK
2024/10/01 04:25:28 DEBUG : dst/three.txt: md5 = bca5d5d5a953bab32141f34803582785 OK
2024/10/01 04:25:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-turinoz6foko/dst"
2024/10/01 04:25:28 DEBUG : Creating backend with remote "TestDrive:crypt/al7rfo5cmpqgu6p9nhaboj31s48lsor407saokfhhdbno4usdsk0/31u3jie661vd5p8j7rtc3hgbh0"
2024/10/01 04:25:30 DEBUG : one: Sizes differ (src 4 vs dst 3)
2024/10/01 04:25:31 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/10/01 04:25:32 DEBUG : one: md5 = 06dca7083ecd6e177b97e36ff6d49a3c OK
2024/10/01 04:25:32 INFO  : one: Copied (new)
2024/10/01 04:25:33 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:25:33 DEBUG : two: Unchanged skipping
2024/10/01 04:25:33 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2024/10/01 04:25:34 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/10/01 04:25:36 DEBUG : three.txt: md5 = e9ad1f26240f328a6b48f0ad793857b0 OK
2024/10/01 04:25:36 INFO  : three.txt: Copied (new)
2024/10/01 04:25:38 DEBUG : one: Sizes differ (src 5 vs dst 4)
2024/10/01 04:25:39 INFO  : one-2019-01-01: Deleted
2024/10/01 04:25:39 INFO  : one: Moved (server-side) to: one-2019-01-01
2024/10/01 04:25:41 DEBUG : one: md5 = d19029ec0dc5604e6dd6c43e35b69ff5 OK
2024/10/01 04:25:41 INFO  : one: Copied (new)
2024/10/01 04:25:41 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:25:41 DEBUG : two: Unchanged skipping
2024/10/01 04:25:42 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2024/10/01 04:25:43 INFO  : three-2019-01-01.txt: Deleted
2024/10/01 04:25:43 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2024/10/01 04:25:45 DEBUG : three.txt: md5 = e83b3033036968e21063c718dc2e9e31 OK
2024/10/01 04:25:45 INFO  : three.txt: Copied (new)
2024/10/01 04:25:50 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2024/10/01 04:25:50 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2024/10/01 04:25:50 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2024/10/01 04:25:50 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2024/10/01 04:25:50 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/10/01 04:25:50 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2024/10/01 04:25:50 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncSuffixKeepExtension (30.07s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:25:53 DEBUG : Testêé: md5 = d331dbf8663781a9e42eebb5542d275a OK
2024/10/01 04:25:53 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2024/10/01 04:25:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:25:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:25:56 DEBUG : Testêé: md5 = 9fda919bd2109c973a611a96023604dd OK
2024/10/01 04:25:56 INFO  : Testêé: Copied (replaced existing) to: Testêé
2024/10/01 04:25:56 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (5.96s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:25:58 DEBUG : existing: Need to transfer - File not found at Destination
2024/10/01 04:25:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:25:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:25:59 DEBUG : existing: md5 = 2a9cb13b60eecad0ec3e83a4d5e88b3e OK
2024/10/01 04:25:59 INFO  : existing: Copied (new)
2024/10/01 04:25:59 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:26:00 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2024/10/01 04:26:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:26:00 ERROR : existing: Source and destination exist but do not match: immutable file modified
2024/10/01 04:26:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:26:00 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': not deleting files as there were IO errors
2024/10/01 04:26:00 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncImmutable (5.97s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:26:05 DEBUG : EXISTING: md5 = 5a0570205c0fd2cdb7c7437468488fcb OK
2024/10/01 04:26:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:26:06 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:26:06 DEBUG : existing: Unchanged skipping
2024/10/01 04:26:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:26:06 DEBUG : Waiting for deletions to finish
2024/10/01 04:26:06 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (4.04s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    sync_test.go:2635: Skipping test as local or remote are case-sensitive
--- SKIP: TestFixCase (0.58s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", 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-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", 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-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.55s)
    --- SKIP: TestMaxTransfer/Hard (0.53s)
    --- SKIP: TestMaxTransfer/Soft (0.50s)
    --- SKIP: TestMaxTransfer/Cautious (0.51s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:26:11 DEBUG : both0: md5 = 3b0240dcf627b0df2e546cf8d1f7e44a OK
2024/10/01 04:26:13 DEBUG : only0: md5 = c47d76b45f8b6ce25b38f2956656d5ec OK
2024/10/01 04:26:15 DEBUG : both1: md5 = e50f35f6a02980cbe03dd5c279590ebd OK
2024/10/01 04:26:16 DEBUG : only1: md5 = 3200f3f7348f56dcdbfb981b3b41cc81 OK
2024/10/01 04:26:18 DEBUG : both2: md5 = 4932076f5b71c500dbf4b0dc7590a625 OK
2024/10/01 04:26:20 DEBUG : only2: md5 = 99c5ccb73abb686a410cd360ec3c8110 OK
2024/10/01 04:26:22 DEBUG : both3: md5 = c65ac1044e464402a269afe7fb28dbae OK
2024/10/01 04:26:23 DEBUG : only3: md5 = 32a325cb4ab2db3f44b79faeaf4bbbdf OK
2024/10/01 04:26:25 DEBUG : both4: md5 = 93b9b96634459b917d740494bb0fb5ae OK
2024/10/01 04:26:27 DEBUG : only4: md5 = 395bcee363e94626512f7445a27a19c1 OK
2024/10/01 04:26:29 DEBUG : both5: md5 = aec8f3f67e661eee2ab7cd3137ba5ef4 OK
2024/10/01 04:26:30 DEBUG : only5: md5 = 0aa8d2af4a74de7b046e013fdc20e3aa OK
2024/10/01 04:26:32 DEBUG : both6: md5 = e450218b99e721892ae6f9c5288209c0 OK
2024/10/01 04:26:34 DEBUG : only6: md5 = 258ba4295d3d384e0cc330379728cbce OK
2024/10/01 04:26:36 DEBUG : both7: md5 = 750f55d4156c33b67020224ba144e689 OK
2024/10/01 04:26:38 DEBUG : only7: md5 = 1ec22d162d756963500a34f4147d9800 OK
2024/10/01 04:26:39 DEBUG : both8: md5 = b59e2dfcae12046daed687df827e68eb OK
2024/10/01 04:26:41 DEBUG : only8: md5 = c2640998824777d605c818cd0e790745 OK
2024/10/01 04:26:43 DEBUG : both9: md5 = 7ebff7c5ec9ece32051f4fcfa4e9dcfc OK
2024/10/01 04:26:45 DEBUG : only9: md5 = 9b7fe05e7129dcd6f36da18cb0a45543 OK
2024/10/01 04:26:46 DEBUG : both10: md5 = 305d033a20cc57087cc06aae23aa20a6 OK
2024/10/01 04:26:48 DEBUG : only10: md5 = 23a25a9a5f0ba774e09acdcc40d291f2 OK
2024/10/01 04:26:50 DEBUG : both11: md5 = c27241b3473825d4400f8a6ded681bfb OK
2024/10/01 04:26:52 DEBUG : only11: md5 = 80f0d84c34430a9237142f15ed8c3ac7 OK
2024/10/01 04:26:53 DEBUG : both12: md5 = 52b57e557830d36c7d3c8f5c724d279f OK
2024/10/01 04:26:55 DEBUG : only12: md5 = e67926e631712ffd0463675b4088141d OK
2024/10/01 04:26:57 DEBUG : both13: md5 = 0b42d24c5ebf4d29ab3ad3f921e078e4 OK
2024/10/01 04:26:58 DEBUG : only13: md5 = 1a33ebc2bcc4e2d1fa688c2359fbe4f2 OK
2024/10/01 04:27:00 DEBUG : both14: md5 = 5a2760050b35a415939b31d2db4c6095 OK
2024/10/01 04:27:02 DEBUG : only14: md5 = 36b5ff851a92298c8d6ce5191cdf164e OK
2024/10/01 04:27:04 DEBUG : both15: md5 = 531fabe1b92a171fe73b84a5985330d7 OK
2024/10/01 04:27:05 DEBUG : only15: md5 = 49e3d88e8d0721e97dc0c473252dee12 OK
2024/10/01 04:27:07 DEBUG : both16: md5 = 3a083f00bb538afea4b3a74634353f94 OK
2024/10/01 04:27:09 DEBUG : only16: md5 = a56b60485c2fe4c1c874bf5f3bab5479 OK
2024/10/01 04:27:11 DEBUG : both17: md5 = 91df028d54d7a8784d04c67e57b453de OK
2024/10/01 04:27:12 DEBUG : only17: md5 = 97a08b02eae14f57e84a87ff9d5f0a7f OK
2024/10/01 04:27:14 DEBUG : both18: md5 = 64355faf2756b10d72d244f805e56dd4 OK
2024/10/01 04:27:16 DEBUG : only18: md5 = 49d8c7ad87aa7744b2fcbcc5236ef07c OK
2024/10/01 04:27:18 DEBUG : both19: md5 = 31d8f8ab659a896fc296ad1a90ebbc3f OK
2024/10/01 04:27:20 DEBUG : only19: md5 = a84dd83b5790d1c631de3d5115d3f388 OK
2024/10/01 04:27:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:27:21 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:27:21 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:27:21 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:27:21 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:27:21 DEBUG : both0: Unchanged skipping
2024/10/01 04:27:21 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:27:21 DEBUG : both12: Unchanged skipping
2024/10/01 04:27:21 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:27:21 DEBUG : both13: Unchanged skipping
2024/10/01 04:27:21 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:27:21 DEBUG : both14: Unchanged skipping
2024/10/01 04:27:21 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:27:21 DEBUG : both11: Unchanged skipping
2024/10/01 04:27:21 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:27:21 DEBUG : both16: Unchanged skipping
2024/10/01 04:27:21 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:27:21 DEBUG : both17: Unchanged skipping
2024/10/01 04:27:21 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:27:21 DEBUG : both1: Unchanged skipping
2024/10/01 04:27:21 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:27:21 DEBUG : both15: Unchanged skipping
2024/10/01 04:27:21 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:27:21 DEBUG : both2: Unchanged skipping
2024/10/01 04:27:21 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:27:21 DEBUG : both3: Unchanged skipping
2024/10/01 04:27:21 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:27:21 DEBUG : both4: Unchanged skipping
2024/10/01 04:27:21 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:27:21 DEBUG : both5: Unchanged skipping
2024/10/01 04:27:21 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:27:21 DEBUG : both6: Unchanged skipping
2024/10/01 04:27:21 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:27:21 DEBUG : both7: Unchanged skipping
2024/10/01 04:27:21 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:27:21 DEBUG : both8: Unchanged skipping
2024/10/01 04:27:21 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:27:21 DEBUG : both9: Unchanged skipping
2024/10/01 04:27:21 DEBUG : both10: Unchanged skipping
2024/10/01 04:27:21 DEBUG : both18: Unchanged skipping
2024/10/01 04:27:21 DEBUG : both19: Unchanged skipping
2024/10/01 04:27:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:27:21 DEBUG : Waiting for deletions to finish
2024/10/01 04:27:21 INFO  : only10: Deleted
2024/10/01 04:27:21 INFO  : only13: Deleted
2024/10/01 04:27:21 INFO  : only14: Deleted
2024/10/01 04:27:21 INFO  : only16: Deleted
2024/10/01 04:27:22 INFO  : only6: Deleted
2024/10/01 04:27:22 INFO  : only7: Deleted
2024/10/01 04:27:22 INFO  : only0: Deleted
2024/10/01 04:27:22 INFO  : only1: Deleted
2024/10/01 04:27:22 INFO  : only2: Deleted
2024/10/01 04:27:23 INFO  : only4: Deleted
2024/10/01 04:27:23 INFO  : only3: Deleted
2024/10/01 04:27:23 INFO  : only9: Deleted
2024/10/01 04:27:23 INFO  : only12: Deleted
2024/10/01 04:27:23 INFO  : only15: Deleted
2024/10/01 04:27:23 INFO  : only17: Deleted
2024/10/01 04:27:23 INFO  : only19: Deleted
2024/10/01 04:27:24 INFO  : only5: Deleted
2024/10/01 04:27:24 INFO  : only11: Deleted
2024/10/01 04:27:24 INFO  : only18: Deleted
2024/10/01 04:27:24 INFO  : only8: Deleted
2024/10/01 04:27:24 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (89.19s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:27:40 DEBUG : both0: md5 = d6bce9c20dc98d19a599bcc8f33a0a07 OK
2024/10/01 04:27:42 DEBUG : only0: md5 = 08a732f71096e9f8f480476b6579e904 OK
2024/10/01 04:27:44 DEBUG : both1: md5 = f381c41db56db1b68b2fd7e7defd428c OK
2024/10/01 04:27:45 DEBUG : only1: md5 = e6bca01e3a6b18339e72ea59acce861f OK
2024/10/01 04:27:47 DEBUG : both2: md5 = 9be4b86e7aca4938bc7a4c233c7698cf OK
2024/10/01 04:27:50 DEBUG : only2: md5 = ab1d46bd3c8f0439306f0d8c68b7ed6f OK
2024/10/01 04:27:51 DEBUG : both3: md5 = 885ae9a11694b53c0609169657a11cc2 OK
2024/10/01 04:27:53 DEBUG : only3: md5 = 5d7dd1e8df566ab8734040e48c56714d OK
2024/10/01 04:27:55 DEBUG : both4: md5 = b960a1dee0cea6366667c70b33c22255 OK
2024/10/01 04:27:57 DEBUG : only4: md5 = 3687d9cfde20ae9eabdfbe4a226dd590 OK
2024/10/01 04:27:58 DEBUG : both5: md5 = 5fb2e1eeea4e5e8cc348d3f7e680db28 OK
2024/10/01 04:28:00 DEBUG : only5: md5 = c7544731eecf7a3801d1152d249547ff OK
2024/10/01 04:28:02 DEBUG : both6: md5 = b76b6ccc832b3e53b6ab924a84bd735b OK
2024/10/01 04:28:04 DEBUG : only6: md5 = 8c9bf3acb5ef834b3a7631d3f5c62ca5 OK
2024/10/01 04:28:06 DEBUG : both7: md5 = 1e99fedc924f7f820183497c07ef56a1 OK
2024/10/01 04:28:08 DEBUG : only7: md5 = 3a8c8ce748f90636bbdf0116e952efb1 OK
2024/10/01 04:28:10 DEBUG : both8: md5 = f6c738dd0c0c562500c68da00f364702 OK
2024/10/01 04:28:11 DEBUG : only8: md5 = b0be37dcec2166e192351a2753f8b96e OK
2024/10/01 04:28:13 DEBUG : both9: md5 = 12ffc4542e9ac14b2a1fa397d53e928a OK
2024/10/01 04:28:15 DEBUG : only9: md5 = 962906df792057d2f3719393ce1b00a0 OK
2024/10/01 04:28:17 DEBUG : both10: md5 = a7860cf6257ecfc1e38b29f7c37d2d9a OK
2024/10/01 04:28:19 DEBUG : only10: md5 = d47e0b54dca0333371c81fbad8beb934 OK
2024/10/01 04:28:20 DEBUG : both11: md5 = 04b3a22742a4f622ef80b29b329ad2a0 OK
2024/10/01 04:28:22 DEBUG : only11: md5 = e93944c02bb929a8578b52004513d291 OK
2024/10/01 04:28:24 DEBUG : both12: md5 = 9d612138c2b45ea83e78e7b3c5f0a389 OK
2024/10/01 04:28:26 DEBUG : only12: md5 = ead06b9cc065ef1877a759d9caae465f OK
2024/10/01 04:28:28 DEBUG : both13: md5 = 87be5536d4c5db767f121ab134671536 OK
2024/10/01 04:28:29 DEBUG : only13: md5 = d39baebd4a09333efd1d150fcbf4ef0c OK
2024/10/01 04:28:31 DEBUG : both14: md5 = 1ad89f55a7ea67e9a8b82fb00e870eb8 OK
2024/10/01 04:28:33 DEBUG : only14: md5 = dae5c120151bb1a47692a2e989f33790 OK
2024/10/01 04:28:35 DEBUG : both15: md5 = 90deda5be6e3ca2788f859cc43ac757f OK
2024/10/01 04:28:36 DEBUG : only15: md5 = a599eda738654bbde85063d949dd5a9e OK
2024/10/01 04:28:38 DEBUG : both16: md5 = 30850e687feef2a6935e593aac8beb78 OK
2024/10/01 04:28:40 DEBUG : only16: md5 = 1066eca58abdd475fcb47c748985e229 OK
2024/10/01 04:28:42 DEBUG : both17: md5 = 968d33d34780b78a697cfbaac47f2ab7 OK
2024/10/01 04:28:44 DEBUG : only17: md5 = e29e0eec45e3974d5eff345a4f8c25ae OK
2024/10/01 04:28:45 DEBUG : both18: md5 = 316524a6f9ca62657a67ab6de4587814 OK
2024/10/01 04:28:47 DEBUG : only18: md5 = a2011cf7d0c73cb37196bc86c9cc31f8 OK
2024/10/01 04:28:50 DEBUG : both19: md5 = 5944d022263834a96bda307b8a15bdab OK
2024/10/01 04:28:52 DEBUG : only19: md5 = 0b40cecd78a9a83b95e6e938503ced86 OK
2024/10/01 04:28:53 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:28:53 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:28:53 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:28:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for checks to finish
2024/10/01 04:28:53 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:28:53 DEBUG : both0: Unchanged skipping
2024/10/01 04:28:53 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:28:53 DEBUG : both12: Unchanged skipping
2024/10/01 04:28:53 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:28:53 DEBUG : both13: Unchanged skipping
2024/10/01 04:28:53 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:28:53 DEBUG : both14: Unchanged skipping
2024/10/01 04:28:53 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:28:53 DEBUG : both11: Unchanged skipping
2024/10/01 04:28:53 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:28:53 DEBUG : both16: Unchanged skipping
2024/10/01 04:28:53 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:28:53 DEBUG : both17: Unchanged skipping
2024/10/01 04:28:53 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:28:53 DEBUG : both18: Unchanged skipping
2024/10/01 04:28:53 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:28:53 DEBUG : both10: Unchanged skipping
2024/10/01 04:28:53 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:28:53 DEBUG : both2: Unchanged skipping
2024/10/01 04:28:53 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:28:53 DEBUG : both1: Unchanged skipping
2024/10/01 04:28:53 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:28:53 DEBUG : both15: Unchanged skipping
2024/10/01 04:28:53 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:28:53 DEBUG : both5: Unchanged skipping
2024/10/01 04:28:53 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:28:53 DEBUG : both19: Unchanged skipping
2024/10/01 04:28:53 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:28:53 DEBUG : both7: Unchanged skipping
2024/10/01 04:28:53 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:28:53 DEBUG : both8: Unchanged skipping
2024/10/01 04:28:53 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2024/10/01 04:28:53 DEBUG : both9: Unchanged skipping
2024/10/01 04:28:53 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2024/10/01 04:28:53 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2024/10/01 04:28:53 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2024/10/01 04:28:53 DEBUG : both3: Unchanged skipping
2024/10/01 04:28:53 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2024/10/01 04:28:53 DEBUG : both4: Unchanged skipping
2024/10/01 04:28:53 DEBUG : both6: Unchanged skipping
2024/10/01 04:28:53 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2024/10/01 04:28:53 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2024/10/01 04:28:53 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2024/10/01 04:28:53 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2024/10/01 04:28:53 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2024/10/01 04:28:53 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2024/10/01 04:28:53 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2024/10/01 04:28:53 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2024/10/01 04:28:53 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2024/10/01 04:28:53 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2024/10/01 04:28:53 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2024/10/01 04:28:53 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2024/10/01 04:28:53 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2024/10/01 04:28:53 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2024/10/01 04:28:53 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2024/10/01 04:28:53 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2024/10/01 04:28:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Waiting for transfers to finish
2024/10/01 04:28:54 DEBUG : only0: md5 = 3185ade4615e464ee2d46361c4a3029a OK
2024/10/01 04:28:54 INFO  : only0: Copied (replaced existing)
2024/10/01 04:28:54 DEBUG : only12: md5 = 5c467c2a09f1b3cbf1576e93e18fdcc8 OK
2024/10/01 04:28:54 INFO  : only12: Copied (replaced existing)
2024/10/01 04:28:54 DEBUG : only14: md5 = 1f4633eca8889b6ff4450d919e6fa597 OK
2024/10/01 04:28:54 INFO  : only14: Copied (replaced existing)
2024/10/01 04:28:54 DEBUG : only1: md5 = ab8cc3db476a9dc63a8c258082e46164 OK
2024/10/01 04:28:54 INFO  : only1: Copied (replaced existing)
2024/10/01 04:28:56 DEBUG : only15: md5 = 4771c0048bdba98b6fb8a0d82716af79 OK
2024/10/01 04:28:56 INFO  : only15: Copied (replaced existing)
2024/10/01 04:28:56 DEBUG : only16: md5 = f6fcef5ef2711acdcbe47ccd4cbb5cc5 OK
2024/10/01 04:28:56 INFO  : only16: Copied (replaced existing)
2024/10/01 04:28:56 DEBUG : only18: md5 = 9718e3c94bc751174cacc6c2f42a524a OK
2024/10/01 04:28:56 INFO  : only18: Copied (replaced existing)
2024/10/01 04:28:56 DEBUG : only17: md5 = eff5848b2e787d6abb71abf4ee906cac OK
2024/10/01 04:28:56 INFO  : only17: Copied (replaced existing)
2024/10/01 04:28:57 DEBUG : only19: md5 = cafbd05459ed069c5be8be1b0ac7bc05 OK
2024/10/01 04:28:57 INFO  : only19: Copied (replaced existing)
2024/10/01 04:28:57 DEBUG : only2: md5 = 59e6ffb155fa71b9aee92f8995fcfc36 OK
2024/10/01 04:28:57 INFO  : only2: Copied (replaced existing)
2024/10/01 04:28:57 DEBUG : only11: md5 = b3fdc1dd3998fc3866c865374a20573c OK
2024/10/01 04:28:57 INFO  : only11: Copied (replaced existing)
2024/10/01 04:28:57 DEBUG : only13: md5 = f3e731624711e86e97b8521f8614b860 OK
2024/10/01 04:28:57 INFO  : only13: Copied (replaced existing)
2024/10/01 04:28:59 DEBUG : only10: md5 = ae0d4764626f3e32195baa71ee5a5a35 OK
2024/10/01 04:28:59 INFO  : only10: Copied (replaced existing)
2024/10/01 04:28:59 DEBUG : only3: md5 = 362f2c174ad664b22816b4a92ea175e2 OK
2024/10/01 04:28:59 INFO  : only3: Copied (replaced existing)
2024/10/01 04:28:59 DEBUG : only7: md5 = 65291fd8ee4251cf47f319fd48e4af8f OK
2024/10/01 04:28:59 INFO  : only7: Copied (replaced existing)
2024/10/01 04:29:00 DEBUG : only8: md5 = 2233035fca849ea4921beb701f43c3ed OK
2024/10/01 04:29:00 INFO  : only8: Copied (replaced existing)
2024/10/01 04:29:00 DEBUG : only9: md5 = a503fbc052539c0fa2d9ea6d0f0f4ebd OK
2024/10/01 04:29:00 INFO  : only9: Copied (replaced existing)
2024/10/01 04:29:01 DEBUG : only4: md5 = f71ed5afb73852c54d0e9d4b9bf5b285 OK
2024/10/01 04:29:01 INFO  : only4: Copied (replaced existing)
2024/10/01 04:29:01 DEBUG : only5: md5 = 69ac172fcb9dbf79c22ae9652b1afb0e OK
2024/10/01 04:29:01 INFO  : only5: Copied (replaced existing)
2024/10/01 04:29:01 DEBUG : only6: md5 = e9a0a9e46b0cecf2787b86cc827efdc6 OK
2024/10/01 04:29:01 INFO  : only6: Copied (replaced existing)
2024/10/01 04:29:01 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (109.55s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:29:28 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/10/01 04:29:28 DEBUG : sub dir: Making directory with metadata
2024/10/01 04:29:29 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:29:54 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/10/01 04:29:55 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/10/01 04:29:55 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/10/01 04:29:55 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:30:12 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2024/10/01 04:30:13 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/10/01 04:30:14 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/10/01 04:30:15 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/10/01 04:30:16 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/10/01 04:30:17 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/10/01 04:30:18 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/10/01 04:30:19 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/10/01 04:30:20 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/10/01 04:30:21 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/10/01 04:30:21 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/10/01 04:30:22 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (56.30s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:30:24 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2024/10/01 04:30:24 DEBUG : sub dir: Making directory with metadata
2024/10/01 04:30:25 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:30:57 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/10/01 04:30:57 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2024/10/01 04:30:57 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2024/10/01 04:30:57 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko'", Local "Local file system at /tmp/rclone3304300658", Modify Window "1ms"
2024/10/01 04:31:13 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/10/01 04:31:14 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2024/10/01 04:31:15 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2024/10/01 04:31:16 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/10/01 04:31:17 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/10/01 04:31:18 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/10/01 04:31:19 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/10/01 04:31:20 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2024/10/01 04:31:21 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2024/10/01 04:31:21 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2024/10/01 04:31:22 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (60.00s)
PASS
2024/10/01 04:31:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-turinoz6foko': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 20m4.805752666s (try 1/5)