"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5) 2025/04/29 02:53:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date" 2025/04/29 02:53:26 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/04/29 02:53:26 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90" 2025/04/29 02:53:28 DEBUG : Creating backend with remote "/tmp/rclone3750888648" === 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-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:53:29 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/29 02:53:29 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/29 02:53:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:53:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:53:29 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/04/29 02:53:29 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.18s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:53:30 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/29 02:53:30 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/29 02:53:30 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/29 02:53:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:53:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:53:32 DEBUG : sub dir/hello world: md5 = 1027cd57e275b0cfea62d796146c3398 OK 2025/04/29 02:53:32 INFO : sub dir/hello world: Copied (new) 2025/04/29 02:53:33 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:53:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (6.40s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:53:36 DEBUG : metadata sub dir: Making directory with metadata 2025/04/29 02:53:36 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/29 02:53:36 DEBUG : empty metadata sub dir: Making directory with metadata 2025/04/29 02:53:36 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/29 02:53:36 DEBUG : Local file system at /tmp/rclone3750888648: File to upload is small (21 bytes), uploading instead of streaming 2025/04/29 02:53:36 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/04/29 02:53:36 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/04/29 02:53:36 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/04/29 02:53:37 DEBUG : Google drive root 'crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90': Skipping btime metadata as can't update it on an existing file: 2025-04-29T02:53:36.627496141Z 2025/04/29 02:53:37 INFO : empty metadata sub dir: Updated directory metadata 2025/04/29 02:53:37 DEBUG : Google drive root 'crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90': Skipping btime metadata as can't update it on an existing file: 2025-04-29T02:53:36.627496141Z 2025/04/29 02:53:38 INFO : metadata sub dir: Updated directory metadata 2025/04/29 02:53:38 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/04/29 02:53:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:53:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:53:39 DEBUG : metadata sub dir/hello metadata world: md5 = 1223afd067a29f136f8ff08033d7fbe1 OK 2025/04/29 02:53:39 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:53:42 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (7.91s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:53:44 DEBUG : metadata sub dir: Making directory with metadata 2025/04/29 02:53:44 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/29 02:53:44 DEBUG : empty metadata sub dir: Making directory with metadata 2025/04/29 02:53:44 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/29 02:53:44 DEBUG : Local file system at /tmp/rclone3750888648: File to upload is small (21 bytes), uploading instead of streaming 2025/04/29 02:53:44 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/04/29 02:53:44 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/04/29 02:53:44 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/04/29 02:53:44 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/04/29 02:53:44 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/04/29 02:53:44 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/04/29 02:53:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:53:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:53:47 DEBUG : metadata sub dir/hello metadata world: md5 = 44de54f2100ef16bd02cf8a20fae8919 OK 2025/04/29 02:53:47 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/04/29 02:53:47 DEBUG : Google drive root 'crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90': Skipping btime metadata as can't update it on an existing file: 2025-04-29T02:53:44.53551212Z 2025/04/29 02:53:47 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:53:50 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (7.19s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:53:51 DEBUG : Creating backend with remote "/non-existing" 2025/04/29 02:53:51 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/04/29 02:53:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:53:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.11s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:53:52 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/29 02:53:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/29 02:53:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:53:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:53:55 DEBUG : sub dir/hello world: md5 = 10e92e3b7f0ff00e06887c7c8e847b1a OK 2025/04/29 02:53:55 INFO : sub dir/hello world: Copied (new) 2025/04/29 02:53:55 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:53:57 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (5.69s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:53:58 INFO : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Running all checks before starting transfers 2025/04/29 02:53:58 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/29 02:53:58 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/29 02:53:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:53:58 INFO : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Checks finished, now starting transfers 2025/04/29 02:53:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:54:00 DEBUG : sub dir/hello world: md5 = 80b7b697b04087f06a56cee28eab38f3 OK 2025/04/29 02:54:00 INFO : sub dir/hello world: Copied (new) 2025/04/29 02:54:01 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:54:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (5.63s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:54:04 ERROR : Ignoring --no-traverse with sync 2025/04/29 02:54:04 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/29 02:54:04 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/29 02:54:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:54:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:54:06 DEBUG : sub dir/hello world: md5 = 0be85089b123bc4d4f8a6fbd16e1484b OK 2025/04/29 02:54:06 INFO : sub dir/hello world: Copied (new) 2025/04/29 02:54:06 DEBUG : Waiting for deletions to finish 2025/04/29 02:54:06 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:54:08 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (5.55s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:54:09 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/04/29 02:54:09 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/29 02:54:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:54:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:54:11 DEBUG : hello world2: md5 = eacf9ee8440f9ce90070df6c88779640 OK 2025/04/29 02:54:11 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.17s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:54:13 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/29 02:54:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:54:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:54:14 DEBUG : potato2: md5 = 3cf43e0972543efefa44c4a5637b42fd OK 2025/04/29 02:54:14 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.20s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:54:16 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/29 02:54:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:54:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:54:17 DEBUG : potato2: md5 = d7f9494fc13210ea9fb59048ea4c9f42 OK 2025/04/29 02:54:17 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.29s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:54:19 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/29 02:54:19 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/29 02:54:19 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/29 02:54:19 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/29 02:54:19 DEBUG : sub dir: Making directory with metadata 2025/04/29 02:54:20 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/29 02:54:20 DEBUG : sub dir2: Making directory with metadata 2025/04/29 02:54:21 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/29 02:54:21 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/29 02:54:21 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/29 02:54:21 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/29 02:54:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:54:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:54:22 DEBUG : sub dir/hello world: md5 = c3aa8fe2503d818320c83e0f472915b0 OK 2025/04/29 02:54:22 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:54:25 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/04/29 02:54:26 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (8.22s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:54:27 INFO : sub dir2: Making directory 2025/04/29 02:54:27 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/29 02:54:27 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/29 02:54:27 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/29 02:54:27 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/29 02:54:27 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/29 02:54:27 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/04/29 02:54:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:54:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:54:30 DEBUG : sub dir/hello world: md5 = b18a26056901c8311d671725d9cb760c OK 2025/04/29 02:54:30 INFO : sub dir/hello world: Copied (new) 2025/04/29 02:54:30 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/29 02:54:32 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (5.26s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:54:32 DEBUG : sub dir2: Making directory with metadata 2025/04/29 02:54:32 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/29 02:54:33 DEBUG : sub dir: Making directory with metadata 2025/04/29 02:54:33 INFO : sub dir: Made directory with metadata (mtime=2025-04-29T02:54:32.84360914Z) 2025/04/29 02:54:33 DEBUG : sub dir2: Making directory with metadata 2025/04/29 02:54:34 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/29 02:54:34 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/29 02:54:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:54:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:54:35 DEBUG : sub dir/hello world: md5 = 13a4a9d09995574a147e1e4d989496e1 OK 2025/04/29 02:54:35 INFO : sub dir/hello world: Copied (new) 2025/04/29 02:54:35 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:54:38 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (7.09s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:54:39 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/04/29 02:54:39 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/29 02:54:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:54:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:54:41 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (3.86s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:54:43 INFO : sub dir2: Making directory 2025/04/29 02:54:44 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/29 02:54:44 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/29 02:54:44 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/29 02:54:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:54:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:54:46 DEBUG : sub dir/hello world: md5 = d08389e16b243f1cb36b78fc49940e74 OK 2025/04/29 02:54:46 INFO : sub dir/hello world: Copied (new) 2025/04/29 02:54:46 INFO : sub dir/hello world: Deleted 2025/04/29 02:54:46 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/29 02:54:48 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (5.09s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:54:48 DEBUG : sub dir2: Making directory with metadata 2025/04/29 02:54:48 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/29 02:54:48 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/29 02:54:49 DEBUG : sub dir: Making directory with metadata 2025/04/29 02:54:49 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/29 02:54:49 DEBUG : sub dir2: Making directory with metadata 2025/04/29 02:54:50 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/29 02:54:50 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/29 02:54:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:54:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:54:51 DEBUG : sub dir/hello world: md5 = e3583c6804a4fcb6d51c4ab75b8800e9 OK 2025/04/29 02:54:51 INFO : sub dir/hello world: Copied (new) 2025/04/29 02:54:51 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:54:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (6.82s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.44s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:54:56 INFO : sub dir2: Making directory 2025/04/29 02:54:56 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/29 02:54:56 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/29 02:54:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/29 02:54:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:54:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:54:58 DEBUG : sub dir/hello world: md5 = 65ec0ec8d45533bf575c93020ed555a0 OK 2025/04/29 02:54:58 INFO : sub dir/hello world: Copied (new) 2025/04/29 02:54:58 DEBUG : Waiting for deletions to finish 2025/04/29 02:54:59 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/29 02:55:00 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (5.28s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:55:03 DEBUG : sub dir/hello world: md5 = 242524bad7ea8b326199ba6aa2d919e1 OK 2025/04/29 02:55:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pucaqen0rexo" 2025/04/29 02:55:04 DEBUG : Creating backend with remote "TestDrive:crypt/0r8kkekilguvbk5pnng71qi2m1vvg7sc8s7mtqp5on7vthnfqirg" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date' -> Encrypted drive 'TestCryptDrive:rclone-test-pucaqen0rexo' 2025/04/29 02:55:05 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/29 02:55:05 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/29 02:55:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pucaqen0rexo': Waiting for checks to finish 2025/04/29 02:55:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pucaqen0rexo': Waiting for transfers to finish 2025/04/29 02:55:08 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/29 02:55:08 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:55:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pucaqen0rexo': Purge remote 2025/04/29 02:55:10 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (10.47s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:55:13 DEBUG : sub dir/hello world: md5 = ab6d29318e37279b18252cbc24119167 OK 2025/04/29 02:55:15 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/29 02:55:15 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/29 02:55:15 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/29 02:55:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:55:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:55:16 DEBUG : sub dir/hello world: md5 = 04c46e6d666589faf276eb65a7bc7653 OK 2025/04/29 02:55:16 INFO : sub dir/hello world: Copied (replaced existing) 2025/04/29 02:55:16 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:55:18 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (8.06s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:55:22 DEBUG : sub dir/hello world: md5 = 84bf7ab61f107b3f1ad5a12d50f30e2c OK 2025/04/29 02:55:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bojonej6vevo" 2025/04/29 02:55:22 DEBUG : Creating backend with remote "TestDrive:crypt/mptvqu2upe4nfkjvjsnc7bq483qckq8sh6em2vuol7ljsk8qhk60" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date' -> Encrypted drive 'TestCryptDrive:rclone-test-bojonej6vevo' 2025/04/29 02:55:23 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/29 02:55:24 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/29 02:55:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bojonej6vevo': Waiting for checks to finish 2025/04/29 02:55:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bojonej6vevo': Waiting for transfers to finish 2025/04/29 02:55:26 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/29 02:55:27 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:55:29 DEBUG : sub dir/hello world: md5 = ab07649d3343cd504d2d21ed81d9e5b0 OK 2025/04/29 02:55:29 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/29 02:55:29 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/29 02:55:29 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/29 02:55:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bojonej6vevo': Waiting for checks to finish 2025/04/29 02:55:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bojonej6vevo': Waiting for transfers to finish 2025/04/29 02:55:31 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/29 02:55:31 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:55:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bojonej6vevo': Purge remote 2025/04/29 02:55:34 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (15.77s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:55:38 DEBUG : sub dir/hello world: md5 = 40ab015ecd735a48c69873e31edf32f5 OK 2025/04/29 02:55:39 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/29 02:55:39 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/29 02:55:39 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/29 02:55:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:55:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:55:40 DEBUG : sub dir/hello world: md5 = 735e2256bed9964bc78e4f0bdc5e0789 OK 2025/04/29 02:55:40 INFO : sub dir/hello world: Copied (replaced existing) 2025/04/29 02:55:40 INFO : sub dir/hello world: Deleted 2025/04/29 02:55:41 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:55:42 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (8.11s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:55:45 DEBUG : sub dir/hello world: md5 = f16c86253294b4de6c5f55230084b06e OK 2025/04/29 02:55:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cusimeh4miyo" 2025/04/29 02:55:46 DEBUG : Creating backend with remote "TestDrive:crypt/34evtn2pneodjur5t1k6rjjfnu4n82kj3nupvvh63k1vijci1jj0" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date' -> Encrypted drive 'TestCryptDrive:rclone-test-cusimeh4miyo' 2025/04/29 02:55:47 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/29 02:55:47 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/29 02:55:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cusimeh4miyo': Waiting for checks to finish 2025/04/29 02:55:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cusimeh4miyo': Waiting for transfers to finish 2025/04/29 02:55:50 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/29 02:55:50 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:55:52 DEBUG : sub dir/hello world: md5 = 33546df1ef76c60fd85ff7252e9c9bb8 OK 2025/04/29 02:55:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cusimeh4miyo': Using server-side directory move 2025/04/29 02:55:53 INFO : Encrypted drive 'TestCryptDrive:rclone-test-cusimeh4miyo': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/29 02:55:53 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/29 02:55:53 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/29 02:55:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cusimeh4miyo': Waiting for checks to finish 2025/04/29 02:55:53 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/29 02:55:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cusimeh4miyo': Waiting for transfers to finish 2025/04/29 02:55:54 INFO : sub dir/hello world: Deleted 2025/04/29 02:55:54 INFO : sub dir/hello world: Moved (server-side) 2025/04/29 02:55:55 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/29 02:55:57 DEBUG : sub dir/hello world: md5 = fadc0deef4b3b33fea48a1a595f97dc6 OK 2025/04/29 02:55:58 DEBUG : testing file moves 2025/04/29 02:55:58 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/29 02:55:58 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/29 02:55:58 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/04/29 02:55:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cusimeh4miyo': Waiting for checks to finish 2025/04/29 02:55:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cusimeh4miyo': Waiting for transfers to finish 2025/04/29 02:55:58 INFO : sub dir/hello world: Deleted 2025/04/29 02:55:59 INFO : sub dir/hello world: Moved (server-side) 2025/04/29 02:55:59 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:56:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cusimeh4miyo': Purge remote --- PASS: TestServerSideMoveOverSelf (19.82s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:56:05 DEBUG : sub dir/hello world: md5 = fd67665bc3fb042c1f7c0606cf69ae43 OK 2025/04/29 02:56:05 ERROR : : error listing: directory not found 2025/04/29 02:56:06 INFO : Local file system at /tmp/rclone3750888648: Making directory 2025/04/29 02:56:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:56:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:56:08 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (5.87s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:56:11 DEBUG : sub dir/hello world: md5 = 7f77b52b5cb20db40346e3e6e8875f39 OK 2025/04/29 02:56:12 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/29 02:56:12 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/29 02:56:12 DEBUG : Local file system at /tmp/rclone3750888648: Waiting for checks to finish 2025/04/29 02:56:12 DEBUG : Local file system at /tmp/rclone3750888648: Waiting for transfers to finish 2025/04/29 02:56:13 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/04/29 02:56:13 INFO : sub dir/hello world: Copied (new) 2025/04/29 02:56:13 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:56:14 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (6.47s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:56:16 DEBUG : check sum: Need to transfer - File not found at Destination 2025/04/29 02:56:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:56:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:56:17 DEBUG : check sum: md5 = a6c368bbb71cd8580371152a47a91103 OK 2025/04/29 02:56:17 INFO : check sum: Copied (new) 2025/04/29 02:56:17 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:56:18 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/04/29 02:56:18 DEBUG : check sum: Size of src and dst objects identical 2025/04/29 02:56:18 DEBUG : check sum: Unchanged skipping 2025/04/29 02:56:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:56:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:56:18 DEBUG : Waiting for deletions to finish 2025/04/29 02:56:18 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.02s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:56:20 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/04/29 02:56:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:56:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:56:21 DEBUG : sizeonly: md5 = fc456b3231ec06bffb5118be0b42e15b OK 2025/04/29 02:56:21 INFO : sizeonly: Copied (new) 2025/04/29 02:56:21 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:56:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:56:22 DEBUG : sizeonly: Sizes identical 2025/04/29 02:56:22 DEBUG : sizeonly: Unchanged skipping 2025/04/29 02:56:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:56:22 DEBUG : Waiting for deletions to finish 2025/04/29 02:56:22 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.27s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:56:24 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/04/29 02:56:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:56:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:56:25 DEBUG : ignore-size: md5 = 7aeeff50d947e48aeed10e7ea05c8e35 OK 2025/04/29 02:56:25 INFO : ignore-size: Copied (new) 2025/04/29 02:56:25 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:56:26 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 02:56:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:56:26 DEBUG : ignore-size: Unchanged skipping 2025/04/29 02:56:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:56:26 DEBUG : Waiting for deletions to finish 2025/04/29 02:56:26 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.01s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:56:29 DEBUG : existing: md5 = f4408b60bb3cb5b52f21dfaffa4b06dc OK 2025/04/29 02:56:30 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 02:56:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:56:30 DEBUG : existing: Unchanged skipping 2025/04/29 02:56:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:56:30 DEBUG : Waiting for deletions to finish 2025/04/29 02:56:30 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:56:30 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/04/29 02:56:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:56:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:56:31 DEBUG : existing: md5 = bce6d0dd49856df74c1475d16a9062bb OK 2025/04/29 02:56:31 INFO : existing: Copied (replaced existing) 2025/04/29 02:56:31 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.30s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:56:33 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/29 02:56:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:56:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:56:35 DEBUG : existing: md5 = 7694688866e60331cecd7618eac39f2e OK 2025/04/29 02:56:35 INFO : existing: Copied (new) 2025/04/29 02:56:35 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:56:35 DEBUG : existing: Destination exists, skipping 2025/04/29 02:56:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:56:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:56:35 DEBUG : Waiting for deletions to finish 2025/04/29 02:56:35 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.21s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:56:39 DEBUG : b/potato: md5 = 1d667e597b180dd9640365d69a15210a OK 2025/04/29 02:56:41 DEBUG : c/non empty space: md5 = 819632faeaf9dfc0066cd6ca1f19942d OK 2025/04/29 02:56:41 INFO : d: Making directory 2025/04/29 02:56:43 DEBUG : Added delayed dir = "a", newDst= 2025/04/29 02:56:43 INFO : c: Set directory modification time (using SetModTime) 2025/04/29 02:56:43 DEBUG : Added delayed dir = "c", newDst=c 2025/04/29 02:56:43 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/29 02:56:44 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 02:56:44 DEBUG : c/non empty space: Unchanged skipping 2025/04/29 02:56:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:56:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:56:45 DEBUG : a/potato2: md5 = dcf733f3fb9361a6780dbc98aec4bab7 OK 2025/04/29 02:56:45 INFO : a/potato2: Copied (new) 2025/04/29 02:56:45 DEBUG : Waiting for deletions to finish 2025/04/29 02:56:46 INFO : b/potato: Deleted 2025/04/29 02:56:46 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/29 02:56:46 INFO : d: Removing directory 2025/04/29 02:56:47 INFO : b: Removing directory 2025/04/29 02:56:47 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/29 02:56:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:56:50 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/29 02:56:50 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (14.28s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:56:53 DEBUG : empty space: md5 = 7cbe96b867cdd7936a92985090535408 OK 2025/04/29 02:56:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:56:54 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/04/29 02:56:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:56:54 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/04/29 02:56:54 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:56:54 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/04/29 02:56:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:56:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:56:55 DEBUG : empty space: md5 = 0639d14ceefe7c2ef360bb76f15c9274 OK 2025/04/29 02:56:55 INFO : empty space: Copied (replaced existing) 2025/04/29 02:56:55 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (5.58s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", 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-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:56:59 DEBUG : foo: md5 = edf985b765f56f52186bd97aab227f4d OK 2025/04/29 02:56:59 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/04/29 02:56:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:56:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:57:01 DEBUG : foo: md5 = 661db6cdbeb0bf9df0f58b8e58fb6a6d OK 2025/04/29 02:57:01 INFO : foo: Copied (replaced existing) 2025/04/29 02:57:01 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (4.38s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:57:03 DEBUG : empty space: md5 = f28a4a840039de087e39ea94a720458f OK 2025/04/29 02:57:04 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 02:57:04 DEBUG : potato: Need to transfer - File not found at Destination 2025/04/29 02:57:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:57:04 DEBUG : empty space: Unchanged skipping 2025/04/29 02:57:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:57:05 DEBUG : potato: md5 = a8647be273db7ac0d021719a7ffb4d6e OK 2025/04/29 02:57:05 INFO : potato: Copied (new) 2025/04/29 02:57:05 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (5.23s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:57:09 DEBUG : potato: md5 = 1cde36893a18fbfec69856e2ed3a9b50 OK 2025/04/29 02:57:09 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/04/29 02:57:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:57:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:57:10 DEBUG : potato: md5 = a6e2273839770b85224fcf81195505d9 OK 2025/04/29 02:57:10 INFO : potato: Copied (replaced existing) 2025/04/29 02:57:10 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (4.55s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:57:13 DEBUG : potato: md5 = a3d816f72f18aba9c7d04e1e15984351 OK 2025/04/29 02:57:14 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/04/29 02:57:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:57:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:57:15 DEBUG : potato: md5 = bff7917d80253b7f94049039376cebe5 OK 2025/04/29 02:57:15 INFO : potato: Copied (replaced existing) 2025/04/29 02:57:15 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (4.72s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:57:18 DEBUG : potato: md5 = 3f21b38c2a6fa42d1bbc09332495f7fc OK 2025/04/29 02:57:20 DEBUG : empty space: md5 = d11808cf9e93432ba7d92fab413cce07 OK 2025/04/29 02:57:20 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/29 02:57:20 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 02:57:20 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/04/29 02:57:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:57:20 DEBUG : empty space: Unchanged skipping 2025/04/29 02:57:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:57:20 DEBUG : Waiting for deletions to finish 2025/04/29 02:57:20 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.66s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:57:24 DEBUG : potato: md5 = 995fbca98ce4df16d912f4c74b99e1d1 OK 2025/04/29 02:57:25 DEBUG : empty space: md5 = a903a6910960c8e25a0349ec5fd5120a OK 2025/04/29 02:57:26 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 02:57:26 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/29 02:57:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:57:26 DEBUG : empty space: Unchanged skipping 2025/04/29 02:57:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:57:27 DEBUG : potato2: md5 = deed55e05bc11adbf19513e7d7ff7120 OK 2025/04/29 02:57:27 INFO : potato2: Copied (new) 2025/04/29 02:57:27 DEBUG : Waiting for deletions to finish 2025/04/29 02:57:27 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (7.43s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:57:32 DEBUG : b/potato: md5 = 486a2046c751a066e217a130b81c5f50 OK 2025/04/29 02:57:34 DEBUG : c/non empty space: md5 = c5ce88dfcdcb1f2c2294769d343cb3c4 OK 2025/04/29 02:57:34 INFO : d: Making directory 2025/04/29 02:57:35 INFO : d/e: Making directory 2025/04/29 02:57:36 DEBUG : Added delayed dir = "a", newDst= 2025/04/29 02:57:37 INFO : c: Set directory modification time (using SetModTime) 2025/04/29 02:57:37 DEBUG : Added delayed dir = "c", newDst=c 2025/04/29 02:57:37 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/29 02:57:37 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 02:57:37 DEBUG : c/non empty space: Unchanged skipping 2025/04/29 02:57:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:57:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:57:39 DEBUG : a/potato2: md5 = 5567272e172399d31fcbbdf1b233381d OK 2025/04/29 02:57:39 INFO : a/potato2: Copied (new) 2025/04/29 02:57:39 DEBUG : Waiting for deletions to finish 2025/04/29 02:57:40 INFO : b/potato: Deleted 2025/04/29 02:57:40 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/29 02:57:40 INFO : d/e: Removing directory 2025/04/29 02:57:41 INFO : d: Removing directory 2025/04/29 02:57:41 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/04/29 02:57:41 INFO : b: Removing directory 2025/04/29 02:57:42 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/29 02:57:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:57:44 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/29 02:57:45 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (16.48s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:57:48 DEBUG : b/potato: md5 = d252a3681c4b9b4eea05e9d129cfd081 OK 2025/04/29 02:57:50 DEBUG : c/non empty space: md5 = 1538f9e3a976724045f412dbb75228bf OK 2025/04/29 02:57:50 INFO : d: Making directory 2025/04/29 02:57:52 DEBUG : Added delayed dir = "a", newDst= 2025/04/29 02:57:52 INFO : c: Set directory modification time (using SetModTime) 2025/04/29 02:57:52 DEBUG : Added delayed dir = "c", newDst=c 2025/04/29 02:57:52 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/29 02:57:52 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 02:57:52 DEBUG : c/non empty space: Unchanged skipping 2025/04/29 02:57:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:57:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:57:54 DEBUG : a/potato2: md5 = aa78ead26a66da9a1adc1b0eabfb67c8 OK 2025/04/29 02:57:54 INFO : a/potato2: Copied (new) 2025/04/29 02:57:54 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': not deleting files as there were IO errors 2025/04/29 02:57:55 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/29 02:57:55 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:57:58 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/29 02:57:59 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/29 02:57:59 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (14.48s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:58:02 DEBUG : potato: md5 = 574b6021359dc9c10ff78ca8ba60198a OK 2025/04/29 02:58:03 DEBUG : empty space: md5 = 92b81687776fb9b944de095678c8221b OK 2025/04/29 02:58:04 DEBUG : Waiting for deletions to finish 2025/04/29 02:58:04 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 02:58:04 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/29 02:58:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:58:04 DEBUG : empty space: Unchanged skipping 2025/04/29 02:58:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:58:04 INFO : potato: Deleted 2025/04/29 02:58:05 DEBUG : potato2: md5 = 11fd3de996a988843de30f68274fdfb5 OK 2025/04/29 02:58:05 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (6.62s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:58:08 DEBUG : potato: md5 = caaeee39999bdd5f45ff2a51dc69eb06 OK 2025/04/29 02:58:10 DEBUG : empty space: md5 = a0ffaf82a82fe78b1a6bd8ebefac3491 OK 2025/04/29 02:58:10 DEBUG : Waiting for deletions to finish 2025/04/29 02:58:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:58:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:58:11 INFO : potato: Deleted 2025/04/29 02:58:11 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 02:58:11 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/29 02:58:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:58:11 DEBUG : empty space: Unchanged skipping 2025/04/29 02:58:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:58:12 DEBUG : potato2: md5 = 1fa14588168d02d89c6de9bda33d7cc4 OK 2025/04/29 02:58:12 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (7.25s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:58:16 DEBUG : potato: md5 = bfee13f50902f7d1202cc50aab6a2d75 OK 2025/04/29 02:58:16 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/29 02:58:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:58:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:58:18 DEBUG : potato2: md5 = 8eaf76aa9627553db330a76a5544448e OK 2025/04/29 02:58:18 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (5.23s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:58:21 DEBUG : potato2: md5 = 54871814cdcfe99c7f256870e5edfc91 OK 2025/04/29 02:58:22 DEBUG : empty space: md5 = c77cae3b5eed936a4291367625ce011c OK 2025/04/29 02:58:23 DEBUG : enormous: Excluded (Size Filter) 2025/04/29 02:58:23 DEBUG : enormous: Excluded 2025/04/29 02:58:23 DEBUG : potato2: Excluded (Size Filter) 2025/04/29 02:58:23 DEBUG : potato2: Excluded 2025/04/29 02:58:23 DEBUG : potato2: Excluded (Size Filter) 2025/04/29 02:58:23 DEBUG : potato2: Excluded 2025/04/29 02:58:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:58:23 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 02:58:23 DEBUG : empty space: Unchanged skipping 2025/04/29 02:58:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:58:23 DEBUG : Waiting for deletions to finish 2025/04/29 02:58:23 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:58:23 DEBUG : enormous: Excluded (Size Filter) 2025/04/29 02:58:23 DEBUG : enormous: Excluded 2025/04/29 02:58:23 DEBUG : potato2: Excluded (Size Filter) 2025/04/29 02:58:23 DEBUG : potato2: Excluded 2025/04/29 02:58:23 DEBUG : potato2: Excluded (Size Filter) 2025/04/29 02:58:23 DEBUG : potato2: Excluded 2025/04/29 02:58:23 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/04/29 02:58:23 DEBUG : empty space: Unchanged skipping 2025/04/29 02:58:23 DEBUG : Local file system at /tmp/rclone3750888648: Waiting for checks to finish 2025/04/29 02:58:23 DEBUG : Local file system at /tmp/rclone3750888648: Waiting for transfers to finish 2025/04/29 02:58:23 DEBUG : Waiting for deletions to finish 2025/04/29 02:58:23 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncWithExclude (5.99s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:58:27 DEBUG : potato2: md5 = b4b137cbead18b4e34e4741b8658ee74 OK 2025/04/29 02:58:29 DEBUG : empty space: md5 = b930731c2222e4a224aeb5075c63f477 OK 2025/04/29 02:58:30 DEBUG : enormous: md5 = dd7342183ddc3b164836c835d0a2e83c OK 2025/04/29 02:58:30 DEBUG : enormous: Excluded (Size Filter) 2025/04/29 02:58:30 DEBUG : enormous: Excluded 2025/04/29 02:58:30 DEBUG : potato2: Excluded (Size Filter) 2025/04/29 02:58:30 DEBUG : potato2: Excluded 2025/04/29 02:58:30 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 02:58:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:58:30 DEBUG : empty space: Unchanged skipping 2025/04/29 02:58:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:58:30 DEBUG : Waiting for deletions to finish 2025/04/29 02:58:31 INFO : enormous: Deleted 2025/04/29 02:58:31 INFO : potato2: Deleted 2025/04/29 02:58:31 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:58:31 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/04/29 02:58:31 DEBUG : empty space: Unchanged skipping 2025/04/29 02:58:31 DEBUG : Local file system at /tmp/rclone3750888648: Waiting for checks to finish 2025/04/29 02:58:31 DEBUG : Local file system at /tmp/rclone3750888648: Waiting for transfers to finish 2025/04/29 02:58:31 DEBUG : Waiting for deletions to finish 2025/04/29 02:58:31 INFO : enormous: Deleted 2025/04/29 02:58:31 INFO : potato2: Deleted 2025/04/29 02:58:31 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.41s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:58:34 DEBUG : one: md5 = dd1667a3c0e914b18e1f7c7286814e7e OK 2025/04/29 02:58:36 DEBUG : two: md5 = 64903eec1d6fb825cda710a67e7567e7 OK 2025/04/29 02:58:37 DEBUG : three: md5 = 6f90cd2160a51e0bfb153a6e35f0e1ba OK 2025/04/29 02:58:38 DEBUG : four: md5 = f820131b5395a344e14eb870e287b498 OK 2025/04/29 02:58:39 DEBUG : five: Need to transfer - File not found at Destination 2025/04/29 02:58:39 DEBUG : one: Destination is newer than source, skipping 2025/04/29 02:58:39 DEBUG : three: Sizes identical 2025/04/29 02:58:39 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/04/29 02:58:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:58:39 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/04/29 02:58:39 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/04/29 02:58:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:58:40 DEBUG : two: md5 = e91c7ff77650190a978c3efb88d1b390 OK 2025/04/29 02:58:40 INFO : two: Copied (replaced existing) 2025/04/29 02:58:40 DEBUG : four: md5 = 79762199c8d33f1d53640e40fa3edbf3 OK 2025/04/29 02:58:40 INFO : four: Copied (replaced existing) 2025/04/29 02:58:40 DEBUG : five: md5 = 316eb40e94121e07b1285fbe2c35f261 OK 2025/04/29 02:58:40 INFO : five: Copied (new) 2025/04/29 02:58:40 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (10.11s) === 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-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/04/29 02:58:43 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Ignoring --track-renames as the source and destination do not have a common hash 2025/04/29 02:58:43 DEBUG : potato: Need to transfer - File not found at Destination 2025/04/29 02:58:43 DEBUG : yam: Need to transfer - File not found at Destination 2025/04/29 02:58:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:58:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:58:45 DEBUG : potato: md5 = 38f8117c9f2d793146c65761bd397fca OK 2025/04/29 02:58:45 INFO : potato: Copied (new) 2025/04/29 02:58:45 DEBUG : yam: md5 = 6e69a794211d4261ec1e687af989f20b OK 2025/04/29 02:58:45 INFO : yam: Copied (new) 2025/04/29 02:58:45 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:58:46 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Ignoring --track-renames as the source and destination do not have a common hash 2025/04/29 02:58:46 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 02:58:46 DEBUG : yaml: Need to transfer - File not found at Destination 2025/04/29 02:58:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:58:46 DEBUG : potato: Unchanged skipping 2025/04/29 02:58:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:58:47 DEBUG : yaml: md5 = 2bf2c15798cf5b0e77e7eb154418deb6 OK 2025/04/29 02:58:47 INFO : yaml: Copied (new) 2025/04/29 02:58:47 DEBUG : Waiting for deletions to finish 2025/04/29 02:58:48 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (7.35s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/04/29 02:58:51 INFO : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Making map for --track-renames 2025/04/29 02:58:51 INFO : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Finished making map for --track-renames 2025/04/29 02:58:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:58:51 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/04/29 02:58:51 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/04/29 02:58:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for renames to finish 2025/04/29 02:58:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:58:52 DEBUG : yam: md5 = 87aed3944940534f3b03772030b6004c OK 2025/04/29 02:58:52 INFO : yam: Copied (new) 2025/04/29 02:58:52 DEBUG : potato: md5 = 7173f72e73d5f800d0b260f51c523660 OK 2025/04/29 02:58:52 INFO : potato: Copied (new) 2025/04/29 02:58:52 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:58:53 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 02:58:53 INFO : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Making map for --track-renames 2025/04/29 02:58:53 INFO : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Finished making map for --track-renames 2025/04/29 02:58:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:58:53 DEBUG : potato: Unchanged skipping 2025/04/29 02:58:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for renames to finish 2025/04/29 02:58:53 INFO : yam: Moved (server-side) to: yaml 2025/04/29 02:58:53 INFO : yaml: Renamed from "yam" 2025/04/29 02:58:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:58:53 DEBUG : Waiting for deletions to finish 2025/04/29 02:58:53 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.25s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/04/29 02:58:56 DEBUG : Added delayed dir = "sub", newDst= 2025/04/29 02:58:56 INFO : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Making map for --track-renames 2025/04/29 02:58:56 INFO : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Finished making map for --track-renames 2025/04/29 02:58:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:58:56 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/04/29 02:58:56 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/04/29 02:58:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for renames to finish 2025/04/29 02:58:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:58:58 DEBUG : sub/yam: md5 = d3b8a434a28c7670630ac3a210bc138f OK 2025/04/29 02:58:58 INFO : sub/yam: Copied (new) 2025/04/29 02:58:58 DEBUG : potato: md5 = 6d4b87233395fc16b48a0b7dfbac6a00 OK 2025/04/29 02:58:58 INFO : potato: Copied (new) 2025/04/29 02:58:58 DEBUG : Waiting for deletions to finish 2025/04/29 02:58:59 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:58:59 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 02:58:59 DEBUG : potato: Unchanged skipping 2025/04/29 02:59:00 INFO : sub: Set directory modification time (using SetModTime) 2025/04/29 02:59:00 DEBUG : Added delayed dir = "sub", newDst=sub 2025/04/29 02:59:00 INFO : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Making map for --track-renames 2025/04/29 02:59:00 INFO : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Finished making map for --track-renames 2025/04/29 02:59:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:59:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for renames to finish 2025/04/29 02:59:01 INFO : sub/yam: Moved (server-side) to: yam 2025/04/29 02:59:01 INFO : yam: Renamed from "sub/yam" 2025/04/29 02:59:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:59:01 DEBUG : Waiting for deletions to finish 2025/04/29 02:59:01 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (8.90s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:59:05 DEBUG : Creating backend with remote "/tmp/rclone3750888648/dir1" 2025/04/29 02:59:05 DEBUG : Config file has changed externally - reloading 2025/04/29 02:59:05 DEBUG : Creating backend with remote "/tmp/rclone3750888648/dir2" 2025/04/29 02:59:05 DEBUG : Local file system at /tmp/rclone3750888648/dir2: Using server-side directory move 2025/04/29 02:59:05 INFO : Local file system at /tmp/rclone3750888648/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/29 02:59:05 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/04/29 02:59:05 DEBUG : Local file system at /tmp/rclone3750888648/dir2: Waiting for checks to finish 2025/04/29 02:59:05 INFO : file1.txt: Moved (server-side) 2025/04/29 02:59:05 DEBUG : Local file system at /tmp/rclone3750888648/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.45s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:59:05 DEBUG : Added delayed dir = "nested", newDst= 2025/04/29 02:59:05 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/29 02:59:05 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/29 02:59:05 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/04/29 02:59:05 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/04/29 02:59:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:59:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:59:07 DEBUG : sub dir/hello world: md5 = 3d9a86a0a637d4cb9fc8a5278f836cfb OK 2025/04/29 02:59:07 INFO : sub dir/hello world: Copied (new) 2025/04/29 02:59:07 INFO : sub dir/hello world: Deleted 2025/04/29 02:59:09 DEBUG : nested/sub dir/file: md5 = e10c201e9f5af0b57845f183517237e9 OK 2025/04/29 02:59:09 INFO : nested/sub dir/file: Copied (new) 2025/04/29 02:59:09 INFO : nested/sub dir/file: Deleted 2025/04/29 02:59:10 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/04/29 02:59:10 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/29 02:59:10 INFO : nested: Set directory modification time (using DirSetModTime) 2025/04/29 02:59:10 INFO : sub dir: Removing directory 2025/04/29 02:59:10 INFO : nested/sub dir: Removing directory 2025/04/29 02:59:10 INFO : nested: Removing directory 2025/04/29 02:59:10 DEBUG : Local file system at /tmp/rclone3750888648: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:59:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/29 02:59:13 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/04/29 02:59:14 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (10.12s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:59:15 DEBUG : Added delayed dir = "nested", newDst= 2025/04/29 02:59:15 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/29 02:59:15 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/29 02:59:15 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/04/29 02:59:15 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/04/29 02:59:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:59:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:59:18 DEBUG : sub dir/hello world: md5 = 429bae76e032ffb747302cfd13719784 OK 2025/04/29 02:59:18 INFO : sub dir/hello world: Copied (new) 2025/04/29 02:59:18 INFO : sub dir/hello world: Deleted 2025/04/29 02:59:19 DEBUG : nested/sub dir/file: md5 = df22e23ca9dc6575743cc74fbf7a29b7 OK 2025/04/29 02:59:19 INFO : nested/sub dir/file: Copied (new) 2025/04/29 02:59:19 INFO : nested/sub dir/file: Deleted 2025/04/29 02:59:20 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/04/29 02:59:20 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/29 02:59:20 INFO : nested: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:59:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/29 02:59:24 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/04/29 02:59:24 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.21s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:59:26 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/29 02:59:26 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/04/29 02:59:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:59:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:59:27 DEBUG : existing-b: md5 = 38cc72e01ee0f9611f0ae88589c29c41 OK 2025/04/29 02:59:27 INFO : existing-b: Copied (new) 2025/04/29 02:59:27 INFO : existing-b: Deleted 2025/04/29 02:59:27 DEBUG : existing: md5 = c7054352e3f73f15f09d3d0e2ba07cb5 OK 2025/04/29 02:59:27 INFO : existing: Copied (new) 2025/04/29 02:59:27 INFO : existing: Deleted 2025/04/29 02:59:28 DEBUG : existing: Destination exists, skipping 2025/04/29 02:59:28 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/04/29 02:59:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 02:59:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 02:59:28 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.17s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:59:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qewepex6vele" 2025/04/29 02:59:30 DEBUG : Creating backend with remote "TestDrive:crypt/skv0v68if11q3ku75e602ir8lvi13fek41chbkug3u80072ed9lg" 2025/04/29 02:59:32 DEBUG : potato2: md5 = 3f1d27ac7dd377986b2d28c84cc42246 OK 2025/04/29 02:59:34 DEBUG : empty space: md5 = e0025ba71e8f49894a4bf77a1bd8c740 OK 2025/04/29 02:59:35 DEBUG : potato3: md5 = 9fe80b4f5a3b031c1ffb37a554fbf83e OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date' -> Encrypted drive 'TestCryptDrive:rclone-test-qewepex6vele' 2025/04/29 02:59:37 DEBUG : empty space: md5 = b62a566f23c876e66a80eb286a317da1 OK 2025/04/29 02:59:39 DEBUG : potato3: md5 = 5aa555e16fd1843b529723674b6c3f45 OK 2025/04/29 02:59:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qewepex6vele': Using server-side directory move 2025/04/29 02:59:39 INFO : Encrypted drive 'TestCryptDrive:rclone-test-qewepex6vele': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/29 02:59:39 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/29 02:59:39 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/04/29 02:59:39 DEBUG : empty space: Unchanged skipping 2025/04/29 02:59:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qewepex6vele': Waiting for checks to finish 2025/04/29 02:59:39 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/29 02:59:39 INFO : empty space: Deleted 2025/04/29 02:59:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qewepex6vele': Waiting for transfers to finish 2025/04/29 02:59:39 INFO : potato3: Deleted 2025/04/29 02:59:40 INFO : potato2: Moved (server-side) 2025/04/29 02:59:40 INFO : potato3: Moved (server-side) 2025/04/29 02:59:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mucijaf3guze" 2025/04/29 02:59:41 DEBUG : Creating backend with remote "TestDrive:crypt/ahdibint43rut400celc5l398ku3a1a780sfm4vdqfg2kqlrqojg" 2025/04/29 02:59:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mucijaf3guze': Using server-side directory move 2025/04/29 02:59:42 INFO : Encrypted drive 'TestCryptDrive:rclone-test-mucijaf3guze': Server side directory move succeeded 2025/04/29 02:59:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mucijaf3guze': Purge remote 2025/04/29 02:59:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qewepex6vele': Purge remote 2025/04/29 02:59:44 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (14.66s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 02:59:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-ziyusum2ralu" 2025/04/29 02:59:44 DEBUG : Creating backend with remote "TestDrive:crypt/215vt9rga763pesb95mp7vurfk6evmv57khm6of5u7fj1vsi9frg" 2025/04/29 02:59:47 DEBUG : potato2: md5 = 2479b6c3f1807b0ff39e5969ae466de0 OK 2025/04/29 02:59:48 DEBUG : empty space: md5 = 3d5153552af3f1da5641729eb2fc1f08 OK 2025/04/29 02:59:49 DEBUG : potato3: md5 = a6b2f209aca6eec05c30306b11a1032f OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date' -> Encrypted drive 'TestCryptDrive:rclone-test-ziyusum2ralu' 2025/04/29 02:59:52 DEBUG : empty space: md5 = 200c6d99c6d39eb260b345178d5cc415 OK 2025/04/29 02:59:53 DEBUG : potato3: md5 = 67cc3fddf2f61b6624f61cd5f74a533e OK 2025/04/29 02:59:54 DEBUG : empty space: Excluded (Size Filter) 2025/04/29 02:59:54 DEBUG : empty space: Excluded 2025/04/29 02:59:54 DEBUG : empty space: Excluded (Size Filter) 2025/04/29 02:59:54 DEBUG : empty space: Excluded 2025/04/29 02:59:54 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/29 02:59:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ziyusum2ralu': Waiting for checks to finish 2025/04/29 02:59:54 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/29 02:59:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ziyusum2ralu': Waiting for transfers to finish 2025/04/29 02:59:54 INFO : potato3: Deleted 2025/04/29 02:59:54 INFO : potato2: Moved (server-side) 2025/04/29 02:59:55 INFO : potato3: Moved (server-side) 2025/04/29 02:59:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wizaqis4suve" 2025/04/29 02:59:55 DEBUG : Creating backend with remote "TestDrive:crypt/9aep9lf362simamfoelmft21lmmu3gf2rka75t3a0rikefgiffm0" 2025/04/29 02:59:56 DEBUG : empty space: Excluded (Size Filter) 2025/04/29 02:59:56 DEBUG : empty space: Excluded 2025/04/29 02:59:56 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/29 02:59:56 DEBUG : potato3: Need to transfer - File not found at Destination 2025/04/29 02:59:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wizaqis4suve': Waiting for checks to finish 2025/04/29 02:59:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wizaqis4suve': Waiting for transfers to finish 2025/04/29 02:59:58 INFO : potato3: Moved (server-side) 2025/04/29 02:59:58 INFO : potato2: Moved (server-side) 2025/04/29 02:59:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wizaqis4suve': Purge remote 2025/04/29 02:59:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ziyusum2ralu': Purge remote --- PASS: TestServerSideMoveWithFilter (15.94s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:00:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-koyuhes3gere" 2025/04/29 03:00:00 DEBUG : Creating backend with remote "TestDrive:crypt/dkljv0t51me6gake7l265nat7tugpkg1u1qqsijf14fe29h2qpq0" 2025/04/29 03:00:03 DEBUG : potato2: md5 = c44d30950b80b5454d5585ba19aa7663 OK 2025/04/29 03:00:04 DEBUG : empty space: md5 = cac20c46f0fdb002302f1a6e58f42d19 OK 2025/04/29 03:00:05 DEBUG : potato3: md5 = 75d6e36685c4c9985bfa21d95a087270 OK 2025/04/29 03:00:05 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date' -> Encrypted drive 'TestCryptDrive:rclone-test-koyuhes3gere' 2025/04/29 03:00:09 DEBUG : empty space: md5 = 5843e2adaacecdf17555db525745e14b OK 2025/04/29 03:00:10 DEBUG : potato3: md5 = 121daab46bea9ad8195ae2038bbb03d5 OK 2025/04/29 03:00:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-koyuhes3gere': Using server-side directory move 2025/04/29 03:00:10 INFO : Encrypted drive 'TestCryptDrive:rclone-test-koyuhes3gere': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/29 03:00:11 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/29 03:00:11 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/04/29 03:00:11 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/29 03:00:11 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/04/29 03:00:11 DEBUG : empty space: Unchanged skipping 2025/04/29 03:00:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-koyuhes3gere': Waiting for checks to finish 2025/04/29 03:00:11 INFO : empty space: Deleted 2025/04/29 03:00:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-koyuhes3gere': Waiting for transfers to finish 2025/04/29 03:00:11 INFO : potato3: Deleted 2025/04/29 03:00:11 INFO : potato2: Moved (server-side) 2025/04/29 03:00:12 INFO : potato3: Moved (server-side) 2025/04/29 03:00:12 INFO : tomatoDir: Removing directory 2025/04/29 03:00:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': deleted 1 directories 2025/04/29 03:00:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lomojap7nuke" 2025/04/29 03:00:13 DEBUG : Creating backend with remote "TestDrive:crypt/oimktmh9ro6ddoeenlpsdcu7g6hshr45nc8r3758f7gv8gj1svh0" 2025/04/29 03:00:14 INFO : tomatoDir: Making directory 2025/04/29 03:00:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lomojap7nuke': Using server-side directory move 2025/04/29 03:00:16 INFO : Encrypted drive 'TestCryptDrive:rclone-test-lomojap7nuke': Server side directory move succeeded 2025/04/29 03:00:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lomojap7nuke': Purge remote 2025/04/29 03:00:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-koyuhes3gere': Purge remote 2025/04/29 03:00:18 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (17.91s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.40s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:00:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/rclone-sync-test" 2025/04/29 03:00:19 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncOverlap (3.69s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:00:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/rclone-sync-test" 2025/04/29 03:00:22 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/04/29 03:00:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/rclone-sync-test-include/layer2" 2025/04/29 03:00:25 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/04/29 03:00:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/rclone-sync-test-ignore-file" 2025/04/29 03:00:27 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/04/29 03:00:31 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = ceafa37172cb4105f6db77cf902a3d61 OK 2025/04/29 03:00:32 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/04/29 03:00:33 DEBUG : rclone-sync-test: Excluded 2025/04/29 03:00:33 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/29 03:00:33 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/04/29 03:00:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/rclone-sync-test': Waiting for checks to finish 2025/04/29 03:00:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/rclone-sync-test': Waiting for transfers to finish 2025/04/29 03:00:33 DEBUG : Waiting for deletions to finish 2025/04/29 03:00:33 INFO : There was nothing to transfer 2025/04/29 03:00:34 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/04/29 03:00:34 DEBUG : rclone-sync-test: Excluded 2025/04/29 03:00:35 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/04/29 03:00:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 03:00:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 03:00:35 DEBUG : Waiting for deletions to finish 2025/04/29 03:00:35 INFO : rclone-sync-test-include: Removing directory 2025/04/29 03:00:35 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/29 03:00:35 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/04/29 03:00:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': failed to delete 1 directories 2025/04/29 03:00:35 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:00:36 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/04/29 03:00:36 DEBUG : rclone-sync-test: Excluded 2025/04/29 03:00:36 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/29 03:00:36 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/04/29 03:00:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/04/29 03:00:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/04/29 03:00:36 DEBUG : Waiting for deletions to finish 2025/04/29 03:00:36 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:00:37 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/04/29 03:00:38 DEBUG : rclone-sync-test: Excluded 2025/04/29 03:00:38 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/04/29 03:00:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 03:00:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 03:00:38 DEBUG : Waiting for deletions to finish 2025/04/29 03:00:38 INFO : rclone-sync-test-include: Removing directory 2025/04/29 03:00:38 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/29 03:00:38 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/04/29 03:00:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': failed to delete 1 directories 2025/04/29 03:00:38 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:00:39 DEBUG : : Excluded 2025/04/29 03:00:39 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/04/29 03:00:39 DEBUG : rclone-sync-test: Excluded 2025/04/29 03:00:39 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/29 03:00:40 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/04/29 03:00:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/04/29 03:00:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/04/29 03:00:40 DEBUG : Waiting for deletions to finish 2025/04/29 03:00:40 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:00:42 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/29 03:00:43 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (29.13s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:00:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/dst" 2025/04/29 03:00:51 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/29 03:00:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/CompareDest" 2025/04/29 03:00:53 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/gveqi14airsml4bgu7krj116o8" 2025/04/29 03:00:55 DEBUG : one: Need to transfer - File not found at Destination 2025/04/29 03:00:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for checks to finish 2025/04/29 03:00:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for transfers to finish 2025/04/29 03:00:57 DEBUG : one: md5 = c1cd7bbc7304c36cca500eddc3747aed OK 2025/04/29 03:00:57 INFO : one: Copied (new) 2025/04/29 03:00:57 DEBUG : Waiting for deletions to finish 2025/04/29 03:00:58 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/29 03:00:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for checks to finish 2025/04/29 03:00:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for transfers to finish 2025/04/29 03:00:59 DEBUG : one: md5 = b6ce65bbaef4c4a6260689a306528b51 OK 2025/04/29 03:00:59 INFO : one: Copied (replaced existing) 2025/04/29 03:00:59 DEBUG : Waiting for deletions to finish 2025/04/29 03:01:02 DEBUG : dst/one: md5 = 7c6e4ec80326ac85d2f21e8d3709a3d0 OK 2025/04/29 03:01:04 DEBUG : CompareDest/one: md5 = 2681503e49d3b7e3d12c9fd679534dc2 OK 2025/04/29 03:01:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for checks to finish 2025/04/29 03:01:04 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/29 03:01:05 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 03:01:05 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/29 03:01:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for transfers to finish 2025/04/29 03:01:05 DEBUG : Waiting for deletions to finish 2025/04/29 03:01:05 INFO : There was nothing to transfer 2025/04/29 03:01:07 DEBUG : CompareDest/two: md5 = ae629b623ae991a381f5eb4b9a3265bf OK 2025/04/29 03:01:07 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/29 03:01:08 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 03:01:08 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/29 03:01:08 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 03:01:08 DEBUG : two: Destination found in --compare-dest, skipping 2025/04/29 03:01:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for checks to finish 2025/04/29 03:01:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for transfers to finish 2025/04/29 03:01:08 DEBUG : Waiting for deletions to finish 2025/04/29 03:01:08 INFO : There was nothing to transfer 2025/04/29 03:01:08 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/29 03:01:09 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 03:01:09 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/29 03:01:09 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 03:01:09 DEBUG : two: Destination found in --compare-dest, skipping 2025/04/29 03:01:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for checks to finish 2025/04/29 03:01:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for transfers to finish 2025/04/29 03:01:09 DEBUG : Waiting for deletions to finish 2025/04/29 03:01:09 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/04/29 03:01:10 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/29 03:01:10 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/04/29 03:01:10 DEBUG : two: Need to transfer - File not found at Destination 2025/04/29 03:01:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for checks to finish 2025/04/29 03:01:10 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 03:01:10 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/29 03:01:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for transfers to finish 2025/04/29 03:01:11 DEBUG : two: md5 = e3f185d6aa98190b05b4be10c56edaed OK 2025/04/29 03:01:11 INFO : two: Copied (new) 2025/04/29 03:01:11 DEBUG : Waiting for deletions to finish 2025/04/29 03:01:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/29 03:01:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/29 03:01:15 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/29 03:01:15 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCompareDest (24.37s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:01:18 DEBUG : pre-dest1/1: md5 = c2a44a5c41870bb4eae9c3c4669b4be7 OK 2025/04/29 03:01:20 DEBUG : pre-dest2/2: md5 = 86bd7344f3156b636d4d67a0d72d4c5d OK 2025/04/29 03:01:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/dest" 2025/04/29 03:01:21 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/rg03c1jvnehrrc617i0lnqjddc" 2025/04/29 03:01:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/pre-dest1" 2025/04/29 03:01:22 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/bbnblvh6k061ssopqrp18kd7gc" 2025/04/29 03:01:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/pre-dest2" 2025/04/29 03:01:23 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/dgicm1h6b5ejvlltm8eeif0bnk" 2025/04/29 03:01:24 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:01:24 DEBUG : 1: Destination found in --compare-dest, skipping 2025/04/29 03:01:25 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:01:25 DEBUG : 2: Destination found in --compare-dest, skipping 2025/04/29 03:01:25 DEBUG : 3: Need to transfer - File not found at Destination 2025/04/29 03:01:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dest': Waiting for checks to finish 2025/04/29 03:01:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dest': Waiting for transfers to finish 2025/04/29 03:01:27 DEBUG : 3: md5 = b8ef2abc73bb6017127ea2c8fb8768e1 OK 2025/04/29 03:01:27 INFO : 3: Copied (new) 2025/04/29 03:01:27 DEBUG : Waiting for deletions to finish 2025/04/29 03:01:30 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/04/29 03:01:31 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/04/29 03:01:32 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (16.55s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:01:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/dst" 2025/04/29 03:01:32 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/29 03:01:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/CopyDest" 2025/04/29 03:01:34 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/d09o6po3f7bm6ce32vdgs8h9ls" 2025/04/29 03:01:36 DEBUG : one: Need to transfer - File not found at Destination 2025/04/29 03:01:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for checks to finish 2025/04/29 03:01:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for transfers to finish 2025/04/29 03:01:38 DEBUG : one: md5 = 480c9bf23a5a91e222669bb7e95e912c OK 2025/04/29 03:01:38 INFO : one: Copied (new) 2025/04/29 03:01:38 DEBUG : Waiting for deletions to finish 2025/04/29 03:01:39 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/29 03:01:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for checks to finish 2025/04/29 03:01:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for transfers to finish 2025/04/29 03:01:40 DEBUG : one: md5 = 115f877e6d164b4cd4440ccbd57fff50 OK 2025/04/29 03:01:40 INFO : one: Copied (replaced existing) 2025/04/29 03:01:40 DEBUG : Waiting for deletions to finish 2025/04/29 03:01:42 DEBUG : dst/one: md5 = 9a03f0beb55e8929e50f0a309aec3205 OK 2025/04/29 03:01:44 DEBUG : CopyDest/one: md5 = 28be20e40a4a9e254aad95485f076dae OK 2025/04/29 03:01:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/BackupDir" 2025/04/29 03:01:45 DEBUG : Config file has changed externally - reloading 2025/04/29 03:01:45 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/04/29 03:01:47 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/29 03:01:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for checks to finish 2025/04/29 03:01:47 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 03:01:47 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/29 03:01:49 INFO : one: Moved (server-side) 2025/04/29 03:01:50 INFO : one: Copied (server-side copy) 2025/04/29 03:01:50 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/04/29 03:01:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for transfers to finish 2025/04/29 03:01:50 DEBUG : Waiting for deletions to finish 2025/04/29 03:01:52 DEBUG : CopyDest/two: md5 = c3ea784f89048bcdbd251e3cfc7f71a7 OK 2025/04/29 03:01:52 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 03:01:52 DEBUG : one: Unchanged skipping 2025/04/29 03:01:52 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 03:01:53 INFO : two: Copied (server-side copy) 2025/04/29 03:01:53 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/04/29 03:01:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for checks to finish 2025/04/29 03:01:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for transfers to finish 2025/04/29 03:01:53 DEBUG : Waiting for deletions to finish 2025/04/29 03:01:54 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 03:01:54 DEBUG : one: Unchanged skipping 2025/04/29 03:01:54 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 03:01:54 DEBUG : two: Unchanged skipping 2025/04/29 03:01:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for checks to finish 2025/04/29 03:01:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for transfers to finish 2025/04/29 03:01:54 DEBUG : Waiting for deletions to finish 2025/04/29 03:01:54 INFO : There was nothing to transfer 2025/04/29 03:01:56 DEBUG : CopyDest/three: md5 = faa520e848c8e29da26360adc3304abb OK 2025/04/29 03:01:57 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 03:01:57 DEBUG : one: Unchanged skipping 2025/04/29 03:01:57 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/04/29 03:01:57 DEBUG : three: Destination not found in --copy-dest 2025/04/29 03:01:57 DEBUG : three: Need to transfer - File not found at Destination 2025/04/29 03:01:57 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/29 03:01:57 DEBUG : two: Unchanged skipping 2025/04/29 03:01:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for checks to finish 2025/04/29 03:01:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for transfers to finish 2025/04/29 03:01:58 DEBUG : three: md5 = 36dc153692aed90c814d63f08c0b0c6b OK 2025/04/29 03:01:58 INFO : three: Copied (new) 2025/04/29 03:01:58 DEBUG : Waiting for deletions to finish 2025/04/29 03:02:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/04/29 03:02:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/29 03:02:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/29 03:02:04 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/29 03:02:04 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/29 03:02:04 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/04/29 03:02:04 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (32.93s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:02:08 DEBUG : dst/one: md5 = d91c79476a03de63ed87f085d310b65d OK 2025/04/29 03:02:09 DEBUG : dst/two: md5 = aaf2f3f16971e5b27e0eb9217e43ca58 OK 2025/04/29 03:02:11 DEBUG : dst/three.txt: md5 = 88df54459743fdac45cf721ead15290e OK 2025/04/29 03:02:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/dst" 2025/04/29 03:02:11 DEBUG : Config file has changed externally - reloading 2025/04/29 03:02:11 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/29 03:02:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/backup" 2025/04/29 03:02:12 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/1nrff024r7pq65ecp72fc28jb0" 2025/04/29 03:02:14 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/29 03:02:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for checks to finish 2025/04/29 03:02:14 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:02:14 DEBUG : two: Unchanged skipping 2025/04/29 03:02:15 INFO : one: Moved (server-side) 2025/04/29 03:02:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for transfers to finish 2025/04/29 03:02:16 DEBUG : one: md5 = 0e5a2b72e5bde989b470e05833972754 OK 2025/04/29 03:02:16 INFO : one: Copied (new) 2025/04/29 03:02:16 DEBUG : Waiting for deletions to finish 2025/04/29 03:02:17 INFO : three.txt: Moved (server-side) 2025/04/29 03:02:17 INFO : three.txt: Moved into backup dir 2025/04/29 03:02:19 DEBUG : dst/three.txt: md5 = e97b08d8ca07a8a3c547f9154eaa2792 OK 2025/04/29 03:02:20 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/29 03:02:20 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:02:20 DEBUG : two: Unchanged skipping 2025/04/29 03:02:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for checks to finish 2025/04/29 03:02:20 INFO : one: Deleted 2025/04/29 03:02:21 INFO : one: Moved (server-side) 2025/04/29 03:02:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for transfers to finish 2025/04/29 03:02:22 DEBUG : one: md5 = be4cb8a973c7ef11b67c50b5c6d9c856 OK 2025/04/29 03:02:22 INFO : one: Copied (new) 2025/04/29 03:02:22 DEBUG : Waiting for deletions to finish 2025/04/29 03:02:23 INFO : three.txt: Deleted 2025/04/29 03:02:24 INFO : three.txt: Moved (server-side) 2025/04/29 03:02:24 INFO : three.txt: Moved into backup dir 2025/04/29 03:02:27 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/29 03:02:27 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/29 03:02:27 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/29 03:02:27 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/29 03:02:27 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/29 03:02:27 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncBackupDir (22.86s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:02:30 DEBUG : dst/one: md5 = 7926ee98ab4c1f5c0f9c89b889823e8b OK 2025/04/29 03:02:31 DEBUG : dst/two: md5 = f500f63cb041c202d9404d98b986fea3 OK 2025/04/29 03:02:33 DEBUG : dst/three.txt: md5 = 4cfac56d6b707cf9afe009e902f7e85e OK 2025/04/29 03:02:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/dst" 2025/04/29 03:02:33 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/29 03:02:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/backup" 2025/04/29 03:02:34 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/1nrff024r7pq65ecp72fc28jb0" 2025/04/29 03:02:36 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/29 03:02:36 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:02:36 DEBUG : two: Unchanged skipping 2025/04/29 03:02:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for checks to finish 2025/04/29 03:02:37 INFO : one: Moved (server-side) to: one.bak 2025/04/29 03:02:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for transfers to finish 2025/04/29 03:02:38 DEBUG : one: md5 = bcead039782183ea0a9123e23b00c2ea OK 2025/04/29 03:02:38 INFO : one: Copied (new) 2025/04/29 03:02:38 DEBUG : Waiting for deletions to finish 2025/04/29 03:02:39 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/29 03:02:39 INFO : three.txt: Moved into backup dir 2025/04/29 03:02:41 DEBUG : dst/three.txt: md5 = b05000ac38a1701481190335f2b39426 OK 2025/04/29 03:02:42 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/29 03:02:42 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:02:42 DEBUG : two: Unchanged skipping 2025/04/29 03:02:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for checks to finish 2025/04/29 03:02:43 INFO : one.bak: Deleted 2025/04/29 03:02:43 INFO : one: Moved (server-side) to: one.bak 2025/04/29 03:02:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for transfers to finish 2025/04/29 03:02:44 DEBUG : one: md5 = 4c17a555b1fdc1395f8c9837bf9119ff OK 2025/04/29 03:02:44 INFO : one: Copied (new) 2025/04/29 03:02:44 DEBUG : Waiting for deletions to finish 2025/04/29 03:02:45 INFO : three.txt.bak: Deleted 2025/04/29 03:02:46 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/29 03:02:46 INFO : three.txt: Moved into backup dir 2025/04/29 03:02:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/29 03:02:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/29 03:02:49 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/29 03:02:49 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/29 03:02:49 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/29 03:02:49 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirWithSuffix (22.00s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:02:53 DEBUG : dst/one: md5 = 746acd4b6cdb0d70839d93dc74f1eaa3 OK 2025/04/29 03:02:54 DEBUG : dst/two: md5 = 32ac55e9ef9b532c135e7f4c5daa6eb4 OK 2025/04/29 03:02:55 DEBUG : dst/three.txt: md5 = 184387c60e4068a16673f26aadde26df OK 2025/04/29 03:02:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/dst" 2025/04/29 03:02:56 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/29 03:02:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/backup" 2025/04/29 03:02:57 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/1nrff024r7pq65ecp72fc28jb0" 2025/04/29 03:02:58 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/29 03:02:58 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:02:58 DEBUG : two: Unchanged skipping 2025/04/29 03:02:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for checks to finish 2025/04/29 03:03:00 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/29 03:03:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for transfers to finish 2025/04/29 03:03:01 DEBUG : one: md5 = 143ba55cf350c39eb929f21a53af4eb6 OK 2025/04/29 03:03:01 INFO : one: Copied (new) 2025/04/29 03:03:01 DEBUG : Waiting for deletions to finish 2025/04/29 03:03:02 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/29 03:03:02 INFO : three.txt: Moved into backup dir 2025/04/29 03:03:04 DEBUG : dst/three.txt: md5 = 95035ef69c4e4fca69837de407e8dd78 OK 2025/04/29 03:03:05 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/29 03:03:05 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:03:05 DEBUG : two: Unchanged skipping 2025/04/29 03:03:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for checks to finish 2025/04/29 03:03:05 INFO : one-2019-01-01: Deleted 2025/04/29 03:03:06 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/29 03:03:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for transfers to finish 2025/04/29 03:03:07 DEBUG : one: md5 = 51b7b9843a627db060eba37104c300e6 OK 2025/04/29 03:03:07 INFO : one: Copied (new) 2025/04/29 03:03:07 DEBUG : Waiting for deletions to finish 2025/04/29 03:03:08 INFO : three-2019-01-01.txt: Deleted 2025/04/29 03:03:08 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/29 03:03:08 INFO : three.txt: Moved into backup dir 2025/04/29 03:03:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/29 03:03:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/29 03:03:12 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/29 03:03:12 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/29 03:03:12 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/29 03:03:12 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (22.79s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:03:15 DEBUG : dst/one: md5 = 740ce7a63b9d291d824f592136c2aff9 OK 2025/04/29 03:03:16 DEBUG : dst/two: md5 = 4a29adde0dca8bbace5267d8acdd87c3 OK 2025/04/29 03:03:17 DEBUG : dst/three.txt: md5 = 97fcaffd8f59feee4bb03cb08985e6e5 OK 2025/04/29 03:03:18 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/dst" 2025/04/29 03:03:18 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/29 03:03:19 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/29 03:03:19 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:03:19 DEBUG : two: Unchanged skipping 2025/04/29 03:03:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for checks to finish 2025/04/29 03:03:20 INFO : one: Moved (server-side) to: one.bak 2025/04/29 03:03:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for transfers to finish 2025/04/29 03:03:21 DEBUG : one: md5 = fdc59e010755850c95e7d280753bf863 OK 2025/04/29 03:03:21 INFO : one: Copied (new) 2025/04/29 03:03:21 DEBUG : Waiting for deletions to finish 2025/04/29 03:03:22 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/29 03:03:22 INFO : three.txt: Moved into backup dir 2025/04/29 03:03:23 DEBUG : dst/three.txt: md5 = ad4ceca403d7caab6b8983df656819fe OK 2025/04/29 03:03:24 DEBUG : one.bak: Excluded (Path Filter) 2025/04/29 03:03:24 DEBUG : one.bak: Excluded 2025/04/29 03:03:24 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/04/29 03:03:24 DEBUG : three.txt.bak: Excluded 2025/04/29 03:03:24 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/29 03:03:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for checks to finish 2025/04/29 03:03:24 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:03:24 DEBUG : two: Unchanged skipping 2025/04/29 03:03:25 INFO : one.bak: Deleted 2025/04/29 03:03:25 INFO : one: Moved (server-side) to: one.bak 2025/04/29 03:03:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date/dst': Waiting for transfers to finish 2025/04/29 03:03:27 DEBUG : one: md5 = a4ab620eaebb3cd52736576f38c555d1 OK 2025/04/29 03:03:27 INFO : one: Copied (new) 2025/04/29 03:03:27 DEBUG : Waiting for deletions to finish 2025/04/29 03:03:27 INFO : three.txt.bak: Deleted 2025/04/29 03:03:28 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/29 03:03:28 INFO : three.txt: Moved into backup dir 2025/04/29 03:03:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/29 03:03:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/29 03:03:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/29 03:03:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/29 03:03:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/29 03:03:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirSuffixOnly (18.91s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:03:34 DEBUG : dst/one: md5 = 88e5dccb902614b98fc1dae5537e8907 OK 2025/04/29 03:03:35 DEBUG : dst/two: md5 = 214b824432877dc60d068777a81752cb OK 2025/04/29 03:03:36 DEBUG : dst/three.txt: md5 = 21ae1b6b72321746dc090fbfc9f72f66 OK 2025/04/29 03:03:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/dst" 2025/04/29 03:03:37 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/29 03:03:38 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/29 03:03:39 INFO : one: Moved (server-side) to: one.bak 2025/04/29 03:03:40 DEBUG : one: md5 = 815817b68c1c4c6450d42fb325d4c546 OK 2025/04/29 03:03:40 INFO : one: Copied (new) 2025/04/29 03:03:40 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:03:40 DEBUG : two: Unchanged skipping 2025/04/29 03:03:41 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/04/29 03:03:41 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/29 03:03:43 DEBUG : three.txt: md5 = b5e28a480a682abaa6c14fe88cf83c15 OK 2025/04/29 03:03:43 INFO : three.txt: Copied (new) 2025/04/29 03:03:44 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/29 03:03:45 INFO : one.bak: Deleted 2025/04/29 03:03:45 INFO : one: Moved (server-side) to: one.bak 2025/04/29 03:03:47 DEBUG : one: md5 = 64d8295b0ea4bd6d3c7abcf8f07f9f1d OK 2025/04/29 03:03:47 INFO : one: Copied (new) 2025/04/29 03:03:47 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:03:47 DEBUG : two: Unchanged skipping 2025/04/29 03:03:47 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/04/29 03:03:48 INFO : three.txt.bak: Deleted 2025/04/29 03:03:48 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/29 03:03:50 DEBUG : three.txt: md5 = a2ae2135d74e65079ed34fe662acbfec OK 2025/04/29 03:03:50 INFO : three.txt: Copied (new) 2025/04/29 03:03:53 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/29 03:03:53 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/29 03:03:53 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/29 03:03:53 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/29 03:03:53 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/29 03:03:53 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/29 03:03:53 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncSuffix (22.00s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:03:56 DEBUG : dst/one: md5 = 906d31656ca5c21b22640ee09e520c08 OK 2025/04/29 03:03:57 DEBUG : dst/two: md5 = 9ac31948db347d2b2c413af6ed4b4a31 OK 2025/04/29 03:03:59 DEBUG : dst/three.txt: md5 = bcd2ed6bd4777fde2d5c245d073afd1f OK 2025/04/29 03:03:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mavayew0date/dst" 2025/04/29 03:03:59 DEBUG : Creating backend with remote "TestDrive:crypt/5jaq268ov9345h5ttphdocnhnu4uikl7d35j5slo3icg7k51ek90/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/29 03:04:00 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/29 03:04:01 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/29 03:04:02 DEBUG : one: md5 = 9c09d910431f792e54bd94b532788028 OK 2025/04/29 03:04:02 INFO : one: Copied (new) 2025/04/29 03:04:03 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:04:03 DEBUG : two: Unchanged skipping 2025/04/29 03:04:03 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/04/29 03:04:04 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/29 03:04:05 DEBUG : three.txt: md5 = 93a70c51a944ffc068a38bf878f680ce OK 2025/04/29 03:04:05 INFO : three.txt: Copied (new) 2025/04/29 03:04:06 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/29 03:04:07 INFO : one-2019-01-01: Deleted 2025/04/29 03:04:07 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/29 03:04:09 DEBUG : one: md5 = 3a81d560763db842bd728685d7a68583 OK 2025/04/29 03:04:09 INFO : one: Copied (new) 2025/04/29 03:04:09 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:04:09 DEBUG : two: Unchanged skipping 2025/04/29 03:04:09 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/04/29 03:04:10 INFO : three-2019-01-01.txt: Deleted 2025/04/29 03:04:10 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/29 03:04:12 DEBUG : three.txt: md5 = eaef38025c61ce31f28de32375fbda5b OK 2025/04/29 03:04:12 INFO : three.txt: Copied (new) 2025/04/29 03:04:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/29 03:04:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/29 03:04:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/29 03:04:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/29 03:04:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/29 03:04:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/29 03:04:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncSuffixKeepExtension (22.14s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:04:17 DEBUG : Testêé: md5 = 672476fea678a941d36ab8d0f160da97 OK 2025/04/29 03:04:18 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/04/29 03:04:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 03:04:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 03:04:19 DEBUG : Testêé: md5 = 662d37b56e47cd07cf8dfe4ff81ac6ad OK 2025/04/29 03:04:19 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/04/29 03:04:19 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.19s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:04:20 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/29 03:04:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 03:04:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 03:04:22 DEBUG : existing: md5 = e98a2521632e510d425091d9ddc76525 OK 2025/04/29 03:04:22 INFO : existing: Copied (new) 2025/04/29 03:04:22 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:04:23 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/04/29 03:04:23 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/04/29 03:04:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 03:04:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 03:04:23 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': not deleting files as there were IO errors 2025/04/29 03:04:23 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncImmutable (4.57s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:04:26 DEBUG : EXISTING: md5 = 4e01638cc29a689fb63cddf4520c2e93 OK 2025/04/29 03:04:27 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:04:27 DEBUG : existing: Unchanged skipping 2025/04/29 03:04:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 03:04:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 03:04:27 DEBUG : Waiting for deletions to finish 2025/04/29 03:04:27 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (3.18s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", 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-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", 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-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", 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-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.31s) --- SKIP: TestMaxTransfer/Hard (0.46s) --- SKIP: TestMaxTransfer/Soft (0.44s) --- SKIP: TestMaxTransfer/Cautious (0.41s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:04:31 DEBUG : both0: md5 = 01108775a1ca3640df4272dda83a7dca OK 2025/04/29 03:04:32 DEBUG : only0: md5 = 85c91c11adfa9158af6c3ff4a5bbd521 OK 2025/04/29 03:04:34 DEBUG : both1: md5 = a51bf0cbaad5594ac0e42cc6a2c89953 OK 2025/04/29 03:04:35 DEBUG : only1: md5 = 1938e172db57de03f35acc82ced1455d OK 2025/04/29 03:04:36 DEBUG : both2: md5 = 409d169952f4dca47f8430e4826afc4e OK 2025/04/29 03:04:38 DEBUG : only2: md5 = f8fc682c9c2bbeb6fdcc778b4ff26853 OK 2025/04/29 03:04:39 DEBUG : both3: md5 = de8517efab7c534d2440da7da9b11664 OK 2025/04/29 03:04:40 DEBUG : only3: md5 = 0038056ed6e8d5843312a0b97a9788a7 OK 2025/04/29 03:04:42 DEBUG : both4: md5 = 860b4599e0a158c84775880ee51921ad OK 2025/04/29 03:04:43 DEBUG : only4: md5 = 1652f61fe9404151719e79f4b2df843b OK 2025/04/29 03:04:44 DEBUG : both5: md5 = 15d41d668c26def532378104c964d164 OK 2025/04/29 03:04:46 DEBUG : only5: md5 = ce06b660726574838a82d2308371a334 OK 2025/04/29 03:04:47 DEBUG : both6: md5 = 5c32dde14ebdea95b2498b95ee9348e9 OK 2025/04/29 03:04:48 DEBUG : only6: md5 = a1bde346323b3893399a4ec49186ccf6 OK 2025/04/29 03:04:50 DEBUG : both7: md5 = 97493a143a6316f982de4d38ea5094a8 OK 2025/04/29 03:04:51 DEBUG : only7: md5 = 5d3831a66c954a98f489ca93be6dff0e OK 2025/04/29 03:04:52 DEBUG : both8: md5 = 0aab95f97ef90d40849357d39055752e OK 2025/04/29 03:04:54 DEBUG : only8: md5 = b7d9a98f751ba3b115d63993cc17d90e OK 2025/04/29 03:04:55 DEBUG : both9: md5 = d98c8b6a3df70a1c69cf6bb7231f06bd OK 2025/04/29 03:04:56 DEBUG : only9: md5 = 08989b25d769a24047b9ce37055c316b OK 2025/04/29 03:04:58 DEBUG : both10: md5 = 4590b2133493218f67fcd787414d0786 OK 2025/04/29 03:04:59 DEBUG : only10: md5 = 3d347e233a14c411dc4c3ab03222efc1 OK 2025/04/29 03:05:00 DEBUG : both11: md5 = 6a57d837d1825b8c62a9a6d994ef40d0 OK 2025/04/29 03:05:02 DEBUG : only11: md5 = 4d130ba632950f9efbf9c9d6253e8d00 OK 2025/04/29 03:05:03 DEBUG : both12: md5 = 106f29195010dadb8e8f69a2b7d42d83 OK 2025/04/29 03:05:04 DEBUG : only12: md5 = c1dda3663405999d41302f0f176fa4e6 OK 2025/04/29 03:05:06 DEBUG : both13: md5 = 5f4a877ee9f5f0dcfc9467e57d2ea2d5 OK 2025/04/29 03:05:07 DEBUG : only13: md5 = eb976779251c49c7d30a50f17d37e4dc OK 2025/04/29 03:05:08 DEBUG : both14: md5 = 4c1034def6f1a55b8bd095c66e1b32db OK 2025/04/29 03:05:10 DEBUG : only14: md5 = 7c1d07b3fe3340d23f308f62c67d0b7e OK 2025/04/29 03:05:11 DEBUG : both15: md5 = 170560aab7e4379914067f61a0d68265 OK 2025/04/29 03:05:12 DEBUG : only15: md5 = 59f059c9b3516cce5d319f443bf5b1e1 OK 2025/04/29 03:05:14 DEBUG : both16: md5 = 0d681175d13af175667a2c9acb871fa7 OK 2025/04/29 03:05:15 DEBUG : only16: md5 = f727c0b63775292bb4cd21f42976a0cd OK 2025/04/29 03:05:16 DEBUG : both17: md5 = 19e0b4ddb2018f205ea999b0e1dd1d56 OK 2025/04/29 03:05:18 DEBUG : only17: md5 = 741e258fa6c76524d280c4109049c2e8 OK 2025/04/29 03:05:19 DEBUG : both18: md5 = 15268e1181e9024ad9a5e8f661c15829 OK 2025/04/29 03:05:20 DEBUG : only18: md5 = d69f34b8dd964848f3dba0a3df7b49f5 OK 2025/04/29 03:05:22 DEBUG : both19: md5 = d3b33f630d87a7907ef8c5994bce3b6f OK 2025/04/29 03:05:23 DEBUG : only19: md5 = b396f14d36e32e12a44cb4b0f68b7cf2 OK 2025/04/29 03:05:24 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:05:24 DEBUG : both0: Unchanged skipping 2025/04/29 03:05:24 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:05:24 DEBUG : both1: Unchanged skipping 2025/04/29 03:05:24 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:05:24 DEBUG : both10: Unchanged skipping 2025/04/29 03:05:24 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:05:24 DEBUG : both11: Unchanged skipping 2025/04/29 03:05:24 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:05:24 DEBUG : both12: Unchanged skipping 2025/04/29 03:05:24 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:05:24 DEBUG : both13: Unchanged skipping 2025/04/29 03:05:24 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:05:24 DEBUG : both14: Unchanged skipping 2025/04/29 03:05:24 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:05:24 DEBUG : both15: Unchanged skipping 2025/04/29 03:05:24 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:05:24 DEBUG : both16: Unchanged skipping 2025/04/29 03:05:24 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:05:24 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:05:24 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:05:24 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:05:24 DEBUG : both17: Unchanged skipping 2025/04/29 03:05:24 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:05:24 DEBUG : both3: Unchanged skipping 2025/04/29 03:05:24 DEBUG : both18: Unchanged skipping 2025/04/29 03:05:24 DEBUG : both19: Unchanged skipping 2025/04/29 03:05:24 DEBUG : both2: Unchanged skipping 2025/04/29 03:05:24 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:05:24 DEBUG : both4: Unchanged skipping 2025/04/29 03:05:24 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:05:24 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:05:24 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:05:24 DEBUG : both5: Unchanged skipping 2025/04/29 03:05:24 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:05:24 DEBUG : both8: Unchanged skipping 2025/04/29 03:05:24 DEBUG : both6: Unchanged skipping 2025/04/29 03:05:24 DEBUG : both7: Unchanged skipping 2025/04/29 03:05:24 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:05:24 DEBUG : both9: Unchanged skipping 2025/04/29 03:05:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 03:05:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 03:05:24 DEBUG : Waiting for deletions to finish 2025/04/29 03:05:24 INFO : only2: Deleted 2025/04/29 03:05:24 INFO : only5: Deleted 2025/04/29 03:05:24 INFO : only13: Deleted 2025/04/29 03:05:24 INFO : only4: Deleted 2025/04/29 03:05:24 INFO : only12: Deleted 2025/04/29 03:05:24 INFO : only0: Deleted 2025/04/29 03:05:24 INFO : only16: Deleted 2025/04/29 03:05:25 INFO : only18: Deleted 2025/04/29 03:05:25 INFO : only3: Deleted 2025/04/29 03:05:25 INFO : only10: Deleted 2025/04/29 03:05:25 INFO : only1: Deleted 2025/04/29 03:05:25 INFO : only15: Deleted 2025/04/29 03:05:25 INFO : only17: Deleted 2025/04/29 03:05:25 INFO : only11: Deleted 2025/04/29 03:05:25 INFO : only14: Deleted 2025/04/29 03:05:25 INFO : only19: Deleted 2025/04/29 03:05:26 INFO : only6: Deleted 2025/04/29 03:05:26 INFO : only7: Deleted 2025/04/29 03:05:26 INFO : only8: Deleted 2025/04/29 03:05:26 INFO : only9: Deleted 2025/04/29 03:05:26 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (66.60s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:05:38 DEBUG : both0: md5 = bfd64a2b257ac50bb0a60e59d5ccb984 OK 2025/04/29 03:05:39 DEBUG : only0: md5 = 1da8d89e4010b4f67e6e85f5d66b2051 OK 2025/04/29 03:05:40 DEBUG : both1: md5 = 453aff5e8a15e515589a8b797e0c99df OK 2025/04/29 03:05:42 DEBUG : only1: md5 = b4e786cb42e4704db15286ee10fa2b1d OK 2025/04/29 03:05:43 DEBUG : both2: md5 = 38912aa981e0c7f4c4915cd6e061582c OK 2025/04/29 03:05:44 DEBUG : only2: md5 = 523c60e244a3105b45791574c5394bbf OK 2025/04/29 03:05:45 DEBUG : both3: md5 = 3b10bfedb79666199b7868bf2c16ebdc OK 2025/04/29 03:05:47 DEBUG : only3: md5 = 0854d81f5dc0605162fcb73ce38db13a OK 2025/04/29 03:05:48 DEBUG : both4: md5 = 08b2ace70979c9616170578aea3a7d18 OK 2025/04/29 03:05:49 DEBUG : only4: md5 = b45ac6c0c47534272a1cf9d65b25ea4a OK 2025/04/29 03:05:51 DEBUG : both5: md5 = ca3caf2f0e5cd1bc0a1a040ece3d6a62 OK 2025/04/29 03:05:52 DEBUG : only5: md5 = 13cffeb1de3a44e4a82baa92ba50adf0 OK 2025/04/29 03:05:54 DEBUG : both6: md5 = 2f0450d6aca5c8797e66289d3050ac4c OK 2025/04/29 03:05:55 DEBUG : only6: md5 = 957fa20892d5b39687f40a3ed781e4e8 OK 2025/04/29 03:05:56 DEBUG : both7: md5 = fdb28d2438d229d567aaf691a6667df2 OK 2025/04/29 03:05:58 DEBUG : only7: md5 = 279394d501a39c2ed8f4ebb22ea93b8c OK 2025/04/29 03:05:59 DEBUG : both8: md5 = eab558ac56b1b494c4603f2997142b97 OK 2025/04/29 03:06:01 DEBUG : only8: md5 = 3fe3119ba8a7c1fb6c94819713308c6c OK 2025/04/29 03:06:02 DEBUG : both9: md5 = 2424cf78776e7ad5ea780b58da88a2cd OK 2025/04/29 03:06:03 DEBUG : only9: md5 = 61937f034225b1c9f33f2dd5f75c2a3d OK 2025/04/29 03:06:04 DEBUG : both10: md5 = e1d52b3f7b72c7dc90fcedf0a4d1d819 OK 2025/04/29 03:06:06 DEBUG : only10: md5 = 279db2251271a597afeb7ef23097fa6e OK 2025/04/29 03:06:07 DEBUG : both11: md5 = dac424783ca2636e4d875245d9958709 OK 2025/04/29 03:06:08 DEBUG : only11: md5 = a7d88da44eedffba15aa9be3125491c7 OK 2025/04/29 03:06:10 DEBUG : both12: md5 = eac8f4f487ad890a1b29a4015ea00426 OK 2025/04/29 03:06:11 DEBUG : only12: md5 = 0bd9fdc78e8d458334fc2ba8778677a3 OK 2025/04/29 03:06:13 DEBUG : both13: md5 = f14d59a631d89f183c1056c201541259 OK 2025/04/29 03:06:14 DEBUG : only13: md5 = ad7ef3ae8e3d9d6e3b53d0a437ee97ae OK 2025/04/29 03:06:15 DEBUG : both14: md5 = 7aa88d4076d9df569bd740bdaa714b1d OK 2025/04/29 03:06:17 DEBUG : only14: md5 = 0da4e21e08b860d83dca7ab47bc00428 OK 2025/04/29 03:06:18 DEBUG : both15: md5 = ebc8f92cfbee3dc4978b1444ca86938e OK 2025/04/29 03:06:19 DEBUG : only15: md5 = 867b885bca5f1b02144659da9e2422fe OK 2025/04/29 03:06:21 DEBUG : both16: md5 = 661389bff4e1a19e82cab60a7ec93f3d OK 2025/04/29 03:06:22 DEBUG : only16: md5 = 6ae240c0b1878f876f6a33c815383e82 OK 2025/04/29 03:06:23 DEBUG : both17: md5 = 4bbaf76671245ba2053f926b41f64aa7 OK 2025/04/29 03:06:25 DEBUG : only17: md5 = b8c46263fde77b2a39e198adc8a9dc2d OK 2025/04/29 03:06:26 DEBUG : both18: md5 = f8b3fdf684e0ab695d490e2e94d400c9 OK 2025/04/29 03:06:27 DEBUG : only18: md5 = a9adecab3bd48aec5065ac55f57ffede OK 2025/04/29 03:06:29 DEBUG : both19: md5 = 59300651595560c954e59624822d2299 OK 2025/04/29 03:06:30 DEBUG : only19: md5 = 44df393807ce5f4bb4ff2c4b11a8216e OK 2025/04/29 03:06:31 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:06:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for checks to finish 2025/04/29 03:06:31 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:06:31 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:06:31 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:06:31 DEBUG : both10: Unchanged skipping 2025/04/29 03:06:31 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:06:31 DEBUG : both12: Unchanged skipping 2025/04/29 03:06:31 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:06:31 DEBUG : both13: Unchanged skipping 2025/04/29 03:06:31 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:06:31 DEBUG : both14: Unchanged skipping 2025/04/29 03:06:31 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:06:31 DEBUG : both0: Unchanged skipping 2025/04/29 03:06:31 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:06:31 DEBUG : both16: Unchanged skipping 2025/04/29 03:06:31 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:06:31 DEBUG : both17: Unchanged skipping 2025/04/29 03:06:31 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:06:31 DEBUG : both18: Unchanged skipping 2025/04/29 03:06:31 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:06:31 DEBUG : both19: Unchanged skipping 2025/04/29 03:06:31 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:06:31 DEBUG : both2: Unchanged skipping 2025/04/29 03:06:31 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:06:31 DEBUG : both3: Unchanged skipping 2025/04/29 03:06:31 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:06:31 DEBUG : both4: Unchanged skipping 2025/04/29 03:06:31 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:06:31 DEBUG : both5: Unchanged skipping 2025/04/29 03:06:31 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:06:31 DEBUG : both6: Unchanged skipping 2025/04/29 03:06:31 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:06:31 DEBUG : both7: Unchanged skipping 2025/04/29 03:06:31 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:06:31 DEBUG : both8: Unchanged skipping 2025/04/29 03:06:31 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/29 03:06:31 DEBUG : both9: Unchanged skipping 2025/04/29 03:06:31 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/04/29 03:06:31 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/04/29 03:06:31 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/04/29 03:06:31 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/04/29 03:06:31 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/04/29 03:06:31 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/04/29 03:06:31 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/04/29 03:06:31 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/04/29 03:06:31 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/04/29 03:06:31 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/04/29 03:06:31 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/04/29 03:06:31 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/04/29 03:06:31 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/04/29 03:06:31 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/04/29 03:06:31 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/04/29 03:06:31 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/04/29 03:06:31 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/04/29 03:06:31 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/04/29 03:06:31 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/04/29 03:06:31 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/04/29 03:06:31 DEBUG : both1: Unchanged skipping 2025/04/29 03:06:31 DEBUG : both11: Unchanged skipping 2025/04/29 03:06:31 DEBUG : both15: Unchanged skipping 2025/04/29 03:06:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Waiting for transfers to finish 2025/04/29 03:06:32 DEBUG : only0: md5 = 7df7c978da162c95c3c48a2c99b9eb9c OK 2025/04/29 03:06:32 INFO : only0: Copied (replaced existing) 2025/04/29 03:06:32 DEBUG : only1: md5 = 1c7c922aa8edecae3c9ae9ed868fbc69 OK 2025/04/29 03:06:32 INFO : only1: Copied (replaced existing) 2025/04/29 03:06:32 DEBUG : only11: md5 = 0f79882cd69000dd13bcd31b425a5da1 OK 2025/04/29 03:06:32 INFO : only11: Copied (replaced existing) 2025/04/29 03:06:33 DEBUG : only10: md5 = 15a674a1aa3883e0ad2273de350b77b4 OK 2025/04/29 03:06:33 INFO : only10: Copied (replaced existing) 2025/04/29 03:06:33 DEBUG : only14: md5 = bc12fa71d7910eed0d377a693f442845 OK 2025/04/29 03:06:33 INFO : only14: Copied (replaced existing) 2025/04/29 03:06:33 DEBUG : only12: md5 = 3f9755f2a98749cea80e2c693dab7a35 OK 2025/04/29 03:06:33 INFO : only12: Copied (replaced existing) 2025/04/29 03:06:33 DEBUG : only13: md5 = d45ef622b69c2cab2867615bdb26949c OK 2025/04/29 03:06:33 INFO : only13: Copied (replaced existing) 2025/04/29 03:06:34 DEBUG : only15: md5 = b4f1a9413e77d668cb56fd55db5ba4f2 OK 2025/04/29 03:06:34 INFO : only15: Copied (replaced existing) 2025/04/29 03:06:34 DEBUG : only17: md5 = ea7d9a55f553bed6c54d38b98c22cd4e OK 2025/04/29 03:06:34 INFO : only17: Copied (replaced existing) 2025/04/29 03:06:34 DEBUG : only18: md5 = 48e94ae73853c0aafee74623694f73c1 OK 2025/04/29 03:06:34 INFO : only18: Copied (replaced existing) 2025/04/29 03:06:34 DEBUG : only16: md5 = 6f5df7930680dc05f8470898ff0de325 OK 2025/04/29 03:06:34 INFO : only16: Copied (replaced existing) 2025/04/29 03:06:35 DEBUG : only19: md5 = 2d63d4f85f6a05f7ca02e1b251941966 OK 2025/04/29 03:06:35 INFO : only19: Copied (replaced existing) 2025/04/29 03:06:35 DEBUG : only3: md5 = 8ab3dddad6da3c9b844839edc942fc18 OK 2025/04/29 03:06:35 INFO : only3: Copied (replaced existing) 2025/04/29 03:06:35 DEBUG : only2: md5 = eb335050d929d0c664878e2d0c33f5a3 OK 2025/04/29 03:06:35 INFO : only2: Copied (replaced existing) 2025/04/29 03:06:35 DEBUG : only4: md5 = 4ec9e6807775cf45556662476779e597 OK 2025/04/29 03:06:35 INFO : only4: Copied (replaced existing) 2025/04/29 03:06:36 DEBUG : only5: md5 = 2bf14274698951877023d6ce04ec3294 OK 2025/04/29 03:06:36 INFO : only5: Copied (replaced existing) 2025/04/29 03:06:36 DEBUG : only6: md5 = 6f9ed2e166d2b926c04259a56e437196 OK 2025/04/29 03:06:36 INFO : only6: Copied (replaced existing) 2025/04/29 03:06:36 DEBUG : only7: md5 = 79410bd1b88b69e76df2f1701911db15 OK 2025/04/29 03:06:36 INFO : only7: Copied (replaced existing) 2025/04/29 03:06:36 DEBUG : only8: md5 = 2407055770cf311523cc1c07844b6bd4 OK 2025/04/29 03:06:36 INFO : only8: Copied (replaced existing) 2025/04/29 03:06:37 DEBUG : only9: md5 = 45d394401a16a89ecfa944fc9b619425 OK 2025/04/29 03:06:37 INFO : only9: Copied (replaced existing) 2025/04/29 03:06:37 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (80.09s) === RUN TestSyncReplaceDirModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:06:56 DEBUG : empty_dir: Making directory with metadata 2025/04/29 03:06:56 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/29 03:06:56 DEBUG : empty_on_remote: Making directory with metadata 2025/04/29 03:06:56 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/29 03:06:56 DEBUG : empty_on_remote: Making directory with metadata 2025/04/29 03:06:57 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:07:02 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/04/29 03:07:02 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/04/29 03:07:02 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/04/29 03:07:02 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:07:09 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/04/29 03:07:10 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/04/29 03:07:11 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTime (16.70s) === RUN TestSyncReplaceDirModTimeWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:07:13 DEBUG : empty_dir: Making directory with metadata 2025/04/29 03:07:13 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/29 03:07:13 DEBUG : empty_on_remote: Making directory with metadata 2025/04/29 03:07:13 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/29 03:07:13 DEBUG : empty_on_remote: Making directory with metadata 2025/04/29 03:07:14 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:07:18 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/04/29 03:07:18 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/04/29 03:07:18 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/04/29 03:07:18 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) 2025/04/29 03:07:18 INFO : empty_dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:07:25 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/04/29 03:07:26 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/04/29 03:07:27 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (16.53s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:07:29 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/29 03:07:29 DEBUG : sub dir: Making directory with metadata 2025/04/29 03:07:30 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:07:47 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/29 03:07:48 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/29 03:07:48 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/29 03:07:48 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:08:00 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/04/29 03:08:00 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/29 03:08:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/04/29 03:08:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/04/29 03:08:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/29 03:08:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/29 03:08:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/29 03:08:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/29 03:08:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/29 03:08:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/04/29 03:08:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/29 03:08:07 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (38.99s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:08:08 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/29 03:08:08 DEBUG : sub dir: Making directory with metadata 2025/04/29 03:08:09 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:08:31 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/29 03:08:31 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/29 03:08:31 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/29 03:08:31 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date'", Local "Local file system at /tmp/rclone3750888648", Modify Window "1ms" 2025/04/29 03:08:42 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/29 03:08:43 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/04/29 03:08:43 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/04/29 03:08:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/29 03:08:45 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/29 03:08:45 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/29 03:08:46 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/29 03:08:47 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/29 03:08:48 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/04/29 03:08:48 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/29 03:08:48 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (41.75s) PASS 2025/04/29 03:08:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mavayew0date': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 15m24.430729847s (try 1/5)