"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5) 2025/03/28 03:08:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo" 2025/03/28 03:08:46 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/03/28 03:08:46 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g" 2025/03/28 03:08:47 DEBUG : Creating backend with remote "/tmp/rclone3566264151" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.05s) === RUN TestPipeOrderBy === RUN TestPipeOrderBy/#00 === RUN TestPipeOrderBy/size === RUN TestPipeOrderBy/name === RUN TestPipeOrderBy/modtime === RUN TestPipeOrderBy/size,ascending === RUN TestPipeOrderBy/name,asc === RUN TestPipeOrderBy/modtime,ascending === RUN TestPipeOrderBy/size,descending === RUN TestPipeOrderBy/name,desc === RUN TestPipeOrderBy/modtime,descending === RUN TestPipeOrderBy/size,mixed,50 === RUN TestPipeOrderBy/size,mixed,51 --- PASS: TestPipeOrderBy (0.00s) --- PASS: TestPipeOrderBy/#00 (0.00s) --- PASS: TestPipeOrderBy/size (0.00s) --- PASS: TestPipeOrderBy/name (0.00s) --- PASS: TestPipeOrderBy/modtime (0.00s) --- PASS: TestPipeOrderBy/size,ascending (0.00s) --- PASS: TestPipeOrderBy/name,asc (0.00s) --- PASS: TestPipeOrderBy/modtime,ascending (0.00s) --- PASS: TestPipeOrderBy/size,descending (0.00s) --- PASS: TestPipeOrderBy/name,desc (0.00s) --- PASS: TestPipeOrderBy/modtime,descending (0.00s) --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s) --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s) === RUN TestNewLess === RUN TestNewLess/blankOK === RUN TestNewLess/tooManyParts === RUN TestNewLess/tooManyParts2 === RUN TestNewLess/badMixed === RUN TestNewLess/unknownComparison === RUN TestNewLess/unknownSortDirection === RUN TestNewLess/size === RUN TestNewLess/name === RUN TestNewLess/modtime === RUN TestNewLess/size,ascending === RUN TestNewLess/name,asc === RUN TestNewLess/modtime,ascending === RUN TestNewLess/size,descending === RUN TestNewLess/name,desc === RUN TestNewLess/modtime,descending === RUN TestNewLess/modtime,mixed === RUN TestNewLess/modtime,mixed,30 --- PASS: TestNewLess (0.00s) --- PASS: TestNewLess/blankOK (0.00s) --- PASS: TestNewLess/tooManyParts (0.00s) --- PASS: TestNewLess/tooManyParts2 (0.00s) --- PASS: TestNewLess/badMixed (0.00s) --- PASS: TestNewLess/unknownComparison (0.00s) --- PASS: TestNewLess/unknownSortDirection (0.00s) --- PASS: TestNewLess/size (0.00s) --- PASS: TestNewLess/name (0.00s) --- PASS: TestNewLess/modtime (0.00s) --- PASS: TestNewLess/size,ascending (0.00s) --- PASS: TestNewLess/name,asc (0.00s) --- PASS: TestNewLess/modtime,ascending (0.00s) --- PASS: TestNewLess/size,descending (0.00s) --- PASS: TestNewLess/name,desc (0.00s) --- PASS: TestNewLess/modtime,descending (0.00s) --- PASS: TestNewLess/modtime,mixed (0.00s) --- PASS: TestNewLess/modtime,mixed,30 (0.00s) === RUN TestRcCopy rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcCopy (0.00s) === RUN TestRcMove rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcMove (0.00s) === RUN TestRcSync rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcSync (0.00s) === RUN TestCopyWithDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:08:48 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/28 03:08:48 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/28 03:08:48 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/03/28 03:08:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:08:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:08:48 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.06s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:08:49 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/28 03:08:50 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/28 03:08:50 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/28 03:08:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:08:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:08:52 DEBUG : sub dir/hello world: md5 = 31f4f007beb56682eb958e4ff613e6e0 OK 2025/03/28 03:08:52 INFO : sub dir/hello world: Copied (new) 2025/03/28 03:08:52 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:08:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (5.77s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:08:55 DEBUG : metadata sub dir: Making directory with metadata 2025/03/28 03:08:55 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/28 03:08:55 DEBUG : empty metadata sub dir: Making directory with metadata 2025/03/28 03:08:55 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/28 03:08:55 DEBUG : Local file system at /tmp/rclone3566264151: File to upload is small (21 bytes), uploading instead of streaming 2025/03/28 03:08:55 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/03/28 03:08:55 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/03/28 03:08:55 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/03/28 03:08:56 DEBUG : Google drive root 'crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g': Skipping btime metadata as can't update it on an existing file: 2025-03-28T03:08:55.737033597Z 2025/03/28 03:08:56 INFO : empty metadata sub dir: Updated directory metadata 2025/03/28 03:08:56 DEBUG : Google drive root 'crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g': Skipping btime metadata as can't update it on an existing file: 2025-03-28T03:08:55.737033597Z 2025/03/28 03:08:57 INFO : metadata sub dir: Updated directory metadata 2025/03/28 03:08:57 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/03/28 03:08:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:08:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:08:58 DEBUG : metadata sub dir/hello metadata world: md5 = 043f6972881c3f3ab8fb755291dcfda3 OK 2025/03/28 03:08:58 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:09:01 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (7.47s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:09:03 DEBUG : metadata sub dir: Making directory with metadata 2025/03/28 03:09:03 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/28 03:09:03 DEBUG : empty metadata sub dir: Making directory with metadata 2025/03/28 03:09:03 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/28 03:09:03 DEBUG : Local file system at /tmp/rclone3566264151: File to upload is small (21 bytes), uploading instead of streaming 2025/03/28 03:09:03 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/03/28 03:09:03 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/03/28 03:09:03 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/03/28 03:09:03 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/03/28 03:09:03 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/03/28 03:09:03 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/03/28 03:09:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:09:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:09:05 DEBUG : metadata sub dir/hello metadata world: md5 = 7232b7b617f1d7cfb5cfb2184294375a OK 2025/03/28 03:09:05 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/03/28 03:09:05 DEBUG : Google drive root 'crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g': Skipping btime metadata as can't update it on an existing file: 2025-03-28T03:09:03.209042725Z 2025/03/28 03:09:05 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:09:08 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (6.55s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:09:09 DEBUG : Creating backend with remote "/non-existing" 2025/03/28 03:09:09 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/03/28 03:09:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:09:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.10s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:09:10 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/28 03:09:11 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/28 03:09:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:09:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:09:13 DEBUG : sub dir/hello world: md5 = 8bcbd92ef9fb73f568173586307adaae OK 2025/03/28 03:09:13 INFO : sub dir/hello world: Copied (new) 2025/03/28 03:09:13 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:09:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (5.95s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:09:16 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Running all checks before starting transfers 2025/03/28 03:09:17 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/28 03:09:17 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/28 03:09:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:09:17 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Checks finished, now starting transfers 2025/03/28 03:09:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:09:19 DEBUG : sub dir/hello world: md5 = 66d0d3ddb748605837c5a311035b0cca OK 2025/03/28 03:09:19 INFO : sub dir/hello world: Copied (new) 2025/03/28 03:09:19 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:09:21 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (5.75s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:09:22 ERROR : Ignoring --no-traverse with sync 2025/03/28 03:09:22 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/28 03:09:22 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/28 03:09:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:09:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:09:24 DEBUG : sub dir/hello world: md5 = b2d3a0940777709930f248d11210b510 OK 2025/03/28 03:09:24 INFO : sub dir/hello world: Copied (new) 2025/03/28 03:09:24 DEBUG : Waiting for deletions to finish 2025/03/28 03:09:25 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:09:27 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (5.70s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:09:28 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/03/28 03:09:28 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/28 03:09:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:09:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:09:30 DEBUG : hello world2: md5 = 30543f21bd3b75437385772b36e11166 OK 2025/03/28 03:09:30 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.48s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:09:31 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/28 03:09:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:09:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:09:33 DEBUG : potato2: md5 = 3dad3f3eca89be95576cefaecbfc2238 OK 2025/03/28 03:09:33 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.09s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:09:35 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/28 03:09:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:09:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:09:36 DEBUG : potato2: md5 = e9a59b6f012c8f5928352a7097fdab04 OK 2025/03/28 03:09:36 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.22s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:09:38 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/03/28 03:09:38 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/28 03:09:38 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/28 03:09:38 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/28 03:09:38 DEBUG : sub dir: Making directory with metadata 2025/03/28 03:09:38 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/03/28 03:09:38 DEBUG : sub dir2: Making directory with metadata 2025/03/28 03:09:39 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/28 03:09:39 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/03/28 03:09:39 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/28 03:09:40 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/28 03:09:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:09:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:09:41 DEBUG : sub dir/hello world: md5 = 5b5550850f1a5d4613218c921e71b845 OK 2025/03/28 03:09:41 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:09:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/03/28 03:09:45 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (8.51s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:09:46 INFO : sub dir2: Making directory 2025/03/28 03:09:46 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/03/28 03:09:46 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/28 03:09:46 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/28 03:09:46 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/03/28 03:09:46 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/03/28 03:09:46 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/28 03:09:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:09:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:09:49 DEBUG : sub dir/hello world: md5 = 6092e0c2e24f3008db2a6487b6dc5441 OK 2025/03/28 03:09:49 INFO : sub dir/hello world: Copied (new) 2025/03/28 03:09:49 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/28 03:09:51 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (5.35s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:09:51 DEBUG : sub dir2: Making directory with metadata 2025/03/28 03:09:51 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/28 03:09:52 DEBUG : sub dir: Making directory with metadata 2025/03/28 03:09:52 INFO : sub dir: Made directory with metadata (mtime=2025-03-28T03:09:51.913102748Z) 2025/03/28 03:09:52 DEBUG : sub dir2: Making directory with metadata 2025/03/28 03:09:53 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/28 03:09:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/28 03:09:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:09:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:09:55 DEBUG : sub dir/hello world: md5 = ae9c802b297627a6e6862277334d2466 OK 2025/03/28 03:09:55 INFO : sub dir/hello world: Copied (new) 2025/03/28 03:09:55 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:09:57 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (7.09s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:09:59 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/03/28 03:09:59 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/03/28 03:10:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:10:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:10:00 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (3.99s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:10:03 INFO : sub dir2: Making directory 2025/03/28 03:10:03 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/28 03:10:03 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/03/28 03:10:03 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/28 03:10:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:10:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:10:05 DEBUG : sub dir/hello world: md5 = c20c83200cc8db22afc1064a785f5ad3 OK 2025/03/28 03:10:05 INFO : sub dir/hello world: Copied (new) 2025/03/28 03:10:05 INFO : sub dir/hello world: Deleted 2025/03/28 03:10:05 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/28 03:10:07 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (4.93s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:10:07 DEBUG : sub dir2: Making directory with metadata 2025/03/28 03:10:07 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/28 03:10:07 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/28 03:10:08 DEBUG : sub dir: Making directory with metadata 2025/03/28 03:10:08 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/03/28 03:10:08 DEBUG : sub dir2: Making directory with metadata 2025/03/28 03:10:09 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/28 03:10:09 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/28 03:10:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:10:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:10:11 DEBUG : sub dir/hello world: md5 = d9adb76e191cb136a56b2958726ec1b0 OK 2025/03/28 03:10:11 INFO : sub dir/hello world: Copied (new) 2025/03/28 03:10:11 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:10:14 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (7.55s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.43s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:10:15 INFO : sub dir2: Making directory 2025/03/28 03:10:16 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/28 03:10:16 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/03/28 03:10:16 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/28 03:10:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:10:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:10:18 DEBUG : sub dir/hello world: md5 = a1e65c1af95cf4c94c39d19928ba5e44 OK 2025/03/28 03:10:18 INFO : sub dir/hello world: Copied (new) 2025/03/28 03:10:18 DEBUG : Waiting for deletions to finish 2025/03/28 03:10:18 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/28 03:10:20 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (5.07s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:10:23 DEBUG : sub dir/hello world: md5 = b39d3d6813b066d30c7c08190e3148ce OK 2025/03/28 03:10:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hoguwip0diyo" 2025/03/28 03:10:23 DEBUG : Creating backend with remote "TestDrive:crypt/sij8k6ip7lu662ff7mc9h7fnf7jd5o9ou1skialgjtm1r9dvdpg0" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo' -> Encrypted drive 'TestCryptDrive:rclone-test-hoguwip0diyo' 2025/03/28 03:10:24 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/28 03:10:24 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/28 03:10:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoguwip0diyo': Waiting for checks to finish 2025/03/28 03:10:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoguwip0diyo': Waiting for transfers to finish 2025/03/28 03:10:27 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/28 03:10:27 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:10:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hoguwip0diyo': Purge remote 2025/03/28 03:10:29 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (10.17s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:10:33 DEBUG : sub dir/hello world: md5 = bdfda9e52945dadbd2c6661d02530f70 OK 2025/03/28 03:10:34 INFO : sub dir: Set directory modification time (using SetModTime) 2025/03/28 03:10:34 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/28 03:10:34 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/28 03:10:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:10:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:10:35 DEBUG : sub dir/hello world: md5 = 021c29f1284fcdb47bb1a8af22304d44 OK 2025/03/28 03:10:35 INFO : sub dir/hello world: Copied (replaced existing) 2025/03/28 03:10:36 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:10:37 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (7.84s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:10:41 DEBUG : sub dir/hello world: md5 = 6d0e93d626c0dcf50a2483cb6f85f01b OK 2025/03/28 03:10:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vimekey9jizi" 2025/03/28 03:10:42 DEBUG : Creating backend with remote "TestDrive:crypt/2ehfj06f791ree0oi4lq4nkogke0p7uijmkeivnos6hj1tsvpjv0" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo' -> Encrypted drive 'TestCryptDrive:rclone-test-vimekey9jizi' 2025/03/28 03:10:43 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/28 03:10:43 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/28 03:10:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vimekey9jizi': Waiting for checks to finish 2025/03/28 03:10:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vimekey9jizi': Waiting for transfers to finish 2025/03/28 03:10:45 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/28 03:10:46 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:10:48 DEBUG : sub dir/hello world: md5 = 4889170ca72828cf633a50324c03a0ce OK 2025/03/28 03:10:49 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/03/28 03:10:49 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/28 03:10:49 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/28 03:10:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vimekey9jizi': Waiting for checks to finish 2025/03/28 03:10:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vimekey9jizi': Waiting for transfers to finish 2025/03/28 03:10:50 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/28 03:10:51 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:10:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vimekey9jizi': Purge remote 2025/03/28 03:10:53 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (15.98s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:10:57 DEBUG : sub dir/hello world: md5 = d93af38d49b5f1757bf61500ef4b96c0 OK 2025/03/28 03:10:58 INFO : sub dir: Set directory modification time (using SetModTime) 2025/03/28 03:10:58 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/28 03:10:58 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/28 03:10:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:10:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:10:59 DEBUG : sub dir/hello world: md5 = e3da0f0c6cd6dffe3e135fdb005421d7 OK 2025/03/28 03:10:59 INFO : sub dir/hello world: Copied (replaced existing) 2025/03/28 03:10:59 INFO : sub dir/hello world: Deleted 2025/03/28 03:11:00 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:11:01 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (7.94s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:11:04 DEBUG : sub dir/hello world: md5 = cd389be5b40bce35e6863c2a6d5defa7 OK 2025/03/28 03:11:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pekuqex5lisa" 2025/03/28 03:11:05 DEBUG : Creating backend with remote "TestDrive:crypt/log11ukf9hv0duo9tbv5iufo4p7c376ci3vqrtev5503oefeck8g" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo' -> Encrypted drive 'TestCryptDrive:rclone-test-pekuqex5lisa' 2025/03/28 03:11:06 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/28 03:11:06 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/28 03:11:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekuqex5lisa': Waiting for checks to finish 2025/03/28 03:11:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekuqex5lisa': Waiting for transfers to finish 2025/03/28 03:11:09 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/28 03:11:09 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:11:11 DEBUG : sub dir/hello world: md5 = 765652bf274c3a5946208f93d1d7ce29 OK 2025/03/28 03:11:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekuqex5lisa': Using server-side directory move 2025/03/28 03:11:12 INFO : Encrypted drive 'TestCryptDrive:rclone-test-pekuqex5lisa': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/28 03:11:12 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/03/28 03:11:12 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/28 03:11:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekuqex5lisa': Waiting for checks to finish 2025/03/28 03:11:12 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/28 03:11:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekuqex5lisa': Waiting for transfers to finish 2025/03/28 03:11:13 INFO : sub dir/hello world: Deleted 2025/03/28 03:11:13 INFO : sub dir/hello world: Moved (server-side) 2025/03/28 03:11:14 INFO : sub dir: Set directory modification time (using SetModTime) 2025/03/28 03:11:16 DEBUG : sub dir/hello world: md5 = 0be0b26d32a12800543da1bf431df035 OK 2025/03/28 03:11:17 DEBUG : testing file moves 2025/03/28 03:11:17 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/03/28 03:11:17 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/28 03:11:17 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/03/28 03:11:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekuqex5lisa': Waiting for checks to finish 2025/03/28 03:11:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekuqex5lisa': Waiting for transfers to finish 2025/03/28 03:11:17 INFO : sub dir/hello world: Deleted 2025/03/28 03:11:18 INFO : sub dir/hello world: Moved (server-side) 2025/03/28 03:11:19 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:11:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pekuqex5lisa': Purge remote --- PASS: TestServerSideMoveOverSelf (19.76s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:11:24 DEBUG : sub dir/hello world: md5 = e176a731b9a0f4ba9a698b3237b5d562 OK 2025/03/28 03:11:24 ERROR : : error listing: directory not found 2025/03/28 03:11:25 INFO : Local file system at /tmp/rclone3566264151: Making directory 2025/03/28 03:11:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:11:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:11:27 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (5.99s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:11:30 DEBUG : sub dir/hello world: md5 = f201d0a841939e874b136d797efa1fc1 OK 2025/03/28 03:11:31 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/28 03:11:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/28 03:11:31 DEBUG : Local file system at /tmp/rclone3566264151: Waiting for checks to finish 2025/03/28 03:11:31 DEBUG : Local file system at /tmp/rclone3566264151: Waiting for transfers to finish 2025/03/28 03:11:32 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/03/28 03:11:32 INFO : sub dir/hello world: Copied (new) 2025/03/28 03:11:32 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:11:34 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (6.88s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:11:35 DEBUG : check sum: Need to transfer - File not found at Destination 2025/03/28 03:11:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:11:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:11:37 DEBUG : check sum: md5 = 11432da2ceea669399f1883ba287027e OK 2025/03/28 03:11:37 INFO : check sum: Copied (new) 2025/03/28 03:11:37 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:11:37 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/03/28 03:11:37 DEBUG : check sum: Size of src and dst objects identical 2025/03/28 03:11:37 DEBUG : check sum: Unchanged skipping 2025/03/28 03:11:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:11:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:11:37 DEBUG : Waiting for deletions to finish 2025/03/28 03:11:37 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (3.92s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:11:39 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/03/28 03:11:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:11:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:11:41 DEBUG : sizeonly: md5 = efd2711963207d070a2beab8e2a43b86 OK 2025/03/28 03:11:41 INFO : sizeonly: Copied (new) 2025/03/28 03:11:41 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:11:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:11:41 DEBUG : sizeonly: Sizes identical 2025/03/28 03:11:41 DEBUG : sizeonly: Unchanged skipping 2025/03/28 03:11:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:11:41 DEBUG : Waiting for deletions to finish 2025/03/28 03:11:41 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.64s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:11:44 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/03/28 03:11:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:11:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:11:45 DEBUG : ignore-size: md5 = c614c84e7c13ab8f34d1249d77825cd4 OK 2025/03/28 03:11:45 INFO : ignore-size: Copied (new) 2025/03/28 03:11:45 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:11:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:11:46 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:11:46 DEBUG : ignore-size: Unchanged skipping 2025/03/28 03:11:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:11:46 DEBUG : Waiting for deletions to finish 2025/03/28 03:11:46 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.02s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:11:49 DEBUG : existing: md5 = eb755af78f8e598f9fa4e67390ab896c OK 2025/03/28 03:11:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:11:49 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:11:49 DEBUG : existing: Unchanged skipping 2025/03/28 03:11:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:11:49 DEBUG : Waiting for deletions to finish 2025/03/28 03:11:49 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:11:50 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/03/28 03:11:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:11:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:11:51 DEBUG : existing: md5 = 726a972fda879f1eb622fbab49d86a40 OK 2025/03/28 03:11:51 INFO : existing: Copied (replaced existing) 2025/03/28 03:11:51 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.24s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:11:53 DEBUG : existing: Need to transfer - File not found at Destination 2025/03/28 03:11:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:11:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:11:54 DEBUG : existing: md5 = 85b9eaf10c0c5d85e3ecffbbcc87a4bd OK 2025/03/28 03:11:54 INFO : existing: Copied (new) 2025/03/28 03:11:54 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:11:55 DEBUG : existing: Destination exists, skipping 2025/03/28 03:11:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:11:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:11:55 DEBUG : Waiting for deletions to finish 2025/03/28 03:11:55 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (3.99s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:11:59 DEBUG : b/potato: md5 = e20e0eebc50f2463d36d6d51453fb379 OK 2025/03/28 03:12:01 DEBUG : c/non empty space: md5 = b77087c30279c571a79eff893aba56b5 OK 2025/03/28 03:12:01 INFO : d: Making directory 2025/03/28 03:12:02 DEBUG : Added delayed dir = "a", newDst= 2025/03/28 03:12:03 INFO : c: Set directory modification time (using SetModTime) 2025/03/28 03:12:03 DEBUG : Added delayed dir = "c", newDst=c 2025/03/28 03:12:03 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/03/28 03:12:03 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:12:03 DEBUG : c/non empty space: Unchanged skipping 2025/03/28 03:12:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:12:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:12:05 DEBUG : a/potato2: md5 = fbe7f4e7d521fa68bd7664269ba2d950 OK 2025/03/28 03:12:05 INFO : a/potato2: Copied (new) 2025/03/28 03:12:05 DEBUG : Waiting for deletions to finish 2025/03/28 03:12:05 INFO : b/potato: Deleted 2025/03/28 03:12:06 INFO : a: Set directory modification time (using DirSetModTime) 2025/03/28 03:12:06 INFO : d: Removing directory 2025/03/28 03:12:06 INFO : b: Removing directory 2025/03/28 03:12:07 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/03/28 03:12:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:12:09 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/03/28 03:12:10 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (14.28s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:12:12 DEBUG : empty space: md5 = 239acf49c760d6ace4593fa2d48431f9 OK 2025/03/28 03:12:13 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/03/28 03:12:13 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/03/28 03:12:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:12:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:12:13 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:12:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:12:13 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/03/28 03:12:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:12:14 DEBUG : empty space: md5 = 1ec62008f3fb6cf3fc3a7ffa9a500df9 OK 2025/03/28 03:12:14 INFO : empty space: Copied (replaced existing) 2025/03/28 03:12:14 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (5.58s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", 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-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:12:18 DEBUG : foo: md5 = 6a29524f8585d77dd98a09d14422d9c6 OK 2025/03/28 03:12:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:12:19 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/03/28 03:12:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:12:20 DEBUG : foo: md5 = e9f1721f77927a2fd149d1d2c6b46622 OK 2025/03/28 03:12:20 INFO : foo: Copied (replaced existing) 2025/03/28 03:12:20 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (4.48s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:12:23 DEBUG : empty space: md5 = b7c3cfe5852b3e62b6cd6c6cc6f1a1c2 OK 2025/03/28 03:12:23 DEBUG : potato: Need to transfer - File not found at Destination 2025/03/28 03:12:23 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:12:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:12:23 DEBUG : empty space: Unchanged skipping 2025/03/28 03:12:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:12:25 DEBUG : potato: md5 = 2749dce152f30a8d6a13ecf71f6507e9 OK 2025/03/28 03:12:25 INFO : potato: Copied (new) 2025/03/28 03:12:25 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (5.01s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:12:28 DEBUG : potato: md5 = 5e03ef4538135d35996ed60ad1286b92 OK 2025/03/28 03:12:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:12:28 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/03/28 03:12:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:12:30 DEBUG : potato: md5 = 7535e0178a288e10e2335dd163b29d76 OK 2025/03/28 03:12:30 INFO : potato: Copied (replaced existing) 2025/03/28 03:12:30 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (4.78s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:12:33 DEBUG : potato: md5 = b1e4841d72b66f3959ed3165531d55a1 OK 2025/03/28 03:12:33 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/03/28 03:12:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:12:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:12:34 DEBUG : potato: md5 = 671bddfa835e54bdfca8f632a907574d OK 2025/03/28 03:12:34 INFO : potato: Copied (replaced existing) 2025/03/28 03:12:34 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (4.43s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:12:37 DEBUG : potato: md5 = 4e5fbc63da0da3abd321af873cc12f34 OK 2025/03/28 03:12:39 DEBUG : empty space: md5 = 1a025835032e1fd2d7449ca929cb9d68 OK 2025/03/28 03:12:39 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/28 03:12:39 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/03/28 03:12:39 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:12:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:12:39 DEBUG : empty space: Unchanged skipping 2025/03/28 03:12:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:12:39 DEBUG : Waiting for deletions to finish 2025/03/28 03:12:39 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.46s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:12:43 DEBUG : potato: md5 = 9e3ff4cae5accd4ec9a14dcc018ff765 OK 2025/03/28 03:12:44 DEBUG : empty space: md5 = 724f482e88f77fa2dec23d15dca5f1d1 OK 2025/03/28 03:12:45 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/28 03:12:45 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:12:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:12:45 DEBUG : empty space: Unchanged skipping 2025/03/28 03:12:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:12:46 DEBUG : potato2: md5 = 2ef19877d3be9bb22c5b3f5c4da604f0 OK 2025/03/28 03:12:46 INFO : potato2: Copied (new) 2025/03/28 03:12:46 DEBUG : Waiting for deletions to finish 2025/03/28 03:12:47 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (7.39s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:12:51 DEBUG : b/potato: md5 = 12ec8c95b3a6d7f0fe9c399d20fd11a4 OK 2025/03/28 03:12:53 DEBUG : c/non empty space: md5 = 8ba86b116962b8fbf953b2e0df70078d OK 2025/03/28 03:12:53 INFO : d: Making directory 2025/03/28 03:12:54 INFO : d/e: Making directory 2025/03/28 03:12:56 DEBUG : Added delayed dir = "a", newDst= 2025/03/28 03:12:56 INFO : c: Set directory modification time (using SetModTime) 2025/03/28 03:12:56 DEBUG : Added delayed dir = "c", newDst=c 2025/03/28 03:12:56 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/03/28 03:12:56 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:12:56 DEBUG : c/non empty space: Unchanged skipping 2025/03/28 03:12:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:12:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:12:58 DEBUG : a/potato2: md5 = 6b087ae6be8e491f4c8c869be579dd62 OK 2025/03/28 03:12:58 INFO : a/potato2: Copied (new) 2025/03/28 03:12:58 DEBUG : Waiting for deletions to finish 2025/03/28 03:12:59 INFO : b/potato: Deleted 2025/03/28 03:12:59 INFO : a: Set directory modification time (using DirSetModTime) 2025/03/28 03:12:59 INFO : d/e: Removing directory 2025/03/28 03:13:00 INFO : d: Removing directory 2025/03/28 03:13:00 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/03/28 03:13:00 INFO : b: Removing directory 2025/03/28 03:13:00 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/03/28 03:13:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:13:03 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/03/28 03:13:04 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (15.95s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:13:07 DEBUG : b/potato: md5 = 66cc2221622751f4745d7cbe16924505 OK 2025/03/28 03:13:09 DEBUG : c/non empty space: md5 = 8c7ecfef6436f22c4cb84a8c43dce46b OK 2025/03/28 03:13:09 INFO : d: Making directory 2025/03/28 03:13:10 DEBUG : Added delayed dir = "a", newDst= 2025/03/28 03:13:11 INFO : c: Set directory modification time (using SetModTime) 2025/03/28 03:13:11 DEBUG : Added delayed dir = "c", newDst=c 2025/03/28 03:13:11 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/03/28 03:13:11 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:13:11 DEBUG : c/non empty space: Unchanged skipping 2025/03/28 03:13:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:13:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:13:13 DEBUG : a/potato2: md5 = debc32ede148184b8636ce2ce7a1bdbe OK 2025/03/28 03:13:13 INFO : a/potato2: Copied (new) 2025/03/28 03:13:13 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': not deleting files as there were IO errors 2025/03/28 03:13:13 INFO : a: Set directory modification time (using DirSetModTime) 2025/03/28 03:13:13 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:13:17 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/03/28 03:13:17 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/03/28 03:13:18 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (14.51s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:13:21 DEBUG : potato: md5 = 428473777d147487d2ccbd763325ca73 OK 2025/03/28 03:13:22 DEBUG : empty space: md5 = d6fbcd118fbc486cba68f53228f5e50b OK 2025/03/28 03:13:22 DEBUG : Waiting for deletions to finish 2025/03/28 03:13:23 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/28 03:13:23 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:13:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:13:23 DEBUG : empty space: Unchanged skipping 2025/03/28 03:13:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:13:23 INFO : potato: Deleted 2025/03/28 03:13:24 DEBUG : potato2: md5 = 19b74fea1f908a8afa52434fb9c0e751 OK 2025/03/28 03:13:24 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (6.59s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:13:27 DEBUG : potato: md5 = acadb8628c5ef4d074048ac877eb9b0d OK 2025/03/28 03:13:28 DEBUG : empty space: md5 = 7d492a5f2d321cdf24148569db7c5d40 OK 2025/03/28 03:13:29 DEBUG : Waiting for deletions to finish 2025/03/28 03:13:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:13:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:13:29 INFO : potato: Deleted 2025/03/28 03:13:30 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/28 03:13:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:13:30 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:13:30 DEBUG : empty space: Unchanged skipping 2025/03/28 03:13:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:13:31 DEBUG : potato2: md5 = 68be62f5ef1231dfdca8a2aad827edd5 OK 2025/03/28 03:13:31 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (7.36s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:13:35 DEBUG : potato: md5 = e339b85f4538fc2892efb91fe6c270d8 OK 2025/03/28 03:13:35 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/28 03:13:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:13:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:13:36 DEBUG : potato2: md5 = 701c99245779f4b9b7b62ca351bde0c9 OK 2025/03/28 03:13:36 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (5.21s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:13:40 DEBUG : potato2: md5 = f43f3204043bc5222ac76784ccc05001 OK 2025/03/28 03:13:42 DEBUG : empty space: md5 = 605aca65d632cea0d147a823c651745e OK 2025/03/28 03:13:42 DEBUG : enormous: Excluded (Size Filter) 2025/03/28 03:13:42 DEBUG : enormous: Excluded 2025/03/28 03:13:42 DEBUG : potato2: Excluded (Size Filter) 2025/03/28 03:13:42 DEBUG : potato2: Excluded 2025/03/28 03:13:42 DEBUG : potato2: Excluded (Size Filter) 2025/03/28 03:13:42 DEBUG : potato2: Excluded 2025/03/28 03:13:42 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:13:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:13:42 DEBUG : empty space: Unchanged skipping 2025/03/28 03:13:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:13:42 DEBUG : Waiting for deletions to finish 2025/03/28 03:13:42 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:13:43 DEBUG : enormous: Excluded (Size Filter) 2025/03/28 03:13:43 DEBUG : enormous: Excluded 2025/03/28 03:13:43 DEBUG : potato2: Excluded (Size Filter) 2025/03/28 03:13:43 DEBUG : potato2: Excluded 2025/03/28 03:13:43 DEBUG : potato2: Excluded (Size Filter) 2025/03/28 03:13:43 DEBUG : potato2: Excluded 2025/03/28 03:13:43 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/03/28 03:13:43 DEBUG : empty space: Unchanged skipping 2025/03/28 03:13:43 DEBUG : Local file system at /tmp/rclone3566264151: Waiting for checks to finish 2025/03/28 03:13:43 DEBUG : Local file system at /tmp/rclone3566264151: Waiting for transfers to finish 2025/03/28 03:13:43 DEBUG : Waiting for deletions to finish 2025/03/28 03:13:43 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncWithExclude (6.91s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:13:47 DEBUG : potato2: md5 = 7fbfa50367f6d467f4744809e5b88524 OK 2025/03/28 03:13:48 DEBUG : empty space: md5 = 3269556dd458c9a6909b132579862623 OK 2025/03/28 03:13:49 DEBUG : enormous: md5 = afe596abbc9fae09e725ccc8e4699597 OK 2025/03/28 03:13:49 DEBUG : enormous: Excluded (Size Filter) 2025/03/28 03:13:49 DEBUG : enormous: Excluded 2025/03/28 03:13:49 DEBUG : potato2: Excluded (Size Filter) 2025/03/28 03:13:49 DEBUG : potato2: Excluded 2025/03/28 03:13:50 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:13:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:13:50 DEBUG : empty space: Unchanged skipping 2025/03/28 03:13:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:13:50 DEBUG : Waiting for deletions to finish 2025/03/28 03:13:50 INFO : potato2: Deleted 2025/03/28 03:13:50 INFO : enormous: Deleted 2025/03/28 03:13:50 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:13:51 DEBUG : Local file system at /tmp/rclone3566264151: Waiting for checks to finish 2025/03/28 03:13:51 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/03/28 03:13:51 DEBUG : empty space: Unchanged skipping 2025/03/28 03:13:51 DEBUG : Local file system at /tmp/rclone3566264151: Waiting for transfers to finish 2025/03/28 03:13:51 DEBUG : Waiting for deletions to finish 2025/03/28 03:13:51 INFO : enormous: Deleted 2025/03/28 03:13:51 INFO : potato2: Deleted 2025/03/28 03:13:51 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.00s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:13:54 DEBUG : one: md5 = 2af9cc852f8eae57946c85f2d534c7f4 OK 2025/03/28 03:13:55 DEBUG : two: md5 = f37ffa5e2943f52df31ff3154c7af78e OK 2025/03/28 03:13:56 DEBUG : three: md5 = 8e796b9d96d1123231fe18ab70533549 OK 2025/03/28 03:13:58 DEBUG : four: md5 = 15f53b18833eb66c7e1d3c1faca3b736 OK 2025/03/28 03:13:58 DEBUG : five: Need to transfer - File not found at Destination 2025/03/28 03:13:58 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/03/28 03:13:58 DEBUG : one: Destination is newer than source, skipping 2025/03/28 03:13:58 DEBUG : three: Sizes identical 2025/03/28 03:13:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:13:58 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/03/28 03:13:58 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/03/28 03:13:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:13:59 DEBUG : two: md5 = f1a2cce93a0dc781252afd6cf70a8206 OK 2025/03/28 03:13:59 INFO : two: Copied (replaced existing) 2025/03/28 03:14:00 DEBUG : four: md5 = 99f4f38b76175b03be798c28795fca63 OK 2025/03/28 03:14:00 INFO : four: Copied (replaced existing) 2025/03/28 03:14:00 DEBUG : five: md5 = 3b2f65456ce70b1baf8b459e1600634c OK 2025/03/28 03:14:00 INFO : five: Copied (new) 2025/03/28 03:14:00 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (10.30s) === 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-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/03/28 03:14:03 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Ignoring --track-renames as the source and destination do not have a common hash 2025/03/28 03:14:03 DEBUG : potato: Need to transfer - File not found at Destination 2025/03/28 03:14:03 DEBUG : yam: Need to transfer - File not found at Destination 2025/03/28 03:14:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:14:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:14:04 DEBUG : yam: md5 = 5d6433465f223a01494ba9ce149a622c OK 2025/03/28 03:14:04 INFO : yam: Copied (new) 2025/03/28 03:14:04 DEBUG : potato: md5 = df9124eef28d307dc7ae75362827c405 OK 2025/03/28 03:14:04 INFO : potato: Copied (new) 2025/03/28 03:14:04 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:14:05 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Ignoring --track-renames as the source and destination do not have a common hash 2025/03/28 03:14:05 DEBUG : yaml: Need to transfer - File not found at Destination 2025/03/28 03:14:05 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:14:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:14:05 DEBUG : potato: Unchanged skipping 2025/03/28 03:14:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:14:06 DEBUG : yaml: md5 = a59984dd157d8af09b9c0e80f888832b OK 2025/03/28 03:14:06 INFO : yaml: Copied (new) 2025/03/28 03:14:06 DEBUG : Waiting for deletions to finish 2025/03/28 03:14:07 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (6.55s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/03/28 03:14:09 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Making map for --track-renames 2025/03/28 03:14:09 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Finished making map for --track-renames 2025/03/28 03:14:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:14:09 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/03/28 03:14:09 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/03/28 03:14:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for renames to finish 2025/03/28 03:14:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:14:11 DEBUG : yam: md5 = 7e2f10874da540b4c37e7388ad891f3e OK 2025/03/28 03:14:11 INFO : yam: Copied (new) 2025/03/28 03:14:11 DEBUG : potato: md5 = b8eff309d83519bc81167b8bbaa4f9b2 OK 2025/03/28 03:14:11 INFO : potato: Copied (new) 2025/03/28 03:14:11 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:14:11 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:14:11 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Making map for --track-renames 2025/03/28 03:14:11 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Finished making map for --track-renames 2025/03/28 03:14:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:14:11 DEBUG : potato: Unchanged skipping 2025/03/28 03:14:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for renames to finish 2025/03/28 03:14:12 INFO : yam: Moved (server-side) to: yaml 2025/03/28 03:14:12 INFO : yaml: Renamed from "yam" 2025/03/28 03:14:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:14:12 DEBUG : Waiting for deletions to finish 2025/03/28 03:14:12 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.62s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/03/28 03:14:15 DEBUG : Added delayed dir = "sub", newDst= 2025/03/28 03:14:15 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Making map for --track-renames 2025/03/28 03:14:15 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Finished making map for --track-renames 2025/03/28 03:14:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:14:15 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/03/28 03:14:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for renames to finish 2025/03/28 03:14:15 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/03/28 03:14:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:14:17 DEBUG : sub/yam: md5 = 699010a3825f096b5685a7c5d2cfcaea OK 2025/03/28 03:14:17 INFO : sub/yam: Copied (new) 2025/03/28 03:14:17 DEBUG : potato: md5 = 1a39b0d9a7b7f275450f703eece0db83 OK 2025/03/28 03:14:17 INFO : potato: Copied (new) 2025/03/28 03:14:17 DEBUG : Waiting for deletions to finish 2025/03/28 03:14:17 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:14:18 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:14:18 DEBUG : potato: Unchanged skipping 2025/03/28 03:14:19 INFO : sub: Set directory modification time (using SetModTime) 2025/03/28 03:14:19 DEBUG : Added delayed dir = "sub", newDst=sub 2025/03/28 03:14:19 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Making map for --track-renames 2025/03/28 03:14:19 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Finished making map for --track-renames 2025/03/28 03:14:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:14:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for renames to finish 2025/03/28 03:14:20 INFO : sub/yam: Moved (server-side) to: yam 2025/03/28 03:14:20 INFO : yam: Renamed from "sub/yam" 2025/03/28 03:14:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:14:20 DEBUG : Waiting for deletions to finish 2025/03/28 03:14:20 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (8.71s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:14:23 DEBUG : Creating backend with remote "/tmp/rclone3566264151/dir1" 2025/03/28 03:14:23 DEBUG : Creating backend with remote "/tmp/rclone3566264151/dir2" 2025/03/28 03:14:23 DEBUG : Local file system at /tmp/rclone3566264151/dir2: Using server-side directory move 2025/03/28 03:14:23 INFO : Local file system at /tmp/rclone3566264151/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/28 03:14:23 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/03/28 03:14:23 INFO : file1.txt: Moved (server-side) 2025/03/28 03:14:23 DEBUG : Local file system at /tmp/rclone3566264151/dir2: Waiting for checks to finish 2025/03/28 03:14:23 DEBUG : Local file system at /tmp/rclone3566264151/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.46s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:14:24 DEBUG : Added delayed dir = "nested", newDst= 2025/03/28 03:14:24 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/28 03:14:24 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/28 03:14:24 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/03/28 03:14:24 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/03/28 03:14:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:14:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:14:26 DEBUG : sub dir/hello world: md5 = 945f953c3efb3332ee03b744feefe977 OK 2025/03/28 03:14:26 INFO : sub dir/hello world: Copied (new) 2025/03/28 03:14:26 INFO : sub dir/hello world: Deleted 2025/03/28 03:14:28 DEBUG : nested/sub dir/file: md5 = 94c6ea6201a9766b859f5907fbcbab22 OK 2025/03/28 03:14:28 INFO : nested/sub dir/file: Copied (new) 2025/03/28 03:14:28 INFO : nested/sub dir/file: Deleted 2025/03/28 03:14:29 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/03/28 03:14:29 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/28 03:14:29 INFO : nested: Set directory modification time (using DirSetModTime) 2025/03/28 03:14:29 INFO : sub dir: Removing directory 2025/03/28 03:14:29 INFO : nested/sub dir: Removing directory 2025/03/28 03:14:29 INFO : nested: Removing directory 2025/03/28 03:14:29 DEBUG : Local file system at /tmp/rclone3566264151: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:14:32 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/28 03:14:32 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/03/28 03:14:33 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (10.22s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:14:34 DEBUG : Added delayed dir = "nested", newDst= 2025/03/28 03:14:34 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/28 03:14:34 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/28 03:14:34 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/03/28 03:14:34 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/03/28 03:14:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:14:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:14:36 DEBUG : sub dir/hello world: md5 = 16938abc571c1010672f52e69d1b86e1 OK 2025/03/28 03:14:36 INFO : sub dir/hello world: Copied (new) 2025/03/28 03:14:36 INFO : sub dir/hello world: Deleted 2025/03/28 03:14:38 DEBUG : nested/sub dir/file: md5 = c33ac4019c45d9c00e887dc7b6c356a0 OK 2025/03/28 03:14:38 INFO : nested/sub dir/file: Copied (new) 2025/03/28 03:14:38 INFO : nested/sub dir/file: Deleted 2025/03/28 03:14:39 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/03/28 03:14:39 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/28 03:14:39 INFO : nested: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:14:42 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/28 03:14:42 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/03/28 03:14:43 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.02s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:14:44 DEBUG : existing: Need to transfer - File not found at Destination 2025/03/28 03:14:44 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/03/28 03:14:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:14:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:14:46 DEBUG : existing: md5 = 8ee2cebad8011fd89014d421c12eeb1b OK 2025/03/28 03:14:46 INFO : existing: Copied (new) 2025/03/28 03:14:46 INFO : existing: Deleted 2025/03/28 03:14:46 DEBUG : existing-b: md5 = a704f588cdeaacf42fc6bf2f86953e76 OK 2025/03/28 03:14:46 INFO : existing-b: Copied (new) 2025/03/28 03:14:46 INFO : existing-b: Deleted 2025/03/28 03:14:46 DEBUG : existing: Destination exists, skipping 2025/03/28 03:14:46 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/03/28 03:14:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:14:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:14:46 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.34s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:14:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vasefoh0yive" 2025/03/28 03:14:49 DEBUG : Creating backend with remote "TestDrive:crypt/eah7tuhd1d8n74rma1sqkj3hgegch2qpg3qjj4oegareicsigcvg" 2025/03/28 03:14:51 DEBUG : potato2: md5 = 5f6ddf6f6de75ee79a75421365372b43 OK 2025/03/28 03:14:52 DEBUG : empty space: md5 = 18adfcc6da644fa8c9a76fd529f3ad63 OK 2025/03/28 03:14:54 DEBUG : potato3: md5 = b4f2dfaebc73fb2069f3df90efc21f17 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo' -> Encrypted drive 'TestCryptDrive:rclone-test-vasefoh0yive' 2025/03/28 03:14:56 DEBUG : empty space: md5 = d2590f37a39dc12cfbcd43cbe9e67c91 OK 2025/03/28 03:14:57 DEBUG : potato3: md5 = 44e6088edd305bce6426b3d11c95f04e OK 2025/03/28 03:14:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vasefoh0yive': Using server-side directory move 2025/03/28 03:14:58 INFO : Encrypted drive 'TestCryptDrive:rclone-test-vasefoh0yive': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/28 03:14:58 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/28 03:14:58 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/03/28 03:14:58 DEBUG : empty space: Unchanged skipping 2025/03/28 03:14:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vasefoh0yive': Waiting for checks to finish 2025/03/28 03:14:58 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/28 03:14:58 INFO : potato3: Deleted 2025/03/28 03:14:58 INFO : empty space: Deleted 2025/03/28 03:14:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vasefoh0yive': Waiting for transfers to finish 2025/03/28 03:14:59 INFO : potato2: Moved (server-side) 2025/03/28 03:14:59 INFO : potato3: Moved (server-side) 2025/03/28 03:14:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bojumas4hoqo" 2025/03/28 03:15:00 DEBUG : Creating backend with remote "TestDrive:crypt/nbg5011737bccnuliucfnba6kmaeqhh7gikb6jbktm5u9u2ic66g" 2025/03/28 03:15:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bojumas4hoqo': Using server-side directory move 2025/03/28 03:15:01 INFO : Encrypted drive 'TestCryptDrive:rclone-test-bojumas4hoqo': Server side directory move succeeded 2025/03/28 03:15:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bojumas4hoqo': Purge remote 2025/03/28 03:15:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vasefoh0yive': Purge remote 2025/03/28 03:15:03 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (14.93s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:15:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xelanen4rawi" 2025/03/28 03:15:03 DEBUG : Creating backend with remote "TestDrive:crypt/56iltou8i8d1jsks70mss1uihn6kkc7ffojhmb9nbn3cr60kuqv0" 2025/03/28 03:15:06 DEBUG : potato2: md5 = 29ea3635e4aefeb0ea3a999082dd8206 OK 2025/03/28 03:15:07 DEBUG : empty space: md5 = a123794e244c81ecb71103a988268624 OK 2025/03/28 03:15:08 DEBUG : potato3: md5 = b42491f6c28299c90b678463cf975b3a OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo' -> Encrypted drive 'TestCryptDrive:rclone-test-xelanen4rawi' 2025/03/28 03:15:11 DEBUG : empty space: md5 = b6cfdd31a62c3ad22185e5eeb3a6505f OK 2025/03/28 03:15:12 DEBUG : potato3: md5 = f121e32c3df34f3f811a8cb5aa4b90f2 OK 2025/03/28 03:15:13 DEBUG : empty space: Excluded (Size Filter) 2025/03/28 03:15:13 DEBUG : empty space: Excluded 2025/03/28 03:15:13 DEBUG : empty space: Excluded (Size Filter) 2025/03/28 03:15:13 DEBUG : empty space: Excluded 2025/03/28 03:15:13 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/28 03:15:13 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/28 03:15:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xelanen4rawi': Waiting for checks to finish 2025/03/28 03:15:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xelanen4rawi': Waiting for transfers to finish 2025/03/28 03:15:13 INFO : potato3: Deleted 2025/03/28 03:15:13 INFO : potato2: Moved (server-side) 2025/03/28 03:15:14 INFO : potato3: Moved (server-side) 2025/03/28 03:15:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bomubov1nema" 2025/03/28 03:15:14 DEBUG : Creating backend with remote "TestDrive:crypt/5qbc9bdm5c77nk485fger03mf6gl3b98lrfr54gg2bebcoce3kl0" 2025/03/28 03:15:15 DEBUG : empty space: Excluded (Size Filter) 2025/03/28 03:15:15 DEBUG : empty space: Excluded 2025/03/28 03:15:15 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/28 03:15:15 DEBUG : potato3: Need to transfer - File not found at Destination 2025/03/28 03:15:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bomubov1nema': Waiting for checks to finish 2025/03/28 03:15:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bomubov1nema': Waiting for transfers to finish 2025/03/28 03:15:17 INFO : potato2: Moved (server-side) 2025/03/28 03:15:17 INFO : potato3: Moved (server-side) 2025/03/28 03:15:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bomubov1nema': Purge remote 2025/03/28 03:15:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xelanen4rawi': Purge remote --- PASS: TestServerSideMoveWithFilter (15.71s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:15:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bonevur8buzu" 2025/03/28 03:15:19 DEBUG : Creating backend with remote "TestDrive:crypt/2eae2vope7mf1rtbokvsu9rii8rtlr20q54je5jhd9gsua771a6g" 2025/03/28 03:15:21 DEBUG : potato2: md5 = 003fb61e481f30513f0b277baa594f3d OK 2025/03/28 03:15:23 DEBUG : empty space: md5 = 507381cf7cb53a137975fba9a22b9794 OK 2025/03/28 03:15:24 DEBUG : potato3: md5 = 328aa61060d09ad84456a06573990f98 OK 2025/03/28 03:15:24 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo' -> Encrypted drive 'TestCryptDrive:rclone-test-bonevur8buzu' 2025/03/28 03:15:27 DEBUG : empty space: md5 = 391bd72c025aabb37be89787fb3c8885 OK 2025/03/28 03:15:29 DEBUG : potato3: md5 = 830c1fe0ac8187f7f9de5ed003ebe947 OK 2025/03/28 03:15:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bonevur8buzu': Using server-side directory move 2025/03/28 03:15:29 INFO : Encrypted drive 'TestCryptDrive:rclone-test-bonevur8buzu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/28 03:15:29 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/28 03:15:29 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/03/28 03:15:29 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/03/28 03:15:29 DEBUG : empty space: Unchanged skipping 2025/03/28 03:15:29 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/28 03:15:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bonevur8buzu': Waiting for checks to finish 2025/03/28 03:15:30 INFO : empty space: Deleted 2025/03/28 03:15:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bonevur8buzu': Waiting for transfers to finish 2025/03/28 03:15:30 INFO : potato3: Deleted 2025/03/28 03:15:30 INFO : potato2: Moved (server-side) 2025/03/28 03:15:30 INFO : potato3: Moved (server-side) 2025/03/28 03:15:30 INFO : tomatoDir: Removing directory 2025/03/28 03:15:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': deleted 1 directories 2025/03/28 03:15:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kawazey6jabu" 2025/03/28 03:15:32 DEBUG : Creating backend with remote "TestDrive:crypt/uvnkfesrgc3hhg3tlp1edo8dutchu0jk9dr840f3clkpprh0u8eg" 2025/03/28 03:15:33 INFO : tomatoDir: Making directory 2025/03/28 03:15:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kawazey6jabu': Using server-side directory move 2025/03/28 03:15:34 INFO : Encrypted drive 'TestCryptDrive:rclone-test-kawazey6jabu': Server side directory move succeeded 2025/03/28 03:15:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kawazey6jabu': Purge remote 2025/03/28 03:15:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bonevur8buzu': Purge remote 2025/03/28 03:15:36 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (17.53s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.46s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:15:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/rclone-sync-test" 2025/03/28 03:15:37 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncOverlap (3.65s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:15:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/rclone-sync-test" 2025/03/28 03:15:41 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/03/28 03:15:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/rclone-sync-test-include/layer2" 2025/03/28 03:15:43 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/03/28 03:15:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/rclone-sync-test-ignore-file" 2025/03/28 03:15:46 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/03/28 03:15:50 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = f193ea2544eabb81be59716919456e8a OK 2025/03/28 03:15:51 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/28 03:15:51 DEBUG : rclone-sync-test: Excluded 2025/03/28 03:15:51 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/03/28 03:15:52 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/28 03:15:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/rclone-sync-test': Waiting for checks to finish 2025/03/28 03:15:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/rclone-sync-test': Waiting for transfers to finish 2025/03/28 03:15:52 DEBUG : Waiting for deletions to finish 2025/03/28 03:15:52 INFO : There was nothing to transfer 2025/03/28 03:15:52 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/28 03:15:53 DEBUG : rclone-sync-test: Excluded 2025/03/28 03:15:53 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/28 03:15:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:15:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:15:53 DEBUG : Waiting for deletions to finish 2025/03/28 03:15:53 INFO : rclone-sync-test-include: Removing directory 2025/03/28 03:15:53 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/03/28 03:15:53 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/03/28 03:15:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': failed to delete 1 directories 2025/03/28 03:15:53 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:15:54 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/28 03:15:54 DEBUG : rclone-sync-test: Excluded 2025/03/28 03:15:54 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/03/28 03:15:55 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/28 03:15:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/03/28 03:15:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/03/28 03:15:55 DEBUG : Waiting for deletions to finish 2025/03/28 03:15:55 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:15:56 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/28 03:15:56 DEBUG : rclone-sync-test: Excluded 2025/03/28 03:15:57 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/28 03:15:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:15:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:15:57 DEBUG : Waiting for deletions to finish 2025/03/28 03:15:57 INFO : rclone-sync-test-include: Removing directory 2025/03/28 03:15:57 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/03/28 03:15:57 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/03/28 03:15:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': failed to delete 1 directories 2025/03/28 03:15:57 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:15:57 DEBUG : : Excluded 2025/03/28 03:15:58 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/28 03:15:58 DEBUG : rclone-sync-test: Excluded 2025/03/28 03:15:58 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/03/28 03:15:59 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/28 03:15:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/03/28 03:15:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/03/28 03:15:59 DEBUG : Waiting for deletions to finish 2025/03/28 03:15:59 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:16:01 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/03/28 03:16:01 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (29.76s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:16:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/dst" 2025/03/28 03:16:11 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/28 03:16:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/CompareDest" 2025/03/28 03:16:12 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/gveqi14airsml4bgu7krj116o8" 2025/03/28 03:16:14 DEBUG : one: Need to transfer - File not found at Destination 2025/03/28 03:16:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for checks to finish 2025/03/28 03:16:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for transfers to finish 2025/03/28 03:16:16 DEBUG : one: md5 = 74bebaa51f5f2b4f056e3ae48e07d959 OK 2025/03/28 03:16:16 INFO : one: Copied (new) 2025/03/28 03:16:16 DEBUG : Waiting for deletions to finish 2025/03/28 03:16:17 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/28 03:16:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for checks to finish 2025/03/28 03:16:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for transfers to finish 2025/03/28 03:16:19 DEBUG : one: md5 = 4d89a24dd0d9007b705829bc664a7d38 OK 2025/03/28 03:16:19 INFO : one: Copied (replaced existing) 2025/03/28 03:16:19 DEBUG : Waiting for deletions to finish 2025/03/28 03:16:21 DEBUG : dst/one: md5 = 3814e576ddd44ae1bc5c053435300057 OK 2025/03/28 03:16:23 DEBUG : CompareDest/one: md5 = 7ea9737571fdc53faf956ae61495d908 OK 2025/03/28 03:16:23 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/28 03:16:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for checks to finish 2025/03/28 03:16:24 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:16:24 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/28 03:16:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for transfers to finish 2025/03/28 03:16:24 DEBUG : Waiting for deletions to finish 2025/03/28 03:16:24 INFO : There was nothing to transfer 2025/03/28 03:16:26 DEBUG : CompareDest/two: md5 = 87d53877d10ffbaeb20210cd411378b6 OK 2025/03/28 03:16:27 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:16:27 DEBUG : two: Destination found in --compare-dest, skipping 2025/03/28 03:16:27 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/28 03:16:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for checks to finish 2025/03/28 03:16:27 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:16:27 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/28 03:16:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for transfers to finish 2025/03/28 03:16:27 DEBUG : Waiting for deletions to finish 2025/03/28 03:16:27 INFO : There was nothing to transfer 2025/03/28 03:16:28 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:16:28 DEBUG : two: Destination found in --compare-dest, skipping 2025/03/28 03:16:28 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/28 03:16:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for checks to finish 2025/03/28 03:16:28 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:16:28 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/28 03:16:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for transfers to finish 2025/03/28 03:16:28 DEBUG : Waiting for deletions to finish 2025/03/28 03:16:28 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/03/28 03:16:29 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/03/28 03:16:29 DEBUG : two: Need to transfer - File not found at Destination 2025/03/28 03:16:29 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/28 03:16:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for checks to finish 2025/03/28 03:16:30 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:16:30 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/28 03:16:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for transfers to finish 2025/03/28 03:16:31 DEBUG : two: md5 = 7a6f41689ea1a44ccc7456031522e174 OK 2025/03/28 03:16:31 INFO : two: Copied (new) 2025/03/28 03:16:31 DEBUG : Waiting for deletions to finish 2025/03/28 03:16:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/28 03:16:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/28 03:16:34 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/28 03:16:34 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncCompareDest (24.58s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:16:37 DEBUG : pre-dest1/1: md5 = c6e6c9c35c09163a604288b4238c316d OK 2025/03/28 03:16:39 DEBUG : pre-dest2/2: md5 = fb2724c9f851f7ea3f104a494224c961 OK 2025/03/28 03:16:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/dest" 2025/03/28 03:16:40 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/rg03c1jvnehrrc617i0lnqjddc" 2025/03/28 03:16:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/pre-dest1" 2025/03/28 03:16:41 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/bbnblvh6k061ssopqrp18kd7gc" 2025/03/28 03:16:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/pre-dest2" 2025/03/28 03:16:42 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/dgicm1h6b5ejvlltm8eeif0bnk" 2025/03/28 03:16:43 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:16:43 DEBUG : 1: Destination found in --compare-dest, skipping 2025/03/28 03:16:44 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:16:44 DEBUG : 2: Destination found in --compare-dest, skipping 2025/03/28 03:16:44 DEBUG : 3: Need to transfer - File not found at Destination 2025/03/28 03:16:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dest': Waiting for checks to finish 2025/03/28 03:16:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dest': Waiting for transfers to finish 2025/03/28 03:16:46 DEBUG : 3: md5 = 40467d363505c2c69070a9439a80c481 OK 2025/03/28 03:16:46 INFO : 3: Copied (new) 2025/03/28 03:16:46 DEBUG : Waiting for deletions to finish 2025/03/28 03:16:49 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/03/28 03:16:50 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/03/28 03:16:50 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (15.82s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:16:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/dst" 2025/03/28 03:16:51 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/28 03:16:52 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/CopyDest" 2025/03/28 03:16:52 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/d09o6po3f7bm6ce32vdgs8h9ls" 2025/03/28 03:16:54 DEBUG : one: Need to transfer - File not found at Destination 2025/03/28 03:16:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for checks to finish 2025/03/28 03:16:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for transfers to finish 2025/03/28 03:16:56 DEBUG : one: md5 = e2929564a3e2771b45ec6e8f026d823c OK 2025/03/28 03:16:56 INFO : one: Copied (new) 2025/03/28 03:16:56 DEBUG : Waiting for deletions to finish 2025/03/28 03:16:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for checks to finish 2025/03/28 03:16:57 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/28 03:16:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for transfers to finish 2025/03/28 03:16:59 DEBUG : one: md5 = 688560cdea3b8a5f74d8009f2aa864cd OK 2025/03/28 03:16:59 INFO : one: Copied (replaced existing) 2025/03/28 03:16:59 DEBUG : Waiting for deletions to finish 2025/03/28 03:17:01 DEBUG : dst/one: md5 = b3bc2bdb2026f2648b72c78232ca790e OK 2025/03/28 03:17:03 DEBUG : CopyDest/one: md5 = 0c2b48cc14a899146e52cb7ce97278f5 OK 2025/03/28 03:17:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/BackupDir" 2025/03/28 03:17:03 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/03/28 03:17:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for checks to finish 2025/03/28 03:17:05 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/28 03:17:06 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:17:06 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/28 03:17:07 INFO : one: Moved (server-side) 2025/03/28 03:17:08 INFO : one: Copied (server-side copy) 2025/03/28 03:17:08 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/03/28 03:17:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for transfers to finish 2025/03/28 03:17:08 DEBUG : Waiting for deletions to finish 2025/03/28 03:17:10 DEBUG : CopyDest/two: md5 = a54b3564504420946ce4ba3f409ee933 OK 2025/03/28 03:17:11 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:17:12 INFO : two: Copied (server-side copy) 2025/03/28 03:17:12 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/03/28 03:17:12 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:17:12 DEBUG : one: Unchanged skipping 2025/03/28 03:17:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for checks to finish 2025/03/28 03:17:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for transfers to finish 2025/03/28 03:17:12 DEBUG : Waiting for deletions to finish 2025/03/28 03:17:12 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:17:12 DEBUG : one: Unchanged skipping 2025/03/28 03:17:12 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:17:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for checks to finish 2025/03/28 03:17:12 DEBUG : two: Unchanged skipping 2025/03/28 03:17:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for transfers to finish 2025/03/28 03:17:12 DEBUG : Waiting for deletions to finish 2025/03/28 03:17:12 INFO : There was nothing to transfer 2025/03/28 03:17:14 DEBUG : CopyDest/three: md5 = 66be5c95d569ae68bad7d60f7a38e35a OK 2025/03/28 03:17:15 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/03/28 03:17:15 DEBUG : three: Destination not found in --copy-dest 2025/03/28 03:17:15 DEBUG : three: Need to transfer - File not found at Destination 2025/03/28 03:17:15 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:17:15 DEBUG : one: Unchanged skipping 2025/03/28 03:17:15 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/28 03:17:15 DEBUG : two: Unchanged skipping 2025/03/28 03:17:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for checks to finish 2025/03/28 03:17:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for transfers to finish 2025/03/28 03:17:16 DEBUG : three: md5 = dfeecc5ff4585866676e50d8eb9298a8 OK 2025/03/28 03:17:16 INFO : three: Copied (new) 2025/03/28 03:17:16 DEBUG : Waiting for deletions to finish 2025/03/28 03:17:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/03/28 03:17:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/28 03:17:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/28 03:17:21 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/28 03:17:21 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/03/28 03:17:21 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/28 03:17:22 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (31.78s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:17:25 DEBUG : dst/one: md5 = 5e7b7f002d7766e19843ae21862c9632 OK 2025/03/28 03:17:26 DEBUG : dst/two: md5 = 0c14f9dc860abf0a25cf08206a97f0c1 OK 2025/03/28 03:17:27 DEBUG : dst/three.txt: md5 = 0f15489fe225867baa15f190272bb2de OK 2025/03/28 03:17:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/dst" 2025/03/28 03:17:28 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/28 03:17:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/backup" 2025/03/28 03:17:29 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/1nrff024r7pq65ecp72fc28jb0" 2025/03/28 03:17:30 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/28 03:17:30 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:17:30 DEBUG : two: Unchanged skipping 2025/03/28 03:17:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for checks to finish 2025/03/28 03:17:32 INFO : one: Moved (server-side) 2025/03/28 03:17:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for transfers to finish 2025/03/28 03:17:33 DEBUG : one: md5 = e375ff06a45b03811194315dc398abe5 OK 2025/03/28 03:17:33 INFO : one: Copied (new) 2025/03/28 03:17:33 DEBUG : Waiting for deletions to finish 2025/03/28 03:17:34 INFO : three.txt: Moved (server-side) 2025/03/28 03:17:34 INFO : three.txt: Moved into backup dir 2025/03/28 03:17:36 DEBUG : dst/three.txt: md5 = 381c85e10d42575b5cc6d9c8087ab659 OK 2025/03/28 03:17:37 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/28 03:17:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for checks to finish 2025/03/28 03:17:37 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:17:37 DEBUG : two: Unchanged skipping 2025/03/28 03:17:37 INFO : one: Deleted 2025/03/28 03:17:38 INFO : one: Moved (server-side) 2025/03/28 03:17:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for transfers to finish 2025/03/28 03:17:39 DEBUG : one: md5 = bd41dd3ee3cdbd26f51324249040ecac OK 2025/03/28 03:17:39 INFO : one: Copied (new) 2025/03/28 03:17:39 DEBUG : Waiting for deletions to finish 2025/03/28 03:17:40 INFO : three.txt: Deleted 2025/03/28 03:17:41 INFO : three.txt: Moved (server-side) 2025/03/28 03:17:41 INFO : three.txt: Moved into backup dir 2025/03/28 03:17:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/28 03:17:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/28 03:17:45 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/03/28 03:17:45 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/28 03:17:45 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/28 03:17:45 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" --- PASS: TestSyncBackupDir (22.69s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:17:47 DEBUG : dst/one: md5 = be81cbce66cd0a7978fe6f70c005ac5a OK 2025/03/28 03:17:49 DEBUG : dst/two: md5 = 58d7c91d126ef982fb227d34ab2d517d OK 2025/03/28 03:17:50 DEBUG : dst/three.txt: md5 = 3ea314fb60de414b97e6ac3ddd7f332e OK 2025/03/28 03:17:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/dst" 2025/03/28 03:17:51 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/28 03:17:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/backup" 2025/03/28 03:17:52 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/1nrff024r7pq65ecp72fc28jb0" 2025/03/28 03:17:53 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/28 03:17:53 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:17:53 DEBUG : two: Unchanged skipping 2025/03/28 03:17:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for checks to finish 2025/03/28 03:17:54 INFO : one: Moved (server-side) to: one.bak 2025/03/28 03:17:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for transfers to finish 2025/03/28 03:17:56 DEBUG : one: md5 = 72587faf0a643b41a2387f4cde84bb7a OK 2025/03/28 03:17:56 INFO : one: Copied (new) 2025/03/28 03:17:56 DEBUG : Waiting for deletions to finish 2025/03/28 03:17:57 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/28 03:17:57 INFO : three.txt: Moved into backup dir 2025/03/28 03:17:59 DEBUG : dst/three.txt: md5 = 79427b803f5818de9a163f82835e6355 OK 2025/03/28 03:17:59 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/28 03:17:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for checks to finish 2025/03/28 03:17:59 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:17:59 DEBUG : two: Unchanged skipping 2025/03/28 03:18:00 INFO : one.bak: Deleted 2025/03/28 03:18:01 INFO : one: Moved (server-side) to: one.bak 2025/03/28 03:18:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for transfers to finish 2025/03/28 03:18:02 DEBUG : one: md5 = 6db5237d3caef4696163c505d69866fc OK 2025/03/28 03:18:02 INFO : one: Copied (new) 2025/03/28 03:18:02 DEBUG : Waiting for deletions to finish 2025/03/28 03:18:03 INFO : three.txt.bak: Deleted 2025/03/28 03:18:03 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/28 03:18:03 INFO : three.txt: Moved into backup dir 2025/03/28 03:18:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/28 03:18:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/28 03:18:07 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/28 03:18:07 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/28 03:18:07 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/28 03:18:07 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirWithSuffix (22.33s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:18:10 DEBUG : dst/one: md5 = 839a3789f7f1623892a3d45cf4c67852 OK 2025/03/28 03:18:11 DEBUG : dst/two: md5 = 616de44eb2aa17d9938215760cf5e884 OK 2025/03/28 03:18:12 DEBUG : dst/three.txt: md5 = a910b04cb82366107d878d2e589afa1c OK 2025/03/28 03:18:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/dst" 2025/03/28 03:18:13 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/28 03:18:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/backup" 2025/03/28 03:18:14 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/1nrff024r7pq65ecp72fc28jb0" 2025/03/28 03:18:15 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/28 03:18:15 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:18:15 DEBUG : two: Unchanged skipping 2025/03/28 03:18:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for checks to finish 2025/03/28 03:18:17 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/28 03:18:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for transfers to finish 2025/03/28 03:18:18 DEBUG : one: md5 = f0276c8043f2a6c2effc50bb81299100 OK 2025/03/28 03:18:18 INFO : one: Copied (new) 2025/03/28 03:18:18 DEBUG : Waiting for deletions to finish 2025/03/28 03:18:19 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/28 03:18:19 INFO : three.txt: Moved into backup dir 2025/03/28 03:18:21 DEBUG : dst/three.txt: md5 = a89ca798a9542732abf08d07798ef13a OK 2025/03/28 03:18:21 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/28 03:18:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for checks to finish 2025/03/28 03:18:21 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:18:21 DEBUG : two: Unchanged skipping 2025/03/28 03:18:22 INFO : one-2019-01-01: Deleted 2025/03/28 03:18:23 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/28 03:18:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for transfers to finish 2025/03/28 03:18:24 DEBUG : one: md5 = 0450f29d8611740252bea05ed492591b OK 2025/03/28 03:18:24 INFO : one: Copied (new) 2025/03/28 03:18:24 DEBUG : Waiting for deletions to finish 2025/03/28 03:18:25 INFO : three-2019-01-01.txt: Deleted 2025/03/28 03:18:25 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/28 03:18:25 INFO : three.txt: Moved into backup dir 2025/03/28 03:18:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/28 03:18:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/28 03:18:29 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/03/28 03:18:29 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/03/28 03:18:29 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/03/28 03:18:29 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (22.03s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:18:32 DEBUG : dst/one: md5 = 4dc7b7dc7e31afc0d01e0e6ae1cb3e3d OK 2025/03/28 03:18:33 DEBUG : dst/two: md5 = 48ec2cbb8c61aa69a7bc4d74bb1478bb OK 2025/03/28 03:18:34 DEBUG : dst/three.txt: md5 = 15941c4112c6baca66609b870dcbb94f OK 2025/03/28 03:18:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/dst" 2025/03/28 03:18:35 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/28 03:18:36 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/28 03:18:36 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:18:36 DEBUG : two: Unchanged skipping 2025/03/28 03:18:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for checks to finish 2025/03/28 03:18:36 INFO : one: Moved (server-side) to: one.bak 2025/03/28 03:18:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for transfers to finish 2025/03/28 03:18:38 DEBUG : one: md5 = feb94c3ab5e0c0624b88efd242af8f0f OK 2025/03/28 03:18:38 INFO : one: Copied (new) 2025/03/28 03:18:38 DEBUG : Waiting for deletions to finish 2025/03/28 03:18:39 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/28 03:18:39 INFO : three.txt: Moved into backup dir 2025/03/28 03:18:40 DEBUG : dst/three.txt: md5 = e5e505803d7480c9e8ea9f4d5f28ad56 OK 2025/03/28 03:18:41 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/03/28 03:18:41 DEBUG : three.txt.bak: Excluded 2025/03/28 03:18:41 DEBUG : one.bak: Excluded (Path Filter) 2025/03/28 03:18:41 DEBUG : one.bak: Excluded 2025/03/28 03:18:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for checks to finish 2025/03/28 03:18:41 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/28 03:18:41 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:18:41 DEBUG : two: Unchanged skipping 2025/03/28 03:18:42 INFO : one.bak: Deleted 2025/03/28 03:18:42 INFO : one: Moved (server-side) to: one.bak 2025/03/28 03:18:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo/dst': Waiting for transfers to finish 2025/03/28 03:18:43 DEBUG : one: md5 = 98d34e80880e6b0c02eafacd223ff341 OK 2025/03/28 03:18:43 INFO : one: Copied (new) 2025/03/28 03:18:43 DEBUG : Waiting for deletions to finish 2025/03/28 03:18:44 INFO : three.txt.bak: Deleted 2025/03/28 03:18:45 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/28 03:18:45 INFO : three.txt: Moved into backup dir 2025/03/28 03:18:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/28 03:18:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/28 03:18:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/28 03:18:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/28 03:18:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/28 03:18:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirSuffixOnly (18.57s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:18:50 DEBUG : dst/one: md5 = 5679355c54c3b490c7a4ad7c7476b5a0 OK 2025/03/28 03:18:52 DEBUG : dst/two: md5 = a17785012dc2f084eb4586584bb88c94 OK 2025/03/28 03:18:53 DEBUG : dst/three.txt: md5 = 1a0dc0d0369b58b94fff1c5a889aa804 OK 2025/03/28 03:18:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/dst" 2025/03/28 03:18:53 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/28 03:18:54 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/28 03:18:55 INFO : one: Moved (server-side) to: one.bak 2025/03/28 03:18:56 DEBUG : one: md5 = 3e4be3e084e333b4c08823d9de3ec604 OK 2025/03/28 03:18:56 INFO : one: Copied (new) 2025/03/28 03:18:56 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:18:56 DEBUG : two: Unchanged skipping 2025/03/28 03:18:57 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/03/28 03:18:57 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/28 03:18:59 DEBUG : three.txt: md5 = eaf310bbf72e45af1270cc72ccfa5d4d OK 2025/03/28 03:18:59 INFO : three.txt: Copied (new) 2025/03/28 03:19:00 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/28 03:19:01 INFO : one.bak: Deleted 2025/03/28 03:19:01 INFO : one: Moved (server-side) to: one.bak 2025/03/28 03:19:02 DEBUG : one: md5 = 6d97a5c81c9cf08b9b820c9df66bb213 OK 2025/03/28 03:19:02 INFO : one: Copied (new) 2025/03/28 03:19:03 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:19:03 DEBUG : two: Unchanged skipping 2025/03/28 03:19:03 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/03/28 03:19:04 INFO : three.txt.bak: Deleted 2025/03/28 03:19:04 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/28 03:19:05 DEBUG : three.txt: md5 = 2d40daa8715e75f2e7665abac0231e8d OK 2025/03/28 03:19:05 INFO : three.txt: Copied (new) 2025/03/28 03:19:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/03/28 03:19:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/28 03:19:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/28 03:19:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/28 03:19:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/28 03:19:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/28 03:19:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncSuffix (20.99s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:19:11 DEBUG : dst/one: md5 = 9269c85f09c4847e08847511e655f458 OK 2025/03/28 03:19:13 DEBUG : dst/two: md5 = 8a985f1c54726bbc1071008ad4ae3ec1 OK 2025/03/28 03:19:14 DEBUG : dst/three.txt: md5 = 8de8fefce40ef11063ab6bdcd5f073ab OK 2025/03/28 03:19:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zigevab8sivo/dst" 2025/03/28 03:19:15 DEBUG : Creating backend with remote "TestDrive:crypt/lbmjstlk93fs7u3r2uv5htuqsdu44u8fb66r5493gcojfcm1ca9g/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/28 03:19:16 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/28 03:19:16 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/28 03:19:18 DEBUG : one: md5 = 9fec9aa97ec752d2f40fbb8c35bc4569 OK 2025/03/28 03:19:18 INFO : one: Copied (new) 2025/03/28 03:19:18 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:19:18 DEBUG : two: Unchanged skipping 2025/03/28 03:19:18 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/03/28 03:19:19 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/28 03:19:20 DEBUG : three.txt: md5 = 2d4fb7a869a0f4e70d48dfc66d1bf8fe OK 2025/03/28 03:19:20 INFO : three.txt: Copied (new) 2025/03/28 03:19:21 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/28 03:19:22 INFO : one-2019-01-01: Deleted 2025/03/28 03:19:22 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/28 03:19:24 DEBUG : one: md5 = 61688d90cdc1fbd947c60a65ea6ff027 OK 2025/03/28 03:19:24 INFO : one: Copied (new) 2025/03/28 03:19:24 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:19:24 DEBUG : two: Unchanged skipping 2025/03/28 03:19:24 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/03/28 03:19:25 INFO : three-2019-01-01.txt: Deleted 2025/03/28 03:19:26 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/28 03:19:27 DEBUG : three.txt: md5 = 26db0cce8cf0d991c68c3d64b1b69e70 OK 2025/03/28 03:19:27 INFO : three.txt: Copied (new) 2025/03/28 03:19:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/28 03:19:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/03/28 03:19:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/03/28 03:19:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/03/28 03:19:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/03/28 03:19:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/28 03:19:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (21.67s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:19:32 DEBUG : Testêé: md5 = 832bdf57732a6b9efa39b7521b6f490e OK 2025/03/28 03:19:33 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/03/28 03:19:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:19:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:19:34 DEBUG : Testêé: md5 = f8520a842e44d942cc6c3faf5900b22d OK 2025/03/28 03:19:34 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/03/28 03:19:34 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.23s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:19:36 DEBUG : existing: Need to transfer - File not found at Destination 2025/03/28 03:19:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:19:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:19:37 DEBUG : existing: md5 = c161370f82c2f956ad7b05f46c780492 OK 2025/03/28 03:19:37 INFO : existing: Copied (new) 2025/03/28 03:19:37 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:19:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:19:38 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/03/28 03:19:38 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/03/28 03:19:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:19:38 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': not deleting files as there were IO errors 2025/03/28 03:19:38 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncImmutable (4.42s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:19:41 DEBUG : EXISTING: md5 = 471b4452913d9a31b539b9149cae383a OK 2025/03/28 03:19:41 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:19:41 DEBUG : existing: Unchanged skipping 2025/03/28 03:19:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:19:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:19:41 DEBUG : Waiting for deletions to finish 2025/03/28 03:19:41 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (2.88s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.42s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", 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-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", 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-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.29s) --- SKIP: TestMaxTransfer/Hard (0.43s) --- SKIP: TestMaxTransfer/Soft (0.45s) --- SKIP: TestMaxTransfer/Cautious (0.41s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:19:45 DEBUG : both0: md5 = 98cbce841e43452aae005b58ee5a15dc OK 2025/03/28 03:19:47 DEBUG : only0: md5 = 7a06f7d16ea20b9bc4267aecb67ae562 OK 2025/03/28 03:19:48 DEBUG : both1: md5 = c5a0c9746bee23e2de834d0244fa0721 OK 2025/03/28 03:19:50 DEBUG : only1: md5 = b79f88e4df6f09ea36a4844a2ac4dafb OK 2025/03/28 03:19:51 DEBUG : both2: md5 = f2253d5c02f6b31b2b2ffaa768825181 OK 2025/03/28 03:19:52 DEBUG : only2: md5 = ccf086bb6395eb60b45a65c5038ca6ae OK 2025/03/28 03:19:53 DEBUG : both3: md5 = 1af3c86e2c4f886f6977c2221799e41a OK 2025/03/28 03:19:55 DEBUG : only3: md5 = 5313540bbecf5905766dc54b69d1a663 OK 2025/03/28 03:19:56 DEBUG : both4: md5 = 48e2ef32cac111c97f1ce30e63805afb OK 2025/03/28 03:19:58 DEBUG : only4: md5 = 08022ef396993600cb5420ad0de2a48a OK 2025/03/28 03:19:59 DEBUG : both5: md5 = 38bebaedd5f56f0a146fa8244c95270c OK 2025/03/28 03:20:00 DEBUG : only5: md5 = dafde30c8df097b3bebf1a4c332ca740 OK 2025/03/28 03:20:02 DEBUG : both6: md5 = 44a2618677ca5a1f68a0e6ed356b5967 OK 2025/03/28 03:20:03 DEBUG : only6: md5 = 3e3d5d7105852d6593757eff56285d00 OK 2025/03/28 03:20:04 DEBUG : both7: md5 = 0e823ce3bc4e47465be511a18948e1aa OK 2025/03/28 03:20:06 DEBUG : only7: md5 = fbdc39e3047afcabde3cf9aa526d6d84 OK 2025/03/28 03:20:07 DEBUG : both8: md5 = 21d3dfcdc9531d7623b5e63c0d2a4001 OK 2025/03/28 03:20:08 DEBUG : only8: md5 = 338e572dc27188e7462fee32f17c6203 OK 2025/03/28 03:20:10 DEBUG : both9: md5 = fdb86a34bc7c79ed57be4d13b05b850e OK 2025/03/28 03:20:11 DEBUG : only9: md5 = a76d16777be0d10f0f4e963be1d45250 OK 2025/03/28 03:20:13 DEBUG : both10: md5 = 3c5eeb21b14d68bbb3e1b8a9ae87702f OK 2025/03/28 03:20:14 DEBUG : only10: md5 = 36f593e8752d1167749658e6939130a4 OK 2025/03/28 03:20:15 DEBUG : both11: md5 = e65d0de9216c44a178087e923c5dc8c6 OK 2025/03/28 03:20:16 DEBUG : only11: md5 = 9956c2d2cebe0ae79bfffc0d42273e43 OK 2025/03/28 03:20:18 DEBUG : both12: md5 = 2afd6a966f71ad51ff0fbb27f6e57d40 OK 2025/03/28 03:20:19 DEBUG : only12: md5 = 77a5af56442181ad6853821e0f3b451f OK 2025/03/28 03:20:20 DEBUG : both13: md5 = 5c834f2ea5773a0d0b2f8f6a1c4f1f0a OK 2025/03/28 03:20:22 DEBUG : only13: md5 = dc0ebae2a925732ffcbbff57c5abfd0d OK 2025/03/28 03:20:23 DEBUG : both14: md5 = ea6804e32db62837effbcaf0e7183655 OK 2025/03/28 03:20:24 DEBUG : only14: md5 = 21c539fd05ad0d7090de205a7e01ca62 OK 2025/03/28 03:20:26 DEBUG : both15: md5 = 1993c7acf3850a3d271d4127f25f1e2b OK 2025/03/28 03:20:27 DEBUG : only15: md5 = 375cdcd925930baf8fbf9802748961ba OK 2025/03/28 03:20:28 DEBUG : both16: md5 = 19af70cf143d57b1c84f17d08f4865cc OK 2025/03/28 03:20:30 DEBUG : only16: md5 = b4d75a4d1433af073c22512e7810b8d7 OK 2025/03/28 03:20:31 DEBUG : both17: md5 = 803e42169fc5ca0a9241aaba58e5fa97 OK 2025/03/28 03:20:33 DEBUG : only17: md5 = 3a42695623f27f7b4bcda16cc38a714d OK 2025/03/28 03:20:34 DEBUG : both18: md5 = 6dd0d8c64d0349eadcd2fd4fa4408bd1 OK 2025/03/28 03:20:35 DEBUG : only18: md5 = 854ed5af6fa25823eddc3c571f5bc9c5 OK 2025/03/28 03:20:37 DEBUG : both19: md5 = 8159e404af27e7201aa7220e363c4d34 OK 2025/03/28 03:20:38 DEBUG : only19: md5 = c177db13fab28a239044fc4954e0d684 OK 2025/03/28 03:20:39 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:20:39 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:20:39 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:20:39 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:20:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:20:39 DEBUG : both1: Unchanged skipping 2025/03/28 03:20:39 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:20:39 DEBUG : both12: Unchanged skipping 2025/03/28 03:20:39 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:20:39 DEBUG : both13: Unchanged skipping 2025/03/28 03:20:39 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:20:39 DEBUG : both14: Unchanged skipping 2025/03/28 03:20:39 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:20:39 DEBUG : both15: Unchanged skipping 2025/03/28 03:20:39 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:20:39 DEBUG : both16: Unchanged skipping 2025/03/28 03:20:39 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:20:39 DEBUG : both10: Unchanged skipping 2025/03/28 03:20:39 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:20:39 DEBUG : both18: Unchanged skipping 2025/03/28 03:20:39 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:20:39 DEBUG : both19: Unchanged skipping 2025/03/28 03:20:39 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:20:39 DEBUG : both2: Unchanged skipping 2025/03/28 03:20:39 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:20:39 DEBUG : both11: Unchanged skipping 2025/03/28 03:20:39 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:20:39 DEBUG : both0: Unchanged skipping 2025/03/28 03:20:39 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:20:39 DEBUG : both17: Unchanged skipping 2025/03/28 03:20:39 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:20:39 DEBUG : both3: Unchanged skipping 2025/03/28 03:20:39 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:20:39 DEBUG : both6: Unchanged skipping 2025/03/28 03:20:39 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:20:39 DEBUG : both7: Unchanged skipping 2025/03/28 03:20:39 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:20:39 DEBUG : both9: Unchanged skipping 2025/03/28 03:20:39 DEBUG : both5: Unchanged skipping 2025/03/28 03:20:39 DEBUG : both4: Unchanged skipping 2025/03/28 03:20:39 DEBUG : both8: Unchanged skipping 2025/03/28 03:20:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:20:39 DEBUG : Waiting for deletions to finish 2025/03/28 03:20:39 INFO : only2: Deleted 2025/03/28 03:20:39 INFO : only4: Deleted 2025/03/28 03:20:39 INFO : only18: Deleted 2025/03/28 03:20:39 INFO : only12: Deleted 2025/03/28 03:20:40 INFO : only8: Deleted 2025/03/28 03:20:40 INFO : only15: Deleted 2025/03/28 03:20:40 INFO : only17: Deleted 2025/03/28 03:20:40 INFO : only7: Deleted 2025/03/28 03:20:40 INFO : only5: Deleted 2025/03/28 03:20:40 INFO : only16: Deleted 2025/03/28 03:20:40 INFO : only19: Deleted 2025/03/28 03:20:40 INFO : only3: Deleted 2025/03/28 03:20:40 INFO : only6: Deleted 2025/03/28 03:20:41 INFO : only0: Deleted 2025/03/28 03:20:41 INFO : only9: Deleted 2025/03/28 03:20:41 INFO : only1: Deleted 2025/03/28 03:20:41 INFO : only10: Deleted 2025/03/28 03:20:41 INFO : only11: Deleted 2025/03/28 03:20:41 INFO : only14: Deleted 2025/03/28 03:20:41 INFO : only13: Deleted 2025/03/28 03:20:41 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (66.89s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:20:53 DEBUG : both0: md5 = ce3c24cc7be2f3947bb314dee02f0d34 OK 2025/03/28 03:20:54 DEBUG : only0: md5 = c1b6add3b22ed4fd06f1d4afae1b1d4c OK 2025/03/28 03:20:55 DEBUG : both1: md5 = 8b9995c210e757d1dd3b6cdb28e2beff OK 2025/03/28 03:20:57 DEBUG : only1: md5 = bd6cf9569e215e57de89e597584737b6 OK 2025/03/28 03:20:58 DEBUG : both2: md5 = 0202f5f6db79c7d4ffce110680090e1c OK 2025/03/28 03:20:59 DEBUG : only2: md5 = 224b037e99e2c5c11f70fdc7d231d530 OK 2025/03/28 03:21:01 DEBUG : both3: md5 = 6e78a500da8c6e9c06ebfd9b1ab24502 OK 2025/03/28 03:21:02 DEBUG : only3: md5 = ac159e47ae662578f9ab0f3479b1cdef OK 2025/03/28 03:21:04 DEBUG : both4: md5 = 9d374162b80e26ac475cfd3f231e39b6 OK 2025/03/28 03:21:05 DEBUG : only4: md5 = 70b701e6dbd6a1b3f735b36eabf91943 OK 2025/03/28 03:21:06 DEBUG : both5: md5 = abf75ccb99ab2dfa56db5980c127cc05 OK 2025/03/28 03:21:08 DEBUG : only5: md5 = 96911da7930c07d0a8f79f4eeb8ef59f OK 2025/03/28 03:21:09 DEBUG : both6: md5 = 3bd491d7c5afe5b07b9539902879bf64 OK 2025/03/28 03:21:10 DEBUG : only6: md5 = 8c9a090cb20b00d7fc9834bff517ca0d OK 2025/03/28 03:21:12 DEBUG : both7: md5 = 3fb0cd5d0ab22bd6bb0bfc95b7146cb2 OK 2025/03/28 03:21:13 DEBUG : only7: md5 = 70697a540beb629c0494ad5af2684400 OK 2025/03/28 03:21:15 DEBUG : both8: md5 = a6a4dc66aa8bbe56e4e4c30d4f44a697 OK 2025/03/28 03:21:16 DEBUG : only8: md5 = ed84cd7e87c79d6469d853d4a14b0ea7 OK 2025/03/28 03:21:17 DEBUG : both9: md5 = aa90088f15d6c103348331c04aa8a8ed OK 2025/03/28 03:21:19 DEBUG : only9: md5 = 9d26dc7881dacf5aa89e2de2d5475ba4 OK 2025/03/28 03:21:20 DEBUG : both10: md5 = e10a0adabaa8d4b2e92dedc8cc7b02a0 OK 2025/03/28 03:21:21 DEBUG : only10: md5 = f0937ea7c2395e20f5a4ed04dc6e35d4 OK 2025/03/28 03:21:23 DEBUG : both11: md5 = 248455a89d766b2393715716b7984d92 OK 2025/03/28 03:21:24 DEBUG : only11: md5 = e50da7a0c4dda6f1a267741bd7ea2e83 OK 2025/03/28 03:21:25 DEBUG : both12: md5 = c8c11add3b994981daaf2094ae9c1525 OK 2025/03/28 03:21:26 DEBUG : only12: md5 = c13470757a1e24e618e4ef58ff33c161 OK 2025/03/28 03:21:28 DEBUG : both13: md5 = ceb448f67f48fbccf44141cf7d7f7053 OK 2025/03/28 03:21:29 DEBUG : only13: md5 = 46101181ae09401c3789c0ca36be2a63 OK 2025/03/28 03:21:30 DEBUG : both14: md5 = db93f13758b93f5c6d94fb2c7c4dded2 OK 2025/03/28 03:21:31 DEBUG : Config file has changed externally - reloading 2025/03/28 03:21:31 DEBUG : TestDrive: Loaded fresh token from config file 2025/03/28 03:21:32 DEBUG : only14: md5 = 3d1f37a909b201da334d2f196ea41b53 OK 2025/03/28 03:21:33 DEBUG : both15: md5 = 19506e5a8770fb7a42170e7d011e1f58 OK 2025/03/28 03:21:35 DEBUG : only15: md5 = 7afac95e7197cdfaf9d36897b882934b OK 2025/03/28 03:21:36 DEBUG : both16: md5 = b25a10420bc24c9643185944a2385dd8 OK 2025/03/28 03:21:37 DEBUG : only16: md5 = 35733d34ec70ec2502e7b0fcbab1f1f2 OK 2025/03/28 03:21:39 DEBUG : both17: md5 = dd59f1b58c89026f35fd6d833480766c OK 2025/03/28 03:21:40 DEBUG : only17: md5 = c72a3a26ea2a839690f4fae3a926cf97 OK 2025/03/28 03:21:41 DEBUG : both18: md5 = bc56f81e00009de6d4695e0d55eab7d1 OK 2025/03/28 03:21:43 DEBUG : only18: md5 = 012fea150b28cf1769a373d0b959860b OK 2025/03/28 03:21:44 DEBUG : both19: md5 = de102b3bf46930d85f046bb7b4f51a37 OK 2025/03/28 03:21:45 DEBUG : only19: md5 = 96a101f2bc85726b656ad7b01a7650e5 OK 2025/03/28 03:21:46 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:21:46 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:21:46 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:21:46 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:21:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for checks to finish 2025/03/28 03:21:46 DEBUG : both0: Unchanged skipping 2025/03/28 03:21:46 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:21:46 DEBUG : both12: Unchanged skipping 2025/03/28 03:21:46 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:21:46 DEBUG : both13: Unchanged skipping 2025/03/28 03:21:46 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:21:46 DEBUG : both1: Unchanged skipping 2025/03/28 03:21:46 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:21:46 DEBUG : both15: Unchanged skipping 2025/03/28 03:21:46 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:21:46 DEBUG : both16: Unchanged skipping 2025/03/28 03:21:46 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:21:46 DEBUG : both17: Unchanged skipping 2025/03/28 03:21:46 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:21:46 DEBUG : both11: Unchanged skipping 2025/03/28 03:21:46 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:21:46 DEBUG : both19: Unchanged skipping 2025/03/28 03:21:46 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:21:46 DEBUG : both10: Unchanged skipping 2025/03/28 03:21:46 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:21:46 DEBUG : both14: Unchanged skipping 2025/03/28 03:21:46 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:21:46 DEBUG : both4: Unchanged skipping 2025/03/28 03:21:46 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:21:46 DEBUG : both5: Unchanged skipping 2025/03/28 03:21:46 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:21:46 DEBUG : both18: Unchanged skipping 2025/03/28 03:21:46 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:21:46 DEBUG : both6: Unchanged skipping 2025/03/28 03:21:46 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:21:46 DEBUG : both8: Unchanged skipping 2025/03/28 03:21:46 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/28 03:21:46 DEBUG : both9: Unchanged skipping 2025/03/28 03:21:46 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/03/28 03:21:46 DEBUG : both2: Unchanged skipping 2025/03/28 03:21:46 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/03/28 03:21:46 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/03/28 03:21:46 DEBUG : both3: Unchanged skipping 2025/03/28 03:21:46 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/03/28 03:21:46 DEBUG : both7: Unchanged skipping 2025/03/28 03:21:46 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/03/28 03:21:46 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/03/28 03:21:46 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/03/28 03:21:46 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/03/28 03:21:46 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/03/28 03:21:46 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/03/28 03:21:46 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/03/28 03:21:46 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/03/28 03:21:46 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/03/28 03:21:46 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/03/28 03:21:46 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/03/28 03:21:46 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/03/28 03:21:46 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/03/28 03:21:46 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/03/28 03:21:46 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/03/28 03:21:46 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/03/28 03:21:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Waiting for transfers to finish 2025/03/28 03:21:47 DEBUG : only10: md5 = 07258e3a5ebd90038086d142780e6335 OK 2025/03/28 03:21:47 INFO : only10: Copied (replaced existing) 2025/03/28 03:21:47 DEBUG : only13: md5 = c73ff6784441eb8b8508ce70639b316a OK 2025/03/28 03:21:47 INFO : only13: Copied (replaced existing) 2025/03/28 03:21:47 DEBUG : only14: md5 = c1ac91cada9a43490c1258639df49c59 OK 2025/03/28 03:21:47 INFO : only14: Copied (replaced existing) 2025/03/28 03:21:47 DEBUG : only0: md5 = f92a159680494bf4636a9940bcefbbd7 OK 2025/03/28 03:21:47 INFO : only0: Copied (replaced existing) 2025/03/28 03:21:48 DEBUG : only15: md5 = 77dc0549c5d117e02dccc939e16e3b7b OK 2025/03/28 03:21:48 INFO : only15: Copied (replaced existing) 2025/03/28 03:21:48 DEBUG : only17: md5 = df2cc1e65da08d1c37f344a868d629a1 OK 2025/03/28 03:21:48 INFO : only17: Copied (replaced existing) 2025/03/28 03:21:48 DEBUG : only16: md5 = 8acd8ec2866560aef800e35e38f31e18 OK 2025/03/28 03:21:48 INFO : only16: Copied (replaced existing) 2025/03/28 03:21:48 DEBUG : only18: md5 = 6f539513e4ed11ee3027b81cd526bd64 OK 2025/03/28 03:21:48 INFO : only18: Copied (replaced existing) 2025/03/28 03:21:49 DEBUG : only2: md5 = de72f0c0c9981fd9c7b1338c60ebc068 OK 2025/03/28 03:21:49 INFO : only2: Copied (replaced existing) 2025/03/28 03:21:49 DEBUG : only11: md5 = 0c49eda8b1b65978999dc4263d7d1b95 OK 2025/03/28 03:21:49 INFO : only11: Copied (replaced existing) 2025/03/28 03:21:49 DEBUG : only19: md5 = b2af05d742d060aa980fee681598ff11 OK 2025/03/28 03:21:49 INFO : only19: Copied (replaced existing) 2025/03/28 03:21:49 DEBUG : only4: md5 = 4f46d5922cef4c6044c8b40ae3241f5c OK 2025/03/28 03:21:49 INFO : only4: Copied (replaced existing) 2025/03/28 03:21:50 DEBUG : only3: md5 = 8beb580886bbfc021d7fcca4f2788a5b OK 2025/03/28 03:21:50 INFO : only3: Copied (replaced existing) 2025/03/28 03:21:50 DEBUG : only12: md5 = 1aa885c224021f8fec7e2d19afce5cea OK 2025/03/28 03:21:50 INFO : only12: Copied (replaced existing) 2025/03/28 03:21:50 DEBUG : only1: md5 = 7e685c7e979f3be78e257806e20f182a OK 2025/03/28 03:21:50 INFO : only1: Copied (replaced existing) 2025/03/28 03:21:50 DEBUG : only5: md5 = beb05231d31b9fe27beade32f06ffe42 OK 2025/03/28 03:21:50 INFO : only5: Copied (replaced existing) 2025/03/28 03:21:51 DEBUG : only9: md5 = 200f646b2365256eb0f3607741cbe872 OK 2025/03/28 03:21:51 INFO : only9: Copied (replaced existing) 2025/03/28 03:21:51 DEBUG : only6: md5 = 7886d677a0e7c4da09ca29c5747950f1 OK 2025/03/28 03:21:51 INFO : only6: Copied (replaced existing) 2025/03/28 03:21:51 DEBUG : only7: md5 = ba51c12d2b7ca16a22c3146bd7eaf646 OK 2025/03/28 03:21:51 INFO : only7: Copied (replaced existing) 2025/03/28 03:21:52 DEBUG : only8: md5 = 632e2c12e32c2558a8242bfee1482f1d OK 2025/03/28 03:21:52 INFO : only8: Copied (replaced existing) 2025/03/28 03:21:52 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (78.87s) === RUN TestSyncReplaceDirModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:22:10 DEBUG : empty_dir: Making directory with metadata 2025/03/28 03:22:10 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/28 03:22:10 DEBUG : empty_on_remote: Making directory with metadata 2025/03/28 03:22:10 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/28 03:22:10 DEBUG : empty_on_remote: Making directory with metadata 2025/03/28 03:22:11 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:22:15 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/03/28 03:22:15 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/03/28 03:22:15 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/03/28 03:22:15 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:22:22 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/03/28 03:22:23 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/03/28 03:22:23 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTime (15.53s) === RUN TestSyncReplaceDirModTimeWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:22:25 DEBUG : empty_dir: Making directory with metadata 2025/03/28 03:22:25 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/28 03:22:25 DEBUG : empty_on_remote: Making directory with metadata 2025/03/28 03:22:25 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/28 03:22:25 DEBUG : empty_on_remote: Making directory with metadata 2025/03/28 03:22:26 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:22:31 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/03/28 03:22:31 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/03/28 03:22:31 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/03/28 03:22:31 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) 2025/03/28 03:22:31 INFO : empty_dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:22:38 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/03/28 03:22:39 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/03/28 03:22:39 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (16.69s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:22:42 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/28 03:22:42 DEBUG : sub dir: Making directory with metadata 2025/03/28 03:22:43 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:22:59 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/28 03:23:00 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/28 03:23:00 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/28 03:23:00 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:23:11 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/03/28 03:23:12 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/28 03:23:13 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/03/28 03:23:13 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/03/28 03:23:14 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/28 03:23:15 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/28 03:23:16 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/28 03:23:16 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/28 03:23:17 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/28 03:23:18 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/03/28 03:23:18 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/28 03:23:18 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (38.12s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:23:20 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/28 03:23:20 DEBUG : sub dir: Making directory with metadata 2025/03/28 03:23:21 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:23:42 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/28 03:23:42 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/28 03:23:42 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/28 03:23:42 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo'", Local "Local file system at /tmp/rclone3566264151", Modify Window "1ms" 2025/03/28 03:23:53 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/28 03:23:54 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/03/28 03:23:55 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/03/28 03:23:55 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/28 03:23:56 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/28 03:23:57 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/28 03:23:57 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/28 03:23:58 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/28 03:23:59 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/03/28 03:23:59 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/28 03:23:59 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (40.99s) PASS 2025/03/28 03:24:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zigevab8sivo': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 15m15.446692042s (try 1/5)