"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5)
2025/01/22 01:58:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume"
2025/01/22 01:58:26 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/01/22 01:58:26 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00"
2025/01/22 01:58:27 DEBUG : Creating backend with remote "/tmp/rclone1262997294"
=== RUN   TestPipe
--- PASS: TestPipe (0.00s)
=== RUN   TestPipeConcurrent
--- PASS: TestPipeConcurrent (0.04s)
=== 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-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:58:29 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/22 01:58:29 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/22 01:58:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 01:58:29 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2025/01/22 01:58:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 01:58:29 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestCopyWithDryRun (2.68s)
=== RUN   TestCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:58:30 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/22 01:58:31 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/22 01:58:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/22 01:58:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 01:58:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 01:58:34 DEBUG : sub dir/hello world: md5 = 36c2136c9040e39bebf93fddb00380e1 OK
2025/01/22 01:58:34 INFO  : sub dir/hello world: Copied (new)
2025/01/22 01:58:35 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:58:37 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopy (8.21s)
=== RUN   TestCopyMetadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:58:38 DEBUG : metadata sub dir: Making directory with metadata
2025/01/22 01:58:38 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/22 01:58:38 DEBUG : empty metadata sub dir: Making directory with metadata
2025/01/22 01:58:38 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/22 01:58:38 DEBUG : Local file system at /tmp/rclone1262997294: File to upload is small (21 bytes), uploading instead of streaming
2025/01/22 01:58:38 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2025/01/22 01:58:38 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2025/01/22 01:58:38 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2025/01/22 01:58:39 DEBUG : Google drive root 'crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00': Skipping btime metadata as can't update it on an existing file: 2025-01-22T01:58:38.819998312Z
2025/01/22 01:58:40 INFO  : empty metadata sub dir: Updated directory metadata
2025/01/22 01:58:40 DEBUG : Google drive root 'crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00': Skipping btime metadata as can't update it on an existing file: 2025-01-22T01:58:38.819998312Z
2025/01/22 01:58:41 INFO  : metadata sub dir: Updated directory metadata
2025/01/22 01:58:41 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2025/01/22 01:58:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 01:58:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 01:58:43 DEBUG : metadata sub dir/hello metadata world: md5 = 00a6cac4fb14ab09a6643f6e1d73db80 OK
2025/01/22 01:58:43 INFO  : metadata sub dir/hello metadata world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:58:46 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadata (9.97s)
=== RUN   TestCopyMetadataNoEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:58:48 DEBUG : metadata sub dir: Making directory with metadata
2025/01/22 01:58:48 INFO  : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/22 01:58:48 DEBUG : empty metadata sub dir: Making directory with metadata
2025/01/22 01:58:48 INFO  : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/22 01:58:48 DEBUG : Local file system at /tmp/rclone1262997294: File to upload is small (21 bytes), uploading instead of streaming
2025/01/22 01:58:48 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK
2025/01/22 01:58:48 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical
2025/01/22 01:58:48 INFO  : metadata sub dir: Set directory modification time (using DirSetModTime)
2025/01/22 01:58:49 DEBUG : Added delayed dir = "empty metadata sub dir", newDst=<nil>
2025/01/22 01:58:49 DEBUG : Added delayed dir = "metadata sub dir", newDst=<nil>
2025/01/22 01:58:49 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination
2025/01/22 01:58:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 01:58:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 01:58:52 DEBUG : metadata sub dir/hello metadata world: md5 = df79bd92b2a47b27fb62317a5b1a3e4b OK
2025/01/22 01:58:52 INFO  : metadata sub dir/hello metadata world: Copied (new)
2025/01/22 01:58:52 DEBUG : Google drive root 'crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00': Skipping btime metadata as can't update it on an existing file: 2025-01-22T01:58:48.791926274Z
2025/01/22 01:58:52 INFO  : metadata sub dir: Updated directory metadata
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:58:55 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470"
--- PASS: TestCopyMetadataNoEmptyDirs (8.60s)
=== RUN   TestCopyMissingDirectory
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:58:57 DEBUG : Creating backend with remote "/non-existing"
2025/01/22 01:58:57 DEBUG : Config file has changed externally - reloading
2025/01/22 01:58:57 ERROR : Local file system at /non-existing: error reading source root directory: directory not found
2025/01/22 01:58:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 01:58:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestCopyMissingDirectory (1.23s)
=== RUN   TestCopyNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:58:58 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/22 01:58:58 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/22 01:58:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 01:58:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 01:59:01 DEBUG : sub dir/hello world: md5 = f3013e6df8279f3108600dfe67ab47a2 OK
2025/01/22 01:59:01 INFO  : sub dir/hello world: Copied (new)
2025/01/22 01:59:02 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:59:04 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoTraverse (7.34s)
=== RUN   TestCopyCheckFirst
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:59:05 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Running all checks before starting transfers
2025/01/22 01:59:06 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/22 01:59:06 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/22 01:59:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 01:59:06 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Checks finished, now starting transfers
2025/01/22 01:59:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 01:59:09 DEBUG : sub dir/hello world: md5 = 0f4351e72d9c7589489eb2947c40be8e OK
2025/01/22 01:59:09 INFO  : sub dir/hello world: Copied (new)
2025/01/22 01:59:09 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:59:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyCheckFirst (7.56s)
=== RUN   TestSyncNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:59:13 ERROR : Ignoring --no-traverse with sync
2025/01/22 01:59:13 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/22 01:59:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/22 01:59:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 01:59:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 01:59:16 DEBUG : sub dir/hello world: md5 = 6cdfcf2befe4003afff6ec464a1cd751 OK
2025/01/22 01:59:16 INFO  : sub dir/hello world: Copied (new)
2025/01/22 01:59:16 DEBUG : Waiting for deletions to finish
2025/01/22 01:59:17 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:59:19 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoTraverse (7.37s)
=== RUN   TestCopyWithDepth
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:59:21 DEBUG : hello world2: Need to transfer - File not found at Destination
2025/01/22 01:59:21 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/22 01:59:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 01:59:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 01:59:22 DEBUG : hello world2: md5 = b3ceb187b469bc84bf26eacaae324224 OK
2025/01/22 01:59:22 INFO  : hello world2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestCopyWithDepth (3.96s)
=== RUN   TestCopyWithFilesFrom
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:59:25 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/22 01:59:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 01:59:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 01:59:26 DEBUG : potato2: md5 = 0bda181cf9c12315b5cc36ce02113163 OK
2025/01/22 01:59:26 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestCopyWithFilesFrom (3.94s)
=== RUN   TestCopyWithFilesFromAndNoTraverse
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:59:29 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/22 01:59:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 01:59:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 01:59:30 DEBUG : potato2: md5 = d6f9214e8f18450bbca2e8bf953935b8 OK
2025/01/22 01:59:30 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestCopyWithFilesFromAndNoTraverse (3.61s)
=== RUN   TestCopyEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:59:32 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/01/22 01:59:32 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/22 01:59:32 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/22 01:59:32 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/22 01:59:32 DEBUG : sub dir: Making directory with metadata
2025/01/22 01:59:33 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/01/22 01:59:33 DEBUG : sub dir2: Making directory with metadata
2025/01/22 01:59:34 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/22 01:59:34 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/01/22 01:59:34 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/22 01:59:35 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/22 01:59:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 01:59:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 01:59:36 DEBUG : sub dir/hello world: md5 = 8dd85ce7616b4cae5c2437a7ad151117 OK
2025/01/22 01:59:36 INFO  : sub dir/hello world: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:59:40 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0"
2025/01/22 01:59:41 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyEmptyDirectories (10.93s)
=== RUN   TestCopyNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:59:43 INFO  : sub dir2: Making directory
2025/01/22 01:59:43 DEBUG : sub dir2/sub sub dir2: Making directory with metadata
2025/01/22 01:59:43 INFO  : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/22 01:59:43 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/22 01:59:43 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/01/22 01:59:43 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst=<nil>
2025/01/22 01:59:43 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/22 01:59:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 01:59:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 01:59:46 DEBUG : sub dir/hello world: md5 = 74de321e5c4e4febafaa17251323d108 OK
2025/01/22 01:59:46 INFO  : sub dir/hello world: Copied (new)
2025/01/22 01:59:47 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/22 01:59:49 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyNoEmptyDirectories (6.78s)
=== RUN   TestMoveEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:59:50 DEBUG : sub dir2: Making directory with metadata
2025/01/22 01:59:50 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/22 01:59:50 DEBUG : sub dir: Making directory with metadata
2025/01/22 01:59:51 INFO  : sub dir: Made directory with metadata (mtime=2025-01-22T01:59:50.099483435Z)
2025/01/22 01:59:51 DEBUG : sub dir2: Making directory with metadata
2025/01/22 01:59:52 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/22 01:59:52 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/22 01:59:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 01:59:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 01:59:54 DEBUG : sub dir/hello world: md5 = 3c3899ae3ae20781f3da392f8de7452d OK
2025/01/22 01:59:54 INFO  : sub dir/hello world: Copied (new)
2025/01/22 01:59:54 INFO  : sub dir/hello world: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:59:57 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveEmptyDirectories (9.18s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 01:59:59 DEBUG : sub dir no update dir modtime: Making directory with metadata
2025/01/22 01:59:59 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/01/22 02:00:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:00:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:00:01 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncNoUpdateDirModtime (4.85s)
=== RUN   TestMoveNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:00:04 INFO  : sub dir2: Making directory
2025/01/22 02:00:04 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/22 02:00:04 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/01/22 02:00:04 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/22 02:00:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:00:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:00:07 DEBUG : sub dir/hello world: md5 = 456ba9b84c4f13db2bf93781eba74d3c OK
2025/01/22 02:00:07 INFO  : sub dir/hello world: Copied (new)
2025/01/22 02:00:07 INFO  : sub dir/hello world: Deleted
2025/01/22 02:00:08 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/22 02:00:10 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveNoEmptyDirectories (6.93s)
=== RUN   TestSyncEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:00:11 DEBUG : sub dir2: Making directory with metadata
2025/01/22 02:00:11 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/22 02:00:11 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/22 02:00:11 DEBUG : sub dir: Making directory with metadata
2025/01/22 02:00:12 INFO  : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2025/01/22 02:00:12 DEBUG : sub dir2: Making directory with metadata
2025/01/22 02:00:13 INFO  : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/22 02:00:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/22 02:00:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:00:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:00:15 DEBUG : sub dir/hello world: md5 = 50c378ac0bd0d7371bfe187825ec7c06 OK
2025/01/22 02:00:15 INFO  : sub dir/hello world: Copied (new)
2025/01/22 02:00:15 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:00:18 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncEmptyDirectories (8.97s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set
--- SKIP: TestSyncSetDelayedModTimes (0.49s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:00:20 INFO  : sub dir2: Making directory
2025/01/22 02:00:20 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/22 02:00:20 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2025/01/22 02:00:20 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/22 02:00:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:00:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:00:23 DEBUG : sub dir/hello world: md5 = 36dc5b85a8b2d8b1b87b95b55bc6034f OK
2025/01/22 02:00:23 INFO  : sub dir/hello world: Copied (new)
2025/01/22 02:00:23 DEBUG : Waiting for deletions to finish
2025/01/22 02:00:24 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/22 02:00:26 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestSyncNoEmptyDirectories (7.03s)
=== RUN   TestServerSideCopy
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:00:30 DEBUG : sub dir/hello world: md5 = b40e4d4f49a1f1401ba1c19135aec4a0 OK
2025/01/22 02:00:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kilijoj6loju"
2025/01/22 02:00:31 DEBUG : Config file has changed externally - reloading
2025/01/22 02:00:31 DEBUG : Creating backend with remote "TestDrive:crypt/jst4sq3kbq5llr96k3iu98pvq055cenctd5trji1l0pndpnte3i0"
    sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume' -> Encrypted drive 'TestCryptDrive:rclone-test-kilijoj6loju'
2025/01/22 02:00:32 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/22 02:00:32 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/22 02:00:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kilijoj6loju': Waiting for checks to finish
2025/01/22 02:00:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kilijoj6loju': Waiting for transfers to finish
2025/01/22 02:00:36 INFO  : sub dir/hello world: Copied (server-side copy)
2025/01/22 02:00:36 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:00:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kilijoj6loju': Purge remote
2025/01/22 02:00:39 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopy (13.53s)
=== RUN   TestCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:00:43 DEBUG : sub dir/hello world: md5 = 1e75cba932fd0031ceeac7bcc8c23c70 OK
2025/01/22 02:00:44 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/22 02:00:45 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/01/22 02:00:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:00:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:00:46 DEBUG : sub dir/hello world: md5 = 6aaaf5d9070e1540fdcc7c31d856356d OK
2025/01/22 02:00:46 INFO  : sub dir/hello world: Copied (replaced existing)
2025/01/22 02:00:47 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:00:49 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyOverSelf (9.86s)
=== RUN   TestServerSideCopyOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:00:54 DEBUG : sub dir/hello world: md5 = 62f7536b92111d1ead7382f25d9a53dc OK
2025/01/22 02:00:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-jecejij0gusa"
2025/01/22 02:00:54 DEBUG : Config file has changed externally - reloading
2025/01/22 02:00:54 DEBUG : Creating backend with remote "TestDrive:crypt/i8f667uahc04kn7dt886jn9ivvld4qqnj2l62647ua0kol342mbg"
    sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume' -> Encrypted drive 'TestCryptDrive:rclone-test-jecejij0gusa'
2025/01/22 02:00:55 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/22 02:00:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/22 02:00:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jecejij0gusa': Waiting for checks to finish
2025/01/22 02:00:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jecejij0gusa': Waiting for transfers to finish
2025/01/22 02:00:59 INFO  : sub dir/hello world: Copied (server-side copy)
2025/01/22 02:01:00 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:01:02 DEBUG : sub dir/hello world: md5 = 77688d3d4e436e950f11b3ef71a6111f OK
2025/01/22 02:01:03 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/01/22 02:01:03 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/22 02:01:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jecejij0gusa': Waiting for checks to finish
2025/01/22 02:01:03 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/01/22 02:01:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jecejij0gusa': Waiting for transfers to finish
2025/01/22 02:01:05 INFO  : sub dir/hello world: Copied (server-side copy)
2025/01/22 02:01:06 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:01:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jecejij0gusa': Purge remote
2025/01/22 02:01:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestServerSideCopyOverSelf (22.05s)
=== RUN   TestMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:01:15 DEBUG : sub dir/hello world: md5 = 228cd546ad7c51a5c2dd5a12e04dd110 OK
2025/01/22 02:01:16 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/22 02:01:16 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/01/22 02:01:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:01:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:01:18 DEBUG : sub dir/hello world: md5 = 43914c7af47c64ec64b55330baa61383 OK
2025/01/22 02:01:18 INFO  : sub dir/hello world: Copied (replaced existing)
2025/01/22 02:01:18 INFO  : sub dir/hello world: Deleted
2025/01/22 02:01:18 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:01:20 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestMoveOverSelf (9.30s)
=== RUN   TestServerSideMoveOverSelf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:01:25 DEBUG : sub dir/hello world: md5 = 6a1f2377ee2956f15da541ec0c50a010 OK
2025/01/22 02:01:25 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xuhavig1fetu"
2025/01/22 02:01:25 DEBUG : Creating backend with remote "TestDrive:crypt/sm051f5daeuu28dt0r1b8j4k0imhb7c31lm7rrb6rat3l60gveh0"
    sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume' -> Encrypted drive 'TestCryptDrive:rclone-test-xuhavig1fetu'
2025/01/22 02:01:27 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/22 02:01:27 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/22 02:01:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuhavig1fetu': Waiting for checks to finish
2025/01/22 02:01:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuhavig1fetu': Waiting for transfers to finish
2025/01/22 02:01:30 INFO  : sub dir/hello world: Copied (server-side copy)
2025/01/22 02:01:31 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:01:33 DEBUG : sub dir/hello world: md5 = 90191e2f9e9f207510086e91eab025ff OK
2025/01/22 02:01:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuhavig1fetu': Using server-side directory move
2025/01/22 02:01:34 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-xuhavig1fetu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/01/22 02:01:34 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/01/22 02:01:34 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/22 02:01:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuhavig1fetu': Waiting for checks to finish
2025/01/22 02:01:34 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/01/22 02:01:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuhavig1fetu': Waiting for transfers to finish
2025/01/22 02:01:35 INFO  : sub dir/hello world: Deleted
2025/01/22 02:01:36 INFO  : sub dir/hello world: Moved (server-side)
2025/01/22 02:01:36 INFO  : sub dir: Set directory modification time (using SetModTime)
2025/01/22 02:01:39 DEBUG : sub dir/hello world: md5 = 6f87a49182ef9e3b5060d0da68a248e2 OK
2025/01/22 02:01:40 DEBUG : testing file moves
2025/01/22 02:01:40 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms)
2025/01/22 02:01:40 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/01/22 02:01:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuhavig1fetu': Waiting for checks to finish
2025/01/22 02:01:40 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17)
2025/01/22 02:01:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuhavig1fetu': Waiting for transfers to finish
2025/01/22 02:01:41 INFO  : sub dir/hello world: Deleted
2025/01/22 02:01:42 INFO  : sub dir/hello world: Moved (server-side)
2025/01/22 02:01:42 INFO  : sub dir: Set directory modification time (using SetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:01:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xuhavig1fetu': Purge remote
--- PASS: TestServerSideMoveOverSelf (24.86s)
=== RUN   TestCopyAfterDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:01:50 DEBUG : sub dir/hello world: md5 = 8f521fd367608a230a385393ee17997f OK
2025/01/22 02:01:50 ERROR : : error listing: directory not found
2025/01/22 02:01:50 INFO  : Local file system at /tmp/rclone1262997294: Making directory
2025/01/22 02:01:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:01:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:01:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyAfterDelete (7.10s)
=== RUN   TestCopyRedownload
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:01:57 DEBUG : sub dir/hello world: md5 = 42b85a79785ba8c6c3d28bfbee9edf60 OK
2025/01/22 02:01:57 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/22 02:01:58 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/22 02:01:58 DEBUG : Local file system at /tmp/rclone1262997294: Waiting for checks to finish
2025/01/22 02:01:58 DEBUG : Local file system at /tmp/rclone1262997294: Waiting for transfers to finish
2025/01/22 02:01:59 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world
2025/01/22 02:01:59 INFO  : sub dir/hello world: Copied (new)
2025/01/22 02:01:59 INFO  : sub dir: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:02:00 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestCopyRedownload (7.81s)
=== RUN   TestSyncBasedOnCheckSum
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:02:02 DEBUG : check sum: Need to transfer - File not found at Destination
2025/01/22 02:02:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:02:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:02:04 DEBUG : check sum: md5 = 0c7871ae255751200fcc7a0d812f29dd OK
2025/01/22 02:02:04 INFO  : check sum: Copied (new)
2025/01/22 02:02:04 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:02:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:02:04 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only
2025/01/22 02:02:04 DEBUG : check sum: Size of src and dst objects identical
2025/01/22 02:02:04 DEBUG : check sum: Unchanged skipping
2025/01/22 02:02:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:02:04 DEBUG : Waiting for deletions to finish
2025/01/22 02:02:04 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncBasedOnCheckSum (6.35s)
=== RUN   TestSyncSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:02:08 DEBUG : sizeonly: Need to transfer - File not found at Destination
2025/01/22 02:02:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:02:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:02:10 DEBUG : sizeonly: md5 = c5dca0f27c00f14ba36ab0fc352fbc92 OK
2025/01/22 02:02:10 INFO  : sizeonly: Copied (new)
2025/01/22 02:02:10 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:02:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:02:10 DEBUG : sizeonly: Sizes identical
2025/01/22 02:02:10 DEBUG : sizeonly: Unchanged skipping
2025/01/22 02:02:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:02:10 DEBUG : Waiting for deletions to finish
2025/01/22 02:02:10 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncSizeOnly (4.63s)
=== RUN   TestSyncIgnoreSize
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:02:13 DEBUG : ignore-size: Need to transfer - File not found at Destination
2025/01/22 02:02:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:02:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:02:14 DEBUG : ignore-size: md5 = b2ae3103afa156ab7cbc8603ea9cfa81 OK
2025/01/22 02:02:14 INFO  : ignore-size: Copied (new)
2025/01/22 02:02:14 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:02:15 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:02:15 DEBUG : ignore-size: Unchanged skipping
2025/01/22 02:02:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:02:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:02:15 DEBUG : Waiting for deletions to finish
2025/01/22 02:02:15 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncIgnoreSize (4.74s)
=== RUN   TestSyncIgnoreTimes
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:02:19 DEBUG : existing: md5 = a133c460bd2f690a0a77ba1717d96115 OK
2025/01/22 02:02:19 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:02:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:02:19 DEBUG : existing: Unchanged skipping
2025/01/22 02:02:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:02:19 DEBUG : Waiting for deletions to finish
2025/01/22 02:02:19 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:02:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:02:20 DEBUG : existing: Transferring unconditionally as --ignore-times is in use
2025/01/22 02:02:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:02:21 DEBUG : existing: md5 = 366e9052b8d565f6c3389d3069a5a793 OK
2025/01/22 02:02:21 INFO  : existing: Copied (replaced existing)
2025/01/22 02:02:21 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncIgnoreTimes (6.18s)
=== RUN   TestSyncIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:02:24 DEBUG : existing: Need to transfer - File not found at Destination
2025/01/22 02:02:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:02:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:02:26 DEBUG : existing: md5 = 42a1d67d1d2e380f4eb2da42eabdd2bb OK
2025/01/22 02:02:26 INFO  : existing: Copied (new)
2025/01/22 02:02:26 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:02:26 DEBUG : existing: Destination exists, skipping
2025/01/22 02:02:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:02:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:02:26 DEBUG : Waiting for deletions to finish
2025/01/22 02:02:26 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncIgnoreExisting (5.65s)
=== RUN   TestSyncIgnoreErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:02:32 DEBUG : b/potato: md5 = 700974139badaacd3f7dac8b44546a98 OK
2025/01/22 02:02:36 DEBUG : c/non empty space: md5 = 495d26adacbc3470c7834580edfb4e32 OK
2025/01/22 02:02:36 INFO  : d: Making directory
2025/01/22 02:02:38 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/01/22 02:02:38 DEBUG : Added delayed dir = "c", newDst=c
2025/01/22 02:02:38 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/01/22 02:02:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:02:38 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:02:38 DEBUG : c/non empty space: Unchanged skipping
2025/01/22 02:02:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:02:41 DEBUG : a/potato2: md5 = 4e546d7e2534909e591f19f64e4404f7 OK
2025/01/22 02:02:41 INFO  : a/potato2: Copied (new)
2025/01/22 02:02:41 DEBUG : Waiting for deletions to finish
2025/01/22 02:02:41 INFO  : b/potato: Deleted
2025/01/22 02:02:42 INFO  : a: Set directory modification time (using DirSetModTime)
2025/01/22 02:02:42 INFO  : d: Removing directory
2025/01/22 02:02:43 INFO  : b: Removing directory
2025/01/22 02:02:43 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/01/22 02:02:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': deleted 2 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:02:47 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/01/22 02:02:48 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncIgnoreErrors (19.93s)
=== RUN   TestSyncAfterChangingModtimeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:02:51 DEBUG : empty space: md5 = 93f89d9d7c41a89634358bc520b0ac72 OK
2025/01/22 02:02:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:02:51 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2025/01/22 02:02:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:02:51 NOTICE: empty space: Skipped copy as --dry-run is set (size 1)
2025/01/22 02:02:51 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:02:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:02:52 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2025/01/22 02:02:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:02:53 DEBUG : empty space: md5 = de7f68d0504a3a6eb8e1b708b8a92d9e OK
2025/01/22 02:02:53 INFO  : empty space: Copied (replaced existing)
2025/01/22 02:02:53 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncAfterChangingModtimeOnly (6.51s)
=== RUN   TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    sync_test.go:1016: Can't check this if no hashes supported
--- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.44s)
=== RUN   TestSyncDoesntUpdateModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:02:58 DEBUG : foo: md5 = 218ee4154d7adb2a4021761b564279c6 OK
2025/01/22 02:02:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:02:58 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC
2025/01/22 02:02:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:03:00 DEBUG : foo: md5 = dd6669eaa2c7d6026cad7043d19a7a3f OK
2025/01/22 02:03:00 INFO  : foo: Copied (replaced existing)
2025/01/22 02:03:00 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncDoesntUpdateModtime (5.95s)
=== RUN   TestSyncAfterAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:03:04 DEBUG : empty space: md5 = 0b31765d837ab5f1338270527a40b138 OK
2025/01/22 02:03:04 DEBUG : potato: Need to transfer - File not found at Destination
2025/01/22 02:03:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:03:04 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:03:04 DEBUG : empty space: Unchanged skipping
2025/01/22 02:03:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:03:07 DEBUG : potato: md5 = e24d289f52226abfddb153d259d9e665 OK
2025/01/22 02:03:07 INFO  : potato: Copied (new)
2025/01/22 02:03:07 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncAfterAddingAFile (7.24s)
=== RUN   TestSyncAfterChangingFilesSizeOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:03:11 DEBUG : potato: md5 = 241944003d65d69737e0cc68b5308774 OK
2025/01/22 02:03:11 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2025/01/22 02:03:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:03:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:03:13 DEBUG : potato: md5 = 178e89f9c267ec9d8f439a993571a310 OK
2025/01/22 02:03:13 INFO  : potato: Copied (replaced existing)
2025/01/22 02:03:13 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncAfterChangingFilesSizeOnly (5.35s)
=== RUN   TestSyncAfterChangingContentsOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:03:16 DEBUG : potato: md5 = a8de7f594c0fa9fc00ce68a2df26dbf6 OK
2025/01/22 02:03:17 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC
2025/01/22 02:03:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:03:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:03:18 DEBUG : potato: md5 = f2c0343212a4128f1fe564d7154ec58f OK
2025/01/22 02:03:18 INFO  : potato: Copied (replaced existing)
2025/01/22 02:03:18 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncAfterChangingContentsOnly (5.67s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileDryRun
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:03:22 DEBUG : potato: md5 = 2e9dbb14c22d27d9e1fef7bd1f1c8c2c OK
2025/01/22 02:03:24 DEBUG : empty space: md5 = a1938b50995de562ab2e6d152a562fdc OK
2025/01/22 02:03:24 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/22 02:03:24 NOTICE: potato2: Skipped copy as --dry-run is set (size 60)
2025/01/22 02:03:24 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:03:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:03:24 DEBUG : empty space: Unchanged skipping
2025/01/22 02:03:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:03:24 DEBUG : Waiting for deletions to finish
2025/01/22 02:03:24 NOTICE: potato: Skipped delete as --dry-run is set (size 21)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (6.34s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFile
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:03:28 DEBUG : potato: md5 = 692ffd7d7c73c4fb41cd32db9c9a5182 OK
2025/01/22 02:03:30 DEBUG : empty space: md5 = 83bb940387895993eafd2c6ec58c3655 OK
2025/01/22 02:03:31 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/22 02:03:31 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:03:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:03:31 DEBUG : empty space: Unchanged skipping
2025/01/22 02:03:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:03:32 DEBUG : potato2: md5 = fc07a064727b2b26e811dd14ac451468 OK
2025/01/22 02:03:32 INFO  : potato2: Copied (new)
2025/01/22 02:03:32 DEBUG : Waiting for deletions to finish
2025/01/22 02:03:33 INFO  : potato: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.77s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:03:38 DEBUG : b/potato: md5 = 549f9b74c2aecf7ebcc6f4241ab7247a OK
2025/01/22 02:03:42 DEBUG : c/non empty space: md5 = 08cab8a4caffeab517d99767a6653bfd OK
2025/01/22 02:03:42 INFO  : d: Making directory
2025/01/22 02:03:43 INFO  : d/e: Making directory
2025/01/22 02:03:45 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/01/22 02:03:45 DEBUG : Added delayed dir = "c", newDst=c
2025/01/22 02:03:45 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/01/22 02:03:46 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:03:46 DEBUG : c/non empty space: Unchanged skipping
2025/01/22 02:03:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:03:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:03:48 DEBUG : a/potato2: md5 = d4d97ad703cf6249b9a8203227a39eaa OK
2025/01/22 02:03:48 INFO  : a/potato2: Copied (new)
2025/01/22 02:03:48 DEBUG : Waiting for deletions to finish
2025/01/22 02:03:49 INFO  : b/potato: Deleted
2025/01/22 02:03:50 INFO  : a: Set directory modification time (using DirSetModTime)
2025/01/22 02:03:50 INFO  : d/e: Removing directory
2025/01/22 02:03:51 INFO  : d: Removing directory
2025/01/22 02:03:51 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8"
2025/01/22 02:03:52 INFO  : b: Removing directory
2025/01/22 02:03:52 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/01/22 02:03:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:03:56 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/01/22 02:03:57 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (22.69s)
=== RUN   TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:04:01 DEBUG : b/potato: md5 = f6ac5550f69b5fb6e88113326659b0a0 OK
2025/01/22 02:04:04 DEBUG : c/non empty space: md5 = b4f04af32754d5d9ab615d1ae9457d27 OK
2025/01/22 02:04:04 INFO  : d: Making directory
2025/01/22 02:04:06 DEBUG : Added delayed dir = "a", newDst=<nil>
2025/01/22 02:04:06 DEBUG : Added delayed dir = "c", newDst=c
2025/01/22 02:04:06 DEBUG : a/potato2: Need to transfer - File not found at Destination
2025/01/22 02:04:06 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:04:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:04:06 DEBUG : c/non empty space: Unchanged skipping
2025/01/22 02:04:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:04:09 DEBUG : a/potato2: md5 = e1259f6a31fa4492d5182ed794111be5 OK
2025/01/22 02:04:09 INFO  : a/potato2: Copied (new)
2025/01/22 02:04:09 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': not deleting files as there were IO errors
2025/01/22 02:04:09 INFO  : a: Set directory modification time (using DirSetModTime)
2025/01/22 02:04:09 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:04:14 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s"
2025/01/22 02:04:14 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4"
2025/01/22 02:04:16 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg"
--- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (19.01s)
=== RUN   TestSyncDeleteAfter
--- PASS: TestSyncDeleteAfter (0.00s)
=== RUN   TestSyncDeleteDuring
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:04:19 DEBUG : potato: md5 = 99f27c69c936b887e784545af58a9d86 OK
2025/01/22 02:04:20 DEBUG : empty space: md5 = c0cc8982764baf519820e818cb605636 OK
2025/01/22 02:04:21 DEBUG : Waiting for deletions to finish
2025/01/22 02:04:21 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/22 02:04:21 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:04:21 DEBUG : empty space: Unchanged skipping
2025/01/22 02:04:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:04:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:04:22 INFO  : potato: Deleted
2025/01/22 02:04:23 DEBUG : potato2: md5 = 9cc8dc4c88a463d61483b134211491d5 OK
2025/01/22 02:04:23 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncDeleteDuring (8.39s)
=== RUN   TestSyncDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:04:27 DEBUG : potato: md5 = 8be9e23d9f32a7e6f4cf51a515f5b466 OK
2025/01/22 02:04:29 DEBUG : empty space: md5 = c7e690f91cf4782d5d0f3bc0d75b7b8a OK
2025/01/22 02:04:29 DEBUG : Waiting for deletions to finish
2025/01/22 02:04:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:04:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:04:30 INFO  : potato: Deleted
2025/01/22 02:04:30 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/22 02:04:30 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:04:30 DEBUG : empty space: Unchanged skipping
2025/01/22 02:04:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:04:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:04:32 DEBUG : potato2: md5 = ad332dd3e9a128cc1120f500e4b8af51 OK
2025/01/22 02:04:32 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncDeleteBefore (9.26s)
=== RUN   TestCopyDeleteBefore
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:04:36 DEBUG : potato: md5 = 54e9aeae0ac827651a65062eb2c8f233 OK
2025/01/22 02:04:37 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/22 02:04:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:04:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:04:39 DEBUG : potato2: md5 = d7bcf2f43949367486712d83eaf2459f OK
2025/01/22 02:04:39 INFO  : potato2: Copied (new)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestCopyDeleteBefore (6.30s)
=== RUN   TestSyncWithExclude
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:04:43 DEBUG : potato2: md5 = 72cca8eb33db626fa2f6b407d10d3142 OK
2025/01/22 02:04:44 DEBUG : empty space: md5 = 3b959e0d635da09c6049f29e0537a5a6 OK
2025/01/22 02:04:45 DEBUG : enormous: Excluded (Size Filter)
2025/01/22 02:04:45 DEBUG : enormous: Excluded
2025/01/22 02:04:45 DEBUG : potato2: Excluded (Size Filter)
2025/01/22 02:04:45 DEBUG : potato2: Excluded
2025/01/22 02:04:45 DEBUG : potato2: Excluded (Size Filter)
2025/01/22 02:04:45 DEBUG : potato2: Excluded
2025/01/22 02:04:45 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:04:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:04:45 DEBUG : empty space: Unchanged skipping
2025/01/22 02:04:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:04:45 DEBUG : Waiting for deletions to finish
2025/01/22 02:04:45 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:04:45 DEBUG : enormous: Excluded (Size Filter)
2025/01/22 02:04:45 DEBUG : enormous: Excluded
2025/01/22 02:04:45 DEBUG : potato2: Excluded (Size Filter)
2025/01/22 02:04:45 DEBUG : potato2: Excluded
2025/01/22 02:04:45 DEBUG : potato2: Excluded (Size Filter)
2025/01/22 02:04:45 DEBUG : potato2: Excluded
2025/01/22 02:04:45 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2025/01/22 02:04:45 DEBUG : empty space: Unchanged skipping
2025/01/22 02:04:45 DEBUG : Local file system at /tmp/rclone1262997294: Waiting for checks to finish
2025/01/22 02:04:45 DEBUG : Local file system at /tmp/rclone1262997294: Waiting for transfers to finish
2025/01/22 02:04:45 DEBUG : Waiting for deletions to finish
2025/01/22 02:04:45 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncWithExclude (7.03s)
=== RUN   TestSyncWithExcludeAndDeleteExcluded
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:04:50 DEBUG : potato2: md5 = d51da357aa52cefbb872fb4419bfbff2 OK
2025/01/22 02:04:52 DEBUG : empty space: md5 = fad115e71d6f3251e0d3d8e39fa6a9a9 OK
2025/01/22 02:04:53 DEBUG : enormous: md5 = 07fbc7d6af82412438eac606ca00326e OK
2025/01/22 02:04:54 DEBUG : enormous: Excluded (Size Filter)
2025/01/22 02:04:54 DEBUG : enormous: Excluded
2025/01/22 02:04:54 DEBUG : potato2: Excluded (Size Filter)
2025/01/22 02:04:54 DEBUG : potato2: Excluded
2025/01/22 02:04:54 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:04:54 DEBUG : empty space: Unchanged skipping
2025/01/22 02:04:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:04:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:04:54 DEBUG : Waiting for deletions to finish
2025/01/22 02:04:54 INFO  : enormous: Deleted
2025/01/22 02:04:55 INFO  : potato2: Deleted
2025/01/22 02:04:55 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:04:55 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms)
2025/01/22 02:04:55 DEBUG : empty space: Unchanged skipping
2025/01/22 02:04:55 DEBUG : Local file system at /tmp/rclone1262997294: Waiting for checks to finish
2025/01/22 02:04:55 DEBUG : Local file system at /tmp/rclone1262997294: Waiting for transfers to finish
2025/01/22 02:04:55 DEBUG : Waiting for deletions to finish
2025/01/22 02:04:55 INFO  : enormous: Deleted
2025/01/22 02:04:55 INFO  : potato2: Deleted
2025/01/22 02:04:55 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncWithExcludeAndDeleteExcluded (9.23s)
=== RUN   TestSyncWithUpdateOlder
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:04:59 DEBUG : one: md5 = 899ded8ed59a01eba22bb1783f8e4895 OK
2025/01/22 02:05:01 DEBUG : two: md5 = 0498a8f21a75d04c282711de777b0248 OK
2025/01/22 02:05:02 DEBUG : three: md5 = 2a352596a694ae58ae3cf4da616715eb OK
2025/01/22 02:05:04 DEBUG : four: md5 = bb8484dde3bc3cd83b333a8ba4afe48f OK
2025/01/22 02:05:05 DEBUG : five: Need to transfer - File not found at Destination
2025/01/22 02:05:05 DEBUG : four: Sizes differ (src 4 vs dst 8)
2025/01/22 02:05:05 DEBUG : one: Destination is newer than source, skipping
2025/01/22 02:05:05 DEBUG : three: Sizes identical
2025/01/22 02:05:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:05:05 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring
2025/01/22 02:05:05 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping
2025/01/22 02:05:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:05:06 DEBUG : two: md5 = 4a8280c581adb1204b8288174b5fa7df OK
2025/01/22 02:05:06 INFO  : two: Copied (replaced existing)
2025/01/22 02:05:06 DEBUG : four: md5 = 2e503db7862ff34f29024ab34efcdb58 OK
2025/01/22 02:05:06 INFO  : four: Copied (replaced existing)
2025/01/22 02:05:06 DEBUG : five: md5 = 55c964e7cb1e58376cb6193ff5db70b2 OK
2025/01/22 02:05:06 INFO  : five: Copied (new)
2025/01/22 02:05:06 DEBUG : Waiting for deletions to finish
    sync_test.go:1449: Skip test with --checksum as no hashes supported
--- PASS: TestSyncWithUpdateOlder (13.28s)
=== 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-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    sync_test.go:1538: Can track renames: false
2025/01/22 02:05:10 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Ignoring --track-renames as the source and destination do not have a common hash
2025/01/22 02:05:11 DEBUG : potato: Need to transfer - File not found at Destination
2025/01/22 02:05:11 DEBUG : yam: Need to transfer - File not found at Destination
2025/01/22 02:05:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:05:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:05:12 DEBUG : yam: md5 = 011692995d4a9c229994920452e50047 OK
2025/01/22 02:05:12 INFO  : yam: Copied (new)
2025/01/22 02:05:12 DEBUG : potato: md5 = 999ff0f9cb95cce578104277f11affc7 OK
2025/01/22 02:05:12 INFO  : potato: Copied (new)
2025/01/22 02:05:12 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:05:13 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Ignoring --track-renames as the source and destination do not have a common hash
2025/01/22 02:05:13 DEBUG : yaml: Need to transfer - File not found at Destination
2025/01/22 02:05:13 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:05:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:05:13 DEBUG : potato: Unchanged skipping
2025/01/22 02:05:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:05:15 DEBUG : yaml: md5 = afae81afb6645400ff576c85c84db7e2 OK
2025/01/22 02:05:15 INFO  : yaml: Copied (new)
2025/01/22 02:05:15 DEBUG : Waiting for deletions to finish
2025/01/22 02:05:15 INFO  : yam: Deleted
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenames (7.67s)
=== RUN   TestParseRenamesStrategyModtime
--- PASS: TestParseRenamesStrategyModtime (0.00s)
=== RUN   TestRenamesStrategyModtime
--- PASS: TestRenamesStrategyModtime (0.00s)
=== RUN   TestSyncWithTrackRenamesStrategyModtime
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    sync_test.go:1610: Can track renames: true
2025/01/22 02:05:18 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Making map for --track-renames
2025/01/22 02:05:18 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Finished making map for --track-renames
2025/01/22 02:05:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:05:18 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/01/22 02:05:18 DEBUG : yam: Need to transfer - No matching file found at Destination
2025/01/22 02:05:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for renames to finish
2025/01/22 02:05:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:05:20 DEBUG : potato: md5 = 188ae55bd6bb1c9869e9a4d61c27c4da OK
2025/01/22 02:05:20 INFO  : potato: Copied (new)
2025/01/22 02:05:20 DEBUG : yam: md5 = 42beb70d4b455352c0595f4e29720fb9 OK
2025/01/22 02:05:20 INFO  : yam: Copied (new)
2025/01/22 02:05:20 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:05:21 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:05:21 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Making map for --track-renames
2025/01/22 02:05:21 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Finished making map for --track-renames
2025/01/22 02:05:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:05:21 DEBUG : potato: Unchanged skipping
2025/01/22 02:05:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for renames to finish
2025/01/22 02:05:22 INFO  : yam: Moved (server-side) to: yaml
2025/01/22 02:05:22 INFO  : yaml: Renamed from "yam"
2025/01/22 02:05:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:05:22 DEBUG : Waiting for deletions to finish
2025/01/22 02:05:22 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyModtime (6.43s)
=== RUN   TestSyncWithTrackRenamesStrategyLeaf
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    sync_test.go:1649: Can track renames: true
2025/01/22 02:05:25 DEBUG : Added delayed dir = "sub", newDst=<nil>
2025/01/22 02:05:25 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Making map for --track-renames
2025/01/22 02:05:25 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Finished making map for --track-renames
2025/01/22 02:05:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:05:25 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/01/22 02:05:25 DEBUG : sub/yam: Need to transfer - No matching file found at Destination
2025/01/22 02:05:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for renames to finish
2025/01/22 02:05:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:05:27 DEBUG : sub/yam: md5 = f9e3cb4333d3f9f9cec160f7d8d2bb61 OK
2025/01/22 02:05:27 INFO  : sub/yam: Copied (new)
2025/01/22 02:05:28 DEBUG : potato: md5 = 295c04fe91b5463e8eb3f56bc8ddac8a OK
2025/01/22 02:05:28 INFO  : potato: Copied (new)
2025/01/22 02:05:28 DEBUG : Waiting for deletions to finish
2025/01/22 02:05:28 INFO  : sub: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:05:29 DEBUG : Added delayed dir = "sub", newDst=sub
2025/01/22 02:05:29 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:05:29 DEBUG : potato: Unchanged skipping
2025/01/22 02:05:29 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Making map for --track-renames
2025/01/22 02:05:29 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Finished making map for --track-renames
2025/01/22 02:05:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:05:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for renames to finish
2025/01/22 02:05:31 INFO  : sub/yam: Moved (server-side) to: yam
2025/01/22 02:05:31 INFO  : yam: Renamed from "sub/yam"
2025/01/22 02:05:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:05:31 DEBUG : Waiting for deletions to finish
2025/01/22 02:05:31 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncWithTrackRenamesStrategyLeaf (10.41s)
=== RUN   TestServerSideMoveLocal
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:05:35 DEBUG : Creating backend with remote "/tmp/rclone1262997294/dir1"
2025/01/22 02:05:35 DEBUG : Config file has changed externally - reloading
2025/01/22 02:05:35 DEBUG : Creating backend with remote "/tmp/rclone1262997294/dir2"
2025/01/22 02:05:35 DEBUG : Local file system at /tmp/rclone1262997294/dir2: Using server-side directory move
2025/01/22 02:05:35 INFO  : Local file system at /tmp/rclone1262997294/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/01/22 02:05:35 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/01/22 02:05:35 INFO  : file1.txt: Moved (server-side)
2025/01/22 02:05:35 DEBUG : Local file system at /tmp/rclone1262997294/dir2: Waiting for checks to finish
2025/01/22 02:05:35 DEBUG : Local file system at /tmp/rclone1262997294/dir2: Waiting for transfers to finish
--- PASS: TestServerSideMoveLocal (0.47s)
=== RUN   TestMoveWithDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:05:36 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/01/22 02:05:36 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/22 02:05:36 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/22 02:05:36 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/01/22 02:05:36 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/01/22 02:05:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:05:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:05:38 DEBUG : sub dir/hello world: md5 = 5b7bf33ac3beb581748da9de7017d85c OK
2025/01/22 02:05:38 INFO  : sub dir/hello world: Copied (new)
2025/01/22 02:05:38 INFO  : sub dir/hello world: Deleted
2025/01/22 02:05:41 DEBUG : nested/sub dir/file: md5 = 7ed04eb3a6a4f226384d95e5b0edd3d0 OK
2025/01/22 02:05:41 INFO  : nested/sub dir/file: Copied (new)
2025/01/22 02:05:41 INFO  : nested/sub dir/file: Deleted
2025/01/22 02:05:41 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/01/22 02:05:42 INFO  : nested: Set directory modification time (using DirSetModTime)
2025/01/22 02:05:42 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/22 02:05:42 INFO  : sub dir: Removing directory
2025/01/22 02:05:42 INFO  : nested/sub dir: Removing directory
2025/01/22 02:05:42 INFO  : nested: Removing directory
2025/01/22 02:05:42 DEBUG : Local file system at /tmp/rclone1262997294: deleted 3 directories
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:05:45 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/22 02:05:46 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2025/01/22 02:05:47 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithDeleteEmptySrcDirs (12.96s)
=== RUN   TestMoveWithoutDeleteEmptySrcDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:05:49 DEBUG : Added delayed dir = "nested", newDst=<nil>
2025/01/22 02:05:49 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2025/01/22 02:05:49 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2025/01/22 02:05:49 DEBUG : Added delayed dir = "nested/sub dir", newDst=<nil>
2025/01/22 02:05:49 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination
2025/01/22 02:05:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:05:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:05:52 DEBUG : sub dir/hello world: md5 = 28b27daa52399544bffb8ce02e69a15a OK
2025/01/22 02:05:52 INFO  : sub dir/hello world: Copied (new)
2025/01/22 02:05:52 INFO  : sub dir/hello world: Deleted
2025/01/22 02:05:54 DEBUG : nested/sub dir/file: md5 = 1054bebc53d0b9cc2593bf048d14b994 OK
2025/01/22 02:05:54 INFO  : nested/sub dir/file: Copied (new)
2025/01/22 02:05:54 INFO  : nested/sub dir/file: Deleted
2025/01/22 02:05:55 INFO  : nested/sub dir: Set directory modification time (using DirSetModTime)
2025/01/22 02:05:56 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/22 02:05:56 INFO  : nested: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:05:59 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/22 02:05:59 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk"
2025/01/22 02:06:00 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0"
--- PASS: TestMoveWithoutDeleteEmptySrcDirs (13.27s)
=== RUN   TestMoveWithIgnoreExisting
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:06:02 DEBUG : existing: Need to transfer - File not found at Destination
2025/01/22 02:06:02 DEBUG : existing-b: Need to transfer - File not found at Destination
2025/01/22 02:06:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:06:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:06:04 DEBUG : existing-b: md5 = 0fcc9b710ede1cede85cc8644dd74d53 OK
2025/01/22 02:06:04 INFO  : existing-b: Copied (new)
2025/01/22 02:06:04 INFO  : existing-b: Deleted
2025/01/22 02:06:04 DEBUG : existing: md5 = 70bf15bc8929bb0591df83ea038b38aa OK
2025/01/22 02:06:04 INFO  : existing: Copied (new)
2025/01/22 02:06:04 INFO  : existing: Deleted
2025/01/22 02:06:04 DEBUG : existing: Destination exists, skipping
2025/01/22 02:06:04 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set
2025/01/22 02:06:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:06:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:06:04 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestMoveWithIgnoreExisting (5.32s)
=== RUN   TestServerSideMove
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:06:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zoxosop2faxe"
2025/01/22 02:06:07 DEBUG : Creating backend with remote "TestDrive:crypt/epo42ti6k1dfs8hmo264o67d9atar7v7o2gmc9d132pne46qfrug"
2025/01/22 02:06:11 DEBUG : potato2: md5 = 2aa61613b614234e8e2717a48f4e9316 OK
2025/01/22 02:06:13 DEBUG : empty space: md5 = 46d2bae4c8a4cba9b3166f3ef22f490d OK
2025/01/22 02:06:14 DEBUG : potato3: md5 = c550c4598e834d3feb7d10cca18a93e9 OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume' -> Encrypted drive 'TestCryptDrive:rclone-test-zoxosop2faxe'
2025/01/22 02:06:17 DEBUG : empty space: md5 = fd555012a37a5cc7b882c3fb77821010 OK
2025/01/22 02:06:19 DEBUG : potato3: md5 = a644dfafe5183f93e3c32f267297ab59 OK
2025/01/22 02:06:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zoxosop2faxe': Using server-side directory move
2025/01/22 02:06:19 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-zoxosop2faxe': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/01/22 02:06:20 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/22 02:06:20 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/01/22 02:06:20 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/01/22 02:06:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zoxosop2faxe': Waiting for checks to finish
2025/01/22 02:06:20 DEBUG : empty space: Unchanged skipping
2025/01/22 02:06:20 INFO  : empty space: Deleted
2025/01/22 02:06:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zoxosop2faxe': Waiting for transfers to finish
2025/01/22 02:06:20 INFO  : potato3: Deleted
2025/01/22 02:06:21 INFO  : potato2: Moved (server-side)
2025/01/22 02:06:21 INFO  : potato3: Moved (server-side)
2025/01/22 02:06:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pipobul7mece"
2025/01/22 02:06:22 DEBUG : Creating backend with remote "TestDrive:crypt/1h56m4h11sfp2pomr4p7pd55udam1dvup8k1fpqvso2lfs546o00"
2025/01/22 02:06:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pipobul7mece': Using server-side directory move
2025/01/22 02:06:24 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-pipobul7mece': Server side directory move succeeded
2025/01/22 02:06:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pipobul7mece': Purge remote
2025/01/22 02:06:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zoxosop2faxe': Purge remote
2025/01/22 02:06:26 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMove (19.10s)
=== RUN   TestServerSideMoveWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:06:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yidozaj5vomo"
2025/01/22 02:06:26 DEBUG : Creating backend with remote "TestDrive:crypt/km90hck8eheeh2jgafscfdka8l0pq6v5mbloaqs9it81m59ltaj0"
2025/01/22 02:06:29 DEBUG : potato2: md5 = 959b25e64f6e8733416bf905071bbfe6 OK
2025/01/22 02:06:31 DEBUG : empty space: md5 = 31e3a6f0d504e2ea8ee3cf647f9c692d OK
2025/01/22 02:06:32 DEBUG : potato3: md5 = 4efd5e0549b5b21f0db91c0f3c50b6be OK
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume' -> Encrypted drive 'TestCryptDrive:rclone-test-yidozaj5vomo'
2025/01/22 02:06:36 DEBUG : empty space: md5 = 8e508d79f20df24f9d60a027e647204e OK
2025/01/22 02:06:38 DEBUG : potato3: md5 = 7830cb848f7c317d6ab3c9c2574fbf38 OK
2025/01/22 02:06:38 DEBUG : empty space: Excluded (Size Filter)
2025/01/22 02:06:38 DEBUG : empty space: Excluded
2025/01/22 02:06:38 DEBUG : empty space: Excluded (Size Filter)
2025/01/22 02:06:38 DEBUG : empty space: Excluded
2025/01/22 02:06:38 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/22 02:06:38 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/01/22 02:06:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yidozaj5vomo': Waiting for checks to finish
2025/01/22 02:06:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yidozaj5vomo': Waiting for transfers to finish
2025/01/22 02:06:39 INFO  : potato3: Deleted
2025/01/22 02:06:39 INFO  : potato2: Moved (server-side)
2025/01/22 02:06:40 INFO  : potato3: Moved (server-side)
2025/01/22 02:06:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-weraxol0qimo"
2025/01/22 02:06:41 DEBUG : Creating backend with remote "TestDrive:crypt/481j5su63keb3d6g9reu1go11pr7jp9l4qkv8p86pe4dojlbtcv0"
2025/01/22 02:06:42 DEBUG : empty space: Excluded (Size Filter)
2025/01/22 02:06:42 DEBUG : empty space: Excluded
2025/01/22 02:06:42 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/22 02:06:42 DEBUG : potato3: Need to transfer - File not found at Destination
2025/01/22 02:06:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-weraxol0qimo': Waiting for checks to finish
2025/01/22 02:06:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-weraxol0qimo': Waiting for transfers to finish
2025/01/22 02:06:44 INFO  : potato2: Moved (server-side)
2025/01/22 02:06:44 INFO  : potato3: Moved (server-side)
2025/01/22 02:06:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-weraxol0qimo': Purge remote
2025/01/22 02:06:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yidozaj5vomo': Purge remote
--- PASS: TestServerSideMoveWithFilter (21.02s)
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:06:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yoqenaz5caco"
2025/01/22 02:06:47 DEBUG : Creating backend with remote "TestDrive:crypt/7s45omvpf45knb22rsi2cme76alls7kftns0rddome247dsihou0"
2025/01/22 02:06:50 DEBUG : potato2: md5 = ffaf3ea85e97109162a68479017676e2 OK
2025/01/22 02:06:51 DEBUG : empty space: md5 = e143c6670dbd6787b139048b2245c1a0 OK
2025/01/22 02:06:53 DEBUG : potato3: md5 = b069304c35a73c7ead840cfc49616ac8 OK
2025/01/22 02:06:53 INFO  : tomatoDir: Making directory
    sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume' -> Encrypted drive 'TestCryptDrive:rclone-test-yoqenaz5caco'
2025/01/22 02:06:57 DEBUG : empty space: md5 = bd7b29984b926cc1f8828a483f694ea8 OK
2025/01/22 02:06:59 DEBUG : potato3: md5 = 41a0cbd32e6f1e33bfefdcecfab9b6a7 OK
2025/01/22 02:06:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yoqenaz5caco': Using server-side directory move
2025/01/22 02:06:59 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-yoqenaz5caco': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2025/01/22 02:07:00 DEBUG : potato2: Need to transfer - File not found at Destination
2025/01/22 02:07:00 DEBUG : Added delayed dir = "tomatoDir", newDst=<nil>
2025/01/22 02:07:00 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/01/22 02:07:00 DEBUG : empty space: Unchanged skipping
2025/01/22 02:07:00 DEBUG : potato3: Sizes differ (src 68 vs dst 60)
2025/01/22 02:07:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yoqenaz5caco': Waiting for checks to finish
2025/01/22 02:07:00 INFO  : potato3: Deleted
2025/01/22 02:07:00 INFO  : empty space: Deleted
2025/01/22 02:07:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yoqenaz5caco': Waiting for transfers to finish
2025/01/22 02:07:01 INFO  : potato2: Moved (server-side)
2025/01/22 02:07:01 INFO  : potato3: Moved (server-side)
2025/01/22 02:07:01 INFO  : tomatoDir: Removing directory
2025/01/22 02:07:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': deleted 1 directories
2025/01/22 02:07:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kadevut7kofe"
2025/01/22 02:07:03 DEBUG : Config file has changed externally - reloading
2025/01/22 02:07:03 DEBUG : Creating backend with remote "TestDrive:crypt/0u4h5p897o0evu4dseh78qau5p78e5b9de2fj3qsihrsh24t1lb0"
2025/01/22 02:07:04 INFO  : tomatoDir: Making directory
2025/01/22 02:07:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kadevut7kofe': Using server-side directory move
2025/01/22 02:07:06 INFO  : Encrypted drive 'TestCryptDrive:rclone-test-kadevut7kofe': Server side directory move succeeded
2025/01/22 02:07:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kadevut7kofe': Purge remote
2025/01/22 02:07:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yoqenaz5caco': Purge remote
2025/01/22 02:07:08 NOTICE: purge failed: directory not found
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (21.83s)
=== RUN   TestServerSideMoveOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    sync_test.go:1910: Skipping test as remote supports DirMove
--- SKIP: TestServerSideMoveOverlap (0.45s)
=== RUN   TestSyncOverlap
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:07:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/rclone-sync-test"
2025/01/22 02:07:09 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncOverlap (3.88s)
=== RUN   TestSyncOverlapWithFilter
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:07:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/rclone-sync-test"
2025/01/22 02:07:13 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0"
2025/01/22 02:07:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/rclone-sync-test-include/layer2"
2025/01/22 02:07:16 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4"
2025/01/22 02:07:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/rclone-sync-test-ignore-file"
2025/01/22 02:07:20 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg"
2025/01/22 02:07:24 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = fe70140839319f995eafabf42e444a44 OK
2025/01/22 02:07:25 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/01/22 02:07:26 DEBUG : rclone-sync-test: Excluded
2025/01/22 02:07:26 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/01/22 02:07:26 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/01/22 02:07:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/rclone-sync-test': Waiting for checks to finish
2025/01/22 02:07:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/rclone-sync-test': Waiting for transfers to finish
2025/01/22 02:07:26 DEBUG : Waiting for deletions to finish
2025/01/22 02:07:26 INFO  : There was nothing to transfer
2025/01/22 02:07:27 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/01/22 02:07:28 DEBUG : rclone-sync-test: Excluded
2025/01/22 02:07:28 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/01/22 02:07:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:07:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:07:28 DEBUG : Waiting for deletions to finish
2025/01/22 02:07:28 INFO  : rclone-sync-test-include: Removing directory
2025/01/22 02:07:28 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/01/22 02:07:28 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2025/01/22 02:07:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': failed to delete 1 directories
2025/01/22 02:07:28 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:07:29 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/01/22 02:07:30 DEBUG : rclone-sync-test: Excluded
2025/01/22 02:07:30 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/01/22 02:07:30 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/01/22 02:07:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/rclone-sync-test-include/layer2': Waiting for checks to finish
2025/01/22 02:07:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/rclone-sync-test-include/layer2': Waiting for transfers to finish
2025/01/22 02:07:30 DEBUG : Waiting for deletions to finish
2025/01/22 02:07:30 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:07:31 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/01/22 02:07:31 DEBUG : rclone-sync-test: Excluded
2025/01/22 02:07:32 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/01/22 02:07:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:07:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:07:32 DEBUG : Waiting for deletions to finish
2025/01/22 02:07:32 INFO  : rclone-sync-test-include: Removing directory
2025/01/22 02:07:32 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/01/22 02:07:32 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty
2025/01/22 02:07:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': failed to delete 1 directories
2025/01/22 02:07:32 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:07:33 DEBUG : : Excluded
2025/01/22 02:07:33 DEBUG : rclone-sync-test-ignore-file: Excluded
2025/01/22 02:07:33 DEBUG : rclone-sync-test: Excluded
2025/01/22 02:07:33 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst=<nil>
2025/01/22 02:07:34 DEBUG : rclone-sync-test-include/layer2: Excluded
2025/01/22 02:07:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/rclone-sync-test-ignore-file': Waiting for checks to finish
2025/01/22 02:07:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/rclone-sync-test-ignore-file': Waiting for transfers to finish
2025/01/22 02:07:34 DEBUG : Waiting for deletions to finish
2025/01/22 02:07:34 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:07:36 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4"
2025/01/22 02:07:37 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8"
--- PASS: TestSyncOverlapWithFilter (33.77s)
=== RUN   TestSyncCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:07:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/dst"
2025/01/22 02:07:47 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/22 02:07:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/CompareDest"
2025/01/22 02:07:49 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/gveqi14airsml4bgu7krj116o8"
2025/01/22 02:07:51 DEBUG : one: Need to transfer - File not found at Destination
2025/01/22 02:07:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for checks to finish
2025/01/22 02:07:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for transfers to finish
2025/01/22 02:07:53 DEBUG : one: md5 = 67da9d3413a2ac09c95bb3231fa152c4 OK
2025/01/22 02:07:53 INFO  : one: Copied (new)
2025/01/22 02:07:53 DEBUG : Waiting for deletions to finish
2025/01/22 02:07:55 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/22 02:07:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for checks to finish
2025/01/22 02:07:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for transfers to finish
2025/01/22 02:07:56 DEBUG : one: md5 = 132d9391831dd90a2e3b372242609cfa OK
2025/01/22 02:07:56 INFO  : one: Copied (replaced existing)
2025/01/22 02:07:56 DEBUG : Waiting for deletions to finish
2025/01/22 02:07:58 DEBUG : dst/one: md5 = d65d1bb4b9ffb5edfd9e52802c15fefd OK
2025/01/22 02:08:01 DEBUG : CompareDest/one: md5 = 94a9ab803e986e0af6d4986f67f59367 OK
2025/01/22 02:08:02 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/22 02:08:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for checks to finish
2025/01/22 02:08:02 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:08:02 DEBUG : one: Destination found in --compare-dest, skipping
2025/01/22 02:08:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for transfers to finish
2025/01/22 02:08:02 DEBUG : Waiting for deletions to finish
2025/01/22 02:08:02 INFO  : There was nothing to transfer
2025/01/22 02:08:05 DEBUG : CompareDest/two: md5 = f7a5504a1db1662ff41e71dde4531fc3 OK
2025/01/22 02:08:06 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:08:06 DEBUG : two: Destination found in --compare-dest, skipping
2025/01/22 02:08:06 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/22 02:08:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for checks to finish
2025/01/22 02:08:06 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:08:06 DEBUG : one: Destination found in --compare-dest, skipping
2025/01/22 02:08:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for transfers to finish
2025/01/22 02:08:06 DEBUG : Waiting for deletions to finish
2025/01/22 02:08:06 INFO  : There was nothing to transfer
2025/01/22 02:08:07 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:08:07 DEBUG : two: Destination found in --compare-dest, skipping
2025/01/22 02:08:07 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/22 02:08:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for checks to finish
2025/01/22 02:08:07 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:08:07 DEBUG : one: Destination found in --compare-dest, skipping
2025/01/22 02:08:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for transfers to finish
2025/01/22 02:08:07 DEBUG : Waiting for deletions to finish
2025/01/22 02:08:07 INFO  : There was nothing to transfer
    sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test
2025/01/22 02:08:09 DEBUG : two: Sizes differ (src 5 vs dst 3)
2025/01/22 02:08:09 DEBUG : two: Need to transfer - File not found at Destination
2025/01/22 02:08:09 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/22 02:08:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for checks to finish
2025/01/22 02:08:09 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:08:09 DEBUG : one: Destination found in --compare-dest, skipping
2025/01/22 02:08:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for transfers to finish
2025/01/22 02:08:10 DEBUG : two: md5 = e31266c2ea217f61fd56395465d03210 OK
2025/01/22 02:08:10 INFO  : two: Copied (new)
2025/01/22 02:08:10 DEBUG : Waiting for deletions to finish
2025/01/22 02:08:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/22 02:08:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/22 02:08:15 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/22 02:08:15 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncCompareDest (29.38s)
=== RUN   TestSyncMultipleCompareDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:08:19 DEBUG : pre-dest1/1: md5 = 95f0d566e0b8a21ec388c3fc3acfd32c OK
2025/01/22 02:08:22 DEBUG : pre-dest2/2: md5 = 7362008ed0f60b6c19e8a299f57a4d1e OK
2025/01/22 02:08:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/dest"
2025/01/22 02:08:23 DEBUG : Config file has changed externally - reloading
2025/01/22 02:08:23 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/rg03c1jvnehrrc617i0lnqjddc"
2025/01/22 02:08:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/pre-dest1"
2025/01/22 02:08:24 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/bbnblvh6k061ssopqrp18kd7gc"
2025/01/22 02:08:25 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/pre-dest2"
2025/01/22 02:08:25 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/dgicm1h6b5ejvlltm8eeif0bnk"
2025/01/22 02:08:26 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:08:26 DEBUG : 1: Destination found in --compare-dest, skipping
2025/01/22 02:08:27 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:08:27 DEBUG : 2: Destination found in --compare-dest, skipping
2025/01/22 02:08:27 DEBUG : 3: Need to transfer - File not found at Destination
2025/01/22 02:08:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dest': Waiting for checks to finish
2025/01/22 02:08:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dest': Waiting for transfers to finish
2025/01/22 02:08:30 DEBUG : 3: md5 = fbe9dc373fc68b5c4c8a2ffccd8568ac OK
2025/01/22 02:08:30 INFO  : 3: Copied (new)
2025/01/22 02:08:30 DEBUG : Waiting for deletions to finish
2025/01/22 02:08:34 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc"
2025/01/22 02:08:35 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro"
2025/01/22 02:08:35 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg"
--- PASS: TestSyncMultipleCompareDest (19.74s)
=== RUN   TestSyncCopyDest
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:08:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/dst"
2025/01/22 02:08:36 DEBUG : Config file has changed externally - reloading
2025/01/22 02:08:36 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/22 02:08:38 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/CopyDest"
2025/01/22 02:08:38 DEBUG : Config file has changed externally - reloading
2025/01/22 02:08:38 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/d09o6po3f7bm6ce32vdgs8h9ls"
2025/01/22 02:08:40 DEBUG : one: Need to transfer - File not found at Destination
2025/01/22 02:08:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for checks to finish
2025/01/22 02:08:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for transfers to finish
2025/01/22 02:08:43 DEBUG : one: md5 = 5dfade74bbd0f45784e156e5f67769a3 OK
2025/01/22 02:08:43 INFO  : one: Copied (new)
2025/01/22 02:08:43 DEBUG : Waiting for deletions to finish
2025/01/22 02:08:44 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/22 02:08:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for checks to finish
2025/01/22 02:08:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for transfers to finish
2025/01/22 02:08:46 DEBUG : one: md5 = f272dd554a860fb2168fe7bae01e0c13 OK
2025/01/22 02:08:46 INFO  : one: Copied (replaced existing)
2025/01/22 02:08:46 DEBUG : Waiting for deletions to finish
2025/01/22 02:08:48 DEBUG : dst/one: md5 = 2b269e071dfecbebae3f0596aa28ebbd OK
2025/01/22 02:08:50 DEBUG : CopyDest/one: md5 = f313328b9b84643cc480d2926f486e8b OK
2025/01/22 02:08:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/BackupDir"
2025/01/22 02:08:51 DEBUG : Config file has changed externally - reloading
2025/01/22 02:08:51 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/s6dbk3lfi7c9kfvo6j7bla9m0g"
2025/01/22 02:08:53 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/22 02:08:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for checks to finish
2025/01/22 02:08:53 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:08:53 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/01/22 02:08:56 INFO  : one: Moved (server-side)
2025/01/22 02:08:57 INFO  : one: Copied (server-side copy)
2025/01/22 02:08:57 DEBUG : one: Destination found in --copy-dest, using server-side copy
2025/01/22 02:08:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for transfers to finish
2025/01/22 02:08:57 DEBUG : Waiting for deletions to finish
2025/01/22 02:08:59 DEBUG : CopyDest/two: md5 = 01879030493ed31239029f8232f15e9b OK
2025/01/22 02:09:00 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:09:01 INFO  : two: Copied (server-side copy)
2025/01/22 02:09:01 DEBUG : two: Destination found in --copy-dest, using server-side copy
2025/01/22 02:09:01 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:09:01 DEBUG : one: Unchanged skipping
2025/01/22 02:09:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for checks to finish
2025/01/22 02:09:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for transfers to finish
2025/01/22 02:09:01 DEBUG : Waiting for deletions to finish
2025/01/22 02:09:02 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:09:02 DEBUG : one: Unchanged skipping
2025/01/22 02:09:02 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:09:02 DEBUG : two: Unchanged skipping
2025/01/22 02:09:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for checks to finish
2025/01/22 02:09:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for transfers to finish
2025/01/22 02:09:02 DEBUG : Waiting for deletions to finish
2025/01/22 02:09:02 INFO  : There was nothing to transfer
2025/01/22 02:09:05 DEBUG : CopyDest/three: md5 = a881880578b6c30a2cdeee90da254817 OK
2025/01/22 02:09:06 DEBUG : three: Sizes differ (src 7 vs dst 5)
2025/01/22 02:09:06 DEBUG : three: Destination not found in --copy-dest
2025/01/22 02:09:06 DEBUG : three: Need to transfer - File not found at Destination
2025/01/22 02:09:06 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:09:06 DEBUG : one: Unchanged skipping
2025/01/22 02:09:06 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2025/01/22 02:09:06 DEBUG : two: Unchanged skipping
2025/01/22 02:09:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for checks to finish
2025/01/22 02:09:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for transfers to finish
2025/01/22 02:09:07 DEBUG : three: md5 = 1a3ca3776e73dd03a03f99cc43e3c129 OK
2025/01/22 02:09:07 INFO  : three: Copied (new)
2025/01/22 02:09:07 DEBUG : Waiting for deletions to finish
2025/01/22 02:09:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2025/01/22 02:09:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/22 02:09:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/22 02:09:14 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/22 02:09:14 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os"
2025/01/22 02:09:14 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/22 02:09:15 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncCopyDest (39.26s)
=== RUN   TestSyncBackupDir
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:09:18 DEBUG : dst/one: md5 = c1c5b2c0c1bfeead7c2e01e4a2f34df7 OK
2025/01/22 02:09:20 DEBUG : dst/two: md5 = f844a012d6e1af55c70a10e3cd404b9e OK
2025/01/22 02:09:22 DEBUG : dst/three.txt: md5 = e72c3c8616b8d0a05a20294a17825a86 OK
2025/01/22 02:09:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/dst"
2025/01/22 02:09:22 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/22 02:09:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/backup"
2025/01/22 02:09:23 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/1nrff024r7pq65ecp72fc28jb0"
2025/01/22 02:09:25 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/22 02:09:25 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:09:25 DEBUG : two: Unchanged skipping
2025/01/22 02:09:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for checks to finish
2025/01/22 02:09:27 INFO  : one: Moved (server-side)
2025/01/22 02:09:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for transfers to finish
2025/01/22 02:09:29 DEBUG : one: md5 = 5280ec3b80b253bf7e820169a9928fea OK
2025/01/22 02:09:29 INFO  : one: Copied (new)
2025/01/22 02:09:29 DEBUG : Waiting for deletions to finish
2025/01/22 02:09:30 INFO  : three.txt: Moved (server-side)
2025/01/22 02:09:30 INFO  : three.txt: Moved into backup dir
2025/01/22 02:09:32 DEBUG : dst/three.txt: md5 = b44836672f87fc98d03a270337e5f1e7 OK
2025/01/22 02:09:33 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/22 02:09:33 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:09:33 DEBUG : two: Unchanged skipping
2025/01/22 02:09:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for checks to finish
2025/01/22 02:09:34 INFO  : one: Deleted
2025/01/22 02:09:35 INFO  : one: Moved (server-side)
2025/01/22 02:09:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for transfers to finish
2025/01/22 02:09:36 DEBUG : one: md5 = cfac13af0a0722772dd2fc38f9e93da2 OK
2025/01/22 02:09:36 INFO  : one: Copied (new)
2025/01/22 02:09:36 DEBUG : Waiting for deletions to finish
2025/01/22 02:09:37 INFO  : three.txt: Deleted
2025/01/22 02:09:38 INFO  : three.txt: Moved (server-side)
2025/01/22 02:09:38 INFO  : three.txt: Moved into backup dir
2025/01/22 02:09:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/22 02:09:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/22 02:09:43 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/22 02:09:43 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/01/22 02:09:43 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/01/22 02:09:43 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
--- PASS: TestSyncBackupDir (28.72s)
=== RUN   TestSyncBackupDirWithSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:09:47 DEBUG : dst/one: md5 = 8cf8a1f214fd377e59fdf2ee6869b367 OK
2025/01/22 02:09:49 DEBUG : dst/two: md5 = 406ab757e37e4ecccc1e7732b6071bb0 OK
2025/01/22 02:09:50 DEBUG : dst/three.txt: md5 = 315be3d15fda343f619baedad3cd27ba OK
2025/01/22 02:09:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/dst"
2025/01/22 02:09:51 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/22 02:09:52 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/backup"
2025/01/22 02:09:52 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/1nrff024r7pq65ecp72fc28jb0"
2025/01/22 02:09:53 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/22 02:09:53 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:09:53 DEBUG : two: Unchanged skipping
2025/01/22 02:09:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for checks to finish
2025/01/22 02:09:56 INFO  : one: Moved (server-side) to: one.bak
2025/01/22 02:09:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for transfers to finish
2025/01/22 02:09:58 DEBUG : one: md5 = f93f2ead41a5c4641aa956fc2187291c OK
2025/01/22 02:09:58 INFO  : one: Copied (new)
2025/01/22 02:09:58 DEBUG : Waiting for deletions to finish
2025/01/22 02:09:59 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/22 02:09:59 INFO  : three.txt: Moved into backup dir
2025/01/22 02:10:01 DEBUG : dst/three.txt: md5 = c95ac13d082c6730ca5b0dcf96ef790e OK
2025/01/22 02:10:02 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/22 02:10:02 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:10:02 DEBUG : two: Unchanged skipping
2025/01/22 02:10:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for checks to finish
2025/01/22 02:10:03 INFO  : one.bak: Deleted
2025/01/22 02:10:04 INFO  : one: Moved (server-side) to: one.bak
2025/01/22 02:10:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for transfers to finish
2025/01/22 02:10:06 DEBUG : one: md5 = c8c1ad6146a1af9afe69398008b33478 OK
2025/01/22 02:10:06 INFO  : one: Copied (new)
2025/01/22 02:10:06 DEBUG : Waiting for deletions to finish
2025/01/22 02:10:07 INFO  : three.txt.bak: Deleted
2025/01/22 02:10:08 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/22 02:10:08 INFO  : three.txt: Moved into backup dir
2025/01/22 02:10:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/22 02:10:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/22 02:10:13 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/22 02:10:13 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/22 02:10:13 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/22 02:10:13 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
--- PASS: TestSyncBackupDirWithSuffix (29.29s)
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:10:16 DEBUG : dst/one: md5 = 8f5c9e31e5c954a9bc355e14f699a83f OK
2025/01/22 02:10:18 DEBUG : dst/two: md5 = ecf53ea128bce06d82de1548d8f9f0c0 OK
2025/01/22 02:10:20 DEBUG : dst/three.txt: md5 = d0d0be5eb723964b1246916c1d5305c3 OK
2025/01/22 02:10:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/dst"
2025/01/22 02:10:20 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/22 02:10:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/backup"
2025/01/22 02:10:21 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/1nrff024r7pq65ecp72fc28jb0"
2025/01/22 02:10:23 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/22 02:10:23 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:10:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for checks to finish
2025/01/22 02:10:23 DEBUG : two: Unchanged skipping
2025/01/22 02:10:25 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/01/22 02:10:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for transfers to finish
2025/01/22 02:10:27 DEBUG : one: md5 = d04a63e393c7e2c235715c2de50e61c8 OK
2025/01/22 02:10:27 INFO  : one: Copied (new)
2025/01/22 02:10:27 DEBUG : Waiting for deletions to finish
2025/01/22 02:10:28 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/01/22 02:10:28 INFO  : three.txt: Moved into backup dir
2025/01/22 02:10:30 DEBUG : dst/three.txt: md5 = 1af38dd138a83a25fad6f70b6aa6dd10 OK
2025/01/22 02:10:31 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/22 02:10:31 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:10:31 DEBUG : two: Unchanged skipping
2025/01/22 02:10:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for checks to finish
2025/01/22 02:10:32 INFO  : one-2019-01-01: Deleted
2025/01/22 02:10:33 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/01/22 02:10:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for transfers to finish
2025/01/22 02:10:35 DEBUG : one: md5 = dcd8efcb786251ef64e2d591bcc1f2fa OK
2025/01/22 02:10:35 INFO  : one: Copied (new)
2025/01/22 02:10:35 DEBUG : Waiting for deletions to finish
2025/01/22 02:10:36 INFO  : three-2019-01-01.txt: Deleted
2025/01/22 02:10:37 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/01/22 02:10:37 INFO  : three.txt: Moved into backup dir
2025/01/22 02:10:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/22 02:10:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/22 02:10:42 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/01/22 02:10:42 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/01/22 02:10:42 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/01/22 02:10:42 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (28.84s)
=== RUN   TestSyncBackupDirSuffixOnly
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:10:46 DEBUG : dst/one: md5 = de0fab5059873bbabebfffe00fc36bd7 OK
2025/01/22 02:10:48 DEBUG : dst/two: md5 = aef68d035c66dd452deef915f3154074 OK
2025/01/22 02:10:49 DEBUG : dst/three.txt: md5 = 25d3de50ce286b5d6402d68de6aab8a8 OK
2025/01/22 02:10:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/dst"
2025/01/22 02:10:50 DEBUG : Config file has changed externally - reloading
2025/01/22 02:10:50 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/22 02:10:51 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/22 02:10:51 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:10:51 DEBUG : two: Unchanged skipping
2025/01/22 02:10:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for checks to finish
2025/01/22 02:10:52 INFO  : one: Moved (server-side) to: one.bak
2025/01/22 02:10:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for transfers to finish
2025/01/22 02:10:53 DEBUG : one: md5 = 89a830851d7c2c4fd3090c2747df5172 OK
2025/01/22 02:10:53 INFO  : one: Copied (new)
2025/01/22 02:10:53 DEBUG : Waiting for deletions to finish
2025/01/22 02:10:54 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/22 02:10:54 INFO  : three.txt: Moved into backup dir
2025/01/22 02:10:56 DEBUG : dst/three.txt: md5 = 51d8933de991df0887b13e323edf7c71 OK
2025/01/22 02:10:57 DEBUG : one.bak: Excluded (Path Filter)
2025/01/22 02:10:57 DEBUG : one.bak: Excluded
2025/01/22 02:10:57 DEBUG : three.txt.bak: Excluded (Path Filter)
2025/01/22 02:10:57 DEBUG : three.txt.bak: Excluded
2025/01/22 02:10:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for checks to finish
2025/01/22 02:10:57 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/22 02:10:57 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:10:57 DEBUG : two: Unchanged skipping
2025/01/22 02:10:58 INFO  : one.bak: Deleted
2025/01/22 02:10:59 INFO  : one: Moved (server-side) to: one.bak
2025/01/22 02:10:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume/dst': Waiting for transfers to finish
2025/01/22 02:11:00 DEBUG : one: md5 = bd26560ff978ade10db997cc88008994 OK
2025/01/22 02:11:00 INFO  : one: Copied (new)
2025/01/22 02:11:00 DEBUG : Waiting for deletions to finish
2025/01/22 02:11:01 INFO  : three.txt.bak: Deleted
2025/01/22 02:11:02 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/22 02:11:02 INFO  : three.txt: Moved into backup dir
2025/01/22 02:11:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/22 02:11:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/22 02:11:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/22 02:11:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/22 02:11:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/22 02:11:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
--- PASS: TestSyncBackupDirSuffixOnly (24.10s)
=== RUN   TestSyncSuffix
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:11:09 DEBUG : dst/one: md5 = cf9c0294e6695775a9d0b16ae9b99771 OK
2025/01/22 02:11:11 DEBUG : dst/two: md5 = 490739b75c619ca373f47e0ef9d520f0 OK
2025/01/22 02:11:13 DEBUG : dst/three.txt: md5 = aa99a13f8794ddcfdcc834ed9bd80e2c OK
2025/01/22 02:11:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/dst"
2025/01/22 02:11:14 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/22 02:11:15 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/22 02:11:15 INFO  : one: Moved (server-side) to: one.bak
2025/01/22 02:11:17 DEBUG : one: md5 = df2fc34e516ff120b8ca1aadccf4bcfe OK
2025/01/22 02:11:17 INFO  : one: Copied (new)
2025/01/22 02:11:17 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:11:17 DEBUG : two: Unchanged skipping
2025/01/22 02:11:18 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/01/22 02:11:19 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/22 02:11:20 DEBUG : three.txt: md5 = 3cb3c7acf3986fe4c33ccfdc3c1825f8 OK
2025/01/22 02:11:20 INFO  : three.txt: Copied (new)
2025/01/22 02:11:22 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/22 02:11:23 INFO  : one.bak: Deleted
2025/01/22 02:11:23 INFO  : one: Moved (server-side) to: one.bak
2025/01/22 02:11:25 DEBUG : one: md5 = 4f5e7ef09fae9e02ed503d03e95c66ff OK
2025/01/22 02:11:25 INFO  : one: Copied (new)
2025/01/22 02:11:25 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:11:25 DEBUG : two: Unchanged skipping
2025/01/22 02:11:26 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/01/22 02:11:26 INFO  : three.txt.bak: Deleted
2025/01/22 02:11:27 INFO  : three.txt: Moved (server-side) to: three.txt.bak
2025/01/22 02:11:29 DEBUG : three.txt: md5 = 2634422e8fb7e8784974f470326bf5d3 OK
2025/01/22 02:11:29 INFO  : three.txt: Copied (new)
2025/01/22 02:11:33 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/01/22 02:11:33 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/22 02:11:33 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/22 02:11:33 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/22 02:11:33 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c"
2025/01/22 02:11:33 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8"
2025/01/22 02:11:33 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
--- PASS: TestSyncSuffix (27.75s)
=== RUN   TestSyncSuffixKeepExtension
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:11:37 DEBUG : dst/one: md5 = a4716b36c5033bec75f4b0b704255da2 OK
2025/01/22 02:11:39 DEBUG : dst/two: md5 = 9ea45a6615559db95f7ed6eea0b72016 OK
2025/01/22 02:11:41 DEBUG : dst/three.txt: md5 = b72b750fdb08a74c453d764df7d19ebb OK
2025/01/22 02:11:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gikuguz6wume/dst"
2025/01/22 02:11:41 DEBUG : Creating backend with remote "TestDrive:crypt/10ckp2iq0noe77ejshel1v9n70n7l2cp2622h3nhh16g47hsmd00/31u3jie661vd5p8j7rtc3hgbh0"
2025/01/22 02:11:42 DEBUG : one: Sizes differ (src 4 vs dst 3)
2025/01/22 02:11:43 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/01/22 02:11:45 DEBUG : one: md5 = caa9b6f809b945d6bafe2b5c0f945984 OK
2025/01/22 02:11:45 INFO  : one: Copied (new)
2025/01/22 02:11:45 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:11:45 DEBUG : two: Unchanged skipping
2025/01/22 02:11:46 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2025/01/22 02:11:46 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/01/22 02:11:48 DEBUG : three.txt: md5 = 6029879cdaed67d21e7fd2c36e5c2a97 OK
2025/01/22 02:11:48 INFO  : three.txt: Copied (new)
2025/01/22 02:11:49 DEBUG : one: Sizes differ (src 5 vs dst 4)
2025/01/22 02:11:50 INFO  : one-2019-01-01: Deleted
2025/01/22 02:11:51 INFO  : one: Moved (server-side) to: one-2019-01-01
2025/01/22 02:11:52 DEBUG : one: md5 = 0ca51fed81bab543b6af2b1352f2ef25 OK
2025/01/22 02:11:52 INFO  : one: Copied (new)
2025/01/22 02:11:53 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:11:53 DEBUG : two: Unchanged skipping
2025/01/22 02:11:53 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2025/01/22 02:11:54 INFO  : three-2019-01-01.txt: Deleted
2025/01/22 02:11:54 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2025/01/22 02:11:56 DEBUG : three.txt: md5 = 63dea27baa9c2f7211a4191b2eeef338 OK
2025/01/22 02:11:56 INFO  : three.txt: Copied (new)
2025/01/22 02:12:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc"
2025/01/22 02:12:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc"
2025/01/22 02:12:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/01/22 02:12:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
2025/01/22 02:12:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90"
2025/01/22 02:12:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k"
2025/01/22 02:12:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50"
--- PASS: TestSyncSuffixKeepExtension (27.00s)
=== RUN   TestSyncUTFNorm
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:12:03 DEBUG : Testêé: md5 = 8c5914999c7e53874d03ce127360bf1a OK
2025/01/22 02:12:03 DEBUG : Testêé: Sizes differ (src 14 vs dst 18)
2025/01/22 02:12:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:12:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:12:05 DEBUG : Testêé: md5 = fe2b3100dd4f922202654f5c4286060f OK
2025/01/22 02:12:05 INFO  : Testêé: Copied (replaced existing) to: Testêé
2025/01/22 02:12:05 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncUTFNorm (5.01s)
=== RUN   TestSyncImmutable
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:12:07 DEBUG : existing: Need to transfer - File not found at Destination
2025/01/22 02:12:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:12:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:12:08 DEBUG : existing: md5 = 63226c937d81b5b130a7b606e0408c79 OK
2025/01/22 02:12:08 INFO  : existing: Copied (new)
2025/01/22 02:12:08 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:12:09 DEBUG : existing: Sizes differ (src 8 vs dst 6)
2025/01/22 02:12:09 ERROR : existing: Source and destination exist but do not match: immutable file modified
2025/01/22 02:12:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:12:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:12:09 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': not deleting files as there were IO errors
2025/01/22 02:12:09 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': not deleting directories as there were IO errors
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncImmutable (5.23s)
=== RUN   TestSyncIgnoreCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:12:13 DEBUG : EXISTING: md5 = dc65541fbf081e05dbfb45e8cc8c3e82 OK
2025/01/22 02:12:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:12:13 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:12:13 DEBUG : existing: Unchanged skipping
2025/01/22 02:12:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:12:13 DEBUG : Waiting for deletions to finish
2025/01/22 02:12:13 INFO  : There was nothing to transfer
--- PASS: TestSyncIgnoreCase (3.45s)
=== RUN   TestFixCase
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    sync_test.go:2635: Skipping test as local or remote are case-sensitive
--- SKIP: TestFixCase (0.45s)
=== RUN   TestMaxTransfer
=== RUN   TestMaxTransfer/Hard
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", 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-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", 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-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    sync_test.go:2674: This test only runs on local
--- PASS: TestMaxTransfer (1.47s)
    --- SKIP: TestMaxTransfer/Hard (0.54s)
    --- SKIP: TestMaxTransfer/Soft (0.47s)
    --- SKIP: TestMaxTransfer/Cautious (0.46s)
=== RUN   TestSyncConcurrentDelete
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:12:19 DEBUG : both0: md5 = 2c5c1dda1fd6bba0875706e2d3dae0a7 OK
2025/01/22 02:12:21 DEBUG : only0: md5 = c79d75b15f061eea3397a915835e5eab OK
2025/01/22 02:12:22 DEBUG : both1: md5 = cebff0f067b17bb2a6d6f4142228b457 OK
2025/01/22 02:12:24 DEBUG : only1: md5 = 7ca905b53ab523f15758d46612e9fabc OK
2025/01/22 02:12:26 DEBUG : both2: md5 = ea3c793436d2c008cc85f31f2514e59a OK
2025/01/22 02:12:27 DEBUG : only2: md5 = 07dc999c01b8bd7e322f19dad15da0ef OK
2025/01/22 02:12:29 DEBUG : both3: md5 = 49a5799571678fd4137508b598ecb033 OK
2025/01/22 02:12:31 DEBUG : only3: md5 = 633cb9589d8d79f26bad2c119020d136 OK
2025/01/22 02:12:33 DEBUG : both4: md5 = deee34123707a3c5fa59bdc3293b54aa OK
2025/01/22 02:12:34 DEBUG : only4: md5 = 1dbd5ab56dc742ba2180c0d021715b3d OK
2025/01/22 02:12:36 DEBUG : both5: md5 = 9652190ce2188cda947a1e71f9d5efd4 OK
2025/01/22 02:12:38 DEBUG : only5: md5 = 936d943893212d7a089729f23c84121c OK
2025/01/22 02:12:39 DEBUG : both6: md5 = ec70345ff5b53b373af89d162604b522 OK
2025/01/22 02:12:41 DEBUG : only6: md5 = 02e5d7fb45f19079c4208eaa1bb64596 OK
2025/01/22 02:12:43 DEBUG : both7: md5 = 17947c736d82073bfa84fef389060583 OK
2025/01/22 02:12:44 DEBUG : only7: md5 = 509a3f0315281d631190ddfb0a75bd49 OK
2025/01/22 02:12:46 DEBUG : both8: md5 = dfb48aeb30b9107daab461a011a65ffb OK
2025/01/22 02:12:48 DEBUG : only8: md5 = a9cc12b03e3b5b4d5d9ab5063feded96 OK
2025/01/22 02:12:49 DEBUG : both9: md5 = 9fc7453e0362a04160df09b1f3f42d94 OK
2025/01/22 02:12:51 DEBUG : only9: md5 = a0ff94ac051532f03dfd48443b5144b9 OK
2025/01/22 02:12:53 DEBUG : both10: md5 = f1845133288af610843f0aede3123487 OK
2025/01/22 02:12:55 DEBUG : only10: md5 = 4cfa9bdd840d98e6146f469ffa4bba02 OK
2025/01/22 02:12:57 DEBUG : both11: md5 = 853cf84d2245c62802e34aec85df4d90 OK
2025/01/22 02:12:58 DEBUG : only11: md5 = 519422cdd5e0b5bda78a57efb4912f01 OK
2025/01/22 02:13:00 DEBUG : both12: md5 = 5d2f20ff04280a97a1819945dad8ddb3 OK
2025/01/22 02:13:02 DEBUG : only12: md5 = f158e66dde3055c4fb93e9e3b1675ffc OK
2025/01/22 02:13:04 DEBUG : both13: md5 = fc9a66b38027011c3499210363a53673 OK
2025/01/22 02:13:05 DEBUG : only13: md5 = 900f2fea4d7d995f0f96e11808a8e656 OK
2025/01/22 02:13:07 DEBUG : both14: md5 = e210356dcc142a1df66b34f658004153 OK
2025/01/22 02:13:09 DEBUG : only14: md5 = 9f7981238347732810ae1f42ca331e44 OK
2025/01/22 02:13:10 DEBUG : both15: md5 = ac0f6f398f61ff2705841c08570bb2bf OK
2025/01/22 02:13:12 DEBUG : only15: md5 = e86b7e0977204d9bb7b9b38745c178dc OK
2025/01/22 02:13:14 DEBUG : both16: md5 = e3b8e4a66fa9e5bee636ab11c326f475 OK
2025/01/22 02:13:15 DEBUG : only16: md5 = f06bf7971b76b7123a067cd5ff061a39 OK
2025/01/22 02:13:17 DEBUG : both17: md5 = 9490e80a6bf271126cf02f3d09e91c30 OK
2025/01/22 02:13:20 DEBUG : only17: md5 = 807fce5c10bbf7cdd084cd5a22a19d5e OK
2025/01/22 02:13:22 DEBUG : both18: md5 = 0e1b245620636658e09f0d9172a38e36 OK
2025/01/22 02:13:24 DEBUG : only18: md5 = 2ad241fc4471675c2c90369e461bbfe0 OK
2025/01/22 02:13:26 DEBUG : both19: md5 = 5ef3f0d4b2092fda0fdd4f897aaa9f1f OK
2025/01/22 02:13:28 DEBUG : only19: md5 = 31fdfaecd78a4daff1537e0776099ad2 OK
2025/01/22 02:13:28 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:13:28 DEBUG : both0: Unchanged skipping
2025/01/22 02:13:28 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:13:28 DEBUG : both1: Unchanged skipping
2025/01/22 02:13:28 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:13:28 DEBUG : both10: Unchanged skipping
2025/01/22 02:13:28 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:13:28 DEBUG : both11: Unchanged skipping
2025/01/22 02:13:28 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:13:28 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:13:28 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:13:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:13:28 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:13:28 DEBUG : both12: Unchanged skipping
2025/01/22 02:13:28 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:13:28 DEBUG : both13: Unchanged skipping
2025/01/22 02:13:28 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:13:28 DEBUG : both17: Unchanged skipping
2025/01/22 02:13:28 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:13:28 DEBUG : both18: Unchanged skipping
2025/01/22 02:13:28 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:13:28 DEBUG : both19: Unchanged skipping
2025/01/22 02:13:28 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:13:28 DEBUG : both2: Unchanged skipping
2025/01/22 02:13:28 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:13:28 DEBUG : both3: Unchanged skipping
2025/01/22 02:13:28 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:13:28 DEBUG : both4: Unchanged skipping
2025/01/22 02:13:28 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:13:28 DEBUG : both5: Unchanged skipping
2025/01/22 02:13:28 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:13:28 DEBUG : both6: Unchanged skipping
2025/01/22 02:13:28 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:13:28 DEBUG : both7: Unchanged skipping
2025/01/22 02:13:28 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:13:28 DEBUG : both8: Unchanged skipping
2025/01/22 02:13:28 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:13:28 DEBUG : both9: Unchanged skipping
2025/01/22 02:13:28 DEBUG : both15: Unchanged skipping
2025/01/22 02:13:28 DEBUG : both14: Unchanged skipping
2025/01/22 02:13:28 DEBUG : both16: Unchanged skipping
2025/01/22 02:13:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:13:28 DEBUG : Waiting for deletions to finish
2025/01/22 02:13:29 INFO  : only15: Deleted
2025/01/22 02:13:29 INFO  : only0: Deleted
2025/01/22 02:13:29 INFO  : only18: Deleted
2025/01/22 02:13:29 INFO  : only19: Deleted
2025/01/22 02:13:29 INFO  : only7: Deleted
2025/01/22 02:13:29 INFO  : only16: Deleted
2025/01/22 02:13:29 INFO  : only14: Deleted
2025/01/22 02:13:30 INFO  : only3: Deleted
2025/01/22 02:13:30 INFO  : only11: Deleted
2025/01/22 02:13:30 INFO  : only5: Deleted
2025/01/22 02:13:30 INFO  : only10: Deleted
2025/01/22 02:13:30 INFO  : only12: Deleted
2025/01/22 02:13:31 INFO  : only2: Deleted
2025/01/22 02:13:31 INFO  : only17: Deleted
2025/01/22 02:13:31 INFO  : only13: Deleted
2025/01/22 02:13:31 INFO  : only4: Deleted
2025/01/22 02:13:31 INFO  : only9: Deleted
2025/01/22 02:13:31 INFO  : only1: Deleted
2025/01/22 02:13:31 INFO  : only6: Deleted
2025/01/22 02:13:31 INFO  : only8: Deleted
2025/01/22 02:13:31 INFO  : There was nothing to transfer
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncConcurrentDelete (87.42s)
=== RUN   TestSyncConcurrentTruncate
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:13:46 DEBUG : both0: md5 = 21095678e8529504e9dcdd86a6a493ed OK
2025/01/22 02:13:48 DEBUG : only0: md5 = 5c2c12928b60b90fa3e48f82e894f4bb OK
2025/01/22 02:13:49 DEBUG : both1: md5 = f22451a463cc177eb93671bd23894dd2 OK
2025/01/22 02:13:51 DEBUG : only1: md5 = 100650ca1b04daf71536aa0949a770a1 OK
2025/01/22 02:13:53 DEBUG : both2: md5 = 359e6ab711370f351a6899ae14437024 OK
2025/01/22 02:13:54 DEBUG : only2: md5 = d6e83d4817ddb8d33c6e6fc3f9fcfa8f OK
2025/01/22 02:13:56 DEBUG : both3: md5 = aea9c43c0e5925248f35ad37e5788524 OK
2025/01/22 02:13:58 DEBUG : only3: md5 = 00ad931384b595c991087ee3e93e9952 OK
2025/01/22 02:14:00 DEBUG : both4: md5 = 572f06d739c55fec44559cad6ece1221 OK
2025/01/22 02:14:01 DEBUG : only4: md5 = 40d7c5dbda6d2cbc2db6590417911432 OK
2025/01/22 02:14:03 DEBUG : both5: md5 = 050414fa06b118911ba4abc29e668d06 OK
2025/01/22 02:14:04 DEBUG : only5: md5 = c60bd9de295e03715d2164249916131b OK
2025/01/22 02:14:06 DEBUG : both6: md5 = cde35691e279ea829ab1ce7e7fba10af OK
2025/01/22 02:14:08 DEBUG : only6: md5 = 325a2d4e674ebf4cd91a1d1ad0e63907 OK
2025/01/22 02:14:09 DEBUG : both7: md5 = 409ca933671f817abdb2ccc30aaf355e OK
2025/01/22 02:14:11 DEBUG : only7: md5 = 9b49ffb501e5fa394581f8ba48c1743e OK
2025/01/22 02:14:13 DEBUG : both8: md5 = ee7a659fa57ade0486b8b0bb538e88c4 OK
2025/01/22 02:14:15 DEBUG : only8: md5 = c0a25484136aa555ee5a7d761ceeab39 OK
2025/01/22 02:14:16 DEBUG : both9: md5 = 14fe88955d877a57efe6e5827f837119 OK
2025/01/22 02:14:18 DEBUG : only9: md5 = 35214c2298bf022a364b6a6065037fbc OK
2025/01/22 02:14:20 DEBUG : both10: md5 = e70ba3006595d6153a910b188b9c80a7 OK
2025/01/22 02:14:22 DEBUG : only10: md5 = 6d0c6db7b361d52ade799a2774b8e5d6 OK
2025/01/22 02:14:23 DEBUG : both11: md5 = d73ae9e20c5dc6f55d9faf4166f66ff9 OK
2025/01/22 02:14:25 DEBUG : only11: md5 = 4eaef45c31b6f0fc7c493746bb2b21ca OK
2025/01/22 02:14:27 DEBUG : both12: md5 = b937144bbd358c946e4bfb251e9b6565 OK
2025/01/22 02:14:29 DEBUG : only12: md5 = 56be7d43af3c4b3f72ec8d424780d173 OK
2025/01/22 02:14:31 DEBUG : both13: md5 = 4c5f012eb852e8f36ba3089afaf24e2e OK
2025/01/22 02:14:33 DEBUG : only13: md5 = 88c48ee4528f49df5ff3a2bb3bcc4d13 OK
2025/01/22 02:14:35 DEBUG : both14: md5 = 6f3c74de2ff41994b0e11e8d0528410a OK
2025/01/22 02:14:37 DEBUG : only14: md5 = 8e59de688b9753c7f62a72f7bb818bc6 OK
2025/01/22 02:14:39 DEBUG : both15: md5 = 4e5df8b0c0b2fa64438482455bd65283 OK
2025/01/22 02:14:41 DEBUG : only15: md5 = 39f8106d2fc3e9cae1759582a6435ec5 OK
2025/01/22 02:14:42 DEBUG : both16: md5 = b14c4e43b96b3a818e45809608fbc7f6 OK
2025/01/22 02:14:44 DEBUG : only16: md5 = d2a0c31e768f96cd70295d83bd9c41df OK
2025/01/22 02:14:46 DEBUG : both17: md5 = 56ec2e9c5de791754c45a2500f192acb OK
2025/01/22 02:14:48 DEBUG : only17: md5 = 32cb181cb756f7de599c7f827c83dcd5 OK
2025/01/22 02:14:49 DEBUG : both18: md5 = d277168f98d151584a1e8ef9aef1796e OK
2025/01/22 02:14:51 DEBUG : only18: md5 = d722ab3794e07e04b816427cb0ca3d72 OK
2025/01/22 02:14:53 DEBUG : both19: md5 = bdbb0da0f1d762da2bda0bd95ee4b175 OK
2025/01/22 02:14:54 DEBUG : only19: md5 = 74934ef9ed574a7b42603aea52f592ae OK
2025/01/22 02:14:55 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:14:55 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:14:55 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:14:55 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:14:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for checks to finish
2025/01/22 02:14:55 DEBUG : both1: Unchanged skipping
2025/01/22 02:14:55 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:14:55 DEBUG : both12: Unchanged skipping
2025/01/22 02:14:55 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:14:55 DEBUG : both13: Unchanged skipping
2025/01/22 02:14:55 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:14:55 DEBUG : both10: Unchanged skipping
2025/01/22 02:14:55 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:14:55 DEBUG : both15: Unchanged skipping
2025/01/22 02:14:55 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:14:55 DEBUG : both16: Unchanged skipping
2025/01/22 02:14:55 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:14:55 DEBUG : both17: Unchanged skipping
2025/01/22 02:14:55 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:14:55 DEBUG : both18: Unchanged skipping
2025/01/22 02:14:55 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:14:55 DEBUG : both19: Unchanged skipping
2025/01/22 02:14:55 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:14:55 DEBUG : both2: Unchanged skipping
2025/01/22 02:14:55 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:14:55 DEBUG : both3: Unchanged skipping
2025/01/22 02:14:55 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:14:55 DEBUG : both4: Unchanged skipping
2025/01/22 02:14:55 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:14:55 DEBUG : both5: Unchanged skipping
2025/01/22 02:14:55 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:14:55 DEBUG : both6: Unchanged skipping
2025/01/22 02:14:55 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:14:55 DEBUG : both7: Unchanged skipping
2025/01/22 02:14:55 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:14:55 DEBUG : both8: Unchanged skipping
2025/01/22 02:14:55 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2025/01/22 02:14:55 DEBUG : both9: Unchanged skipping
2025/01/22 02:14:55 DEBUG : only0: Sizes differ (src 0 vs dst 6)
2025/01/22 02:14:55 DEBUG : only1: Sizes differ (src 0 vs dst 6)
2025/01/22 02:14:55 DEBUG : only10: Sizes differ (src 0 vs dst 6)
2025/01/22 02:14:55 DEBUG : only11: Sizes differ (src 0 vs dst 6)
2025/01/22 02:14:55 DEBUG : only12: Sizes differ (src 0 vs dst 6)
2025/01/22 02:14:55 DEBUG : only13: Sizes differ (src 0 vs dst 6)
2025/01/22 02:14:55 DEBUG : only14: Sizes differ (src 0 vs dst 6)
2025/01/22 02:14:55 DEBUG : only15: Sizes differ (src 0 vs dst 6)
2025/01/22 02:14:55 DEBUG : only16: Sizes differ (src 0 vs dst 6)
2025/01/22 02:14:55 DEBUG : only17: Sizes differ (src 0 vs dst 6)
2025/01/22 02:14:55 DEBUG : only18: Sizes differ (src 0 vs dst 6)
2025/01/22 02:14:55 DEBUG : only19: Sizes differ (src 0 vs dst 6)
2025/01/22 02:14:55 DEBUG : only2: Sizes differ (src 0 vs dst 6)
2025/01/22 02:14:55 DEBUG : only3: Sizes differ (src 0 vs dst 6)
2025/01/22 02:14:55 DEBUG : only4: Sizes differ (src 0 vs dst 6)
2025/01/22 02:14:55 DEBUG : only5: Sizes differ (src 0 vs dst 6)
2025/01/22 02:14:55 DEBUG : only6: Sizes differ (src 0 vs dst 6)
2025/01/22 02:14:55 DEBUG : only7: Sizes differ (src 0 vs dst 6)
2025/01/22 02:14:55 DEBUG : only8: Sizes differ (src 0 vs dst 6)
2025/01/22 02:14:55 DEBUG : only9: Sizes differ (src 0 vs dst 6)
2025/01/22 02:14:55 DEBUG : both0: Unchanged skipping
2025/01/22 02:14:55 DEBUG : both11: Unchanged skipping
2025/01/22 02:14:55 DEBUG : both14: Unchanged skipping
2025/01/22 02:14:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Waiting for transfers to finish
2025/01/22 02:14:56 DEBUG : only11: md5 = dfb2fff10915f4e6f27489774211ef64 OK
2025/01/22 02:14:56 INFO  : only11: Copied (replaced existing)
2025/01/22 02:14:56 DEBUG : only0: md5 = af7aaec134475317275322569c8280eb OK
2025/01/22 02:14:56 INFO  : only0: Copied (replaced existing)
2025/01/22 02:14:56 DEBUG : only10: md5 = 9f48cb4ace13d772e85d356d57e1e340 OK
2025/01/22 02:14:56 INFO  : only10: Copied (replaced existing)
2025/01/22 02:14:56 DEBUG : only1: md5 = f8b5f11b6573fb264c5f7057d34f8d4e OK
2025/01/22 02:14:56 INFO  : only1: Copied (replaced existing)
2025/01/22 02:14:57 DEBUG : only12: md5 = 2d6045658a840744ef371f06b1544c26 OK
2025/01/22 02:14:57 INFO  : only12: Copied (replaced existing)
2025/01/22 02:14:58 DEBUG : only15: md5 = 38477accd86b00b917de7185acef9896 OK
2025/01/22 02:14:58 INFO  : only15: Copied (replaced existing)
2025/01/22 02:14:58 DEBUG : only14: md5 = 691314b9fc97c09f2e33c0ff781db1f6 OK
2025/01/22 02:14:58 INFO  : only14: Copied (replaced existing)
2025/01/22 02:14:58 DEBUG : only13: md5 = b58d323c9c34f41ba8ed596dfaa9ac6d OK
2025/01/22 02:14:58 INFO  : only13: Copied (replaced existing)
2025/01/22 02:14:59 DEBUG : only16: md5 = 22f2036a18ee7507f59848fc93e0e413 OK
2025/01/22 02:14:59 INFO  : only16: Copied (replaced existing)
2025/01/22 02:14:59 DEBUG : only18: md5 = dd2847bc400556944b0ac9f2821baeb9 OK
2025/01/22 02:14:59 INFO  : only18: Copied (replaced existing)
2025/01/22 02:14:59 DEBUG : only17: md5 = b5cd1ce498436be830bf4c0d67efe486 OK
2025/01/22 02:14:59 INFO  : only17: Copied (replaced existing)
2025/01/22 02:14:59 DEBUG : only19: md5 = 5aff7bfb9d31c082fc336b54d3493134 OK
2025/01/22 02:14:59 INFO  : only19: Copied (replaced existing)
2025/01/22 02:15:00 DEBUG : only2: md5 = 65aedb115b6791d5ca5d4ac12e1c2953 OK
2025/01/22 02:15:00 INFO  : only2: Copied (replaced existing)
2025/01/22 02:15:00 DEBUG : only3: md5 = 6edc8acb14498a4e88c30bc437fe9d6b OK
2025/01/22 02:15:00 INFO  : only3: Copied (replaced existing)
2025/01/22 02:15:00 DEBUG : only4: md5 = 2693b93c623decf751e275bb22ee61da OK
2025/01/22 02:15:00 INFO  : only4: Copied (replaced existing)
2025/01/22 02:15:00 DEBUG : only5: md5 = 5f6cba611d20491ce8d112bb1f26e8ba OK
2025/01/22 02:15:00 INFO  : only5: Copied (replaced existing)
2025/01/22 02:15:01 DEBUG : only6: md5 = 8dcf2db410a54b28bf037cda07bc9fda OK
2025/01/22 02:15:01 INFO  : only6: Copied (replaced existing)
2025/01/22 02:15:01 DEBUG : only7: md5 = 0562407303e4cc41277403ef3aad17ff OK
2025/01/22 02:15:01 INFO  : only7: Copied (replaced existing)
2025/01/22 02:15:01 DEBUG : only8: md5 = 8b26d91cf0c4b3a77595d027dae4eff3 OK
2025/01/22 02:15:01 INFO  : only8: Copied (replaced existing)
2025/01/22 02:15:02 DEBUG : only9: md5 = 04e7c8e294d94007186ca20bf5fdbd8c OK
2025/01/22 02:15:02 INFO  : only9: Copied (replaced existing)
2025/01/22 02:15:02 DEBUG : Waiting for deletions to finish
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
--- PASS: TestSyncConcurrentTruncate (103.18s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:15:27 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/22 02:15:27 DEBUG : sub dir: Making directory with metadata
2025/01/22 02:15:28 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:15:49 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/22 02:15:49 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/22 02:15:49 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/22 02:15:49 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:16:03 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0"
2025/01/22 02:16:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/22 02:16:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2025/01/22 02:16:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2025/01/22 02:16:07 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/22 02:16:08 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/22 02:16:09 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/22 02:16:10 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/22 02:16:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/22 02:16:12 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2025/01/22 02:16:12 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/22 02:16:12 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithEmptyDirs (47.20s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:16:15 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/01/22 02:16:15 DEBUG : sub dir: Making directory with metadata
2025/01/22 02:16:16 INFO  : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:16:41 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/22 02:16:42 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/01/22 02:16:42 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/01/22 02:16:42 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume'", Local "Local file system at /tmp/rclone1262997294", Modify Window "1ms"
2025/01/22 02:16:54 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/22 02:16:55 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o"
2025/01/22 02:16:56 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8"
2025/01/22 02:16:57 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/22 02:16:58 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/22 02:16:58 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/22 02:16:59 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/22 02:17:00 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
2025/01/22 02:17:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns"
2025/01/22 02:17:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak"
2025/01/22 02:17:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo"
--- PASS: TestNothingToTransferWithoutEmptyDirs (49.82s)
PASS
2025/01/22 02:17:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gikuguz6wume': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 18m38.839960248s (try 1/5)